2019-02-15T22:57:56.248Z,1550271476.248 [Supervisor](DEBUG): Initializing supervisor.
2019-02-15T22:57:56.251Z,1550271476.251 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2019-02-15T22:57:56.251Z,1550271476.251 [SyncHandler](INFO): Protected caller Thread ID is 8593
2019-02-15T22:57:56.251Z,1550271476.251 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2019-02-15T22:57:56.252Z,1550271476.252 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2019-02-15T22:57:56.253Z,1550271476.253 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 8594
2019-02-15T22:57:56.256Z,1550271476.256 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2019-02-15T22:57:56.268Z,1550271476.268 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2019-02-15T22:57:56.269Z,1550271476.269 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2019-02-15T22:57:56.269Z,1550271476.269 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 8595
2019-02-15T22:57:56.270Z,1550271476.270 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2019-02-15T22:57:56.271Z,1550271476.271 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2019-02-15T22:57:56.271Z,1550271476.271 [logger ThreadHandler](INFO): Protected caller Thread ID is 8596
2019-02-15T22:57:56.273Z,1550271476.273 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2019-02-15T22:57:56.274Z,1550271476.274 [Supervisor](INFO): Looking for Config files in directory: Config/
2019-02-15T22:57:56.275Z,1550271476.275 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2019-02-15T22:57:56.427Z,1550271476.427 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2019-02-15T22:57:56.427Z,1550271476.427 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2019-02-15T22:57:56.630Z,1550271476.630 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2019-02-15T22:57:56.630Z,1550271476.630 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2019-02-15T22:57:56.770Z,1550271476.770 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2019-02-15T22:57:56.771Z,1550271476.771 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2019-02-15T22:57:57.258Z,1550271477.258 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2019-02-15T22:57:57.258Z,1550271477.258 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2019-02-15T22:57:57.773Z,1550271477.773 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2019-02-15T22:57:57.773Z,1550271477.773 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2019-02-15T22:57:58.341Z,1550271478.341 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2019-02-15T22:57:58.341Z,1550271478.341 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2019-02-15T22:57:58.658Z,1550271478.658 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2019-02-15T22:57:58.659Z,1550271478.659 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2019-02-15T22:57:59.018Z,1550271479.018 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2019-02-15T22:57:59.018Z,1550271479.018 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2019-02-15T22:57:59.496Z,1550271479.496 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2019-02-15T22:57:59.497Z,1550271479.497 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2019-02-15T22:57:59.943Z,1550271479.943 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2019-02-15T22:57:59.943Z,1550271479.943 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2019-02-15T22:58:00.099Z,1550271480.099 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2019-02-15T22:58:00.100Z,1550271480.100 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2019-02-15T22:58:00.181Z,1550271480.181 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2019-02-15T22:58:00.284Z,1550271480.284 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2019-02-15T22:58:00.284Z,1550271480.284 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2019-02-15T22:58:00.546Z,1550271480.546 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2019-02-15T22:58:00.547Z,1550271480.547 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2019-02-15T22:58:00.758Z,1550271480.758 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2019-02-15T22:58:00.760Z,1550271480.760 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/
2019-02-15T22:58:00.761Z,1550271480.761 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/secure.cfg
2019-02-15T22:58:00.845Z,1550271480.845 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Battery.cfg
2019-02-15T22:58:01.088Z,1550271481.088 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2019-02-15T22:58:01.089Z,1550271481.089 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Navigation.cfg
2019-02-15T22:58:01.185Z,1550271481.185 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Sensor.cfg
2019-02-15T22:58:01.349Z,1550271481.349 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/vehicle.cfg
2019-02-15T22:58:01.560Z,1550271481.560 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Simulator.cfg
2019-02-15T22:58:01.646Z,1550271481.646 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Servo.cfg
2019-02-15T22:58:01.746Z,1550271481.746 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Control.cfg
2019-02-15T22:58:01.840Z,1550271481.840 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Science.cfg
2019-02-15T22:58:01.995Z,1550271481.995 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/logger.cfg
2019-02-15T22:58:02.102Z,1550271482.102 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/BIT.cfg
2019-02-15T22:58:02.202Z,1550271482.202 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/root/
2019-02-15T22:58:02.202Z,1550271482.202 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2019-02-15T22:58:02.204Z,1550271482.204 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2019-02-15T22:58:02.320Z,1550271482.320 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2019-02-15T22:58:02.320Z,1550271482.320 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2019-02-15T22:58:02.435Z,1550271482.435 [BuoyancyServo] Loaded
2019-02-15T22:58:02.436Z,1550271482.436 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2019-02-15T22:58:02.451Z,1550271482.451 [ElevatorServo] Loaded
2019-02-15T22:58:02.452Z,1550271482.452 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2019-02-15T22:58:02.467Z,1550271482.467 [MassServo] Loaded
2019-02-15T22:58:02.467Z,1550271482.467 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2019-02-15T22:58:02.482Z,1550271482.482 [RudderServo] Loaded
2019-02-15T22:58:02.483Z,1550271482.483 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2019-02-15T22:58:02.497Z,1550271482.497 [ThrusterServo] Loaded
2019-02-15T22:58:02.497Z,1550271482.497 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2019-02-15T22:58:02.498Z,1550271482.498 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2019-02-15T22:58:02.498Z,1550271482.498 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2019-02-15T22:58:02.651Z,1550271482.651 [SBIT](DEBUG): Construct Startup Built In Test.
2019-02-15T22:58:02.681Z,1550271482.681 [SBIT] Loaded
2019-02-15T22:58:02.681Z,1550271482.681 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2019-02-15T22:58:02.682Z,1550271482.682 [IBIT](DEBUG): Construct Initiated Built In Test.
2019-02-15T22:58:02.711Z,1550271482.711 [IBIT] Loaded
2019-02-15T22:58:02.711Z,1550271482.711 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2019-02-15T22:58:02.714Z,1550271482.714 [CBIT](DEBUG): Construct Continuous Built In Test.
2019-02-15T22:58:03.128Z,1550271483.128 [CBIT] Loaded
2019-02-15T22:58:03.129Z,1550271483.129 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2019-02-15T22:58:03.129Z,1550271483.129 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2019-02-15T22:58:03.129Z,1550271483.129 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2019-02-15T22:58:03.332Z,1550271483.332 [Aanderaa_O2] Loaded
2019-02-15T22:58:03.332Z,1550271483.332 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread.
2019-02-15T22:58:03.342Z,1550271483.342 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_density
2019-02-15T22:58:03.347Z,1550271483.347 [CTD_Seabird](INFO): created writer for : sea_water_density
2019-02-15T22:58:03.350Z,1550271483.350 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): depth
2019-02-15T22:58:03.355Z,1550271483.355 [CTD_Seabird](INFO): created writer for : depth
2019-02-15T22:58:03.355Z,1550271483.355 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_pressure
2019-02-15T22:58:03.361Z,1550271483.361 [CTD_Seabird](INFO): created writer for : sea_water_pressure
2019-02-15T22:58:03.361Z,1550271483.361 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_salinity
2019-02-15T22:58:03.367Z,1550271483.367 [CTD_Seabird](INFO): created writer for : sea_water_salinity
2019-02-15T22:58:03.367Z,1550271483.367 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_temperature
2019-02-15T22:58:03.373Z,1550271483.373 [CTD_Seabird](INFO): created writer for : sea_water_temperature
2019-02-15T22:58:03.374Z,1550271483.374 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_electrical_conductivity
2019-02-15T22:58:03.380Z,1550271483.380 [CTD_Seabird](INFO): created writer for : sea_water_electrical_conductivity
2019-02-15T22:58:03.380Z,1550271483.380 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): speed_of_sound_in_sea_water
2019-02-15T22:58:03.386Z,1550271483.386 [CTD_Seabird](INFO): created writer for : speed_of_sound_in_sea_water
2019-02-15T22:58:03.414Z,1550271483.414 [CTD_Seabird] Loaded
2019-02-15T22:58:03.414Z,1550271483.414 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2019-02-15T22:58:03.415Z,1550271483.415 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 4062F4E0
2019-02-15T22:58:03.416Z,1550271483.416 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 8676
2019-02-15T22:58:03.438Z,1550271483.438 [ESPComponent] Loaded
2019-02-15T22:58:03.438Z,1550271483.438 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread.
2019-02-15T22:58:03.489Z,1550271483.489 [PAR_Licor] Loaded
2019-02-15T22:58:03.489Z,1550271483.489 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2019-02-15T22:58:03.565Z,1550271483.565 [WetLabsBB2FL] Loaded
2019-02-15T22:58:03.566Z,1550271483.566 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2019-02-15T22:58:03.567Z,1550271483.567 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 4065F4E0
2019-02-15T22:58:03.567Z,1550271483.567 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 8677
2019-02-15T22:58:03.568Z,1550271483.568 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2019-02-15T22:58:03.568Z,1550271483.568 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2019-02-15T22:58:03.614Z,1550271483.614 [DepthRateCalculator] Loaded
2019-02-15T22:58:03.614Z,1550271483.614 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2019-02-15T22:58:03.620Z,1550271483.620 [PitchRateCalculator] Loaded
2019-02-15T22:58:03.620Z,1550271483.620 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2019-02-15T22:58:03.637Z,1550271483.637 [SpeedCalculator] Loaded
2019-02-15T22:58:03.637Z,1550271483.637 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2019-02-15T22:58:03.658Z,1550271483.658 [TempGradientCalculator] Loaded
2019-02-15T22:58:03.659Z,1550271483.659 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2019-02-15T22:58:03.665Z,1550271483.665 [YawRateCalculator] Loaded
2019-02-15T22:58:03.665Z,1550271483.665 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2019-02-15T22:58:03.700Z,1550271483.700 [ElevatorOffsetCalculator] Loaded
2019-02-15T22:58:03.700Z,1550271483.700 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2019-02-15T22:58:03.700Z,1550271483.700 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2019-02-15T22:58:03.701Z,1550271483.701 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2019-02-15T22:58:03.731Z,1550271483.731 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2019-02-15T22:58:03.732Z,1550271483.732 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2019-02-15T22:58:03.841Z,1550271483.841 [DeadReckonUsingMultipleVelocitySources] Loaded
2019-02-15T22:58:03.841Z,1550271483.841 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2019-02-15T22:58:03.904Z,1550271483.904 [DeadReckonUsingSpeedCalculator] Loaded
2019-02-15T22:58:03.904Z,1550271483.904 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread.
2019-02-15T22:58:03.966Z,1550271483.966 [DeadReckonWithRespectToSeafloor] Loaded
2019-02-15T22:58:03.967Z,1550271483.967 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonWithRespectToSeafloor" handled in the control thread.
2019-02-15T22:58:03.984Z,1550271483.984 [NavChart] Loaded
2019-02-15T22:58:03.984Z,1550271483.984 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2019-02-15T22:58:03.988Z,1550271483.988 [UniversalFixResidualReporter] Loaded
2019-02-15T22:58:03.988Z,1550271483.988 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2019-02-15T22:58:03.989Z,1550271483.989 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2019-02-15T22:58:03.989Z,1550271483.989 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2019-02-15T22:58:04.342Z,1550271484.342 [AcousticModem_Benthos_ATM900] Loaded
2019-02-15T22:58:04.342Z,1550271484.342 [ComponentRegistry](DEBUG): SyncComponent "AcousticModem_Benthos_ATM900" handled in the control thread.
2019-02-15T22:58:04.428Z,1550271484.428 [DataOverHttps] Loaded
2019-02-15T22:58:04.428Z,1550271484.428 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2019-02-15T22:58:04.429Z,1550271484.429 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 409264E0
2019-02-15T22:58:04.430Z,1550271484.430 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 8678
2019-02-15T22:58:04.443Z,1550271484.443 [Depth_Keller] Loaded
2019-02-15T22:58:04.444Z,1550271484.444 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2019-02-15T22:58:04.449Z,1550271484.449 [DropWeight] Loaded
2019-02-15T22:58:04.449Z,1550271484.449 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2019-02-15T22:58:04.546Z,1550271484.546 [NAL9602] Loaded
2019-02-15T22:58:04.546Z,1550271484.546 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2019-02-15T22:58:04.551Z,1550271484.551 [Onboard] Loaded
2019-02-15T22:58:04.552Z,1550271484.552 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2019-02-15T22:58:04.559Z,1550271484.559 [Radio_Surface] Loaded
2019-02-15T22:58:04.560Z,1550271484.560 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2019-02-15T22:58:04.561Z,1550271484.561 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 409564E0
2019-02-15T22:58:04.561Z,1550271484.561 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 8679
2019-02-15T22:58:04.611Z,1550271484.611 [PNI_TCM] Loaded
2019-02-15T22:58:04.611Z,1550271484.611 [ComponentRegistry](DEBUG): SyncComponent "PNI_TCM" handled in the control thread.
2019-02-15T22:58:04.675Z,1550271484.675 [Rowe_600LCM] Loaded
2019-02-15T22:58:04.675Z,1550271484.675 [ComponentRegistry](DEBUG): Component "Rowe_600LCM" handled in its own thread.
2019-02-15T22:58:04.676Z,1550271484.676 [Rowe_600LCM ThreadHandler](DEBUG): Created PCaller Thread at 409864E0
2019-02-15T22:58:04.676Z,1550271484.676 [Rowe_600LCM ThreadHandler](INFO): Protected caller Thread ID is 8680
2019-02-15T22:58:07.050Z,1550271487.050 [BPC1] Loaded
2019-02-15T22:58:07.050Z,1550271487.050 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2019-02-15T22:58:07.051Z,1550271487.051 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2019-02-15T22:58:07.051Z,1550271487.051 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2019-02-15T22:58:07.125Z,1550271487.125 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2019-02-15T22:58:07.126Z,1550271487.126 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2019-02-15T22:58:07.202Z,1550271487.202 [VerticalControl](DEBUG): Construct VerticalControl.
2019-02-15T22:58:07.289Z,1550271487.289 [VerticalControl] Loaded
2019-02-15T22:58:07.289Z,1550271487.289 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2019-02-15T22:58:07.290Z,1550271487.290 [HorizontalControl](DEBUG): Construct HorizontalControl.
2019-02-15T22:58:07.350Z,1550271487.350 [HorizontalControl] Loaded
2019-02-15T22:58:07.350Z,1550271487.350 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2019-02-15T22:58:07.351Z,1550271487.351 [SpeedControl](DEBUG): Construct SpeedControl.
2019-02-15T22:58:07.352Z,1550271487.352 [SpeedControl] Loaded
2019-02-15T22:58:07.353Z,1550271487.353 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2019-02-15T22:58:07.353Z,1550271487.353 [LoopControl](DEBUG): Construct LoopControl.
2019-02-15T22:58:07.354Z,1550271487.354 [LoopControl] Loaded
2019-02-15T22:58:07.354Z,1550271487.354 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2019-02-15T22:58:07.355Z,1550271487.355 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2019-02-15T22:58:07.355Z,1550271487.355 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2019-02-15T22:58:07.370Z,1550271487.370 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2019-02-15T22:58:07.370Z,1550271487.370 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2019-02-15T22:58:07.643Z,1550271487.643 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2019-02-15T22:58:07.647Z,1550271487.647 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2019-02-15T22:58:07.648Z,1550271487.648 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2019-02-15T22:58:07.655Z,1550271487.655 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2019-02-15T22:58:07.656Z,1550271487.656 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40AA84E0
2019-02-15T22:58:07.656Z,1550271487.656 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 8681
2019-02-15T22:58:07.661Z,1550271487.661 [Supervisor](INFO): Main Thread ID is 8592
2019-02-15T22:58:07.661Z,1550271487.661 [Supervisor](DEBUG): Running supervisor.
2019-02-15T22:58:07.661Z,1550271487.661 [CommandLine ThreadHandler](INFO): Handler Thread ID is 8682
2019-02-15T22:58:07.664Z,1550271487.664 [controlThread ThreadHandler](INFO): Handler Thread ID is 8683
2019-02-15T22:58:07.664Z,1550271487.664 [controlThread](DEBUG): Initializing ControlThread
2019-02-15T22:58:07.666Z,1550271487.666 [SBIT](INFO): Initialize SBIT Component.
2019-02-15T22:58:07.667Z,1550271487.667 [SBIT](IMPORTANT): git: 2019-02-11-17-g39ce128
2019-02-15T22:58:07.667Z,1550271487.667 [SBIT](INFO): git hash: 39ce1284db7b6a04b9b34859acc7cb9eff4ab2f4
2019-02-15T22:58:07.667Z,1550271487.667 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2019-02-15T22:58:07.669Z,1550271487.669 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #2 PREEMPT Thu Jan 11 20:13:48 PST 2018
Kernel Reported: #1 PREEMPT Tue Dec 18 21:19:28 PST 2018
2019-02-15T22:58:07.670Z,1550271487.670 [SBIT](INFO): Beginning SBIT in 24.000000 seconds.
2019-02-15T22:58:07.670Z,1550271487.670 [IBIT](INFO): Initialize IBIT Component.
2019-02-15T22:58:07.671Z,1550271487.671 [CBIT](DEBUG): Initialize CBIT Component.
2019-02-15T22:58:07.672Z,1550271487.672 [logger ThreadHandler](INFO): Handler Thread ID is 8684
2019-02-15T22:58:07.683Z,1550271487.683 [CBIT](DEBUG): Initialized mux pins.
2019-02-15T22:58:07.683Z,1550271487.683 [CBIT](DEBUG): Initializing the watchdog timer.
2019-02-15T22:58:07.691Z,1550271487.691 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 8685
2019-02-15T22:58:07.692Z,1550271487.692 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2019-02-15T22:58:07.695Z,1550271487.695 [CTD_Seabird](INFO): Opening uart, block timeout 10ths=20
2019-02-15T22:58:07.697Z,1550271487.697 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 8687
2019-02-15T22:58:07.698Z,1550271487.698 [WetLabsBB2FL](INFO): Powering down
2019-02-15T22:58:07.711Z,1550271487.711 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2019-02-15T22:58:07.711Z,1550271487.711 [CBIT](DEBUG): Initializing heartbeat.
2019-02-15T22:58:07.731Z,1550271487.731 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 8688
2019-02-15T22:58:07.739Z,1550271487.739 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2019-02-15T22:58:07.755Z,1550271487.755 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 8689
2019-02-15T22:58:07.760Z,1550271487.760 [Radio_Surface](INFO): Powering up
2019-02-15T22:58:07.761Z,1550271487.761 [Rowe_600LCM ThreadHandler](INFO): Handler Thread ID is 8690
2019-02-15T22:58:07.761Z,1550271487.761 [Rowe_600LCM](INFO): Initializing
2019-02-15T22:58:07.771Z,1550271487.771 [Rowe_600LCM](INFO): Powering up
2019-02-15T22:58:07.783Z,1550271487.783 [CBIT](DEBUG): Deactivating GF circuits.
2019-02-15T22:58:07.783Z,1550271487.783 [CBIT](DEBUG): Deactivating emergency mode.
2019-02-15T22:58:07.783Z,1550271487.783 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 8691
2019-02-15T22:58:07.792Z,1550271487.792 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2019-02-15T22:58:07.792Z,1550271487.792 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2019-02-15T22:58:07.792Z,1550271487.792 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2019-02-15T22:58:07.792Z,1550271487.792 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2019-02-15T22:58:07.793Z,1550271487.793 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2019-02-15T22:58:07.793Z,1550271487.793 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2019-02-15T22:58:07.793Z,1550271487.793 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2019-02-15T22:58:07.793Z,1550271487.793 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2019-02-15T22:58:07.793Z,1550271487.793 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2019-02-15T22:58:07.793Z,1550271487.793 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2019-02-15T22:58:07.794Z,1550271487.794 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2019-02-15T22:58:07.794Z,1550271487.794 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2019-02-15T22:58:07.794Z,1550271487.794 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2019-02-15T22:58:07.794Z,1550271487.794 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2019-02-15T22:58:07.794Z,1550271487.794 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2019-02-15T22:58:07.795Z,1550271487.795 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2019-02-15T22:58:07.823Z,1550271487.823 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2019-02-15T22:58:07.824Z,1550271487.824 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2019-02-15T22:58:07.824Z,1550271487.824 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2019-02-15T22:58:07.825Z,1550271487.825 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2019-02-15T22:58:07.825Z,1550271487.825 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2019-02-15T22:58:07.825Z,1550271487.825 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2019-02-15T22:58:07.827Z,1550271487.827 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2019-02-15T22:58:07.828Z,1550271487.828 [NavChart](DEBUG): Initialize NavChart Navigation.
2019-02-15T22:58:07.828Z,1550271487.828 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2019-02-15T22:58:07.833Z,1550271487.833 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2019-02-15T22:58:07.839Z,1550271487.839 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2019-02-15T22:58:07.840Z,1550271487.840 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2019-02-15T22:58:07.840Z,1550271487.840 [LoopControl](DEBUG): Initialize LoopControlComponent.
2019-02-15T22:58:07.841Z,1550271487.841 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2019-02-15T22:58:07.869Z,1550271487.869 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2019-02-15T22:58:07.907Z,1550271487.907 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
       xmlns:Control="Tethys/Control"
       xmlns:Guidance="Tethys/Guidance" 
       xmlns:Units="Tethys/Units"
       xmlns:Universal="Tethys/Universal"
       xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
       xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                           Tethys/Control http://okeanids.mbari.org/tethys/Xml/Control.xsd
                           Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                           Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                           Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
       Id="Startup">

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

    <Aggregate Id="StartupSatComms">

        <Sequence/>

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

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

    </Aggregate>

