2019-04-04T16:59:42.986Z,1554397182.986 [Supervisor](DEBUG): Initializing supervisor.
2019-04-04T16:59:42.989Z,1554397182.989 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2019-04-04T16:59:42.990Z,1554397182.990 [SyncHandler](INFO): Protected caller Thread ID is 6712
2019-04-04T16:59:42.990Z,1554397182.990 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2019-04-04T16:59:42.991Z,1554397182.991 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2019-04-04T16:59:42.991Z,1554397182.991 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 6713
2019-04-04T16:59:42.994Z,1554397182.994 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2019-04-04T16:59:43.006Z,1554397183.006 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2019-04-04T16:59:43.007Z,1554397183.007 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2019-04-04T16:59:43.007Z,1554397183.007 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 6714
2019-04-04T16:59:43.008Z,1554397183.008 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2019-04-04T16:59:43.009Z,1554397183.009 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2019-04-04T16:59:43.010Z,1554397183.010 [logger ThreadHandler](INFO): Protected caller Thread ID is 6715
2019-04-04T16:59:43.012Z,1554397183.012 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2019-04-04T16:59:43.012Z,1554397183.012 [Supervisor](INFO): Looking for Config files in directory: Config/
2019-04-04T16:59:43.016Z,1554397183.016 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2019-04-04T16:59:43.509Z,1554397183.509 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2019-04-04T16:59:43.510Z,1554397183.510 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2019-04-04T16:59:43.610Z,1554397183.610 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2019-04-04T16:59:43.612Z,1554397183.612 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2019-04-04T16:59:43.964Z,1554397183.964 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2019-04-04T16:59:44.099Z,1554397184.099 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2019-04-04T16:59:44.252Z,1554397184.252 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2019-04-04T16:59:44.254Z,1554397184.254 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2019-04-04T16:59:44.452Z,1554397184.452 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2019-04-04T16:59:44.454Z,1554397184.454 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2019-04-04T16:59:44.926Z,1554397184.926 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2019-04-04T16:59:44.927Z,1554397184.927 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2019-04-04T16:59:45.253Z,1554397185.253 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2019-04-04T16:59:45.254Z,1554397185.254 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2019-04-04T16:59:45.403Z,1554397185.403 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2019-04-04T16:59:45.405Z,1554397185.405 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2019-04-04T16:59:45.608Z,1554397185.608 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2019-04-04T16:59:45.609Z,1554397185.609 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2019-04-04T16:59:45.707Z,1554397185.707 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2019-04-04T16:59:45.707Z,1554397185.707 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2019-04-04T16:59:46.055Z,1554397186.055 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2019-04-04T16:59:46.057Z,1554397186.057 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2019-04-04T16:59:46.139Z,1554397186.139 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2019-04-04T16:59:46.244Z,1554397186.244 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2019-04-04T16:59:46.245Z,1554397186.245 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2019-04-04T16:59:46.764Z,1554397186.764 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2019-04-04T16:59:46.764Z,1554397186.764 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2019-04-04T16:59:47.172Z,1554397187.172 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2019-04-04T16:59:47.174Z,1554397187.174 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-whoidhs/
2019-04-04T16:59:47.176Z,1554397187.176 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/vehicle.cfg
2019-04-04T16:59:47.392Z,1554397187.392 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Control.cfg
2019-04-04T16:59:47.497Z,1554397187.497 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/BIT.cfg
2019-04-04T16:59:47.599Z,1554397187.599 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Battery.cfg
2019-04-04T16:59:47.834Z,1554397187.834 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2019-04-04T16:59:47.835Z,1554397187.835 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Simulator.cfg
2019-04-04T16:59:47.923Z,1554397187.923 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Navigation.cfg
2019-04-04T16:59:48.018Z,1554397188.018 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/logger.cfg
2019-04-04T16:59:48.118Z,1554397188.118 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/secure.cfg
2019-04-04T16:59:48.203Z,1554397188.203 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Servo.cfg
2019-04-04T16:59:48.319Z,1554397188.319 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Sensor.cfg
2019-04-04T16:59:48.507Z,1554397188.507 [Supervisor](INFO): Opening Config file at: Config/lrauv-whoidhs/Science.cfg
2019-04-04T16:59:48.643Z,1554397188.643 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2019-04-04T16:59:48.655Z,1554397188.655 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2019-04-04T16:59:49.026Z,1554397189.026 [AHRS_M2] Loaded
2019-04-04T16:59:49.027Z,1554397189.027 [ComponentRegistry](DEBUG): SyncComponent "AHRS_M2" handled in the control thread.
2019-04-04T16:59:49.100Z,1554397189.100 [DataOverHttps] Loaded
2019-04-04T16:59:49.100Z,1554397189.100 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2019-04-04T16:59:49.101Z,1554397189.101 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 4075B4E0
2019-04-04T16:59:49.102Z,1554397189.102 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 6794
2019-04-04T16:59:49.115Z,1554397189.115 [Depth_Keller] Loaded
2019-04-04T16:59:49.115Z,1554397189.115 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2019-04-04T16:59:49.120Z,1554397189.120 [DropWeight] Loaded
2019-04-04T16:59:49.120Z,1554397189.120 [ComponentRegistry](DEBUG): SyncComponent "DropWeight" handled in the control thread.
2019-04-04T16:59:49.173Z,1554397189.173 [DUSBL_Hydroid] Loaded
2019-04-04T16:59:49.173Z,1554397189.173 [ComponentRegistry](DEBUG): SyncComponent "DUSBL_Hydroid" handled in the control thread.
2019-04-04T16:59:49.213Z,1554397189.213 [Micromodem] Loaded
2019-04-04T16:59:49.214Z,1554397189.214 [ComponentRegistry](DEBUG): SyncComponent "Micromodem" handled in the control thread.
2019-04-04T16:59:49.312Z,1554397189.312 [NAL9602] Loaded
2019-04-04T16:59:49.312Z,1554397189.312 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2019-04-04T16:59:49.328Z,1554397189.328 [Onboard] Loaded
2019-04-04T16:59:49.328Z,1554397189.328 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2019-04-04T16:59:49.334Z,1554397189.334 [PowerOnly] Loaded
2019-04-04T16:59:49.334Z,1554397189.334 [ComponentRegistry](DEBUG): SyncComponent "PowerOnly" handled in the control thread.
2019-04-04T16:59:49.341Z,1554397189.341 [Radio_Surface] Loaded
2019-04-04T16:59:49.341Z,1554397189.341 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2019-04-04T16:59:49.342Z,1554397189.342 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 4078B4E0
2019-04-04T16:59:49.342Z,1554397189.342 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 6795
2019-04-04T16:59:49.387Z,1554397189.387 [RDI_Pathfinder] Loaded
2019-04-04T16:59:49.387Z,1554397189.387 [ComponentRegistry](DEBUG): SyncComponent "RDI_Pathfinder" handled in the control thread.
2019-04-04T16:59:51.821Z,1554397191.821 [BPC1] Loaded
2019-04-04T16:59:51.821Z,1554397191.821 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2019-04-04T16:59:51.821Z,1554397191.821 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2019-04-04T16:59:51.822Z,1554397191.822 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2019-04-04T16:59:51.835Z,1554397191.835 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2019-04-04T16:59:51.835Z,1554397191.835 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2019-04-04T16:59:51.941Z,1554397191.941 [DeadReckonUsingMultipleVelocitySources] Loaded
2019-04-04T16:59:51.941Z,1554397191.941 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2019-04-04T16:59:51.962Z,1554397191.962 [NavChart] Loaded
2019-04-04T16:59:51.962Z,1554397191.962 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2019-04-04T16:59:51.966Z,1554397191.966 [UniversalFixResidualReporter] Loaded
2019-04-04T16:59:51.966Z,1554397191.966 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2019-04-04T16:59:51.967Z,1554397191.967 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2019-04-04T16:59:51.967Z,1554397191.967 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2019-04-04T16:59:52.067Z,1554397192.067 [BuoyancyServo] Loaded
2019-04-04T16:59:52.068Z,1554397192.068 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2019-04-04T16:59:52.083Z,1554397192.083 [ElevatorServo] Loaded
2019-04-04T16:59:52.083Z,1554397192.083 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2019-04-04T16:59:52.098Z,1554397192.098 [MassServo] Loaded
2019-04-04T16:59:52.098Z,1554397192.098 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2019-04-04T16:59:52.114Z,1554397192.114 [RudderServo] Loaded
2019-04-04T16:59:52.114Z,1554397192.114 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2019-04-04T16:59:52.129Z,1554397192.129 [ThrusterServo] Loaded
2019-04-04T16:59:52.129Z,1554397192.129 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2019-04-04T16:59:52.129Z,1554397192.129 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2019-04-04T16:59:52.130Z,1554397192.130 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2019-04-04T16:59:52.377Z,1554397192.377 [CTD_NeilBrown] Loaded
2019-04-04T16:59:52.377Z,1554397192.377 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2019-04-04T16:59:52.378Z,1554397192.378 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 408D04E0
2019-04-04T16:59:52.378Z,1554397192.378 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 6796
2019-04-04T16:59:52.423Z,1554397192.423 [WetLabsSeaOWL_UV_A] Loaded
2019-04-04T16:59:52.423Z,1554397192.423 [ComponentRegistry](DEBUG): Component "WetLabsSeaOWL_UV_A" handled in its own thread.
2019-04-04T16:59:52.424Z,1554397192.424 [WetLabsSeaOWL_UV_A ThreadHandler](DEBUG): Created PCaller Thread at 409004E0
2019-04-04T16:59:52.425Z,1554397192.425 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Protected caller Thread ID is 6797
2019-04-04T16:59:52.425Z,1554397192.425 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2019-04-04T16:59:52.426Z,1554397192.426 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2019-04-04T16:59:52.698Z,1554397192.698 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2019-04-04T16:59:52.698Z,1554397192.698 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2019-04-04T16:59:52.739Z,1554397192.739 [DepthRateCalculator] Loaded
2019-04-04T16:59:52.740Z,1554397192.740 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2019-04-04T16:59:52.745Z,1554397192.745 [PitchRateCalculator] Loaded
2019-04-04T16:59:52.746Z,1554397192.746 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2019-04-04T16:59:52.758Z,1554397192.758 [SpeedCalculator] Loaded
2019-04-04T16:59:52.758Z,1554397192.758 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2019-04-04T16:59:52.779Z,1554397192.779 [TempGradientCalculator] Loaded
2019-04-04T16:59:52.779Z,1554397192.779 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2019-04-04T16:59:52.785Z,1554397192.785 [YawRateCalculator] Loaded
2019-04-04T16:59:52.785Z,1554397192.785 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2019-04-04T16:59:52.826Z,1554397192.826 [ElevatorOffsetCalculator] Loaded
2019-04-04T16:59:52.826Z,1554397192.826 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2019-04-04T16:59:52.826Z,1554397192.826 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2019-04-04T16:59:52.827Z,1554397192.827 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2019-04-04T16:59:52.961Z,1554397192.961 [SBIT](DEBUG): Construct Startup Built In Test.
2019-04-04T16:59:52.984Z,1554397192.984 [SBIT] Loaded
2019-04-04T16:59:52.984Z,1554397192.984 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2019-04-04T16:59:52.985Z,1554397192.985 [IBIT](DEBUG): Construct Initiated Built In Test.
2019-04-04T16:59:52.997Z,1554397192.997 [IBIT] Loaded
2019-04-04T16:59:52.997Z,1554397192.997 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2019-04-04T16:59:53.000Z,1554397193.000 [CBIT](DEBUG): Construct Continuous Built In Test.
2019-04-04T16:59:53.139Z,1554397193.139 [CBIT] Loaded
2019-04-04T16:59:53.140Z,1554397193.140 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2019-04-04T16:59:53.140Z,1554397193.140 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2019-04-04T16:59:53.141Z,1554397193.141 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2019-04-04T16:59:53.210Z,1554397193.210 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2019-04-04T16:59:53.210Z,1554397193.210 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2019-04-04T16:59:53.308Z,1554397193.308 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2019-04-04T16:59:53.309Z,1554397193.309 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2019-04-04T16:59:53.374Z,1554397193.374 [VerticalControl](DEBUG): Construct VerticalControl.
2019-04-04T16:59:53.459Z,1554397193.459 [VerticalControl] Loaded
2019-04-04T16:59:53.460Z,1554397193.460 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2019-04-04T16:59:53.460Z,1554397193.460 [HorizontalControl](DEBUG): Construct HorizontalControl.
2019-04-04T16:59:53.517Z,1554397193.517 [HorizontalControl] Loaded
2019-04-04T16:59:53.518Z,1554397193.518 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2019-04-04T16:59:53.518Z,1554397193.518 [SpeedControl](DEBUG): Construct SpeedControl.
2019-04-04T16:59:53.520Z,1554397193.520 [SpeedControl] Loaded
2019-04-04T16:59:53.520Z,1554397193.520 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2019-04-04T16:59:53.521Z,1554397193.521 [LoopControl](DEBUG): Construct LoopControl.
2019-04-04T16:59:53.522Z,1554397193.522 [LoopControl] Loaded
2019-04-04T16:59:53.522Z,1554397193.522 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2019-04-04T16:59:53.522Z,1554397193.522 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2019-04-04T16:59:53.523Z,1554397193.523 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2019-04-04T16:59:53.550Z,1554397193.550 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2019-04-04T16:59:53.554Z,1554397193.554 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2019-04-04T16:59:53.555Z,1554397193.555 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2019-04-04T16:59:53.562Z,1554397193.562 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2019-04-04T16:59:53.563Z,1554397193.563 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40AD04E0
2019-04-04T16:59:53.563Z,1554397193.563 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 6798
2019-04-04T16:59:53.568Z,1554397193.568 [Supervisor](INFO): Main Thread ID is 801
2019-04-04T16:59:53.568Z,1554397193.568 [Supervisor](DEBUG): Running supervisor.
2019-04-04T16:59:53.569Z,1554397193.569 [CommandLine ThreadHandler](INFO): Handler Thread ID is 6799
2019-04-04T16:59:53.571Z,1554397193.571 [controlThread ThreadHandler](INFO): Handler Thread ID is 6800
2019-04-04T16:59:53.572Z,1554397193.572 [controlThread](DEBUG): Initializing ControlThread
2019-04-04T16:59:53.581Z,1554397193.581 [NavChart](DEBUG): Initialize NavChart Navigation.
2019-04-04T16:59:53.581Z,1554397193.581 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2019-04-04T16:59:53.582Z,1554397193.582 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2019-04-04T16:59:53.583Z,1554397193.583 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2019-04-04T16:59:53.583Z,1554397193.583 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2019-04-04T16:59:53.583Z,1554397193.583 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2019-04-04T16:59:53.584Z,1554397193.584 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2019-04-04T16:59:53.584Z,1554397193.584 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2019-04-04T16:59:53.585Z,1554397193.585 [SBIT](INFO): Initialize SBIT Component.
2019-04-04T16:59:53.585Z,1554397193.585 [SBIT](IMPORTANT): git: 2019-04-03_docking
2019-04-04T16:59:53.585Z,1554397193.585 [SBIT](INFO): git hash: 4133750a826247d6fa9b310476a882604c466498
2019-04-04T16:59:53.586Z,1554397193.586 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2019-04-04T16:59:53.586Z,1554397193.586 [SBIT](IMPORTANT): Kernel Version:#2 PREEMPT Thu Jan 11 20:13:48 PST 2018
2019-04-04T16:59:53.587Z,1554397193.587 [SBIT](INFO): Beginning SBIT in 44.000000 seconds.
2019-04-04T16:59:53.587Z,1554397193.587 [IBIT](INFO): Initialize IBIT Component.
2019-04-04T16:59:53.588Z,1554397193.588 [CBIT](DEBUG): Initialize CBIT Component.
2019-04-04T16:59:53.589Z,1554397193.589 [logger ThreadHandler](INFO): Handler Thread ID is 6801
2019-04-04T16:59:53.601Z,1554397193.601 [CBIT](DEBUG): Initialized mux pins.
2019-04-04T16:59:53.601Z,1554397193.601 [CBIT](DEBUG): Initializing the watchdog timer.
2019-04-04T16:59:53.609Z,1554397193.609 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 6802
2019-04-04T16:59:53.610Z,1554397193.610 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2019-04-04T16:59:53.621Z,1554397193.621 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 6803
2019-04-04T16:59:53.625Z,1554397193.625 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2019-04-04T16:59:53.625Z,1554397193.625 [CBIT](DEBUG): Initializing heartbeat.
2019-04-04T16:59:53.641Z,1554397193.641 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 6804
2019-04-04T16:59:53.642Z,1554397193.642 [CTD_NeilBrown](INFO): Powering down
2019-04-04T16:59:53.677Z,1554397193.677 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Handler Thread ID is 6805
2019-04-04T16:59:53.678Z,1554397193.678 [WetLabsSeaOWL_UV_A](INFO): Powering down
2019-04-04T16:59:53.697Z,1554397193.697 [CBIT](DEBUG): Deactivating GF circuits.
2019-04-04T16:59:53.697Z,1554397193.697 [CBIT](DEBUG): Deactivating emergency mode.
2019-04-04T16:59:53.709Z,1554397193.709 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 6806
2019-04-04T16:59:53.716Z,1554397193.716 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2019-04-04T16:59:53.716Z,1554397193.716 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2019-04-04T16:59:53.716Z,1554397193.716 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2019-04-04T16:59:53.717Z,1554397193.717 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2019-04-04T16:59:53.717Z,1554397193.717 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2019-04-04T16:59:53.717Z,1554397193.717 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2019-04-04T16:59:53.717Z,1554397193.717 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2019-04-04T16:59:53.717Z,1554397193.717 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2019-04-04T16:59:53.718Z,1554397193.718 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2019-04-04T16:59:53.718Z,1554397193.718 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2019-04-04T16:59:53.718Z,1554397193.718 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2019-04-04T16:59:53.718Z,1554397193.718 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2019-04-04T16:59:53.718Z,1554397193.718 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2019-04-04T16:59:53.719Z,1554397193.719 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2019-04-04T16:59:53.719Z,1554397193.719 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2019-04-04T16:59:53.719Z,1554397193.719 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2019-04-04T16:59:53.733Z,1554397193.733 [CBIT](DEBUG): Backplane powered.
2019-04-04T16:59:53.733Z,1554397193.733 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2019-04-04T16:59:53.735Z,1554397193.735 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2019-04-04T16:59:53.736Z,1554397193.736 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2019-04-04T16:59:53.736Z,1554397193.736 [LoopControl](DEBUG): Initialize LoopControlComponent.
2019-04-04T16:59:53.737Z,1554397193.737 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2019-04-04T16:59:53.750Z,1554397193.750 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2019-04-04T16:59:53.785Z,1554397193.785 [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-04-04T16:59:53.786Z,1554397193.786 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2019-04-04T16:59:53.878Z,1554397193.878 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2019-04-04T16:59:53.879Z,1554397193.879 [Default:A.Wait](DEBUG): Construct Wait.
2019-04-04T16:59:53.881Z,1554397193.881 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2019-04-04T16:59:53.912Z,1554397193.912 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2019-04-04T16:59:53.930Z,1554397193.930 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2019-04-04T16:59:53.936Z,1554397193.936 [Default:E.Execute](DEBUG): Construct Execute.
2019-04-04T16:59:53.967Z,1554397193.967 [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-04-04T16:59:53.972Z,1554397193.972 [controlThread](DEBUG): Component order: CycleStarter,AHRS_M2,Depth_Keller,DropWeight,DUSBL_Hydroid,Micromodem,NAL9602,Onboard,PowerOnly,RDI_Pathfinder,BPC1,Depth_Keller,DepthRateCalculator,PitchRateCalculator,SpeedCalculator,TempGradientCalculator,YawRateCalculator,ElevatorOffsetCalculator,DeadReckonUsingMultipleVelocitySources,NavChart,UniversalFixResidualReporter,MissionManager,VerticalControl,HorizontalControl,SpeedControl,LoopControl,BuoyancyServo,ElevatorServo,MassServo,RudderServo,ThrusterServo,SBIT,IBIT,CBIT,Reporter,LogSplitter,
2019-04-04T16:59:53.978Z,1554397193.978 [AHRS_M2](DEBUG): Initializing AHRS_M2.
2019-04-04T16:59:54.025Z,1554397194.025 [Radio_Surface](INFO): Powering up
2019-04-04T16:59:54.027Z,1554397194.027 [DUSBL_Hydroid](INFO): Powering up
2019-04-04T16:59:54.027Z,1554397194.027 [DUSBL_Hydroid](DEBUG): Initializing DUSBL_Hydroid.
2019-04-04T16:59:54.116Z,1554397194.116 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2019-04-04T16:59:54.125Z,1554397194.125 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2019-04-04T16:59:54.126Z,1554397194.126 [ElevatorServo](DEBUG): Initializing EZServoServo.
2019-04-04T16:59:54.133Z,1554397194.133 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2019-04-04T16:59:54.134Z,1554397194.134 [MassServo](DEBUG): Initializing EZServoServo.
2019-04-04T16:59:54.141Z,1554397194.141 [MassServo](DEBUG): Initializing MassServo.
2019-04-04T16:59:54.142Z,1554397194.142 [RudderServo](DEBUG): Initializing EZServoServo.
2019-04-04T16:59:54.149Z,1554397194.149 [RudderServo](DEBUG): Initializing RudderServo.
2019-04-04T16:59:54.150Z,1554397194.150 [ThrusterServo](DEBUG): Initializing EZServoServo.
2019-04-04T16:59:54.157Z,1554397194.157 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2019-04-04T16:59:54.402Z,1554397194.402 [Depth_Keller](ERROR): Pressure reading out of range: 1913.424561 decibar
2019-04-04T16:59:54.404Z,1554397194.404 [Micromodem](INFO): Powering up
2019-04-04T16:59:54.404Z,1554397194.404 [Micromodem](DEBUG): Initializing Micromodem.
2019-04-04T16:59:55.117Z,1554397195.117 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2019-04-04T16:59:55.117Z,1554397195.117 [RudderServo](FAULT): Rudder failed to initialize
2019-04-04T16:59:55.117Z,1554397195.117 [RudderServo] Communications Fault, FailCount= 1
2019-04-04T16:59:55.117Z,1554397195.117 [RudderServo](ERROR): Communications Fault
2019-04-04T16:59:55.228Z,1554397195.228 [CBIT](ERROR): Communications Fault in component: RudderServo
2019-04-04T16:59:55.386Z,1554397195.386 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2019-04-04T16:59:55.386Z,1554397195.386 [RudderServo](INFO): Powering down
2019-04-04T16:59:56.073Z,1554397196.073 [RudderServo](DEBUG): Initializing EZServoServo.
2019-04-04T16:59:56.194Z,1554397196.194 [RudderServo](DEBUG): Initializing RudderServo.
2019-04-04T16:59:56.198Z,1554397196.198 [CBIT](INFO): Clearing failed state for component RudderServo
2019-04-04T16:59:56.198Z,1554397196.198 [RudderServo] No Fault, FailCount= 1
2019-04-04T16:59:59.315Z,1554397199.315 [Micromodem](INFO): Nmea out: $CCCFG,ALL,0*33

2019-04-04T17:00:01.335Z,1554397201.335 [Micromodem](INFO): Nmea out: $CCCFG,SRC,1*31

2019-04-04T17:00:07.393Z,1554397207.393 [RDI_Pathfinder](ERROR): Failed to parse:Pathfinder
2019-04-04T17:00:09.387Z,1554397209.387 [Micromodem](INFO): Nmea out: $CCCFG,nav.dt.txtrig_gpio4,1*64

2019-04-04T17:00:12.227Z,1554397212.227 [DUSBL_Hydroid](INFO): DUSBL Version:O
2019-04-04T17:00:19.480Z,1554397219.480 [Micromodem](INFO): Nmea out: $CCCFG,BND,1*3B

2019-04-04T17:00:19.482Z,1554397219.482 [NAL9602](INFO): Powering up NAL9602
2019-04-04T17:00:29.580Z,1554397229.580 [Micromodem](INFO): Nmea out: $CCTMS,2019-04-04T17:00:30Z,0*7B

2019-04-04T17:00:30.388Z,1554397230.388 [NAL9602](INFO): NAL9602 initialized
2019-04-04T17:00:31.217Z,1554397231.217 [NAL9602](DEBUG): Fix Requested
2019-04-04T17:00:38.111Z,1554397238.111 [SBIT](IMPORTANT): Beginning Startup BIT
2019-04-04T17:00:38.135Z,1554397238.135 [CBIT](IMPORTANT): Beginning ground fault scan
2019-04-04T17:00:45.449Z,1554397245.449 [NAL9602](INFO): SBD MO Status=0, MOMSN=2752, MT Status=0, MTMSN=0
2019-04-04T17:00:45.449Z,1554397245.449 [NAL9602](INFO): No messages in MT queue
2019-04-04T17:00:46.269Z,1554397246.269 [NAL9602](DEBUG): Fix Requested
2019-04-04T17:00:49.101Z,1554397249.101 [NAL9602](DEBUG): Fix Requested
2019-04-04T17:00:49.200Z,1554397249.200 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): -0.016519
CHAN A1 (24V): -0.026495
CHAN A2 (12V): -0.006968
CHAN A3 (5V): -0.001933
CHAN B0 (3.3V): 0.000388
CHAN B1 (3.15aV): -0.000208
CHAN B2 (3.15bV): -0.000139
CHAN B3 (GND): 0.001945
OPEN: 0.006036
Full Scale Calc: 4.765 mA, -1.589 mA
2019-04-04T17:00:51.933Z,1554397251.933 [NAL9602](DEBUG): Fix Requested
2019-04-04T17:00:54.917Z,1554397254.917 [NAL9602](DEBUG): Fix Requested
2019-04-04T17:00:57.741Z,1554397257.741 [NAL9602](DEBUG): Fix Requested
2019-04-04T17:01:00.216Z,1554397260.216 [RDI_Pathfinder](ERROR): only read 0 of 1 data item for BIT error
2019-04-04T17:01:00.216Z,1554397260.216 [RDI_Pathfinder](ERROR): Failed to parse:
:TS,1904041009341V
2019-04-04T17:01:00.973Z,1554397260.973 [NAL9602](DEBUG): Fix Requested
2019-04-04T17:01:03.801Z,1554397263.801 [NAL9602](DEBUG): Fix Requested
2019-04-04T17:01:07.033Z,1554397267.033 [NAL9602](DEBUG): Fix Requested
2019-04-04T17:01:09.857Z,1554397269.857 [NAL9602](DEBUG): Fix Requested
2019-04-04T17:01:13.089Z,1554397273.089 [NAL9602](DEBUG): Fix Requested
2019-04-04T17:01:15.917Z,1554397275.917 [NAL9602](DEBUG): Fix Requested
2019-04-04T17:01:19.158Z,1554397279.158 [NAL9602](DEBUG): Fix Requested
2019-04-04T17:01:21.681Z,1554397281.681 [NAL9602](DEBUG): Fix Requested
2019-04-04T17:01:24.913Z,1554397284.913 [NAL9602](DEBUG): Fix Requested
2019-04-04T17:01:27.737Z,1554397287.737 [NAL9602](DEBUG): Fix Requested
2019-04-04T17:01:30.965Z,1554397290.965 [NAL9602](DEBUG): Fix Requested
2019-04-04T17:01:31.410Z,1554397291.410 [SBIT](IMPORTANT): SBIT PASSED
2019-04-04T17:01:31.458Z,1554397291.458 [CommandLine](IMPORTANT): got command configSet list
2019-04-04T17:01:31.458Z,1554397291.458 [CommandLine](IMPORTANT): Listing configuration overrides from Data/persisted.cfg
2019-04-04T17:01:31.459Z,1554397291.459 [CommandLine](IMPORTANT): DUSBL_Hydroid.detectionThreshold=75 count;

2019-04-04T17:01:31.459Z,1554397291.459 [CommandLine](IMPORTANT): Express linearApproximation DUSBL_Hydroid.range 2.000000 meter;

2019-04-04T17:01:31.459Z,1554397291.459 [CommandLine](IMPORTANT): Express linearApproximation DUSBL_Hydroid.xAngle 2.000000 angular_degree;

2019-04-04T17:01:31.459Z,1554397291.459 [CommandLine](IMPORTANT): Express linearApproximation RDI_Pathfinder.height_above_sea_floor 2.000000 meter;

2019-04-04T17:01:31.460Z,1554397291.460 [CommandLine](IMPORTANT): Express none TrackAcousticContact.contact_latitude;

2019-04-04T17:01:31.460Z,1554397291.460 [CommandLine](IMPORTANT): Express none TrackAcousticContact.contact_longitude;

2019-04-04T17:01:31.460Z,1554397291.460 [CommandLine](IMPORTANT): Express linearApproximation acoustic_contact_range 1.000000 meter;

2019-04-04T17:01:31.460Z,1554397291.460 [CommandLine](IMPORTANT): NAL9602.fastGPSFix=1 bool;

2019-04-04T17:01:31.460Z,1554397291.460 [CommandLine](IMPORTANT): VerticalControl.buoyancyNeutral=190 cubic_centimeter;

2019-04-04T17:01:31.460Z,1554397291.460 [CommandLine](IMPORTANT): VerticalControl.massDefault=6 millimeter;

2019-04-04T17:01:31.802Z,1554397291.802 [MissionManager](IMPORTANT): Started mission Startup
2019-04-04T17:01:31.803Z,1554397291.803 [Startup] Running Loop=1
2019-04-04T17:01:31.803Z,1554397291.803 [Startup](DEBUG): Aggregate::initialize Startup
2019-04-04T17:01:31.803Z,1554397291.803 [Startup:A.GoToSurface] Running Loop=1
2019-04-04T17:01:31.803Z,1554397291.803 [Startup:A.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-04-04T17:01:31.804Z,1554397291.804 [Startup:A.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-04-04T17:01:31.804Z,1554397291.804 [Startup:A.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-04-04T17:01:31.804Z,1554397291.804 [Startup:A.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-04-04T17:01:31.805Z,1554397291.805 [Startup:A.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-04-04T17:01:31.805Z,1554397291.805 [Startup:A.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-04-04T17:01:31.807Z,1554397291.807 [Startup:StartupSatComms] Running Loop=1
2019-04-04T17:01:31.807Z,1554397291.807 [Startup:StartupSatComms](DEBUG): Aggregate::initialize Startup:StartupSatComms
2019-04-04T17:01:31.807Z,1554397291.807 [Startup:StartupSatComms:A] Running Loop=1
2019-04-04T17:01:32.223Z,1554397292.223 [Startup:StartupSatComms:A](DEBUG): Initialize ReadDataComponent to sense latitude_fix
2019-04-04T17:01:33.797Z,1554397293.797 [NAL9602](DEBUG): Fix Requested
2019-04-04T17:01:37.029Z,1554397297.029 [NAL9602](DEBUG): Fix Requested
2019-04-04T17:01:39.853Z,1554397299.853 [NAL9602](DEBUG): Fix Requested
2019-04-04T17:01:43.089Z,1554397303.089 [NAL9602](DEBUG): Fix Requested
2019-04-04T17:01:45.913Z,1554397305.913 [NAL9602](DEBUG): Fix Requested
2019-04-04T17:01:48.744Z,1554397308.744 [NAL9602](DEBUG): Fix Requested
2019-04-04T17:01:51.989Z,1554397311.989 [NAL9602](DEBUG): Fix Requested
2019-04-04T17:01:54.805Z,1554397314.805 [NAL9602](DEBUG): Fix Requested
2019-04-04T17:01:58.033Z,1554397318.033 [NAL9602](DEBUG): Fix Requested
2019-04-04T17:02:00.861Z,1554397320.861 [NAL9602](DEBUG): Fix Requested
2019-04-04T17:02:04.093Z,1554397324.093 [NAL9602](DEBUG): Fix Requested
2019-04-04T17:02:06.921Z,1554397326.921 [NAL9602](DEBUG): Fix Requested
2019-04-04T17:02:09.753Z,1554397329.753 [NAL9602](DEBUG): Fix Requested
2019-04-04T17:02:12.981Z,1554397332.981 [NAL9602](DEBUG): Fix Requested
2019-04-04T17:02:15.813Z,1554397335.813 [NAL9602](DEBUG): Fix Requested
2019-04-04T17:02:19.045Z,1554397339.045 [NAL9602](DEBUG): Fix Requested
2019-04-04T17:02:21.873Z,1554397341.873 [NAL9602](DEBUG): Fix Requested
2019-04-04T17:02:25.101Z,1554397345.101 [NAL9602](DEBUG): Fix Requested
2019-04-04T17:02:27.929Z,1554397347.929 [NAL9602](DEBUG): Fix Requested
2019-04-04T17:02:28.325Z,1554397348.325 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,170221.00,A,3645.94956,N,12151.04163,W,1.147,92.56,040419,,,A*4D
2019-04-04T17:02:28.329Z,1554397348.329 [NAL9602](INFO): GPS fix at 20190404T170221: (36.765826, -121.850694)
2019-04-04T17:02:28.364Z,1554397348.364 [Startup:StartupSatComms:A] Stopped
2019-04-04T17:02:28.364Z,1554397348.364 [Startup:StartupSatComms:B] Running Loop=1
2019-04-04T17:02:28.772Z,1554397348.772 [Startup:StartupSatComms:B](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-04-04T17:02:30.403Z,1554397350.403 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2019-04-04T17:02:40.142Z,1554397360.142 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2019-04-04T17:02:49.830Z,1554397369.830 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2019-04-04T17:02:56.281Z,1554397376.281 [NAL9602](INFO): SBD MO Status=1, MOMSN=2753, MT Status=0, MTMSN=0
2019-04-04T17:02:56.329Z,1554397376.329 [NAL9602](INFO): Sent 25 bytes from file Logs/20190404T062936/Courier0045.lzma
2019-04-04T17:02:56.329Z,1554397376.329 [NAL9602](INFO): Packets left to send: 0
2019-04-04T17:02:59.718Z,1554397379.718 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2019-04-04T17:03:08.148Z,1554397388.148 [NAL9602](INFO): SBD MO Status=1, MOMSN=2754, MT Status=0, MTMSN=0
2019-04-04T17:03:08.198Z,1554397388.198 [NAL9602](INFO): Sent 213 bytes from file Logs/20190404T165942/Courier0000.lzma
2019-04-04T17:03:08.199Z,1554397388.199 [NAL9602](INFO): Packets left to send: 0
2019-04-04T17:03:11.412Z,1554397391.412 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2019-04-04T17:03:16.255Z,1554397396.255 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004943
2019-04-04T17:03:21.282Z,1554397401.282 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2019-04-04T17:03:21.925Z,1554397401.925 [DataOverHttps](INFO): Sending 405 bytes from file Logs/20190404T062936/Express0046.lzma
2019-04-04T17:03:22.731Z,1554397402.731 [DataOverHttps](INFO): Moved sent file to Logs/20190404T062936/Express0046.lzma.bak
2019-04-04T17:03:22.731Z,1554397402.731 [DataOverHttps](INFO): SBD MOMSN=10438361
2019-04-04T17:03:26.501Z,1554397406.501 [NAL9602](INFO): SBD MO Status=2, MOMSN=2755, MT Status=2, MTMSN=0
2019-04-04T17:03:26.501Z,1554397406.501 [NAL9602](ERROR): Failed to initiate SBD session. Error code: 2
2019-04-04T17:03:28.533Z,1554397408.533 [Startup:StartupSatComms:B](INFO): Timed out from 2019-04-04T17:02:28.4Z
2019-04-04T17:03:28.533Z,1554397408.533 [Startup:StartupSatComms:B] Stopped
2019-04-04T17:03:28.534Z,1554397408.534 [Startup:StartupSatComms](INFO): Completed Startup:StartupSatComms
2019-04-04T17:03:28.534Z,1554397408.534 [Startup:StartupSatComms] Stopped
2019-04-04T17:03:28.534Z,1554397408.534 [Startup:StartupSatComms](DEBUG): Aggregate::uninitialize Startup:StartupSatComms
2019-04-04T17:03:28.534Z,1554397408.534 [Startup](INFO): Completed Startup
2019-04-04T17:03:28.535Z,1554397408.535 [MissionManager](INFO): Startup is completed.
2019-04-04T17:03:28.535Z,1554397408.535 [MissionManager](INFO): Uninitializing Mission Startup
2019-04-04T17:03:28.535Z,1554397408.535 [Startup] Stopped
2019-04-04T17:03:28.535Z,1554397408.535 [Startup](DEBUG): Aggregate::uninitialize Startup
2019-04-04T17:03:28.535Z,1554397408.535 [Startup:A.GoToSurface] Stopped
2019-04-04T17:03:28.535Z,1554397408.535 [Startup:A.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-04-04T17:03:28.932Z,1554397408.932 [MissionManager](IMPORTANT): Started mission Default
2019-04-04T17:03:28.932Z,1554397408.932 [Default] Running Loop=1
2019-04-04T17:03:28.932Z,1554397408.932 [Default](DEBUG): Aggregate::initialize Default
2019-04-04T17:03:28.933Z,1554397408.933 [Default:B.GoToSurface] Running Loop=1
2019-04-04T17:03:28.933Z,1554397408.933 [Default:B.GoToSurface](DEBUG): Initialize GoToSurfaceComponent.
2019-04-04T17:03:28.933Z,1554397408.933 [Default:B.GoToSurface](DEBUG): No depth rate setting specified. Using default value of nan m/s.
2019-04-04T17:03:28.934Z,1554397408.934 [Default:B.GoToSurface](DEBUG): No pitch setting specified. Using default value of nan degrees.
2019-04-04T17:03:28.934Z,1554397408.934 [Default:B.GoToSurface](DEBUG): No speed setting specified. Using default value of 1.000000 m/s.
2019-04-04T17:03:28.934Z,1554397408.934 [Default:B.GoToSurface](DEBUG): No surface timeout specified. Using default value of 1000.000000 seconds.
2019-04-04T17:03:28.934Z,1554397408.934 [Default:B.GoToSurface](INFO): Received pitch timeout configuration 60.000000 seconds.
2019-04-04T17:03:28.935Z,1554397408.935 [Default:A.Wait] Running Loop=1
2019-04-04T17:03:28.935Z,1554397408.935 [Default:A.Wait](DEBUG): Initialize Wait Component.
2019-04-04T17:03:30.943Z,1554397410.943 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2019-04-04T17:03:38.822Z,1554397418.822 [DataOverHttps](INFO): Sending 1035 bytes from file Logs/20190404T165942/Express0001.lzma
2019-04-04T17:03:39.627Z,1554397419.627 [DataOverHttps](INFO): Moved sent file to Logs/20190404T165942/Express0001.lzma.bak
2019-04-04T17:03:39.627Z,1554397419.627 [DataOverHttps](IMPORTANT): SBD MOMSN=10438371, MTMSN=20190404T170333
2019-04-04T17:03:40.634Z,1554397420.634 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2019-04-04T17:03:42.284Z,1554397422.284 [Default:A.Wait](INFO): Done Waiting.
2019-04-04T17:03:42.284Z,1554397422.284 [Default:A.Wait] Stopped
2019-04-04T17:03:42.284Z,1554397422.284 [Default:A.Wait](DEBUG): Uninitialize Wait Component.
2019-04-04T17:03:42.688Z,1554397422.688 [Default:CheckIn] Running Loop=1
2019-04-04T17:03:42.688Z,1554397422.688 [Default:CheckIn](DEBUG): Aggregate::initialize Default:CheckIn
2019-04-04T17:03:42.693Z,1554397422.693 [Default:CheckIn:Read_GPS] Running Loop=1
2019-04-04T17:03:43.081Z,1554397423.081 [Default:CheckIn:Read_GPS](DEBUG): Initialize ReadDataComponent to sense time_fix
2019-04-04T17:03:44.281Z,1554397424.281 [NAL9602](DEBUG): Fix Requested
2019-04-04T17:03:44.661Z,1554397424.661 [NAL9602](DEBUG): Parsing RMC sentence: $GPRMC,170338.00,A,3645.94960,N,12151.03963,W,1.166,131.38,040419,,,D*78
2019-04-04T17:03:44.663Z,1554397424.663 [NAL9602](INFO): GPS fix at 20190404T170338: (36.765827, -121.850661)
2019-04-04T17:03:44.748Z,1554397424.748 [Default:CheckIn:Read_GPS] Stopped
2019-04-04T17:03:44.748Z,1554397424.748 [Default:CheckIn:Read_Iridium] Running Loop=1
2019-04-04T17:03:45.258Z,1554397425.258 [Default:CheckIn:Read_Iridium](DEBUG): Initialize ReadDataComponent to sense platform_communications
2019-04-04T17:03:45.437Z,1554397425.437 [DataOverHttps](INFO): Received command:configSet DUSBL_Hydroid.detectionThreshold 90 count persist
2019-04-04T17:03:45.792Z,1554397425.792 [CommandLine](IMPORTANT): got command configSet DUSBL_Hydroid.detectionThreshold 90.000000 count persist
2019-04-04T17:03:50.550Z,1554397430.550 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2019-04-04T17:03:52.088Z,1554397432.088 [DataOverHttps](INFO): Sending 62 bytes from file Logs/20190404T165942/Courier0004.lzma
2019-04-04T17:03:52.894Z,1554397432.894 [DataOverHttps](INFO): Moved sent file to Logs/20190404T165942/Courier0004.lzma.bak
2019-04-04T17:03:52.895Z,1554397432.895 [DataOverHttps](INFO): SBD MOMSN=10438397
2019-04-04T17:04:00.252Z,1554397440.252 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2019-04-04T17:04:04.812Z,1554397444.812 [DataOverHttps](INFO): Sending 25 bytes from file Logs/20190404T165942/Courier0007.lzma
2019-04-04T17:04:05.618Z,1554397445.618 [DataOverHttps](INFO): Moved sent file to Logs/20190404T165942/Courier0007.lzma.bak
2019-04-04T17:04:05.619Z,1554397445.619 [DataOverHttps](INFO): SBD MOMSN=10438399
2019-04-04T17:04:10.344Z,1554397450.344 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2019-04-04T17:04:16.782Z,1554397456.782 [NAL9602](INFO): Not Powering down - fast GPS
2019-04-04T17:04:20.452Z,1554397460.452 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2019-04-04T17:04:22.556Z,1554397462.556 [DataOverHttps](INFO): Sending 178 bytes from file Logs/20190404T165942/Express0005.lzma
2019-04-04T17:04:23.362Z,1554397463.362 [DataOverHttps](INFO): Moved sent file to Logs/20190404T165942/Express0005.lzma.bak
2019-04-04T17:04:23.363Z,1554397463.363 [DataOverHttps](INFO): SBD MOMSN=10438401
2019-04-04T17:04:30.552Z,1554397470.552 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2019-04-04T17:04:35.292Z,1554397475.292 [DataOverHttps](INFO): Sending 123 bytes from file Logs/20190404T165942/Express0008.lzma
2019-04-04T17:04:36.098Z,1554397476.098 [DataOverHttps](INFO): Moved sent file to Logs/20190404T165942/Express0008.lzma.bak
2019-04-04T17:04:36.099Z,1554397476.099 [DataOverHttps](INFO): SBD MOMSN=10438403
2019-04-04T17:04:37.070Z,1554397477.070 [Default:CheckIn:Read_Iridium] Stopped
2019-04-04T17:04:37.070Z,1554397477.070 [Default:CheckIn:C.Wait] Running Loop=1
2019-04-04T17:04:37.070Z,1554397477.070 [Default:CheckIn:C.Wait](DEBUG): Initialize Wait Component.
2019-04-04T17:04:40.244Z,1554397480.244 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2019-04-04T17:04:48.922Z,1554397488.922 [DataOverHttps](IMPORTANT): SBD MTMSN=20190404T170442
2019-04-04T17:04:50.337Z,1554397490.337 [BPC1](ERROR): BPC1A got IPBS message with 5 sticks (min is 7).
2019-04-04T17:04:54.652Z,1554397494.652 [DataOverHttps](INFO): Received command:restart app
2019-04-04T17:04:54.713Z,1554397494.713 [CommandLine](IMPORTANT): got command restart application
2019-04-04T17:04:55.717Z,1554397495.717 [Supervisor](INFO): Stop Mission called by Supervisor::terminate
2019-04-04T17:04:55.717Z,1554397495.717 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2019-04-04T17:04:55.718Z,1554397495.718 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-04-04T17:04:55.833Z,1554397495.833 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2019-04-04T17:04:55.833Z,1554397495.833 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-04-04T17:04:55.834Z,1554397495.834 [CommandLine](INFO): Join timeout helper Thread ID is 6830
2019-04-04T17:04:55.841Z,1554397495.841 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2019-04-04T17:04:55.841Z,1554397495.841 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-04-04T17:04:55.842Z,1554397495.842 [NavChartDb](INFO): Join timeout helper Thread ID is 6831
2019-04-04T17:04:55.856Z,1554397495.856 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2019-04-04T17:04:55.856Z,1554397495.856 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-04-04T17:04:55.869Z,1554397495.869 [ComponentRegistry](INFO): Shutting down WetLabsSeaOWL_UV_A ThreadHandler
2019-04-04T17:04:55.869Z,1554397495.869 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2019-04-04T17:04:55.869Z,1554397495.869 [WetLabsSeaOWL_UV_A](INFO): Join timeout helper Thread ID is 6832
2019-04-04T17:04:55.925Z,1554397495.925 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Uninitializing protected caller thread.
2019-04-04T17:04:55.926Z,1554397495.926 [WetLabsSeaOWL_UV_A](INFO): Powering down
2019-04-04T17:04:55.927Z,1554397495.927 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2019-04-04T17:04:55.933Z,1554397495.933 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler
2019-04-04T17:04:55.933Z,1554397495.933 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2019-04-04T17:04:55.934Z,1554397495.934 [CTD_NeilBrown](INFO): Join timeout helper Thread ID is 6833
2019-04-04T17:04:56.097Z,1554397496.097 [CTD_NeilBrown ThreadHandler](INFO): Uninitializing protected caller thread.
2019-04-04T17:04:56.097Z,1554397496.097 [CTD_NeilBrown](INFO): Powering down
2019-04-04T17:04:56.109Z,1554397496.109 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2019-04-04T17:04:56.129Z,1554397496.129 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2019-04-04T17:04:56.129Z,1554397496.129 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-04-04T17:04:56.129Z,1554397496.129 [Radio_Surface](INFO): Join timeout helper Thread ID is 6834
2019-04-04T17:04:56.257Z,1554397496.257 [Radio_Surface](INFO): Powering down
2019-04-04T17:04:56.258Z,1554397496.258 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2019-04-04T17:04:56.258Z,1554397496.258 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-04-04T17:04:56.265Z,1554397496.265 [DataOverHttps](INFO): Radio surface powered OFF, will not connect.
2019-04-04T17:04:56.270Z,1554397496.270 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2019-04-04T17:04:56.270Z,1554397496.270 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-04-04T17:04:56.270Z,1554397496.270 [DataOverHttps](INFO): Join timeout helper Thread ID is 6835
2019-04-04T17:04:56.669Z,1554397496.669 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2019-04-04T17:04:56.669Z,1554397496.669 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-04-04T17:04:56.674Z,1554397496.674 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2019-04-04T17:04:56.674Z,1554397496.674 [logger ThreadHandler](INFO): Thread cancelled.
2019-04-04T17:04:56.674Z,1554397496.674 [logger](INFO): Join timeout helper Thread ID is 6836
2019-04-04T17:04:56.749Z,1554397496.749 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2019-04-04T17:04:56.749Z,1554397496.749 [logger ThreadHandler](INFO): Thread cancelled.
2019-04-04T17:04:56.754Z,1554397496.754 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2019-04-04T17:04:56.754Z,1554397496.754 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-04-04T17:04:56.754Z,1554397496.754 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2019-04-04T17:04:56.754Z,1554397496.754 [controlThread ThreadHandler](INFO): Thread cancelled.
2019-04-04T17:04:56.754Z,1554397496.754 [controlThread](INFO): Join timeout helper Thread ID is 6837
2019-04-04T17:04:56.757Z,1554397496.757 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2019-04-04T17:04:56.757Z,1554397496.757 [controlThread](DEBUG): Uninitializing ControlThread
2019-04-04T17:04:56.758Z,1554397496.758 [AHRS_M2](INFO): Powering down
2019-04-04T17:04:56.830Z,1554397496.830 [DUSBL_Hydroid](INFO): Powering down
2019-04-04T17:04:56.921Z,1554397496.921 [Micromodem](INFO): Powering down
2019-04-04T17:04:57.017Z,1554397497.017 [NAL9602](INFO): Powering down
2019-04-04T17:04:57.089Z,1554397497.089 [RDI_Pathfinder](INFO): Powering down
2019-04-04T17:04:57.091Z,1554397497.091 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2019-04-04T17:04:57.092Z,1554397497.092 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2019-04-04T17:04:57.092Z,1554397497.092 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2019-04-04T17:04:57.092Z,1554397497.092 [MissionManager](INFO): Uninitializing Mission Default
2019-04-04T17:04:57.093Z,1554397497.093 [Default] Stopped
2019-04-04T17:04:57.093Z,1554397497.093 [Default](DEBUG): Aggregate::uninitialize Default
2019-04-04T17:04:57.093Z,1554397497.093 [Default:B.GoToSurface] Stopped
2019-04-04T17:04:57.093Z,1554397497.093 [Default:B.GoToSurface](DEBUG): Uninitialize GoToSurfaceComponent.
2019-04-04T17:04:57.093Z,1554397497.093 [Default:CheckIn] Stopped
2019-04-04T17:04:57.093Z,1554397497.093 [Default:CheckIn](DEBUG): Aggregate::uninitialize Default:CheckIn
2019-04-04T17:04:57.093Z,1554397497.093 [Default:CheckIn:C.Wait] Stopped
2019-04-04T17:04:57.093Z,1554397497.093 [Default:CheckIn:C.Wait](DEBUG): Uninitialize Wait Component.
2019-04-04T17:04:57.096Z,1554397497.096 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2019-04-04T17:04:57.096Z,1554397497.096 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2019-04-04T17:04:57.096Z,1554397497.096 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2019-04-04T17:04:57.097Z,1554397497.097 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2019-04-04T17:04:57.097Z,1554397497.097 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2019-04-04T17:04:57.097Z,1554397497.097 [BuoyancyServo](INFO): Powering down
2019-04-04T17:04:57.109Z,1554397497.109 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2019-04-04T17:04:57.109Z,1554397497.109 [ElevatorServo](INFO): Powering down
2019-04-04T17:04:57.110Z,1554397497.110 [MassServo](DEBUG): Uninitialize Mass Servo.
2019-04-04T17:04:57.110Z,1554397497.110 [MassServo](INFO): Powering down
2019-04-04T17:04:57.111Z,1554397497.111 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2019-04-04T17:04:57.111Z,1554397497.111 [RudderServo](INFO): Powering down
2019-04-04T17:04:57.112Z,1554397497.112 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2019-04-04T17:04:57.112Z,1554397497.112 [ThrusterServo](INFO): Powering down
2019-04-04T17:04:57.112Z,1554397497.112 [SBIT](DEBUG): Uninitialize SBIT Component.
2019-04-04T17:04:57.113Z,1554397497.113 [IBIT](DEBUG): Uninitialize IBIT Component.
2019-04-04T17:04:57.113Z,1554397497.113 [CBIT](DEBUG): Uninitialize CBIT Component.
2019-04-04T17:04:57.113Z,1554397497.113 [CBIT](DEBUG): Powering off loads.
2019-04-04T17:04:57.125Z,1554397497.125 [CBIT](DEBUG): Disabling WDT.
2019-04-04T17:04:57.137Z,1554397497.137 [CBIT](DEBUG): Opening all GF detection circuits.
2019-04-04T17:04:57.138Z,1554397497.138 [controlThread ThreadHandler](INFO): Thread cancelled.
2019-04-04T17:04:57.196Z,1554397497.196 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-04-04T17:04:57.205Z,1554397497.205 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-04-04T17:04:57.246Z,1554397497.246 [WetLabsSeaOWL_UV_A ThreadHandler](INFO): Thread cancelled.
2019-04-04T17:04:57.248Z,1554397497.248 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2019-04-04T17:04:57.302Z,1554397497.302 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-04-04T17:04:57.375Z,1554397497.375 [logger ThreadHandler](INFO): Thread cancelled.