2020-08-19T14:23:38.019Z,1597847018.019 [Supervisor](DEBUG): Initializing supervisor.
2020-08-19T14:23:38.021Z,1597847018.021 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2020-08-19T14:23:38.022Z,1597847018.022 [SyncHandler](INFO): Protected caller Thread ID is 819
2020-08-19T14:23:38.022Z,1597847018.022 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2020-08-19T14:23:38.023Z,1597847018.023 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2020-08-19T14:23:38.024Z,1597847018.024 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 820
2020-08-19T14:23:38.027Z,1597847018.027 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2020-08-19T14:23:38.040Z,1597847018.040 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2020-08-19T14:23:38.041Z,1597847018.041 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2020-08-19T14:23:38.041Z,1597847018.041 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 821
2020-08-19T14:23:38.042Z,1597847018.042 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2020-08-19T14:23:38.043Z,1597847018.043 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2020-08-19T14:23:38.043Z,1597847018.043 [logger ThreadHandler](INFO): Protected caller Thread ID is 822
2020-08-19T14:23:38.046Z,1597847018.046 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2020-08-19T14:23:38.046Z,1597847018.046 [Supervisor](INFO): Looking for Config files in directory: Config/
2020-08-19T14:23:38.050Z,1597847018.050 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2020-08-19T14:23:38.261Z,1597847018.261 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2020-08-19T14:23:38.263Z,1597847018.263 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2020-08-19T14:23:38.345Z,1597847018.345 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2020-08-19T14:23:38.786Z,1597847018.786 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2020-08-19T14:23:38.788Z,1597847018.788 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2020-08-19T14:23:39.144Z,1597847019.144 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2020-08-19T14:23:39.146Z,1597847019.146 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2020-08-19T14:23:39.243Z,1597847019.243 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2020-08-19T14:23:39.244Z,1597847019.244 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2020-08-19T14:23:39.551Z,1597847019.551 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2020-08-19T14:23:39.551Z,1597847019.551 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2020-08-19T14:23:39.750Z,1597847019.750 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2020-08-19T14:23:39.752Z,1597847019.752 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2020-08-19T14:23:40.235Z,1597847020.235 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2020-08-19T14:23:40.237Z,1597847020.237 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2020-08-19T14:23:40.342Z,1597847020.342 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2020-08-19T14:23:40.344Z,1597847020.344 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2020-08-19T14:23:40.446Z,1597847020.446 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2020-08-19T14:23:40.446Z,1597847020.446 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2020-08-19T14:23:41.348Z,1597847021.348 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2020-08-19T14:23:41.504Z,1597847021.504 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2020-08-19T14:23:42.393Z,1597847022.393 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2020-08-19T14:23:42.393Z,1597847022.393 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2020-08-19T14:23:42.594Z,1597847022.594 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2020-08-19T14:23:42.596Z,1597847022.596 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2020-08-19T14:23:42.744Z,1597847022.744 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2020-08-19T14:23:42.744Z,1597847022.744 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2020-08-19T14:23:42.896Z,1597847022.896 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2020-08-19T14:23:42.896Z,1597847022.896 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2020-08-19T14:23:43.109Z,1597847023.109 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2020-08-19T14:23:43.111Z,1597847023.111 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2020-08-19T14:23:43.113Z,1597847023.113 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg
2020-08-19T14:23:43.205Z,1597847023.205 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2020-08-19T14:23:43.291Z,1597847023.291 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2020-08-19T14:23:43.395Z,1597847023.395 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg
2020-08-19T14:23:43.479Z,1597847023.479 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2020-08-19T14:23:43.575Z,1597847023.575 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2020-08-19T14:23:43.677Z,1597847023.677 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2020-08-19T14:23:43.891Z,1597847023.891 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/workSite.cfg
2020-08-19T14:23:43.968Z,1597847023.968 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2020-08-19T14:23:44.131Z,1597847024.131 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2020-08-19T14:23:44.281Z,1597847024.281 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2020-08-19T14:23:44.400Z,1597847024.400 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Battery.cfg
2020-08-19T14:23:44.633Z,1597847024.633 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2020-08-19T14:23:44.634Z,1597847024.634 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/root/
2020-08-19T14:23:44.634Z,1597847024.634 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2020-08-19T14:23:44.647Z,1597847024.647 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2020-08-19T14:23:44.712Z,1597847024.712 [VerticalControl](DEBUG): Construct VerticalControl.
2020-08-19T14:23:44.825Z,1597847024.825 [VerticalControl] Loaded
2020-08-19T14:23:44.826Z,1597847024.826 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2020-08-19T14:23:44.827Z,1597847024.827 [HorizontalControl](DEBUG): Construct HorizontalControl.
2020-08-19T14:23:44.907Z,1597847024.907 [HorizontalControl] Loaded
2020-08-19T14:23:44.908Z,1597847024.908 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2020-08-19T14:23:44.908Z,1597847024.908 [SpeedControl](DEBUG): Construct SpeedControl.
2020-08-19T14:23:44.914Z,1597847024.914 [SpeedControl] Loaded
2020-08-19T14:23:44.914Z,1597847024.914 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2020-08-19T14:23:44.915Z,1597847024.915 [LoopControl](DEBUG): Construct LoopControl.
2020-08-19T14:23:44.915Z,1597847024.915 [LoopControl] Loaded
2020-08-19T14:23:44.915Z,1597847024.915 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2020-08-19T14:23:44.916Z,1597847024.916 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2020-08-19T14:23:44.918Z,1597847024.918 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2020-08-19T14:23:44.948Z,1597847024.948 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2020-08-19T14:23:44.948Z,1597847024.948 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2020-08-19T14:23:45.070Z,1597847025.070 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2020-08-19T14:23:45.071Z,1597847025.071 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2020-08-19T14:23:45.240Z,1597847025.240 [BuoyancyServo] Loaded
2020-08-19T14:23:45.240Z,1597847025.240 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2020-08-19T14:23:45.268Z,1597847025.268 [ElevatorServo] Loaded
2020-08-19T14:23:45.268Z,1597847025.268 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2020-08-19T14:23:45.296Z,1597847025.296 [MassServo] Loaded
2020-08-19T14:23:45.296Z,1597847025.296 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2020-08-19T14:23:45.323Z,1597847025.323 [RudderServo] Loaded
2020-08-19T14:23:45.324Z,1597847025.324 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2020-08-19T14:23:45.350Z,1597847025.350 [ThrusterServo] Loaded
2020-08-19T14:23:45.350Z,1597847025.350 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2020-08-19T14:23:45.351Z,1597847025.351 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2020-08-19T14:23:45.351Z,1597847025.351 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2020-08-19T14:23:45.491Z,1597847025.491 [DeadReckonUsingMultipleVelocitySources] Loaded
2020-08-19T14:23:45.491Z,1597847025.491 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2020-08-19T14:23:45.512Z,1597847025.512 [NavChart] Loaded
2020-08-19T14:23:45.512Z,1597847025.512 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2020-08-19T14:23:45.516Z,1597847025.516 [UniversalFixResidualReporter] Loaded
2020-08-19T14:23:45.517Z,1597847025.517 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2020-08-19T14:23:45.517Z,1597847025.517 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2020-08-19T14:23:45.518Z,1597847025.518 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2020-08-19T14:23:45.643Z,1597847025.643 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2020-08-19T14:23:45.644Z,1597847025.644 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2020-08-19T14:23:46.178Z,1597847026.178 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_orientation
2020-08-19T14:23:46.183Z,1597847026.183 [AHRS_M2](INFO): created writer for : platform_orientation
2020-08-19T14:23:46.184Z,1597847026.184 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_magnetic_orientation
2020-08-19T14:23:46.190Z,1597847026.190 [AHRS_M2](INFO): created writer for : platform_magnetic_orientation
2020-08-19T14:23:46.190Z,1597847026.190 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_pitch_angle
2020-08-19T14:23:46.195Z,1597847026.195 [AHRS_M2](INFO): created writer for : platform_pitch_angle
2020-08-19T14:23:46.196Z,1597847026.196 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_roll_angle
2020-08-19T14:23:46.201Z,1597847026.201 [AHRS_M2](INFO): created writer for : platform_roll_angle
2020-08-19T14:23:46.378Z,1597847026.378 [AHRS_M2] Loaded
2020-08-19T14:23:46.378Z,1597847026.378 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2020-08-19T14:23:46.618Z,1597847026.618 [DataOverHttps] Loaded
2020-08-19T14:23:46.618Z,1597847026.618 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2020-08-19T14:23:46.646Z,1597847026.646 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 4089B4E0
2020-08-19T14:23:46.646Z,1597847026.646 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 909
2020-08-19T14:23:46.825Z,1597847026.825 [Depth_Keller] Loaded
2020-08-19T14:23:46.826Z,1597847026.826 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2020-08-19T14:23:46.831Z,1597847026.831 [DropWeight] Loaded
2020-08-19T14:23:46.831Z,1597847026.831 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2020-08-19T14:23:47.043Z,1597847027.043 [NAL9602] Loaded
2020-08-19T14:23:47.043Z,1597847027.043 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2020-08-19T14:23:47.092Z,1597847027.092 [Onboard] Loaded
2020-08-19T14:23:47.092Z,1597847027.092 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2020-08-19T14:23:47.093Z,1597847027.093 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 408CB4E0
2020-08-19T14:23:47.093Z,1597847027.093 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 910
2020-08-19T14:23:47.112Z,1597847027.112 [Radio_Surface] Loaded
2020-08-19T14:23:47.113Z,1597847027.113 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2020-08-19T14:23:47.114Z,1597847027.114 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 408FB4E0
2020-08-19T14:23:47.114Z,1597847027.114 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 911
2020-08-19T14:23:48.736Z,1597847028.736 [BPC1] Loaded
2020-08-19T14:23:48.736Z,1597847028.736 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2020-08-19T14:23:48.737Z,1597847028.737 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2020-08-19T14:23:48.737Z,1597847028.737 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2020-08-19T14:23:48.792Z,1597847028.792 [DepthRateCalculator] Loaded
2020-08-19T14:23:48.792Z,1597847028.792 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2020-08-19T14:23:48.798Z,1597847028.798 [PitchRateCalculator] Loaded
2020-08-19T14:23:48.798Z,1597847028.798 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2020-08-19T14:23:48.810Z,1597847028.810 [SpeedCalculator] Loaded
2020-08-19T14:23:48.810Z,1597847028.810 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2020-08-19T14:23:48.857Z,1597847028.857 [TempGradientCalculator] Loaded
2020-08-19T14:23:48.863Z,1597847028.863 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2020-08-19T14:23:48.868Z,1597847028.868 [YawRateCalculator] Loaded
2020-08-19T14:23:48.868Z,1597847028.868 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2020-08-19T14:23:48.898Z,1597847028.898 [ElevatorOffsetCalculator] Loaded
2020-08-19T14:23:48.898Z,1597847028.898 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2020-08-19T14:23:48.898Z,1597847028.898 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2020-08-19T14:23:48.899Z,1597847028.899 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2020-08-19T14:23:49.675Z,1597847029.675 [CANONSampler] Loaded
2020-08-19T14:23:49.675Z,1597847029.675 [ComponentRegistry](DEBUG): SyncComponent "CANONSampler" handled in the control thread.
2020-08-19T14:23:49.703Z,1597847029.703 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_density
2020-08-19T14:23:49.709Z,1597847029.709 [CTD_Seabird](INFO): created writer for : sea_water_density
2020-08-19T14:23:49.709Z,1597847029.709 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): depth
2020-08-19T14:23:49.714Z,1597847029.714 [CTD_Seabird](INFO): created writer for : depth
2020-08-19T14:23:49.714Z,1597847029.714 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_pressure
2020-08-19T14:23:49.719Z,1597847029.719 [CTD_Seabird](INFO): created writer for : sea_water_pressure
2020-08-19T14:23:49.720Z,1597847029.720 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_salinity
2020-08-19T14:23:49.725Z,1597847029.725 [CTD_Seabird](INFO): created writer for : sea_water_salinity
2020-08-19T14:23:49.725Z,1597847029.725 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_temperature
2020-08-19T14:23:49.730Z,1597847029.730 [CTD_Seabird](INFO): created writer for : sea_water_temperature
2020-08-19T14:23:49.731Z,1597847029.731 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_electrical_conductivity
2020-08-19T14:23:49.736Z,1597847029.736 [CTD_Seabird](INFO): created writer for : sea_water_electrical_conductivity
2020-08-19T14:23:49.737Z,1597847029.737 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): speed_of_sound_in_sea_water
2020-08-19T14:23:49.742Z,1597847029.742 [CTD_Seabird](INFO): created writer for : speed_of_sound_in_sea_water
2020-08-19T14:23:49.742Z,1597847029.742 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): mass_concentration_of_oxygen_in_sea_water
2020-08-19T14:23:49.748Z,1597847029.748 [CTD_Seabird](INFO): created writer for : mass_concentration_of_oxygen_in_sea_water
2020-08-19T14:23:49.748Z,1597847029.748 [CTD_Seabird](DEBUG): LcmSlateWriter::add(DAtaURI): CTD_Seabird.sea_water_dissolved_oxygen_freq
2020-08-19T14:23:49.749Z,1597847029.749 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): dataName: sea_water_dissolved_oxygen_freq
2020-08-19T14:23:49.780Z,1597847029.780 [CTD_Seabird] Loaded
2020-08-19T14:23:49.780Z,1597847029.780 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2020-08-19T14:23:49.782Z,1597847029.782 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40A074E0
2020-08-19T14:23:49.782Z,1597847029.782 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 912
2020-08-19T14:23:49.814Z,1597847029.814 [PAR_Licor] Loaded
2020-08-19T14:23:49.814Z,1597847029.814 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2020-08-19T14:23:49.835Z,1597847029.835 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.Output470
2020-08-19T14:23:49.835Z,1597847029.835 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: Output470
2020-08-19T14:23:49.839Z,1597847029.839 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.Output650
2020-08-19T14:23:49.840Z,1597847029.840 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: Output650
2020-08-19T14:23:49.844Z,1597847029.844 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.OutputChl
2020-08-19T14:23:49.844Z,1597847029.844 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: OutputChl
2020-08-19T14:23:49.848Z,1597847029.848 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.VolumeScatCoeff117deg470nm
2020-08-19T14:23:49.848Z,1597847029.848 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: VolumeScatCoeff117deg470nm
2020-08-19T14:23:49.852Z,1597847029.852 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.VolumeScatCoeff117deg650nm
2020-08-19T14:23:49.852Z,1597847029.852 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: VolumeScatCoeff117deg650nm
2020-08-19T14:23:49.857Z,1597847029.857 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.BackscatteringCoeff470nm
2020-08-19T14:23:49.857Z,1597847029.857 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: BackscatteringCoeff470nm
2020-08-19T14:23:49.861Z,1597847029.861 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.BackscatteringCoeff650nm
2020-08-19T14:23:49.861Z,1597847029.861 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: BackscatteringCoeff650nm
2020-08-19T14:23:49.865Z,1597847029.865 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): mass_concentration_of_chlorophyll_in_sea_water
2020-08-19T14:23:49.870Z,1597847029.870 [WetLabsBB2FL](INFO): created writer for : mass_concentration_of_chlorophyll_in_sea_water
2020-08-19T14:23:49.870Z,1597847029.870 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_median_mass_concentration_of_chlorophyll_in_sea_water
2020-08-19T14:23:49.871Z,1597847029.871 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_median_mass_concentration_of_chlorophyll_in_sea_water
2020-08-19T14:23:49.875Z,1597847029.875 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_mean_mass_concentration_of_chlorophyll_in_sea_water
2020-08-19T14:23:49.875Z,1597847029.875 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_mean_mass_concentration_of_chlorophyll_in_sea_water
2020-08-19T14:23:49.879Z,1597847029.879 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_variance_mass_concentration_of_chlorophyll_in_sea_water
2020-08-19T14:23:49.879Z,1597847029.879 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_variance_mass_concentration_of_chlorophyll_in_sea_water
2020-08-19T14:23:49.883Z,1597847029.883 [WetLabsBB2FL] Loaded
2020-08-19T14:23:49.884Z,1597847029.884 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2020-08-19T14:23:49.885Z,1597847029.885 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40A374E0
2020-08-19T14:23:49.885Z,1597847029.885 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 913
2020-08-19T14:23:49.886Z,1597847029.886 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2020-08-19T14:23:49.887Z,1597847029.887 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2020-08-19T14:23:49.927Z,1597847029.927 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2020-08-19T14:23:49.928Z,1597847029.928 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2020-08-19T14:23:50.258Z,1597847030.258 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2020-08-19T14:23:50.259Z,1597847030.259 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2020-08-19T14:23:50.418Z,1597847030.418 [SBIT](DEBUG): Construct Startup Built In Test.
2020-08-19T14:23:50.429Z,1597847030.429 [SBIT] Loaded
2020-08-19T14:23:50.429Z,1597847030.429 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2020-08-19T14:23:50.430Z,1597847030.430 [IBIT](DEBUG): Construct Initiated Built In Test.
2020-08-19T14:23:50.443Z,1597847030.443 [IBIT] Loaded
2020-08-19T14:23:50.443Z,1597847030.443 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2020-08-19T14:23:50.447Z,1597847030.447 [CBIT](DEBUG): Construct Continuous Built In Test.
2020-08-19T14:23:50.586Z,1597847030.586 [CBIT] Loaded
2020-08-19T14:23:50.587Z,1597847030.587 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2020-08-19T14:23:50.587Z,1597847030.587 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2020-08-19T14:23:50.588Z,1597847030.588 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2020-08-19T14:23:50.683Z,1597847030.683 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2020-08-19T14:23:50.687Z,1597847030.687 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2020-08-19T14:23:50.688Z,1597847030.688 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2020-08-19T14:23:50.695Z,1597847030.695 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2020-08-19T14:23:50.696Z,1597847030.696 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40B5D4E0
2020-08-19T14:23:50.696Z,1597847030.696 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 914
2020-08-19T14:23:50.701Z,1597847030.701 [Supervisor](INFO): Main Thread ID is 815
2020-08-19T14:23:50.701Z,1597847030.701 [Supervisor](DEBUG): Running supervisor.
2020-08-19T14:23:50.702Z,1597847030.702 [CommandLine ThreadHandler](INFO): Handler Thread ID is 915
2020-08-19T14:23:50.704Z,1597847030.704 [controlThread ThreadHandler](INFO): Handler Thread ID is 916
2020-08-19T14:23:50.704Z,1597847030.704 [controlThread](DEBUG): Initializing ControlThread
2020-08-19T14:23:50.705Z,1597847030.705 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2020-08-19T14:23:50.707Z,1597847030.707 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2020-08-19T14:23:50.708Z,1597847030.708 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2020-08-19T14:23:50.708Z,1597847030.708 [LoopControl](DEBUG): Initialize LoopControlComponent.
2020-08-19T14:23:50.710Z,1597847030.710 [NavChart](DEBUG): Initialize NavChart Navigation.
2020-08-19T14:23:50.710Z,1597847030.710 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2020-08-19T14:23:50.716Z,1597847030.716 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2020-08-19T14:23:50.716Z,1597847030.716 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2020-08-19T14:23:50.716Z,1597847030.716 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2020-08-19T14:23:50.716Z,1597847030.716 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2020-08-19T14:23:50.717Z,1597847030.717 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2020-08-19T14:23:50.717Z,1597847030.717 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2020-08-19T14:23:50.722Z,1597847030.722 [SBIT](INFO): Initialize SBIT Component.
2020-08-19T14:23:50.723Z,1597847030.723 [SBIT](IMPORTANT): git: 2020-08-18a
2020-08-19T14:23:50.723Z,1597847030.723 [SBIT](INFO): git hash: 77519d12954ee93339c6cb522e5e7960b0ad92da
2020-08-19T14:23:50.723Z,1597847030.723 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2020-08-19T14:23:50.724Z,1597847030.724 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018
Kernel Reported: #1 PREEMPT Wed Nov 13 12:38:10 PST 2019
2020-08-19T14:23:50.725Z,1597847030.725 [SBIT](INFO): Beginning SBIT in 60.000000 seconds.
2020-08-19T14:23:50.726Z,1597847030.726 [IBIT](INFO): Initialize IBIT Component.
2020-08-19T14:23:50.727Z,1597847030.727 [CBIT](DEBUG): Initialize CBIT Component.
2020-08-19T14:23:50.728Z,1597847030.728 [logger ThreadHandler](INFO): Handler Thread ID is 917
2020-08-19T14:23:50.738Z,1597847030.738 [CBIT](DEBUG): Initialized mux pins.
2020-08-19T14:23:50.738Z,1597847030.738 [CBIT](DEBUG): Initializing the watchdog timer.
2020-08-19T14:23:50.746Z,1597847030.746 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 918
2020-08-19T14:23:50.747Z,1597847030.747 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2020-08-19T14:23:50.758Z,1597847030.758 [Onboard ThreadHandler](INFO): Handler Thread ID is 919
2020-08-19T14:23:50.762Z,1597847030.762 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2020-08-19T14:23:50.763Z,1597847030.763 [CBIT](DEBUG): Initializing heartbeat.
2020-08-19T14:23:50.788Z,1597847030.788 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 920
2020-08-19T14:23:50.794Z,1597847030.794 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 921
2020-08-19T14:23:50.795Z,1597847030.795 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2020-08-19T14:23:50.799Z,1597847030.799 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 923
2020-08-19T14:23:50.800Z,1597847030.800 [WetLabsBB2FL](INFO): Powering down
2020-08-19T14:23:50.834Z,1597847030.834 [CBIT](DEBUG): Deactivating GF circuits.
2020-08-19T14:23:50.834Z,1597847030.834 [CBIT](DEBUG): Deactivating emergency mode.
2020-08-19T14:23:50.870Z,1597847030.870 [CBIT](DEBUG): Backplane powered.
2020-08-19T14:23:50.871Z,1597847030.871 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2020-08-19T14:23:50.936Z,1597847030.936 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 924
2020-08-19T14:23:51.030Z,1597847031.030 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2020-08-19T14:23:51.030Z,1597847031.030 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2020-08-19T14:23:51.031Z,1597847031.031 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2020-08-19T14:23:51.031Z,1597847031.031 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2020-08-19T14:23:51.031Z,1597847031.031 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2020-08-19T14:23:51.031Z,1597847031.031 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2020-08-19T14:23:51.031Z,1597847031.031 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2020-08-19T14:23:51.031Z,1597847031.031 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2020-08-19T14:23:51.032Z,1597847031.032 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2020-08-19T14:23:51.032Z,1597847031.032 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2020-08-19T14:23:51.032Z,1597847031.032 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2020-08-19T14:23:51.032Z,1597847031.032 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2020-08-19T14:23:51.032Z,1597847031.032 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2020-08-19T14:23:51.032Z,1597847031.032 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2020-08-19T14:23:51.032Z,1597847031.032 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2020-08-19T14:23:51.033Z,1597847031.033 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2020-08-19T14:23:51.150Z,1597847031.150 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2020-08-19T14:23:51.190Z,1597847031.190 [Radio_Surface](INFO): Powering up
2020-08-19T14:23:51.250Z,1597847031.250 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
       xmlns:Control="Tethys/Control"
       xmlns:Guidance="Tethys/Guidance" 
       xmlns:Units="Tethys/Units"
       xmlns:Universal="Tethys/Universal"
       xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
       xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                           Tethys/Control http://okeanids.mbari.org/tethys/Xml/Control.xsd
                           Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                           Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                           Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
       Id="Startup">

    <Guidance:GoToSurface>
        <Progression/>
    </Guidance:GoToSurface>

    <Aggregate Id="StartupSatComms">

        <Sequence/>

        <ReadDatum>
            <Timeout Duration="P1M" />
            <Universal:latitude_fix/>
        </ReadDatum>

        <ReadDatum>
            <Timeout Duration="P1M" />
            <Universal:platform_communications/>
        </ReadDatum>

    </Aggregate>

