2020-10-07T19:42:02.644Z,1602099722.644 [Supervisor](DEBUG): Initializing supervisor.
2020-10-07T19:42:02.647Z,1602099722.647 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2020-10-07T19:42:02.647Z,1602099722.647 [SyncHandler](INFO): Protected caller Thread ID is 819
2020-10-07T19:42:02.648Z,1602099722.648 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2020-10-07T19:42:02.649Z,1602099722.649 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2020-10-07T19:42:02.649Z,1602099722.649 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 820
2020-10-07T19:42:02.652Z,1602099722.652 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2020-10-07T19:42:02.669Z,1602099722.669 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2020-10-07T19:42:02.670Z,1602099722.670 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2020-10-07T19:42:02.670Z,1602099722.670 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 821
2020-10-07T19:42:02.671Z,1602099722.671 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2020-10-07T19:42:02.671Z,1602099722.671 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2020-10-07T19:42:02.672Z,1602099722.672 [logger ThreadHandler](INFO): Protected caller Thread ID is 822
2020-10-07T19:42:02.674Z,1602099722.674 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2020-10-07T19:42:02.674Z,1602099722.674 [Supervisor](INFO): Looking for Config files in directory: Config/
2020-10-07T19:42:02.678Z,1602099722.678 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2020-10-07T19:42:02.772Z,1602099722.772 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2020-10-07T19:42:02.774Z,1602099722.774 [Supervisor](INFO): Opening Config file at: Config/Dock.cfg
2020-10-07T19:42:02.957Z,1602099722.957 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Dock
2020-10-07T19:42:02.958Z,1602099722.958 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2020-10-07T19:42:03.155Z,1602099723.155 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2020-10-07T19:42:03.157Z,1602099723.157 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2020-10-07T19:42:03.294Z,1602099723.294 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2020-10-07T19:42:03.294Z,1602099723.294 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2020-10-07T19:42:03.879Z,1602099723.879 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2020-10-07T19:42:03.881Z,1602099723.881 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2020-10-07T19:42:04.337Z,1602099724.337 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2020-10-07T19:42:04.338Z,1602099724.338 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2020-10-07T19:42:04.832Z,1602099724.832 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2020-10-07T19:42:04.833Z,1602099724.833 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2020-10-07T19:42:05.136Z,1602099725.136 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2020-10-07T19:42:05.137Z,1602099725.137 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2020-10-07T19:42:05.446Z,1602099725.446 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2020-10-07T19:42:05.446Z,1602099725.446 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2020-10-07T19:42:05.850Z,1602099725.850 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2020-10-07T19:42:05.851Z,1602099725.851 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2020-10-07T19:42:05.997Z,1602099725.997 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2020-10-07T19:42:05.998Z,1602099725.998 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2020-10-07T19:42:06.528Z,1602099726.528 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2020-10-07T19:42:06.529Z,1602099726.529 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2020-10-07T19:42:06.610Z,1602099726.610 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2020-10-07T19:42:06.709Z,1602099726.709 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2020-10-07T19:42:06.710Z,1602099726.710 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2020-10-07T19:42:06.898Z,1602099726.898 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2020-10-07T19:42:06.900Z,1602099726.900 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2020-10-07T19:42:07.104Z,1602099727.104 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2020-10-07T19:42:07.106Z,1602099727.106 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/
2020-10-07T19:42:07.108Z,1602099727.108 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/secure.cfg
2020-10-07T19:42:07.191Z,1602099727.191 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Battery.cfg
2020-10-07T19:42:07.437Z,1602099727.437 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2020-10-07T19:42:07.437Z,1602099727.437 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Navigation.cfg
2020-10-07T19:42:07.530Z,1602099727.530 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Sensor.cfg
2020-10-07T19:42:07.690Z,1602099727.690 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/vehicle.cfg
2020-10-07T19:42:07.887Z,1602099727.887 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Simulator.cfg
2020-10-07T19:42:07.971Z,1602099727.971 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Servo.cfg
2020-10-07T19:42:08.070Z,1602099728.070 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Control.cfg
2020-10-07T19:42:08.160Z,1602099728.160 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Science.cfg
2020-10-07T19:42:08.317Z,1602099728.317 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/logger.cfg
2020-10-07T19:42:08.419Z,1602099728.419 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/BIT.cfg
2020-10-07T19:42:08.515Z,1602099728.515 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2020-10-07T19:42:08.527Z,1602099728.527 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2020-10-07T19:42:08.652Z,1602099728.652 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2020-10-07T19:42:08.654Z,1602099728.654 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2020-10-07T19:42:08.810Z,1602099728.810 [BuoyancyServo] Loaded
2020-10-07T19:42:08.810Z,1602099728.810 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2020-10-07T19:42:08.827Z,1602099728.827 [ElevatorServo] Loaded
2020-10-07T19:42:08.827Z,1602099728.827 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2020-10-07T19:42:08.844Z,1602099728.844 [MassServo] Loaded
2020-10-07T19:42:08.844Z,1602099728.844 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2020-10-07T19:42:08.861Z,1602099728.861 [RudderServo] Loaded
2020-10-07T19:42:08.861Z,1602099728.861 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2020-10-07T19:42:08.876Z,1602099728.876 [ThrusterServo] Loaded
2020-10-07T19:42:08.877Z,1602099728.877 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2020-10-07T19:42:08.877Z,1602099728.877 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2020-10-07T19:42:08.879Z,1602099728.879 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2020-10-07T19:42:09.038Z,1602099729.038 [SBIT](DEBUG): Construct Startup Built In Test.
2020-10-07T19:42:09.052Z,1602099729.052 [SBIT] Loaded
2020-10-07T19:42:09.052Z,1602099729.052 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2020-10-07T19:42:09.053Z,1602099729.053 [IBIT](DEBUG): Construct Initiated Built In Test.
2020-10-07T19:42:09.072Z,1602099729.072 [IBIT] Loaded
2020-10-07T19:42:09.073Z,1602099729.073 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2020-10-07T19:42:09.075Z,1602099729.075 [CBIT](DEBUG): Construct Continuous Built In Test.
2020-10-07T19:42:09.271Z,1602099729.271 [CBIT] Loaded
2020-10-07T19:42:09.271Z,1602099729.271 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2020-10-07T19:42:09.271Z,1602099729.271 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2020-10-07T19:42:09.273Z,1602099729.273 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2020-10-07T19:42:09.543Z,1602099729.543 [CANONSampler] Loaded
2020-10-07T19:42:09.544Z,1602099729.544 [ComponentRegistry](DEBUG): SyncComponent "CANONSampler" handled in the control thread.
2020-10-07T19:42:09.561Z,1602099729.561 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_density
2020-10-07T19:42:09.564Z,1602099729.564 [CTD_Seabird](INFO): created writer for : sea_water_density
2020-10-07T19:42:09.566Z,1602099729.566 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): depth
2020-10-07T19:42:09.568Z,1602099729.568 [CTD_Seabird](INFO): created writer for : depth
2020-10-07T19:42:09.569Z,1602099729.569 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_pressure
2020-10-07T19:42:09.571Z,1602099729.571 [CTD_Seabird](INFO): created writer for : sea_water_pressure
2020-10-07T19:42:09.572Z,1602099729.572 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_salinity
2020-10-07T19:42:09.575Z,1602099729.575 [CTD_Seabird](INFO): created writer for : sea_water_salinity
2020-10-07T19:42:09.575Z,1602099729.575 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_temperature
2020-10-07T19:42:09.578Z,1602099729.578 [CTD_Seabird](INFO): created writer for : sea_water_temperature
2020-10-07T19:42:09.579Z,1602099729.579 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_electrical_conductivity
2020-10-07T19:42:09.582Z,1602099729.582 [CTD_Seabird](INFO): created writer for : sea_water_electrical_conductivity
2020-10-07T19:42:09.582Z,1602099729.582 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): speed_of_sound_in_sea_water
2020-10-07T19:42:09.585Z,1602099729.585 [CTD_Seabird](INFO): created writer for : speed_of_sound_in_sea_water
2020-10-07T19:42:09.585Z,1602099729.585 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): mass_concentration_of_oxygen_in_sea_water
2020-10-07T19:42:09.588Z,1602099729.588 [CTD_Seabird](INFO): created writer for : mass_concentration_of_oxygen_in_sea_water
2020-10-07T19:42:09.589Z,1602099729.589 [CTD_Seabird](DEBUG): LcmSlateWriter::add(DAtaURI): CTD_Seabird.sea_water_dissolved_oxygen_freq
2020-10-07T19:42:09.589Z,1602099729.589 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): dataName: sea_water_dissolved_oxygen_freq
2020-10-07T19:42:09.604Z,1602099729.604 [CTD_Seabird] Loaded
2020-10-07T19:42:09.604Z,1602099729.604 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2020-10-07T19:42:09.605Z,1602099729.605 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 406784E0
2020-10-07T19:42:09.606Z,1602099729.606 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 904
2020-10-07T19:42:09.633Z,1602099729.633 [ESPComponent] Loaded
2020-10-07T19:42:09.633Z,1602099729.633 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread.
2020-10-07T19:42:09.650Z,1602099729.650 [PAR_Licor] Loaded
2020-10-07T19:42:09.650Z,1602099729.650 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2020-10-07T19:42:09.662Z,1602099729.662 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.Output470
2020-10-07T19:42:09.662Z,1602099729.662 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: Output470
2020-10-07T19:42:09.664Z,1602099729.664 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.Output650
2020-10-07T19:42:09.664Z,1602099729.664 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: Output650
2020-10-07T19:42:09.666Z,1602099729.666 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.OutputChl
2020-10-07T19:42:09.666Z,1602099729.666 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: OutputChl
2020-10-07T19:42:09.668Z,1602099729.668 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.VolumeScatCoeff117deg470nm
2020-10-07T19:42:09.668Z,1602099729.668 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: VolumeScatCoeff117deg470nm
2020-10-07T19:42:09.670Z,1602099729.670 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.VolumeScatCoeff117deg650nm
2020-10-07T19:42:09.670Z,1602099729.670 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: VolumeScatCoeff117deg650nm
2020-10-07T19:42:09.672Z,1602099729.672 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.BackscatteringCoeff470nm
2020-10-07T19:42:09.672Z,1602099729.672 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: BackscatteringCoeff470nm
2020-10-07T19:42:09.674Z,1602099729.674 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.BackscatteringCoeff650nm
2020-10-07T19:42:09.674Z,1602099729.674 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: BackscatteringCoeff650nm
2020-10-07T19:42:09.676Z,1602099729.676 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): mass_concentration_of_chlorophyll_in_sea_water
2020-10-07T19:42:09.678Z,1602099729.678 [WetLabsBB2FL](INFO): created writer for : mass_concentration_of_chlorophyll_in_sea_water
2020-10-07T19:42:09.679Z,1602099729.679 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_median_mass_concentration_of_chlorophyll_in_sea_water
2020-10-07T19:42:09.679Z,1602099729.679 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_median_mass_concentration_of_chlorophyll_in_sea_water
2020-10-07T19:42:09.681Z,1602099729.681 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_mean_mass_concentration_of_chlorophyll_in_sea_water
2020-10-07T19:42:09.681Z,1602099729.681 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_mean_mass_concentration_of_chlorophyll_in_sea_water
2020-10-07T19:42:09.683Z,1602099729.683 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(DAtaURI): WetLabsBB2FL.bin_variance_mass_concentration_of_chlorophyll_in_sea_water
2020-10-07T19:42:09.683Z,1602099729.683 [WetLabsBB2FL](DEBUG): LcmSlateWriter::add(): dataName: bin_variance_mass_concentration_of_chlorophyll_in_sea_water
2020-10-07T19:42:09.685Z,1602099729.685 [WetLabsBB2FL] Loaded
2020-10-07T19:42:09.685Z,1602099729.685 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2020-10-07T19:42:09.686Z,1602099729.686 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 406A84E0
2020-10-07T19:42:09.686Z,1602099729.686 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 905
2020-10-07T19:42:09.687Z,1602099729.687 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2020-10-07T19:42:09.689Z,1602099729.689 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2020-10-07T19:42:09.740Z,1602099729.740 [DepthRateCalculator] Loaded
2020-10-07T19:42:09.740Z,1602099729.740 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2020-10-07T19:42:09.743Z,1602099729.743 [PitchRateCalculator] Loaded
2020-10-07T19:42:09.743Z,1602099729.743 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2020-10-07T19:42:09.751Z,1602099729.751 [SpeedCalculator] Loaded
2020-10-07T19:42:09.752Z,1602099729.752 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2020-10-07T19:42:09.762Z,1602099729.762 [TempGradientCalculator] Loaded
2020-10-07T19:42:09.762Z,1602099729.762 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2020-10-07T19:42:09.765Z,1602099729.765 [YawRateCalculator] Loaded
2020-10-07T19:42:09.766Z,1602099729.766 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2020-10-07T19:42:09.781Z,1602099729.781 [ElevatorOffsetCalculator] Loaded
2020-10-07T19:42:09.781Z,1602099729.781 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2020-10-07T19:42:09.781Z,1602099729.781 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2020-10-07T19:42:09.782Z,1602099729.782 [Module Loader](DEBUG): Loading Module at Modules/Dock.so
2020-10-07T19:42:09.877Z,1602099729.877 [Module Loader](DEBUG): Loaded Module: Dock (Contains behaviors and commands for docking)
2020-10-07T19:42:09.879Z,1602099729.879 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2020-10-07T19:42:09.919Z,1602099729.919 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2020-10-07T19:42:09.919Z,1602099729.919 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2020-10-07T19:42:10.015Z,1602099730.015 [DeadReckonUsingMultipleVelocitySources] Loaded
2020-10-07T19:42:10.015Z,1602099730.015 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2020-10-07T19:42:10.026Z,1602099730.026 [NavChart] Loaded
2020-10-07T19:42:10.026Z,1602099730.026 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2020-10-07T19:42:10.030Z,1602099730.030 [UniversalFixResidualReporter] Loaded
2020-10-07T19:42:10.030Z,1602099730.030 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2020-10-07T19:42:10.031Z,1602099730.031 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2020-10-07T19:42:10.033Z,1602099730.033 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2020-10-07T19:42:10.561Z,1602099730.561 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_orientation
2020-10-07T19:42:10.563Z,1602099730.563 [AHRS_M2](INFO): created writer for : platform_orientation
2020-10-07T19:42:10.564Z,1602099730.564 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_magnetic_orientation
2020-10-07T19:42:10.567Z,1602099730.567 [AHRS_M2](INFO): created writer for : platform_magnetic_orientation
2020-10-07T19:42:10.567Z,1602099730.567 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_pitch_angle
2020-10-07T19:42:10.570Z,1602099730.570 [AHRS_M2](INFO): created writer for : platform_pitch_angle
2020-10-07T19:42:10.570Z,1602099730.570 [AHRS_M2](DEBUG): LcmSlateWriter::add(): platform_roll_angle
2020-10-07T19:42:10.573Z,1602099730.573 [AHRS_M2](INFO): created writer for : platform_roll_angle
2020-10-07T19:42:10.716Z,1602099730.716 [AHRS_M2] Loaded
2020-10-07T19:42:10.717Z,1602099730.717 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2020-10-07T19:42:10.857Z,1602099730.857 [DataOverHttps] Loaded
2020-10-07T19:42:10.858Z,1602099730.858 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2020-10-07T19:42:10.859Z,1602099730.859 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 409CC4E0
2020-10-07T19:42:10.859Z,1602099730.859 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 906
2020-10-07T19:42:10.875Z,1602099730.875 [Depth_Keller] Loaded
2020-10-07T19:42:10.875Z,1602099730.875 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2020-10-07T19:42:10.878Z,1602099730.878 [DropWeight] Loaded
2020-10-07T19:42:10.878Z,1602099730.878 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2020-10-07T19:42:10.929Z,1602099730.929 [NAL9602] Loaded
2020-10-07T19:42:10.930Z,1602099730.930 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2020-10-07T19:42:10.951Z,1602099730.951 [Onboard] Loaded
2020-10-07T19:42:10.951Z,1602099730.951 [ComponentRegistry](DEBUG): Component "Onboard" handled in its own thread.
2020-10-07T19:42:10.952Z,1602099730.952 [Onboard ThreadHandler](DEBUG): Created PCaller Thread at 409FC4E0
2020-10-07T19:42:10.953Z,1602099730.953 [Onboard ThreadHandler](INFO): Protected caller Thread ID is 907
2020-10-07T19:42:10.963Z,1602099730.963 [Radio_Surface] Loaded
2020-10-07T19:42:10.963Z,1602099730.963 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2020-10-07T19:42:10.964Z,1602099730.964 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 40A2C4E0
2020-10-07T19:42:10.964Z,1602099730.964 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 908
2020-10-07T19:42:11.639Z,1602099731.639 [BPC1] Loaded
2020-10-07T19:42:11.639Z,1602099731.639 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2020-10-07T19:42:11.657Z,1602099731.657 [AMEcho] Loaded
2020-10-07T19:42:11.658Z,1602099731.658 [ComponentRegistry](DEBUG): SyncComponent "AMEcho" handled in the control thread.
2020-10-07T19:42:11.658Z,1602099731.658 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2020-10-07T19:42:11.659Z,1602099731.659 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2020-10-07T19:42:12.101Z,1602099732.101 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2020-10-07T19:42:12.101Z,1602099732.101 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2020-10-07T19:42:12.296Z,1602099732.296 [VerticalControl](DEBUG): Construct VerticalControl.
2020-10-07T19:42:12.344Z,1602099732.344 [VerticalControl] Loaded
2020-10-07T19:42:12.344Z,1602099732.344 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2020-10-07T19:42:12.345Z,1602099732.345 [HorizontalControl](DEBUG): Construct HorizontalControl.
2020-10-07T19:42:12.379Z,1602099732.379 [HorizontalControl] Loaded
2020-10-07T19:42:12.379Z,1602099732.379 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2020-10-07T19:42:12.379Z,1602099732.379 [SpeedControl](DEBUG): Construct SpeedControl.
2020-10-07T19:42:12.381Z,1602099732.381 [SpeedControl] Loaded
2020-10-07T19:42:12.381Z,1602099732.381 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2020-10-07T19:42:12.382Z,1602099732.382 [LoopControl](DEBUG): Construct LoopControl.
2020-10-07T19:42:12.383Z,1602099732.383 [LoopControl] Loaded
2020-10-07T19:42:12.383Z,1602099732.383 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2020-10-07T19:42:12.383Z,1602099732.383 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2020-10-07T19:42:12.384Z,1602099732.384 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2020-10-07T19:42:12.413Z,1602099732.413 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2020-10-07T19:42:12.414Z,1602099732.414 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2020-10-07T19:42:12.742Z,1602099732.742 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2020-10-07T19:42:12.745Z,1602099732.745 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2020-10-07T19:42:12.746Z,1602099732.746 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2020-10-07T19:42:12.754Z,1602099732.754 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2020-10-07T19:42:12.755Z,1602099732.755 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40B664E0
2020-10-07T19:42:12.756Z,1602099732.756 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 909
2020-10-07T19:42:12.760Z,1602099732.760 [Supervisor](INFO): Main Thread ID is 815
2020-10-07T19:42:12.760Z,1602099732.760 [Supervisor](DEBUG): Running supervisor.
2020-10-07T19:42:12.761Z,1602099732.761 [CommandLine ThreadHandler](INFO): Handler Thread ID is 910
2020-10-07T19:42:12.763Z,1602099732.763 [controlThread ThreadHandler](INFO): Handler Thread ID is 911
2020-10-07T19:42:12.764Z,1602099732.764 [controlThread](DEBUG): Initializing ControlThread
2020-10-07T19:42:12.765Z,1602099732.765 [SBIT](INFO): Initialize SBIT Component.
2020-10-07T19:42:12.766Z,1602099732.766 [SBIT](IMPORTANT): git: 2020-10-07_A
2020-10-07T19:42:12.766Z,1602099732.766 [SBIT](INFO): git hash: c52f40a9277e8d17c6912ac1d266a8bed1742f02
2020-10-07T19:42:12.766Z,1602099732.766 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2020-10-07T19:42:12.768Z,1602099732.768 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018
Kernel Reported: #1 PREEMPT Wed Nov 13 12:38:10 PST 2019
2020-10-07T19:42:12.769Z,1602099732.769 [SBIT](INFO): Beginning SBIT in 53.000000 seconds.
2020-10-07T19:42:12.769Z,1602099732.769 [IBIT](INFO): Initialize IBIT Component.
2020-10-07T19:42:12.770Z,1602099732.770 [CBIT](DEBUG): Initialize CBIT Component.
2020-10-07T19:42:12.771Z,1602099732.771 [logger ThreadHandler](INFO): Handler Thread ID is 912
2020-10-07T19:42:12.781Z,1602099732.781 [CBIT](DEBUG): Initialized mux pins.
2020-10-07T19:42:12.781Z,1602099732.781 [CBIT](DEBUG): Initializing the watchdog timer.
2020-10-07T19:42:12.789Z,1602099732.789 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 913
2020-10-07T19:42:12.790Z,1602099732.790 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2020-10-07T19:42:12.794Z,1602099732.794 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 915
2020-10-07T19:42:12.795Z,1602099732.795 [WetLabsBB2FL](INFO): Powering down
2020-10-07T19:42:12.805Z,1602099732.805 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2020-10-07T19:42:12.805Z,1602099732.805 [CBIT](DEBUG): Initializing heartbeat.
2020-10-07T19:42:12.877Z,1602099732.877 [CBIT](DEBUG): Deactivating GF circuits.
2020-10-07T19:42:12.877Z,1602099732.877 [CBIT](DEBUG): Deactivating emergency mode.
2020-10-07T19:42:12.913Z,1602099732.913 [CBIT](DEBUG): Backplane powered.
2020-10-07T19:42:12.922Z,1602099732.922 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2020-10-07T19:42:12.922Z,1602099732.922 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2020-10-07T19:42:12.922Z,1602099732.922 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2020-10-07T19:42:12.923Z,1602099732.923 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2020-10-07T19:42:12.923Z,1602099732.923 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2020-10-07T19:42:12.924Z,1602099732.924 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2020-10-07T19:42:12.925Z,1602099732.925 [NavChart](DEBUG): Initialize NavChart Navigation.
2020-10-07T19:42:12.925Z,1602099732.925 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2020-10-07T19:42:12.930Z,1602099732.930 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 916
2020-10-07T19:42:12.931Z,1602099732.931 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2020-10-07T19:42:12.939Z,1602099732.939 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2020-10-07T19:42:12.941Z,1602099732.941 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2020-10-07T19:42:12.942Z,1602099732.942 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2020-10-07T19:42:12.945Z,1602099732.945 [LoopControl](DEBUG): Initialize LoopControlComponent.
2020-10-07T19:42:13.041Z,1602099733.041 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2020-10-07T19:42:13.051Z,1602099733.051 [Onboard ThreadHandler](INFO): Handler Thread ID is 917
2020-10-07T19:42:13.075Z,1602099733.075 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 918
2020-10-07T19:42:13.085Z,1602099733.085 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 919
2020-10-07T19:42:13.429Z,1602099733.429 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2020-10-07T19:42:13.442Z,1602099733.442 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2020-10-07T19:42:13.443Z,1602099733.443 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2020-10-07T19:42:13.443Z,1602099733.443 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2020-10-07T19:42:13.443Z,1602099733.443 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2020-10-07T19:42:13.443Z,1602099733.443 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2020-10-07T19:42:13.443Z,1602099733.443 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2020-10-07T19:42:13.443Z,1602099733.443 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2020-10-07T19:42:13.443Z,1602099733.443 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2020-10-07T19:42:13.444Z,1602099733.444 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2020-10-07T19:42:13.444Z,1602099733.444 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2020-10-07T19:42:13.444Z,1602099733.444 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2020-10-07T19:42:13.444Z,1602099733.444 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2020-10-07T19:42:13.444Z,1602099733.444 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2020-10-07T19:42:13.444Z,1602099733.444 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2020-10-07T19:42:13.445Z,1602099733.445 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2020-10-07T19:42:13.445Z,1602099733.445 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2020-10-07T19:42:13.452Z,1602099733.452 [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-10-07T19:42:13.483Z,1602099733.483 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2020-10-07T19:42:13.505Z,1602099733.505 [Radio_Surface](INFO): Powering up
2020-10-07T19:42:13.556Z,1602099733.556 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2020-10-07T19:42:13.557Z,1602099733.557 [Default:A.Wait](DEBUG): Construct Wait.
2020-10-07T19:42:13.559Z,1602099733.559 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2020-10-07T19:42:13.601Z,1602099733.601 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2020-10-07T19:42:13.604Z,1602099733.604 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2020-10-07T19:42:13.620Z,1602099733.620 [Default:E.Execute](DEBUG): Construct Execute.
2020-10-07T19:42:13.624Z,1602099733.624 [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-10-07T19:42:13.628Z,1602099733.628 [controlThread](DEBUG): Component order: CycleStarter,CANONSampler,ESPComponent,PAR_Licor,AHRS_M2,Depth_Keller,DropWeight,NAL9602,BPC1,AMEcho,PAR_Licor,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2020-10-07T19:42:13.649Z,1602099733.649 [CANONSampler](INFO): Powering down
2020-10-07T19:42:13.652Z,1602099733.652 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2020-10-07T19:42:13.937Z,1602099733.937 [AMEcho](INFO): Powering up
2020-10-07T19:42:13.939Z,1602099733.939 [AMEcho](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2
2020-10-07T19:42:13.961Z,1602099733.961 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2
2020-10-07T19:42:14.017Z,1602099734.017 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2020-10-07T19:42:14.029Z,1602099734.029 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2020-10-07T19:42:14.030Z,1602099734.030 [ElevatorServo](DEBUG): Initializing EZServoServo.
2020-10-07T19:42:14.041Z,1602099734.041 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2020-10-07T19:42:14.042Z,1602099734.042 [MassServo](DEBUG): Initializing EZServoServo.
2020-10-07T19:42:14.053Z,1602099734.053 [MassServo](DEBUG): Initializing MassServo.
2020-10-07T19:42:14.054Z,1602099734.054 [RudderServo](DEBUG): Initializing EZServoServo.
2020-10-07T19:42:14.065Z,1602099734.065 [RudderServo](DEBUG): Initializing RudderServo.
2020-10-07T19:42:14.066Z,1602099734.066 [ThrusterServo](DEBUG): Initializing EZServoServo.
2020-10-07T19:42:14.077Z,1602099734.077 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2020-10-07T19:42:14.329Z,1602099734.329 [AMEcho](INFO): Powering down
2020-10-07T19:42:41.170Z,1602099761.170 [NAL9602](INFO): Powering up NAL9602
2020-10-07T19:42:52.087Z,1602099772.087 [NAL9602](INFO): NAL9602 initialized
2020-10-07T19:43:06.230Z,1602099786.230 [SBIT](IMPORTANT): Beginning Startup BIT
2020-10-07T19:43:06.234Z,1602099786.234 [CBIT](IMPORTANT): Beginning ground fault scan
2020-10-07T19:43:17.191Z,1602099797.191 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.005860
CHAN A1 (24V): 0.003365
CHAN A2 (12V): -0.004183
CHAN A3 (5V): -0.002060
CHAN B0 (3.3V): -0.001325
CHAN B1 (3.15aV): -0.000966
CHAN B2 (3.15bV): -0.000943
CHAN B3 (GND): -0.000457
OPEN: 0.004584
Full Scale Calc: 4.765 mA, -1.589 mA
2020-10-07T19:43:18.341Z,1602099798.341 [NAL9602](INFO): SBD MO Status=0, MOMSN=39086, MT Status=0, MTMSN=0
2020-10-07T19:43:18.341Z,1602099798.341 [NAL9602](INFO): No messages in MT queue
2020-10-07T19:43:20.361Z,1602099800.361 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2020-10-07T19:43:31.685Z,1602099811.685 [BPC1](ERROR): BPC1B got IPBS message with 6 sticks (min is 7).
2020-10-07T19:43:34.098Z,1602099814.098 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194332.00,A,3648.13698,N,12147.20688,W,0.039,8.38,071020,,,A*76
2020-10-07T19:43:34.101Z,1602099814.101 [NAL9602](INFO): GPS fix at 20201007T194332: (36.802283, -121.786781)
2020-10-07T19:43:59.977Z,1602099839.977 [SBIT](IMPORTANT): SBIT PASSED
2020-10-07T19:43:59.977Z,1602099839.977 [SBIT](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2020-10-07T19:43:59.978Z,1602099839.978 [SBIT](IMPORTANT): Aanderaa_O2.loadAtStartup=0 bool;

2020-10-07T19:43:59.978Z,1602099839.978 [SBIT](IMPORTANT): BPC1.batteryMissingStickThreshold=2 count;

2020-10-07T19:43:59.978Z,1602099839.978 [SBIT](IMPORTANT): CANONSampler.loadAtStartup=1 bool;

2020-10-07T19:43:59.978Z,1602099839.978 [SBIT](IMPORTANT): CANONSampler.rotateOnly=1 bool;

2020-10-07T19:43:59.978Z,1602099839.978 [SBIT](IMPORTANT): CBIT.gf24Offset=148.5 microampere;

2020-10-07T19:43:59.978Z,1602099839.978 [SBIT](IMPORTANT): DVL_micro.loadAtStartup=0 bool;

2020-10-07T19:43:59.978Z,1602099839.978 [SBIT](IMPORTANT): VerticalControl.buoyancyNeutral=261 cubic_centimeter;

2020-10-07T19:43:59.979Z,1602099839.979 [SBIT](IMPORTANT): VerticalControl.massDefault=8.4 millimeter;

2020-10-07T19:44:00.366Z,1602099840.366 [MissionManager](IMPORTANT): Started mission Startup
2020-10-07T19:44:00.366Z,1602099840.366 [Startup] Running Loop=1
2020-10-07T19:44:00.366Z,1602099840.366 [Startup](DEBUG): Aggregate::initialize Startup
2020-10-07T19:44:00.367Z,1602099840.367 [Startup:A.GoToSurface] Running Loop=1
2020-10-07T19:44:00.367Z,1602099840.367 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2020-10-07T19:44:00.367Z,1602099840.367 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2020-10-07T19:44:00.368Z,1602099840.368 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2020-10-07T19:44:00.368Z,1602099840.368 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2020-10-07T19:44:00.368Z,1602099840.368 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2020-10-07T19:44:00.369Z,1602099840.369 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2020-10-07T19:44:00.370Z,1602099840.370 [Startup:StartupSatComms] Running Loop=1
2020-10-07T19:44:00.370Z,1602099840.370 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2020-10-07T19:44:00.370Z,1602099840.370 [Startup:StartupSatComms:A] Running Loop=1
2020-10-07T19:44:00.773Z,1602099840.773 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2020-10-07T19:44:01.230Z,1602099841.230 [AMEcho](INFO): Powering up
2020-10-07T19:44:01.232Z,1602099841.232 [AMEcho](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2
2020-10-07T19:44:01.254Z,1602099841.254 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2
2020-10-07T19:44:02.383Z,1602099842.383 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194400.00,A,3648.13825,N,12147.20738,W,0.156,8.38,071020,,,D*7F
2020-10-07T19:44:02.385Z,1602099842.385 [NAL9602](INFO): GPS fix at 20201007T194400: (36.802304, -121.786790)
2020-10-07T19:44:02.429Z,1602099842.429 [Startup:StartupSatComms:A] Stopped
2020-10-07T19:44:02.429Z,1602099842.429 [Startup:StartupSatComms:B] Running Loop=1
2020-10-07T19:44:02.817Z,1602099842.817 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2020-10-07T19:44:11.358Z,1602099851.358 [NAL9602](INFO): SBD MO Status=1, MOMSN=39087, MT Status=0, MTMSN=0
2020-10-07T19:44:11.409Z,1602099851.409 [NAL9602](INFO): Sent 72 bytes from file Logs/20201007T190924/Courier0016.lzma
2020-10-07T19:44:11.409Z,1602099851.409 [NAL9602](INFO): Packets left to send: 0
2020-10-07T19:44:26.063Z,1602099866.063 [NAL9602](INFO): SBD MO Status=1, MOMSN=39088, MT Status=0, MTMSN=0
2020-10-07T19:44:26.113Z,1602099866.113 [NAL9602](INFO): Sent 267 bytes from file Logs/20201007T194202/Courier0000.lzma
2020-10-07T19:44:26.113Z,1602099866.113 [NAL9602](INFO): Packets left to send: 0
2020-10-07T19:44:44.648Z,1602099884.648 [NAL9602](INFO): SBD MO Status=1, MOMSN=39089, MT Status=0, MTMSN=0
2020-10-07T19:44:44.697Z,1602099884.697 [NAL9602](INFO): Sent 332 bytes from file Logs/20201007T190924/Express0017.lzma
2020-10-07T19:44:44.697Z,1602099884.697 [NAL9602](INFO): Packets left to send: 1
2020-10-07T19:45:02.701Z,1602099902.701 [Startup:StartupSatComms:B](INFO): Timed out from 2020-10-07T19:44:02.4Z
2020-10-07T19:45:02.702Z,1602099902.702 [Startup:StartupSatComms:B] Stopped
2020-10-07T19:45:02.702Z,1602099902.702 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2020-10-07T19:45:02.702Z,1602099902.702 [Startup:StartupSatComms] Stopped
2020-10-07T19:45:02.702Z,1602099902.702 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2020-10-07T19:45:02.703Z,1602099902.703 [Startup](INFO): Completed Startup
2020-10-07T19:45:02.703Z,1602099902.703 [MissionManager](INFO): Startup is completed.
2020-10-07T19:45:02.703Z,1602099902.703 [MissionManager](INFO): Uninitializing Mission Startup
2020-10-07T19:45:02.703Z,1602099902.703 [Startup] Stopped
2020-10-07T19:45:02.703Z,1602099902.703 [Startup](DEBUG): Aggregate::uninitialize Startup
2020-10-07T19:45:02.703Z,1602099902.703 [Startup:A.GoToSurface] Stopped
2020-10-07T19:45:02.703Z,1602099902.703 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2020-10-07T19:45:03.115Z,1602099903.115 [MissionManager](IMPORTANT): Started mission Default
2020-10-07T19:45:03.115Z,1602099903.115 [Default] Running Loop=1
2020-10-07T19:45:03.115Z,1602099903.115 [Default](DEBUG): Aggregate::initialize Default
2020-10-07T19:45:03.115Z,1602099903.115 [Default:B.GoToSurface] Running Loop=1
2020-10-07T19:45:03.115Z,1602099903.115 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2020-10-07T19:45:03.115Z,1602099903.115 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2020-10-07T19:45:03.116Z,1602099903.116 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2020-10-07T19:45:03.116Z,1602099903.116 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2020-10-07T19:45:03.116Z,1602099903.116 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2020-10-07T19:45:03.117Z,1602099903.117 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2020-10-07T19:45:03.117Z,1602099903.117 [Default:A.Wait] Running Loop=1
2020-10-07T19:45:03.117Z,1602099903.117 [Default:A.Wait](DEBUG): Initialize Wait Component.
2020-10-07T19:45:03.657Z,1602099903.657 [AMEcho](INFO): Powering down
2020-10-07T19:45:04.711Z,1602099904.711 [AMEcho](INFO): Powering up
2020-10-07T19:45:04.713Z,1602099904.713 [AMEcho](INFO): Powered 24V power converter LCB with command: ! echo 1 > /dev/loadB2
2020-10-07T19:45:04.797Z,1602099904.797 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB2
2020-10-07T19:45:07.536Z,1602099907.536 [NAL9602](INFO): SBD MO Status=2, MOMSN=39090, MT Status=2, MTMSN=0
2020-10-07T19:45:07.537Z,1602099907.537 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-10-07T19:45:16.434Z,1602099916.434 [Default:A.Wait](INFO): Done Waiting.
2020-10-07T19:45:16.434Z,1602099916.434 [Default:A.Wait] Stopped
2020-10-07T19:45:16.434Z,1602099916.434 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2020-10-07T19:45:16.836Z,1602099916.836 [Default:CheckIn] Running Loop=1
2020-10-07T19:45:16.836Z,1602099916.836 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-10-07T19:45:16.836Z,1602099916.836 [Default:CheckIn:Read_GPS] Running Loop=1
2020-10-07T19:45:17.251Z,1602099917.251 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2020-10-07T19:45:18.857Z,1602099918.857 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,194516.00,A,3648.13878,N,12147.20807,W,0.039,8.38,071020,,,D*7A
2020-10-07T19:45:18.859Z,1602099918.859 [NAL9602](INFO): GPS fix at 20201007T194516: (36.802313, -121.786801)
2020-10-07T19:45:18.936Z,1602099918.936 [Default:CheckIn:Read_GPS] Stopped
2020-10-07T19:45:18.936Z,1602099918.936 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-10-07T19:45:19.282Z,1602099919.282 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2020-10-07T19:45:37.471Z,1602099937.471 [NAL9602](INFO): SBD MO Status=1, MOMSN=39090, MT Status=0, MTMSN=0
2020-10-07T19:45:37.529Z,1602099937.529 [NAL9602](INFO): Sent 72 bytes from file Logs/20201007T194202/Courier0004.lzma
2020-10-07T19:45:37.529Z,1602099937.529 [NAL9602](INFO): Packets left to send: 0
2020-10-07T19:45:49.959Z,1602099949.959 [NAL9602](INFO): SBD MO Status=1, MOMSN=39091, MT Status=0, MTMSN=0
2020-10-07T19:45:50.009Z,1602099950.009 [NAL9602](INFO): Sent 197 bytes from file Logs/20201007T190924/Express0017.lzma
2020-10-07T19:45:50.009Z,1602099950.009 [NAL9602](INFO): Packets left to send: 0
2020-10-07T19:46:10.832Z,1602099970.832 [NAL9602](INFO): SBD MO Status=1, MOMSN=39092, MT Status=0, MTMSN=0
2020-10-07T19:46:10.882Z,1602099970.882 [NAL9602](INFO): Sent 332 bytes from file Logs/20201007T194202/Express0001.lzma
2020-10-07T19:46:10.882Z,1602099970.882 [NAL9602](INFO): Packets left to send: 2
2020-10-07T19:46:22.834Z,1602099982.834 [NAL9602](INFO): SBD MO Status=1, MOMSN=39093, MT Status=0, MTMSN=0
2020-10-07T19:46:22.893Z,1602099982.893 [NAL9602](INFO): Sent 332 bytes from file Logs/20201007T194202/Express0001.lzma
2020-10-07T19:46:22.893Z,1602099982.893 [NAL9602](INFO): Packets left to send: 1
2020-10-07T19:46:31.676Z,1602099991.676 [NAL9602](INFO): SBD MO Status=1, MOMSN=39094, MT Status=0, MTMSN=0
2020-10-07T19:46:31.733Z,1602099991.733 [NAL9602](INFO): Sent 202 bytes from file Logs/20201007T194202/Express0001.lzma
2020-10-07T19:46:31.733Z,1602099991.733 [NAL9602](INFO): Packets left to send: 0
2020-10-07T19:46:56.223Z,1602100016.223 [NAL9602](INFO): SBD MO Status=2, MOMSN=39095, MT Status=2, MTMSN=0
2020-10-07T19:46:56.223Z,1602100016.223 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2020-10-07T19:47:15.694Z,1602100035.694 [NAL9602](INFO): SBD MO Status=1, MOMSN=39095, MT Status=0, MTMSN=0
2020-10-07T19:47:15.741Z,1602100035.741 [NAL9602](INFO): Sent 262 bytes from file Logs/20201007T194202/Express0005.lzma
2020-10-07T19:47:15.741Z,1602100035.741 [NAL9602](INFO): Packets left to send: 0
2020-10-07T19:47:24.577Z,1602100044.577 [NAL9602](INFO): SBD MO Status=0, MOMSN=39096, MT Status=0, MTMSN=0
2020-10-07T19:47:24.660Z,1602100044.660 [Default:CheckIn:Read_Iridium] Stopped
2020-10-07T19:47:24.660Z,1602100044.660 [Default:CheckIn:C.Wait] Running Loop=1
2020-10-07T19:47:24.660Z,1602100044.660 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-10-07T19:47:55.280Z,1602100075.280 [NAL9602](INFO): Not Powering down - fast GPS
2020-10-07T19:48:49.022Z,1602100129.022 [BPC1](INFO): Calculating totals. Valid battery stick count: 55. Valid reserve battery stick count: 5.
2020-10-07T19:48:49.041Z,1602100129.041 [BPC1](INFO): Received data from all battery sticks.
2020-10-07T19:52:25.166Z,1602100345.166 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-10-07T19:52:25.166Z,1602100345.166 [Default:CheckIn:C.Wait] Stopped
2020-10-07T19:52:25.166Z,1602100345.166 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-10-07T19:52:25.166Z,1602100345.166 [Default:CheckIn:D] Running Loop=1
2020-10-07T19:52:25.569Z,1602100345.569 [Default:CheckIn:D] Stopped
2020-10-07T19:52:25.569Z,1602100345.569 [Default:CheckIn:E] Running Loop=1
2020-10-07T19:52:25.971Z,1602100345.971 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 7.374240 min 
2020-10-07T19:52:25.971Z,1602100345.971 [Default:CheckIn:E] Stopped
2020-10-07T19:52:25.972Z,1602100345.972 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-10-07T19:52:25.972Z,1602100345.972 [Default:CheckIn] Stopped
2020-10-07T19:52:25.972Z,1602100345.972 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-10-07T19:52:25.972Z,1602100345.972 [Default:CheckIn](INFO): Running loop #2
2020-10-07T19:52:25.972Z,1602100345.972 [Default:CheckIn] Running Loop=2
2020-10-07T19:52:25.972Z,1602100345.972 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-10-07T19:52:25.972Z,1602100345.972 [Default:CheckIn:Read_GPS] Running Loop=1
2020-10-07T19:52:27.984Z,1602100347.984 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,195226.00,A,3648.13516,N,12147.20945,W,0.058,196.10,071020,,,D*76
2020-10-07T19:52:27.995Z,1602100347.995 [NAL9602](INFO): GPS fix at 20201007T195226: (36.802253, -121.786824)
2020-10-07T19:52:28.004Z,1602100348.004 [Default:CheckIn:Read_GPS] Stopped
2020-10-07T19:52:28.004Z,1602100348.004 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-10-07T19:52:44.191Z,1602100364.191 [NAL9602](IMPORTANT): SBD MO Status=1, MOMSN=39097, MT Status=1, MTMSN=2752
2020-10-07T19:52:44.253Z,1602100364.253 [NAL9602](INFO): Sent 202 bytes from file Logs/20201007T194202/Courier0007.lzma
2020-10-07T19:52:44.253Z,1602100364.253 [NAL9602](INFO): Packets left to send: 0
2020-10-07T19:52:44.761Z,1602100364.761 [NAL9602](INFO): Received command:! echo 0 > /dev/loadB6
2020-10-07T19:52:44.778Z,1602100364.778 [CommandLine](IMPORTANT): got command ! echo 0 > /dev/loadB6
2020-10-07T19:53:02.294Z,1602100382.294 [NAL9602](INFO): SBD MO Status=1, MOMSN=39098, MT Status=0, MTMSN=0
2020-10-07T19:53:02.357Z,1602100382.357 [NAL9602](INFO): Sent 160 bytes from file Logs/20201007T194202/Express0008.lzma
2020-10-07T19:53:02.357Z,1602100382.357 [NAL9602](INFO): Packets left to send: 0
2020-10-07T19:53:12.038Z,1602100392.038 [NAL9602](INFO): SBD MO Status=0, MOMSN=39099, MT Status=0, MTMSN=0
2020-10-07T19:53:26.630Z,1602100406.630 [NAL9602](INFO): SBD MO Status=1, MOMSN=39100, MT Status=0, MTMSN=0
2020-10-07T19:53:26.693Z,1602100406.693 [NAL9602](INFO): Sent 38 bytes from file Logs/20201007T194202/Courier0010.lzma
2020-10-07T19:53:26.693Z,1602100406.693 [NAL9602](INFO): Packets left to send: 0
2020-10-07T19:53:52.637Z,1602100432.637 [NAL9602](INFO): SBD MO Status=1, MOMSN=39101, MT Status=0, MTMSN=0
2020-10-07T19:53:52.697Z,1602100432.697 [NAL9602](INFO): Sent 185 bytes from file Logs/20201007T194202/Express0011.lzma
2020-10-07T19:53:52.697Z,1602100432.697 [NAL9602](INFO): Packets left to send: 0
2020-10-07T19:54:02.338Z,1602100442.338 [NAL9602](IMPORTANT): SBD MO Status=0, MOMSN=39102, MT Status=1, MTMSN=2753
2020-10-07T19:54:02.949Z,1602100442.949 [NAL9602](INFO): Received command:! echo 1 > /dev/loadB6
2020-10-07T19:54:03.045Z,1602100443.045 [CommandLine](IMPORTANT): got command ! echo 1 > /dev/loadB6
2020-10-07T19:54:13.683Z,1602100453.683 [NAL9602](INFO): SBD MO Status=0, MOMSN=39103, MT Status=0, MTMSN=0
2020-10-07T19:54:33.931Z,1602100473.931 [NAL9602](INFO): SBD MO Status=1, MOMSN=39104, MT Status=0, MTMSN=0
2020-10-07T19:54:33.985Z,1602100473.985 [NAL9602](INFO): Sent 39 bytes from file Logs/20201007T194202/Courier0013.lzma
2020-10-07T19:54:33.985Z,1602100473.985 [NAL9602](INFO): Packets left to send: 0
2020-10-07T19:54:45.458Z,1602100485.458 [NAL9602](INFO): SBD MO Status=1, MOMSN=39105, MT Status=0, MTMSN=0
2020-10-07T19:54:45.504Z,1602100485.504 [NAL9602](INFO): Sent 161 bytes from file Logs/20201007T194202/Express0014.lzma
2020-10-07T19:54:45.504Z,1602100485.504 [NAL9602](INFO): Packets left to send: 0
2020-10-07T19:54:54.019Z,1602100494.019 [NAL9602](INFO): SBD MO Status=0, MOMSN=39106, MT Status=0, MTMSN=0
2020-10-07T19:54:54.121Z,1602100494.121 [Default:CheckIn:Read_Iridium] Stopped
2020-10-07T19:54:54.121Z,1602100494.121 [Default:CheckIn:C.Wait] Running Loop=1
2020-10-07T19:54:54.121Z,1602100494.121 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-10-07T19:55:24.655Z,1602100524.655 [NAL9602](INFO): Not Powering down - fast GPS
2020-10-07T19:57:40.171Z,1602100660.171 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004492
2020-10-07T19:58:11.797Z,1602100691.797 [CommandLine](IMPORTANT): got command ibit
2020-10-07T19:58:11.955Z,1602100691.955 [IBIT](IMPORTANT): Beginning Initiated BIT
2020-10-07T19:58:11.955Z,1602100691.955 [IBIT](IMPORTANT): Beginning control surface checks.
2020-10-07T19:58:11.958Z,1602100691.958 [CBIT](IMPORTANT): Beginning ground fault scan
2020-10-07T19:58:13.560Z,1602100693.560 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,195812.00,A,3648.13513,N,12147.20860,W,0.058,196.10,071020,,,D*78
2020-10-07T19:58:13.562Z,1602100693.562 [NAL9602](INFO): GPS fix at 20201007T195812: (36.802252, -121.786810)
2020-10-07T19:58:22.892Z,1602100702.892 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.005310
CHAN A1 (24V): 0.003293
CHAN A2 (12V): -0.004334
CHAN A3 (5V): -0.002405
CHAN B0 (3.3V): -0.000714
CHAN B1 (3.15aV): -0.000906
CHAN B2 (3.15bV): -0.001120
CHAN B3 (GND): -0.000203
OPEN: 0.004590
Full Scale Calc: 4.765 mA, -1.589 mA
2020-10-07T19:58:33.360Z,1602100713.360 [NAL9602](IMPORTANT): SBD MO Status=0, MOMSN=39107, MT Status=1, MTMSN=2754
2020-10-07T19:58:33.360Z,1602100713.360 [NAL9602](INFO): Data available in MT queue
2020-10-07T19:58:34.061Z,1602100714.061 [NAL9602](INFO): Received command: Configset CANONSampler.loadControl /dev/loadB1 persist
2020-10-07T19:58:34.312Z,1602100714.312 [CommandLine](IMPORTANT): got command configSet CANONSampler.loadControl 1.000000 
2020-10-07T19:58:34.312Z,1602100714.312 [CommandLine](FAULT): Incomplete syntax. Try: help configSet
2020-10-07T19:58:35.236Z,1602100715.236 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,195834.00,A,3648.13507,N,12147.20912,W,0.078,196.10,071020,,,D*7F
2020-10-07T19:58:35.238Z,1602100715.238 [NAL9602](INFO): GPS fix at 20201007T195834: (36.802251, -121.786819)
2020-10-07T19:58:38.464Z,1602100718.464 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,195837.00,A,3648.13507,N,12147.20918,W,0.019,196.10,071020,,,D*71
2020-10-07T19:58:38.466Z,1602100718.466 [NAL9602](INFO): GPS fix at 20201007T195837: (36.802251, -121.786820)
2020-10-07T19:58:41.290Z,1602100721.290 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,195840.00,A,3648.13504,N,12147.20917,W,0.019,196.10,071020,,,D*7D
2020-10-07T19:58:41.292Z,1602100721.292 [NAL9602](INFO): GPS fix at 20201007T195840: (36.802251, -121.786820)
2020-10-07T19:58:44.520Z,1602100724.520 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,195843.00,A,3648.13499,N,12147.20910,W,0.058,196.10,071020,,,D*79
2020-10-07T19:58:44.530Z,1602100724.530 [NAL9602](INFO): GPS fix at 20201007T195843: (36.802250, -121.786818)
2020-10-07T19:58:47.382Z,1602100727.382 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,195846.00,A,3648.13483,N,12147.20904,W,0.097,196.10,071020,,,D*71
2020-10-07T19:58:47.384Z,1602100727.384 [NAL9602](INFO): GPS fix at 20201007T195846: (36.802247, -121.786817)
2020-10-07T19:58:50.585Z,1602100730.585 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,195849.00,A,3648.13475,N,12147.20913,W,0.039,196.10,071020,,,D*75
2020-10-07T19:58:50.587Z,1602100730.587 [NAL9602](INFO): GPS fix at 20201007T195849: (36.802246, -121.786819)
2020-10-07T19:58:53.412Z,1602100733.412 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,195852.00,A,3648.13472,N,12147.20930,W,0.039,196.10,071020,,,D*79
2020-10-07T19:58:53.415Z,1602100733.415 [NAL9602](INFO): GPS fix at 20201007T195852: (36.802245, -121.786822)
2020-10-07T19:58:56.238Z,1602100736.238 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,195855.00,A,3648.13468,N,12147.20944,W,0.039,196.10,071020,,,D*76
2020-10-07T19:58:56.241Z,1602100736.241 [NAL9602](INFO): GPS fix at 20201007T195855: (36.802245, -121.786824)
2020-10-07T19:58:58.325Z,1602100738.325 [IBIT](IMPORTANT): Communications Status:
Fix Status: 1
Iridium Signal Strength: 5
Latitude: 36.802246 Longitude: -121.786827
2020-10-07T19:58:58.684Z,1602100738.684 [IBIT](IMPORTANT): Battery Status:
Battery Charge (AH): 0.000000
Voltage: 16.650999
2020-10-07T19:58:58.684Z,1602100738.684 [IBIT](IMPORTANT): batteryCapacityThreshold: 50.000000 Ah
2020-10-07T19:58:58.689Z,1602100738.689 [IBIT](IMPORTANT): batteryVoltageThreshold: 13.700000 V
2020-10-07T19:58:59.111Z,1602100739.111 [IBIT](IMPORTANT): bitHumidityThreshold: 55.000000 %
2020-10-07T19:58:59.111Z,1602100739.111 [IBIT](IMPORTANT): bitPressureThreshold: 0.750000 psi
2020-10-07T19:58:59.111Z,1602100739.111 [IBIT](IMPORTANT): Pressure:8.408512 PSI
2020-10-07T19:58:59.112Z,1602100739.112 [IBIT](IMPORTANT): Humidity:19.808327 %
2020-10-07T19:58:59.503Z,1602100739.503 [IBIT](IMPORTANT): Vehicle Pitch:-0.759086 degrees
2020-10-07T19:58:59.503Z,1602100739.503 [IBIT](IMPORTANT): Vehicle  Roll:-0.548001 degrees
2020-10-07T19:58:59.504Z,1602100739.504 [IBIT](IMPORTANT): Vehicle  Heading:22.529680 degrees
2020-10-07T19:58:59.905Z,1602100739.905 [IBIT](IMPORTANT): surfaceThreshold: 1.000000 m
2020-10-07T19:58:59.906Z,1602100739.906 [IBIT](IMPORTANT): buoyancyNeutral: 261.000000 cc
2020-10-07T19:58:59.906Z,1602100739.906 [IBIT](IMPORTANT): massDefault: 0.840000 cm
2020-10-07T19:58:59.906Z,1602100739.906 [IBIT](IMPORTANT): stopDepth: 265.000000 m
2020-10-07T19:58:59.906Z,1602100739.906 [IBIT](IMPORTANT): abortDepth: 300.000000 m
2020-10-07T19:58:59.906Z,1602100739.906 [IBIT](IMPORTANT): IBIT PASSED
2020-10-07T19:59:28.966Z,1602100768.966 [NAL9602](INFO): Not Powering down - fast GPS
2020-10-07T19:59:54.432Z,1602100794.432 [Default:CheckIn:C.Wait](INFO): Done Waiting.
2020-10-07T19:59:54.432Z,1602100794.432 [Default:CheckIn:C.Wait] Stopped
2020-10-07T19:59:54.432Z,1602100794.432 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-10-07T19:59:54.432Z,1602100794.432 [Default:CheckIn:D] Running Loop=1
2020-10-07T19:59:54.826Z,1602100794.826 [Default:CheckIn:D] Stopped
2020-10-07T19:59:54.827Z,1602100794.827 [Default:CheckIn:E] Running Loop=1
2020-10-07T19:59:55.230Z,1602100795.230 [Default:CheckIn:E](IMPORTANT): Default mission has been running for 14.861860 min 
2020-10-07T19:59:55.230Z,1602100795.230 [Default:CheckIn:E] Stopped
2020-10-07T19:59:55.230Z,1602100795.230 [Default:CheckIn](INFO): Completed Default:CheckIn
2020-10-07T19:59:55.230Z,1602100795.230 [Default:CheckIn] Stopped
2020-10-07T19:59:55.230Z,1602100795.230 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-10-07T19:59:55.231Z,1602100795.231 [Default:CheckIn](INFO): Running loop #3
2020-10-07T19:59:55.231Z,1602100795.231 [Default:CheckIn] Running Loop=3
2020-10-07T19:59:55.231Z,1602100795.231 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2020-10-07T19:59:55.231Z,1602100795.231 [Default:CheckIn:Read_GPS] Running Loop=1
2020-10-07T19:59:57.248Z,1602100797.248 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,195956.00,A,3648.13477,N,12147.21120,W,0.039,196.10,071020,,,D*71
2020-10-07T19:59:57.250Z,1602100797.250 [NAL9602](INFO): GPS fix at 20201007T195956: (36.802246, -121.786853)
2020-10-07T19:59:57.259Z,1602100797.259 [Default:CheckIn:Read_GPS] Stopped
2020-10-07T19:59:57.259Z,1602100797.259 [Default:CheckIn:Read_Iridium] Running Loop=1
2020-10-07T20:00:00.203Z,1602100800.203 [CommandLine](IMPORTANT): got command configSet CANONSampler.loadControl 
2020-10-07T20:00:00.203Z,1602100800.203 [CommandLine](FAULT): Incomplete syntax. Try: help configSet
2020-10-07T20:00:04.646Z,1602100804.646 [CommandLine](IMPORTANT): got command failComponent
2020-10-07T20:00:04.646Z,1602100804.646 [CommandLine](IMPORTANT): Failed components:
2020-10-07T20:00:04.647Z,1602100804.647 [CommandLine](IMPORTANT): No failed Components.
2020-10-07T20:00:11.768Z,1602100811.768 [DataOverHttps](INFO): Sending 72 bytes from file Logs/20201007T194202/Courier0016.lzma
2020-10-07T20:00:12.770Z,1602100812.770 [DataOverHttps](INFO): Moved sent file to Logs/20201007T194202/Courier0016.lzma.bak
2020-10-07T20:00:12.771Z,1602100812.771 [DataOverHttps](INFO): SBD MOMSN=12811657
2020-10-07T20:00:15.019Z,1602100815.019 [NAL9602](INFO): SBD MO Status=0, MOMSN=39108, MT Status=0, MTMSN=0
2020-10-07T20:00:15.019Z,1602100815.019 [NAL9602](INFO): No messages in MT queue
2020-10-07T20:00:28.453Z,1602100828.453 [DataOverHttps](INFO): Sending 872 bytes from file Logs/20201007T194202/Express0017.lzma
2020-10-07T20:00:29.454Z,1602100829.454 [DataOverHttps](INFO): Moved sent file to Logs/20201007T194202/Express0017.lzma.bak
2020-10-07T20:00:29.455Z,1602100829.455 [DataOverHttps](INFO): SBD MOMSN=12811660
2020-10-07T20:00:31.185Z,1602100831.185 [Default:CheckIn:Read_Iridium] Stopped
2020-10-07T20:00:31.185Z,1602100831.185 [Default:CheckIn:C.Wait] Running Loop=1
2020-10-07T20:00:31.185Z,1602100831.185 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2020-10-07T20:00:45.730Z,1602100845.730 [NAL9602](INFO): Not Powering down - fast GPS
2020-10-07T20:01:05.514Z,1602100865.514 [CommandLine](IMPORTANT): got command restart application
2020-10-07T20:01:06.517Z,1602100866.517 [Supervisor](INFO): Stop Mission called by Supervisor::terminate
2020-10-07T20:01:06.517Z,1602100866.517 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2020-10-07T20:01:06.517Z,1602100866.517 [CommandLine ThreadHandler](INFO): Thread cancelled.
2020-10-07T20:01:06.521Z,1602100866.521 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2020-10-07T20:01:06.521Z,1602100866.521 [CommandLine ThreadHandler](INFO): Thread cancelled.
2020-10-07T20:01:06.522Z,1602100866.522 [CommandLine](INFO): Join timeout helper Thread ID is 1019
2020-10-07T20:01:06.522Z,1602100866.522 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2020-10-07T20:01:06.522Z,1602100866.522 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2020-10-07T20:01:06.522Z,1602100866.522 [NavChartDb](INFO): Join timeout helper Thread ID is 1020
2020-10-07T20:01:06.573Z,1602100866.573 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2020-10-07T20:01:06.573Z,1602100866.573 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2020-10-07T20:01:06.581Z,1602100866.581 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2020-10-07T20:01:06.581Z,1602100866.581 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2020-10-07T20:01:06.581Z,1602100866.581 [Radio_Surface](INFO): Join timeout helper Thread ID is 1021
2020-10-07T20:01:06.593Z,1602100866.593 [Radio_Surface](INFO): Powering down
2020-10-07T20:01:06.594Z,1602100866.594 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2020-10-07T20:01:06.594Z,1602100866.594 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2020-10-07T20:01:06.601Z,1602100866.601 [ComponentRegistry](INFO): Shutting down Onboard ThreadHandler
2020-10-07T20:01:06.601Z,1602100866.601 [Onboard ThreadHandler](INFO): Thread cancelled.
2020-10-07T20:01:06.601Z,1602100866.601 [Onboard](INFO): Join timeout helper Thread ID is 1022
2020-10-07T20:01:08.997Z,1602100868.997 [Onboard ThreadHandler](INFO): Uninitializing protected caller thread.
2020-10-07T20:01:08.997Z,1602100868.997 [Onboard ThreadHandler](INFO): Thread cancelled.
2020-10-07T20:01:09.009Z,1602100869.009 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2020-10-07T20:01:09.009Z,1602100869.009 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2020-10-07T20:01:09.009Z,1602100869.009 [DataOverHttps](INFO): Join timeout helper Thread ID is 1023
2020-10-07T20:01:09.449Z,1602100869.449 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2020-10-07T20:01:09.453Z,1602100869.453 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2020-10-07T20:01:09.470Z,1602100869.470 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2020-10-07T20:01:09.470Z,1602100869.470 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2020-10-07T20:01:09.470Z,1602100869.470 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 1024
2020-10-07T20:01:09.677Z,1602100869.677 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2020-10-07T20:01:09.677Z,1602100869.677 [WetLabsBB2FL](INFO): Powering down
2020-10-07T20:01:09.678Z,1602100869.678 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2020-10-07T20:01:09.695Z,1602100869.695 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2020-10-07T20:01:09.695Z,1602100869.695 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2020-10-07T20:01:09.695Z,1602100869.695 [CTD_Seabird](INFO): Join timeout helper Thread ID is 1025
2020-10-07T20:01:10.561Z,1602100870.561 [CTD_Seabird](INFO): Powering down
2020-10-07T20:01:10.573Z,1602100870.573 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2020-10-07T20:01:10.573Z,1602100870.573 [CTD_Seabird](INFO): Powering down
2020-10-07T20:01:10.585Z,1602100870.585 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2020-10-07T20:01:10.601Z,1602100870.601 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2020-10-07T20:01:10.602Z,1602100870.602 [logger ThreadHandler](INFO): Thread cancelled.
2020-10-07T20:01:10.602Z,1602100870.602 [logger](INFO): Join timeout helper Thread ID is 1026
2020-10-07T20:01:10.629Z,1602100870.629 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2020-10-07T20:01:10.629Z,1602100870.629 [logger ThreadHandler](INFO): Thread cancelled.
2020-10-07T20:01:10.641Z,1602100870.641 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2020-10-07T20:01:10.642Z,1602100870.642 [CommandLine ThreadHandler](INFO): Thread cancelled.
2020-10-07T20:01:10.642Z,1602100870.642 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2020-10-07T20:01:10.642Z,1602100870.642 [controlThread ThreadHandler](INFO): Thread cancelled.
2020-10-07T20:01:10.642Z,1602100870.642 [controlThread](INFO): Join timeout helper Thread ID is 1027
2020-10-07T20:01:10.745Z,1602100870.745 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2020-10-07T20:01:10.745Z,1602100870.745 [controlThread](DEBUG): Uninitializing ControlThread
2020-10-07T20:01:10.747Z,1602100870.747 [AHRS_M2](INFO): Powering down
2020-10-07T20:01:10.817Z,1602100870.817 [NAL9602](INFO): Powering down
2020-10-07T20:01:10.985Z,1602100870.985 [AMEcho](INFO): Powering down
2020-10-07T20:01:10.986Z,1602100870.986 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2020-10-07T20:01:10.987Z,1602100870.987 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2020-10-07T20:01:10.987Z,1602100870.987 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2020-10-07T20:01:10.988Z,1602100870.988 [MissionManager](INFO): Uninitializing Mission Default
2020-10-07T20:01:10.988Z,1602100870.988 [Default] Stopped
2020-10-07T20:01:10.988Z,1602100870.988 [Default](DEBUG): Aggregate::uninitialize Default
2020-10-07T20:01:10.988Z,1602100870.988 [Default:B.GoToSurface] Stopped
2020-10-07T20:01:10.988Z,1602100870.988 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2020-10-07T20:01:10.988Z,1602100870.988 [Default:CheckIn] Stopped
2020-10-07T20:01:10.988Z,1602100870.988 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2020-10-07T20:01:10.988Z,1602100870.988 [Default:CheckIn:C.Wait] Stopped
2020-10-07T20:01:10.988Z,1602100870.988 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2020-10-07T20:01:10.991Z,1602100870.991 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2020-10-07T20:01:10.991Z,1602100870.991 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2020-10-07T20:01:10.991Z,1602100870.991 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2020-10-07T20:01:10.992Z,1602100870.992 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2020-10-07T20:01:10.992Z,1602100870.992 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2020-10-07T20:01:10.992Z,1602100870.992 [BuoyancyServo](INFO): Powering down
2020-10-07T20:01:11.005Z,1602100871.005 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2020-10-07T20:01:11.005Z,1602100871.005 [ElevatorServo](INFO): Powering down
2020-10-07T20:01:11.006Z,1602100871.006 [MassServo](DEBUG): Uninitialize Mass Servo.
2020-10-07T20:01:11.006Z,1602100871.006 [MassServo](INFO): Powering down
2020-10-07T20:01:11.007Z,1602100871.007 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2020-10-07T20:01:11.007Z,1602100871.007 [RudderServo](INFO): Powering down
2020-10-07T20:01:11.007Z,1602100871.007 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2020-10-07T20:01:11.007Z,1602100871.007 [ThrusterServo](INFO): Powering down
2020-10-07T20:01:11.008Z,1602100871.008 [SBIT](DEBUG): Uninitialize SBIT Component.
2020-10-07T20:01:11.009Z,1602100871.009 [IBIT](DEBUG): Uninitialize IBIT Component.
2020-10-07T20:01:11.009Z,1602100871.009 [CBIT](DEBUG): Uninitialize CBIT Component.
2020-10-07T20:01:11.009Z,1602100871.009 [CBIT](DEBUG): Powering off loads.
2020-10-07T20:01:11.021Z,1602100871.021 [CBIT](DEBUG): Disabling WDT.
2020-10-07T20:01:11.033Z,1602100871.033 [CBIT](DEBUG): Opening all GF detection circuits.
2020-10-07T20:01:11.033Z,1602100871.033 [controlThread ThreadHandler](INFO): Thread cancelled.
2020-10-07T20:01:11.069Z,1602100871.069 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2020-10-07T20:01:11.075Z,1602100871.075 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2020-10-07T20:01:11.141Z,1602100871.141 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2020-10-07T20:01:11.142Z,1602100871.142 [Onboard ThreadHandler](INFO): Thread cancelled.
2020-10-07T20:01:11.148Z,1602100871.148 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2020-10-07T20:01:11.200Z,1602100871.200 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2020-10-07T20:01:11.270Z,1602100871.270 [logger ThreadHandler](INFO): Thread cancelled.