2020-07-14T21:41:20.579Z,1594762880.579 [Supervisor](DEBUG): Initializing supervisor.
2020-07-14T21:41:20.582Z,1594762880.582 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2020-07-14T21:41:20.582Z,1594762880.582 [SyncHandler](INFO): Protected caller Thread ID is 952
2020-07-14T21:41:20.583Z,1594762880.583 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2020-07-14T21:41:20.584Z,1594762880.584 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2020-07-14T21:41:20.584Z,1594762880.584 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 953
2020-07-14T21:41:20.587Z,1594762880.587 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2020-07-14T21:41:20.600Z,1594762880.600 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2020-07-14T21:41:20.601Z,1594762880.601 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2020-07-14T21:41:20.602Z,1594762880.602 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 954
2020-07-14T21:41:20.602Z,1594762880.602 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2020-07-14T21:41:20.603Z,1594762880.603 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2020-07-14T21:41:20.604Z,1594762880.604 [logger ThreadHandler](INFO): Protected caller Thread ID is 955
2020-07-14T21:41:20.606Z,1594762880.606 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2020-07-14T21:41:20.606Z,1594762880.606 [Supervisor](INFO): Looking for Config files in directory: Config/
2020-07-14T21:41:20.608Z,1594762880.608 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2020-07-14T21:41:20.915Z,1594762880.915 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2020-07-14T21:41:20.916Z,1594762880.916 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2020-07-14T21:41:21.503Z,1594762881.503 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2020-07-14T21:41:21.504Z,1594762881.504 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2020-07-14T21:41:21.642Z,1594762881.642 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2020-07-14T21:41:21.642Z,1594762881.642 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2020-07-14T21:41:22.101Z,1594762882.101 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2020-07-14T21:41:22.102Z,1594762882.102 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2020-07-14T21:41:22.197Z,1594762882.197 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2020-07-14T21:41:22.197Z,1594762882.197 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2020-07-14T21:41:22.276Z,1594762882.276 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2020-07-14T21:41:22.570Z,1594762882.570 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2020-07-14T21:41:22.571Z,1594762882.571 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2020-07-14T21:41:22.715Z,1594762882.715 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2020-07-14T21:41:22.715Z,1594762882.715 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2020-07-14T21:41:22.817Z,1594762882.817 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2020-07-14T21:41:22.818Z,1594762882.818 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2020-07-14T21:41:23.015Z,1594762883.015 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2020-07-14T21:41:23.016Z,1594762883.016 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2020-07-14T21:41:23.497Z,1594762883.497 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2020-07-14T21:41:23.498Z,1594762883.498 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2020-07-14T21:41:24.310Z,1594762884.310 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2020-07-14T21:41:24.311Z,1594762884.311 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2020-07-14T21:41:24.411Z,1594762884.411 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2020-07-14T21:41:24.411Z,1594762884.411 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2020-07-14T21:41:24.600Z,1594762884.600 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2020-07-14T21:41:24.601Z,1594762884.601 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2020-07-14T21:41:24.804Z,1594762884.804 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2020-07-14T21:41:24.805Z,1594762884.805 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2020-07-14T21:41:25.027Z,1594762885.027 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2020-07-14T21:41:25.029Z,1594762885.029 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-brizo/
2020-07-14T21:41:25.030Z,1594762885.030 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Control.cfg
2020-07-14T21:41:25.122Z,1594762885.122 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Sensor.cfg
2020-07-14T21:41:25.261Z,1594762885.261 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Simulator.cfg
2020-07-14T21:41:25.344Z,1594762885.344 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/secure.cfg
2020-07-14T21:41:25.426Z,1594762885.426 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Servo.cfg
2020-07-14T21:41:25.530Z,1594762885.530 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/vehicle.cfg
2020-07-14T21:41:25.712Z,1594762885.712 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Battery.cfg
2020-07-14T21:41:25.937Z,1594762885.937 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2020-07-14T21:41:25.937Z,1594762885.937 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Science.cfg
2020-07-14T21:41:26.047Z,1594762886.047 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/logger.cfg
2020-07-14T21:41:26.140Z,1594762886.140 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/BIT.cfg
2020-07-14T21:41:26.236Z,1594762886.236 [Supervisor](INFO): Opening Config file at: Config/lrauv-brizo/Navigation.cfg
2020-07-14T21:41:26.329Z,1594762886.329 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-brizo/root/
2020-07-14T21:41:26.330Z,1594762886.330 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2020-07-14T21:41:26.339Z,1594762886.339 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2020-07-14T21:41:26.413Z,1594762886.413 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2020-07-14T21:41:26.414Z,1594762886.414 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2020-07-14T21:41:26.432Z,1594762886.432 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2020-07-14T21:41:26.433Z,1594762886.433 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2020-07-14T21:41:26.473Z,1594762886.473 [DepthRateCalculator] Loaded
2020-07-14T21:41:26.473Z,1594762886.473 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2020-07-14T21:41:26.479Z,1594762886.479 [PitchRateCalculator] Loaded
2020-07-14T21:41:26.479Z,1594762886.479 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2020-07-14T21:41:26.494Z,1594762886.494 [SpeedCalculator] Loaded
2020-07-14T21:41:26.494Z,1594762886.494 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2020-07-14T21:41:26.516Z,1594762886.516 [TempGradientCalculator] Loaded
2020-07-14T21:41:26.516Z,1594762886.516 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2020-07-14T21:41:26.522Z,1594762886.522 [YawRateCalculator] Loaded
2020-07-14T21:41:26.522Z,1594762886.522 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2020-07-14T21:41:26.561Z,1594762886.561 [ElevatorOffsetCalculator] Loaded
2020-07-14T21:41:26.561Z,1594762886.561 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2020-07-14T21:41:26.562Z,1594762886.562 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2020-07-14T21:41:26.562Z,1594762886.562 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2020-07-14T21:41:26.609Z,1594762886.609 [VerticalControl](DEBUG): Construct VerticalControl.
2020-07-14T21:41:26.706Z,1594762886.706 [VerticalControl] Loaded
2020-07-14T21:41:26.706Z,1594762886.706 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2020-07-14T21:41:26.707Z,1594762886.707 [HorizontalControl](DEBUG): Construct HorizontalControl.
2020-07-14T21:41:26.786Z,1594762886.786 [HorizontalControl] Loaded
2020-07-14T21:41:26.787Z,1594762886.787 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2020-07-14T21:41:26.787Z,1594762886.787 [SpeedControl](DEBUG): Construct SpeedControl.
2020-07-14T21:41:26.792Z,1594762886.792 [SpeedControl] Loaded
2020-07-14T21:41:26.792Z,1594762886.792 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2020-07-14T21:41:26.793Z,1594762886.793 [LoopControl](DEBUG): Construct LoopControl.
2020-07-14T21:41:26.793Z,1594762886.793 [LoopControl] Loaded
2020-07-14T21:41:26.794Z,1594762886.794 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2020-07-14T21:41:26.794Z,1594762886.794 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2020-07-14T21:41:26.795Z,1594762886.795 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2020-07-14T21:41:26.908Z,1594762886.908 [DeadReckonUsingMultipleVelocitySources] Loaded
2020-07-14T21:41:26.908Z,1594762886.908 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2020-07-14T21:41:26.929Z,1594762886.929 [NavChart] Loaded
2020-07-14T21:41:26.929Z,1594762886.929 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2020-07-14T21:41:26.933Z,1594762886.933 [UniversalFixResidualReporter] Loaded
2020-07-14T21:41:26.933Z,1594762886.933 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2020-07-14T21:41:26.934Z,1594762886.934 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2020-07-14T21:41:26.934Z,1594762886.934 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2020-07-14T21:41:27.032Z,1594762887.032 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2020-07-14T21:41:27.033Z,1594762887.033 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2020-07-14T21:41:27.336Z,1594762887.336 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_orientation
2020-07-14T21:41:27.340Z,1594762887.340 [AHRS_M2](INFO): created writer for : platform_orientation
2020-07-14T21:41:27.342Z,1594762887.342 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_magnetic_orientation
2020-07-14T21:41:27.347Z,1594762887.347 [AHRS_M2](INFO): created writer for : platform_magnetic_orientation
2020-07-14T21:41:27.348Z,1594762887.348 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_pitch_angle
2020-07-14T21:41:27.353Z,1594762887.353 [AHRS_M2](INFO): created writer for : platform_pitch_angle
2020-07-14T21:41:27.353Z,1594762887.353 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_roll_angle
2020-07-14T21:41:27.358Z,1594762887.358 [AHRS_M2](INFO): created writer for : platform_roll_angle
2020-07-14T21:41:27.428Z,1594762887.428 [AHRS_M2] Loaded
2020-07-14T21:41:27.429Z,1594762887.429 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2020-07-14T21:41:27.507Z,1594762887.507 [DataOverHttps] Loaded
2020-07-14T21:41:27.507Z,1594762887.507 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2020-07-14T21:41:27.508Z,1594762887.508 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 408544E0
2020-07-14T21:41:27.509Z,1594762887.509 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 1037
2020-07-14T21:41:27.522Z,1594762887.522 [Depth_Keller] Loaded
2020-07-14T21:41:27.522Z,1594762887.522 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2020-07-14T21:41:27.617Z,1594762887.617 [NAL9602] Loaded
2020-07-14T21:41:27.617Z,1594762887.617 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2020-07-14T21:41:27.656Z,1594762887.656 [Onboard] Loaded
2020-07-14T21:41:27.656Z,1594762887.656 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2020-07-14T21:41:27.659Z,1594762887.659 [Radio_Surface] Loaded
2020-07-14T21:41:27.660Z,1594762887.660 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2020-07-14T21:41:27.661Z,1594762887.661 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 408844E0
2020-07-14T21:41:27.661Z,1594762887.661 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 1038
2020-07-14T21:41:29.124Z,1594762889.124 [BPC1] Loaded
2020-07-14T21:41:29.124Z,1594762889.124 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2020-07-14T21:41:29.125Z,1594762889.125 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2020-07-14T21:41:29.125Z,1594762889.125 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2020-07-14T21:41:29.551Z,1594762889.551 [BuoyancyServo] Loaded
2020-07-14T21:41:29.552Z,1594762889.552 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2020-07-14T21:41:29.571Z,1594762889.571 [ElevatorServo] Loaded
2020-07-14T21:41:29.571Z,1594762889.571 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2020-07-14T21:41:29.626Z,1594762889.626 [MassServo] Loaded
2020-07-14T21:41:29.626Z,1594762889.626 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2020-07-14T21:41:29.699Z,1594762889.699 [RudderServo] Loaded
2020-07-14T21:41:29.699Z,1594762889.699 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2020-07-14T21:41:29.742Z,1594762889.742 [ThrusterServo] Loaded
2020-07-14T21:41:29.742Z,1594762889.742 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2020-07-14T21:41:29.743Z,1594762889.743 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2020-07-14T21:41:29.743Z,1594762889.743 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2020-07-14T21:41:30.016Z,1594762890.016 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2020-07-14T21:41:30.017Z,1594762890.017 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2020-07-14T21:41:30.139Z,1594762890.139 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2020-07-14T21:41:30.139Z,1594762890.139 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2020-07-14T21:41:30.420Z,1594762890.420 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2020-07-14T21:41:30.420Z,1594762890.420 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2020-07-14T21:41:30.602Z,1594762890.602 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_density
2020-07-14T21:41:30.607Z,1594762890.607 [CTD_Seabird](INFO): created writer for : sea_water_density
2020-07-14T21:41:30.608Z,1594762890.608 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): depth
2020-07-14T21:41:30.612Z,1594762890.612 [CTD_Seabird](INFO): created writer for : depth
2020-07-14T21:41:30.613Z,1594762890.613 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_pressure
2020-07-14T21:41:30.618Z,1594762890.618 [CTD_Seabird](INFO): created writer for : sea_water_pressure
2020-07-14T21:41:30.618Z,1594762890.618 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_salinity
2020-07-14T21:41:30.624Z,1594762890.624 [CTD_Seabird](INFO): created writer for : sea_water_salinity
2020-07-14T21:41:30.624Z,1594762890.624 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_temperature
2020-07-14T21:41:30.629Z,1594762890.629 [CTD_Seabird](INFO): created writer for : sea_water_temperature
2020-07-14T21:41:30.630Z,1594762890.630 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_electrical_conductivity
2020-07-14T21:41:30.635Z,1594762890.635 [CTD_Seabird](INFO): created writer for : sea_water_electrical_conductivity
2020-07-14T21:41:30.636Z,1594762890.636 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): speed_of_sound_in_sea_water
2020-07-14T21:41:30.641Z,1594762890.641 [CTD_Seabird](INFO): created writer for : speed_of_sound_in_sea_water
2020-07-14T21:41:30.667Z,1594762890.667 [CTD_Seabird] Loaded
2020-07-14T21:41:30.667Z,1594762890.667 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2020-07-14T21:41:30.668Z,1594762890.668 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 40A904E0
2020-07-14T21:41:30.669Z,1594762890.669 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 1039
2020-07-14T21:41:30.699Z,1594762890.699 [ESPComponent] Loaded
2020-07-14T21:41:30.700Z,1594762890.700 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread.
2020-07-14T21:41:30.714Z,1594762890.714 [PAR_Licor] Loaded
2020-07-14T21:41:30.714Z,1594762890.714 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2020-07-14T21:41:30.720Z,1594762890.720 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.Output470
2020-07-14T21:41:30.720Z,1594762890.720 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: Output470
2020-07-14T21:41:30.724Z,1594762890.724 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.Output650
2020-07-14T21:41:30.725Z,1594762890.725 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: Output650
2020-07-14T21:41:30.729Z,1594762890.729 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.OutputChl
2020-07-14T21:41:30.729Z,1594762890.729 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: OutputChl
2020-07-14T21:41:30.733Z,1594762890.733 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.VolumeScatCoeff117deg470nm
2020-07-14T21:41:30.733Z,1594762890.733 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: VolumeScatCoeff117deg470nm
2020-07-14T21:41:30.737Z,1594762890.737 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.VolumeScatCoeff117deg650nm
2020-07-14T21:41:30.737Z,1594762890.737 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: VolumeScatCoeff117deg650nm
2020-07-14T21:41:30.742Z,1594762890.742 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.BackscatteringCoeff470nm
2020-07-14T21:41:30.742Z,1594762890.742 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: BackscatteringCoeff470nm
2020-07-14T21:41:30.746Z,1594762890.746 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.BackscatteringCoeff650nm
2020-07-14T21:41:30.746Z,1594762890.746 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: BackscatteringCoeff650nm
2020-07-14T21:41:30.750Z,1594762890.750 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): mass_concentration_of_chlorophyll_in_sea_water
2020-07-14T21:41:30.754Z,1594762890.754 [WetLabsBB2FL](INFO): created writer for : mass_concentration_of_chlorophyll_in_sea_water
2020-07-14T21:41:30.755Z,1594762890.755 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_median_mass_concentration_of_chlorophyll_in_sea_water
2020-07-14T21:41:30.755Z,1594762890.755 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_median_mass_concentration_of_chlorophyll_in_sea_water
2020-07-14T21:41:30.759Z,1594762890.759 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_mean_mass_concentration_of_chlorophyll_in_sea_water
2020-07-14T21:41:30.760Z,1594762890.760 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_mean_mass_concentration_of_chlorophyll_in_sea_water
2020-07-14T21:41:30.764Z,1594762890.764 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_variance_mass_concentration_of_chlorophyll_in_sea_water
2020-07-14T21:41:30.764Z,1594762890.764 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_variance_mass_concentration_of_chlorophyll_in_sea_water
2020-07-14T21:41:30.768Z,1594762890.768 [WetLabsBB2FL] Loaded
2020-07-14T21:41:30.768Z,1594762890.768 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2020-07-14T21:41:30.770Z,1594762890.770 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40AC04E0
2020-07-14T21:41:30.770Z,1594762890.770 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 1040
2020-07-14T21:41:30.771Z,1594762890.771 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2020-07-14T21:41:30.771Z,1594762890.771 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2020-07-14T21:41:30.903Z,1594762890.903 [SBIT](DEBUG): Construct Startup Built In Test.
2020-07-14T21:41:30.915Z,1594762890.915 [SBIT] Loaded
2020-07-14T21:41:30.915Z,1594762890.915 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2020-07-14T21:41:30.916Z,1594762890.916 [IBIT](DEBUG): Construct Initiated Built In Test.
2020-07-14T21:41:30.928Z,1594762890.928 [IBIT] Loaded
2020-07-14T21:41:30.928Z,1594762890.928 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2020-07-14T21:41:30.931Z,1594762890.931 [CBIT](DEBUG): Construct Continuous Built In Test.
2020-07-14T21:41:31.069Z,1594762891.069 [CBIT] Loaded
2020-07-14T21:41:31.069Z,1594762891.069 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2020-07-14T21:41:31.070Z,1594762891.070 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2020-07-14T21:41:31.073Z,1594762891.073 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2020-07-14T21:41:31.074Z,1594762891.074 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2020-07-14T21:41:31.081Z,1594762891.081 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2020-07-14T21:41:31.082Z,1594762891.082 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40B2B4E0
2020-07-14T21:41:31.082Z,1594762891.082 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 1041
2020-07-14T21:41:31.087Z,1594762891.087 [Supervisor](INFO): Main Thread ID is 815
2020-07-14T21:41:31.087Z,1594762891.087 [Supervisor](DEBUG): Running supervisor.
2020-07-14T21:41:31.087Z,1594762891.087 [CommandLine ThreadHandler](INFO): Handler Thread ID is 1042
2020-07-14T21:41:31.090Z,1594762891.090 [controlThread ThreadHandler](INFO): Handler Thread ID is 1043
2020-07-14T21:41:31.090Z,1594762891.090 [controlThread](DEBUG): Initializing ControlThread
2020-07-14T21:41:31.091Z,1594762891.091 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2020-07-14T21:41:31.091Z,1594762891.091 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2020-07-14T21:41:31.092Z,1594762891.092 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2020-07-14T21:41:31.092Z,1594762891.092 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2020-07-14T21:41:31.093Z,1594762891.093 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2020-07-14T21:41:31.093Z,1594762891.093 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2020-07-14T21:41:31.094Z,1594762891.094 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2020-07-14T21:41:31.095Z,1594762891.095 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2020-07-14T21:41:31.096Z,1594762891.096 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2020-07-14T21:41:31.096Z,1594762891.096 [LoopControl](DEBUG): Initialize LoopControlComponent.
2020-07-14T21:41:31.097Z,1594762891.097 [NavChart](DEBUG): Initialize NavChart Navigation.
2020-07-14T21:41:31.098Z,1594762891.098 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2020-07-14T21:41:31.106Z,1594762891.106 [SBIT](INFO): Initialize SBIT Component.
2020-07-14T21:41:31.106Z,1594762891.106 [SBIT](IMPORTANT): git: 2020-06-09
2020-07-14T21:41:31.107Z,1594762891.107 [SBIT](INFO): git hash: 492c82351796d8646f9bb5d9c938bbc9efa48549
2020-07-14T21:41:31.107Z,1594762891.107 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2020-07-14T21:41:31.107Z,1594762891.107 [SBIT](IMPORTANT): Kernel Version:#1 PREEMPT Tue Sep 24 11:12:27 PDT 2019
2020-07-14T21:41:31.108Z,1594762891.108 [SBIT](INFO): Beginning SBIT in 54.000000 seconds.
2020-07-14T21:41:31.109Z,1594762891.109 [IBIT](INFO): Initialize IBIT Component.
2020-07-14T21:41:31.109Z,1594762891.109 [CBIT](DEBUG): Initialize CBIT Component.
2020-07-14T21:41:31.111Z,1594762891.111 [logger ThreadHandler](INFO): Handler Thread ID is 1044
2020-07-14T21:41:31.122Z,1594762891.122 [CBIT](DEBUG): Initialized mux pins.
2020-07-14T21:41:31.122Z,1594762891.122 [CBIT](DEBUG): Initializing the watchdog timer.
2020-07-14T21:41:31.130Z,1594762891.130 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 1045
2020-07-14T21:41:31.131Z,1594762891.131 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2020-07-14T21:41:31.142Z,1594762891.142 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 1046
2020-07-14T21:41:31.146Z,1594762891.146 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2020-07-14T21:41:31.146Z,1594762891.146 [CBIT](DEBUG): Initializing heartbeat.
2020-07-14T21:41:31.154Z,1594762891.154 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 1047
2020-07-14T21:41:31.155Z,1594762891.155 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2020-07-14T21:41:31.159Z,1594762891.159 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 1049
2020-07-14T21:41:31.160Z,1594762891.160 [WetLabsBB2FL](INFO): Powering down
2020-07-14T21:41:31.194Z,1594762891.194 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 1050
2020-07-14T21:41:31.197Z,1594762891.197 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2020-07-14T21:41:31.198Z,1594762891.198 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2020-07-14T21:41:31.198Z,1594762891.198 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2020-07-14T21:41:31.198Z,1594762891.198 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2020-07-14T21:41:31.198Z,1594762891.198 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2020-07-14T21:41:31.198Z,1594762891.198 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2020-07-14T21:41:31.199Z,1594762891.199 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2020-07-14T21:41:31.199Z,1594762891.199 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2020-07-14T21:41:31.199Z,1594762891.199 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2020-07-14T21:41:31.199Z,1594762891.199 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2020-07-14T21:41:31.199Z,1594762891.199 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2020-07-14T21:41:31.199Z,1594762891.199 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2020-07-14T21:41:31.200Z,1594762891.200 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2020-07-14T21:41:31.200Z,1594762891.200 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2020-07-14T21:41:31.200Z,1594762891.200 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2020-07-14T21:41:31.200Z,1594762891.200 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2020-07-14T21:41:31.218Z,1594762891.218 [CBIT](DEBUG): Deactivating GF circuits.
2020-07-14T21:41:31.218Z,1594762891.218 [CBIT](DEBUG): Deactivating emergency mode.
2020-07-14T21:41:31.254Z,1594762891.254 [CBIT](DEBUG): Backplane powered.
2020-07-14T21:41:31.255Z,1594762891.255 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2020-07-14T21:41:31.264Z,1594762891.264 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2020-07-14T21:41:31.275Z,1594762891.275 [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-07-14T21:41:31.275Z,1594762891.275 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2020-07-14T21:41:31.350Z,1594762891.350 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2020-07-14T21:41:31.351Z,1594762891.351 [Default:A.Wait](DEBUG): Construct Wait.
2020-07-14T21:41:31.352Z,1594762891.352 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2020-07-14T21:41:31.397Z,1594762891.397 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2020-07-14T21:41:31.417Z,1594762891.417 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2020-07-14T21:41:31.442Z,1594762891.442 [Default:E.Execute](DEBUG): Construct Execute.
2020-07-14T21:41:31.446Z,1594762891.446 [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-07-14T21:41:31.457Z,1594762891.457 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,Depth_Keller,NAL9602,Onboard,BPC1,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,
2020-07-14T21:41:31.483Z,1594762891.483 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2020-07-14T21:41:31.546Z,1594762891.546 [Radio_Surface](INFO): Powering up
2020-07-14T21:41:31.649Z,1594762891.649 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2020-07-14T21:41:31.658Z,1594762891.658 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2020-07-14T21:41:31.659Z,1594762891.659 [ElevatorServo](DEBUG): Initializing EZServoServo.
2020-07-14T21:41:31.666Z,1594762891.666 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2020-07-14T21:41:31.667Z,1594762891.667 [MassServo](DEBUG): Initializing EZServoServo.
2020-07-14T21:41:31.674Z,1594762891.674 [MassServo](DEBUG): Initializing MassServo.
2020-07-14T21:41:31.675Z,1594762891.675 [RudderServo](DEBUG): Initializing EZServoServo.
2020-07-14T21:41:31.682Z,1594762891.682 [RudderServo](DEBUG): Initializing RudderServo.
2020-07-14T21:41:31.683Z,1594762891.683 [ThrusterServo](DEBUG): Initializing EZServoServo.
2020-07-14T21:41:31.690Z,1594762891.690 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2020-07-14T21:41:32.626Z,1594762892.626 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2020-07-14T21:41:32.626Z,1594762892.626 [RudderServo](FAULT): Rudder failed to initialize
2020-07-14T21:41:32.626Z,1594762892.626 [RudderServo] Communications Fault, FailCount= 1
2020-07-14T21:41:32.626Z,1594762892.626 [RudderServo](ERROR): Communications Fault
2020-07-14T21:41:32.737Z,1594762892.737 [CBIT](ERROR): Communications Fault in component: RudderServo
2020-07-14T21:41:32.943Z,1594762892.943 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2020-07-14T21:41:32.943Z,1594762892.943 [RudderServo](INFO): Powering down
2020-07-14T21:41:33.586Z,1594762893.586 [RudderServo](DEBUG): Initializing EZServoServo.
2020-07-14T21:41:33.707Z,1594762893.707 [RudderServo](DEBUG): Initializing RudderServo.
2020-07-14T21:41:33.711Z,1594762893.711 [CBIT](INFO): Clearing failed state for component RudderServo
2020-07-14T21:41:33.711Z,1594762893.711 [RudderServo] No Fault, FailCount= 1
2020-07-14T21:41:57.799Z,1594762917.799 [NAL9602](INFO): Powering up NAL9602
2020-07-14T21:42:08.707Z,1594762928.707 [NAL9602](INFO): NAL9602 initialized
2020-07-14T21:42:25.714Z,1594762945.714 [SBIT](IMPORTANT): Beginning Startup BIT
2020-07-14T21:42:25.718Z,1594762945.718 [CBIT](IMPORTANT): Beginning ground fault scan
2020-07-14T21:42:36.791Z,1594762956.791 [CBIT](IMPORTANT): Ground fault detected
mA:
CHAN A0 (Batt): 0.003837
CHAN A1 (24V): -0.168348
CHAN A2 (12V): -0.000422
CHAN A3 (5V): 0.000013
CHAN B0 (3.3V): -0.000116
CHAN B1 (3.15aV): 0.000175
CHAN B2 (3.15bV): 0.000494
CHAN B3 (GND): 0.001203
OPEN: 0.003587
Full Scale Calc: 4.765 mA, -1.589 mA
2020-07-14T21:43:06.187Z,1594762986.187 [CommandLine](IMPORTANT): got command failComponent
2020-07-14T21:43:06.188Z,1594762986.188 [CommandLine](IMPORTANT): Failed components:
2020-07-14T21:43:06.188Z,1594762986.188 [CommandLine](IMPORTANT): No failed Components.
2020-07-14T21:43:10.048Z,1594762990.048 [CommandLine](IMPORTANT): got command show stack
2020-07-14T21:43:10.048Z,1594762990.048 [CommandLine](IMPORTANT): Behavior Stack:

2020-07-14T21:43:10.048Z,1594762990.048 [MissionManager](IMPORTANT): Mission loaded, but not running.
2020-07-14T21:43:19.000Z,1594762999.000 [SBIT](IMPORTANT): SBIT PASSED
2020-07-14T21:43:19.001Z,1594762999.001 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2020-07-14T21:43:19.001Z,1594762999.001 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=2 count;

2020-07-14T21:43:19.029Z,1594762999.029 [SBIT](IMPORTANT): DAT.loadAtStartup=0 bool;

2020-07-14T21:43:19.030Z,1594762999.030 [SBIT](IMPORTANT): DVL_micro.loadAtStartup=0 bool;

2020-07-14T21:43:19.031Z,1594762999.031 [SBIT](IMPORTANT): DropWeight.loadAtStartup=0 bool;

2020-07-14T21:43:19.031Z,1594762999.031 [SBIT](IMPORTANT): ESPComponent.loadAtStartup=1 bool;

2020-07-14T21:43:19.031Z,1594762999.031 [SBIT](IMPORTANT): ESPComponent.simulateHardware=0 bool;

2020-07-14T21:43:19.031Z,1594762999.031 [SBIT](IMPORTANT): Express linearApproximation height_above_sea_floor 5.000000 meter;

2020-07-14T21:43:19.031Z,1594762999.031 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=222 cubic_centimeter;

2020-07-14T21:43:19.031Z,1594762999.031 [SBIT](IMPORTANT): VerticalControl.massDefault=8.6 millimeter;

2020-07-14T21:43:19.400Z,1594762999.400 [MissionManager](IMPORTANT): Started mission Startup
2020-07-14T21:43:19.400Z,1594762999.400 [Startup] Running Loop=1
2020-07-14T21:43:19.400Z,1594762999.400 [Startup](DEBUG): Aggregate::initialize Startup
2020-07-14T21:43:19.400Z,1594762999.400 [Startup:A.GoToSurface] Running Loop=1
2020-07-14T21:43:19.400Z,1594762999.400 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2020-07-14T21:43:19.401Z,1594762999.401 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2020-07-14T21:43:19.401Z,1594762999.401 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2020-07-14T21:43:19.402Z,1594762999.402 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2020-07-14T21:43:19.402Z,1594762999.402 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2020-07-14T21:43:19.403Z,1594762999.403 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2020-07-14T21:43:19.404Z,1594762999.404 [Startup:StartupSatComms] Running Loop=1
2020-07-14T21:43:19.404Z,1594762999.404 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2020-07-14T21:43:19.404Z,1594762999.404 [Startup:StartupSatComms:A] Running Loop=1
2020-07-14T21:43:19.808Z,1594762999.808 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2020-07-14T21:43:57.001Z,1594763037.001 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.005403
2020-07-14T21:44:19.584Z,1594763059.584 [Startup:StartupSatComms:A](INFO): Timed out from 2020-07-14T21:43:19.4Z
2020-07-14T21:44:19.584Z,1594763059.584 [Startup:StartupSatComms:A] Stopped
2020-07-14T21:44:19.584Z,1594763059.584 [Startup:StartupSatComms:B] Running Loop=1
2020-07-14T21:44:19.984Z,1594763059.984 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2020-07-14T21:44:26.309Z,1594763066.309 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20200714T205906/Courier0010.lzma
2020-07-14T21:44:27.312Z,1594763067.312 [DataOverHttps](INFO): Moved sent file to Logs/20200714T205906/Courier0010.lzma.bak
2020-07-14T21:44:27.312Z,1594763067.312 [DataOverHttps](INFO): SBD MOMSN=12440816
2020-07-14T21:44:31.295Z,1594763071.295 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2020-07-14T21:44:31.295Z,1594763071.295 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-07-14T21:44:31.345Z,1594763071.345 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-07-14T21:44:31.776Z,1594763071.776 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-07-14T21:44:31.777Z,1594763071.777 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2020-07-14T21:44:43.508Z,1594763083.508 [DataOverHttps](INFO): Sending 282 bytes from file Logs/20200714T213625/Courier0000.lzma
2020-07-14T21:44:44.507Z,1594763084.507 [DataOverHttps](INFO): Moved sent file to Logs/20200714T213625/Courier0000.lzma.bak
2020-07-14T21:44:44.508Z,1594763084.508 [DataOverHttps](INFO): SBD MOMSN=12440821
2020-07-14T21:44:59.950Z,1594763099.950 [DataOverHttps](INFO): Sending 212 bytes from file Logs/20200714T213923/Courier0000.lzma
2020-07-14T21:45:00.952Z,1594763100.952 [DataOverHttps](INFO): Moved sent file to Logs/20200714T213923/Courier0000.lzma.bak
2020-07-14T21:45:00.952Z,1594763100.952 [DataOverHttps](INFO): SBD MOMSN=12440836
2020-07-14T21:45:16.462Z,1594763116.462 [DataOverHttps](INFO): Sending 150 bytes from file Logs/20200714T214120/Courier0000.lzma
2020-07-14T21:45:17.463Z,1594763117.463 [DataOverHttps](INFO): Moved sent file to Logs/20200714T214120/Courier0000.lzma.bak
2020-07-14T21:45:17.464Z,1594763117.464 [DataOverHttps](INFO): SBD MOMSN=12440840
2020-07-14T21:45:19.828Z,1594763119.828 [Startup:StartupSatComms:B](INFO): Timed out from 2020-07-14T21:44:19.6Z
2020-07-14T21:45:19.828Z,1594763119.828 [Startup:StartupSatComms:B] Stopped
2020-07-14T21:45:19.828Z,1594763119.828 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2020-07-14T21:45:19.829Z,1594763119.829 [Startup:StartupSatComms] Stopped
2020-07-14T21:45:19.829Z,1594763119.829 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2020-07-14T21:45:19.829Z,1594763119.829 [Startup](INFO): Completed Startup
2020-07-14T21:45:19.830Z,1594763119.830 [MissionManager](INFO): Startup is completed.
2020-07-14T21:45:19.830Z,1594763119.830 [MissionManager](INFO): Uninitializing Mission Startup
2020-07-14T21:45:19.830Z,1594763119.830 [Startup] Stopped
2020-07-14T21:45:19.830Z,1594763119.830 [Startup](DEBUG): Aggregate::uninitialize Startup
2020-07-14T21:45:19.830Z,1594763119.830 [Startup:A.GoToSurface] Stopped
2020-07-14T21:45:19.830Z,1594763119.830 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2020-07-14T21:45:20.244Z,1594763120.244 [MissionManager](IMPORTANT): Started mission Default
2020-07-14T21:45:20.244Z,1594763120.244 [Default] Running Loop=1
2020-07-14T21:45:20.244Z,1594763120.244 [Default](DEBUG): Aggregate::initialize Default
2020-07-14T21:45:20.244Z,1594763120.244 [Default:B.GoToSurface] Running Loop=1
2020-07-14T21:45:20.244Z,1594763120.244 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2020-07-14T21:45:20.244Z,1594763120.244 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2020-07-14T21:45:20.245Z,1594763120.245 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2020-07-14T21:45:20.245Z,1594763120.245 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2020-07-14T21:45:20.245Z,1594763120.245 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2020-07-14T21:45:20.246Z,1594763120.246 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2020-07-14T21:45:20.246Z,1594763120.246 [Default:A.Wait] Running Loop=1
2020-07-14T21:45:20.246Z,1594763120.246 [Default:A.Wait](DEBUG): Initialize Wait Component.
2020-07-14T21:45:32.881Z,1594763132.881 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20200714T205906/Express0011.lzma
2020-07-14T21:45:33.547Z,1594763133.547 [Default:A.Wait](INFO): Done Waiting.
2020-07-14T21:45:33.547Z,1594763133.547 [Default:A.Wait] Stopped
2020-07-14T21:45:33.547Z,1594763133.547 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2020-07-14T21:45:33.883Z,1594763133.883 [DataOverHttps](INFO): Moved sent file to Logs/20200714T205906/Express0011.lzma.bak
2020-07-14T21:45:33.884Z,1594763133.884 [DataOverHttps](INFO): SBD MOMSN=12440843
2020-07-14T21:45:34.004Z,1594763134.004 [Default:CheckIn] Running Loop=1
2020-07-14T21:45:34.004Z,1594763134.004 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-07-14T21:45:34.004Z,1594763134.004 [Default:CheckIn:Read_GPS] Running Loop=1
2020-07-14T21:45:34.357Z,1594763134.357 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2020-07-14T21:47:11.689Z,1594763231.689 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2020-07-14T21:47:32.331Z,1594763252.331 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 2
2020-07-14T21:47:32.331Z,1594763252.331 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-07-14T21:47:32.341Z,1594763252.341 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-07-14T21:47:32.751Z,1594763252.751 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-07-14T21:47:32.751Z,1594763252.751 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 2
2020-07-14T21:49:40.717Z,1594763380.717 [CommandLine](IMPORTANT): got command show stack
2020-07-14T21:49:40.717Z,1594763380.717 [CommandLine](IMPORTANT): Behavior Stack:

2020-07-14T21:49:40.717Z,1594763380.717 [Default](IMPORTANT): Priority 0: Default:B.GoToSurface
2020-07-14T21:49:40.717Z,1594763380.717 [Default:CheckIn](IMPORTANT): Priority 1: Default:CheckIn:Read_GPS
2020-07-14T21:50:20.373Z,1594763420.373 [BPC1](ERROR): Battery stick #6 (s/n: 00CA) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0.
2020-07-14T21:50:20.374Z,1594763420.374 [BPC1](INFO): Calculating totals. Valid battery stick count: 55. Valid reserve battery stick count: 6.
2020-07-14T21:50:20.377Z,1594763420.377 [BPC1](INFO): Received data from all battery sticks.
2020-07-14T21:50:33.299Z,1594763433.299 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 3
2020-07-14T21:50:33.300Z,1594763433.300 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-07-14T21:50:33.339Z,1594763433.339 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-07-14T21:50:33.739Z,1594763433.739 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-07-14T21:50:33.739Z,1594763433.739 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 3
2020-07-14T21:50:34.128Z,1594763434.128 [Default:CheckIn:Read_GPS](INFO): Timed out from 2020-07-14T21:45:34.0Z
2020-07-14T21:50:34.128Z,1594763434.128 [Default:CheckIn:Read_GPS] Stopped
2020-07-14T21:50:34.128Z,1594763434.128 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-07-14T21:50:34.526Z,1594763434.526 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2020-07-14T21:50:41.485Z,1594763441.485 [DataOverHttps](INFO): Sending 167 bytes from file Logs/20200714T214120/Courier0004.lzma
2020-07-14T21:50:42.483Z,1594763442.483 [DataOverHttps](INFO): Moved sent file to Logs/20200714T214120/Courier0004.lzma.bak
2020-07-14T21:50:42.484Z,1594763442.484 [DataOverHttps](INFO): SBD MOMSN=12440852
2020-07-14T21:50:57.916Z,1594763457.916 [DataOverHttps](INFO): Sending 667 bytes from file Logs/20200714T213625/Express0001.lzma
2020-07-14T21:50:58.915Z,1594763458.915 [DataOverHttps](INFO): Moved sent file to Logs/20200714T213625/Express0001.lzma.bak
2020-07-14T21:50:58.916Z,1594763458.916 [DataOverHttps](INFO): SBD MOMSN=12440854
2020-07-14T21:51:14.412Z,1594763474.412 [DataOverHttps](INFO): Sending 732 bytes from file Logs/20200714T213923/Express0001.lzma
2020-07-14T21:51:15.412Z,1594763475.412 [DataOverHttps](INFO): Moved sent file to Logs/20200714T213923/Express0001.lzma.bak
2020-07-14T21:51:15.412Z,1594763475.412 [DataOverHttps](INFO): SBD MOMSN=12440868
2020-07-14T21:51:30.808Z,1594763490.808 [DataOverHttps](INFO): Sending 1002 bytes from file Logs/20200714T214120/Express0001.lzma
2020-07-14T21:51:31.807Z,1594763491.807 [DataOverHttps](INFO): Moved sent file to Logs/20200714T214120/Express0001.lzma.bak
2020-07-14T21:51:31.808Z,1594763491.808 [DataOverHttps](INFO): SBD MOMSN=12440885
2020-07-14T21:51:47.326Z,1594763507.326 [DataOverHttps](INFO): Sending 298 bytes from file Logs/20200714T214120/Express0005.lzma
2020-07-14T21:51:48.328Z,1594763508.328 [DataOverHttps](INFO): Moved sent file to Logs/20200714T214120/Express0005.lzma.bak
2020-07-14T21:51:48.328Z,1594763508.328 [DataOverHttps](INFO): SBD MOMSN=12440913
2020-07-14T21:51:49.668Z,1594763509.668 [Default:CheckIn:Read_Iridium] Stopped
2020-07-14T21:51:49.668Z,1594763509.668 [Default:CheckIn:C.Wait] Running Loop=1
2020-07-14T21:51:49.668Z,1594763509.668 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-07-14T21:52:11.855Z,1594763531.855 [NAL9602](FAULT): GPS failed to acquire within timeout.
2020-07-14T21:52:11.855Z,1594763531.855 [NAL9602] Data Fault, FailCount= 1
2020-07-14T21:52:11.855Z,1594763531.855 [NAL9602](ERROR): Data Fault
2020-07-14T21:52:11.885Z,1594763531.885 [CBIT](ERROR): Data Fault in component: NAL9602
2020-07-14T21:52:12.263Z,1594763532.263 [NAL9602](INFO): Powering down
2020-07-14T21:52:13.107Z,1594763533.107 [CBIT](INFO): Clearing failed state for component NAL9602
2020-07-14T21:52:13.107Z,1594763533.107 [NAL9602] No Fault, FailCount= 1
2020-07-14T21:52:42.563Z,1594763562.563 [NAL9602](INFO): Powering up NAL9602
2020-07-14T21:52:53.476Z,1594763573.476 [NAL9602](INFO): NAL9602 initialized
2020-07-14T21:53:34.305Z,1594763614.305 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 4
2020-07-14T21:53:34.305Z,1594763614.305 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-07-14T21:53:34.315Z,1594763614.315 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-07-14T21:53:34.719Z,1594763614.719 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-07-14T21:53:34.719Z,1594763614.719 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 4
2020-07-14T21:56:04.263Z,1594763764.263 [DataOverHttps](IMPORTANT): SBD MTMSN=20200714T215122
2020-07-14T21:56:11.478Z,1594763771.478 [DataOverHttps](INFO): Received command:load Maintenance/sample_lab.xml;set sample_lab.CartridgeType -6 count;run 
2020-07-14T21:56:11.532Z,1594763771.532 [CommandLine](IMPORTANT): got command load ./Missions/Maintenance/sample_lab.xml
2020-07-14T21:56:11.532Z,1594763771.532 [MissionManager](INFO): Loading Mission: ./Missions/Maintenance/sample_lab.xml
2020-07-14T21:56:11.581Z,1594763771.581 [MissionManager](INFO): DefineArg sample_lab.MissionTimeout = 90.000000 min
2020-07-14T21:56:11.584Z,1594763771.584 [MissionManager](INFO): DefineArg sample_lab.CartridgeType = -4.000000 count
2020-07-14T21:56:11.587Z,1594763771.587 [MissionManager](INFO): DefineArg sample_lab.NumberOfSamples = 1.000000 count
2020-07-14T21:56:11.588Z,1594763771.588 [sample_lab:A.AbortSample](DEBUG): Construct.
2020-07-14T21:56:11.630Z,1594763771.630 [sample_lab:SampleRepeater:B.ESPCartridgeSelect](DEBUG): Construct.
2020-07-14T21:56:11.648Z,1594763771.648 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<!-- ====================
     Generated by TethysL
     ==================== -->
<Mission xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xmlns="Tethys"
         xmlns:Units="Tethys/Units"
         xmlns:Guidance="Tethys/Guidance"
         xmlns:Trigger="Tethys/Trigger"
         xmlns:Control="Tethys/Control"
         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/Trigger http://okeanids.mbari.org/tethys/Xml/Trigger.xsd
                             Tethys/Control http://okeanids.mbari.org/tethys/Xml/Control.xsd"
       Id="sample_lab">

    <Description>
        This mission is designed to run in the lab only and triggers an ESP sample with specified type.
    </Description>

    <DefineArg Name="MissionTimeout"><Description>
        How long to let the mission run.
    </Description><Units:minute/><Value>90</Value></DefineArg>

    <DefineArg Name="CartridgeType"><Description>
        Specifies ESP cartridge type code (defaults to archiveHiBiomass_bac: -4)
    </Description><Units:count/><Value>-4</Value></DefineArg>

    <DefineArg Name="NumberOfSamples"><Description>
        Number of samples to take.
    </Description><Units:count/><Value>1</Value></DefineArg>

    <Timeout Duration="MissionTimeout"/>

     <Sample:AbortSample>
     	  <Parallel/>
     </Sample:AbortSample>


    <Aggregate Id="SampleRepeater">

        <Sequence Repeat="NumberOfSamples"/>

        <Syslog Severity="Important">Sampling ESP cartridge type <Arg Name="CartridgeType"/><Units:count/></Syslog>

        <Science:ESPCartridgeSelect>
            <Sequence/>
            <Timeout Duration="P1M"/>
            <Setting><Science:ESPCartridgeSelect.cartridgeType/><Arg Name="CartridgeType"/></Setting>
        </Science:ESPCartridgeSelect>

        <ReadDatum Id="TriggerESP">
            <Science:ESPComponent.sampling/>
        </ReadDatum>

        <ReadDatum Id="WaitForESP">
            <Science:ESPComponent.sample_number/>
        </ReadDatum>

    </Aggregate>

</Mission>


2020-07-14T21:56:11.649Z,1594763771.649 [CommandLine](IMPORTANT): Loaded ./Missions/Maintenance/sample_lab.xml
2020-07-14T21:56:13.408Z,1594763773.408 [CommandLine](IMPORTANT): got command set sample_lab.CartridgeType -6.000000 count
2020-07-14T21:56:13.409Z,1594763773.409 [CommandLine](IMPORTANT): got command run 
2020-07-14T21:56:13.411Z,1594763773.411 [CommandLine](IMPORTANT): Running 
2020-07-14T21:56:13.498Z,1594763773.498 [Default] Stopped
2020-07-14T21:56:13.498Z,1594763773.498 [Default](DEBUG): Aggregate::uninitialize Default
2020-07-14T21:56:13.499Z,1594763773.499 [Default:B.GoToSurface] Stopped
2020-07-14T21:56:13.499Z,1594763773.499 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2020-07-14T21:56:13.499Z,1594763773.499 [Default:CheckIn] Stopped
2020-07-14T21:56:13.499Z,1594763773.499 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-07-14T21:56:13.499Z,1594763773.499 [Default:CheckIn:C.Wait] Stopped
2020-07-14T21:56:13.499Z,1594763773.499 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-07-14T21:56:13.499Z,1594763773.499 [MissionManager](IMPORTANT): Started mission sample_lab
2020-07-14T21:56:13.499Z,1594763773.499 [sample_lab] Running Loop=1
2020-07-14T21:56:13.499Z,1594763773.499 [sample_lab](DEBUG): Aggregate::initialize sample_lab
2020-07-14T21:56:13.500Z,1594763773.500 [sample_lab:A.AbortSample] Running Loop=1
2020-07-14T21:56:13.500Z,1594763773.500 [sample_lab:A.AbortSample](INFO): Initializing AbortSample.
2020-07-14T21:56:13.500Z,1594763773.500 [sample_lab:SampleRepeater] Running Loop=1
2020-07-14T21:56:13.500Z,1594763773.500 [sample_lab:SampleRepeater](DEBUG): Aggregate::initialize sample_lab:SampleRepeater
2020-07-14T21:56:13.500Z,1594763773.500 [sample_lab:SampleRepeater:A] Running Loop=1
2020-07-14T21:56:13.501Z,1594763773.501 [sample_lab:SampleRepeater:A](IMPORTANT): Sampling ESP cartridge type -6.000000 count 
2020-07-14T21:56:13.501Z,1594763773.501 [sample_lab:SampleRepeater:A] Stopped
2020-07-14T21:56:13.501Z,1594763773.501 [sample_lab:SampleRepeater:B.ESPCartridgeSelect] Running Loop=1
2020-07-14T21:56:13.501Z,1594763773.501 [sample_lab:SampleRepeater:B.ESPCartridgeSelect](INFO): Initializing ESPCartridgeSelect.
2020-07-14T21:56:13.501Z,1594763773.501 [sample_lab:A.AbortSample] Running Loop=1
2020-07-14T21:56:13.904Z,1594763773.904 [sample_lab:SampleRepeater:B.ESPCartridgeSelect](INFO): Issuing request for ESP cartridge type: -6.
2020-07-14T21:56:13.904Z,1594763773.904 [sample_lab:SampleRepeater:B.ESPCartridgeSelect] Stopped
2020-07-14T21:56:13.904Z,1594763773.904 [sample_lab:SampleRepeater:B.ESPCartridgeSelect](INFO): Uninitializing ESPCartridgeSelect.
2020-07-14T21:56:13.905Z,1594763773.905 [sample_lab:SampleRepeater:TriggerESP] Running Loop=1
2020-07-14T21:56:14.300Z,1594763774.300 [sample_lab:SampleRepeater:TriggerESP](DEBUG): Initialize ReadDataComponent to sense ESPComponent.sampling
2020-07-14T21:56:15.082Z,1594763775.082 [ESPComponent](IMPORTANT): Setting regex for ESP Log summary: 'Selecting Cartridge|Sampled|Error|Underpressure|Overpressure|Fail|Retry|Cmd::|Sampler::'
2020-07-14T21:56:15.085Z,1594763775.085 [ESPComponent](INFO): compiled regex: "Selecting Cartridge|Sampled|Error|Underpressure|Overpressure|Fail|Retry|Cmd::|Sampler::"
2020-07-14T21:56:15.509Z,1594763775.509 [ESPComponent](INFO): powering up ESP
2020-07-14T21:56:15.526Z,1594763775.526 [ESPComponent](INFO): powering up ESP secondary power supply
2020-07-14T21:56:15.558Z,1594763775.558 [ESPComponent](IMPORTANT): Starting PPPD with command:/sbin/pppd xonxoff asyncmap A0000 /dev/ttyTX1 linkname esp noauth local lock 115200 134.89.10.51:134.89.10.60 persist maxfail 0 holdoff 10 lcp-echo-interval 60 lcp-echo-failure 3 proxyarp ktune deflate 12 ms-dns 134.89.10.32 ms-dns 134.89.10.10
2020-07-14T21:56:15.657Z,1594763775.657 [ESPComponent](IMPORTANT): Waiting for ESP to connect (timeout=150.0000)
2020-07-14T21:56:15.982Z,1594763775.982 [ESPComponent](INFO): console:
2020-07-14T21:56:16.711Z,1594763776.711 [ESPComponent](INFO): console:

2020-07-14T21:56:17.106Z,1594763777.106 [ESPComponent](INFO): console:NAND:  256 MiB
2020-07-14T21:56:17.538Z,1594763777.538 [ESPComponent](INFO): console:
BOOTMODE: SPI
2020-07-14T21:56:17.994Z,1594763777.994 [ESPComponent](INFO): console:
reading SPI NOR..
2020-07-14T21:56:19.126Z,1594763779.126 [ESPComponent](INFO): console:Done
2020-07-14T21:56:19.538Z,1594763779.538 [ESPComponent](INFO): console:

2020-07-14T21:56:19.932Z,1594763779.932 [ESPComponent](INFO): console:

2020-07-14T21:56:20.346Z,1594763780.346 [ESPComponent](INFO): console:
U-Boot 2009.11-mbariC (Apr 02 2019 - 13:08:14)
2020-07-14T21:56:20.756Z,1594763780.756 [ESPComponent](INFO): console:

2020-07-14T21:56:21.160Z,1594763781.160 [ESPComponent](INFO): console:
MBARI LPC31xx ESP 3G
2020-07-14T21:56:21.571Z,1594763781.571 [ESPComponent](INFO): console:
flash params are already written into flash
2020-07-14T21:56:21.951Z,1594763781.951 [ESPComponent](INFO): console:
DRAM:  64 MB
2020-07-14T21:56:22.355Z,1594763782.355 [ESPComponent](INFO): console:
In:    serial
2020-07-14T21:56:22.770Z,1594763782.770 [ESPComponent](INFO): console:
Out:   serial
2020-07-14T21:56:23.162Z,1594763783.162 [ESPComponent](INFO): console:
Err:   serial
2020-07-14T21:56:23.582Z,1594763783.582 [ESPComponent](INFO): console:
Net:   ks8851_mll
2020-07-14T21:56:23.981Z,1594763783.981 [ESPComponent](INFO): console:
Hit <ctrl-C> to stop autoboot:  1  0 
2020-07-14T21:56:24.396Z,1594763784.396 [ESPComponent](INFO): console:
mmc1 is available
2020-07-14T21:56:24.779Z,1594763784.779 [ESPComponent](INFO): console:
reading uImage
2020-07-14T21:56:25.183Z,1594763785.183 [ESPComponent](INFO): console:

2020-07-14T21:56:25.589Z,1594763785.589 [ESPComponent](INFO): console:
1681452 bytes read
2020-07-14T21:56:25.989Z,1594763785.989 [ESPComponent](INFO): console:
## Booting kernel from Legacy Image at 31000000 ...
2020-07-14T21:56:26.395Z,1594763786.395 [ESPComponent](INFO): console:
   Image Name:   Linux-2.6.33-ea3131-mbari6
2020-07-14T21:56:26.813Z,1594763786.813 [ESPComponent](INFO): console:
   Image Type:   ARM Linux Kernel Image (uncompressed)
2020-07-14T21:56:27.215Z,1594763787.215 [ESPComponent](INFO): console:
   Data Size:    1681388 Bytes =  1.6 MB
2020-07-14T21:56:27.624Z,1594763787.624 [ESPComponent](INFO): console:
   Load Address: 30008000
2020-07-14T21:56:28.010Z,1594763788.010 [ESPComponent](INFO): console:
   Entry Point:  30008000
2020-07-14T21:56:28.419Z,1594763788.419 [ESPComponent](INFO): console:
   Verifying Checksum ... OK
2020-07-14T21:56:28.825Z,1594763788.825 [ESPComponent](INFO): console:
   Loading Kernel Image ... OK
2020-07-14T21:56:29.219Z,1594763789.219 [ESPComponent](INFO): console:
OK
2020-07-14T21:56:29.633Z,1594763789.633 [ESPComponent](INFO): console:

2020-07-14T21:56:30.045Z,1594763790.045 [ESPComponent](INFO): console:
Starting kernel ...
2020-07-14T21:56:30.463Z,1594763790.463 [ESPComponent](INFO): console:

2020-07-14T21:56:30.842Z,1594763790.842 [ESPComponent](INFO): console:
Uncompressing Linux... done, booting the kernel.
2020-07-14T21:56:31.239Z,1594763791.239 [ESPComponent](INFO): console:
[    0.00] CPU: ARM926EJ-S [41069265] revision 5 (ARMv5TEJ), cr=00053177
2020-07-14T21:56:31.648Z,1594763791.648 [ESPComponent](INFO): console:
[    0.00] CPU: VIVT data cache, VIVT instruction cache
2020-07-14T21:56:32.056Z,1594763792.056 [ESPComponent](INFO): console:
[    0.00] Machine: NXP EA313X
2020-07-14T21:56:32.447Z,1594763792.447 [ESPComponent](INFO): console:
0] Memory ECC disabled, Data cache writeback
2020-07-14T21:56:32.877Z,1594763792.877 [ESPComponent](INFO): console:
[    0.00] Built 1 zonelists in Zone order, mobility grouping on.  Total pages: 16256
2020-07-14T21:56:33.278Z,1594763793.278 [ESPComponent](INFO): console:
[    0.24] Mount-cache hash table entries: 512
2020-07-14T21:56:33.681Z,1594763793.681 [ESPComponent](INFO): console:
[    0.30] MBARI ESP 3G
2020-07-14T21:56:34.075Z,1594763794.075 [ESPComponent](INFO): console:
[    0.40] bio: create slab <bio-0> at 0
2020-07-14T21:56:34.469Z,1594763794.469 [ESPComponent](INFO): console:
[    0.47] i2c i2c-0: Master timed out. stat = 2a00, cntrl = 000e. Resetting master...
2020-07-14T21:56:34.873Z,1594763794.873 [ESPComponent](INFO): console:
[    0.49] i2c i2c-0: Master timed out. stat = 2a00, cntrl = 000e. Resetting master...
2020-07-14T21:56:35.284Z,1594763795.284 [ESPComponent](INFO): console:
[    0.51] i2c i2c-0: Master timed out. stat = 2a00, cntrl = 000e. Resetting master...
2020-07-14T21:56:35.291Z,1594763795.291 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 5
2020-07-14T21:56:35.291Z,1594763795.291 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-07-14T21:56:35.300Z,1594763795.300 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-07-14T21:56:35.697Z,1594763795.697 [ESPComponent](INFO): console:
[    0.53] i2c i2c-0: Master timed out. stat = 2a00, cntrl = 000e. Resetting master...
2020-07-14T21:56:35.719Z,1594763795.719 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-07-14T21:56:35.719Z,1594763795.719 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 5
2020-07-14T21:56:36.111Z,1594763796.111 [ESPComponent](INFO): console:
[    0.55] i2c i2c-0: Master timed out. stat = 2a00, cntrl = 000e. Resetting master...
2020-07-14T21:56:36.502Z,1594763796.502 [ESPComponent](INFO): console:
[    0.57] i2c i2c-0: Master timed out. stat = 2a00, cntrl = 000e. Resetting master...
2020-07-14T21:56:36.901Z,1594763796.901 [ESPComponent](INFO): console:
[    0.57] NetWinder Floating Point Emulator V0.97 (double precision)
2020-07-14T21:56:37.305Z,1594763797.305 [ESPComponent](INFO): console:
[    0.59] yaffs Dec 14 2018 09:19:05 Installing. 
2020-07-14T21:56:37.708Z,1594763797.708 [ESPComponent](INFO): console:
[    0.73] m25p80 spi0.3: m25p80 found s25sl032a flash
2020-07-14T21:56:38.107Z,1594763798.107 [ESPComponent](INFO): console:
[    2.23] VFS: Mounted root (ext2 filesystem) readonly on device 179:2.
2020-07-14T21:56:38.520Z,1594763798.520 [ESPComponent](INFO): console:

2020-07-14T21:56:38.933Z,1594763798.933 [ESPComponent](INFO): console:INIT: version 2.85 booting
2020-07-14T21:56:39.330Z,1594763799.330 [ESPComponent](INFO): console:

2020-07-14T21:56:39.719Z,1594763799.719 [ESPComponent](INFO): console:MBARI ESP Embedded Linux    http://www.mbari.org   mailto:brent@mbari.org
2020-07-14T21:56:40.131Z,1594763800.131 [ESPComponent](INFO): console:
ESPmv1
2020-07-14T21:56:40.555Z,1594763800.555 [ESPComponent](INFO): console:

2020-07-14T21:56:40.932Z,1594763800.932 [ESPComponent](INFO): console:INIT: Entering runlevel: 3
2020-07-14T21:56:41.342Z,1594763801.342 [ESPComponent](INFO): console:

2020-07-14T21:56:41.773Z,1594763801.773 [ESPComponent](INFO): console:Loading kernel modules
2020-07-14T21:56:42.163Z,1594763802.163 [ESPComponent](INFO): console:
Mounting filesystems and adding swapfiles listed in /etc/fstab
2020-07-14T21:56:42.565Z,1594763802.565 [ESPComponent](INFO): console:
mount: /dev/mmcblk0p2 already mounted or /card busy
2020-07-14T21:56:42.959Z,1594763802.959 [ESPComponent](INFO): console:
Starting hotplug events dispatcher udevd
2020-07-14T21:56:43.359Z,1594763803.359 [ESPComponent](INFO): console:
Set system clock to:  Tue Jul 14 14:52:33 PDT 2020
2020-07-14T21:56:43.772Z,1594763803.772 [ESPComponent](INFO): console:
Starting syslogd klogd...
2020-07-14T21:56:44.167Z,1594763804.167 [ESPComponent](INFO): console:
Bringing up interface lo ...
2020-07-14T21:56:44.583Z,1594763804.583 [ESPComponent](INFO): console:
lo IP=127.0.0.1
2020-07-14T21:56:44.996Z,1594763804.996 [ESPComponent](INFO): console:
Packet forwarding enabled
2020-07-14T21:56:45.386Z,1594763805.386 [ESPComponent](INFO): console:
Bringing up interface ppp2 ...
2020-07-14T21:56:45.782Z,1594763805.782 [ESPComponent](INFO): console:
Starting portmap...
2020-07-14T21:56:46.196Z,1594763806.196 [ESPComponent](INFO): console:
Bringing up interface eth0 ...
2020-07-14T21:56:46.597Z,1594763806.597 [ESPComponent](INFO): console:
Missing Network -- skipping nfs mounts
2020-07-14T21:56:46.000Z,1594763807.000 [ESPComponent](INFO): console:
Network unavailable:  Local time is Tue Jul 14 14:52:35 PDT 2020
2020-07-14T21:56:47.399Z,1594763807.399 [ESPComponent](INFO): console:
Determining IP configuration for eth0....udhcpc (v1.11.2) started
2020-07-14T21:56:47.821Z,1594763807.821 [ESPComponent](INFO): console:
Starting thttpd...
2020-07-14T21:56:48.222Z,1594763808.222 [ESPComponent](INFO): console:
Sending discover...
2020-07-14T21:56:48.629Z,1594763808.629 [ESPComponent](INFO): console:

2020-07-14T21:56:49.014Z,1594763809.014 [ESPComponent](INFO): console:

2020-07-14T21:56:49.424Z,1594763809.424 [ESPComponent](INFO): console:MBARI ESP Embedded Linux 2.45 -- 3/21/19 brent@mbari.org
2020-07-14T21:56:49.830Z,1594763809.830 [ESPComponent](IMPORTANT): ESP has connected as client
2020-07-14T21:56:50.665Z,1594763810.665 [ESPComponent](IMPORTANT): [sample #1] Setting cartridge argument to -6
2020-07-14T21:56:50.665Z,1594763810.665 [ESPComponent](IMPORTANT): [sample #1] ESP sampling sequence starting. Sampling state: S_WAITING_INITIAL_PROMPT
2020-07-14T21:56:50.667Z,1594763810.667 [ESPComponent](DEBUG): Writing samplingActive=1, sampleNumber=1
2020-07-14T21:56:50.674Z,1594763810.674 [sample_lab:SampleRepeater:TriggerESP] Stopped
2020-07-14T21:56:50.674Z,1594763810.674 [sample_lab:SampleRepeater:WaitForESP] Running Loop=1
2020-07-14T21:56:51.072Z,1594763811.072 [sample_lab:SampleRepeater:WaitForESP](DEBUG): Initialize ReadDataComponent to sense ESPComponent.sample_number
2020-07-14T21:56:51.840Z,1594763811.840 [ESPComponent](IMPORTANT): [sample #1] ESP sampling state: S_PREPARING_SHOW_LOG
2020-07-14T21:56:52.251Z,1594763812.251 [ESPComponent](IMPORTANT): [sample #1] ESP sampling state: S_PREPARING_SHOW_STATUS
2020-07-14T21:56:53.881Z,1594763813.881 [ESPComponent](IMPORTANT): [sample #1] ESP sampling state: S_LOADING_CARTRIDGE
2020-07-14T21:57:26.595Z,1594763846.595 [ESPComponent](IMPORTANT): [sample #1] ESP sampling state: S_WAITING_FOR_PRIMING (@60,archive_bac)
2020-07-14T21:57:28.219Z,1594763848.219 [ESPComponent](IMPORTANT): [sample #1] ESP sampling state: S_PRIMING (@100.0)
2020-07-14T21:57:29.012Z,1594763849.012 [ESPComponent](IMPORTANT): [sample #1] ESP sampling state: S_WAITING_FOR_FILTERING (@100.0)
2020-07-14T21:59:36.303Z,1594763976.303 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 6
2020-07-14T21:59:36.303Z,1594763976.303 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-07-14T21:59:36.312Z,1594763976.312 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-07-14T21:59:36.708Z,1594763976.708 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-07-14T21:59:36.709Z,1594763976.709 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 6
2020-07-14T22:00:02.131Z,1594764002.131 [ESPComponent](IMPORTANT): [sample #1] ESP sampling state: S_FILTERING (@0.0)
2020-07-14T22:00:02.551Z,1594764002.551 [ESPComponent](IMPORTANT): [sample #1] ESP sampling state: S_WAITING_FOR_PAUSED (@0.0)
2020-07-14T22:02:37.298Z,1594764157.298 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 7
2020-07-14T22:02:37.298Z,1594764157.298 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-07-14T22:02:37.324Z,1594764157.324 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-07-14T22:02:37.714Z,1594764157.714 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-07-14T22:02:37.714Z,1594764157.714 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 7
2020-07-14T22:02:54.627Z,1594764174.627 [NAL9602](FAULT): GPS failed to acquire within timeout.
2020-07-14T22:02:54.627Z,1594764174.627 [NAL9602] Data Fault, FailCount= 2
2020-07-14T22:02:54.627Z,1594764174.627 [NAL9602](ERROR): Data Fault
2020-07-14T22:02:54.657Z,1594764174.657 [CBIT](ERROR): Data Fault in component: NAL9602
2020-07-14T22:02:55.023Z,1594764175.023 [NAL9602](INFO): Powering down
2020-07-14T22:02:55.878Z,1594764175.878 [CBIT](INFO): Clearing failed state for component NAL9602
2020-07-14T22:02:55.878Z,1594764175.878 [NAL9602] No Fault, FailCount= 2
2020-07-14T22:03:25.323Z,1594764205.323 [NAL9602](INFO): Powering up NAL9602
2020-07-14T22:03:36.231Z,1594764216.231 [NAL9602](INFO): NAL9602 initialized
2020-07-14T22:05:38.283Z,1594764338.283 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 8
2020-07-14T22:05:38.283Z,1594764338.283 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-07-14T22:05:38.306Z,1594764338.306 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-07-14T22:05:38.698Z,1594764338.698 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-07-14T22:05:38.698Z,1594764338.698 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 8
2020-07-14T22:08:39.279Z,1594764519.279 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 9
2020-07-14T22:08:39.279Z,1594764519.279 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-07-14T22:08:39.288Z,1594764519.288 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-07-14T22:08:39.691Z,1594764519.691 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-07-14T22:08:39.691Z,1594764519.691 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 9
2020-07-14T22:11:40.267Z,1594764700.267 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 10
2020-07-14T22:11:40.267Z,1594764700.267 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-07-14T22:11:40.276Z,1594764700.276 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-07-14T22:11:40.683Z,1594764700.683 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-07-14T22:11:40.683Z,1594764700.683 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 10
2020-07-14T22:13:37.383Z,1594764817.383 [NAL9602](FAULT): GPS failed to acquire within timeout.
2020-07-14T22:13:37.383Z,1594764817.383 [NAL9602] Data Fault, FailCount= 3
2020-07-14T22:13:37.383Z,1594764817.383 [NAL9602](ERROR): Data Fault
2020-07-14T22:13:37.439Z,1594764817.439 [CBIT](ERROR): Data Fault in component: NAL9602
2020-07-14T22:13:37.787Z,1594764817.787 [NAL9602](INFO): Powering down
2020-07-14T22:13:38.632Z,1594764818.632 [CBIT](INFO): Clearing failed state for component NAL9602
2020-07-14T22:13:38.632Z,1594764818.632 [NAL9602] No Fault, FailCount= 3
2020-07-14T22:14:08.087Z,1594764848.087 [NAL9602](INFO): Powering up NAL9602
2020-07-14T22:14:18.995Z,1594764858.995 [NAL9602](INFO): NAL9602 initialized
2020-07-14T22:14:41.258Z,1594764881.258 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 11
2020-07-14T22:14:41.258Z,1594764881.258 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-07-14T22:14:41.283Z,1594764881.283 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-07-14T22:14:41.664Z,1594764881.664 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-07-14T22:14:41.664Z,1594764881.664 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 11
2020-07-14T22:17:42.233Z,1594765062.233 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 12
2020-07-14T22:17:42.233Z,1594765062.233 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-07-14T22:17:42.242Z,1594765062.242 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-07-14T22:17:42.647Z,1594765062.647 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-07-14T22:17:42.647Z,1594765062.647 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 12
2020-07-14T22:20:43.220Z,1594765243.220 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 13
2020-07-14T22:20:43.220Z,1594765243.220 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-07-14T22:20:43.230Z,1594765243.230 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-07-14T22:20:43.639Z,1594765243.639 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-07-14T22:20:43.639Z,1594765243.639 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 13
2020-07-14T22:23:44.234Z,1594765424.234 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 14
2020-07-14T22:23:44.234Z,1594765424.234 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-07-14T22:23:44.243Z,1594765424.243 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-07-14T22:23:44.659Z,1594765424.659 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-07-14T22:23:44.659Z,1594765424.659 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 14
2020-07-14T22:24:20.147Z,1594765460.147 [NAL9602](FAULT): GPS failed to acquire within timeout.
2020-07-14T22:24:20.147Z,1594765460.147 [NAL9602] Data Fault, FailCount= 4
2020-07-14T22:24:20.147Z,1594765460.147 [NAL9602](ERROR): Data Fault
2020-07-14T22:24:20.202Z,1594765460.202 [CBIT](ERROR): Data Fault in component: NAL9602
2020-07-14T22:24:20.555Z,1594765460.555 [NAL9602](INFO): Powering down
2020-07-14T22:24:21.399Z,1594765461.399 [CBIT](INFO): Clearing failed state for component NAL9602
2020-07-14T22:24:21.399Z,1594765461.399 [NAL9602] No Fault, FailCount= 4
2020-07-14T22:24:50.855Z,1594765490.855 [NAL9602](INFO): Powering up NAL9602
2020-07-14T22:25:01.763Z,1594765501.763 [NAL9602](INFO): NAL9602 initialized
2020-07-14T22:26:45.234Z,1594765605.234 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 15
2020-07-14T22:26:45.234Z,1594765605.234 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-07-14T22:26:45.243Z,1594765605.243 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-07-14T22:26:45.638Z,1594765605.638 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-07-14T22:26:45.638Z,1594765605.638 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 15
2020-07-14T22:29:46.199Z,1594765786.199 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 16
2020-07-14T22:29:46.199Z,1594765786.199 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-07-14T22:29:46.226Z,1594765786.226 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-07-14T22:29:46.608Z,1594765786.608 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-07-14T22:29:46.609Z,1594765786.609 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 16
2020-07-14T22:32:47.219Z,1594765967.219 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 17
2020-07-14T22:32:47.219Z,1594765967.219 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-07-14T22:32:47.228Z,1594765967.228 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-07-14T22:32:47.630Z,1594765967.630 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-07-14T22:32:47.630Z,1594765967.630 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 17
2020-07-14T22:32:54.048Z,1594765974.048 [ESPComponent](IMPORTANT): [sample #1] ESP sampling state: S_PAUSED (@1000.0)
2020-07-14T22:32:54.048Z,1594765974.048 [ESPComponent](DEBUG): Writing sampleVolume=1000.000000
2020-07-14T22:32:54.460Z,1594765974.460 [ESPComponent](IMPORTANT): [sample #1] ESP sampling state: S_PROCESSING (@1000.0)
2020-07-14T22:32:56.889Z,1594765976.889 [ESPComponent](IMPORTANT): [sample #1] ESP sampling state: S_WAITING_FOR_PROCESSED (@60,archive_bac)
2020-07-14T22:35:02.911Z,1594766102.911 [NAL9602](FAULT): GPS failed to acquire within timeout.
2020-07-14T22:35:02.911Z,1594766102.911 [NAL9602] Data Fault, FailCount= 5
2020-07-14T22:35:02.911Z,1594766102.911 [NAL9602](ERROR): Data Fault
2020-07-14T22:35:02.972Z,1594766102.972 [CBIT](ERROR): Data Fault in component: NAL9602
2020-07-14T22:35:02.972Z,1594766102.972 [CBIT](CRITICAL): Data Fault in component: NAL9602
2020-07-14T22:35:03.311Z,1594766103.311 [NAL9602](INFO): Powering down
2020-07-14T22:35:03.401Z,1594766103.401 [CommandLine](FAULT): Scheduling is paused
2020-07-14T22:35:03.406Z,1594766103.406 [CBIT](INFO): Critical error at 20200714T223502
2020-07-14T22:35:03.406Z,1594766103.406 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2020-07-14T22:35:03.771Z,1594766103.771 [MissionManager](INFO): MissionManager is completed.
2020-07-14T22:35:03.771Z,1594766103.771 [MissionManager](INFO): Uninitializing Mission sample_lab
2020-07-14T22:35:03.771Z,1594766103.771 [sample_lab] Stopped
2020-07-14T22:35:03.771Z,1594766103.771 [sample_lab](DEBUG): Aggregate::uninitialize sample_lab
2020-07-14T22:35:03.771Z,1594766103.771 [sample_lab:A.AbortSample] Stopped
2020-07-14T22:35:03.771Z,1594766103.771 [sample_lab:A.AbortSample](INFO): Uninitializing AbortSample.
2020-07-14T22:35:03.771Z,1594766103.771 [sample_lab:SampleRepeater] Stopped
2020-07-14T22:35:03.771Z,1594766103.771 [sample_lab:SampleRepeater](DEBUG): Aggregate::uninitialize sample_lab:SampleRepeater
2020-07-14T22:35:03.772Z,1594766103.772 [sample_lab:SampleRepeater:WaitForESP] Stopped
2020-07-14T22:35:04.150Z,1594766104.150 [ESPComponent](DEBUG): Resetting stopSampling to false
2020-07-14T22:35:04.151Z,1594766104.151 [ESPComponent](IMPORTANT): [sample #1] Stop sampling requested.
2020-07-14T22:35:04.160Z,1594766104.160 [MissionManager](IMPORTANT): Started mission Default
2020-07-14T22:35:04.160Z,1594766104.160 [Default] Running Loop=1
2020-07-14T22:35:04.160Z,1594766104.160 [Default](DEBUG): Aggregate::initialize Default
2020-07-14T22:35:04.160Z,1594766104.160 [Default:B.GoToSurface] Running Loop=1
2020-07-14T22:35:04.160Z,1594766104.160 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2020-07-14T22:35:04.160Z,1594766104.160 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2020-07-14T22:35:04.161Z,1594766104.161 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2020-07-14T22:35:04.161Z,1594766104.161 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2020-07-14T22:35:04.161Z,1594766104.161 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2020-07-14T22:35:04.162Z,1594766104.162 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2020-07-14T22:35:04.162Z,1594766104.162 [Default:A.Wait] Running Loop=1
2020-07-14T22:35:04.162Z,1594766104.162 [Default:A.Wait](DEBUG): Initialize Wait Component.
2020-07-14T22:35:17.481Z,1594766117.481 [Default:A.Wait](INFO): Done Waiting.
2020-07-14T22:35:17.481Z,1594766117.481 [Default:A.Wait] Stopped
2020-07-14T22:35:17.482Z,1594766117.482 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2020-07-14T22:35:17.889Z,1594766117.889 [Default:CheckIn] Running Loop=1
2020-07-14T22:35:17.889Z,1594766117.889 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-07-14T22:35:17.889Z,1594766117.889 [Default:CheckIn:Read_GPS] Running Loop=1
2020-07-14T22:35:48.180Z,1594766148.180 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 18
2020-07-14T22:35:48.180Z,1594766148.180 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-07-14T22:35:48.190Z,1594766148.190 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-07-14T22:35:48.597Z,1594766148.597 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-07-14T22:35:48.597Z,1594766148.597 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 18
2020-07-14T22:37:02.940Z,1594766222.940 [CBIT](INFO): Clearing failed state for component NAL9602
2020-07-14T22:37:02.940Z,1594766222.940 [NAL9602] No Fault, FailCount= 5
2020-07-14T22:37:03.307Z,1594766223.307 [NAL9602](INFO): Powering up NAL9602
2020-07-14T22:37:14.220Z,1594766234.220 [NAL9602](INFO): NAL9602 initialized
2020-07-14T22:38:49.188Z,1594766329.188 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 19
2020-07-14T22:38:49.188Z,1594766329.188 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-07-14T22:38:49.198Z,1594766329.198 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-07-14T22:38:49.607Z,1594766329.607 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-07-14T22:38:49.607Z,1594766329.607 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 19
2020-07-14T22:40:18.092Z,1594766418.092 [Default:CheckIn:Read_GPS](INFO): Timed out from 2020-07-14T22:35:17.9Z
2020-07-14T22:40:18.092Z,1594766418.092 [Default:CheckIn:Read_GPS] Stopped
2020-07-14T22:40:18.093Z,1594766418.093 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-07-14T22:40:23.929Z,1594766423.929 [DataOverHttps](INFO): Sending 104 bytes from file Logs/20200714T214120/Courier0007.lzma
2020-07-14T22:40:24.931Z,1594766424.931 [DataOverHttps](INFO): Moved sent file to Logs/20200714T214120/Courier0007.lzma.bak
2020-07-14T22:40:24.932Z,1594766424.932 [DataOverHttps](INFO): SBD MOMSN=12440968
2020-07-14T22:40:40.580Z,1594766440.580 [DataOverHttps](INFO): Sending 1015 bytes from file Logs/20200714T214120/Express0008.lzma
2020-07-14T22:40:41.580Z,1594766441.580 [DataOverHttps](INFO): Moved sent file to Logs/20200714T214120/Express0008.lzma.bak
2020-07-14T22:40:41.580Z,1594766441.580 [DataOverHttps](INFO): SBD MOMSN=12440971
2020-07-14T22:40:57.157Z,1594766457.157 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20200714T214120/Express0011.lzma
2020-07-14T22:40:58.159Z,1594766458.159 [DataOverHttps](INFO): Moved sent file to Logs/20200714T214120/Express0011.lzma.bak
2020-07-14T22:40:58.160Z,1594766458.160 [DataOverHttps](INFO): SBD MOMSN=12441006
2020-07-14T22:40:59.696Z,1594766459.696 [Default:CheckIn:Read_Iridium] Stopped
2020-07-14T22:40:59.696Z,1594766459.696 [Default:CheckIn:C.Wait] Running Loop=1
2020-07-14T22:40:59.696Z,1594766459.696 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-07-14T22:41:50.201Z,1594766510.201 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 20
2020-07-14T22:41:50.201Z,1594766510.201 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-07-14T22:41:50.211Z,1594766510.211 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-07-14T22:41:50.615Z,1594766510.615 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-07-14T22:41:50.615Z,1594766510.615 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 20
2020-07-14T22:44:51.177Z,1594766691.177 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 21
2020-07-14T22:44:51.177Z,1594766691.177 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-07-14T22:44:51.187Z,1594766691.187 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-07-14T22:44:51.600Z,1594766691.600 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-07-14T22:44:51.600Z,1594766691.600 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 21
2020-07-14T22:45:00.065Z,1594766700.065 [ESPComponent](IMPORTANT): [sample #1] ESP sampling state: S_STOPPING (@60,archive_bac)
2020-07-14T22:45:25.515Z,1594766725.515 [ESPComponent](IMPORTANT): Syncing ESP logs with command: rsync -azPq --timeout=60 esp@esp:'/var/log/esp/real /var/log/esp/real.out /var/log/esp/real.slot /var/log/esp/*.spr' /LRAUV/ESPlogs &
2020-07-14T22:45:25.530Z,1594766725.530 [ESPComponent](INFO): closing pipe.
2020-07-14T22:45:25.915Z,1594766725.915 [ESPComponent](IMPORTANT): [sample #1] ESP sampling state: S_STOPPED
2020-07-14T22:46:00.280Z,1594766760.280 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-07-14T22:46:00.280Z,1594766760.280 [Default:CheckIn:C.Wait] Stopped
2020-07-14T22:46:00.280Z,1594766760.280 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-07-14T22:46:00.280Z,1594766760.280 [Default:CheckIn:D] Running Loop=1
2020-07-14T22:46:00.682Z,1594766760.682 [Default:CheckIn:D] Stopped
2020-07-14T22:46:00.682Z,1594766760.682 [Default:CheckIn:E] Running Loop=1
2020-07-14T22:46:01.084Z,1594766761.084 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 10.942038 min 
2020-07-14T22:46:01.084Z,1594766761.084 [Default:CheckIn:E] Stopped
2020-07-14T22:46:01.084Z,1594766761.084 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-07-14T22:46:01.085Z,1594766761.085 [Default:CheckIn] Stopped
2020-07-14T22:46:01.085Z,1594766761.085 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-07-14T22:46:01.085Z,1594766761.085 [Default:CheckIn](INFO): Running loop #2
2020-07-14T22:46:01.085Z,1594766761.085 [Default:CheckIn] Running Loop=2
2020-07-14T22:46:01.085Z,1594766761.085 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-07-14T22:46:01.085Z,1594766761.085 [Default:CheckIn:Read_GPS] Running Loop=1
2020-07-14T22:47:16.187Z,1594766836.187 [NAL9602](FAULT): GPS failed to acquire within timeout.
2020-07-14T22:47:16.187Z,1594766836.187 [NAL9602] Data Fault, FailCount= 1
2020-07-14T22:47:16.187Z,1594766836.187 [NAL9602](ERROR): Data Fault
2020-07-14T22:47:16.239Z,1594766836.239 [CBIT](ERROR): Data Fault in component: NAL9602
2020-07-14T22:47:16.591Z,1594766836.591 [NAL9602](INFO): Powering down
2020-07-14T22:47:17.432Z,1594766837.432 [CBIT](INFO): Clearing failed state for component NAL9602
2020-07-14T22:47:17.432Z,1594766837.432 [NAL9602] No Fault, FailCount= 1
2020-07-14T22:47:46.896Z,1594766866.896 [NAL9602](INFO): Powering up NAL9602
2020-07-14T22:47:52.163Z,1594766872.163 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 22
2020-07-14T22:47:52.163Z,1594766872.163 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-07-14T22:47:52.173Z,1594766872.173 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-07-14T22:47:52.580Z,1594766872.580 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-07-14T22:47:52.580Z,1594766872.580 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 22
2020-07-14T22:47:57.799Z,1594766877.799 [NAL9602](INFO): NAL9602 initialized
2020-07-14T22:50:25.689Z,1594767025.689 [ESPComponent](IMPORTANT): [sample #1] ESP sampling sequence completed normally.
2020-07-14T22:50:25.689Z,1594767025.689 [ESPComponent](DEBUG): Writing samplingActive=1, sampleNumber=1
2020-07-14T22:50:26.100Z,1594767026.100 [ESPComponent](IMPORTANT): [sample #1] ESP log summary report (2 messages):
@14:57:03.81 Selecting Cartridge 60
@15:32:52.30 Sampled  1000.0ml

2020-07-14T22:50:26.101Z,1594767026.101 [ESPComponent](INFO): powering down ESP
2020-07-14T22:50:26.101Z,1594767026.101 [ESPComponent](INFO): powering down ESP secondary power supply
2020-07-14T22:50:53.164Z,1594767053.164 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 23
2020-07-14T22:50:53.164Z,1594767053.164 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-07-14T22:50:53.174Z,1594767053.174 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-07-14T22:50:53.579Z,1594767053.579 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-07-14T22:50:53.579Z,1594767053.579 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 23
2020-07-14T22:51:01.244Z,1594767061.244 [Default:CheckIn:Read_GPS](INFO): Timed out from 2020-07-14T22:46:01.1Z
2020-07-14T22:51:01.244Z,1594767061.244 [Default:CheckIn:Read_GPS] Stopped
2020-07-14T22:51:01.244Z,1594767061.244 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-07-14T22:51:07.237Z,1594767067.237 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20200714T214120/Courier0013.lzma
2020-07-14T22:51:08.240Z,1594767068.240 [DataOverHttps](INFO): Moved sent file to Logs/20200714T214120/Courier0013.lzma.bak
2020-07-14T22:51:08.240Z,1594767068.240 [DataOverHttps](INFO): SBD MOMSN=12441017
2020-07-14T22:51:23.755Z,1594767083.755 [DataOverHttps](INFO): Sending 453 bytes from file Logs/20200714T214120/Express0014.lzma
2020-07-14T22:51:24.757Z,1594767084.757 [DataOverHttps](INFO): Moved sent file to Logs/20200714T214120/Express0014.lzma.bak
2020-07-14T22:51:24.757Z,1594767084.757 [DataOverHttps](INFO): SBD MOMSN=12441019
2020-07-14T22:51:26.296Z,1594767086.296 [Default:CheckIn:Read_Iridium] Stopped
2020-07-14T22:51:26.296Z,1594767086.296 [Default:CheckIn:C.Wait] Running Loop=1
2020-07-14T22:51:26.296Z,1594767086.296 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-07-14T22:53:54.179Z,1594767234.179 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 24
2020-07-14T22:53:54.179Z,1594767234.179 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-07-14T22:53:54.189Z,1594767234.189 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-07-14T22:53:54.597Z,1594767234.597 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-07-14T22:53:54.597Z,1594767234.597 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 24
2020-07-14T22:56:26.870Z,1594767386.870 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-07-14T22:56:26.870Z,1594767386.870 [Default:CheckIn:C.Wait] Stopped
2020-07-14T22:56:26.870Z,1594767386.870 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-07-14T22:56:26.871Z,1594767386.871 [Default:CheckIn:D] Running Loop=1
2020-07-14T22:56:27.273Z,1594767387.273 [Default:CheckIn:D] Stopped
2020-07-14T22:56:27.273Z,1594767387.273 [Default:CheckIn:E] Running Loop=1
2020-07-14T22:56:27.684Z,1594767387.684 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 21.385219 min 
2020-07-14T22:56:27.684Z,1594767387.684 [Default:CheckIn:E] Stopped
2020-07-14T22:56:27.684Z,1594767387.684 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-07-14T22:56:27.684Z,1594767387.684 [Default:CheckIn] Stopped
2020-07-14T22:56:27.685Z,1594767387.685 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-07-14T22:56:27.685Z,1594767387.685 [Default:CheckIn](INFO): Running loop #3
2020-07-14T22:56:27.685Z,1594767387.685 [Default:CheckIn] Running Loop=3
2020-07-14T22:56:27.685Z,1594767387.685 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-07-14T22:56:27.685Z,1594767387.685 [Default:CheckIn:Read_GPS] Running Loop=1
2020-07-14T22:56:55.186Z,1594767415.186 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 25
2020-07-14T22:56:55.186Z,1594767415.186 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-07-14T22:56:55.196Z,1594767415.196 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-07-14T22:56:55.616Z,1594767415.616 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-07-14T22:56:55.616Z,1594767415.616 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 25
2020-07-14T22:57:59.400Z,1594767479.400 [BPC1](ERROR): Battery stick #6 (s/n: 00CA) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0.
2020-07-14T22:57:59.401Z,1594767479.401 [BPC1](INFO): Calculating totals. Valid battery stick count: 55. Valid reserve battery stick count: 6.
2020-07-14T22:57:59.428Z,1594767479.428 [BPC1](INFO): Received data from all battery sticks.
2020-07-14T22:58:00.999Z,1594767480.999 [NAL9602](FAULT): GPS failed to acquire within timeout.
2020-07-14T22:58:00.999Z,1594767480.999 [NAL9602] Data Fault, FailCount= 2
2020-07-14T22:58:00.999Z,1594767480.999 [NAL9602](ERROR): Data Fault
2020-07-14T22:58:01.054Z,1594767481.054 [CBIT](ERROR): Data Fault in component: NAL9602
2020-07-14T22:58:01.403Z,1594767481.403 [NAL9602](INFO): Powering down
2020-07-14T22:58:02.259Z,1594767482.259 [CBIT](INFO): Clearing failed state for component NAL9602
2020-07-14T22:58:02.259Z,1594767482.259 [NAL9602] No Fault, FailCount= 2
2020-07-14T22:58:31.707Z,1594767511.707 [NAL9602](INFO): Powering up NAL9602
2020-07-14T22:58:42.611Z,1594767522.611 [NAL9602](INFO): NAL9602 initialized
2020-07-14T22:59:56.162Z,1594767596.162 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 26
2020-07-14T22:59:56.162Z,1594767596.162 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-07-14T22:59:56.172Z,1594767596.172 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-07-14T22:59:56.583Z,1594767596.583 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-07-14T22:59:56.583Z,1594767596.583 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 26
2020-07-14T23:01:27.869Z,1594767687.869 [Default:CheckIn:Read_GPS](INFO): Timed out from 2020-07-14T22:56:27.7Z
2020-07-14T23:01:27.869Z,1594767687.869 [Default:CheckIn:Read_GPS] Stopped
2020-07-14T23:01:27.870Z,1594767687.870 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-07-14T23:01:33.705Z,1594767693.705 [DataOverHttps](INFO): Sending 50 bytes from file Logs/20200714T214120/Courier0016.lzma
2020-07-14T23:01:34.708Z,1594767694.708 [DataOverHttps](INFO): Moved sent file to Logs/20200714T214120/Courier0016.lzma.bak
2020-07-14T23:01:34.708Z,1594767694.708 [DataOverHttps](INFO): SBD MOMSN=12441037
2020-07-14T23:01:50.154Z,1594767710.154 [DataOverHttps](INFO): Sending 149 bytes from file Logs/20200714T214120/Express0017.lzma
2020-07-14T23:01:51.156Z,1594767711.156 [DataOverHttps](INFO): Moved sent file to Logs/20200714T214120/Express0017.lzma.bak
2020-07-14T23:01:51.156Z,1594767711.156 [DataOverHttps](INFO): SBD MOMSN=12441039
2020-07-14T23:01:52.527Z,1594767712.527 [Default:CheckIn:Read_Iridium] Stopped
2020-07-14T23:01:52.527Z,1594767712.527 [Default:CheckIn:C.Wait] Running Loop=1
2020-07-14T23:01:52.527Z,1594767712.527 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-07-14T23:02:57.152Z,1594767777.152 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 27
2020-07-14T23:02:57.152Z,1594767777.152 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-07-14T23:02:57.179Z,1594767777.179 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-07-14T23:02:57.564Z,1594767777.564 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-07-14T23:02:57.564Z,1594767777.564 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 27
2020-07-14T23:05:58.148Z,1594767958.148 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 28
2020-07-14T23:05:58.148Z,1594767958.148 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-07-14T23:05:58.158Z,1594767958.158 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-07-14T23:05:58.572Z,1594767958.572 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-07-14T23:05:58.572Z,1594767958.572 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 28
2020-07-14T23:06:53.099Z,1594768013.099 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-07-14T23:06:53.099Z,1594768013.099 [Default:CheckIn:C.Wait] Stopped
2020-07-14T23:06:53.099Z,1594768013.099 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-07-14T23:06:53.100Z,1594768013.100 [Default:CheckIn:D] Running Loop=1
2020-07-14T23:06:53.493Z,1594768013.493 [Default:CheckIn:D] Stopped
2020-07-14T23:06:53.493Z,1594768013.493 [Default:CheckIn:E] Running Loop=1
2020-07-14T23:06:53.915Z,1594768013.915 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 31.822221 min 
2020-07-14T23:06:53.915Z,1594768013.915 [Default:CheckIn:E] Stopped
2020-07-14T23:06:53.916Z,1594768013.916 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-07-14T23:06:53.916Z,1594768013.916 [Default:CheckIn] Stopped
2020-07-14T23:06:53.917Z,1594768013.917 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-07-14T23:06:53.918Z,1594768013.918 [Default:CheckIn](INFO): Running loop #4
2020-07-14T23:06:53.918Z,1594768013.918 [Default:CheckIn] Running Loop=4
2020-07-14T23:06:53.918Z,1594768013.918 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-07-14T23:06:53.918Z,1594768013.918 [Default:CheckIn:Read_GPS] Running Loop=1
2020-07-14T23:08:43.767Z,1594768123.767 [NAL9602](FAULT): GPS failed to acquire within timeout.
2020-07-14T23:08:43.768Z,1594768123.768 [NAL9602] Data Fault, FailCount= 3
2020-07-14T23:08:43.768Z,1594768123.768 [NAL9602](ERROR): Data Fault
2020-07-14T23:08:43.798Z,1594768123.798 [CBIT](ERROR): Data Fault in component: NAL9602
2020-07-14T23:08:44.163Z,1594768124.163 [NAL9602](INFO): Powering down
2020-07-14T23:08:45.005Z,1594768125.005 [CBIT](INFO): Clearing failed state for component NAL9602
2020-07-14T23:08:45.005Z,1594768125.005 [NAL9602] No Fault, FailCount= 3
2020-07-14T23:08:59.142Z,1594768139.142 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 29
2020-07-14T23:08:59.142Z,1594768139.142 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-07-14T23:08:59.163Z,1594768139.163 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-07-14T23:08:59.575Z,1594768139.575 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-07-14T23:08:59.575Z,1594768139.575 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 29
2020-07-14T23:09:14.463Z,1594768154.463 [NAL9602](INFO): Powering up NAL9602
2020-07-14T23:09:25.383Z,1594768165.383 [NAL9602](INFO): NAL9602 initialized
2020-07-14T23:11:54.076Z,1594768314.076 [Default:CheckIn:Read_GPS](INFO): Timed out from 2020-07-14T23:06:53.9Z
2020-07-14T23:11:54.076Z,1594768314.076 [Default:CheckIn:Read_GPS] Stopped
2020-07-14T23:11:54.077Z,1594768314.077 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-07-14T23:11:59.061Z,1594768319.061 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20200714T214120/Courier0019.lzma
2020-07-14T23:12:00.064Z,1594768320.064 [DataOverHttps](INFO): Moved sent file to Logs/20200714T214120/Courier0019.lzma.bak
2020-07-14T23:12:00.064Z,1594768320.064 [DataOverHttps](INFO): SBD MOMSN=12441050
2020-07-14T23:12:00.140Z,1594768320.140 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 30
2020-07-14T23:12:00.141Z,1594768320.141 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-07-14T23:12:00.150Z,1594768320.150 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-07-14T23:12:00.561Z,1594768320.561 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-07-14T23:12:00.561Z,1594768320.561 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 30
2020-07-14T23:12:15.966Z,1594768335.966 [DataOverHttps](INFO): Sending 148 bytes from file Logs/20200714T214120/Express0020.lzma
2020-07-14T23:12:16.964Z,1594768336.964 [DataOverHttps](INFO): Moved sent file to Logs/20200714T214120/Express0020.lzma.bak
2020-07-14T23:12:16.964Z,1594768336.964 [DataOverHttps](INFO): SBD MOMSN=12441052
2020-07-14T23:12:18.324Z,1594768338.324 [Default:CheckIn:Read_Iridium] Stopped
2020-07-14T23:12:18.324Z,1594768338.324 [Default:CheckIn:C.Wait] Running Loop=1
2020-07-14T23:12:18.324Z,1594768338.324 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-07-14T23:15:01.123Z,1594768501.123 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 31
2020-07-14T23:15:01.123Z,1594768501.123 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-07-14T23:15:01.133Z,1594768501.133 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-07-14T23:15:01.571Z,1594768501.571 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-07-14T23:15:01.571Z,1594768501.571 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 31
2020-07-14T23:17:18.903Z,1594768638.903 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-07-14T23:17:18.903Z,1594768638.903 [Default:CheckIn:C.Wait] Stopped
2020-07-14T23:17:18.903Z,1594768638.903 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-07-14T23:17:18.904Z,1594768638.904 [Default:CheckIn:D] Running Loop=1
2020-07-14T23:17:19.300Z,1594768639.300 [Default:CheckIn:D] Stopped
2020-07-14T23:17:19.300Z,1594768639.300 [Default:CheckIn:E] Running Loop=1
2020-07-14T23:17:19.719Z,1594768639.719 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 42.252336 min 
2020-07-14T23:17:19.719Z,1594768639.719 [Default:CheckIn:E] Stopped
2020-07-14T23:17:19.720Z,1594768639.720 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-07-14T23:17:19.720Z,1594768639.720 [Default:CheckIn] Stopped
2020-07-14T23:17:19.720Z,1594768639.720 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-07-14T23:17:19.720Z,1594768639.720 [Default:CheckIn](INFO): Running loop #5
2020-07-14T23:17:19.720Z,1594768639.720 [Default:CheckIn] Running Loop=5
2020-07-14T23:17:19.720Z,1594768639.720 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-07-14T23:17:19.720Z,1594768639.720 [Default:CheckIn:Read_GPS] Running Loop=1
2020-07-14T23:18:02.120Z,1594768682.120 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 32
2020-07-14T23:18:02.120Z,1594768682.120 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-07-14T23:18:02.149Z,1594768682.149 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-07-14T23:18:02.559Z,1594768682.559 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-07-14T23:18:02.559Z,1594768682.559 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 32
2020-07-14T23:19:27.747Z,1594768767.747 [NAL9602](FAULT): GPS failed to acquire within timeout.
2020-07-14T23:19:27.747Z,1594768767.747 [NAL9602] Data Fault, FailCount= 4
2020-07-14T23:19:27.747Z,1594768767.747 [NAL9602](ERROR): Data Fault
2020-07-14T23:19:27.792Z,1594768767.792 [CBIT](ERROR): Data Fault in component: NAL9602
2020-07-14T23:19:28.155Z,1594768768.155 [NAL9602](INFO): Powering down
2020-07-14T23:19:28.992Z,1594768768.992 [CBIT](INFO): Clearing failed state for component NAL9602
2020-07-14T23:19:28.992Z,1594768768.992 [NAL9602] No Fault, FailCount= 4
2020-07-14T23:19:58.455Z,1594768798.455 [NAL9602](INFO): Powering up NAL9602
2020-07-14T23:20:09.360Z,1594768809.360 [NAL9602](INFO): NAL9602 initialized
2020-07-14T23:21:03.134Z,1594768863.134 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 33
2020-07-14T23:21:03.134Z,1594768863.134 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-07-14T23:21:03.144Z,1594768863.144 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-07-14T23:21:03.539Z,1594768863.539 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-07-14T23:21:03.539Z,1594768863.539 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 33
2020-07-14T23:22:19.903Z,1594768939.903 [Default:CheckIn:Read_GPS](INFO): Timed out from 2020-07-14T23:17:19.7Z
2020-07-14T23:22:19.903Z,1594768939.903 [Default:CheckIn:Read_GPS] Stopped
2020-07-14T23:22:19.903Z,1594768939.903 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-07-14T23:22:24.981Z,1594768944.981 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20200714T214120/Courier0022.lzma
2020-07-14T23:22:25.983Z,1594768945.983 [DataOverHttps](INFO): Moved sent file to Logs/20200714T214120/Courier0022.lzma.bak
2020-07-14T23:22:25.984Z,1594768945.984 [DataOverHttps](INFO): SBD MOMSN=12441063
2020-07-14T23:22:41.578Z,1594768961.578 [DataOverHttps](INFO): Sending 150 bytes from file Logs/20200714T214120/Express0023.lzma
2020-07-14T23:22:42.580Z,1594768962.580 [DataOverHttps](INFO): Moved sent file to Logs/20200714T214120/Express0023.lzma.bak
2020-07-14T23:22:42.580Z,1594768962.580 [DataOverHttps](INFO): SBD MOMSN=12441065
2020-07-14T23:22:44.136Z,1594768964.136 [Default:CheckIn:Read_Iridium] Stopped
2020-07-14T23:22:44.136Z,1594768964.136 [Default:CheckIn:C.Wait] Running Loop=1
2020-07-14T23:22:44.136Z,1594768964.136 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-07-14T23:24:04.121Z,1594769044.121 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 34
2020-07-14T23:24:04.121Z,1594769044.121 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-07-14T23:24:04.151Z,1594769044.151 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-07-14T23:24:04.539Z,1594769044.539 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-07-14T23:24:04.539Z,1594769044.539 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 34
2020-07-14T23:27:05.120Z,1594769225.120 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 35
2020-07-14T23:27:05.120Z,1594769225.120 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-07-14T23:27:05.130Z,1594769225.130 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-07-14T23:27:05.530Z,1594769225.530 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-07-14T23:27:05.530Z,1594769225.530 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 35
2020-07-14T23:27:44.709Z,1594769264.709 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-07-14T23:27:44.709Z,1594769264.709 [Default:CheckIn:C.Wait] Stopped
2020-07-14T23:27:44.709Z,1594769264.709 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-07-14T23:27:44.709Z,1594769264.709 [Default:CheckIn:D] Running Loop=1
2020-07-14T23:27:45.116Z,1594769265.116 [Default:CheckIn:D] Stopped
2020-07-14T23:27:45.116Z,1594769265.116 [Default:CheckIn:E] Running Loop=1
2020-07-14T23:27:45.505Z,1594769265.505 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 52.682593 min 
2020-07-14T23:27:45.505Z,1594769265.505 [Default:CheckIn:E] Stopped
2020-07-14T23:27:45.505Z,1594769265.505 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-07-14T23:27:45.505Z,1594769265.505 [Default:CheckIn] Stopped
2020-07-14T23:27:45.505Z,1594769265.505 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-07-14T23:27:45.506Z,1594769265.506 [Default:CheckIn](INFO): Running loop #6
2020-07-14T23:27:45.506Z,1594769265.506 [Default:CheckIn] Running Loop=6
2020-07-14T23:27:45.506Z,1594769265.506 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-07-14T23:27:45.506Z,1594769265.506 [Default:CheckIn:Read_GPS] Running Loop=1
2020-07-14T23:30:06.107Z,1594769406.107 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 36
2020-07-14T23:30:06.107Z,1594769406.107 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-07-14T23:30:06.136Z,1594769406.136 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-07-14T23:30:06.506Z,1594769406.506 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-07-14T23:30:06.506Z,1594769406.506 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 36
2020-07-14T23:30:10.515Z,1594769410.515 [NAL9602](FAULT): GPS failed to acquire within timeout.
2020-07-14T23:30:10.515Z,1594769410.515 [NAL9602] Data Fault, FailCount= 5
2020-07-14T23:30:10.515Z,1594769410.515 [NAL9602](ERROR): Data Fault
2020-07-14T23:30:10.563Z,1594769410.563 [CBIT](ERROR): Data Fault in component: NAL9602
2020-07-14T23:30:10.563Z,1594769410.563 [CBIT](CRITICAL): Data Fault in component: NAL9602
2020-07-14T23:30:10.915Z,1594769410.915 [NAL9602](INFO): Powering down
2020-07-14T23:30:10.944Z,1594769410.944 [CBIT](INFO): Critical error at 20200714T233010
2020-07-14T23:32:10.527Z,1594769530.527 [CBIT](INFO): Clearing failed state for component NAL9602
2020-07-14T23:32:10.528Z,1594769530.528 [NAL9602] No Fault, FailCount= 5
2020-07-14T23:32:10.915Z,1594769530.915 [NAL9602](INFO): Powering up NAL9602
2020-07-14T23:32:21.813Z,1594769541.813 [NAL9602](INFO): NAL9602 initialized
2020-07-14T23:32:45.679Z,1594769565.679 [Default:CheckIn:Read_GPS](INFO): Timed out from 2020-07-14T23:27:45.5Z
2020-07-14T23:32:45.679Z,1594769565.679 [Default:CheckIn:Read_GPS] Stopped
2020-07-14T23:32:45.680Z,1594769565.680 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-07-14T23:32:50.569Z,1594769570.569 [DataOverHttps](INFO): Sending 82 bytes from file Logs/20200714T214120/Courier0025.lzma
2020-07-14T23:32:51.571Z,1594769571.571 [DataOverHttps](INFO): Moved sent file to Logs/20200714T214120/Courier0025.lzma.bak
2020-07-14T23:32:51.572Z,1594769571.572 [DataOverHttps](INFO): SBD MOMSN=12441078
2020-07-14T23:33:07.087Z,1594769587.087 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 37
2020-07-14T23:33:07.087Z,1594769587.087 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-07-14T23:33:07.096Z,1594769587.096 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-07-14T23:33:07.129Z,1594769587.129 [DataOverHttps](INFO): Sending 150 bytes from file Logs/20200714T214120/Express0026.lzma
2020-07-14T23:33:07.503Z,1594769587.503 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-07-14T23:33:07.503Z,1594769587.503 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 37
2020-07-14T23:33:08.128Z,1594769588.128 [DataOverHttps](INFO): Moved sent file to Logs/20200714T214120/Express0026.lzma.bak
2020-07-14T23:33:08.128Z,1594769588.128 [DataOverHttps](INFO): SBD MOMSN=12441081
2020-07-14T23:33:09.536Z,1594769589.536 [Default:CheckIn:Read_Iridium] Stopped
2020-07-14T23:33:09.536Z,1594769589.536 [Default:CheckIn:C.Wait] Running Loop=1
2020-07-14T23:33:09.536Z,1594769589.536 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-07-14T23:36:08.078Z,1594769768.078 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 38
2020-07-14T23:36:08.078Z,1594769768.078 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-07-14T23:36:08.132Z,1594769768.132 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-07-14T23:36:08.510Z,1594769768.510 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-07-14T23:36:08.510Z,1594769768.510 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 38
2020-07-14T23:38:10.091Z,1594769890.091 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-07-14T23:38:10.091Z,1594769890.091 [Default:CheckIn:C.Wait] Stopped
2020-07-14T23:38:10.091Z,1594769890.091 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-07-14T23:38:10.091Z,1594769890.091 [Default:CheckIn:D] Running Loop=1
2020-07-14T23:38:10.508Z,1594769890.508 [Default:CheckIn:D] Stopped
2020-07-14T23:38:10.508Z,1594769890.508 [Default:CheckIn:E] Running Loop=1
2020-07-14T23:38:10.905Z,1594769890.905 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 63.105802 min 
2020-07-14T23:38:10.905Z,1594769890.905 [Default:CheckIn:E] Stopped
2020-07-14T23:38:10.905Z,1594769890.905 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-07-14T23:38:10.905Z,1594769890.905 [Default:CheckIn] Stopped
2020-07-14T23:38:10.905Z,1594769890.905 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-07-14T23:38:10.905Z,1594769890.905 [Default:CheckIn](INFO): Running loop #7
2020-07-14T23:38:10.905Z,1594769890.905 [Default:CheckIn] Running Loop=7
2020-07-14T23:38:10.905Z,1594769890.905 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-07-14T23:38:10.905Z,1594769890.905 [Default:CheckIn:Read_GPS] Running Loop=1
2020-07-14T23:39:09.073Z,1594769949.073 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 39
2020-07-14T23:39:09.073Z,1594769949.073 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-07-14T23:39:09.083Z,1594769949.083 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-07-14T23:39:09.495Z,1594769949.495 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-07-14T23:39:09.495Z,1594769949.495 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 39
2020-07-14T23:42:10.060Z,1594770130.060 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 40
2020-07-14T23:42:10.060Z,1594770130.060 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-07-14T23:42:10.070Z,1594770130.070 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-07-14T23:42:10.481Z,1594770130.481 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-07-14T23:42:10.481Z,1594770130.481 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 40
2020-07-14T23:42:24.980Z,1594770144.980 [NAL9602](FAULT): GPS failed to acquire within timeout.
2020-07-14T23:42:24.980Z,1594770144.980 [NAL9602] Data Fault, FailCount= 1
2020-07-14T23:42:24.980Z,1594770144.980 [NAL9602](ERROR): Data Fault
2020-07-14T23:42:25.028Z,1594770145.028 [CBIT](ERROR): Data Fault in component: NAL9602
2020-07-14T23:42:25.387Z,1594770145.387 [NAL9602](INFO): Powering down
2020-07-14T23:42:26.232Z,1594770146.232 [CBIT](INFO): Clearing failed state for component NAL9602
2020-07-14T23:42:26.232Z,1594770146.232 [NAL9602] No Fault, FailCount= 1
2020-07-14T23:42:55.687Z,1594770175.687 [NAL9602](INFO): Powering up NAL9602
2020-07-14T23:43:06.611Z,1594770186.611 [NAL9602](INFO): NAL9602 initialized
2020-07-14T23:43:11.057Z,1594770191.057 [Default:CheckIn:Read_GPS](INFO): Timed out from 2020-07-14T23:38:10.9Z
2020-07-14T23:43:11.058Z,1594770191.058 [Default:CheckIn:Read_GPS] Stopped
2020-07-14T23:43:11.058Z,1594770191.058 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-07-14T23:43:15.961Z,1594770195.961 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20200714T214120/Courier0028.lzma
2020-07-14T23:43:16.963Z,1594770196.963 [DataOverHttps](INFO): Moved sent file to Logs/20200714T214120/Courier0028.lzma.bak
2020-07-14T23:43:16.964Z,1594770196.964 [DataOverHttps](INFO): SBD MOMSN=12441094
2020-07-14T23:43:32.350Z,1594770212.350 [DataOverHttps](INFO): Sending 148 bytes from file Logs/20200714T214120/Express0029.lzma
2020-07-14T23:43:33.351Z,1594770213.351 [DataOverHttps](INFO): Moved sent file to Logs/20200714T214120/Express0029.lzma.bak
2020-07-14T23:43:33.352Z,1594770213.352 [DataOverHttps](INFO): SBD MOMSN=12441096
2020-07-14T23:43:34.900Z,1594770214.900 [Default:CheckIn:Read_Iridium] Stopped
2020-07-14T23:43:34.900Z,1594770214.900 [Default:CheckIn:C.Wait] Running Loop=1
2020-07-14T23:43:34.900Z,1594770214.900 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-07-14T23:45:11.065Z,1594770311.065 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 41
2020-07-14T23:45:11.066Z,1594770311.066 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-07-14T23:45:11.075Z,1594770311.075 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-07-14T23:45:11.484Z,1594770311.484 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-07-14T23:45:11.484Z,1594770311.484 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 41
2020-07-14T23:48:12.070Z,1594770492.070 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 42
2020-07-14T23:48:12.070Z,1594770492.070 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-07-14T23:48:12.080Z,1594770492.080 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-07-14T23:48:12.488Z,1594770492.488 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-07-14T23:48:12.488Z,1594770492.488 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 42
2020-07-14T23:48:35.476Z,1594770515.476 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-07-14T23:48:35.476Z,1594770515.476 [Default:CheckIn:C.Wait] Stopped
2020-07-14T23:48:35.476Z,1594770515.476 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-07-14T23:48:35.476Z,1594770515.476 [Default:CheckIn:D] Running Loop=1
2020-07-14T23:48:35.890Z,1594770515.890 [Default:CheckIn:D] Stopped
2020-07-14T23:48:35.890Z,1594770515.890 [Default:CheckIn:E] Running Loop=1
2020-07-14T23:48:36.296Z,1594770516.296 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 73.528825 min 
2020-07-14T23:48:36.296Z,1594770516.296 [Default:CheckIn:E] Stopped
2020-07-14T23:48:36.296Z,1594770516.296 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-07-14T23:48:36.297Z,1594770516.297 [Default:CheckIn] Stopped
2020-07-14T23:48:36.297Z,1594770516.297 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-07-14T23:48:36.297Z,1594770516.297 [Default:CheckIn](INFO): Running loop #8
2020-07-14T23:48:36.297Z,1594770516.297 [Default:CheckIn] Running Loop=8
2020-07-14T23:48:36.297Z,1594770516.297 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-07-14T23:48:36.297Z,1594770516.297 [Default:CheckIn:Read_GPS] Running Loop=1
2020-07-14T23:51:13.062Z,1594770673.062 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 43
2020-07-14T23:51:13.062Z,1594770673.062 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-07-14T23:51:13.072Z,1594770673.072 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-07-14T23:51:13.467Z,1594770673.467 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-07-14T23:51:13.467Z,1594770673.467 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 43
2020-07-14T23:53:08.967Z,1594770788.967 [NAL9602](FAULT): GPS failed to acquire within timeout.
2020-07-14T23:53:08.967Z,1594770788.967 [NAL9602] Data Fault, FailCount= 2
2020-07-14T23:53:08.967Z,1594770788.967 [NAL9602](ERROR): Data Fault
2020-07-14T23:53:09.014Z,1594770789.014 [CBIT](ERROR): Data Fault in component: NAL9602
2020-07-14T23:53:09.367Z,1594770789.367 [NAL9602](INFO): Powering down
2020-07-14T23:53:10.210Z,1594770790.210 [CBIT](INFO): Clearing failed state for component NAL9602
2020-07-14T23:53:10.211Z,1594770790.211 [NAL9602] No Fault, FailCount= 2
2020-07-14T23:53:36.460Z,1594770816.460 [Default:CheckIn:Read_GPS](INFO): Timed out from 2020-07-14T23:48:36.3Z
2020-07-14T23:53:36.460Z,1594770816.460 [Default:CheckIn:Read_GPS] Stopped
2020-07-14T23:53:36.460Z,1594770816.460 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-07-14T23:53:39.703Z,1594770819.703 [NAL9602](INFO): Powering up NAL9602
2020-07-14T23:53:40.333Z,1594770820.333 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20200714T214120/Courier0031.lzma
2020-07-14T23:53:41.263Z,1594770821.263 [DataOverHttps](INFO): Moved sent file to Logs/20200714T214120/Courier0031.lzma.bak
2020-07-14T23:53:41.264Z,1594770821.264 [DataOverHttps](INFO): SBD MOMSN=12441107
2020-07-14T23:53:50.619Z,1594770830.619 [NAL9602](INFO): NAL9602 initialized
2020-07-14T23:53:56.894Z,1594770836.894 [DataOverHttps](INFO): Sending 149 bytes from file Logs/20200714T214120/Express0032.lzma
2020-07-14T23:53:57.896Z,1594770837.896 [DataOverHttps](INFO): Moved sent file to Logs/20200714T214120/Express0032.lzma.bak
2020-07-14T23:53:57.896Z,1594770837.896 [DataOverHttps](INFO): SBD MOMSN=12441109
2020-07-14T23:53:59.121Z,1594770839.121 [Default:CheckIn:Read_Iridium] Stopped
2020-07-14T23:53:59.122Z,1594770839.122 [Default:CheckIn:C.Wait] Running Loop=1
2020-07-14T23:53:59.122Z,1594770839.122 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-07-14T23:54:14.081Z,1594770854.081 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 44
2020-07-14T23:54:14.081Z,1594770854.081 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-07-14T23:54:14.091Z,1594770854.091 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-07-14T23:54:14.500Z,1594770854.500 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-07-14T23:54:14.500Z,1594770854.500 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 44
2020-07-14T23:57:15.083Z,1594771035.083 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 45
2020-07-14T23:57:15.083Z,1594771035.083 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-07-14T23:57:15.093Z,1594771035.093 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-07-14T23:57:15.491Z,1594771035.491 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-07-14T23:57:15.491Z,1594771035.491 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 45
2020-07-14T23:58:59.714Z,1594771139.714 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-07-14T23:58:59.714Z,1594771139.714 [Default:CheckIn:C.Wait] Stopped
2020-07-14T23:58:59.714Z,1594771139.714 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-07-14T23:58:59.715Z,1594771139.715 [Default:CheckIn:D] Running Loop=1
2020-07-14T23:59:00.098Z,1594771140.098 [Default:CheckIn:D] Stopped
2020-07-14T23:59:00.098Z,1594771140.098 [Default:CheckIn:E] Running Loop=1
2020-07-14T23:59:00.547Z,1594771140.547 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 83.932308 min 
2020-07-14T23:59:00.547Z,1594771140.547 [Default:CheckIn:E] Stopped
2020-07-14T23:59:00.547Z,1594771140.547 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-07-14T23:59:00.547Z,1594771140.547 [Default:CheckIn] Stopped
2020-07-14T23:59:00.547Z,1594771140.547 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-07-14T23:59:00.547Z,1594771140.547 [Default:CheckIn](INFO): Running loop #9
2020-07-14T23:59:00.547Z,1594771140.547 [Default:CheckIn] Running Loop=9
2020-07-14T23:59:00.547Z,1594771140.547 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-07-14T23:59:00.548Z,1594771140.548 [Default:CheckIn:Read_GPS] Running Loop=1
2020-07-15T00:00:16.070Z,1594771216.070 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 46
2020-07-15T00:00:16.070Z,1594771216.070 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-07-15T00:00:16.080Z,1594771216.080 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-07-15T00:00:16.487Z,1594771216.487 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-07-15T00:00:16.487Z,1594771216.487 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 46
2020-07-15T00:03:17.047Z,1594771397.047 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 47
2020-07-15T00:03:17.047Z,1594771397.047 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-07-15T00:03:17.057Z,1594771397.057 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-07-15T00:03:17.460Z,1594771397.460 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-07-15T00:03:17.460Z,1594771397.460 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 47
2020-07-15T00:03:53.812Z,1594771433.812 [NAL9602](FAULT): GPS failed to acquire within timeout.
2020-07-15T00:03:53.812Z,1594771433.812 [NAL9602] Data Fault, FailCount= 3
2020-07-15T00:03:53.812Z,1594771433.812 [NAL9602](ERROR): Data Fault
2020-07-15T00:03:53.881Z,1594771433.881 [CBIT](ERROR): Data Fault in component: NAL9602
2020-07-15T00:03:54.207Z,1594771434.207 [NAL9602](INFO): Powering down
2020-07-15T00:03:55.053Z,1594771435.053 [CBIT](INFO): Clearing failed state for component NAL9602
2020-07-15T00:03:55.053Z,1594771435.053 [NAL9602] No Fault, FailCount= 3
2020-07-15T00:04:00.705Z,1594771440.705 [Default:CheckIn:Read_GPS](INFO): Timed out from 2020-07-14T23:59:00.5Z
2020-07-15T00:04:00.705Z,1594771440.705 [Default:CheckIn:Read_GPS] Stopped
2020-07-15T00:04:00.706Z,1594771440.706 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-07-15T00:04:06.313Z,1594771446.313 [DataOverHttps](INFO): Sending 39 bytes from file Logs/20200714T214120/Courier0034.lzma
2020-07-15T00:04:07.315Z,1594771447.315 [DataOverHttps](INFO): Moved sent file to Logs/20200714T214120/Courier0034.lzma.bak
2020-07-15T00:04:07.316Z,1594771447.316 [DataOverHttps](INFO): SBD MOMSN=12441121
2020-07-15T00:04:22.922Z,1594771462.922 [DataOverHttps](INFO): Sending 148 bytes from file Logs/20200714T214120/Express0035.lzma
2020-07-15T00:04:23.924Z,1594771463.924 [DataOverHttps](INFO): Moved sent file to Logs/20200714T214120/Express0035.lzma.bak
2020-07-15T00:04:23.924Z,1594771463.924 [DataOverHttps](INFO): SBD MOMSN=12441123
2020-07-15T00:04:24.507Z,1594771464.507 [NAL9602](INFO): Powering up NAL9602
2020-07-15T00:04:25.344Z,1594771465.344 [Default:CheckIn:Read_Iridium] Stopped
2020-07-15T00:04:25.344Z,1594771465.344 [Default:CheckIn:C.Wait] Running Loop=1
2020-07-15T00:04:25.344Z,1594771465.344 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-07-15T00:04:35.419Z,1594771475.419 [NAL9602](INFO): NAL9602 initialized
2020-07-15T00:05:33.621Z,1594771533.621 [BPC1](ERROR): BPC1B: No match for serial number 1717 in BPC1B's battery stick inventory (sticks 32-63 in onboard configuration file).
2020-07-15T00:05:38.883Z,1594771538.883 [BPC1](FAULT): Battery stick #6 (s/n: 00CA) reported TERMINATE_DISCHARGE_ALARM. Status code: 0x48C0.
2020-07-15T00:05:38.884Z,1594771538.884 [BPC1](INFO): Calculating totals. Valid battery stick count: 55. Valid reserve battery stick count: 6.
2020-07-15T00:05:38.887Z,1594771538.887 [BPC1](INFO): Received data from all battery sticks.
2020-07-15T00:06:18.061Z,1594771578.061 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 48
2020-07-15T00:06:18.061Z,1594771578.061 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-07-15T00:06:18.071Z,1594771578.071 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-07-15T00:06:18.491Z,1594771578.491 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-07-15T00:06:18.491Z,1594771578.491 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 48
2020-07-15T00:09:19.059Z,1594771759.059 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 49
2020-07-15T00:09:19.059Z,1594771759.059 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2020-07-15T00:09:19.069Z,1594771759.069 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2020-07-15T00:09:19.510Z,1594771759.510 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2020-07-15T00:09:19.511Z,1594771759.510 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 49
2020-07-15T00:09:25.951Z,1594771765.951 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-07-15T00:09:25.951Z,1594771765.951 [Default:CheckIn:C.Wait] Stopped
2020-07-15T00:09:25.952Z,1594771765.952 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-07-15T00:09:25.952Z,1594771765.952 [Default:CheckIn:D] Running Loop=1
2020-07-15T00:09:26.346Z,1594771766.346 [Default:CheckIn:D] Stopped
2020-07-15T00:09:26.346Z,1594771766.346 [Default:CheckIn:E] Running Loop=1
2020-07-15T00:09:26.736Z,1594771766.736 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 94.369775 min 
2020-07-15T00:09:26.736Z,1594771766.736 [Default:CheckIn:E] Stopped
2020-07-15T00:09:26.736Z,1594771766.736 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-07-15T00:09:26.737Z,1594771766.737 [Default:CheckIn] Stopped
2020-07-15T00:09:26.737Z,1594771766.737 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-07-15T00:09:26.737Z,1594771766.737 [Default:CheckIn](INFO): Running loop #10
2020-07-15T00:09:26.737Z,1594771766.737 [Default:CheckIn] Running Loop=10
2020-07-15T00:09:26.737Z,1594771766.737 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-07-15T00:09:26.737Z,1594771766.737 [Default:CheckIn:Read_GPS] Running Loop=1
2020-07-15T00:10:15.207Z,1594771815.207 [CommandLine](IMPORTANT): got command quit
2020-07-15T00:10:16.215Z,1594771816.215 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2020-07-15T00:10:16.216Z,1594771816.216 [CommandLine ThreadHandler](INFO): Thread cancelled.
2020-07-15T00:10:16.326Z,1594771816.326 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2020-07-15T00:10:16.326Z,1594771816.326 [CommandLine ThreadHandler](INFO): Thread cancelled.
2020-07-15T00:10:16.327Z,1594771816.327 [CommandLine](INFO): Join timeout helper Thread ID is 1327
2020-07-15T00:10:16.327Z,1594771816.327 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2020-07-15T00:10:16.327Z,1594771816.327 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2020-07-15T00:10:16.327Z,1594771816.327 [NavChartDb](INFO): Join timeout helper Thread ID is 1328
2020-07-15T00:10:16.586Z,1594771816.586 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2020-07-15T00:10:16.586Z,1594771816.586 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2020-07-15T00:10:16.606Z,1594771816.606 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2020-07-15T00:10:16.606Z,1594771816.606 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2020-07-15T00:10:16.606Z,1594771816.606 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 1329
2020-07-15T00:10:17.010Z,1594771817.010 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2020-07-15T00:10:17.010Z,1594771817.010 [WetLabsBB2FL](INFO): Powering down
2020-07-15T00:10:17.012Z,1594771817.012 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2020-07-15T00:10:17.026Z,1594771817.026 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2020-07-15T00:10:17.026Z,1594771817.026 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2020-07-15T00:10:17.026Z,1594771817.026 [CTD_Seabird](INFO): Join timeout helper Thread ID is 1330
2020-07-15T00:10:17.502Z,1594771817.502 [CTD_Seabird](INFO): Powering down
2020-07-15T00:10:17.514Z,1594771817.514 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2020-07-15T00:10:17.514Z,1594771817.514 [CTD_Seabird](INFO): Powering down
2020-07-15T00:10:17.526Z,1594771817.526 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2020-07-15T00:10:17.526Z,1594771817.526 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2020-07-15T00:10:17.526Z,1594771817.526 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2020-07-15T00:10:17.527Z,1594771817.527 [Radio_Surface](INFO): Join timeout helper Thread ID is 1331
2020-07-15T00:10:17.742Z,1594771817.742 [Radio_Surface](INFO): Powering down
2020-07-15T00:10:17.743Z,1594771817.743 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2020-07-15T00:10:17.743Z,1594771817.743 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2020-07-15T00:10:17.755Z,1594771817.755 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2020-07-15T00:10:17.755Z,1594771817.755 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2020-07-15T00:10:17.755Z,1594771817.755 [DataOverHttps](INFO): Join timeout helper Thread ID is 1332
2020-07-15T00:10:18.338Z,1594771818.338 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2020-07-15T00:10:18.338Z,1594771818.338 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2020-07-15T00:10:18.342Z,1594771818.342 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2020-07-15T00:10:18.343Z,1594771818.343 [logger ThreadHandler](INFO): Thread cancelled.
2020-07-15T00:10:18.343Z,1594771818.343 [logger](INFO): Join timeout helper Thread ID is 1333
2020-07-15T00:10:18.382Z,1594771818.382 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2020-07-15T00:10:18.382Z,1594771818.382 [logger ThreadHandler](INFO): Thread cancelled.
2020-07-15T00:10:18.402Z,1594771818.402 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2020-07-15T00:10:18.403Z,1594771818.403 [CommandLine ThreadHandler](INFO): Thread cancelled.
2020-07-15T00:10:18.403Z,1594771818.403 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2020-07-15T00:10:18.403Z,1594771818.403 [controlThread ThreadHandler](INFO): Thread cancelled.
2020-07-15T00:10:18.403Z,1594771818.403 [controlThread](INFO): Join timeout helper Thread ID is 1334
2020-07-15T00:10:18.410Z,1594771818.410 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2020-07-15T00:10:18.410Z,1594771818.410 [controlThread](DEBUG): Uninitializing ControlThread
2020-07-15T00:10:18.410Z,1594771818.410 [AHRS_M2](INFO): Powering down
2020-07-15T00:10:18.482Z,1594771818.482 [NAL9602](INFO): Powering down
2020-07-15T00:10:18.485Z,1594771818.485 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2020-07-15T00:10:18.486Z,1594771818.486 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2020-07-15T00:10:18.487Z,1594771818.487 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2020-07-15T00:10:18.487Z,1594771818.487 [MissionManager](INFO): Uninitializing Mission Default
2020-07-15T00:10:18.487Z,1594771818.487 [Default] Stopped
2020-07-15T00:10:18.488Z,1594771818.488 [Default](DEBUG): Aggregate::uninitialize Default
2020-07-15T00:10:18.488Z,1594771818.488 [Default:B.GoToSurface] Stopped
2020-07-15T00:10:18.488Z,1594771818.488 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2020-07-15T00:10:18.488Z,1594771818.488 [Default:CheckIn] Stopped
2020-07-15T00:10:18.488Z,1594771818.488 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-07-15T00:10:18.488Z,1594771818.488 [Default:CheckIn:Read_GPS] Stopped
2020-07-15T00:10:18.490Z,1594771818.490 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2020-07-15T00:10:18.491Z,1594771818.491 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2020-07-15T00:10:18.491Z,1594771818.491 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2020-07-15T00:10:18.491Z,1594771818.491 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2020-07-15T00:10:18.492Z,1594771818.492 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2020-07-15T00:10:18.492Z,1594771818.492 [BuoyancyServo](INFO): Powering down
2020-07-15T00:10:18.506Z,1594771818.506 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2020-07-15T00:10:18.506Z,1594771818.506 [ElevatorServo](INFO): Powering down
2020-07-15T00:10:18.507Z,1594771818.507 [MassServo](DEBUG): Uninitialize Mass Servo.
2020-07-15T00:10:18.507Z,1594771818.507 [MassServo](INFO): Powering down
2020-07-15T00:10:18.508Z,1594771818.508 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2020-07-15T00:10:18.508Z,1594771818.508 [RudderServo](INFO): Powering down
2020-07-15T00:10:18.509Z,1594771818.509 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2020-07-15T00:10:18.509Z,1594771818.509 [ThrusterServo](INFO): Powering down
2020-07-15T00:10:18.510Z,1594771818.510 [SBIT](DEBUG): Uninitialize SBIT Component.
2020-07-15T00:10:18.510Z,1594771818.510 [IBIT](DEBUG): Uninitialize IBIT Component.
2020-07-15T00:10:18.510Z,1594771818.510 [CBIT](DEBUG): Uninitialize CBIT Component.
2020-07-15T00:10:18.510Z,1594771818.510 [CBIT](DEBUG): Powering off loads.
2020-07-15T00:10:18.522Z,1594771818.522 [CBIT](DEBUG): Disabling WDT.
2020-07-15T00:10:18.534Z,1594771818.534 [CBIT](DEBUG): Opening all GF detection circuits.
2020-07-15T00:10:18.534Z,1594771818.534 [controlThread ThreadHandler](INFO): Thread cancelled.
2020-07-15T00:10:18.614Z,1594771818.614 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2020-07-15T00:10:18.621Z,1594771818.621 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2020-07-15T00:10:18.680Z,1594771818.680 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2020-07-15T00:10:18.763Z,1594771818.763 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2020-07-15T00:10:18.789Z,1594771818.789 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2020-07-15T00:10:18.852Z,1594771818.852 [logger ThreadHandler](INFO): Thread cancelled.