</Mission>


2020-08-19T14:23:51.251Z,1597847031.251 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2020-08-19T14:23:51.329Z,1597847031.329 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2020-08-19T14:23:51.330Z,1597847031.330 [Default:A.Wait](DEBUG): Construct Wait.
2020-08-19T14:23:51.332Z,1597847031.332 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2020-08-19T14:23:51.365Z,1597847031.365 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2020-08-19T14:23:51.368Z,1597847031.368 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2020-08-19T14:23:51.385Z,1597847031.385 [Default:E.Execute](DEBUG): Construct Execute.
2020-08-19T14:23:51.389Z,1597847031.389 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xmlns="Tethys"
         xmlns:Units="Tethys/Units"
         xmlns:Guidance="Tethys/Guidance"
         xmlns:Universal="Tethys/Universal"
         xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                             Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                             Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                             Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
         Id="Default">

    <DefineArg Name="ElapsedSinceDefaultStarted"><Units:minute/><Value>0</Value></DefineArg>

    <Guidance:Wait>
        <Description>
            Wait a moment to see if the scheduler starts a new mission before
            starting to actually run Default.
        </Description>
        <Sequence/>
        <Setting><Guidance:Wait.duration/><Units:second/><Value>13</Value></Setting>
    </Guidance:Wait>

    <Guidance:GoToSurface>
        <Progression/>
    </Guidance:GoToSurface>

    <Aggregate Id="CheckIn">

        <Sequence Repeat="288"/>

        <ReadDatum Id="Read_GPS">
            <Timeout Duration="P5M"/>
            <Universal:time_fix/>
        </ReadDatum>

        <ReadDatum Id="Read_Iridium">
            <Timeout Duration="P2H">
                <Guidance:Execute>
                    <Sequence/>
                    <Setting><Guidance:Execute.command/><String>Burn on</String></Setting>
                </Guidance:Execute>
                <Syslog Severity="Critical">Dropped weight due to communications timeout.</Syslog>
            </Timeout>
            <Universal:platform_communications/>
        </ReadDatum>

        <Guidance:Wait>
            <Sequence/>
            <Setting><Guidance:Wait.duration/><Units:minute/><Value>5</Value></Setting>
        </Guidance:Wait>

        <Assign><Sequence/><Arg Name="ElapsedSinceDefaultStarted"/><Elapsed><Universal:mission_started/></Elapsed></Assign>

        <Syslog Severity="Important">Default mission has been running for <Arg Name="ElapsedSinceDefaultStarted"/><Units:minute/></Syslog>

    </Aggregate>

    <Syslog Severity="Important">Restarting logs and Default mission.</Syslog>

    <Guidance:Execute>
        <Sequence/>
        <Setting><Guidance:Execute.command/><String>restart logs</String></Setting>
    </Guidance:Execute>

</Mission>


2020-08-19T14:23:51.405Z,1597847031.405 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,Depth_Keller,DropWeight,NAL9602,BPC1,CANONSampler,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,Reporter,LogSplitter,
2020-08-19T14:23:51.410Z,1597847031.410 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2020-08-19T14:23:51.586Z,1597847031.586 [CANONSampler](INFO): Powering down
2020-08-19T14:23:51.660Z,1597847031.660 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2020-08-19T14:23:51.666Z,1597847031.666 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2020-08-19T14:23:51.667Z,1597847031.667 [ElevatorServo](DEBUG): Initializing EZServoServo.
2020-08-19T14:23:51.674Z,1597847031.674 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2020-08-19T14:23:51.675Z,1597847031.675 [MassServo](DEBUG): Initializing EZServoServo.
2020-08-19T14:23:51.682Z,1597847031.682 [MassServo](DEBUG): Initializing MassServo.
2020-08-19T14:23:51.683Z,1597847031.683 [RudderServo](DEBUG): Initializing EZServoServo.
2020-08-19T14:23:51.690Z,1597847031.690 [RudderServo](DEBUG): Initializing RudderServo.
2020-08-19T14:23:51.691Z,1597847031.691 [ThrusterServo](DEBUG): Initializing EZServoServo.
2020-08-19T14:23:51.698Z,1597847031.698 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2020-08-19T14:23:52.538Z,1597847032.538 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2020-08-19T14:23:52.538Z,1597847032.538 [RudderServo](FAULT): Rudder failed to initialize
2020-08-19T14:23:52.538Z,1597847032.538 [RudderServo] Communications Fault, FailCount= 1
2020-08-19T14:23:52.538Z,1597847032.538 [RudderServo](ERROR): Communications Fault
2020-08-19T14:23:52.721Z,1597847032.721 [CBIT](ERROR): Communications Fault in component: RudderServo
2020-08-19T14:23:52.927Z,1597847032.927 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2020-08-19T14:23:52.927Z,1597847032.927 [RudderServo](INFO): Powering down
2020-08-19T14:23:53.558Z,1597847033.558 [RudderServo](DEBUG): Initializing EZServoServo.
2020-08-19T14:23:53.679Z,1597847033.679 [RudderServo](DEBUG): Initializing RudderServo.
2020-08-19T14:23:53.683Z,1597847033.683 [CBIT](INFO): Clearing failed state for component RudderServo
2020-08-19T14:23:53.683Z,1597847033.683 [RudderServo] No Fault, FailCount= 1
2020-08-19T14:24:17.375Z,1597847057.375 [NAL9602](INFO): Powering up NAL9602
2020-08-19T14:24:28.287Z,1597847068.287 [NAL9602](INFO): NAL9602 initialized
2020-08-19T14:24:51.329Z,1597847091.329 [SBIT](IMPORTANT): Beginning Startup BIT
2020-08-19T14:24:51.333Z,1597847091.333 [CBIT](IMPORTANT): Beginning ground fault scan
2020-08-19T14:25:02.268Z,1597847102.268 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.013008
CHAN A1 (24V): -0.009128
CHAN A2 (12V): -0.002204
CHAN A3 (5V): -0.001492
CHAN B0 (3.3V): 0.000147
CHAN B1 (3.15aV): 4.767929
CHAN B2 (3.15bV): 0.000148
CHAN B3 (GND): -0.000074
OPEN: -0.000274
Full Scale Calc: 4.765 mA, -1.589 mA
2020-08-19T14:25:41.799Z,1597847141.799 [CommandLine](IMPORTANT): got command gfscan
2020-08-19T14:25:41.867Z,1597847141.867 [CBIT](IMPORTANT): Beginning ground fault scan
2020-08-19T14:25:45.113Z,1597847145.113 [SBIT](IMPORTANT): SBIT PASSED
2020-08-19T14:25:45.118Z,1597847145.118 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2020-08-19T14:25:45.119Z,1597847145.119 [SBIT](IMPORTANT): CBIT.gf24Offset=-17 microampere;

2020-08-19T14:25:45.119Z,1597847145.119 [SBIT](IMPORTANT): ElevatorOffsetCalculator.loadAtStartup=1 bool;

2020-08-19T14:25:45.119Z,1597847145.119 [SBIT](IMPORTANT): Express linearApproximation acoustic_contact_range 10.000000 meter;

2020-08-19T14:25:45.119Z,1597847145.119 [SBIT](IMPORTANT): Express linearApproximation platform_average_power 1.000000 watt;

2020-08-19T14:25:45.119Z,1597847145.119 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=245.938302 cubic_centimeter;

2020-08-19T14:25:45.119Z,1597847145.119 [SBIT](IMPORTANT): VerticalControl.massDefault=-10.009265 millimeter;

2020-08-19T14:25:45.549Z,1597847145.549 [MissionManager](IMPORTANT): Started mission Startup
2020-08-19T14:25:45.550Z,1597847145.550 [Startup] Running Loop=1
2020-08-19T14:25:45.550Z,1597847145.550 [Startup](DEBUG): Aggregate::initialize Startup
2020-08-19T14:25:45.550Z,1597847145.550 [Startup:A.GoToSurface] Running Loop=1
2020-08-19T14:25:45.550Z,1597847145.550 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2020-08-19T14:25:45.551Z,1597847145.551 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2020-08-19T14:25:45.551Z,1597847145.551 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2020-08-19T14:25:45.551Z,1597847145.551 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2020-08-19T14:25:45.552Z,1597847145.552 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2020-08-19T14:25:45.552Z,1597847145.552 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2020-08-19T14:25:45.553Z,1597847145.553 [Startup:StartupSatComms] Running Loop=1
2020-08-19T14:25:45.554Z,1597847145.554 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2020-08-19T14:25:45.554Z,1597847145.554 [Startup:StartupSatComms:A] Running Loop=1
2020-08-19T14:25:45.921Z,1597847145.921 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2020-08-19T14:25:52.767Z,1597847152.767 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 4.660556
CHAN A1 (24V): -0.009800
CHAN A2 (12V): -0.002051
CHAN A3 (5V): -0.001310
CHAN B0 (3.3V): -0.000187
CHAN B1 (3.15aV): -0.000001
CHAN B2 (3.15bV): -0.000087
CHAN B3 (GND): 0.000094
OPEN: -0.000773
Full Scale Calc: 4.765 mA, -1.589 mA
2020-08-19T14:25:58.966Z,1597847158.966 [CommandLine](IMPORTANT): got command gfscan
2020-08-19T14:25:59.252Z,1597847159.252 [CBIT](IMPORTANT): Beginning ground fault scan
2020-08-19T14:26:10.121Z,1597847170.121 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): 0.015053
CHAN A1 (24V): -0.009571
CHAN A2 (12V): -0.002366
CHAN A3 (5V): -0.001459
CHAN B0 (3.3V): -0.000222
CHAN B1 (3.15aV): -0.000391
CHAN B2 (3.15bV): -0.000090
CHAN B3 (GND): 0.000320
OPEN: -0.000285
Full Scale Calc: 4.765 mA, -1.589 mA
2020-08-19T14:26:35.653Z,1597847195.653 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.005523
2020-08-19T14:26:45.669Z,1597847205.669 [Startup:StartupSatComms:A](INFO): Timed out from 2020-08-19T14:25:45.6Z
2020-08-19T14:26:45.669Z,1597847205.669 [Startup:StartupSatComms:A] Stopped
2020-08-19T14:26:45.691Z,1597847205.691 [Startup:StartupSatComms:B] Running Loop=1
2020-08-19T14:26:46.080Z,1597847206.080 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2020-08-19T14:26:50.946Z,1597847210.946 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2020-08-19T14:26:50.946Z,1597847210.946 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-08-19T14:26:50.961Z,1597847210.961 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-08-19T14:26:51.365Z,1597847211.365 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-08-19T14:26:51.365Z,1597847211.365 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2020-08-19T14:26:52.918Z,1597847212.918 [DataOverHttps](INFO): Sending 151 bytes from file Logs/20200819T142337/Courier0000.lzma
2020-08-19T14:26:53.920Z,1597847213.920 [DataOverHttps](INFO): Moved sent file to Logs/20200819T142337/Courier0000.lzma.bak
2020-08-19T14:26:53.920Z,1597847213.920 [DataOverHttps](INFO): SBD MOMSN=12570207
2020-08-19T14:27:09.515Z,1597847229.515 [DataOverHttps](INFO): Sending 999 bytes from file Logs/20200819T142337/Express0001.lzma
2020-08-19T14:27:10.516Z,1597847230.516 [DataOverHttps](INFO): Moved sent file to Logs/20200819T142337/Express0001.lzma.bak
2020-08-19T14:27:10.516Z,1597847230.516 [DataOverHttps](INFO): SBD MOMSN=12570210
2020-08-19T14:27:11.526Z,1597847231.526 [Startup:StartupSatComms:B] Stopped
2020-08-19T14:27:11.526Z,1597847231.526 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2020-08-19T14:27:11.526Z,1597847231.526 [Startup:StartupSatComms] Stopped
2020-08-19T14:27:11.527Z,1597847231.527 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2020-08-19T14:27:11.527Z,1597847231.527 [Startup](INFO): Completed Startup
2020-08-19T14:27:11.527Z,1597847231.527 [MissionManager](INFO): Startup is completed.
2020-08-19T14:27:11.528Z,1597847231.528 [MissionManager](INFO): Uninitializing Mission Startup
2020-08-19T14:27:11.528Z,1597847231.528 [Startup] Stopped
2020-08-19T14:27:11.528Z,1597847231.528 [Startup](DEBUG): Aggregate::uninitialize Startup
2020-08-19T14:27:11.528Z,1597847231.528 [Startup:A.GoToSurface] Stopped
2020-08-19T14:27:11.528Z,1597847231.528 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2020-08-19T14:27:11.935Z,1597847231.935 [MissionManager](IMPORTANT): Started mission Default
2020-08-19T14:27:11.935Z,1597847231.935 [Default] Running Loop=1
2020-08-19T14:27:11.935Z,1597847231.935 [Default](DEBUG): Aggregate::initialize Default
2020-08-19T14:27:11.935Z,1597847231.935 [Default:B.GoToSurface] Running Loop=1
2020-08-19T14:27:11.935Z,1597847231.935 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2020-08-19T14:27:11.935Z,1597847231.935 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2020-08-19T14:27:11.936Z,1597847231.936 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2020-08-19T14:27:11.936Z,1597847231.936 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2020-08-19T14:27:11.936Z,1597847231.936 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2020-08-19T14:27:11.936Z,1597847231.936 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2020-08-19T14:27:11.937Z,1597847231.937 [Default:A.Wait] Running Loop=1
2020-08-19T14:27:11.937Z,1597847231.937 [Default:A.Wait](DEBUG): Initialize Wait Component.
2020-08-19T14:27:25.262Z,1597847245.262 [Default:A.Wait](INFO): Done Waiting.
2020-08-19T14:27:25.262Z,1597847245.262 [Default:A.Wait] Stopped
2020-08-19T14:27:25.262Z,1597847245.262 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2020-08-19T14:27:25.665Z,1597847245.665 [Default:CheckIn] Running Loop=1
2020-08-19T14:27:25.665Z,1597847245.665 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-08-19T14:27:25.665Z,1597847245.665 [Default:CheckIn:Read_GPS] Running Loop=1
2020-08-19T14:27:26.056Z,1597847246.056 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2020-08-19T14:27:32.024Z,1597847252.024 [CommandLine](IMPORTANT): got command configSet CBIT.gf24Offset -27.000000 microampere
2020-08-19T14:27:34.727Z,1597847254.727 [CommandLine](IMPORTANT): got command gfscan
2020-08-19T14:27:34.973Z,1597847254.973 [CBIT](IMPORTANT): Beginning ground fault scan
2020-08-19T14:27:45.897Z,1597847265.897 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): 0.014920
CHAN A1 (24V): 0.001031
CHAN A2 (12V): -0.002307
CHAN A3 (5V): -0.001839
CHAN B0 (3.3V): -0.000142
CHAN B1 (3.15aV): 0.000242
CHAN B2 (3.15bV): 0.000245
CHAN B3 (GND): 0.000005
OPEN: -0.000421
Full Scale Calc: 4.765 mA, -1.589 mA
2020-08-19T14:27:53.576Z,1597847273.576 [CommandLine](IMPORTANT): got command configSet CBIT.gf24Offset -27.000000 microampere persist
2020-08-19T14:27:59.143Z,1597847279.143 [CommandLine](IMPORTANT): got command configSet list
2020-08-19T14:27:59.144Z,1597847279.144 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2020-08-19T14:27:59.144Z,1597847279.144 [CommandLine](IMPORTANT): CBIT.gf24Offset=-27 microampere;

