2019-02-21T23:05:32.376Z,1550790332.376 [Supervisor](DEBUG): Initializing supervisor.
2019-02-21T23:05:32.379Z,1550790332.379 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2019-02-21T23:05:32.380Z,1550790332.380 [SyncHandler](INFO): Protected caller Thread ID is 806
2019-02-21T23:05:32.380Z,1550790332.380 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2019-02-21T23:05:32.381Z,1550790332.381 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2019-02-21T23:05:32.381Z,1550790332.381 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 807
2019-02-21T23:05:32.384Z,1550790332.384 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2019-02-21T23:05:32.396Z,1550790332.396 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2019-02-21T23:05:32.397Z,1550790332.397 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2019-02-21T23:05:32.397Z,1550790332.397 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 808
2019-02-21T23:05:32.398Z,1550790332.398 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2019-02-21T23:05:32.399Z,1550790332.399 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2019-02-21T23:05:32.399Z,1550790332.399 [logger ThreadHandler](INFO): Protected caller Thread ID is 809
2019-02-21T23:05:32.401Z,1550790332.401 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2019-02-21T23:05:32.402Z,1550790332.402 [Supervisor](INFO): Looking for Config files in directory: Config/
2019-02-21T23:05:32.406Z,1550790332.406 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2019-02-21T23:05:32.612Z,1550790332.612 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2019-02-21T23:05:32.613Z,1550790332.613 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2019-02-21T23:05:32.695Z,1550790332.695 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2019-02-21T23:05:33.155Z,1550790333.155 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2019-02-21T23:05:33.155Z,1550790333.155 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2019-02-21T23:05:33.500Z,1550790333.500 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2019-02-21T23:05:33.500Z,1550790333.500 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2019-02-21T23:05:33.598Z,1550790333.598 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2019-02-21T23:05:33.599Z,1550790333.599 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2019-02-21T23:05:33.913Z,1550790333.913 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2019-02-21T23:05:33.914Z,1550790333.914 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2019-02-21T23:05:34.123Z,1550790334.123 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2019-02-21T23:05:34.123Z,1550790334.123 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2019-02-21T23:05:34.593Z,1550790334.593 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2019-02-21T23:05:34.594Z,1550790334.594 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2019-02-21T23:05:34.700Z,1550790334.700 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2019-02-21T23:05:34.702Z,1550790334.702 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2019-02-21T23:05:34.806Z,1550790334.806 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2019-02-21T23:05:34.807Z,1550790334.807 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2019-02-21T23:05:35.322Z,1550790335.322 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2019-02-21T23:05:35.323Z,1550790335.323 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2019-02-21T23:05:35.742Z,1550790335.742 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2019-02-21T23:05:35.742Z,1550790335.742 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2019-02-21T23:05:36.574Z,1550790336.574 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2019-02-21T23:05:36.575Z,1550790336.575 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2019-02-21T23:05:36.724Z,1550790336.724 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2019-02-21T23:05:36.725Z,1550790336.725 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2019-02-21T23:05:36.879Z,1550790336.879 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2019-02-21T23:05:36.881Z,1550790336.881 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-daphne/
2019-02-21T23:05:36.885Z,1550790336.885 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Navigation.cfg
2019-02-21T23:05:36.979Z,1550790336.979 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Simulator.cfg
2019-02-21T23:05:37.066Z,1550790337.066 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Control.cfg
2019-02-21T23:05:37.173Z,1550790337.173 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/secure.cfg
2019-02-21T23:05:37.258Z,1550790337.258 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Servo.cfg
2019-02-21T23:05:37.356Z,1550790337.356 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/BIT.cfg
2019-02-21T23:05:37.458Z,1550790337.458 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/vehicle.cfg
2019-02-21T23:05:37.650Z,1550790337.650 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/workSite.cfg
2019-02-21T23:05:37.726Z,1550790337.726 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Sensor.cfg
2019-02-21T23:05:37.896Z,1550790337.896 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Science.cfg
2019-02-21T23:05:38.027Z,1550790338.027 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/logger.cfg
2019-02-21T23:05:38.151Z,1550790338.151 [Supervisor](INFO): Opening Config file at: Config/lrauv-daphne/Battery.cfg
2019-02-21T23:05:38.388Z,1550790338.388 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2019-02-21T23:05:38.388Z,1550790338.388 [Supervisor](FAULT): Ignoring configuration overrides from Data/persisted.cfg
2019-02-21T23:05:38.393Z,1550790338.393 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2019-02-21T23:05:38.483Z,1550790338.483 [VerticalControl](DEBUG): Construct VerticalControl.
2019-02-21T23:05:38.605Z,1550790338.605 [VerticalControl] Loaded
2019-02-21T23:05:38.605Z,1550790338.605 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2019-02-21T23:05:38.606Z,1550790338.606 [HorizontalControl](DEBUG): Construct HorizontalControl.
2019-02-21T23:05:38.678Z,1550790338.678 [HorizontalControl] Loaded
2019-02-21T23:05:38.678Z,1550790338.678 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2019-02-21T23:05:38.679Z,1550790338.679 [SpeedControl](DEBUG): Construct SpeedControl.
2019-02-21T23:05:38.684Z,1550790338.684 [SpeedControl] Loaded
2019-02-21T23:05:38.685Z,1550790338.685 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2019-02-21T23:05:38.685Z,1550790338.685 [LoopControl](DEBUG): Construct LoopControl.
2019-02-21T23:05:38.687Z,1550790338.687 [LoopControl] Loaded
2019-02-21T23:05:38.687Z,1550790338.687 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2019-02-21T23:05:38.687Z,1550790338.687 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2019-02-21T23:05:38.688Z,1550790338.688 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2019-02-21T23:05:38.712Z,1550790338.712 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2019-02-21T23:05:38.713Z,1550790338.713 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2019-02-21T23:05:38.844Z,1550790338.844 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2019-02-21T23:05:38.845Z,1550790338.845 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2019-02-21T23:05:38.994Z,1550790338.994 [BuoyancyServo] Loaded
2019-02-21T23:05:38.994Z,1550790338.994 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2019-02-21T23:05:39.006Z,1550790339.006 [ElevatorServo] Loaded
2019-02-21T23:05:39.007Z,1550790339.007 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2019-02-21T23:05:39.018Z,1550790339.018 [MassServo] Loaded
2019-02-21T23:05:39.018Z,1550790339.018 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2019-02-21T23:05:39.030Z,1550790339.030 [RudderServo] Loaded
2019-02-21T23:05:39.030Z,1550790339.030 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2019-02-21T23:05:39.042Z,1550790339.042 [ThrusterServo] Loaded
2019-02-21T23:05:39.042Z,1550790339.042 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2019-02-21T23:05:39.042Z,1550790339.042 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2019-02-21T23:05:39.043Z,1550790339.043 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2019-02-21T23:05:39.172Z,1550790339.172 [DeadReckonUsingMultipleVelocitySources] Loaded
2019-02-21T23:05:39.173Z,1550790339.173 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2019-02-21T23:05:39.235Z,1550790339.235 [DeadReckonUsingSpeedCalculator] Loaded
2019-02-21T23:05:39.235Z,1550790339.235 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread.
2019-02-21T23:05:39.296Z,1550790339.296 [DeadReckonWithRespectToSeafloor] Loaded
2019-02-21T23:05:39.296Z,1550790339.296 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonWithRespectToSeafloor" handled in the control thread.
2019-02-21T23:05:39.313Z,1550790339.313 [NavChart] Loaded
2019-02-21T23:05:39.313Z,1550790339.313 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2019-02-21T23:05:39.318Z,1550790339.318 [UniversalFixResidualReporter] Loaded
2019-02-21T23:05:39.318Z,1550790339.318 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2019-02-21T23:05:39.319Z,1550790339.319 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2019-02-21T23:05:39.319Z,1550790339.319 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2019-02-21T23:05:39.425Z,1550790339.425 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2019-02-21T23:05:39.426Z,1550790339.426 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2019-02-21T23:05:40.030Z,1550790340.030 [DataOverHttps] Loaded
2019-02-21T23:05:40.030Z,1550790340.030 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread.
2019-02-21T23:05:40.044Z,1550790340.044 [Depth_Keller] Loaded
2019-02-21T23:05:40.045Z,1550790340.045 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2019-02-21T23:05:40.050Z,1550790340.050 [DropWeight] Loaded
2019-02-21T23:05:40.050Z,1550790340.050 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2019-02-21T23:05:40.151Z,1550790340.151 [NAL9602] Loaded
2019-02-21T23:05:40.152Z,1550790340.152 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2019-02-21T23:05:40.169Z,1550790340.169 [Onboard] Loaded
2019-02-21T23:05:40.169Z,1550790340.169 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2019-02-21T23:05:40.176Z,1550790340.176 [Radio_Surface] Loaded
2019-02-21T23:05:40.176Z,1550790340.176 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2019-02-21T23:05:40.178Z,1550790340.178 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 408624E0
2019-02-21T23:05:40.178Z,1550790340.178 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 891
2019-02-21T23:05:40.332Z,1550790340.332 [PNI_TCM] Loaded
2019-02-21T23:05:40.333Z,1550790340.333 [ComponentRegistry](DEBUG): SyncComponent "PNI_TCM" handled in the control thread.
2019-02-21T23:05:40.396Z,1550790340.396 [Rowe_600LCM] Loaded
2019-02-21T23:05:40.397Z,1550790340.397 [ComponentRegistry](DEBUG): Component "Rowe_600LCM" handled in its own thread.
2019-02-21T23:05:40.398Z,1550790340.398 [Rowe_600LCM ThreadHandler](DEBUG): Created PCaller Thread at 408924E0
2019-02-21T23:05:40.398Z,1550790340.398 [Rowe_600LCM ThreadHandler](INFO): Protected caller Thread ID is 892
2019-02-21T23:05:40.398Z,1550790340.398 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2019-02-21T23:05:40.399Z,1550790340.399 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2019-02-21T23:05:40.457Z,1550790340.457 [DepthRateCalculator] Loaded
2019-02-21T23:05:40.457Z,1550790340.457 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2019-02-21T23:05:40.462Z,1550790340.462 [PitchRateCalculator] Loaded
2019-02-21T23:05:40.463Z,1550790340.463 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2019-02-21T23:05:40.475Z,1550790340.475 [SpeedCalculator] Loaded
2019-02-21T23:05:40.475Z,1550790340.475 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2019-02-21T23:05:40.497Z,1550790340.497 [TempGradientCalculator] Loaded
2019-02-21T23:05:40.497Z,1550790340.497 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2019-02-21T23:05:40.503Z,1550790340.503 [YawRateCalculator] Loaded
2019-02-21T23:05:40.503Z,1550790340.503 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2019-02-21T23:05:40.535Z,1550790340.535 [ElevatorOffsetCalculator] Loaded
2019-02-21T23:05:40.535Z,1550790340.535 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2019-02-21T23:05:40.536Z,1550790340.536 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2019-02-21T23:05:40.536Z,1550790340.536 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2019-02-21T23:05:41.174Z,1550790341.174 [Aanderaa_O2] Loaded
2019-02-21T23:05:41.175Z,1550790341.175 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread.
2019-02-21T23:05:41.288Z,1550790341.288 [CTD_NeilBrown] Loaded
2019-02-21T23:05:41.288Z,1550790341.288 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2019-02-21T23:05:41.289Z,1550790341.289 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 4095C4E0
2019-02-21T23:05:41.290Z,1550790341.290 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 894
2019-02-21T23:05:41.299Z,1550790341.299 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_density
2019-02-21T23:05:41.304Z,1550790341.304 [CTD_Seabird](INFO): created writer for : sea_water_density
2019-02-21T23:05:41.306Z,1550790341.306 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): depth
2019-02-21T23:05:41.311Z,1550790341.311 [CTD_Seabird](INFO): created writer for : depth
2019-02-21T23:05:41.312Z,1550790341.312 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_pressure
2019-02-21T23:05:41.367Z,1550790341.367 [CTD_Seabird](INFO): created writer for : sea_water_pressure
2019-02-21T23:05:41.368Z,1550790341.368 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_salinity
2019-02-21T23:05:41.373Z,1550790341.373 [CTD_Seabird](INFO): created writer for : sea_water_salinity
2019-02-21T23:05:41.374Z,1550790341.374 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_temperature
2019-02-21T23:05:41.439Z,1550790341.439 [CTD_Seabird](INFO): created writer for : sea_water_temperature
2019-02-21T23:05:41.440Z,1550790341.440 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): sea_water_electrical_conductivity
2019-02-21T23:05:41.447Z,1550790341.447 [CTD_Seabird](INFO): created writer for : sea_water_electrical_conductivity
2019-02-21T23:05:41.448Z,1550790341.448 [CTD_Seabird](DEBUG): LcmSlateWriter::add(): speed_of_sound_in_sea_water
2019-02-21T23:05:41.453Z,1550790341.453 [CTD_Seabird](INFO): created writer for : speed_of_sound_in_sea_water
2019-02-21T23:05:41.481Z,1550790341.481 [CTD_Seabird] Loaded
2019-02-21T23:05:41.482Z,1550790341.482 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2019-02-21T23:05:41.483Z,1550790341.483 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 4098C4E0
2019-02-21T23:05:41.483Z,1550790341.483 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 895
2019-02-21T23:05:41.498Z,1550790341.498 [PAR_Licor] Loaded
2019-02-21T23:05:41.498Z,1550790341.498 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2019-02-21T23:05:41.549Z,1550790341.549 [WetLabsBB2FL] Loaded
2019-02-21T23:05:41.550Z,1550790341.550 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2019-02-21T23:05:41.551Z,1550790341.551 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 409BC4E0
2019-02-21T23:05:41.551Z,1550790341.551 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 896
2019-02-21T23:05:41.552Z,1550790341.552 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2019-02-21T23:05:41.553Z,1550790341.553 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2019-02-21T23:05:41.595Z,1550790341.595 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2019-02-21T23:05:41.596Z,1550790341.596 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2019-02-21T23:05:41.891Z,1550790341.891 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2019-02-21T23:05:41.892Z,1550790341.892 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2019-02-21T23:05:42.059Z,1550790342.059 [SBIT](DEBUG): Construct Startup Built In Test.
2019-02-21T23:05:42.071Z,1550790342.071 [SBIT] Loaded
2019-02-21T23:05:42.071Z,1550790342.071 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2019-02-21T23:05:42.072Z,1550790342.072 [IBIT](DEBUG): Construct Initiated Built In Test.
2019-02-21T23:05:42.085Z,1550790342.085 [IBIT] Loaded
2019-02-21T23:05:42.086Z,1550790342.086 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2019-02-21T23:05:42.089Z,1550790342.089 [CBIT](DEBUG): Construct Continuous Built In Test.
2019-02-21T23:05:42.495Z,1550790342.495 [CBIT] Loaded
2019-02-21T23:05:42.495Z,1550790342.495 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2019-02-21T23:05:42.495Z,1550790342.495 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2019-02-21T23:05:42.499Z,1550790342.499 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2019-02-21T23:05:42.500Z,1550790342.500 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2019-02-21T23:05:42.507Z,1550790342.507 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2019-02-21T23:05:42.508Z,1550790342.508 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40AA64E0
2019-02-21T23:05:42.509Z,1550790342.509 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 897
2019-02-21T23:05:42.513Z,1550790342.513 [Supervisor](INFO): Main Thread ID is 802
2019-02-21T23:05:42.513Z,1550790342.513 [Supervisor](DEBUG): Running supervisor.
2019-02-21T23:05:42.514Z,1550790342.514 [CommandLine ThreadHandler](INFO): Handler Thread ID is 898
2019-02-21T23:05:42.516Z,1550790342.516 [controlThread ThreadHandler](INFO): Handler Thread ID is 899
2019-02-21T23:05:42.517Z,1550790342.517 [controlThread](DEBUG): Initializing ControlThread
2019-02-21T23:05:42.517Z,1550790342.517 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2019-02-21T23:05:42.519Z,1550790342.519 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2019-02-21T23:05:42.520Z,1550790342.520 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2019-02-21T23:05:42.520Z,1550790342.520 [LoopControl](DEBUG): Initialize LoopControlComponent.
2019-02-21T23:05:42.522Z,1550790342.522 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2019-02-21T23:05:42.523Z,1550790342.523 [NavChart](DEBUG): Initialize NavChart Navigation.
2019-02-21T23:05:42.524Z,1550790342.524 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2019-02-21T23:05:42.529Z,1550790342.529 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2019-02-21T23:05:42.529Z,1550790342.529 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2019-02-21T23:05:42.530Z,1550790342.530 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2019-02-21T23:05:42.530Z,1550790342.530 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2019-02-21T23:05:42.531Z,1550790342.531 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2019-02-21T23:05:42.531Z,1550790342.531 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2019-02-21T23:05:42.535Z,1550790342.535 [SBIT](INFO): Initialize SBIT Component.
2019-02-21T23:05:42.536Z,1550790342.536 [SBIT](IMPORTANT): git: 2019-01-14A-50-g9cfb34a
2019-02-21T23:05:42.536Z,1550790342.536 [SBIT](INFO): git hash: 9cfb34a5380b67c155f39980646156fa9a5482a4
2019-02-21T23:05:42.536Z,1550790342.536 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2019-02-21T23:05:42.538Z,1550790342.538 [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-21T23:05:42.539Z,1550790342.539 [SBIT](INFO): Beginning SBIT in 23.000000 seconds.
2019-02-21T23:05:42.539Z,1550790342.539 [IBIT](INFO): Initialize IBIT Component.
2019-02-21T23:05:42.540Z,1550790342.540 [CBIT](DEBUG): Initialize CBIT Component.
2019-02-21T23:05:42.541Z,1550790342.541 [logger ThreadHandler](INFO): Handler Thread ID is 900
2019-02-21T23:05:42.551Z,1550790342.551 [CBIT](DEBUG): Initialized mux pins.
2019-02-21T23:05:42.551Z,1550790342.551 [CBIT](FAULT): LAST RESTART WAS UNINTENTIONAL.
2019-02-21T23:05:42.551Z,1550790342.551 [CBIT](DEBUG): Initializing the watchdog timer.
2019-02-21T23:05:42.560Z,1550790342.560 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 901
2019-02-21T23:05:42.566Z,1550790342.566 [Radio_Surface](INFO): Powering up
2019-02-21T23:05:42.572Z,1550790342.572 [Rowe_600LCM ThreadHandler](INFO): Handler Thread ID is 902
2019-02-21T23:05:42.572Z,1550790342.572 [Rowe_600LCM](INFO): Initializing
2019-02-21T23:05:42.579Z,1550790342.579 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2019-02-21T23:05:42.579Z,1550790342.579 [CBIT](DEBUG): Initializing heartbeat.
2019-02-21T23:05:42.660Z,1550790342.660 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 903
2019-02-21T23:05:42.660Z,1550790342.660 [CBIT](DEBUG): Deactivating GF circuits.
2019-02-21T23:05:42.661Z,1550790342.661 [CBIT](DEBUG): Deactivating emergency mode.
2019-02-21T23:05:42.668Z,1550790342.668 [CTD_NeilBrown](INFO): Powering down
2019-02-21T23:05:42.688Z,1550790342.688 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 904
2019-02-21T23:05:42.689Z,1550790342.689 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2019-02-21T23:05:42.692Z,1550790342.692 [CTD_Seabird](INFO): Opening uart, block timeout 10ths=20
2019-02-21T23:05:42.788Z,1550790342.788 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2019-02-21T23:05:42.798Z,1550790342.798 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 906
2019-02-21T23:05:42.804Z,1550790342.804 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 907
2019-02-21T23:05:42.817Z,1550790342.817 [WetLabsBB2FL](INFO): Powering down
2019-02-21T23:05:42.829Z,1550790342.829 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2019-02-21T23:05:42.829Z,1550790342.829 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2019-02-21T23:05:42.830Z,1550790342.830 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2019-02-21T23:05:42.830Z,1550790342.830 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2019-02-21T23:05:42.830Z,1550790342.830 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2019-02-21T23:05:42.830Z,1550790342.830 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2019-02-21T23:05:42.830Z,1550790342.830 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2019-02-21T23:05:42.831Z,1550790342.831 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2019-02-21T23:05:42.831Z,1550790342.831 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2019-02-21T23:05:42.831Z,1550790342.831 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2019-02-21T23:05:42.831Z,1550790342.831 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2019-02-21T23:05:42.832Z,1550790342.832 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2019-02-21T23:05:42.832Z,1550790342.832 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2019-02-21T23:05:42.832Z,1550790342.832 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2019-02-21T23:05:42.832Z,1550790342.832 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2019-02-21T23:05:42.832Z,1550790342.832 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2019-02-21T23:05:42.961Z,1550790342.961 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2019-02-21T23:05:43.064Z,1550790343.064 [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-21T23:05:43.072Z,1550790343.072 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2019-02-21T23:05:43.095Z,1550790343.095 [Rowe_600LCM](INFO): Powering up
2019-02-21T23:05:43.158Z,1550790343.158 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2019-02-21T23:05:43.183Z,1550790343.183 [Default:A.Wait](DEBUG): Construct Wait.
2019-02-21T23:05:43.185Z,1550790343.185 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2019-02-21T23:05:43.213Z,1550790343.213 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2019-02-21T23:05:43.247Z,1550790343.247 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2019-02-21T23:05:43.253Z,1550790343.253 [Default:E.Execute](DEBUG): Construct Execute.
2019-02-21T23:05:43.293Z,1550790343.293 [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-21T23:05:43.298Z,1550790343.298 [controlThread](DEBUG): Component order: CycleStarter,DataOverHttps,Depth_Keller,DropWeight,NAL9602,Onboard,PNI_TCM,Aanderaa_O2,PAR_Licor,Depth_Keller,PAR_Licor,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-21T23:05:43.325Z,1550790343.325 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2019-02-21T23:05:44.116Z,1550790344.116 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2019-02-21T23:05:44.123Z,1550790344.123 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2019-02-21T23:05:44.130Z,1550790344.130 [ElevatorServo](DEBUG): Initializing EZServoServo.
2019-02-21T23:05:44.135Z,1550790344.135 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2019-02-21T23:05:44.157Z,1550790344.157 [MassServo](DEBUG): Initializing EZServoServo.
2019-02-21T23:05:44.166Z,1550790344.166 [MassServo](DEBUG): Initializing MassServo.
2019-02-21T23:05:44.182Z,1550790344.182 [RudderServo](DEBUG): Initializing EZServoServo.
2019-02-21T23:05:44.187Z,1550790344.187 [RudderServo](DEBUG): Initializing RudderServo.
2019-02-21T23:05:44.209Z,1550790344.209 [ThrusterServo](DEBUG): Initializing EZServoServo.
2019-02-21T23:05:44.219Z,1550790344.219 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2019-02-21T23:05:44.418Z,1550790344.418 [DropWeight](CRITICAL): DROP WEIGHT MISSING.

2019-02-21T23:05:44.419Z,1550790344.419 [DropWeight] Hardware Fault, FailCount= 1
2019-02-21T23:05:44.419Z,1550790344.419 [DropWeight](ERROR): Hardware Fault
2019-02-21T23:05:44.554Z,1550790344.554 [CommandLine](FAULT): Scheduling is paused
2019-02-21T23:05:44.554Z,1550790344.554 [CBIT](INFO): Critical error at 20190221T230544
2019-02-21T23:05:44.555Z,1550790344.555 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2019-02-21T23:05:44.557Z,1550790344.557 [CBIT](ERROR): Hardware Fault in component: DropWeight
2019-02-21T23:05:44.558Z,1550790344.558 [CBIT](CRITICAL): Hardware Fault in component: DropWeight
2019-02-21T23:05:45.237Z,1550790345.237 [CBIT](INFO): Critical error at 20190221T230544
2019-02-21T23:05:46.611Z,1550790346.611 [PAR_Licor](INFO): A/D timeout, 7 tries over 140 ms

2019-02-21T23:05:46.611Z,1550790346.611 [PAR_Licor] Data Fault, FailCount= 1
2019-02-21T23:05:46.611Z,1550790346.611 [PAR_Licor](ERROR): Data Fault
2019-02-21T23:05:46.779Z,1550790346.779 [CBIT](ERROR): Data Fault in component: PAR_Licor
2019-02-21T23:05:46.779Z,1550790346.779 [CBIT](INFO): Clearing failed state for component PAR_Licor
2019-02-21T23:05:46.780Z,1550790346.780 [PAR_Licor] No Fault, FailCount= 1
2019-02-21T23:05:47.201Z,1550790347.201 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2019-02-21T23:05:47.334Z,1550790347.334 [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-21T23:05:52.091Z,1550790352.091 [PNI_TCM](FAULT): Failed to acquire valid data within timeout.
2019-02-21T23:05:52.091Z,1550790352.091 [PNI_TCM] Data Fault, FailCount= 1
2019-02-21T23:05:52.091Z,1550790352.091 [PNI_TCM](ERROR): Data Fault
2019-02-21T23:05:52.189Z,1550790352.189 [CBIT](ERROR): Data Fault in component: PNI_TCM
2019-02-21T23:05:52.470Z,1550790352.470 [PNI_TCM](INFO): Powering down
2019-02-21T23:05:52.568Z,1550790352.568 [CBIT](CRITICAL): Environmental Failure. Press:14.527070 PSI. Humidity:19%. Temp:24 C. ABORTING MISSION
2019-02-21T23:05:52.927Z,1550790352.927 [CBIT](INFO): Critical error at 20190221T230552
2019-02-21T23:05:53.411Z,1550790353.411 [PAR_Licor](INFO): A/D timeout, 7 tries over 136 ms

2019-02-21T23:05:53.411Z,1550790353.411 [PAR_Licor] Data Fault, FailCount= 1
2019-02-21T23:05:53.411Z,1550790353.411 [PAR_Licor](ERROR): Data Fault
2019-02-21T23:05:53.466Z,1550790353.466 [CBIT](ERROR): Data Fault in component: PAR_Licor
2019-02-21T23:05:53.467Z,1550790353.467 [CBIT](INFO): Clearing failed state for component PAR_Licor
2019-02-21T23:05:53.467Z,1550790353.467 [PAR_Licor] No Fault, FailCount= 1
2019-02-21T23:05:53.671Z,1550790353.671 [Aanderaa_O2](FAULT): Failed to initialize within timeout.
2019-02-21T23:05:53.671Z,1550790353.671 [Aanderaa_O2] Communications Fault, FailCount= 1
2019-02-21T23:05:53.671Z,1550790353.671 [Aanderaa_O2](ERROR): Communications Fault
2019-02-21T23:05:53.748Z,1550790353.748 [CBIT](INFO): Clearing failed state for component PNI_TCM
2019-02-21T23:05:53.748Z,1550790353.748 [PNI_TCM] No Fault, FailCount= 1
2019-02-21T23:05:53.749Z,1550790353.749 [CBIT](ERROR): Communications Fault in component: Aanderaa_O2
2019-02-21T23:05:54.073Z,1550790354.073 [Aanderaa_O2](INFO): Powering down
2019-02-21T23:05:54.922Z,1550790354.922 [CBIT](INFO): Clearing failed state for component Aanderaa_O2
2019-02-21T23:05:54.922Z,1550790354.922 [Aanderaa_O2] No Fault, FailCount= 1
2019-02-21T23:05:56.731Z,1550790356.731 [CTD_Seabird](FAULT): Failed to initialize within timeout.
2019-02-21T23:05:56.731Z,1550790356.731 [CTD_Seabird] Communications Fault, FailCount= 1
2019-02-21T23:05:56.731Z,1550790356.731 [CTD_Seabird](ERROR): Communications Fault
2019-02-21T23:05:56.921Z,1550790356.921 [CBIT](ERROR): Communications Fault in component: CTD_Seabird
2019-02-21T23:05:57.135Z,1550790357.135 [CTD_Seabird](INFO): Powering down
2019-02-21T23:05:58.199Z,1550790358.199 [PAR_Licor](INFO): A/D timeout, 7 tries over 122 ms

2019-02-21T23:05:58.199Z,1550790358.199 [PAR_Licor] Data Fault, FailCount= 1
2019-02-21T23:05:58.199Z,1550790358.199 [PAR_Licor](ERROR): Data Fault
2019-02-21T23:05:58.233Z,1550790358.233 [CBIT](ERROR): Data Fault in component: PAR_Licor
2019-02-21T23:05:58.233Z,1550790358.233 [CBIT](INFO): Clearing failed state for component PAR_Licor
2019-02-21T23:05:58.233Z,1550790358.233 [PAR_Licor] No Fault, FailCount= 1
2019-02-21T23:05:59.007Z,1550790359.007 [PAR_Licor](INFO): A/D timeout, 8 tries over 131 ms

2019-02-21T23:05:59.007Z,1550790359.007 [PAR_Licor] Data Fault, FailCount= 2
2019-02-21T23:05:59.007Z,1550790359.007 [PAR_Licor](ERROR): Data Fault
2019-02-21T23:05:59.056Z,1550790359.056 [CBIT](INFO): Clearing failed state for component CTD_Seabird
2019-02-21T23:05:59.056Z,1550790359.056 [CTD_Seabird] No Fault, FailCount= 1
2019-02-21T23:05:59.056Z,1550790359.056 [CBIT](ERROR): Data Fault in component: PAR_Licor
2019-02-21T23:05:59.056Z,1550790359.056 [CBIT](INFO): Clearing failed state for component PAR_Licor
2019-02-21T23:05:59.057Z,1550790359.057 [PAR_Licor] No Fault, FailCount= 2
2019-02-21T23:05:59.811Z,1550790359.811 [PAR_Licor](INFO): A/D timeout, 7 tries over 136 ms

2019-02-21T23:05:59.811Z,1550790359.811 [PAR_Licor] Data Fault, FailCount= 3
2019-02-21T23:05:59.811Z,1550790359.811 [PAR_Licor](ERROR): Data Fault
2019-02-21T23:05:59.858Z,1550790359.858 [CBIT](ERROR): Data Fault in component: PAR_Licor
2019-02-21T23:05:59.859Z,1550790359.859 [CBIT](CRITICAL): Data Fault in component: PAR_Licor
2019-02-21T23:05:59.983Z,1550790359.983 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2019-02-21T23:05:59.984Z,1550790359.984 [CTD_Seabird](INFO): Opening uart, block timeout 10ths=20
2019-02-21T23:06:00.089Z,1550790360.089 [CBIT](INFO): Critical error at 20190221T230559
2019-02-21T23:06:01.271Z,1550790361.271 [PNI_TCM](FAULT): Failed to set parameters during initialization.
2019-02-21T23:06:01.271Z,1550790361.271 [PNI_TCM] Data Fault, FailCount= 2
2019-02-21T23:06:01.271Z,1550790361.271 [PNI_TCM](ERROR): Data Fault
2019-02-21T23:06:01.311Z,1550790361.311 [CBIT](ERROR): Data Fault in component: PNI_TCM
2019-02-21T23:06:01.672Z,1550790361.672 [PNI_TCM](INFO): Powering down
2019-02-21T23:06:02.929Z,1550790362.929 [CBIT](INFO): Clearing failed state for component PNI_TCM
2019-02-21T23:06:02.929Z,1550790362.929 [PNI_TCM] No Fault, FailCount= 2
2019-02-21T23:06:05.289Z,1550790365.289 [Aanderaa_O2](FAULT): Failed to initialize within timeout.
2019-02-21T23:06:05.289Z,1550790365.289 [Aanderaa_O2] Communications Fault, FailCount= 2
2019-02-21T23:06:05.289Z,1550790365.289 [Aanderaa_O2](ERROR): Communications Fault
2019-02-21T23:06:05.308Z,1550790365.308 [CBIT](ERROR): Communications Fault in component: Aanderaa_O2
2019-02-21T23:06:05.677Z,1550790365.677 [Aanderaa_O2](INFO): Powering down
2019-02-21T23:06:06.109Z,1550790366.109 [SBIT](IMPORTANT): Beginning Startup BIT
2019-02-21T23:06:06.114Z,1550790366.114 [CBIT](IMPORTANT): Beginning ground fault scan
2019-02-21T23:06:06.590Z,1550790366.590 [CBIT](INFO): Clearing failed state for component Aanderaa_O2
2019-02-21T23:06:06.590Z,1550790366.590 [Aanderaa_O2] No Fault, FailCount= 2
2019-02-21T23:06:10.156Z,1550790370.156 [NAL9602](INFO): Powering up NAL9602
2019-02-21T23:06:10.571Z,1550790370.571 [PNI_TCM](FAULT): Failed to set parameters during initialization.
2019-02-21T23:06:10.571Z,1550790370.571 [PNI_TCM] Data Fault, FailCount= 3
2019-02-21T23:06:10.571Z,1550790370.571 [PNI_TCM](ERROR): Data Fault
2019-02-21T23:06:10.712Z,1550790370.712 [CBIT](ERROR): Data Fault in component: PNI_TCM
2019-02-21T23:06:10.971Z,1550790370.971 [PNI_TCM](INFO): Powering down
2019-02-21T23:06:12.244Z,1550790372.244 [CBIT](INFO): Clearing failed state for component PNI_TCM
2019-02-21T23:06:12.244Z,1550790372.244 [PNI_TCM] No Fault, FailCount= 3
2019-02-21T23:06:14.027Z,1550790374.027 [CTD_Seabird](FAULT): Failed to initialize within timeout.
2019-02-21T23:06:14.027Z,1550790374.027 [CTD_Seabird] Communications Fault, FailCount= 2
2019-02-21T23:06:14.027Z,1550790374.027 [CTD_Seabird](ERROR): Communications Fault
2019-02-21T23:06:14.230Z,1550790374.230 [CBIT](ERROR): Communications Fault in component: CTD_Seabird
2019-02-21T23:06:14.431Z,1550790374.431 [CTD_Seabird](INFO): Powering down
2019-02-21T23:06:16.668Z,1550790376.668 [CBIT](INFO): Clearing failed state for component CTD_Seabird
2019-02-21T23:06:16.668Z,1550790376.668 [CTD_Seabird] No Fault, FailCount= 2
2019-02-21T23:06:16.976Z,1550790376.976 [Aanderaa_O2](FAULT): Failed to initialize within timeout.
2019-02-21T23:06:16.976Z,1550790376.976 [Aanderaa_O2] Communications Fault, FailCount= 3
2019-02-21T23:06:16.976Z,1550790376.976 [Aanderaa_O2](ERROR): Communications Fault
2019-02-21T23:06:17.016Z,1550790377.016 [CBIT](ERROR): Communications Fault in component: Aanderaa_O2
2019-02-21T23:06:17.016Z,1550790377.016 [CBIT](FAULT): Communications Fault in component: Aanderaa_O2
2019-02-21T23:06:17.048Z,1550790377.048 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.001861
CHAN A1 (24V): -0.006276
CHAN A2 (12V): -0.002365
CHAN A3 (5V): -0.001065
CHAN B0 (3.3V): -0.000395
CHAN B1 (3.15aV): -0.000017
CHAN B2 (3.15bV): -0.000090
CHAN B3 (GND): 0.000277
OPEN: -0.000341
Full Scale Calc: 4.765 mA, -1.589 mA
2019-02-21T23:06:17.259Z,1550790377.259 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2019-02-21T23:06:17.260Z,1550790377.260 [CTD_Seabird](INFO): Opening uart, block timeout 10ths=20
2019-02-21T23:06:17.376Z,1550790377.376 [Aanderaa_O2](INFO): Powering down
2019-02-21T23:06:19.784Z,1550790379.784 [PNI_TCM](FAULT): Failed to set parameters during initialization.
2019-02-21T23:06:19.784Z,1550790379.784 [PNI_TCM] Data Fault, FailCount= 4
2019-02-21T23:06:19.784Z,1550790379.784 [PNI_TCM](ERROR): Data Fault
2019-02-21T23:06:19.805Z,1550790379.805 [CBIT](ERROR): Data Fault in component: PNI_TCM
2019-02-21T23:06:20.170Z,1550790380.170 [PNI_TCM](INFO): Powering down
2019-02-21T23:06:21.928Z,1550790381.928 [CBIT](INFO): Clearing failed state for component PNI_TCM
2019-02-21T23:06:21.928Z,1550790381.928 [PNI_TCM] No Fault, FailCount= 4
2019-02-21T23:06:29.155Z,1550790389.155 [PNI_TCM](FAULT): Failed to set parameters during initialization.
2019-02-21T23:06:29.156Z,1550790389.156 [PNI_TCM] Data Fault, FailCount= 5
2019-02-21T23:06:29.156Z,1550790389.156 [PNI_TCM](ERROR): Data Fault
2019-02-21T23:06:29.238Z,1550790389.238 [CBIT](ERROR): Data Fault in component: PNI_TCM
2019-02-21T23:06:29.238Z,1550790389.238 [CBIT](CRITICAL): Data Fault in component: PNI_TCM
2019-02-21T23:06:29.567Z,1550790389.567 [PNI_TCM](INFO): Powering down
2019-02-21T23:06:29.664Z,1550790389.664 [CBIT](INFO): Critical error at 20190221T230629
2019-02-21T23:06:31.144Z,1550790391.144 [NAL9602](ERROR): NAL9602 initialization error.
2019-02-21T23:06:31.144Z,1550790391.144 [NAL9602] Communications Fault, FailCount= 1
2019-02-21T23:06:31.145Z,1550790391.145 [NAL9602](ERROR): Communications Fault
2019-02-21T23:06:31.246Z,1550790391.246 [CBIT](ERROR): Communications Fault in component: NAL9602
2019-02-21T23:06:31.319Z,1550790391.319 [CTD_Seabird](FAULT): Failed to initialize within timeout.
2019-02-21T23:06:31.319Z,1550790391.319 [CTD_Seabird] Communications Fault, FailCount= 3
2019-02-21T23:06:31.319Z,1550790391.319 [CTD_Seabird](ERROR): Communications Fault
2019-02-21T23:06:31.540Z,1550790391.540 [NAL9602](INFO): Powering down
2019-02-21T23:06:31.614Z,1550790391.614 [CBIT](ERROR): Communications Fault in component: CTD_Seabird
2019-02-21T23:06:31.614Z,1550790391.614 [CBIT](FAULT): Communications Fault in component: CTD_Seabird
2019-02-21T23:06:31.723Z,1550790391.723 [CTD_Seabird](INFO): Powering down
2019-02-21T23:06:32.454Z,1550790392.454 [CBIT](INFO): Clearing failed state for component NAL9602
2019-02-21T23:06:32.454Z,1550790392.454 [NAL9602] No Fault, FailCount= 1
2019-02-21T23:07:00.125Z,1550790420.125 [SBIT](IMPORTANT): SBIT PASSED
2019-02-21T23:07:00.179Z,1550790420.179 [CommandLine](IMPORTANT): got command configSet list
2019-02-21T23:07:00.180Z,1550790420.180 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2019-02-21T23:07:00.180Z,1550790420.180 [CommandLine](IMPORTANT): No configSet variables persisted
2019-02-21T23:07:00.474Z,1550790420.474 [MissionManager](IMPORTANT): Started mission Startup
2019-02-21T23:07:00.474Z,1550790420.474 [Startup] Running Loop=1
2019-02-21T23:07:00.474Z,1550790420.474 [Startup](DEBUG): Aggregate::initialize Startup
2019-02-21T23:07:00.474Z,1550790420.474 [Startup:A.GoToSurface] Running Loop=1
2019-02-21T23:07:00.474Z,1550790420.474 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-02-21T23:07:00.475Z,1550790420.475 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-02-21T23:07:00.475Z,1550790420.475 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-02-21T23:07:00.476Z,1550790420.476 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-02-21T23:07:00.476Z,1550790420.476 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-02-21T23:07:00.476Z,1550790420.476 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-02-21T23:07:00.506Z,1550790420.506 [Startup:StartupSatComms] Running Loop=1
2019-02-21T23:07:00.506Z,1550790420.506 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2019-02-21T23:07:00.506Z,1550790420.506 [Startup:StartupSatComms:A] Running Loop=1
2019-02-21T23:07:00.878Z,1550790420.878 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2019-02-21T23:07:01.668Z,1550790421.668 [NAL9602](INFO): Powering up NAL9602
2019-02-21T23:07:22.856Z,1550790442.856 [NAL9602](ERROR): NAL9602 initialization error.
2019-02-21T23:07:22.856Z,1550790442.856 [NAL9602] Communications Fault, FailCount= 2
2019-02-21T23:07:22.857Z,1550790442.857 [NAL9602](ERROR): Communications Fault
2019-02-21T23:07:22.916Z,1550790442.916 [CBIT](ERROR): Communications Fault in component: NAL9602
2019-02-21T23:07:23.248Z,1550790443.248 [NAL9602](INFO): Powering down
2019-02-21T23:07:24.117Z,1550790444.117 [CBIT](INFO): Clearing failed state for component NAL9602
2019-02-21T23:07:24.117Z,1550790444.117 [NAL9602] No Fault, FailCount= 2
2019-02-21T23:07:29.248Z,1550790449.248 [CommandLine](IMPORTANT): got command failComponent
2019-02-21T23:07:29.248Z,1550790449.248 [CommandLine](IMPORTANT): Failed components:
2019-02-21T23:07:29.248Z,1550790449.248 [CommandLine](IMPORTANT): DropWeight: Hardware Fault
2019-02-21T23:07:29.249Z,1550790449.249 [CommandLine](IMPORTANT): PNI_TCM: Data Fault
2019-02-21T23:07:29.249Z,1550790449.249 [CommandLine](IMPORTANT): Aanderaa_O2: Communications Fault
2019-02-21T23:07:29.249Z,1550790449.249 [CommandLine](IMPORTANT): CTD_Seabird: Communications Fault
2019-02-21T23:07:29.249Z,1550790449.249 [CommandLine](IMPORTANT): PAR_Licor: Data Fault
2019-02-21T23:07:42.885Z,1550790462.885 [DeadReckonUsingMultipleVelocitySources](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds.
2019-02-21T23:07:42.885Z,1550790462.885 [DeadReckonUsingMultipleVelocitySources] Software Fault, FailCount= 1
2019-02-21T23:07:42.885Z,1550790462.885 [DeadReckonUsingMultipleVelocitySources](ERROR): Software Fault
2019-02-21T23:07:42.887Z,1550790462.887 [DeadReckonUsingSpeedCalculator](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds.
2019-02-21T23:07:42.887Z,1550790462.887 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 1
2019-02-21T23:07:42.887Z,1550790462.887 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2019-02-21T23:07:42.888Z,1550790462.888 [DeadReckonWithRespectToSeafloor](FAULT): Unable to read the rotation from vehicle frame to navigation frame for more than 120 seconds.
2019-02-21T23:07:42.889Z,1550790462.889 [DeadReckonWithRespectToSeafloor] Software Fault, FailCount= 1
2019-02-21T23:07:42.889Z,1550790462.889 [DeadReckonWithRespectToSeafloor](ERROR): Software Fault
2019-02-21T23:07:42.914Z,1550790462.914 [CBIT](ERROR): Software Fault in component: DeadReckonUsingMultipleVelocitySources
2019-02-21T23:07:42.915Z,1550790462.915 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2019-02-21T23:07:42.947Z,1550790462.947 [CBIT](ERROR): Software Fault in component: DeadReckonWithRespectToSeafloor
2019-02-21T23:07:43.235Z,1550790463.235 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2019-02-21T23:07:43.235Z,1550790463.235 [Rowe_600LCM] Communications Fault, FailCount= 1
2019-02-21T23:07:43.235Z,1550790463.235 [Rowe_600LCM](ERROR): Communications Fault
2019-02-21T23:07:43.303Z,1550790463.303 [CBIT](INFO): Clearing failed state for component DeadReckonUsingMultipleVelocitySources
2019-02-21T23:07:43.303Z,1550790463.303 [DeadReckonUsingMultipleVelocitySources] No Fault, FailCount= 1
2019-02-21T23:07:43.303Z,1550790463.303 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2019-02-21T23:07:43.304Z,1550790463.304 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 1
2019-02-21T23:07:43.304Z,1550790463.304 [CBIT](INFO): Clearing failed state for component DeadReckonWithRespectToSeafloor
2019-02-21T23:07:43.304Z,1550790463.304 [DeadReckonWithRespectToSeafloor] No Fault, FailCount= 1
2019-02-21T23:07:43.305Z,1550790463.305 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2019-02-21T23:07:43.649Z,1550790463.649 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2019-02-21T23:07:43.726Z,1550790463.726 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2019-02-21T23:07:43.910Z,1550790463.910 [Rowe_600LCM](INFO): Powering down
2019-02-21T23:07:45.304Z,1550790465.304 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2019-02-21T23:07:45.304Z,1550790465.304 [Rowe_600LCM] No Fault, FailCount= 1
2019-02-21T23:07:45.523Z,1550790465.523 [Rowe_600LCM](INFO): Initializing
2019-02-21T23:07:45.524Z,1550790465.524 [Rowe_600LCM](INFO): Powering up
2019-02-21T23:07:49.710Z,1550790469.710 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2019-02-21T23:07:49.806Z,1550790469.806 [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-21T23:07:53.649Z,1550790473.649 [NAL9602](INFO): Powering up NAL9602
2019-02-21T23:08:00.878Z,1550790480.878 [Startup:StartupSatComms:A](INFO): Timed out from 2019-02-21T23:07:00.5Z
2019-02-21T23:08:00.878Z,1550790480.878 [Startup:StartupSatComms:A] Stopped
2019-02-21T23:08:00.878Z,1550790480.878 [Startup:StartupSatComms:B] Running Loop=1
2019-02-21T23:08:01.274Z,1550790481.274 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-02-21T23:08:09.644Z,1550790489.644 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004641
2019-02-21T23:08:13.647Z,1550790493.647 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20190221T230119/Courier0004.lzma
2019-02-21T23:08:14.448Z,1550790494.448 [DataOverHttps](INFO): Moved sent file to Logs/20190221T230119/Courier0004.lzma.bak
2019-02-21T23:08:14.448Z,1550790494.448 [DataOverHttps](INFO): SBD MOMSN=10067468
2019-02-21T23:08:14.457Z,1550790494.457 [NAL9602](ERROR): NAL9602 initialization error.
2019-02-21T23:08:14.457Z,1550790494.457 [NAL9602] Communications Fault, FailCount= 3
2019-02-21T23:08:14.457Z,1550790494.457 [NAL9602](ERROR): Communications Fault
2019-02-21T23:08:14.549Z,1550790494.549 [CBIT](ERROR): Communications Fault in component: NAL9602
2019-02-21T23:08:14.935Z,1550790494.935 [NAL9602](INFO): Powering down
2019-02-21T23:08:19.917Z,1550790499.917 [CBIT](INFO): Clearing failed state for component NAL9602
2019-02-21T23:08:19.917Z,1550790499.917 [NAL9602] No Fault, FailCount= 3
2019-02-21T23:08:22.952Z,1550790502.952 [CommandLine](IMPORTANT): got command failComponent none PNI_TCM
2019-02-21T23:08:22.952Z,1550790502.952 [PNI_TCM] No Fault, FailCount= 5
2019-02-21T23:08:22.953Z,1550790502.953 [CommandLine](IMPORTANT): PNI_TCM failureMode is No Fault
2019-02-21T23:08:27.667Z,1550790507.667 [DataOverHttps](INFO): Sending 246 bytes from file Logs/20190221T230532/Courier0000.lzma
2019-02-21T23:08:28.440Z,1550790508.440 [DataOverHttps](INFO): Moved sent file to Logs/20190221T230532/Courier0000.lzma.bak
2019-02-21T23:08:28.440Z,1550790508.440 [DataOverHttps](INFO): SBD MOMSN=10067470
2019-02-21T23:08:43.130Z,1550790523.130 [PNI_TCM](FAULT): Failed to set parameters during initialization.
2019-02-21T23:08:43.131Z,1550790523.131 [PNI_TCM] Data Fault, FailCount= 6
2019-02-21T23:08:43.131Z,1550790523.131 [PNI_TCM](ERROR): Data Fault
2019-02-21T23:08:43.212Z,1550790523.212 [CBIT](ERROR): Data Fault in component: PNI_TCM
2019-02-21T23:08:43.213Z,1550790523.213 [CBIT](CRITICAL): Data Fault in component: PNI_TCM
2019-02-21T23:08:43.230Z,1550790523.230 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20190221T230119/Express0005.lzma
2019-02-21T23:08:43.313Z,1550790523.313 [PNI_TCM](INFO): Powering down
2019-02-21T23:08:43.424Z,1550790523.424 [CBIT](INFO): Critical error at 20190221T230843
2019-02-21T23:08:44.020Z,1550790524.020 [DataOverHttps](INFO): Moved sent file to Logs/20190221T230119/Express0005.lzma.bak
2019-02-21T23:08:44.020Z,1550790524.020 [DataOverHttps](INFO): SBD MOMSN=10067478
2019-02-21T23:08:50.888Z,1550790530.888 [NAL9602](INFO): Powering up NAL9602
2019-02-21T23:08:50.962Z,1550790530.962 [CBIT](INFO): Clearing failed state for component Aanderaa_O2
2019-02-21T23:08:50.963Z,1550790530.963 [Aanderaa_O2] No Fault, FailCount= 3
2019-02-21T23:08:58.753Z,1550790538.753 [DataOverHttps](INFO): Sending 1156 bytes from file Logs/20190221T230532/Express0001.lzma
2019-02-21T23:08:59.520Z,1550790539.520 [DataOverHttps](INFO): Moved sent file to Logs/20190221T230532/Express0001.lzma.bak
2019-02-21T23:08:59.520Z,1550790539.520 [DataOverHttps](INFO): SBD MOMSN=10067480
2019-02-21T23:09:00.278Z,1550790540.278 [Startup:StartupSatComms:B] Stopped
2019-02-21T23:09:00.278Z,1550790540.278 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2019-02-21T23:09:00.278Z,1550790540.278 [Startup:StartupSatComms] Stopped
2019-02-21T23:09:00.278Z,1550790540.278 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2019-02-21T23:09:00.279Z,1550790540.279 [Startup](INFO): Completed Startup
2019-02-21T23:09:00.279Z,1550790540.279 [MissionManager](INFO): Startup is completed.
2019-02-21T23:09:00.279Z,1550790540.279 [MissionManager](INFO): Uninitializing Mission Startup
2019-02-21T23:09:00.279Z,1550790540.279 [Startup] Stopped
2019-02-21T23:09:00.280Z,1550790540.280 [Startup](DEBUG): Aggregate::uninitialize Startup
2019-02-21T23:09:00.280Z,1550790540.280 [Startup:A.GoToSurface] Stopped
2019-02-21T23:09:00.280Z,1550790540.280 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-02-21T23:09:00.435Z,1550790540.435 [MissionManager](IMPORTANT): Started mission Default
2019-02-21T23:09:00.435Z,1550790540.435 [Default] Running Loop=1
2019-02-21T23:09:00.435Z,1550790540.435 [Default](DEBUG): Aggregate::initialize Default
2019-02-21T23:09:00.435Z,1550790540.435 [Default:B.GoToSurface] Running Loop=1
2019-02-21T23:09:00.435Z,1550790540.435 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-02-21T23:09:00.435Z,1550790540.435 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-02-21T23:09:00.436Z,1550790540.436 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-02-21T23:09:00.436Z,1550790540.436 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-02-21T23:09:00.436Z,1550790540.436 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-02-21T23:09:00.437Z,1550790540.437 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-02-21T23:09:00.437Z,1550790540.437 [Default:A.Wait] Running Loop=1
2019-02-21T23:09:00.437Z,1550790540.437 [Default:A.Wait](DEBUG): Initialize Wait Component.
2019-02-21T23:09:06.416Z,1550790546.416 [Aanderaa_O2](FAULT): Failed to initialize within timeout.
2019-02-21T23:09:06.416Z,1550790546.416 [Aanderaa_O2] Communications Fault, FailCount= 1
2019-02-21T23:09:06.416Z,1550790546.416 [Aanderaa_O2](ERROR): Communications Fault
2019-02-21T23:09:06.485Z,1550790546.485 [CBIT](ERROR): Communications Fault in component: Aanderaa_O2
2019-02-21T23:09:06.485Z,1550790546.485 [CBIT](INFO): Clearing failed state for component CTD_Seabird
2019-02-21T23:09:06.485Z,1550790546.485 [CTD_Seabird] No Fault, FailCount= 3
2019-02-21T23:09:06.491Z,1550790546.491 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2019-02-21T23:09:06.503Z,1550790546.503 [CTD_Seabird](INFO): Opening uart, block timeout 10ths=20
2019-02-21T23:09:06.719Z,1550790546.719 [Aanderaa_O2](INFO): Powering down
2019-02-21T23:09:07.393Z,1550790547.393 [CBIT](INFO): Clearing failed state for component Aanderaa_O2
2019-02-21T23:09:07.393Z,1550790547.393 [Aanderaa_O2] No Fault, FailCount= 1
2019-02-21T23:09:13.730Z,1550790553.730 [Default:A.Wait](INFO): Done Waiting.
2019-02-21T23:09:13.731Z,1550790553.731 [Default:A.Wait] Stopped
2019-02-21T23:09:13.731Z,1550790553.731 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2019-02-21T23:09:14.126Z,1550790554.126 [Default:CheckIn] Running Loop=1
2019-02-21T23:09:14.126Z,1550790554.126 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-02-21T23:09:14.126Z,1550790554.126 [Default:CheckIn:Read_GPS] Running Loop=1
2019-02-21T23:09:14.534Z,1550790554.534 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2019-02-21T23:09:16.901Z,1550790556.901 [NAL9602](ERROR): NAL9602 initialization error.
2019-02-21T23:09:16.901Z,1550790556.901 [NAL9602] Communications Fault, FailCount= 4
2019-02-21T23:09:16.901Z,1550790556.901 [NAL9602](ERROR): Communications Fault
2019-02-21T23:09:16.958Z,1550790556.958 [CBIT](ERROR): Communications Fault in component: NAL9602
2019-02-21T23:09:17.312Z,1550790557.312 [NAL9602](INFO): Powering down
2019-02-21T23:09:18.116Z,1550790558.116 [Aanderaa_O2](FAULT): Failed to initialize within timeout.
2019-02-21T23:09:18.116Z,1550790558.116 [Aanderaa_O2] Communications Fault, FailCount= 2
2019-02-21T23:09:18.116Z,1550790558.116 [Aanderaa_O2](ERROR): Communications Fault
2019-02-21T23:09:18.153Z,1550790558.153 [CBIT](INFO): Clearing failed state for component NAL9602
2019-02-21T23:09:18.153Z,1550790558.153 [NAL9602] No Fault, FailCount= 4
2019-02-21T23:09:18.153Z,1550790558.153 [CBIT](ERROR): Communications Fault in component: Aanderaa_O2
2019-02-21T23:09:18.635Z,1550790558.635 [Aanderaa_O2](INFO): Powering down
2019-02-21T23:09:19.351Z,1550790559.351 [CBIT](INFO): Clearing failed state for component Aanderaa_O2
2019-02-21T23:09:19.351Z,1550790559.351 [Aanderaa_O2] No Fault, FailCount= 2
2019-02-21T23:09:20.547Z,1550790560.547 [CTD_Seabird](FAULT): Failed to initialize within timeout.
2019-02-21T23:09:20.547Z,1550790560.547 [CTD_Seabird] Communications Fault, FailCount= 1
2019-02-21T23:09:20.547Z,1550790560.547 [CTD_Seabird](ERROR): Communications Fault
2019-02-21T23:09:20.951Z,1550790560.951 [CTD_Seabird](INFO): Powering down
2019-02-21T23:09:20.964Z,1550790560.964 [CBIT](ERROR): Communications Fault in component: CTD_Seabird
2019-02-21T23:09:22.940Z,1550790562.940 [CBIT](INFO): Clearing failed state for component CTD_Seabird
2019-02-21T23:09:22.940Z,1550790562.940 [CTD_Seabird] No Fault, FailCount= 1
2019-02-21T23:09:23.899Z,1550790563.899 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2019-02-21T23:09:23.908Z,1550790563.908 [CTD_Seabird](INFO): Opening uart, block timeout 10ths=20
2019-02-21T23:09:26.141Z,1550790566.141 [CommandLine](IMPORTANT): got command get platform_pitch_angle
2019-02-21T23:09:26.141Z,1550790566.141 [CommandLine](FAULT): Element has no value
2019-02-21T23:09:30.111Z,1550790570.111 [Aanderaa_O2](FAULT): Failed to initialize within timeout.
2019-02-21T23:09:30.112Z,1550790570.112 [Aanderaa_O2] Communications Fault, FailCount= 3
2019-02-21T23:09:30.112Z,1550790570.112 [Aanderaa_O2](ERROR): Communications Fault
2019-02-21T23:09:30.195Z,1550790570.195 [CBIT](ERROR): Communications Fault in component: Aanderaa_O2
2019-02-21T23:09:30.195Z,1550790570.195 [CBIT](FAULT): Communications Fault in component: Aanderaa_O2
2019-02-21T23:09:30.635Z,1550790570.635 [Aanderaa_O2](INFO): Powering down
2019-02-21T23:09:36.621Z,1550790576.621 [CommandLine](IMPORTANT): got command quit
2019-02-21T23:09:37.630Z,1550790577.630 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2019-02-21T23:09:37.630Z,1550790577.630 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-02-21T23:09:37.635Z,1550790577.635 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2019-02-21T23:09:37.635Z,1550790577.635 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-02-21T23:09:37.636Z,1550790577.636 [CommandLine](INFO): Join timeout helper Thread ID is 945
2019-02-21T23:09:37.643Z,1550790577.643 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2019-02-21T23:09:37.643Z,1550790577.643 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-02-21T23:09:37.644Z,1550790577.644 [NavChartDb](INFO): Join timeout helper Thread ID is 946
2019-02-21T23:09:37.695Z,1550790577.695 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2019-02-21T23:09:37.696Z,1550790577.696 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-02-21T23:09:37.701Z,1550790577.701 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2019-02-21T23:09:37.701Z,1550790577.701 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2019-02-21T23:09:37.704Z,1550790577.704 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 947
2019-02-21T23:09:37.971Z,1550790577.971 [CTD_Seabird](FAULT): Failed to initialize within timeout.
2019-02-21T23:09:37.971Z,1550790577.971 [CTD_Seabird] Communications Fault, FailCount= 2
2019-02-21T23:09:37.971Z,1550790577.971 [CTD_Seabird](ERROR): Communications Fault
2019-02-21T23:09:37.976Z,1550790577.976 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2019-02-21T23:09:37.976Z,1550790577.976 [WetLabsBB2FL](INFO): Powering down
2019-02-21T23:09:37.977Z,1550790577.977 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2019-02-21T23:09:37.979Z,1550790577.979 [ComponentRegistry](INFO): Shutting down CTD_Seabird ThreadHandler
2019-02-21T23:09:37.979Z,1550790577.979 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2019-02-21T23:09:37.980Z,1550790577.980 [CTD_Seabird](INFO): Join timeout helper Thread ID is 948
2019-02-21T23:09:38.141Z,1550790578.141 [CBIT](ERROR): Communications Fault in component: CTD_Seabird
2019-02-21T23:09:38.375Z,1550790578.375 [CTD_Seabird](INFO): Powering down
2019-02-21T23:09:39.511Z,1550790579.511 [CTD_Seabird ThreadHandler](INFO): Uninitializing protected caller thread.
2019-02-21T23:09:39.511Z,1550790579.511 [CTD_Seabird](INFO): Powering down
2019-02-21T23:09:39.523Z,1550790579.523 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2019-02-21T23:09:39.527Z,1550790579.527 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler
2019-02-21T23:09:39.527Z,1550790579.527 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2019-02-21T23:09:39.528Z,1550790579.528 [CTD_NeilBrown](INFO): Join timeout helper Thread ID is 949
2019-02-21T23:09:39.595Z,1550790579.595 [CTD_NeilBrown ThreadHandler](INFO): Uninitializing protected caller thread.
2019-02-21T23:09:39.596Z,1550790579.596 [CTD_NeilBrown](INFO): Powering down
2019-02-21T23:09:39.607Z,1550790579.607 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2019-02-21T23:09:39.624Z,1550790579.624 [ComponentRegistry](INFO): Shutting down Rowe_600LCM ThreadHandler
2019-02-21T23:09:39.624Z,1550790579.624 [Rowe_600LCM ThreadHandler](INFO): Thread cancelled.
2019-02-21T23:09:39.624Z,1550790579.624 [Rowe_600LCM](INFO): Join timeout helper Thread ID is 950
2019-02-21T23:09:40.095Z,1550790580.095 [Rowe_600LCM ThreadHandler](INFO): Uninitializing protected caller thread.
2019-02-21T23:09:40.096Z,1550790580.096 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2019-02-21T23:09:40.329Z,1550790580.329 [Rowe_600LCM](INFO): Powering down
2019-02-21T23:09:40.330Z,1550790580.330 [Rowe_600LCM ThreadHandler](INFO): Thread cancelled.
2019-02-21T23:09:40.332Z,1550790580.332 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2019-02-21T23:09:40.332Z,1550790580.332 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-02-21T23:09:40.333Z,1550790580.333 [Radio_Surface](INFO): Join timeout helper Thread ID is 952
2019-02-21T23:09:40.459Z,1550790580.459 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2019-02-21T23:09:40.460Z,1550790580.460 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-02-21T23:09:40.472Z,1550790580.472 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2019-02-21T23:09:40.472Z,1550790580.472 [logger ThreadHandler](INFO): Thread cancelled.
2019-02-21T23:09:40.472Z,1550790580.472 [logger](INFO): Join timeout helper Thread ID is 953
2019-02-21T23:09:40.475Z,1550790580.475 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2019-02-21T23:09:40.475Z,1550790580.475 [logger ThreadHandler](INFO): Thread cancelled.
2019-02-21T23:09:40.492Z,1550790580.492 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2019-02-21T23:09:40.492Z,1550790580.492 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-02-21T23:09:40.492Z,1550790580.492 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2019-02-21T23:09:40.492Z,1550790580.492 [controlThread ThreadHandler](INFO): Thread cancelled.
2019-02-21T23:09:40.493Z,1550790580.493 [controlThread](INFO): Join timeout helper Thread ID is 954
2019-02-21T23:09:40.493Z,1550790580.493 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2019-02-21T23:09:40.493Z,1550790580.493 [controlThread](DEBUG): Uninitializing ControlThread
2019-02-21T23:09:40.494Z,1550790580.494 [NAL9602](INFO): Powering down
2019-02-21T23:09:40.496Z,1550790580.496 [PNI_TCM](INFO): Powering down
2019-02-21T23:09:40.497Z,1550790580.497 [Aanderaa_O2](INFO): Powering down
2019-02-21T23:09:40.498Z,1550790580.498 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2019-02-21T23:09:40.499Z,1550790580.499 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2019-02-21T23:09:40.500Z,1550790580.500 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2019-02-21T23:09:40.500Z,1550790580.500 [MissionManager](INFO): Uninitializing Mission Default
2019-02-21T23:09:40.501Z,1550790580.501 [Default] Stopped
2019-02-21T23:09:40.501Z,1550790580.501 [Default](DEBUG): Aggregate::uninitialize Default
2019-02-21T23:09:40.501Z,1550790580.501 [Default:B.GoToSurface] Stopped
2019-02-21T23:09:40.501Z,1550790580.501 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-02-21T23:09:40.501Z,1550790580.501 [Default:CheckIn] Stopped
2019-02-21T23:09:40.501Z,1550790580.501 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-02-21T23:09:40.501Z,1550790580.501 [Default:CheckIn:Read_GPS] Stopped
2019-02-21T23:09:40.504Z,1550790580.504 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2019-02-21T23:09:40.504Z,1550790580.504 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2019-02-21T23:09:40.505Z,1550790580.505 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2019-02-21T23:09:40.505Z,1550790580.505 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2019-02-21T23:09:40.505Z,1550790580.505 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2019-02-21T23:09:40.505Z,1550790580.505 [BuoyancyServo](INFO): Powering down
2019-02-21T23:09:40.519Z,1550790580.519 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2019-02-21T23:09:40.519Z,1550790580.519 [ElevatorServo](INFO): Powering down
2019-02-21T23:09:40.520Z,1550790580.520 [MassServo](DEBUG): Uninitialize Mass Servo.
2019-02-21T23:09:40.520Z,1550790580.520 [MassServo](INFO): Powering down
2019-02-21T23:09:40.521Z,1550790580.521 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2019-02-21T23:09:40.521Z,1550790580.521 [RudderServo](INFO): Powering down
2019-02-21T23:09:40.522Z,1550790580.522 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2019-02-21T23:09:40.522Z,1550790580.522 [ThrusterServo](INFO): Powering down
2019-02-21T23:09:40.524Z,1550790580.524 [SBIT](DEBUG): Uninitialize SBIT Component.
2019-02-21T23:09:40.524Z,1550790580.524 [IBIT](DEBUG): Uninitialize IBIT Component.
2019-02-21T23:09:40.524Z,1550790580.524 [CBIT](DEBUG): Uninitialize CBIT Component.
2019-02-21T23:09:40.524Z,1550790580.524 [CBIT](DEBUG): Powering off loads.
2019-02-21T23:09:40.535Z,1550790580.535 [CBIT](DEBUG): Disabling WDT.
2019-02-21T23:09:40.547Z,1550790580.547 [CBIT](DEBUG): Opening all GF detection circuits.
2019-02-21T23:09:40.548Z,1550790580.548 [controlThread ThreadHandler](INFO): Thread cancelled.
2019-02-21T23:09:40.616Z,1550790580.616 [Rowe_600LCM ThreadHandler](INFO): Thread cancelled.
2019-02-21T23:09:40.622Z,1550790580.622 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-02-21T23:09:40.656Z,1550790580.656 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2019-02-21T23:09:40.660Z,1550790580.660 [CTD_Seabird ThreadHandler](INFO): Thread cancelled.
2019-02-21T23:09:40.664Z,1550790580.664 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2019-02-21T23:09:40.701Z,1550790580.701 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-02-21T23:09:40.762Z,1550790580.762 [logger ThreadHandler](INFO): Thread cancelled.