2018-12-18T19:59:23.953Z,1545163163.953 [Supervisor](DEBUG): Initializing supervisor.
2018-12-18T19:59:23.956Z,1545163163.956 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2018-12-18T19:59:23.957Z,1545163163.957 [SyncHandler](INFO): Protected caller Thread ID is 594
2018-12-18T19:59:23.957Z,1545163163.957 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2018-12-18T19:59:23.958Z,1545163163.958 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2018-12-18T19:59:23.958Z,1545163163.958 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 595
2018-12-18T19:59:23.961Z,1545163163.961 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2018-12-18T19:59:23.972Z,1545163163.972 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2018-12-18T19:59:23.973Z,1545163163.973 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2018-12-18T19:59:23.974Z,1545163163.974 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 596
2018-12-18T19:59:23.975Z,1545163163.975 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2018-12-18T19:59:23.975Z,1545163163.975 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2018-12-18T19:59:23.976Z,1545163163.976 [logger ThreadHandler](INFO): Protected caller Thread ID is 597
2018-12-18T19:59:23.978Z,1545163163.978 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2018-12-18T19:59:23.978Z,1545163163.978 [Supervisor](INFO): Looking for Config files in directory: Config/
2018-12-18T19:59:23.982Z,1545163163.982 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2018-12-18T19:59:24.080Z,1545163164.080 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2018-12-18T19:59:24.082Z,1545163164.082 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2018-12-18T19:59:24.181Z,1545163164.181 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2018-12-18T19:59:24.183Z,1545163164.183 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2018-12-18T19:59:24.378Z,1545163164.378 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2018-12-18T19:59:24.380Z,1545163164.380 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2018-12-18T19:59:24.739Z,1545163164.739 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2018-12-18T19:59:24.740Z,1545163164.740 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2018-12-18T19:59:25.066Z,1545163165.066 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2018-12-18T19:59:25.066Z,1545163165.066 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2018-12-18T19:59:25.512Z,1545163165.512 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2018-12-18T19:59:25.514Z,1545163165.514 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2018-12-18T19:59:25.996Z,1545163165.996 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2018-12-18T19:59:25.997Z,1545163165.997 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2018-12-18T19:59:26.446Z,1545163166.446 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2018-12-18T19:59:26.448Z,1545163166.448 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2018-12-18T19:59:26.530Z,1545163166.530 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2018-12-18T19:59:26.927Z,1545163166.927 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2018-12-18T19:59:26.929Z,1545163166.929 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2018-12-18T19:59:27.075Z,1545163167.075 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2018-12-18T19:59:27.076Z,1545163167.076 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2018-12-18T19:59:27.292Z,1545163167.292 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2018-12-18T19:59:27.293Z,1545163167.293 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2018-12-18T19:59:27.501Z,1545163167.501 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2018-12-18T19:59:27.502Z,1545163167.502 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2018-12-18T19:59:28.022Z,1545163168.022 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2018-12-18T19:59:28.023Z,1545163168.023 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2018-12-18T19:59:28.167Z,1545163168.167 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2018-12-18T19:59:28.169Z,1545163168.169 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-INSERTREALNAME/
2018-12-18T19:59:28.170Z,1545163168.170 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-INSERTREALNAME/root/
2018-12-18T19:59:28.170Z,1545163168.170 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2018-12-18T19:59:28.180Z,1545163168.180 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2018-12-18T19:59:28.370Z,1545163168.370 [InternalSim] Loaded
2018-12-18T19:59:28.371Z,1545163168.371 [ComponentRegistry](DEBUG): SyncComponent "InternalSim" handled in the control thread.
2018-12-18T19:59:28.371Z,1545163168.371 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2018-12-18T19:59:28.372Z,1545163168.372 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2018-12-18T19:59:28.395Z,1545163168.395 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2018-12-18T19:59:28.396Z,1545163168.396 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2018-12-18T19:59:28.450Z,1545163168.450 [DepthRateCalculator] Loaded
2018-12-18T19:59:28.450Z,1545163168.450 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2018-12-18T19:59:28.456Z,1545163168.456 [PitchRateCalculator] Loaded
2018-12-18T19:59:28.456Z,1545163168.456 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2018-12-18T19:59:28.471Z,1545163168.471 [SpeedCalculator] Loaded
2018-12-18T19:59:28.471Z,1545163168.471 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2018-12-18T19:59:28.491Z,1545163168.491 [TempGradientCalculator] Loaded
2018-12-18T19:59:28.491Z,1545163168.491 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2018-12-18T19:59:28.497Z,1545163168.497 [YawRateCalculator] Loaded
2018-12-18T19:59:28.497Z,1545163168.497 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2018-12-18T19:59:28.534Z,1545163168.534 [ElevatorOffsetCalculator] Loaded
2018-12-18T19:59:28.535Z,1545163168.535 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2018-12-18T19:59:28.535Z,1545163168.535 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2018-12-18T19:59:28.536Z,1545163168.536 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2018-12-18T19:59:28.576Z,1545163168.576 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2018-12-18T19:59:28.577Z,1545163168.577 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2018-12-18T19:59:28.750Z,1545163168.750 [Module Loader](ERROR): Cannot load library: libboost_system.so.1.63.0: cannot open shared object file: No such file or directory
2018-12-18T19:59:28.750Z,1545163168.750 [Module Loader](ERROR): Could not load the module at Modules/Sensor.so
2018-12-18T19:59:28.752Z,1545163168.752 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2018-12-18T19:59:28.908Z,1545163168.908 [SBIT](DEBUG): Construct Startup Built In Test.
2018-12-18T19:59:28.932Z,1545163168.932 [SBIT] Loaded
2018-12-18T19:59:28.933Z,1545163168.933 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2018-12-18T19:59:28.933Z,1545163168.933 [IBIT](DEBUG): Construct Initiated Built In Test.
2018-12-18T19:59:28.959Z,1545163168.959 [IBIT] Loaded
2018-12-18T19:59:28.959Z,1545163168.959 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2018-12-18T19:59:28.962Z,1545163168.962 [CBIT](DEBUG): Construct Continuous Built In Test.
2018-12-18T19:59:29.326Z,1545163169.326 [CBIT] Loaded
2018-12-18T19:59:29.326Z,1545163169.326 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2018-12-18T19:59:29.327Z,1545163169.327 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2018-12-18T19:59:29.327Z,1545163169.327 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2018-12-18T19:59:29.638Z,1545163169.638 [CTD_NeilBrown] Loaded
2018-12-18T19:59:29.638Z,1545163169.638 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2018-12-18T19:59:29.639Z,1545163169.639 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 4064D4E0
2018-12-18T19:59:29.639Z,1545163169.639 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 644
2018-12-18T19:59:29.653Z,1545163169.653 [PAR_Licor] Loaded
2018-12-18T19:59:29.653Z,1545163169.653 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2018-12-18T19:59:29.700Z,1545163169.700 [WetLabsBB2FL] Loaded
2018-12-18T19:59:29.700Z,1545163169.700 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2018-12-18T19:59:29.701Z,1545163169.701 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 4067D4E0
2018-12-18T19:59:29.702Z,1545163169.702 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 645
2018-12-18T19:59:29.702Z,1545163169.702 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2018-12-18T19:59:29.703Z,1545163169.703 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2018-12-18T19:59:29.978Z,1545163169.978 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2018-12-18T19:59:29.978Z,1545163169.978 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2018-12-18T19:59:30.065Z,1545163170.065 [VerticalControl](DEBUG): Construct VerticalControl.
2018-12-18T19:59:30.151Z,1545163170.151 [VerticalControl] Loaded
2018-12-18T19:59:30.151Z,1545163170.151 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2018-12-18T19:59:30.152Z,1545163170.152 [HorizontalControl](DEBUG): Construct HorizontalControl.
2018-12-18T19:59:30.206Z,1545163170.206 [HorizontalControl] Loaded
2018-12-18T19:59:30.207Z,1545163170.207 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2018-12-18T19:59:30.207Z,1545163170.207 [SpeedControl](DEBUG): Construct SpeedControl.
2018-12-18T19:59:30.209Z,1545163170.209 [SpeedControl] Loaded
2018-12-18T19:59:30.209Z,1545163170.209 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2018-12-18T19:59:30.210Z,1545163170.210 [BackSeatDriver](DEBUG): Construct BackSeatDriver.
2018-12-18T19:59:30.212Z,1545163170.212 [BackSeatDriver] Loaded
2018-12-18T19:59:30.212Z,1545163170.212 [ComponentRegistry](DEBUG): SyncComponent "BackSeatDriver" handled in the control thread.
2018-12-18T19:59:30.213Z,1545163170.213 [LoopControl](DEBUG): Construct LoopControl.
2018-12-18T19:59:30.213Z,1545163170.213 [LoopControl] Loaded
2018-12-18T19:59:30.213Z,1545163170.213 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2018-12-18T19:59:30.214Z,1545163170.214 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2018-12-18T19:59:30.214Z,1545163170.214 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2018-12-18T19:59:30.315Z,1545163170.315 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2018-12-18T19:59:30.316Z,1545163170.316 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2018-12-18T19:59:30.431Z,1545163170.431 [BuoyancyServo] Loaded
2018-12-18T19:59:30.431Z,1545163170.431 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2018-12-18T19:59:30.442Z,1545163170.442 [ElevatorServo] Loaded
2018-12-18T19:59:30.442Z,1545163170.442 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2018-12-18T19:59:30.452Z,1545163170.452 [MassServo] Loaded
2018-12-18T19:59:30.453Z,1545163170.453 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2018-12-18T19:59:30.463Z,1545163170.463 [RudderServo] Loaded
2018-12-18T19:59:30.464Z,1545163170.464 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2018-12-18T19:59:30.474Z,1545163170.474 [ThrusterServo] Loaded
2018-12-18T19:59:30.474Z,1545163170.474 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2018-12-18T19:59:30.475Z,1545163170.475 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2018-12-18T19:59:30.476Z,1545163170.476 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2018-12-18T19:59:30.592Z,1545163170.592 [DeadReckonUsingMultipleVelocitySources] Loaded
2018-12-18T19:59:30.592Z,1545163170.592 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2018-12-18T19:59:30.649Z,1545163170.649 [DeadReckonUsingSpeedCalculator] Loaded
2018-12-18T19:59:30.650Z,1545163170.650 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread.
2018-12-18T19:59:30.666Z,1545163170.666 [NavChart] Loaded
2018-12-18T19:59:30.666Z,1545163170.666 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2018-12-18T19:59:30.670Z,1545163170.670 [UniversalFixResidualReporter] Loaded
2018-12-18T19:59:30.670Z,1545163170.670 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2018-12-18T19:59:30.670Z,1545163170.670 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2018-12-18T19:59:30.674Z,1545163170.674 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2018-12-18T19:59:30.675Z,1545163170.675 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2018-12-18T19:59:30.681Z,1545163170.681 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2018-12-18T19:59:30.682Z,1545163170.682 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 407D74E0
2018-12-18T19:59:30.683Z,1545163170.683 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 646
2018-12-18T19:59:30.687Z,1545163170.687 [Supervisor](INFO): Main Thread ID is 590
2018-12-18T19:59:30.687Z,1545163170.687 [Supervisor](DEBUG): Running supervisor.
2018-12-18T19:59:30.688Z,1545163170.688 [CommandLine ThreadHandler](INFO): Handler Thread ID is 647
2018-12-18T19:59:30.695Z,1545163170.695 [controlThread ThreadHandler](INFO): Handler Thread ID is 648
2018-12-18T19:59:30.695Z,1545163170.695 [controlThread](DEBUG): Initializing ControlThread
2018-12-18T19:59:30.696Z,1545163170.696 [InternalSim](DEBUG):  InternalSim initializing...
2018-12-18T19:59:30.702Z,1545163170.702 [InternalSim](DEBUG): oceanModelVarCount=0
2018-12-18T19:59:30.760Z,1545163170.760 [logger ThreadHandler](INFO): Handler Thread ID is 649
2018-12-18T19:59:30.815Z,1545163170.815 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 650
2018-12-18T19:59:30.818Z,1545163170.818 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2018-12-18T19:59:30.819Z,1545163170.819 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2018-12-18T19:59:30.819Z,1545163170.819 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2018-12-18T19:59:30.819Z,1545163170.819 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2018-12-18T19:59:30.820Z,1545163170.820 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2018-12-18T19:59:30.820Z,1545163170.820 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2018-12-18T19:59:30.821Z,1545163170.821 [SBIT](INFO): Initialize SBIT Component.
2018-12-18T19:59:30.821Z,1545163170.821 [SBIT](IMPORTANT): git: 2018-12-13
2018-12-18T19:59:30.821Z,1545163170.821 [SBIT](INFO): git hash: 8200dc43e6ef01082c531ff0fab84136a371dc2d
2018-12-18T19:59:30.823Z,1545163170.823 [SBIT](INFO): Kernel Reporting Different Release From Configuration.
Kernel Expected: 2.6.32-45-generic-pae
Kernel Reported: 2.6.27.8
2018-12-18T19:59:30.823Z,1545163170.823 [SBIT](INFO): Kernel Reporting Different Version From Configuration.
Kernel Expected: #102-Ubuntu SMP Wed Jan 2 22:10:16 UTC 2013
Kernel Reported: #8 PREEMPT Mon Dec 17 22:13:11 PST 2018
2018-12-18T19:59:30.824Z,1545163170.824 [SBIT](INFO): Beginning SBIT in 20.000000 seconds.
2018-12-18T19:59:30.825Z,1545163170.825 [IBIT](INFO): Initialize IBIT Component.
2018-12-18T19:59:30.833Z,1545163170.833 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 651
2018-12-18T19:59:30.835Z,1545163170.835 [CBIT](DEBUG): Initialize CBIT Component.
2018-12-18T19:59:30.845Z,1545163170.845 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 652
2018-12-18T19:59:30.849Z,1545163170.849 [CBIT](DEBUG): Initialized mux pins.
2018-12-18T19:59:30.849Z,1545163170.849 [CBIT](DEBUG): Initializing the watchdog timer.
2018-12-18T19:59:30.854Z,1545163170.854 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2018-12-18T19:59:30.854Z,1545163170.854 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2018-12-18T19:59:30.855Z,1545163170.855 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2018-12-18T19:59:30.855Z,1545163170.855 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2018-12-18T19:59:30.855Z,1545163170.855 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2018-12-18T19:59:30.855Z,1545163170.855 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2018-12-18T19:59:30.855Z,1545163170.855 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2018-12-18T19:59:30.856Z,1545163170.856 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2018-12-18T19:59:30.856Z,1545163170.856 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2018-12-18T19:59:30.856Z,1545163170.856 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2018-12-18T19:59:30.856Z,1545163170.856 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2018-12-18T19:59:30.856Z,1545163170.856 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2018-12-18T19:59:30.856Z,1545163170.856 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2018-12-18T19:59:30.857Z,1545163170.857 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2018-12-18T19:59:30.857Z,1545163170.857 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2018-12-18T19:59:30.857Z,1545163170.857 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2018-12-18T19:59:30.873Z,1545163170.873 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2018-12-18T19:59:30.881Z,1545163170.881 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2018-12-18T19:59:30.882Z,1545163170.882 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2018-12-18T19:59:30.883Z,1545163170.883 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2018-12-18T19:59:30.883Z,1545163170.883 [BackSeatDriver](DEBUG): Initialize BackSeatDriver Component.
2018-12-18T19:59:31.021Z,1545163171.021 [CTD_NeilBrown](DEBUG): Initializing CTD_NeilBrown.
2018-12-18T19:59:31.627Z,1545163171.627 [LoopControl](DEBUG): Initialize LoopControlComponent.
2018-12-18T19:59:31.629Z,1545163171.629 [DeadReckonUsingMultipleVelocitySources](DEBUG): Initializing DeadReckonUsingMultipleVelocitySources component.
2018-12-18T19:59:31.629Z,1545163171.629 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider orientation measurement stale after 120s.
2018-12-18T19:59:31.630Z,1545163171.630 [DeadReckonUsingMultipleVelocitySources](INFO): Will consider velocity measurement stale after 20s.
2018-12-18T19:59:31.630Z,1545163171.630 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2018-12-18T19:59:31.631Z,1545163171.631 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2018-12-18T19:59:31.631Z,1545163171.631 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2018-12-18T19:59:31.631Z,1545163171.631 [NavChart](DEBUG): Initialize NavChart Navigation.
2018-12-18T19:59:31.632Z,1545163171.632 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2018-12-18T19:59:31.634Z,1545163171.634 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2018-12-18T19:59:31.658Z,1545163171.658 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2018-12-18T19:59:31.685Z,1545163171.685 [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>


2018-12-18T19:59:31.685Z,1545163171.685 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2018-12-18T19:59:31.773Z,1545163171.773 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2018-12-18T19:59:31.774Z,1545163171.774 [Default:A.Wait](DEBUG): Construct Wait.
2018-12-18T19:59:31.776Z,1545163171.776 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2018-12-18T19:59:31.798Z,1545163171.798 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2018-12-18T19:59:31.825Z,1545163171.825 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2018-12-18T19:59:31.830Z,1545163171.830 [Default:E.Execute](DEBUG): Construct Execute.
2018-12-18T19:59:31.846Z,1545163171.846 [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>


2018-12-18T19:59:31.850Z,1545163171.850 [controlThread](DEBUG): Component order: CycleStarter,InternalSim,PAR_Licor,PAR_Licor,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,DeadReckonUsingSpeedCalculator,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,BackSeatDriver,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2018-12-18T19:59:32.157Z,1545163172.157 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2018-12-18T19:59:32.169Z,1545163172.169 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2018-12-18T19:59:32.181Z,1545163172.181 [MassServo](DEBUG): Initializing MassServo.
2018-12-18T19:59:32.193Z,1545163172.193 [RudderServo](DEBUG): Initializing RudderServo.
2018-12-18T19:59:32.205Z,1545163172.205 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2018-12-18T19:59:35.673Z,1545163175.673 [CommandLine](IMPORTANT): got command quit
2018-12-18T19:59:36.677Z,1545163176.677 [Supervisor](INFO): Stop Mission called by Supervisor::terminate
2018-12-18T19:59:36.679Z,1545163176.679 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2018-12-18T19:59:36.680Z,1545163176.680 [CommandLine ThreadHandler](INFO): Thread cancelled.
2018-12-18T19:59:36.769Z,1545163176.769 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2018-12-18T19:59:36.769Z,1545163176.769 [CommandLine ThreadHandler](INFO): Thread cancelled.
2018-12-18T19:59:36.769Z,1545163176.769 [CommandLine](INFO): Join timeout helper Thread ID is 654
2018-12-18T19:59:36.785Z,1545163176.785 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2018-12-18T19:59:36.785Z,1545163176.785 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2018-12-18T19:59:36.785Z,1545163176.785 [NavChartDb](INFO): Join timeout helper Thread ID is 655
2018-12-18T19:59:38.182Z,1545163178.182 [CTD_NeilBrown](FAULT): Failed to acquire real or simulated CTD data within timeout.
2018-12-18T19:59:38.182Z,1545163178.182 [CTD_NeilBrown] Communications Fault, FailCount= 1
2018-12-18T19:59:38.182Z,1545163178.182 [CTD_NeilBrown](ERROR): Communications Fault
2018-12-18T19:59:38.306Z,1545163178.306 [CBIT](ERROR): Communications Fault in component: CTD_NeilBrown
2018-12-18T19:59:38.306Z,1545163178.306 [CBIT](FAULT): Communications Fault in component: CTD_NeilBrown
2018-12-18T19:59:43.511Z,1545163183.511 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2018-12-18T19:59:43.511Z,1545163183.511 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2018-12-18T19:59:43.513Z,1545163183.513 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2018-12-18T19:59:43.513Z,1545163183.513 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2018-12-18T19:59:43.513Z,1545163183.513 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 656
2018-12-18T19:59:43.957Z,1545163183.957 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2018-12-18T19:59:43.957Z,1545163183.957 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2018-12-18T19:59:43.969Z,1545163183.969 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler
2018-12-18T19:59:43.969Z,1545163183.969 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2018-12-18T19:59:43.969Z,1545163183.969 [CTD_NeilBrown](INFO): Join timeout helper Thread ID is 657
2018-12-18T19:59:44.045Z,1545163184.045 [CTD_NeilBrown ThreadHandler](INFO): Uninitializing protected caller thread.
2018-12-18T19:59:44.045Z,1545163184.045 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2018-12-18T19:59:44.061Z,1545163184.061 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2018-12-18T19:59:44.061Z,1545163184.061 [logger ThreadHandler](INFO): Thread cancelled.
2018-12-18T19:59:44.061Z,1545163184.061 [logger](INFO): Join timeout helper Thread ID is 658
2018-12-18T19:59:44.095Z,1545163184.095 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2018-12-18T19:59:44.095Z,1545163184.095 [logger ThreadHandler](INFO): Thread cancelled.
2018-12-18T19:59:44.114Z,1545163184.114 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2018-12-18T19:59:44.114Z,1545163184.114 [CommandLine ThreadHandler](INFO): Thread cancelled.
2018-12-18T19:59:44.114Z,1545163184.114 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2018-12-18T19:59:44.114Z,1545163184.114 [controlThread ThreadHandler](INFO): Thread cancelled.
2018-12-18T19:59:44.114Z,1545163184.114 [controlThread](INFO): Join timeout helper Thread ID is 659
2018-12-18T19:59:44.269Z,1545163184.269 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2018-12-18T19:59:44.269Z,1545163184.269 [controlThread](DEBUG): Uninitializing ControlThread
2018-12-18T19:59:44.270Z,1545163184.270 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2018-12-18T19:59:44.271Z,1545163184.271 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2018-12-18T19:59:44.271Z,1545163184.271 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2018-12-18T19:59:44.272Z,1545163184.272 [MissionManager](INFO): Uninitializing Mission Default
2018-12-18T19:59:44.274Z,1545163184.274 [MissionManager](INFO): Uninitializing Mission Startup
2018-12-18T19:59:44.276Z,1545163184.276 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2018-12-18T19:59:44.276Z,1545163184.276 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2018-12-18T19:59:44.276Z,1545163184.276 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2018-12-18T19:59:44.276Z,1545163184.276 [BackSeatDriver](DEBUG): Uninitialize BackSeatDriver Component.
2018-12-18T19:59:44.276Z,1545163184.276 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2018-12-18T19:59:44.277Z,1545163184.277 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2018-12-18T19:59:44.277Z,1545163184.277 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2018-12-18T19:59:44.277Z,1545163184.277 [MassServo](DEBUG): Uninitialize Mass Servo.
2018-12-18T19:59:44.278Z,1545163184.278 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2018-12-18T19:59:44.278Z,1545163184.278 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2018-12-18T19:59:44.278Z,1545163184.278 [SBIT](DEBUG): Uninitialize SBIT Component.
2018-12-18T19:59:44.278Z,1545163184.278 [IBIT](DEBUG): Uninitialize IBIT Component.
2018-12-18T19:59:44.278Z,1545163184.278 [CBIT](DEBUG): Uninitialize CBIT Component.
2018-12-18T19:59:44.279Z,1545163184.279 [controlThread ThreadHandler](INFO): Thread cancelled.
2018-12-18T19:59:44.332Z,1545163184.332 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2018-12-18T19:59:44.335Z,1545163184.335 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2018-12-18T19:59:44.376Z,1545163184.376 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2018-12-18T19:59:44.423Z,1545163184.423 [logger ThreadHandler](INFO): Thread cancelled.