2020-02-27T15:47:47.614Z,1582818467.614 [Supervisor](DEBUG): Initializing supervisor.
2020-02-27T15:47:47.617Z,1582818467.617 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2020-02-27T15:47:47.617Z,1582818467.617 [SyncHandler](INFO): Protected caller Thread ID is 4081
2020-02-27T15:47:47.618Z,1582818467.618 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2020-02-27T15:47:47.619Z,1582818467.619 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2020-02-27T15:47:47.619Z,1582818467.619 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 4082
2020-02-27T15:47:47.622Z,1582818467.622 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2020-02-27T15:47:47.635Z,1582818467.635 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2020-02-27T15:47:47.636Z,1582818467.636 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2020-02-27T15:47:47.637Z,1582818467.637 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 4083
2020-02-27T15:47:47.637Z,1582818467.637 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2020-02-27T15:47:47.638Z,1582818467.638 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2020-02-27T15:47:47.639Z,1582818467.639 [logger ThreadHandler](INFO): Protected caller Thread ID is 4084
2020-02-27T15:47:47.641Z,1582818467.641 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2020-02-27T15:47:47.641Z,1582818467.641 [Supervisor](INFO): Looking for Config files in directory: Config/
2020-02-27T15:47:47.643Z,1582818467.643 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2020-02-27T15:47:47.858Z,1582818467.858 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2020-02-27T15:47:47.859Z,1582818467.859 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2020-02-27T15:47:47.937Z,1582818467.937 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2020-02-27T15:47:48.388Z,1582818468.388 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2020-02-27T15:47:48.388Z,1582818468.388 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2020-02-27T15:47:48.722Z,1582818468.722 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2020-02-27T15:47:48.722Z,1582818468.722 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2020-02-27T15:47:48.817Z,1582818468.817 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2020-02-27T15:47:48.818Z,1582818468.818 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2020-02-27T15:47:49.126Z,1582818469.126 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2020-02-27T15:47:49.127Z,1582818469.127 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2020-02-27T15:47:49.329Z,1582818469.329 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2020-02-27T15:47:49.330Z,1582818469.330 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2020-02-27T15:47:49.815Z,1582818469.815 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2020-02-27T15:47:49.816Z,1582818469.816 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2020-02-27T15:47:49.919Z,1582818469.919 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2020-02-27T15:47:49.920Z,1582818469.920 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2020-02-27T15:47:50.019Z,1582818470.019 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2020-02-27T15:47:50.020Z,1582818470.020 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2020-02-27T15:47:50.711Z,1582818470.711 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2020-02-27T15:47:50.712Z,1582818470.712 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2020-02-27T15:47:51.144Z,1582818471.144 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2020-02-27T15:47:51.145Z,1582818471.145 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2020-02-27T15:47:51.343Z,1582818471.343 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2020-02-27T15:47:51.344Z,1582818471.344 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2020-02-27T15:47:51.493Z,1582818471.493 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2020-02-27T15:47:51.494Z,1582818471.494 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2020-02-27T15:47:51.645Z,1582818471.645 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2020-02-27T15:47:51.647Z,1582818471.647 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2020-02-27T15:47:51.648Z,1582818471.648 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg
2020-02-27T15:47:51.737Z,1582818471.737 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2020-02-27T15:47:51.820Z,1582818471.820 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2020-02-27T15:47:51.920Z,1582818471.920 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg
2020-02-27T15:47:52.002Z,1582818472.002 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2020-02-27T15:47:52.095Z,1582818472.095 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2020-02-27T15:47:52.196Z,1582818472.196 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2020-02-27T15:47:52.409Z,1582818472.409 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/workSite.cfg
2020-02-27T15:47:52.483Z,1582818472.483 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2020-02-27T15:47:52.661Z,1582818472.661 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2020-02-27T15:47:53.232Z,1582818473.232 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2020-02-27T15:47:53.352Z,1582818473.352 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Battery.cfg
2020-02-27T15:47:53.693Z,1582818473.693 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2020-02-27T15:47:53.693Z,1582818473.693 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2020-02-27T15:47:53.698Z,1582818473.698 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2020-02-27T15:47:53.750Z,1582818473.750 [VerticalControl](DEBUG): Construct VerticalControl.
2020-02-27T15:47:53.874Z,1582818473.874 [VerticalControl] Loaded
2020-02-27T15:47:53.874Z,1582818473.874 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2020-02-27T15:47:53.875Z,1582818473.875 [HorizontalControl](DEBUG): Construct HorizontalControl.
2020-02-27T15:47:53.963Z,1582818473.963 [HorizontalControl] Loaded
2020-02-27T15:47:53.963Z,1582818473.963 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2020-02-27T15:47:53.964Z,1582818473.964 [SpeedControl](DEBUG): Construct SpeedControl.
2020-02-27T15:47:53.970Z,1582818473.970 [SpeedControl] Loaded
2020-02-27T15:47:53.970Z,1582818473.970 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2020-02-27T15:47:53.971Z,1582818473.971 [LoopControl](DEBUG): Construct LoopControl.
2020-02-27T15:47:53.971Z,1582818473.971 [LoopControl] Loaded
2020-02-27T15:47:53.972Z,1582818473.972 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2020-02-27T15:47:53.972Z,1582818473.972 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2020-02-27T15:47:53.973Z,1582818473.973 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2020-02-27T15:47:53.986Z,1582818473.986 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2020-02-27T15:47:53.987Z,1582818473.987 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2020-02-27T15:47:54.093Z,1582818474.093 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2020-02-27T15:47:54.093Z,1582818474.093 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2020-02-27T15:47:54.203Z,1582818474.203 [BuoyancyServo] Loaded
2020-02-27T15:47:54.203Z,1582818474.203 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2020-02-27T15:47:54.215Z,1582818474.215 [ElevatorServo] Loaded
2020-02-27T15:47:54.215Z,1582818474.215 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2020-02-27T15:47:54.227Z,1582818474.227 [MassServo] Loaded
2020-02-27T15:47:54.227Z,1582818474.227 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2020-02-27T15:47:54.239Z,1582818474.239 [RudderServo] Loaded
2020-02-27T15:47:54.239Z,1582818474.239 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2020-02-27T15:47:54.251Z,1582818474.251 [ThrusterServo] Loaded
2020-02-27T15:47:54.251Z,1582818474.251 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2020-02-27T15:47:54.252Z,1582818474.252 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2020-02-27T15:47:54.252Z,1582818474.252 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2020-02-27T15:47:54.365Z,1582818474.365 [DeadReckonUsingMultipleVelocitySources] Loaded
2020-02-27T15:47:54.366Z,1582818474.366 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2020-02-27T15:47:54.388Z,1582818474.388 [NavChart] Loaded
2020-02-27T15:47:54.389Z,1582818474.389 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2020-02-27T15:47:54.393Z,1582818474.393 [UniversalFixResidualReporter] Loaded
2020-02-27T15:47:54.393Z,1582818474.393 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2020-02-27T15:47:54.393Z,1582818474.393 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2020-02-27T15:47:54.394Z,1582818474.394 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2020-02-27T15:47:54.481Z,1582818474.481 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2020-02-27T15:47:54.482Z,1582818474.482 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2020-02-27T15:47:54.781Z,1582818474.781 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_orientation
2020-02-27T15:47:54.786Z,1582818474.786 [AHRS_M2](INFO): created writer for : platform_orientation
2020-02-27T15:47:54.788Z,1582818474.788 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_magnetic_orientation
2020-02-27T15:47:54.794Z,1582818474.794 [AHRS_M2](INFO): created writer for : platform_magnetic_orientation
2020-02-27T15:47:54.795Z,1582818474.795 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_pitch_angle
2020-02-27T15:47:54.800Z,1582818474.800 [AHRS_M2](INFO): created writer for : platform_pitch_angle
2020-02-27T15:47:54.801Z,1582818474.801 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_roll_angle
2020-02-27T15:47:54.806Z,1582818474.806 [AHRS_M2](INFO): created writer for : platform_roll_angle
2020-02-27T15:47:54.885Z,1582818474.885 [AHRS_M2] Loaded
2020-02-27T15:47:54.885Z,1582818474.885 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2020-02-27T15:47:54.967Z,1582818474.967 [DataOverHttps] Loaded
2020-02-27T15:47:54.967Z,1582818474.967 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2020-02-27T15:47:54.968Z,1582818474.968 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 4088E4E0
2020-02-27T15:47:54.969Z,1582818474.969 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 4166
2020-02-27T15:47:54.983Z,1582818474.983 [Depth_Keller] Loaded
2020-02-27T15:47:54.983Z,1582818474.983 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2020-02-27T15:47:54.988Z,1582818474.988 [DropWeight] Loaded
2020-02-27T15:47:54.989Z,1582818474.989 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2020-02-27T15:47:55.094Z,1582818475.094 [NAL9602] Loaded
2020-02-27T15:47:55.094Z,1582818475.094 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2020-02-27T15:47:55.136Z,1582818475.136 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-0/voltage_now
2020-02-27T15:47:55.136Z,1582818475.136 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-0/current_now
2020-02-27T15:47:55.137Z,1582818475.137 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-0/charge_now
2020-02-27T15:47:55.137Z,1582818475.137 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-0/charge_full
2020-02-27T15:47:55.138Z,1582818475.138 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-1/voltage_now
2020-02-27T15:47:55.139Z,1582818475.139 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-1/current_now
2020-02-27T15:47:55.139Z,1582818475.139 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-1/charge_now
2020-02-27T15:47:55.140Z,1582818475.140 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-1/charge_full
2020-02-27T15:47:55.140Z,1582818475.140 [Onboard] Loaded
2020-02-27T15:47:55.140Z,1582818475.140 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2020-02-27T15:47:55.144Z,1582818475.144 [Radio_Surface] Loaded
2020-02-27T15:47:55.144Z,1582818475.144 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2020-02-27T15:47:55.145Z,1582818475.145 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 408BE4E0
2020-02-27T15:47:55.145Z,1582818475.145 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 4167
2020-02-27T15:47:56.753Z,1582818476.753 [BPC1] Loaded
2020-02-27T15:47:56.753Z,1582818476.753 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2020-02-27T15:47:56.754Z,1582818476.754 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2020-02-27T15:47:56.754Z,1582818476.754 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2020-02-27T15:47:56.797Z,1582818476.797 [DepthRateCalculator] Loaded
2020-02-27T15:47:56.797Z,1582818476.797 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2020-02-27T15:47:56.803Z,1582818476.803 [PitchRateCalculator] Loaded
2020-02-27T15:47:56.803Z,1582818476.803 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2020-02-27T15:47:56.816Z,1582818476.816 [SpeedCalculator] Loaded
2020-02-27T15:47:56.816Z,1582818476.816 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2020-02-27T15:47:56.840Z,1582818476.840 [TempGradientCalculator] Loaded
2020-02-27T15:47:56.840Z,1582818476.840 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2020-02-27T15:47:56.846Z,1582818476.846 [YawRateCalculator] Loaded
2020-02-27T15:47:56.846Z,1582818476.846 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2020-02-27T15:47:56.879Z,1582818476.879 [ElevatorOffsetCalculator] Loaded
2020-02-27T15:47:56.879Z,1582818476.879 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2020-02-27T15:47:56.879Z,1582818476.879 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2020-02-27T15:47:56.880Z,1582818476.880 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2020-02-27T15:47:57.076Z,1582818477.076 [CANONSampler] Loaded
2020-02-27T15:47:57.077Z,1582818477.077 [ComponentRegistry](DEBUG): SyncComponent "CANONSampler" handled in the control thread.
2020-02-27T15:47:57.086Z,1582818477.086 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_density
2020-02-27T15:47:57.092Z,1582818477.092 [CTD_Seabird](INFO): created writer for : sea_water_density
2020-02-27T15:47:57.092Z,1582818477.092 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): depth
2020-02-27T15:47:57.098Z,1582818477.098 [CTD_Seabird](INFO): created writer for : depth
2020-02-27T15:47:57.098Z,1582818477.098 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_pressure
2020-02-27T15:47:57.104Z,1582818477.104 [CTD_Seabird](INFO): created writer for : sea_water_pressure
2020-02-27T15:47:57.104Z,1582818477.104 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_salinity
2020-02-27T15:47:57.110Z,1582818477.110 [CTD_Seabird](INFO): created writer for : sea_water_salinity
2020-02-27T15:47:57.111Z,1582818477.111 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_temperature
2020-02-27T15:47:57.116Z,1582818477.116 [CTD_Seabird](INFO): created writer for : sea_water_temperature
2020-02-27T15:47:57.117Z,1582818477.117 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_electrical_conductivity
2020-02-27T15:47:57.123Z,1582818477.123 [CTD_Seabird](INFO): created writer for : sea_water_electrical_conductivity
2020-02-27T15:47:57.124Z,1582818477.124 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): speed_of_sound_in_sea_water
2020-02-27T15:47:57.129Z,1582818477.129 [CTD_Seabird](INFO): created writer for : speed_of_sound_in_sea_water
2020-02-27T15:47:57.130Z,1582818477.130 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): mass_concentration_of_oxygen_in_sea_water
2020-02-27T15:47:57.135Z,1582818477.135 [CTD_Seabird](INFO): created writer for : mass_concentration_of_oxygen_in_sea_water
2020-02-27T15:47:57.136Z,1582818477.136 [CTD_Seabird](DEBUG): LcmSlateWriter::add(DAtaURI): CTD_Seabird.sea_water_dissolved_oxygen_freq
2020-02-27T15:47:57.136Z,1582818477.136 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): dataName: sea_water_dissolved_oxygen_freq
2020-02-27T15:47:57.172Z,1582818477.172 [CTD_Seabird] Loaded
2020-02-27T15:47:57.172Z,1582818477.172 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2020-02-27T15:47:57.173Z,1582818477.173 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 409C04E0
2020-02-27T15:47:57.173Z,1582818477.173 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 4168
2020-02-27T15:47:57.190Z,1582818477.190 [PAR_Licor] Loaded
2020-02-27T15:47:57.190Z,1582818477.190 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2020-02-27T15:47:57.196Z,1582818477.196 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.Output470
2020-02-27T15:47:57.197Z,1582818477.197 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: Output470
2020-02-27T15:47:57.201Z,1582818477.201 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.Output650
2020-02-27T15:47:57.201Z,1582818477.201 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: Output650
2020-02-27T15:47:57.206Z,1582818477.206 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.OutputChl
2020-02-27T15:47:57.206Z,1582818477.206 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: OutputChl
2020-02-27T15:47:57.211Z,1582818477.211 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.VolumeScatCoeff117deg470nm
2020-02-27T15:47:57.211Z,1582818477.211 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: VolumeScatCoeff117deg470nm
2020-02-27T15:47:57.216Z,1582818477.216 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.VolumeScatCoeff117deg650nm
2020-02-27T15:47:57.216Z,1582818477.216 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: VolumeScatCoeff117deg650nm
2020-02-27T15:47:57.221Z,1582818477.221 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.BackscatteringCoeff470nm
2020-02-27T15:47:57.221Z,1582818477.221 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: BackscatteringCoeff470nm
2020-02-27T15:47:57.226Z,1582818477.226 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.BackscatteringCoeff650nm
2020-02-27T15:47:57.226Z,1582818477.226 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: BackscatteringCoeff650nm
2020-02-27T15:47:57.230Z,1582818477.230 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): mass_concentration_of_chlorophyll_in_sea_water
2020-02-27T15:47:57.235Z,1582818477.235 [WetLabsBB2FL](INFO): created writer for : mass_concentration_of_chlorophyll_in_sea_water
2020-02-27T15:47:57.236Z,1582818477.236 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_median_mass_concentration_of_chlorophyll_in_sea_water
2020-02-27T15:47:57.236Z,1582818477.236 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_median_mass_concentration_of_chlorophyll_in_sea_water
2020-02-27T15:47:57.241Z,1582818477.241 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_mean_mass_concentration_of_chlorophyll_in_sea_water
2020-02-27T15:47:57.241Z,1582818477.241 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_mean_mass_concentration_of_chlorophyll_in_sea_water
2020-02-27T15:47:57.246Z,1582818477.246 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_variance_mass_concentration_of_chlorophyll_in_sea_water
2020-02-27T15:47:57.246Z,1582818477.246 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_variance_mass_concentration_of_chlorophyll_in_sea_water
2020-02-27T15:47:57.251Z,1582818477.251 [WetLabsBB2FL] Loaded
2020-02-27T15:47:57.251Z,1582818477.251 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2020-02-27T15:47:57.252Z,1582818477.252 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 409F04E0
2020-02-27T15:47:57.253Z,1582818477.253 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 4169
2020-02-27T15:47:57.253Z,1582818477.253 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2020-02-27T15:47:57.254Z,1582818477.254 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2020-02-27T15:47:57.287Z,1582818477.287 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2020-02-27T15:47:57.288Z,1582818477.288 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2020-02-27T15:47:57.617Z,1582818477.617 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2020-02-27T15:47:57.618Z,1582818477.618 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2020-02-27T15:47:57.761Z,1582818477.761 [SBIT](DEBUG): Construct Startup Built In Test.
2020-02-27T15:47:57.772Z,1582818477.772 [SBIT] Loaded
2020-02-27T15:47:57.773Z,1582818477.773 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2020-02-27T15:47:57.774Z,1582818477.774 [IBIT](DEBUG): Construct Initiated Built In Test.
2020-02-27T15:47:57.787Z,1582818477.787 [IBIT] Loaded
2020-02-27T15:47:57.787Z,1582818477.787 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2020-02-27T15:47:57.790Z,1582818477.790 [CBIT](DEBUG): Construct Continuous Built In Test.
2020-02-27T15:47:57.939Z,1582818477.939 [CBIT] Loaded
2020-02-27T15:47:57.939Z,1582818477.939 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2020-02-27T15:47:57.940Z,1582818477.940 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2020-02-27T15:47:57.951Z,1582818477.951 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2020-02-27T15:47:57.952Z,1582818477.952 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2020-02-27T15:47:58.010Z,1582818478.010 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2020-02-27T15:47:58.033Z,1582818478.033 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40AFA4E0
2020-02-27T15:47:58.033Z,1582818478.033 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 4170
2020-02-27T15:47:58.077Z,1582818478.077 [Supervisor](INFO): Main Thread ID is 4080
2020-02-27T15:47:58.077Z,1582818478.077 [Supervisor](DEBUG): Running supervisor.
2020-02-27T15:47:58.078Z,1582818478.078 [CommandLine ThreadHandler](INFO): Handler Thread ID is 4171
2020-02-27T15:47:58.081Z,1582818478.081 [controlThread ThreadHandler](INFO): Handler Thread ID is 4172
2020-02-27T15:47:58.081Z,1582818478.081 [controlThread](DEBUG): Initializing ControlThread
2020-02-27T15:47:58.082Z,1582818478.082 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2020-02-27T15:47:58.083Z,1582818478.083 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2020-02-27T15:47:58.084Z,1582818478.084 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2020-02-27T15:47:58.085Z,1582818478.085 [LoopControl](DEBUG): Initialize LoopControlComponent.
2020-02-27T15:47:58.086Z,1582818478.086 [NavChart](DEBUG): Initialize NavChart Navigation.
2020-02-27T15:47:58.086Z,1582818478.086 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2020-02-27T15:47:58.091Z,1582818478.091 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2020-02-27T15:47:58.091Z,1582818478.091 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2020-02-27T15:47:58.092Z,1582818478.092 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2020-02-27T15:47:58.092Z,1582818478.092 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2020-02-27T15:47:58.093Z,1582818478.093 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2020-02-27T15:47:58.093Z,1582818478.093 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2020-02-27T15:47:58.097Z,1582818478.097 [SBIT](INFO): Initialize SBIT Component.
2020-02-27T15:47:58.098Z,1582818478.098 [SBIT](IMPORTANT): git: 2020-02-26
2020-02-27T15:47:58.098Z,1582818478.098 [SBIT](INFO): git hash: de1c7d7324ed84a0a2d3b39115edd3b5f312562f
2020-02-27T15:47:58.098Z,1582818478.098 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2020-02-27T15:47:58.099Z,1582818478.099 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018
Kernel Reported: #1 PREEMPT Tue Dec 18 21:19:28 PST 2018
2020-02-27T15:47:58.100Z,1582818478.100 [SBIT](INFO): Beginning SBIT in 39.000000 seconds.
2020-02-27T15:47:58.101Z,1582818478.101 [IBIT](INFO): Initialize IBIT Component.
2020-02-27T15:47:58.102Z,1582818478.102 [CBIT](DEBUG): Initialize CBIT Component.
2020-02-27T15:47:58.103Z,1582818478.103 [logger ThreadHandler](INFO): Handler Thread ID is 4173
2020-02-27T15:47:58.113Z,1582818478.113 [CBIT](DEBUG): Initialized mux pins.
2020-02-27T15:47:58.113Z,1582818478.113 [CBIT](DEBUG): Initializing the watchdog timer.
2020-02-27T15:47:58.121Z,1582818478.121 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 4174
2020-02-27T15:47:58.122Z,1582818478.122 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2020-02-27T15:47:58.133Z,1582818478.133 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 4175
2020-02-27T15:47:58.137Z,1582818478.137 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2020-02-27T15:47:58.137Z,1582818478.137 [CBIT](DEBUG): Initializing heartbeat.
2020-02-27T15:47:58.145Z,1582818478.145 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 4176
2020-02-27T15:47:58.146Z,1582818478.146 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2020-02-27T15:47:58.149Z,1582818478.149 [CTD_Seabird](INFO): Opening uart, block timeout 10ths=20
2020-02-27T15:47:58.150Z,1582818478.150 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 4178
2020-02-27T15:47:58.151Z,1582818478.151 [WetLabsBB2FL](INFO): Powering down
2020-02-27T15:47:58.181Z,1582818478.181 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 4179
2020-02-27T15:47:58.184Z,1582818478.184 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2020-02-27T15:47:58.185Z,1582818478.185 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2020-02-27T15:47:58.185Z,1582818478.185 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2020-02-27T15:47:58.185Z,1582818478.185 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2020-02-27T15:47:58.185Z,1582818478.185 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2020-02-27T15:47:58.186Z,1582818478.186 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2020-02-27T15:47:58.186Z,1582818478.186 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2020-02-27T15:47:58.186Z,1582818478.186 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2020-02-27T15:47:58.186Z,1582818478.186 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2020-02-27T15:47:58.186Z,1582818478.186 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2020-02-27T15:47:58.187Z,1582818478.187 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2020-02-27T15:47:58.187Z,1582818478.187 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2020-02-27T15:47:58.187Z,1582818478.187 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2020-02-27T15:47:58.187Z,1582818478.187 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2020-02-27T15:47:58.187Z,1582818478.187 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2020-02-27T15:47:58.188Z,1582818478.188 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2020-02-27T15:47:58.209Z,1582818478.209 [CBIT](DEBUG): Deactivating GF circuits.
2020-02-27T15:47:58.209Z,1582818478.209 [CBIT](DEBUG): Deactivating emergency mode.
2020-02-27T15:47:58.245Z,1582818478.245 [CBIT](DEBUG): Backplane powered.
2020-02-27T15:47:58.246Z,1582818478.246 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2020-02-27T15:47:58.256Z,1582818478.256 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2020-02-27T15:47:58.266Z,1582818478.266 [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-02-27T15:47:58.267Z,1582818478.267 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2020-02-27T15:47:58.333Z,1582818478.333 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2020-02-27T15:47:58.334Z,1582818478.334 [Default:A.Wait](DEBUG): Construct Wait.
2020-02-27T15:47:58.336Z,1582818478.336 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2020-02-27T15:47:58.379Z,1582818478.379 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2020-02-27T15:47:58.382Z,1582818478.382 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2020-02-27T15:47:58.408Z,1582818478.408 [Default:E.Execute](DEBUG): Construct Execute.
2020-02-27T15:47:58.411Z,1582818478.411 [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-02-27T15:47:58.429Z,1582818478.429 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,Depth_Keller,DropWeight,NAL9602,Onboard,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-02-27T15:47:58.434Z,1582818478.434 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2020-02-27T15:47:58.470Z,1582818478.470 [Depth_Keller](ERROR): Pressure reading out of range: 1831.023193 decibar
2020-02-27T15:47:58.513Z,1582818478.513 [CANONSampler](INFO): Powering down
2020-02-27T15:47:58.537Z,1582818478.537 [Radio_Surface](INFO): Powering up
2020-02-27T15:47:58.733Z,1582818478.733 [DepthRateCalculator](ERROR): Depth measurement is not active
2020-02-27T15:47:58.759Z,1582818478.759 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2020-02-27T15:47:58.765Z,1582818478.765 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2020-02-27T15:47:58.766Z,1582818478.766 [ElevatorServo](DEBUG): Initializing EZServoServo.
2020-02-27T15:47:58.773Z,1582818478.773 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2020-02-27T15:47:58.774Z,1582818478.774 [MassServo](DEBUG): Initializing EZServoServo.
2020-02-27T15:47:58.781Z,1582818478.781 [MassServo](DEBUG): Initializing MassServo.
2020-02-27T15:47:58.782Z,1582818478.782 [RudderServo](DEBUG): Initializing EZServoServo.
2020-02-27T15:47:58.789Z,1582818478.789 [RudderServo](DEBUG): Initializing RudderServo.
2020-02-27T15:47:58.790Z,1582818478.790 [ThrusterServo](DEBUG): Initializing EZServoServo.
2020-02-27T15:47:58.797Z,1582818478.797 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2020-02-27T15:47:59.621Z,1582818479.621 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2020-02-27T15:47:59.621Z,1582818479.621 [RudderServo](FAULT): Rudder failed to initialize
2020-02-27T15:47:59.621Z,1582818479.621 [RudderServo] Communications Fault, FailCount= 1
2020-02-27T15:47:59.621Z,1582818479.621 [RudderServo](ERROR): Communications Fault
2020-02-27T15:47:59.756Z,1582818479.756 [CBIT](ERROR): Communications Fault in component: RudderServo
2020-02-27T15:47:59.962Z,1582818479.962 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2020-02-27T15:47:59.962Z,1582818479.962 [RudderServo](INFO): Powering down
2020-02-27T15:48:00.627Z,1582818480.627 [RudderServo](DEBUG): Initializing EZServoServo.
2020-02-27T15:48:00.746Z,1582818480.746 [RudderServo](DEBUG): Initializing RudderServo.
2020-02-27T15:48:00.750Z,1582818480.750 [CBIT](INFO): Clearing failed state for component RudderServo
2020-02-27T15:48:00.750Z,1582818480.750 [RudderServo] No Fault, FailCount= 1
2020-02-27T15:48:05.201Z,1582818485.201 [CTD_Seabird](ERROR): Device message queue exceeded the allowed limit.
2020-02-27T15:48:13.031Z,1582818493.031 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.005264
2020-02-27T15:48:25.270Z,1582818505.270 [NAL9602](INFO): Powering up NAL9602
2020-02-27T15:48:36.178Z,1582818516.178 [NAL9602](INFO): NAL9602 initialized
2020-02-27T15:48:37.858Z,1582818517.858 [SBIT](IMPORTANT): Beginning Startup BIT
2020-02-27T15:48:37.861Z,1582818517.861 [CBIT](IMPORTANT): Beginning ground fault scan
2020-02-27T15:48:48.913Z,1582818528.913 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.003483
CHAN A1 (24V): -0.000556
CHAN A2 (12V): -0.002450
CHAN A3 (5V): -0.001110
CHAN B0 (3.3V): 0.000363
CHAN B1 (3.15aV): -0.000028
CHAN B2 (3.15bV): -0.000381
CHAN B3 (GND): 0.000406
OPEN: -0.000536
Full Scale Calc: 4.765 mA, -1.589 mA
2020-02-27T15:49:31.512Z,1582818571.512 [SBIT](IMPORTANT): SBIT PASSED
2020-02-27T15:49:31.512Z,1582818571.512 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2020-02-27T15:49:31.513Z,1582818571.513 [SBIT](IMPORTANT): CBIT.gf24Offset=-26 microampere;

2020-02-27T15:49:31.514Z,1582818571.514 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=162 cubic_centimeter;

2020-02-27T15:49:31.514Z,1582818571.514 [SBIT](IMPORTANT): VerticalControl.massDefault=-5 millimeter;

2020-02-27T15:49:31.942Z,1582818571.942 [MissionManager](IMPORTANT): Started mission Startup
2020-02-27T15:49:31.942Z,1582818571.942 [Startup] Running Loop=1
2020-02-27T15:49:31.942Z,1582818571.942 [Startup](DEBUG): Aggregate::initialize Startup
2020-02-27T15:49:31.942Z,1582818571.942 [Startup:A.GoToSurface] Running Loop=1
2020-02-27T15:49:31.942Z,1582818571.942 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2020-02-27T15:49:31.943Z,1582818571.943 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2020-02-27T15:49:31.944Z,1582818571.944 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2020-02-27T15:49:31.944Z,1582818571.944 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2020-02-27T15:49:31.944Z,1582818571.944 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2020-02-27T15:49:31.949Z,1582818571.949 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2020-02-27T15:49:31.950Z,1582818571.950 [Startup:StartupSatComms] Running Loop=1
2020-02-27T15:49:31.950Z,1582818571.950 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2020-02-27T15:49:31.950Z,1582818571.950 [Startup:StartupSatComms:A] Running Loop=1
2020-02-27T15:49:32.338Z,1582818572.338 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2020-02-27T15:49:41.642Z,1582818581.642 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2020-02-27T15:50:29.715Z,1582818629.715 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2020-02-27T15:50:32.072Z,1582818632.072 [Startup:StartupSatComms:A](INFO): Timed out from 2020-02-27T15:49:31.0Z
2020-02-27T15:50:32.073Z,1582818632.073 [Startup:StartupSatComms:A] Stopped
2020-02-27T15:50:32.073Z,1582818632.073 [Startup:StartupSatComms:B] Running Loop=1
2020-02-27T15:50:32.483Z,1582818632.483 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2020-02-27T15:50:36.961Z,1582818636.961 [DataOverHttps](INFO): Sending 152 bytes from file Logs/20200227T150755/Express0005.lzma
2020-02-27T15:50:38.966Z,1582818638.966 [DataOverHttps](INFO): Moved sent file to Logs/20200227T150755/Express0005.lzma.bak
2020-02-27T15:50:38.967Z,1582818638.967 [DataOverHttps](INFO): SBD MOMSN=12272204
2020-02-27T15:50:55.169Z,1582818655.169 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2020-02-27T15:50:55.533Z,1582818655.533 [DataOverHttps](INFO): Sending 669 bytes from file Logs/20200227T154747/Express0001.lzma
2020-02-27T15:50:57.539Z,1582818657.539 [DataOverHttps](INFO): Moved sent file to Logs/20200227T154747/Express0001.lzma.bak
2020-02-27T15:50:57.539Z,1582818657.539 [DataOverHttps](INFO): SBD MOMSN=12272228
2020-02-27T15:50:58.338Z,1582818658.338 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2020-02-27T15:50:58.338Z,1582818658.338 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-02-27T15:50:58.348Z,1582818658.348 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-02-27T15:50:58.738Z,1582818658.738 [Startup:StartupSatComms:B] Stopped
2020-02-27T15:50:58.738Z,1582818658.738 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2020-02-27T15:50:58.738Z,1582818658.738 [Startup:StartupSatComms] Stopped
2020-02-27T15:50:58.738Z,1582818658.738 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2020-02-27T15:50:58.739Z,1582818658.739 [Startup](INFO): Completed Startup
2020-02-27T15:50:58.739Z,1582818658.739 [MissionManager](INFO): Startup is completed.
2020-02-27T15:50:58.739Z,1582818658.739 [MissionManager](INFO): Uninitializing Mission Startup
2020-02-27T15:50:58.739Z,1582818658.739 [Startup] Stopped
2020-02-27T15:50:58.740Z,1582818658.740 [Startup](DEBUG): Aggregate::uninitialize Startup
2020-02-27T15:50:58.740Z,1582818658.740 [Startup:A.GoToSurface] Stopped
2020-02-27T15:50:58.740Z,1582818658.740 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2020-02-27T15:50:58.781Z,1582818658.781 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-02-27T15:50:58.781Z,1582818658.781 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2020-02-27T15:50:59.146Z,1582818659.146 [MissionManager](IMPORTANT): Started mission Default
2020-02-27T15:50:59.147Z,1582818659.147 [Default] Running Loop=1
2020-02-27T15:50:59.147Z,1582818659.147 [Default](DEBUG): Aggregate::initialize Default
2020-02-27T15:50:59.147Z,1582818659.147 [Default:B.GoToSurface] Running Loop=1
2020-02-27T15:50:59.147Z,1582818659.147 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2020-02-27T15:50:59.147Z,1582818659.147 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2020-02-27T15:50:59.147Z,1582818659.147 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2020-02-27T15:50:59.148Z,1582818659.148 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2020-02-27T15:50:59.148Z,1582818659.148 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2020-02-27T15:50:59.148Z,1582818659.148 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2020-02-27T15:50:59.149Z,1582818659.149 [Default:A.Wait] Running Loop=1
2020-02-27T15:50:59.149Z,1582818659.149 [Default:A.Wait](DEBUG): Initialize Wait Component.
2020-02-27T15:51:12.481Z,1582818672.481 [Default:A.Wait](INFO): Done Waiting.
2020-02-27T15:51:12.481Z,1582818672.481 [Default:A.Wait] Stopped
2020-02-27T15:51:12.481Z,1582818672.481 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2020-02-27T15:51:12.883Z,1582818672.883 [Default:CheckIn] Running Loop=1
2020-02-27T15:51:12.883Z,1582818672.883 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-02-27T15:51:12.883Z,1582818672.883 [Default:CheckIn:Read_GPS] Running Loop=1
2020-02-27T15:51:13.284Z,1582818673.284 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2020-02-27T15:51:44.434Z,1582818704.434 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2020-02-27T15:52:24.851Z,1582818744.851 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2020-02-27T15:52:54.328Z,1582818774.328 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2020-02-27T15:53:07.280Z,1582818787.280 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2020-02-27T15:53:39.508Z,1582818819.508 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2020-02-27T15:53:59.334Z,1582818839.334 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2020-02-27T15:53:59.334Z,1582818839.334 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-02-27T15:53:59.343Z,1582818839.343 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-02-27T15:53:59.763Z,1582818839.763 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-02-27T15:53:59.763Z,1582818839.763 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2020-02-27T15:54:03.911Z,1582818843.911 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2020-02-27T15:55:29.479Z,1582818929.479 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2020-02-27T15:55:44.779Z,1582818944.779 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2020-02-27T15:55:44.782Z,1582818944.782 [BPC1](INFO): Received data from all battery sticks.
2020-02-27T15:56:13.051Z,1582818973.051 [Default:CheckIn:Read_GPS](INFO): Timed out from 2020-02-27T15:51:12.9Z
2020-02-27T15:56:13.051Z,1582818973.051 [Default:CheckIn:Read_GPS] Stopped
2020-02-27T15:56:13.051Z,1582818973.051 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-02-27T15:56:13.455Z,1582818973.455 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2020-02-27T15:56:20.153Z,1582818980.153 [DataOverHttps](INFO): Sending 186 bytes from file Logs/20200227T154747/Courier0004.lzma
2020-02-27T15:56:22.158Z,1582818982.158 [DataOverHttps](INFO): Moved sent file to Logs/20200227T154747/Courier0004.lzma.bak
2020-02-27T15:56:22.158Z,1582818982.158 [DataOverHttps](INFO): SBD MOMSN=12272248
2020-02-27T15:56:38.645Z,1582818998.645 [DataOverHttps](INFO): Sending 176 bytes from file Logs/20200227T154747/Express0005.lzma
2020-02-27T15:56:40.650Z,1582819000.650 [DataOverHttps](INFO): Moved sent file to Logs/20200227T154747/Express0005.lzma.bak
2020-02-27T15:56:40.650Z,1582819000.650 [DataOverHttps](INFO): SBD MOMSN=12272250
2020-02-27T15:56:41.723Z,1582819001.723 [Default:CheckIn:Read_Iridium] Stopped
2020-02-27T15:56:41.723Z,1582819001.723 [Default:CheckIn:C.Wait] Running Loop=1
2020-02-27T15:56:41.723Z,1582819001.723 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-02-27T15:57:00.334Z,1582819020.334 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3
2020-02-27T15:57:00.334Z,1582819020.334 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-02-27T15:57:00.366Z,1582819020.366 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-02-27T15:57:00.735Z,1582819020.735 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-02-27T15:57:00.735Z,1582819020.735 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3
2020-02-27T15:58:38.498Z,1582819118.498 [NAL9602](FAULT): GPS failed to acquire within timeout.
2020-02-27T15:58:38.498Z,1582819118.498 [NAL9602] Data Fault, FailCount= 1
2020-02-27T15:58:38.498Z,1582819118.498 [NAL9602](ERROR): Data Fault
2020-02-27T15:58:38.570Z,1582819118.570 [CBIT](ERROR): Data Fault in component: NAL9602
2020-02-27T15:58:38.898Z,1582819118.898 [NAL9602](INFO): Powering down
2020-02-27T15:58:39.768Z,1582819119.768 [CBIT](INFO): Clearing failed state for component NAL9602
2020-02-27T15:58:39.768Z,1582819119.768 [NAL9602] No Fault, FailCount= 1
2020-02-27T15:59:09.204Z,1582819149.204 [NAL9602](INFO): Powering up NAL9602
2020-02-27T15:59:20.110Z,1582819160.110 [NAL9602](INFO): NAL9602 initialized
2020-02-27T16:00:01.348Z,1582819201.348 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4
2020-02-27T16:00:01.348Z,1582819201.348 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-02-27T16:00:01.358Z,1582819201.358 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-02-27T16:00:01.778Z,1582819201.778 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-02-27T16:00:01.778Z,1582819201.778 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4
2020-02-27T16:01:42.363Z,1582819302.363 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-02-27T16:01:42.363Z,1582819302.363 [Default:CheckIn:C.Wait] Stopped
2020-02-27T16:01:42.363Z,1582819302.363 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-02-27T16:01:42.363Z,1582819302.363 [Default:CheckIn:D] Running Loop=1
2020-02-27T16:01:42.763Z,1582819302.763 [Default:CheckIn:D] Stopped
2020-02-27T16:01:42.763Z,1582819302.763 [Default:CheckIn:E] Running Loop=1
2020-02-27T16:01:43.147Z,1582819303.147 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 10.726937 min 
2020-02-27T16:01:43.147Z,1582819303.147 [Default:CheckIn:E] Stopped
2020-02-27T16:01:43.147Z,1582819303.147 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-02-27T16:01:43.147Z,1582819303.147 [Default:CheckIn] Stopped
2020-02-27T16:01:43.148Z,1582819303.148 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-02-27T16:01:43.148Z,1582819303.148 [Default:CheckIn](INFO): Running loop #2
2020-02-27T16:01:43.148Z,1582819303.148 [Default:CheckIn] Running Loop=2
2020-02-27T16:01:43.148Z,1582819303.148 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-02-27T16:01:43.148Z,1582819303.148 [Default:CheckIn:Read_GPS] Running Loop=1
2020-02-27T16:03:02.344Z,1582819382.344 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5
2020-02-27T16:03:02.344Z,1582819382.344 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-02-27T16:03:02.354Z,1582819382.354 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-02-27T16:03:02.769Z,1582819382.769 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-02-27T16:03:02.769Z,1582819382.769 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5
2020-02-27T16:06:03.326Z,1582819563.326 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 6
2020-02-27T16:06:03.326Z,1582819563.326 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-02-27T16:06:03.336Z,1582819563.336 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-02-27T16:06:03.740Z,1582819563.740 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-02-27T16:06:03.740Z,1582819563.740 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 6
2020-02-27T16:06:43.316Z,1582819603.316 [Default:CheckIn:Read_GPS](INFO): Timed out from 2020-02-27T16:01:43.1Z
2020-02-27T16:06:43.316Z,1582819603.316 [Default:CheckIn:Read_GPS] Stopped
2020-02-27T16:06:43.316Z,1582819603.316 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-02-27T16:06:50.960Z,1582819610.960 [DataOverHttps](INFO): Sending 171 bytes from file Logs/20200227T154747/Express0008.lzma
2020-02-27T16:06:52.967Z,1582819612.967 [DataOverHttps](INFO): Moved sent file to Logs/20200227T154747/Express0008.lzma.bak
2020-02-27T16:06:52.967Z,1582819612.967 [DataOverHttps](INFO): SBD MOMSN=12272263
2020-02-27T16:06:54.243Z,1582819614.243 [Default:CheckIn:Read_Iridium] Stopped
2020-02-27T16:06:54.243Z,1582819614.243 [Default:CheckIn:C.Wait] Running Loop=1
2020-02-27T16:06:54.243Z,1582819614.243 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-02-27T16:09:04.323Z,1582819744.323 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 7
2020-02-27T16:09:04.323Z,1582819744.323 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-02-27T16:09:04.333Z,1582819744.333 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-02-27T16:09:04.741Z,1582819744.741 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-02-27T16:09:04.741Z,1582819744.741 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 7
2020-02-27T16:09:21.262Z,1582819761.262 [NAL9602](FAULT): GPS failed to acquire within timeout.
2020-02-27T16:09:21.262Z,1582819761.262 [NAL9602] Data Fault, FailCount= 2
2020-02-27T16:09:21.262Z,1582819761.262 [NAL9602](ERROR): Data Fault
2020-02-27T16:09:21.366Z,1582819761.366 [CBIT](ERROR): Data Fault in component: NAL9602
2020-02-27T16:09:21.662Z,1582819761.662 [NAL9602](INFO): Powering down
2020-02-27T16:09:22.511Z,1582819762.511 [CBIT](INFO): Clearing failed state for component NAL9602
2020-02-27T16:09:22.512Z,1582819762.512 [NAL9602] No Fault, FailCount= 2
2020-02-27T16:09:51.962Z,1582819791.962 [NAL9602](INFO): Powering up NAL9602
2020-02-27T16:10:02.885Z,1582819802.885 [NAL9602](INFO): NAL9602 initialized
2020-02-27T16:11:54.827Z,1582819914.827 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-02-27T16:11:54.827Z,1582819914.827 [Default:CheckIn:C.Wait] Stopped
2020-02-27T16:11:54.827Z,1582819914.827 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-02-27T16:11:54.827Z,1582819914.827 [Default:CheckIn:D] Running Loop=1
2020-02-27T16:11:55.235Z,1582819915.235 [Default:CheckIn:D] Stopped
2020-02-27T16:11:55.235Z,1582819915.235 [Default:CheckIn:E] Running Loop=1
2020-02-27T16:11:55.634Z,1582819915.634 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 20.934802 min 
2020-02-27T16:11:55.634Z,1582819915.634 [Default:CheckIn:E] Stopped
2020-02-27T16:11:55.634Z,1582819915.634 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-02-27T16:11:55.634Z,1582819915.634 [Default:CheckIn] Stopped
2020-02-27T16:11:55.634Z,1582819915.634 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-02-27T16:11:55.635Z,1582819915.635 [Default:CheckIn](INFO): Running loop #3
2020-02-27T16:11:55.635Z,1582819915.635 [Default:CheckIn] Running Loop=3
2020-02-27T16:11:55.635Z,1582819915.635 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-02-27T16:11:55.635Z,1582819915.635 [Default:CheckIn:Read_GPS] Running Loop=1
2020-02-27T16:12:05.331Z,1582819925.331 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 8
2020-02-27T16:12:05.331Z,1582819925.331 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-02-27T16:12:05.344Z,1582819925.344 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-02-27T16:12:05.756Z,1582819925.756 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-02-27T16:12:05.756Z,1582819925.756 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 8
2020-02-27T16:15:06.377Z,1582820106.377 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 9
2020-02-27T16:15:06.377Z,1582820106.377 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-02-27T16:15:06.404Z,1582820106.404 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-02-27T16:15:06.787Z,1582820106.787 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-02-27T16:15:06.787Z,1582820106.787 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 9
2020-02-27T16:16:55.834Z,1582820215.834 [Default:CheckIn:Read_GPS](INFO): Timed out from 2020-02-27T16:11:55.6Z
2020-02-27T16:16:55.834Z,1582820215.834 [Default:CheckIn:Read_GPS] Stopped
2020-02-27T16:16:55.834Z,1582820215.834 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-02-27T16:17:02.836Z,1582820222.836 [DataOverHttps](INFO): Sending 140 bytes from file Logs/20200227T154747/Express0011.lzma
2020-02-27T16:17:04.842Z,1582820224.842 [DataOverHttps](INFO): Moved sent file to Logs/20200227T154747/Express0011.lzma.bak
2020-02-27T16:17:04.843Z,1582820224.843 [DataOverHttps](INFO): SBD MOMSN=12272277
2020-02-27T16:17:05.934Z,1582820225.934 [Default:CheckIn:Read_Iridium] Stopped
2020-02-27T16:17:05.935Z,1582820225.935 [Default:CheckIn:C.Wait] Running Loop=1
2020-02-27T16:17:05.935Z,1582820225.935 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-02-27T16:18:07.342Z,1582820287.342 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 10
2020-02-27T16:18:07.342Z,1582820287.342 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-02-27T16:18:07.352Z,1582820287.352 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-02-27T16:18:07.740Z,1582820287.740 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-02-27T16:18:07.740Z,1582820287.740 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 10
2020-02-27T16:20:04.470Z,1582820404.470 [NAL9602](FAULT): GPS failed to acquire within timeout.
2020-02-27T16:20:04.470Z,1582820404.470 [NAL9602] Data Fault, FailCount= 3
2020-02-27T16:20:04.470Z,1582820404.470 [NAL9602](ERROR): Data Fault
2020-02-27T16:20:04.531Z,1582820404.531 [CBIT](ERROR): Data Fault in component: NAL9602
2020-02-27T16:20:04.870Z,1582820404.870 [NAL9602](INFO): Powering down
2020-02-27T16:20:05.720Z,1582820405.720 [CBIT](INFO): Clearing failed state for component NAL9602
2020-02-27T16:20:05.720Z,1582820405.720 [NAL9602] No Fault, FailCount= 3
2020-02-27T16:20:35.180Z,1582820435.180 [NAL9602](INFO): Powering up NAL9602
2020-02-27T16:20:46.082Z,1582820446.082 [NAL9602](INFO): NAL9602 initialized
2020-02-27T16:21:08.334Z,1582820468.334 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 11
2020-02-27T16:21:08.334Z,1582820468.334 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-02-27T16:21:08.344Z,1582820468.344 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-02-27T16:21:08.750Z,1582820468.750 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-02-27T16:21:08.750Z,1582820468.750 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 11
2020-02-27T16:22:06.503Z,1582820526.503 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-02-27T16:22:06.504Z,1582820526.504 [Default:CheckIn:C.Wait] Stopped
2020-02-27T16:22:06.504Z,1582820526.504 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-02-27T16:22:06.504Z,1582820526.504 [Default:CheckIn:D] Running Loop=1
2020-02-27T16:22:06.919Z,1582820526.919 [Default:CheckIn:D] Stopped
2020-02-27T16:22:06.919Z,1582820526.919 [Default:CheckIn:E] Running Loop=1
2020-02-27T16:22:07.320Z,1582820527.320 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 31.129537 min 
2020-02-27T16:22:07.320Z,1582820527.320 [Default:CheckIn:E] Stopped
2020-02-27T16:22:07.321Z,1582820527.321 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-02-27T16:22:07.321Z,1582820527.321 [Default:CheckIn] Stopped
2020-02-27T16:22:07.321Z,1582820527.321 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-02-27T16:22:07.321Z,1582820527.321 [Default:CheckIn](INFO): Running loop #4
2020-02-27T16:22:07.321Z,1582820527.321 [Default:CheckIn] Running Loop=4
2020-02-27T16:22:07.321Z,1582820527.321 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-02-27T16:22:07.321Z,1582820527.321 [Default:CheckIn:Read_GPS] Running Loop=1
2020-02-27T16:22:26.280Z,1582820546.280 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162218.00,A,3648.15085,N,12147.23992,W,2.585,80.09,270220,,,A*4E
2020-02-27T16:22:26.283Z,1582820546.283 [NAL9602](INFO): GPS fix at 20200227T162218: (36.802514, -121.787332)
2020-02-27T16:22:26.333Z,1582820546.333 [Default:CheckIn:Read_GPS] Stopped
2020-02-27T16:22:26.333Z,1582820546.333 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-02-27T16:22:39.616Z,1582820559.616 [DataOverHttps](INFO): Sending 212 bytes from file Logs/20200227T154747/Courier0013.lzma
2020-02-27T16:22:41.622Z,1582820561.622 [DataOverHttps](INFO): Moved sent file to Logs/20200227T154747/Courier0013.lzma.bak
2020-02-27T16:22:41.622Z,1582820561.622 [DataOverHttps](INFO): SBD MOMSN=12272291
2020-02-27T16:22:58.642Z,1582820578.642 [NAL9602](INFO): Not Powering down - fast GPS
2020-02-27T16:22:59.501Z,1582820579.501 [DataOverHttps](INFO): Sending 281 bytes from file Logs/20200227T154747/Express0014.lzma
2020-02-27T16:23:01.506Z,1582820581.506 [DataOverHttps](INFO): Moved sent file to Logs/20200227T154747/Express0014.lzma.bak
2020-02-27T16:23:01.507Z,1582820581.507 [DataOverHttps](INFO): SBD MOMSN=12272294
2020-02-27T16:23:02.705Z,1582820582.705 [Default:CheckIn:Read_Iridium] Stopped
2020-02-27T16:23:02.705Z,1582820582.705 [Default:CheckIn:C.Wait] Running Loop=1
2020-02-27T16:23:02.705Z,1582820582.705 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-02-27T16:27:46.326Z,1582820866.326 [DataOverHttps](IMPORTANT): SBD MTMSN=20200227T162737
2020-02-27T16:27:53.677Z,1582820873.677 [DataOverHttps](INFO): Received command:ibit
2020-02-27T16:27:53.722Z,1582820873.722 [CommandLine](IMPORTANT): got command ibit
2020-02-27T16:27:53.999Z,1582820873.999 [IBIT](IMPORTANT): Beginning Initiated BIT
2020-02-27T16:27:53.999Z,1582820873.999 [IBIT](IMPORTANT): Beginning control surface checks.
2020-02-27T16:27:54.002Z,1582820874.002 [CBIT](IMPORTANT): Beginning ground fault scan
2020-02-27T16:27:55.579Z,1582820875.579 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162748.00,A,3648.14105,N,12147.22880,W,0.039,36.29,270220,,,D*4F
2020-02-27T16:27:55.593Z,1582820875.593 [NAL9602](INFO): GPS fix at 20200227T162748: (36.802351, -121.787147)
2020-02-27T16:28:04.901Z,1582820884.901 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.004769
CHAN A1 (24V): -0.000571
CHAN A2 (12V): -0.002204
CHAN A3 (5V): -0.001245
CHAN B0 (3.3V): -0.000213
CHAN B1 (3.15aV): 0.000096
CHAN B2 (3.15bV): -0.000278
CHAN B3 (GND): -0.000774
OPEN: -0.000373
Full Scale Calc: 4.765 mA, -1.589 mA
2020-02-27T16:28:10.119Z,1582820890.119 [NAL9602](INFO): SBD MO Status=0, MOMSN=19675, MT Status=0, MTMSN=0
2020-02-27T16:28:10.120Z,1582820890.120 [NAL9602](INFO): No messages in MT queue
2020-02-27T16:28:11.335Z,1582820891.335 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162803.00,A,3648.14186,N,12147.22861,W,1.089,36.29,270220,,,D*41
2020-02-27T16:28:11.350Z,1582820891.350 [NAL9602](INFO): GPS fix at 20200227T162803: (36.802364, -121.787143)
2020-02-27T16:28:13.759Z,1582820893.759 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162806.00,A,3648.14198,N,12147.22842,W,0.175,36.29,270220,,,D*49
2020-02-27T16:28:13.762Z,1582820893.762 [NAL9602](INFO): GPS fix at 20200227T162806: (36.802366, -121.787140)
2020-02-27T16:28:16.588Z,1582820896.588 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162809.00,A,3648.14184,N,12147.22848,W,0.233,36.29,270220,,,D*40
2020-02-27T16:28:16.590Z,1582820896.590 [NAL9602](INFO): GPS fix at 20200227T162809: (36.802364, -121.787141)
2020-02-27T16:28:19.832Z,1582820899.832 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162812.00,A,3648.14181,N,12147.22855,W,0.175,36.29,270220,,,D*42
2020-02-27T16:28:19.846Z,1582820899.846 [NAL9602](INFO): GPS fix at 20200227T162812: (36.802363, -121.787143)
2020-02-27T16:28:22.644Z,1582820902.644 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162815.00,A,3648.14167,N,12147.22874,W,0.058,36.29,270220,,,D*40
2020-02-27T16:28:22.659Z,1582820902.659 [NAL9602](INFO): GPS fix at 20200227T162815: (36.802361, -121.787146)
2020-02-27T16:28:25.874Z,1582820905.874 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162818.00,A,3648.14150,N,12147.22893,W,0.117,36.29,270220,,,D*4A
2020-02-27T16:28:25.876Z,1582820905.876 [NAL9602](INFO): GPS fix at 20200227T162818: (36.802358, -121.787149)
2020-02-27T16:28:28.708Z,1582820908.708 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162821.00,A,3648.14113,N,12147.22938,W,0.078,36.29,270220,,,D*4F
2020-02-27T16:28:28.710Z,1582820908.710 [NAL9602](INFO): GPS fix at 20200227T162821: (36.802352, -121.787156)
2020-02-27T16:28:31.940Z,1582820911.940 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162824.00,A,3648.14072,N,12147.22980,W,0.039,36.29,270220,,,D*4A
2020-02-27T16:28:31.942Z,1582820911.942 [NAL9602](INFO): GPS fix at 20200227T162824: (36.802345, -121.787163)
2020-02-27T16:28:34.780Z,1582820914.780 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162827.00,A,3648.14042,N,12147.23006,W,0.078,36.29,270220,,,D*49
2020-02-27T16:28:34.782Z,1582820914.782 [NAL9602](INFO): GPS fix at 20200227T162827: (36.802340, -121.787168)
2020-02-27T16:28:37.608Z,1582820917.608 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162830.00,A,3648.14036,N,12147.23012,W,0.078,36.29,270220,,,D*49
2020-02-27T16:28:37.619Z,1582820917.619 [NAL9602](INFO): GPS fix at 20200227T162830: (36.802339, -121.787169)
2020-02-27T16:28:40.495Z,1582820920.495 [IBIT](IMPORTANT): Communications Status:
Fix Status: 1
Iridium Signal Strength: 5
Latitude: 36.802338 Longitude: -121.787170
2020-02-27T16:28:40.840Z,1582820920.840 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162833.00,A,3648.14045,N,12147.23001,W,0.039,36.29,270220,,,D*49
2020-02-27T16:28:40.842Z,1582820920.842 [NAL9602](INFO): GPS fix at 20200227T162833: (36.802341, -121.787167)
2020-02-27T16:28:40.895Z,1582820920.895 [IBIT](IMPORTANT): Battery Status:
Battery Charge (AH): 0.000000
Voltage: 0.000000
2020-02-27T16:28:40.896Z,1582820920.896 [IBIT](IMPORTANT): batteryCapacityThreshold: 50.000000 Ah
2020-02-27T16:28:40.896Z,1582820920.896 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.700000 V
2020-02-27T16:28:41.291Z,1582820921.291 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 %
2020-02-27T16:28:41.291Z,1582820921.291 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi
2020-02-27T16:28:41.291Z,1582820921.291 [IBIT](IMPORTANT): Pressure:8.135773 PSI
2020-02-27T16:28:41.292Z,1582820921.292 [IBIT](IMPORTANT): Humidity:9.626419 %
2020-02-27T16:28:41.679Z,1582820921.679 [IBIT](IMPORTANT): Vehicle Pitch:-0.333121 degrees
2020-02-27T16:28:41.679Z,1582820921.679 [IBIT](IMPORTANT): Vehicle  Roll:-3.511107 degrees
2020-02-27T16:28:41.679Z,1582820921.679 [IBIT](IMPORTANT): Vehicle  Heading:204.922729 degrees
2020-02-27T16:28:42.100Z,1582820922.100 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m
2020-02-27T16:28:42.100Z,1582820922.100 [IBIT](IMPORTANT): buoyancyNeutral: 162.000000 cc
2020-02-27T16:28:42.105Z,1582820922.105 [IBIT](IMPORTANT): massDefault: -0.500000 cm
2020-02-27T16:28:42.105Z,1582820922.105 [IBIT](IMPORTANT): stopDepth: 205.000000 m
2020-02-27T16:28:42.105Z,1582820922.105 [IBIT](IMPORTANT): abortDepth: 250.000000 m
2020-02-27T16:28:42.106Z,1582820922.106 [IBIT](IMPORTANT): IBIT PASSED
2020-02-27T16:28:42.504Z,1582820922.504 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-02-27T16:28:42.504Z,1582820922.504 [Default:CheckIn:C.Wait] Stopped
2020-02-27T16:28:42.504Z,1582820922.504 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-02-27T16:28:42.505Z,1582820922.505 [Default:CheckIn:D] Running Loop=1
2020-02-27T16:28:42.879Z,1582820922.879 [Default:CheckIn:D] Stopped
2020-02-27T16:28:42.879Z,1582820922.879 [Default:CheckIn:E] Running Loop=1
2020-02-27T16:28:43.292Z,1582820923.292 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 37.728866 min 
2020-02-27T16:28:43.292Z,1582820923.292 [Default:CheckIn:E] Stopped
2020-02-27T16:28:43.292Z,1582820923.292 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-02-27T16:28:43.292Z,1582820923.292 [Default:CheckIn] Stopped
2020-02-27T16:28:43.293Z,1582820923.293 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-02-27T16:28:43.294Z,1582820923.294 [Default:CheckIn](INFO): Running loop #5
2020-02-27T16:28:43.294Z,1582820923.294 [Default:CheckIn] Running Loop=5
2020-02-27T16:28:43.294Z,1582820923.294 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-02-27T16:28:43.294Z,1582820923.294 [Default:CheckIn:Read_GPS] Running Loop=1
2020-02-27T16:28:45.298Z,1582820925.298 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,162837.00,A,3648.14064,N,12147.22980,W,0.136,36.29,270220,,,D*41
2020-02-27T16:28:45.301Z,1582820925.301 [NAL9602](INFO): GPS fix at 20200227T162837: (36.802344, -121.787163)
2020-02-27T16:28:45.327Z,1582820925.327 [Default:CheckIn:Read_GPS] Stopped
2020-02-27T16:28:45.327Z,1582820925.327 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-02-27T16:28:53.292Z,1582820933.292 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20200227T154747/Courier0016.lzma
2020-02-27T16:28:55.298Z,1582820935.298 [DataOverHttps](INFO): Moved sent file to Logs/20200227T154747/Courier0016.lzma.bak
2020-02-27T16:28:55.298Z,1582820935.298 [DataOverHttps](INFO): SBD MOMSN=12272309
2020-02-27T16:29:12.178Z,1582820952.178 [DataOverHttps](INFO): Sending 802 bytes from file Logs/20200227T154747/Express0017.lzma
2020-02-27T16:29:14.182Z,1582820954.182 [DataOverHttps](INFO): Moved sent file to Logs/20200227T154747/Express0017.lzma.bak
2020-02-27T16:29:14.182Z,1582820954.182 [DataOverHttps](INFO): SBD MOMSN=12272312
2020-02-27T16:29:17.192Z,1582820957.192 [NAL9602](INFO): Not Powering down - fast GPS
2020-02-27T16:29:31.328Z,1582820971.328 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20200227T154747/Express0020.lzma
2020-02-27T16:29:33.334Z,1582820973.334 [DataOverHttps](INFO): Moved sent file to Logs/20200227T154747/Express0020.lzma.bak
2020-02-27T16:29:33.334Z,1582820973.334 [DataOverHttps](INFO): SBD MOMSN=12272338
2020-02-27T16:29:34.593Z,1582820974.593 [Default:CheckIn:Read_Iridium] Stopped
2020-02-27T16:29:34.593Z,1582820974.593 [Default:CheckIn:C.Wait] Running Loop=1
2020-02-27T16:29:34.593Z,1582820974.593 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-02-27T16:34:35.209Z,1582821275.209 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-02-27T16:34:35.209Z,1582821275.209 [Default:CheckIn:C.Wait] Stopped
2020-02-27T16:34:35.209Z,1582821275.209 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-02-27T16:34:35.209Z,1582821275.209 [Default:CheckIn:D] Running Loop=1
2020-02-27T16:34:35.589Z,1582821275.589 [Default:CheckIn:D] Stopped
2020-02-27T16:34:35.589Z,1582821275.589 [Default:CheckIn:E] Running Loop=1
2020-02-27T16:34:35.995Z,1582821275.995 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 43.607365 min 
2020-02-27T16:34:35.995Z,1582821275.995 [Default:CheckIn:E] Stopped
2020-02-27T16:34:35.995Z,1582821275.995 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-02-27T16:34:35.995Z,1582821275.995 [Default:CheckIn] Stopped
2020-02-27T16:34:35.996Z,1582821275.996 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-02-27T16:34:35.996Z,1582821275.996 [Default:CheckIn](INFO): Running loop #6
2020-02-27T16:34:35.996Z,1582821275.996 [Default:CheckIn] Running Loop=6
2020-02-27T16:34:35.996Z,1582821275.996 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-02-27T16:34:35.996Z,1582821275.996 [Default:CheckIn:Read_GPS] Running Loop=1
2020-02-27T16:34:37.982Z,1582821277.982 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,163429.00,A,3648.13976,N,12147.23084,W,0.233,36.29,270220,,,D*44
2020-02-27T16:34:37.985Z,1582821277.985 [NAL9602](INFO): GPS fix at 20200227T163429: (36.802329, -121.787181)
2020-02-27T16:34:38.008Z,1582821278.008 [Default:CheckIn:Read_GPS] Stopped
2020-02-27T16:34:38.008Z,1582821278.008 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-02-27T16:34:38.813Z,1582821278.813 [Default:CheckIn:Read_Iridium] Stopped
2020-02-27T16:34:38.813Z,1582821278.813 [Default:CheckIn:C.Wait] Running Loop=1
2020-02-27T16:34:38.813Z,1582821278.813 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-02-27T16:34:46.918Z,1582821286.918 [DataOverHttps](IMPORTANT): SBD MTMSN=20200227T163437
2020-02-27T16:34:54.300Z,1582821294.300 [DataOverHttps](INFO): Received command:failc
2020-02-27T16:34:54.310Z,1582821294.310 [CommandLine](IMPORTANT): got command failComponent
2020-02-27T16:34:54.310Z,1582821294.310 [CommandLine](IMPORTANT): Failed components:
2020-02-27T16:34:54.310Z,1582821294.310 [CommandLine](IMPORTANT): No failed Components.
2020-02-27T16:35:01.807Z,1582821301.807 [NAL9602](INFO): SBD MO Status=0, MOMSN=19676, MT Status=0, MTMSN=0
2020-02-27T16:35:01.808Z,1582821301.808 [NAL9602](INFO): No messages in MT queue
2020-02-27T16:35:32.508Z,1582821332.508 [NAL9602](INFO): Not Powering down - fast GPS
2020-02-27T16:39:39.381Z,1582821579.381 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-02-27T16:39:39.381Z,1582821579.381 [Default:CheckIn:C.Wait] Stopped
2020-02-27T16:39:39.381Z,1582821579.381 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-02-27T16:39:39.381Z,1582821579.381 [Default:CheckIn:D] Running Loop=1
2020-02-27T16:39:39.793Z,1582821579.793 [Default:CheckIn:D] Stopped
2020-02-27T16:39:39.794Z,1582821579.794 [Default:CheckIn:E] Running Loop=1
2020-02-27T16:39:40.199Z,1582821580.199 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 48.677445 min 
2020-02-27T16:39:40.199Z,1582821580.199 [Default:CheckIn:E] Stopped
2020-02-27T16:39:40.200Z,1582821580.200 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-02-27T16:39:40.200Z,1582821580.200 [Default:CheckIn] Stopped
2020-02-27T16:39:40.200Z,1582821580.200 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-02-27T16:39:40.200Z,1582821580.200 [Default:CheckIn](INFO): Running loop #7
2020-02-27T16:39:40.200Z,1582821580.200 [Default:CheckIn] Running Loop=7
2020-02-27T16:39:40.200Z,1582821580.200 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-02-27T16:39:40.200Z,1582821580.200 [Default:CheckIn:Read_GPS] Running Loop=1
2020-02-27T16:39:42.184Z,1582821582.184 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,163933.00,A,3648.14241,N,12147.22893,W,0.019,36.29,270220,,,D*4F
2020-02-27T16:39:42.186Z,1582821582.186 [NAL9602](INFO): GPS fix at 20200227T163933: (36.802374, -121.787149)
2020-02-27T16:39:42.210Z,1582821582.210 [Default:CheckIn:Read_GPS] Stopped
2020-02-27T16:39:42.210Z,1582821582.210 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-02-27T16:39:50.192Z,1582821590.192 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20200227T154747/Courier0022.lzma
2020-02-27T16:39:52.198Z,1582821592.198 [DataOverHttps](INFO): Moved sent file to Logs/20200227T154747/Courier0022.lzma.bak
2020-02-27T16:39:52.198Z,1582821592.198 [DataOverHttps](INFO): SBD MOMSN=12272399
2020-02-27T16:40:09.000Z,1582821609.000 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20200227T154747/Courier0025.lzma
2020-02-27T16:40:11.006Z,1582821611.006 [DataOverHttps](INFO): Moved sent file to Logs/20200227T154747/Courier0025.lzma.bak
2020-02-27T16:40:11.006Z,1582821611.006 [DataOverHttps](INFO): SBD MOMSN=12272402
2020-02-27T16:40:14.099Z,1582821614.099 [NAL9602](INFO): SBD MO Status=0, MOMSN=19677, MT Status=0, MTMSN=0
2020-02-27T16:40:14.100Z,1582821614.100 [NAL9602](INFO): No messages in MT queue
2020-02-27T16:40:28.160Z,1582821628.160 [DataOverHttps](INFO): Sending 120 bytes from file Logs/20200227T154747/Express0023.lzma
2020-02-27T16:40:30.166Z,1582821630.166 [DataOverHttps](INFO): Moved sent file to Logs/20200227T154747/Express0023.lzma.bak
2020-02-27T16:40:30.167Z,1582821630.167 [DataOverHttps](INFO): SBD MOMSN=12272405
2020-02-27T16:40:44.802Z,1582821644.802 [NAL9602](INFO): Not Powering down - fast GPS
2020-02-27T16:40:47.565Z,1582821647.565 [DataOverHttps](INFO): Sending 204 bytes from file Logs/20200227T154747/Express0026.lzma
2020-02-27T16:40:49.570Z,1582821649.570 [DataOverHttps](INFO): Moved sent file to Logs/20200227T154747/Express0026.lzma.bak
2020-02-27T16:40:49.570Z,1582821649.570 [DataOverHttps](INFO): SBD MOMSN=12272408
2020-02-27T16:41:06.556Z,1582821666.556 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20200227T154747/Express0029.lzma
2020-02-27T16:41:08.562Z,1582821668.562 [DataOverHttps](INFO): Moved sent file to Logs/20200227T154747/Express0029.lzma.bak
2020-02-27T16:41:08.563Z,1582821668.563 [DataOverHttps](INFO): SBD MOMSN=12272415
2020-02-27T16:41:09.884Z,1582821669.884 [Default:CheckIn:Read_Iridium] Stopped
2020-02-27T16:41:09.884Z,1582821669.884 [Default:CheckIn:C.Wait] Running Loop=1
2020-02-27T16:41:09.885Z,1582821669.885 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-02-27T16:46:10.463Z,1582821970.463 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-02-27T16:46:10.463Z,1582821970.463 [Default:CheckIn:C.Wait] Stopped
2020-02-27T16:46:10.463Z,1582821970.463 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-02-27T16:46:10.463Z,1582821970.463 [Default:CheckIn:D] Running Loop=1
2020-02-27T16:46:10.857Z,1582821970.857 [Default:CheckIn:D] Stopped
2020-02-27T16:46:10.857Z,1582821970.857 [Default:CheckIn:E] Running Loop=1
2020-02-27T16:46:11.258Z,1582821971.258 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 55.195170 min 
2020-02-27T16:46:11.258Z,1582821971.258 [Default:CheckIn:E] Stopped
2020-02-27T16:46:11.258Z,1582821971.258 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-02-27T16:46:11.258Z,1582821971.258 [Default:CheckIn] Stopped
2020-02-27T16:46:11.258Z,1582821971.258 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-02-27T16:46:11.259Z,1582821971.259 [Default:CheckIn](INFO): Running loop #8
2020-02-27T16:46:11.259Z,1582821971.259 [Default:CheckIn] Running Loop=8
2020-02-27T16:46:11.259Z,1582821971.259 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-02-27T16:46:11.259Z,1582821971.259 [Default:CheckIn:Read_GPS] Running Loop=1
2020-02-27T16:46:13.260Z,1582821973.260 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,164604.00,A,3648.14125,N,12147.23250,W,0.311,36.29,270220,,,D*4D
2020-02-27T16:46:13.273Z,1582821973.273 [NAL9602](INFO): GPS fix at 20200227T164604: (36.802354, -121.787208)
2020-02-27T16:46:13.300Z,1582821973.300 [Default:CheckIn:Read_GPS] Stopped
2020-02-27T16:46:13.300Z,1582821973.300 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-02-27T16:46:20.864Z,1582821980.864 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20200227T154747/Courier0031.lzma
2020-02-27T16:46:22.871Z,1582821982.871 [DataOverHttps](INFO): Moved sent file to Logs/20200227T154747/Courier0031.lzma.bak
2020-02-27T16:46:22.871Z,1582821982.871 [DataOverHttps](INFO): SBD MOMSN=12272458
2020-02-27T16:46:31.839Z,1582821991.839 [NAL9602](INFO): SBD MO Status=0, MOMSN=19678, MT Status=0, MTMSN=0
2020-02-27T16:46:31.840Z,1582821991.840 [NAL9602](INFO): No messages in MT queue
2020-02-27T16:46:39.840Z,1582821999.840 [DataOverHttps](INFO): Sending 120 bytes from file Logs/20200227T154747/Express0032.lzma
2020-02-27T16:46:41.846Z,1582822001.846 [DataOverHttps](INFO): Moved sent file to Logs/20200227T154747/Express0032.lzma.bak
2020-02-27T16:46:41.846Z,1582822001.846 [DataOverHttps](INFO): SBD MOMSN=12272461
2020-02-27T16:46:43.185Z,1582822003.185 [Default:CheckIn:Read_Iridium] Stopped
2020-02-27T16:46:43.185Z,1582822003.185 [Default:CheckIn:C.Wait] Running Loop=1
2020-02-27T16:46:43.185Z,1582822003.185 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-02-27T16:47:02.540Z,1582822022.540 [NAL9602](INFO): Not Powering down - fast GPS
2020-02-27T16:51:43.757Z,1582822303.757 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-02-27T16:51:43.757Z,1582822303.757 [Default:CheckIn:C.Wait] Stopped
2020-02-27T16:51:43.757Z,1582822303.757 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-02-27T16:51:43.757Z,1582822303.757 [Default:CheckIn:D] Running Loop=1
2020-02-27T16:51:44.173Z,1582822304.173 [Default:CheckIn:D] Stopped
2020-02-27T16:51:44.173Z,1582822304.173 [Default:CheckIn:E] Running Loop=1
2020-02-27T16:51:44.582Z,1582822304.582 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 60.750431 min 
2020-02-27T16:51:44.583Z,1582822304.583 [Default:CheckIn:E] Stopped
2020-02-27T16:51:44.583Z,1582822304.583 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-02-27T16:51:44.583Z,1582822304.583 [Default:CheckIn] Stopped
2020-02-27T16:51:44.583Z,1582822304.583 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-02-27T16:51:44.583Z,1582822304.583 [Default:CheckIn](INFO): Running loop #9
2020-02-27T16:51:44.583Z,1582822304.583 [Default:CheckIn] Running Loop=9
2020-02-27T16:51:44.583Z,1582822304.583 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-02-27T16:51:44.583Z,1582822304.583 [Default:CheckIn:Read_GPS] Running Loop=1
2020-02-27T16:51:46.568Z,1582822306.568 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165136.00,A,3648.14011,N,12147.23472,W,0.058,249.16,270220,,,D*72
2020-02-27T16:51:46.570Z,1582822306.570 [NAL9602](INFO): GPS fix at 20200227T165136: (36.802335, -121.787245)
2020-02-27T16:51:46.593Z,1582822306.593 [Default:CheckIn:Read_GPS] Stopped
2020-02-27T16:51:46.593Z,1582822306.593 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-02-27T16:51:54.368Z,1582822314.368 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20200227T154747/Courier0034.lzma
2020-02-27T16:51:56.374Z,1582822316.374 [DataOverHttps](INFO): Moved sent file to Logs/20200227T154747/Courier0034.lzma.bak
2020-02-27T16:51:56.374Z,1582822316.374 [DataOverHttps](INFO): SBD MOMSN=12272472
2020-02-27T16:52:02.723Z,1582822322.723 [NAL9602](INFO): SBD MO Status=0, MOMSN=19679, MT Status=0, MTMSN=0
2020-02-27T16:52:02.724Z,1582822322.724 [NAL9602](INFO): No messages in MT queue
2020-02-27T16:52:13.384Z,1582822333.384 [DataOverHttps](INFO): Sending 120 bytes from file Logs/20200227T154747/Express0035.lzma
2020-02-27T16:52:15.390Z,1582822335.390 [DataOverHttps](INFO): Moved sent file to Logs/20200227T154747/Express0035.lzma.bak
2020-02-27T16:52:15.391Z,1582822335.391 [DataOverHttps](INFO): SBD MOMSN=12272475
2020-02-27T16:52:16.493Z,1582822336.493 [Default:CheckIn:Read_Iridium] Stopped
2020-02-27T16:52:16.493Z,1582822336.493 [Default:CheckIn:C.Wait] Running Loop=1
2020-02-27T16:52:16.493Z,1582822336.493 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-02-27T16:52:33.426Z,1582822353.426 [NAL9602](INFO): Not Powering down - fast GPS
2020-02-27T16:57:17.067Z,1582822637.067 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-02-27T16:57:17.068Z,1582822637.068 [Default:CheckIn:C.Wait] Stopped
2020-02-27T16:57:17.068Z,1582822637.068 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-02-27T16:57:17.068Z,1582822637.068 [Default:CheckIn:D] Running Loop=1
2020-02-27T16:57:17.473Z,1582822637.473 [Default:CheckIn:D] Stopped
2020-02-27T16:57:17.473Z,1582822637.473 [Default:CheckIn:E] Running Loop=1
2020-02-27T16:57:17.892Z,1582822637.892 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 66.305432 min 
2020-02-27T16:57:17.892Z,1582822637.892 [Default:CheckIn:E] Stopped
2020-02-27T16:57:17.892Z,1582822637.892 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-02-27T16:57:17.893Z,1582822637.893 [Default:CheckIn] Stopped
2020-02-27T16:57:17.893Z,1582822637.893 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-02-27T16:57:17.893Z,1582822637.893 [Default:CheckIn](INFO): Running loop #10
2020-02-27T16:57:17.893Z,1582822637.893 [Default:CheckIn] Running Loop=10
2020-02-27T16:57:17.893Z,1582822637.893 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-02-27T16:57:17.893Z,1582822637.893 [Default:CheckIn:Read_GPS] Running Loop=1
2020-02-27T16:57:19.864Z,1582822639.864 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,165709.00,A,3648.14109,N,12147.22977,W,0.019,249.16,270220,,,D*7C
2020-02-27T16:57:19.866Z,1582822639.866 [NAL9602](INFO): GPS fix at 20200227T165709: (36.802352, -121.787163)
2020-02-27T16:57:19.966Z,1582822639.966 [Default:CheckIn:Read_GPS] Stopped
2020-02-27T16:57:19.967Z,1582822639.967 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-02-27T16:57:27.876Z,1582822647.876 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20200227T154747/Courier0037.lzma
2020-02-27T16:57:29.882Z,1582822649.882 [DataOverHttps](INFO): Moved sent file to Logs/20200227T154747/Courier0037.lzma.bak
2020-02-27T16:57:29.882Z,1582822649.882 [DataOverHttps](INFO): SBD MOMSN=12272494
2020-02-27T16:57:46.976Z,1582822666.976 [DataOverHttps](INFO): Sending 120 bytes from file Logs/20200227T154747/Express0038.lzma
2020-02-27T16:57:48.982Z,1582822668.982 [DataOverHttps](INFO): Moved sent file to Logs/20200227T154747/Express0038.lzma.bak
2020-02-27T16:57:48.983Z,1582822668.983 [DataOverHttps](INFO): SBD MOMSN=12272498
2020-02-27T16:57:50.193Z,1582822670.193 [Default:CheckIn:Read_Iridium] Stopped
2020-02-27T16:57:50.193Z,1582822670.193 [Default:CheckIn:C.Wait] Running Loop=1
2020-02-27T16:57:50.193Z,1582822670.193 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-02-27T17:00:30.959Z,1582822830.959 [NAL9602](INFO): SBD MO Status=0, MOMSN=19680, MT Status=0, MTMSN=0
2020-02-27T17:00:30.959Z,1582822830.959 [NAL9602](INFO): No messages in MT queue
2020-02-27T17:01:01.658Z,1582822861.658 [NAL9602](INFO): Not Powering down - fast GPS
2020-02-27T17:02:16.826Z,1582822936.826 [BPC1](ERROR): BPC1A: No match for serial number 1717 in BPC1A's battery stick inventory (sticks 1-32 in onboard configuration file).
2020-02-27T17:02:50.773Z,1582822970.773 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-02-27T17:02:50.773Z,1582822970.773 [Default:CheckIn:C.Wait] Stopped
2020-02-27T17:02:50.773Z,1582822970.773 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-02-27T17:02:50.773Z,1582822970.773 [Default:CheckIn:D] Running Loop=1
2020-02-27T17:02:51.183Z,1582822971.183 [Default:CheckIn:D] Stopped
2020-02-27T17:02:51.183Z,1582822971.183 [Default:CheckIn:E] Running Loop=1
2020-02-27T17:02:51.585Z,1582822971.585 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 71.867269 min 
2020-02-27T17:02:51.585Z,1582822971.585 [Default:CheckIn:E] Stopped
2020-02-27T17:02:51.585Z,1582822971.585 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-02-27T17:02:51.586Z,1582822971.586 [Default:CheckIn] Stopped
2020-02-27T17:02:51.586Z,1582822971.586 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-02-27T17:02:51.586Z,1582822971.586 [Default:CheckIn](INFO): Running loop #11
2020-02-27T17:02:51.586Z,1582822971.586 [Default:CheckIn] Running Loop=11
2020-02-27T17:02:51.586Z,1582822971.586 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-02-27T17:02:51.586Z,1582822971.586 [Default:CheckIn:Read_GPS] Running Loop=1
2020-02-27T17:02:53.575Z,1582822973.575 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,170242.00,A,3648.16539,N,12147.21546,W,0.019,22.16,270220,,,D*45
2020-02-27T17:02:53.578Z,1582822973.578 [NAL9602](INFO): GPS fix at 20200227T170242: (36.802757, -121.786924)
2020-02-27T17:02:53.636Z,1582822973.636 [Default:CheckIn:Read_GPS] Stopped
2020-02-27T17:02:53.636Z,1582822973.636 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-02-27T17:03:01.652Z,1582822981.652 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20200227T154747/Courier0040.lzma
2020-02-27T17:03:03.658Z,1582822983.658 [DataOverHttps](INFO): Moved sent file to Logs/20200227T154747/Courier0040.lzma.bak
2020-02-27T17:03:03.659Z,1582822983.659 [DataOverHttps](INFO): SBD MOMSN=12272573
2020-02-27T17:03:08.944Z,1582822988.944 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2020-02-27T17:03:08.966Z,1582822988.966 [BPC1](INFO): Received data from all battery sticks.
2020-02-27T17:03:20.673Z,1582823000.673 [DataOverHttps](INFO): Sending 134 bytes from file Logs/20200227T154747/Express0041.lzma
2020-02-27T17:03:22.678Z,1582823002.678 [DataOverHttps](INFO): Moved sent file to Logs/20200227T154747/Express0041.lzma.bak
2020-02-27T17:03:22.679Z,1582823002.679 [DataOverHttps](INFO): SBD MOMSN=12272580
2020-02-27T17:03:23.900Z,1582823003.900 [Default:CheckIn:Read_Iridium] Stopped
2020-02-27T17:03:23.900Z,1582823003.900 [Default:CheckIn:C.Wait] Running Loop=1
2020-02-27T17:03:23.900Z,1582823003.900 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-02-27T17:03:34.375Z,1582823014.375 [NAL9602](INFO): SBD MO Status=0, MOMSN=19681, MT Status=0, MTMSN=0
2020-02-27T17:03:34.376Z,1582823014.376 [NAL9602](INFO): No messages in MT queue
2020-02-27T17:04:05.085Z,1582823045.085 [NAL9602](INFO): Not Powering down - fast GPS
2020-02-27T17:08:24.498Z,1582823304.498 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-02-27T17:08:24.498Z,1582823304.498 [Default:CheckIn:C.Wait] Stopped
2020-02-27T17:08:24.498Z,1582823304.498 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-02-27T17:08:24.498Z,1582823304.498 [Default:CheckIn:D] Running Loop=1
2020-02-27T17:08:24.914Z,1582823304.914 [Default:CheckIn:D] Stopped
2020-02-27T17:08:24.914Z,1582823304.914 [Default:CheckIn:E] Running Loop=1
2020-02-27T17:08:25.317Z,1582823305.317 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 77.429451 min 
2020-02-27T17:08:25.317Z,1582823305.317 [Default:CheckIn:E] Stopped
2020-02-27T17:08:25.318Z,1582823305.318 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-02-27T17:08:25.318Z,1582823305.318 [Default:CheckIn] Stopped
2020-02-27T17:08:25.318Z,1582823305.318 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-02-27T17:08:25.318Z,1582823305.318 [Default:CheckIn](INFO): Running loop #12
2020-02-27T17:08:25.318Z,1582823305.318 [Default:CheckIn] Running Loop=12
2020-02-27T17:08:25.318Z,1582823305.318 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-02-27T17:08:25.318Z,1582823305.318 [Default:CheckIn:Read_GPS] Running Loop=1
2020-02-27T17:08:27.308Z,1582823307.308 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,170816.00,A,3648.16505,N,12147.21658,W,0.000,22.16,270220,,,D*45
2020-02-27T17:08:27.310Z,1582823307.310 [NAL9602](INFO): GPS fix at 20200227T170816: (36.802751, -121.786943)
2020-02-27T17:08:27.357Z,1582823307.357 [Default:CheckIn:Read_GPS] Stopped
2020-02-27T17:08:27.357Z,1582823307.357 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-02-27T17:08:36.460Z,1582823316.460 [DataOverHttps](INFO): Sending 79 bytes from file Logs/20200227T154747/Courier0043.lzma
2020-02-27T17:08:38.466Z,1582823318.466 [DataOverHttps](INFO): Moved sent file to Logs/20200227T154747/Courier0043.lzma.bak
2020-02-27T17:08:38.466Z,1582823318.466 [DataOverHttps](INFO): SBD MOMSN=12272591
2020-02-27T17:08:51.971Z,1582823331.971 [NAL9602](INFO): SBD MO Status=0, MOMSN=19682, MT Status=0, MTMSN=0
2020-02-27T17:08:51.972Z,1582823331.972 [NAL9602](INFO): No messages in MT queue
2020-02-27T17:08:55.332Z,1582823335.332 [DataOverHttps](INFO): Sending 120 bytes from file Logs/20200227T154747/Express0044.lzma
2020-02-27T17:08:57.339Z,1582823337.339 [DataOverHttps](INFO): Moved sent file to Logs/20200227T154747/Express0044.lzma.bak
2020-02-27T17:08:57.339Z,1582823337.339 [DataOverHttps](INFO): SBD MOMSN=12272594
2020-02-27T17:08:58.454Z,1582823338.454 [Default:CheckIn:Read_Iridium] Stopped
2020-02-27T17:08:58.454Z,1582823338.454 [Default:CheckIn:C.Wait] Running Loop=1
2020-02-27T17:08:58.454Z,1582823338.454 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-02-27T17:09:22.682Z,1582823362.682 [NAL9602](INFO): Not Powering down - fast GPS
2020-02-27T17:13:59.064Z,1582823639.064 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-02-27T17:13:59.064Z,1582823639.064 [Default:CheckIn:C.Wait] Stopped
2020-02-27T17:13:59.064Z,1582823639.064 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-02-27T17:13:59.064Z,1582823639.064 [Default:CheckIn:D] Running Loop=1
2020-02-27T17:13:59.460Z,1582823639.460 [Default:CheckIn:D] Stopped
2020-02-27T17:13:59.477Z,1582823639.477 [Default:CheckIn:E] Running Loop=1
2020-02-27T17:13:59.869Z,1582823639.869 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 83.005233 min 
2020-02-27T17:13:59.869Z,1582823639.869 [Default:CheckIn:E] Stopped
2020-02-27T17:13:59.869Z,1582823639.869 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-02-27T17:13:59.869Z,1582823639.869 [Default:CheckIn] Stopped
2020-02-27T17:13:59.869Z,1582823639.869 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-02-27T17:13:59.869Z,1582823639.869 [Default:CheckIn](INFO): Running loop #13
2020-02-27T17:13:59.869Z,1582823639.869 [Default:CheckIn] Running Loop=13
2020-02-27T17:13:59.869Z,1582823639.869 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-02-27T17:13:59.870Z,1582823639.870 [Default:CheckIn:Read_GPS] Running Loop=1
2020-02-27T17:14:01.880Z,1582823641.880 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,171350.00,A,3648.16476,N,12147.21674,W,0.058,22.16,270220,,,D*4B
2020-02-27T17:14:01.882Z,1582823641.882 [NAL9602](INFO): GPS fix at 20200227T171350: (36.802746, -121.786946)
2020-02-27T17:14:01.909Z,1582823641.909 [Default:CheckIn:Read_GPS] Stopped
2020-02-27T17:14:01.909Z,1582823641.909 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-02-27T17:14:09.128Z,1582823649.128 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20200227T154747/Courier0046.lzma
2020-02-27T17:14:11.134Z,1582823651.134 [DataOverHttps](INFO): Moved sent file to Logs/20200227T154747/Courier0046.lzma.bak
2020-02-27T17:14:11.134Z,1582823651.134 [DataOverHttps](INFO): SBD MOMSN=12272613
2020-02-27T17:14:19.639Z,1582823659.639 [NAL9602](INFO): SBD MO Status=2, MOMSN=19683, MT Status=2, MTMSN=0
2020-02-27T17:14:19.639Z,1582823659.639 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-02-27T17:14:28.072Z,1582823668.072 [DataOverHttps](INFO): Sending 119 bytes from file Logs/20200227T154747/Express0047.lzma
2020-02-27T17:14:30.078Z,1582823670.078 [DataOverHttps](INFO): Moved sent file to Logs/20200227T154747/Express0047.lzma.bak
2020-02-27T17:14:30.078Z,1582823670.078 [DataOverHttps](INFO): SBD MOMSN=12272616
2020-02-27T17:14:31.383Z,1582823671.383 [Default:CheckIn:Read_Iridium] Stopped
2020-02-27T17:14:31.384Z,1582823671.384 [Default:CheckIn:C.Wait] Running Loop=1
2020-02-27T17:14:31.384Z,1582823671.384 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-02-27T17:15:22.707Z,1582823722.707 [NAL9602](INFO): SBD MO Status=2, MOMSN=19683, MT Status=2, MTMSN=0
2020-02-27T17:15:22.708Z,1582823722.708 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-02-27T17:15:52.199Z,1582823752.199 [NAL9602](INFO): SBD MO Status=0, MOMSN=19683, MT Status=0, MTMSN=0
2020-02-27T17:15:52.199Z,1582823752.199 [NAL9602](INFO): No messages in MT queue
2020-02-27T17:16:22.898Z,1582823782.898 [NAL9602](INFO): Not Powering down - fast GPS
2020-02-27T17:19:32.003Z,1582823972.003 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-02-27T17:19:32.003Z,1582823972.003 [Default:CheckIn:C.Wait] Stopped
2020-02-27T17:19:32.003Z,1582823972.003 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-02-27T17:19:32.003Z,1582823972.003 [Default:CheckIn:D] Running Loop=1
2020-02-27T17:19:32.407Z,1582823972.407 [Default:CheckIn:D] Stopped
2020-02-27T17:19:32.407Z,1582823972.407 [Default:CheckIn:E] Running Loop=1
2020-02-27T17:19:32.805Z,1582823972.805 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 88.554346 min 
2020-02-27T17:19:32.805Z,1582823972.805 [Default:CheckIn:E] Stopped
2020-02-27T17:19:32.806Z,1582823972.806 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-02-27T17:19:32.806Z,1582823972.806 [Default:CheckIn] Stopped
2020-02-27T17:19:32.806Z,1582823972.806 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-02-27T17:19:32.806Z,1582823972.806 [Default:CheckIn](INFO): Running loop #14
2020-02-27T17:19:32.806Z,1582823972.806 [Default:CheckIn] Running Loop=14
2020-02-27T17:19:32.806Z,1582823972.806 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-02-27T17:19:32.806Z,1582823972.806 [Default:CheckIn:Read_GPS] Running Loop=1
2020-02-27T17:19:34.803Z,1582823974.803 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,171922.00,A,3648.16304,N,12147.21789,W,0.039,35.46,270220,,,D*41
2020-02-27T17:19:34.806Z,1582823974.806 [NAL9602](INFO): GPS fix at 20200227T171922: (36.802717, -121.786965)
2020-02-27T17:19:34.851Z,1582823974.851 [Default:CheckIn:Read_GPS] Stopped
2020-02-27T17:19:34.851Z,1582823974.851 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-02-27T17:19:41.996Z,1582823981.996 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20200227T154747/Courier0049.lzma
2020-02-27T17:19:44.002Z,1582823984.002 [DataOverHttps](INFO): Moved sent file to Logs/20200227T154747/Courier0049.lzma.bak
2020-02-27T17:19:44.002Z,1582823984.002 [DataOverHttps](INFO): SBD MOMSN=12272659
2020-02-27T17:19:51.368Z,1582823991.368 [NAL9602](INFO): SBD MO Status=0, MOMSN=19684, MT Status=0, MTMSN=0
2020-02-27T17:19:51.368Z,1582823991.368 [NAL9602](INFO): No messages in MT queue
2020-02-27T17:20:00.980Z,1582824000.980 [DataOverHttps](INFO): Sending 119 bytes from file Logs/20200227T154747/Express0050.lzma
2020-02-27T17:20:02.986Z,1582824002.986 [DataOverHttps](INFO): Moved sent file to Logs/20200227T154747/Express0050.lzma.bak
2020-02-27T17:20:02.987Z,1582824002.987 [DataOverHttps](INFO): SBD MOMSN=12272662
2020-02-27T17:20:04.325Z,1582824004.325 [Default:CheckIn:Read_Iridium] Stopped
2020-02-27T17:20:04.325Z,1582824004.325 [Default:CheckIn:C.Wait] Running Loop=1
2020-02-27T17:20:04.325Z,1582824004.325 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-02-27T17:20:22.066Z,1582824022.066 [NAL9602](INFO): Not Powering down - fast GPS
2020-02-27T17:25:04.891Z,1582824304.891 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-02-27T17:25:04.891Z,1582824304.891 [Default:CheckIn:C.Wait] Stopped
2020-02-27T17:25:04.891Z,1582824304.891 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-02-27T17:25:04.891Z,1582824304.891 [Default:CheckIn:D] Running Loop=1
2020-02-27T17:25:05.301Z,1582824305.301 [Default:CheckIn:D] Stopped
2020-02-27T17:25:05.301Z,1582824305.301 [Default:CheckIn:E] Running Loop=1
2020-02-27T17:25:05.706Z,1582824305.706 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 94.102572 min 
2020-02-27T17:25:05.707Z,1582824305.707 [Default:CheckIn:E] Stopped
2020-02-27T17:25:05.707Z,1582824305.707 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-02-27T17:25:05.707Z,1582824305.707 [Default:CheckIn] Stopped
2020-02-27T17:25:05.707Z,1582824305.707 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-02-27T17:25:05.707Z,1582824305.707 [Default:CheckIn](INFO): Running loop #15
2020-02-27T17:25:05.707Z,1582824305.707 [Default:CheckIn] Running Loop=15
2020-02-27T17:25:05.707Z,1582824305.707 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-02-27T17:25:05.707Z,1582824305.707 [Default:CheckIn:Read_GPS] Running Loop=1
2020-02-27T17:25:07.704Z,1582824307.704 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,172454.00,A,3648.16559,N,12147.21501,W,0.058,35.46,270220,,,A*40
2020-02-27T17:25:07.706Z,1582824307.706 [NAL9602](INFO): GPS fix at 20200227T172454: (36.802760, -121.786917)
2020-02-27T17:25:07.753Z,1582824307.753 [Default:CheckIn:Read_GPS] Stopped
2020-02-27T17:25:07.753Z,1582824307.753 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-02-27T17:25:15.068Z,1582824315.068 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20200227T154747/Courier0052.lzma
2020-02-27T17:25:17.074Z,1582824317.074 [DataOverHttps](INFO): Moved sent file to Logs/20200227T154747/Courier0052.lzma.bak
2020-02-27T17:25:17.075Z,1582824317.075 [DataOverHttps](INFO): SBD MOMSN=12272679
2020-02-27T17:25:34.068Z,1582824334.068 [DataOverHttps](INFO): Sending 120 bytes from file Logs/20200227T154747/Express0053.lzma
2020-02-27T17:25:35.171Z,1582824335.171 [NAL9602](INFO): SBD MO Status=0, MOMSN=19685, MT Status=0, MTMSN=0
2020-02-27T17:25:35.171Z,1582824335.171 [NAL9602](INFO): No messages in MT queue
2020-02-27T17:25:36.074Z,1582824336.074 [DataOverHttps](INFO): Moved sent file to Logs/20200227T154747/Express0053.lzma.bak
2020-02-27T17:25:36.075Z,1582824336.075 [DataOverHttps](INFO): SBD MOMSN=12272682
2020-02-27T17:25:37.231Z,1582824337.231 [Default:CheckIn:Read_Iridium] Stopped
2020-02-27T17:25:37.231Z,1582824337.231 [Default:CheckIn:C.Wait] Running Loop=1
2020-02-27T17:25:37.231Z,1582824337.231 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-02-27T17:26:05.878Z,1582824365.878 [NAL9602](INFO): Not Powering down - fast GPS
2020-02-27T17:30:37.821Z,1582824637.821 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-02-27T17:30:37.821Z,1582824637.821 [Default:CheckIn:C.Wait] Stopped
2020-02-27T17:30:37.821Z,1582824637.821 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-02-27T17:30:37.821Z,1582824637.821 [Default:CheckIn:D] Running Loop=1
2020-02-27T17:30:38.225Z,1582824638.225 [Default:CheckIn:D] Stopped
2020-02-27T17:30:38.225Z,1582824638.225 [Default:CheckIn:E] Running Loop=1
2020-02-27T17:30:38.619Z,1582824638.619 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 99.651237 min 
2020-02-27T17:30:38.619Z,1582824638.619 [Default:CheckIn:E] Stopped
2020-02-27T17:30:38.620Z,1582824638.620 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-02-27T17:30:38.620Z,1582824638.620 [Default:CheckIn] Stopped
2020-02-27T17:30:38.620Z,1582824638.620 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-02-27T17:30:38.620Z,1582824638.620 [Default:CheckIn](INFO): Running loop #16
2020-02-27T17:30:38.620Z,1582824638.620 [Default:CheckIn] Running Loop=16
2020-02-27T17:30:38.620Z,1582824638.620 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-02-27T17:30:38.620Z,1582824638.620 [Default:CheckIn:Read_GPS] Running Loop=1
2020-02-27T17:30:40.604Z,1582824640.604 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173027.00,A,3648.16676,N,12147.21438,W,0.058,35.46,270220,,,D*41
2020-02-27T17:30:40.606Z,1582824640.606 [NAL9602](INFO): GPS fix at 20200227T173027: (36.802779, -121.786906)
2020-02-27T17:30:40.631Z,1582824640.631 [Default:CheckIn:Read_GPS] Stopped
2020-02-27T17:30:40.631Z,1582824640.631 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-02-27T17:30:47.816Z,1582824647.816 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20200227T154747/Courier0055.lzma
2020-02-27T17:30:49.822Z,1582824649.822 [DataOverHttps](INFO): Moved sent file to Logs/20200227T154747/Courier0055.lzma.bak
2020-02-27T17:30:49.822Z,1582824649.822 [DataOverHttps](INFO): SBD MOMSN=12272694
2020-02-27T17:31:06.824Z,1582824666.824 [DataOverHttps](INFO): Sending 120 bytes from file Logs/20200227T154747/Express0056.lzma
2020-02-27T17:31:08.830Z,1582824668.830 [DataOverHttps](INFO): Moved sent file to Logs/20200227T154747/Express0056.lzma.bak
2020-02-27T17:31:08.831Z,1582824668.831 [DataOverHttps](INFO): SBD MOMSN=12272697
2020-02-27T17:31:10.129Z,1582824670.129 [Default:CheckIn:Read_Iridium] Stopped
2020-02-27T17:31:10.129Z,1582824670.129 [Default:CheckIn:C.Wait] Running Loop=1
2020-02-27T17:31:10.129Z,1582824670.129 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-02-27T17:32:11.907Z,1582824731.907 [NAL9602](INFO): SBD MO Status=0, MOMSN=19686, MT Status=0, MTMSN=0
2020-02-27T17:32:11.908Z,1582824731.908 [NAL9602](INFO): No messages in MT queue
2020-02-27T17:32:42.660Z,1582824762.660 [NAL9602](INFO): Not Powering down - fast GPS
2020-02-27T17:36:10.740Z,1582824970.740 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-02-27T17:36:10.740Z,1582824970.740 [Default:CheckIn:C.Wait] Stopped
2020-02-27T17:36:10.740Z,1582824970.740 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-02-27T17:36:10.740Z,1582824970.740 [Default:CheckIn:D] Running Loop=1
2020-02-27T17:36:11.146Z,1582824971.146 [Default:CheckIn:D] Stopped
2020-02-27T17:36:11.146Z,1582824971.146 [Default:CheckIn:E] Running Loop=1
2020-02-27T17:36:11.555Z,1582824971.555 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 105.199992 min 
2020-02-27T17:36:11.555Z,1582824971.555 [Default:CheckIn:E] Stopped
2020-02-27T17:36:11.555Z,1582824971.555 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-02-27T17:36:11.555Z,1582824971.555 [Default:CheckIn] Stopped
2020-02-27T17:36:11.556Z,1582824971.556 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-02-27T17:36:11.556Z,1582824971.556 [Default:CheckIn](INFO): Running loop #17
2020-02-27T17:36:11.556Z,1582824971.556 [Default:CheckIn] Running Loop=17
2020-02-27T17:36:11.556Z,1582824971.556 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-02-27T17:36:11.556Z,1582824971.556 [Default:CheckIn:Read_GPS] Running Loop=1
2020-02-27T17:36:13.547Z,1582824973.547 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173559.00,A,3648.16676,N,12147.21497,W,0.039,35.46,270220,,,D*4F
2020-02-27T17:36:13.550Z,1582824973.550 [NAL9602](INFO): GPS fix at 20200227T173559: (36.802779, -121.786916)
2020-02-27T17:36:13.595Z,1582824973.595 [Default:CheckIn:Read_GPS] Stopped
2020-02-27T17:36:13.595Z,1582824973.595 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-02-27T17:36:21.556Z,1582824981.556 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20200227T154747/Courier0058.lzma
2020-02-27T17:36:23.562Z,1582824983.562 [DataOverHttps](INFO): Moved sent file to Logs/20200227T154747/Courier0058.lzma.bak
2020-02-27T17:36:23.563Z,1582824983.563 [DataOverHttps](INFO): SBD MOMSN=12272713
2020-02-27T17:36:27.683Z,1582824987.683 [NAL9602](INFO): SBD MO Status=0, MOMSN=19687, MT Status=0, MTMSN=0
2020-02-27T17:36:27.683Z,1582824987.684 [NAL9602](INFO): No messages in MT queue
2020-02-27T17:36:42.508Z,1582825002.508 [DataOverHttps](INFO): Sending 119 bytes from file Logs/20200227T154747/Express0059.lzma
2020-02-27T17:36:44.514Z,1582825004.514 [DataOverHttps](INFO): Moved sent file to Logs/20200227T154747/Express0059.lzma.bak
2020-02-27T17:36:44.515Z,1582825004.515 [DataOverHttps](INFO): SBD MOMSN=12272717
2020-02-27T17:36:45.889Z,1582825005.889 [Default:CheckIn:Read_Iridium] Stopped
2020-02-27T17:36:45.889Z,1582825005.889 [Default:CheckIn:C.Wait] Running Loop=1
2020-02-27T17:36:45.889Z,1582825005.889 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-02-27T17:36:58.384Z,1582825018.384 [NAL9602](INFO): Not Powering down - fast GPS
2020-02-27T17:41:46.473Z,1582825306.473 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-02-27T17:41:46.473Z,1582825306.473 [Default:CheckIn:C.Wait] Stopped
2020-02-27T17:41:46.473Z,1582825306.473 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-02-27T17:41:46.473Z,1582825306.473 [Default:CheckIn:D] Running Loop=1
2020-02-27T17:41:46.868Z,1582825306.868 [Default:CheckIn:D] Stopped
2020-02-27T17:41:46.869Z,1582825306.869 [Default:CheckIn:E] Running Loop=1
2020-02-27T17:41:47.269Z,1582825307.269 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 110.795361 min 
2020-02-27T17:41:47.269Z,1582825307.269 [Default:CheckIn:E] Stopped
2020-02-27T17:41:47.270Z,1582825307.270 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-02-27T17:41:47.270Z,1582825307.270 [Default:CheckIn] Stopped
2020-02-27T17:41:47.270Z,1582825307.270 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-02-27T17:41:47.270Z,1582825307.270 [Default:CheckIn](INFO): Running loop #18
2020-02-27T17:41:47.270Z,1582825307.270 [Default:CheckIn] Running Loop=18
2020-02-27T17:41:47.270Z,1582825307.270 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-02-27T17:41:47.270Z,1582825307.270 [Default:CheckIn:Read_GPS] Running Loop=1
2020-02-27T17:41:49.266Z,1582825309.266 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174134.00,A,3648.16529,N,12147.21468,W,0.019,35.46,270220,,,D*4C
2020-02-27T17:41:49.268Z,1582825309.268 [NAL9602](INFO): GPS fix at 20200227T174134: (36.802755, -121.786911)
2020-02-27T17:41:49.314Z,1582825309.314 [Default:CheckIn:Read_GPS] Stopped
2020-02-27T17:41:49.314Z,1582825309.314 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-02-27T17:41:57.064Z,1582825317.064 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20200227T154747/Courier0061.lzma
2020-02-27T17:41:59.070Z,1582825319.070 [DataOverHttps](INFO): Moved sent file to Logs/20200227T154747/Courier0061.lzma.bak
2020-02-27T17:41:59.071Z,1582825319.071 [DataOverHttps](INFO): SBD MOMSN=12272723
2020-02-27T17:42:16.056Z,1582825336.056 [DataOverHttps](INFO): Sending 121 bytes from file Logs/20200227T154747/Express0062.lzma
2020-02-27T17:42:18.062Z,1582825338.062 [DataOverHttps](INFO): Moved sent file to Logs/20200227T154747/Express0062.lzma.bak
2020-02-27T17:42:18.063Z,1582825338.063 [DataOverHttps](INFO): SBD MOMSN=12272727
2020-02-27T17:42:19.196Z,1582825339.196 [Default:CheckIn:Read_Iridium] Stopped
2020-02-27T17:42:19.196Z,1582825339.196 [Default:CheckIn:C.Wait] Running Loop=1
2020-02-27T17:42:19.196Z,1582825339.196 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-02-27T17:42:51.481Z,1582825371.481 [NAL9602](INFO): SBD MO Status=2, MOMSN=19688, MT Status=2, MTMSN=0
2020-02-27T17:42:51.482Z,1582825371.482 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-02-27T17:43:01.987Z,1582825381.987 [NAL9602](INFO): SBD MO Status=0, MOMSN=19688, MT Status=0, MTMSN=0
2020-02-27T17:43:01.988Z,1582825381.988 [NAL9602](INFO): No messages in MT queue
2020-02-27T17:43:32.688Z,1582825412.688 [NAL9602](INFO): Not Powering down - fast GPS
2020-02-27T17:47:19.805Z,1582825639.805 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-02-27T17:47:19.806Z,1582825639.806 [Default:CheckIn:C.Wait] Stopped
2020-02-27T17:47:19.806Z,1582825639.806 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-02-27T17:47:19.806Z,1582825639.806 [Default:CheckIn:D] Running Loop=1
2020-02-27T17:47:20.191Z,1582825640.191 [Default:CheckIn:D] Stopped
2020-02-27T17:47:20.191Z,1582825640.191 [Default:CheckIn:E] Running Loop=1
2020-02-27T17:47:20.607Z,1582825640.607 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 116.350732 min 
2020-02-27T17:47:20.607Z,1582825640.607 [Default:CheckIn:E] Stopped
2020-02-27T17:47:20.607Z,1582825640.607 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-02-27T17:47:20.607Z,1582825640.607 [Default:CheckIn] Stopped
2020-02-27T17:47:20.607Z,1582825640.607 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-02-27T17:47:20.608Z,1582825640.608 [Default:CheckIn](INFO): Running loop #19
2020-02-27T17:47:20.608Z,1582825640.608 [Default:CheckIn] Running Loop=19
2020-02-27T17:47:20.608Z,1582825640.608 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-02-27T17:47:20.608Z,1582825640.608 [Default:CheckIn:Read_GPS] Running Loop=1
2020-02-27T17:47:22.600Z,1582825642.600 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174707.00,A,3648.42797,N,12147.11684,W,4.957,359.37,270220,,,D*77
2020-02-27T17:47:22.602Z,1582825642.602 [NAL9602](INFO): GPS fix at 20200227T174707: (36.807133, -121.785281)
2020-02-27T17:47:22.648Z,1582825642.648 [Default:CheckIn:Read_GPS] Stopped
2020-02-27T17:47:22.648Z,1582825642.648 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-02-27T17:47:29.812Z,1582825649.812 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20200227T154747/Courier0064.lzma
2020-02-27T17:47:31.818Z,1582825651.818 [DataOverHttps](INFO): Moved sent file to Logs/20200227T154747/Courier0064.lzma.bak
2020-02-27T17:47:31.818Z,1582825651.818 [DataOverHttps](INFO): SBD MOMSN=12272753
2020-02-27T17:47:41.600Z,1582825661.600 [NAL9602](INFO): SBD MO Status=0, MOMSN=19689, MT Status=0, MTMSN=0
2020-02-27T17:47:41.600Z,1582825661.600 [NAL9602](INFO): No messages in MT queue
2020-02-27T17:47:48.748Z,1582825668.748 [DataOverHttps](INFO): Sending 136 bytes from file Logs/20200227T154747/Express0065.lzma
2020-02-27T17:47:50.754Z,1582825670.754 [DataOverHttps](INFO): Moved sent file to Logs/20200227T154747/Express0065.lzma.bak
2020-02-27T17:47:50.755Z,1582825670.755 [DataOverHttps](INFO): SBD MOMSN=12272756
2020-02-27T17:47:52.114Z,1582825672.114 [Default:CheckIn:Read_Iridium] Stopped
2020-02-27T17:47:52.114Z,1582825672.114 [Default:CheckIn:C.Wait] Running Loop=1
2020-02-27T17:47:52.114Z,1582825672.114 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-02-27T17:48:12.284Z,1582825692.284 [NAL9602](INFO): Not Powering down - fast GPS
2020-02-27T17:52:52.700Z,1582825972.700 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-02-27T17:52:52.700Z,1582825972.700 [Default:CheckIn:C.Wait] Stopped
2020-02-27T17:52:52.700Z,1582825972.700 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-02-27T17:52:52.700Z,1582825972.700 [Default:CheckIn:D] Running Loop=1
2020-02-27T17:52:53.118Z,1582825973.118 [Default:CheckIn:D] Stopped
2020-02-27T17:52:53.118Z,1582825973.118 [Default:CheckIn:E] Running Loop=1
2020-02-27T17:52:53.497Z,1582825973.497 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 121.899528 min 
2020-02-27T17:52:53.497Z,1582825973.497 [Default:CheckIn:E] Stopped
2020-02-27T17:52:53.497Z,1582825973.497 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-02-27T17:52:53.497Z,1582825973.497 [Default:CheckIn] Stopped
2020-02-27T17:52:53.497Z,1582825973.497 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-02-27T17:52:53.497Z,1582825973.497 [Default:CheckIn](INFO): Running loop #20
2020-02-27T17:52:53.498Z,1582825973.498 [Default:CheckIn] Running Loop=20
2020-02-27T17:52:53.498Z,1582825973.498 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-02-27T17:52:53.498Z,1582825973.498 [Default:CheckIn:Read_GPS] Running Loop=1
2020-02-27T17:52:55.494Z,1582825975.494 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175240.00,A,3648.32195,N,12148.33799,W,26.592,270.23,270220,,,D*4B
2020-02-27T17:52:55.496Z,1582825975.496 [NAL9602](INFO): GPS fix at 20200227T175240: (36.805366, -121.805633)
2020-02-27T17:52:55.542Z,1582825975.542 [Default:CheckIn:Read_GPS] Stopped
2020-02-27T17:52:55.542Z,1582825975.542 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-02-27T17:53:03.344Z,1582825983.344 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20200227T154747/Courier0067.lzma
2020-02-27T17:53:05.350Z,1582825985.350 [DataOverHttps](INFO): Moved sent file to Logs/20200227T154747/Courier0067.lzma.bak
2020-02-27T17:53:05.350Z,1582825985.350 [DataOverHttps](INFO): SBD MOMSN=12272783
2020-02-27T17:53:10.039Z,1582825990.039 [NAL9602](INFO): SBD MO Status=0, MOMSN=19690, MT Status=0, MTMSN=0
2020-02-27T17:53:10.040Z,1582825990.040 [NAL9602](INFO): No messages in MT queue
2020-02-27T17:53:22.416Z,1582826002.416 [DataOverHttps](INFO): Sending 134 bytes from file Logs/20200227T154747/Express0068.lzma
2020-02-27T17:53:24.422Z,1582826004.422 [DataOverHttps](INFO): Moved sent file to Logs/20200227T154747/Express0068.lzma.bak
2020-02-27T17:53:24.423Z,1582826004.423 [DataOverHttps](INFO): SBD MOMSN=12272786
2020-02-27T17:53:25.829Z,1582826005.829 [Default:CheckIn:Read_Iridium] Stopped
2020-02-27T17:53:25.829Z,1582826005.829 [Default:CheckIn:C.Wait] Running Loop=1
2020-02-27T17:53:25.829Z,1582826005.829 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-02-27T17:53:40.740Z,1582826020.740 [NAL9602](INFO): Not Powering down - fast GPS
2020-02-27T17:58:26.405Z,1582826306.405 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-02-27T17:58:26.405Z,1582826306.405 [Default:CheckIn:C.Wait] Stopped
2020-02-27T17:58:26.405Z,1582826306.405 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-02-27T17:58:26.405Z,1582826306.405 [Default:CheckIn:D] Running Loop=1
2020-02-27T17:58:26.812Z,1582826306.812 [Default:CheckIn:D] Stopped
2020-02-27T17:58:26.812Z,1582826306.812 [Default:CheckIn:E] Running Loop=1
2020-02-27T17:58:27.220Z,1582826307.220 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 127.461084 min 
2020-02-27T17:58:27.220Z,1582826307.220 [Default:CheckIn:E] Stopped
2020-02-27T17:58:27.220Z,1582826307.220 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-02-27T17:58:27.220Z,1582826307.220 [Default:CheckIn] Stopped
2020-02-27T17:58:27.220Z,1582826307.220 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-02-27T17:58:27.225Z,1582826307.225 [Default:CheckIn](INFO): Running loop #21
2020-02-27T17:58:27.225Z,1582826307.225 [Default:CheckIn] Running Loop=21
2020-02-27T17:58:27.225Z,1582826307.225 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-02-27T17:58:27.225Z,1582826307.225 [Default:CheckIn:Read_GPS] Running Loop=1
2020-02-27T17:58:29.208Z,1582826309.208 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175813.00,A,3648.20492,N,12150.92406,W,3.168,287.17,270220,,,D*78
2020-02-27T17:58:29.210Z,1582826309.210 [NAL9602](INFO): GPS fix at 20200227T175813: (36.803415, -121.848734)
2020-02-27T17:58:29.277Z,1582826309.277 [Default:CheckIn:Read_GPS] Stopped
2020-02-27T17:58:29.277Z,1582826309.277 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-02-27T17:58:36.852Z,1582826316.852 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20200227T154747/Courier0070.lzma
2020-02-27T17:58:38.858Z,1582826318.858 [DataOverHttps](INFO): Moved sent file to Logs/20200227T154747/Courier0070.lzma.bak
2020-02-27T17:58:38.859Z,1582826318.859 [DataOverHttps](INFO): SBD MOMSN=12272804
2020-02-27T17:58:46.207Z,1582826326.207 [NAL9602](INFO): SBD MO Status=0, MOMSN=19691, MT Status=0, MTMSN=0
2020-02-27T17:58:46.207Z,1582826326.207 [NAL9602](INFO): No messages in MT queue
2020-02-27T17:58:55.872Z,1582826335.872 [DataOverHttps](INFO): Sending 136 bytes from file Logs/20200227T154747/Express0071.lzma
2020-02-27T17:58:57.878Z,1582826337.878 [DataOverHttps](INFO): Moved sent file to Logs/20200227T154747/Express0071.lzma.bak
2020-02-27T17:58:57.879Z,1582826337.879 [DataOverHttps](INFO): SBD MOMSN=12272807
2020-02-27T17:58:59.157Z,1582826339.157 [Default:CheckIn:Read_Iridium] Stopped
2020-02-27T17:58:59.157Z,1582826339.157 [Default:CheckIn:C.Wait] Running Loop=1
2020-02-27T17:58:59.157Z,1582826339.157 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-02-27T17:59:16.906Z,1582826356.906 [NAL9602](INFO): Not Powering down - fast GPS
2020-02-27T18:03:03.177Z,1582826583.177 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2020-02-27T18:03:34.301Z,1582826614.301 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2020-02-27T18:03:59.745Z,1582826639.745 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-02-27T18:03:59.745Z,1582826639.745 [Default:CheckIn:C.Wait] Stopped
2020-02-27T18:03:59.745Z,1582826639.745 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-02-27T18:03:59.745Z,1582826639.745 [Default:CheckIn:D] Running Loop=1
2020-02-27T18:04:00.160Z,1582826640.160 [Default:CheckIn:D] Stopped
2020-02-27T18:04:00.160Z,1582826640.160 [Default:CheckIn:E] Running Loop=1
2020-02-27T18:04:00.565Z,1582826640.565 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 133.016886 min 
2020-02-27T18:04:00.565Z,1582826640.565 [Default:CheckIn:E] Stopped
2020-02-27T18:04:00.565Z,1582826640.565 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-02-27T18:04:00.565Z,1582826640.565 [Default:CheckIn] Stopped
2020-02-27T18:04:00.566Z,1582826640.566 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-02-27T18:04:00.566Z,1582826640.566 [Default:CheckIn](INFO): Running loop #22
2020-02-27T18:04:00.566Z,1582826640.566 [Default:CheckIn] Running Loop=22
2020-02-27T18:04:00.566Z,1582826640.566 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-02-27T18:04:00.566Z,1582826640.566 [Default:CheckIn:Read_GPS] Running Loop=1
2020-02-27T18:04:02.548Z,1582826642.548 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,180346.00,A,3648.22973,N,12151.02674,W,0.914,321.65,270220,,,D*7E
2020-02-27T18:04:02.550Z,1582826642.550 [NAL9602](INFO): GPS fix at 20200227T180346: (36.803829, -121.850446)
2020-02-27T18:04:02.576Z,1582826642.576 [Default:CheckIn:Read_GPS] Stopped
2020-02-27T18:04:02.576Z,1582826642.576 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-02-27T18:04:17.903Z,1582826657.903 [NAL9602](INFO): SBD MO Status=0, MOMSN=19692, MT Status=0, MTMSN=0
2020-02-27T18:04:17.904Z,1582826657.904 [NAL9602](INFO): No messages in MT queue
2020-02-27T18:04:25.260Z,1582826665.260 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20200227T154747/Courier0073.lzma
2020-02-27T18:04:27.266Z,1582826667.266 [DataOverHttps](INFO): Moved sent file to Logs/20200227T154747/Courier0073.lzma.bak
2020-02-27T18:04:27.267Z,1582826667.267 [DataOverHttps](INFO): SBD MOMSN=12272823
2020-02-27T18:04:46.244Z,1582826686.244 [DataOverHttps](INFO): Sending 134 bytes from file Logs/20200227T154747/Express0074.lzma
2020-02-27T18:04:48.250Z,1582826688.250 [DataOverHttps](INFO): Moved sent file to Logs/20200227T154747/Express0074.lzma.bak
2020-02-27T18:04:48.251Z,1582826688.251 [DataOverHttps](INFO): SBD MOMSN=12272827
2020-02-27T18:04:48.600Z,1582826688.600 [NAL9602](INFO): Not Powering down - fast GPS
2020-02-27T18:04:49.437Z,1582826689.437 [Default:CheckIn:Read_Iridium] Stopped
2020-02-27T18:04:49.437Z,1582826689.437 [Default:CheckIn:C.Wait] Running Loop=1
2020-02-27T18:04:49.437Z,1582826689.437 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-02-27T18:05:50.141Z,1582826750.141 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2020-02-27T18:06:21.277Z,1582826781.277 [DataOverHttps](INFO): Exceeded connect timeout, disconnecting.
2020-02-27T18:06:30.726Z,1582826790.726 [DataOverHttps](IMPORTANT): SBD MTMSN=20200227T180612