2020-02-26T20:29:49.083Z,1582748989.083 [Supervisor](DEBUG): Initializing supervisor.
2020-02-26T20:29:49.086Z,1582748989.086 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2020-02-26T20:29:49.087Z,1582748989.087 [SyncHandler](INFO): Protected caller Thread ID is 1459
2020-02-26T20:29:49.087Z,1582748989.087 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2020-02-26T20:29:49.088Z,1582748989.088 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2020-02-26T20:29:49.088Z,1582748989.088 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 1460
2020-02-26T20:29:49.091Z,1582748989.091 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2020-02-26T20:29:49.102Z,1582748989.102 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2020-02-26T20:29:49.103Z,1582748989.103 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2020-02-26T20:29:49.103Z,1582748989.103 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 1461
2020-02-26T20:29:49.104Z,1582748989.104 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2020-02-26T20:29:49.105Z,1582748989.105 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2020-02-26T20:29:49.105Z,1582748989.105 [logger ThreadHandler](INFO): Protected caller Thread ID is 1462
2020-02-26T20:29:49.107Z,1582748989.107 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2020-02-26T20:29:49.108Z,1582748989.108 [Supervisor](INFO): Looking for Config files in directory: Config/
2020-02-26T20:29:49.109Z,1582748989.109 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2020-02-26T20:29:49.203Z,1582748989.203 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2020-02-26T20:29:49.204Z,1582748989.204 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2020-02-26T20:29:49.789Z,1582748989.789 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2020-02-26T20:29:49.790Z,1582748989.790 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2020-02-26T20:29:49.887Z,1582748989.887 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2020-02-26T20:29:49.888Z,1582748989.888 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2020-02-26T20:29:49.988Z,1582748989.988 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2020-02-26T20:29:49.989Z,1582748989.989 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2020-02-26T20:29:50.069Z,1582748990.069 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2020-02-26T20:29:50.205Z,1582748990.205 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2020-02-26T20:29:50.206Z,1582748990.206 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2020-02-26T20:29:50.492Z,1582748990.492 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2020-02-26T20:29:50.493Z,1582748990.493 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2020-02-26T20:29:50.938Z,1582748990.938 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2020-02-26T20:29:50.938Z,1582748990.938 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2020-02-26T20:29:51.083Z,1582748991.083 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2020-02-26T20:29:51.084Z,1582748991.084 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2020-02-26T20:29:51.272Z,1582748991.272 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2020-02-26T20:29:51.273Z,1582748991.273 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2020-02-26T20:29:51.732Z,1582748991.732 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2020-02-26T20:29:51.733Z,1582748991.733 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2020-02-26T20:29:51.947Z,1582748991.947 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2020-02-26T20:29:51.947Z,1582748991.947 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2020-02-26T20:29:52.144Z,1582748992.144 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2020-02-26T20:29:52.145Z,1582748992.145 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2020-02-26T20:29:52.550Z,1582748992.550 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2020-02-26T20:29:52.551Z,1582748992.551 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2020-02-26T20:29:52.885Z,1582748992.885 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2020-02-26T20:29:52.887Z,1582748992.887 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-pontus/
2020-02-26T20:29:52.888Z,1582748992.888 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/secure.cfg
2020-02-26T20:29:52.970Z,1582748992.970 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Sensor.cfg
2020-02-26T20:29:53.127Z,1582748993.127 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Servo.cfg
2020-02-26T20:29:53.474Z,1582748993.474 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Simulator.cfg
2020-02-26T20:29:53.634Z,1582748993.634 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/logger.cfg
2020-02-26T20:29:53.731Z,1582748993.731 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/vehicle.cfg
2020-02-26T20:29:54.081Z,1582748994.081 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Battery.cfg
2020-02-26T20:29:54.305Z,1582748994.305 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2020-02-26T20:29:54.306Z,1582748994.306 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Navigation.cfg
2020-02-26T20:29:54.398Z,1582748994.398 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/BIT.cfg
2020-02-26T20:29:54.495Z,1582748994.495 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Science.cfg
2020-02-26T20:29:54.633Z,1582748994.633 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Control.cfg
2020-02-26T20:29:54.732Z,1582748994.732 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-pontus/root/
2020-02-26T20:29:54.732Z,1582748994.732 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2020-02-26T20:29:54.748Z,1582748994.748 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2020-02-26T20:29:54.794Z,1582748994.794 [VerticalControl](DEBUG): Construct VerticalControl.
2020-02-26T20:29:54.905Z,1582748994.905 [VerticalControl] Loaded
2020-02-26T20:29:54.905Z,1582748994.905 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2020-02-26T20:29:54.906Z,1582748994.906 [HorizontalControl](DEBUG): Construct HorizontalControl.
2020-02-26T20:29:54.973Z,1582748994.973 [HorizontalControl] Loaded
2020-02-26T20:29:54.974Z,1582748994.974 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2020-02-26T20:29:54.974Z,1582748994.974 [SpeedControl](DEBUG): Construct SpeedControl.
2020-02-26T20:29:54.980Z,1582748994.980 [SpeedControl] Loaded
2020-02-26T20:29:54.980Z,1582748994.980 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2020-02-26T20:29:54.981Z,1582748994.981 [LoopControl](DEBUG): Construct LoopControl.
2020-02-26T20:29:54.981Z,1582748994.981 [LoopControl] Loaded
2020-02-26T20:29:54.981Z,1582748994.981 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2020-02-26T20:29:54.982Z,1582748994.982 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2020-02-26T20:29:54.982Z,1582748994.982 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2020-02-26T20:29:55.022Z,1582748995.022 [DepthRateCalculator] Loaded
2020-02-26T20:29:55.022Z,1582748995.022 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2020-02-26T20:29:55.027Z,1582748995.027 [PitchRateCalculator] Loaded
2020-02-26T20:29:55.027Z,1582748995.027 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2020-02-26T20:29:55.042Z,1582748995.042 [SpeedCalculator] Loaded
2020-02-26T20:29:55.043Z,1582748995.043 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2020-02-26T20:29:55.063Z,1582748995.063 [TempGradientCalculator] Loaded
2020-02-26T20:29:55.064Z,1582748995.064 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2020-02-26T20:29:55.068Z,1582748995.068 [YawRateCalculator] Loaded
2020-02-26T20:29:55.069Z,1582748995.069 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2020-02-26T20:29:55.097Z,1582748995.097 [ElevatorOffsetCalculator] Loaded
2020-02-26T20:29:55.097Z,1582748995.097 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2020-02-26T20:29:55.098Z,1582748995.098 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2020-02-26T20:29:55.098Z,1582748995.098 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2020-02-26T20:29:55.130Z,1582748995.130 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2020-02-26T20:29:55.131Z,1582748995.131 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2020-02-26T20:29:55.200Z,1582748995.200 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2020-02-26T20:29:55.200Z,1582748995.200 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2020-02-26T20:29:55.481Z,1582748995.481 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2020-02-26T20:29:55.482Z,1582748995.482 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2020-02-26T20:29:55.575Z,1582748995.575 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2020-02-26T20:29:55.576Z,1582748995.576 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2020-02-26T20:29:55.831Z,1582748995.831 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_orientation
2020-02-26T20:29:55.836Z,1582748995.836 [AHRS_M2](INFO): created writer for : platform_orientation
2020-02-26T20:29:55.837Z,1582748995.837 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_magnetic_orientation
2020-02-26T20:29:55.842Z,1582748995.842 [AHRS_M2](INFO): created writer for : platform_magnetic_orientation
2020-02-26T20:29:55.843Z,1582748995.843 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_pitch_angle
2020-02-26T20:29:55.848Z,1582748995.848 [AHRS_M2](INFO): created writer for : platform_pitch_angle
2020-02-26T20:29:55.848Z,1582748995.848 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_roll_angle
2020-02-26T20:29:55.853Z,1582748995.853 [AHRS_M2](INFO): created writer for : platform_roll_angle
2020-02-26T20:29:55.924Z,1582748995.924 [AHRS_M2] Loaded
2020-02-26T20:29:55.924Z,1582748995.924 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2020-02-26T20:29:56.004Z,1582748996.004 [DataOverHttps] Loaded
2020-02-26T20:29:56.004Z,1582748996.004 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2020-02-26T20:29:56.005Z,1582748996.005 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 408B14E0
2020-02-26T20:29:56.006Z,1582748996.006 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 1541
2020-02-26T20:29:56.019Z,1582748996.019 [Depth_Keller] Loaded
2020-02-26T20:29:56.019Z,1582748996.019 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2020-02-26T20:29:56.024Z,1582748996.024 [DropWeight] Loaded
2020-02-26T20:29:56.024Z,1582748996.024 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2020-02-26T20:29:56.120Z,1582748996.120 [NAL9602] Loaded
2020-02-26T20:29:56.120Z,1582748996.120 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2020-02-26T20:29:56.136Z,1582748996.136 [Onboard] Loaded
2020-02-26T20:29:56.136Z,1582748996.136 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2020-02-26T20:29:56.139Z,1582748996.139 [Radio_Surface] Loaded
2020-02-26T20:29:56.139Z,1582748996.139 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2020-02-26T20:29:56.140Z,1582748996.140 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 408E14E0
2020-02-26T20:29:56.141Z,1582748996.141 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 1542
2020-02-26T20:29:56.263Z,1582748996.263 [DAT] Loaded
2020-02-26T20:29:56.263Z,1582748996.263 [ComponentRegistry](DEBUG): SyncComponent "DAT" handled in the control thread.
2020-02-26T20:29:57.732Z,1582748997.732 [BPC1] Loaded
2020-02-26T20:29:57.732Z,1582748997.732 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2020-02-26T20:29:57.733Z,1582748997.733 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2020-02-26T20:29:57.733Z,1582748997.733 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2020-02-26T20:29:57.832Z,1582748997.832 [DeadReckonUsingMultipleVelocitySources] Loaded
2020-02-26T20:29:57.833Z,1582748997.833 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2020-02-26T20:29:57.853Z,1582748997.853 [NavChart] Loaded
2020-02-26T20:29:57.854Z,1582748997.854 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2020-02-26T20:29:57.858Z,1582748997.858 [UniversalFixResidualReporter] Loaded
2020-02-26T20:29:57.858Z,1582748997.858 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2020-02-26T20:29:57.858Z,1582748997.858 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2020-02-26T20:29:57.859Z,1582748997.859 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2020-02-26T20:29:57.989Z,1582748997.989 [SBIT](DEBUG): Construct Startup Built In Test.
2020-02-26T20:29:57.000Z,1582748998.000 [SBIT] Loaded
2020-02-26T20:29:58.000Z,1582748998.000 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2020-02-26T20:29:58.001Z,1582748998.001 [IBIT](DEBUG): Construct Initiated Built In Test.
2020-02-26T20:29:58.013Z,1582748998.013 [IBIT] Loaded
2020-02-26T20:29:58.014Z,1582748998.014 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2020-02-26T20:29:58.017Z,1582748998.017 [CBIT](DEBUG): Construct Continuous Built In Test.
2020-02-26T20:29:58.153Z,1582748998.153 [CBIT] Loaded
2020-02-26T20:29:58.153Z,1582748998.153 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2020-02-26T20:29:58.154Z,1582748998.154 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2020-02-26T20:29:58.154Z,1582748998.154 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2020-02-26T20:29:58.256Z,1582748998.256 [BuoyancyServo] Loaded
2020-02-26T20:29:58.256Z,1582748998.256 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2020-02-26T20:29:58.268Z,1582748998.268 [ElevatorServo] Loaded
2020-02-26T20:29:58.268Z,1582748998.268 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2020-02-26T20:29:58.279Z,1582748998.279 [MassServo] Loaded
2020-02-26T20:29:58.279Z,1582748998.279 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2020-02-26T20:29:58.290Z,1582748998.290 [RudderServo] Loaded
2020-02-26T20:29:58.291Z,1582748998.291 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2020-02-26T20:29:58.301Z,1582748998.301 [ThrusterServo] Loaded
2020-02-26T20:29:58.301Z,1582748998.301 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2020-02-26T20:29:58.302Z,1582748998.302 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2020-02-26T20:29:58.302Z,1582748998.302 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2020-02-26T20:29:58.315Z,1582748998.315 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2020-02-26T20:29:58.316Z,1582748998.316 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2020-02-26T20:29:58.523Z,1582748998.523 [BackSeatDriver] Loaded
2020-02-26T20:29:58.523Z,1582748998.523 [ComponentRegistry](DEBUG): Component "BackSeatDriver" handled in its own thread.
2020-02-26T20:29:58.524Z,1582748998.524 [BackSeatDriver ThreadHandler](DEBUG): Created PCaller Thread at 40A654E0
2020-02-26T20:29:58.524Z,1582748998.524 [BackSeatDriver ThreadHandler](INFO): Protected caller Thread ID is 1543
2020-02-26T20:29:58.534Z,1582748998.534 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_density
2020-02-26T20:29:58.539Z,1582748998.539 [CTD_Seabird](INFO): created writer for : sea_water_density
2020-02-26T20:29:58.539Z,1582748998.539 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): depth
2020-02-26T20:29:58.544Z,1582748998.544 [CTD_Seabird](INFO): created writer for : depth
2020-02-26T20:29:58.544Z,1582748998.544 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_pressure
2020-02-26T20:29:58.549Z,1582748998.549 [CTD_Seabird](INFO): created writer for : sea_water_pressure
2020-02-26T20:29:58.550Z,1582748998.550 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_salinity
2020-02-26T20:29:58.555Z,1582748998.555 [CTD_Seabird](INFO): created writer for : sea_water_salinity
2020-02-26T20:29:58.555Z,1582748998.555 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_temperature
2020-02-26T20:29:58.560Z,1582748998.560 [CTD_Seabird](INFO): created writer for : sea_water_temperature
2020-02-26T20:29:58.561Z,1582748998.561 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_electrical_conductivity
2020-02-26T20:29:58.566Z,1582748998.566 [CTD_Seabird](INFO): created writer for : sea_water_electrical_conductivity
2020-02-26T20:29:58.567Z,1582748998.567 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): speed_of_sound_in_sea_water
2020-02-26T20:29:58.572Z,1582748998.572 [CTD_Seabird](INFO): created writer for : speed_of_sound_in_sea_water
2020-02-26T20:29:58.599Z,1582748998.599 [CTD_Seabird] Loaded
2020-02-26T20:29:58.599Z,1582748998.599 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2020-02-26T20:29:58.601Z,1582748998.601 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40A954E0
2020-02-26T20:29:58.601Z,1582748998.601 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 1544
2020-02-26T20:29:58.631Z,1582748998.631 [ESPComponent] Loaded
2020-02-26T20:29:58.631Z,1582748998.631 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread.
2020-02-26T20:29:58.637Z,1582748998.637 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.Output470
2020-02-26T20:29:58.637Z,1582748998.637 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: Output470
2020-02-26T20:29:58.642Z,1582748998.642 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.Output650
2020-02-26T20:29:58.642Z,1582748998.642 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: Output650
2020-02-26T20:29:58.646Z,1582748998.646 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.OutputChl
2020-02-26T20:29:58.646Z,1582748998.646 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: OutputChl
2020-02-26T20:29:58.650Z,1582748998.650 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.VolumeScatCoeff117deg470nm
2020-02-26T20:29:58.651Z,1582748998.651 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: VolumeScatCoeff117deg470nm
2020-02-26T20:29:58.655Z,1582748998.655 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.VolumeScatCoeff117deg650nm
2020-02-26T20:29:58.655Z,1582748998.655 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: VolumeScatCoeff117deg650nm
2020-02-26T20:29:58.659Z,1582748998.659 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.BackscatteringCoeff470nm
2020-02-26T20:29:58.659Z,1582748998.659 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: BackscatteringCoeff470nm
2020-02-26T20:29:58.663Z,1582748998.663 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.BackscatteringCoeff650nm
2020-02-26T20:29:58.664Z,1582748998.664 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: BackscatteringCoeff650nm
2020-02-26T20:29:58.668Z,1582748998.668 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): mass_concentration_of_chlorophyll_in_sea_water
2020-02-26T20:29:58.672Z,1582748998.672 [WetLabsBB2FL](INFO): created writer for : mass_concentration_of_chlorophyll_in_sea_water
2020-02-26T20:29:58.673Z,1582748998.673 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_median_mass_concentration_of_chlorophyll_in_sea_water
2020-02-26T20:29:58.673Z,1582748998.673 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_median_mass_concentration_of_chlorophyll_in_sea_water
2020-02-26T20:29:58.677Z,1582748998.677 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_mean_mass_concentration_of_chlorophyll_in_sea_water
2020-02-26T20:29:58.677Z,1582748998.677 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_mean_mass_concentration_of_chlorophyll_in_sea_water
2020-02-26T20:29:58.681Z,1582748998.681 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_variance_mass_concentration_of_chlorophyll_in_sea_water
2020-02-26T20:29:58.681Z,1582748998.681 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_variance_mass_concentration_of_chlorophyll_in_sea_water
2020-02-26T20:29:58.686Z,1582748998.686 [WetLabsBB2FL] Loaded
2020-02-26T20:29:58.686Z,1582748998.686 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2020-02-26T20:29:58.687Z,1582748998.687 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40AC54E0
2020-02-26T20:29:58.687Z,1582748998.687 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 1545
2020-02-26T20:29:58.703Z,1582748998.703 [WetLabsUBAT..SerialDriver](INFO): Created logger
2020-02-26T20:29:58.704Z,1582748998.704 [WetLabsUBAT..SerialDriver](INFO): publishing on LCM channel WetLabsUBAT
2020-02-26T20:29:58.704Z,1582748998.704 [WetLabsUBAT..StreamSerialDriver](INFO): Created logger
2020-02-26T20:29:58.709Z,1582748998.709 [WetLabsUBAT](INFO): readConfig(): serialNo_: UBAT0051, uartName_: /dev/ttyC1, optionalArgs_: -ldir /mnt/mmc/LRAUV/Logs/latest
2020-02-26T20:29:58.709Z,1582748998.709 [WetLabsUBAT](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsUBAT.biolum_potential
2020-02-26T20:29:58.709Z,1582748998.709 [WetLabsUBAT](DEBUG): LcmSlateWriter::add(): dataName: biolum_potential
2020-02-26T20:29:58.714Z,1582748998.714 [WetLabsUBAT](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsUBAT.flow_rate
2020-02-26T20:29:58.714Z,1582748998.714 [WetLabsUBAT](DEBUG): LcmSlateWriter::add(): dataName: flow_rate
2020-02-26T20:29:58.718Z,1582748998.718 [WetLabsUBAT] Loaded
2020-02-26T20:29:58.719Z,1582748998.719 [ComponentRegistry](DEBUG): Component "WetLabsUBAT" handled in its own thread.
2020-02-26T20:29:58.720Z,1582748998.720 [WetLabsUBAT ThreadHandler](DEBUG): Created PCaller Thread at 40AF54E0
2020-02-26T20:29:58.720Z,1582748998.720 [WetLabsUBAT ThreadHandler](INFO): Protected caller Thread ID is 1546
2020-02-26T20:29:58.720Z,1582748998.720 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2020-02-26T20:29:58.741Z,1582748998.741 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2020-02-26T20:29:58.742Z,1582748998.742 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2020-02-26T20:29:58.748Z,1582748998.748 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2020-02-26T20:29:58.774Z,1582748998.774 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40B254E0
2020-02-26T20:29:58.775Z,1582748998.775 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 1547
2020-02-26T20:29:58.793Z,1582748998.793 [Supervisor](INFO): Main Thread ID is 804
2020-02-26T20:29:58.793Z,1582748998.793 [Supervisor](DEBUG): Running supervisor.
2020-02-26T20:29:58.794Z,1582748998.794 [CommandLine ThreadHandler](INFO): Handler Thread ID is 1548
2020-02-26T20:29:58.813Z,1582748998.813 [controlThread ThreadHandler](INFO): Handler Thread ID is 1549
2020-02-26T20:29:58.814Z,1582748998.814 [controlThread](DEBUG): Initializing ControlThread
2020-02-26T20:29:58.815Z,1582748998.815 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2020-02-26T20:29:58.816Z,1582748998.816 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2020-02-26T20:29:58.817Z,1582748998.817 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2020-02-26T20:29:58.818Z,1582748998.818 [LoopControl](DEBUG): Initialize LoopControlComponent.
2020-02-26T20:29:58.818Z,1582748998.818 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2020-02-26T20:29:58.818Z,1582748998.818 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2020-02-26T20:29:58.818Z,1582748998.818 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2020-02-26T20:29:58.819Z,1582748998.819 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2020-02-26T20:29:58.819Z,1582748998.819 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2020-02-26T20:29:58.820Z,1582748998.820 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2020-02-26T20:29:58.828Z,1582748998.828 [NavChart](DEBUG): Initialize NavChart Navigation.
2020-02-26T20:29:58.828Z,1582748998.828 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2020-02-26T20:29:58.828Z,1582748998.828 [SBIT](INFO): Initialize SBIT Component.
2020-02-26T20:29:58.829Z,1582748998.829 [SBIT](IMPORTANT): git: 2020-01-30-5-g8936940
2020-02-26T20:29:58.829Z,1582748998.829 [SBIT](INFO): git hash: 89369400977e1b78137104c631ef72a2c0222586
2020-02-26T20:29:58.829Z,1582748998.829 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2020-02-26T20:29:58.830Z,1582748998.830 [SBIT](IMPORTANT): Kernel Version:#1 PREEMPT Thu Feb 21 11:17:40 PST 2019
2020-02-26T20:29:58.831Z,1582748998.831 [SBIT](INFO): Beginning SBIT in 39.000000 seconds.
2020-02-26T20:29:58.831Z,1582748998.831 [IBIT](INFO): Initialize IBIT Component.
2020-02-26T20:29:58.832Z,1582748998.832 [CBIT](DEBUG): Initialize CBIT Component.
2020-02-26T20:29:58.845Z,1582748998.845 [CBIT](DEBUG): Initialized mux pins.
2020-02-26T20:29:58.845Z,1582748998.845 [CBIT](DEBUG): Initializing the watchdog timer.
2020-02-26T20:29:58.855Z,1582748998.855 [logger ThreadHandler](INFO): Handler Thread ID is 1550
2020-02-26T20:29:58.865Z,1582748998.865 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 1551
2020-02-26T20:29:58.867Z,1582748998.867 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2020-02-26T20:29:58.869Z,1582748998.869 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2020-02-26T20:29:58.869Z,1582748998.869 [CBIT](DEBUG): Initializing heartbeat.
2020-02-26T20:29:58.873Z,1582748998.873 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 1552
2020-02-26T20:29:58.875Z,1582748998.875 [BackSeatDriver ThreadHandler](INFO): Handler Thread ID is 1553
2020-02-26T20:29:58.876Z,1582748998.876 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 1554
2020-02-26T20:29:58.877Z,1582748998.877 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2020-02-26T20:29:58.885Z,1582748998.885 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 1556
2020-02-26T20:29:58.886Z,1582748998.886 [WetLabsBB2FL](INFO): Powering down
2020-02-26T20:29:58.909Z,1582748998.909 [WetLabsUBAT ThreadHandler](INFO): Handler Thread ID is 1557
2020-02-26T20:29:58.923Z,1582748998.923 [CTD_Seabird](INFO): Opening uart, block timeout 10ths=20
2020-02-26T20:29:58.924Z,1582748998.924 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 1558
2020-02-26T20:29:58.936Z,1582748998.936 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2020-02-26T20:29:58.936Z,1582748998.936 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2020-02-26T20:29:58.936Z,1582748998.936 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2020-02-26T20:29:58.936Z,1582748998.936 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2020-02-26T20:29:58.936Z,1582748998.936 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2020-02-26T20:29:58.937Z,1582748998.937 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2020-02-26T20:29:58.937Z,1582748998.937 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2020-02-26T20:29:58.937Z,1582748998.937 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2020-02-26T20:29:58.938Z,1582748998.938 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2020-02-26T20:29:58.938Z,1582748998.938 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2020-02-26T20:29:58.938Z,1582748998.938 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2020-02-26T20:29:58.938Z,1582748998.938 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2020-02-26T20:29:58.938Z,1582748998.938 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2020-02-26T20:29:58.939Z,1582748998.939 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2020-02-26T20:29:58.939Z,1582748998.939 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2020-02-26T20:29:58.939Z,1582748998.939 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2020-02-26T20:29:58.941Z,1582748998.941 [CBIT](DEBUG): Deactivating GF circuits.
2020-02-26T20:29:58.941Z,1582748998.941 [CBIT](DEBUG): Deactivating emergency mode.
2020-02-26T20:29:58.977Z,1582748998.977 [CBIT](DEBUG): Backplane powered.
2020-02-26T20:29:58.979Z,1582748998.979 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2020-02-26T20:29:58.989Z,1582748998.989 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2020-02-26T20:29:58.999Z,1582748998.999 [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-26T20:29:59.000Z,1582748999.000 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2020-02-26T20:29:59.104Z,1582748999.104 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2020-02-26T20:29:59.106Z,1582748999.106 [Default:A.Wait](DEBUG): Construct Wait.
2020-02-26T20:29:59.107Z,1582748999.107 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2020-02-26T20:29:59.154Z,1582748999.154 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2020-02-26T20:29:59.156Z,1582748999.156 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2020-02-26T20:29:59.178Z,1582748999.178 [Default:E.Execute](DEBUG): Construct Execute.
2020-02-26T20:29:59.181Z,1582748999.181 [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-26T20:29:59.193Z,1582748999.193 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,Depth_Keller,DropWeight,NAL9602,Onboard,DAT,BPC1,ESPComponent,Depth_Keller,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-26T20:29:59.205Z,1582748999.205 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2020-02-26T20:29:59.266Z,1582748999.266 [Depth_Keller](ERROR): Pressure reading out of range: 1650.297119 decibar
2020-02-26T20:29:59.277Z,1582748999.277 [Radio_Surface](INFO): Powering up
2020-02-26T20:29:59.309Z,1582748999.309 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2
2020-02-26T20:29:59.309Z,1582748999.309 [DAT](INFO): Powering up
2020-02-26T20:29:59.309Z,1582748999.309 [DAT](DEBUG): Initializing DAT.
2020-02-26T20:29:59.357Z,1582748999.357 [DepthRateCalculator](ERROR): Depth measurement is not active
2020-02-26T20:29:59.374Z,1582748999.374 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2020-02-26T20:29:59.381Z,1582748999.381 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2020-02-26T20:29:59.382Z,1582748999.382 [ElevatorServo](DEBUG): Initializing EZServoServo.
2020-02-26T20:29:59.389Z,1582748999.389 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2020-02-26T20:29:59.390Z,1582748999.390 [MassServo](DEBUG): Initializing EZServoServo.
2020-02-26T20:29:59.393Z,1582748999.393 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2
2020-02-26T20:29:59.421Z,1582748999.421 [MassServo](DEBUG): Initializing MassServo.
2020-02-26T20:29:59.422Z,1582748999.422 [RudderServo](DEBUG): Initializing EZServoServo.
2020-02-26T20:29:59.433Z,1582748999.433 [RudderServo](DEBUG): Initializing RudderServo.
2020-02-26T20:29:59.434Z,1582748999.434 [ThrusterServo](DEBUG): Initializing EZServoServo.
2020-02-26T20:29:59.449Z,1582748999.449 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2020-02-26T20:29:59.645Z,1582748999.645 [DepthRateCalculator](ERROR): Depth measurement is not active
2020-02-26T20:30:00.349Z,1582749000.349 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2020-02-26T20:30:00.349Z,1582749000.349 [RudderServo](FAULT): Rudder failed to initialize
2020-02-26T20:30:00.349Z,1582749000.349 [RudderServo] Communications Fault, FailCount= 1
2020-02-26T20:30:00.349Z,1582749000.349 [RudderServo](ERROR): Communications Fault
2020-02-26T20:30:00.460Z,1582749000.460 [CBIT](ERROR): Communications Fault in component: RudderServo
2020-02-26T20:30:00.638Z,1582749000.638 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2020-02-26T20:30:00.638Z,1582749000.638 [RudderServo](INFO): Powering down
2020-02-26T20:30:01.305Z,1582749001.305 [RudderServo](DEBUG): Initializing EZServoServo.
2020-02-26T20:30:01.426Z,1582749001.426 [RudderServo](DEBUG): Initializing RudderServo.
2020-02-26T20:30:01.430Z,1582749001.430 [CBIT](INFO): Clearing failed state for component RudderServo
2020-02-26T20:30:01.430Z,1582749001.430 [RudderServo] No Fault, FailCount= 1
2020-02-26T20:30:06.914Z,1582749006.914 [CTD_Seabird](ERROR): Device message queue exceeded the allowed limit.
2020-02-26T20:30:11.805Z,1582749011.805 [DAT](INFO): Got CONNECT
2020-02-26T20:30:11.817Z,1582749011.817 [DAT](INFO): entering command mode
2020-02-26T20:30:13.014Z,1582749013.014 [DAT](INFO): command mode acknowledged
2020-02-26T20:30:13.417Z,1582749013.417 [DAT](INFO): setting local address to 9
2020-02-26T20:30:13.821Z,1582749013.821 [DAT](INFO): set local address to 9
2020-02-26T20:30:26.326Z,1582749026.326 [NAL9602](INFO): Powering up NAL9602
2020-02-26T20:30:37.235Z,1582749037.235 [NAL9602](INFO): NAL9602 initialized
2020-02-26T20:30:38.495Z,1582749038.495 [SBIT](IMPORTANT): Beginning Startup BIT
2020-02-26T20:30:38.504Z,1582749038.504 [CBIT](IMPORTANT): Beginning ground fault scan
2020-02-26T20:30:49.552Z,1582749049.552 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.011959
CHAN A1 (24V): 0.071268
CHAN A2 (12V): -0.007465
CHAN A3 (5V): -0.002398
CHAN B0 (3.3V): 0.000164
CHAN B1 (3.15aV): -0.000128
CHAN B2 (3.15bV): 0.000158
CHAN B3 (GND): 0.002063
OPEN: 0.005149
Full Scale Calc: 4.765 mA, -1.589 mA
2020-02-26T20:31:31.882Z,1582749091.882 [SBIT](IMPORTANT): SBIT PASSED
2020-02-26T20:31:31.882Z,1582749091.882 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2020-02-26T20:31:31.883Z,1582749091.883 [SBIT](IMPORTANT): BR_Ping1D.loadAtStartup=0 bool;

2020-02-26T20:31:31.883Z,1582749091.883 [SBIT](IMPORTANT): CBIT.gf24Offset=143 microampere;

2020-02-26T20:31:31.883Z,1582749091.883 [SBIT](IMPORTANT): DAT.sbdAddress=-1 enum;

2020-02-26T20:31:31.883Z,1582749091.883 [SBIT](IMPORTANT): DAT.transponderAddress=4 enum;

2020-02-26T20:31:31.883Z,1582749091.883 [SBIT](IMPORTANT): DAT.verbosity=3 count;

2020-02-26T20:31:31.883Z,1582749091.883 [SBIT](IMPORTANT): ESPComponent.loadAtStartup=1 bool;

2020-02-26T20:31:31.883Z,1582749091.883 [SBIT](IMPORTANT): ESPComponent.sampleTimeout=5 minute;

2020-02-26T20:31:31.884Z,1582749091.884 [SBIT](IMPORTANT): ESPComponent.simulateHardware=1 bool;

2020-02-26T20:31:31.884Z,1582749091.884 [SBIT](IMPORTANT): Express linearApproximation CTD_Seabird.bin_median_sea_water_temperature 0.025000 kelvin;

2020-02-26T20:31:31.884Z,1582749091.884 [SBIT](IMPORTANT): Express linearApproximation WetLabsUBAT.flow_rate 50.000000 liter_per_second;

2020-02-26T20:31:31.884Z,1582749091.884 [SBIT](IMPORTANT): Express linearApproximation acoustic_contact_range 15.000000 meter;

2020-02-26T20:31:31.884Z,1582749091.884 [SBIT](IMPORTANT): Express linearApproximation height_above_sea_floor 5.000000 meter;

2020-02-26T20:31:31.884Z,1582749091.884 [SBIT](IMPORTANT): IBIT.batteryCapacityThreshold=5 ampere_hour;

2020-02-26T20:31:31.884Z,1582749091.884 [SBIT](IMPORTANT): IBIT.batteryVoltageThreshold=13 volt;

2020-02-26T20:31:31.884Z,1582749091.884 [SBIT](IMPORTANT): RDI_Pathfinder.loadAtStartup=0 bool;

2020-02-26T20:31:31.884Z,1582749091.884 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=225 cubic_centimeter;

2020-02-26T20:31:31.885Z,1582749091.885 [SBIT](IMPORTANT): VerticalControl.massDefault=5 millimeter;

2020-02-26T20:31:31.885Z,1582749091.885 [SBIT](IMPORTANT): WetLabsUBAT.loadAtStartup=1 bool;

2020-02-26T20:31:32.222Z,1582749092.222 [MissionManager](IMPORTANT): Started mission Startup
2020-02-26T20:31:32.223Z,1582749092.223 [Startup] Running Loop=1
2020-02-26T20:31:32.223Z,1582749092.223 [Startup](DEBUG): Aggregate::initialize Startup
2020-02-26T20:31:32.223Z,1582749092.223 [Startup:A.GoToSurface] Running Loop=1
2020-02-26T20:31:32.223Z,1582749092.223 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2020-02-26T20:31:32.224Z,1582749092.224 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2020-02-26T20:31:32.224Z,1582749092.224 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2020-02-26T20:31:32.225Z,1582749092.225 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2020-02-26T20:31:32.225Z,1582749092.225 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2020-02-26T20:31:32.226Z,1582749092.226 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2020-02-26T20:31:32.227Z,1582749092.227 [Startup:StartupSatComms] Running Loop=1
2020-02-26T20:31:32.227Z,1582749092.227 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2020-02-26T20:31:32.227Z,1582749092.227 [Startup:StartupSatComms:A] Running Loop=1
2020-02-26T20:31:32.612Z,1582749092.612 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2020-02-26T20:32:32.405Z,1582749152.405 [Startup:StartupSatComms:A](INFO): Timed out from 2020-02-26T20:31:32.2Z
2020-02-26T20:32:32.405Z,1582749152.405 [Startup:StartupSatComms:A] Stopped
2020-02-26T20:32:32.406Z,1582749152.406 [Startup:StartupSatComms:B] Running Loop=1
2020-02-26T20:32:32.812Z,1582749152.812 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2020-02-26T20:32:59.070Z,1582749179.070 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2020-02-26T20:32:59.070Z,1582749179.070 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-02-26T20:32:59.141Z,1582749179.141 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-02-26T20:32:59.557Z,1582749179.557 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-02-26T20:32:59.557Z,1582749179.557 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2020-02-26T20:33:08.740Z,1582749188.740 [NAL9602](INFO): SBD MO Status=0, MOMSN=6601, MT Status=0, MTMSN=0
2020-02-26T20:33:08.740Z,1582749188.740 [NAL9602](INFO): No messages in MT queue
2020-02-26T20:33:09.958Z,1582749189.958 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,202149.00,A,3648.16867,N,12147.28217,W,0.292,182.75,260220,,,A*7C
2020-02-26T20:33:09.962Z,1582749189.962 [NAL9602](INFO): GPS fix at 20200226T202149: (36.802811, -121.788036)
2020-02-26T20:33:23.472Z,1582749203.472 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.020969
2020-02-26T20:33:29.971Z,1582749209.971 [NAL9602](INFO): SBD MO Status=1, MOMSN=6602, MT Status=0, MTMSN=0
2020-02-26T20:33:30.045Z,1582749210.045 [NAL9602](INFO): Sent 25 bytes from file Logs/20200226T192559/Courier0034.lzma
2020-02-26T20:33:30.045Z,1582749210.045 [NAL9602](INFO): Packets left to send: 0
2020-02-26T20:33:30.130Z,1582749210.130 [Startup:StartupSatComms:B] Stopped
2020-02-26T20:33:30.130Z,1582749210.130 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2020-02-26T20:33:30.130Z,1582749210.130 [Startup:StartupSatComms] Stopped
2020-02-26T20:33:30.130Z,1582749210.130 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2020-02-26T20:33:30.131Z,1582749210.131 [Startup](INFO): Completed Startup
2020-02-26T20:33:30.131Z,1582749210.131 [MissionManager](INFO): Startup is completed.
2020-02-26T20:33:30.131Z,1582749210.131 [MissionManager](INFO): Uninitializing Mission Startup
2020-02-26T20:33:30.132Z,1582749210.132 [Startup] Stopped
2020-02-26T20:33:30.132Z,1582749210.132 [Startup](DEBUG): Aggregate::uninitialize Startup
2020-02-26T20:33:30.132Z,1582749210.132 [Startup:A.GoToSurface] Stopped
2020-02-26T20:33:30.132Z,1582749210.132 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2020-02-26T20:33:30.468Z,1582749210.468 [MissionManager](IMPORTANT): Started mission Default
2020-02-26T20:33:30.468Z,1582749210.468 [Default] Running Loop=1
2020-02-26T20:33:30.468Z,1582749210.468 [Default](DEBUG): Aggregate::initialize Default
2020-02-26T20:33:30.468Z,1582749210.468 [Default:B.GoToSurface] Running Loop=1
2020-02-26T20:33:30.468Z,1582749210.468 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2020-02-26T20:33:30.477Z,1582749210.477 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2020-02-26T20:33:30.477Z,1582749210.477 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2020-02-26T20:33:30.478Z,1582749210.478 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2020-02-26T20:33:30.478Z,1582749210.478 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2020-02-26T20:33:30.478Z,1582749210.478 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2020-02-26T20:33:30.478Z,1582749210.478 [Default:A.Wait] Running Loop=1
2020-02-26T20:33:30.478Z,1582749210.478 [Default:A.Wait](DEBUG): Initialize Wait Component.
2020-02-26T20:33:37.711Z,1582749217.711 [DataOverHttps](IMPORTANT): Could not stat file Logs/20200226T192559/Courier0034.lzma
2020-02-26T20:33:37.711Z,1582749217.711 [DataOverHttps](CRITICAL): Could not open file Logs/20200226T192559/Courier0034.lzma
2020-02-26T20:33:37.830Z,1582749217.830 [CommandLine](FAULT): Scheduling is paused
2020-02-26T20:33:37.831Z,1582749217.831 [CBIT](INFO): Critical error at 20200226T203337
2020-02-26T20:33:37.831Z,1582749217.831 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2020-02-26T20:33:43.839Z,1582749223.839 [Default:A.Wait](INFO): Done Waiting.
2020-02-26T20:33:43.839Z,1582749223.839 [Default:A.Wait] Stopped
2020-02-26T20:33:43.839Z,1582749223.839 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2020-02-26T20:33:44.184Z,1582749224.184 [Default:CheckIn] Running Loop=1
2020-02-26T20:33:44.184Z,1582749224.184 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-02-26T20:33:44.184Z,1582749224.184 [Default:CheckIn:Read_GPS] Running Loop=1
2020-02-26T20:33:44.624Z,1582749224.624 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2020-02-26T20:33:46.172Z,1582749226.172 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,202225.00,A,3648.16335,N,12147.28436,W,1.166,182.75,260220,,,A*75
2020-02-26T20:33:46.178Z,1582749226.178 [NAL9602](INFO): GPS fix at 20200226T202225: (36.802723, -121.788073)
2020-02-26T20:33:46.231Z,1582749226.231 [Default:CheckIn:Read_GPS] Stopped
2020-02-26T20:33:46.232Z,1582749226.232 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-02-26T20:33:46.622Z,1582749226.622 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2020-02-26T20:33:48.592Z,1582749228.592 [DataOverHttps](INFO): Sending 292 bytes from file Logs/20200226T202949/Courier0004.lzma
2020-02-26T20:33:50.146Z,1582749230.146 [DataOverHttps](INFO): Moved sent file to Logs/20200226T202949/Courier0004.lzma.bak
2020-02-26T20:33:50.146Z,1582749230.146 [DataOverHttps](INFO): SBD MOMSN=12269302
2020-02-26T20:34:09.221Z,1582749249.221 [DataOverHttps](INFO): Sending 320 bytes from file Logs/20200226T192559/Express0035.lzma
2020-02-26T20:34:11.226Z,1582749251.226 [DataOverHttps](INFO): Moved sent file to Logs/20200226T192559/Express0035.lzma.bak
2020-02-26T20:34:11.227Z,1582749251.227 [DataOverHttps](INFO): SBD MOMSN=12269307
2020-02-26T20:34:18.632Z,1582749258.632 [NAL9602](INFO): Not Powering down - fast GPS
2020-02-26T20:34:31.188Z,1582749271.188 [DataOverHttps](INFO): Sending 1097 bytes from file Logs/20200226T202949/Express0001.lzma
2020-02-26T20:34:33.243Z,1582749273.243 [DataOverHttps](INFO): Moved sent file to Logs/20200226T202949/Express0001.lzma.bak
2020-02-26T20:34:33.243Z,1582749273.243 [DataOverHttps](INFO): SBD MOMSN=12269322
2020-02-26T20:34:53.462Z,1582749293.462 [DataOverHttps](INFO): Sending 329 bytes from file Logs/20200226T202949/Express0005.lzma
2020-02-26T20:34:55.458Z,1582749295.458 [DataOverHttps](INFO): Moved sent file to Logs/20200226T202949/Express0005.lzma.bak
2020-02-26T20:34:55.458Z,1582749295.458 [DataOverHttps](INFO): SBD MOMSN=12269354
2020-02-26T20:34:57.649Z,1582749297.649 [Default:CheckIn:Read_Iridium] Stopped
2020-02-26T20:34:57.650Z,1582749297.650 [Default:CheckIn:C.Wait] Running Loop=1
2020-02-26T20:34:57.650Z,1582749297.650 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-02-26T20:37:32.236Z,1582749452.236 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2020-02-26T20:37:32.333Z,1582749452.333 [BPC1](INFO): Received data from all battery sticks.
2020-02-26T20:39:58.120Z,1582749598.120 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-02-26T20:39:58.164Z,1582749598.164 [Default:CheckIn:C.Wait] Stopped
2020-02-26T20:39:58.164Z,1582749598.164 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-02-26T20:39:58.164Z,1582749598.164 [Default:CheckIn:D] Running Loop=1
2020-02-26T20:39:58.476Z,1582749598.476 [Default:CheckIn:D] Stopped
2020-02-26T20:39:58.476Z,1582749598.476 [Default:CheckIn:E] Running Loop=1
2020-02-26T20:39:58.876Z,1582749598.876 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 6.466794 min 
2020-02-26T20:39:58.876Z,1582749598.876 [Default:CheckIn:E] Stopped
2020-02-26T20:39:58.876Z,1582749598.876 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-02-26T20:39:58.876Z,1582749598.876 [Default:CheckIn] Stopped
2020-02-26T20:39:58.876Z,1582749598.876 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-02-26T20:39:58.876Z,1582749598.876 [Default:CheckIn](INFO): Running loop #2
2020-02-26T20:39:58.876Z,1582749598.876 [Default:CheckIn] Running Loop=2
2020-02-26T20:39:58.877Z,1582749598.877 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-02-26T20:39:58.877Z,1582749598.877 [Default:CheckIn:Read_GPS] Running Loop=1
2020-02-26T20:40:00.875Z,1582749600.875 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,202841.00,A,3648.17045,N,12147.27994,W,0.661,276.99,260220,,,A*79
2020-02-26T20:40:00.878Z,1582749600.878 [NAL9602](INFO): GPS fix at 20200226T202841: (36.802841, -121.787999)
2020-02-26T20:40:00.904Z,1582749600.904 [Default:CheckIn:Read_GPS] Stopped
2020-02-26T20:40:00.904Z,1582749600.904 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-02-26T20:40:02.821Z,1582749602.821 [DataOverHttps](INFO): Sending 222 bytes from file Logs/20200226T202949/Courier0007.lzma
2020-02-26T20:40:04.078Z,1582749604.078 [DataOverHttps](INFO): Moved sent file to Logs/20200226T202949/Courier0007.lzma.bak
2020-02-26T20:40:04.078Z,1582749604.078 [DataOverHttps](INFO): SBD MOMSN=12269378
2020-02-26T20:40:25.517Z,1582749625.517 [DataOverHttps](INFO): Sending 150 bytes from file Logs/20200226T202949/Express0008.lzma
2020-02-26T20:40:27.522Z,1582749627.522 [DataOverHttps](INFO): Moved sent file to Logs/20200226T202949/Express0008.lzma.bak
2020-02-26T20:40:27.522Z,1582749627.522 [DataOverHttps](INFO): SBD MOMSN=12269381
2020-02-26T20:40:29.699Z,1582749629.699 [Default:CheckIn:Read_Iridium] Stopped
2020-02-26T20:40:29.700Z,1582749629.700 [Default:CheckIn:C.Wait] Running Loop=1
2020-02-26T20:40:29.700Z,1582749629.700 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-02-26T20:41:44.760Z,1582749704.760 [NAL9602](INFO): SBD MO Status=2, MOMSN=6603, MT Status=2, MTMSN=0
2020-02-26T20:41:44.760Z,1582749704.760 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-02-26T20:42:00.513Z,1582749720.513 [NAL9602](INFO): SBD MO Status=2, MOMSN=6603, MT Status=2, MTMSN=0
2020-02-26T20:42:00.514Z,1582749720.514 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-02-26T20:42:51.821Z,1582749771.821 [NAL9602](INFO): SBD MO Status=2, MOMSN=6603, MT Status=2, MTMSN=0
2020-02-26T20:42:51.821Z,1582749771.821 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-02-26T20:43:35.461Z,1582749815.461 [NAL9602](INFO): SBD MO Status=2, MOMSN=6603, MT Status=2, MTMSN=0
2020-02-26T20:43:35.461Z,1582749815.461 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-02-26T20:44:05.775Z,1582749845.775 [NAL9602](INFO): SBD MO Status=2, MOMSN=6603, MT Status=2, MTMSN=0
2020-02-26T20:44:05.775Z,1582749845.775 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-02-26T20:44:19.511Z,1582749859.511 [NAL9602](INFO): SBD MO Status=2, MOMSN=6603, MT Status=2, MTMSN=0
2020-02-26T20:44:19.512Z,1582749859.512 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-02-26T20:45:04.359Z,1582749904.359 [NAL9602](INFO): SBD MO Status=2, MOMSN=6603, MT Status=2, MTMSN=0
2020-02-26T20:45:04.360Z,1582749904.360 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-02-26T20:45:04.758Z,1582749904.758 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2020-02-26T20:45:30.258Z,1582749930.258 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-02-26T20:45:30.258Z,1582749930.258 [Default:CheckIn:C.Wait] Stopped
2020-02-26T20:45:30.258Z,1582749930.258 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-02-26T20:45:30.259Z,1582749930.259 [Default:CheckIn:D] Running Loop=1
2020-02-26T20:45:30.656Z,1582749930.656 [Default:CheckIn:D] Stopped
2020-02-26T20:45:30.656Z,1582749930.656 [Default:CheckIn:E] Running Loop=1
2020-02-26T20:45:31.040Z,1582749931.040 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 12.003123 min 
2020-02-26T20:45:31.040Z,1582749931.040 [Default:CheckIn:E] Stopped
2020-02-26T20:45:31.040Z,1582749931.040 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-02-26T20:45:31.040Z,1582749931.040 [Default:CheckIn] Stopped
2020-02-26T20:45:31.040Z,1582749931.040 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-02-26T20:45:31.041Z,1582749931.041 [Default:CheckIn](INFO): Running loop #3
2020-02-26T20:45:31.041Z,1582749931.041 [Default:CheckIn] Running Loop=3
2020-02-26T20:45:31.041Z,1582749931.041 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-02-26T20:45:31.041Z,1582749931.041 [Default:CheckIn:Read_GPS] Running Loop=1
2020-02-26T20:45:33.039Z,1582749933.039 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,203413.00,A,3648.16560,N,12147.28114,W,0.019,276.99,260220,,,A*76
2020-02-26T20:45:33.041Z,1582749933.041 [NAL9602](INFO): GPS fix at 20200226T203413: (36.802760, -121.788019)
2020-02-26T20:45:33.065Z,1582749933.065 [Default:CheckIn:Read_GPS] Stopped
2020-02-26T20:45:33.065Z,1582749933.065 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-02-26T20:45:34.110Z,1582749934.110 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20200226T202949/Courier0010.lzma
2020-02-26T20:45:35.506Z,1582749935.506 [DataOverHttps](INFO): Moved sent file to Logs/20200226T202949/Courier0010.lzma.bak
2020-02-26T20:45:35.506Z,1582749935.506 [DataOverHttps](INFO): SBD MOMSN=12269384
2020-02-26T20:45:54.062Z,1582749954.062 [DataOverHttps](INFO): Sending 220 bytes from file Logs/20200226T202949/Express0011.lzma
2020-02-26T20:45:56.066Z,1582749956.066 [DataOverHttps](INFO): Moved sent file to Logs/20200226T202949/Express0011.lzma.bak
2020-02-26T20:45:56.066Z,1582749956.066 [DataOverHttps](INFO): SBD MOMSN=12269387
2020-02-26T20:45:57.840Z,1582749957.840 [Default:CheckIn:Read_Iridium] Stopped
2020-02-26T20:45:57.840Z,1582749957.840 [Default:CheckIn:C.Wait] Running Loop=1
2020-02-26T20:45:57.840Z,1582749957.840 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-02-26T20:46:05.478Z,1582749965.478 [NAL9602](INFO): Not Powering down - fast GPS
2020-02-26T20:50:58.419Z,1582750258.419 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-02-26T20:50:58.419Z,1582750258.419 [Default:CheckIn:C.Wait] Stopped
2020-02-26T20:50:58.419Z,1582750258.419 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-02-26T20:50:58.419Z,1582750258.419 [Default:CheckIn:D] Running Loop=1
2020-02-26T20:50:58.805Z,1582750258.805 [Default:CheckIn:D] Stopped
2020-02-26T20:50:58.805Z,1582750258.805 [Default:CheckIn:E] Running Loop=1
2020-02-26T20:50:59.241Z,1582750259.241 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 17.472276 min 
2020-02-26T20:50:59.241Z,1582750259.241 [Default:CheckIn:E] Stopped
2020-02-26T20:50:59.241Z,1582750259.241 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-02-26T20:50:59.241Z,1582750259.241 [Default:CheckIn] Stopped
2020-02-26T20:50:59.242Z,1582750259.242 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-02-26T20:50:59.242Z,1582750259.242 [Default:CheckIn](INFO): Running loop #4
2020-02-26T20:50:59.242Z,1582750259.242 [Default:CheckIn] Running Loop=4
2020-02-26T20:50:59.242Z,1582750259.242 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-02-26T20:50:59.242Z,1582750259.242 [Default:CheckIn:Read_GPS] Running Loop=1
2020-02-26T20:51:01.214Z,1582750261.214 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,203941.00,A,3648.16453,N,12147.28053,W,0.058,156.79,260220,,,A*75
2020-02-26T20:51:01.216Z,1582750261.216 [NAL9602](INFO): GPS fix at 20200226T203941: (36.802742, -121.788009)
2020-02-26T20:51:01.244Z,1582750261.244 [Default:CheckIn:Read_GPS] Stopped
2020-02-26T20:51:01.244Z,1582750261.244 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-02-26T20:51:10.812Z,1582750270.812 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20200226T202949/Courier0013.lzma
2020-02-26T20:51:12.819Z,1582750272.819 [DataOverHttps](INFO): Moved sent file to Logs/20200226T202949/Courier0013.lzma.bak
2020-02-26T20:51:12.819Z,1582750272.819 [DataOverHttps](INFO): SBD MOMSN=12269413
2020-02-26T20:51:35.559Z,1582750295.559 [NAL9602](INFO): SBD MO Status=2, MOMSN=6603, MT Status=2, MTMSN=0
2020-02-26T20:51:35.560Z,1582750295.560 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-02-26T20:51:36.401Z,1582750296.401 [DataOverHttps](INFO): Sending 119 bytes from file Logs/20200226T202949/Express0014.lzma
2020-02-26T20:51:38.407Z,1582750298.407 [DataOverHttps](INFO): Moved sent file to Logs/20200226T202949/Express0014.lzma.bak
2020-02-26T20:51:38.407Z,1582750298.407 [DataOverHttps](INFO): SBD MOMSN=12269416
2020-02-26T20:51:40.847Z,1582750300.847 [Default:CheckIn:Read_Iridium] Stopped
2020-02-26T20:51:40.848Z,1582750300.848 [Default:CheckIn:C.Wait] Running Loop=1
2020-02-26T20:51:40.848Z,1582750300.848 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-02-26T20:52:49.087Z,1582750369.087 [NAL9602](INFO): SBD MO Status=2, MOMSN=6603, MT Status=2, MTMSN=0
2020-02-26T20:52:49.088Z,1582750369.088 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-02-26T20:53:45.667Z,1582750425.667 [NAL9602](INFO): SBD MO Status=2, MOMSN=6603, MT Status=2, MTMSN=0
2020-02-26T20:53:45.667Z,1582750425.667 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-02-26T20:55:04.451Z,1582750504.451 [NAL9602](INFO): SBD MO Status=2, MOMSN=6603, MT Status=2, MTMSN=0
2020-02-26T20:55:04.451Z,1582750504.451 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-02-26T20:55:20.207Z,1582750520.207 [NAL9602](INFO): SBD MO Status=2, MOMSN=6603, MT Status=2, MTMSN=0
2020-02-26T20:55:20.207Z,1582750520.207 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-02-26T20:56:03.430Z,1582750563.430 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2020-02-26T20:56:34.146Z,1582750594.146 [NAL9602](INFO): Not Powering down - fast GPS
2020-02-26T20:56:41.435Z,1582750601.435 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-02-26T20:56:41.436Z,1582750601.436 [Default:CheckIn:C.Wait] Stopped
2020-02-26T20:56:41.436Z,1582750601.436 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-02-26T20:56:41.436Z,1582750601.436 [Default:CheckIn:D] Running Loop=1
2020-02-26T20:56:41.848Z,1582750601.848 [Default:CheckIn:D] Stopped
2020-02-26T20:56:41.848Z,1582750601.848 [Default:CheckIn:E] Running Loop=1
2020-02-26T20:56:42.240Z,1582750602.240 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 23.189657 min 
2020-02-26T20:56:42.240Z,1582750602.240 [Default:CheckIn:E] Stopped
2020-02-26T20:56:42.240Z,1582750602.240 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-02-26T20:56:42.240Z,1582750602.240 [Default:CheckIn] Stopped
2020-02-26T20:56:42.240Z,1582750602.240 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-02-26T20:56:42.245Z,1582750602.245 [Default:CheckIn](INFO): Running loop #5
2020-02-26T20:56:42.245Z,1582750602.245 [Default:CheckIn] Running Loop=5
2020-02-26T20:56:42.245Z,1582750602.245 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-02-26T20:56:42.245Z,1582750602.245 [Default:CheckIn:Read_GPS] Running Loop=1
2020-02-26T20:56:44.249Z,1582750604.249 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,204524.00,A,3648.16615,N,12147.28325,W,0.272,156.79,260220,,,A*75
2020-02-26T20:56:44.251Z,1582750604.251 [NAL9602](INFO): GPS fix at 20200226T204524: (36.802769, -121.788054)
2020-02-26T20:56:44.280Z,1582750604.280 [Default:CheckIn:Read_GPS] Stopped
2020-02-26T20:56:44.280Z,1582750604.280 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-02-26T20:56:53.420Z,1582750613.420 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20200226T202949/Courier0016.lzma
2020-02-26T20:56:55.426Z,1582750615.426 [DataOverHttps](INFO): Moved sent file to Logs/20200226T202949/Courier0016.lzma.bak
2020-02-26T20:56:55.426Z,1582750615.426 [DataOverHttps](INFO): SBD MOMSN=12269419
2020-02-26T20:57:13.149Z,1582750633.149 [DataOverHttps](INFO): Sending 195 bytes from file Logs/20200226T202949/Express0017.lzma
2020-02-26T20:57:14.942Z,1582750634.942 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2020-02-26T20:57:15.021Z,1582750635.021 [NAL9602](FAULT): received: 
+CSQ:0

OK03, 2, 0, 0, 0

OK
2020-02-26T20:57:15.021Z,1582750635.021 [NAL9602] Data Fault, FailCount= 1
2020-02-26T20:57:15.021Z,1582750635.021 [NAL9602](ERROR): Data Fault
2020-02-26T20:57:15.155Z,1582750635.155 [DataOverHttps](INFO): Moved sent file to Logs/20200226T202949/Express0017.lzma.bak
2020-02-26T20:57:15.155Z,1582750635.155 [DataOverHttps](INFO): SBD MOMSN=12269422
2020-02-26T20:57:15.163Z,1582750635.163 [CBIT](ERROR): Data Fault in component: NAL9602
2020-02-26T20:57:15.359Z,1582750635.359 [NAL9602](INFO): Powering down
2020-02-26T20:57:16.297Z,1582750636.297 [CBIT](INFO): Clearing failed state for component NAL9602
2020-02-26T20:57:16.297Z,1582750636.297 [NAL9602] No Fault, FailCount= 1
2020-02-26T20:57:16.996Z,1582750636.996 [Default:CheckIn:Read_Iridium] Stopped
2020-02-26T20:57:16.997Z,1582750636.997 [Default:CheckIn:C.Wait] Running Loop=1
2020-02-26T20:57:16.997Z,1582750636.997 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-02-26T20:57:45.651Z,1582750665.651 [NAL9602](INFO): Powering up NAL9602
2020-02-26T20:57:56.550Z,1582750676.550 [NAL9602](INFO): NAL9602 initialized
2020-02-26T20:58:27.655Z,1582750707.655 [NAL9602](INFO): Not Powering down - fast GPS
2020-02-26T21:02:17.580Z,1582750937.580 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-02-26T21:02:17.580Z,1582750937.580 [Default:CheckIn:C.Wait] Stopped
2020-02-26T21:02:17.580Z,1582750937.580 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-02-26T21:02:17.580Z,1582750937.580 [Default:CheckIn:D] Running Loop=1
2020-02-26T21:02:17.976Z,1582750937.976 [Default:CheckIn:D] Stopped
2020-02-26T21:02:17.976Z,1582750937.976 [Default:CheckIn:E] Running Loop=1
2020-02-26T21:02:18.376Z,1582750938.376 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 28.791797 min 
2020-02-26T21:02:18.376Z,1582750938.376 [Default:CheckIn:E] Stopped
2020-02-26T21:02:18.409Z,1582750938.409 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-02-26T21:02:18.409Z,1582750938.409 [Default:CheckIn] Stopped
2020-02-26T21:02:18.409Z,1582750938.409 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-02-26T21:02:18.410Z,1582750938.410 [Default:CheckIn](INFO): Running loop #6
2020-02-26T21:02:18.410Z,1582750938.410 [Default:CheckIn] Running Loop=6
2020-02-26T21:02:18.410Z,1582750938.410 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-02-26T21:02:18.410Z,1582750938.410 [Default:CheckIn:Read_GPS] Running Loop=1
2020-02-26T21:02:20.375Z,1582750940.375 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,205059.00,A,3648.16864,N,12147.28027,W,2.158,0.00,260220,,,A*77
2020-02-26T21:02:20.378Z,1582750940.378 [NAL9602](INFO): GPS fix at 20200226T205059: (36.802811, -121.788004)
2020-02-26T21:02:20.401Z,1582750940.401 [Default:CheckIn:Read_GPS] Stopped
2020-02-26T21:02:20.401Z,1582750940.401 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-02-26T21:02:22.390Z,1582750942.390 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2020-02-26T21:02:27.700Z,1582750947.700 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20200226T202949/Courier0019.lzma
2020-02-26T21:02:29.706Z,1582750949.706 [DataOverHttps](INFO): Moved sent file to Logs/20200226T202949/Courier0019.lzma.bak
2020-02-26T21:02:29.707Z,1582750949.707 [DataOverHttps](INFO): SBD MOMSN=12269454
2020-02-26T21:02:46.929Z,1582750966.929 [DataOverHttps](INFO): Sending 163 bytes from file Logs/20200226T202949/Express0020.lzma
2020-02-26T21:02:48.934Z,1582750968.934 [DataOverHttps](INFO): Moved sent file to Logs/20200226T202949/Express0020.lzma.bak
2020-02-26T21:02:48.934Z,1582750968.934 [DataOverHttps](INFO): SBD MOMSN=12269457
2020-02-26T21:02:50.699Z,1582750970.699 [Default:CheckIn:Read_Iridium] Stopped
2020-02-26T21:02:50.699Z,1582750970.699 [Default:CheckIn:C.Wait] Running Loop=1
2020-02-26T21:02:50.700Z,1582750970.700 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-02-26T21:02:53.094Z,1582750973.094 [NAL9602](INFO): Not Powering down - fast GPS
2020-02-26T21:07:51.316Z,1582751271.316 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-02-26T21:07:51.316Z,1582751271.316 [Default:CheckIn:C.Wait] Stopped
2020-02-26T21:07:51.316Z,1582751271.316 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-02-26T21:07:51.316Z,1582751271.316 [Default:CheckIn:D] Running Loop=1
2020-02-26T21:07:51.720Z,1582751271.720 [Default:CheckIn:D] Stopped
2020-02-26T21:07:51.720Z,1582751271.720 [Default:CheckIn:E] Running Loop=1
2020-02-26T21:07:52.127Z,1582751272.127 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 34.354195 min 
2020-02-26T21:07:52.127Z,1582751272.127 [Default:CheckIn:E] Stopped
2020-02-26T21:07:52.127Z,1582751272.127 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-02-26T21:07:52.127Z,1582751272.127 [Default:CheckIn] Stopped
2020-02-26T21:07:52.127Z,1582751272.127 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-02-26T21:07:52.127Z,1582751272.127 [Default:CheckIn](INFO): Running loop #7
2020-02-26T21:07:52.127Z,1582751272.127 [Default:CheckIn] Running Loop=7
2020-02-26T21:07:52.127Z,1582751272.127 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-02-26T21:07:52.127Z,1582751272.127 [Default:CheckIn:Read_GPS] Running Loop=1
2020-02-26T21:07:54.124Z,1582751274.124 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,205634.00,A,3648.16496,N,12147.28085,W,0.564,0.00,260220,,,A*7A
2020-02-26T21:07:54.126Z,1582751274.126 [NAL9602](INFO): GPS fix at 20200226T205634: (36.802749, -121.788014)
2020-02-26T21:07:54.181Z,1582751274.181 [Default:CheckIn:Read_GPS] Stopped
2020-02-26T21:07:54.181Z,1582751274.181 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-02-26T21:08:02.209Z,1582751282.209 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20200226T202949/Courier0022.lzma
2020-02-26T21:08:04.214Z,1582751284.214 [DataOverHttps](INFO): Moved sent file to Logs/20200226T202949/Courier0022.lzma.bak
2020-02-26T21:08:04.214Z,1582751284.214 [DataOverHttps](INFO): SBD MOMSN=12269461
2020-02-26T21:08:22.619Z,1582751302.619 [DataOverHttps](INFO): Sending 196 bytes from file Logs/20200226T202949/Express0023.lzma
2020-02-26T21:08:24.631Z,1582751304.631 [DataOverHttps](INFO): Moved sent file to Logs/20200226T202949/Express0023.lzma.bak
2020-02-26T21:08:24.631Z,1582751304.631 [DataOverHttps](INFO): SBD MOMSN=12269465
2020-02-26T21:08:26.475Z,1582751306.475 [Default:CheckIn:Read_Iridium] Stopped
2020-02-26T21:08:26.475Z,1582751306.475 [Default:CheckIn:C.Wait] Running Loop=1
2020-02-26T21:08:26.475Z,1582751306.475 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-02-26T21:10:17.959Z,1582751417.959 [NAL9602](INFO): SBD MO Status=2, MOMSN=6603, MT Status=2, MTMSN=0
2020-02-26T21:10:17.959Z,1582751417.959 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-02-26T21:11:52.091Z,1582751512.091 [NAL9602](INFO): SBD MO Status=2, MOMSN=6603, MT Status=2, MTMSN=0
2020-02-26T21:11:52.091Z,1582751512.091 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-02-26T21:12:56.320Z,1582751576.320 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2020-02-26T21:13:27.025Z,1582751607.025 [NAL9602](INFO): Not Powering down - fast GPS
2020-02-26T21:13:27.056Z,1582751607.056 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-02-26T21:13:27.056Z,1582751607.056 [Default:CheckIn:C.Wait] Stopped
2020-02-26T21:13:27.056Z,1582751607.056 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-02-26T21:13:27.056Z,1582751607.056 [Default:CheckIn:D] Running Loop=1
2020-02-26T21:13:27.463Z,1582751607.463 [Default:CheckIn:D] Stopped
2020-02-26T21:13:27.463Z,1582751607.463 [Default:CheckIn:E] Running Loop=1
2020-02-26T21:13:27.866Z,1582751607.866 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 39.949923 min 
2020-02-26T21:13:27.866Z,1582751607.866 [Default:CheckIn:E] Stopped
2020-02-26T21:13:27.866Z,1582751607.866 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-02-26T21:13:27.866Z,1582751607.866 [Default:CheckIn] Stopped
2020-02-26T21:13:27.866Z,1582751607.866 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-02-26T21:13:27.866Z,1582751607.866 [Default:CheckIn](INFO): Running loop #8
2020-02-26T21:13:27.866Z,1582751607.866 [Default:CheckIn] Running Loop=8
2020-02-26T21:13:27.867Z,1582751607.867 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-02-26T21:13:27.867Z,1582751607.867 [Default:CheckIn:Read_GPS] Running Loop=1
2020-02-26T21:13:29.860Z,1582751609.860 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,210210.00,A,3648.16640,N,12147.28070,W,0.292,149.51,260220,,,A*79
2020-02-26T21:13:29.862Z,1582751609.862 [NAL9602](INFO): GPS fix at 20200226T210210: (36.802773, -121.788012)
2020-02-26T21:13:29.915Z,1582751609.915 [Default:CheckIn:Read_GPS] Stopped
2020-02-26T21:13:29.915Z,1582751609.915 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-02-26T21:13:37.653Z,1582751617.653 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20200226T202949/Courier0025.lzma
2020-02-26T21:13:39.655Z,1582751619.655 [DataOverHttps](INFO): Moved sent file to Logs/20200226T202949/Courier0025.lzma.bak
2020-02-26T21:13:39.655Z,1582751619.655 [DataOverHttps](INFO): SBD MOMSN=12269490
2020-02-26T21:13:57.973Z,1582751637.973 [DataOverHttps](INFO): Sending 196 bytes from file Logs/20200226T202949/Express0026.lzma
2020-02-26T21:13:59.980Z,1582751639.980 [DataOverHttps](INFO): Moved sent file to Logs/20200226T202949/Express0026.lzma.bak
2020-02-26T21:13:59.980Z,1582751639.980 [DataOverHttps](INFO): SBD MOMSN=12269493
2020-02-26T21:14:00.566Z,1582751640.566 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2020-02-26T21:14:00.649Z,1582751640.649 [NAL9602](FAULT): received: 
+CSQ:0

OK03, 2, 0, 0, 0

OK
2020-02-26T21:14:00.649Z,1582751640.649 [NAL9602] Data Fault, FailCount= 1
2020-02-26T21:14:00.649Z,1582751640.649 [NAL9602](ERROR): Data Fault
2020-02-26T21:14:00.765Z,1582751640.765 [CBIT](ERROR): Data Fault in component: NAL9602
2020-02-26T21:14:00.960Z,1582751640.960 [NAL9602](INFO): Powering down
2020-02-26T21:14:01.812Z,1582751641.812 [Default:CheckIn:Read_Iridium] Stopped
2020-02-26T21:14:01.813Z,1582751641.813 [Default:CheckIn:C.Wait] Running Loop=1
2020-02-26T21:14:01.813Z,1582751641.813 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-02-26T21:14:01.885Z,1582751641.885 [CBIT](INFO): Clearing failed state for component NAL9602
2020-02-26T21:14:01.885Z,1582751641.885 [NAL9602] No Fault, FailCount= 1
2020-02-26T21:14:31.260Z,1582751671.260 [NAL9602](INFO): Powering up NAL9602
2020-02-26T21:14:42.170Z,1582751682.170 [NAL9602](INFO): NAL9602 initialized
2020-02-26T21:15:13.282Z,1582751713.282 [NAL9602](INFO): Not Powering down - fast GPS
2020-02-26T21:19:02.376Z,1582751942.376 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-02-26T21:19:02.376Z,1582751942.376 [Default:CheckIn:C.Wait] Stopped
2020-02-26T21:19:02.376Z,1582751942.376 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-02-26T21:19:02.376Z,1582751942.376 [Default:CheckIn:D] Running Loop=1
2020-02-26T21:19:02.792Z,1582751942.792 [Default:CheckIn:D] Stopped
2020-02-26T21:19:02.792Z,1582751942.792 [Default:CheckIn:E] Running Loop=1
2020-02-26T21:19:03.196Z,1582751943.196 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 45.538725 min 
2020-02-26T21:19:03.196Z,1582751943.196 [Default:CheckIn:E] Stopped
2020-02-26T21:19:03.196Z,1582751943.196 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-02-26T21:19:03.196Z,1582751943.196 [Default:CheckIn] Stopped
2020-02-26T21:19:03.196Z,1582751943.196 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-02-26T21:19:03.197Z,1582751943.197 [Default:CheckIn](INFO): Running loop #9
2020-02-26T21:19:03.197Z,1582751943.197 [Default:CheckIn] Running Loop=9
2020-02-26T21:19:03.197Z,1582751943.197 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-02-26T21:19:03.197Z,1582751943.197 [Default:CheckIn:Read_GPS] Running Loop=1
2020-02-26T21:19:07.210Z,1582751947.210 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2020-02-26T21:19:37.905Z,1582751977.905 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,210817.00,A,3648.15632,N,12147.27212,W,0.253,353.98,260220,,,A*7A
2020-02-26T21:19:37.908Z,1582751977.908 [NAL9602](INFO): GPS fix at 20200226T210817: (36.802605, -121.787869)
2020-02-26T21:19:37.956Z,1582751977.956 [Default:CheckIn:Read_GPS] Stopped
2020-02-26T21:19:37.956Z,1582751977.956 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-02-26T21:19:47.056Z,1582751987.056 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20200226T202949/Courier0028.lzma
2020-02-26T21:19:49.065Z,1582751989.065 [DataOverHttps](INFO): Moved sent file to Logs/20200226T202949/Courier0028.lzma.bak
2020-02-26T21:19:49.065Z,1582751989.065 [DataOverHttps](INFO): SBD MOMSN=12269501
2020-02-26T21:20:06.233Z,1582752006.233 [DataOverHttps](INFO): Sending 235 bytes from file Logs/20200226T202949/Express0029.lzma
2020-02-26T21:20:08.238Z,1582752008.238 [DataOverHttps](INFO): Moved sent file to Logs/20200226T202949/Express0029.lzma.bak
2020-02-26T21:20:08.239Z,1582752008.239 [DataOverHttps](INFO): SBD MOMSN=12269519
2020-02-26T21:20:09.968Z,1582752009.968 [Default:CheckIn:Read_Iridium] Stopped
2020-02-26T21:20:09.968Z,1582752009.968 [Default:CheckIn:C.Wait] Running Loop=1
2020-02-26T21:20:09.968Z,1582752009.968 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-02-26T21:20:10.357Z,1582752010.357 [NAL9602](INFO): Not Powering down - fast GPS
2020-02-26T21:25:10.556Z,1582752310.556 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-02-26T21:25:10.556Z,1582752310.556 [Default:CheckIn:C.Wait] Stopped
2020-02-26T21:25:10.556Z,1582752310.556 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-02-26T21:25:10.556Z,1582752310.556 [Default:CheckIn:D] Running Loop=1
2020-02-26T21:25:10.957Z,1582752310.957 [Default:CheckIn:D] Stopped
2020-02-26T21:25:10.957Z,1582752310.957 [Default:CheckIn:E] Running Loop=1
2020-02-26T21:25:11.372Z,1582752311.372 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 51.674809 min 
2020-02-26T21:25:11.372Z,1582752311.372 [Default:CheckIn:E] Stopped
2020-02-26T21:25:11.372Z,1582752311.372 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-02-26T21:25:11.372Z,1582752311.372 [Default:CheckIn] Stopped
2020-02-26T21:25:11.372Z,1582752311.372 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-02-26T21:25:11.373Z,1582752311.373 [Default:CheckIn](INFO): Running loop #10
2020-02-26T21:25:11.373Z,1582752311.373 [Default:CheckIn] Running Loop=10
2020-02-26T21:25:11.373Z,1582752311.373 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-02-26T21:25:11.373Z,1582752311.373 [Default:CheckIn:Read_GPS] Running Loop=1
2020-02-26T21:25:13.359Z,1582752313.359 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,211352.00,A,3648.16210,N,12147.28227,W,0.272,48.14,260220,,,A*41
2020-02-26T21:25:13.361Z,1582752313.361 [NAL9602](INFO): GPS fix at 20200226T211352: (36.802702, -121.788038)
2020-02-26T21:25:13.401Z,1582752313.401 [Default:CheckIn:Read_GPS] Stopped
2020-02-26T21:25:13.401Z,1582752313.401 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-02-26T21:25:21.489Z,1582752321.489 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20200226T202949/Courier0031.lzma
2020-02-26T21:25:23.494Z,1582752323.494 [DataOverHttps](INFO): Moved sent file to Logs/20200226T202949/Courier0031.lzma.bak
2020-02-26T21:25:23.495Z,1582752323.495 [DataOverHttps](INFO): SBD MOMSN=12269524
2020-02-26T21:25:40.669Z,1582752340.669 [DataOverHttps](INFO): Sending 120 bytes from file Logs/20200226T202949/Express0032.lzma
2020-02-26T21:25:42.675Z,1582752342.675 [DataOverHttps](INFO): Moved sent file to Logs/20200226T202949/Express0032.lzma.bak
2020-02-26T21:25:42.675Z,1582752342.675 [DataOverHttps](INFO): SBD MOMSN=12269527
2020-02-26T21:25:44.904Z,1582752344.904 [Default:CheckIn:Read_Iridium] Stopped
2020-02-26T21:25:44.904Z,1582752344.904 [Default:CheckIn:C.Wait] Running Loop=1
2020-02-26T21:25:44.904Z,1582752344.904 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-02-26T21:25:51.743Z,1582752351.743 [NAL9602](INFO): SBD MO Status=2, MOMSN=6603, MT Status=2, MTMSN=0
2020-02-26T21:25:51.743Z,1582752351.743 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-02-26T21:26:10.725Z,1582752370.725 [NAL9602](INFO): SBD MO Status=0, MOMSN=6603, MT Status=0, MTMSN=0
2020-02-26T21:26:10.725Z,1582752370.725 [NAL9602](INFO): No messages in MT queue
2020-02-26T21:26:41.427Z,1582752401.427 [NAL9602](INFO): Not Powering down - fast GPS
2020-02-26T21:27:43.569Z,1582752463.569 [CommandLine](IMPORTANT): got command gfscan
2020-02-26T21:27:43.802Z,1582752463.802 [CBIT](IMPORTANT): Beginning ground fault scan
2020-02-26T21:27:54.668Z,1582752474.668 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.010296
CHAN A1 (24V): 0.074161
CHAN A2 (12V): -0.007536
CHAN A3 (5V): -0.001692
CHAN B0 (3.3V): 0.000588
CHAN B1 (3.15aV): -0.000285
CHAN B2 (3.15bV): -0.000307
CHAN B3 (GND): 0.002363
OPEN: 0.004914
Full Scale Calc: 4.765 mA, -1.589 mA
2020-02-26T21:30:45.506Z,1582752645.506 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-02-26T21:30:45.506Z,1582752645.506 [Default:CheckIn:C.Wait] Stopped
2020-02-26T21:30:45.506Z,1582752645.506 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-02-26T21:30:45.506Z,1582752645.506 [Default:CheckIn:D] Running Loop=1
2020-02-26T21:30:45.912Z,1582752645.912 [Default:CheckIn:D] Stopped
2020-02-26T21:30:45.912Z,1582752645.912 [Default:CheckIn:E] Running Loop=1
2020-02-26T21:30:46.312Z,1582752646.312 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 57.257389 min 
2020-02-26T21:30:46.312Z,1582752646.312 [Default:CheckIn:E] Stopped
2020-02-26T21:30:46.312Z,1582752646.312 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-02-26T21:30:46.312Z,1582752646.312 [Default:CheckIn] Stopped
2020-02-26T21:30:46.355Z,1582752646.355 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-02-26T21:30:46.355Z,1582752646.355 [Default:CheckIn](INFO): Running loop #11
2020-02-26T21:30:46.355Z,1582752646.355 [Default:CheckIn] Running Loop=11
2020-02-26T21:30:46.355Z,1582752646.355 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-02-26T21:30:46.355Z,1582752646.355 [Default:CheckIn:Read_GPS] Running Loop=1
2020-02-26T21:30:48.307Z,1582752648.307 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,211928.00,A,3648.16280,N,12147.27950,W,0.194,32.92,260220,,,A*43
2020-02-26T21:30:48.310Z,1582752648.310 [NAL9602](INFO): GPS fix at 20200226T211928: (36.802713, -121.787992)
2020-02-26T21:30:48.333Z,1582752648.333 [Default:CheckIn:Read_GPS] Stopped
2020-02-26T21:30:48.333Z,1582752648.333 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-02-26T21:30:55.927Z,1582752655.927 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20200226T202949/Courier0034.lzma
2020-02-26T21:30:57.930Z,1582752657.930 [DataOverHttps](INFO): Moved sent file to Logs/20200226T202949/Courier0034.lzma.bak
2020-02-26T21:30:57.930Z,1582752657.930 [DataOverHttps](INFO): SBD MOMSN=12269548
2020-02-26T21:31:15.195Z,1582752675.195 [DataOverHttps](INFO): Sending 329 bytes from file Logs/20200226T202949/Express0035.lzma
2020-02-26T21:31:17.650Z,1582752677.650 [DataOverHttps](INFO): Moved sent file to Logs/20200226T202949/Express0035.lzma.bak
2020-02-26T21:31:17.650Z,1582752677.650 [DataOverHttps](INFO): SBD MOMSN=12269551
2020-02-26T21:31:19.059Z,1582752679.059 [Default:CheckIn:Read_Iridium] Stopped
2020-02-26T21:31:19.059Z,1582752679.059 [Default:CheckIn:C.Wait] Running Loop=1
2020-02-26T21:31:19.059Z,1582752679.059 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-02-26T21:32:46.307Z,1582752766.307 [NAL9602](INFO): SBD MO Status=0, MOMSN=6604, MT Status=0, MTMSN=0
2020-02-26T21:32:46.307Z,1582752766.307 [NAL9602](INFO): No messages in MT queue
2020-02-26T21:33:17.010Z,1582752797.010 [NAL9602](INFO): Not Powering down - fast GPS
2020-02-26T21:36:19.650Z,1582752979.650 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-02-26T21:36:19.650Z,1582752979.650 [Default:CheckIn:C.Wait] Stopped
2020-02-26T21:36:19.651Z,1582752979.651 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-02-26T21:36:19.651Z,1582752979.651 [Default:CheckIn:D] Running Loop=1
2020-02-26T21:36:20.053Z,1582752980.053 [Default:CheckIn:D] Stopped
2020-02-26T21:36:20.053Z,1582752980.053 [Default:CheckIn:E] Running Loop=1
2020-02-26T21:36:20.452Z,1582752980.452 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 62.826416 min 
2020-02-26T21:36:20.452Z,1582752980.452 [Default:CheckIn:E] Stopped
2020-02-26T21:36:20.452Z,1582752980.452 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-02-26T21:36:20.452Z,1582752980.452 [Default:CheckIn] Stopped
2020-02-26T21:36:20.452Z,1582752980.452 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-02-26T21:36:20.469Z,1582752980.469 [Default:CheckIn](INFO): Running loop #12
2020-02-26T21:36:20.469Z,1582752980.469 [Default:CheckIn] Running Loop=12
2020-02-26T21:36:20.469Z,1582752980.469 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-02-26T21:36:20.469Z,1582752980.469 [Default:CheckIn:Read_GPS] Running Loop=1
2020-02-26T21:36:22.444Z,1582752982.444 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,212502.00,A,3648.16591,N,12147.28152,W,0.097,348.64,260220,,,A*73
2020-02-26T21:36:22.447Z,1582752982.447 [NAL9602](INFO): GPS fix at 20200226T212502: (36.802765, -121.788025)
2020-02-26T21:36:22.470Z,1582752982.470 [Default:CheckIn:Read_GPS] Stopped
2020-02-26T21:36:22.470Z,1582752982.470 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-02-26T21:36:30.589Z,1582752990.589 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20200226T202949/Courier0037.lzma
2020-02-26T21:36:32.594Z,1582752992.594 [DataOverHttps](INFO): Moved sent file to Logs/20200226T202949/Courier0037.lzma.bak
2020-02-26T21:36:32.595Z,1582752992.595 [DataOverHttps](INFO): SBD MOMSN=12269604
2020-02-26T21:36:50.766Z,1582753010.766 [DataOverHttps](INFO): Sending 119 bytes from file Logs/20200226T202949/Express0038.lzma
2020-02-26T21:36:52.734Z,1582753012.734 [DataOverHttps](INFO): Moved sent file to Logs/20200226T202949/Express0038.lzma.bak
2020-02-26T21:36:52.735Z,1582753012.735 [DataOverHttps](INFO): SBD MOMSN=12269608
2020-02-26T21:36:54.812Z,1582753014.812 [Default:CheckIn:Read_Iridium] Stopped
2020-02-26T21:36:54.812Z,1582753014.812 [Default:CheckIn:C.Wait] Running Loop=1
2020-02-26T21:36:54.812Z,1582753014.812 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-02-26T21:37:08.307Z,1582753028.307 [CommandLine](IMPORTANT): got command show variable wetla
2020-02-26T21:37:08.367Z,1582753028.367 [CommandLine](IMPORTANT): WetLabsBB2FL.loadControl (none)
2020-02-26T21:37:08.368Z,1582753028.368 [CommandLine](IMPORTANT): WetLabsBB2FL.uart (none)
2020-02-26T21:37:08.368Z,1582753028.368 [CommandLine](IMPORTANT): WetLabsBB2FL.baud (bit_per_second)
2020-02-26T21:37:08.368Z,1582753028.368 [CommandLine](IMPORTANT): WetLabsSeaOWL_UV_A.loadControl (none)
2020-02-26T21:37:08.373Z,1582753028.373 [CommandLine](IMPORTANT): WetLabsSeaOWL_UV_A.uart (none)
2020-02-26T21:37:08.373Z,1582753028.373 [CommandLine](IMPORTANT): WetLabsSeaOWL_UV_A.baud (bit_per_second)
2020-02-26T21:37:08.374Z,1582753028.374 [CommandLine](IMPORTANT): WetLabsUBAT.loadControl (none)
2020-02-26T21:37:08.374Z,1582753028.374 [CommandLine](IMPORTANT): WetLabsUBAT.uart (none)
2020-02-26T21:37:08.374Z,1582753028.374 [CommandLine](IMPORTANT): WetLabsUBAT.baud (bit_per_second)
2020-02-26T21:37:08.434Z,1582753028.434 [CommandLine](IMPORTANT): WetLabsBB2FL.loadAtStartup (bool)
2020-02-26T21:37:08.434Z,1582753028.434 [CommandLine](IMPORTANT): WetLabsBB2FL.simulateHardware (bool)
2020-02-26T21:37:08.435Z,1582753028.435 [CommandLine](IMPORTANT): WetLabsBB2FL.chlAccuracy (microgram_per_liter)
2020-02-26T21:37:08.435Z,1582753028.435 [CommandLine](IMPORTANT): WetLabsBB2FL.darkCounts470 (count)
2020-02-26T21:37:08.436Z,1582753028.436 [CommandLine](IMPORTANT): WetLabsBB2FL.darkCounts650 (count)
2020-02-26T21:37:08.436Z,1582753028.436 [CommandLine](IMPORTANT): WetLabsBB2FL.darkCountsChl (count)
2020-02-26T21:37:08.436Z,1582753028.436 [CommandLine](IMPORTANT): WetLabsBB2FL.power (watt)
2020-02-26T21:37:08.457Z,1582753028.457 [CommandLine](IMPORTANT): WetLabsBB2FL.scaleFactor470 (reciprocal_meter_per_steradian_count)
2020-02-26T21:37:08.457Z,1582753028.457 [CommandLine](IMPORTANT): WetLabsBB2FL.scaleFactor650 (reciprocal_meter_per_steradian_count)
2020-02-26T21:37:08.458Z,1582753028.458 [CommandLine](IMPORTANT): WetLabsBB2FL.scaleFactorChl (microgram_per_liter_per_count)
2020-02-26T21:37:08.458Z,1582753028.458 [CommandLine](IMPORTANT): WetLabsBB2FL.serial (none)
2020-02-26T21:37:08.458Z,1582753028.458 [CommandLine](IMPORTANT): WetLabsSeaOWL_UV_A.loadAtStartup (bool)
2020-02-26T21:37:08.459Z,1582753028.459 [CommandLine](IMPORTANT): WetLabsSeaOWL_UV_A.simulateHardware (bool)
2020-02-26T21:37:08.459Z,1582753028.459 [CommandLine](IMPORTANT): WetLabsSeaOWL_UV_A.chlAccuracy (microgram_per_liter)
2020-02-26T21:37:08.459Z,1582753028.459 [CommandLine](IMPORTANT): WetLabsSeaOWL_UV_A.darkCounts700 (count)
2020-02-26T21:37:08.460Z,1582753028.460 [CommandLine](IMPORTANT): WetLabsSeaOWL_UV_A.darkCountsChl (count)
2020-02-26T21:37:08.460Z,1582753028.460 [CommandLine](IMPORTANT): WetLabsSeaOWL_UV_A.darkCountsFDOM (count)
2020-02-26T21:37:08.460Z,1582753028.460 [CommandLine](IMPORTANT): WetLabsSeaOWL_UV_A.darkCountsOil (count)
2020-02-26T21:37:08.473Z,1582753028.473 [CommandLine](IMPORTANT): WetLabsSeaOWL_UV_A.fdomAccuracy (part_per_billion)
2020-02-26T21:37:08.474Z,1582753028.474 [CommandLine](IMPORTANT): WetLabsSeaOWL_UV_A.oilAccuracy (part_per_billion)
2020-02-26T21:37:08.474Z,1582753028.474 [CommandLine](IMPORTANT): WetLabsSeaOWL_UV_A.period (second)
2020-02-26T21:37:08.474Z,1582753028.474 [CommandLine](IMPORTANT): WetLabsSeaOWL_UV_A.power (watt)
2020-02-26T21:37:08.475Z,1582753028.475 [CommandLine](IMPORTANT): WetLabsSeaOWL_UV_A.scaleFactor700 (reciprocal_meter_per_steradian_count)
2020-02-26T21:37:08.475Z,1582753028.475 [CommandLine](IMPORTANT): WetLabsSeaOWL_UV_A.scaleFactorChl (microgram_per_liter_per_count)
2020-02-26T21:37:08.475Z,1582753028.475 [CommandLine](IMPORTANT): WetLabsSeaOWL_UV_A.scaleFactorFDOM (part_per_billion_per_count)
2020-02-26T21:37:08.476Z,1582753028.476 [CommandLine](IMPORTANT): WetLabsSeaOWL_UV_A.scaleFactorOil (part_per_billion_per_count)
2020-02-26T21:37:08.476Z,1582753028.476 [CommandLine](IMPORTANT): WetLabsSeaOWL_UV_A.serial (none)
2020-02-26T21:37:08.476Z,1582753028.476 [CommandLine](IMPORTANT): WetLabsSeaOWL_UV_A.timeout (second)
2020-02-26T21:37:08.533Z,1582753028.533 [CommandLine](IMPORTANT): WetLabsUBAT.loadAtStartup (bool)
2020-02-26T21:37:08.533Z,1582753028.533 [CommandLine](IMPORTANT): WetLabsUBAT.simulateHardware (bool)
2020-02-26T21:37:08.534Z,1582753028.534 [CommandLine](IMPORTANT): WetLabsUBAT.emulateHardware (bool)
2020-02-26T21:37:08.534Z,1582753028.534 [CommandLine](IMPORTANT): WetLabsUBAT.serial (none)
2020-02-26T21:37:08.535Z,1582753028.535 [CommandLine](IMPORTANT): WetLabsUBAT.optionalArgs (none)
2020-02-26T21:37:08.567Z,1582753028.567 [CommandLine](IMPORTANT): WetLabsUBAT.lcmAppName (none)
2020-02-26T21:37:08.568Z,1582753028.568 [CommandLine](IMPORTANT): WetLabsUBAT.flowrateCalibCoeff (none_float)
2020-02-26T21:37:08.568Z,1582753028.568 [CommandLine](IMPORTANT): WetLabsUBAT.minFlowrate (liter_per_second)
2020-02-26T21:37:08.651Z,1582753028.651 [CommandLine](IMPORTANT): WetLabsBB2FL.Output470 (count)
2020-02-26T21:37:08.652Z,1582753028.652 [CommandLine](IMPORTANT): WetLabsBB2FL.Output650 (count)
2020-02-26T21:37:08.652Z,1582753028.652 [CommandLine](IMPORTANT): WetLabsBB2FL.OutputChl (count)
2020-02-26T21:37:08.652Z,1582753028.652 [CommandLine](IMPORTANT): WetLabsBB2FL.VolumeScatCoeff117deg470nm (reciprocal_meter_per_steradian)
2020-02-26T21:37:08.665Z,1582753028.665 [CommandLine](IMPORTANT): WetLabsBB2FL.VolumeScatCoeff117deg650nm (reciprocal_meter_per_steradian)
2020-02-26T21:37:08.665Z,1582753028.665 [CommandLine](IMPORTANT): WetLabsBB2FL.BackscatteringCoeff470nm (reciprocal_meter)
2020-02-26T21:37:08.666Z,1582753028.666 [CommandLine](IMPORTANT): WetLabsBB2FL.BackscatteringCoeff650nm (reciprocal_meter)
2020-02-26T21:37:08.666Z,1582753028.666 [CommandLine](IMPORTANT): WetLabsBB2FL.mass_concentration_of_chlorophyll_in_sea_water (microgram_per_liter)
2020-02-26T21:37:08.667Z,1582753028.667 [CommandLine](IMPORTANT): WetLabsBB2FL.bin_median_mass_concentration_of_chlorophyll_in_sea_water (microgram_per_liter)
2020-02-26T21:37:08.667Z,1582753028.667 [CommandLine](IMPORTANT): WetLabsBB2FL.bin_mean_mass_concentration_of_chlorophyll_in_sea_water (microgram_per_liter)
2020-02-26T21:37:08.668Z,1582753028.668 [CommandLine](IMPORTANT): WetLabsBB2FL.bin_variance_mass_concentration_of_chlorophyll_in_sea_water (microgram_per_liter)
2020-02-26T21:37:08.668Z,1582753028.668 [CommandLine](IMPORTANT): WetLabsUBAT.biolum_potential (none)
2020-02-26T21:37:08.668Z,1582753028.668 [CommandLine](IMPORTANT): WetLabsUBAT.flow_rate (liter_per_second)
2020-02-26T21:37:08.685Z,1582753028.685 [CommandLine](IMPORTANT): WetLabsBB2FL.component_voltage (volt)
2020-02-26T21:37:08.686Z,1582753028.686 [CommandLine](IMPORTANT): WetLabsBB2FL.component_avgVoltage (volt)
2020-02-26T21:37:08.686Z,1582753028.686 [CommandLine](IMPORTANT): WetLabsBB2FL.component_current (milliampere)
2020-02-26T21:37:08.686Z,1582753028.686 [CommandLine](IMPORTANT): WetLabsBB2FL.component_avgCurrent (milliampere)
2020-02-26T21:37:17.618Z,1582753037.618 [CommandLine](IMPORTANT): got command get WetLabsUBAT.serial
2020-02-26T21:37:17.619Z,1582753037.619 [CommandLine](IMPORTANT): WetLabsUBAT.serial UBAT0051
2020-02-26T21:37:29.996Z,1582753049.996 [CommandLine](INFO): End of History
2020-02-26T21:37:30.006Z,1582753050.006 [CommandLine](INFO): End of History
2020-02-26T21:37:30.013Z,1582753050.013 [CommandLine](INFO): End of History
2020-02-26T21:37:30.015Z,1582753050.015 [CommandLine](INFO): End of History
2020-02-26T21:37:30.030Z,1582753050.030 [CommandLine](INFO): End of History
2020-02-26T21:37:30.032Z,1582753050.032 [CommandLine](INFO): End of History
2020-02-26T21:37:30.048Z,1582753050.048 [CommandLine](INFO): End of History
2020-02-26T21:37:30.058Z,1582753050.058 [CommandLine](INFO): End of History
2020-02-26T21:37:30.060Z,1582753050.060 [CommandLine](INFO): End of History
2020-02-26T21:37:30.071Z,1582753050.071 [CommandLine](INFO): End of History
2020-02-26T21:37:30.081Z,1582753050.081 [CommandLine](INFO): End of History
2020-02-26T21:37:30.084Z,1582753050.084 [CommandLine](INFO): End of History
2020-02-26T21:37:30.094Z,1582753050.094 [CommandLine](INFO): End of History
2020-02-26T21:37:30.096Z,1582753050.096 [CommandLine](INFO): End of History
2020-02-26T21:37:30.106Z,1582753050.106 [CommandLine](INFO): End of History
2020-02-26T21:37:30.117Z,1582753050.117 [CommandLine](INFO): End of History
2020-02-26T21:37:33.897Z,1582753053.897 [CommandLine](INFO): End of History
2020-02-26T21:37:53.452Z,1582753073.452 [CommandLine](IMPORTANT): got command show variable wetlabsubat
2020-02-26T21:37:53.487Z,1582753073.487 [CommandLine](IMPORTANT): WetLabsUBAT.loadControl (none)
2020-02-26T21:37:53.487Z,1582753073.487 [CommandLine](IMPORTANT): WetLabsUBAT.uart (none)
2020-02-26T21:37:53.488Z,1582753073.488 [CommandLine](IMPORTANT): WetLabsUBAT.baud (bit_per_second)
2020-02-26T21:37:53.546Z,1582753073.546 [CommandLine](IMPORTANT): WetLabsUBAT.loadAtStartup (bool)
2020-02-26T21:37:53.546Z,1582753073.546 [CommandLine](IMPORTANT): WetLabsUBAT.simulateHardware (bool)
2020-02-26T21:37:53.546Z,1582753073.546 [CommandLine](IMPORTANT): WetLabsUBAT.emulateHardware (bool)
2020-02-26T21:37:53.547Z,1582753073.547 [CommandLine](IMPORTANT): WetLabsUBAT.serial (none)
2020-02-26T21:37:53.547Z,1582753073.547 [CommandLine](IMPORTANT): WetLabsUBAT.optionalArgs (none)
2020-02-26T21:37:53.564Z,1582753073.564 [CommandLine](IMPORTANT): WetLabsUBAT.lcmAppName (none)
2020-02-26T21:37:53.564Z,1582753073.564 [CommandLine](IMPORTANT): WetLabsUBAT.flowrateCalibCoeff (none_float)
2020-02-26T21:37:53.577Z,1582753073.577 [CommandLine](IMPORTANT): WetLabsUBAT.minFlowrate (liter_per_second)
2020-02-26T21:37:53.663Z,1582753073.663 [CommandLine](IMPORTANT): WetLabsUBAT.biolum_potential (none)
2020-02-26T21:37:53.664Z,1582753073.664 [CommandLine](IMPORTANT): WetLabsUBAT.flow_rate (liter_per_second)
2020-02-26T21:37:59.849Z,1582753079.849 [CommandLine](IMPORTANT): got command get WetLabsUBAT.uart
2020-02-26T21:37:59.849Z,1582753079.849 [CommandLine](IMPORTANT): WetLabsUBAT.uart /dev/ttyC1
2020-02-26T21:38:16.807Z,1582753096.807 [CommandLine](IMPORTANT): got command ! echo i > /dev/loadC1
2020-02-26T21:38:19.686Z,1582753099.686 [CommandLine](IMPORTANT): got command gfscan
2020-02-26T21:38:19.737Z,1582753099.737 [CBIT](IMPORTANT): Beginning ground fault scan
2020-02-26T21:38:30.634Z,1582753110.634 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.008831
CHAN A1 (24V): 0.072879
CHAN A2 (12V): -0.007047
CHAN A3 (5V): -0.003190
CHAN B0 (3.3V): 0.000435
CHAN B1 (3.15aV): -0.000467
CHAN B2 (3.15bV): 0.000143
CHAN B3 (GND): 0.002171
OPEN: 0.005398
Full Scale Calc: 4.765 mA, -1.589 mA
2020-02-26T21:38:55.846Z,1582753135.846 [CommandLine](IMPORTANT): got command get CBIT.gf24Offset
2020-02-26T21:38:55.847Z,1582753135.847 [CommandLine](IMPORTANT): CBIT.gf24Offset 143.000000 uA
2020-02-26T21:39:17.087Z,1582753157.087 [CommandLine](IMPORTANT): got command show variable rdi
2020-02-26T21:39:17.115Z,1582753157.115 [CommandLine](IMPORTANT): projection_x_coordinate (unknown)
2020-02-26T21:39:17.116Z,1582753157.116 [CommandLine](IMPORTANT): projection_y_coordinate (unknown)
2020-02-26T21:39:17.195Z,1582753157.195 [CommandLine](IMPORTANT): RDI_Pathfinder.loadAtStartup (bool)
2020-02-26T21:39:17.195Z,1582753157.195 [CommandLine](IMPORTANT): RDI_Pathfinder.simulateHardware (bool)
2020-02-26T21:39:17.196Z,1582753157.196 [CommandLine](IMPORTANT): RDI_PathfinderUp.loadAtStartup (bool)
2020-02-26T21:39:17.196Z,1582753157.196 [CommandLine](IMPORTANT): RDI_PathfinderUp.simulateHardware (bool)
2020-02-26T21:39:17.274Z,1582753157.274 [CommandLine](IMPORTANT): RDI_Pathfinder.loadControl (none)
2020-02-26T21:39:17.275Z,1582753157.275 [CommandLine](IMPORTANT): RDI_Pathfinder.uart (none)
2020-02-26T21:39:17.275Z,1582753157.275 [CommandLine](IMPORTANT): RDI_Pathfinder.baud (bit_per_second)
2020-02-26T21:39:32.975Z,1582753172.975 [CommandLine](IMPORTANT): got command get RDI_PathfinderUp.loadAtStartup
2020-02-26T21:39:32.976Z,1582753172.976 [CommandLine](IMPORTANT): RDI_PathfinderUp.loadAtStartup 0 bool
2020-02-26T21:39:43.229Z,1582753183.229 [CommandLine](IMPORTANT): got command ! echo i > /dev/loadB4
2020-02-26T21:39:50.247Z,1582753190.247 [CommandLine](IMPORTANT): got command gfscan
2020-02-26T21:39:50.607Z,1582753190.607 [CBIT](IMPORTANT): Beginning ground fault scan
2020-02-26T21:40:01.606Z,1582753201.606 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.011274
CHAN A1 (24V): 0.071651
CHAN A2 (12V): -0.006991
CHAN A3 (5V): -0.002074
CHAN B0 (3.3V): 0.000376
CHAN B1 (3.15aV): 0.000075
CHAN B2 (3.15bV): 0.000201
CHAN B3 (GND): 0.002236
OPEN: 0.004955
Full Scale Calc: 4.765 mA, -1.589 mA
2020-02-26T21:40:20.647Z,1582753220.647 [CommandLine](IMPORTANT): got command ! echo 0 > /dev/loadB2
2020-02-26T21:40:23.952Z,1582753223.952 [CommandLine](IMPORTANT): got command gfscan
2020-02-26T21:40:24.149Z,1582753224.149 [CBIT](IMPORTANT): Beginning ground fault scan
2020-02-26T21:40:35.069Z,1582753235.069 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.010177
CHAN A1 (24V): -0.142683
CHAN A2 (12V): -0.007065
CHAN A3 (5V): -0.001480
CHAN B0 (3.3V): 0.000026
CHAN B1 (3.15aV): 0.000213
CHAN B2 (3.15bV): 0.000533
CHAN B3 (GND): 0.002274
OPEN: 0.004644
Full Scale Calc: 4.765 mA, -1.589 mA
2020-02-26T21:40:49.090Z,1582753249.090 [NAL9602](INFO): SBD MO Status=0, MOMSN=6605, MT Status=0, MTMSN=0
2020-02-26T21:40:49.090Z,1582753249.090 [NAL9602](INFO): No messages in MT queue
2020-02-26T21:40:57.126Z,1582753257.126 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2
2020-02-26T21:41:07.694Z,1582753267.694 [DAT](DEBUG): uncaught empty line in deviceResponse_: 

2020-02-26T21:41:08.905Z,1582753268.905 [DAT](FAULT): unknown deviceResponse_: Teledyne Benthos DAT-900 Series

2020-02-26T21:41:08.906Z,1582753268.906 [DAT] Communications Fault, FailCount= 1
2020-02-26T21:41:08.906Z,1582753268.906 [DAT](ERROR): Communications Fault
2020-02-26T21:41:08.907Z,1582753268.907 [DAT](FAULT): unknown deviceResponse_: MF Frequency Band

2020-02-26T21:41:08.908Z,1582753268.908 [DAT](FAULT): unknown deviceResponse_: Directional Acoustic Transponder version 8.12.21

2020-02-26T21:41:09.137Z,1582753269.137 [CBIT](ERROR): Communications Fault in component: DAT
2020-02-26T21:41:09.315Z,1582753269.315 [DAT](INFO): Powering down
2020-02-26T21:41:10.212Z,1582753270.212 [CBIT](INFO): Clearing failed state for component DAT
2020-02-26T21:41:10.213Z,1582753270.213 [DAT] No Fault, FailCount= 1
2020-02-26T21:41:12.549Z,1582753272.549 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2
2020-02-26T21:41:12.549Z,1582753272.549 [DAT](INFO): Powering up
2020-02-26T21:41:12.550Z,1582753272.550 [DAT](DEBUG): Initializing DAT.
2020-02-26T21:41:12.621Z,1582753272.621 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2
2020-02-26T21:41:14.296Z,1582753274.296 [CommandLine](IMPORTANT): got command gfscan
2020-02-26T21:41:14.665Z,1582753274.665 [CBIT](IMPORTANT): Beginning ground fault scan
2020-02-26T21:41:19.790Z,1582753279.790 [NAL9602](INFO): Not Powering down - fast GPS
2020-02-26T21:41:25.097Z,1582753285.097 [DAT](INFO): Got CONNECT
2020-02-26T21:41:25.142Z,1582753285.142 [DAT](INFO): entering command mode
2020-02-26T21:41:25.621Z,1582753285.621 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.012258
CHAN A1 (24V): 0.069506
CHAN A2 (12V): -0.008186
CHAN A3 (5V): -0.001616
CHAN B0 (3.3V): -0.000528
CHAN B1 (3.15aV): -0.000569
CHAN B2 (3.15bV): 0.000081
CHAN B3 (GND): 0.001903
OPEN: 0.004777
Full Scale Calc: 4.765 mA, -1.589 mA
2020-02-26T21:41:26.276Z,1582753286.276 [DAT](INFO): command mode acknowledged
2020-02-26T21:41:26.683Z,1582753286.683 [DAT](INFO): setting local address to 9
2020-02-26T21:41:27.084Z,1582753287.084 [DAT](INFO): set local address to 9
2020-02-26T21:41:41.246Z,1582753301.246 [CommandLine](IMPORTANT): got command ! echo i > /dev/loadB3
2020-02-26T21:41:43.298Z,1582753303.298 [CommandLine](IMPORTANT): got command gfscan
2020-02-26T21:41:43.401Z,1582753303.401 [CBIT](IMPORTANT): Beginning ground fault scan
2020-02-26T21:41:54.247Z,1582753314.247 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.011733
CHAN A1 (24V): 0.067504
CHAN A2 (12V): -0.007183
CHAN A3 (5V): -0.002315
CHAN B0 (3.3V): 0.000472
CHAN B1 (3.15aV): 0.000102
CHAN B2 (3.15bV): -0.000137
CHAN B3 (GND): 0.001815
OPEN: 0.003023
Full Scale Calc: 4.765 mA, -1.589 mA
2020-02-26T21:41:55.376Z,1582753315.376 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-02-26T21:41:55.376Z,1582753315.376 [Default:CheckIn:C.Wait] Stopped
2020-02-26T21:41:55.376Z,1582753315.376 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-02-26T21:41:55.376Z,1582753315.376 [Default:CheckIn:D] Running Loop=1
2020-02-26T21:41:55.780Z,1582753315.780 [Default:CheckIn:D] Stopped
2020-02-26T21:41:55.780Z,1582753315.780 [Default:CheckIn:E] Running Loop=1
2020-02-26T21:41:56.172Z,1582753316.172 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 68.421867 min 
2020-02-26T21:41:56.172Z,1582753316.172 [Default:CheckIn:E] Stopped
2020-02-26T21:41:56.172Z,1582753316.172 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-02-26T21:41:56.172Z,1582753316.172 [Default:CheckIn] Stopped
2020-02-26T21:41:56.173Z,1582753316.173 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-02-26T21:41:56.173Z,1582753316.173 [Default:CheckIn](INFO): Running loop #13
2020-02-26T21:41:56.173Z,1582753316.173 [Default:CheckIn] Running Loop=13
2020-02-26T21:41:56.174Z,1582753316.174 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-02-26T21:41:56.174Z,1582753316.174 [Default:CheckIn:Read_GPS] Running Loop=1
2020-02-26T21:41:58.172Z,1582753318.172 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,213038.00,A,3648.16711,N,12147.28303,W,0.058,348.64,260220,,,A*71
2020-02-26T21:41:58.175Z,1582753318.175 [NAL9602](INFO): GPS fix at 20200226T213038: (36.802785, -121.788050)
2020-02-26T21:41:58.261Z,1582753318.261 [Default:CheckIn:Read_GPS] Stopped
2020-02-26T21:41:58.261Z,1582753318.261 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-02-26T21:42:06.402Z,1582753326.402 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20200226T202949/Courier0040.lzma
2020-02-26T21:42:08.406Z,1582753328.406 [DataOverHttps](INFO): Moved sent file to Logs/20200226T202949/Courier0040.lzma.bak
2020-02-26T21:42:08.407Z,1582753328.407 [DataOverHttps](INFO): SBD MOMSN=12269644
2020-02-26T21:42:20.439Z,1582753340.439 [NAL9602](INFO): SBD MO Status=2, MOMSN=6606, MT Status=2, MTMSN=0
2020-02-26T21:42:20.440Z,1582753340.440 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-02-26T21:42:25.645Z,1582753345.645 [DataOverHttps](INFO): Sending 1775 bytes from file Logs/20200226T202949/Express0041.lzma
2020-02-26T21:42:27.646Z,1582753347.646 [DataOverHttps](INFO): Moved sent file to Logs/20200226T202949/Express0041.lzma.bak
2020-02-26T21:42:27.647Z,1582753347.647 [DataOverHttps](INFO): SBD MOMSN=12269647
2020-02-26T21:42:29.415Z,1582753349.415 [Default:CheckIn:Read_Iridium] Stopped
2020-02-26T21:42:29.415Z,1582753349.415 [Default:CheckIn:C.Wait] Running Loop=1
2020-02-26T21:42:29.415Z,1582753349.415 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-02-26T21:42:32.553Z,1582753352.553 [NAL9602](INFO): SBD MO Status=0, MOMSN=6606, MT Status=0, MTMSN=0
2020-02-26T21:42:32.553Z,1582753352.553 [NAL9602](INFO): No messages in MT queue
2020-02-26T21:43:03.250Z,1582753383.250 [NAL9602](INFO): Not Powering down - fast GPS
2020-02-26T21:45:05.002Z,1582753505.002 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2020-02-26T21:45:05.004Z,1582753505.004 [BPC1](INFO): Received data from all battery sticks.
2020-02-26T21:47:30.037Z,1582753650.037 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-02-26T21:47:30.037Z,1582753650.037 [Default:CheckIn:C.Wait] Stopped
2020-02-26T21:47:30.037Z,1582753650.037 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-02-26T21:47:30.037Z,1582753650.037 [Default:CheckIn:D] Running Loop=1
2020-02-26T21:47:30.445Z,1582753650.445 [Default:CheckIn:D] Stopped
2020-02-26T21:47:30.445Z,1582753650.445 [Default:CheckIn:E] Running Loop=1
2020-02-26T21:47:30.853Z,1582753650.853 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 73.999618 min 
2020-02-26T21:47:30.853Z,1582753650.853 [Default:CheckIn:E] Stopped
2020-02-26T21:47:30.853Z,1582753650.853 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-02-26T21:47:30.853Z,1582753650.853 [Default:CheckIn] Stopped
2020-02-26T21:47:30.853Z,1582753650.853 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-02-26T21:47:30.854Z,1582753650.854 [Default:CheckIn](INFO): Running loop #14
2020-02-26T21:47:30.854Z,1582753650.854 [Default:CheckIn] Running Loop=14
2020-02-26T21:47:30.854Z,1582753650.854 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-02-26T21:47:30.854Z,1582753650.854 [Default:CheckIn:Read_GPS] Running Loop=1
2020-02-26T21:47:32.846Z,1582753652.846 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,213613.00,A,3648.16650,N,12147.28362,W,0.078,348.64,260220,,,A*7F
2020-02-26T21:47:32.848Z,1582753652.848 [NAL9602](INFO): GPS fix at 20200226T213613: (36.802775, -121.788060)
2020-02-26T21:47:32.904Z,1582753652.904 [Default:CheckIn:Read_GPS] Stopped
2020-02-26T21:47:32.904Z,1582753652.904 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-02-26T21:47:40.888Z,1582753660.888 [DataOverHttps](INFO): Sending 80 bytes from file Logs/20200226T202949/Courier0043.lzma
2020-02-26T21:47:42.894Z,1582753662.894 [DataOverHttps](INFO): Moved sent file to Logs/20200226T202949/Courier0043.lzma.bak
2020-02-26T21:47:42.894Z,1582753662.894 [DataOverHttps](INFO): SBD MOMSN=12269778
2020-02-26T21:48:00.053Z,1582753680.053 [DataOverHttps](INFO): Sending 119 bytes from file Logs/20200226T202949/Express0044.lzma
2020-02-26T21:48:02.060Z,1582753682.060 [DataOverHttps](INFO): Moved sent file to Logs/20200226T202949/Express0044.lzma.bak
2020-02-26T21:48:02.061Z,1582753682.061 [DataOverHttps](INFO): SBD MOMSN=12269781
2020-02-26T21:48:03.982Z,1582753683.982 [Default:CheckIn:Read_Iridium] Stopped
2020-02-26T21:48:03.982Z,1582753683.982 [Default:CheckIn:C.Wait] Running Loop=1
2020-02-26T21:48:03.982Z,1582753683.982 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-02-26T21:49:55.467Z,1582753795.467 [NAL9602](INFO): SBD MO Status=2, MOMSN=6607, MT Status=2, MTMSN=0
2020-02-26T21:49:55.467Z,1582753795.467 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-02-26T21:50:19.734Z,1582753819.734 [NAL9602](INFO): SBD MO Status=0, MOMSN=6607, MT Status=0, MTMSN=0
2020-02-26T21:50:19.735Z,1582753819.735 [NAL9602](INFO): No messages in MT queue
2020-02-26T21:50:50.408Z,1582753850.408 [NAL9602](INFO): Not Powering down - fast GPS
2020-02-26T21:53:04.563Z,1582753984.563 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-02-26T21:53:04.563Z,1582753984.563 [Default:CheckIn:C.Wait] Stopped
2020-02-26T21:53:04.563Z,1582753984.563 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-02-26T21:53:04.563Z,1582753984.563 [Default:CheckIn:D] Running Loop=1
2020-02-26T21:53:04.965Z,1582753984.965 [Default:CheckIn:D] Stopped
2020-02-26T21:53:04.965Z,1582753984.965 [Default:CheckIn:E] Running Loop=1
2020-02-26T21:53:05.392Z,1582753985.392 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 79.574943 min 
2020-02-26T21:53:05.392Z,1582753985.392 [Default:CheckIn:E] Stopped
2020-02-26T21:53:05.392Z,1582753985.392 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-02-26T21:53:05.392Z,1582753985.392 [Default:CheckIn] Stopped
2020-02-26T21:53:05.397Z,1582753985.397 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-02-26T21:53:05.397Z,1582753985.397 [Default:CheckIn](INFO): Running loop #15
2020-02-26T21:53:05.397Z,1582753985.397 [Default:CheckIn] Running Loop=15
2020-02-26T21:53:05.397Z,1582753985.397 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-02-26T21:53:05.397Z,1582753985.397 [Default:CheckIn:Read_GPS] Running Loop=1
2020-02-26T21:53:07.368Z,1582753987.368 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,214147.00,A,3648.17024,N,12147.27993,W,0.214,0.00,260220,,,A*74
2020-02-26T21:53:07.370Z,1582753987.370 [NAL9602](INFO): GPS fix at 20200226T214147: (36.802837, -121.787999)
2020-02-26T21:53:07.393Z,1582753987.393 [Default:CheckIn:Read_GPS] Stopped
2020-02-26T21:53:07.393Z,1582753987.393 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-02-26T21:53:14.623Z,1582753994.623 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20200226T202949/Courier0046.lzma
2020-02-26T21:53:16.626Z,1582753996.626 [DataOverHttps](INFO): Moved sent file to Logs/20200226T202949/Courier0046.lzma.bak
2020-02-26T21:53:16.627Z,1582753996.627 [DataOverHttps](INFO): SBD MOMSN=12269927
2020-02-26T21:53:36.701Z,1582754016.701 [DataOverHttps](INFO): Sending 120 bytes from file Logs/20200226T202949/Express0047.lzma
2020-02-26T21:53:38.708Z,1582754018.708 [DataOverHttps](INFO): Moved sent file to Logs/20200226T202949/Express0047.lzma.bak
2020-02-26T21:53:38.708Z,1582754018.708 [DataOverHttps](INFO): SBD MOMSN=12269930
2020-02-26T21:53:40.643Z,1582754020.643 [Default:CheckIn:Read_Iridium] Stopped
2020-02-26T21:53:40.644Z,1582754020.644 [Default:CheckIn:C.Wait] Running Loop=1
2020-02-26T21:53:40.644Z,1582754020.644 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-02-26T21:54:29.893Z,1582754069.893 [NAL9602](INFO): SBD MO Status=2, MOMSN=6608, MT Status=2, MTMSN=0
2020-02-26T21:54:29.893Z,1582754069.893 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-02-26T21:58:09.278Z,1582754289.278 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2020-02-26T21:58:39.978Z,1582754319.978 [NAL9602](INFO): Not Powering down - fast GPS
2020-02-26T21:58:41.211Z,1582754321.211 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-02-26T21:58:41.211Z,1582754321.211 [Default:CheckIn:C.Wait] Stopped
2020-02-26T21:58:41.212Z,1582754321.212 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-02-26T21:58:41.212Z,1582754321.212 [Default:CheckIn:D] Running Loop=1
2020-02-26T21:58:41.621Z,1582754321.621 [Default:CheckIn:D] Stopped
2020-02-26T21:58:41.621Z,1582754321.621 [Default:CheckIn:E] Running Loop=1
2020-02-26T21:58:42.037Z,1582754322.037 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 85.185872 min 
2020-02-26T21:58:42.037Z,1582754322.037 [Default:CheckIn:E] Stopped
2020-02-26T21:58:42.037Z,1582754322.037 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-02-26T21:58:42.037Z,1582754322.037 [Default:CheckIn] Stopped
2020-02-26T21:58:42.037Z,1582754322.037 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-02-26T21:58:42.037Z,1582754322.037 [Default:CheckIn](INFO): Running loop #16
2020-02-26T21:58:42.038Z,1582754322.038 [Default:CheckIn] Running Loop=16
2020-02-26T21:58:42.038Z,1582754322.038 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-02-26T21:58:42.038Z,1582754322.038 [Default:CheckIn:Read_GPS] Running Loop=1
2020-02-26T21:58:44.020Z,1582754324.020 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,214724.00,A,3648.16531,N,12147.28326,W,0.058,35.06,260220,,,A*46
2020-02-26T21:58:44.022Z,1582754324.022 [NAL9602](INFO): GPS fix at 20200226T214724: (36.802755, -121.788054)
2020-02-26T21:58:44.044Z,1582754324.044 [Default:CheckIn:Read_GPS] Stopped
2020-02-26T21:58:44.044Z,1582754324.044 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-02-26T21:58:51.360Z,1582754331.360 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20200226T202949/Courier0049.lzma
2020-02-26T21:58:53.366Z,1582754333.366 [DataOverHttps](INFO): Moved sent file to Logs/20200226T202949/Courier0049.lzma.bak
2020-02-26T21:58:53.367Z,1582754333.367 [DataOverHttps](INFO): SBD MOMSN=12269933
2020-02-26T21:59:10.621Z,1582754350.621 [DataOverHttps](INFO): Sending 194 bytes from file Logs/20200226T202949/Express0050.lzma
2020-02-26T21:59:12.626Z,1582754352.626 [DataOverHttps](INFO): Moved sent file to Logs/20200226T202949/Express0050.lzma.bak
2020-02-26T21:59:12.627Z,1582754352.627 [DataOverHttps](INFO): SBD MOMSN=12269936
2020-02-26T21:59:14.340Z,1582754354.340 [Default:CheckIn:Read_Iridium] Stopped
2020-02-26T21:59:14.340Z,1582754354.340 [Default:CheckIn:C.Wait] Running Loop=1
2020-02-26T21:59:14.340Z,1582754354.340 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-02-26T21:59:14.727Z,1582754354.727 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2020-02-26T21:59:14.805Z,1582754354.805 [NAL9602](FAULT): received: 
+CSQ:0

OK08, 2, 0, 0, 0

OK
2020-02-26T21:59:14.805Z,1582754354.805 [NAL9602] Data Fault, FailCount= 1
2020-02-26T21:59:14.805Z,1582754354.805 [NAL9602](ERROR): Data Fault
2020-02-26T21:59:14.945Z,1582754354.945 [CBIT](ERROR): Data Fault in component: NAL9602
2020-02-26T21:59:15.124Z,1582754355.124 [NAL9602](INFO): Powering down
2020-02-26T21:59:16.074Z,1582754356.074 [CBIT](INFO): Clearing failed state for component NAL9602
2020-02-26T21:59:16.074Z,1582754356.074 [NAL9602] No Fault, FailCount= 1
2020-02-26T21:59:45.434Z,1582754385.434 [NAL9602](INFO): Powering up NAL9602
2020-02-26T21:59:56.338Z,1582754396.338 [NAL9602](INFO): NAL9602 initialized
2020-02-26T22:00:27.446Z,1582754427.446 [NAL9602](INFO): Not Powering down - fast GPS
2020-02-26T22:04:14.956Z,1582754654.956 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-02-26T22:04:14.956Z,1582754654.956 [Default:CheckIn:C.Wait] Stopped
2020-02-26T22:04:14.956Z,1582754654.956 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-02-26T22:04:14.956Z,1582754654.956 [Default:CheckIn:D] Running Loop=1
2020-02-26T22:04:15.348Z,1582754655.348 [Default:CheckIn:D] Stopped
2020-02-26T22:04:15.348Z,1582754655.348 [Default:CheckIn:E] Running Loop=1
2020-02-26T22:04:15.757Z,1582754655.757 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 90.747998 min 
2020-02-26T22:04:15.757Z,1582754655.757 [Default:CheckIn:E] Stopped
2020-02-26T22:04:15.757Z,1582754655.757 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-02-26T22:04:15.758Z,1582754655.758 [Default:CheckIn] Stopped
2020-02-26T22:04:15.758Z,1582754655.758 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-02-26T22:04:15.758Z,1582754655.758 [Default:CheckIn](INFO): Running loop #17
2020-02-26T22:04:15.758Z,1582754655.758 [Default:CheckIn] Running Loop=17
2020-02-26T22:04:15.758Z,1582754655.758 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-02-26T22:04:15.758Z,1582754655.758 [Default:CheckIn:Read_GPS] Running Loop=1
2020-02-26T22:04:17.746Z,1582754657.746 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,215257.00,A,3648.18914,N,12147.26878,W,1.380,21.07,260220,,,A*4E
2020-02-26T22:04:17.748Z,1582754657.748 [NAL9602](INFO): GPS fix at 20200226T215257: (36.803152, -121.787813)
2020-02-26T22:04:17.794Z,1582754657.794 [Default:CheckIn:Read_GPS] Stopped
2020-02-26T22:04:17.794Z,1582754657.794 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-02-26T22:04:20.174Z,1582754660.174 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2020-02-26T22:04:25.441Z,1582754665.441 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20200226T202949/Courier0052.lzma
2020-02-26T22:04:27.447Z,1582754667.447 [DataOverHttps](INFO): Moved sent file to Logs/20200226T202949/Courier0052.lzma.bak
2020-02-26T22:04:27.447Z,1582754667.447 [DataOverHttps](INFO): SBD MOMSN=12269989
2020-02-26T22:04:44.509Z,1582754684.509 [DataOverHttps](INFO): Sending 161 bytes from file Logs/20200226T202949/Express0053.lzma
2020-02-26T22:04:46.514Z,1582754686.514 [DataOverHttps](INFO): Moved sent file to Logs/20200226T202949/Express0053.lzma.bak
2020-02-26T22:04:46.515Z,1582754686.515 [DataOverHttps](INFO): SBD MOMSN=12269992
2020-02-26T22:04:48.487Z,1582754688.487 [Default:CheckIn:Read_Iridium] Stopped
2020-02-26T22:04:48.487Z,1582754688.487 [Default:CheckIn:C.Wait] Running Loop=1
2020-02-26T22:04:48.487Z,1582754688.487 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-02-26T22:04:50.874Z,1582754690.874 [NAL9602](INFO): Not Powering down - fast GPS
2020-02-26T22:09:49.079Z,1582754989.079 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-02-26T22:09:49.079Z,1582754989.079 [Default:CheckIn:C.Wait] Stopped
2020-02-26T22:09:49.079Z,1582754989.079 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-02-26T22:09:49.079Z,1582754989.079 [Default:CheckIn:D] Running Loop=1
2020-02-26T22:09:49.473Z,1582754989.473 [Default:CheckIn:D] Stopped
2020-02-26T22:09:49.474Z,1582754989.474 [Default:CheckIn:E] Running Loop=1
2020-02-26T22:09:49.876Z,1582754989.876 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 96.316748 min 
2020-02-26T22:09:49.876Z,1582754989.876 [Default:CheckIn:E] Stopped
2020-02-26T22:09:49.876Z,1582754989.876 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-02-26T22:09:49.876Z,1582754989.876 [Default:CheckIn] Stopped
2020-02-26T22:09:49.876Z,1582754989.876 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-02-26T22:09:49.877Z,1582754989.877 [Default:CheckIn](INFO): Running loop #18
2020-02-26T22:09:49.877Z,1582754989.877 [Default:CheckIn] Running Loop=18
2020-02-26T22:09:49.877Z,1582754989.877 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-02-26T22:09:49.877Z,1582754989.877 [Default:CheckIn:Read_GPS] Running Loop=1
2020-02-26T22:09:51.870Z,1582754991.870 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,215832.00,A,3648.16316,N,12147.28988,W,0.739,48.63,260220,,,A*4B
2020-02-26T22:09:51.872Z,1582754991.872 [NAL9602](INFO): GPS fix at 20200226T215832: (36.802719, -121.788165)
2020-02-26T22:09:51.948Z,1582754991.948 [Default:CheckIn:Read_GPS] Stopped
2020-02-26T22:09:51.948Z,1582754991.948 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-02-26T22:09:59.616Z,1582754999.616 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20200226T202949/Courier0055.lzma
2020-02-26T22:10:01.626Z,1582755001.626 [DataOverHttps](INFO): Moved sent file to Logs/20200226T202949/Courier0055.lzma.bak
2020-02-26T22:10:01.627Z,1582755001.627 [DataOverHttps](INFO): SBD MOMSN=12269996
2020-02-26T22:10:16.563Z,1582755016.563 [NAL9602](INFO): SBD MO Status=2, MOMSN=6608, MT Status=2, MTMSN=0
2020-02-26T22:10:16.563Z,1582755016.563 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-02-26T22:10:18.837Z,1582755018.837 [DataOverHttps](INFO): Sending 196 bytes from file Logs/20200226T202949/Express0056.lzma
2020-02-26T22:10:20.842Z,1582755020.842 [DataOverHttps](INFO): Moved sent file to Logs/20200226T202949/Express0056.lzma.bak
2020-02-26T22:10:20.843Z,1582755020.843 [DataOverHttps](INFO): SBD MOMSN=12269999
2020-02-26T22:10:22.660Z,1582755022.660 [Default:CheckIn:Read_Iridium] Stopped
2020-02-26T22:10:22.661Z,1582755022.661 [Default:CheckIn:C.Wait] Running Loop=1
2020-02-26T22:10:22.661Z,1582755022.661 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-02-26T22:10:37.979Z,1582755037.979 [NAL9602](INFO): SBD MO Status=2, MOMSN=6608, MT Status=2, MTMSN=0
2020-02-26T22:10:37.979Z,1582755037.979 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-02-26T22:13:04.636Z,1582755184.636 [NAL9602](INFO): SBD MO Status=2, MOMSN=6608, MT Status=2, MTMSN=0
2020-02-26T22:13:04.636Z,1582755184.636 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-02-26T22:14:54.524Z,1582755294.524 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2020-02-26T22:15:23.248Z,1582755323.248 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-02-26T22:15:23.248Z,1582755323.248 [Default:CheckIn:C.Wait] Stopped
2020-02-26T22:15:23.248Z,1582755323.248 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-02-26T22:15:23.248Z,1582755323.248 [Default:CheckIn:D] Running Loop=1
2020-02-26T22:15:23.679Z,1582755323.679 [Default:CheckIn:D] Stopped
2020-02-26T22:15:23.679Z,1582755323.679 [Default:CheckIn:E] Running Loop=1
2020-02-26T22:15:24.087Z,1582755324.087 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 101.886841 min 
2020-02-26T22:15:24.087Z,1582755324.087 [Default:CheckIn:E] Stopped
2020-02-26T22:15:24.087Z,1582755324.087 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-02-26T22:15:24.087Z,1582755324.087 [Default:CheckIn] Stopped
2020-02-26T22:15:24.087Z,1582755324.087 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-02-26T22:15:24.087Z,1582755324.087 [Default:CheckIn](INFO): Running loop #19
2020-02-26T22:15:24.088Z,1582755324.088 [Default:CheckIn] Running Loop=19
2020-02-26T22:15:24.088Z,1582755324.088 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-02-26T22:15:24.088Z,1582755324.088 [Default:CheckIn:Read_GPS] Running Loop=1
2020-02-26T22:15:26.044Z,1582755326.044 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,220406.00,A,3648.16500,N,12147.28479,W,1.283,298.05,260220,,,A*7E
2020-02-26T22:15:26.046Z,1582755326.046 [NAL9602](INFO): GPS fix at 20200226T220406: (36.802750, -121.788080)
2020-02-26T22:15:26.112Z,1582755326.112 [Default:CheckIn:Read_GPS] Stopped
2020-02-26T22:15:26.112Z,1582755326.112 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-02-26T22:15:33.440Z,1582755333.440 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20200226T202949/Courier0058.lzma
2020-02-26T22:15:35.446Z,1582755335.446 [DataOverHttps](INFO): Moved sent file to Logs/20200226T202949/Courier0058.lzma.bak
2020-02-26T22:15:35.446Z,1582755335.446 [DataOverHttps](INFO): SBD MOMSN=12270042
2020-02-26T22:15:52.577Z,1582755352.577 [DataOverHttps](INFO): Sending 195 bytes from file Logs/20200226T202949/Express0059.lzma
2020-02-26T22:15:54.583Z,1582755354.583 [DataOverHttps](INFO): Moved sent file to Logs/20200226T202949/Express0059.lzma.bak
2020-02-26T22:15:54.583Z,1582755354.583 [DataOverHttps](INFO): SBD MOMSN=12270046
2020-02-26T22:15:56.576Z,1582755356.576 [Default:CheckIn:Read_Iridium] Stopped
2020-02-26T22:15:56.576Z,1582755356.576 [Default:CheckIn:C.Wait] Running Loop=1
2020-02-26T22:15:56.576Z,1582755356.576 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-02-26T22:15:58.566Z,1582755358.566 [NAL9602](INFO): Not Powering down - fast GPS
2020-02-26T22:20:57.172Z,1582755657.172 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-02-26T22:20:57.172Z,1582755657.172 [Default:CheckIn:C.Wait] Stopped
2020-02-26T22:20:57.172Z,1582755657.172 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-02-26T22:20:57.172Z,1582755657.172 [Default:CheckIn:D] Running Loop=1
2020-02-26T22:20:57.585Z,1582755657.585 [Default:CheckIn:D] Stopped
2020-02-26T22:20:57.585Z,1582755657.585 [Default:CheckIn:E] Running Loop=1
2020-02-26T22:20:57.975Z,1582755657.975 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 107.451953 min 
2020-02-26T22:20:57.975Z,1582755657.975 [Default:CheckIn:E] Stopped
2020-02-26T22:20:57.975Z,1582755657.975 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-02-26T22:20:57.975Z,1582755657.975 [Default:CheckIn] Stopped
2020-02-26T22:20:57.975Z,1582755657.975 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-02-26T22:20:57.976Z,1582755657.976 [Default:CheckIn](INFO): Running loop #20
2020-02-26T22:20:57.976Z,1582755657.976 [Default:CheckIn] Running Loop=20
2020-02-26T22:20:57.976Z,1582755657.976 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-02-26T22:20:57.976Z,1582755657.976 [Default:CheckIn:Read_GPS] Running Loop=1
2020-02-26T22:20:59.976Z,1582755659.976 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,220940.00,A,3648.16183,N,12147.29202,W,0.233,201.36,260220,,,A*7F
2020-02-26T22:20:59.979Z,1582755659.979 [NAL9602](INFO): GPS fix at 20200226T220940: (36.802697, -121.788200)
2020-02-26T22:21:00.003Z,1582755660.003 [Default:CheckIn:Read_GPS] Stopped
2020-02-26T22:21:00.003Z,1582755660.003 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-02-26T22:21:08.008Z,1582755668.008 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20200226T202949/Courier0061.lzma
2020-02-26T22:21:10.014Z,1582755670.014 [DataOverHttps](INFO): Moved sent file to Logs/20200226T202949/Courier0061.lzma.bak
2020-02-26T22:21:10.015Z,1582755670.015 [DataOverHttps](INFO): SBD MOMSN=12270082
2020-02-26T22:21:30.458Z,1582755690.458 [DataOverHttps](INFO): Sending 120 bytes from file Logs/20200226T202949/Express0062.lzma
2020-02-26T22:21:30.692Z,1582755690.692 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2020-02-26T22:21:30.769Z,1582755690.769 [NAL9602](FAULT): received: 
+CSQ:0

OK08, 2, 0, 0, 0

OK
2020-02-26T22:21:30.769Z,1582755690.769 [NAL9602] Data Fault, FailCount= 1
2020-02-26T22:21:30.769Z,1582755690.769 [NAL9602](ERROR): Data Fault
2020-02-26T22:21:30.877Z,1582755690.877 [CBIT](ERROR): Data Fault in component: NAL9602
2020-02-26T22:21:31.098Z,1582755691.098 [NAL9602](INFO): Powering down
2020-02-26T22:21:32.009Z,1582755692.009 [CBIT](INFO): Clearing failed state for component NAL9602
2020-02-26T22:21:32.009Z,1582755692.009 [NAL9602] No Fault, FailCount= 1
2020-02-26T22:21:32.462Z,1582755692.462 [DataOverHttps](INFO): Moved sent file to Logs/20200226T202949/Express0062.lzma.bak
2020-02-26T22:21:32.463Z,1582755692.463 [DataOverHttps](INFO): SBD MOMSN=12270085
2020-02-26T22:21:34.771Z,1582755694.771 [Default:CheckIn:Read_Iridium] Stopped
2020-02-26T22:21:34.772Z,1582755694.772 [Default:CheckIn:C.Wait] Running Loop=1
2020-02-26T22:21:34.772Z,1582755694.772 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-02-26T22:22:01.404Z,1582755721.404 [NAL9602](INFO): Powering up NAL9602
2020-02-26T22:22:12.304Z,1582755732.304 [NAL9602](INFO): NAL9602 initialized
2020-02-26T22:22:43.414Z,1582755763.414 [NAL9602](INFO): Not Powering down - fast GPS
2020-02-26T22:26:35.345Z,1582755995.345 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-02-26T22:26:35.345Z,1582755995.345 [Default:CheckIn:C.Wait] Stopped
2020-02-26T22:26:35.345Z,1582755995.345 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-02-26T22:26:35.345Z,1582755995.345 [Default:CheckIn:D] Running Loop=1
2020-02-26T22:26:35.734Z,1582755995.734 [Default:CheckIn:D] Stopped
2020-02-26T22:26:35.734Z,1582755995.734 [Default:CheckIn:E] Running Loop=1
2020-02-26T22:26:36.140Z,1582755996.140 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 113.087769 min 
2020-02-26T22:26:36.140Z,1582755996.140 [Default:CheckIn:E] Stopped
2020-02-26T22:26:36.141Z,1582755996.141 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-02-26T22:26:36.141Z,1582755996.141 [Default:CheckIn] Stopped
2020-02-26T22:26:36.141Z,1582755996.141 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-02-26T22:26:36.142Z,1582755996.142 [Default:CheckIn](INFO): Running loop #21
2020-02-26T22:26:36.142Z,1582755996.142 [Default:CheckIn] Running Loop=21
2020-02-26T22:26:36.142Z,1582755996.142 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-02-26T22:26:36.142Z,1582755996.142 [Default:CheckIn:Read_GPS] Running Loop=1
2020-02-26T22:26:40.162Z,1582756000.162 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2020-02-26T22:27:27.830Z,1582756047.830 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,221607.00,A,3648.16420,N,12147.28992,W,0.758,242.54,260220,,,A*76
2020-02-26T22:27:27.832Z,1582756047.832 [NAL9602](INFO): GPS fix at 20200226T221607: (36.802737, -121.788165)
2020-02-26T22:27:27.887Z,1582756047.887 [Default:CheckIn:Read_GPS] Stopped
2020-02-26T22:27:27.887Z,1582756047.887 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-02-26T22:27:35.195Z,1582756055.195 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20200226T202949/Courier0064.lzma
2020-02-26T22:27:37.194Z,1582756057.194 [DataOverHttps](INFO): Moved sent file to Logs/20200226T202949/Courier0064.lzma.bak
2020-02-26T22:27:37.194Z,1582756057.194 [DataOverHttps](INFO): SBD MOMSN=12270144
2020-02-26T22:27:54.345Z,1582756074.345 [DataOverHttps](INFO): Sending 237 bytes from file Logs/20200226T202949/Express0065.lzma
2020-02-26T22:27:56.350Z,1582756076.350 [DataOverHttps](INFO): Moved sent file to Logs/20200226T202949/Express0065.lzma.bak
2020-02-26T22:27:56.351Z,1582756076.351 [DataOverHttps](INFO): SBD MOMSN=12270147
2020-02-26T22:27:58.572Z,1582756078.572 [Default:CheckIn:Read_Iridium] Stopped
2020-02-26T22:27:58.572Z,1582756078.572 [Default:CheckIn:C.Wait] Running Loop=1
2020-02-26T22:27:58.572Z,1582756078.572 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-02-26T22:28:00.570Z,1582756080.570 [NAL9602](INFO): Not Powering down - fast GPS
2020-02-26T22:32:59.180Z,1582756379.180 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-02-26T22:32:59.180Z,1582756379.180 [Default:CheckIn:C.Wait] Stopped
2020-02-26T22:32:59.180Z,1582756379.180 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-02-26T22:32:59.180Z,1582756379.180 [Default:CheckIn:D] Running Loop=1
2020-02-26T22:32:59.576Z,1582756379.576 [Default:CheckIn:D] Stopped
2020-02-26T22:32:59.576Z,1582756379.576 [Default:CheckIn:E] Running Loop=1
2020-02-26T22:32:59.990Z,1582756379.990 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 119.485124 min 
2020-02-26T22:32:59.990Z,1582756379.990 [Default:CheckIn:E] Stopped
2020-02-26T22:32:59.990Z,1582756379.990 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-02-26T22:32:59.990Z,1582756379.990 [Default:CheckIn] Stopped
2020-02-26T22:32:59.990Z,1582756379.990 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-02-26T22:32:59.990Z,1582756379.990 [Default:CheckIn](INFO): Running loop #22
2020-02-26T22:32:59.990Z,1582756379.990 [Default:CheckIn] Running Loop=22
2020-02-26T22:32:59.990Z,1582756379.990 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-02-26T22:32:59.990Z,1582756379.990 [Default:CheckIn:Read_GPS] Running Loop=1
2020-02-26T22:33:01.976Z,1582756381.976 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,222142.00,A,3648.16870,N,12147.28645,W,0.933,341.56,260220,,,A*7C
2020-02-26T22:33:01.978Z,1582756381.978 [NAL9602](INFO): GPS fix at 20200226T222142: (36.802812, -121.788107)
2020-02-26T22:33:02.033Z,1582756382.033 [Default:CheckIn:Read_GPS] Stopped
2020-02-26T22:33:02.033Z,1582756382.033 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-02-26T22:33:10.517Z,1582756390.517 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20200226T202949/Courier0067.lzma
2020-02-26T22:33:12.526Z,1582756392.526 [DataOverHttps](INFO): Moved sent file to Logs/20200226T202949/Courier0067.lzma.bak
2020-02-26T22:33:12.526Z,1582756392.526 [DataOverHttps](INFO): SBD MOMSN=12270161
2020-02-26T22:33:29.889Z,1582756409.889 [DataOverHttps](INFO): Sending 120 bytes from file Logs/20200226T202949/Express0068.lzma
2020-02-26T22:33:31.895Z,1582756411.895 [DataOverHttps](INFO): Moved sent file to Logs/20200226T202949/Express0068.lzma.bak
2020-02-26T22:33:31.895Z,1582756411.895 [DataOverHttps](INFO): SBD MOMSN=12270165
2020-02-26T22:33:33.943Z,1582756413.943 [Default:CheckIn:Read_Iridium] Stopped
2020-02-26T22:33:33.943Z,1582756413.943 [Default:CheckIn:C.Wait] Running Loop=1
2020-02-26T22:33:33.943Z,1582756413.943 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-02-26T22:38:04.178Z,1582756684.178 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2020-02-26T22:38:34.516Z,1582756714.516 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-02-26T22:38:34.516Z,1582756714.516 [Default:CheckIn:C.Wait] Stopped
2020-02-26T22:38:34.516Z,1582756714.516 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-02-26T22:38:34.516Z,1582756714.516 [Default:CheckIn:D] Running Loop=1
2020-02-26T22:38:34.886Z,1582756714.886 [NAL9602](INFO): Not Powering down - fast GPS
2020-02-26T22:38:34.910Z,1582756714.910 [Default:CheckIn:D] Stopped
2020-02-26T22:38:34.910Z,1582756714.910 [Default:CheckIn:E] Running Loop=1
2020-02-26T22:38:35.316Z,1582756715.316 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 125.074032 min 
2020-02-26T22:38:35.316Z,1582756715.316 [Default:CheckIn:E] Stopped
2020-02-26T22:38:35.316Z,1582756715.316 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-02-26T22:38:35.316Z,1582756715.316 [Default:CheckIn] Stopped
2020-02-26T22:38:35.316Z,1582756715.316 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-02-26T22:38:35.317Z,1582756715.317 [Default:CheckIn](INFO): Running loop #23
2020-02-26T22:38:35.317Z,1582756715.317 [Default:CheckIn] Running Loop=23
2020-02-26T22:38:35.317Z,1582756715.317 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-02-26T22:38:35.317Z,1582756715.317 [Default:CheckIn:Read_GPS] Running Loop=1
2020-02-26T22:38:37.317Z,1582756717.317 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,222717.00,A,3648.16382,N,12147.28313,W,0.097,341.56,260220,,,A*7D
2020-02-26T22:38:37.319Z,1582756717.319 [NAL9602](INFO): GPS fix at 20200226T222717: (36.802730, -121.788052)
2020-02-26T22:38:37.342Z,1582756717.342 [Default:CheckIn:Read_GPS] Stopped
2020-02-26T22:38:37.342Z,1582756717.342 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-02-26T22:38:44.932Z,1582756724.932 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20200226T202949/Courier0070.lzma
2020-02-26T22:38:46.934Z,1582756726.934 [DataOverHttps](INFO): Moved sent file to Logs/20200226T202949/Courier0070.lzma.bak
2020-02-26T22:38:46.935Z,1582756726.935 [DataOverHttps](INFO): SBD MOMSN=12270195
2020-02-26T22:39:05.069Z,1582756745.069 [DataOverHttps](INFO): Sending 197 bytes from file Logs/20200226T202949/Express0071.lzma
2020-02-26T22:39:07.075Z,1582756747.075 [DataOverHttps](INFO): Moved sent file to Logs/20200226T202949/Express0071.lzma.bak
2020-02-26T22:39:07.075Z,1582756747.075 [DataOverHttps](INFO): SBD MOMSN=12270198
2020-02-26T22:39:08.863Z,1582756748.863 [Default:CheckIn:Read_Iridium] Stopped
2020-02-26T22:39:08.863Z,1582756748.863 [Default:CheckIn:C.Wait] Running Loop=1
2020-02-26T22:39:08.864Z,1582756748.864 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-02-26T22:41:25.809Z,1582756885.809 [NAL9602](INFO): SBD MO Status=2, MOMSN=6608, MT Status=2, MTMSN=0
2020-02-26T22:41:25.809Z,1582756885.809 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-02-26T22:42:53.455Z,1582756973.455 [NAL9602](INFO): SBD MO Status=2, MOMSN=6608, MT Status=2, MTMSN=0
2020-02-26T22:42:53.455Z,1582756973.455 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-02-26T22:43:39.530Z,1582757019.530 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2020-02-26T22:44:09.448Z,1582757049.448 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-02-26T22:44:09.448Z,1582757049.448 [Default:CheckIn:C.Wait] Stopped
2020-02-26T22:44:09.448Z,1582757049.448 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-02-26T22:44:09.448Z,1582757049.448 [Default:CheckIn:D] Running Loop=1
2020-02-26T22:44:09.858Z,1582757049.858 [Default:CheckIn:D] Stopped
2020-02-26T22:44:09.858Z,1582757049.858 [Default:CheckIn:E] Running Loop=1
2020-02-26T22:44:10.234Z,1582757050.234 [NAL9602](INFO): Not Powering down - fast GPS
2020-02-26T22:44:10.286Z,1582757050.286 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 130.656502 min 
2020-02-26T22:44:10.286Z,1582757050.286 [Default:CheckIn:E] Stopped
2020-02-26T22:44:10.287Z,1582757050.287 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-02-26T22:44:10.287Z,1582757050.287 [Default:CheckIn] Stopped
2020-02-26T22:44:10.287Z,1582757050.287 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-02-26T22:44:10.287Z,1582757050.287 [Default:CheckIn](INFO): Running loop #24
2020-02-26T22:44:10.287Z,1582757050.287 [Default:CheckIn] Running Loop=24
2020-02-26T22:44:10.287Z,1582757050.287 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-02-26T22:44:10.287Z,1582757050.287 [Default:CheckIn:Read_GPS] Running Loop=1
2020-02-26T22:44:12.256Z,1582757052.256 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,223252.00,A,3648.16262,N,12147.28515,W,0.233,341.56,260220,,,A*7B
2020-02-26T22:44:12.258Z,1582757052.258 [NAL9602](INFO): GPS fix at 20200226T223252: (36.802710, -121.788086)
2020-02-26T22:44:12.303Z,1582757052.303 [Default:CheckIn:Read_GPS] Stopped
2020-02-26T22:44:12.304Z,1582757052.304 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-02-26T22:44:20.084Z,1582757060.084 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20200226T202949/Courier0073.lzma
2020-02-26T22:44:22.090Z,1582757062.090 [DataOverHttps](INFO): Moved sent file to Logs/20200226T202949/Courier0073.lzma.bak
2020-02-26T22:44:22.091Z,1582757062.091 [DataOverHttps](INFO): SBD MOMSN=12270224
2020-02-26T22:44:39.269Z,1582757079.269 [DataOverHttps](INFO): Sending 197 bytes from file Logs/20200226T202949/Express0074.lzma
2020-02-26T22:44:41.274Z,1582757081.274 [DataOverHttps](INFO): Moved sent file to Logs/20200226T202949/Express0074.lzma.bak
2020-02-26T22:44:41.275Z,1582757081.275 [DataOverHttps](INFO): SBD MOMSN=12270227
2020-02-26T22:44:42.954Z,1582757082.954 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2020-02-26T22:44:43.029Z,1582757083.029 [NAL9602](FAULT): received: 
+CSQ:1

OK08, 2, 0, 0, 0

OK
2020-02-26T22:44:43.029Z,1582757083.029 [NAL9602] Data Fault, FailCount= 1
2020-02-26T22:44:43.029Z,1582757083.029 [NAL9602](ERROR): Data Fault
2020-02-26T22:44:43.060Z,1582757083.060 [Default:CheckIn:Read_Iridium] Stopped
2020-02-26T22:44:43.060Z,1582757083.060 [Default:CheckIn:C.Wait] Running Loop=1
2020-02-26T22:44:43.060Z,1582757083.060 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-02-26T22:44:43.141Z,1582757083.141 [CBIT](ERROR): Data Fault in component: NAL9602
2020-02-26T22:44:43.358Z,1582757083.358 [NAL9602](INFO): Powering down
2020-02-26T22:44:44.288Z,1582757084.288 [CBIT](INFO): Clearing failed state for component NAL9602
2020-02-26T22:44:44.305Z,1582757084.305 [NAL9602] No Fault, FailCount= 1
2020-02-26T22:45:13.656Z,1582757113.656 [NAL9602](INFO): Powering up NAL9602
2020-02-26T22:45:24.578Z,1582757124.578 [NAL9602](INFO): NAL9602 initialized
2020-02-26T22:45:55.706Z,1582757155.706 [NAL9602](INFO): Not Powering down - fast GPS
2020-02-26T22:48:27.650Z,1582757307.650 [BPC1](ERROR): BPC1B: No match for serial number 1717 in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2020-02-26T22:49:43.597Z,1582757383.597 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-02-26T22:49:43.597Z,1582757383.597 [Default:CheckIn:C.Wait] Stopped
2020-02-26T22:49:43.597Z,1582757383.597 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-02-26T22:49:43.597Z,1582757383.597 [Default:CheckIn:D] Running Loop=1
2020-02-26T22:49:44.007Z,1582757384.007 [Default:CheckIn:D] Stopped
2020-02-26T22:49:44.007Z,1582757384.007 [Default:CheckIn:E] Running Loop=1
2020-02-26T22:49:44.413Z,1582757384.413 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 136.225651 min 
2020-02-26T22:49:44.413Z,1582757384.413 [Default:CheckIn:E] Stopped
2020-02-26T22:49:44.413Z,1582757384.413 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-02-26T22:49:44.413Z,1582757384.413 [Default:CheckIn] Stopped
2020-02-26T22:49:44.413Z,1582757384.413 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-02-26T22:49:44.413Z,1582757384.413 [Default:CheckIn](INFO): Running loop #25
2020-02-26T22:49:44.414Z,1582757384.414 [Default:CheckIn] Running Loop=25
2020-02-26T22:49:44.414Z,1582757384.414 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-02-26T22:49:44.414Z,1582757384.414 [Default:CheckIn:Read_GPS] Running Loop=1
2020-02-26T22:49:46.402Z,1582757386.402 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,223825.00,A,3648.16106,N,12147.28074,W,0.467,14.24,260220,,,A*43
2020-02-26T22:49:46.404Z,1582757386.404 [NAL9602](INFO): GPS fix at 20200226T223825: (36.802684, -121.788012)
2020-02-26T22:49:46.429Z,1582757386.429 [Default:CheckIn:Read_GPS] Stopped
2020-02-26T22:49:46.429Z,1582757386.429 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-02-26T22:49:48.309Z,1582757388.309 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2020-02-26T22:49:54.838Z,1582757394.838 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20200226T202949/Courier0076.lzma
2020-02-26T22:49:56.847Z,1582757396.847 [DataOverHttps](INFO): Moved sent file to Logs/20200226T202949/Courier0076.lzma.bak
2020-02-26T22:49:56.847Z,1582757396.847 [DataOverHttps](INFO): SBD MOMSN=12270238
2020-02-26T22:50:14.201Z,1582757414.201 [DataOverHttps](INFO): Sending 162 bytes from file Logs/20200226T202949/Express0077.lzma
2020-02-26T22:50:16.207Z,1582757416.207 [DataOverHttps](INFO): Moved sent file to Logs/20200226T202949/Express0077.lzma.bak
2020-02-26T22:50:16.207Z,1582757416.207 [DataOverHttps](INFO): SBD MOMSN=12270241
2020-02-26T22:50:18.248Z,1582757418.248 [Default:CheckIn:Read_Iridium] Stopped
2020-02-26T22:50:18.248Z,1582757418.248 [Default:CheckIn:C.Wait] Running Loop=1
2020-02-26T22:50:18.248Z,1582757418.248 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-02-26T22:50:19.014Z,1582757419.014 [NAL9602](INFO): Not Powering down - fast GPS
2020-02-26T22:52:34.802Z,1582757554.802 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2020-02-26T22:52:34.804Z,1582757554.804 [BPC1](INFO): Received data from all battery sticks.
2020-02-26T22:55:18.827Z,1582757718.827 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-02-26T22:55:18.828Z,1582757718.828 [Default:CheckIn:C.Wait] Stopped
2020-02-26T22:55:18.828Z,1582757718.828 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-02-26T22:55:18.828Z,1582757718.828 [Default:CheckIn:D] Running Loop=1
2020-02-26T22:55:19.214Z,1582757719.214 [Default:CheckIn:D] Stopped
2020-02-26T22:55:19.214Z,1582757719.214 [Default:CheckIn:E] Running Loop=1
2020-02-26T22:55:19.624Z,1582757719.624 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 141.812435 min 
2020-02-26T22:55:19.624Z,1582757719.624 [Default:CheckIn:E] Stopped
2020-02-26T22:55:19.624Z,1582757719.624 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-02-26T22:55:19.624Z,1582757719.624 [Default:CheckIn] Stopped
2020-02-26T22:55:19.624Z,1582757719.624 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-02-26T22:55:19.625Z,1582757719.625 [Default:CheckIn](INFO): Running loop #26
2020-02-26T22:55:19.625Z,1582757719.625 [Default:CheckIn] Running Loop=26
2020-02-26T22:55:19.625Z,1582757719.625 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-02-26T22:55:19.625Z,1582757719.625 [Default:CheckIn:Read_GPS] Running Loop=1
2020-02-26T22:55:21.620Z,1582757721.620 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,224401.00,A,3648.16158,N,12147.28423,W,0.389,14.24,260220,,,A*44
2020-02-26T22:55:21.626Z,1582757721.626 [NAL9602](INFO): GPS fix at 20200226T224401: (36.802693, -121.788071)
2020-02-26T22:55:21.698Z,1582757721.698 [Default:CheckIn:Read_GPS] Stopped
2020-02-26T22:55:21.698Z,1582757721.698 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-02-26T22:55:29.379Z,1582757729.379 [DataOverHttps](INFO): Sending 80 bytes from file Logs/20200226T202949/Courier0079.lzma
2020-02-26T22:55:31.385Z,1582757731.385 [DataOverHttps](INFO): Moved sent file to Logs/20200226T202949/Courier0079.lzma.bak
2020-02-26T22:55:31.385Z,1582757731.385 [DataOverHttps](INFO): SBD MOMSN=12270255
2020-02-26T22:55:48.637Z,1582757748.637 [DataOverHttps](INFO): Sending 197 bytes from file Logs/20200226T202949/Express0080.lzma
2020-02-26T22:55:50.643Z,1582757750.643 [DataOverHttps](INFO): Moved sent file to Logs/20200226T202949/Express0080.lzma.bak
2020-02-26T22:55:50.643Z,1582757750.643 [DataOverHttps](INFO): SBD MOMSN=12270258
2020-02-26T22:55:52.365Z,1582757752.365 [Default:CheckIn:Read_Iridium] Stopped
2020-02-26T22:55:52.365Z,1582757752.365 [Default:CheckIn:C.Wait] Running Loop=1
2020-02-26T22:55:52.365Z,1582757752.365 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-02-26T22:59:57.166Z,1582757997.166 [NAL9602](INFO): SBD MO Status=2, MOMSN=6608, MT Status=2, MTMSN=0
2020-02-26T22:59:57.166Z,1582757997.166 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-02-26T23:00:24.235Z,1582758024.235 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2020-02-26T23:00:52.939Z,1582758052.939 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-02-26T23:00:52.939Z,1582758052.939 [Default:CheckIn:C.Wait] Stopped
2020-02-26T23:00:52.940Z,1582758052.940 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-02-26T23:00:52.940Z,1582758052.940 [Default:CheckIn:D] Running Loop=1
2020-02-26T23:00:53.359Z,1582758053.359 [Default:CheckIn:D] Stopped
2020-02-26T23:00:53.359Z,1582758053.359 [Default:CheckIn:E] Running Loop=1
2020-02-26T23:00:53.756Z,1582758053.756 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 147.381527 min 
2020-02-26T23:00:53.757Z,1582758053.757 [Default:CheckIn:E] Stopped
2020-02-26T23:00:53.758Z,1582758053.758 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-02-26T23:00:53.758Z,1582758053.758 [Default:CheckIn] Stopped
2020-02-26T23:00:53.758Z,1582758053.758 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-02-26T23:00:53.759Z,1582758053.759 [Default:CheckIn](INFO): Running loop #27
2020-02-26T23:00:53.759Z,1582758053.759 [Default:CheckIn] Running Loop=27
2020-02-26T23:00:53.760Z,1582758053.760 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-02-26T23:00:53.760Z,1582758053.760 [Default:CheckIn:Read_GPS] Running Loop=1
2020-02-26T23:00:55.750Z,1582758055.750 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,224936.00,A,3648.16357,N,12147.28028,W,0.039,14.24,260220,,,A*47
2020-02-26T23:00:55.752Z,1582758055.752 [NAL9602](INFO): GPS fix at 20200226T224936: (36.802726, -121.788005)
2020-02-26T23:00:55.776Z,1582758055.776 [Default:CheckIn:Read_GPS] Stopped
2020-02-26T23:00:55.776Z,1582758055.776 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-02-26T23:01:03.092Z,1582758063.092 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20200226T202949/Courier0082.lzma
2020-02-26T23:01:05.099Z,1582758065.099 [DataOverHttps](INFO): Moved sent file to Logs/20200226T202949/Courier0082.lzma.bak
2020-02-26T23:01:05.099Z,1582758065.099 [DataOverHttps](INFO): SBD MOMSN=12270268
2020-02-26T23:01:22.841Z,1582758082.841 [DataOverHttps](INFO): Sending 196 bytes from file Logs/20200226T202949/Express0083.lzma
2020-02-26T23:01:24.847Z,1582758084.847 [DataOverHttps](INFO): Moved sent file to Logs/20200226T202949/Express0083.lzma.bak
2020-02-26T23:01:24.847Z,1582758084.847 [DataOverHttps](INFO): SBD MOMSN=12270271
2020-02-26T23:01:26.907Z,1582758086.907 [Default:CheckIn:Read_Iridium] Stopped
2020-02-26T23:01:26.907Z,1582758086.907 [Default:CheckIn:C.Wait] Running Loop=1
2020-02-26T23:01:26.907Z,1582758086.907 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-02-26T23:01:28.474Z,1582758088.474 [NAL9602](INFO): Not Powering down - fast GPS
2020-02-26T23:06:27.472Z,1582758387.472 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-02-26T23:06:27.472Z,1582758387.472 [Default:CheckIn:C.Wait] Stopped
2020-02-26T23:06:27.472Z,1582758387.472 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-02-26T23:06:27.472Z,1582758387.472 [Default:CheckIn:D] Running Loop=1
2020-02-26T23:06:27.882Z,1582758387.882 [Default:CheckIn:D] Stopped
2020-02-26T23:06:27.882Z,1582758387.882 [Default:CheckIn:E] Running Loop=1
2020-02-26T23:06:28.272Z,1582758388.272 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 152.956885 min 
2020-02-26T23:06:28.273Z,1582758388.273 [Default:CheckIn:E] Stopped
2020-02-26T23:06:28.273Z,1582758388.273 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-02-26T23:06:28.273Z,1582758388.273 [Default:CheckIn] Stopped
2020-02-26T23:06:28.273Z,1582758388.273 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-02-26T23:06:28.273Z,1582758388.273 [Default:CheckIn](INFO): Running loop #28
2020-02-26T23:06:28.273Z,1582758388.273 [Default:CheckIn] Running Loop=28
2020-02-26T23:06:28.273Z,1582758388.273 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-02-26T23:06:28.274Z,1582758388.274 [Default:CheckIn:Read_GPS] Running Loop=1
2020-02-26T23:06:30.269Z,1582758390.269 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,225510.00,A,3648.16505,N,12147.28244,W,0.000,0.00,260220,,,A*7E
2020-02-26T23:06:30.271Z,1582758390.271 [NAL9602](INFO): GPS fix at 20200226T225510: (36.802751, -121.788041)
2020-02-26T23:06:30.300Z,1582758390.300 [Default:CheckIn:Read_GPS] Stopped
2020-02-26T23:06:30.300Z,1582758390.300 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-02-26T23:06:37.584Z,1582758397.584 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20200226T202949/Courier0085.lzma
2020-02-26T23:06:39.592Z,1582758399.592 [DataOverHttps](INFO): Moved sent file to Logs/20200226T202949/Courier0085.lzma.bak
2020-02-26T23:06:39.592Z,1582758399.592 [DataOverHttps](INFO): SBD MOMSN=12270281
2020-02-26T23:06:56.785Z,1582758416.785 [DataOverHttps](INFO): Sending 120 bytes from file Logs/20200226T202949/Express0086.lzma
2020-02-26T23:06:58.791Z,1582758418.791 [DataOverHttps](INFO): Moved sent file to Logs/20200226T202949/Express0086.lzma.bak
2020-02-26T23:06:58.791Z,1582758418.791 [DataOverHttps](INFO): SBD MOMSN=12270284
2020-02-26T23:07:00.688Z,1582758420.688 [Default:CheckIn:Read_Iridium] Stopped
2020-02-26T23:07:00.688Z,1582758420.688 [Default:CheckIn:C.Wait] Running Loop=1
2020-02-26T23:07:00.688Z,1582758420.688 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-02-26T23:07:01.052Z,1582758421.052 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2020-02-26T23:07:01.129Z,1582758421.129 [NAL9602](FAULT): received: 
+CSQ:1

OK08, 2, 0, 0, 0

OK
2020-02-26T23:07:01.129Z,1582758421.129 [NAL9602] Data Fault, FailCount= 1
2020-02-26T23:07:01.129Z,1582758421.129 [NAL9602](ERROR): Data Fault
2020-02-26T23:07:01.241Z,1582758421.241 [CBIT](ERROR): Data Fault in component: NAL9602
2020-02-26T23:07:01.458Z,1582758421.458 [NAL9602](INFO): Powering down
2020-02-26T23:07:02.381Z,1582758422.381 [CBIT](INFO): Clearing failed state for component NAL9602
2020-02-26T23:07:02.381Z,1582758422.381 [NAL9602] No Fault, FailCount= 1
2020-02-26T23:07:31.756Z,1582758451.756 [NAL9602](INFO): Powering up NAL9602
2020-02-26T23:07:42.666Z,1582758462.666 [NAL9602](INFO): NAL9602 initialized
2020-02-26T23:08:13.774Z,1582758493.774 [NAL9602](INFO): Not Powering down - fast GPS
2020-02-26T23:12:01.267Z,1582758721.267 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-02-26T23:12:01.267Z,1582758721.267 [Default:CheckIn:C.Wait] Stopped
2020-02-26T23:12:01.267Z,1582758721.267 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-02-26T23:12:01.268Z,1582758721.268 [Default:CheckIn:D] Running Loop=1
2020-02-26T23:12:01.672Z,1582758721.672 [Default:CheckIn:D] Stopped
2020-02-26T23:12:01.672Z,1582758721.672 [Default:CheckIn:E] Running Loop=1
2020-02-26T23:12:02.088Z,1582758722.088 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 158.520052 min 
2020-02-26T23:12:02.088Z,1582758722.088 [Default:CheckIn:E] Stopped
2020-02-26T23:12:02.088Z,1582758722.088 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-02-26T23:12:02.088Z,1582758722.088 [Default:CheckIn] Stopped
2020-02-26T23:12:02.089Z,1582758722.089 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-02-26T23:12:02.089Z,1582758722.089 [Default:CheckIn](INFO): Running loop #29
2020-02-26T23:12:02.089Z,1582758722.089 [Default:CheckIn] Running Loop=29
2020-02-26T23:12:02.089Z,1582758722.089 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-02-26T23:12:02.089Z,1582758722.089 [Default:CheckIn:Read_GPS] Running Loop=1
2020-02-26T23:12:04.076Z,1582758724.076 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,230043.00,A,3648.16408,N,12147.28275,W,0.700,98.69,260220,,,A*4E
2020-02-26T23:12:04.078Z,1582758724.078 [NAL9602](INFO): GPS fix at 20200226T230043: (36.802735, -121.788046)
2020-02-26T23:12:04.131Z,1582758724.131 [Default:CheckIn:Read_GPS] Stopped
2020-02-26T23:12:04.131Z,1582758724.131 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-02-26T23:12:06.098Z,1582758726.098 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2020-02-26T23:12:11.648Z,1582758731.648 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20200226T202949/Courier0088.lzma
2020-02-26T23:12:13.654Z,1582758733.654 [DataOverHttps](INFO): Moved sent file to Logs/20200226T202949/Courier0088.lzma.bak
2020-02-26T23:12:13.655Z,1582758733.655 [DataOverHttps](INFO): SBD MOMSN=12270294
2020-02-26T23:12:16.829Z,1582758736.829 [CommandLine](IMPORTANT): got command report
2020-02-26T23:12:19.985Z,1582758739.985 [CommandLine](IMPORTANT): got command show variable x_velo
2020-02-26T23:12:19.990Z,1582758739.990 [CommandLine](IMPORTANT): platform_x_velocity_wrt_ground (unknown)
2020-02-26T23:12:19.991Z,1582758739.991 [CommandLine](IMPORTANT): platform_x_velocity_wrt_sea_water (meter_per_second)
2020-02-26T23:12:19.991Z,1582758739.991 [CommandLine](IMPORTANT): platform_x_velocity_current (unknown)
2020-02-26T23:12:20.091Z,1582758740.091 [CommandLine](IMPORTANT): SpeedCalculator.platform_x_velocity_wrt_sea_water (meter_per_second)
2020-02-26T23:12:31.414Z,1582758751.414 [DataOverHttps](INFO): Sending 163 bytes from file Logs/20200226T202949/Express0089.lzma
2020-02-26T23:12:33.419Z,1582758753.419 [DataOverHttps](INFO): Moved sent file to Logs/20200226T202949/Express0089.lzma.bak
2020-02-26T23:12:33.419Z,1582758753.419 [DataOverHttps](INFO): SBD MOMSN=12270297
2020-02-26T23:12:35.216Z,1582758755.216 [Default:CheckIn:Read_Iridium] Stopped
2020-02-26T23:12:35.216Z,1582758755.216 [Default:CheckIn:C.Wait] Running Loop=1
2020-02-26T23:12:35.216Z,1582758755.216 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-02-26T23:12:35.264Z,1582758755.264 [CommandLine](IMPORTANT): got command report touch platform_x_velocity_wrt_ground
2020-02-26T23:12:35.265Z,1582758755.265 [CommandLine](IMPORTANT): got command report touch platform_y_velocity_wrt_ground
2020-02-26T23:12:36.802Z,1582758756.802 [NAL9602](INFO): Not Powering down - fast GPS
2020-02-26T23:12:45.866Z,1582758765.866 [CommandLine](IMPORTANT): got command show best height_above_sea_floor
2020-02-26T23:12:45.866Z,1582758765.866 [CommandLine](IMPORTANT): height_above_sea_floor best is null
2020-02-26T23:12:48.081Z,1582758768.081 [CommandLine](IMPORTANT): got command failComponent
2020-02-26T23:12:48.081Z,1582758768.081 [CommandLine](IMPORTANT): Failed components:
2020-02-26T23:12:48.081Z,1582758768.081 [CommandLine](IMPORTANT): No failed Components.
2020-02-26T23:13:32.594Z,1582758812.594 [CommandLine](IMPORTANT): got command configSet list
2020-02-26T23:13:32.594Z,1582758812.594 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2020-02-26T23:13:32.595Z,1582758812.595 [CommandLine](IMPORTANT): BR_Ping1D.loadAtStartup=0 bool;

2020-02-26T23:13:32.595Z,1582758812.595 [CommandLine](IMPORTANT): CBIT.gf24Offset=143 microampere;

2020-02-26T23:13:32.595Z,1582758812.595 [CommandLine](IMPORTANT): DAT.sbdAddress=-1 enum;

2020-02-26T23:13:32.595Z,1582758812.595 [CommandLine](IMPORTANT): DAT.transponderAddress=4 enum;

2020-02-26T23:13:32.595Z,1582758812.595 [CommandLine](IMPORTANT): DAT.verbosity=3 count;

2020-02-26T23:13:32.595Z,1582758812.595 [CommandLine](IMPORTANT): ESPComponent.loadAtStartup=1 bool;

2020-02-26T23:13:32.595Z,1582758812.595 [CommandLine](IMPORTANT): ESPComponent.sampleTimeout=5 minute;

2020-02-26T23:13:32.595Z,1582758812.595 [CommandLine](IMPORTANT): ESPComponent.simulateHardware=1 bool;

2020-02-26T23:13:32.596Z,1582758812.596 [CommandLine](IMPORTANT): Express linearApproximation CTD_Seabird.bin_median_sea_water_temperature 0.025000 kelvin;

2020-02-26T23:13:32.596Z,1582758812.596 [CommandLine](IMPORTANT): Express linearApproximation WetLabsUBAT.flow_rate 50.000000 liter_per_second;

2020-02-26T23:13:32.596Z,1582758812.596 [CommandLine](IMPORTANT): Express linearApproximation acoustic_contact_range 15.000000 meter;

2020-02-26T23:13:32.596Z,1582758812.596 [CommandLine](IMPORTANT): Express linearApproximation height_above_sea_floor 5.000000 meter;

2020-02-26T23:13:32.596Z,1582758812.596 [CommandLine](IMPORTANT): IBIT.batteryCapacityThreshold=5 ampere_hour;

2020-02-26T23:13:32.596Z,1582758812.596 [CommandLine](IMPORTANT): IBIT.batteryVoltageThreshold=13 volt;

2020-02-26T23:13:32.596Z,1582758812.596 [CommandLine](IMPORTANT): RDI_Pathfinder.loadAtStartup=0 bool;

2020-02-26T23:13:32.596Z,1582758812.596 [CommandLine](IMPORTANT): VerticalControl.buoyancyNeutral=225 cubic_centimeter;

2020-02-26T23:13:32.596Z,1582758812.596 [CommandLine](IMPORTANT): VerticalControl.massDefault=5 millimeter;

2020-02-26T23:13:32.605Z,1582758812.605 [CommandLine](IMPORTANT): WetLabsUBAT.loadAtStartup=1 bool;

2020-02-26T23:17:30.126Z,1582759050.126 [DataOverHttps](IMPORTANT): SBD MTMSN=20200226T230609
2020-02-26T23:17:35.787Z,1582759055.787 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-02-26T23:17:35.788Z,1582759055.788 [Default:CheckIn:C.Wait] Stopped
2020-02-26T23:17:35.788Z,1582759055.788 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-02-26T23:17:35.788Z,1582759055.788 [Default:CheckIn:D] Running Loop=1
2020-02-26T23:17:36.204Z,1582759056.204 [Default:CheckIn:D] Stopped
2020-02-26T23:17:36.204Z,1582759056.204 [Default:CheckIn:E] Running Loop=1
2020-02-26T23:17:36.610Z,1582759056.610 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 164.095589 min 
2020-02-26T23:17:36.610Z,1582759056.610 [Default:CheckIn:E] Stopped
2020-02-26T23:17:36.611Z,1582759056.611 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-02-26T23:17:36.611Z,1582759056.611 [Default:CheckIn] Stopped
2020-02-26T23:17:36.611Z,1582759056.611 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-02-26T23:17:36.611Z,1582759056.611 [Default:CheckIn](INFO): Running loop #30
2020-02-26T23:17:36.611Z,1582759056.611 [Default:CheckIn] Running Loop=30
2020-02-26T23:17:36.611Z,1582759056.611 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-02-26T23:17:36.611Z,1582759056.611 [Default:CheckIn:Read_GPS] Running Loop=1
2020-02-26T23:17:37.713Z,1582759057.713 [DataOverHttps](INFO): Received command:restart app
2020-02-26T23:17:37.769Z,1582759057.769 [CommandLine](IMPORTANT): got command restart application
2020-02-26T23:17:38.592Z,1582759058.592 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,230617.00,A,3648.16798,N,12147.28252,W,0.156,8.86,260220,,,A*7B
2020-02-26T23:17:38.594Z,1582759058.594 [NAL9602](INFO): GPS fix at 20200226T230617: (36.802800, -121.788042)
2020-02-26T23:17:38.618Z,1582759058.618 [Default:CheckIn:Read_GPS] Stopped
2020-02-26T23:17:38.618Z,1582759058.618 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-02-26T23:17:38.825Z,1582759058.825 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2020-02-26T23:17:38.825Z,1582759058.825 [CommandLine ThreadHandler](INFO): Thread cancelled.
2020-02-26T23:17:38.925Z,1582759058.925 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2020-02-26T23:17:38.925Z,1582759058.925 [CommandLine ThreadHandler](INFO): Thread cancelled.
2020-02-26T23:17:38.926Z,1582759058.926 [CommandLine](INFO): Join timeout helper Thread ID is 2428
2020-02-26T23:17:38.926Z,1582759058.926 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2020-02-26T23:17:38.926Z,1582759058.926 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2020-02-26T23:17:38.927Z,1582759058.927 [NavChartDb](INFO): Join timeout helper Thread ID is 2429
2020-02-26T23:17:39.233Z,1582759059.233 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2020-02-26T23:17:39.233Z,1582759059.233 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2020-02-26T23:17:39.249Z,1582759059.249 [ComponentRegistry](INFO): Shutting down WetLabsUBAT ThreadHandler
2020-02-26T23:17:39.249Z,1582759059.249 [WetLabsUBAT ThreadHandler](INFO): Thread cancelled.
2020-02-26T23:17:39.249Z,1582759059.249 [WetLabsUBAT](INFO): Join timeout helper Thread ID is 2430
2020-02-26T23:17:39.589Z,1582759059.589 [WetLabsUBAT ThreadHandler](INFO): Uninitializing protected caller thread.
2020-02-26T23:17:39.589Z,1582759059.589 [WetLabsUBAT](INFO): Powering down
2020-02-26T23:17:39.606Z,1582759059.606 [WetLabsUBAT ThreadHandler](INFO): Thread cancelled.
2020-02-26T23:17:39.617Z,1582759059.617 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2020-02-26T23:17:39.617Z,1582759059.617 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2020-02-26T23:17:39.617Z,1582759059.617 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 2431
2020-02-26T23:17:40.026Z,1582759060.026 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2020-02-26T23:17:40.026Z,1582759060.026 [WetLabsBB2FL](INFO): Powering down
2020-02-26T23:17:40.027Z,1582759060.027 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2020-02-26T23:17:40.037Z,1582759060.037 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2020-02-26T23:17:40.037Z,1582759060.037 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2020-02-26T23:17:40.037Z,1582759060.037 [CTD_Seabird](INFO): Join timeout helper Thread ID is 2432
2020-02-26T23:17:40.993Z,1582759060.993 [CTD_Seabird](INFO): Powering down
2020-02-26T23:17:41.005Z,1582759061.005 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2020-02-26T23:17:41.005Z,1582759061.005 [CTD_Seabird](INFO): Powering down
2020-02-26T23:17:41.017Z,1582759061.017 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2020-02-26T23:17:41.026Z,1582759061.026 [ComponentRegistry](INFO): Shutting down BackSeatDriver ThreadHandler
2020-02-26T23:17:41.026Z,1582759061.026 [BackSeatDriver ThreadHandler](INFO): Thread cancelled.
2020-02-26T23:17:41.026Z,1582759061.026 [BackSeatDriver](INFO): Join timeout helper Thread ID is 2433
2020-02-26T23:17:41.281Z,1582759061.281 [BackSeatDriver ThreadHandler](INFO): Uninitializing protected caller thread.
2020-02-26T23:17:41.281Z,1582759061.281 [BackSeatDriver ThreadHandler](INFO): Thread cancelled.
2020-02-26T23:17:41.294Z,1582759061.294 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2020-02-26T23:17:41.294Z,1582759061.294 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2020-02-26T23:17:41.294Z,1582759061.294 [Radio_Surface](INFO): Join timeout helper Thread ID is 2435
2020-02-26T23:17:41.625Z,1582759061.625 [Radio_Surface](INFO): Powering down
2020-02-26T23:17:41.626Z,1582759061.626 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2020-02-26T23:17:41.626Z,1582759061.626 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2020-02-26T23:17:41.646Z,1582759061.646 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2020-02-26T23:17:41.646Z,1582759061.646 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2020-02-26T23:17:41.646Z,1582759061.646 [DataOverHttps](INFO): Join timeout helper Thread ID is 2438
2020-02-26T23:17:41.725Z,1582759061.725 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2020-02-26T23:17:41.726Z,1582759061.726 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2020-02-26T23:17:41.727Z,1582759061.727 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2020-02-26T23:17:41.727Z,1582759061.727 [logger ThreadHandler](INFO): Thread cancelled.
2020-02-26T23:17:41.727Z,1582759061.727 [logger](INFO): Join timeout helper Thread ID is 2439
2020-02-26T23:17:41.773Z,1582759061.773 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2020-02-26T23:17:41.773Z,1582759061.773 [logger ThreadHandler](INFO): Thread cancelled.
2020-02-26T23:17:41.786Z,1582759061.786 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2020-02-26T23:17:41.786Z,1582759061.786 [CommandLine ThreadHandler](INFO): Thread cancelled.
2020-02-26T23:17:41.786Z,1582759061.786 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2020-02-26T23:17:41.786Z,1582759061.786 [controlThread ThreadHandler](INFO): Thread cancelled.
2020-02-26T23:17:41.786Z,1582759061.786 [controlThread](INFO): Join timeout helper Thread ID is 2440
2020-02-26T23:17:41.801Z,1582759061.801 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2020-02-26T23:17:41.801Z,1582759061.801 [controlThread](DEBUG): Uninitializing ControlThread
2020-02-26T23:17:41.802Z,1582759061.802 [AHRS_M2](INFO): Powering down
2020-02-26T23:17:41.874Z,1582759061.874 [NAL9602](INFO): Powering down
2020-02-26T23:17:41.875Z,1582759061.875 [DAT](INFO): Powering down
2020-02-26T23:17:41.994Z,1582759061.994 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2020-02-26T23:17:41.995Z,1582759061.995 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2020-02-26T23:17:41.995Z,1582759061.995 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2020-02-26T23:17:41.996Z,1582759061.996 [MissionManager](INFO): Uninitializing Mission Default
2020-02-26T23:17:41.996Z,1582759061.996 [Default] Stopped
2020-02-26T23:17:41.996Z,1582759061.996 [Default](DEBUG): Aggregate::uninitialize Default
2020-02-26T23:17:41.996Z,1582759061.996 [Default:B.GoToSurface] Stopped
2020-02-26T23:17:41.996Z,1582759061.996 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2020-02-26T23:17:41.996Z,1582759061.996 [Default:CheckIn] Stopped
2020-02-26T23:17:41.996Z,1582759061.996 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-02-26T23:17:41.996Z,1582759061.996 [Default:CheckIn:Read_Iridium] Stopped
2020-02-26T23:17:41.999Z,1582759061.999 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2020-02-26T23:17:41.999Z,1582759061.999 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2020-02-26T23:17:41.999Z,1582759061.999 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2020-02-26T23:17:41.999Z,1582759061.999 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2020-02-26T23:17:41.000Z,1582759062.000 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2020-02-26T23:17:41.000Z,1582759062.000 [BuoyancyServo](INFO): Powering down
2020-02-26T23:17:42.013Z,1582759062.013 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2020-02-26T23:17:42.013Z,1582759062.013 [ElevatorServo](INFO): Powering down
2020-02-26T23:17:42.014Z,1582759062.014 [MassServo](DEBUG): Uninitialize Mass Servo.
2020-02-26T23:17:42.014Z,1582759062.014 [MassServo](INFO): Powering down
2020-02-26T23:17:42.015Z,1582759062.015 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2020-02-26T23:17:42.015Z,1582759062.015 [RudderServo](INFO): Powering down
2020-02-26T23:17:42.016Z,1582759062.016 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2020-02-26T23:17:42.016Z,1582759062.016 [ThrusterServo](INFO): Powering down
2020-02-26T23:17:42.017Z,1582759062.017 [SBIT](DEBUG): Uninitialize SBIT Component.
2020-02-26T23:17:42.017Z,1582759062.017 [IBIT](DEBUG): Uninitialize IBIT Component.
2020-02-26T23:17:42.017Z,1582759062.017 [CBIT](DEBUG): Uninitialize CBIT Component.
2020-02-26T23:17:42.017Z,1582759062.017 [CBIT](DEBUG): Powering off loads.
2020-02-26T23:17:42.029Z,1582759062.029 [CBIT](DEBUG): Disabling WDT.
2020-02-26T23:17:42.041Z,1582759062.041 [CBIT](DEBUG): Opening all GF detection circuits.
2020-02-26T23:17:42.042Z,1582759062.042 [controlThread ThreadHandler](INFO): Thread cancelled.
2020-02-26T23:17:42.186Z,1582759062.186 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2020-02-26T23:17:42.202Z,1582759062.202 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2020-02-26T23:17:42.305Z,1582759062.305 [WetLabsUBAT ThreadHandler](INFO): Thread cancelled.
2020-02-26T23:17:42.318Z,1582759062.318 [WetLabsUBAT](INFO): WetLabs destructor: _dataLog is not open
2020-02-26T23:17:42.318Z,1582759062.318 [WetLabsUBAT](INFO): WetLabs destructor: done
2020-02-26T23:17:42.321Z,1582759062.321 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2020-02-26T23:17:42.324Z,1582759062.324 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2020-02-26T23:17:42.339Z,1582759062.339 [BackSeatDriver ThreadHandler](INFO): Thread cancelled.
2020-02-26T23:17:42.348Z,1582759062.348 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2020-02-26T23:17:42.494Z,1582759062.494 [logger ThreadHandler](INFO): Thread cancelled.