</Mission>


2019-02-15T22:58:07.908Z,1550271487.908 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2019-02-15T22:58:07.966Z,1550271487.966 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2019-02-15T22:58:07.967Z,1550271487.967 [Default:A.Wait](DEBUG): Construct Wait.
2019-02-15T22:58:07.969Z,1550271487.969 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2019-02-15T22:58:08.020Z,1550271488.020 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2019-02-15T22:58:08.022Z,1550271488.022 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2019-02-15T22:58:08.075Z,1550271488.075 [Default:E.Execute](DEBUG): Construct Execute.
2019-02-15T22:58:08.098Z,1550271488.098 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xmlns="Tethys"
         xmlns:Units="Tethys/Units"
         xmlns:Guidance="Tethys/Guidance"
         xmlns:Universal="Tethys/Universal"
         xsi:schemaLocation="Tethys http://okeanids.mbari.org/tethys/Xml/Tethys.xsd
                             Tethys/Units http://okeanids.mbari.org/tethys/Xml/Units.xsd
                             Tethys/Guidance http://okeanids.mbari.org/tethys/Xml/Guidance.xsd
                             Tethys/Universal http://okeanids.mbari.org/tethys/Xml/Universal.xsd"
         Id="Default">

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

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

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

    <Aggregate Id="CheckIn">

        <Sequence Repeat="288"/>

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

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

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

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

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

    </Aggregate>

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

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