2020-08-19T14:27:59.145Z,1597847279.145 [CommandLine](IMPORTANT): ElevatorOffsetCalculator.loadAtStartup=1 bool;

2020-08-19T14:27:59.145Z,1597847279.145 [CommandLine](IMPORTANT): Express linearApproximation acoustic_contact_range 10.000000 meter;

2020-08-19T14:27:59.145Z,1597847279.145 [CommandLine](IMPORTANT): Express linearApproximation platform_average_power 1.000000 watt;

2020-08-19T14:27:59.145Z,1597847279.145 [CommandLine](IMPORTANT): VerticalControl.buoyancyNeutral=245.938302 cubic_centimeter;

2020-08-19T14:27:59.145Z,1597847279.145 [CommandLine](IMPORTANT): VerticalControl.massDefault=-10.009265 millimeter;

2020-08-19T14:29:31.284Z,1597847371.284 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2020-08-19T14:29:51.898Z,1597847391.898 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2020-08-19T14:29:51.898Z,1597847391.898 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-08-19T14:29:51.933Z,1597847391.933 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-08-19T14:29:52.311Z,1597847392.311 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-08-19T14:29:52.311Z,1597847392.311 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2020-08-19T14:30:57.251Z,1597847457.251 [CommandLine](IMPORTANT): got command failComponent
2020-08-19T14:30:57.252Z,1597847457.252 [CommandLine](IMPORTANT): Failed components:
2020-08-19T14:30:57.252Z,1597847457.252 [CommandLine](IMPORTANT): No failed Components.
2020-08-19T14:31:01.211Z,1597847461.211 [CommandLine](IMPORTANT): got command burn on
2020-08-19T14:31:01.212Z,1597847461.212 [CommandLine](IMPORTANT): Activating dropweight wire
2020-08-19T14:31:48.258Z,1597847508.258 [BPC1](ERROR): Battery stick #50 (s/n: 01DE) reported OVER_TEMP_ALARM. Status code: 0x1717.
2020-08-19T14:31:48.259Z,1597847508.259 [BPC1](INFO): Calculating totals. Valid battery stick count: 55. Valid reserve battery stick count: 6.
2020-08-19T14:31:48.262Z,1597847508.262 [BPC1](INFO): Received data from all battery sticks.
2020-08-19T14:32:02.901Z,1597847522.901 [CommandLine](IMPORTANT): got command burn off
2020-08-19T14:32:02.901Z,1597847522.901 [CommandLine](IMPORTANT): Deactivating dropweight wire
2020-08-19T14:32:25.824Z,1597847545.824 [Default:CheckIn:Read_GPS](INFO): Timed out from 2020-08-19T14:27:25.7Z
2020-08-19T14:32:25.824Z,1597847545.824 [Default:CheckIn:Read_GPS] Stopped
2020-08-19T14:32:25.824Z,1597847545.824 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-08-19T14:32:26.235Z,1597847546.235 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2020-08-19T14:32:32.401Z,1597847552.401 [DataOverHttps](INFO): Sending 168 bytes from file Logs/20200819T142337/Courier0004.lzma
2020-08-19T14:32:33.403Z,1597847553.403 [DataOverHttps](INFO): Moved sent file to Logs/20200819T142337/Courier0004.lzma.bak
2020-08-19T14:32:33.404Z,1597847553.404 [DataOverHttps](INFO): SBD MOMSN=12570280
2020-08-19T14:32:48.621Z,1597847568.621 [DataOverHttps](INFO): Sending 774 bytes from file Logs/20200819T142337/Express0005.lzma
2020-08-19T14:32:49.619Z,1597847569.619 [DataOverHttps](INFO): Moved sent file to Logs/20200819T142337/Express0005.lzma.bak
2020-08-19T14:32:49.620Z,1597847569.620 [DataOverHttps](INFO): SBD MOMSN=12570282
2020-08-19T14:32:50.888Z,1597847570.888 [Default:CheckIn:Read_Iridium] Stopped
2020-08-19T14:32:50.888Z,1597847570.888 [Default:CheckIn:C.Wait] Running Loop=1
2020-08-19T14:32:50.888Z,1597847570.888 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-08-19T14:32:52.918Z,1597847572.918 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3
2020-08-19T14:32:52.918Z,1597847572.918 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-08-19T14:32:52.965Z,1597847572.965 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-08-19T14:32:53.331Z,1597847573.331 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-08-19T14:32:53.331Z,1597847573.331 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3
2020-08-19T14:34:29.843Z,1597847669.843 [NAL9602](FAULT): GPS failed to acquire within timeout.
2020-08-19T14:34:29.843Z,1597847669.843 [NAL9602] Data Fault, FailCount= 1
2020-08-19T14:34:29.843Z,1597847669.843 [NAL9602](ERROR): Data Fault
2020-08-19T14:34:29.859Z,1597847669.859 [CBIT](ERROR): Data Fault in component: NAL9602
2020-08-19T14:34:30.243Z,1597847670.243 [NAL9602](INFO): Powering down
2020-08-19T14:34:31.090Z,1597847671.090 [CBIT](INFO): Clearing failed state for component NAL9602
2020-08-19T14:34:31.090Z,1597847671.090 [NAL9602] No Fault, FailCount= 1
2020-08-19T14:35:00.551Z,1597847700.551 [NAL9602](INFO): Powering up NAL9602
2020-08-19T14:35:11.460Z,1597847711.460 [NAL9602](INFO): NAL9602 initialized
2020-08-19T14:35:53.901Z,1597847753.901 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4
2020-08-19T14:35:53.901Z,1597847753.901 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-08-19T14:35:53.912Z,1597847753.912 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-08-19T14:35:54.331Z,1597847754.331 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-08-19T14:35:54.331Z,1597847754.331 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4
2020-08-19T14:37:51.486Z,1597847871.486 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-08-19T14:37:51.486Z,1597847871.486 [Default:CheckIn:C.Wait] Stopped
2020-08-19T14:37:51.486Z,1597847871.486 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-08-19T14:37:51.487Z,1597847871.487 [Default:CheckIn:D] Running Loop=1
2020-08-19T14:37:51.876Z,1597847871.876 [Default:CheckIn:D] Stopped
2020-08-19T14:37:51.876Z,1597847871.876 [Default:CheckIn:E] Running Loop=1
2020-08-19T14:37:52.274Z,1597847872.274 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 10.665684 min 
2020-08-19T14:37:52.275Z,1597847872.275 [Default:CheckIn:E] Stopped
2020-08-19T14:37:52.275Z,1597847872.275 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-08-19T14:37:52.275Z,1597847872.275 [Default:CheckIn] Stopped
2020-08-19T14:37:52.275Z,1597847872.275 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-08-19T14:37:52.275Z,1597847872.275 [Default:CheckIn](INFO): Running loop #2
2020-08-19T14:37:52.275Z,1597847872.275 [Default:CheckIn] Running Loop=2
2020-08-19T14:37:52.275Z,1597847872.275 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-08-19T14:37:52.275Z,1597847872.275 [Default:CheckIn:Read_GPS] Running Loop=1
2020-08-19T14:38:54.875Z,1597847934.875 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5
2020-08-19T14:38:54.875Z,1597847934.875 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-08-19T14:38:54.885Z,1597847934.885 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-08-19T14:38:55.293Z,1597847935.293 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-08-19T14:38:55.293Z,1597847935.293 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5
2020-08-19T14:41:55.884Z,1597848115.884 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 6
2020-08-19T14:41:55.884Z,1597848115.884 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-08-19T14:41:55.894Z,1597848115.894 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-08-19T14:41:56.304Z,1597848116.304 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-08-19T14:41:56.304Z,1597848116.304 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 6
2020-08-19T14:42:52.459Z,1597848172.459 [Default:CheckIn:Read_GPS](INFO): Timed out from 2020-08-19T14:37:52.3Z
2020-08-19T14:42:52.459Z,1597848172.459 [Default:CheckIn:Read_GPS] Stopped
2020-08-19T14:42:52.459Z,1597848172.459 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-08-19T14:42:53.867Z,1597848173.867 [CommandLine](IMPORTANT): got command failComponent
2020-08-19T14:42:53.867Z,1597848173.867 [CommandLine](IMPORTANT): Failed components:
2020-08-19T14:42:53.867Z,1597848173.867 [CommandLine](IMPORTANT): No failed Components.
2020-08-19T14:42:58.151Z,1597848178.151 [CommandLine](IMPORTANT): got command configSet list
2020-08-19T14:42:58.151Z,1597848178.151 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2020-08-19T14:42:58.152Z,1597848178.152 [CommandLine](IMPORTANT): CBIT.gf24Offset=-27 microampere;

2020-08-19T14:42:58.152Z,1597848178.152 [CommandLine](IMPORTANT): ElevatorOffsetCalculator.loadAtStartup=1 bool;

2020-08-19T14:42:58.152Z,1597848178.152 [CommandLine](IMPORTANT): Express linearApproximation acoustic_contact_range 10.000000 meter;

2020-08-19T14:42:58.153Z,1597848178.153 [CommandLine](IMPORTANT): Express linearApproximation platform_average_power 1.000000 watt;

2020-08-19T14:42:58.153Z,1597848178.153 [CommandLine](IMPORTANT): VerticalControl.buoyancyNeutral=245.938302 cubic_centimeter;

2020-08-19T14:42:58.153Z,1597848178.153 [CommandLine](IMPORTANT): VerticalControl.massDefault=-10.009265 millimeter;

