2019-12-13T19:14:52.723Z,1576264492.723 [Supervisor](DEBUG): Initializing supervisor.
2019-12-13T19:14:52.725Z,1576264492.725 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2019-12-13T19:14:52.726Z,1576264492.726 [SyncHandler](INFO): Protected caller Thread ID is 806
2019-12-13T19:14:52.726Z,1576264492.726 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2019-12-13T19:14:52.727Z,1576264492.727 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2019-12-13T19:14:52.728Z,1576264492.728 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 807
2019-12-13T19:14:52.730Z,1576264492.730 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2019-12-13T19:14:52.741Z,1576264492.741 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2019-12-13T19:14:52.742Z,1576264492.742 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2019-12-13T19:14:52.743Z,1576264492.743 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 808
2019-12-13T19:14:52.744Z,1576264492.744 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2019-12-13T19:14:52.744Z,1576264492.744 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2019-12-13T19:14:52.745Z,1576264492.745 [logger ThreadHandler](INFO): Protected caller Thread ID is 809
2019-12-13T19:14:52.747Z,1576264492.747 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2019-12-13T19:14:52.747Z,1576264492.747 [Supervisor](INFO): Looking for Config files in directory: Config/
2019-12-13T19:14:52.751Z,1576264492.751 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2019-12-13T19:14:53.165Z,1576264493.165 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2019-12-13T19:14:53.167Z,1576264493.167 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2019-12-13T19:14:53.305Z,1576264493.305 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2019-12-13T19:14:53.305Z,1576264493.305 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2019-12-13T19:14:53.386Z,1576264493.386 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2019-12-13T19:14:53.482Z,1576264493.482 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2019-12-13T19:14:53.484Z,1576264493.484 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2019-12-13T19:14:53.577Z,1576264493.577 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2019-12-13T19:14:53.578Z,1576264493.578 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2019-12-13T19:14:53.949Z,1576264493.949 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2019-12-13T19:14:53.951Z,1576264493.951 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2019-12-13T19:14:54.051Z,1576264494.051 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2019-12-13T19:14:54.053Z,1576264494.053 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2019-12-13T19:14:54.507Z,1576264494.507 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2019-12-13T19:14:54.509Z,1576264494.509 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2019-12-13T19:14:54.692Z,1576264494.692 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2019-12-13T19:14:54.694Z,1576264494.694 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2019-12-13T19:14:54.983Z,1576264494.983 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2019-12-13T19:14:54.985Z,1576264494.985 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2019-12-13T19:14:55.195Z,1576264495.195 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2019-12-13T19:14:55.197Z,1576264495.197 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2019-12-13T19:14:55.334Z,1576264495.334 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2019-12-13T19:14:55.335Z,1576264495.335 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2019-12-13T19:14:56.195Z,1576264496.195 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2019-12-13T19:14:56.417Z,1576264496.417 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2019-12-13T19:14:57.032Z,1576264497.032 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2019-12-13T19:14:57.034Z,1576264497.034 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2019-12-13T19:14:57.239Z,1576264497.239 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2019-12-13T19:14:57.241Z,1576264497.241 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-triton/
2019-12-13T19:14:57.245Z,1576264497.245 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/vehicle.cfg
2019-12-13T19:14:57.430Z,1576264497.430 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/secure.cfg
2019-12-13T19:14:57.513Z,1576264497.513 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Science.cfg
2019-12-13T19:14:57.659Z,1576264497.659 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Simulator.cfg
2019-12-13T19:14:57.743Z,1576264497.743 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Battery.cfg
2019-12-13T19:14:57.967Z,1576264497.967 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2019-12-13T19:14:57.968Z,1576264497.968 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/logger.cfg
2019-12-13T19:14:58.075Z,1576264498.075 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Servo.cfg
2019-12-13T19:14:58.183Z,1576264498.183 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Navigation.cfg
2019-12-13T19:14:58.277Z,1576264498.277 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Sensor.cfg
2019-12-13T19:14:58.423Z,1576264498.423 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/Control.cfg
2019-12-13T19:14:58.521Z,1576264498.521 [Supervisor](INFO): Opening Config file at: Config/lrauv-triton/BIT.cfg
2019-12-13T19:14:58.619Z,1576264498.619 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2019-12-13T19:14:58.633Z,1576264498.633 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2019-12-13T19:14:58.657Z,1576264498.657 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2019-12-13T19:14:58.658Z,1576264498.658 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2019-12-13T19:14:58.721Z,1576264498.721 [VerticalControl](DEBUG): Construct VerticalControl.
2019-12-13T19:14:58.831Z,1576264498.831 [VerticalControl] Loaded
2019-12-13T19:14:58.831Z,1576264498.831 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2019-12-13T19:14:58.832Z,1576264498.832 [HorizontalControl](DEBUG): Construct HorizontalControl.
2019-12-13T19:14:58.912Z,1576264498.912 [HorizontalControl] Loaded
2019-12-13T19:14:58.913Z,1576264498.913 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2019-12-13T19:14:58.913Z,1576264498.913 [SpeedControl](DEBUG): Construct SpeedControl.
2019-12-13T19:14:58.919Z,1576264498.919 [SpeedControl] Loaded
2019-12-13T19:14:58.919Z,1576264498.919 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2019-12-13T19:14:58.920Z,1576264498.920 [LoopControl](DEBUG): Construct LoopControl.
2019-12-13T19:14:58.920Z,1576264498.920 [LoopControl] Loaded
2019-12-13T19:14:58.921Z,1576264498.921 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2019-12-13T19:14:58.921Z,1576264498.921 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2019-12-13T19:14:58.923Z,1576264498.923 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2019-12-13T19:14:59.072Z,1576264499.072 [BuoyancyServo] Loaded
2019-12-13T19:14:59.072Z,1576264499.072 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2019-12-13T19:14:59.083Z,1576264499.083 [ElevatorServo] Loaded
2019-12-13T19:14:59.083Z,1576264499.083 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2019-12-13T19:14:59.094Z,1576264499.094 [MassServo] Loaded
2019-12-13T19:14:59.094Z,1576264499.094 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2019-12-13T19:14:59.106Z,1576264499.106 [RudderServo] Loaded
2019-12-13T19:14:59.106Z,1576264499.106 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2019-12-13T19:14:59.117Z,1576264499.117 [ThrusterServo] Loaded
2019-12-13T19:14:59.117Z,1576264499.117 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2019-12-13T19:14:59.118Z,1576264499.118 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2019-12-13T19:14:59.118Z,1576264499.118 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2019-12-13T19:14:59.174Z,1576264499.174 [DepthRateCalculator] Loaded
2019-12-13T19:14:59.174Z,1576264499.174 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2019-12-13T19:14:59.180Z,1576264499.180 [PitchRateCalculator] Loaded
2019-12-13T19:14:59.180Z,1576264499.180 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2019-12-13T19:14:59.195Z,1576264499.195 [SpeedCalculator] Loaded
2019-12-13T19:14:59.195Z,1576264499.195 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2019-12-13T19:14:59.215Z,1576264499.215 [TempGradientCalculator] Loaded
2019-12-13T19:14:59.216Z,1576264499.216 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2019-12-13T19:14:59.221Z,1576264499.221 [YawRateCalculator] Loaded
2019-12-13T19:14:59.221Z,1576264499.221 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2019-12-13T19:14:59.249Z,1576264499.249 [ElevatorOffsetCalculator] Loaded
2019-12-13T19:14:59.249Z,1576264499.249 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2019-12-13T19:14:59.250Z,1576264499.250 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2019-12-13T19:14:59.251Z,1576264499.251 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2019-12-13T19:14:59.369Z,1576264499.369 [DeadReckonUsingMultipleVelocitySources] Loaded
2019-12-13T19:14:59.369Z,1576264499.369 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2019-12-13T19:14:59.389Z,1576264499.389 [NavChart] Loaded
2019-12-13T19:14:59.390Z,1576264499.390 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2019-12-13T19:14:59.394Z,1576264499.394 [UniversalFixResidualReporter] Loaded
2019-12-13T19:14:59.394Z,1576264499.394 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2019-12-13T19:14:59.394Z,1576264499.394 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2019-12-13T19:14:59.395Z,1576264499.395 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2019-12-13T19:14:59.910Z,1576264499.910 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_orientation
2019-12-13T19:14:59.915Z,1576264499.915 [AHRS_M2](INFO): created writer for : platform_orientation
2019-12-13T19:14:59.917Z,1576264499.917 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_magnetic_orientation
2019-12-13T19:14:59.922Z,1576264499.922 [AHRS_M2](INFO): created writer for : platform_magnetic_orientation
2019-12-13T19:14:59.922Z,1576264499.922 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_pitch_angle
2019-12-13T19:14:59.927Z,1576264499.927 [AHRS_M2](INFO): created writer for : platform_pitch_angle
2019-12-13T19:14:59.928Z,1576264499.928 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_roll_angle
2019-12-13T19:14:59.933Z,1576264499.933 [AHRS_M2](INFO): created writer for : platform_roll_angle
2019-12-13T19:15:00.188Z,1576264500.188 [AHRS_M2] Loaded
2019-12-13T19:15:00.188Z,1576264500.188 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2019-12-13T19:15:00.344Z,1576264500.344 [DataOverHttps] Loaded
2019-12-13T19:15:00.344Z,1576264500.344 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2019-12-13T19:15:00.345Z,1576264500.345 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 408164E0
2019-12-13T19:15:00.346Z,1576264500.346 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 889
2019-12-13T19:15:00.360Z,1576264500.360 [Depth_Keller] Loaded
2019-12-13T19:15:00.360Z,1576264500.360 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2019-12-13T19:15:00.365Z,1576264500.365 [DropWeight] Loaded
2019-12-13T19:15:00.365Z,1576264500.365 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2019-12-13T19:15:00.460Z,1576264500.460 [NAL9602] Loaded
2019-12-13T19:15:00.460Z,1576264500.460 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2019-12-13T19:15:00.497Z,1576264500.497 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-0/voltage_now
2019-12-13T19:15:00.498Z,1576264500.498 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-0/current_now
2019-12-13T19:15:00.498Z,1576264500.498 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-0/charge_now
2019-12-13T19:15:00.499Z,1576264500.499 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-0/charge_full
2019-12-13T19:15:00.500Z,1576264500.500 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-1/voltage_now
2019-12-13T19:15:00.500Z,1576264500.500 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-1/current_now
2019-12-13T19:15:00.501Z,1576264500.501 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-1/charge_now
2019-12-13T19:15:00.501Z,1576264500.501 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-1/charge_full
2019-12-13T19:15:00.501Z,1576264500.501 [Onboard] Loaded
2019-12-13T19:15:00.501Z,1576264500.501 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2019-12-13T19:15:00.505Z,1576264500.505 [Radio_Surface] Loaded
2019-12-13T19:15:00.505Z,1576264500.505 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2019-12-13T19:15:00.506Z,1576264500.506 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 408464E0
2019-12-13T19:15:00.506Z,1576264500.506 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 890
2019-12-13T19:15:02.079Z,1576264502.079 [BPC1] Loaded
2019-12-13T19:15:02.080Z,1576264502.080 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2019-12-13T19:15:02.080Z,1576264502.080 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2019-12-13T19:15:02.081Z,1576264502.081 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2019-12-13T19:15:03.074Z,1576264503.074 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2019-12-13T19:15:03.075Z,1576264503.075 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2019-12-13T19:15:03.199Z,1576264503.199 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2019-12-13T19:15:03.200Z,1576264503.200 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2019-12-13T19:15:03.248Z,1576264503.248 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2019-12-13T19:15:03.249Z,1576264503.249 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2019-12-13T19:15:03.517Z,1576264503.517 [Aanderaa_O2] Loaded
2019-12-13T19:15:03.517Z,1576264503.517 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread.
2019-12-13T19:15:03.526Z,1576264503.526 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_density
2019-12-13T19:15:03.532Z,1576264503.532 [CTD_Seabird](INFO): created writer for : sea_water_density
2019-12-13T19:15:03.532Z,1576264503.532 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): depth
2019-12-13T19:15:03.537Z,1576264503.537 [CTD_Seabird](INFO): created writer for : depth
2019-12-13T19:15:03.537Z,1576264503.537 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_pressure
2019-12-13T19:15:03.542Z,1576264503.542 [CTD_Seabird](INFO): created writer for : sea_water_pressure
2019-12-13T19:15:03.543Z,1576264503.543 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_salinity
2019-12-13T19:15:03.548Z,1576264503.548 [CTD_Seabird](INFO): created writer for : sea_water_salinity
2019-12-13T19:15:03.548Z,1576264503.548 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_temperature
2019-12-13T19:15:03.553Z,1576264503.553 [CTD_Seabird](INFO): created writer for : sea_water_temperature
2019-12-13T19:15:03.554Z,1576264503.554 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_electrical_conductivity
2019-12-13T19:15:03.560Z,1576264503.560 [CTD_Seabird](INFO): created writer for : sea_water_electrical_conductivity
2019-12-13T19:15:03.560Z,1576264503.560 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): speed_of_sound_in_sea_water
2019-12-13T19:15:03.565Z,1576264503.565 [CTD_Seabird](INFO): created writer for : speed_of_sound_in_sea_water
2019-12-13T19:15:03.591Z,1576264503.591 [CTD_Seabird] Loaded
2019-12-13T19:15:03.592Z,1576264503.592 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2019-12-13T19:15:03.593Z,1576264503.593 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 409E04E0
2019-12-13T19:15:03.593Z,1576264503.593 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 891
2019-12-13T19:15:03.624Z,1576264503.624 [ESPComponent] Loaded
2019-12-13T19:15:03.624Z,1576264503.624 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread.
2019-12-13T19:15:03.639Z,1576264503.639 [PAR_Licor] Loaded
2019-12-13T19:15:03.639Z,1576264503.639 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2019-12-13T19:15:03.645Z,1576264503.645 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.Output470
2019-12-13T19:15:03.645Z,1576264503.645 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: Output470
2019-12-13T19:15:03.649Z,1576264503.649 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.Output650
2019-12-13T19:15:03.649Z,1576264503.649 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: Output650
2019-12-13T19:15:03.653Z,1576264503.653 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.OutputChl
2019-12-13T19:15:03.654Z,1576264503.654 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: OutputChl
2019-12-13T19:15:03.658Z,1576264503.658 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.VolumeScatCoeff117deg470nm
2019-12-13T19:15:03.658Z,1576264503.658 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: VolumeScatCoeff117deg470nm
2019-12-13T19:15:03.662Z,1576264503.662 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.VolumeScatCoeff117deg650nm
2019-12-13T19:15:03.663Z,1576264503.663 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: VolumeScatCoeff117deg650nm
2019-12-13T19:15:03.667Z,1576264503.667 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.BackscatteringCoeff470nm
2019-12-13T19:15:03.667Z,1576264503.667 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: BackscatteringCoeff470nm
2019-12-13T19:15:03.671Z,1576264503.671 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.BackscatteringCoeff650nm
2019-12-13T19:15:03.671Z,1576264503.671 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: BackscatteringCoeff650nm
2019-12-13T19:15:03.676Z,1576264503.676 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): mass_concentration_of_chlorophyll_in_sea_water
2019-12-13T19:15:03.680Z,1576264503.680 [WetLabsBB2FL](INFO): created writer for : mass_concentration_of_chlorophyll_in_sea_water
2019-12-13T19:15:03.681Z,1576264503.681 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_median_mass_concentration_of_chlorophyll_in_sea_water
2019-12-13T19:15:03.681Z,1576264503.681 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_median_mass_concentration_of_chlorophyll_in_sea_water
2019-12-13T19:15:03.685Z,1576264503.685 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_mean_mass_concentration_of_chlorophyll_in_sea_water
2019-12-13T19:15:03.685Z,1576264503.685 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_mean_mass_concentration_of_chlorophyll_in_sea_water
2019-12-13T19:15:03.689Z,1576264503.689 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_variance_mass_concentration_of_chlorophyll_in_sea_water
2019-12-13T19:15:03.689Z,1576264503.689 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_variance_mass_concentration_of_chlorophyll_in_sea_water
2019-12-13T19:15:03.694Z,1576264503.694 [WetLabsBB2FL] Loaded
2019-12-13T19:15:03.694Z,1576264503.694 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2019-12-13T19:15:03.695Z,1576264503.695 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40A104E0
2019-12-13T19:15:03.695Z,1576264503.695 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 892
2019-12-13T19:15:03.696Z,1576264503.696 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2019-12-13T19:15:03.697Z,1576264503.697 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2019-12-13T19:15:04.051Z,1576264504.051 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2019-12-13T19:15:04.052Z,1576264504.052 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2019-12-13T19:15:04.253Z,1576264504.253 [SBIT](DEBUG): Construct Startup Built In Test.
2019-12-13T19:15:04.263Z,1576264504.263 [SBIT] Loaded
2019-12-13T19:15:04.264Z,1576264504.264 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2019-12-13T19:15:04.264Z,1576264504.264 [IBIT](DEBUG): Construct Initiated Built In Test.
2019-12-13T19:15:04.277Z,1576264504.277 [IBIT] Loaded
2019-12-13T19:15:04.277Z,1576264504.277 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2019-12-13T19:15:04.280Z,1576264504.280 [CBIT](DEBUG): Construct Continuous Built In Test.
2019-12-13T19:15:04.416Z,1576264504.416 [CBIT] Loaded
2019-12-13T19:15:04.416Z,1576264504.416 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2019-12-13T19:15:04.417Z,1576264504.417 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2019-12-13T19:15:04.420Z,1576264504.420 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2019-12-13T19:15:04.421Z,1576264504.421 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2019-12-13T19:15:04.428Z,1576264504.428 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2019-12-13T19:15:04.429Z,1576264504.429 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40AF94E0
2019-12-13T19:15:04.429Z,1576264504.429 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 894
2019-12-13T19:15:04.433Z,1576264504.433 [Supervisor](INFO): Main Thread ID is 802
2019-12-13T19:15:04.434Z,1576264504.434 [Supervisor](DEBUG): Running supervisor.
2019-12-13T19:15:04.434Z,1576264504.434 [CommandLine ThreadHandler](INFO): Handler Thread ID is 895
2019-12-13T19:15:04.437Z,1576264504.437 [controlThread ThreadHandler](INFO): Handler Thread ID is 896
2019-12-13T19:15:04.437Z,1576264504.437 [controlThread](DEBUG): Initializing ControlThread
2019-12-13T19:15:04.438Z,1576264504.438 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2019-12-13T19:15:04.439Z,1576264504.439 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2019-12-13T19:15:04.440Z,1576264504.440 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2019-12-13T19:15:04.441Z,1576264504.441 [LoopControl](DEBUG): Initialize LoopControlComponent.
2019-12-13T19:15:04.442Z,1576264504.442 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2019-12-13T19:15:04.442Z,1576264504.442 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2019-12-13T19:15:04.443Z,1576264504.443 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2019-12-13T19:15:04.443Z,1576264504.443 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2019-12-13T19:15:04.443Z,1576264504.443 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2019-12-13T19:15:04.444Z,1576264504.444 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2019-12-13T19:15:04.445Z,1576264504.445 [NavChart](DEBUG): Initialize NavChart Navigation.
2019-12-13T19:15:04.445Z,1576264504.445 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2019-12-13T19:15:04.451Z,1576264504.451 [SBIT](INFO): Initialize SBIT Component.
2019-12-13T19:15:04.451Z,1576264504.451 [SBIT](IMPORTANT): git: 2019-12-13
2019-12-13T19:15:04.451Z,1576264504.451 [SBIT](INFO): git hash: acb51ddeff3b98c650dbf9534f1cbf95eba4c7ce
2019-12-13T19:15:04.452Z,1576264504.452 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2019-12-13T19:15:04.453Z,1576264504.453 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #1 PREEMPT Tue Dec 18 21:19:28 PST 2018
Kernel Reported: #1 PREEMPT Thu Feb 21 11:17:40 PST 2019
2019-12-13T19:15:04.454Z,1576264504.454 [SBIT](INFO): Beginning SBIT in 34.000000 seconds.
2019-12-13T19:15:04.455Z,1576264504.455 [IBIT](INFO): Initialize IBIT Component.
2019-12-13T19:15:04.456Z,1576264504.456 [CBIT](DEBUG): Initialize CBIT Component.
2019-12-13T19:15:04.456Z,1576264504.456 [logger ThreadHandler](INFO): Handler Thread ID is 897
2019-12-13T19:15:04.459Z,1576264504.459 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 898
2019-12-13T19:15:04.466Z,1576264504.466 [CBIT](DEBUG): Initialized mux pins.
2019-12-13T19:15:04.466Z,1576264504.466 [CBIT](DEBUG): Initializing the watchdog timer.
2019-12-13T19:15:04.471Z,1576264504.471 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2019-12-13T19:15:04.479Z,1576264504.479 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 899
2019-12-13T19:15:04.487Z,1576264504.487 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 900
2019-12-13T19:15:04.487Z,1576264504.487 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2019-12-13T19:15:04.490Z,1576264504.490 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2019-12-13T19:15:04.491Z,1576264504.491 [CBIT](DEBUG): Initializing heartbeat.
2019-12-13T19:15:04.491Z,1576264504.491 [CTD_Seabird](INFO): Opening uart, block timeout 10ths=20
2019-12-13T19:15:04.492Z,1576264504.492 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 902
2019-12-13T19:15:04.493Z,1576264504.493 [WetLabsBB2FL](INFO): Powering down
2019-12-13T19:15:04.537Z,1576264504.537 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 903
2019-12-13T19:15:04.543Z,1576264504.543 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2019-12-13T19:15:04.543Z,1576264504.543 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2019-12-13T19:15:04.543Z,1576264504.543 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2019-12-13T19:15:04.543Z,1576264504.543 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2019-12-13T19:15:04.544Z,1576264504.544 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2019-12-13T19:15:04.544Z,1576264504.544 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2019-12-13T19:15:04.544Z,1576264504.544 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2019-12-13T19:15:04.544Z,1576264504.544 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2019-12-13T19:15:04.544Z,1576264504.544 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2019-12-13T19:15:04.544Z,1576264504.544 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2019-12-13T19:15:04.545Z,1576264504.545 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2019-12-13T19:15:04.545Z,1576264504.545 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2019-12-13T19:15:04.545Z,1576264504.545 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2019-12-13T19:15:04.545Z,1576264504.545 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2019-12-13T19:15:04.545Z,1576264504.545 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2019-12-13T19:15:04.546Z,1576264504.546 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2019-12-13T19:15:04.562Z,1576264504.562 [CBIT](DEBUG): Deactivating GF circuits.
2019-12-13T19:15:04.562Z,1576264504.562 [CBIT](DEBUG): Deactivating emergency mode.
2019-12-13T19:15:04.598Z,1576264504.598 [CBIT](DEBUG): Backplane powered.
2019-12-13T19:15:04.599Z,1576264504.599 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2019-12-13T19:15:04.815Z,1576264504.815 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2019-12-13T19:15:04.883Z,1576264504.883 [Radio_Surface](INFO): Powering up
2019-12-13T19:15:04.898Z,1576264504.898 [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>


2019-12-13T19:15:04.911Z,1576264504.911 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2019-12-13T19:15:05.046Z,1576264505.046 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2019-12-13T19:15:05.047Z,1576264505.047 [Default:A.Wait](DEBUG): Construct Wait.
2019-12-13T19:15:05.049Z,1576264505.049 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2019-12-13T19:15:05.092Z,1576264505.092 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2019-12-13T19:15:05.119Z,1576264505.119 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2019-12-13T19:15:05.124Z,1576264505.124 [Default:E.Execute](DEBUG): Construct Execute.
2019-12-13T19:15:05.139Z,1576264505.139 [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>


2019-12-13T19:15:05.150Z,1576264505.150 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,Depth_Keller,DropWeight,NAL9602,Onboard,BPC1,Aanderaa_O2,ESPComponent,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2019-12-13T19:15:05.170Z,1576264505.170 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2019-12-13T19:15:05.390Z,1576264505.390 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2019-12-13T19:15:05.399Z,1576264505.399 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2019-12-13T19:15:05.400Z,1576264505.400 [ElevatorServo](DEBUG): Initializing EZServoServo.
2019-12-13T19:15:05.407Z,1576264505.407 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2019-12-13T19:15:05.408Z,1576264505.408 [MassServo](DEBUG): Initializing EZServoServo.
2019-12-13T19:15:05.415Z,1576264505.415 [MassServo](DEBUG): Initializing MassServo.
2019-12-13T19:15:05.415Z,1576264505.415 [RudderServo](DEBUG): Initializing EZServoServo.
2019-12-13T19:15:05.423Z,1576264505.423 [RudderServo](DEBUG): Initializing RudderServo.
2019-12-13T19:15:05.424Z,1576264505.424 [ThrusterServo](DEBUG): Initializing EZServoServo.
2019-12-13T19:15:05.431Z,1576264505.431 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2019-12-13T19:15:06.350Z,1576264506.350 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2019-12-13T19:15:06.351Z,1576264506.351 [RudderServo](FAULT): Rudder failed to initialize
2019-12-13T19:15:06.351Z,1576264506.351 [RudderServo] Communications Fault, FailCount= 1
2019-12-13T19:15:06.351Z,1576264506.351 [RudderServo](ERROR): Communications Fault
2019-12-13T19:15:06.466Z,1576264506.466 [CBIT](ERROR): Communications Fault in component: RudderServo
2019-12-13T19:15:06.676Z,1576264506.676 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2019-12-13T19:15:06.676Z,1576264506.676 [RudderServo](INFO): Powering down
2019-12-13T19:15:07.333Z,1576264507.333 [RudderServo](DEBUG): Initializing EZServoServo.
2019-12-13T19:15:07.451Z,1576264507.451 [RudderServo](DEBUG): Initializing RudderServo.
2019-12-13T19:15:07.455Z,1576264507.455 [CBIT](INFO): Clearing failed state for component RudderServo
2019-12-13T19:15:07.455Z,1576264507.455 [RudderServo] No Fault, FailCount= 1
2019-12-13T19:15:08.702Z,1576264508.702 [Aanderaa_O2](INFO): Powering down
2019-12-13T19:15:30.772Z,1576264530.772 [NAL9602](INFO): Powering up NAL9602
2019-12-13T19:15:38.908Z,1576264538.908 [SBIT](IMPORTANT): Beginning Startup BIT
2019-12-13T19:15:38.912Z,1576264538.912 [CBIT](IMPORTANT): Beginning ground fault scan
2019-12-13T19:15:41.800Z,1576264541.800 [NAL9602](INFO): NAL9602 initialized
2019-12-13T19:15:49.958Z,1576264549.958 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.040315
CHAN A1 (24V): -0.218373
CHAN A2 (12V): 0.019859
CHAN A3 (5V): -0.014537
CHAN B0 (3.3V): -0.009036
CHAN B1 (3.15aV): -0.005357
CHAN B2 (3.15bV): -0.004059
CHAN B3 (GND): -0.012027
OPEN: 0.007025
Full Scale Calc: 4.765 mA, -1.589 mA
2019-12-13T19:16:15.949Z,1576264575.949 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-12-13T19:16:22.438Z,1576264582.438 [NAL9602](INFO): SBD MO Status=2, MOMSN=3653, MT Status=2, MTMSN=0
2019-12-13T19:16:22.438Z,1576264582.438 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-12-13T19:16:32.164Z,1576264592.164 [SBIT](IMPORTANT): SBIT PASSED
2019-12-13T19:16:32.191Z,1576264592.191 [CommandLine](IMPORTANT): got command configSet list
2019-12-13T19:16:32.192Z,1576264592.192 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2019-12-13T19:16:32.192Z,1576264592.192 [CommandLine](IMPORTANT): BPC1.batteryMissingStickThreshold=2 count;

2019-12-13T19:16:32.193Z,1576264592.193 [CommandLine](IMPORTANT): DAT.loadAtStartup=0 bool;

2019-12-13T19:16:32.193Z,1576264592.193 [CommandLine](IMPORTANT): DVL_micro.loadAtStartup=0 bool;

2019-12-13T19:16:32.193Z,1576264592.193 [CommandLine](IMPORTANT): Express none CTD_Seabird.bin_median_sea_water_salinity;

2019-12-13T19:16:32.193Z,1576264592.193 [CommandLine](IMPORTANT): Express linearApproximation WetLabsBB2FL.bin_mean_mass_concentration_of_chlorophyll_in_sea_water 0.100000 microgram_per_liter;

2019-12-13T19:16:32.193Z,1576264592.193 [CommandLine](IMPORTANT): Express linearApproximation depth 5.000000 meter;

2019-12-13T19:16:32.193Z,1576264592.193 [CommandLine](IMPORTANT): Express linearApproximation latitude 0.005000 degree;

2019-12-13T19:16:32.193Z,1576264592.193 [CommandLine](IMPORTANT): Express linearApproximation longitude 0.005000 degree;

2019-12-13T19:16:32.193Z,1576264592.193 [CommandLine](IMPORTANT): VerticalControl.buoyancyNeutral=168 cubic_centimeter;

2019-12-13T19:16:32.193Z,1576264592.193 [CommandLine](IMPORTANT): VerticalControl.massDefault=3.7 millimeter;

2019-12-13T19:16:32.564Z,1576264592.564 [MissionManager](IMPORTANT): Started mission Startup
2019-12-13T19:16:32.564Z,1576264592.564 [Startup] Running Loop=1
2019-12-13T19:16:32.565Z,1576264592.565 [Startup](DEBUG): Aggregate::initialize Startup
2019-12-13T19:16:32.565Z,1576264592.565 [Startup:A.GoToSurface] Running Loop=1
2019-12-13T19:16:32.565Z,1576264592.565 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-12-13T19:16:32.565Z,1576264592.565 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-12-13T19:16:32.566Z,1576264592.566 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-12-13T19:16:32.567Z,1576264592.567 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-12-13T19:16:32.568Z,1576264592.568 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-12-13T19:16:32.568Z,1576264592.568 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-12-13T19:16:32.569Z,1576264592.569 [Startup:StartupSatComms] Running Loop=1
2019-12-13T19:16:32.569Z,1576264592.569 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2019-12-13T19:16:32.569Z,1576264592.569 [Startup:StartupSatComms:A] Running Loop=1
2019-12-13T19:16:32.976Z,1576264592.976 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2019-12-13T19:16:43.508Z,1576264603.508 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-12-13T19:17:06.473Z,1576264626.473 [NAL9602](INFO): SBD MO Status=2, MOMSN=3653, MT Status=2, MTMSN=0
2019-12-13T19:17:06.473Z,1576264626.473 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-12-13T19:17:32.753Z,1576264652.753 [Startup:StartupSatComms:A](INFO): Timed out from 2019-12-13T19:16:32.6Z
2019-12-13T19:17:32.753Z,1576264652.753 [Startup:StartupSatComms:A] Stopped
2019-12-13T19:17:32.753Z,1576264652.753 [Startup:StartupSatComms:B] Running Loop=1
2019-12-13T19:17:33.157Z,1576264653.157 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-12-13T19:17:35.256Z,1576264655.256 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004956
2019-12-13T19:17:42.599Z,1576264662.599 [DataOverHttps](INFO): Sending 898 bytes from file Logs/20191213T191452/Express0001.lzma
2019-12-13T19:17:44.604Z,1576264664.604 [DataOverHttps](INFO): Moved sent file to Logs/20191213T191452/Express0001.lzma.bak
2019-12-13T19:17:44.604Z,1576264664.604 [DataOverHttps](INFO): SBD MOMSN=12155669
2019-12-13T19:17:45.684Z,1576264665.684 [Startup:StartupSatComms:B] Stopped
2019-12-13T19:17:45.684Z,1576264665.684 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2019-12-13T19:17:45.684Z,1576264665.684 [Startup:StartupSatComms] Stopped
2019-12-13T19:17:45.684Z,1576264665.684 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2019-12-13T19:17:45.685Z,1576264665.685 [Startup](INFO): Completed Startup
2019-12-13T19:17:45.685Z,1576264665.685 [MissionManager](INFO): Startup is completed.
2019-12-13T19:17:45.685Z,1576264665.685 [MissionManager](INFO): Uninitializing Mission Startup
2019-12-13T19:17:45.685Z,1576264665.685 [Startup] Stopped
2019-12-13T19:17:45.686Z,1576264665.686 [Startup](DEBUG): Aggregate::uninitialize Startup
2019-12-13T19:17:45.686Z,1576264665.686 [Startup:A.GoToSurface] Stopped
2019-12-13T19:17:45.686Z,1576264665.686 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-12-13T19:17:46.092Z,1576264666.092 [MissionManager](IMPORTANT): Started mission Default
2019-12-13T19:17:46.092Z,1576264666.092 [Default] Running Loop=1
2019-12-13T19:17:46.092Z,1576264666.092 [Default](DEBUG): Aggregate::initialize Default
2019-12-13T19:17:46.092Z,1576264666.092 [Default:B.GoToSurface] Running Loop=1
2019-12-13T19:17:46.092Z,1576264666.092 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-12-13T19:17:46.093Z,1576264666.093 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-12-13T19:17:46.093Z,1576264666.093 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-12-13T19:17:46.093Z,1576264666.093 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-12-13T19:17:46.094Z,1576264666.094 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-12-13T19:17:46.094Z,1576264666.094 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-12-13T19:17:46.094Z,1576264666.094 [Default:A.Wait] Running Loop=1
2019-12-13T19:17:46.094Z,1576264666.094 [Default:A.Wait](DEBUG): Initialize Wait Component.
2019-12-13T19:17:56.586Z,1576264676.586 [BPC1](ERROR): BPC1B got IPBS message with 5 sticks (min is 7).
2019-12-13T19:17:56.589Z,1576264676.589 [BPC1](ERROR): BPC1B failed to parse battery stick message.
2019-12-13T19:17:59.414Z,1576264679.414 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-12-13T19:17:59.444Z,1576264679.444 [Default:A.Wait](INFO): Done Waiting.
2019-12-13T19:17:59.444Z,1576264679.444 [Default:A.Wait] Stopped
2019-12-13T19:17:59.444Z,1576264679.444 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2019-12-13T19:17:59.841Z,1576264679.841 [Default:CheckIn] Running Loop=1
2019-12-13T19:17:59.841Z,1576264679.841 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-12-13T19:17:59.841Z,1576264679.841 [Default:CheckIn:Read_GPS] Running Loop=1
2019-12-13T19:18:00.252Z,1576264680.252 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2019-12-13T19:18:02.638Z,1576264682.638 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-12-13T19:18:04.698Z,1576264684.698 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2019-12-13T19:18:04.698Z,1576264684.698 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-12-13T19:18:04.708Z,1576264684.708 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-12-13T19:18:05.089Z,1576264685.089 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-12-13T19:18:05.089Z,1576264685.089 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2019-12-13T19:18:05.871Z,1576264685.871 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-12-13T19:18:09.116Z,1576264689.116 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-12-13T19:18:12.334Z,1576264692.334 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-12-13T19:18:15.567Z,1576264695.567 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-12-13T19:18:18.820Z,1576264698.820 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-12-13T19:18:21.691Z,1576264701.691 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-12-13T19:18:24.462Z,1576264704.462 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-12-13T19:18:27.687Z,1576264707.687 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-12-13T19:18:30.924Z,1576264710.924 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-12-13T19:18:34.156Z,1576264714.156 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-12-13T19:18:37.419Z,1576264717.419 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-12-13T19:18:40.620Z,1576264720.620 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-12-13T19:18:43.883Z,1576264723.883 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-12-13T19:18:47.082Z,1576264727.082 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-12-13T19:18:50.336Z,1576264730.336 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-12-13T19:18:53.559Z,1576264733.559 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-12-13T19:18:56.778Z,1576264736.778 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-12-13T19:19:00.030Z,1576264740.030 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-12-13T19:19:03.253Z,1576264743.253 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-12-13T19:19:06.079Z,1576264746.079 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-12-13T19:19:09.309Z,1576264749.309 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-12-13T19:19:12.570Z,1576264752.570 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-12-13T19:19:13.663Z,1576264753.663 [CommandLine](IMPORTANT): got command burn on
2019-12-13T19:19:13.663Z,1576264753.663 [CommandLine](IMPORTANT): Activating dropweight wire
2019-12-13T19:19:16.176Z,1576264756.176 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-12-13T19:19:19.420Z,1576264759.420 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-12-13T19:19:22.635Z,1576264762.635 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-12-13T19:19:25.875Z,1576264765.875 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-12-13T19:19:28.253Z,1576264768.253 [CommandLine](IMPORTANT): got command burn off
2019-12-13T19:19:28.254Z,1576264768.254 [CommandLine](IMPORTANT): Deactivating dropweight wire
2019-12-13T19:19:29.163Z,1576264769.163 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-12-13T19:19:32.327Z,1576264772.327 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-12-13T19:19:35.559Z,1576264775.559 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-12-13T19:19:38.795Z,1576264778.795 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-12-13T19:19:42.031Z,1576264782.031 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-12-13T19:19:45.266Z,1576264785.266 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-12-13T19:19:48.487Z,1576264788.487 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-12-13T19:19:51.728Z,1576264791.728 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-12-13T19:19:54.963Z,1576264794.963 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-12-13T19:19:58.204Z,1576264798.204 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-12-13T19:19:59.863Z,1576264799.863 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-12-13T19:20:01.424Z,1576264801.424 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-12-13T19:20:04.265Z,1576264804.265 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-12-13T19:20:07.483Z,1576264807.483 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-12-13T19:20:10.712Z,1576264810.712 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-12-13T19:20:13.952Z,1576264813.952 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-12-13T19:20:43.899Z,1576264843.899 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-12-13T19:20:45.028Z,1576264845.028 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2019-12-13T19:20:52.305Z,1576264852.305 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,192052.00,A,3648.16416,N,12147.28557,W,0.389,0.00,131219,,,A*7B
2019-12-13T19:20:52.308Z,1576264852.308 [NAL9602](INFO): GPS fix at 20191213T192052: (36.802736, -121.788093)
2019-12-13T19:20:52.332Z,1576264852.332 [Default:CheckIn:Read_GPS] Stopped
2019-12-13T19:20:52.332Z,1576264852.332 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-12-13T19:20:52.788Z,1576264852.788 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-12-13T19:21:02.530Z,1576264862.530 [DataOverHttps](INFO): Sending 213 bytes from file Logs/20191213T191452/Courier0004.lzma
2019-12-13T19:21:04.049Z,1576264864.049 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-12-13T19:21:04.536Z,1576264864.536 [DataOverHttps](INFO): Moved sent file to Logs/20191213T191452/Courier0004.lzma.bak
2019-12-13T19:21:04.536Z,1576264864.536 [DataOverHttps](INFO): SBD MOMSN=12155693
2019-12-13T19:21:06.875Z,1576264866.875 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-12-13T19:21:09.705Z,1576264869.705 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-12-13T19:21:12.930Z,1576264872.930 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-12-13T19:21:16.570Z,1576264876.570 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-12-13T19:21:19.799Z,1576264879.799 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-12-13T19:21:21.862Z,1576264881.862 [DataOverHttps](INFO): Sending 366 bytes from file Logs/20191213T191452/Express0005.lzma
2019-12-13T19:21:23.034Z,1576264883.034 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-12-13T19:21:23.852Z,1576264883.852 [DataOverHttps](INFO): Moved sent file to Logs/20191213T191452/Express0005.lzma.bak
2019-12-13T19:21:23.852Z,1576264883.852 [DataOverHttps](INFO): SBD MOMSN=12155696
2019-12-13T19:21:24.635Z,1576264884.635 [NAL9602](INFO): Not Powering down - fast GPS
2019-12-13T19:21:25.065Z,1576264885.065 [Default:CheckIn:Read_Iridium] Stopped
2019-12-13T19:21:25.065Z,1576264885.065 [Default:CheckIn:C.Wait] Running Loop=1
2019-12-13T19:21:25.065Z,1576264885.065 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-12-13T19:21:33.124Z,1576264893.124 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2019-12-13T19:21:33.124Z,1576264893.124 [BPC1](ERROR): BPC1A failed to parse battery stick message.
2019-12-13T19:21:35.967Z,1576264895.967 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-12-13T19:21:38.790Z,1576264898.790 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-12-13T19:21:42.023Z,1576264902.023 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-12-13T19:21:42.488Z,1576264902.488 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-12-13T19:21:44.849Z,1576264904.849 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-12-13T19:21:47.673Z,1576264907.673 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-12-13T19:21:50.909Z,1576264910.909 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-12-13T19:21:53.744Z,1576264913.744 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-12-13T19:21:56.571Z,1576264916.571 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-12-13T19:21:59.394Z,1576264919.394 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-12-13T19:22:02.620Z,1576264922.620 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-12-13T19:22:05.856Z,1576264925.856 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-12-13T19:22:09.489Z,1576264929.489 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-12-13T19:22:12.322Z,1576264932.322 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-12-13T19:22:15.547Z,1576264935.547 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-12-13T19:22:18.780Z,1576264938.780 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-12-13T19:22:22.017Z,1576264942.017 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-12-13T19:22:24.840Z,1576264944.840 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-12-13T19:22:28.080Z,1576264948.080 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-12-13T19:22:30.910Z,1576264950.910 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-12-13T19:22:34.138Z,1576264954.138 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-12-13T19:22:37.781Z,1576264957.781 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-12-13T19:22:41.009Z,1576264961.009 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-12-13T19:22:42.624Z,1576264962.624 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2019-12-13T19:22:44.245Z,1576264964.245 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-12-13T19:22:47.066Z,1576264967.066 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-12-13T19:22:50.703Z,1576264970.703 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-12-13T19:22:50.704Z,1576264970.704 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2019-12-13T19:22:53.535Z,1576264973.535 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-12-13T19:22:56.354Z,1576264976.354 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-12-13T19:22:59.180Z,1576264979.180 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-12-13T19:23:02.422Z,1576264982.422 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-12-13T19:23:05.649Z,1576264985.649 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-12-13T19:23:08.474Z,1576264988.474 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2019-12-13T19:23:09.291Z,1576264989.291 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-12-13T19:23:12.113Z,1576264992.113 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-12-13T19:23:15.342Z,1576264995.342 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-12-13T19:23:18.571Z,1576264998.571 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-12-13T19:23:21.413Z,1576265001.413 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-12-13T19:23:24.632Z,1576265004.632 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-12-13T19:23:26.250Z,1576265006.250 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2019-12-13T19:23:44.040Z,1576265024.040 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2019-12-13T19:23:54.611Z,1576265034.611 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-12-13T19:24:02.224Z,1576265042.224 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2019-12-13T19:24:20.400Z,1576265060.400 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2019-12-13T19:24:38.248Z,1576265078.248 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2019-12-13T19:24:56.361Z,1576265096.361 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2019-12-13T19:25:11.759Z,1576265111.759 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2019-12-13T19:25:39.250Z,1576265139.250 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2019-12-13T19:26:25.659Z,1576265185.659 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-12-13T19:26:25.660Z,1576265185.660 [Default:CheckIn:C.Wait] Stopped
2019-12-13T19:26:25.660Z,1576265185.660 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-12-13T19:26:25.660Z,1576265185.660 [Default:CheckIn:D] Running Loop=1
2019-12-13T19:26:26.066Z,1576265186.066 [Default:CheckIn:D] Stopped
2019-12-13T19:26:26.066Z,1576265186.066 [Default:CheckIn:E] Running Loop=1
2019-12-13T19:26:26.464Z,1576265186.464 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 8.666232 min 
2019-12-13T19:26:26.464Z,1576265186.464 [Default:CheckIn:E] Stopped
2019-12-13T19:26:26.464Z,1576265186.464 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-12-13T19:26:26.464Z,1576265186.464 [Default:CheckIn] Stopped
2019-12-13T19:26:26.464Z,1576265186.464 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-12-13T19:26:26.464Z,1576265186.464 [Default:CheckIn](INFO): Running loop #2
2019-12-13T19:26:26.464Z,1576265186.464 [Default:CheckIn] Running Loop=2
2019-12-13T19:26:26.464Z,1576265186.464 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-12-13T19:26:26.464Z,1576265186.464 [Default:CheckIn:Read_GPS] Running Loop=1
2019-12-13T19:26:28.457Z,1576265188.457 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,192628.00,A,3648.16250,N,12147.28203,W,0.369,0.00,131219,,,A*7C
2019-12-13T19:26:28.459Z,1576265188.459 [NAL9602](INFO): GPS fix at 20191213T192628: (36.802708, -121.788034)
2019-12-13T19:26:28.483Z,1576265188.483 [Default:CheckIn:Read_GPS] Stopped
2019-12-13T19:26:28.483Z,1576265188.483 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-12-13T19:26:36.078Z,1576265196.078 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20191213T191452/Courier0007.lzma
2019-12-13T19:26:38.084Z,1576265198.084 [DataOverHttps](INFO): Moved sent file to Logs/20191213T191452/Courier0007.lzma.bak
2019-12-13T19:26:38.084Z,1576265198.084 [DataOverHttps](INFO): SBD MOMSN=12155704
2019-12-13T19:26:54.877Z,1576265214.877 [DataOverHttps](INFO): Sending 150 bytes from file Logs/20191213T191452/Express0008.lzma
2019-12-13T19:26:56.881Z,1576265216.881 [DataOverHttps](INFO): Moved sent file to Logs/20191213T191452/Express0008.lzma.bak
2019-12-13T19:26:56.881Z,1576265216.881 [DataOverHttps](INFO): SBD MOMSN=12155707
2019-12-13T19:26:57.982Z,1576265217.982 [Default:CheckIn:Read_Iridium] Stopped
2019-12-13T19:26:57.982Z,1576265217.982 [Default:CheckIn:C.Wait] Running Loop=1
2019-12-13T19:26:57.982Z,1576265217.982 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-12-13T19:26:59.159Z,1576265219.159 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2019-12-13T19:26:59.238Z,1576265219.238 [NAL9602](FAULT): received: 
+CSQ:0

OK53, 2, 0, 0, 0

OK
2019-12-13T19:26:59.239Z,1576265219.239 [NAL9602] Data Fault, FailCount= 1
2019-12-13T19:26:59.239Z,1576265219.239 [NAL9602](ERROR): Data Fault
2019-12-13T19:26:59.323Z,1576265219.323 [CBIT](ERROR): Data Fault in component: NAL9602
2019-12-13T19:26:59.567Z,1576265219.567 [NAL9602](INFO): Powering down
2019-12-13T19:27:00.450Z,1576265220.450 [CBIT](INFO): Clearing failed state for component NAL9602
2019-12-13T19:27:00.450Z,1576265220.450 [NAL9602] No Fault, FailCount= 1
2019-12-13T19:27:29.867Z,1576265249.867 [NAL9602](INFO): Powering up NAL9602
2019-12-13T19:27:40.776Z,1576265260.776 [NAL9602](INFO): NAL9602 initialized
2019-12-13T19:28:11.879Z,1576265291.879 [NAL9602](INFO): Not Powering down - fast GPS
2019-12-13T19:30:50.273Z,1576265450.273 [BPC1](INFO): Calculating totals. Valid battery stick count: 55. Valid reserve battery stick count: 5.
2019-12-13T19:30:50.276Z,1576265450.276 [BPC1](INFO): Received data from all battery sticks.
2019-12-13T19:31:58.550Z,1576265518.550 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-12-13T19:31:58.550Z,1576265518.550 [Default:CheckIn:C.Wait] Stopped
2019-12-13T19:31:58.550Z,1576265518.550 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-12-13T19:31:58.551Z,1576265518.551 [Default:CheckIn:D] Running Loop=1
2019-12-13T19:31:58.958Z,1576265518.958 [Default:CheckIn:D] Stopped
2019-12-13T19:31:58.958Z,1576265518.958 [Default:CheckIn:E] Running Loop=1
2019-12-13T19:31:59.370Z,1576265519.370 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 14.214429 min 
2019-12-13T19:31:59.370Z,1576265519.370 [Default:CheckIn:E] Stopped
2019-12-13T19:31:59.370Z,1576265519.370 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-12-13T19:31:59.370Z,1576265519.370 [Default:CheckIn] Stopped
2019-12-13T19:31:59.370Z,1576265519.370 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-12-13T19:31:59.370Z,1576265519.370 [Default:CheckIn](INFO): Running loop #3
2019-12-13T19:31:59.371Z,1576265519.371 [Default:CheckIn] Running Loop=3
2019-12-13T19:31:59.371Z,1576265519.371 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-12-13T19:31:59.371Z,1576265519.371 [Default:CheckIn:Read_GPS] Running Loop=1
2019-12-13T19:32:03.371Z,1576265523.371 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2019-12-13T19:32:04.583Z,1576265524.583 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,193204.00,A,3648.16457,N,12147.28570,W,0.525,2.50,131219,,,A*7C
2019-12-13T19:32:04.585Z,1576265524.585 [NAL9602](INFO): GPS fix at 20191213T193204: (36.802743, -121.788095)
2019-12-13T19:32:04.634Z,1576265524.634 [Default:CheckIn:Read_GPS] Stopped
2019-12-13T19:32:04.634Z,1576265524.634 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-12-13T19:32:12.312Z,1576265532.312 [DataOverHttps](INFO): Sending 222 bytes from file Logs/20191213T191452/Courier0010.lzma
2019-12-13T19:32:14.312Z,1576265534.312 [DataOverHttps](INFO): Moved sent file to Logs/20191213T191452/Courier0010.lzma.bak
2019-12-13T19:32:14.312Z,1576265534.312 [DataOverHttps](INFO): SBD MOMSN=12155717
2019-12-13T19:32:30.974Z,1576265550.974 [DataOverHttps](INFO): Sending 235 bytes from file Logs/20191213T191452/Express0011.lzma
2019-12-13T19:32:32.980Z,1576265552.980 [DataOverHttps](INFO): Moved sent file to Logs/20191213T191452/Express0011.lzma.bak
2019-12-13T19:32:32.980Z,1576265552.980 [DataOverHttps](INFO): SBD MOMSN=12155720
2019-12-13T19:32:34.108Z,1576265554.108 [Default:CheckIn:Read_Iridium] Stopped
2019-12-13T19:32:34.108Z,1576265554.108 [Default:CheckIn:C.Wait] Running Loop=1
2019-12-13T19:32:34.109Z,1576265554.109 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-12-13T19:32:36.903Z,1576265556.903 [NAL9602](INFO): Not Powering down - fast GPS
2019-12-13T19:37:34.682Z,1576265854.682 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-12-13T19:37:34.682Z,1576265854.682 [Default:CheckIn:C.Wait] Stopped
2019-12-13T19:37:34.682Z,1576265854.682 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-12-13T19:37:34.704Z,1576265854.704 [Default:CheckIn:D] Running Loop=1
2019-12-13T19:37:35.081Z,1576265855.081 [Default:CheckIn:D] Stopped
2019-12-13T19:37:35.081Z,1576265855.081 [Default:CheckIn:E] Running Loop=1
2019-12-13T19:37:35.493Z,1576265855.493 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 19.816486 min 
2019-12-13T19:37:35.493Z,1576265855.493 [Default:CheckIn:E] Stopped
2019-12-13T19:37:35.494Z,1576265855.494 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-12-13T19:37:35.494Z,1576265855.494 [Default:CheckIn] Stopped
2019-12-13T19:37:35.494Z,1576265855.494 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-12-13T19:37:35.494Z,1576265855.494 [Default:CheckIn](INFO): Running loop #4
2019-12-13T19:37:35.494Z,1576265855.494 [Default:CheckIn] Running Loop=4
2019-12-13T19:37:35.494Z,1576265855.494 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-12-13T19:37:35.494Z,1576265855.494 [Default:CheckIn:Read_GPS] Running Loop=1
2019-12-13T19:37:37.483Z,1576265857.483 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,193737.00,A,3648.15968,N,12147.28576,W,0.369,342.13,131219,,,A*73
2019-12-13T19:37:37.485Z,1576265857.485 [NAL9602](INFO): GPS fix at 20191213T193737: (36.802661, -121.788096)
2019-12-13T19:37:37.530Z,1576265857.530 [Default:CheckIn:Read_GPS] Stopped
2019-12-13T19:37:37.530Z,1576265857.530 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-12-13T19:37:45.366Z,1576265865.366 [DataOverHttps](INFO): Sending 64 bytes from file Logs/20191213T191452/Courier0013.lzma
2019-12-13T19:37:47.372Z,1576265867.372 [DataOverHttps](INFO): Moved sent file to Logs/20191213T191452/Courier0013.lzma.bak
2019-12-13T19:37:47.372Z,1576265867.372 [DataOverHttps](INFO): SBD MOMSN=12155728
2019-12-13T19:38:04.178Z,1576265884.178 [DataOverHttps](INFO): Sending 120 bytes from file Logs/20191213T191452/Express0014.lzma
2019-12-13T19:38:06.184Z,1576265886.184 [DataOverHttps](INFO): Moved sent file to Logs/20191213T191452/Express0014.lzma.bak
2019-12-13T19:38:06.184Z,1576265886.184 [DataOverHttps](INFO): SBD MOMSN=12155738
2019-12-13T19:38:07.405Z,1576265887.405 [Default:CheckIn:Read_Iridium] Stopped
2019-12-13T19:38:07.405Z,1576265887.405 [Default:CheckIn:C.Wait] Running Loop=1
2019-12-13T19:38:07.405Z,1576265887.405 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-12-13T19:42:39.679Z,1576266159.679 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2019-12-13T19:43:07.986Z,1576266187.986 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-12-13T19:43:07.986Z,1576266187.986 [Default:CheckIn:C.Wait] Stopped
2019-12-13T19:43:07.986Z,1576266187.986 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-12-13T19:43:07.986Z,1576266187.986 [Default:CheckIn:D] Running Loop=1
2019-12-13T19:43:08.398Z,1576266188.398 [Default:CheckIn:D] Stopped
2019-12-13T19:43:08.398Z,1576266188.398 [Default:CheckIn:E] Running Loop=1
2019-12-13T19:43:08.794Z,1576266188.794 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 25.371763 min 
2019-12-13T19:43:08.794Z,1576266188.794 [Default:CheckIn:E] Stopped
2019-12-13T19:43:08.794Z,1576266188.794 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-12-13T19:43:08.794Z,1576266188.794 [Default:CheckIn] Stopped
2019-12-13T19:43:08.794Z,1576266188.794 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-12-13T19:43:08.794Z,1576266188.794 [Default:CheckIn](INFO): Running loop #5
2019-12-13T19:43:08.795Z,1576266188.795 [Default:CheckIn] Running Loop=5
2019-12-13T19:43:08.795Z,1576266188.795 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-12-13T19:43:08.795Z,1576266188.795 [Default:CheckIn:Read_GPS] Running Loop=1
2019-12-13T19:43:10.793Z,1576266190.793 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194310.00,A,3648.15607,N,12147.27742,W,0.292,342.13,131219,,,A*7C
2019-12-13T19:43:10.795Z,1576266190.795 [NAL9602](INFO): GPS fix at 20191213T194310: (36.802601, -121.787957)
2019-12-13T19:43:10.834Z,1576266190.834 [Default:CheckIn:Read_GPS] Stopped
2019-12-13T19:43:10.834Z,1576266190.834 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-12-13T19:43:18.334Z,1576266198.334 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20191213T191452/Courier0016.lzma
2019-12-13T19:43:20.340Z,1576266200.340 [DataOverHttps](INFO): Moved sent file to Logs/20191213T191452/Courier0016.lzma.bak
2019-12-13T19:43:20.340Z,1576266200.340 [DataOverHttps](INFO): SBD MOMSN=12155753
2019-12-13T19:43:37.026Z,1576266217.026 [DataOverHttps](INFO): Sending 195 bytes from file Logs/20191213T191452/Express0017.lzma
2019-12-13T19:43:39.032Z,1576266219.032 [DataOverHttps](INFO): Moved sent file to Logs/20191213T191452/Express0017.lzma.bak
2019-12-13T19:43:39.032Z,1576266219.032 [DataOverHttps](INFO): SBD MOMSN=12155756
2019-12-13T19:43:40.306Z,1576266220.306 [Default:CheckIn:Read_Iridium] Stopped
2019-12-13T19:43:40.306Z,1576266220.306 [Default:CheckIn:C.Wait] Running Loop=1
2019-12-13T19:43:40.307Z,1576266220.307 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-12-13T19:43:42.703Z,1576266222.703 [NAL9602](INFO): Not Powering down - fast GPS
2019-12-13T19:48:40.882Z,1576266520.882 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-12-13T19:48:40.882Z,1576266520.882 [Default:CheckIn:C.Wait] Stopped
2019-12-13T19:48:40.882Z,1576266520.882 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-12-13T19:48:40.882Z,1576266520.882 [Default:CheckIn:D] Running Loop=1
2019-12-13T19:48:41.292Z,1576266521.292 [Default:CheckIn:D] Stopped
2019-12-13T19:48:41.292Z,1576266521.292 [Default:CheckIn:E] Running Loop=1
2019-12-13T19:48:41.736Z,1576266521.736 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 30.920003 min 
2019-12-13T19:48:41.736Z,1576266521.736 [Default:CheckIn:E] Stopped
2019-12-13T19:48:41.737Z,1576266521.737 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-12-13T19:48:41.737Z,1576266521.737 [Default:CheckIn] Stopped
2019-12-13T19:48:41.737Z,1576266521.737 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-12-13T19:48:41.737Z,1576266521.737 [Default:CheckIn](INFO): Running loop #6
2019-12-13T19:48:41.737Z,1576266521.737 [Default:CheckIn] Running Loop=6
2019-12-13T19:48:41.737Z,1576266521.737 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-12-13T19:48:41.737Z,1576266521.737 [Default:CheckIn:Read_GPS] Running Loop=1
2019-12-13T19:48:43.685Z,1576266523.685 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194843.00,A,3648.16266,N,12147.28629,W,0.855,0.00,131219,,,A*74
2019-12-13T19:48:43.687Z,1576266523.687 [NAL9602](INFO): GPS fix at 20191213T194843: (36.802711, -121.788105)
2019-12-13T19:48:43.774Z,1576266523.774 [Default:CheckIn:Read_GPS] Stopped
2019-12-13T19:48:43.774Z,1576266523.774 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-12-13T19:48:50.795Z,1576266530.795 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20191213T191452/Courier0019.lzma
2019-12-13T19:48:52.800Z,1576266532.800 [DataOverHttps](INFO): Moved sent file to Logs/20191213T191452/Courier0019.lzma.bak
2019-12-13T19:48:52.800Z,1576266532.800 [DataOverHttps](INFO): SBD MOMSN=12155767
2019-12-13T19:49:08.626Z,1576266548.626 [DataOverHttps](INFO): Sending 121 bytes from file Logs/20191213T191452/Express0020.lzma
2019-12-13T19:49:10.632Z,1576266550.632 [DataOverHttps](INFO): Moved sent file to Logs/20191213T191452/Express0020.lzma.bak
2019-12-13T19:49:10.632Z,1576266550.632 [DataOverHttps](INFO): SBD MOMSN=12155770
2019-12-13T19:49:11.817Z,1576266551.817 [Default:CheckIn:Read_Iridium] Stopped
2019-12-13T19:49:11.818Z,1576266551.818 [Default:CheckIn:C.Wait] Running Loop=1
2019-12-13T19:49:11.818Z,1576266551.818 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-12-13T19:49:14.220Z,1576266554.220 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2019-12-13T19:49:14.302Z,1576266554.302 [NAL9602](FAULT): received: 
+CSQ:0

OK53, 2, 0, 0, 0

OK
2019-12-13T19:49:14.302Z,1576266554.302 [NAL9602] Data Fault, FailCount= 1
2019-12-13T19:49:14.303Z,1576266554.303 [NAL9602](ERROR): Data Fault
2019-12-13T19:49:14.386Z,1576266554.386 [CBIT](ERROR): Data Fault in component: NAL9602
2019-12-13T19:49:14.635Z,1576266554.635 [NAL9602](INFO): Powering down
2019-12-13T19:49:15.494Z,1576266555.494 [CBIT](INFO): Clearing failed state for component NAL9602
2019-12-13T19:49:15.498Z,1576266555.498 [NAL9602] No Fault, FailCount= 1
2019-12-13T19:49:44.932Z,1576266584.932 [NAL9602](INFO): Powering up NAL9602
2019-12-13T19:49:55.831Z,1576266595.831 [NAL9602](INFO): NAL9602 initialized
2019-12-13T19:50:26.947Z,1576266626.947 [NAL9602](INFO): Not Powering down - fast GPS
2019-12-13T19:54:12.398Z,1576266852.398 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-12-13T19:54:12.398Z,1576266852.398 [Default:CheckIn:C.Wait] Stopped
2019-12-13T19:54:12.399Z,1576266852.399 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-12-13T19:54:12.399Z,1576266852.399 [Default:CheckIn:D] Running Loop=1
2019-12-13T19:54:12.810Z,1576266852.810 [Default:CheckIn:D] Stopped
2019-12-13T19:54:12.810Z,1576266852.810 [Default:CheckIn:E] Running Loop=1
2019-12-13T19:54:13.208Z,1576266853.208 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 36.445296 min 
2019-12-13T19:54:13.209Z,1576266853.209 [Default:CheckIn:E] Stopped
2019-12-13T19:54:13.209Z,1576266853.209 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-12-13T19:54:13.209Z,1576266853.209 [Default:CheckIn] Stopped
2019-12-13T19:54:13.209Z,1576266853.209 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-12-13T19:54:13.209Z,1576266853.209 [Default:CheckIn](INFO): Running loop #7
2019-12-13T19:54:13.209Z,1576266853.209 [Default:CheckIn] Running Loop=7
2019-12-13T19:54:13.209Z,1576266853.209 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-12-13T19:54:13.209Z,1576266853.209 [Default:CheckIn:Read_GPS] Running Loop=1
2019-12-13T19:54:17.633Z,1576266857.633 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2019-12-13T19:55:27.111Z,1576266927.111 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,195526.00,A,3648.12879,N,12147.26067,W,0.156,144.07,131219,,,A*75
2019-12-13T19:55:27.113Z,1576266927.113 [NAL9602](INFO): GPS fix at 20191213T195526: (36.802146, -121.787678)
2019-12-13T19:55:27.157Z,1576266927.157 [Default:CheckIn:Read_GPS] Stopped
2019-12-13T19:55:27.157Z,1576266927.157 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-12-13T19:55:34.838Z,1576266934.838 [DataOverHttps](INFO): Sending 64 bytes from file Logs/20191213T191452/Courier0022.lzma
2019-12-13T19:55:36.844Z,1576266936.844 [DataOverHttps](INFO): Moved sent file to Logs/20191213T191452/Courier0022.lzma.bak
2019-12-13T19:55:36.844Z,1576266936.844 [DataOverHttps](INFO): SBD MOMSN=12155773
2019-12-13T19:55:53.530Z,1576266953.530 [DataOverHttps](INFO): Sending 238 bytes from file Logs/20191213T191452/Express0023.lzma
2019-12-13T19:55:55.536Z,1576266955.536 [DataOverHttps](INFO): Moved sent file to Logs/20191213T191452/Express0023.lzma.bak
2019-12-13T19:55:55.536Z,1576266955.536 [DataOverHttps](INFO): SBD MOMSN=12155776
2019-12-13T19:55:56.636Z,1576266956.636 [Default:CheckIn:Read_Iridium] Stopped
2019-12-13T19:55:56.636Z,1576266956.636 [Default:CheckIn:C.Wait] Running Loop=1
2019-12-13T19:55:56.636Z,1576266956.636 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-12-13T19:55:59.835Z,1576266959.835 [NAL9602](INFO): Not Powering down - fast GPS
2019-12-13T20:00:57.212Z,1576267257.212 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-12-13T20:00:57.212Z,1576267257.212 [Default:CheckIn:C.Wait] Stopped
2019-12-13T20:00:57.212Z,1576267257.212 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-12-13T20:00:57.212Z,1576267257.212 [Default:CheckIn:D] Running Loop=1
2019-12-13T20:00:57.622Z,1576267257.622 [Default:CheckIn:D] Stopped
2019-12-13T20:00:57.622Z,1576267257.622 [Default:CheckIn:E] Running Loop=1
2019-12-13T20:00:58.011Z,1576267258.011 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 43.192159 min 
2019-12-13T20:00:58.011Z,1576267258.011 [Default:CheckIn:E] Stopped
2019-12-13T20:00:58.011Z,1576267258.011 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-12-13T20:00:58.011Z,1576267258.011 [Default:CheckIn] Stopped
2019-12-13T20:00:58.011Z,1576267258.011 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-12-13T20:00:58.011Z,1576267258.011 [Default:CheckIn](INFO): Running loop #8
2019-12-13T20:00:58.012Z,1576267258.012 [Default:CheckIn] Running Loop=8
2019-12-13T20:00:58.012Z,1576267258.012 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-12-13T20:00:58.012Z,1576267258.012 [Default:CheckIn:Read_GPS] Running Loop=1
2019-12-13T20:01:00.013Z,1576267260.013 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,200059.00,A,3648.15476,N,12147.27794,W,0.875,144.07,131219,,,A*71
2019-12-13T20:01:00.015Z,1576267260.015 [NAL9602](INFO): GPS fix at 20191213T200059: (36.802579, -121.787966)
2019-12-13T20:01:00.039Z,1576267260.039 [Default:CheckIn:Read_GPS] Stopped
2019-12-13T20:01:00.039Z,1576267260.039 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-12-13T20:01:07.687Z,1576267267.687 [DataOverHttps](INFO): Sending 64 bytes from file Logs/20191213T191452/Courier0025.lzma
2019-12-13T20:01:09.693Z,1576267269.693 [DataOverHttps](INFO): Moved sent file to Logs/20191213T191452/Courier0025.lzma.bak
2019-12-13T20:01:09.693Z,1576267269.693 [DataOverHttps](INFO): SBD MOMSN=12155788
2019-12-13T20:01:26.406Z,1576267286.406 [DataOverHttps](INFO): Sending 120 bytes from file Logs/20191213T191452/Express0026.lzma
2019-12-13T20:01:28.412Z,1576267288.412 [DataOverHttps](INFO): Moved sent file to Logs/20191213T191452/Express0026.lzma.bak
2019-12-13T20:01:28.412Z,1576267288.412 [DataOverHttps](INFO): SBD MOMSN=12155792
2019-12-13T20:01:29.527Z,1576267289.527 [Default:CheckIn:Read_Iridium] Stopped
2019-12-13T20:01:29.527Z,1576267289.527 [Default:CheckIn:C.Wait] Running Loop=1
2019-12-13T20:01:29.527Z,1576267289.527 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-12-13T20:06:02.607Z,1576267562.607 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2019-12-13T20:06:30.110Z,1576267590.110 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-12-13T20:06:30.110Z,1576267590.110 [Default:CheckIn:C.Wait] Stopped
2019-12-13T20:06:30.110Z,1576267590.110 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-12-13T20:06:30.111Z,1576267590.111 [Default:CheckIn:D] Running Loop=1
2019-12-13T20:06:30.520Z,1576267590.520 [Default:CheckIn:D] Stopped
2019-12-13T20:06:30.520Z,1576267590.520 [Default:CheckIn:E] Running Loop=1
2019-12-13T20:06:30.911Z,1576267590.911 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 48.740458 min 
2019-12-13T20:06:30.911Z,1576267590.911 [Default:CheckIn:E] Stopped
2019-12-13T20:06:30.911Z,1576267590.911 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-12-13T20:06:30.911Z,1576267590.911 [Default:CheckIn] Stopped
2019-12-13T20:06:30.911Z,1576267590.911 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-12-13T20:06:30.912Z,1576267590.912 [Default:CheckIn](INFO): Running loop #9
2019-12-13T20:06:30.912Z,1576267590.912 [Default:CheckIn] Running Loop=9
2019-12-13T20:06:30.912Z,1576267590.912 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-12-13T20:06:30.912Z,1576267590.912 [Default:CheckIn:Read_GPS] Running Loop=1
2019-12-13T20:06:32.904Z,1576267592.904 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,200632.00,A,3648.16163,N,12147.28354,W,0.097,0.00,131219,,,A*7D
2019-12-13T20:06:32.907Z,1576267592.907 [NAL9602](INFO): GPS fix at 20191213T200632: (36.802694, -121.788059)
2019-12-13T20:06:32.931Z,1576267592.931 [Default:CheckIn:Read_GPS] Stopped
2019-12-13T20:06:32.931Z,1576267592.931 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-12-13T20:06:39.754Z,1576267599.754 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20191213T191452/Courier0028.lzma
2019-12-13T20:06:41.760Z,1576267601.760 [DataOverHttps](INFO): Moved sent file to Logs/20191213T191452/Courier0028.lzma.bak
2019-12-13T20:06:41.760Z,1576267601.760 [DataOverHttps](INFO): SBD MOMSN=12155795
2019-12-13T20:06:58.506Z,1576267618.506 [DataOverHttps](INFO): Sending 196 bytes from file Logs/20191213T191452/Express0029.lzma
2019-12-13T20:07:00.512Z,1576267620.512 [DataOverHttps](INFO): Moved sent file to Logs/20191213T191452/Express0029.lzma.bak
2019-12-13T20:07:00.512Z,1576267620.512 [DataOverHttps](INFO): SBD MOMSN=12155798
2019-12-13T20:07:01.627Z,1576267621.627 [Default:CheckIn:Read_Iridium] Stopped
2019-12-13T20:07:01.627Z,1576267621.627 [Default:CheckIn:C.Wait] Running Loop=1
2019-12-13T20:07:01.627Z,1576267621.627 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-12-13T20:07:04.819Z,1576267624.819 [NAL9602](INFO): Not Powering down - fast GPS
2019-12-13T20:12:02.186Z,1576267922.186 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-12-13T20:12:02.186Z,1576267922.186 [Default:CheckIn:C.Wait] Stopped
2019-12-13T20:12:02.186Z,1576267922.186 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-12-13T20:12:02.186Z,1576267922.186 [Default:CheckIn:D] Running Loop=1
2019-12-13T20:12:02.597Z,1576267922.597 [Default:CheckIn:D] Stopped
2019-12-13T20:12:02.597Z,1576267922.597 [Default:CheckIn:E] Running Loop=1
2019-12-13T20:12:03.005Z,1576267923.005 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 54.275081 min 
2019-12-13T20:12:03.005Z,1576267923.005 [Default:CheckIn:E] Stopped
2019-12-13T20:12:03.005Z,1576267923.005 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-12-13T20:12:03.005Z,1576267923.005 [Default:CheckIn] Stopped
2019-12-13T20:12:03.006Z,1576267923.006 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-12-13T20:12:03.006Z,1576267923.006 [Default:CheckIn](INFO): Running loop #10
2019-12-13T20:12:03.006Z,1576267923.006 [Default:CheckIn] Running Loop=10
2019-12-13T20:12:03.006Z,1576267923.006 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-12-13T20:12:03.006Z,1576267923.006 [Default:CheckIn:Read_GPS] Running Loop=1
2019-12-13T20:12:04.991Z,1576267924.991 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,201204.00,A,3648.16146,N,12147.28268,W,0.156,0.00,131219,,,A*78
2019-12-13T20:12:04.993Z,1576267924.993 [NAL9602](INFO): GPS fix at 20191213T201204: (36.802691, -121.788045)
2019-12-13T20:12:05.017Z,1576267925.017 [Default:CheckIn:Read_GPS] Stopped
2019-12-13T20:12:05.017Z,1576267925.017 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-12-13T20:12:12.506Z,1576267932.506 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20191213T191452/Courier0031.lzma
2019-12-13T20:12:14.512Z,1576267934.512 [DataOverHttps](INFO): Moved sent file to Logs/20191213T191452/Courier0031.lzma.bak
2019-12-13T20:12:14.512Z,1576267934.512 [DataOverHttps](INFO): SBD MOMSN=12155815
2019-12-13T20:12:33.210Z,1576267953.210 [DataOverHttps](INFO): Sending 119 bytes from file Logs/20191213T191452/Express0032.lzma
2019-12-13T20:12:35.216Z,1576267955.216 [DataOverHttps](INFO): Moved sent file to Logs/20191213T191452/Express0032.lzma.bak
2019-12-13T20:12:35.216Z,1576267955.216 [DataOverHttps](INFO): SBD MOMSN=12155821
2019-12-13T20:12:35.700Z,1576267955.700 [NAL9602](ERROR): Failed to receive proper response when querying signal strength for MT queue check.
2019-12-13T20:12:35.774Z,1576267955.774 [NAL9602](FAULT): received: 
+CSQ:0

OK53, 2, 0, 0, 0

OK
2019-12-13T20:12:35.774Z,1576267955.774 [NAL9602] Data Fault, FailCount= 1
2019-12-13T20:12:35.774Z,1576267955.774 [NAL9602](ERROR): Data Fault
2019-12-13T20:12:35.815Z,1576267955.815 [CBIT](ERROR): Data Fault in component: NAL9602
2019-12-13T20:12:36.099Z,1576267956.099 [NAL9602](INFO): Powering down
2019-12-13T20:12:36.507Z,1576267956.507 [NAL9602](FAULT): LCB fault:  Software Overcurrent.
2019-12-13T20:12:36.507Z,1576267956.507 [NAL9602] Hardware Fault, FailCount= 1
2019-12-13T20:12:36.508Z,1576267956.508 [NAL9602](ERROR): Hardware Fault
2019-12-13T20:12:36.556Z,1576267956.556 [Default:CheckIn:Read_Iridium] Stopped
2019-12-13T20:12:36.556Z,1576267956.556 [Default:CheckIn:C.Wait] Running Loop=1
2019-12-13T20:12:36.556Z,1576267956.556 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-12-13T20:12:36.962Z,1576267956.962 [CBIT](INFO): Clearing failed state for component NAL9602
2019-12-13T20:12:36.963Z,1576267956.963 [NAL9602] No Fault, FailCount= 1
2019-12-13T20:13:06.403Z,1576267986.403 [NAL9602](INFO): Powering up NAL9602
2019-12-13T20:13:17.307Z,1576267997.307 [NAL9602](INFO): NAL9602 initialized
2019-12-13T20:13:48.420Z,1576268028.420 [NAL9602](INFO): Not Powering down - fast GPS
2019-12-13T20:17:37.106Z,1576268257.106 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-12-13T20:17:37.106Z,1576268257.106 [Default:CheckIn:C.Wait] Stopped
2019-12-13T20:17:37.106Z,1576268257.106 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-12-13T20:17:37.107Z,1576268257.107 [Default:CheckIn:D] Running Loop=1
2019-12-13T20:17:37.516Z,1576268257.516 [Default:CheckIn:D] Stopped
2019-12-13T20:17:37.516Z,1576268257.516 [Default:CheckIn:E] Running Loop=1
2019-12-13T20:17:37.917Z,1576268257.917 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 59.857064 min 
2019-12-13T20:17:37.917Z,1576268257.917 [Default:CheckIn:E] Stopped
2019-12-13T20:17:37.917Z,1576268257.917 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-12-13T20:17:37.917Z,1576268257.917 [Default:CheckIn] Stopped
2019-12-13T20:17:37.917Z,1576268257.917 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-12-13T20:17:37.917Z,1576268257.917 [Default:CheckIn](INFO): Running loop #11
2019-12-13T20:17:37.917Z,1576268257.917 [Default:CheckIn] Running Loop=11
2019-12-13T20:17:37.918Z,1576268257.918 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-12-13T20:17:37.918Z,1576268257.918 [Default:CheckIn:Read_GPS] Running Loop=1
2019-12-13T20:17:39.913Z,1576268259.913 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,201738.00,A,3648.16316,N,12147.28100,W,0.428,0.00,131219,,,A*74
2019-12-13T20:17:39.915Z,1576268259.915 [NAL9602](INFO): GPS fix at 20191213T201738: (36.802719, -121.788017)
2019-12-13T20:17:39.960Z,1576268259.960 [Default:CheckIn:Read_GPS] Stopped
2019-12-13T20:17:39.960Z,1576268259.960 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-12-13T20:17:41.528Z,1576268261.528 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2019-12-13T20:17:47.182Z,1576268267.182 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20191213T191452/Courier0034.lzma
2019-12-13T20:17:49.188Z,1576268269.188 [DataOverHttps](INFO): Moved sent file to Logs/20191213T191452/Courier0034.lzma.bak
2019-12-13T20:17:49.188Z,1576268269.188 [DataOverHttps](INFO): SBD MOMSN=12155832
2019-12-13T20:18:05.870Z,1576268285.870 [DataOverHttps](INFO): Sending 195 bytes from file Logs/20191213T191452/Express0035.lzma
2019-12-13T20:18:07.876Z,1576268287.876 [DataOverHttps](INFO): Moved sent file to Logs/20191213T191452/Express0035.lzma.bak
2019-12-13T20:18:07.876Z,1576268287.876 [DataOverHttps](INFO): SBD MOMSN=12155835
2019-12-13T20:18:09.022Z,1576268289.022 [Default:CheckIn:Read_Iridium] Stopped
2019-12-13T20:18:09.022Z,1576268289.022 [Default:CheckIn:C.Wait] Running Loop=1
2019-12-13T20:18:09.022Z,1576268289.022 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-12-13T20:18:12.227Z,1576268292.227 [NAL9602](INFO): Not Powering down - fast GPS
2019-12-13T20:18:40.675Z,1576268320.675 [CommandLine](IMPORTANT): got command burn off
2019-12-13T20:18:40.675Z,1576268320.675 [CommandLine](IMPORTANT): Deactivating dropweight wire
2019-12-13T20:23:09.599Z,1576268589.599 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-12-13T20:23:09.599Z,1576268589.599 [Default:CheckIn:C.Wait] Stopped
2019-12-13T20:23:09.599Z,1576268589.599 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-12-13T20:23:09.599Z,1576268589.599 [Default:CheckIn:D] Running Loop=1
2019-12-13T20:23:10.006Z,1576268590.006 [Default:CheckIn:D] Stopped
2019-12-13T20:23:10.006Z,1576268590.006 [Default:CheckIn:E] Running Loop=1
2019-12-13T20:23:10.418Z,1576268590.418 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 65.398564 min 
2019-12-13T20:23:10.418Z,1576268590.418 [Default:CheckIn:E] Stopped
2019-12-13T20:23:10.418Z,1576268590.418 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-12-13T20:23:10.418Z,1576268590.418 [Default:CheckIn] Stopped
2019-12-13T20:23:10.418Z,1576268590.418 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-12-13T20:23:10.418Z,1576268590.418 [Default:CheckIn](INFO): Running loop #12
2019-12-13T20:23:10.419Z,1576268590.419 [Default:CheckIn] Running Loop=12
2019-12-13T20:23:10.419Z,1576268590.419 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-12-13T20:23:10.419Z,1576268590.419 [Default:CheckIn:Read_GPS] Running Loop=1
2019-12-13T20:23:12.400Z,1576268592.400 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,202312.00,A,3648.15764,N,12147.28137,W,0.194,356.61,131219,,,A*78
2019-12-13T20:23:12.403Z,1576268592.403 [NAL9602](INFO): GPS fix at 20191213T202312: (36.802627, -121.788023)
2019-12-13T20:23:12.428Z,1576268592.428 [Default:CheckIn:Read_GPS] Stopped
2019-12-13T20:23:12.428Z,1576268592.428 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-12-13T20:23:20.010Z,1576268600.010 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20191213T191452/Courier0037.lzma
2019-12-13T20:23:22.016Z,1576268602.016 [DataOverHttps](INFO): Moved sent file to Logs/20191213T191452/Courier0037.lzma.bak
2019-12-13T20:23:22.016Z,1576268602.016 [DataOverHttps](INFO): SBD MOMSN=12155847
2019-12-13T20:23:38.710Z,1576268618.710 [DataOverHttps](INFO): Sending 245 bytes from file Logs/20191213T191452/Express0038.lzma
2019-12-13T20:23:40.717Z,1576268620.717 [DataOverHttps](INFO): Moved sent file to Logs/20191213T191452/Express0038.lzma.bak
2019-12-13T20:23:40.717Z,1576268620.717 [DataOverHttps](INFO): SBD MOMSN=12155850
2019-12-13T20:23:41.931Z,1576268621.931 [Default:CheckIn:Read_Iridium] Stopped
2019-12-13T20:23:41.931Z,1576268621.931 [Default:CheckIn:C.Wait] Running Loop=1
2019-12-13T20:23:41.931Z,1576268621.931 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-12-13T20:24:49.381Z,1576268689.381 [NAL9602](INFO): SBD MO Status=0, MOMSN=3653, MT Status=0, MTMSN=0
2019-12-13T20:24:49.381Z,1576268689.381 [NAL9602](INFO): No messages in MT queue
2019-12-13T20:25:20.075Z,1576268720.075 [NAL9602](INFO): Not Powering down - fast GPS
2019-12-13T20:28:42.507Z,1576268922.507 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-12-13T20:28:42.507Z,1576268922.507 [Default:CheckIn:C.Wait] Stopped
2019-12-13T20:28:42.507Z,1576268922.507 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-12-13T20:28:42.507Z,1576268922.507 [Default:CheckIn:D] Running Loop=1
2019-12-13T20:28:42.910Z,1576268922.910 [Default:CheckIn:D] Stopped
2019-12-13T20:28:42.910Z,1576268922.910 [Default:CheckIn:E] Running Loop=1
2019-12-13T20:28:43.314Z,1576268923.314 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 70.946973 min 
2019-12-13T20:28:43.314Z,1576268923.314 [Default:CheckIn:E] Stopped
2019-12-13T20:28:43.315Z,1576268923.315 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-12-13T20:28:43.315Z,1576268923.315 [Default:CheckIn] Stopped
2019-12-13T20:28:43.315Z,1576268923.315 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-12-13T20:28:43.315Z,1576268923.315 [Default:CheckIn](INFO): Running loop #13
2019-12-13T20:28:43.315Z,1576268923.315 [Default:CheckIn] Running Loop=13
2019-12-13T20:28:43.315Z,1576268923.315 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-12-13T20:28:43.315Z,1576268923.315 [Default:CheckIn:Read_GPS] Running Loop=1
2019-12-13T20:28:45.313Z,1576268925.313 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,202845.00,A,3648.16226,N,12147.27880,W,0.272,356.61,131219,,,A*70
2019-12-13T20:28:45.315Z,1576268925.315 [NAL9602](INFO): GPS fix at 20191213T202845: (36.802704, -121.787980)
2019-12-13T20:28:45.363Z,1576268925.363 [Default:CheckIn:Read_GPS] Stopped
2019-12-13T20:28:45.363Z,1576268925.363 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-12-13T20:28:52.922Z,1576268932.922 [DataOverHttps](INFO): Sending 64 bytes from file Logs/20191213T191452/Courier0040.lzma
2019-12-13T20:28:54.928Z,1576268934.928 [DataOverHttps](INFO): Moved sent file to Logs/20191213T191452/Courier0040.lzma.bak
2019-12-13T20:28:54.928Z,1576268934.928 [DataOverHttps](INFO): SBD MOMSN=12155888
2019-12-13T20:29:11.654Z,1576268951.654 [DataOverHttps](INFO): Sending 119 bytes from file Logs/20191213T191452/Express0041.lzma
2019-12-13T20:29:13.660Z,1576268953.660 [DataOverHttps](INFO): Moved sent file to Logs/20191213T191452/Express0041.lzma.bak
2019-12-13T20:29:13.660Z,1576268953.660 [DataOverHttps](INFO): SBD MOMSN=12155891
2019-12-13T20:29:14.838Z,1576268954.838 [Default:CheckIn:Read_Iridium] Stopped
2019-12-13T20:29:14.838Z,1576268954.838 [Default:CheckIn:C.Wait] Running Loop=1
2019-12-13T20:29:14.838Z,1576268954.838 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-12-13T20:33:18.423Z,1576269198.423 [NAL9602](INFO): SBD MO Status=0, MOMSN=3654, MT Status=0, MTMSN=0
2019-12-13T20:33:18.423Z,1576269198.423 [NAL9602](INFO): No messages in MT queue
2019-12-13T20:33:49.131Z,1576269229.131 [NAL9602](INFO): Not Powering down - fast GPS
2019-12-13T20:34:15.424Z,1576269255.424 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-12-13T20:34:15.425Z,1576269255.425 [Default:CheckIn:C.Wait] Stopped
2019-12-13T20:34:15.425Z,1576269255.425 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-12-13T20:34:15.425Z,1576269255.425 [Default:CheckIn:D] Running Loop=1
2019-12-13T20:34:15.839Z,1576269255.839 [Default:CheckIn:D] Stopped
2019-12-13T20:34:15.839Z,1576269255.839 [Default:CheckIn:E] Running Loop=1
2019-12-13T20:34:16.223Z,1576269256.223 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 76.495785 min 
2019-12-13T20:34:16.223Z,1576269256.223 [Default:CheckIn:E] Stopped
2019-12-13T20:34:16.224Z,1576269256.224 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-12-13T20:34:16.224Z,1576269256.224 [Default:CheckIn] Stopped
2019-12-13T20:34:16.224Z,1576269256.224 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-12-13T20:34:16.224Z,1576269256.224 [Default:CheckIn](INFO): Running loop #14
2019-12-13T20:34:16.224Z,1576269256.224 [Default:CheckIn] Running Loop=14
2019-12-13T20:34:16.224Z,1576269256.224 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-12-13T20:34:16.224Z,1576269256.224 [Default:CheckIn:Read_GPS] Running Loop=1
2019-12-13T20:34:18.218Z,1576269258.218 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,203418.00,A,3648.16550,N,12147.28633,W,0.019,0.00,131219,,,A*72
2019-12-13T20:34:18.228Z,1576269258.228 [NAL9602](INFO): GPS fix at 20191213T203418: (36.802758, -121.788106)
2019-12-13T20:34:18.252Z,1576269258.252 [Default:CheckIn:Read_GPS] Stopped
2019-12-13T20:34:18.252Z,1576269258.252 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-12-13T20:34:25.391Z,1576269265.391 [DataOverHttps](INFO): Sending 64 bytes from file Logs/20191213T191452/Courier0043.lzma
2019-12-13T20:34:27.396Z,1576269267.396 [DataOverHttps](INFO): Moved sent file to Logs/20191213T191452/Courier0043.lzma.bak
2019-12-13T20:34:27.396Z,1576269267.396 [DataOverHttps](INFO): SBD MOMSN=12155912
2019-12-13T20:34:29.931Z,1576269269.931 [NAL9602](INFO): SBD MO Status=0, MOMSN=3655, MT Status=0, MTMSN=0
2019-12-13T20:34:29.931Z,1576269269.931 [NAL9602](INFO): No messages in MT queue
2019-12-13T20:34:45.622Z,1576269285.622 [DataOverHttps](INFO): Sending 120 bytes from file Logs/20191213T191452/Express0044.lzma
2019-12-13T20:34:47.628Z,1576269287.628 [DataOverHttps](INFO): Moved sent file to Logs/20191213T191452/Express0044.lzma.bak
2019-12-13T20:34:47.628Z,1576269287.628 [DataOverHttps](INFO): SBD MOMSN=12155915
2019-12-13T20:34:48.947Z,1576269288.947 [Default:CheckIn:Read_Iridium] Stopped
2019-12-13T20:34:48.947Z,1576269288.947 [Default:CheckIn:C.Wait] Running Loop=1
2019-12-13T20:34:48.947Z,1576269288.947 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-12-13T20:35:00.643Z,1576269300.643 [NAL9602](INFO): Not Powering down - fast GPS
2019-12-13T20:35:47.521Z,1576269347.521 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2019-12-13T20:36:02.876Z,1576269362.876 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2019-12-13T20:36:18.631Z,1576269378.631 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2019-12-13T20:36:33.994Z,1576269393.994 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2019-12-13T20:36:49.344Z,1576269409.344 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2019-12-13T20:37:04.702Z,1576269424.702 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2019-12-13T20:37:19.651Z,1576269439.651 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2019-12-13T20:37:34.998Z,1576269454.998 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2019-12-13T20:37:49.948Z,1576269469.948 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2019-12-13T20:38:04.897Z,1576269484.897 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2019-12-13T20:38:19.852Z,1576269499.852 [BPC1](INFO): Calculating totals. Valid battery stick count: 55. Valid reserve battery stick count: 5.
2019-12-13T20:38:19.855Z,1576269499.855 [BPC1](INFO): Received data from all battery sticks.
2019-12-13T20:39:49.549Z,1576269589.549 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-12-13T20:39:49.549Z,1576269589.549 [Default:CheckIn:C.Wait] Stopped
2019-12-13T20:39:49.549Z,1576269589.549 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-12-13T20:39:49.549Z,1576269589.549 [Default:CheckIn:D] Running Loop=1
2019-12-13T20:39:49.958Z,1576269589.958 [Default:CheckIn:D] Stopped
2019-12-13T20:39:49.958Z,1576269589.958 [Default:CheckIn:E] Running Loop=1
2019-12-13T20:39:50.350Z,1576269590.350 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 82.064437 min 
2019-12-13T20:39:50.350Z,1576269590.350 [Default:CheckIn:E] Stopped
2019-12-13T20:39:50.351Z,1576269590.351 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-12-13T20:39:50.351Z,1576269590.351 [Default:CheckIn] Stopped
2019-12-13T20:39:50.351Z,1576269590.351 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-12-13T20:39:50.351Z,1576269590.351 [Default:CheckIn](INFO): Running loop #15
2019-12-13T20:39:50.351Z,1576269590.351 [Default:CheckIn] Running Loop=15
2019-12-13T20:39:50.351Z,1576269590.351 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-12-13T20:39:50.351Z,1576269590.351 [Default:CheckIn:Read_GPS] Running Loop=1
2019-12-13T20:39:52.344Z,1576269592.344 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,203952.00,A,3648.17741,N,12147.27949,W,0.447,0.00,131219,,,A*70
2019-12-13T20:39:52.347Z,1576269592.347 [NAL9602](INFO): GPS fix at 20191213T203952: (36.802957, -121.787992)
2019-12-13T20:39:52.371Z,1576269592.371 [Default:CheckIn:Read_GPS] Stopped
2019-12-13T20:39:52.371Z,1576269592.371 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-12-13T20:40:00.030Z,1576269600.030 [DataOverHttps](INFO): Sending 80 bytes from file Logs/20191213T191452/Courier0046.lzma
2019-12-13T20:40:02.036Z,1576269602.036 [DataOverHttps](INFO): Moved sent file to Logs/20191213T191452/Courier0046.lzma.bak
2019-12-13T20:40:02.036Z,1576269602.036 [DataOverHttps](INFO): SBD MOMSN=12155920
2019-12-13T20:40:18.762Z,1576269618.762 [DataOverHttps](INFO): Sending 120 bytes from file Logs/20191213T191452/Express0047.lzma
2019-12-13T20:40:20.768Z,1576269620.768 [DataOverHttps](INFO): Moved sent file to Logs/20191213T191452/Express0047.lzma.bak
2019-12-13T20:40:20.768Z,1576269620.768 [DataOverHttps](INFO): SBD MOMSN=12155923
2019-12-13T20:40:21.869Z,1576269621.869 [Default:CheckIn:Read_Iridium] Stopped
2019-12-13T20:40:21.869Z,1576269621.869 [Default:CheckIn:C.Wait] Running Loop=1
2019-12-13T20:40:21.869Z,1576269621.869 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-12-13T20:40:58.205Z,1576269658.205 [NAL9602](INFO): SBD MO Status=0, MOMSN=3656, MT Status=0, MTMSN=0
2019-12-13T20:40:58.205Z,1576269658.205 [NAL9602](INFO): No messages in MT queue
2019-12-13T20:41:28.903Z,1576269688.903 [NAL9602](INFO): Not Powering down - fast GPS
2019-12-13T20:45:22.482Z,1576269922.482 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-12-13T20:45:22.482Z,1576269922.482 [Default:CheckIn:C.Wait] Stopped
2019-12-13T20:45:22.483Z,1576269922.483 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-12-13T20:45:22.483Z,1576269922.483 [Default:CheckIn:D] Running Loop=1
2019-12-13T20:45:22.885Z,1576269922.885 [Default:CheckIn:D] Stopped
2019-12-13T20:45:22.885Z,1576269922.885 [Default:CheckIn:E] Running Loop=1
2019-12-13T20:45:23.297Z,1576269923.297 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 87.613216 min 
2019-12-13T20:45:23.297Z,1576269923.297 [Default:CheckIn:E] Stopped
2019-12-13T20:45:23.297Z,1576269923.297 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-12-13T20:45:23.297Z,1576269923.297 [Default:CheckIn] Stopped
2019-12-13T20:45:23.298Z,1576269923.298 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-12-13T20:45:23.298Z,1576269923.298 [Default:CheckIn](INFO): Running loop #16
2019-12-13T20:45:23.298Z,1576269923.298 [Default:CheckIn] Running Loop=16
2019-12-13T20:45:23.298Z,1576269923.298 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-12-13T20:45:23.299Z,1576269923.299 [Default:CheckIn:Read_GPS] Running Loop=1
2019-12-13T20:45:25.293Z,1576269925.293 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,204525.00,A,3648.13484,N,12147.22718,W,0.058,31.55,131219,,,D*47
2019-12-13T20:45:25.295Z,1576269925.295 [NAL9602](INFO): GPS fix at 20191213T204525: (36.802247, -121.787120)
2019-12-13T20:45:25.334Z,1576269925.334 [Default:CheckIn:Read_GPS] Stopped
2019-12-13T20:45:25.334Z,1576269925.334 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-12-13T20:45:32.886Z,1576269932.886 [DataOverHttps](INFO): Sending 64 bytes from file Logs/20191213T191452/Courier0049.lzma
2019-12-13T20:45:34.892Z,1576269934.892 [DataOverHttps](INFO): Moved sent file to Logs/20191213T191452/Courier0049.lzma.bak
2019-12-13T20:45:34.892Z,1576269934.892 [DataOverHttps](INFO): SBD MOMSN=12156131
2019-12-13T20:45:51.634Z,1576269951.634 [DataOverHttps](INFO): Sending 120 bytes from file Logs/20191213T191452/Express0050.lzma
2019-12-13T20:45:53.640Z,1576269953.640 [DataOverHttps](INFO): Moved sent file to Logs/20191213T191452/Express0050.lzma.bak
2019-12-13T20:45:53.640Z,1576269953.640 [DataOverHttps](INFO): SBD MOMSN=12156135
2019-12-13T20:45:54.806Z,1576269954.806 [Default:CheckIn:Read_Iridium] Stopped
2019-12-13T20:45:54.807Z,1576269954.807 [Default:CheckIn:C.Wait] Running Loop=1
2019-12-13T20:45:54.807Z,1576269954.807 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-12-13T20:45:56.801Z,1576269956.801 [NAL9602](INFO): SBD MO Status=2, MOMSN=3657, MT Status=2, MTMSN=0
2019-12-13T20:45:56.801Z,1576269956.801 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-12-13T20:46:17.808Z,1576269977.808 [NAL9602](INFO): SBD MO Status=0, MOMSN=3657, MT Status=0, MTMSN=0
2019-12-13T20:46:17.808Z,1576269977.808 [NAL9602](INFO): No messages in MT queue
2019-12-13T20:46:48.523Z,1576270008.523 [NAL9602](INFO): Not Powering down - fast GPS
2019-12-13T20:47:14.315Z,1576270034.315 [DataOverHttps](IMPORTANT): SBD MTMSN=20191213T204713
2019-12-13T20:47:21.778Z,1576270041.778 [DataOverHttps](INFO): Received command:ibit
2019-12-13T20:47:21.823Z,1576270041.823 [CommandLine](IMPORTANT): got command ibit
2019-12-13T20:47:22.086Z,1576270042.086 [IBIT](IMPORTANT): Beginning Initiated BIT
2019-12-13T20:47:22.086Z,1576270042.086 [IBIT](IMPORTANT): Beginning control surface checks.
2019-12-13T20:47:22.089Z,1576270042.089 [CBIT](IMPORTANT): Beginning ground fault scan
2019-12-13T20:47:23.678Z,1576270043.678 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,204723.00,A,3648.14137,N,12147.22719,W,0.136,31.55,131219,,,D*41
2019-12-13T20:47:23.680Z,1576270043.680 [NAL9602](INFO): GPS fix at 20191213T204723: (36.802356, -121.787120)
2019-12-13T20:47:33.005Z,1576270053.005 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.042931
CHAN A1 (24V): -0.214928
CHAN A2 (12V): 0.022434
CHAN A3 (5V): -0.010814
CHAN B0 (3.3V): -0.008805
CHAN B1 (3.15aV): -0.006108
CHAN B2 (3.15bV): -0.004121
CHAN B3 (GND): -0.013910
OPEN: 0.004623
Full Scale Calc: 4.765 mA, -1.589 mA
2019-12-13T20:47:43.463Z,1576270063.463 [NAL9602](INFO): SBD MO Status=0, MOMSN=3658, MT Status=0, MTMSN=0
2019-12-13T20:47:43.463Z,1576270063.463 [NAL9602](INFO): No messages in MT queue
2019-12-13T20:47:44.677Z,1576270064.677 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,204744.00,A,3648.14113,N,12147.22741,W,0.097,31.55,131219,,,D*41
2019-12-13T20:47:44.680Z,1576270064.680 [NAL9602](INFO): GPS fix at 20191213T204744: (36.802352, -121.787124)
2019-12-13T20:47:47.504Z,1576270067.504 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,204747.00,A,3648.14112,N,12147.22744,W,0.039,31.55,131219,,,D*42
2019-12-13T20:47:47.507Z,1576270067.507 [NAL9602](INFO): GPS fix at 20191213T204747: (36.802352, -121.787124)
2019-12-13T20:47:50.337Z,1576270070.337 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,204750.00,A,3648.14108,N,12147.22740,W,0.058,31.55,131219,,,D*4C
2019-12-13T20:47:50.339Z,1576270070.339 [NAL9602](INFO): GPS fix at 20191213T204750: (36.802351, -121.787123)
2019-12-13T20:47:53.161Z,1576270073.161 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,204753.00,A,3648.14100,N,12147.22731,W,0.039,31.55,131219,,,D*46
2019-12-13T20:47:53.163Z,1576270073.163 [NAL9602](INFO): GPS fix at 20191213T204753: (36.802350, -121.787122)
2019-12-13T20:47:56.393Z,1576270076.393 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,204756.00,A,3648.14107,N,12147.22735,W,0.000,31.55,131219,,,D*4A
2019-12-13T20:47:56.395Z,1576270076.395 [NAL9602](INFO): GPS fix at 20191213T204756: (36.802351, -121.787122)
2019-12-13T20:47:59.221Z,1576270079.221 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,204759.00,A,3648.14111,N,12147.22741,W,0.039,31.55,131219,,,D*4B
2019-12-13T20:47:59.224Z,1576270079.224 [NAL9602](INFO): GPS fix at 20191213T204759: (36.802352, -121.787124)
2019-12-13T20:48:02.457Z,1576270082.457 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,204802.00,A,3648.14115,N,12147.22750,W,0.039,31.55,131219,,,D*4E
2019-12-13T20:48:02.459Z,1576270082.459 [NAL9602](INFO): GPS fix at 20191213T204802: (36.802352, -121.787125)
2019-12-13T20:48:05.302Z,1576270085.302 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,204805.00,A,3648.14116,N,12147.22752,W,0.058,31.55,131219,,,D*4F
2019-12-13T20:48:05.304Z,1576270085.304 [NAL9602](INFO): GPS fix at 20191213T204805: (36.802353, -121.787125)
2019-12-13T20:48:08.517Z,1576270088.517 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,204808.00,A,3648.14116,N,12147.22751,W,0.058,31.55,131219,,,D*41
2019-12-13T20:48:08.519Z,1576270088.519 [NAL9602](INFO): GPS fix at 20191213T204808: (36.802353, -121.787125)
2019-12-13T20:48:08.563Z,1576270088.563 [IBIT](IMPORTANT): Communications Status:
Fix Status: 1
Iridium Signal Strength: 4
Latitude: 36.802353 Longitude: -121.787125
2019-12-13T20:48:08.968Z,1576270088.968 [IBIT](IMPORTANT): Battery Status:
Battery Charge (AH): 0.000000
Voltage: 0.000000
2019-12-13T20:48:08.968Z,1576270088.968 [IBIT](IMPORTANT): batteryCapacityThreshold: 50.000000 Ah
2019-12-13T20:48:08.968Z,1576270088.968 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.700000 V
2019-12-13T20:48:09.359Z,1576270089.359 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 %
2019-12-13T20:48:09.360Z,1576270089.360 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi
2019-12-13T20:48:09.360Z,1576270089.360 [IBIT](IMPORTANT): Pressure:8.155732 PSI
2019-12-13T20:48:09.360Z,1576270089.360 [IBIT](IMPORTANT): Humidity:12.764009 %
2019-12-13T20:48:09.758Z,1576270089.758 [IBIT](IMPORTANT): Vehicle Pitch:0.529744 degrees
2019-12-13T20:48:09.759Z,1576270089.759 [IBIT](IMPORTANT): Vehicle  Roll:17.866770 degrees
2019-12-13T20:48:09.759Z,1576270089.759 [IBIT](IMPORTANT): Vehicle  Heading:19.623238 degrees
2019-12-13T20:48:10.175Z,1576270090.175 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m
2019-12-13T20:48:10.175Z,1576270090.175 [IBIT](IMPORTANT): buoyancyNeutral: 168.000000 cc
2019-12-13T20:48:10.175Z,1576270090.175 [IBIT](IMPORTANT): massDefault: 0.370000 cm
2019-12-13T20:48:10.176Z,1576270090.176 [IBIT](IMPORTANT): stopDepth: 50.000000 m
2019-12-13T20:48:10.176Z,1576270090.176 [IBIT](IMPORTANT): abortDepth: 60.000000 m
2019-12-13T20:48:10.176Z,1576270090.176 [IBIT](IMPORTANT): IBIT PASSED
2019-12-13T20:48:40.829Z,1576270120.829 [NAL9602](INFO): Not Powering down - fast GPS
2019-12-13T20:50:55.395Z,1576270255.395 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-12-13T20:50:55.396Z,1576270255.396 [Default:CheckIn:C.Wait] Stopped
2019-12-13T20:50:55.396Z,1576270255.396 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-12-13T20:50:55.396Z,1576270255.396 [Default:CheckIn:D] Running Loop=1
2019-12-13T20:50:55.804Z,1576270255.804 [Default:CheckIn:D] Stopped
2019-12-13T20:50:55.804Z,1576270255.804 [Default:CheckIn:E] Running Loop=1
2019-12-13T20:50:56.203Z,1576270256.203 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 93.161865 min 
2019-12-13T20:50:56.203Z,1576270256.203 [Default:CheckIn:E] Stopped
2019-12-13T20:50:56.203Z,1576270256.203 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-12-13T20:50:56.203Z,1576270256.203 [Default:CheckIn] Stopped
2019-12-13T20:50:56.203Z,1576270256.203 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-12-13T20:50:56.203Z,1576270256.203 [Default:CheckIn](INFO): Running loop #17
2019-12-13T20:50:56.203Z,1576270256.203 [Default:CheckIn] Running Loop=17
2019-12-13T20:50:56.203Z,1576270256.203 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-12-13T20:50:56.204Z,1576270256.204 [Default:CheckIn:Read_GPS] Running Loop=1
2019-12-13T20:50:58.201Z,1576270258.201 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,205058.00,A,3648.14210,N,12147.22908,W,0.039,31.55,131219,,,D*4D
2019-12-13T20:50:58.203Z,1576270258.203 [NAL9602](INFO): GPS fix at 20191213T205058: (36.802368, -121.787151)
2019-12-13T20:50:58.227Z,1576270258.227 [Default:CheckIn:Read_GPS] Stopped
2019-12-13T20:50:58.227Z,1576270258.227 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-12-13T20:51:05.610Z,1576270265.610 [DataOverHttps](INFO): Sending 64 bytes from file Logs/20191213T191452/Courier0052.lzma
2019-12-13T20:51:07.616Z,1576270267.616 [DataOverHttps](INFO): Moved sent file to Logs/20191213T191452/Courier0052.lzma.bak
2019-12-13T20:51:07.616Z,1576270267.616 [DataOverHttps](INFO): SBD MOMSN=12156146
2019-12-13T20:51:11.935Z,1576270271.935 [NAL9602](INFO): SBD MO Status=0, MOMSN=3659, MT Status=0, MTMSN=0
2019-12-13T20:51:11.935Z,1576270271.935 [NAL9602](INFO): No messages in MT queue
2019-12-13T20:51:24.367Z,1576270284.367 [DataOverHttps](INFO): Sending 804 bytes from file Logs/20191213T191452/Express0053.lzma
2019-12-13T20:51:26.372Z,1576270286.372 [DataOverHttps](INFO): Moved sent file to Logs/20191213T191452/Express0053.lzma.bak
2019-12-13T20:51:26.372Z,1576270286.372 [DataOverHttps](INFO): SBD MOMSN=12156150
2019-12-13T20:51:42.633Z,1576270302.633 [NAL9602](INFO): Not Powering down - fast GPS
2019-12-13T20:51:43.134Z,1576270303.134 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20191213T191452/Express0056.lzma
2019-12-13T20:51:45.140Z,1576270305.140 [DataOverHttps](INFO): Moved sent file to Logs/20191213T191452/Express0056.lzma.bak
2019-12-13T20:51:45.140Z,1576270305.140 [DataOverHttps](INFO): SBD MOMSN=12156176
2019-12-13T20:51:46.298Z,1576270306.298 [Default:CheckIn:Read_Iridium] Stopped
2019-12-13T20:51:46.298Z,1576270306.298 [Default:CheckIn:C.Wait] Running Loop=1
2019-12-13T20:51:46.298Z,1576270306.298 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-12-13T20:56:46.878Z,1576270606.878 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-12-13T20:56:46.878Z,1576270606.878 [Default:CheckIn:C.Wait] Stopped
2019-12-13T20:56:46.878Z,1576270606.878 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-12-13T20:56:46.879Z,1576270606.879 [Default:CheckIn:D] Running Loop=1
2019-12-13T20:56:47.284Z,1576270607.284 [Default:CheckIn:D] Stopped
2019-12-13T20:56:47.284Z,1576270607.284 [Default:CheckIn:E] Running Loop=1
2019-12-13T20:56:47.682Z,1576270607.682 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 99.019857 min 
2019-12-13T20:56:47.683Z,1576270607.683 [Default:CheckIn:E] Stopped
2019-12-13T20:56:47.683Z,1576270607.683 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-12-13T20:56:47.683Z,1576270607.683 [Default:CheckIn] Stopped
2019-12-13T20:56:47.683Z,1576270607.683 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-12-13T20:56:47.683Z,1576270607.683 [Default:CheckIn](INFO): Running loop #18
2019-12-13T20:56:47.683Z,1576270607.683 [Default:CheckIn] Running Loop=18
2019-12-13T20:56:47.683Z,1576270607.683 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-12-13T20:56:47.683Z,1576270607.683 [Default:CheckIn:Read_GPS] Running Loop=1
2019-12-13T20:56:49.676Z,1576270609.676 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,205649.00,A,3648.13928,N,12147.22820,W,0.039,31.55,131219,,,D*47
2019-12-13T20:56:49.678Z,1576270609.678 [NAL9602](INFO): GPS fix at 20191213T205649: (36.802321, -121.787137)
2019-12-13T20:56:49.701Z,1576270609.701 [Default:CheckIn:Read_GPS] Stopped
2019-12-13T20:56:49.702Z,1576270609.702 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-12-13T20:56:57.110Z,1576270617.110 [DataOverHttps](INFO): Sending 64 bytes from file Logs/20191213T191452/Courier0058.lzma
2019-12-13T20:56:59.116Z,1576270619.116 [DataOverHttps](INFO): Moved sent file to Logs/20191213T191452/Courier0058.lzma.bak
2019-12-13T20:56:59.116Z,1576270619.116 [DataOverHttps](INFO): SBD MOMSN=12156193
2019-12-13T20:57:07.457Z,1576270627.457 [NAL9602](INFO): SBD MO Status=2, MOMSN=3660, MT Status=2, MTMSN=0
2019-12-13T20:57:07.457Z,1576270627.457 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-12-13T20:57:15.944Z,1576270635.944 [DataOverHttps](INFO): Sending 120 bytes from file Logs/20191213T191452/Express0059.lzma
2019-12-13T20:57:17.948Z,1576270637.948 [DataOverHttps](INFO): Moved sent file to Logs/20191213T191452/Express0059.lzma.bak
2019-12-13T20:57:17.948Z,1576270637.948 [DataOverHttps](INFO): SBD MOMSN=12156196
2019-12-13T20:57:19.203Z,1576270639.203 [Default:CheckIn:Read_Iridium] Stopped
2019-12-13T20:57:19.203Z,1576270639.203 [Default:CheckIn:C.Wait] Running Loop=1
2019-12-13T20:57:19.203Z,1576270639.203 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-12-13T20:57:21.593Z,1576270641.593 [NAL9602](INFO): SBD MO Status=0, MOMSN=3660, MT Status=0, MTMSN=0
2019-12-13T20:57:21.593Z,1576270641.593 [NAL9602](INFO): No messages in MT queue
2019-12-13T20:57:52.294Z,1576270672.294 [NAL9602](INFO): Not Powering down - fast GPS
2019-12-13T21:02:19.794Z,1576270939.794 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-12-13T21:02:19.794Z,1576270939.794 [Default:CheckIn:C.Wait] Stopped
2019-12-13T21:02:19.795Z,1576270939.795 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-12-13T21:02:19.795Z,1576270939.795 [Default:CheckIn:D] Running Loop=1
2019-12-13T21:02:20.179Z,1576270940.179 [Default:CheckIn:D] Stopped
2019-12-13T21:02:20.179Z,1576270940.179 [Default:CheckIn:E] Running Loop=1
2019-12-13T21:02:20.590Z,1576270940.590 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 104.568107 min 
2019-12-13T21:02:20.590Z,1576270940.590 [Default:CheckIn:E] Stopped
2019-12-13T21:02:20.591Z,1576270940.591 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-12-13T21:02:20.591Z,1576270940.591 [Default:CheckIn] Stopped
2019-12-13T21:02:20.591Z,1576270940.591 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-12-13T21:02:20.591Z,1576270940.591 [Default:CheckIn](INFO): Running loop #19
2019-12-13T21:02:20.591Z,1576270940.591 [Default:CheckIn] Running Loop=19
2019-12-13T21:02:20.591Z,1576270940.591 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-12-13T21:02:20.591Z,1576270940.591 [Default:CheckIn:Read_GPS] Running Loop=1
2019-12-13T21:02:22.575Z,1576270942.575 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,210222.00,A,3648.14250,N,12147.22839,W,0.058,31.55,131219,,,D*46
2019-12-13T21:02:22.577Z,1576270942.577 [NAL9602](INFO): GPS fix at 20191213T210222: (36.802375, -121.787140)
2019-12-13T21:02:22.625Z,1576270942.625 [Default:CheckIn:Read_GPS] Stopped
2019-12-13T21:02:22.626Z,1576270942.626 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-12-13T21:02:30.626Z,1576270950.626 [DataOverHttps](INFO): Sending 64 bytes from file Logs/20191213T191452/Courier0061.lzma
2019-12-13T21:02:32.632Z,1576270952.632 [DataOverHttps](INFO): Moved sent file to Logs/20191213T191452/Courier0061.lzma.bak
2019-12-13T21:02:32.632Z,1576270952.632 [DataOverHttps](INFO): SBD MOMSN=12156207
2019-12-13T21:02:34.695Z,1576270954.695 [NAL9602](INFO): SBD MO Status=0, MOMSN=3661, MT Status=0, MTMSN=0
2019-12-13T21:02:34.696Z,1576270954.696 [NAL9602](INFO): No messages in MT queue
2019-12-13T21:02:51.242Z,1576270971.242 [DataOverHttps](INFO): Sending 121 bytes from file Logs/20191213T191452/Express0062.lzma
2019-12-13T21:02:53.248Z,1576270973.248 [DataOverHttps](INFO): Moved sent file to Logs/20191213T191452/Express0062.lzma.bak
2019-12-13T21:02:53.248Z,1576270973.248 [DataOverHttps](INFO): SBD MOMSN=12156211
2019-12-13T21:02:54.544Z,1576270974.544 [Default:CheckIn:Read_Iridium] Stopped
2019-12-13T21:02:54.544Z,1576270974.544 [Default:CheckIn:C.Wait] Running Loop=1
2019-12-13T21:02:54.544Z,1576270974.544 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-12-13T21:03:05.439Z,1576270985.439 [NAL9602](INFO): Not Powering down - fast GPS
2019-12-13T21:07:55.140Z,1576271275.140 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-12-13T21:07:55.140Z,1576271275.140 [Default:CheckIn:C.Wait] Stopped
2019-12-13T21:07:55.141Z,1576271275.141 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-12-13T21:07:55.141Z,1576271275.141 [Default:CheckIn:D] Running Loop=1
2019-12-13T21:07:55.538Z,1576271275.538 [Default:CheckIn:D] Stopped
2019-12-13T21:07:55.538Z,1576271275.538 [Default:CheckIn:E] Running Loop=1
2019-12-13T21:07:55.939Z,1576271275.939 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 110.157430 min 
2019-12-13T21:07:55.939Z,1576271275.939 [Default:CheckIn:E] Stopped
2019-12-13T21:07:55.939Z,1576271275.939 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-12-13T21:07:55.939Z,1576271275.939 [Default:CheckIn] Stopped
2019-12-13T21:07:55.939Z,1576271275.939 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-12-13T21:07:55.939Z,1576271275.939 [Default:CheckIn](INFO): Running loop #20
2019-12-13T21:07:55.939Z,1576271275.939 [Default:CheckIn] Running Loop=20
2019-12-13T21:07:55.940Z,1576271275.940 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-12-13T21:07:55.940Z,1576271275.940 [Default:CheckIn:Read_GPS] Running Loop=1
2019-12-13T21:07:57.935Z,1576271277.935 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,210757.00,A,3648.14179,N,12147.22875,W,0.039,31.55,131219,,,D*46
2019-12-13T21:07:57.937Z,1576271277.937 [NAL9602](INFO): GPS fix at 20191213T210757: (36.802363, -121.787146)
2019-12-13T21:07:57.974Z,1576271277.974 [Default:CheckIn:Read_GPS] Stopped
2019-12-13T21:07:57.974Z,1576271277.974 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-12-13T21:08:05.218Z,1576271285.218 [DataOverHttps](INFO): Sending 64 bytes from file Logs/20191213T191452/Courier0064.lzma
2019-12-13T21:08:07.224Z,1576271287.224 [DataOverHttps](INFO): Moved sent file to Logs/20191213T191452/Courier0064.lzma.bak
2019-12-13T21:08:07.224Z,1576271287.224 [DataOverHttps](INFO): SBD MOMSN=12156222
2019-12-13T21:08:23.942Z,1576271303.942 [DataOverHttps](INFO): Sending 121 bytes from file Logs/20191213T191452/Express0065.lzma
2019-12-13T21:08:25.948Z,1576271305.948 [DataOverHttps](INFO): Moved sent file to Logs/20191213T191452/Express0065.lzma.bak
2019-12-13T21:08:25.948Z,1576271305.948 [DataOverHttps](INFO): SBD MOMSN=12156225
2019-12-13T21:08:26.221Z,1576271306.221 [NAL9602](INFO): SBD MO Status=2, MOMSN=3662, MT Status=2, MTMSN=0
2019-12-13T21:08:26.221Z,1576271306.221 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-12-13T21:08:27.056Z,1576271307.056 [Default:CheckIn:Read_Iridium] Stopped
2019-12-13T21:08:27.056Z,1576271307.056 [Default:CheckIn:C.Wait] Running Loop=1
2019-12-13T21:08:27.056Z,1576271307.056 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-12-13T21:08:37.529Z,1576271317.529 [NAL9602](INFO): SBD MO Status=0, MOMSN=3662, MT Status=0, MTMSN=0
2019-12-13T21:08:37.529Z,1576271317.529 [NAL9602](INFO): No messages in MT queue
2019-12-13T21:09:08.235Z,1576271348.235 [NAL9602](INFO): Not Powering down - fast GPS
2019-12-13T21:13:27.638Z,1576271607.638 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-12-13T21:13:27.638Z,1576271607.638 [Default:CheckIn:C.Wait] Stopped
2019-12-13T21:13:27.639Z,1576271607.639 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-12-13T21:13:27.639Z,1576271607.639 [Default:CheckIn:D] Running Loop=1
2019-12-13T21:13:28.046Z,1576271608.046 [Default:CheckIn:D] Stopped
2019-12-13T21:13:28.046Z,1576271608.046 [Default:CheckIn:E] Running Loop=1
2019-12-13T21:13:28.456Z,1576271608.456 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 115.699227 min 
2019-12-13T21:13:28.456Z,1576271608.456 [Default:CheckIn:E] Stopped
2019-12-13T21:13:28.456Z,1576271608.456 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-12-13T21:13:28.456Z,1576271608.456 [Default:CheckIn] Stopped
2019-12-13T21:13:28.457Z,1576271608.457 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-12-13T21:13:28.457Z,1576271608.457 [Default:CheckIn](INFO): Running loop #21
2019-12-13T21:13:28.457Z,1576271608.457 [Default:CheckIn] Running Loop=21
2019-12-13T21:13:28.457Z,1576271608.457 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-12-13T21:13:28.457Z,1576271608.457 [Default:CheckIn:Read_GPS] Running Loop=1
2019-12-13T21:13:30.445Z,1576271610.445 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,211330.00,A,3648.14882,N,12147.22124,W,0.078,108.71,131219,,,D*7A
2019-12-13T21:13:30.448Z,1576271610.448 [NAL9602](INFO): GPS fix at 20191213T211330: (36.802480, -121.787021)
2019-12-13T21:13:30.496Z,1576271610.496 [Default:CheckIn:Read_GPS] Stopped
2019-12-13T21:13:30.496Z,1576271610.496 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-12-13T21:13:37.554Z,1576271617.554 [DataOverHttps](INFO): Sending 64 bytes from file Logs/20191213T191452/Courier0067.lzma
2019-12-13T21:13:39.560Z,1576271619.560 [DataOverHttps](INFO): Moved sent file to Logs/20191213T191452/Courier0067.lzma.bak
2019-12-13T21:13:39.560Z,1576271619.560 [DataOverHttps](INFO): SBD MOMSN=12156235
2019-12-13T21:13:45.793Z,1576271625.793 [NAL9602](INFO): SBD MO Status=0, MOMSN=3663, MT Status=0, MTMSN=0
2019-12-13T21:13:45.793Z,1576271625.793 [NAL9602](INFO): No messages in MT queue
2019-12-13T21:13:56.330Z,1576271636.330 [DataOverHttps](INFO): Sending 120 bytes from file Logs/20191213T191452/Express0068.lzma
2019-12-13T21:13:58.336Z,1576271638.336 [DataOverHttps](INFO): Moved sent file to Logs/20191213T191452/Express0068.lzma.bak
2019-12-13T21:13:58.336Z,1576271638.336 [DataOverHttps](INFO): SBD MOMSN=12156238
2019-12-13T21:13:59.561Z,1576271639.561 [Default:CheckIn:Read_Iridium] Stopped
2019-12-13T21:13:59.561Z,1576271639.561 [Default:CheckIn:C.Wait] Running Loop=1
2019-12-13T21:13:59.561Z,1576271639.561 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-12-13T21:14:16.495Z,1576271656.495 [NAL9602](INFO): Not Powering down - fast GPS
2019-12-13T21:19:00.146Z,1576271940.146 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-12-13T21:19:00.146Z,1576271940.146 [Default:CheckIn:C.Wait] Stopped
2019-12-13T21:19:00.146Z,1576271940.146 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-12-13T21:19:00.147Z,1576271940.147 [Default:CheckIn:D] Running Loop=1
2019-12-13T21:19:00.558Z,1576271940.558 [Default:CheckIn:D] Stopped
2019-12-13T21:19:00.558Z,1576271940.558 [Default:CheckIn:E] Running Loop=1
2019-12-13T21:19:00.962Z,1576271940.962 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 121.241097 min 
2019-12-13T21:19:00.962Z,1576271940.962 [Default:CheckIn:E] Stopped
2019-12-13T21:19:00.963Z,1576271940.963 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-12-13T21:19:00.963Z,1576271940.963 [Default:CheckIn] Stopped
2019-12-13T21:19:00.963Z,1576271940.963 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-12-13T21:19:00.963Z,1576271940.963 [Default:CheckIn](INFO): Running loop #22
2019-12-13T21:19:00.963Z,1576271940.963 [Default:CheckIn] Running Loop=22
2019-12-13T21:19:00.963Z,1576271940.963 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-12-13T21:19:00.963Z,1576271940.963 [Default:CheckIn:Read_GPS] Running Loop=1
2019-12-13T21:19:02.947Z,1576271942.947 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,211902.00,A,3648.15110,N,12147.21935,W,0.039,108.71,131219,,,D*7C
2019-12-13T21:19:02.949Z,1576271942.949 [NAL9602](INFO): GPS fix at 20191213T211902: (36.802518, -121.786989)
2019-12-13T21:19:02.972Z,1576271942.972 [Default:CheckIn:Read_GPS] Stopped
2019-12-13T21:19:02.972Z,1576271942.972 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-12-13T21:19:10.066Z,1576271950.066 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20191213T191452/Courier0070.lzma
2019-12-13T21:19:12.068Z,1576271952.068 [DataOverHttps](INFO): Moved sent file to Logs/20191213T191452/Courier0070.lzma.bak
2019-12-13T21:19:12.068Z,1576271952.068 [DataOverHttps](INFO): SBD MOMSN=12156259
2019-12-13T21:19:24.360Z,1576271964.360 [NAL9602](INFO): SBD MO Status=0, MOMSN=3664, MT Status=0, MTMSN=0
2019-12-13T21:19:24.360Z,1576271964.360 [NAL9602](INFO): No messages in MT queue
2019-12-13T21:19:28.850Z,1576271968.850 [DataOverHttps](INFO): Sending 119 bytes from file Logs/20191213T191452/Express0071.lzma
2019-12-13T21:19:30.856Z,1576271970.856 [DataOverHttps](INFO): Moved sent file to Logs/20191213T191452/Express0071.lzma.bak
2019-12-13T21:19:30.856Z,1576271970.856 [DataOverHttps](INFO): SBD MOMSN=12156262
2019-12-13T21:19:32.055Z,1576271972.055 [Default:CheckIn:Read_Iridium] Stopped
2019-12-13T21:19:32.055Z,1576271972.055 [Default:CheckIn:C.Wait] Running Loop=1
2019-12-13T21:19:32.055Z,1576271972.055 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-12-13T21:19:55.067Z,1576271995.067 [NAL9602](INFO): Not Powering down - fast GPS
2019-12-13T21:24:32.646Z,1576272272.646 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-12-13T21:24:32.647Z,1576272272.647 [Default:CheckIn:C.Wait] Stopped
2019-12-13T21:24:32.647Z,1576272272.647 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-12-13T21:24:32.647Z,1576272272.647 [Default:CheckIn:D] Running Loop=1
2019-12-13T21:24:33.052Z,1576272273.052 [Default:CheckIn:D] Stopped
2019-12-13T21:24:33.052Z,1576272273.052 [Default:CheckIn:E] Running Loop=1
2019-12-13T21:24:33.441Z,1576272273.441 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 126.782674 min 
2019-12-13T21:24:33.441Z,1576272273.441 [Default:CheckIn:E] Stopped
2019-12-13T21:24:33.441Z,1576272273.441 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-12-13T21:24:33.441Z,1576272273.441 [Default:CheckIn] Stopped
2019-12-13T21:24:33.441Z,1576272273.441 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-12-13T21:24:33.441Z,1576272273.441 [Default:CheckIn](INFO): Running loop #23
2019-12-13T21:24:33.441Z,1576272273.441 [Default:CheckIn] Running Loop=23
2019-12-13T21:24:33.442Z,1576272273.442 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-12-13T21:24:33.442Z,1576272273.442 [Default:CheckIn:Read_GPS] Running Loop=1
2019-12-13T21:24:35.445Z,1576272275.445 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,212435.00,A,3648.24292,N,12147.13931,W,5.015,13.87,131219,,,D*41
2019-12-13T21:24:35.456Z,1576272275.456 [NAL9602](INFO): GPS fix at 20191213T212435: (36.804049, -121.785655)
2019-12-13T21:24:35.479Z,1576272275.479 [Default:CheckIn:Read_GPS] Stopped
2019-12-13T21:24:35.479Z,1576272275.479 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-12-13T21:24:43.527Z,1576272283.527 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20191213T191452/Courier0073.lzma
2019-12-13T21:24:45.532Z,1576272285.532 [DataOverHttps](INFO): Moved sent file to Logs/20191213T191452/Courier0073.lzma.bak
2019-12-13T21:24:45.532Z,1576272285.532 [DataOverHttps](INFO): SBD MOMSN=12156272
2019-12-13T21:24:59.277Z,1576272299.277 [NAL9602](INFO): SBD MO Status=0, MOMSN=3665, MT Status=0, MTMSN=0
2019-12-13T21:24:59.277Z,1576272299.277 [NAL9602](INFO): No messages in MT queue
2019-12-13T21:25:02.246Z,1576272302.246 [DataOverHttps](INFO): Sending 120 bytes from file Logs/20191213T191452/Express0074.lzma
2019-12-13T21:25:04.252Z,1576272304.252 [DataOverHttps](INFO): Moved sent file to Logs/20191213T191452/Express0074.lzma.bak
2019-12-13T21:25:04.252Z,1576272304.252 [DataOverHttps](INFO): SBD MOMSN=12156275
2019-12-13T21:25:05.367Z,1576272305.367 [Default:CheckIn:Read_Iridium] Stopped
2019-12-13T21:25:05.367Z,1576272305.367 [Default:CheckIn:C.Wait] Running Loop=1
2019-12-13T21:25:05.367Z,1576272305.367 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-12-13T21:25:29.983Z,1576272329.983 [NAL9602](INFO): Not Powering down - fast GPS
2019-12-13T21:30:05.938Z,1576272605.938 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-12-13T21:30:05.938Z,1576272605.938 [Default:CheckIn:C.Wait] Stopped
2019-12-13T21:30:05.938Z,1576272605.938 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-12-13T21:30:05.939Z,1576272605.939 [Default:CheckIn:D] Running Loop=1
2019-12-13T21:30:06.347Z,1576272606.347 [Default:CheckIn:D] Stopped
2019-12-13T21:30:06.347Z,1576272606.347 [Default:CheckIn:E] Running Loop=1
2019-12-13T21:30:06.753Z,1576272606.753 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 132.337590 min 
2019-12-13T21:30:06.753Z,1576272606.753 [Default:CheckIn:E] Stopped
2019-12-13T21:30:06.753Z,1576272606.753 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-12-13T21:30:06.753Z,1576272606.753 [Default:CheckIn] Stopped
2019-12-13T21:30:06.753Z,1576272606.753 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-12-13T21:30:06.754Z,1576272606.754 [Default:CheckIn](INFO): Running loop #24
2019-12-13T21:30:06.754Z,1576272606.754 [Default:CheckIn] Running Loop=24
2019-12-13T21:30:06.754Z,1576272606.754 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-12-13T21:30:06.754Z,1576272606.754 [Default:CheckIn:Read_GPS] Running Loop=1
2019-12-13T21:30:08.739Z,1576272608.739 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,213008.00,A,3648.17375,N,12147.81618,W,22.121,235.68,131219,,,D*49
2019-12-13T21:30:08.741Z,1576272608.741 [NAL9602](INFO): GPS fix at 20191213T213008: (36.802896, -121.796936)
2019-12-13T21:30:08.764Z,1576272608.764 [Default:CheckIn:Read_GPS] Stopped
2019-12-13T21:30:08.764Z,1576272608.764 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-12-13T21:30:16.646Z,1576272616.646 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20191213T191452/Courier0076.lzma
2019-12-13T21:30:18.652Z,1576272618.652 [DataOverHttps](INFO): Moved sent file to Logs/20191213T191452/Courier0076.lzma.bak
2019-12-13T21:30:18.652Z,1576272618.652 [DataOverHttps](INFO): SBD MOMSN=12156296
2019-12-13T21:30:30.153Z,1576272630.153 [NAL9602](INFO): SBD MO Status=0, MOMSN=3666, MT Status=0, MTMSN=0
2019-12-13T21:30:30.153Z,1576272630.153 [NAL9602](INFO): No messages in MT queue
2019-12-13T21:30:35.402Z,1576272635.402 [DataOverHttps](INFO): Sending 132 bytes from file Logs/20191213T191452/Express0077.lzma
2019-12-13T21:30:37.408Z,1576272637.408 [DataOverHttps](INFO): Moved sent file to Logs/20191213T191452/Express0077.lzma.bak
2019-12-13T21:30:37.408Z,1576272637.408 [DataOverHttps](INFO): SBD MOMSN=12156300
2019-12-13T21:30:38.661Z,1576272638.661 [Default:CheckIn:Read_Iridium] Stopped
2019-12-13T21:30:38.661Z,1576272638.661 [Default:CheckIn:C.Wait] Running Loop=1
2019-12-13T21:30:38.661Z,1576272638.661 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-12-13T21:31:00.863Z,1576272660.863 [NAL9602](INFO): Not Powering down - fast GPS
2019-12-13T21:32:33.263Z,1576272753.263 [DataOverHttps](IMPORTANT): SBD MTMSN=20191213T213232
2019-12-13T21:32:43.638Z,1576272763.638 [DataOverHttps](INFO): Received command:Ibit
2019-12-13T21:32:43.683Z,1576272763.683 [CommandLine](IMPORTANT): got command ibit
2019-12-13T21:32:43.939Z,1576272763.939 [IBIT](IMPORTANT): Beginning Initiated BIT
2019-12-13T21:32:43.939Z,1576272763.939 [IBIT](IMPORTANT): Beginning control surface checks.
2019-12-13T21:32:43.942Z,1576272763.942 [CBIT](IMPORTANT): Beginning ground fault scan
2019-12-13T21:32:45.517Z,1576272765.517 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,213245.00,A,3647.66523,N,12148.89185,W,22.374,241.78,131219,,,D*4A
2019-12-13T21:32:45.520Z,1576272765.520 [NAL9602](INFO): GPS fix at 20191213T213245: (36.794421, -121.814864)
2019-12-13T21:32:54.850Z,1576272774.850 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.016757
CHAN A1 (24V): -0.217667
CHAN A2 (12V): 0.020841
CHAN A3 (5V): -0.010989
CHAN B0 (3.3V): -0.007084
CHAN B1 (3.15aV): -0.003860
CHAN B2 (3.15bV): -0.002541
CHAN B3 (GND): -0.013157
OPEN: 0.005530
Full Scale Calc: 4.765 mA, -1.589 mA
2019-12-13T21:33:03.287Z,1576272783.287 [NAL9602](INFO): SBD MO Status=0, MOMSN=3667, MT Status=0, MTMSN=0
2019-12-13T21:33:03.287Z,1576272783.287 [NAL9602](INFO): No messages in MT queue
2019-12-13T21:33:04.499Z,1576272784.499 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,213304.00,A,3647.60832,N,12149.02377,W,22.743,242.87,131219,,,D*4B
2019-12-13T21:33:04.501Z,1576272784.501 [NAL9602](INFO): GPS fix at 20191213T213304: (36.793472, -121.817063)
2019-12-13T21:33:07.329Z,1576272787.329 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,213307.00,A,3647.59964,N,12149.04558,W,24.240,245.03,131219,,,D*46
2019-12-13T21:33:07.331Z,1576272787.331 [NAL9602](INFO): GPS fix at 20191213T213307: (36.793327, -121.817426)
2019-12-13T21:33:10.161Z,1576272790.161 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,213310.00,A,3647.59115,N,12149.06767,W,23.093,243.20,131219,,,D*4E
2019-12-13T21:33:10.163Z,1576272790.163 [NAL9602](INFO): GPS fix at 20191213T213310: (36.793186, -121.817795)
2019-12-13T21:33:13.390Z,1576272793.390 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,213313.00,A,3647.58235,N,12149.08934,W,24.065,243.34,131219,,,D*40
2019-12-13T21:33:13.404Z,1576272793.404 [NAL9602](INFO): GPS fix at 20191213T213313: (36.793039, -121.818156)
2019-12-13T21:33:16.216Z,1576272796.216 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,213316.00,A,3647.57452,N,12149.11167,W,22.801,246.46,131219,,,D*47
2019-12-13T21:33:16.218Z,1576272796.218 [NAL9602](INFO): GPS fix at 20191213T213316: (36.792909, -121.818528)
2019-12-13T21:33:19.449Z,1576272799.449 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,213319.00,A,3647.56669,N,12149.13421,W,23.579,246.97,131219,,,D*49
2019-12-13T21:33:19.451Z,1576272799.451 [NAL9602](INFO): GPS fix at 20191213T213319: (36.792778, -121.818904)
2019-12-13T21:33:22.281Z,1576272802.281 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,213322.00,A,3647.55856,N,12149.15640,W,23.209,243.28,131219,,,D*42
2019-12-13T21:33:22.283Z,1576272802.283 [NAL9602](INFO): GPS fix at 20191213T213322: (36.792643, -121.819273)
2019-12-13T21:33:25.511Z,1576272805.511 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,213325.00,A,3647.54924,N,12149.17773,W,23.754,240.94,131219,,,D*4A
2019-12-13T21:33:25.513Z,1576272805.513 [NAL9602](INFO): GPS fix at 20191213T213325: (36.792487, -121.819629)
2019-12-13T21:33:28.336Z,1576272808.336 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,213328.00,A,3647.53915,N,12149.19921,W,23.773,238.47,131219,,,D*41
2019-12-13T21:33:28.339Z,1576272808.339 [NAL9602](INFO): GPS fix at 20191213T213328: (36.792319, -121.819987)
2019-12-13T21:33:30.395Z,1576272810.395 [IBIT](IMPORTANT): Communications Status:
Fix Status: 1
Iridium Signal Strength: 5
Latitude: 36.792320 Longitude: -121.819984
2019-12-13T21:33:30.816Z,1576272810.816 [IBIT](IMPORTANT): Battery Status:
Battery Charge (AH): 0.000000
Voltage: 0.000000
2019-12-13T21:33:30.816Z,1576272810.816 [IBIT](IMPORTANT): batteryCapacityThreshold: 50.000000 Ah
2019-12-13T21:33:30.816Z,1576272810.816 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.700000 V
2019-12-13T21:33:31.173Z,1576272811.173 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,213331.00,A,3647.52851,N,12149.21978,W,23.618,236.99,131219,,,D*4F
2019-12-13T21:33:31.175Z,1576272811.175 [NAL9602](INFO): GPS fix at 20191213T213331: (36.792142, -121.820330)
2019-12-13T21:33:31.204Z,1576272811.204 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 %
2019-12-13T21:33:31.204Z,1576272811.204 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi
2019-12-13T21:33:31.204Z,1576272811.204 [IBIT](IMPORTANT): Pressure:8.194259 PSI
2019-12-13T21:33:31.205Z,1576272811.205 [IBIT](IMPORTANT): Humidity:12.507631 %
2019-12-13T21:33:31.615Z,1576272811.615 [IBIT](IMPORTANT): Vehicle Pitch:9.559574 degrees
2019-12-13T21:33:31.616Z,1576272811.616 [IBIT](IMPORTANT): Vehicle  Roll:5.241243 degrees
2019-12-13T21:33:31.616Z,1576272811.616 [IBIT](IMPORTANT): Vehicle  Heading:244.229431 degrees
2019-12-13T21:33:32.014Z,1576272812.014 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m
2019-12-13T21:33:32.015Z,1576272812.015 [IBIT](IMPORTANT): buoyancyNeutral: 168.000000 cc
2019-12-13T21:33:32.015Z,1576272812.015 [IBIT](IMPORTANT): massDefault: 0.370000 cm
2019-12-13T21:33:32.015Z,1576272812.015 [IBIT](IMPORTANT): stopDepth: 50.000000 m
2019-12-13T21:33:32.016Z,1576272812.016 [IBIT](IMPORTANT): abortDepth: 60.000000 m
2019-12-13T21:33:32.016Z,1576272812.016 [IBIT](IMPORTANT): IBIT PASSED
2019-12-13T21:34:03.891Z,1576272843.891 [NAL9602](INFO): Not Powering down - fast GPS
2019-12-13T21:35:39.270Z,1576272939.270 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-12-13T21:35:39.270Z,1576272939.270 [Default:CheckIn:C.Wait] Stopped
2019-12-13T21:35:39.270Z,1576272939.270 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-12-13T21:35:39.270Z,1576272939.270 [Default:CheckIn:D] Running Loop=1
2019-12-13T21:35:39.676Z,1576272939.676 [Default:CheckIn:D] Stopped
2019-12-13T21:35:39.676Z,1576272939.676 [Default:CheckIn:E] Running Loop=1
2019-12-13T21:35:40.088Z,1576272940.088 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 137.893066 min 
2019-12-13T21:35:40.089Z,1576272940.089 [Default:CheckIn:E] Stopped
2019-12-13T21:35:40.089Z,1576272940.089 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-12-13T21:35:40.089Z,1576272940.089 [Default:CheckIn] Stopped
2019-12-13T21:35:40.089Z,1576272940.089 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-12-13T21:35:40.089Z,1576272940.089 [Default:CheckIn](INFO): Running loop #25
2019-12-13T21:35:40.089Z,1576272940.089 [Default:CheckIn] Running Loop=25
2019-12-13T21:35:40.089Z,1576272940.089 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-12-13T21:35:40.089Z,1576272940.089 [Default:CheckIn:Read_GPS] Running Loop=1
2019-12-13T21:35:42.069Z,1576272942.069 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,213542.00,A,3647.11757,N,12150.15230,W,23.559,246.63,131219,,,D*4F
2019-12-13T21:35:42.071Z,1576272942.071 [NAL9602](INFO): GPS fix at 20191213T213542: (36.785293, -121.835872)
2019-12-13T21:35:42.095Z,1576272942.095 [Default:CheckIn:Read_GPS] Stopped
2019-12-13T21:35:42.095Z,1576272942.095 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-12-13T21:35:48.086Z,1576272948.086 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20191213T191452/Courier0079.lzma
2019-12-13T21:35:50.092Z,1576272950.092 [DataOverHttps](INFO): Moved sent file to Logs/20191213T191452/Courier0079.lzma.bak
2019-12-13T21:35:50.093Z,1576272950.093 [DataOverHttps](INFO): SBD MOMSN=12156311
2019-12-13T21:36:05.501Z,1576272965.501 [NAL9602](INFO): SBD MO Status=2, MOMSN=3668, MT Status=2, MTMSN=0
2019-12-13T21:36:05.501Z,1576272965.501 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-12-13T21:36:06.915Z,1576272966.915 [DataOverHttps](INFO): Sending 818 bytes from file Logs/20191213T191452/Express0080.lzma
2019-12-13T21:36:08.920Z,1576272968.920 [DataOverHttps](INFO): Moved sent file to Logs/20191213T191452/Express0080.lzma.bak
2019-12-13T21:36:08.920Z,1576272968.920 [DataOverHttps](INFO): SBD MOMSN=12156314
2019-12-13T21:36:23.681Z,1576272983.681 [NAL9602](INFO): SBD MO Status=2, MOMSN=3668, MT Status=2, MTMSN=0
2019-12-13T21:36:23.681Z,1576272983.681 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-12-13T21:36:26.678Z,1576272986.678 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20191213T191452/Express0083.lzma
2019-12-13T21:36:28.684Z,1576272988.684 [DataOverHttps](INFO): Moved sent file to Logs/20191213T191452/Express0083.lzma.bak
2019-12-13T21:36:28.684Z,1576272988.684 [DataOverHttps](INFO): SBD MOMSN=12156343
2019-12-13T21:36:29.774Z,1576272989.774 [Default:CheckIn:Read_Iridium] Stopped
2019-12-13T21:36:29.774Z,1576272989.774 [Default:CheckIn:C.Wait] Running Loop=1
2019-12-13T21:36:29.774Z,1576272989.774 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-12-13T21:36:42.269Z,1576273002.269 [NAL9602](INFO): SBD MO Status=2, MOMSN=3668, MT Status=2, MTMSN=0
2019-12-13T21:36:42.269Z,1576273002.269 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-12-13T21:36:58.828Z,1576273018.828 [NAL9602](INFO): SBD MO Status=2, MOMSN=3668, MT Status=2, MTMSN=0
2019-12-13T21:36:58.829Z,1576273018.829 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-12-13T21:37:17.417Z,1576273037.417 [NAL9602](INFO): SBD MO Status=2, MOMSN=3668, MT Status=2, MTMSN=0
2019-12-13T21:37:17.417Z,1576273037.417 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-12-13T21:37:35.187Z,1576273055.187 [NAL9602](INFO): SBD MO Status=2, MOMSN=3668, MT Status=2, MTMSN=0
2019-12-13T21:37:35.187Z,1576273055.187 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-12-13T21:37:52.155Z,1576273072.155 [NAL9602](INFO): SBD MO Status=2, MOMSN=3668, MT Status=2, MTMSN=0
2019-12-13T21:37:52.155Z,1576273072.155 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-12-13T21:38:11.475Z,1576273091.475 [DataOverHttps](INFO): Exceeded connection timeout, disconnecting.
2019-12-13T21:38:14.487Z,1576273094.487 [DataOverHttps](INFO): setting unavailable, lastComms_.elapsed()=60.607567
2019-12-13T21:38:24.881Z,1576273104.881 [NAL9602](INFO): SBD MO Status=0, MOMSN=3668, MT Status=0, MTMSN=0
2019-12-13T21:38:24.881Z,1576273104.881 [NAL9602](INFO): No messages in MT queue
2019-12-13T21:38:55.591Z,1576273135.591 [NAL9602](INFO): Not Powering down - fast GPS
2019-12-13T21:39:13.338Z,1576273153.338 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.003247
2019-12-13T21:41:30.377Z,1576273290.377 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2019-12-13T21:41:30.377Z,1576273290.377 [Default:CheckIn:C.Wait] Stopped
2019-12-13T21:41:30.377Z,1576273290.377 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-12-13T21:41:30.377Z,1576273290.377 [Default:CheckIn:D] Running Loop=1
2019-12-13T21:41:30.752Z,1576273290.752 [Default:CheckIn:D] Stopped
2019-12-13T21:41:30.752Z,1576273290.752 [Default:CheckIn:E] Running Loop=1
2019-12-13T21:41:31.157Z,1576273291.157 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 143.744320 min 
2019-12-13T21:41:31.157Z,1576273291.157 [Default:CheckIn:E] Stopped
2019-12-13T21:41:31.157Z,1576273291.157 [Default:CheckIn](INFO): Completed Default:CheckIn
2019-12-13T21:41:31.157Z,1576273291.157 [Default:CheckIn] Stopped
2019-12-13T21:41:31.158Z,1576273291.158 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-12-13T21:41:31.158Z,1576273291.158 [Default:CheckIn](INFO): Running loop #26
2019-12-13T21:41:31.158Z,1576273291.158 [Default:CheckIn] Running Loop=26
2019-12-13T21:41:31.158Z,1576273291.158 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-12-13T21:41:31.158Z,1576273291.158 [Default:CheckIn:Read_GPS] Running Loop=1
2019-12-13T21:41:33.149Z,1576273293.149 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,214133.00,A,3646.67172,N,12151.32705,W,2.449,161.34,131219,,,A*7E
2019-12-13T21:41:33.151Z,1576273293.151 [NAL9602](INFO): GPS fix at 20191213T214133: (36.777862, -121.855451)
2019-12-13T21:41:33.200Z,1576273293.200 [Default:CheckIn:Read_GPS] Stopped
2019-12-13T21:41:33.200Z,1576273293.200 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-12-13T21:41:41.182Z,1576273301.182 [DataOverHttps](INFO): Sending 63 bytes from file Logs/20191213T191452/Courier0085.lzma
2019-12-13T21:41:43.188Z,1576273303.188 [DataOverHttps](INFO): Moved sent file to Logs/20191213T191452/Courier0085.lzma.bak
2019-12-13T21:41:43.188Z,1576273303.188 [DataOverHttps](INFO): SBD MOMSN=12156347
2019-12-13T21:41:59.413Z,1576273319.413 [NAL9602](INFO): SBD MO Status=0, MOMSN=3669, MT Status=0, MTMSN=0
2019-12-13T21:41:59.413Z,1576273319.413 [NAL9602](INFO): No messages in MT queue
2019-12-13T21:42:00.246Z,1576273320.246 [DataOverHttps](INFO): Sending 137 bytes from file Logs/20191213T191452/Express0086.lzma
2019-12-13T21:42:02.252Z,1576273322.252 [DataOverHttps](INFO): Moved sent file to Logs/20191213T191452/Express0086.lzma.bak
2019-12-13T21:42:02.252Z,1576273322.252 [DataOverHttps](INFO): SBD MOMSN=12156350
2019-12-13T21:42:03.475Z,1576273323.475 [Default:CheckIn:Read_Iridium] Stopped
2019-12-13T21:42:03.475Z,1576273323.475 [Default:CheckIn:C.Wait] Running Loop=1
2019-12-13T21:42:03.475Z,1576273323.475 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-12-13T21:42:30.115Z,1576273350.115 [NAL9602](INFO): Not Powering down - fast GPS
2019-12-13T21:43:16.596Z,1576273396.596 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2019-12-13T21:43:31.951Z,1576273411.951 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2019-12-13T21:43:47.292Z,1576273427.292 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2019-12-13T21:44:03.050Z,1576273443.050 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2019-12-13T21:44:18.408Z,1576273458.408 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2019-12-13T21:44:33.349Z,1576273473.349 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2019-12-13T21:44:49.106Z,1576273489.106 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2019-12-13T21:45:04.175Z,1576273504.175 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2019-12-13T21:45:19.814Z,1576273519.814 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2019-12-13T21:45:35.574Z,1576273535.574 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2019-12-13T21:45:44.464Z,1576273544.464 [BPC1](INFO): Calculating totals. Valid battery stick count: 55. Valid reserve battery stick count: 5.
2019-12-13T21:45:44.467Z,1576273544.467 [BPC1](INFO): Received data from all battery sticks.
2019-12-13T21:46:55.871Z,1576273615.871 [DataOverHttps](IMPORTANT): SBD MTMSN=20191213T214654
2019-12-13T21:47:03.342Z,1576273623.342 [DataOverHttps](INFO): Received command:restart logs