</Mission>


2019-02-15T22:58:08.119Z,1550271488.119 [controlThread](DEBUG): Component order: CycleStarter,Aanderaa_O2,ESPComponent,PAR_Licor,AcousticModem_Benthos_ATM900,Depth_Keller,DropWeight,NAL9602,Onboard,PNI_TCM,BPC1,PAR_Licor,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,DeadReckonUsingSpeedCalculator,DeadReckonWithRespectToSeafloor,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2019-02-15T22:58:08.182Z,1550271488.182 [ESPComponent](INFO): powering down ESP
2019-02-15T22:58:08.491Z,1550271488.491 [AcousticModem_Benthos_ATM900](INFO): Powering up
2019-02-15T22:58:08.491Z,1550271488.491 [AcousticModem_Benthos_ATM900](DEBUG): Initializing AcousticModem_Benthos_ATM900.
2019-02-15T22:58:09.020Z,1550271489.020 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2019-02-15T22:58:09.027Z,1550271489.027 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2019-02-15T22:58:09.042Z,1550271489.042 [ElevatorServo](DEBUG): Initializing EZServoServo.
2019-02-15T22:58:09.047Z,1550271489.047 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2019-02-15T22:58:09.054Z,1550271489.054 [MassServo](DEBUG): Initializing EZServoServo.
2019-02-15T22:58:09.083Z,1550271489.083 [MassServo](DEBUG): Initializing MassServo.
2019-02-15T22:58:09.101Z,1550271489.101 [RudderServo](DEBUG): Initializing EZServoServo.
2019-02-15T22:58:09.107Z,1550271489.107 [RudderServo](DEBUG): Initializing RudderServo.
2019-02-15T22:58:09.113Z,1550271489.113 [ThrusterServo](DEBUG): Initializing EZServoServo.
2019-02-15T22:58:09.119Z,1550271489.119 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2019-02-15T22:58:09.286Z,1550271489.286 [DropWeight](CRITICAL): DROP WEIGHT MISSING.