2020-08-19T14:42:59.781Z,1597848179.781 [DataOverHttps](INFO): Sending 38 bytes from file Logs/20200819T142337/Courier0007.lzma
2020-08-19T14:43:00.783Z,1597848180.783 [DataOverHttps](INFO): Moved sent file to Logs/20200819T142337/Courier0007.lzma.bak
2020-08-19T14:43:00.784Z,1597848180.784 [DataOverHttps](INFO): SBD MOMSN=12570352
2020-08-19T14:43:15.993Z,1597848195.993 [DataOverHttps](INFO): Sending 205 bytes from file Logs/20200819T142337/Express0008.lzma
2020-08-19T14:43:16.995Z,1597848196.995 [DataOverHttps](INFO): Moved sent file to Logs/20200819T142337/Express0008.lzma.bak
2020-08-19T14:43:16.996Z,1597848196.996 [DataOverHttps](INFO): SBD MOMSN=12570354
2020-08-19T14:43:18.344Z,1597848198.344 [Default:CheckIn:Read_Iridium] Stopped
2020-08-19T14:43:18.344Z,1597848198.344 [Default:CheckIn:C.Wait] Running Loop=1
2020-08-19T14:43:18.344Z,1597848198.344 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-08-19T14:44:56.919Z,1597848296.919 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 7
2020-08-19T14:44:56.919Z,1597848296.919 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-08-19T14:44:56.929Z,1597848296.929 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-08-19T14:44:57.340Z,1597848297.340 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-08-19T14:44:57.340Z,1597848297.340 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 7
2020-08-19T14:45:13.863Z,1597848313.863 [NAL9602](FAULT): GPS failed to acquire within timeout.
2020-08-19T14:45:13.864Z,1597848313.864 [NAL9602] Data Fault, FailCount= 2
2020-08-19T14:45:13.864Z,1597848313.864 [NAL9602](ERROR): Data Fault
2020-08-19T14:45:13.880Z,1597848313.880 [CBIT](ERROR): Data Fault in component: NAL9602
2020-08-19T14:45:14.255Z,1597848314.255 [NAL9602](INFO): Powering down
2020-08-19T14:45:15.079Z,1597848315.079 [CBIT](INFO): Clearing failed state for component NAL9602
2020-08-19T14:45:15.079Z,1597848315.079 [NAL9602] No Fault, FailCount= 2
2020-08-19T14:45:44.555Z,1597848344.555 [NAL9602](INFO): Powering up NAL9602
2020-08-19T14:45:55.463Z,1597848355.463 [NAL9602](INFO): NAL9602 initialized
2020-08-19T14:47:38.526Z,1597848458.526 [CommandLine](IMPORTANT): got command failComponent
2020-08-19T14:47:38.527Z,1597848458.527 [CommandLine](IMPORTANT): Failed components:
2020-08-19T14:47:38.527Z,1597848458.527 [CommandLine](IMPORTANT): No failed Components.
2020-08-19T14:47:57.891Z,1597848477.891 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 8
2020-08-19T14:47:57.891Z,1597848477.891 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-08-19T14:47:57.901Z,1597848477.901 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-08-19T14:47:58.312Z,1597848478.312 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-08-19T14:47:58.312Z,1597848478.312 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 8
2020-08-19T14:48:18.913Z,1597848498.913 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-08-19T14:48:18.913Z,1597848498.913 [Default:CheckIn:C.Wait] Stopped
2020-08-19T14:48:18.913Z,1597848498.913 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-08-19T14:48:18.913Z,1597848498.913 [Default:CheckIn:D] Running Loop=1
2020-08-19T14:48:19.295Z,1597848499.295 [Default:CheckIn:D] Stopped
2020-08-19T14:48:19.295Z,1597848499.295 [Default:CheckIn:E] Running Loop=1
2020-08-19T14:48:19.707Z,1597848499.707 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 21.122673 min 
2020-08-19T14:48:19.707Z,1597848499.707 [Default:CheckIn:E] Stopped
2020-08-19T14:48:19.707Z,1597848499.707 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-08-19T14:48:19.707Z,1597848499.707 [Default:CheckIn] Stopped
2020-08-19T14:48:19.708Z,1597848499.708 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-08-19T14:48:19.708Z,1597848499.708 [Default:CheckIn](INFO): Running loop #3
2020-08-19T14:48:19.708Z,1597848499.708 [Default:CheckIn] Running Loop=3
2020-08-19T14:48:19.708Z,1597848499.708 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-08-19T14:48:19.708Z,1597848499.708 [Default:CheckIn:Read_GPS] Running Loop=1
2020-08-19T14:50:33.425Z,1597848633.425 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,145034.00,A,3648.16583,N,12147.28076,W,0.544,0.58,190820,,,A*7B
2020-08-19T14:50:33.428Z,1597848633.428 [NAL9602](INFO): GPS fix at 20200819T145034: (36.802764, -121.788013)
2020-08-19T14:50:33.439Z,1597848633.439 [Default:CheckIn:Read_GPS] Stopped
2020-08-19T14:50:33.439Z,1597848633.439 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-08-19T14:50:58.849Z,1597848658.849 [DataOverHttps](INFO): Sending 223 bytes from file Logs/20200819T142337/Courier0010.lzma
2020-08-19T14:50:59.851Z,1597848659.851 [DataOverHttps](INFO): Moved sent file to Logs/20200819T142337/Courier0010.lzma.bak
2020-08-19T14:50:59.852Z,1597848659.852 [DataOverHttps](INFO): SBD MOMSN=12570403
2020-08-19T14:51:05.747Z,1597848665.747 [NAL9602](INFO): Not Powering down - fast GPS
2020-08-19T14:51:15.786Z,1597848675.786 [DataOverHttps](INFO): Sending 622 bytes from file Logs/20200819T142337/Express0011.lzma
2020-08-19T14:51:16.787Z,1597848676.787 [DataOverHttps](INFO): Moved sent file to Logs/20200819T142337/Express0011.lzma.bak
2020-08-19T14:51:16.788Z,1597848676.788 [DataOverHttps](INFO): SBD MOMSN=12570406
2020-08-19T14:51:17.880Z,1597848677.880 [Default:CheckIn:Read_Iridium] Stopped
2020-08-19T14:51:17.880Z,1597848677.880 [Default:CheckIn:C.Wait] Running Loop=1
2020-08-19T14:51:17.880Z,1597848677.880 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-08-19T14:56:18.472Z,1597848978.472 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-08-19T14:56:18.472Z,1597848978.472 [Default:CheckIn:C.Wait] Stopped
2020-08-19T14:56:18.472Z,1597848978.472 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-08-19T14:56:18.472Z,1597848978.472 [Default:CheckIn:D] Running Loop=1
2020-08-19T14:56:18.854Z,1597848978.854 [Default:CheckIn:D] Stopped
2020-08-19T14:56:18.854Z,1597848978.854 [Default:CheckIn:E] Running Loop=1
2020-08-19T14:56:19.259Z,1597848979.259 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 29.115322 min 
2020-08-19T14:56:19.259Z,1597848979.259 [Default:CheckIn:E] Stopped
2020-08-19T14:56:19.259Z,1597848979.259 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-08-19T14:56:19.260Z,1597848979.260 [Default:CheckIn] Stopped
2020-08-19T14:56:19.260Z,1597848979.260 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-08-19T14:56:19.260Z,1597848979.260 [Default:CheckIn](INFO): Running loop #4
2020-08-19T14:56:19.260Z,1597848979.260 [Default:CheckIn] Running Loop=4
2020-08-19T14:56:19.260Z,1597848979.260 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-08-19T14:56:19.260Z,1597848979.260 [Default:CheckIn:Read_GPS] Running Loop=1
2020-08-19T14:56:21.277Z,1597848981.277 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,145622.00,A,3648.14300,N,12147.22796,W,0.078,45.05,190820,,,A*45
2020-08-19T14:56:21.290Z,1597848981.290 [NAL9602](INFO): GPS fix at 20200819T145622: (36.802383, -121.787133)
2020-08-19T14:56:21.300Z,1597848981.300 [Default:CheckIn:Read_GPS] Stopped
2020-08-19T14:56:21.300Z,1597848981.300 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-08-19T14:56:29.073Z,1597848989.073 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20200819T142337/Courier0013.lzma
2020-08-19T14:56:30.075Z,1597848990.075 [DataOverHttps](INFO): Moved sent file to Logs/20200819T142337/Courier0013.lzma.bak
2020-08-19T14:56:30.076Z,1597848990.076 [DataOverHttps](INFO): SBD MOMSN=12570424
2020-08-19T14:56:45.837Z,1597849005.837 [DataOverHttps](INFO): Sending 150 bytes from file Logs/20200819T142337/Express0014.lzma
2020-08-19T14:56:46.840Z,1597849006.840 [DataOverHttps](INFO): Moved sent file to Logs/20200819T142337/Express0014.lzma.bak
2020-08-19T14:56:46.840Z,1597849006.840 [DataOverHttps](INFO): SBD MOMSN=12570427
2020-08-19T14:56:47.948Z,1597849007.948 [Default:CheckIn:Read_Iridium] Stopped
2020-08-19T14:56:47.949Z,1597849007.949 [Default:CheckIn:C.Wait] Running Loop=1
2020-08-19T14:56:47.949Z,1597849007.949 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-08-19T14:56:50.764Z,1597849010.764 [NAL9602](INFO): SBD MO Status=2, MOMSN=22432, MT Status=2, MTMSN=0
2020-08-19T14:56:50.765Z,1597849010.765 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-08-19T14:57:12.174Z,1597849032.174 [NAL9602](INFO): SBD MO Status=0, MOMSN=22432, MT Status=0, MTMSN=0
2020-08-19T14:57:12.174Z,1597849032.174 [NAL9602](INFO): No messages in MT queue
2020-08-19T14:57:42.876Z,1597849062.876 [NAL9602](INFO): Not Powering down - fast GPS
2020-08-19T14:57:46.232Z,1597849066.232 [CommandLine](IMPORTANT): got command ibit
2020-08-19T14:57:46.529Z,1597849066.529 [IBIT](IMPORTANT): Beginning Initiated BIT
2020-08-19T14:57:46.529Z,1597849066.529 [IBIT](IMPORTANT): Beginning control surface checks.
2020-08-19T14:57:46.532Z,1597849066.532 [CBIT](IMPORTANT): Beginning ground fault scan
2020-08-19T14:57:48.133Z,1597849068.133 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,145748.00,A,3648.14260,N,12147.22706,W,0.019,45.05,190820,,,D*44
2020-08-19T14:57:48.135Z,1597849068.135 [NAL9602](INFO): GPS fix at 20200819T145748: (36.802377, -121.787118)
2020-08-19T14:57:57.498Z,1597849077.498 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.002805
CHAN A1 (24V): 0.000327
CHAN A2 (12V): -0.002515
CHAN A3 (5V): -0.001530
CHAN B0 (3.3V): -0.000022
CHAN B1 (3.15aV): -0.000013
CHAN B2 (3.15bV): 0.000395
CHAN B3 (GND): 0.000303
OPEN: -0.000595
Full Scale Calc: 4.765 mA, -1.589 mA
2020-08-19T14:57:57.844Z,1597849077.844 [NAL9602](INFO): SBD MO Status=0, MOMSN=22433, MT Status=0, MTMSN=0
2020-08-19T14:57:57.845Z,1597849077.845 [NAL9602](INFO): No messages in MT queue
2020-08-19T14:57:59.045Z,1597849079.045 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,145759.00,A,3648.14317,N,12147.22729,W,0.039,45.05,190820,,,D*4A
2020-08-19T14:57:59.047Z,1597849079.047 [NAL9602](INFO): GPS fix at 20200819T145759: (36.802386, -121.787121)
2020-08-19T14:58:01.473Z,1597849081.473 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,145802.00,A,3648.14332,N,12147.22730,W,0.000,45.05,190820,,,D*4E
2020-08-19T14:58:01.475Z,1597849081.475 [NAL9602](INFO): GPS fix at 20200819T145802: (36.802389, -121.787122)
2020-08-19T14:58:04.292Z,1597849084.292 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,145805.00,A,3648.14346,N,12147.22731,W,0.058,45.05,190820,,,D*46
2020-08-19T14:58:04.294Z,1597849084.294 [NAL9602](INFO): GPS fix at 20200819T145805: (36.802391, -121.787122)
2020-08-19T14:58:07.525Z,1597849087.525 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,145808.00,A,3648.14357,N,12147.22740,W,0.019,45.05,190820,,,D*48
2020-08-19T14:58:07.527Z,1597849087.527 [NAL9602](INFO): GPS fix at 20200819T145808: (36.802393, -121.787123)
2020-08-19T14:58:10.357Z,1597849090.357 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,145811.00,A,3648.14361,N,12147.22757,W,0.039,45.05,190820,,,D*41
2020-08-19T14:58:10.359Z,1597849090.359 [NAL9602](INFO): GPS fix at 20200819T145811: (36.802394, -121.787126)
2020-08-19T14:58:13.589Z,1597849093.589 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,145814.00,A,3648.14367,N,12147.22766,W,0.078,45.05,190820,,,D*45
2020-08-19T14:58:13.591Z,1597849093.591 [NAL9602](INFO): GPS fix at 20200819T145814: (36.802394, -121.787128)
2020-08-19T14:58:16.417Z,1597849096.417 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,145817.00,A,3648.14381,N,12147.22793,W,0.058,45.05,190820,,,D*46
2020-08-19T14:58:16.419Z,1597849096.419 [NAL9602](INFO): GPS fix at 20200819T145817: (36.802397, -121.787132)
2020-08-19T14:58:19.644Z,1597849099.644 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,145820.00,A,3648.14384,N,12147.22811,W,0.136,45.05,190820,,,D*4B
2020-08-19T14:58:19.646Z,1597849099.646 [NAL9602](INFO): GPS fix at 20200819T145820: (36.802397, -121.787135)
2020-08-19T14:58:22.477Z,1597849102.477 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,145823.00,A,3648.14384,N,12147.22802,W,0.039,45.05,190820,,,D*44
2020-08-19T14:58:22.479Z,1597849102.479 [NAL9602](INFO): GPS fix at 20200819T145823: (36.802397, -121.787134)
2020-08-19T14:58:25.299Z,1597849105.299 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,145826.00,A,3648.14390,N,12147.22796,W,0.097,45.05,190820,,,D*42
2020-08-19T14:58:25.301Z,1597849105.301 [NAL9602](INFO): GPS fix at 20200819T145826: (36.802398, -121.787133)
2020-08-19T14:58:28.537Z,1597849108.537 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,145829.00,A,3648.14401,N,12147.22807,W,0.097,45.05,190820,,,D*45
2020-08-19T14:58:28.539Z,1597849108.539 [NAL9602](INFO): GPS fix at 20200819T145829: (36.802400, -121.787134)
2020-08-19T14:58:31.359Z,1597849111.359 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,145832.00,A,3648.14423,N,12147.22847,W,0.097,45.05,190820,,,D*4B
2020-08-19T14:58:31.361Z,1597849111.361 [NAL9602](INFO): GPS fix at 20200819T145832: (36.802404, -121.787141)
2020-08-19T14:58:33.009Z,1597849113.009 [IBIT](IMPORTANT): Communications Status:
Fix Status: 1
Iridium Signal Strength: 4
Latitude: 36.802402 Longitude: -121.787140
2020-08-19T14:58:33.398Z,1597849113.398 [IBIT](IMPORTANT): Battery Status:
Battery Charge (AH): 0.000000
Voltage: 16.690001
2020-08-19T14:58:33.398Z,1597849113.398 [IBIT](IMPORTANT): batteryCapacityThreshold: 50.000000 Ah
2020-08-19T14:58:33.399Z,1597849113.399 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.700000 V
2020-08-19T14:58:33.802Z,1597849113.802 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 %
2020-08-19T14:58:33.802Z,1597849113.802 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi
2020-08-19T14:58:33.803Z,1597849113.803 [IBIT](IMPORTANT): Pressure:8.458685 PSI
2020-08-19T14:58:33.803Z,1597849113.803 [IBIT](IMPORTANT): Humidity:10.749603 %
2020-08-19T14:58:34.227Z,1597849114.227 [IBIT](IMPORTANT): Vehicle Pitch:3.058191 degrees
2020-08-19T14:58:34.227Z,1597849114.227 [IBIT](IMPORTANT): Vehicle  Roll:-1.947616 degrees
2020-08-19T14:58:34.228Z,1597849114.228 [IBIT](IMPORTANT): Vehicle  Heading:201.111511 degrees
2020-08-19T14:58:34.605Z,1597849114.605 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m
2020-08-19T14:58:34.605Z,1597849114.605 [IBIT](IMPORTANT): buoyancyNeutral: 245.938309 cc
2020-08-19T14:58:34.606Z,1597849114.606 [IBIT](IMPORTANT): massDefault: -1.000926 cm
2020-08-19T14:58:34.606Z,1597849114.606 [IBIT](IMPORTANT): stopDepth: 205.000000 m
2020-08-19T14:58:34.606Z,1597849114.606 [IBIT](IMPORTANT): abortDepth: 250.000000 m
2020-08-19T14:58:34.606Z,1597849114.606 [IBIT](IMPORTANT): IBIT PASSED
2020-08-19T14:59:04.083Z,1597849144.082 [NAL9602](INFO): Not Powering down - fast GPS
2020-08-19T14:59:36.077Z,1597849176.077 [CommandLine](IMPORTANT): got command failComponent
2020-08-19T14:59:36.077Z,1597849176.077 [CommandLine](IMPORTANT): Failed components:
2020-08-19T14:59:36.077Z,1597849176.077 [CommandLine](IMPORTANT): No failed Components.
2020-08-19T15:01:48.526Z,1597849308.526 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-08-19T15:01:48.527Z,1597849308.527 [Default:CheckIn:C.Wait] Stopped
2020-08-19T15:01:48.527Z,1597849308.527 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-08-19T15:01:48.527Z,1597849308.527 [Default:CheckIn:D] Running Loop=1
2020-08-19T15:01:48.923Z,1597849308.923 [Default:CheckIn:D] Stopped
2020-08-19T15:01:48.923Z,1597849308.923 [Default:CheckIn:E] Running Loop=1
2020-08-19T15:01:49.332Z,1597849309.332 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 34.616471 min 
2020-08-19T15:01:49.332Z,1597849309.332 [Default:CheckIn:E] Stopped
2020-08-19T15:01:49.332Z,1597849309.332 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-08-19T15:01:49.333Z,1597849309.333 [Default:CheckIn] Stopped
2020-08-19T15:01:49.333Z,1597849309.333 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-08-19T15:01:49.333Z,1597849309.333 [Default:CheckIn](INFO): Running loop #5
2020-08-19T15:01:49.333Z,1597849309.333 [Default:CheckIn] Running Loop=5
2020-08-19T15:01:49.333Z,1597849309.333 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-08-19T15:01:49.333Z,1597849309.333 [Default:CheckIn:Read_GPS] Running Loop=1
2020-08-19T15:01:51.340Z,1597849311.340 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,150152.00,A,3648.14492,N,12147.22971,W,0.136,45.05,190820,,,D*44
2020-08-19T15:01:51.342Z,1597849311.342 [NAL9602](INFO): GPS fix at 20200819T150152: (36.802415, -121.787162)
2020-08-19T15:01:51.352Z,1597849311.352 [Default:CheckIn:Read_GPS] Stopped
2020-08-19T15:01:51.353Z,1597849311.353 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-08-19T15:01:58.253Z,1597849318.253 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20200819T142337/Courier0016.lzma
2020-08-19T15:01:59.255Z,1597849319.255 [DataOverHttps](INFO): Moved sent file to Logs/20200819T142337/Courier0016.lzma.bak
2020-08-19T15:01:59.256Z,1597849319.256 [DataOverHttps](INFO): SBD MOMSN=12570472
2020-08-19T15:02:15.031Z,1597849335.031 [DataOverHttps](INFO): Sending 828 bytes from file Logs/20200819T142337/Express0017.lzma
2020-08-19T15:02:15.180Z,1597849335.180 [NAL9602](INFO): SBD MO Status=0, MOMSN=22434, MT Status=0, MTMSN=0
2020-08-19T15:02:15.180Z,1597849335.180 [NAL9602](INFO): No messages in MT queue
2020-08-19T15:02:16.031Z,1597849336.031 [DataOverHttps](INFO): Moved sent file to Logs/20200819T142337/Express0017.lzma.bak
2020-08-19T15:02:16.032Z,1597849336.032 [DataOverHttps](INFO): SBD MOMSN=12570475
2020-08-19T15:02:17.210Z,1597849337.210 [Default:CheckIn:Read_Iridium] Stopped
2020-08-19T15:02:17.210Z,1597849337.210 [Default:CheckIn:C.Wait] Running Loop=1
2020-08-19T15:02:17.210Z,1597849337.210 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-08-19T15:02:45.878Z,1597849365.878 [NAL9602](INFO): Not Powering down - fast GPS
2020-08-19T15:07:17.786Z,1597849637.786 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-08-19T15:07:17.786Z,1597849637.786 [Default:CheckIn:C.Wait] Stopped
2020-08-19T15:07:17.786Z,1597849637.786 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-08-19T15:07:17.786Z,1597849637.786 [Default:CheckIn:D] Running Loop=1
2020-08-19T15:07:18.193Z,1597849638.193 [Default:CheckIn:D] Stopped
2020-08-19T15:07:18.193Z,1597849638.193 [Default:CheckIn:E] Running Loop=1
2020-08-19T15:07:18.595Z,1597849638.595 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 40.104297 min 
2020-08-19T15:07:18.595Z,1597849638.595 [Default:CheckIn:E] Stopped
2020-08-19T15:07:18.595Z,1597849638.595 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-08-19T15:07:18.595Z,1597849638.595 [Default:CheckIn] Stopped
2020-08-19T15:07:18.595Z,1597849638.595 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-08-19T15:07:18.596Z,1597849638.596 [Default:CheckIn](INFO): Running loop #6
2020-08-19T15:07:18.596Z,1597849638.596 [Default:CheckIn] Running Loop=6
2020-08-19T15:07:18.596Z,1597849638.596 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-08-19T15:07:18.596Z,1597849638.596 [Default:CheckIn:Read_GPS] Running Loop=1
2020-08-19T15:07:20.605Z,1597849640.605 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,150721.00,A,3648.14393,N,12147.22938,W,0.019,297.67,190820,,,D*78
2020-08-19T15:07:20.607Z,1597849640.607 [NAL9602](INFO): GPS fix at 20200819T150721: (36.802399, -121.787156)
2020-08-19T15:07:20.617Z,1597849640.617 [Default:CheckIn:Read_GPS] Stopped
2020-08-19T15:07:20.617Z,1597849640.617 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-08-19T15:07:27.805Z,1597849647.805 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20200819T142337/Courier0019.lzma
2020-08-19T15:07:28.807Z,1597849648.807 [DataOverHttps](INFO): Moved sent file to Logs/20200819T142337/Courier0019.lzma.bak
2020-08-19T15:07:28.808Z,1597849648.808 [DataOverHttps](INFO): SBD MOMSN=12570504
2020-08-19T15:07:43.224Z,1597849663.224 [NAL9602](INFO): SBD MO Status=2, MOMSN=22435, MT Status=2, MTMSN=0
2020-08-19T15:07:43.224Z,1597849663.224 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-08-19T15:07:44.537Z,1597849664.537 [DataOverHttps](INFO): Sending 138 bytes from file Logs/20200819T142337/Express0020.lzma
2020-08-19T15:07:45.539Z,1597849665.539 [DataOverHttps](INFO): Moved sent file to Logs/20200819T142337/Express0020.lzma.bak
2020-08-19T15:07:45.540Z,1597849665.540 [DataOverHttps](INFO): SBD MOMSN=12570507
2020-08-19T15:07:46.874Z,1597849666.874 [Default:CheckIn:Read_Iridium] Stopped
2020-08-19T15:07:46.874Z,1597849666.874 [Default:CheckIn:C.Wait] Running Loop=1
2020-08-19T15:07:46.874Z,1597849666.874 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-08-19T15:08:32.511Z,1597849712.511 [NAL9602](INFO): SBD MO Status=2, MOMSN=22435, MT Status=2, MTMSN=0
2020-08-19T15:08:32.511Z,1597849712.511 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-08-19T15:08:57.561Z,1597849737.561 [NAL9602](INFO): SBD MO Status=2, MOMSN=22435, MT Status=2, MTMSN=0
2020-08-19T15:08:57.561Z,1597849737.561 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-08-19T15:09:25.844Z,1597849765.844 [NAL9602](INFO): SBD MO Status=2, MOMSN=22435, MT Status=2, MTMSN=0
2020-08-19T15:09:25.844Z,1597849765.844 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-08-19T15:10:04.624Z,1597849804.624 [NAL9602](INFO): SBD MO Status=2, MOMSN=22435, MT Status=2, MTMSN=0
2020-08-19T15:10:04.624Z,1597849804.624 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-08-19T15:11:06.051Z,1597849866.051 [NAL9602](INFO): SBD MO Status=0, MOMSN=22435, MT Status=0, MTMSN=0
2020-08-19T15:11:06.051Z,1597849866.051 [NAL9602](INFO): No messages in MT queue
2020-08-19T15:11:36.745Z,1597849896.745 [NAL9602](INFO): Not Powering down - fast GPS
2020-08-19T15:12:47.475Z,1597849967.475 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-08-19T15:12:47.475Z,1597849967.475 [Default:CheckIn:C.Wait] Stopped
2020-08-19T15:12:47.475Z,1597849967.475 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-08-19T15:12:47.475Z,1597849967.475 [Default:CheckIn:D] Running Loop=1
2020-08-19T15:12:47.889Z,1597849967.889 [Default:CheckIn:D] Stopped
2020-08-19T15:12:47.889Z,1597849967.889 [Default:CheckIn:E] Running Loop=1
2020-08-19T15:12:48.301Z,1597849968.301 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 45.599243 min 
2020-08-19T15:12:48.301Z,1597849968.301 [Default:CheckIn:E] Stopped
2020-08-19T15:12:48.302Z,1597849968.302 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-08-19T15:12:48.302Z,1597849968.302 [Default:CheckIn] Stopped
2020-08-19T15:12:48.302Z,1597849968.302 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-08-19T15:12:48.302Z,1597849968.302 [Default:CheckIn](INFO): Running loop #7
2020-08-19T15:12:48.302Z,1597849968.302 [Default:CheckIn] Running Loop=7
2020-08-19T15:12:48.302Z,1597849968.302 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-08-19T15:12:48.302Z,1597849968.302 [Default:CheckIn:Read_GPS] Running Loop=1
2020-08-19T15:12:50.296Z,1597849970.296 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,151251.00,A,3648.14384,N,12147.22748,W,0.078,297.67,190820,,,D*73
2020-08-19T15:12:50.299Z,1597849970.299 [NAL9602](INFO): GPS fix at 20200819T151251: (36.802397, -121.787125)
2020-08-19T15:12:50.308Z,1597849970.308 [Default:CheckIn:Read_GPS] Stopped
2020-08-19T15:12:50.308Z,1597849970.308 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-08-19T15:12:57.293Z,1597849977.293 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20200819T142337/Courier0022.lzma
2020-08-19T15:12:57.564Z,1597849977.564 [NAL9602](INFO): SBD MO Status=0, MOMSN=22436, MT Status=0, MTMSN=0
2020-08-19T15:12:57.564Z,1597849977.564 [NAL9602](INFO): No messages in MT queue
2020-08-19T15:12:58.295Z,1597849978.295 [DataOverHttps](INFO): Moved sent file to Logs/20200819T142337/Courier0022.lzma.bak
2020-08-19T15:12:58.296Z,1597849978.296 [DataOverHttps](INFO): SBD MOMSN=12570551
2020-08-19T15:13:14.041Z,1597849994.041 [DataOverHttps](INFO): Sending 134 bytes from file Logs/20200819T142337/Express0023.lzma
2020-08-19T15:13:15.044Z,1597849995.044 [DataOverHttps](INFO): Moved sent file to Logs/20200819T142337/Express0023.lzma.bak
2020-08-19T15:13:15.044Z,1597849995.044 [DataOverHttps](INFO): SBD MOMSN=12570554
2020-08-19T15:13:16.154Z,1597849996.154 [Default:CheckIn:Read_Iridium] Stopped
2020-08-19T15:13:16.154Z,1597849996.154 [Default:CheckIn:C.Wait] Running Loop=1
2020-08-19T15:13:16.154Z,1597849996.154 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-08-19T15:13:28.266Z,1597850008.266 [NAL9602](INFO): Not Powering down - fast GPS
2020-08-19T15:18:16.750Z,1597850296.750 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-08-19T15:18:16.751Z,1597850296.751 [Default:CheckIn:C.Wait] Stopped
2020-08-19T15:18:16.751Z,1597850296.751 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-08-19T15:18:16.751Z,1597850296.751 [Default:CheckIn:D] Running Loop=1
2020-08-19T15:18:17.160Z,1597850297.160 [Default:CheckIn:D] Stopped
2020-08-19T15:18:17.160Z,1597850297.160 [Default:CheckIn:E] Running Loop=1
2020-08-19T15:18:17.561Z,1597850297.561 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 51.087085 min 
2020-08-19T15:18:17.561Z,1597850297.561 [Default:CheckIn:E] Stopped
2020-08-19T15:18:17.561Z,1597850297.561 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-08-19T15:18:17.561Z,1597850297.561 [Default:CheckIn] Stopped
2020-08-19T15:18:17.561Z,1597850297.561 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-08-19T15:18:17.561Z,1597850297.561 [Default:CheckIn](INFO): Running loop #8
2020-08-19T15:18:17.561Z,1597850297.561 [Default:CheckIn] Running Loop=8
2020-08-19T15:18:17.561Z,1597850297.561 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-08-19T15:18:17.562Z,1597850297.562 [Default:CheckIn:Read_GPS] Running Loop=1
2020-08-19T15:18:19.573Z,1597850299.573 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,151820.00,A,3648.14459,N,12147.22884,W,0.175,297.67,190820,,,D*7B
2020-08-19T15:18:19.575Z,1597850299.575 [NAL9602](INFO): GPS fix at 20200819T151820: (36.802410, -121.787147)
2020-08-19T15:18:19.608Z,1597850299.608 [Default:CheckIn:Read_GPS] Stopped
2020-08-19T15:18:19.608Z,1597850299.608 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-08-19T15:18:26.801Z,1597850306.801 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20200819T142337/Courier0025.lzma
2020-08-19T15:18:27.804Z,1597850307.804 [DataOverHttps](INFO): Moved sent file to Logs/20200819T142337/Courier0025.lzma.bak
2020-08-19T15:18:27.804Z,1597850307.804 [DataOverHttps](INFO): SBD MOMSN=12570559
2020-08-19T15:18:43.629Z,1597850323.629 [DataOverHttps](INFO): Sending 137 bytes from file Logs/20200819T142337/Express0026.lzma
2020-08-19T15:18:44.632Z,1597850324.632 [DataOverHttps](INFO): Moved sent file to Logs/20200819T142337/Express0026.lzma.bak
2020-08-19T15:18:44.632Z,1597850324.632 [DataOverHttps](INFO): SBD MOMSN=12570562
2020-08-19T15:18:45.855Z,1597850325.855 [Default:CheckIn:Read_Iridium] Stopped
2020-08-19T15:18:45.855Z,1597850325.855 [Default:CheckIn:C.Wait] Running Loop=1
2020-08-19T15:18:45.855Z,1597850325.855 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-08-19T15:20:06.236Z,1597850406.236 [NAL9602](INFO): SBD MO Status=0, MOMSN=22437, MT Status=0, MTMSN=0
2020-08-19T15:20:06.236Z,1597850406.236 [NAL9602](INFO): No messages in MT queue
2020-08-19T15:20:36.941Z,1597850436.941 [NAL9602](INFO): Not Powering down - fast GPS
2020-08-19T15:23:46.454Z,1597850626.454 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-08-19T15:23:46.455Z,1597850626.455 [Default:CheckIn:C.Wait] Stopped
2020-08-19T15:23:46.455Z,1597850626.455 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-08-19T15:23:46.455Z,1597850626.455 [Default:CheckIn:D] Running Loop=1
2020-08-19T15:23:46.844Z,1597850626.844 [Default:CheckIn:D] Stopped
2020-08-19T15:23:46.844Z,1597850626.844 [Default:CheckIn:E] Running Loop=1
2020-08-19T15:23:47.254Z,1597850627.254 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 56.581820 min 
2020-08-19T15:23:47.254Z,1597850627.254 [Default:CheckIn:E] Stopped
2020-08-19T15:23:47.254Z,1597850627.254 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-08-19T15:23:47.254Z,1597850627.254 [Default:CheckIn] Stopped
2020-08-19T15:23:47.254Z,1597850627.254 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-08-19T15:23:47.255Z,1597850627.255 [Default:CheckIn](INFO): Running loop #9
2020-08-19T15:23:47.255Z,1597850627.255 [Default:CheckIn] Running Loop=9
2020-08-19T15:23:47.255Z,1597850627.255 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-08-19T15:23:47.255Z,1597850627.255 [Default:CheckIn:Read_GPS] Running Loop=1
2020-08-19T15:23:49.264Z,1597850629.264 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,152350.00,A,3648.14336,N,12147.22838,W,0.019,297.67,190820,,,D*76
2020-08-19T15:23:49.267Z,1597850629.267 [NAL9602](INFO): GPS fix at 20200819T152350: (36.802389, -121.787140)
2020-08-19T15:23:49.276Z,1597850629.276 [Default:CheckIn:Read_GPS] Stopped
2020-08-19T15:23:49.276Z,1597850629.276 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-08-19T15:23:56.485Z,1597850636.485 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20200819T142337/Courier0028.lzma
2020-08-19T15:23:57.487Z,1597850637.487 [DataOverHttps](INFO): Moved sent file to Logs/20200819T142337/Courier0028.lzma.bak
2020-08-19T15:23:57.488Z,1597850637.488 [DataOverHttps](INFO): SBD MOMSN=12570617
2020-08-19T15:24:13.161Z,1597850653.161 [DataOverHttps](INFO): Sending 136 bytes from file Logs/20200819T142337/Express0029.lzma
2020-08-19T15:24:14.163Z,1597850654.163 [DataOverHttps](INFO): Moved sent file to Logs/20200819T142337/Express0029.lzma.bak
2020-08-19T15:24:14.164Z,1597850654.164 [DataOverHttps](INFO): SBD MOMSN=12570620
2020-08-19T15:24:15.543Z,1597850655.543 [Default:CheckIn:Read_Iridium] Stopped
2020-08-19T15:24:15.543Z,1597850655.543 [Default:CheckIn:C.Wait] Running Loop=1
2020-08-19T15:24:15.543Z,1597850655.543 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-08-19T15:24:32.106Z,1597850672.106 [NAL9602](INFO): SBD MO Status=2, MOMSN=22438, MT Status=2, MTMSN=0
2020-08-19T15:24:32.107Z,1597850672.107 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-08-19T15:25:30.297Z,1597850730.297 [CommandLine](IMPORTANT): got command failComponent
2020-08-19T15:25:30.298Z,1597850730.298 [CommandLine](IMPORTANT): Failed components:
2020-08-19T15:25:30.298Z,1597850730.298 [CommandLine](IMPORTANT): No failed Components.
2020-08-19T15:26:02.762Z,1597850762.762 [CommandLine](IMPORTANT): got command show variable charge
2020-08-19T15:26:02.766Z,1597850762.766 [CommandLine](IMPORTANT): platform_battery_charge (unknown)
2020-08-19T15:26:02.767Z,1597850762.767 [CommandLine](IMPORTANT): platform_battery_charge_usage (unknown)
2020-08-19T15:26:02.767Z,1597850762.767 [CommandLine](IMPORTANT): platform_battery_fully_charged (unknown)
2020-08-19T15:26:02.887Z,1597850762.887 [CommandLine](IMPORTANT): BPC1.reserve_battery_charge (ampere_hour)
2020-08-19T15:26:02.887Z,1597850762.887 [CommandLine](IMPORTANT): BPC1.platform_battery_charge (ampere_hour)
2020-08-19T15:26:05.424Z,1597850765.424 [NAL9602](INFO): SBD MO Status=2, MOMSN=22438, MT Status=2, MTMSN=0
2020-08-19T15:26:05.425Z,1597850765.425 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-08-19T15:26:09.480Z,1597850769.480 [CommandLine](IMPORTANT): got command get platform_battery_charge
2020-08-19T15:26:09.481Z,1597850769.481 [CommandLine](FAULT): Element has no value
2020-08-19T15:26:40.164Z,1597850800.164 [NAL9602](INFO): SBD MO Status=2, MOMSN=22438, MT Status=2, MTMSN=0
2020-08-19T15:26:40.164Z,1597850800.164 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-08-19T15:27:55.744Z,1597850875.744 [NAL9602](INFO): SBD MO Status=0, MOMSN=22438, MT Status=0, MTMSN=0
2020-08-19T15:27:55.744Z,1597850875.744 [NAL9602](INFO): No messages in MT queue
2020-08-19T15:28:26.439Z,1597850906.439 [NAL9602](INFO): Not Powering down - fast GPS
2020-08-19T15:29:16.140Z,1597850956.140 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-08-19T15:29:16.140Z,1597850956.140 [Default:CheckIn:C.Wait] Stopped
2020-08-19T15:29:16.140Z,1597850956.140 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-08-19T15:29:16.140Z,1597850956.140 [Default:CheckIn:D] Running Loop=1
2020-08-19T15:29:16.557Z,1597850956.557 [Default:CheckIn:D] Stopped
2020-08-19T15:29:16.557Z,1597850956.557 [Default:CheckIn:E] Running Loop=1
2020-08-19T15:29:16.952Z,1597850956.952 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 62.077030 min 
2020-08-19T15:29:16.952Z,1597850956.952 [Default:CheckIn:E] Stopped
2020-08-19T15:29:16.952Z,1597850956.952 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-08-19T15:29:16.952Z,1597850956.952 [Default:CheckIn] Stopped
2020-08-19T15:29:16.953Z,1597850956.953 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-08-19T15:29:16.953Z,1597850956.953 [Default:CheckIn](INFO): Running loop #10
2020-08-19T15:29:16.953Z,1597850956.953 [Default:CheckIn] Running Loop=10
2020-08-19T15:29:16.953Z,1597850956.953 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-08-19T15:29:16.953Z,1597850956.953 [Default:CheckIn:Read_GPS] Running Loop=1
2020-08-19T15:29:18.965Z,1597850958.965 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,152919.00,A,3648.14295,N,12147.22987,W,0.078,297.67,190820,,,D*7B
2020-08-19T15:29:18.967Z,1597850958.967 [NAL9602](INFO): GPS fix at 20200819T152919: (36.802383, -121.787165)
2020-08-19T15:29:18.977Z,1597850958.977 [Default:CheckIn:Read_GPS] Stopped
2020-08-19T15:29:18.977Z,1597850958.977 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-08-19T15:29:25.885Z,1597850965.885 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20200819T142337/Courier0031.lzma
2020-08-19T15:29:26.888Z,1597850966.888 [DataOverHttps](INFO): Moved sent file to Logs/20200819T142337/Courier0031.lzma.bak
2020-08-19T15:29:26.888Z,1597850966.888 [DataOverHttps](INFO): SBD MOMSN=12570623
2020-08-19T15:29:42.490Z,1597850982.490 [DataOverHttps](INFO): Sending 338 bytes from file Logs/20200819T142337/Express0032.lzma
2020-08-19T15:29:42.800Z,1597850982.800 [NAL9602](INFO): SBD MO Status=2, MOMSN=22439, MT Status=2, MTMSN=0
2020-08-19T15:29:42.800Z,1597850982.800 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-08-19T15:29:43.492Z,1597850983.492 [DataOverHttps](INFO): Moved sent file to Logs/20200819T142337/Express0032.lzma.bak
2020-08-19T15:29:43.492Z,1597850983.492 [DataOverHttps](INFO): SBD MOMSN=12570626
2020-08-19T15:29:44.823Z,1597850984.823 [Default:CheckIn:Read_Iridium] Stopped
2020-08-19T15:29:44.823Z,1597850984.823 [Default:CheckIn:C.Wait] Running Loop=1
2020-08-19T15:29:44.823Z,1597850984.823 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-08-19T15:30:01.788Z,1597851001.788 [NAL9602](INFO): SBD MO Status=2, MOMSN=22439, MT Status=2, MTMSN=0
2020-08-19T15:30:01.789Z,1597851001.789 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-08-19T15:30:12.296Z,1597851012.296 [NAL9602](INFO): SBD MO Status=0, MOMSN=22439, MT Status=0, MTMSN=0
2020-08-19T15:30:12.296Z,1597851012.296 [NAL9602](INFO): No messages in MT queue
2020-08-19T15:30:42.995Z,1597851042.995 [NAL9602](INFO): Not Powering down - fast GPS
2020-08-19T15:34:45.425Z,1597851285.425 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-08-19T15:34:45.425Z,1597851285.425 [Default:CheckIn:C.Wait] Stopped
2020-08-19T15:34:45.425Z,1597851285.425 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-08-19T15:34:45.426Z,1597851285.426 [Default:CheckIn:D] Running Loop=1
2020-08-19T15:34:45.811Z,1597851285.811 [Default:CheckIn:D] Stopped
2020-08-19T15:34:45.811Z,1597851285.811 [Default:CheckIn:E] Running Loop=1
2020-08-19T15:34:46.220Z,1597851286.220 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 67.564604 min 
2020-08-19T15:34:46.221Z,1597851286.221 [Default:CheckIn:E] Stopped
2020-08-19T15:34:46.221Z,1597851286.221 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-08-19T15:34:46.221Z,1597851286.221 [Default:CheckIn] Stopped
2020-08-19T15:34:46.221Z,1597851286.221 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-08-19T15:34:46.221Z,1597851286.221 [Default:CheckIn](INFO): Running loop #11
2020-08-19T15:34:46.221Z,1597851286.221 [Default:CheckIn] Running Loop=11
2020-08-19T15:34:46.221Z,1597851286.221 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-08-19T15:34:46.221Z,1597851286.221 [Default:CheckIn:Read_GPS] Running Loop=1
2020-08-19T15:34:48.228Z,1597851288.228 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,153449.00,A,3648.14446,N,12147.22797,W,0.019,297.67,190820,,,D*72
2020-08-19T15:34:48.231Z,1597851288.231 [NAL9602](INFO): GPS fix at 20200819T153449: (36.802408, -121.787133)
2020-08-19T15:34:48.241Z,1597851288.241 [Default:CheckIn:Read_GPS] Stopped
2020-08-19T15:34:48.241Z,1597851288.241 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-08-19T15:34:55.949Z,1597851295.949 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20200819T142337/Courier0034.lzma
2020-08-19T15:34:56.954Z,1597851296.954 [DataOverHttps](INFO): Moved sent file to Logs/20200819T142337/Courier0034.lzma.bak
2020-08-19T15:34:56.955Z,1597851296.955 [DataOverHttps](INFO): SBD MOMSN=12570685
2020-08-19T15:35:12.989Z,1597851312.989 [DataOverHttps](INFO): Sending 136 bytes from file Logs/20200819T142337/Express0035.lzma
2020-08-19T15:35:13.992Z,1597851313.992 [DataOverHttps](INFO): Moved sent file to Logs/20200819T142337/Express0035.lzma.bak
2020-08-19T15:35:13.992Z,1597851313.992 [DataOverHttps](INFO): SBD MOMSN=12570688
2020-08-19T15:35:15.319Z,1597851315.319 [Default:CheckIn:Read_Iridium] Stopped
2020-08-19T15:35:15.319Z,1597851315.319 [Default:CheckIn:C.Wait] Running Loop=1
2020-08-19T15:35:15.319Z,1597851315.319 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-08-19T15:35:37.515Z,1597851337.515 [NAL9602](INFO): SBD MO Status=2, MOMSN=22440, MT Status=2, MTMSN=0
2020-08-19T15:35:37.515Z,1597851337.515 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-08-19T15:37:05.996Z,1597851425.996 [NAL9602](INFO): SBD MO Status=2, MOMSN=22440, MT Status=2, MTMSN=0
2020-08-19T15:37:05.997Z,1597851425.997 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-08-19T15:37:33.872Z,1597851453.872 [NAL9602](INFO): SBD MO Status=0, MOMSN=22440, MT Status=0, MTMSN=0
2020-08-19T15:37:33.872Z,1597851453.872 [NAL9602](INFO): No messages in MT queue
2020-08-19T15:38:04.571Z,1597851484.571 [NAL9602](INFO): Not Powering down - fast GPS
2020-08-19T15:40:15.888Z,1597851615.888 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-08-19T15:40:15.889Z,1597851615.889 [Default:CheckIn:C.Wait] Stopped
2020-08-19T15:40:15.889Z,1597851615.889 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-08-19T15:40:15.889Z,1597851615.889 [Default:CheckIn:D] Running Loop=1
2020-08-19T15:40:16.349Z,1597851616.349 [Default:CheckIn:D] Stopped
2020-08-19T15:40:16.349Z,1597851616.349 [Default:CheckIn:E] Running Loop=1
2020-08-19T15:40:16.717Z,1597851616.717 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 73.073568 min 
2020-08-19T15:40:16.717Z,1597851616.717 [Default:CheckIn:E] Stopped
2020-08-19T15:40:16.717Z,1597851616.717 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-08-19T15:40:16.722Z,1597851616.722 [Default:CheckIn] Stopped
2020-08-19T15:40:16.722Z,1597851616.722 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-08-19T15:40:16.722Z,1597851616.722 [Default:CheckIn](INFO): Running loop #12
2020-08-19T15:40:16.722Z,1597851616.722 [Default:CheckIn] Running Loop=12
2020-08-19T15:40:16.722Z,1597851616.722 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-08-19T15:40:16.722Z,1597851616.722 [Default:CheckIn:Read_GPS] Running Loop=1
2020-08-19T15:40:18.713Z,1597851618.713 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,154019.00,A,3648.14466,N,12147.22852,W,0.019,297.67,190820,,,D*70
2020-08-19T15:40:18.715Z,1597851618.715 [NAL9602](INFO): GPS fix at 20200819T154019: (36.802411, -121.787142)
2020-08-19T15:40:18.725Z,1597851618.725 [Default:CheckIn:Read_GPS] Stopped
2020-08-19T15:40:18.725Z,1597851618.725 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-08-19T15:40:19.524Z,1597851619.524 [Default:CheckIn:Read_Iridium] Stopped
2020-08-19T15:40:19.524Z,1597851619.524 [Default:CheckIn:C.Wait] Running Loop=1
2020-08-19T15:40:19.525Z,1597851619.525 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-08-19T15:40:28.807Z,1597851628.807 [NAL9602](INFO): SBD MO Status=0, MOMSN=22441, MT Status=0, MTMSN=0
2020-08-19T15:40:28.807Z,1597851628.807 [NAL9602](INFO): No messages in MT queue
2020-08-19T15:40:59.516Z,1597851659.516 [NAL9602](INFO): Not Powering down - fast GPS
2020-08-19T15:45:20.112Z,1597851920.112 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-08-19T15:45:20.112Z,1597851920.112 [Default:CheckIn:C.Wait] Stopped
2020-08-19T15:45:20.112Z,1597851920.112 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-08-19T15:45:20.112Z,1597851920.112 [Default:CheckIn:D] Running Loop=1
2020-08-19T15:45:20.513Z,1597851920.513 [Default:CheckIn:D] Stopped
2020-08-19T15:45:20.513Z,1597851920.513 [Default:CheckIn:E] Running Loop=1
2020-08-19T15:45:20.926Z,1597851920.926 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 78.142969 min 
2020-08-19T15:45:20.926Z,1597851920.926 [Default:CheckIn:E] Stopped
2020-08-19T15:45:20.926Z,1597851920.926 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-08-19T15:45:20.926Z,1597851920.926 [Default:CheckIn] Stopped
2020-08-19T15:45:20.926Z,1597851920.926 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-08-19T15:45:20.927Z,1597851920.927 [Default:CheckIn](INFO): Running loop #13
2020-08-19T15:45:20.927Z,1597851920.927 [Default:CheckIn] Running Loop=13
2020-08-19T15:45:20.927Z,1597851920.927 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-08-19T15:45:20.927Z,1597851920.927 [Default:CheckIn:Read_GPS] Running Loop=1
2020-08-19T15:45:22.933Z,1597851922.933 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,154523.00,A,3648.14284,N,12147.22743,W,0.000,0.00,190820,,,D*7C
2020-08-19T15:45:22.935Z,1597851922.935 [NAL9602](INFO): GPS fix at 20200819T154523: (36.802381, -121.787124)
2020-08-19T15:45:22.975Z,1597851922.975 [Default:CheckIn:Read_GPS] Stopped
2020-08-19T15:45:22.975Z,1597851922.975 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-08-19T15:45:29.941Z,1597851929.941 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20200819T142337/Courier0037.lzma
2020-08-19T15:45:30.943Z,1597851930.943 [DataOverHttps](INFO): Moved sent file to Logs/20200819T142337/Courier0037.lzma.bak
2020-08-19T15:45:30.944Z,1597851930.944 [DataOverHttps](INFO): SBD MOMSN=12570733
2020-08-19T15:45:46.765Z,1597851946.765 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20200819T142337/Courier0040.lzma
2020-08-19T15:45:47.768Z,1597851947.768 [DataOverHttps](INFO): Moved sent file to Logs/20200819T142337/Courier0040.lzma.bak
2020-08-19T15:45:47.768Z,1597851947.768 [DataOverHttps](INFO): SBD MOMSN=12570736
2020-08-19T15:46:02.524Z,1597851962.524 [NAL9602](INFO): SBD MO Status=0, MOMSN=22442, MT Status=0, MTMSN=0
2020-08-19T15:46:02.524Z,1597851962.524 [NAL9602](INFO): No messages in MT queue
2020-08-19T15:46:03.733Z,1597851963.733 [DataOverHttps](INFO): Sending 136 bytes from file Logs/20200819T142337/Express0038.lzma
2020-08-19T15:46:04.736Z,1597851964.736 [DataOverHttps](INFO): Moved sent file to Logs/20200819T142337/Express0038.lzma.bak
2020-08-19T15:46:04.736Z,1597851964.736 [DataOverHttps](INFO): SBD MOMSN=12570739
2020-08-19T15:46:20.785Z,1597851980.785 [DataOverHttps](INFO): Sending 136 bytes from file Logs/20200819T142337/Express0041.lzma
2020-08-19T15:46:21.788Z,1597851981.788 [DataOverHttps](INFO): Moved sent file to Logs/20200819T142337/Express0041.lzma.bak
2020-08-19T15:46:21.788Z,1597851981.788 [DataOverHttps](INFO): SBD MOMSN=12570742
2020-08-19T15:46:23.154Z,1597851983.154 [Default:CheckIn:Read_Iridium] Stopped
2020-08-19T15:46:23.154Z,1597851983.154 [Default:CheckIn:C.Wait] Running Loop=1
2020-08-19T15:46:23.154Z,1597851983.154 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-08-19T15:46:33.247Z,1597851993.247 [NAL9602](INFO): Not Powering down - fast GPS
2020-08-19T15:51:23.754Z,1597852283.754 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-08-19T15:51:23.755Z,1597852283.755 [Default:CheckIn:C.Wait] Stopped
2020-08-19T15:51:23.755Z,1597852283.755 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-08-19T15:51:23.755Z,1597852283.755 [Default:CheckIn:D] Running Loop=1
2020-08-19T15:51:24.170Z,1597852284.170 [Default:CheckIn:D] Stopped
2020-08-19T15:51:24.170Z,1597852284.170 [Default:CheckIn:E] Running Loop=1
2020-08-19T15:51:24.557Z,1597852284.557 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 84.203923 min 
2020-08-19T15:51:24.557Z,1597852284.557 [Default:CheckIn:E] Stopped
2020-08-19T15:51:24.557Z,1597852284.557 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-08-19T15:51:24.557Z,1597852284.557 [Default:CheckIn] Stopped
2020-08-19T15:51:24.557Z,1597852284.557 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-08-19T15:51:24.558Z,1597852284.558 [Default:CheckIn](INFO): Running loop #14
2020-08-19T15:51:24.558Z,1597852284.558 [Default:CheckIn] Running Loop=14
2020-08-19T15:51:24.558Z,1597852284.558 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-08-19T15:51:24.558Z,1597852284.558 [Default:CheckIn:Read_GPS] Running Loop=1
2020-08-19T15:51:26.565Z,1597852286.565 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,155127.00,A,3648.14290,N,12147.22663,W,0.058,0.00,190820,,,D*76
2020-08-19T15:51:26.567Z,1597852286.567 [NAL9602](INFO): GPS fix at 20200819T155127: (36.802382, -121.787110)
2020-08-19T15:51:26.611Z,1597852286.611 [Default:CheckIn:Read_GPS] Stopped
2020-08-19T15:51:26.611Z,1597852286.611 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-08-19T15:51:34.345Z,1597852294.345 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20200819T142337/Courier0043.lzma
2020-08-19T15:51:35.347Z,1597852295.347 [DataOverHttps](INFO): Moved sent file to Logs/20200819T142337/Courier0043.lzma.bak
2020-08-19T15:51:35.348Z,1597852295.348 [DataOverHttps](INFO): SBD MOMSN=12570748
2020-08-19T15:51:51.310Z,1597852311.310 [DataOverHttps](INFO): Sending 137 bytes from file Logs/20200819T142337/Express0044.lzma
2020-08-19T15:51:52.312Z,1597852312.312 [DataOverHttps](INFO): Moved sent file to Logs/20200819T142337/Express0044.lzma.bak
2020-08-19T15:51:52.312Z,1597852312.312 [DataOverHttps](INFO): SBD MOMSN=12570787
2020-08-19T15:51:53.670Z,1597852313.670 [Default:CheckIn:Read_Iridium] Stopped
2020-08-19T15:51:53.670Z,1597852313.670 [Default:CheckIn:C.Wait] Running Loop=1
2020-08-19T15:51:53.671Z,1597852313.671 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-08-19T15:51:54.442Z,1597852314.442 [NAL9602](INFO): SBD MO Status=0, MOMSN=22443, MT Status=0, MTMSN=0
2020-08-19T15:51:54.442Z,1597852314.442 [NAL9602](INFO): No messages in MT queue
2020-08-19T15:52:25.165Z,1597852345.165 [NAL9602](INFO): Not Powering down - fast GPS
2020-08-19T15:56:54.245Z,1597852614.245 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-08-19T15:56:54.245Z,1597852614.245 [Default:CheckIn:C.Wait] Stopped
2020-08-19T15:56:54.245Z,1597852614.245 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-08-19T15:56:54.245Z,1597852614.245 [Default:CheckIn:D] Running Loop=1
2020-08-19T15:56:54.648Z,1597852614.648 [Default:CheckIn:D] Stopped
2020-08-19T15:56:54.648Z,1597852614.648 [Default:CheckIn:E] Running Loop=1
2020-08-19T15:56:55.050Z,1597852615.050 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 89.711890 min 
2020-08-19T15:56:55.050Z,1597852615.050 [Default:CheckIn:E] Stopped
2020-08-19T15:56:55.050Z,1597852615.050 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-08-19T15:56:55.050Z,1597852615.050 [Default:CheckIn] Stopped
2020-08-19T15:56:55.050Z,1597852615.050 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-08-19T15:56:55.051Z,1597852615.051 [Default:CheckIn](INFO): Running loop #15
2020-08-19T15:56:55.051Z,1597852615.051 [Default:CheckIn] Running Loop=15
2020-08-19T15:56:55.051Z,1597852615.051 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-08-19T15:56:55.051Z,1597852615.051 [Default:CheckIn:Read_GPS] Running Loop=1
2020-08-19T15:56:57.065Z,1597852617.065 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,155657.00,A,3648.14451,N,12147.22520,W,0.058,0.00,190820,,,D*79
2020-08-19T15:56:57.067Z,1597852617.067 [NAL9602](INFO): GPS fix at 20200819T155657: (36.802408, -121.787087)
2020-08-19T15:56:57.100Z,1597852617.100 [Default:CheckIn:Read_GPS] Stopped
2020-08-19T15:56:57.100Z,1597852617.100 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-08-19T15:57:04.813Z,1597852624.813 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20200819T142337/Courier0046.lzma
2020-08-19T15:57:05.815Z,1597852625.815 [DataOverHttps](INFO): Moved sent file to Logs/20200819T142337/Courier0046.lzma.bak
2020-08-19T15:57:05.816Z,1597852625.816 [DataOverHttps](INFO): SBD MOMSN=12570797
2020-08-19T15:57:21.673Z,1597852641.673 [DataOverHttps](INFO): Sending 136 bytes from file Logs/20200819T142337/Express0047.lzma
2020-08-19T15:57:22.676Z,1597852642.676 [DataOverHttps](INFO): Moved sent file to Logs/20200819T142337/Express0047.lzma.bak
2020-08-19T15:57:22.676Z,1597852642.676 [DataOverHttps](INFO): SBD MOMSN=12570800
2020-08-19T15:57:23.745Z,1597852643.745 [Default:CheckIn:Read_Iridium] Stopped
2020-08-19T15:57:23.745Z,1597852643.745 [Default:CheckIn:C.Wait] Running Loop=1
2020-08-19T15:57:23.745Z,1597852643.745 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-08-19T15:57:24.136Z,1597852644.136 [NAL9602](INFO): SBD MO Status=2, MOMSN=22444, MT Status=2, MTMSN=0
2020-08-19T15:57:24.136Z,1597852644.136 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-08-19T15:57:41.498Z,1597852661.498 [NAL9602](INFO): SBD MO Status=0, MOMSN=22444, MT Status=0, MTMSN=0
2020-08-19T15:57:41.498Z,1597852661.498 [NAL9602](INFO): No messages in MT queue
2020-08-19T15:58:12.239Z,1597852692.239 [NAL9602](INFO): Not Powering down - fast GPS
2020-08-19T16:02:24.352Z,1597852944.352 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-08-19T16:02:24.352Z,1597852944.352 [Default:CheckIn:C.Wait] Stopped
2020-08-19T16:02:24.352Z,1597852944.352 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-08-19T16:02:24.352Z,1597852944.352 [Default:CheckIn:D] Running Loop=1
2020-08-19T16:02:24.754Z,1597852944.754 [Default:CheckIn:D] Stopped
2020-08-19T16:02:24.754Z,1597852944.754 [Default:CheckIn:E] Running Loop=1
2020-08-19T16:02:25.169Z,1597852945.169 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 95.213647 min 
2020-08-19T16:02:25.169Z,1597852945.169 [Default:CheckIn:E] Stopped
2020-08-19T16:02:25.169Z,1597852945.169 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-08-19T16:02:25.169Z,1597852945.169 [Default:CheckIn] Stopped
2020-08-19T16:02:25.169Z,1597852945.169 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-08-19T16:02:25.169Z,1597852945.169 [Default:CheckIn](INFO): Running loop #16
2020-08-19T16:02:25.169Z,1597852945.169 [Default:CheckIn] Running Loop=16
2020-08-19T16:02:25.170Z,1597852945.170 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-08-19T16:02:25.170Z,1597852945.170 [Default:CheckIn:Read_GPS] Running Loop=1
2020-08-19T16:02:27.169Z,1597852947.169 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,160227.00,A,3648.14517,N,12147.22646,W,0.019,234.92,190820,,,D*77
2020-08-19T16:02:27.171Z,1597852947.171 [NAL9602](INFO): GPS fix at 20200819T160227: (36.802419, -121.787108)
2020-08-19T16:02:27.214Z,1597852947.214 [Default:CheckIn:Read_GPS] Stopped
2020-08-19T16:02:27.214Z,1597852947.214 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-08-19T16:02:34.261Z,1597852954.261 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20200819T142337/Courier0049.lzma
2020-08-19T16:02:35.264Z,1597852955.264 [DataOverHttps](INFO): Moved sent file to Logs/20200819T142337/Courier0049.lzma.bak
2020-08-19T16:02:35.264Z,1597852955.264 [DataOverHttps](INFO): SBD MOMSN=12570849
2020-08-19T16:02:49.400Z,1597852969.400 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2020-08-19T16:02:49.403Z,1597852969.403 [BPC1](ERROR): Failed to receive data from all sticks prior to timeout. Will not retry this scan cycle.
2020-08-19T16:02:50.969Z,1597852970.969 [DataOverHttps](INFO): Sending 134 bytes from file Logs/20200819T142337/Express0050.lzma
2020-08-19T16:02:51.972Z,1597852971.972 [DataOverHttps](INFO): Moved sent file to Logs/20200819T142337/Express0050.lzma.bak
2020-08-19T16:02:51.972Z,1597852971.972 [DataOverHttps](INFO): SBD MOMSN=12570852
2020-08-19T16:02:53.037Z,1597852973.037 [Default:CheckIn:Read_Iridium] Stopped
2020-08-19T16:02:53.037Z,1597852973.037 [Default:CheckIn:C.Wait] Running Loop=1
2020-08-19T16:02:53.037Z,1597852973.037 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-08-19T16:03:01.912Z,1597852981.912 [NAL9602](INFO): SBD MO Status=0, MOMSN=22445, MT Status=0, MTMSN=0
2020-08-19T16:03:01.912Z,1597852981.912 [NAL9602](INFO): No messages in MT queue
2020-08-19T16:03:32.613Z,1597853012.613 [NAL9602](INFO): Not Powering down - fast GPS
2020-08-19T16:07:53.662Z,1597853273.662 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-08-19T16:07:53.662Z,1597853273.662 [Default:CheckIn:C.Wait] Stopped
2020-08-19T16:07:53.662Z,1597853273.662 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-08-19T16:07:53.662Z,1597853273.662 [Default:CheckIn:D] Running Loop=1
2020-08-19T16:07:54.058Z,1597853274.058 [Default:CheckIn:D] Stopped
2020-08-19T16:07:54.058Z,1597853274.058 [Default:CheckIn:E] Running Loop=1
2020-08-19T16:07:54.455Z,1597853274.455 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 100.702043 min 
2020-08-19T16:07:54.455Z,1597853274.455 [Default:CheckIn:E] Stopped
2020-08-19T16:07:54.455Z,1597853274.455 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-08-19T16:07:54.455Z,1597853274.455 [Default:CheckIn] Stopped
2020-08-19T16:07:54.455Z,1597853274.455 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-08-19T16:07:54.456Z,1597853274.456 [Default:CheckIn](INFO): Running loop #17
2020-08-19T16:07:54.456Z,1597853274.456 [Default:CheckIn] Running Loop=17
2020-08-19T16:07:54.456Z,1597853274.456 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-08-19T16:07:54.456Z,1597853274.456 [Default:CheckIn:Read_GPS] Running Loop=1
2020-08-19T16:07:56.473Z,1597853276.473 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,160757.00,A,3648.14325,N,12147.22887,W,0.058,234.92,190820,,,D*74
2020-08-19T16:07:56.475Z,1597853276.475 [NAL9602](INFO): GPS fix at 20200819T160757: (36.802388, -121.787148)
2020-08-19T16:07:56.484Z,1597853276.484 [Default:CheckIn:Read_GPS] Stopped
2020-08-19T16:07:56.484Z,1597853276.484 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-08-19T16:08:03.686Z,1597853283.686 [DataOverHttps](INFO): Sending 86 bytes from file Logs/20200819T142337/Courier0052.lzma
2020-08-19T16:08:04.692Z,1597853284.692 [DataOverHttps](INFO): Moved sent file to Logs/20200819T142337/Courier0052.lzma.bak
2020-08-19T16:08:04.692Z,1597853284.692 [DataOverHttps](INFO): SBD MOMSN=12570863
2020-08-19T16:08:17.072Z,1597853297.072 [NAL9602](INFO): SBD MO Status=0, MOMSN=22446, MT Status=0, MTMSN=0
2020-08-19T16:08:17.072Z,1597853297.072 [NAL9602](INFO): No messages in MT queue
2020-08-19T16:08:20.297Z,1597853300.297 [DataOverHttps](INFO): Sending 137 bytes from file Logs/20200819T142337/Express0053.lzma
2020-08-19T16:08:21.300Z,1597853301.300 [DataOverHttps](INFO): Moved sent file to Logs/20200819T142337/Express0053.lzma.bak
2020-08-19T16:08:21.300Z,1597853301.300 [DataOverHttps](INFO): SBD MOMSN=12570866
2020-08-19T16:08:22.337Z,1597853302.337 [Default:CheckIn:Read_Iridium] Stopped
2020-08-19T16:08:22.337Z,1597853302.337 [Default:CheckIn:C.Wait] Running Loop=1
2020-08-19T16:08:22.337Z,1597853302.337 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-08-19T16:08:47.773Z,1597853327.773 [NAL9602](INFO): Not Powering down - fast GPS
2020-08-19T16:13:22.921Z,1597853602.921 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-08-19T16:13:22.921Z,1597853602.921 [Default:CheckIn:C.Wait] Stopped
2020-08-19T16:13:22.922Z,1597853602.922 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-08-19T16:13:22.922Z,1597853602.922 [Default:CheckIn:D] Running Loop=1
2020-08-19T16:13:23.331Z,1597853603.331 [Default:CheckIn:D] Stopped
2020-08-19T16:13:23.331Z,1597853603.331 [Default:CheckIn:E] Running Loop=1
2020-08-19T16:13:23.733Z,1597853603.733 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 106.189933 min 
2020-08-19T16:13:23.733Z,1597853603.733 [Default:CheckIn:E] Stopped
2020-08-19T16:13:23.733Z,1597853603.733 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-08-19T16:13:23.733Z,1597853603.733 [Default:CheckIn] Stopped
2020-08-19T16:13:23.733Z,1597853603.733 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-08-19T16:13:23.733Z,1597853603.733 [Default:CheckIn](INFO): Running loop #18
2020-08-19T16:13:23.734Z,1597853603.734 [Default:CheckIn] Running Loop=18
2020-08-19T16:13:23.734Z,1597853603.734 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-08-19T16:13:23.734Z,1597853603.734 [Default:CheckIn:Read_GPS] Running Loop=1
2020-08-19T16:13:25.745Z,1597853605.745 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,161326.00,A,3648.16462,N,12147.21687,W,0.019,29.97,190820,,,D*42
2020-08-19T16:13:25.748Z,1597853605.748 [NAL9602](INFO): GPS fix at 20200819T161326: (36.802744, -121.786948)
2020-08-19T16:13:25.758Z,1597853605.758 [Default:CheckIn:Read_GPS] Stopped
2020-08-19T16:13:25.758Z,1597853605.758 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-08-19T16:13:33.017Z,1597853613.017 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20200819T142337/Courier0055.lzma
2020-08-19T16:13:34.020Z,1597853614.020 [DataOverHttps](INFO): Moved sent file to Logs/20200819T142337/Courier0055.lzma.bak
2020-08-19T16:13:34.020Z,1597853614.020 [DataOverHttps](INFO): SBD MOMSN=12570901
2020-08-19T16:13:46.352Z,1597853626.352 [NAL9602](INFO): SBD MO Status=2, MOMSN=22447, MT Status=2, MTMSN=0
2020-08-19T16:13:46.353Z,1597853626.353 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-08-19T16:13:49.693Z,1597853629.693 [DataOverHttps](INFO): Sending 145 bytes from file Logs/20200819T142337/Express0056.lzma
2020-08-19T16:13:50.696Z,1597853630.696 [DataOverHttps](INFO): Moved sent file to Logs/20200819T142337/Express0056.lzma.bak
2020-08-19T16:13:50.696Z,1597853630.696 [DataOverHttps](INFO): SBD MOMSN=12570904
2020-08-19T16:13:52.010Z,1597853632.010 [Default:CheckIn:Read_Iridium] Stopped
2020-08-19T16:13:52.011Z,1597853632.011 [Default:CheckIn:C.Wait] Running Loop=1
2020-08-19T16:13:52.011Z,1597853632.011 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-08-19T16:14:38.871Z,1597853678.871 [NAL9602](INFO): SBD MO Status=2, MOMSN=22447, MT Status=2, MTMSN=0
2020-08-19T16:14:38.872Z,1597853678.872 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-08-19T16:14:46.539Z,1597853686.539 [NAL9602](INFO): SBD MO Status=0, MOMSN=22447, MT Status=0, MTMSN=0
2020-08-19T16:14:46.539Z,1597853686.539 [NAL9602](INFO): No messages in MT queue
2020-08-19T16:15:17.243Z,1597853717.243 [NAL9602](INFO): Not Powering down - fast GPS
2020-08-19T16:18:52.607Z,1597853932.607 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-08-19T16:18:52.607Z,1597853932.607 [Default:CheckIn:C.Wait] Stopped
2020-08-19T16:18:52.607Z,1597853932.607 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-08-19T16:18:52.607Z,1597853932.607 [Default:CheckIn:D] Running Loop=1
2020-08-19T16:18:52.999Z,1597853932.999 [Default:CheckIn:D] Stopped
2020-08-19T16:18:52.999Z,1597853932.999 [Default:CheckIn:E] Running Loop=1
2020-08-19T16:18:53.408Z,1597853933.408 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 111.684399 min 
2020-08-19T16:18:53.408Z,1597853933.408 [Default:CheckIn:E] Stopped
2020-08-19T16:18:53.408Z,1597853933.408 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-08-19T16:18:53.408Z,1597853933.408 [Default:CheckIn] Stopped
2020-08-19T16:18:53.409Z,1597853933.409 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-08-19T16:18:53.409Z,1597853933.409 [Default:CheckIn](INFO): Running loop #19
2020-08-19T16:18:53.409Z,1597853933.409 [Default:CheckIn] Running Loop=19
2020-08-19T16:18:53.409Z,1597853933.409 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-08-19T16:18:53.409Z,1597853933.409 [Default:CheckIn:Read_GPS] Running Loop=1
2020-08-19T16:18:55.423Z,1597853935.423 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,161856.00,A,3648.16477,N,12147.21538,W,0.330,29.97,190820,,,D*45
2020-08-19T16:18:55.425Z,1597853935.425 [NAL9602](INFO): GPS fix at 20200819T161856: (36.802746, -121.786923)
2020-08-19T16:18:55.435Z,1597853935.435 [Default:CheckIn:Read_GPS] Stopped
2020-08-19T16:18:55.435Z,1597853935.435 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-08-19T16:19:02.413Z,1597853942.413 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20200819T142337/Courier0058.lzma
2020-08-19T16:19:03.416Z,1597853943.416 [DataOverHttps](INFO): Moved sent file to Logs/20200819T142337/Courier0058.lzma.bak
2020-08-19T16:19:03.416Z,1597853943.416 [DataOverHttps](INFO): SBD MOMSN=12570916
2020-08-19T16:19:19.158Z,1597853959.158 [DataOverHttps](INFO): Sending 135 bytes from file Logs/20200819T142337/Express0059.lzma
2020-08-19T16:19:20.160Z,1597853960.160 [DataOverHttps](INFO): Moved sent file to Logs/20200819T142337/Express0059.lzma.bak
2020-08-19T16:19:20.160Z,1597853960.160 [DataOverHttps](INFO): SBD MOMSN=12570919
2020-08-19T16:19:21.288Z,1597853961.288 [Default:CheckIn:Read_Iridium] Stopped
2020-08-19T16:19:21.288Z,1597853961.288 [Default:CheckIn:C.Wait] Running Loop=1
2020-08-19T16:19:21.288Z,1597853961.288 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-08-19T16:19:22.889Z,1597853962.889 [NAL9602](INFO): SBD MO Status=0, MOMSN=22448, MT Status=0, MTMSN=0
2020-08-19T16:19:22.890Z,1597853962.890 [NAL9602](INFO): No messages in MT queue
2020-08-19T16:19:53.597Z,1597853993.597 [NAL9602](INFO): Not Powering down - fast GPS
2020-08-19T16:24:21.949Z,1597854261.949 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-08-19T16:24:21.949Z,1597854261.949 [Default:CheckIn:C.Wait] Stopped
2020-08-19T16:24:21.949Z,1597854261.949 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-08-19T16:24:21.949Z,1597854261.949 [Default:CheckIn:D] Running Loop=1
2020-08-19T16:24:22.284Z,1597854262.284 [Default:CheckIn:D] Stopped
2020-08-19T16:24:22.284Z,1597854262.284 [Default:CheckIn:E] Running Loop=1
2020-08-19T16:24:22.683Z,1597854262.683 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 117.172493 min 
2020-08-19T16:24:22.683Z,1597854262.683 [Default:CheckIn:E] Stopped
2020-08-19T16:24:22.683Z,1597854262.683 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-08-19T16:24:22.683Z,1597854262.683 [Default:CheckIn] Stopped
2020-08-19T16:24:22.683Z,1597854262.683 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-08-19T16:24:22.683Z,1597854262.683 [Default:CheckIn](INFO): Running loop #20
2020-08-19T16:24:22.683Z,1597854262.683 [Default:CheckIn] Running Loop=20
2020-08-19T16:24:22.684Z,1597854262.684 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-08-19T16:24:22.684Z,1597854262.684 [Default:CheckIn:Read_GPS] Running Loop=1
2020-08-19T16:24:24.701Z,1597854264.701 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162425.00,A,3648.16498,N,12147.21347,W,0.097,29.97,190820,,,D*4F
2020-08-19T16:24:24.714Z,1597854264.714 [NAL9602](INFO): GPS fix at 20200819T162425: (36.802750, -121.786891)
2020-08-19T16:24:24.724Z,1597854264.724 [Default:CheckIn:Read_GPS] Stopped
2020-08-19T16:24:24.725Z,1597854264.725 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-08-19T16:24:31.717Z,1597854271.717 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20200819T142337/Courier0061.lzma
2020-08-19T16:24:32.720Z,1597854272.720 [DataOverHttps](INFO): Moved sent file to Logs/20200819T142337/Courier0061.lzma.bak
2020-08-19T16:24:32.720Z,1597854272.720 [DataOverHttps](INFO): SBD MOMSN=12570964
2020-08-19T16:24:34.800Z,1597854274.800 [NAL9602](INFO): SBD MO Status=0, MOMSN=22449, MT Status=0, MTMSN=0
2020-08-19T16:24:34.801Z,1597854274.801 [NAL9602](INFO): No messages in MT queue
2020-08-19T16:24:48.301Z,1597854288.301 [DataOverHttps](INFO): Sending 138 bytes from file Logs/20200819T142337/Express0062.lzma
2020-08-19T16:24:49.304Z,1597854289.304 [DataOverHttps](INFO): Moved sent file to Logs/20200819T142337/Express0062.lzma.bak
2020-08-19T16:24:49.304Z,1597854289.304 [DataOverHttps](INFO): SBD MOMSN=12570967
2020-08-19T16:24:50.564Z,1597854290.564 [Default:CheckIn:Read_Iridium] Stopped
2020-08-19T16:24:50.564Z,1597854290.564 [Default:CheckIn:C.Wait] Running Loop=1
2020-08-19T16:24:50.564Z,1597854290.564 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-08-19T16:25:05.499Z,1597854305.499 [NAL9602](INFO): Not Powering down - fast GPS
2020-08-19T16:28:03.783Z,1597854483.783 [CommandLine](IMPORTANT): got command failComponent
2020-08-19T16:28:03.783Z,1597854483.783 [CommandLine](IMPORTANT): Failed components:
2020-08-19T16:28:03.783Z,1597854483.783 [CommandLine](IMPORTANT): No failed Components.
2020-08-19T16:29:51.164Z,1597854591.164 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-08-19T16:29:51.164Z,1597854591.164 [Default:CheckIn:C.Wait] Stopped
2020-08-19T16:29:51.164Z,1597854591.164 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-08-19T16:29:51.164Z,1597854591.164 [Default:CheckIn:D] Running Loop=1
2020-08-19T16:29:51.574Z,1597854591.574 [Default:CheckIn:D] Stopped
2020-08-19T16:29:51.574Z,1597854591.574 [Default:CheckIn:E] Running Loop=1
2020-08-19T16:29:51.984Z,1597854591.984 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 122.660653 min 
2020-08-19T16:29:51.984Z,1597854591.984 [Default:CheckIn:E] Stopped
2020-08-19T16:29:51.984Z,1597854591.984 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-08-19T16:29:51.984Z,1597854591.984 [Default:CheckIn] Stopped
2020-08-19T16:29:51.984Z,1597854591.984 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-08-19T16:29:51.984Z,1597854591.984 [Default:CheckIn](INFO): Running loop #21
2020-08-19T16:29:51.984Z,1597854591.984 [Default:CheckIn] Running Loop=21
2020-08-19T16:29:51.984Z,1597854591.984 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-08-19T16:29:51.984Z,1597854591.984 [Default:CheckIn:Read_GPS] Running Loop=1
2020-08-19T16:29:53.988Z,1597854593.988 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162954.00,A,3648.45808,N,12147.11342,W,5.851,357.27,190820,,,D*77
2020-08-19T16:29:53.991Z,1597854593.991 [NAL9602](INFO): GPS fix at 20200819T162954: (36.807635, -121.785224)
2020-08-19T16:29:54.023Z,1597854594.023 [Default:CheckIn:Read_GPS] Stopped
2020-08-19T16:29:54.024Z,1597854594.024 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-08-19T16:30:00.885Z,1597854600.885 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20200819T142337/Courier0064.lzma
2020-08-19T16:30:01.888Z,1597854601.888 [DataOverHttps](INFO): Moved sent file to Logs/20200819T142337/Courier0064.lzma.bak
2020-08-19T16:30:01.888Z,1597854601.888 [DataOverHttps](INFO): SBD MOMSN=12570981
2020-08-19T16:30:22.300Z,1597854622.300 [NAL9602](INFO): SBD MO Status=0, MOMSN=22450, MT Status=0, MTMSN=0
2020-08-19T16:30:22.300Z,1597854622.300 [NAL9602](INFO): No messages in MT queue
2020-08-19T16:30:23.681Z,1597854623.681 [DataOverHttps](INFO): Sending 209 bytes from file Logs/20200819T142337/Express0065.lzma
2020-08-19T16:30:24.684Z,1597854624.684 [DataOverHttps](INFO): Moved sent file to Logs/20200819T142337/Express0065.lzma.bak
2020-08-19T16:30:24.684Z,1597854624.684 [DataOverHttps](INFO): SBD MOMSN=12570984
2020-08-19T16:30:25.943Z,1597854625.943 [Default:CheckIn:Read_Iridium] Stopped
2020-08-19T16:30:25.943Z,1597854625.943 [Default:CheckIn:C.Wait] Running Loop=1
2020-08-19T16:30:25.943Z,1597854625.943 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-08-19T16:30:53.010Z,1597854653.010 [NAL9602](INFO): Not Powering down - fast GPS
2020-08-19T16:35:26.527Z,1597854926.527 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-08-19T16:35:26.527Z,1597854926.527 [Default:CheckIn:C.Wait] Stopped
2020-08-19T16:35:26.527Z,1597854926.527 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-08-19T16:35:26.527Z,1597854926.527 [Default:CheckIn:D] Running Loop=1
2020-08-19T16:35:26.936Z,1597854926.936 [Default:CheckIn:D] Stopped
2020-08-19T16:35:26.936Z,1597854926.936 [Default:CheckIn:E] Running Loop=1
2020-08-19T16:35:27.340Z,1597854927.340 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 128.250024 min 
2020-08-19T16:35:27.340Z,1597854927.340 [Default:CheckIn:E] Stopped
2020-08-19T16:35:27.340Z,1597854927.340 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-08-19T16:35:27.340Z,1597854927.340 [Default:CheckIn] Stopped
2020-08-19T16:35:27.341Z,1597854927.341 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-08-19T16:35:27.341Z,1597854927.341 [Default:CheckIn](INFO): Running loop #22
2020-08-19T16:35:27.341Z,1597854927.341 [Default:CheckIn] Running Loop=22
2020-08-19T16:35:27.341Z,1597854927.341 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-08-19T16:35:27.341Z,1597854927.341 [Default:CheckIn:Read_GPS] Running Loop=1
2020-08-19T16:35:29.358Z,1597854929.358 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,163530.00,A,3648.29887,N,12148.10590,W,8.048,257.90,190820,,,D*72
2020-08-19T16:35:29.360Z,1597854929.360 [NAL9602](INFO): GPS fix at 20200819T163530: (36.804981, -121.801765)
2020-08-19T16:35:29.370Z,1597854929.370 [Default:CheckIn:Read_GPS] Stopped
2020-08-19T16:35:29.371Z,1597854929.371 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-08-19T16:35:37.241Z,1597854937.241 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20200819T142337/Courier0067.lzma
2020-08-19T16:35:38.245Z,1597854938.245 [DataOverHttps](INFO): Moved sent file to Logs/20200819T142337/Courier0067.lzma.bak
2020-08-19T16:35:38.246Z,1597854938.246 [DataOverHttps](INFO): SBD MOMSN=12571033
2020-08-19T16:36:02.321Z,1597854962.321 [DataOverHttps](INFO): Sending 150 bytes from file Logs/20200819T142337/Express0068.lzma
2020-08-19T16:36:03.324Z,1597854963.324 [DataOverHttps](INFO): Moved sent file to Logs/20200819T142337/Express0068.lzma.bak
2020-08-19T16:36:03.324Z,1597854963.324 [DataOverHttps](INFO): SBD MOMSN=12571040
2020-08-19T16:36:04.516Z,1597854964.516 [Default:CheckIn:Read_Iridium] Stopped
2020-08-19T16:36:04.517Z,1597854964.517 [Default:CheckIn:C.Wait] Running Loop=1
2020-08-19T16:36:04.517Z,1597854964.517 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-08-19T16:36:59.440Z,1597855019.440 [NAL9602](INFO): SBD MO Status=2, MOMSN=22451, MT Status=2, MTMSN=0
2020-08-19T16:36:59.441Z,1597855019.441 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-08-19T16:38:14.614Z,1597855094.614 [NAL9602](INFO): SBD MO Status=0, MOMSN=22451, MT Status=0, MTMSN=0
2020-08-19T16:38:14.614Z,1597855094.614 [NAL9602](INFO): No messages in MT queue
2020-08-19T16:38:45.309Z,1597855125.309 [NAL9602](INFO): Not Powering down - fast GPS
2020-08-19T16:41:05.116Z,1597855265.116 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-08-19T16:41:05.116Z,1597855265.116 [Default:CheckIn:C.Wait] Stopped
2020-08-19T16:41:05.117Z,1597855265.117 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-08-19T16:41:05.117Z,1597855265.117 [Default:CheckIn:D] Running Loop=1
2020-08-19T16:41:05.528Z,1597855265.528 [Default:CheckIn:D] Stopped
2020-08-19T16:41:05.528Z,1597855265.528 [Default:CheckIn:E] Running Loop=1
2020-08-19T16:41:05.915Z,1597855265.915 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 133.893229 min 
2020-08-19T16:41:05.915Z,1597855265.915 [Default:CheckIn:E] Stopped
2020-08-19T16:41:05.915Z,1597855265.915 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-08-19T16:41:05.916Z,1597855265.916 [Default:CheckIn] Stopped
2020-08-19T16:41:05.916Z,1597855265.916 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-08-19T16:41:05.916Z,1597855265.916 [Default:CheckIn](INFO): Running loop #23
2020-08-19T16:41:05.916Z,1597855265.916 [Default:CheckIn] Running Loop=23
2020-08-19T16:41:05.916Z,1597855265.916 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-08-19T16:41:05.916Z,1597855265.916 [Default:CheckIn:Read_GPS] Running Loop=1
2020-08-19T16:41:07.935Z,1597855267.935 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164108.00,A,3647.90235,N,12149.99420,W,12.188,240.31,190820,,,D*45
2020-08-19T16:41:07.938Z,1597855267.938 [NAL9602](INFO): GPS fix at 20200819T164108: (36.798372, -121.833237)
2020-08-19T16:41:07.948Z,1597855267.948 [Default:CheckIn:Read_GPS] Stopped
2020-08-19T16:41:07.948Z,1597855267.948 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-08-19T16:41:15.185Z,1597855275.185 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20200819T142337/Courier0070.lzma
2020-08-19T16:41:16.188Z,1597855276.188 [DataOverHttps](INFO): Moved sent file to Logs/20200819T142337/Courier0070.lzma.bak
2020-08-19T16:41:16.188Z,1597855276.188 [DataOverHttps](INFO): SBD MOMSN=12571044
2020-08-19T16:41:31.865Z,1597855291.865 [DataOverHttps](INFO): Sending 153 bytes from file Logs/20200819T142337/Express0071.lzma
2020-08-19T16:41:32.868Z,1597855292.868 [DataOverHttps](INFO): Moved sent file to Logs/20200819T142337/Express0071.lzma.bak
2020-08-19T16:41:32.868Z,1597855292.868 [DataOverHttps](INFO): SBD MOMSN=12571048
2020-08-19T16:41:34.190Z,1597855294.190 [NAL9602](INFO): SBD MO Status=0, MOMSN=22452, MT Status=0, MTMSN=0
2020-08-19T16:41:34.190Z,1597855294.190 [NAL9602](INFO): No messages in MT queue
2020-08-19T16:41:34.200Z,1597855294.200 [Default:CheckIn:Read_Iridium] Stopped
2020-08-19T16:41:34.200Z,1597855294.200 [Default:CheckIn:C.Wait] Running Loop=1
2020-08-19T16:41:34.200Z,1597855294.200 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-08-19T16:42:04.899Z,1597855324.899 [NAL9602](INFO): Not Powering down - fast GPS
2020-08-19T16:46:34.804Z,1597855594.804 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-08-19T16:46:34.805Z,1597855594.805 [Default:CheckIn:C.Wait] Stopped
2020-08-19T16:46:34.805Z,1597855594.805 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-08-19T16:46:34.805Z,1597855594.805 [Default:CheckIn:D] Running Loop=1
2020-08-19T16:46:35.221Z,1597855595.221 [Default:CheckIn:D] Stopped
2020-08-19T16:46:35.221Z,1597855595.221 [Default:CheckIn:E] Running Loop=1
2020-08-19T16:46:35.613Z,1597855595.613 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 139.388102 min 
2020-08-19T16:46:35.615Z,1597855595.615 [Default:CheckIn:E] Stopped
2020-08-19T16:46:35.615Z,1597855595.615 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-08-19T16:46:35.615Z,1597855595.615 [Default:CheckIn] Stopped
2020-08-19T16:46:35.615Z,1597855595.615 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-08-19T16:46:35.616Z,1597855595.616 [Default:CheckIn](INFO): Running loop #24
2020-08-19T16:46:35.616Z,1597855595.616 [Default:CheckIn] Running Loop=24
2020-08-19T16:46:35.616Z,1597855595.616 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-08-19T16:46:35.616Z,1597855595.616 [Default:CheckIn:Read_GPS] Running Loop=1
2020-08-19T16:46:37.629Z,1597855597.629 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164638.00,A,3647.79325,N,12150.22271,W,0.175,274.35,190820,,,D*7E
2020-08-19T16:46:37.641Z,1597855597.641 [NAL9602](INFO): GPS fix at 20200819T164638: (36.796554, -121.837045)
2020-08-19T16:46:37.651Z,1597855597.651 [Default:CheckIn:Read_GPS] Stopped
2020-08-19T16:46:37.651Z,1597855597.651 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-08-19T16:46:52.713Z,1597855612.713 [DataOverHttps](INFO): Sending 74 bytes from file Logs/20200819T142337/Courier0073.lzma
2020-08-19T16:46:53.716Z,1597855613.716 [DataOverHttps](INFO): Moved sent file to Logs/20200819T142337/Courier0073.lzma.bak
2020-08-19T16:46:53.716Z,1597855613.716 [DataOverHttps](INFO): SBD MOMSN=12571094
2020-08-19T16:47:03.111Z,1597855623.111 [NAL9602](INFO): SBD MO Status=0, MOMSN=22453, MT Status=0, MTMSN=0
2020-08-19T16:47:03.111Z,1597855623.111 [NAL9602](INFO): No messages in MT queue
2020-08-19T16:47:09.389Z,1597855629.389 [DataOverHttps](INFO): Sending 153 bytes from file Logs/20200819T142337/Express0074.lzma
2020-08-19T16:47:10.392Z,1597855630.392 [DataOverHttps](INFO): Moved sent file to Logs/20200819T142337/Express0074.lzma.bak
2020-08-19T16:47:10.392Z,1597855630.392 [DataOverHttps](INFO): SBD MOMSN=12571097
2020-08-19T16:47:11.572Z,1597855631.572 [Default:CheckIn:Read_Iridium] Stopped
2020-08-19T16:47:11.572Z,1597855631.572 [Default:CheckIn:C.Wait] Running Loop=1
2020-08-19T16:47:11.572Z,1597855631.572 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-08-19T16:47:33.785Z,1597855653.785 [NAL9602](INFO): Not Powering down - fast GPS
2020-08-19T16:52:12.165Z,1597855932.165 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-08-19T16:52:12.165Z,1597855932.165 [Default:CheckIn:C.Wait] Stopped
2020-08-19T16:52:12.166Z,1597855932.166 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-08-19T16:52:12.166Z,1597855932.166 [Default:CheckIn:D] Running Loop=1
2020-08-19T16:52:12.584Z,1597855932.584 [Default:CheckIn:D] Stopped
2020-08-19T16:52:12.584Z,1597855932.584 [Default:CheckIn:E] Running Loop=1
2020-08-19T16:52:12.967Z,1597855932.967 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 145.010824 min 
2020-08-19T16:52:12.967Z,1597855932.967 [Default:CheckIn:E] Stopped
2020-08-19T16:52:12.967Z,1597855932.967 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-08-19T16:52:12.967Z,1597855932.967 [Default:CheckIn] Stopped
2020-08-19T16:52:12.967Z,1597855932.967 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-08-19T16:52:12.967Z,1597855932.967 [Default:CheckIn](INFO): Running loop #25
2020-08-19T16:52:12.967Z,1597855932.967 [Default:CheckIn] Running Loop=25
2020-08-19T16:52:12.967Z,1597855932.967 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-08-19T16:52:12.967Z,1597855932.967 [Default:CheckIn:Read_GPS] Running Loop=1
2020-08-19T16:52:14.981Z,1597855934.981 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165215.00,A,3647.82832,N,12150.83103,W,1.205,91.89,190820,,,D*4B
2020-08-19T16:52:14.984Z,1597855934.984 [NAL9602](INFO): GPS fix at 20200819T165215: (36.797139, -121.847184)
2020-08-19T16:52:14.994Z,1597855934.994 [Default:CheckIn:Read_GPS] Stopped
2020-08-19T16:52:14.994Z,1597855934.994 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-08-19T16:52:22.277Z,1597855942.277 [DataOverHttps](INFO): Sending 73 bytes from file Logs/20200819T142337/Courier0076.lzma
2020-08-19T16:52:23.280Z,1597855943.280 [DataOverHttps](INFO): Moved sent file to Logs/20200819T142337/Courier0076.lzma.bak
2020-08-19T16:52:23.280Z,1597855943.280 [DataOverHttps](INFO): SBD MOMSN=12571101
2020-08-19T16:52:33.159Z,1597855953.159 [NAL9602](INFO): SBD MO Status=0, MOMSN=22454, MT Status=0, MTMSN=0
2020-08-19T16:52:33.159Z,1597855953.159 [NAL9602](INFO): No messages in MT queue
2020-08-19T16:52:39.125Z,1597855959.125 [DataOverHttps](INFO): Sending 152 bytes from file Logs/20200819T142337/Express0077.lzma
2020-08-19T16:52:40.128Z,1597855960.128 [DataOverHttps](INFO): Moved sent file to Logs/20200819T142337/Express0077.lzma.bak
2020-08-19T16:52:40.128Z,1597855960.128 [DataOverHttps](INFO): SBD MOMSN=12571104
2020-08-19T16:52:41.254Z,1597855961.254 [Default:CheckIn:Read_Iridium] Stopped
2020-08-19T16:52:41.254Z,1597855961.254 [Default:CheckIn:C.Wait] Running Loop=1
2020-08-19T16:52:41.254Z,1597855961.254 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-08-19T16:53:03.871Z,1597855983.871 [NAL9602](INFO): Not Powering down - fast GPS
2020-08-19T16:56:51.995Z,1597856211.995 [DataOverHttps](IMPORTANT): SBD MTMSN=20200819T165652
2020-08-19T16:56:59.335Z,1597856219.335 [DataOverHttps](INFO): Received command:restart logs