2019-01-10T14:07:09.690Z,1547129229.690 [Supervisor](DEBUG): Initializing supervisor.
2019-01-10T14:07:09.712Z,1547129229.712 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2019-01-10T14:07:09.713Z,1547129229.713 [SyncHandler](INFO): Protected caller Thread ID is 4787
2019-01-10T14:07:09.713Z,1547129229.713 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2019-01-10T14:07:09.714Z,1547129229.714 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2019-01-10T14:07:09.714Z,1547129229.714 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 4788
2019-01-10T14:07:09.718Z,1547129229.718 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2019-01-10T14:07:09.729Z,1547129229.729 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2019-01-10T14:07:09.730Z,1547129229.730 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2019-01-10T14:07:09.730Z,1547129229.730 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 4789
2019-01-10T14:07:09.731Z,1547129229.731 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2019-01-10T14:07:09.732Z,1547129229.732 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2019-01-10T14:07:09.733Z,1547129229.733 [logger ThreadHandler](INFO): Protected caller Thread ID is 4790
2019-01-10T14:07:09.734Z,1547129229.734 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2019-01-10T14:07:09.735Z,1547129229.735 [Supervisor](INFO): Looking for Config files in directory: Config/
2019-01-10T14:07:09.737Z,1547129229.737 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2019-01-10T14:07:09.835Z,1547129229.835 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2019-01-10T14:07:09.836Z,1547129229.836 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2019-01-10T14:07:09.936Z,1547129229.936 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2019-01-10T14:07:09.937Z,1547129229.937 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2019-01-10T14:07:10.130Z,1547129230.130 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2019-01-10T14:07:10.130Z,1547129230.130 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2019-01-10T14:07:10.485Z,1547129230.485 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2019-01-10T14:07:10.486Z,1547129230.486 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2019-01-10T14:07:10.803Z,1547129230.803 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2019-01-10T14:07:10.804Z,1547129230.804 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2019-01-10T14:07:11.248Z,1547129231.248 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2019-01-10T14:07:11.249Z,1547129231.249 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2019-01-10T14:07:11.715Z,1547129231.715 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2019-01-10T14:07:11.715Z,1547129231.715 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2019-01-10T14:07:12.161Z,1547129232.161 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2019-01-10T14:07:12.161Z,1547129232.161 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2019-01-10T14:07:12.242Z,1547129232.242 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2019-01-10T14:07:12.545Z,1547129232.545 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2019-01-10T14:07:12.546Z,1547129232.546 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2019-01-10T14:07:12.693Z,1547129232.693 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2019-01-10T14:07:12.693Z,1547129232.693 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2019-01-10T14:07:12.907Z,1547129232.907 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2019-01-10T14:07:12.908Z,1547129232.908 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2019-01-10T14:07:13.110Z,1547129233.110 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2019-01-10T14:07:13.111Z,1547129233.111 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2019-01-10T14:07:13.209Z,1547129233.209 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2019-01-10T14:07:13.210Z,1547129233.210 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2019-01-10T14:07:13.370Z,1547129233.370 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2019-01-10T14:07:13.372Z,1547129233.372 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/
2019-01-10T14:07:13.373Z,1547129233.373 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Battery.cfg
2019-01-10T14:07:13.874Z,1547129233.874 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2019-01-10T14:07:13.875Z,1547129233.875 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/logger.cfg
2019-01-10T14:07:13.980Z,1547129233.980 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Science.cfg
2019-01-10T14:07:14.129Z,1547129234.129 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Control.cfg
2019-01-10T14:07:14.223Z,1547129234.223 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Simulator.cfg
2019-01-10T14:07:14.309Z,1547129234.309 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Sensor.cfg
2019-01-10T14:07:14.466Z,1547129234.466 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/vehicle.cfg
2019-01-10T14:07:14.666Z,1547129234.666 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Servo.cfg
2019-01-10T14:07:14.765Z,1547129234.765 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/Navigation.cfg
2019-01-10T14:07:14.860Z,1547129234.860 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/BIT.cfg
2019-01-10T14:07:14.958Z,1547129234.958 [Supervisor](INFO): Opening Config file at: Config/lrauv-makai/secure.cfg
2019-01-10T14:07:15.042Z,1547129235.042 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-makai/LOGIN/
2019-01-10T14:07:15.043Z,1547129235.043 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2019-01-10T14:07:15.051Z,1547129235.051 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2019-01-10T14:07:15.148Z,1547129235.148 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2019-01-10T14:07:15.149Z,1547129235.149 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2019-01-10T14:07:15.162Z,1547129235.162 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2019-01-10T14:07:15.163Z,1547129235.163 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2019-01-10T14:07:15.204Z,1547129235.204 [DepthRateCalculator] Loaded
2019-01-10T14:07:15.204Z,1547129235.204 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2019-01-10T14:07:15.210Z,1547129235.210 [PitchRateCalculator] Loaded
2019-01-10T14:07:15.210Z,1547129235.210 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2019-01-10T14:07:15.225Z,1547129235.225 [SpeedCalculator] Loaded
2019-01-10T14:07:15.226Z,1547129235.226 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2019-01-10T14:07:15.245Z,1547129235.245 [TempGradientCalculator] Loaded
2019-01-10T14:07:15.246Z,1547129235.246 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2019-01-10T14:07:15.251Z,1547129235.251 [YawRateCalculator] Loaded
2019-01-10T14:07:15.251Z,1547129235.251 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2019-01-10T14:07:15.289Z,1547129235.289 [ElevatorOffsetCalculator] Loaded
2019-01-10T14:07:15.289Z,1547129235.289 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2019-01-10T14:07:15.290Z,1547129235.290 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2019-01-10T14:07:15.290Z,1547129235.290 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2019-01-10T14:07:15.317Z,1547129235.317 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2019-01-10T14:07:15.317Z,1547129235.317 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2019-01-10T14:07:23.766Z,1547129243.766 [AcousticModem_Benthos_ATM900] Loaded
2019-01-10T14:07:23.766Z,1547129243.766 [ComponentRegistry](DEBUG): SyncComponent "AcousticModem_Benthos_ATM900" handled in the control thread.
2019-01-10T14:07:23.833Z,1547129243.833 [DataOverHttps] Loaded
2019-01-10T14:07:23.834Z,1547129243.834 [ComponentRegistry](DEBUG): SyncComponent "DataOverHttps" handled in the control thread.
2019-01-10T14:07:23.847Z,1547129243.847 [Depth_Keller] Loaded
2019-01-10T14:07:23.847Z,1547129243.847 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2019-01-10T14:07:23.939Z,1547129243.939 [NAL9602] Loaded
2019-01-10T14:07:23.940Z,1547129243.940 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2019-01-10T14:07:23.955Z,1547129243.955 [Onboard] Loaded
2019-01-10T14:07:23.955Z,1547129243.955 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2019-01-10T14:07:23.965Z,1547129243.965 [Radio_Surface] Loaded
2019-01-10T14:07:23.965Z,1547129243.965 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2019-01-10T14:07:23.966Z,1547129243.966 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 419E84E0
2019-01-10T14:07:23.967Z,1547129243.967 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 4869
2019-01-10T14:07:24.011Z,1547129244.011 [PNI_TCM] Loaded
2019-01-10T14:07:24.011Z,1547129244.011 [ComponentRegistry](DEBUG): SyncComponent "PNI_TCM" handled in the control thread.
2019-01-10T14:07:24.069Z,1547129244.069 [Rowe_600LCM] Loaded
2019-01-10T14:07:24.069Z,1547129244.069 [ComponentRegistry](DEBUG): Component "Rowe_600LCM" handled in its own thread.
2019-01-10T14:07:24.070Z,1547129244.070 [Rowe_600LCM ThreadHandler](DEBUG): Created PCaller Thread at 41A184E0
2019-01-10T14:07:24.070Z,1547129244.070 [Rowe_600LCM ThreadHandler](INFO): Protected caller Thread ID is 4870
2019-01-10T14:07:25.768Z,1547129245.768 [BPC1] Loaded
2019-01-10T14:07:25.768Z,1547129245.768 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2019-01-10T14:07:25.768Z,1547129245.768 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2019-01-10T14:07:25.769Z,1547129245.769 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2019-01-10T14:07:25.899Z,1547129245.899 [SBIT](DEBUG): Construct Startup Built In Test.
2019-01-10T14:07:25.921Z,1547129245.921 [SBIT] Loaded
2019-01-10T14:07:25.922Z,1547129245.922 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2019-01-10T14:07:25.922Z,1547129245.922 [IBIT](DEBUG): Construct Initiated Built In Test.
2019-01-10T14:07:25.934Z,1547129245.934 [IBIT] Loaded
2019-01-10T14:07:25.934Z,1547129245.934 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2019-01-10T14:07:25.937Z,1547129245.937 [CBIT](DEBUG): Construct Continuous Built In Test.
2019-01-10T14:07:26.068Z,1547129246.068 [CBIT] Loaded
2019-01-10T14:07:26.068Z,1547129246.068 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2019-01-10T14:07:26.068Z,1547129246.068 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2019-01-10T14:07:26.069Z,1547129246.069 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2019-01-10T14:07:26.244Z,1547129246.244 [ESPComponent] Loaded
2019-01-10T14:07:26.244Z,1547129246.244 [ComponentRegistry](DEBUG): SyncComponent "ESPComponent" handled in the control thread.
2019-01-10T14:07:26.258Z,1547129246.258 [PAR_Licor] Loaded
2019-01-10T14:07:26.258Z,1547129246.258 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2019-01-10T14:07:26.304Z,1547129246.304 [WetLabsBB2FL] Loaded
2019-01-10T14:07:26.305Z,1547129246.305 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2019-01-10T14:07:26.306Z,1547129246.306 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 41AF84E0
2019-01-10T14:07:26.306Z,1547129246.306 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 4871
2019-01-10T14:07:26.307Z,1547129246.307 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2019-01-10T14:07:26.307Z,1547129246.307 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2019-01-10T14:07:26.537Z,1547129246.537 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2019-01-10T14:07:26.538Z,1547129246.538 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2019-01-10T14:07:26.603Z,1547129246.603 [VerticalControl](DEBUG): Construct VerticalControl.
2019-01-10T14:07:26.693Z,1547129246.693 [VerticalControl] Loaded
2019-01-10T14:07:26.693Z,1547129246.693 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2019-01-10T14:07:26.694Z,1547129246.694 [HorizontalControl](DEBUG): Construct HorizontalControl.
2019-01-10T14:07:26.751Z,1547129246.751 [HorizontalControl] Loaded
2019-01-10T14:07:26.751Z,1547129246.751 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2019-01-10T14:07:26.752Z,1547129246.752 [SpeedControl](DEBUG): Construct SpeedControl.
2019-01-10T14:07:26.757Z,1547129246.757 [SpeedControl] Loaded
2019-01-10T14:07:26.757Z,1547129246.757 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2019-01-10T14:07:26.758Z,1547129246.758 [LoopControl](DEBUG): Construct LoopControl.
2019-01-10T14:07:26.758Z,1547129246.758 [LoopControl] Loaded
2019-01-10T14:07:26.759Z,1547129246.759 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2019-01-10T14:07:26.759Z,1547129246.759 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2019-01-10T14:07:26.760Z,1547129246.760 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2019-01-10T14:07:26.826Z,1547129246.826 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2019-01-10T14:07:26.826Z,1547129246.826 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2019-01-10T14:07:26.922Z,1547129246.922 [BuoyancyServo] Loaded
2019-01-10T14:07:26.922Z,1547129246.922 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2019-01-10T14:07:26.933Z,1547129246.933 [ElevatorServo] Loaded
2019-01-10T14:07:26.933Z,1547129246.933 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2019-01-10T14:07:26.945Z,1547129246.945 [MassServo] Loaded
2019-01-10T14:07:26.945Z,1547129246.945 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2019-01-10T14:07:26.956Z,1547129246.956 [RudderServo] Loaded
2019-01-10T14:07:26.956Z,1547129246.956 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2019-01-10T14:07:26.966Z,1547129246.966 [ThrusterServo] Loaded
2019-01-10T14:07:26.967Z,1547129246.967 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2019-01-10T14:07:26.967Z,1547129246.967 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2019-01-10T14:07:26.968Z,1547129246.968 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2019-01-10T14:07:27.062Z,1547129247.062 [DeadReckonUsingSpeedCalculator] Loaded
2019-01-10T14:07:27.062Z,1547129247.062 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingSpeedCalculator" handled in the control thread.
2019-01-10T14:07:27.078Z,1547129247.078 [NavChart] Loaded
2019-01-10T14:07:27.078Z,1547129247.078 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2019-01-10T14:07:27.082Z,1547129247.082 [UniversalFixResidualReporter] Loaded
2019-01-10T14:07:27.083Z,1547129247.083 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2019-01-10T14:07:27.083Z,1547129247.083 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2019-01-10T14:07:27.087Z,1547129247.087 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2019-01-10T14:07:27.088Z,1547129247.088 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2019-01-10T14:07:27.094Z,1547129247.094 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2019-01-10T14:07:27.095Z,1547129247.095 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 41C524E0
2019-01-10T14:07:27.096Z,1547129247.096 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 4872
2019-01-10T14:07:27.100Z,1547129247.100 [Supervisor](INFO): Main Thread ID is 4786
2019-01-10T14:07:27.101Z,1547129247.101 [Supervisor](DEBUG): Running supervisor.
2019-01-10T14:07:27.101Z,1547129247.101 [CommandLine ThreadHandler](INFO): Handler Thread ID is 4873
2019-01-10T14:07:27.103Z,1547129247.103 [controlThread ThreadHandler](INFO): Handler Thread ID is 4874
2019-01-10T14:07:27.104Z,1547129247.104 [controlThread](DEBUG): Initializing ControlThread
2019-01-10T14:07:27.105Z,1547129247.105 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2019-01-10T14:07:27.105Z,1547129247.105 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2019-01-10T14:07:27.105Z,1547129247.105 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2019-01-10T14:07:27.106Z,1547129247.106 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2019-01-10T14:07:27.106Z,1547129247.106 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2019-01-10T14:07:27.106Z,1547129247.106 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2019-01-10T14:07:27.109Z,1547129247.109 [SBIT](INFO): Initialize SBIT Component.
2019-01-10T14:07:27.110Z,1547129247.110 [SBIT](IMPORTANT): git: 2018-12-19-33-g7a9485f
2019-01-10T14:07:27.110Z,1547129247.110 [SBIT](INFO): git hash: 7a9485f35819a7024d1a01c3daca1d5dca0e188a
2019-01-10T14:07:27.110Z,1547129247.110 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2019-01-10T14:07:27.111Z,1547129247.111 [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-10T14:07:27.113Z,1547129247.113 [SBIT](INFO): Beginning SBIT in 24.000000 seconds.
2019-01-10T14:07:27.113Z,1547129247.113 [IBIT](INFO): Initialize IBIT Component.
2019-01-10T14:07:27.114Z,1547129247.114 [CBIT](DEBUG): Initialize CBIT Component.
2019-01-10T14:07:27.115Z,1547129247.115 [logger ThreadHandler](INFO): Handler Thread ID is 4875
2019-01-10T14:07:27.128Z,1547129247.128 [CBIT](DEBUG): Initialized mux pins.
2019-01-10T14:07:27.128Z,1547129247.128 [CBIT](DEBUG): Initializing the watchdog timer.
2019-01-10T14:07:27.133Z,1547129247.133 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 4876
2019-01-10T14:07:27.138Z,1547129247.138 [Radio_Surface](INFO): Powering up
2019-01-10T14:07:27.148Z,1547129247.148 [Rowe_600LCM ThreadHandler](INFO): Handler Thread ID is 4877
2019-01-10T14:07:27.149Z,1547129247.149 [Rowe_600LCM](INFO): Initializing
2019-01-10T14:07:27.156Z,1547129247.156 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2019-01-10T14:07:27.156Z,1547129247.156 [CBIT](DEBUG): Initializing heartbeat.
2019-01-10T14:07:27.159Z,1547129247.159 [Rowe_600LCM](INFO): Powering up
2019-01-10T14:07:27.165Z,1547129247.165 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 4878
2019-01-10T14:07:27.166Z,1547129247.166 [WetLabsBB2FL](INFO): Powering down
2019-01-10T14:07:27.193Z,1547129247.193 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 4879
2019-01-10T14:07:27.196Z,1547129247.196 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2019-01-10T14:07:27.196Z,1547129247.196 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2019-01-10T14:07:27.197Z,1547129247.197 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2019-01-10T14:07:27.197Z,1547129247.197 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2019-01-10T14:07:27.197Z,1547129247.197 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2019-01-10T14:07:27.197Z,1547129247.197 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2019-01-10T14:07:27.197Z,1547129247.197 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2019-01-10T14:07:27.198Z,1547129247.198 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2019-01-10T14:07:27.198Z,1547129247.198 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2019-01-10T14:07:27.198Z,1547129247.198 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2019-01-10T14:07:27.198Z,1547129247.198 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2019-01-10T14:07:27.198Z,1547129247.198 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2019-01-10T14:07:27.199Z,1547129247.199 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2019-01-10T14:07:27.199Z,1547129247.199 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2019-01-10T14:07:27.199Z,1547129247.199 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2019-01-10T14:07:27.199Z,1547129247.199 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2019-01-10T14:07:27.228Z,1547129247.228 [CBIT](DEBUG): Deactivating GF circuits.
2019-01-10T14:07:27.228Z,1547129247.228 [CBIT](DEBUG): Deactivating emergency mode.
2019-01-10T14:07:27.268Z,1547129247.268 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2019-01-10T14:07:27.270Z,1547129247.270 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2019-01-10T14:07:27.271Z,1547129247.271 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2019-01-10T14:07:27.271Z,1547129247.271 [LoopControl](DEBUG): Initialize LoopControlComponent.
2019-01-10T14:07:27.273Z,1547129247.273 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2019-01-10T14:07:27.274Z,1547129247.274 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2019-01-10T14:07:27.274Z,1547129247.274 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2019-01-10T14:07:27.274Z,1547129247.274 [NavChart](DEBUG): Initialize NavChart Navigation.
2019-01-10T14:07:27.275Z,1547129247.275 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2019-01-10T14:07:27.276Z,1547129247.276 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2019-01-10T14:07:27.299Z,1547129247.299 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2019-01-10T14:07:27.322Z,1547129247.322 [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-10T14:07:27.323Z,1547129247.323 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2019-01-10T14:07:27.412Z,1547129247.412 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2019-01-10T14:07:27.413Z,1547129247.413 [Default:A.Wait](DEBUG): Construct Wait.
2019-01-10T14:07:27.415Z,1547129247.415 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2019-01-10T14:07:27.451Z,1547129247.451 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2019-01-10T14:07:27.454Z,1547129247.454 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2019-01-10T14:07:27.468Z,1547129247.468 [Default:E.Execute](DEBUG): Construct Execute.
2019-01-10T14:07:27.472Z,1547129247.472 [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-10T14:07:27.501Z,1547129247.501 [controlThread](DEBUG): Component order: CycleStarter,AcousticModem_Benthos_ATM900,DataOverHttps,Depth_Keller,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-10T14:07:27.541Z,1547129247.541 [AcousticModem_Benthos_ATM900](INFO): Powering up
2019-01-10T14:07:27.541Z,1547129247.541 [AcousticModem_Benthos_ATM900](DEBUG): Initializing AcousticModem_Benthos_ATM900.
2019-01-10T14:07:27.571Z,1547129247.571 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2019-01-10T14:07:27.862Z,1547129247.862 [ESPComponent](INFO): powering down ESP
2019-01-10T14:07:28.417Z,1547129248.417 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2019-01-10T14:07:28.424Z,1547129248.424 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2019-01-10T14:07:28.446Z,1547129248.446 [ElevatorServo](DEBUG): Initializing EZServoServo.
2019-01-10T14:07:28.452Z,1547129248.452 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2019-01-10T14:07:28.474Z,1547129248.474 [MassServo](DEBUG): Initializing EZServoServo.
2019-01-10T14:07:28.480Z,1547129248.480 [MassServo](DEBUG): Initializing MassServo.
2019-01-10T14:07:28.486Z,1547129248.486 [RudderServo](DEBUG): Initializing EZServoServo.
2019-01-10T14:07:28.492Z,1547129248.492 [RudderServo](DEBUG): Initializing RudderServo.
2019-01-10T14:07:28.517Z,1547129248.517 [ThrusterServo](DEBUG): Initializing EZServoServo.
2019-01-10T14:07:28.524Z,1547129248.524 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2019-01-10T14:07:29.368Z,1547129249.368 [BuoyancyServo](ERROR): Buoyancy initialization uart error serial timeout
2019-01-10T14:07:29.368Z,1547129249.368 [BuoyancyServo](FAULT): Buoyancy failed to initialize
2019-01-10T14:07:29.368Z,1547129249.368 [BuoyancyServo] Communications Fault, FailCount= 1
2019-01-10T14:07:29.368Z,1547129249.368 [BuoyancyServo](ERROR): Communications Fault
2019-01-10T14:07:29.576Z,1547129249.576 [CBIT](ERROR): Communications Fault in component: BuoyancyServo
2019-01-10T14:07:31.469Z,1547129251.469 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of Rowe LCM interface
2019-01-10T14:07:31.627Z,1547129251.627 [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-10T14:07:42.715Z,1547129262.715 [CBIT](CRITICAL): Environmental Failure. Press:14.816804 PSI. Humidity:36%. Temp:23 C. ABORTING MISSION
2019-01-10T14:07:42.715Z,1547129262.715 [Supervisor](INFO): Stop Mission called by CBIT::monitorEnvironmentals
2019-01-10T14:07:42.748Z,1547129262.748 [AcousticModem_Benthos_ATM900](DEBUG): 
2019-01-10T14:07:42.750Z,1547129262.750 [AcousticModem_Benthos_ATM900](DEBUG): Teledyne Benthos ATM-900 Series OEM w/burn wire
2019-01-10T14:07:42.751Z,1547129262.751 [AcousticModem_Benthos_ATM900](DEBUG): MF Frequency Band
2019-01-10T14:07:42.751Z,1547129262.751 [AcousticModem_Benthos_ATM900](DEBUG): Standard version 8.6.3
2019-01-10T14:07:42.752Z,1547129262.752 [AcousticModem_Benthos_ATM900](DEBUG): Jan  9 2019 23:20:23 
2019-01-10T14:07:42.753Z,1547129262.753 [AcousticModem_Benthos_ATM900](DEBUG): WARNING: battery low
2019-01-10T14:07:43.142Z,1547129263.142 [CommandLine](FAULT): Scheduling is paused
2019-01-10T14:07:43.142Z,1547129263.142 [CBIT](INFO): Critical error at 20190110T140742
2019-01-10T14:07:43.556Z,1547129263.556 [AcousticModem_Benthos_ATM900](INFO): entering command mode
2019-01-10T14:07:43.563Z,1547129263.563 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004593
2019-01-10T14:07:43.955Z,1547129263.955 [AcousticModem_Benthos_ATM900](DEBUG): checking for command mode acknowledgment
2019-01-10T14:07:43.956Z,1547129263.956 [AcousticModem_Benthos_ATM900](DEBUG): read user prompt 1: user:1>
2019-01-10T14:07:43.956Z,1547129263.956 [AcousticModem_Benthos_ATM900](INFO): command mode acknowledged
2019-01-10T14:07:44.353Z,1547129264.353 [AcousticModem_Benthos_ATM900](INFO): setting local address to 3
2019-01-10T14:07:44.753Z,1547129264.753 [AcousticModem_Benthos_ATM900](DEBUG): checking for local address setting acknowledgment
2019-01-10T14:07:44.754Z,1547129264.754 [AcousticModem_Benthos_ATM900](INFO): set local address to 3
2019-01-10T14:07:44.891Z,1547129264.891 [CBIT](INFO): Clearing failed state for component BuoyancyServo
2019-01-10T14:07:44.891Z,1547129264.891 [BuoyancyServo] No Fault, FailCount= 1
2019-01-10T14:07:45.154Z,1547129265.154 [AcousticModem_Benthos_ATM900](DEBUG): read user prompt 2: user:2>
2019-01-10T14:07:45.277Z,1547129265.277 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2019-01-10T14:07:45.277Z,1547129265.277 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2019-01-10T14:07:51.635Z,1547129271.635 [SBIT](IMPORTANT): Beginning Startup BIT
2019-01-10T14:07:51.651Z,1547129271.651 [CBIT](IMPORTANT): Beginning ground fault scan
2019-01-10T14:07:54.134Z,1547129274.134 [NAL9602](INFO): Powering up NAL9602
2019-01-10T14:08:02.670Z,1547129282.670 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.008927
CHAN A1 (24V): -0.012401
CHAN A2 (12V): -0.006983
CHAN A3 (5V): -0.003001
CHAN B0 (3.3V): -0.001334
CHAN B1 (3.15aV): -0.001606
CHAN B2 (3.15bV): -0.000966
CHAN B3 (GND): -0.000141
OPEN: 0.004296
Full Scale Calc: 4.765 mA, -1.589 mA
2019-01-10T14:08:05.329Z,1547129285.329 [NAL9602](INFO): NAL9602 initialized
2019-01-10T14:08:40.133Z,1547129320.133 [BPC1](FAULT): Failed to parse data from all battery packs.
2019-01-10T14:08:40.133Z,1547129320.133 [BPC1] Data Fault, FailCount= 1
2019-01-10T14:08:40.133Z,1547129320.133 [BPC1](ERROR): Data Fault
2019-01-10T14:08:40.385Z,1547129320.385 [CBIT](ERROR): Data Fault in component: BPC1
2019-01-10T14:08:49.305Z,1547129329.305 [SBIT](IMPORTANT): SBIT PASSED
2019-01-10T14:08:49.383Z,1547129329.383 [CommandLine](IMPORTANT): got command configSet list
2019-01-10T14:08:49.383Z,1547129329.383 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2019-01-10T14:08:49.384Z,1547129329.384 [CommandLine](IMPORTANT): Aanderaa_O2.loadAtStartup=0 bool;

2019-01-10T14:08:49.384Z,1547129329.384 [CommandLine](IMPORTANT): CTD_Seabird.loadAtStartup=0 bool;

2019-01-10T14:08:49.384Z,1547129329.384 [CommandLine](IMPORTANT): DropWeight.loadAtStartup=0 bool;

2019-01-10T14:08:49.384Z,1547129329.384 [CommandLine](IMPORTANT): PAR_Licor.loadAtStartup=1 bool;

2019-01-10T14:08:49.384Z,1547129329.384 [CommandLine](IMPORTANT): Rowe_600LCM.loadAtStartup=1 bool;

2019-01-10T14:08:49.687Z,1547129329.687 [MissionManager](IMPORTANT): Started mission Startup
2019-01-10T14:08:49.692Z,1547129329.692 [Startup] Running Loop=1
2019-01-10T14:08:49.692Z,1547129329.692 [Startup](DEBUG): Aggregate::initialize Startup
2019-01-10T14:08:49.692Z,1547129329.692 [Startup:A.GoToSurface] Running Loop=1
2019-01-10T14:08:49.692Z,1547129329.692 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-01-10T14:08:49.693Z,1547129329.693 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-01-10T14:08:49.693Z,1547129329.693 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-01-10T14:08:49.694Z,1547129329.694 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-01-10T14:08:49.694Z,1547129329.694 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-01-10T14:08:49.695Z,1547129329.695 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-01-10T14:08:49.708Z,1547129329.708 [Startup:StartupSatComms] Running Loop=1
2019-01-10T14:08:49.708Z,1547129329.708 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2019-01-10T14:08:49.709Z,1547129329.709 [Startup:StartupSatComms:A] Running Loop=1
2019-01-10T14:08:50.161Z,1547129330.161 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2019-01-10T14:09:49.901Z,1547129389.901 [Startup:StartupSatComms:A](INFO): Timed out from 2019-01-10T14:08:49.7Z
2019-01-10T14:09:49.901Z,1547129389.901 [Startup:StartupSatComms:A] Stopped
2019-01-10T14:09:49.901Z,1547129389.901 [Startup:StartupSatComms:B] Running Loop=1
2019-01-10T14:09:50.311Z,1547129390.311 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-01-10T14:09:55.768Z,1547129395.768 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190108T205212/Courier0013.lzma
2019-01-10T14:09:56.535Z,1547129396.535 [DataOverHttps](INFO): Moved sent file to Logs/20190108T205212/Courier0013.lzma.bak
2019-01-10T14:09:56.535Z,1547129396.535 [DataOverHttps](INFO): SBD MOMSN=9162330
2019-01-10T14:10:07.893Z,1547129407.893 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20190109T220524/Courier0000.lzma
2019-01-10T14:10:08.695Z,1547129408.695 [DataOverHttps](INFO): Moved sent file to Logs/20190109T220524/Courier0000.lzma.bak
2019-01-10T14:10:08.695Z,1547129408.695 [DataOverHttps](INFO): SBD MOMSN=9162332
2019-01-10T14:10:20.131Z,1547129420.131 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20190109T231605/Courier0000.lzma
2019-01-10T14:10:20.899Z,1547129420.899 [DataOverHttps](INFO): Moved sent file to Logs/20190109T231605/Courier0000.lzma.bak
2019-01-10T14:10:20.899Z,1547129420.899 [DataOverHttps](INFO): SBD MOMSN=9162335
2019-01-10T14:10:27.331Z,1547129427.331 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = 1000162.874369
2019-01-10T14:10:27.331Z,1547129427.331 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 1
2019-01-10T14:10:27.331Z,1547129427.331 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2019-01-10T14:10:27.343Z,1547129427.343 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2019-01-10T14:10:27.658Z,1547129427.658 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2019-01-10T14:10:27.658Z,1547129427.658 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 1
2019-01-10T14:10:28.045Z,1547129428.045 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2019-01-10T14:10:28.045Z,1547129428.046 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2019-01-10T14:10:28.046Z,1547129428.046 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2019-01-10T14:10:34.641Z,1547129434.641 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20190110T135155/Courier0000.lzma
2019-01-10T14:10:35.443Z,1547129435.443 [DataOverHttps](INFO): Moved sent file to Logs/20190110T135155/Courier0000.lzma.bak
2019-01-10T14:10:35.443Z,1547129435.443 [DataOverHttps](INFO): SBD MOMSN=9162338
2019-01-10T14:10:46.449Z,1547129446.449 [DataOverHttps](INFO): Sending 142 bytes from file Logs/20190110T140709/Courier0000.lzma
2019-01-10T14:10:47.223Z,1547129447.223 [DataOverHttps](INFO): Moved sent file to Logs/20190110T140709/Courier0000.lzma.bak
2019-01-10T14:10:47.223Z,1547129447.223 [DataOverHttps](INFO): SBD MOMSN=9162341
2019-01-10T14:10:52.163Z,1547129452.163 [Startup:StartupSatComms:B](INFO): Timed out from 2019-01-10T14:09:49.9Z
2019-01-10T14:10:52.163Z,1547129452.163 [Startup:StartupSatComms:B] Stopped
2019-01-10T14:10:52.163Z,1547129452.163 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2019-01-10T14:10:52.164Z,1547129452.164 [Startup:StartupSatComms] Stopped
2019-01-10T14:10:52.164Z,1547129452.164 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2019-01-10T14:10:52.165Z,1547129452.165 [Startup](INFO): Completed Startup
2019-01-10T14:10:52.165Z,1547129452.165 [MissionManager](INFO): Startup is completed.
2019-01-10T14:10:52.165Z,1547129452.165 [MissionManager](INFO): Uninitializing Mission Startup
2019-01-10T14:10:52.165Z,1547129452.165 [Startup] Stopped
2019-01-10T14:10:52.165Z,1547129452.165 [Startup](DEBUG): Aggregate::uninitialize Startup
2019-01-10T14:10:52.165Z,1547129452.165 [Startup:A.GoToSurface] Stopped
2019-01-10T14:10:52.165Z,1547129452.165 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-01-10T14:10:52.336Z,1547129452.336 [MissionManager](IMPORTANT): Started mission Default
2019-01-10T14:10:52.337Z,1547129452.337 [Default] Running Loop=1
2019-01-10T14:10:52.337Z,1547129452.337 [Default](DEBUG): Aggregate::initialize Default
2019-01-10T14:10:52.337Z,1547129452.337 [Default:B.GoToSurface] Running Loop=1
2019-01-10T14:10:52.337Z,1547129452.337 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-01-10T14:10:52.337Z,1547129452.337 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-01-10T14:10:52.338Z,1547129452.338 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-01-10T14:10:52.338Z,1547129452.338 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-01-10T14:10:52.339Z,1547129452.339 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-01-10T14:10:52.339Z,1547129452.339 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-01-10T14:10:52.340Z,1547129452.340 [Default:A.Wait] Running Loop=1
2019-01-10T14:10:52.340Z,1547129452.340 [Default:A.Wait](DEBUG): Initialize Wait Component.
2019-01-10T14:11:05.683Z,1547129465.683 [Default:A.Wait](INFO): Done Waiting.
2019-01-10T14:11:05.684Z,1547129465.684 [Default:A.Wait] Stopped
2019-01-10T14:11:05.684Z,1547129465.684 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2019-01-10T14:11:06.089Z,1547129466.089 [Default:CheckIn] Running Loop=1
2019-01-10T14:11:06.089Z,1547129466.089 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-01-10T14:11:06.089Z,1547129466.089 [Default:CheckIn:Read_GPS] Running Loop=1
2019-01-10T14:11:06.484Z,1547129466.484 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2019-01-10T14:11:56.263Z,1547129516.263 [DataOverHttps](INFO): Sending 64 bytes from file Logs/20190108T205212/Express0014.lzma
2019-01-10T14:11:57.059Z,1547129517.059 [DataOverHttps](INFO): Moved sent file to Logs/20190108T205212/Express0014.lzma.bak
2019-01-10T14:11:57.060Z,1547129517.060 [DataOverHttps](INFO): SBD MOMSN=9162345
2019-01-10T14:12:42.720Z,1547129562.720 [CommandLine](IMPORTANT): got command run ./Missions/Demo/senddata_direct_test.xml
2019-01-10T14:12:42.721Z,1547129562.721 [MissionManager](INFO): Loading Mission: ./Missions/Demo/senddata_direct_test.xml
2019-01-10T14:12:42.764Z,1547129562.764 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
xmlns:BIT="Tethys/BIT"
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/BIT http://okeanids.mbari.org/tethys/Xml/BIT.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="senddata_direct_test">

    <SendData Service="Direct" Destination="modem:1:_.pressure">
        <Sensor:Onboard.Pressure/><Units:atmosphere/>
    </SendData>
    
    <SendData Service="Direct" Destination="modem:1:_.temperature">
        <Sensor:Onboard.Temperature/><Units:celsius/>
    </SendData>
    
    <SendData Service="Direct" Destination="modem:1:_.humidity">
        <Sensor:Onboard.Humidity/><Units:percent/>
    </SendData>

</Mission>


2019-01-10T14:12:42.766Z,1547129562.766 [CommandLine](IMPORTANT): Running ./Missions/Demo/senddata_direct_test.xml
2019-01-10T14:12:42.781Z,1547129562.781 [Default] Stopped
2019-01-10T14:12:42.781Z,1547129562.781 [Default](DEBUG): Aggregate::uninitialize Default
2019-01-10T14:12:42.782Z,1547129562.782 [Default:B.GoToSurface] Stopped
2019-01-10T14:12:42.782Z,1547129562.782 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-01-10T14:12:42.782Z,1547129562.782 [Default:CheckIn] Stopped
2019-01-10T14:12:42.782Z,1547129562.782 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-01-10T14:12:42.782Z,1547129562.782 [Default:CheckIn:Read_GPS] Stopped
2019-01-10T14:12:42.782Z,1547129562.782 [MissionManager](IMPORTANT): Started mission senddata_direct_test
2019-01-10T14:12:42.782Z,1547129562.782 [senddata_direct_test] Running Loop=1
2019-01-10T14:12:42.782Z,1547129562.782 [senddata_direct_test](DEBUG): Aggregate::initialize senddata_direct_test
2019-01-10T14:12:42.782Z,1547129562.782 [senddata_direct_test:A] Running Loop=1
2019-01-10T14:12:42.784Z,1547129562.784 [senddata_direct_test:A] Stopped
2019-01-10T14:12:42.784Z,1547129562.784 [senddata_direct_test:B] Running Loop=1
2019-01-10T14:12:43.145Z,1547129563.145 [senddata_direct_test:B] Stopped
2019-01-10T14:12:43.145Z,1547129563.145 [senddata_direct_test:C] Running Loop=1
2019-01-10T14:12:43.551Z,1547129563.551 [senddata_direct_test:C] Stopped
2019-01-10T14:12:43.551Z,1547129563.551 [senddata_direct_test](INFO): Completed senddata_direct_test
2019-01-10T14:12:43.551Z,1547129563.551 [MissionManager](INFO): senddata_direct_test is completed.
2019-01-10T14:12:43.551Z,1547129563.551 [MissionManager](INFO): Uninitializing Mission senddata_direct_test
2019-01-10T14:12:43.551Z,1547129563.551 [senddata_direct_test] Stopped
2019-01-10T14:12:43.551Z,1547129563.551 [senddata_direct_test](DEBUG): Aggregate::uninitialize senddata_direct_test
2019-01-10T14:12:43.945Z,1547129563.945 [MissionManager](IMPORTANT): Started mission Default
2019-01-10T14:12:43.945Z,1547129563.945 [Default] Running Loop=1
2019-01-10T14:12:43.945Z,1547129563.945 [Default](DEBUG): Aggregate::initialize Default
2019-01-10T14:12:43.945Z,1547129563.945 [Default:B.GoToSurface] Running Loop=1
2019-01-10T14:12:43.945Z,1547129563.945 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-01-10T14:12:43.946Z,1547129563.946 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-01-10T14:12:43.946Z,1547129563.946 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-01-10T14:12:43.946Z,1547129563.946 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-01-10T14:12:43.947Z,1547129563.947 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-01-10T14:12:43.947Z,1547129563.947 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-01-10T14:12:43.947Z,1547129563.947 [Default:A.Wait] Running Loop=1
2019-01-10T14:12:43.947Z,1547129563.947 [Default:A.Wait](DEBUG): Initialize Wait Component.
2019-01-10T14:12:58.546Z,1547129578.546 [Default:A.Wait](INFO): Done Waiting.
2019-01-10T14:12:58.546Z,1547129578.546 [Default:A.Wait] Stopped
2019-01-10T14:12:58.546Z,1547129578.546 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2019-01-10T14:12:58.691Z,1547129578.691 [Default:CheckIn] Running Loop=1
2019-01-10T14:12:58.692Z,1547129578.692 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-01-10T14:12:58.692Z,1547129578.692 [Default:CheckIn:Read_GPS] Running Loop=1
2019-01-10T14:13:08.569Z,1547129588.569 [NAL9602](FAULT): MT Queue status failed to be acquired within timeout. Will not retry this session.
2019-01-10T14:13:22.949Z,1547129602.949 [CommandLine](IMPORTANT): got command run ./Missions/Demo/senddata_direct_test.xml
2019-01-10T14:13:22.950Z,1547129602.950 [MissionManager](INFO): Loading Mission: ./Missions/Demo/senddata_direct_test.xml
2019-01-10T14:13:23.019Z,1547129603.019 [MissionManager](DEBUG): 
<?xml version="1.0" encoding="UTF-8"?>
<Mission xmlns="Tethys"
xmlns:BIT="Tethys/BIT"
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/BIT http://okeanids.mbari.org/tethys/Xml/BIT.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="senddata_direct_test">

    <SendData Service="Direct" Destination="modem:1:_.pressure">
        <Sensor:Onboard.Pressure/><Units:atmosphere/>
    </SendData>
    
    <SendData Service="Direct" Destination="modem:1:_.temperature">
        <Sensor:Onboard.Temperature/><Units:celsius/>
    </SendData>
    
    <SendData Service="Direct" Destination="modem:1:_.humidity">
        <Sensor:Onboard.Humidity/><Units:percent/>
    </SendData>

</Mission>


2019-01-10T14:13:23.024Z,1547129603.024 [CommandLine](IMPORTANT): Running ./Missions/Demo/senddata_direct_test.xml
2019-01-10T14:13:23.029Z,1547129603.029 [Default] Stopped
2019-01-10T14:13:23.029Z,1547129603.029 [Default](DEBUG): Aggregate::uninitialize Default
2019-01-10T14:13:23.029Z,1547129603.029 [Default:B.GoToSurface] Stopped
2019-01-10T14:13:23.029Z,1547129603.029 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-01-10T14:13:23.029Z,1547129603.029 [Default:CheckIn] Stopped
2019-01-10T14:13:23.029Z,1547129603.029 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-01-10T14:13:23.029Z,1547129603.029 [Default:CheckIn:Read_GPS] Stopped
2019-01-10T14:13:23.029Z,1547129603.029 [MissionManager](IMPORTANT): Started mission senddata_direct_test
2019-01-10T14:13:23.029Z,1547129603.029 [senddata_direct_test] Running Loop=1
2019-01-10T14:13:23.030Z,1547129603.030 [senddata_direct_test](DEBUG): Aggregate::initialize senddata_direct_test
2019-01-10T14:13:23.030Z,1547129603.030 [senddata_direct_test:A] Running Loop=1
2019-01-10T14:13:23.031Z,1547129603.031 [senddata_direct_test:A] Stopped
2019-01-10T14:13:23.031Z,1547129603.031 [senddata_direct_test:B] Running Loop=1
2019-01-10T14:13:23.437Z,1547129603.437 [senddata_direct_test:B] Stopped
2019-01-10T14:13:23.437Z,1547129603.437 [senddata_direct_test:C] Running Loop=1
2019-01-10T14:13:23.830Z,1547129603.830 [senddata_direct_test:C] Stopped
2019-01-10T14:13:23.830Z,1547129603.830 [senddata_direct_test](INFO): Completed senddata_direct_test
2019-01-10T14:13:23.830Z,1547129603.830 [MissionManager](INFO): senddata_direct_test is completed.
2019-01-10T14:13:23.830Z,1547129603.830 [MissionManager](INFO): Uninitializing Mission senddata_direct_test
2019-01-10T14:13:23.830Z,1547129603.830 [senddata_direct_test] Stopped
2019-01-10T14:13:23.831Z,1547129603.831 [senddata_direct_test](DEBUG): Aggregate::uninitialize senddata_direct_test
2019-01-10T14:13:24.222Z,1547129604.222 [MissionManager](IMPORTANT): Started mission Default
2019-01-10T14:13:24.222Z,1547129604.222 [Default] Running Loop=1
2019-01-10T14:13:24.222Z,1547129604.222 [Default](DEBUG): Aggregate::initialize Default
2019-01-10T14:13:24.223Z,1547129604.223 [Default:B.GoToSurface] Running Loop=1
2019-01-10T14:13:24.223Z,1547129604.223 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-01-10T14:13:24.223Z,1547129604.223 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-01-10T14:13:24.223Z,1547129604.223 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-01-10T14:13:24.223Z,1547129604.223 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-01-10T14:13:24.224Z,1547129604.224 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-01-10T14:13:24.224Z,1547129604.224 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-01-10T14:13:24.225Z,1547129604.225 [Default:A.Wait] Running Loop=1
2019-01-10T14:13:24.225Z,1547129604.225 [Default:A.Wait](DEBUG): Initialize Wait Component.
2019-01-10T14:13:28.215Z,1547129608.215 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = 1000343.759005
2019-01-10T14:13:28.215Z,1547129608.215 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 2
2019-01-10T14:13:28.215Z,1547129608.215 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2019-01-10T14:13:28.244Z,1547129608.244 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2019-01-10T14:13:28.633Z,1547129608.633 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2019-01-10T14:13:28.633Z,1547129608.633 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 2
2019-01-10T14:13:29.013Z,1547129609.013 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2019-01-10T14:13:29.013Z,1547129609.013 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2019-01-10T14:13:29.014Z,1547129609.014 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2019-01-10T14:13:37.413Z,1547129617.413 [Default:A.Wait](INFO): Done Waiting.
2019-01-10T14:13:37.413Z,1547129617.413 [Default:A.Wait] Stopped
2019-01-10T14:13:37.414Z,1547129617.414 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2019-01-10T14:13:37.823Z,1547129617.823 [Default:CheckIn] Running Loop=1
2019-01-10T14:13:37.823Z,1547129617.823 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-01-10T14:13:37.824Z,1547129617.824 [Default:CheckIn:Read_GPS] Running Loop=1
2019-01-10T14:15:06.996Z,1547129706.996 [CommandLine](IMPORTANT): got command ?
2019-01-10T14:15:39.245Z,1547129739.245 [CommandLine](IMPORTANT): got command help send
2019-01-10T14:16:29.302Z,1547129789.302 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = 1000524.845957
2019-01-10T14:16:29.302Z,1547129789.302 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 3
2019-01-10T14:16:29.302Z,1547129789.302 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2019-01-10T14:16:29.327Z,1547129789.327 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2019-01-10T14:16:29.777Z,1547129789.777 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2019-01-10T14:16:29.778Z,1547129789.778 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 3
2019-01-10T14:16:30.098Z,1547129790.098 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2019-01-10T14:16:30.099Z,1547129790.099 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2019-01-10T14:16:30.099Z,1547129790.099 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2019-01-10T14:18:07.485Z,1547129887.485 [NAL9602](FAULT): GPS failed to acquire within timeout.
2019-01-10T14:18:07.485Z,1547129887.485 [NAL9602] Data Fault, FailCount= 1
2019-01-10T14:18:07.486Z,1547129887.486 [NAL9602](ERROR): Data Fault
2019-01-10T14:18:07.562Z,1547129887.562 [CBIT](ERROR): Data Fault in component: NAL9602
2019-01-10T14:18:07.892Z,1547129887.892 [NAL9602](INFO): Powering down
2019-01-10T14:18:08.754Z,1547129888.754 [CBIT](INFO): Clearing failed state for component NAL9602
2019-01-10T14:18:08.754Z,1547129888.754 [NAL9602] No Fault, FailCount= 1
2019-01-10T14:18:37.944Z,1547129917.944 [Default:CheckIn:Read_GPS](INFO): Timed out from 2019-01-10T14:13:37.8Z
2019-01-10T14:18:37.962Z,1547129917.962 [Default:CheckIn:Read_GPS] Stopped
2019-01-10T14:18:37.962Z,1547129917.962 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-01-10T14:18:38.281Z,1547129918.281 [NAL9602](INFO): Powering up NAL9602
2019-01-10T14:18:38.332Z,1547129918.332 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-01-10T14:18:43.913Z,1547129923.913 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190110T140709/Courier0004.lzma
2019-01-10T14:18:44.057Z,1547129924.057 [CBIT](INFO): Clearing failed state for component BPC1
2019-01-10T14:18:44.057Z,1547129924.057 [BPC1] No Fault, FailCount= 1
2019-01-10T14:18:44.603Z,1547129924.603 [DataOverHttps](INFO): Moved sent file to Logs/20190110T140709/Courier0004.lzma.bak
2019-01-10T14:18:44.603Z,1547129924.603 [DataOverHttps](INFO): SBD MOMSN=9162363
2019-01-10T14:18:48.758Z,1547129928.758 [NAL9602](INFO): NAL9602 initialized
2019-01-10T14:19:00.472Z,1547129940.472 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20190109T220524/Express0001.lzma
2019-01-10T14:19:01.271Z,1547129941.271 [DataOverHttps](INFO): Moved sent file to Logs/20190109T220524/Express0001.lzma.bak
2019-01-10T14:19:01.271Z,1547129941.271 [DataOverHttps](INFO): SBD MOMSN=9162365
2019-01-10T14:19:17.614Z,1547129957.614 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20190109T231605/Express0001.lzma
2019-01-10T14:19:18.415Z,1547129958.415 [DataOverHttps](INFO): Moved sent file to Logs/20190109T231605/Express0001.lzma.bak
2019-01-10T14:19:18.415Z,1547129958.415 [DataOverHttps](INFO): SBD MOMSN=9162367
2019-01-10T14:19:32.842Z,1547129972.842 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = 1000708.385666
2019-01-10T14:19:32.842Z,1547129972.842 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 4
2019-01-10T14:19:32.842Z,1547129972.842 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2019-01-10T14:19:32.854Z,1547129972.854 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2019-01-10T14:19:32.864Z,1547129972.864 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20190110T135155/Express0001.lzma
2019-01-10T14:19:33.011Z,1547129973.011 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2019-01-10T14:19:33.011Z,1547129973.011 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 4
2019-01-10T14:19:33.322Z,1547129973.322 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2019-01-10T14:19:33.322Z,1547129973.322 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2019-01-10T14:19:33.322Z,1547129973.322 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2019-01-10T14:19:33.663Z,1547129973.663 [DataOverHttps](INFO): Moved sent file to Logs/20190110T135155/Express0001.lzma.bak
2019-01-10T14:19:33.663Z,1547129973.663 [DataOverHttps](INFO): SBD MOMSN=9162369
2019-01-10T14:19:45.635Z,1547129985.635 [DataOverHttps](INFO): Sending 18 bytes from file Logs/20190110T135359/Express0001.lzma
2019-01-10T14:19:46.435Z,1547129986.435 [DataOverHttps](INFO): Moved sent file to Logs/20190110T135359/Express0001.lzma.bak
2019-01-10T14:19:46.435Z,1547129986.435 [DataOverHttps](INFO): SBD MOMSN=9162371
2019-01-10T14:19:52.696Z,1547129992.696 [CommandLine](IMPORTANT): got command show variable Goby
2019-01-10T14:19:52.840Z,1547129992.840 [CommandLine](IMPORTANT): GobyModem.loadAtStartup (bool)
2019-01-10T14:19:52.840Z,1547129992.840 [CommandLine](IMPORTANT): GobyModem.simulateHardware (bool)
2019-01-10T14:19:52.840Z,1547129992.840 [CommandLine](IMPORTANT): GobyModem.modemType (none)
2019-01-10T14:19:52.841Z,1547129992.841 [CommandLine](IMPORTANT): GobyModem.networkIds (none)
2019-01-10T14:19:52.841Z,1547129992.841 [CommandLine](IMPORTANT): GobyModem.maxDistance (kilometer)
2019-01-10T14:19:52.841Z,1547129992.841 [CommandLine](IMPORTANT): GobyModem.transBaud (bit_per_second)
2019-01-10T14:19:52.898Z,1547129992.898 [CommandLine](IMPORTANT): GobyModem.loadControl (none)
2019-01-10T14:19:52.899Z,1547129992.899 [CommandLine](IMPORTANT): GobyModem.uart (none)
2019-01-10T14:19:52.899Z,1547129992.899 [CommandLine](IMPORTANT): GobyModem.baud (bit_per_second)
2019-01-10T14:19:53.809Z,1547129993.809 [BPC1](FAULT): Failed to parse data from all battery packs.
2019-01-10T14:19:53.810Z,1547129993.810 [BPC1] Data Fault, FailCount= 2
2019-01-10T14:19:53.810Z,1547129993.810 [BPC1](ERROR): Data Fault
2019-01-10T14:19:53.847Z,1547129993.847 [CBIT](ERROR): Data Fault in component: BPC1
2019-01-10T14:19:58.751Z,1547129998.751 [DataOverHttps](INFO): Sending 768 bytes from file Logs/20190110T140709/Express0001.lzma
2019-01-10T14:19:59.543Z,1547129999.543 [DataOverHttps](INFO): Moved sent file to Logs/20190110T140709/Express0001.lzma.bak
2019-01-10T14:19:59.544Z,1547129999.544 [DataOverHttps](INFO): SBD MOMSN=9162374
2019-01-10T14:20:13.588Z,1547130013.588 [CommandLine](IMPORTANT): got command get GobyModem.loadAtStartup
2019-01-10T14:20:13.589Z,1547130013.589 [CommandLine](IMPORTANT): GobyModem.loadAtStartup 0 bool
2019-01-10T14:20:15.850Z,1547130015.850 [DataOverHttps](INFO): Sending 323 bytes from file Logs/20190110T140709/Express0005.lzma
2019-01-10T14:20:16.627Z,1547130016.627 [DataOverHttps](INFO): Moved sent file to Logs/20190110T140709/Express0005.lzma.bak
2019-01-10T14:20:16.627Z,1547130016.627 [DataOverHttps](INFO): SBD MOMSN=9162394
2019-01-10T14:20:20.401Z,1547130020.401 [Default:CheckIn:Read_Iridium] Stopped
2019-01-10T14:20:20.401Z,1547130020.401 [Default:CheckIn:C.Wait] Running Loop=1
2019-01-10T14:20:20.401Z,1547130020.401 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-01-10T14:20:25.033Z,1547130025.033 [CommandLine](IMPORTANT): got command get GobyModem.simulateHardware
2019-01-10T14:20:25.033Z,1547130025.033 [CommandLine](IMPORTANT): GobyModem.simulateHardware 0 bool
2019-01-10T14:22:33.543Z,1547130153.543 [DeadReckonUsingSpeedCalculator](ERROR): Will not write estimated position: latitudeAccuracy_ = nan, longitudeAccuracy_ = nan, depthAccuracy_ = 1000889.087275
2019-01-10T14:22:33.543Z,1547130153.543 [DeadReckonUsingSpeedCalculator] Software Fault, FailCount= 5
2019-01-10T14:22:33.544Z,1547130153.544 [DeadReckonUsingSpeedCalculator](ERROR): Software Fault
2019-01-10T14:22:33.572Z,1547130153.572 [CBIT](ERROR): Software Fault in component: DeadReckonUsingSpeedCalculator
2019-01-10T14:22:33.958Z,1547130153.958 [CBIT](INFO): Clearing failed state for component DeadReckonUsingSpeedCalculator
2019-01-10T14:22:33.958Z,1547130153.958 [DeadReckonUsingSpeedCalculator] No Fault, FailCount= 5
2019-01-10T14:22:34.352Z,1547130154.352 [DeadReckonUsingSpeedCalculator](DEBUG): Initializing DeadReckonUsingSpeedCalculator component.
2019-01-10T14:22:34.357Z,1547130154.357 [DeadReckonUsingSpeedCalculator](INFO): Will consider orientation measurement stale after 120s.
2019-01-10T14:22:34.357Z,1547130154.357 [DeadReckonUsingSpeedCalculator](INFO): Will consider velocity measurement stale after 20s.
2019-01-10T14:23:41.104Z,1547130221.104 [CommandLine](IMPORTANT): got command restart system
2019-01-10T14:23:43.680Z,1547130223.680 [Supervisor](INFO): Stop Mission called by Supervisor::terminate
2019-01-10T14:23:43.684Z,1547130223.684 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2019-01-10T14:23:43.684Z,1547130223.684 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-01-10T14:23:43.880Z,1547130223.880 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2019-01-10T14:23:43.880Z,1547130223.880 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-01-10T14:23:43.881Z,1547130223.881 [CommandLine](INFO): Join timeout helper Thread ID is 4927
2019-01-10T14:23:43.886Z,1547130223.886 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2019-01-10T14:23:43.886Z,1547130223.886 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-01-10T14:23:43.886Z,1547130223.886 [NavChartDb](INFO): Join timeout helper Thread ID is 4928
2019-01-10T14:23:44.096Z,1547130224.096 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2019-01-10T14:23:44.096Z,1547130224.096 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-01-10T14:23:44.104Z,1547130224.104 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2019-01-10T14:23:44.104Z,1547130224.104 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2019-01-10T14:23:44.104Z,1547130224.104 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 4929
2019-01-10T14:23:44.501Z,1547130224.501 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2019-01-10T14:23:44.501Z,1547130224.501 [WetLabsBB2FL](INFO): Powering down
2019-01-10T14:23:44.502Z,1547130224.502 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2019-01-10T14:23:44.516Z,1547130224.516 [ComponentRegistry](INFO): Shutting down Rowe_600LCM ThreadHandler
2019-01-10T14:23:44.516Z,1547130224.516 [Rowe_600LCM ThreadHandler](INFO): Thread cancelled.
2019-01-10T14:23:44.517Z,1547130224.517 [Rowe_600LCM](INFO): Join timeout helper Thread ID is 4930
2019-01-10T14:23:44.528Z,1547130224.528 [Rowe_600LCM ThreadHandler](INFO): Uninitializing protected caller thread.
2019-01-10T14:23:44.528Z,1547130224.528 [Rowe_600LCM](INFO): Stopping potential previous instance(s) of roweadcp LCM interface
2019-01-10T14:23:44.699Z,1547130224.699 [Rowe_600LCM](INFO): Powering down
2019-01-10T14:23:44.700Z,1547130224.700 [Rowe_600LCM ThreadHandler](INFO): Thread cancelled.
2019-01-10T14:23:44.701Z,1547130224.701 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2019-01-10T14:23:44.701Z,1547130224.701 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-01-10T14:23:44.702Z,1547130224.702 [Radio_Surface](INFO): Join timeout helper Thread ID is 4932
2019-01-10T14:23:45.076Z,1547130225.076 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2019-01-10T14:23:45.077Z,1547130225.077 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-01-10T14:23:45.081Z,1547130225.081 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2019-01-10T14:23:45.081Z,1547130225.081 [logger ThreadHandler](INFO): Thread cancelled.
2019-01-10T14:23:45.082Z,1547130225.082 [logger](INFO): Join timeout helper Thread ID is 4933
2019-01-10T14:23:45.082Z,1547130225.082 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2019-01-10T14:23:45.082Z,1547130225.082 [logger ThreadHandler](INFO): Thread cancelled.
2019-01-10T14:23:45.101Z,1547130225.101 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2019-01-10T14:23:45.101Z,1547130225.101 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-01-10T14:23:45.101Z,1547130225.101 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2019-01-10T14:23:45.101Z,1547130225.101 [controlThread ThreadHandler](INFO): Thread cancelled.
2019-01-10T14:23:45.101Z,1547130225.101 [controlThread](INFO): Join timeout helper Thread ID is 4934
2019-01-10T14:23:45.408Z,1547130225.408 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2019-01-10T14:23:45.408Z,1547130225.408 [controlThread](DEBUG): Uninitializing ControlThread
2019-01-10T14:23:45.409Z,1547130225.409 [AcousticModem_Benthos_ATM900](INFO): Powering down
2019-01-10T14:23:45.529Z,1547130225.529 [NAL9602](INFO): Powering down
2019-01-10T14:23:45.531Z,1547130225.531 [PNI_TCM](INFO): Powering down
2019-01-10T14:23:45.622Z,1547130225.622 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2019-01-10T14:23:45.623Z,1547130225.623 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2019-01-10T14:23:45.624Z,1547130225.624 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2019-01-10T14:23:45.624Z,1547130225.624 [MissionManager](INFO): Uninitializing Mission Default
2019-01-10T14:23:45.625Z,1547130225.625 [Default] Stopped
2019-01-10T14:23:45.625Z,1547130225.625 [Default](DEBUG): Aggregate::uninitialize Default
2019-01-10T14:23:45.625Z,1547130225.625 [Default:B.GoToSurface] Stopped
2019-01-10T14:23:45.625Z,1547130225.625 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-01-10T14:23:45.625Z,1547130225.625 [Default:CheckIn] Stopped
2019-01-10T14:23:45.625Z,1547130225.625 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-01-10T14:23:45.625Z,1547130225.625 [Default:CheckIn:C.Wait] Stopped
2019-01-10T14:23:45.625Z,1547130225.625 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-01-10T14:23:45.629Z,1547130225.629 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2019-01-10T14:23:45.629Z,1547130225.629 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2019-01-10T14:23:45.629Z,1547130225.629 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2019-01-10T14:23:45.630Z,1547130225.630 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2019-01-10T14:23:45.630Z,1547130225.630 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2019-01-10T14:23:45.630Z,1547130225.630 [BuoyancyServo](INFO): Powering down
2019-01-10T14:23:45.644Z,1547130225.644 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2019-01-10T14:23:45.644Z,1547130225.644 [ElevatorServo](INFO): Powering down
2019-01-10T14:23:45.645Z,1547130225.645 [MassServo](DEBUG): Uninitialize Mass Servo.
2019-01-10T14:23:45.645Z,1547130225.645 [MassServo](INFO): Powering down
2019-01-10T14:23:45.646Z,1547130225.646 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2019-01-10T14:23:45.646Z,1547130225.646 [RudderServo](INFO): Powering down
2019-01-10T14:23:45.647Z,1547130225.647 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2019-01-10T14:23:45.647Z,1547130225.647 [ThrusterServo](INFO): Powering down
2019-01-10T14:23:45.648Z,1547130225.648 [SBIT](DEBUG): Uninitialize SBIT Component.
2019-01-10T14:23:45.649Z,1547130225.649 [IBIT](DEBUG): Uninitialize IBIT Component.
2019-01-10T14:23:45.649Z,1547130225.649 [CBIT](DEBUG): Uninitialize CBIT Component.
2019-01-10T14:23:45.649Z,1547130225.649 [CBIT](DEBUG): Powering off loads.
2019-01-10T14:23:45.660Z,1547130225.660 [CBIT](DEBUG): Disabling WDT.
2019-01-10T14:23:45.672Z,1547130225.672 [CBIT](DEBUG): Opening all GF detection circuits.
2019-01-10T14:23:45.673Z,1547130225.673 [controlThread ThreadHandler](INFO): Thread cancelled.
2019-01-10T14:23:45.760Z,1547130225.760 [Rowe_600LCM ThreadHandler](INFO): Thread cancelled.
2019-01-10T14:23:45.766Z,1547130225.766 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-01-10T14:23:46.035Z,1547130226.035 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2019-01-10T14:23:46.083Z,1547130226.083 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-01-10T14:23:46.143Z,1547130226.143 [logger ThreadHandler](INFO): Thread cancelled.