2019-02-15T22:58:09.286Z,1550271489.286 [DropWeight] Hardware Fault, FailCount= 1
2019-02-15T22:58:09.286Z,1550271489.286 [DropWeight](ERROR): Hardware Fault
2019-02-15T22:58:09.399Z,1550271489.399 [CommandLine](FAULT): Scheduling is paused
2019-02-15T22:58:09.399Z,1550271489.399 [CBIT](INFO): Critical error at 20190215T225809
2019-02-15T22:58:09.400Z,1550271489.400 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2019-02-15T22:58:09.420Z,1550271489.420 [CBIT](ERROR): Hardware Fault in component: DropWeight
2019-02-15T22:58:09.420Z,1550271489.420 [CBIT](CRITICAL): Hardware Fault in component: DropWeight
2019-02-15T22:58:09.987Z,1550271489.987 [BuoyancyServo](ERROR): Buoyancy initialization uart error serial timeout
2019-02-15T22:58:09.987Z,1550271489.987 [BuoyancyServo](FAULT): Buoyancy failed to initialize
2019-02-15T22:58:09.987Z,1550271489.987 [BuoyancyServo] Communications Fault, FailCount= 1
2019-02-15T22:58:09.987Z,1550271489.987 [BuoyancyServo](ERROR): Communications Fault
2019-02-15T22:58:10.201Z,1550271490.201 [CBIT](INFO): Critical error at 20190215T225809
2019-02-15T22:58:10.204Z,1550271490.204 [CBIT](ERROR): Communications Fault in component: BuoyancyServo
2019-02-15T22:58:11.539Z,1550271491.539 [Aanderaa_O2](INFO): Powering down
2019-02-15T22:58:12.115Z,1550271492.115 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2019-02-15T22:58:12.174Z,1550271492.174 [Rowe_600LCM](INFO): Started Rowe LCM interface with command:nohup ./lrauv-framework/onboard/bin/roweadcp -ldir /mnt/mmc/LRAUV/Logs/latest/ -dev /dev/ttyB4 -b 9600 >& /dev/null &
2019-02-15T22:58:12.460Z,1550271492.460 [CBIT](INFO): Clearing failed state for component BuoyancyServo
2019-02-15T22:58:12.460Z,1550271492.460 [BuoyancyServo] No Fault, FailCount= 1
2019-02-15T22:58:12.750Z,1550271492.750 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2019-02-15T22:58:12.750Z,1550271492.750 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2019-02-15T22:58:14.752Z,1550271494.752 [CTD_Seabird](ERROR): Device message queue exceeded the allowed limit.
2019-02-15T22:58:16.308Z,1550271496.308 [AcousticModem_Benthos_ATM900](DEBUG): 
2019-02-15T22:58:17.540Z,1550271497.540 [AcousticModem_Benthos_ATM900](DEBUG): Teledyne Benthos ATM-900 Series OEM w/burn wire
2019-02-15T22:58:17.541Z,1550271497.541 [AcousticModem_Benthos_ATM900](DEBUG): MF Frequency Band
2019-02-15T22:58:17.542Z,1550271497.542 [AcousticModem_Benthos_ATM900](DEBUG): Standard version 8.6.3
2019-02-15T22:58:17.542Z,1550271497.542 [AcousticModem_Benthos_ATM900](DEBUG): Feb 11 2019 19:26:21 
2019-02-15T22:58:17.756Z,1550271497.756 [CBIT](CRITICAL): Environmental Failure. Press:14.795944 PSI. Humidity:30%. Temp:24 C. ABORTING MISSION
2019-02-15T22:58:17.924Z,1550271497.924 [AcousticModem_Benthos_ATM900](DEBUG): WARNING: battery low
2019-02-15T22:58:18.067Z,1550271498.067 [CBIT](INFO): Critical error at 20190215T225817
2019-02-15T22:58:18.734Z,1550271498.734 [AcousticModem_Benthos_ATM900](INFO): entering command mode
2019-02-15T22:58:19.140Z,1550271499.140 [AcousticModem_Benthos_ATM900](DEBUG): checking for command mode acknowledgmen