2020-06-10T17:19:11.101Z,1591809551.101 [Supervisor](DEBUG): Initializing supervisor.
2020-06-10T17:19:11.104Z,1591809551.104 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2020-06-10T17:19:11.104Z,1591809551.104 [SyncHandler](INFO): Protected caller Thread ID is 806
2020-06-10T17:19:11.105Z,1591809551.105 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2020-06-10T17:19:11.106Z,1591809551.106 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2020-06-10T17:19:11.106Z,1591809551.106 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 807
2020-06-10T17:19:11.109Z,1591809551.109 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2020-06-10T17:19:11.122Z,1591809551.122 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2020-06-10T17:19:11.123Z,1591809551.123 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2020-06-10T17:19:11.123Z,1591809551.123 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 808
2020-06-10T17:19:11.124Z,1591809551.124 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2020-06-10T17:19:11.125Z,1591809551.125 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2020-06-10T17:19:11.125Z,1591809551.125 [logger ThreadHandler](INFO): Protected caller Thread ID is 809
2020-06-10T17:19:11.127Z,1591809551.127 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2020-06-10T17:19:11.127Z,1591809551.127 [Supervisor](INFO): Looking for Config files in directory: Config/
2020-06-10T17:19:11.131Z,1591809551.131 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2020-06-10T17:19:11.341Z,1591809551.341 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2020-06-10T17:19:11.343Z,1591809551.343 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2020-06-10T17:19:11.424Z,1591809551.424 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2020-06-10T17:19:11.867Z,1591809551.867 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2020-06-10T17:19:11.869Z,1591809551.869 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2020-06-10T17:19:12.182Z,1591809552.182 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2020-06-10T17:19:12.184Z,1591809552.184 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2020-06-10T17:19:12.279Z,1591809552.279 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2020-06-10T17:19:12.281Z,1591809552.281 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2020-06-10T17:19:12.585Z,1591809552.585 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2020-06-10T17:19:12.587Z,1591809552.587 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2020-06-10T17:19:12.777Z,1591809552.777 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2020-06-10T17:19:12.779Z,1591809552.779 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2020-06-10T17:19:13.251Z,1591809553.251 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2020-06-10T17:19:13.253Z,1591809553.253 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2020-06-10T17:19:13.355Z,1591809553.355 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2020-06-10T17:19:13.357Z,1591809553.357 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2020-06-10T17:19:13.458Z,1591809553.458 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2020-06-10T17:19:13.460Z,1591809553.460 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2020-06-10T17:19:14.867Z,1591809554.867 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2020-06-10T17:19:14.868Z,1591809554.868 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2020-06-10T17:19:15.290Z,1591809555.290 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2020-06-10T17:19:15.291Z,1591809555.291 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2020-06-10T17:19:15.480Z,1591809555.480 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2020-06-10T17:19:15.480Z,1591809555.480 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2020-06-10T17:19:15.627Z,1591809555.627 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2020-06-10T17:19:15.628Z,1591809555.628 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2020-06-10T17:19:15.774Z,1591809555.774 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2020-06-10T17:19:15.774Z,1591809555.774 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2020-06-10T17:19:15.993Z,1591809555.993 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2020-06-10T17:19:15.995Z,1591809555.995 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2020-06-10T17:19:15.998Z,1591809555.998 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg
2020-06-10T17:19:16.088Z,1591809556.088 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2020-06-10T17:19:16.217Z,1591809556.217 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2020-06-10T17:19:16.317Z,1591809556.317 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg
2020-06-10T17:19:16.399Z,1591809556.399 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2020-06-10T17:19:16.493Z,1591809556.493 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2020-06-10T17:19:16.592Z,1591809556.592 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2020-06-10T17:19:16.796Z,1591809556.796 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/workSite.cfg
2020-06-10T17:19:16.872Z,1591809556.872 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2020-06-10T17:19:17.037Z,1591809557.037 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2020-06-10T17:19:17.184Z,1591809557.184 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2020-06-10T17:19:17.340Z,1591809557.340 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Battery.cfg
2020-06-10T17:19:17.596Z,1591809557.596 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2020-06-10T17:19:17.596Z,1591809557.596 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2020-06-10T17:19:17.606Z,1591809557.606 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2020-06-10T17:19:17.674Z,1591809557.674 [VerticalControl](DEBUG): Construct VerticalControl.
2020-06-10T17:19:17.786Z,1591809557.786 [VerticalControl] Loaded
2020-06-10T17:19:17.787Z,1591809557.787 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2020-06-10T17:19:17.787Z,1591809557.787 [HorizontalControl](DEBUG): Construct HorizontalControl.
2020-06-10T17:19:17.868Z,1591809557.868 [HorizontalControl] Loaded
2020-06-10T17:19:17.868Z,1591809557.868 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2020-06-10T17:19:17.869Z,1591809557.869 [SpeedControl](DEBUG): Construct SpeedControl.
2020-06-10T17:19:17.875Z,1591809557.875 [SpeedControl] Loaded
2020-06-10T17:19:17.875Z,1591809557.875 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2020-06-10T17:19:17.876Z,1591809557.876 [LoopControl](DEBUG): Construct LoopControl.
2020-06-10T17:19:17.876Z,1591809557.876 [LoopControl] Loaded
2020-06-10T17:19:17.876Z,1591809557.876 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2020-06-10T17:19:17.877Z,1591809557.877 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2020-06-10T17:19:17.878Z,1591809557.878 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2020-06-10T17:19:17.908Z,1591809557.908 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2020-06-10T17:19:17.910Z,1591809557.910 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2020-06-10T17:19:18.037Z,1591809558.037 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2020-06-10T17:19:18.038Z,1591809558.038 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2020-06-10T17:19:18.191Z,1591809558.191 [BuoyancyServo] Loaded
2020-06-10T17:19:18.191Z,1591809558.191 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2020-06-10T17:19:18.202Z,1591809558.202 [ElevatorServo] Loaded
2020-06-10T17:19:18.203Z,1591809558.203 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2020-06-10T17:19:18.213Z,1591809558.213 [MassServo] Loaded
2020-06-10T17:19:18.214Z,1591809558.214 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2020-06-10T17:19:18.225Z,1591809558.225 [RudderServo] Loaded
2020-06-10T17:19:18.225Z,1591809558.225 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2020-06-10T17:19:18.236Z,1591809558.236 [ThrusterServo] Loaded
2020-06-10T17:19:18.236Z,1591809558.236 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2020-06-10T17:19:18.237Z,1591809558.237 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2020-06-10T17:19:18.237Z,1591809558.237 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2020-06-10T17:19:18.360Z,1591809558.360 [DeadReckonUsingMultipleVelocitySources] Loaded
2020-06-10T17:19:18.360Z,1591809558.360 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2020-06-10T17:19:18.381Z,1591809558.381 [NavChart] Loaded
2020-06-10T17:19:18.381Z,1591809558.381 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2020-06-10T17:19:18.385Z,1591809558.385 [UniversalFixResidualReporter] Loaded
2020-06-10T17:19:18.386Z,1591809558.386 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2020-06-10T17:19:18.386Z,1591809558.386 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2020-06-10T17:19:18.388Z,1591809558.388 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2020-06-10T17:19:18.513Z,1591809558.513 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2020-06-10T17:19:18.514Z,1591809558.514 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2020-06-10T17:19:19.035Z,1591809559.035 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_orientation
2020-06-10T17:19:19.040Z,1591809559.040 [AHRS_M2](INFO): created writer for : platform_orientation
2020-06-10T17:19:19.042Z,1591809559.042 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_magnetic_orientation
2020-06-10T17:19:19.047Z,1591809559.047 [AHRS_M2](INFO): created writer for : platform_magnetic_orientation
2020-06-10T17:19:19.048Z,1591809559.048 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_pitch_angle
2020-06-10T17:19:19.053Z,1591809559.053 [AHRS_M2](INFO): created writer for : platform_pitch_angle
2020-06-10T17:19:19.053Z,1591809559.053 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_roll_angle
2020-06-10T17:19:19.059Z,1591809559.059 [AHRS_M2](INFO): created writer for : platform_roll_angle
2020-06-10T17:19:19.237Z,1591809559.237 [AHRS_M2] Loaded
2020-06-10T17:19:19.237Z,1591809559.237 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2020-06-10T17:19:19.394Z,1591809559.394 [DataOverHttps] Loaded
2020-06-10T17:19:19.394Z,1591809559.394 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2020-06-10T17:19:19.396Z,1591809559.396 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 408924E0
2020-06-10T17:19:19.396Z,1591809559.396 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 896
2020-06-10T17:19:19.410Z,1591809559.410 [Depth_Keller] Loaded
2020-06-10T17:19:19.410Z,1591809559.410 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2020-06-10T17:19:19.415Z,1591809559.415 [DropWeight] Loaded
2020-06-10T17:19:19.415Z,1591809559.415 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2020-06-10T17:19:19.514Z,1591809559.514 [NAL9602] Loaded
2020-06-10T17:19:19.514Z,1591809559.514 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2020-06-10T17:19:19.561Z,1591809559.561 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-0/voltage_now
2020-06-10T17:19:19.561Z,1591809559.561 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-0/current_now
2020-06-10T17:19:19.562Z,1591809559.562 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-0/charge_now
2020-06-10T17:19:19.562Z,1591809559.562 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-0/charge_full
2020-06-10T17:19:19.563Z,1591809559.563 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-1/voltage_now
2020-06-10T17:19:19.564Z,1591809559.564 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-1/current_now
2020-06-10T17:19:19.564Z,1591809559.564 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-1/charge_now
2020-06-10T17:19:19.565Z,1591809559.565 [Onboard](ERROR): Can't open SysFS node file: /sys/class/power_supply/ds2782-1/charge_full
2020-06-10T17:19:19.565Z,1591809559.565 [Onboard] Loaded
2020-06-10T17:19:19.565Z,1591809559.565 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2020-06-10T17:19:19.566Z,1591809559.566 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 408C24E0
2020-06-10T17:19:19.567Z,1591809559.566 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 897
2020-06-10T17:19:19.570Z,1591809559.570 [Radio_Surface] Loaded
2020-06-10T17:19:19.570Z,1591809559.570 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2020-06-10T17:19:19.571Z,1591809559.571 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 408F24E0
2020-06-10T17:19:19.572Z,1591809559.572 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 898
2020-06-10T17:19:19.708Z,1591809559.708 [DAT] Loaded
2020-06-10T17:19:19.708Z,1591809559.708 [ComponentRegistry](DEBUG): SyncComponent "DAT" handled in the control thread.
2020-06-10T17:19:21.759Z,1591809561.759 [BPC1] Loaded
2020-06-10T17:19:21.759Z,1591809561.759 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2020-06-10T17:19:21.760Z,1591809561.760 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2020-06-10T17:19:21.760Z,1591809561.760 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2020-06-10T17:19:21.815Z,1591809561.815 [DepthRateCalculator] Loaded
2020-06-10T17:19:21.816Z,1591809561.816 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2020-06-10T17:19:21.821Z,1591809561.821 [PitchRateCalculator] Loaded
2020-06-10T17:19:21.821Z,1591809561.821 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2020-06-10T17:19:21.833Z,1591809561.833 [SpeedCalculator] Loaded
2020-06-10T17:19:21.833Z,1591809561.833 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2020-06-10T17:19:21.854Z,1591809561.854 [TempGradientCalculator] Loaded
2020-06-10T17:19:21.855Z,1591809561.855 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2020-06-10T17:19:21.860Z,1591809561.860 [YawRateCalculator] Loaded
2020-06-10T17:19:21.860Z,1591809561.860 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2020-06-10T17:19:21.890Z,1591809561.890 [ElevatorOffsetCalculator] Loaded
2020-06-10T17:19:21.891Z,1591809561.891 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2020-06-10T17:19:21.891Z,1591809561.891 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2020-06-10T17:19:21.892Z,1591809561.892 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2020-06-10T17:19:22.168Z,1591809562.168 [CANONSampler] Loaded
2020-06-10T17:19:22.169Z,1591809562.169 [ComponentRegistry](DEBUG): SyncComponent "CANONSampler" handled in the control thread.
2020-06-10T17:19:22.178Z,1591809562.178 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_density
2020-06-10T17:19:22.183Z,1591809562.183 [CTD_Seabird](INFO): created writer for : sea_water_density
2020-06-10T17:19:22.184Z,1591809562.184 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): depth
2020-06-10T17:19:22.189Z,1591809562.189 [CTD_Seabird](INFO): created writer for : depth
2020-06-10T17:19:22.189Z,1591809562.189 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_pressure
2020-06-10T17:19:22.194Z,1591809562.194 [CTD_Seabird](INFO): created writer for : sea_water_pressure
2020-06-10T17:19:22.195Z,1591809562.195 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_salinity
2020-06-10T17:19:22.200Z,1591809562.200 [CTD_Seabird](INFO): created writer for : sea_water_salinity
2020-06-10T17:19:22.201Z,1591809562.201 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_temperature
2020-06-10T17:19:22.206Z,1591809562.206 [CTD_Seabird](INFO): created writer for : sea_water_temperature
2020-06-10T17:19:22.207Z,1591809562.207 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_electrical_conductivity
2020-06-10T17:19:22.212Z,1591809562.212 [CTD_Seabird](INFO): created writer for : sea_water_electrical_conductivity
2020-06-10T17:19:22.213Z,1591809562.213 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): speed_of_sound_in_sea_water
2020-06-10T17:19:22.218Z,1591809562.218 [CTD_Seabird](INFO): created writer for : speed_of_sound_in_sea_water
2020-06-10T17:19:22.218Z,1591809562.218 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): mass_concentration_of_oxygen_in_sea_water
2020-06-10T17:19:22.224Z,1591809562.224 [CTD_Seabird](INFO): created writer for : mass_concentration_of_oxygen_in_sea_water
2020-06-10T17:19:22.224Z,1591809562.224 [CTD_Seabird](DEBUG): LcmSlateWriter::add(DAtaURI): CTD_Seabird.sea_water_dissolved_oxygen_freq
2020-06-10T17:19:22.225Z,1591809562.225 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): dataName: sea_water_dissolved_oxygen_freq
2020-06-10T17:19:22.258Z,1591809562.258 [CTD_Seabird] Loaded
2020-06-10T17:19:22.258Z,1591809562.258 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2020-06-10T17:19:22.259Z,1591809562.259 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 409FE4E0
2020-06-10T17:19:22.260Z,1591809562.260 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 899
2020-06-10T17:19:22.276Z,1591809562.276 [PAR_Licor] Loaded
2020-06-10T17:19:22.276Z,1591809562.276 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2020-06-10T17:19:22.282Z,1591809562.282 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.Output470
2020-06-10T17:19:22.282Z,1591809562.282 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: Output470
2020-06-10T17:19:22.287Z,1591809562.287 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.Output650
2020-06-10T17:19:22.287Z,1591809562.287 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: Output650
2020-06-10T17:19:22.291Z,1591809562.291 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.OutputChl
2020-06-10T17:19:22.291Z,1591809562.291 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: OutputChl
2020-06-10T17:19:22.296Z,1591809562.296 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.VolumeScatCoeff117deg470nm
2020-06-10T17:19:22.296Z,1591809562.296 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: VolumeScatCoeff117deg470nm
2020-06-10T17:19:22.300Z,1591809562.300 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.VolumeScatCoeff117deg650nm
2020-06-10T17:19:22.300Z,1591809562.300 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: VolumeScatCoeff117deg650nm
2020-06-10T17:19:22.305Z,1591809562.305 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.BackscatteringCoeff470nm
2020-06-10T17:19:22.305Z,1591809562.305 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: BackscatteringCoeff470nm
2020-06-10T17:19:22.310Z,1591809562.310 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.BackscatteringCoeff650nm
2020-06-10T17:19:22.310Z,1591809562.310 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: BackscatteringCoeff650nm
2020-06-10T17:19:22.314Z,1591809562.314 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): mass_concentration_of_chlorophyll_in_sea_water
2020-06-10T17:19:22.319Z,1591809562.319 [WetLabsBB2FL](INFO): created writer for : mass_concentration_of_chlorophyll_in_sea_water
2020-06-10T17:19:22.319Z,1591809562.319 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_median_mass_concentration_of_chlorophyll_in_sea_water
2020-06-10T17:19:22.319Z,1591809562.319 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_median_mass_concentration_of_chlorophyll_in_sea_water
2020-06-10T17:19:22.324Z,1591809562.324 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_mean_mass_concentration_of_chlorophyll_in_sea_water
2020-06-10T17:19:22.324Z,1591809562.324 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_mean_mass_concentration_of_chlorophyll_in_sea_water
2020-06-10T17:19:22.328Z,1591809562.328 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_variance_mass_concentration_of_chlorophyll_in_sea_water
2020-06-10T17:19:22.328Z,1591809562.328 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_variance_mass_concentration_of_chlorophyll_in_sea_water
2020-06-10T17:19:22.333Z,1591809562.333 [WetLabsBB2FL] Loaded
2020-06-10T17:19:22.333Z,1591809562.333 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2020-06-10T17:19:22.334Z,1591809562.334 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40A2E4E0
2020-06-10T17:19:22.334Z,1591809562.334 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 900
2020-06-10T17:19:22.335Z,1591809562.335 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2020-06-10T17:19:22.336Z,1591809562.336 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2020-06-10T17:19:22.377Z,1591809562.377 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2020-06-10T17:19:22.378Z,1591809562.378 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2020-06-10T17:19:22.742Z,1591809562.742 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2020-06-10T17:19:22.744Z,1591809562.744 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2020-06-10T17:19:22.905Z,1591809562.905 [SBIT](DEBUG): Construct Startup Built In Test.
2020-06-10T17:19:22.916Z,1591809562.916 [SBIT] Loaded
2020-06-10T17:19:22.917Z,1591809562.917 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2020-06-10T17:19:22.917Z,1591809562.917 [IBIT](DEBUG): Construct Initiated Built In Test.
2020-06-10T17:19:22.930Z,1591809562.930 [IBIT] Loaded
2020-06-10T17:19:22.930Z,1591809562.930 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2020-06-10T17:19:22.933Z,1591809562.933 [CBIT](DEBUG): Construct Continuous Built In Test.
2020-06-10T17:19:23.074Z,1591809563.074 [CBIT] Loaded
2020-06-10T17:19:23.074Z,1591809563.074 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2020-06-10T17:19:23.074Z,1591809563.074 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2020-06-10T17:19:23.076Z,1591809563.076 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2020-06-10T17:19:23.173Z,1591809563.173 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2020-06-10T17:19:23.177Z,1591809563.177 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2020-06-10T17:19:23.178Z,1591809563.178 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2020-06-10T17:19:23.184Z,1591809563.184 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2020-06-10T17:19:23.186Z,1591809563.186 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40B5F4E0
2020-06-10T17:19:23.186Z,1591809563.186 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 901
2020-06-10T17:19:23.191Z,1591809563.191 [Supervisor](INFO): Main Thread ID is 802
2020-06-10T17:19:23.191Z,1591809563.191 [Supervisor](DEBUG): Running supervisor.
2020-06-10T17:19:23.191Z,1591809563.191 [CommandLine ThreadHandler](INFO): Handler Thread ID is 902
2020-06-10T17:19:23.194Z,1591809563.194 [controlThread ThreadHandler](INFO): Handler Thread ID is 903
2020-06-10T17:19:23.194Z,1591809563.194 [controlThread](DEBUG): Initializing ControlThread
2020-06-10T17:19:23.195Z,1591809563.195 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2020-06-10T17:19:23.196Z,1591809563.196 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2020-06-10T17:19:23.199Z,1591809563.199 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2020-06-10T17:19:23.199Z,1591809563.199 [LoopControl](DEBUG): Initialize LoopControlComponent.
2020-06-10T17:19:23.201Z,1591809563.201 [NavChart](DEBUG): Initialize NavChart Navigation.
2020-06-10T17:19:23.201Z,1591809563.201 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2020-06-10T17:19:23.204Z,1591809563.204 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2020-06-10T17:19:23.204Z,1591809563.204 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2020-06-10T17:19:23.205Z,1591809563.205 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2020-06-10T17:19:23.205Z,1591809563.205 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2020-06-10T17:19:23.206Z,1591809563.206 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2020-06-10T17:19:23.206Z,1591809563.206 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2020-06-10T17:19:23.208Z,1591809563.208 [SBIT](INFO): Initialize SBIT Component.
2020-06-10T17:19:23.208Z,1591809563.208 [SBIT](IMPORTANT): git: 2020-06-05
2020-06-10T17:19:23.210Z,1591809563.210 [SBIT](INFO): git hash: c12bfff2bdf9b929af60ba43c4eb841aed31d072
2020-06-10T17:19:23.210Z,1591809563.210 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2020-06-10T17:19:23.211Z,1591809563.211 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018
Kernel Reported: #1 PREEMPT Tue Dec 18 21:19:28 PST 2018
2020-06-10T17:19:23.212Z,1591809563.212 [SBIT](INFO): Beginning SBIT in 39.000000 seconds.
2020-06-10T17:19:23.214Z,1591809563.214 [logger ThreadHandler](INFO): Handler Thread ID is 904
2020-06-10T17:19:23.241Z,1591809563.241 [IBIT](INFO): Initialize IBIT Component.
2020-06-10T17:19:23.242Z,1591809563.242 [CBIT](DEBUG): Initialize CBIT Component.
2020-06-10T17:19:23.243Z,1591809563.243 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 905
2020-06-10T17:19:23.244Z,1591809563.244 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2020-06-10T17:19:23.247Z,1591809563.247 [Onboard ThreadHandler](INFO): Handler Thread ID is 906
2020-06-10T17:19:23.254Z,1591809563.254 [CBIT](DEBUG): Initialized mux pins.
2020-06-10T17:19:23.258Z,1591809563.258 [CBIT](DEBUG): Initializing the watchdog timer.
2020-06-10T17:19:23.265Z,1591809563.265 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 907
2020-06-10T17:19:23.267Z,1591809563.267 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 908
2020-06-10T17:19:23.268Z,1591809563.268 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2020-06-10T17:19:23.273Z,1591809563.273 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 910
2020-06-10T17:19:23.275Z,1591809563.275 [WetLabsBB2FL](INFO): Powering down
2020-06-10T17:19:23.292Z,1591809563.292 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2020-06-10T17:19:23.292Z,1591809563.292 [CBIT](DEBUG): Initializing heartbeat.
2020-06-10T17:19:23.339Z,1591809563.339 [CTD_Seabird](INFO): Opening uart, block timeout 10ths=20
2020-06-10T17:19:23.361Z,1591809563.361 [CBIT](DEBUG): Deactivating GF circuits.
2020-06-10T17:19:23.361Z,1591809563.361 [CBIT](DEBUG): Deactivating emergency mode.
2020-06-10T17:19:23.390Z,1591809563.390 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 911
2020-06-10T17:19:23.397Z,1591809563.397 [CBIT](DEBUG): Backplane powered.
2020-06-10T17:19:23.398Z,1591809563.398 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2020-06-10T17:19:23.669Z,1591809563.669 [Radio_Surface](INFO): Powering up
2020-06-10T17:19:23.686Z,1591809563.686 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2020-06-10T17:19:23.686Z,1591809563.686 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2020-06-10T17:19:23.686Z,1591809563.686 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2020-06-10T17:19:23.686Z,1591809563.686 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2020-06-10T17:19:23.687Z,1591809563.687 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2020-06-10T17:19:23.687Z,1591809563.687 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2020-06-10T17:19:23.687Z,1591809563.687 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2020-06-10T17:19:23.687Z,1591809563.687 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2020-06-10T17:19:23.687Z,1591809563.687 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2020-06-10T17:19:23.687Z,1591809563.687 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2020-06-10T17:19:23.688Z,1591809563.688 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2020-06-10T17:19:23.688Z,1591809563.688 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2020-06-10T17:19:23.688Z,1591809563.688 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2020-06-10T17:19:23.688Z,1591809563.688 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2020-06-10T17:19:23.688Z,1591809563.688 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2020-06-10T17:19:23.693Z,1591809563.693 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2020-06-10T17:19:23.723Z,1591809563.723 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2020-06-10T17:19:23.799Z,1591809563.799 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
       xmlns:Control="Tethys/Control"
       xmlns:Guidance="Tethys/Guidance" 
       xmlns:Units="Tethys/Units"
       xmlns:Universal="Tethys/Universal"
       xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
       xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                           Tethys/Control http://okeanids.mbari.org/tethys/Xml/Control.xsd
                           Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                           Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                           Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
       Id="Startup">

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

    <Aggregate Id="StartupSatComms">

        <Sequence/>

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

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

    </Aggregate>

