2019-01-02T18:58:19.492Z,1546455499.492 [Supervisor](DEBUG): Initializing supervisor.
2019-01-02T18:58:19.494Z,1546455499.494 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2019-01-02T18:58:19.495Z,1546455499.495 [SyncHandler](INFO): Protected caller Thread ID is 800
2019-01-02T18:58:19.495Z,1546455499.495 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2019-01-02T18:58:19.496Z,1546455499.496 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2019-01-02T18:58:19.497Z,1546455499.497 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 801
2019-01-02T18:58:19.499Z,1546455499.499 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2019-01-02T18:58:19.511Z,1546455499.511 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2019-01-02T18:58:19.512Z,1546455499.512 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2019-01-02T18:58:19.512Z,1546455499.512 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 802
2019-01-02T18:58:19.513Z,1546455499.513 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2019-01-02T18:58:19.514Z,1546455499.514 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2019-01-02T18:58:19.514Z,1546455499.514 [logger ThreadHandler](INFO): Protected caller Thread ID is 803
2019-01-02T18:58:19.516Z,1546455499.516 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2019-01-02T18:58:19.516Z,1546455499.516 [Supervisor](INFO): Looking for Config files in directory: Config/
2019-01-02T18:58:19.521Z,1546455499.521 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2019-01-02T18:58:19.618Z,1546455499.618 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2019-01-02T18:58:19.620Z,1546455499.620 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2019-01-02T18:58:19.720Z,1546455499.720 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2019-01-02T18:58:19.722Z,1546455499.722 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2019-01-02T18:58:19.918Z,1546455499.918 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2019-01-02T18:58:19.919Z,1546455499.919 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2019-01-02T18:58:20.281Z,1546455500.281 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2019-01-02T18:58:20.282Z,1546455500.282 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2019-01-02T18:58:20.653Z,1546455500.653 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2019-01-02T18:58:20.654Z,1546455500.654 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2019-01-02T18:58:21.135Z,1546455501.135 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2019-01-02T18:58:21.137Z,1546455501.137 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2019-01-02T18:58:21.612Z,1546455501.612 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2019-01-02T18:58:21.613Z,1546455501.613 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2019-01-02T18:58:22.064Z,1546455502.064 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2019-01-02T18:58:22.066Z,1546455502.066 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2019-01-02T18:58:22.148Z,1546455502.148 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2019-01-02T18:58:22.458Z,1546455502.458 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2019-01-02T18:58:22.460Z,1546455502.460 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2019-01-02T18:58:22.612Z,1546455502.612 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2019-01-02T18:58:22.614Z,1546455502.614 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2019-01-02T18:58:22.831Z,1546455502.831 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2019-01-02T18:58:22.832Z,1546455502.832 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2019-01-02T18:58:23.168Z,1546455503.168 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2019-01-02T18:58:23.169Z,1546455503.169 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2019-01-02T18:58:23.592Z,1546455503.592 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2019-01-02T18:58:23.593Z,1546455503.593 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2019-01-02T18:58:23.737Z,1546455503.737 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2019-01-02T18:58:23.740Z,1546455503.740 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/
2019-01-02T18:58:23.742Z,1546455503.742 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Battery.cfg
2019-01-02T18:58:23.973Z,1546455503.973 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2019-01-02T18:58:23.975Z,1546455503.975 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/logger.cfg
2019-01-02T18:58:24.080Z,1546455504.080 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Science.cfg
2019-01-02T18:58:24.235Z,1546455504.235 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Control.cfg
2019-01-02T18:58:24.329Z,1546455504.329 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Simulator.cfg
2019-01-02T18:58:24.416Z,1546455504.416 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Sensor.cfg
2019-01-02T18:58:24.581Z,1546455504.581 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/vehicle.cfg
2019-01-02T18:58:24.785Z,1546455504.785 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Servo.cfg
2019-01-02T18:58:24.884Z,1546455504.884 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Navigation.cfg
2019-01-02T18:58:24.980Z,1546455504.980 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/BIT.cfg
2019-01-02T18:58:25.080Z,1546455505.080 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/secure.cfg
2019-01-02T18:58:25.163Z,1546455505.163 [Supervisor](FAULT): Ignoring configuration overrides from Data/persisted.cfg
2019-01-02T18:58:25.167Z,1546455505.167 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2019-01-02T18:58:25.293Z,1546455505.293 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2019-01-02T18:58:25.294Z,1546455505.294 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2019-01-02T18:58:25.318Z,1546455505.318 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2019-01-02T18:58:25.319Z,1546455505.319 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2019-01-02T18:58:25.373Z,1546455505.373 [DepthRateCalculator] Loaded
2019-01-02T18:58:25.374Z,1546455505.374 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2019-01-02T18:58:25.380Z,1546455505.380 [PitchRateCalculator] Loaded
2019-01-02T18:58:25.380Z,1546455505.380 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2019-01-02T18:58:25.395Z,1546455505.395 [SpeedCalculator] Loaded
2019-01-02T18:58:25.396Z,1546455505.396 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2019-01-02T18:58:25.416Z,1546455505.416 [TempGradientCalculator] Loaded
2019-01-02T18:58:25.416Z,1546455505.416 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2019-01-02T18:58:25.422Z,1546455505.422 [YawRateCalculator] Loaded
2019-01-02T18:58:25.422Z,1546455505.422 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2019-01-02T18:58:25.461Z,1546455505.461 [ElevatorOffsetCalculator] Loaded
2019-01-02T18:58:25.461Z,1546455505.461 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2019-01-02T18:58:25.462Z,1546455505.462 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2019-01-02T18:58:25.462Z,1546455505.462 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2019-01-02T18:58:25.503Z,1546455505.503 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2019-01-02T18:58:25.504Z,1546455505.504 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2019-01-02T18:58:37.089Z,1546455517.089 [DataOverHttps] Loaded
2019-01-02T18:58:37.090Z,1546455517.090 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread.
2019-01-02T18:58:37.129Z,1546455517.129 [Depth_Keller] Loaded
2019-01-02T18:58:37.129Z,1546455517.129 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2019-01-02T18:58:37.134Z,1546455517.134 [DropWeight] Loaded
2019-01-02T18:58:37.134Z,1546455517.134 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2019-01-02T18:58:37.142Z,1546455517.142 [GobyModem] Loaded
2019-01-02T18:58:37.143Z,1546455517.143 [ComponentRegistry](DEBUG): SyncComponent "GobyModem" handled in the control thread.
2019-01-02T18:58:37.238Z,1546455517.238 [NAL9602] Loaded
2019-01-02T18:58:37.238Z,1546455517.238 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2019-01-02T18:58:37.253Z,1546455517.253 [Onboard] Loaded
2019-01-02T18:58:37.253Z,1546455517.253 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2019-01-02T18:58:37.263Z,1546455517.263 [Radio_Surface] Loaded
2019-01-02T18:58:37.264Z,1546455517.264 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2019-01-02T18:58:37.265Z,1546455517.265 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 419E04E0
2019-01-02T18:58:37.265Z,1546455517.265 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 885
2019-01-02T18:58:37.418Z,1546455517.418 [PNI_TCM] Loaded
2019-01-02T18:58:37.418Z,1546455517.418 [ComponentRegistry](DEBUG): SyncComponent "PNI_TCM" handled in the control thread.
2019-01-02T18:58:37.477Z,1546455517.477 [Rowe_600LCM] Loaded
2019-01-02T18:58:37.477Z,1546455517.477 [ComponentRegistry](DEBUG): Component "Rowe_600LCM" handled in its own thread.
2019-01-02T18:58:37.478Z,1546455517.478 [Rowe_600LCM ThreadHandler](DEBUG): Created PCaller Thread at 41A104E0
2019-01-02T18:58:37.478Z,1546455517.478 [Rowe_600LCM ThreadHandler](INFO): Protected caller Thread ID is 886
2019-01-02T18:58:39.208Z,1546455519.208 [BPC1] Loaded
2019-01-02T18:58:39.208Z,1546455519.208 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2019-01-02T18:58:39.208Z,1546455519.208 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2019-01-02T18:58:39.209Z,1546455519.209 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2019-01-02T18:58:39.366Z,1546455519.366 [SBIT](DEBUG): Construct Startup Built In Test.
2019-01-02T18:58:39.388Z,1546455519.388 [SBIT] Loaded
2019-01-02T18:58:39.388Z,1546455519.388 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2019-01-02T18:58:39.389Z,1546455519.389 [IBIT](DEBUG): Construct Initiated Built In Test.
2019-01-02T18:58:39.401Z,1546455519.401 [IBIT] Loaded
2019-01-02T18:58:39.401Z,1546455519.401 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2019-01-02T18:58:39.404Z,1546455519.404 [CBIT](DEBUG): Construct Continuous Built In Test.
2019-01-02T18:58:39.541Z,1546455519.541 [CBIT] Loaded
2019-01-02T18:58:39.541Z,1546455519.541 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2019-01-02T18:58:39.542Z,1546455519.542 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2019-01-02T18:58:39.542Z,1546455519.542 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2019-01-02T18:58:39.771Z,1546455519.771 [Aanderaa_O2] Loaded
2019-01-02T18:58:39.771Z,1546455519.771 [ComponentRegistry](DEBUG): SyncComponent "Aanderaa_O2" handled in the control thread.
2019-01-02T18:58:39.854Z,1546455519.854 [CTD_Seabird] Loaded
2019-01-02T18:58:39.854Z,1546455519.854 [ComponentRegistry](DEBUG): Component "CTD_Seabird" handled in its own thread.
2019-01-02T18:58:39.855Z,1546455519.855 [CTD_Seabird ThreadHandler](DEBUG): Created PCaller Thread at 41AF04E0
2019-01-02T18:58:39.855Z,1546455519.855 [CTD_Seabird ThreadHandler](INFO): Protected caller Thread ID is 887
2019-01-02T18:58:39.872Z,1546455519.872 [ESPComponent] Loaded
2019-01-02T18:58:39.873Z,1546455519.873 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread.
2019-01-02T18:58:39.886Z,1546455519.886 [PAR_Licor] Loaded
2019-01-02T18:58:39.887Z,1546455519.887 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2019-01-02T18:58:39.934Z,1546455519.934 [WetLabsBB2FL] Loaded
2019-01-02T18:58:39.935Z,1546455519.935 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2019-01-02T18:58:39.936Z,1546455519.936 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 41B204E0
2019-01-02T18:58:39.936Z,1546455519.936 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 888
2019-01-02T18:58:39.937Z,1546455519.937 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2019-01-02T18:58:39.938Z,1546455519.938 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2019-01-02T18:58:40.213Z,1546455520.213 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2019-01-02T18:58:40.213Z,1546455520.213 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2019-01-02T18:58:40.300Z,1546455520.300 [VerticalControl](DEBUG): Construct VerticalControl.
2019-01-02T18:58:40.393Z,1546455520.393 [VerticalControl] Loaded
2019-01-02T18:58:40.393Z,1546455520.393 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2019-01-02T18:58:40.394Z,1546455520.394 [HorizontalControl](DEBUG): Construct HorizontalControl.
2019-01-02T18:58:40.453Z,1546455520.453 [HorizontalControl] Loaded
2019-01-02T18:58:40.454Z,1546455520.454 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2019-01-02T18:58:40.454Z,1546455520.454 [SpeedControl](DEBUG): Construct SpeedControl.
2019-01-02T18:58:40.460Z,1546455520.460 [SpeedControl] Loaded
2019-01-02T18:58:40.460Z,1546455520.460 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2019-01-02T18:58:40.461Z,1546455520.461 [LoopControl](DEBUG): Construct LoopControl.
2019-01-02T18:58:40.461Z,1546455520.461 [LoopControl] Loaded
2019-01-02T18:58:40.461Z,1546455520.461 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2019-01-02T18:58:40.462Z,1546455520.462 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2019-01-02T18:58:40.463Z,1546455520.463 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2019-01-02T18:58:40.564Z,1546455520.564 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2019-01-02T18:58:40.565Z,1546455520.565 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2019-01-02T18:58:40.681Z,1546455520.681 [BuoyancyServo] Loaded
2019-01-02T18:58:40.682Z,1546455520.682 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2019-01-02T18:58:40.693Z,1546455520.693 [ElevatorServo] Loaded
2019-01-02T18:58:40.694Z,1546455520.694 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2019-01-02T18:58:40.704Z,1546455520.704 [MassServo] Loaded
2019-01-02T18:58:40.705Z,1546455520.705 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2019-01-02T18:58:40.716Z,1546455520.716 [RudderServo] Loaded
2019-01-02T18:58:40.716Z,1546455520.716 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2019-01-02T18:58:40.726Z,1546455520.726 [ThrusterServo] Loaded
2019-01-02T18:58:40.727Z,1546455520.727 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2019-01-02T18:58:40.727Z,1546455520.727 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2019-01-02T18:58:40.728Z,1546455520.728 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2019-01-02T18:58:40.842Z,1546455520.842 [DeadReckonUsingSpeedCalculator] Loaded
2019-01-02T18:58:40.842Z,1546455520.842 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread.
2019-01-02T18:58:40.858Z,1546455520.858 [NavChart] Loaded
2019-01-02T18:58:40.858Z,1546455520.858 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2019-01-02T18:58:40.862Z,1546455520.862 [UniversalFixResidualReporter] Loaded
2019-01-02T18:58:40.862Z,1546455520.862 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2019-01-02T18:58:40.863Z,1546455520.863 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2019-01-02T18:58:40.866Z,1546455520.866 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2019-01-02T18:58:40.867Z,1546455520.867 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2019-01-02T18:58:40.874Z,1546455520.874 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2019-01-02T18:58:40.875Z,1546455520.875 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 41C7A4E0
2019-01-02T18:58:40.875Z,1546455520.875 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 889
2019-01-02T18:58:40.880Z,1546455520.880 [Supervisor](INFO): Main Thread ID is 796
2019-01-02T18:58:40.880Z,1546455520.880 [Supervisor](DEBUG): Running supervisor.
2019-01-02T18:58:40.880Z,1546455520.880 [CommandLine ThreadHandler](INFO): Handler Thread ID is 890
2019-01-02T18:58:40.883Z,1546455520.883 [controlThread ThreadHandler](INFO): Handler Thread ID is 891
2019-01-02T18:58:40.883Z,1546455520.883 [controlThread](DEBUG): Initializing ControlThread
2019-01-02T18:58:40.884Z,1546455520.884 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2019-01-02T18:58:40.885Z,1546455520.885 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2019-01-02T18:58:40.885Z,1546455520.885 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2019-01-02T18:58:40.885Z,1546455520.885 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2019-01-02T18:58:40.886Z,1546455520.886 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2019-01-02T18:58:40.886Z,1546455520.886 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2019-01-02T18:58:40.910Z,1546455520.910 [logger ThreadHandler](INFO): Handler Thread ID is 892
2019-01-02T18:58:40.938Z,1546455520.938 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 893
2019-01-02T18:58:40.944Z,1546455520.944 [Radio_Surface](INFO): Powering up
2019-01-02T18:58:40.958Z,1546455520.958 [Rowe_600LCM ThreadHandler](INFO): Handler Thread ID is 894
2019-01-02T18:58:40.959Z,1546455520.959 [Rowe_600LCM](INFO): Initializing
2019-01-02T18:58:40.960Z,1546455520.960 [Rowe_600LCM](INFO): Checking LCM
2019-01-02T18:58:41.079Z,1546455521.079 [CTD_Seabird ThreadHandler](INFO): Handler Thread ID is 895
2019-01-02T18:58:41.080Z,1546455521.080 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2019-01-02T18:58:41.083Z,1546455521.083 [CTD_Seabird](INFO): Opening uart, block timeout 10ths=20
2019-01-02T18:58:41.246Z,1546455521.246 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 897
2019-01-02T18:58:41.247Z,1546455521.247 [WetLabsBB2FL](INFO): Powering down
2019-01-02T18:58:41.278Z,1546455521.278 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 898
2019-01-02T18:58:41.287Z,1546455521.287 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2019-01-02T18:58:41.287Z,1546455521.287 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2019-01-02T18:58:41.287Z,1546455521.287 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2019-01-02T18:58:41.287Z,1546455521.287 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2019-01-02T18:58:41.288Z,1546455521.288 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2019-01-02T18:58:41.288Z,1546455521.288 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2019-01-02T18:58:41.288Z,1546455521.288 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2019-01-02T18:58:41.288Z,1546455521.288 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2019-01-02T18:58:41.288Z,1546455521.288 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2019-01-02T18:58:41.289Z,1546455521.289 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2019-01-02T18:58:41.289Z,1546455521.289 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2019-01-02T18:58:41.289Z,1546455521.289 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2019-01-02T18:58:41.289Z,1546455521.289 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2019-01-02T18:58:41.289Z,1546455521.289 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2019-01-02T18:58:41.290Z,1546455521.290 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2019-01-02T18:58:41.290Z,1546455521.290 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2019-01-02T18:58:41.590Z,1546455521.590 [Rowe_600LCM](INFO): LCM OK
2019-01-02T18:58:41.607Z,1546455521.607 [Rowe_600LCM](INFO): Powering up
2019-01-02T18:58:45.520Z,1546455525.520 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2019-01-02T18:58:45.609Z,1546455525.609 [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-01-02T18:58:45.788Z,1546455525.788 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2019-01-02T18:58:45.788Z,1546455525.788 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2019-01-02T18:58:45.789Z,1546455525.789 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2019-01-02T18:58:55.194Z,1546455535.194 [CTD_Seabird](FAULT): Failed to initialize within timeout.
2019-01-02T18:58:55.194Z,1546455535.194 [CTD_Seabird] Communications Fault, FailCount= 1
2019-01-02T18:58:55.194Z,1546455535.194 [CTD_Seabird](ERROR): Communications Fault
2019-01-02T18:58:55.598Z,1546455535.598 [CTD_Seabird](INFO): Powering down
2019-01-02T18:59:28.871Z,1546455568.871 [CommandLine](IMPORTANT): got command failComponent
2019-01-02T18:59:28.871Z,1546455568.871 [CommandLine](IMPORTANT): Failed components:
2019-01-02T18:59:28.871Z,1546455568.871 [CommandLine](IMPORTANT): CTD_Seabird: Communications Fault
2019-01-02T19:00:14.731Z,1546455614.731 [GobyModem](CRITICAL): exception at startup: Failed to startup.
2019-01-02T19:00:14.788Z,1546455614.788 [SBIT](INFO): Initialize SBIT Component.
2019-01-02T19:00:14.789Z,1546455614.789 [SBIT](IMPORTANT): git: 2018-12-19
2019-01-02T19:00:14.789Z,1546455614.789 [SBIT](INFO): git hash: f0e90a53519ed2f91f39351bc58b7b0f50855756
2019-01-02T19:00:14.789Z,1546455614.789 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2019-01-02T19:00:14.791Z,1546455614.791 [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-01-02T19:00:14.792Z,1546455614.792 [SBIT](INFO): Beginning SBIT in 24.000000 seconds.
2019-01-02T19:00:14.792Z,1546455614.792 [IBIT](INFO): Initialize IBIT Component.
2019-01-02T19:00:14.793Z,1546455614.793 [CBIT](DEBUG): Initialize CBIT Component.
2019-01-02T19:00:14.806Z,1546455614.806 [CBIT](DEBUG): Initialized mux pins.
2019-01-02T19:00:14.806Z,1546455614.806 [CBIT](FAULT): LAST RESTART WAS UNINTENTIONAL.
2019-01-02T19:00:14.806Z,1546455614.806 [CBIT](DEBUG): Initializing the watchdog timer.
2019-01-02T19:00:14.831Z,1546455614.831 [CBIT](CRITICAL): LAST REBOOT DUE TO WATCHDOG TIMER RESET.
2019-01-02T19:00:14.831Z,1546455614.831 [CBIT](DEBUG): Initializing heartbeat.
2019-01-02T19:00:14.902Z,1546455614.902 [CBIT](DEBUG): Deactivating GF circuits.
2019-01-02T19:00:14.902Z,1546455614.902 [CBIT](DEBUG): Deactivating emergency mode.
2019-01-02T19:00:14.946Z,1546455614.946 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2019-01-02T19:00:14.948Z,1546455614.948 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2019-01-02T19:00:14.949Z,1546455614.949 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2019-01-02T19:00:14.949Z,1546455614.949 [LoopControl](DEBUG): Initialize LoopControlComponent.
2019-01-02T19:00:14.951Z,1546455614.951 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2019-01-02T19:00:14.952Z,1546455614.952 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2019-01-02T19:00:14.952Z,1546455614.952 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2019-01-02T19:00:14.952Z,1546455614.952 [NavChart](DEBUG): Initialize NavChart Navigation.
2019-01-02T19:00:14.953Z,1546455614.953 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2019-01-02T19:00:14.954Z,1546455614.954 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2019-01-02T19:00:15.004Z,1546455615.004 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2019-01-02T19:00:15.014Z,1546455615.014 [MissionManager](DEBUG):
2019-01-02T19:00:15.015Z,1546455615.015 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2019-01-02T19:00:15.085Z,1546455615.085 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2019-01-02T19:00:15.086Z,1546455615.086 [Default:A.Wait](DEBUG): Construct Wait.
2019-01-02T19:00:15.088Z,1546455615.088 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2019-01-02T19:00:15.098Z,1546455615.098 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2019-01-02T19:00:15.101Z,1546455615.101 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2019-01-02T19:00:15.107Z,1546455615.107 [Default:E.Execute](DEBUG): Construct Execute.
2019-01-02T19:00:15.111Z,1546455615.111 [MissionManager](DEBUG):
0
Wait a moment to see if the scheduler starts a new mission before
starting to actually run Default.
13
Burn on
Dropped weight due to communications timeout.
5
Default mission has been running for
Restarting logs and Default mission.
restart logs
2019-01-02T19:00:15.116Z,1546455615.116 [controlThread](DEBUG): Component order: CycleStarter,DataOverHttps,Depth_Keller,DropWeight,GobyModem,NAL9602,Onboard,PNI_TCM,BPC1,Aanderaa_O2,ESPComponent,PAR_Licor,Depth_Keller,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingSpeedCalculator,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2019-01-02T19:00:15.125Z,1546455615.125 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2019-01-02T19:00:15.197Z,1546455615.197 [NAL9602](INFO): Powering up NAL9602
2019-01-02T19:00:15.292Z,1546455615.292 [ESPComponent](INFO): powering down ESP
2019-01-02T19:00:15.684Z,1546455615.684 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2019-01-02T19:00:15.690Z,1546455615.690 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2019-01-02T19:00:15.696Z,1546455615.696 [ElevatorServo](DEBUG): Initializing EZServoServo.
2019-01-02T19:00:15.703Z,1546455615.703 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2019-01-02T19:00:15.709Z,1546455615.709 [MassServo](DEBUG): Initializing EZServoServo.
2019-01-02T19:00:15.714Z,1546455615.714 [MassServo](DEBUG): Initializing MassServo.
2019-01-02T19:00:15.720Z,1546455615.720 [RudderServo](DEBUG): Initializing EZServoServo.
2019-01-02T19:00:15.726Z,1546455615.726 [RudderServo](DEBUG): Initializing RudderServo.
2019-01-02T19:00:15.732Z,1546455615.732 [ThrusterServo](DEBUG): Initializing EZServoServo.
2019-01-02T19:00:15.738Z,1546455615.738 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2019-01-02T19:00:15.763Z,1546455615.763 [CommandLine](FAULT): Scheduling is paused
2019-01-02T19:00:15.764Z,1546455615.764 [CBIT](INFO): Critical error at 20190102T190014
2019-01-02T19:00:15.764Z,1546455615.764 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2019-01-02T19:00:15.768Z,1546455615.768 [CBIT](ERROR): Communications Fault in component: CTD_Seabird
2019-01-02T19:00:15.768Z,1546455615.768 [CBIT](INFO): Clearing failed state for component CTD_Seabird
2019-01-02T19:00:15.768Z,1546455615.768 [CTD_Seabird] No Fault, FailCount= 1
2019-01-02T19:00:15.927Z,1546455615.927 [DropWeight](CRITICAL): DROP WEIGHT MISSING.
2019-01-02T19:00:15.927Z,1546455615.927 [DropWeight] Hardware Fault, FailCount= 1
2019-01-02T19:00:15.927Z,1546455615.927 [DropWeight](ERROR): Hardware Fault
2019-01-02T19:00:16.014Z,1546455616.014 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2019-01-02T19:00:16.016Z,1546455616.016 [CTD_Seabird](INFO): Opening uart, block timeout 10ths=20
2019-01-02T19:00:16.017Z,1546455616.017 [CBIT](INFO): Critical error at 20190102T190015
2019-01-02T19:00:16.020Z,1546455616.020 [CBIT](ERROR): Hardware Fault in component: DropWeight
2019-01-02T19:00:16.020Z,1546455616.020 [CBIT](CRITICAL): Hardware Fault in component: DropWeight
2019-01-02T19:00:16.566Z,1546455616.566 [BuoyancyServo](ERROR): Buoyancy initialization uart error serial timeout
2019-01-02T19:00:16.566Z,1546455616.566 [BuoyancyServo](FAULT): Buoyancy failed to initialize
2019-01-02T19:00:16.566Z,1546455616.566 [BuoyancyServo] Communications Fault, FailCount= 1
2019-01-02T19:00:16.566Z,1546455616.566 [BuoyancyServo](ERROR): Communications Fault
2019-01-02T19:00:16.768Z,1546455616.768 [CBIT](INFO): Critical error at 20190102T190016
2019-01-02T19:00:16.771Z,1546455616.771 [CBIT](ERROR): Communications Fault in component: BuoyancyServo
2019-01-02T19:00:18.919Z,1546455618.919 [CBIT](INFO): Clearing failed state for component BuoyancyServo
2019-01-02T19:00:18.919Z,1546455618.919 [BuoyancyServo] No Fault, FailCount= 1
2019-01-02T19:00:19.240Z,1546455619.240 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2019-01-02T19:00:19.359Z,1546455619.359 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2019-01-02T19:00:25.112Z,1546455625.112 [CBIT](CRITICAL): Environmental Failure. Press:14.808410 PSI. Humidity:19%. Temp:24 C. ABORTING MISSION
2019-01-02T19:00:25.303Z,1546455625.303 [Aanderaa_O2](FAULT): Failed to initialize within timeout.
2019-01-02T19:00:25.304Z,1546455625.304 [Aanderaa_O2] Communications Fault, FailCount= 1
2019-01-02T19:00:25.304Z,1546455625.304 [Aanderaa_O2](ERROR): Communications Fault
2019-01-02T19:00:25.332Z,1546455625.332 [CBIT](INFO): Critical error at 20190102T190025
2019-01-02T19:00:25.339Z,1546455625.339 [CBIT](ERROR): Communications Fault in component: Aanderaa_O2
2019-01-02T19:00:25.677Z,1546455625.677 [GobyModem](INFO): Added slot 1
2019-01-02T19:00:25.677Z,1546455625.677 [GobyModem](INFO): Added slot 2
2019-01-02T19:00:27.238Z,1546455627.238 [Aanderaa_O2](INFO): Powering down
2019-01-02T19:00:27.371Z,1546455627.371 [NAL9602](INFO): NAL9602 initialized
2019-01-02T19:00:27.811Z,1546455627.811 [CBIT](INFO): Clearing failed state for component Aanderaa_O2
2019-01-02T19:00:27.811Z,1546455627.811 [Aanderaa_O2] No Fault, FailCount= 1
2019-01-02T19:00:30.062Z,1546455630.062 [CTD_Seabird](FAULT): Failed to initialize within timeout.
2019-01-02T19:00:30.062Z,1546455630.062 [CTD_Seabird] Communications Fault, FailCount= 2
2019-01-02T19:00:30.062Z,1546455630.062 [CTD_Seabird](ERROR): Communications Fault
2019-01-02T19:00:30.203Z,1546455630.203 [CBIT](ERROR): Communications Fault in component: CTD_Seabird
2019-01-02T19:00:30.470Z,1546455630.470 [CTD_Seabird](INFO): Powering down
2019-01-02T19:00:32.604Z,1546455632.604 [CBIT](INFO): Clearing failed state for component CTD_Seabird
2019-01-02T19:00:32.604Z,1546455632.604 [CTD_Seabird] No Fault, FailCount= 2
2019-01-02T19:00:33.418Z,1546455633.418 [CTD_Seabird](DEBUG): Initializing CTD_Seabird.
2019-01-02T19:00:33.420Z,1546455633.420 [CTD_Seabird](INFO): Opening uart, block timeout 10ths=20
2019-01-02T19:00:38.557Z,1546455638.557 [Aanderaa_O2](FAULT): Failed to initialize within timeout.
2019-01-02T19:00:38.557Z,1546455638.557 [Aanderaa_O2] Communications Fault, FailCount= 2
2019-01-02T19:00:38.557Z,1546455638.557 [Aanderaa_O2](ERROR): Communications Fault
2019-01-02T19:00:38.648Z,1546455638.648 [CBIT](ERROR): Communications Fault in component: Aanderaa_O2
2019-01-02T19:00:39.078Z,1546455639.078 [Aanderaa_O2](INFO): Powering down
2019-01-02T19:00:39.404Z,1546455639.404 [SBIT](IMPORTANT): Beginning Startup BIT
2019-01-02T19:00:39.416Z,1546455639.416 [CBIT](IMPORTANT): Beginning ground fault scan
2019-01-02T19:00:39.888Z,1546455639.888 [CBIT](INFO): Clearing failed state for component Aanderaa_O2
2019-01-02T19:00:39.888Z,1546455639.888 [Aanderaa_O2] No Fault, FailCount= 2
2019-01-02T19:00:42.030Z,1546455642.030 [Rowe_600LCM](FAULT): Did not receive valid device response within the specified allowable sample time.
2019-01-02T19:00:42.030Z,1546455642.030 [Rowe_600LCM] Communications Fault, FailCount= 1
2019-01-02T19:00:42.030Z,1546455642.030 [Rowe_600LCM](ERROR): Communications Fault
2019-01-02T19:00:42.415Z,1546455642.415 [CBIT](ERROR): Communications Fault in component: Rowe_600LCM
2019-01-02T19:00:42.434Z,1546455642.434 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2019-01-02T19:00:42.626Z,1546455642.626 [Rowe_600LCM](INFO): Powering down
2019-01-02T19:00:44.023Z,1546455644.023 [CBIT](INFO): Clearing failed state for component Rowe_600LCM
2019-01-02T19:00:44.023Z,1546455644.023 [Rowe_600LCM] No Fault, FailCount= 1
2019-01-02T19:00:44.242Z,1546455644.242 [Rowe_600LCM](INFO): Initializing
2019-01-02T19:00:44.243Z,1546455644.243 [Rowe_600LCM](INFO): Checking LCM
2019-01-02T19:00:44.243Z,1546455644.243 [Rowe_600LCM](INFO): LCM OK
2019-01-02T19:00:44.243Z,1546455644.243 [Rowe_600LCM](INFO): Powering up
2019-01-02T19:00:47.474Z,1546455647.474 [CTD_Seabird](FAULT): Failed to initialize within timeout.
2019-01-02T19:00:47.475Z,1546455647.475 [CTD_Seabird] Communications Fault, FailCount= 3
2019-01-02T19:00:47.475Z,1546455647.475 [CTD_Seabird](ERROR): Communications Fault
2019-01-02T19:00:47.572Z,1546455647.572 [CBIT](ERROR): Communications Fault in component: CTD_Seabird
2019-01-02T19:00:47.572Z,1546455647.572 [CBIT](FAULT): Communications Fault in component: CTD_Seabird
2019-01-02T19:00:47.879Z,1546455647.879 [CTD_Seabird](INFO): Powering down
2019-01-02T19:00:47.884Z,1546455647.884 [CommandLine](IMPORTANT): got command restart application
2019-01-02T19:00:48.452Z,1546455648.452 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2019-01-02T19:00:48.513Z,1546455648.513 [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-01-02T19:00:48.514Z,1546455648.514 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.bottom_track
2019-01-02T19:00:48.515Z,1546455648.515 [Rowe_600LCM](INFO): LCM subscribed to channel:Rowe_600LCM.adcp_dvl.vehicle_water_velocity
2019-01-02T19:00:48.515Z,1546455648.515 [Rowe_600LCM](INFO): LCM subscribed to channel:rowe_dvl.rowe
2019-01-02T19:00:48.890Z,1546455648.890 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2019-01-02T19:00:48.890Z,1546455648.890 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-01-02T19:00:49.082Z,1546455649.082 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup. Bye!
2019-01-02T19:00:49.082Z,1546455649.082 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-01-02T19:00:49.083Z,1546455649.083 [CommandLine](INFO): Join timeout helper Thread ID is 934
2019-01-02T19:00:49.083Z,1546455649.083 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2019-01-02T19:00:49.083Z,1546455649.083 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-01-02T19:00:49.084Z,1546455649.0