2019-01-02T23:18:30.598Z,1546471110.598 [Supervisor](DEBUG): Initializing supervisor.
2019-01-02T23:18:30.601Z,1546471110.601 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2019-01-02T23:18:30.601Z,1546471110.601 [SyncHandler](INFO): Protected caller Thread ID is 801
2019-01-02T23:18:30.602Z,1546471110.602 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2019-01-02T23:18:30.603Z,1546471110.603 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2019-01-02T23:18:30.603Z,1546471110.603 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 802
2019-01-02T23:18:30.606Z,1546471110.606 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2019-01-02T23:18:30.618Z,1546471110.618 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2019-01-02T23:18:30.619Z,1546471110.619 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2019-01-02T23:18:30.619Z,1546471110.619 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 803
2019-01-02T23:18:30.620Z,1546471110.620 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2019-01-02T23:18:30.621Z,1546471110.621 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2019-01-02T23:18:30.621Z,1546471110.621 [logger ThreadHandler](INFO): Protected caller Thread ID is 804
2019-01-02T23:18:30.623Z,1546471110.623 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2019-01-02T23:18:30.623Z,1546471110.623 [Supervisor](INFO): Looking for Config files in directory: Config/
2019-01-02T23:18:30.628Z,1546471110.628 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2019-01-02T23:18:30.727Z,1546471110.727 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2019-01-02T23:18:30.729Z,1546471110.729 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2019-01-02T23:18:30.883Z,1546471110.883 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2019-01-02T23:18:30.884Z,1546471110.884 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2019-01-02T23:18:31.103Z,1546471111.103 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2019-01-02T23:18:31.105Z,1546471111.105 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2019-01-02T23:18:31.481Z,1546471111.481 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2019-01-02T23:18:31.482Z,1546471111.482 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2019-01-02T23:18:31.824Z,1546471111.824 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2019-01-02T23:18:31.825Z,1546471111.825 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2019-01-02T23:18:32.292Z,1546471112.292 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2019-01-02T23:18:32.294Z,1546471112.294 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2019-01-02T23:18:32.789Z,1546471112.789 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2019-01-02T23:18:32.790Z,1546471112.790 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2019-01-02T23:18:33.260Z,1546471113.260 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2019-01-02T23:18:33.261Z,1546471113.261 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2019-01-02T23:18:33.345Z,1546471113.345 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2019-01-02T23:18:33.669Z,1546471113.669 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2019-01-02T23:18:33.671Z,1546471113.671 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2019-01-02T23:18:33.823Z,1546471113.823 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2019-01-02T23:18:33.825Z,1546471113.825 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2019-01-02T23:18:34.056Z,1546471114.056 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2019-01-02T23:18:34.056Z,1546471114.056 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2019-01-02T23:18:34.514Z,1546471114.514 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2019-01-02T23:18:34.515Z,1546471114.515 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2019-01-02T23:18:34.615Z,1546471114.615 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2019-01-02T23:18:34.615Z,1546471114.615 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2019-01-02T23:18:34.764Z,1546471114.764 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2019-01-02T23:18:34.766Z,1546471114.766 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/
2019-01-02T23:18:34.768Z,1546471114.768 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Battery.cfg
2019-01-02T23:18:35.003Z,1546471115.003 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2019-01-02T23:18:35.005Z,1546471115.005 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/logger.cfg
2019-01-02T23:18:35.112Z,1546471115.112 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Science.cfg
2019-01-02T23:18:35.271Z,1546471115.271 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Control.cfg
2019-01-02T23:18:35.367Z,1546471115.367 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Simulator.cfg
2019-01-02T23:18:35.455Z,1546471115.455 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Sensor.cfg
2019-01-02T23:18:35.629Z,1546471115.629 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/vehicle.cfg
2019-01-02T23:18:35.844Z,1546471115.844 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Servo.cfg
2019-01-02T23:18:35.944Z,1546471115.944 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Navigation.cfg
2019-01-02T23:18:36.041Z,1546471116.041 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/BIT.cfg
2019-01-02T23:18:36.143Z,1546471116.143 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/secure.cfg
2019-01-02T23:18:36.227Z,1546471116.227 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2019-01-02T23:18:36.238Z,1546471116.238 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2019-01-02T23:18:36.366Z,1546471116.366 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2019-01-02T23:18:36.367Z,1546471116.367 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2019-01-02T23:18:36.391Z,1546471116.391 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2019-01-02T23:18:36.391Z,1546471116.391 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2019-01-02T23:18:36.447Z,1546471116.447 [DepthRateCalculator] Loaded
2019-01-02T23:18:36.447Z,1546471116.447 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2019-01-02T23:18:36.453Z,1546471116.453 [PitchRateCalculator] Loaded
2019-01-02T23:18:36.454Z,1546471116.454 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2019-01-02T23:18:36.469Z,1546471116.469 [SpeedCalculator] Loaded
2019-01-02T23:18:36.469Z,1546471116.469 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2019-01-02T23:18:36.491Z,1546471116.491 [TempGradientCalculator] Loaded
2019-01-02T23:18:36.491Z,1546471116.491 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2019-01-02T23:18:36.497Z,1546471116.497 [YawRateCalculator] Loaded
2019-01-02T23:18:36.497Z,1546471116.497 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2019-01-02T23:18:36.537Z,1546471116.537 [ElevatorOffsetCalculator] Loaded
2019-01-02T23:18:36.537Z,1546471116.537 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2019-01-02T23:18:36.537Z,1546471116.537 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2019-01-02T23:18:36.538Z,1546471116.538 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2019-01-02T23:18:36.579Z,1546471116.579 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2019-01-02T23:18:36.580Z,1546471116.580 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2019-01-02T23:18:47.934Z,1546471127.934 [DataOverHttps] Loaded
2019-01-02T23:18:47.934Z,1546471127.934 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread.
2019-01-02T23:18:47.973Z,1546471127.973 [Depth_Keller] Loaded
2019-01-02T23:18:47.973Z,1546471127.973 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2019-01-02T23:18:47.982Z,1546471127.982 [GobyModem] Loaded
2019-01-02T23:18:47.982Z,1546471127.982 [ComponentRegistry](DEBUG): SyncComponent "GobyModem" handled in the control thread.
2019-01-02T23:18:48.077Z,1546471128.077 [NAL9602] Loaded
2019-01-02T23:18:48.077Z,1546471128.077 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2019-01-02T23:18:48.093Z,1546471128.093 [Onboard] Loaded
2019-01-02T23:18:48.093Z,1546471128.093 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2019-01-02T23:18:48.103Z,1546471128.103 [Radio_Surface] Loaded
2019-01-02T23:18:48.103Z,1546471128.103 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2019-01-02T23:18:48.104Z,1546471128.104 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 419E04E0
2019-01-02T23:18:48.104Z,1546471128.104 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 885
2019-01-02T23:18:48.257Z,1546471128.257 [PNI_TCM] Loaded
2019-01-02T23:18:48.258Z,1546471128.258 [ComponentRegistry](DEBUG): SyncComponent "PNI_TCM" handled in the control thread.
2019-01-02T23:18:49.981Z,1546471129.981 [BPC1] Loaded
2019-01-02T23:18:49.981Z,1546471129.981 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2019-01-02T23:18:49.982Z,1546471129.982 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2019-01-02T23:18:49.982Z,1546471129.982 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2019-01-02T23:18:50.139Z,1546471130.139 [SBIT](DEBUG): Construct Startup Built In Test.
2019-01-02T23:18:50.163Z,1546471130.163 [SBIT] Loaded
2019-01-02T23:18:50.163Z,1546471130.163 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2019-01-02T23:18:50.163Z,1546471130.163 [IBIT](DEBUG): Construct Initiated Built In Test.
2019-01-02T23:18:50.175Z,1546471130.175 [IBIT] Loaded
2019-01-02T23:18:50.175Z,1546471130.175 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2019-01-02T23:18:50.178Z,1546471130.178 [CBIT](DEBUG): Construct Continuous Built In Test.
2019-01-02T23:18:50.315Z,1546471130.315 [CBIT] Loaded
2019-01-02T23:18:50.315Z,1546471130.315 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2019-01-02T23:18:50.315Z,1546471130.315 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2019-01-02T23:18:50.316Z,1546471130.316 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2019-01-02T23:18:50.543Z,1546471130.543 [ESPComponent] Loaded
2019-01-02T23:18:50.543Z,1546471130.543 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread.
2019-01-02T23:18:50.557Z,1546471130.557 [PAR_Licor] Loaded
2019-01-02T23:18:50.557Z,1546471130.557 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2019-01-02T23:18:50.605Z,1546471130.605 [WetLabsBB2FL] Loaded
2019-01-02T23:18:50.606Z,1546471130.606 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2019-01-02T23:18:50.607Z,1546471130.607 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 41AC04E0
2019-01-02T23:18:50.607Z,1546471130.607 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 886
2019-01-02T23:18:50.608Z,1546471130.608 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2019-01-02T23:18:50.609Z,1546471130.609 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2019-01-02T23:18:50.905Z,1546471130.905 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2019-01-02T23:18:50.905Z,1546471130.905 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2019-01-02T23:18:51.273Z,1546471131.273 [VerticalControl](DEBUG): Construct VerticalControl.
2019-01-02T23:18:51.365Z,1546471131.365 [VerticalControl] Loaded
2019-01-02T23:18:51.366Z,1546471131.366 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2019-01-02T23:18:51.367Z,1546471131.367 [HorizontalControl](DEBUG): Construct HorizontalControl.
2019-01-02T23:18:51.425Z,1546471131.425 [HorizontalControl] Loaded
2019-01-02T23:18:51.426Z,1546471131.426 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2019-01-02T23:18:51.426Z,1546471131.426 [SpeedControl](DEBUG): Construct SpeedControl.
2019-01-02T23:18:51.432Z,1546471131.432 [SpeedControl] Loaded
2019-01-02T23:18:51.432Z,1546471131.432 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2019-01-02T23:18:51.433Z,1546471131.433 [LoopControl](DEBUG): Construct LoopControl.
2019-01-02T23:18:51.433Z,1546471131.433 [LoopControl] Loaded
2019-01-02T23:18:51.433Z,1546471131.433 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2019-01-02T23:18:51.434Z,1546471131.434 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2019-01-02T23:18:51.435Z,1546471131.435 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2019-01-02T23:18:51.536Z,1546471131.536 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2019-01-02T23:18:51.537Z,1546471131.537 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2019-01-02T23:18:51.653Z,1546471131.653 [BuoyancyServo] Loaded
2019-01-02T23:18:51.654Z,1546471131.654 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2019-01-02T23:18:51.665Z,1546471131.665 [ElevatorServo] Loaded
2019-01-02T23:18:51.666Z,1546471131.666 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2019-01-02T23:18:51.676Z,1546471131.676 [MassServo] Loaded
2019-01-02T23:18:51.677Z,1546471131.677 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2019-01-02T23:18:51.688Z,1546471131.688 [RudderServo] Loaded
2019-01-02T23:18:51.688Z,1546471131.688 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2019-01-02T23:18:51.699Z,1546471131.699 [ThrusterServo] Loaded
2019-01-02T23:18:51.699Z,1546471131.699 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2019-01-02T23:18:51.699Z,1546471131.699 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2019-01-02T23:18:51.700Z,1546471131.700 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2019-01-02T23:18:51.813Z,1546471131.813 [DeadReckonUsingSpeedCalculator] Loaded
2019-01-02T23:18:51.813Z,1546471131.813 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread.
2019-01-02T23:18:51.829Z,1546471131.829 [NavChart] Loaded
2019-01-02T23:18:51.830Z,1546471131.830 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2019-01-02T23:18:51.833Z,1546471131.833 [UniversalFixResidualReporter] Loaded
2019-01-02T23:18:51.834Z,1546471131.834 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2019-01-02T23:18:51.834Z,1546471131.834 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2019-01-02T23:18:51.838Z,1546471131.838 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2019-01-02T23:18:51.839Z,1546471131.839 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2019-01-02T23:18:51.845Z,1546471131.845 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2019-01-02T23:18:51.846Z,1546471131.846 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 41C1A4E0
2019-01-02T23:18:51.847Z,1546471131.847 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 887
2019-01-02T23:18:51.851Z,1546471131.851 [Supervisor](INFO): Main Thread ID is 797
2019-01-02T23:18:51.851Z,1546471131.851 [Supervisor](DEBUG): Running supervisor.
2019-01-02T23:18:51.852Z,1546471131.852 [CommandLine ThreadHandler](INFO): Handler Thread ID is 888
2019-01-02T23:18:51.854Z,1546471131.854 [controlThread ThreadHandler](INFO): Handler Thread ID is 889
2019-01-02T23:18:51.855Z,1546471131.855 [controlThread](DEBUG): Initializing ControlThread
2019-01-02T23:18:51.856Z,1546471131.856 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2019-01-02T23:18:51.856Z,1546471131.856 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2019-01-02T23:18:51.856Z,1546471131.856 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2019-01-02T23:18:51.857Z,1546471131.857 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2019-01-02T23:18:51.857Z,1546471131.857 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2019-01-02T23:18:51.858Z,1546471131.858 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2019-01-02T23:18:51.878Z,1546471131.878 [logger ThreadHandler](INFO): Handler Thread ID is 890
2019-01-02T23:18:51.907Z,1546471131.907 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 891
2019-01-02T23:18:51.913Z,1546471131.913 [Radio_Surface](INFO): Powering up
2019-01-02T23:18:51.927Z,1546471131.927 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 892
2019-01-02T23:18:51.928Z,1546471131.928 [WetLabsBB2FL](INFO): Powering down
2019-01-02T23:18:51.966Z,1546471131.966 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 893
2019-01-02T23:18:51.976Z,1546471131.976 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2019-01-02T23:18:51.976Z,1546471131.976 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2019-01-02T23:18:51.977Z,1546471131.977 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2019-01-02T23:18:51.977Z,1546471131.977 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2019-01-02T23:18:51.977Z,1546471131.977 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2019-01-02T23:18:51.977Z,1546471131.977 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2019-01-02T23:18:51.977Z,1546471131.977 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2019-01-02T23:18:51.977Z,1546471131.977 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2019-01-02T23:18:51.978Z,1546471131.978 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2019-01-02T23:18:51.978Z,1546471131.978 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2019-01-02T23:18:51.978Z,1546471131.978 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2019-01-02T23:18:51.978Z,1546471131.978 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2019-01-02T23:18:51.978Z,1546471131.978 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2019-01-02T23:18:51.979Z,1546471131.979 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2019-01-02T23:18:51.979Z,1546471131.979 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2019-01-02T23:18:51.979Z,1546471131.979 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2019-01-02T23:20:24.343Z,1546471224.343 [GobyModem](CRITICAL): exception at startup: Failed to startup.
2019-01-02T23:20:24.405Z,1546471224.405 [SBIT](INFO): Initialize SBIT Component.
2019-01-02T23:20:24.406Z,1546471224.406 [SBIT](IMPORTANT): git: 2018-12-19
2019-01-02T23:20:24.406Z,1546471224.406 [SBIT](INFO): git hash: f0e90a53519ed2f91f39351bc58b7b0f50855756
2019-01-02T23:20:24.406Z,1546471224.406 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2019-01-02T23:20:24.407Z,1546471224.407 [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-02T23:20:24.408Z,1546471224.408 [SBIT](INFO): Beginning SBIT in 24.000000 seconds.
2019-01-02T23:20:24.409Z,1546471224.409 [IBIT](INFO): Initialize IBIT Component.
2019-01-02T23:20:24.409Z,1546471224.409 [CBIT](DEBUG): Initialize CBIT Component.
2019-01-02T23:20:24.422Z,1546471224.422 [CBIT](DEBUG): Initialized mux pins.
2019-01-02T23:20:24.422Z,1546471224.422 [CBIT](DEBUG): Initializing the watchdog timer.
2019-01-02T23:20:24.446Z,1546471224.446 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2019-01-02T23:20:24.446Z,1546471224.446 [CBIT](DEBUG): Initializing heartbeat.
2019-01-02T23:20:24.518Z,1546471224.518 [CBIT](DEBUG): Deactivating GF circuits.
2019-01-02T23:20:24.518Z,1546471224.518 [CBIT](DEBUG): Deactivating emergency mode.
2019-01-02T23:20:24.567Z,1546471224.567 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2019-01-02T23:20:24.569Z,1546471224.569 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2019-01-02T23:20:24.569Z,1546471224.569 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2019-01-02T23:20:24.570Z,1546471224.570 [LoopControl](DEBUG): Initialize LoopControlComponent.
2019-01-02T23:20:24.572Z,1546471224.572 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2019-01-02T23:20:24.572Z,1546471224.572 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2019-01-02T23:20:24.573Z,1546471224.573 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2019-01-02T23:20:24.573Z,1546471224.573 [NavChart](DEBUG): Initialize NavChart Navigation.
2019-01-02T23:20:24.573Z,1546471224.573 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2019-01-02T23:20:24.575Z,1546471224.575 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2019-01-02T23:20:24.600Z,1546471224.600 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2019-01-02T23:20:24.651Z,1546471224.651 [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-01-02T23:20:24.652Z,1546471224.652 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2019-01-02T23:20:24.717Z,1546471224.717 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2019-01-02T23:20:24.719Z,1546471224.719 [Default:A.Wait](DEBUG): Construct Wait.
2019-01-02T23:20:24.720Z,1546471224.720 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2019-01-02T23:20:24.761Z,1546471224.761 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2019-01-02T23:20:24.764Z,1546471224.764 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2019-01-02T23:20:24.769Z,1546471224.769 [Default:E.Execute](DEBUG): Construct Execute.
2019-01-02T23:20:24.777Z,1546471224.777 [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-01-02T23:20:24.782Z,1546471224.782 [controlThread](DEBUG): Component order: CycleStarter,DataOverHttps,Depth_Keller,GobyModem,NAL9602,Onboard,PNI_TCM,BPC1,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-02T23:20:24.799Z,1546471224.799 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2019-01-02T23:20:24.928Z,1546471224.928 [NAL9602](INFO): Powering up NAL9602
2019-01-02T23:20:25.032Z,1546471225.032 [ESPComponent](INFO): powering down ESP
2019-01-02T23:20:25.351Z,1546471225.351 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2019-01-02T23:20:25.358Z,1546471225.358 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2019-01-02T23:20:25.365Z,1546471225.365 [ElevatorServo](DEBUG): Initializing EZServoServo.
2019-01-02T23:20:25.370Z,1546471225.370 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2019-01-02T23:20:25.376Z,1546471225.376 [MassServo](DEBUG): Initializing EZServoServo.
2019-01-02T23:20:25.382Z,1546471225.382 [MassServo](DEBUG): Initializing MassServo.
2019-01-02T23:20:25.388Z,1546471225.388 [RudderServo](DEBUG): Initializing EZServoServo.
2019-01-02T23:20:25.394Z,1546471225.394 [RudderServo](DEBUG): Initializing RudderServo.
2019-01-02T23:20:25.400Z,1546471225.400 [ThrusterServo](DEBUG): Initializing EZServoServo.
2019-01-02T23:20:25.406Z,1546471225.406 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2019-01-02T23:20:25.427Z,1546471225.427 [CommandLine](FAULT): Scheduling is paused
2019-01-02T23:20:25.428Z,1546471225.428 [CBIT](INFO): Critical error at 20190102T232024
2019-01-02T23:20:25.428Z,1546471225.428 [Supervisor](INFO): Stop Mission called by CBIT::checkCriticals
2019-01-02T23:20:26.234Z,1546471226.234 [BuoyancyServo](ERROR): Buoyancy initialization uart error serial timeout
2019-01-02T23:20:26.234Z,1546471226.234 [BuoyancyServo](FAULT): Buoyancy failed to initialize
2019-01-02T23:20:26.234Z,1546471226.234 [BuoyancyServo] Communications Fault, FailCount= 1
2019-01-02T23:20:26.234Z,1546471226.234 [BuoyancyServo](ERROR): Communications Fault
2019-01-02T23:20:26.430Z,1546471226.430 [CBIT](ERROR): Communications Fault in component: BuoyancyServo
2019-01-02T23:20:28.539Z,1546471228.539 [CBIT](INFO): Clearing failed state for component BuoyancyServo
2019-01-02T23:20:28.539Z,1546471228.539 [BuoyancyServo] No Fault, FailCount= 1
2019-01-02T23:20:28.893Z,1546471228.893 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2019-01-02T23:20:29.011Z,1546471229.011 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2019-01-02T23:20:34.494Z,1546471234.494 [CBIT](CRITICAL): Environmental Failure. Press:14.798020 PSI. Humidity:25%. Temp:23 C. ABORTING MISSION
2019-01-02T23:20:34.896Z,1546471234.896 [CBIT](INFO): Critical error at 20190102T232034
2019-01-02T23:20:35.653Z,1546471235.653 [GobyModem](INFO): Added slot 1
2019-01-02T23:20:35.654Z,1546471235.654 [GobyModem](INFO): Added slot 2
2019-01-02T23:20:35.654Z,1546471235.654 [GobyModem](INFO): Added slot 3
2019-01-02T23:20:37.565Z,1546471237.565 [NAL9602](INFO): NAL9602 initialized
2019-01-02T23:20:48.384Z,1546471248.384 [GobyModem](INFO): {control} starting send from me
2019-01-02T23:20:48.808Z,1546471248.808 [SBIT](IMPORTANT): Beginning Startup BIT
2019-01-02T23:20:48.812Z,1546471248.812 [CBIT](IMPORTANT): Beginning ground fault scan
2019-01-02T23:20:59.772Z,1546471259.772 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.016078
CHAN A1 (24V): -0.019265
CHAN A2 (12V): -0.005254
CHAN A3 (5V): -0.002354
CHAN B0 (3.3V): -0.001040
CHAN B1 (3.15aV): -0.000632
CHAN B2 (3.15bV): -0.001153
CHAN B3 (GND): 0.000085
OPEN: 0.003967
Full Scale Calc: 4.765 mA, -1.589 mA
2019-01-02T23:21:24.266Z,1546471284.266 [GobyModem](INFO): {control} starting send from me
2019-01-02T23:21:32.780Z,1546471292.780 [BPC1](FAULT): Failed to parse data from all battery packs.
2019-01-02T23:21:32.780Z,1546471292.780 [BPC1] Data Fault, FailCount= 1
2019-01-02T23:21:32.780Z,1546471292.780 [BPC1](ERROR): Data Fault
2019-01-02T23:21:32.835Z,1546471292.835 [CBIT](ERROR): Data Fault in component: BPC1
2019-01-02T23:21:33.488Z,1546471293.488 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004459
2019-01-02T23:21:42.565Z,1546471302.565 [SBIT](IMPORTANT): SBIT PASSED
2019-01-02T23:21:42.652Z,1546471302.652 [CommandLine](IMPORTANT): got command configSet list
2019-01-02T23:21:42.652Z,1546471302.652 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2019-01-02T23:21:42.653Z,1546471302.653 [CommandLine](IMPORTANT): Aanderaa_O2.loadAtStartu