</Mission>


2020-06-10T17:19:23.801Z,1591809563.801 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2020-06-10T17:19:23.929Z,1591809563.929 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2020-06-10T17:19:23.930Z,1591809563.930 [Default:A.Wait](DEBUG): Construct Wait.
2020-06-10T17:19:23.932Z,1591809563.932 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2020-06-10T17:19:23.980Z,1591809563.980 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2020-06-10T17:19:23.982Z,1591809563.982 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2020-06-10T17:19:23.992Z,1591809563.992 [Default:E.Execute](DEBUG): Construct Execute.
2020-06-10T17:19:23.996Z,1591809563.996 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xmlns="Tethys"
         xmlns:Units="Tethys/Units"
         xmlns:Guidance="Tethys/Guidance"
         xmlns:Universal="Tethys/Universal"
         xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                             Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                             Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                             Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
         Id="Default">

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

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

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

    <Aggregate Id="CheckIn">

        <Sequence Repeat="288"/>

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

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

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

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

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

    </Aggregate>

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

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

</Mission>


2020-06-10T17:19:24.001Z,1591809564.001 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,Depth_Keller,DropWeight,NAL9602,DAT,BPC1,CANONSampler,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2020-06-10T17:19:24.022Z,1591809564.022 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2020-06-10T17:19:24.181Z,1591809564.181 [DAT](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2
2020-06-10T17:19:24.182Z,1591809564.182 [DAT](INFO): Powering up
2020-06-10T17:19:24.182Z,1591809564.182 [DAT](DEBUG): Initializing DAT.
2020-06-10T17:19:24.198Z,1591809564.198 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2
2020-06-10T17:19:24.262Z,1591809564.262 [CANONSampler](INFO): Powering down
2020-06-10T17:19:24.359Z,1591809564.359 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2020-06-10T17:19:24.365Z,1591809564.365 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2020-06-10T17:19:24.366Z,1591809564.366 [ElevatorServo](DEBUG): Initializing EZServoServo.
2020-06-10T17:19:24.373Z,1591809564.373 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2020-06-10T17:19:24.374Z,1591809564.374 [MassServo](DEBUG): Initializing EZServoServo.
2020-06-10T17:19:24.381Z,1591809564.381 [MassServo](DEBUG): Initializing MassServo.
2020-06-10T17:19:24.382Z,1591809564.382 [RudderServo](DEBUG): Initializing EZServoServo.
2020-06-10T17:19:24.389Z,1591809564.389 [RudderServo](DEBUG): Initializing RudderServo.
2020-06-10T17:19:24.390Z,1591809564.390 [ThrusterServo](DEBUG): Initializing EZServoServo.
2020-06-10T17:19:24.397Z,1591809564.397 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2020-06-10T17:19:31.303Z,1591809571.303 [CTD_Seabird](ERROR): Device message queue exceeded the allowed limit.
2020-06-10T17:19:34.922Z,1591809574.922 [DAT](DEBUG): 
2020-06-10T17:19:34.923Z,1591809574.923 [DAT](DEBUG): Teledyne Benthos DAT-900 Series
2020-06-10T17:19:36.135Z,1591809576.135 [DAT](DEBUG): MF Frequency Band
2020-06-10T17:19:36.136Z,1591809576.136 [DAT](DEBUG): Directional Acoustic Transponder version 8.12.21
2020-06-10T17:19:36.137Z,1591809576.137 [DAT](DEBUG): Jan  4 2000 12:46:59 
2020-06-10T17:19:36.943Z,1591809576.943 [DAT](DEBUG): Features enabled [Bearing]
2020-06-10T17:19:36.944Z,1591809576.944 [DAT](DEBUG): CONNECT 00800 bits/sec 1 of 4, Rate 1/2 CC 12.50ms MGP
2020-06-10T17:19:36.945Z,1591809576.945 [DAT](INFO): commRate: 800
2020-06-10T17:19:37.347Z,1591809577.347 [DAT](INFO): entering command mode
2020-06-10T17:19:37.750Z,1591809577.750 [DAT](DEBUG): checking for command mode acknowledgment
2020-06-10T17:19:37.751Z,1591809577.751 [DAT](INFO): command mode acknowledged
2020-06-10T17:19:37.751Z,1591809577.751 [DAT](INFO): setting verbose to 3
2020-06-10T17:19:38.154Z,1591809578.154 [DAT](DEBUG): checking for verbose setting acknowledgment
2020-06-10T17:19:38.155Z,1591809578.155 [DAT](INFO): set verbose to 3
2020-06-10T17:19:38.559Z,1591809578.559 [DAT](INFO): setting transmit power to 8
2020-06-10T17:19:38.965Z,1591809578.965 [DAT](DEBUG): checking for transmit power setting acknowledgment
2020-06-10T17:19:39.366Z,1591809579.366 [DAT](DEBUG): checking for transmit power setting acknowledgment
2020-06-10T17:19:39.367Z,1591809579.367 [DAT](INFO): set transmit power to 8
2020-06-10T17:19:39.771Z,1591809579.771 [DAT](INFO): setting local address to 7
2020-06-10T17:19:40.174Z,1591809580.174 [DAT](DEBUG): checking for local address setting acknowledgment
2020-06-10T17:19:40.578Z,1591809580.578 [DAT](DEBUG): checking for local address setting acknowledgment
2020-06-10T17:19:40.579Z,1591809580.579 [DAT](INFO): set local address to 7
2020-06-10T17:19:49.866Z,1591809589.866 [NAL9602](INFO): Powering up NAL9602
2020-06-10T17:20:00.778Z,1591809600.778 [NAL9602](INFO): NAL9602 initialized
2020-06-10T17:20:02.853Z,1591809602.853 [SBIT](IMPORTANT): Beginning Startup BIT
2020-06-10T17:20:02.865Z,1591809602.865 [CBIT](IMPORTANT): Beginning ground fault scan
2020-06-10T17:20:13.566Z,1591809613.566 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.002979
CHAN A1 (24V): 0.000554
CHAN A2 (12V): -0.002018
CHAN A3 (5V): -0.001590
CHAN B0 (3.3V): -0.000340
CHAN B1 (3.15aV): -0.000334
CHAN B2 (3.15bV): -0.000487
CHAN B3 (GND): -0.000006
OPEN: -0.000289
Full Scale Calc: 4.765 mA, -1.589 mA
2020-06-10T17:20:42.147Z,1591809642.147 [CommandLine](IMPORTANT): got command show stack
2020-06-10T17:20:42.147Z,1591809642.147 [CommandLine](IMPORTANT): Behavior Stack:

2020-06-10T17:20:42.147Z,1591809642.147 [MissionManager](IMPORTANT): Mission loaded, but not running.
2020-06-10T17:20:56.192Z,1591809656.192 [SBIT](IMPORTANT): SBIT PASSED
2020-06-10T17:20:56.192Z,1591809656.192 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2020-06-10T17:20:56.193Z,1591809656.193 [SBIT](IMPORTANT): CBIT.gf24Offset=154 microampere;

2020-06-10T17:20:56.193Z,1591809656.193 [SBIT](IMPORTANT): DAT.loadAtStartup=1 bool;

2020-06-10T17:20:56.193Z,1591809656.193 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=250 cubic_centimeter;

2020-06-10T17:20:56.193Z,1591809656.193 [SBIT](IMPORTANT): VerticalControl.massDefault=5 millimeter;

2020-06-10T17:20:56.606Z,1591809656.606 [MissionManager](IMPORTANT): Started mission Startup
2020-06-10T17:20:56.606Z,1591809656.606 [Startup] Running Loop=1
2020-06-10T17:20:56.606Z,1591809656.606 [Startup](DEBUG): Aggregate::initialize Startup
2020-06-10T17:20:56.606Z,1591809656.606 [Startup:A.GoToSurface] Running Loop=1
2020-06-10T17:20:56.607Z,1591809656.607 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2020-06-10T17:20:56.607Z,1591809656.607 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2020-06-10T17:20:56.608Z,1591809656.608 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2020-06-10T17:20:56.608Z,1591809656.608 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2020-06-10T17:20:56.608Z,1591809656.608 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2020-06-10T17:20:56.609Z,1591809656.609 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2020-06-10T17:20:56.614Z,1591809656.614 [Startup:StartupSatComms] Running Loop=1
2020-06-10T17:20:56.614Z,1591809656.614 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2020-06-10T17:20:56.614Z,1591809656.614 [Startup:StartupSatComms:A] Running Loop=1
2020-06-10T17:20:56.999Z,1591809656.999 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2020-06-10T17:21:07.152Z,1591809667.152 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2020-06-10T17:21:21.692Z,1591809681.692 [BPC1](ERROR): BPC1B failed to parse battery data due to unrecognized msg size.
2020-06-10T17:21:22.910Z,1591809682.910 [BPC1](ERROR): BPC1A failed to parse battery data due to unrecognized msg size.
2020-06-10T17:21:56.779Z,1591809716.779 [Startup:StartupSatComms:A](INFO): Timed out from 2020-06-10T17:20:56.6Z
2020-06-10T17:21:56.779Z,1591809716.779 [Startup:StartupSatComms:A] Stopped
2020-06-10T17:21:56.780Z,1591809716.780 [Startup:StartupSatComms:B] Running Loop=1
2020-06-10T17:21:57.194Z,1591809717.194 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2020-06-10T17:22:10.236Z,1591809730.236 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.005296
2020-06-10T17:22:23.453Z,1591809743.453 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2020-06-10T17:22:23.453Z,1591809743.453 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-06-10T17:22:23.463Z,1591809743.463 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-06-10T17:22:23.874Z,1591809743.874 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-06-10T17:22:23.874Z,1591809743.874 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2020-06-10T17:22:56.984Z,1591809776.984 [Startup:StartupSatComms:B](INFO): Timed out from 2020-06-10T17:21:56.8Z
2020-06-10T17:22:56.984Z,1591809776.984 [Startup:StartupSatComms:B] Stopped
2020-06-10T17:22:56.984Z,1591809776.984 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2020-06-10T17:22:56.984Z,1591809776.984 [Startup:StartupSatComms] Stopped
2020-06-10T17:22:56.984Z,1591809776.984 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2020-06-10T17:22:56.985Z,1591809776.985 [Startup](INFO): Completed Startup
2020-06-10T17:22:56.985Z,1591809776.985 [MissionManager](INFO): Startup is completed.
2020-06-10T17:22:56.985Z,1591809776.985 [MissionManager](INFO): Uninitializing Mission Startup
2020-06-10T17:22:56.985Z,1591809776.985 [Startup] Stopped
2020-06-10T17:22:56.985Z,1591809776.985 [Startup](DEBUG): Aggregate::uninitialize Startup
2020-06-10T17:22:56.986Z,1591809776.986 [Startup:A.GoToSurface] Stopped
2020-06-10T17:22:56.986Z,1591809776.986 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2020-06-10T17:22:57.403Z,1591809777.403 [MissionManager](IMPORTANT): Started mission Default
2020-06-10T17:22:57.403Z,1591809777.403 [Default] Running Loop=1
2020-06-10T17:22:57.403Z,1591809777.403 [Default](DEBUG): Aggregate::initialize Default
2020-06-10T17:22:57.403Z,1591809777.403 [Default:B.GoToSurface] Running Loop=1
2020-06-10T17:22:57.403Z,1591809777.403 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2020-06-10T17:22:57.403Z,1591809777.403 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2020-06-10T17:22:57.404Z,1591809777.404 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2020-06-10T17:22:57.404Z,1591809777.404 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2020-06-10T17:22:57.404Z,1591809777.404 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2020-06-10T17:22:57.405Z,1591809777.405 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2020-06-10T17:22:57.405Z,1591809777.405 [Default:A.Wait] Running Loop=1
2020-06-10T17:22:57.405Z,1591809777.405 [Default:A.Wait](DEBUG): Initialize Wait Component.
2020-06-10T17:23:08.774Z,1591809788.774 [DataOverHttps](INFO): Sending 739 bytes from file Logs/20200610T171911/Express0001.lzma
2020-06-10T17:23:09.767Z,1591809789.767 [DataOverHttps](INFO): Moved sent file to Logs/20200610T171911/Express0001.lzma.bak
2020-06-10T17:23:09.767Z,1591809789.767 [DataOverHttps](INFO): SBD MOMSN=12377564
2020-06-10T17:23:10.715Z,1591809790.715 [Default:A.Wait](INFO): Done Waiting.
2020-06-10T17:23:10.715Z,1591809790.715 [Default:A.Wait] Stopped
2020-06-10T17:23:10.716Z,1591809790.716 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2020-06-10T17:23:11.177Z,1591809791.177 [Default:CheckIn] Running Loop=1
2020-06-10T17:23:11.177Z,1591809791.177 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-06-10T17:23:11.178Z,1591809791.178 [Default:CheckIn:Read_GPS] Running Loop=1
2020-06-10T17:23:11.612Z,1591809791.612 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2020-06-10T17:25:04.640Z,1591809904.640 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2020-06-10T17:25:24.451Z,1591809924.451 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2020-06-10T17:25:24.452Z,1591809924.452 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-06-10T17:25:24.461Z,1591809924.461 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-06-10T17:25:24.870Z,1591809924.870 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-06-10T17:25:24.870Z,1591809924.870 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2020-06-10T17:27:48.693Z,1591810068.693 [BPC1](INFO): Calculating totals. Valid battery stick count: 56. Valid reserve battery stick count: 6.
2020-06-10T17:27:48.696Z,1591810068.696 [BPC1](INFO): Received data from all battery sticks.
2020-06-10T17:28:11.298Z,1591810091.298 [Default:CheckIn:Read_GPS](INFO): Timed out from 2020-06-10T17:23:11.2Z
2020-06-10T17:28:11.298Z,1591810091.298 [Default:CheckIn:Read_GPS] Stopped
2020-06-10T17:28:11.298Z,1591810091.298 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-06-10T17:28:11.695Z,1591810091.695 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2020-06-10T17:28:18.093Z,1591810098.093 [DataOverHttps](INFO): Sending 186 bytes from file Logs/20200610T171911/Courier0004.lzma
2020-06-10T17:28:19.095Z,1591810099.095 [DataOverHttps](INFO): Moved sent file to Logs/20200610T171911/Courier0004.lzma.bak
2020-06-10T17:28:19.095Z,1591810099.095 [DataOverHttps](INFO): SBD MOMSN=12377585
2020-06-10T17:28:25.448Z,1591810105.448 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3
2020-06-10T17:28:25.449Z,1591810105.449 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-06-10T17:28:25.458Z,1591810105.458 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-06-10T17:28:25.854Z,1591810105.854 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-06-10T17:28:25.854Z,1591810105.854 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3
2020-06-10T17:28:34.389Z,1591810114.389 [DataOverHttps](INFO): Sending 176 bytes from file Logs/20200610T171911/Express0005.lzma
2020-06-10T17:28:35.390Z,1591810115.390 [DataOverHttps](INFO): Moved sent file to Logs/20200610T171911/Express0005.lzma.bak
2020-06-10T17:28:35.391Z,1591810115.391 [DataOverHttps](INFO): SBD MOMSN=12377587
2020-06-10T17:28:36.747Z,1591810116.747 [Default:CheckIn:Read_Iridium] Stopped
2020-06-10T17:28:36.747Z,1591810116.747 [Default:CheckIn:C.Wait] Running Loop=1
2020-06-10T17:28:36.747Z,1591810116.747 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-06-10T17:30:01.978Z,1591810201.978 [NAL9602](FAULT): GPS failed to acquire within timeout.
2020-06-10T17:30:01.978Z,1591810201.978 [NAL9602] Data Fault, FailCount= 1
2020-06-10T17:30:01.978Z,1591810201.978 [NAL9602](ERROR): Data Fault
2020-06-10T17:30:01.995Z,1591810201.995 [CBIT](ERROR): Data Fault in component: NAL9602
2020-06-10T17:30:02.388Z,1591810202.388 [NAL9602](INFO): Powering down
2020-06-10T17:30:03.207Z,1591810203.207 [CBIT](INFO): Clearing failed state for component NAL9602
2020-06-10T17:30:03.207Z,1591810203.207 [NAL9602] No Fault, FailCount= 1
2020-06-10T17:30:32.686Z,1591810232.686 [NAL9602](INFO): Powering up NAL9602
2020-06-10T17:30:43.590Z,1591810243.590 [NAL9602](INFO): NAL9602 initialized
2020-06-10T17:31:26.426Z,1591810286.426 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4
2020-06-10T17:31:26.426Z,1591810286.426 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-06-10T17:31:26.463Z,1591810286.463 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-06-10T17:31:26.833Z,1591810286.833 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-06-10T17:31:26.834Z,1591810286.834 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4
2020-06-10T17:33:37.327Z,1591810417.327 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-06-10T17:33:37.327Z,1591810417.327 [Default:CheckIn:C.Wait] Stopped
2020-06-10T17:33:37.327Z,1591810417.327 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-06-10T17:33:37.327Z,1591810417.327 [Default:CheckIn:D] Running Loop=1
2020-06-10T17:33:37.743Z,1591810417.743 [Default:CheckIn:D] Stopped
2020-06-10T17:33:37.743Z,1591810417.743 [Default:CheckIn:E] Running Loop=1
2020-06-10T17:33:38.159Z,1591810418.159 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 10.672329 min 
2020-06-10T17:33:38.159Z,1591810418.159 [Default:CheckIn:E] Stopped
2020-06-10T17:33:38.159Z,1591810418.159 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-06-10T17:33:38.159Z,1591810418.159 [Default:CheckIn] Stopped
2020-06-10T17:33:38.159Z,1591810418.159 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-06-10T17:33:38.160Z,1591810418.160 [Default:CheckIn](INFO): Running loop #2
2020-06-10T17:33:38.160Z,1591810418.160 [Default:CheckIn] Running Loop=2
2020-06-10T17:33:38.160Z,1591810418.160 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-06-10T17:33:38.160Z,1591810418.160 [Default:CheckIn:Read_GPS] Running Loop=1
2020-06-10T17:33:44.184Z,1591810424.184 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173342.00,A,3648.16793,N,12147.27139,W,0.583,0.00,100620,,,A*7B
2020-06-10T17:33:44.187Z,1591810424.187 [NAL9602](INFO): GPS fix at 20200610T173342: (36.802799, -121.787857)
2020-06-10T17:33:44.236Z,1591810424.236 [Default:CheckIn:Read_GPS] Stopped
2020-06-10T17:33:44.236Z,1591810424.236 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-06-10T17:33:45.118Z,1591810425.118 [DataOverHttps](INFO): Sending 213 bytes from file Logs/20200610T171911/Courier0007.lzma
2020-06-10T17:33:46.115Z,1591810426.115 [DataOverHttps](INFO): Moved sent file to Logs/20200610T171911/Courier0007.lzma.bak
2020-06-10T17:33:46.115Z,1591810426.115 [DataOverHttps](INFO): SBD MOMSN=12377591
2020-06-10T17:34:03.163Z,1591810443.163 [DataOverHttps](INFO): Sending 296 bytes from file Logs/20200610T171911/Express0008.lzma
2020-06-10T17:34:04.163Z,1591810444.163 [DataOverHttps](INFO): Moved sent file to Logs/20200610T171911/Express0008.lzma.bak
2020-06-10T17:34:04.163Z,1591810444.163 [DataOverHttps](INFO): SBD MOMSN=12377595
2020-06-10T17:34:05.210Z,1591810445.210 [Default:CheckIn:Read_Iridium] Stopped
2020-06-10T17:34:05.210Z,1591810445.210 [Default:CheckIn:C.Wait] Running Loop=1
2020-06-10T17:34:05.210Z,1591810445.210 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-06-10T17:34:16.542Z,1591810456.542 [NAL9602](INFO): Not Powering down - fast GPS
2020-06-10T17:39:05.850Z,1591810745.850 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-06-10T17:39:05.850Z,1591810745.850 [Default:CheckIn:C.Wait] Stopped
2020-06-10T17:39:05.850Z,1591810745.850 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-06-10T17:39:05.850Z,1591810745.850 [Default:CheckIn:D] Running Loop=1
2020-06-10T17:39:06.275Z,1591810746.275 [Default:CheckIn:D] Stopped
2020-06-10T17:39:06.275Z,1591810746.275 [Default:CheckIn:E] Running Loop=1
2020-06-10T17:39:06.673Z,1591810746.673 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 16.147871 min 
2020-06-10T17:39:06.673Z,1591810746.673 [Default:CheckIn:E] Stopped
2020-06-10T17:39:06.673Z,1591810746.673 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-06-10T17:39:06.673Z,1591810746.673 [Default:CheckIn] Stopped
2020-06-10T17:39:06.673Z,1591810746.673 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-06-10T17:39:06.673Z,1591810746.673 [Default:CheckIn](INFO): Running loop #3
2020-06-10T17:39:06.673Z,1591810746.673 [Default:CheckIn] Running Loop=3
2020-06-10T17:39:06.674Z,1591810746.674 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-06-10T17:39:06.674Z,1591810746.674 [Default:CheckIn:Read_GPS] Running Loop=1
2020-06-10T17:39:08.676Z,1591810748.676 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,173906.00,A,3648.17074,N,12147.27818,W,1.050,0.00,100620,,,A*7E
2020-06-10T17:39:08.688Z,1591810748.688 [NAL9602](INFO): GPS fix at 20200610T173906: (36.802846, -121.787970)
2020-06-10T17:39:08.699Z,1591810748.699 [Default:CheckIn:Read_GPS] Stopped
2020-06-10T17:39:08.699Z,1591810748.699 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-06-10T17:39:15.748Z,1591810755.748 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20200610T171911/Courier0010.lzma
2020-06-10T17:39:16.751Z,1591810756.751 [DataOverHttps](INFO): Moved sent file to Logs/20200610T171911/Courier0010.lzma.bak
2020-06-10T17:39:16.751Z,1591810756.751 [DataOverHttps](INFO): SBD MOMSN=12377602
2020-06-10T17:39:32.485Z,1591810772.485 [DataOverHttps](INFO): Sending 121 bytes from file Logs/20200610T171911/Express0011.lzma
2020-06-10T17:39:32.534Z,1591810772.534 [NAL9602](INFO): SBD MO Status=0, MOMSN=20340, MT Status=0, MTMSN=0
2020-06-10T17:39:32.534Z,1591810772.534 [NAL9602](INFO): No messages in MT queue
2020-06-10T17:39:33.487Z,1591810773.487 [DataOverHttps](INFO): Moved sent file to Logs/20200610T171911/Express0011.lzma.bak
2020-06-10T17:39:33.487Z,1591810773.487 [DataOverHttps](INFO): SBD MOMSN=12377607
2020-06-10T17:39:34.561Z,1591810774.561 [Default:CheckIn:Read_Iridium] Stopped
2020-06-10T17:39:34.561Z,1591810774.561 [Default:CheckIn:C.Wait] Running Loop=1
2020-06-10T17:39:34.561Z,1591810774.561 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-06-10T17:40:03.238Z,1591810803.238 [NAL9602](INFO): Not Powering down - fast GPS
2020-06-10T17:44:35.155Z,1591811075.155 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-06-10T17:44:35.155Z,1591811075.155 [Default:CheckIn:C.Wait] Stopped
2020-06-10T17:44:35.155Z,1591811075.155 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-06-10T17:44:35.156Z,1591811075.156 [Default:CheckIn:D] Running Loop=1
2020-06-10T17:44:35.554Z,1591811075.554 [Default:CheckIn:D] Stopped
2020-06-10T17:44:35.554Z,1591811075.554 [Default:CheckIn:E] Running Loop=1
2020-06-10T17:44:35.968Z,1591811075.968 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 21.635850 min 
2020-06-10T17:44:35.968Z,1591811075.968 [Default:CheckIn:E] Stopped
2020-06-10T17:44:35.968Z,1591811075.968 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-06-10T17:44:35.968Z,1591811075.968 [Default:CheckIn] Stopped
2020-06-10T17:44:35.968Z,1591811075.968 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-06-10T17:44:35.968Z,1591811075.968 [Default:CheckIn](INFO): Running loop #4
2020-06-10T17:44:35.968Z,1591811075.968 [Default:CheckIn] Running Loop=4
2020-06-10T17:44:35.968Z,1591811075.968 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-06-10T17:44:35.968Z,1591811075.968 [Default:CheckIn:Read_GPS] Running Loop=1
2020-06-10T17:44:37.976Z,1591811077.976 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174437.00,A,3648.15080,N,12147.22526,W,0.136,25.38,100620,,,A*46
2020-06-10T17:44:37.988Z,1591811077.988 [NAL9602](INFO): GPS fix at 20200610T174437: (36.802513, -121.787088)
2020-06-10T17:44:37.998Z,1591811077.998 [Default:CheckIn:Read_GPS] Stopped
2020-06-10T17:44:37.998Z,1591811077.998 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-06-10T17:44:45.168Z,1591811085.168 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20200610T171911/Courier0013.lzma
2020-06-10T17:44:46.171Z,1591811086.171 [DataOverHttps](INFO): Moved sent file to Logs/20200610T171911/Courier0013.lzma.bak
2020-06-10T17:44:46.171Z,1591811086.171 [DataOverHttps](IMPORTANT): SBD MOMSN=12377637, MTMSN=20200610T174445
2020-06-10T17:44:52.516Z,1591811092.516 [NAL9602](INFO): SBD MO Status=0, MOMSN=20341, MT Status=0, MTMSN=0
2020-06-10T17:44:52.516Z,1591811092.516 [NAL9602](INFO): No messages in MT queue
2020-06-10T17:44:53.457Z,1591811093.457 [DataOverHttps](INFO): Received command:Ibit
2020-06-10T17:44:53.502Z,1591811093.502 [CommandLine](IMPORTANT): got command ibit
2020-06-10T17:44:53.740Z,1591811093.740 [IBIT](IMPORTANT): Beginning Initiated BIT
2020-06-10T17:44:53.740Z,1591811093.740 [IBIT](IMPORTANT): Beginning control surface checks.
2020-06-10T17:44:53.743Z,1591811093.743 [CBIT](IMPORTANT): Beginning ground fault scan
2020-06-10T17:44:55.348Z,1591811095.348 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174454.00,A,3648.15031,N,12147.22392,W,0.078,25.38,100620,,,A*4B
2020-06-10T17:44:55.350Z,1591811095.350 [NAL9602](INFO): GPS fix at 20200610T174454: (36.802505, -121.787065)
2020-06-10T17:44:58.172Z,1591811098.172 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174457.00,A,3648.15029,N,12147.22407,W,0.058,25.38,100620,,,A*48
2020-06-10T17:44:58.178Z,1591811098.178 [NAL9602](INFO): GPS fix at 20200610T174457: (36.802505, -121.787068)
2020-06-10T17:45:00.000Z,1591811101.000 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174500.00,A,3648.15041,N,12147.22440,W,0.583,25.38,100620,,,A*45
2020-06-10T17:45:01.006Z,1591811101.006 [NAL9602](INFO): GPS fix at 20200610T174500: (36.802507, -121.787073)
2020-06-10T17:45:02.164Z,1591811102.164 [DataOverHttps](INFO): Sending 135 bytes from file Logs/20200610T171911/Express0014.lzma
2020-06-10T17:45:03.167Z,1591811103.167 [DataOverHttps](INFO): Moved sent file to Logs/20200610T171911/Express0014.lzma.bak
2020-06-10T17:45:03.167Z,1591811103.167 [DataOverHttps](INFO): SBD MOMSN=12377642
2020-06-10T17:45:04.232Z,1591811104.232 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174503.00,A,3648.15046,N,12147.22461,W,0.156,25.38,100620,,,A*4E
2020-06-10T17:45:04.244Z,1591811104.244 [NAL9602](INFO): GPS fix at 20200610T174503: (36.802508, -121.787077)
2020-06-10T17:45:04.679Z,1591811104.679 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.006890
CHAN A1 (24V): 0.000403
CHAN A2 (12V): -0.002565
CHAN A3 (5V): -0.001424
CHAN B0 (3.3V): -0.000122
CHAN B1 (3.15aV): -0.000328
CHAN B2 (3.15bV): -0.000108
CHAN B3 (GND): -0.000428
OPEN: -0.000368
Full Scale Calc: 4.765 mA, -1.589 mA
2020-06-10T17:45:07.060Z,1591811107.060 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174506.00,A,3648.15046,N,12147.22471,W,0.564,334.53,100620,,,A*71
2020-06-10T17:45:07.062Z,1591811107.062 [NAL9602](INFO): GPS fix at 20200610T174506: (36.802508, -121.787079)
2020-06-10T17:45:10.290Z,1591811110.290 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174509.00,A,3648.15001,N,12147.22356,W,1.166,76.21,100620,,,A*48
2020-06-10T17:45:10.292Z,1591811110.292 [NAL9602](INFO): GPS fix at 20200610T174509: (36.802500, -121.787059)
2020-06-10T17:45:13.118Z,1591811113.118 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174512.00,A,3648.15002,N,12147.22394,W,0.058,76.21,100620,,,A*42
2020-06-10T17:45:13.120Z,1591811113.120 [NAL9602](INFO): GPS fix at 20200610T174512: (36.802500, -121.787066)
2020-06-10T17:45:15.948Z,1591811115.948 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174515.00,A,3648.15016,N,12147.22502,W,0.117,76.21,100620,,,A*43
2020-06-10T17:45:15.951Z,1591811115.951 [NAL9602](INFO): GPS fix at 20200610T174515: (36.802503, -121.787084)
2020-06-10T17:45:19.184Z,1591811119.184 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174518.00,A,3648.15003,N,12147.22529,W,0.019,76.21,100620,,,A*4C
2020-06-10T17:45:19.186Z,1591811119.186 [NAL9602](INFO): GPS fix at 20200610T174518: (36.802501, -121.787088)
2020-06-10T17:45:19.494Z,1591811119.494 [DataOverHttps](INFO): Sending 250 bytes from file Logs/20200610T171911/Express0017.lzma
2020-06-10T17:45:20.495Z,1591811120.495 [DataOverHttps](INFO): Moved sent file to Logs/20200610T171911/Express0017.lzma.bak
2020-06-10T17:45:20.495Z,1591811120.495 [DataOverHttps](INFO): SBD MOMSN=12377645
2020-06-10T17:45:22.008Z,1591811122.008 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174521.00,A,3648.14989,N,12147.22562,W,0.078,76.21,100620,,,A*44
2020-06-10T17:45:22.018Z,1591811122.018 [NAL9602](INFO): GPS fix at 20200610T174521: (36.802498, -121.787094)
2020-06-10T17:45:25.240Z,1591811125.240 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174524.00,A,3648.14969,N,12147.22601,W,0.194,76.21,100620,,,A*4A
2020-06-10T17:45:25.242Z,1591811125.242 [NAL9602](INFO): GPS fix at 20200610T174524: (36.802495, -121.787100)
2020-06-10T17:45:28.076Z,1591811128.076 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174527.00,A,3648.14970,N,12147.22589,W,0.330,76.21,100620,,,A*4E
2020-06-10T17:45:28.078Z,1591811128.078 [NAL9602](INFO): GPS fix at 20200610T174527: (36.802495, -121.787098)
2020-06-10T17:45:31.298Z,1591811131.298 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174530.00,A,3648.14967,N,12147.22561,W,0.194,76.21,100620,,,A*44
2020-06-10T17:45:31.300Z,1591811131.300 [NAL9602](INFO): GPS fix at 20200610T174530: (36.802495, -121.787093)
2020-06-10T17:45:34.128Z,1591811134.128 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174533.00,A,3648.14957,N,12147.22524,W,0.097,76.21,100620,,,A*47
2020-06-10T17:45:34.130Z,1591811134.130 [NAL9602](INFO): GPS fix at 20200610T174533: (36.802493, -121.787087)
2020-06-10T17:45:36.956Z,1591811136.956 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174536.00,A,3648.14951,N,12147.22500,W,0.311,76.21,100620,,,A*4F
2020-06-10T17:45:36.970Z,1591811136.970 [NAL9602](INFO): GPS fix at 20200610T174536: (36.802492, -121.787083)
2020-06-10T17:45:40.197Z,1591811140.197 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,174539.00,A,3648.14940,N,12147.22458,W,0.175,76.21,100620,,,A*4C
2020-06-10T17:45:40.199Z,1591811140.199 [NAL9602](INFO): GPS fix at 20200610T174539: (36.802490, -121.787076)
2020-06-10T17:45:40.215Z,1591811140.215 [IBIT](IMPORTANT): Communications Status:
Fix Status: 1
Iridium Signal Strength: 4
Latitude: 36.802490 Longitude: -121.787079
2020-06-10T17:45:40.630Z,1591811140.630 [IBIT](IMPORTANT): Battery Status:
Battery Charge (AH): 0.000000
Voltage: 0.000000
2020-06-10T17:45:40.630Z,1591811140.630 [IBIT](IMPORTANT): batteryCapacityThreshold: 50.000000 Ah
2020-06-10T17:45:40.631Z,1591811140.631 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.700000 V
2020-06-10T17:45:41.023Z,1591811141.023 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 %
2020-06-10T17:45:41.023Z,1591811141.023 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi
2020-06-10T17:45:41.024Z,1591811141.024 [IBIT](IMPORTANT): Pressure:8.341099 PSI
2020-06-10T17:45:41.024Z,1591811141.024 [IBIT](IMPORTANT): Humidity:9.650836 %
2020-06-10T17:45:41.473Z,1591811141.473 [IBIT](IMPORTANT): Vehicle Pitch:0.593326 degrees
2020-06-10T17:45:41.473Z,1591811141.473 [IBIT](IMPORTANT): Vehicle  Roll:12.411819 degrees
2020-06-10T17:45:41.474Z,1591811141.474 [IBIT](IMPORTANT): Vehicle  Heading:234.357315 degrees
2020-06-10T17:45:41.890Z,1591811141.890 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m
2020-06-10T17:45:41.890Z,1591811141.890 [IBIT](IMPORTANT): buoyancyNeutral: 250.000015 cc
2020-06-10T17:45:41.890Z,1591811141.890 [IBIT](IMPORTANT): massDefault: 0.500000 cm
2020-06-10T17:45:41.890Z,1591811141.890 [IBIT](IMPORTANT): stopDepth: 205.000000 m
2020-06-10T17:45:41.891Z,1591811141.891 [IBIT](IMPORTANT): abortDepth: 250.000000 m
2020-06-10T17:45:41.891Z,1591811141.891 [IBIT](IMPORTANT): IBIT PASSED
2020-06-10T17:45:42.228Z,1591811142.228 [Default:CheckIn:Read_Iridium] Stopped
2020-06-10T17:45:42.228Z,1591811142.228 [Default:CheckIn:C.Wait] Running Loop=1
2020-06-10T17:45:42.228Z,1591811142.228 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-06-10T17:46:12.504Z,1591811172.504 [NAL9602](INFO): Not Powering down - fast GPS
2020-06-10T17:50:42.794Z,1591811442.794 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-06-10T17:50:42.794Z,1591811442.794 [Default:CheckIn:C.Wait] Stopped
2020-06-10T17:50:42.794Z,1591811442.794 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-06-10T17:50:42.794Z,1591811442.794 [Default:CheckIn:D] Running Loop=1
2020-06-10T17:50:43.204Z,1591811443.204 [Default:CheckIn:D] Stopped
2020-06-10T17:50:43.205Z,1591811443.205 [Default:CheckIn:E] Running Loop=1
2020-06-10T17:50:43.604Z,1591811443.604 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 27.763361 min 
2020-06-10T17:50:43.604Z,1591811443.604 [Default:CheckIn:E] Stopped
2020-06-10T17:50:43.604Z,1591811443.604 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-06-10T17:50:43.604Z,1591811443.604 [Default:CheckIn] Stopped
2020-06-10T17:50:43.604Z,1591811443.604 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-06-10T17:50:43.604Z,1591811443.605 [Default:CheckIn](INFO): Running loop #5
2020-06-10T17:50:43.641Z,1591811443.641 [Default:CheckIn] Running Loop=5
2020-06-10T17:50:43.641Z,1591811443.641 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-06-10T17:50:43.642Z,1591811443.642 [Default:CheckIn:Read_GPS] Running Loop=1
2020-06-10T17:50:45.620Z,1591811445.620 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175044.00,A,3648.14842,N,12147.22538,W,0.117,76.21,100620,,,D*47
2020-06-10T17:50:45.622Z,1591811445.622 [NAL9602](INFO): GPS fix at 20200610T175044: (36.802474, -121.787090)
2020-06-10T17:50:45.632Z,1591811445.632 [Default:CheckIn:Read_GPS] Stopped
2020-06-10T17:50:45.632Z,1591811445.632 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-06-10T17:50:53.328Z,1591811453.328 [DataOverHttps](INFO): Sending 61 bytes from file Logs/20200610T171911/Courier0019.lzma
2020-06-10T17:50:54.331Z,1591811454.331 [DataOverHttps](INFO): Moved sent file to Logs/20200610T171911/Courier0019.lzma.bak
2020-06-10T17:50:54.331Z,1591811454.331 [DataOverHttps](INFO): SBD MOMSN=12377653
2020-06-10T17:51:10.158Z,1591811470.158 [DataOverHttps](INFO): Sending 667 bytes from file Logs/20200610T171911/Express0020.lzma
2020-06-10T17:51:11.159Z,1591811471.159 [DataOverHttps](INFO): Moved sent file to Logs/20200610T171911/Express0020.lzma.bak
2020-06-10T17:51:11.159Z,1591811471.159 [DataOverHttps](INFO): SBD MOMSN=12377656
2020-06-10T17:51:12.291Z,1591811472.291 [Default:CheckIn:Read_Iridium] Stopped
2020-06-10T17:51:12.292Z,1591811472.292 [Default:CheckIn:C.Wait] Running Loop=1
2020-06-10T17:51:12.292Z,1591811472.292 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-06-10T17:51:57.931Z,1591811517.931 [NAL9602](INFO): SBD MO Status=0, MOMSN=20342, MT Status=0, MTMSN=0
2020-06-10T17:51:57.931Z,1591811517.931 [NAL9602](INFO): No messages in MT queue
2020-06-10T17:52:28.634Z,1591811548.634 [NAL9602](INFO): Not Powering down - fast GPS
2020-06-10T17:55:22.814Z,1591811722.814 [DataOverHttps](IMPORTANT): SBD MTMSN=20200610T175521
2020-06-10T17:55:30.137Z,1591811730.137 [DataOverHttps](INFO): Received command:Failc
2020-06-10T17:55:30.210Z,1591811730.210 [CommandLine](IMPORTANT): got command failComponent
2020-06-10T17:55:30.210Z,1591811730.210 [CommandLine](IMPORTANT): Failed components:
2020-06-10T17:55:30.210Z,1591811730.210 [CommandLine](IMPORTANT): No failed Components.
2020-06-10T17:56:12.875Z,1591811772.875 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-06-10T17:56:12.875Z,1591811772.875 [Default:CheckIn:C.Wait] Stopped
2020-06-10T17:56:12.875Z,1591811772.875 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-06-10T17:56:12.875Z,1591811772.875 [Default:CheckIn:D] Running Loop=1
2020-06-10T17:56:13.287Z,1591811773.287 [Default:CheckIn:D] Stopped
2020-06-10T17:56:13.288Z,1591811773.288 [Default:CheckIn:E] Running Loop=1
2020-06-10T17:56:13.690Z,1591811773.690 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 33.264744 min 
2020-06-10T17:56:13.690Z,1591811773.690 [Default:CheckIn:E] Stopped
2020-06-10T17:56:13.691Z,1591811773.691 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-06-10T17:56:13.691Z,1591811773.691 [Default:CheckIn] Stopped
2020-06-10T17:56:13.691Z,1591811773.691 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-06-10T17:56:13.691Z,1591811773.691 [Default:CheckIn](INFO): Running loop #6
2020-06-10T17:56:13.691Z,1591811773.691 [Default:CheckIn] Running Loop=6
2020-06-10T17:56:13.691Z,1591811773.691 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-06-10T17:56:13.691Z,1591811773.691 [Default:CheckIn:Read_GPS] Running Loop=1
2020-06-10T17:56:15.700Z,1591811775.700 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,175614.00,A,3648.14848,N,12147.22437,W,0.058,348.14,100620,,,D*72
2020-06-10T17:56:15.702Z,1591811775.702 [NAL9602](INFO): GPS fix at 20200610T175614: (36.802475, -121.787073)
2020-06-10T17:56:15.739Z,1591811775.739 [Default:CheckIn:Read_GPS] Stopped
2020-06-10T17:56:15.739Z,1591811775.739 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-06-10T17:56:22.976Z,1591811782.976 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20200610T171911/Courier0022.lzma
2020-06-10T17:56:23.979Z,1591811783.979 [DataOverHttps](INFO): Moved sent file to Logs/20200610T171911/Courier0022.lzma.bak
2020-06-10T17:56:23.979Z,1591811783.979 [DataOverHttps](INFO): SBD MOMSN=12377680
2020-06-10T17:56:39.769Z,1591811799.769 [DataOverHttps](INFO): Sending 205 bytes from file Logs/20200610T171911/Express0023.lzma
2020-06-10T17:56:40.771Z,1591811800.771 [DataOverHttps](INFO): Moved sent file to Logs/20200610T171911/Express0023.lzma.bak
2020-06-10T17:56:40.771Z,1591811800.771 [DataOverHttps](INFO): SBD MOMSN=12377683
2020-06-10T17:56:56.525Z,1591811816.525 [DataOverHttps](INFO): Sending 52 bytes from file Logs/20200610T171911/Express0026.lzma
2020-06-10T17:56:57.527Z,1591811817.527 [DataOverHttps](INFO): Moved sent file to Logs/20200610T171911/Express0026.lzma.bak
2020-06-10T17:56:57.527Z,1591811817.527 [DataOverHttps](INFO): SBD MOMSN=12377690
2020-06-10T17:56:58.609Z,1591811818.609 [Default:CheckIn:Read_Iridium] Stopped
2020-06-10T17:56:58.609Z,1591811818.609 [Default:CheckIn:C.Wait] Running Loop=1
2020-06-10T17:56:58.609Z,1591811818.609 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-06-10T17:58:59.766Z,1591811939.766 [NAL9602](INFO): SBD MO Status=0, MOMSN=20343, MT Status=0, MTMSN=0
2020-06-10T17:58:59.766Z,1591811939.766 [NAL9602](INFO): No messages in MT queue
2020-06-10T17:59:30.474Z,1591811970.474 [NAL9602](INFO): Not Powering down - fast GPS
2020-06-10T18:01:59.172Z,1591812119.172 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-06-10T18:01:59.172Z,1591812119.172 [Default:CheckIn:C.Wait] Stopped
2020-06-10T18:01:59.172Z,1591812119.172 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-06-10T18:01:59.172Z,1591812119.172 [Default:CheckIn:D] Running Loop=1
2020-06-10T18:01:59.584Z,1591812119.584 [Default:CheckIn:D] Stopped
2020-06-10T18:01:59.584Z,1591812119.584 [Default:CheckIn:E] Running Loop=1
2020-06-10T18:02:00.002Z,1591812120.002 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 39.036348 min 
2020-06-10T18:02:00.002Z,1591812120.002 [Default:CheckIn:E] Stopped
2020-06-10T18:02:00.002Z,1591812120.002 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-06-10T18:02:00.002Z,1591812120.002 [Default:CheckIn] Stopped
2020-06-10T18:02:00.002Z,1591812120.002 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-06-10T18:02:00.002Z,1591812120.002 [Default:CheckIn](INFO): Running loop #7
2020-06-10T18:02:00.002Z,1591812120.002 [Default:CheckIn] Running Loop=7
2020-06-10T18:02:00.002Z,1591812120.002 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-06-10T18:02:00.003Z,1591812120.003 [Default:CheckIn:Read_GPS] Running Loop=1
2020-06-10T18:02:01.996Z,1591812121.996 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,180201.00,A,3648.14861,N,12147.22440,W,0.078,348.14,100620,,,D*71
2020-06-10T18:02:01.998Z,1591812121.998 [NAL9602](INFO): GPS fix at 20200610T180201: (36.802477, -121.787073)
2020-06-10T18:02:02.008Z,1591812122.008 [Default:CheckIn:Read_GPS] Stopped
2020-06-10T18:02:02.008Z,1591812122.008 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-06-10T18:02:12.164Z,1591812132.164 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20200610T171911/Courier0028.lzma
2020-06-10T18:02:13.167Z,1591812133.167 [DataOverHttps](INFO): Moved sent file to Logs/20200610T171911/Courier0028.lzma.bak
2020-06-10T18:02:13.167Z,1591812133.167 [DataOverHttps](INFO): SBD MOMSN=12377693
2020-06-10T18:02:28.746Z,1591812148.746 [DataOverHttps](INFO): Sending 121 bytes from file Logs/20200610T171911/Express0029.lzma
2020-06-10T18:02:29.747Z,1591812149.747 [DataOverHttps](INFO): Moved sent file to Logs/20200610T171911/Express0029.lzma.bak
2020-06-10T18:02:29.747Z,1591812149.747 [DataOverHttps](INFO): SBD MOMSN=12377696
2020-06-10T18:02:31.087Z,1591812151.087 [Default:CheckIn:Read_Iridium] Stopped
2020-06-10T18:02:31.087Z,1591812151.087 [Default:CheckIn:C.Wait] Running Loop=1
2020-06-10T18:02:31.087Z,1591812151.087 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-06-10T18:03:10.669Z,1591812190.669 [NAL9602](INFO): SBD MO Status=0, MOMSN=20344, MT Status=0, MTMSN=0
2020-06-10T18:03:10.669Z,1591812190.669 [NAL9602](INFO): No messages in MT queue
2020-06-10T18:03:41.378Z,1591812221.378 [NAL9602](INFO): Not Powering down - fast GPS
2020-06-10T18:07:31.707Z,1591812451.707 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-06-10T18:07:31.707Z,1591812451.707 [Default:CheckIn:C.Wait] Stopped
2020-06-10T18:07:31.707Z,1591812451.707 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-06-10T18:07:31.707Z,1591812451.707 [Default:CheckIn:D] Running Loop=1
2020-06-10T18:07:32.118Z,1591812452.118 [Default:CheckIn:D] Stopped
2020-06-10T18:07:32.118Z,1591812452.118 [Default:CheckIn:E] Running Loop=1
2020-06-10T18:07:32.516Z,1591812452.516 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 44.578589 min 
2020-06-10T18:07:32.516Z,1591812452.516 [Default:CheckIn:E] Stopped
2020-06-10T18:07:32.516Z,1591812452.516 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-06-10T18:07:32.516Z,1591812452.516 [Default:CheckIn] Stopped
2020-06-10T18:07:32.516Z,1591812452.516 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-06-10T18:07:32.516Z,1591812452.516 [Default:CheckIn](INFO): Running loop #8
2020-06-10T18:07:32.517Z,1591812452.517 [Default:CheckIn] Running Loop=8
2020-06-10T18:07:32.517Z,1591812452.517 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-06-10T18:07:32.517Z,1591812452.517 [Default:CheckIn:Read_GPS] Running Loop=1
2020-06-10T18:07:34.528Z,1591812454.528 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,180733.00,A,3648.31384,N,12147.11711,W,5.093,7.27,100620,,,D*7D
2020-06-10T18:07:34.530Z,1591812454.530 [NAL9602](INFO): GPS fix at 20200610T180733: (36.805231, -121.785285)
2020-06-10T18:07:34.540Z,1591812454.540 [Default:CheckIn:Read_GPS] Stopped
2020-06-10T18:07:34.540Z,1591812454.540 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-06-10T18:07:41.412Z,1591812461.412 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20200610T171911/Courier0031.lzma
2020-06-10T18:07:42.415Z,1591812462.415 [DataOverHttps](INFO): Moved sent file to Logs/20200610T171911/Courier0031.lzma.bak
2020-06-10T18:07:42.415Z,1591812462.415 [DataOverHttps](INFO): SBD MOMSN=12377700
2020-06-10T18:07:58.097Z,1591812478.097 [DataOverHttps](INFO): Sending 136 bytes from file Logs/20200610T171911/Express0032.lzma
2020-06-10T18:07:59.099Z,1591812479.099 [DataOverHttps](INFO): Moved sent file to Logs/20200610T171911/Express0032.lzma.bak
2020-06-10T18:07:59.099Z,1591812479.099 [DataOverHttps](INFO): SBD MOMSN=12377703
2020-06-10T18:08:00.379Z,1591812480.379 [NAL9602](INFO): SBD MO Status=2, MOMSN=20345, MT Status=2, MTMSN=0
2020-06-10T18:08:00.379Z,1591812480.379 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-06-10T18:08:00.418Z,1591812480.418 [Default:CheckIn:Read_Iridium] Stopped
2020-06-10T18:08:00.418Z,1591812480.418 [Default:CheckIn:C.Wait] Running Loop=1
2020-06-10T18:08:00.419Z,1591812480.419 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-06-10T18:09:19.971Z,1591812559.971 [NAL9602](INFO): SBD MO Status=2, MOMSN=20345, MT Status=2, MTMSN=0
2020-06-10T18:09:19.971Z,1591812559.971 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-06-10T18:09:47.030Z,1591812587.030 [NAL9602](INFO): SBD MO Status=0, MOMSN=20345, MT Status=0, MTMSN=0
2020-06-10T18:09:47.030Z,1591812587.030 [NAL9602](INFO): No messages in MT queue
2020-06-10T18:10:17.762Z,1591812617.762 [NAL9602](INFO): Not Powering down - fast GPS
2020-06-10T18:13:01.050Z,1591812781.050 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-06-10T18:13:01.050Z,1591812781.050 [Default:CheckIn:C.Wait] Stopped
2020-06-10T18:13:01.050Z,1591812781.050 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-06-10T18:13:01.050Z,1591812781.050 [Default:CheckIn:D] Running Loop=1
2020-06-10T18:13:01.452Z,1591812781.452 [Default:CheckIn:D] Stopped
2020-06-10T18:13:01.453Z,1591812781.453 [Default:CheckIn:E] Running Loop=1
2020-06-10T18:13:01.856Z,1591812781.856 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 50.067493 min 
2020-06-10T18:13:01.856Z,1591812781.856 [Default:CheckIn:E] Stopped
2020-06-10T18:13:01.856Z,1591812781.856 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-06-10T18:13:01.856Z,1591812781.856 [Default:CheckIn] Stopped
2020-06-10T18:13:01.856Z,1591812781.856 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-06-10T18:13:01.856Z,1591812781.856 [Default:CheckIn](INFO): Running loop #9
2020-06-10T18:13:01.856Z,1591812781.856 [Default:CheckIn] Running Loop=9
2020-06-10T18:13:01.856Z,1591812781.856 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-06-10T18:13:01.857Z,1591812781.857 [Default:CheckIn:Read_GPS] Running Loop=1
2020-06-10T18:13:03.868Z,1591812783.868 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181302.00,A,3648.35035,N,12147.78131,W,14.909,277.14,100620,,,D*43
2020-06-10T18:13:03.870Z,1591812783.870 [NAL9602](INFO): GPS fix at 20200610T181302: (36.805839, -121.796355)
2020-06-10T18:13:03.880Z,1591812783.880 [Default:CheckIn:Read_GPS] Stopped
2020-06-10T18:13:03.880Z,1591812783.880 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-06-10T18:13:11.564Z,1591812791.564 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20200610T171911/Courier0034.lzma
2020-06-10T18:13:12.567Z,1591812792.567 [DataOverHttps](INFO): Moved sent file to Logs/20200610T171911/Courier0034.lzma.bak
2020-06-10T18:13:12.567Z,1591812792.567 [DataOverHttps](INFO): SBD MOMSN=12377708
2020-06-10T18:13:28.485Z,1591812808.485 [DataOverHttps](INFO): Sending 135 bytes from file Logs/20200610T171911/Express0035.lzma
2020-06-10T18:13:29.487Z,1591812809.487 [DataOverHttps](INFO): Moved sent file to Logs/20200610T171911/Express0035.lzma.bak
2020-06-10T18:13:29.487Z,1591812809.487 [DataOverHttps](INFO): SBD MOMSN=12377711
2020-06-10T18:13:30.540Z,1591812810.540 [Default:CheckIn:Read_Iridium] Stopped
2020-06-10T18:13:30.540Z,1591812810.540 [Default:CheckIn:C.Wait] Running Loop=1
2020-06-10T18:13:30.540Z,1591812810.540 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-06-10T18:13:39.423Z,1591812819.423 [NAL9602](INFO): SBD MO Status=2, MOMSN=20346, MT Status=2, MTMSN=0
2020-06-10T18:13:39.424Z,1591812819.424 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-06-10T18:13:56.791Z,1591812836.791 [NAL9602](INFO): SBD MO Status=2, MOMSN=20346, MT Status=2, MTMSN=0
2020-06-10T18:13:56.792Z,1591812836.792 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-06-10T18:14:22.641Z,1591812862.641 [NAL9602](INFO): SBD MO Status=2, MOMSN=20346, MT Status=2, MTMSN=0
2020-06-10T18:14:22.642Z,1591812862.642 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-06-10T18:15:26.474Z,1591812926.474 [NAL9602](INFO): SBD MO Status=2, MOMSN=20346, MT Status=2, MTMSN=0
2020-06-10T18:15:26.474Z,1591812926.474 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-06-10T18:15:47.087Z,1591812947.087 [NAL9602](INFO): SBD MO Status=2, MOMSN=20346, MT Status=2, MTMSN=0
2020-06-10T18:15:47.087Z,1591812947.087 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-06-10T18:16:21.431Z,1591812981.431 [NAL9602](INFO): SBD MO Status=2, MOMSN=20346, MT Status=2, MTMSN=0
2020-06-10T18:16:21.432Z,1591812981.432 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-06-10T18:16:39.608Z,1591812999.608 [NAL9602](INFO): SBD MO Status=2, MOMSN=20346, MT Status=2, MTMSN=0
2020-06-10T18:16:39.608Z,1591812999.608 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-06-10T18:17:07.483Z,1591813027.483 [NAL9602](INFO): SBD MO Status=2, MOMSN=20346, MT Status=2, MTMSN=0
2020-06-10T18:17:07.484Z,1591813027.484 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-06-10T18:17:24.047Z,1591813044.047 [NAL9602](INFO): SBD MO Status=2, MOMSN=20346, MT Status=2, MTMSN=0
2020-06-10T18:17:24.047Z,1591813044.047 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-06-10T18:17:44.657Z,1591813064.657 [NAL9602](INFO): SBD MO Status=2, MOMSN=20346, MT Status=2, MTMSN=0
2020-06-10T18:17:44.657Z,1591813064.657 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-06-10T18:18:04.857Z,1591813084.857 [NAL9602](INFO): SBD MO Status=0, MOMSN=20346, MT Status=0, MTMSN=0
2020-06-10T18:18:04.858Z,1591813084.858 [NAL9602](INFO): No messages in MT queue
2020-06-10T18:18:31.147Z,1591813111.147 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-06-10T18:18:31.147Z,1591813111.147 [Default:CheckIn:C.Wait] Stopped
2020-06-10T18:18:31.147Z,1591813111.147 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-06-10T18:18:31.147Z,1591813111.147 [Default:CheckIn:D] Running Loop=1
2020-06-10T18:18:31.547Z,1591813111.547 [Default:CheckIn:D] Stopped
2020-06-10T18:18:31.547Z,1591813111.547 [Default:CheckIn:E] Running Loop=1
2020-06-10T18:18:31.947Z,1591813111.947 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 55.569076 min 
2020-06-10T18:18:31.947Z,1591813111.947 [Default:CheckIn:E] Stopped
2020-06-10T18:18:31.947Z,1591813111.947 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-06-10T18:18:31.947Z,1591813111.947 [Default:CheckIn] Stopped
2020-06-10T18:18:31.947Z,1591813111.947 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-06-10T18:18:31.947Z,1591813111.947 [Default:CheckIn](INFO): Running loop #10
2020-06-10T18:18:31.947Z,1591813111.947 [Default:CheckIn] Running Loop=10
2020-06-10T18:18:31.947Z,1591813111.947 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-06-10T18:18:31.947Z,1591813111.947 [Default:CheckIn:Read_GPS] Running Loop=1
2020-06-10T18:18:33.964Z,1591813113.964 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,181833.00,A,3648.34387,N,12149.22390,W,14.909,263.84,100620,,,A*40
2020-06-10T18:18:33.966Z,1591813113.966 [NAL9602](INFO): GPS fix at 20200610T181833: (36.805731, -121.820398)
2020-06-10T18:18:33.976Z,1591813113.976 [Default:CheckIn:Read_GPS] Stopped
2020-06-10T18:18:33.976Z,1591813113.976 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-06-10T18:18:40.948Z,1591813120.948 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20200610T171911/Courier0037.lzma
2020-06-10T18:18:41.951Z,1591813121.951 [DataOverHttps](INFO): Moved sent file to Logs/20200610T171911/Courier0037.lzma.bak
2020-06-10T18:18:41.951Z,1591813121.951 [DataOverHttps](INFO): SBD MOMSN=12377714
2020-06-10T18:18:57.553Z,1591813137.553 [DataOverHttps](INFO): Sending 132 bytes from file Logs/20200610T171911/Express0038.lzma
2020-06-10T18:18:58.555Z,1591813138.555 [DataOverHttps](INFO): Moved sent file to Logs/20200610T171911/Express0038.lzma.bak
2020-06-10T18:18:58.555Z,1591813138.555 [DataOverHttps](INFO): SBD MOMSN=12377717
2020-06-10T18:18:59.842Z,1591813139.842 [Default:CheckIn:Read_Iridium] Stopped
2020-06-10T18:18:59.842Z,1591813139.842 [Default:CheckIn:C.Wait] Running Loop=1
2020-06-10T18:18:59.842Z,1591813139.842 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-06-10T18:19:06.688Z,1591813146.688 [NAL9602](INFO): Not Powering down - fast GPS
2020-06-10T18:21:08.439Z,1591813268.439 [DataOverHttps](IMPORTANT): SBD MTMSN=20200610T182107
2020-06-10T18:21:15.696Z,1591813275.696 [DataOverHttps](INFO): Received command:restart logs