2019-05-08T15:49:15.350Z,1557330555.351 [Supervisor](DEBUG): Initializing supervisor.
2019-05-08T15:49:15.353Z,1557330555.353 [SyncHandler](DEBUG): Created PCaller Thread at 404514E0
2019-05-08T15:49:15.354Z,1557330555.354 [SyncHandler](INFO): Protected caller Thread ID is 1267
2019-05-08T15:49:15.354Z,1557330555.354 [ComponentRegistry](DEBUG): Component "controlThread" handled in its own thread.
2019-05-08T15:49:15.355Z,1557330555.355 [controlThread ThreadHandler](DEBUG): Created PCaller Thread at 404814E0
2019-05-08T15:49:15.355Z,1557330555.355 [controlThread ThreadHandler](INFO): Protected caller Thread ID is 1268
2019-05-08T15:49:15.358Z,1557330555.358 [ComponentRegistry](DEBUG): SyncComponent "CycleStarter" handled in the control thread.
2019-05-08T15:49:15.370Z,1557330555.370 [ComponentRegistry](DEBUG): Component "CommandLine" handled in its own thread.
2019-05-08T15:49:15.371Z,1557330555.371 [CommandLine ThreadHandler](DEBUG): Created PCaller Thread at 404B14E0
2019-05-08T15:49:15.371Z,1557330555.371 [CommandLine ThreadHandler](INFO): Protected caller Thread ID is 1269
2019-05-08T15:49:15.372Z,1557330555.372 [ComponentRegistry](DEBUG): Component "logger" handled in its own thread.
2019-05-08T15:49:15.373Z,1557330555.373 [logger ThreadHandler](DEBUG): Created PCaller Thread at 404E14E0
2019-05-08T15:49:15.373Z,1557330555.373 [logger ThreadHandler](INFO): Protected caller Thread ID is 1270
2019-05-08T15:49:15.375Z,1557330555.375 [ComponentRegistry](DEBUG): SyncComponent "LogSplitter" handled in the control thread.
2019-05-08T15:49:15.376Z,1557330555.376 [Supervisor](INFO): Looking for Config files in directory: Config/
2019-05-08T15:49:15.377Z,1557330555.377 [Supervisor](INFO): Opening Config file at: Config/secure.cfg
2019-05-08T15:49:15.473Z,1557330555.473 [ComponentRegistry](DEBUG): Loaded Config Component "Config/secure
2019-05-08T15:49:15.474Z,1557330555.474 [Supervisor](INFO): Opening Config file at: Config/Sensor.cfg
2019-05-08T15:49:16.007Z,1557330556.007 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sensor
2019-05-08T15:49:16.008Z,1557330556.008 [Supervisor](INFO): Opening Config file at: Config/Sample.cfg
2019-05-08T15:49:16.107Z,1557330556.107 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Sample
2019-05-08T15:49:16.108Z,1557330556.108 [Supervisor](INFO): Opening Config file at: Config/workSite.cfg
2019-05-08T15:49:16.211Z,1557330556.211 [ComponentRegistry](DEBUG): Loaded Config Component "Config/workSite
2019-05-08T15:49:16.211Z,1557330556.211 [Supervisor](INFO): Opening Config file at: Config/Guidance.cfg
2019-05-08T15:49:16.292Z,1557330556.292 [Supervisor](INFO): Opening Config file at: Config/Estimation.cfg
2019-05-08T15:49:16.432Z,1557330556.432 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Estimation
2019-05-08T15:49:16.433Z,1557330556.433 [Supervisor](INFO): Opening Config file at: Config/Servo.cfg
2019-05-08T15:49:16.733Z,1557330556.733 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Servo
2019-05-08T15:49:16.734Z,1557330556.734 [Supervisor](INFO): Opening Config file at: Config/Simulator.cfg
2019-05-08T15:49:17.203Z,1557330557.203 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Simulator
2019-05-08T15:49:17.203Z,1557330557.203 [Supervisor](INFO): Opening Config file at: Config/Derivation.cfg
2019-05-08T15:49:17.351Z,1557330557.351 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Derivation
2019-05-08T15:49:17.351Z,1557330557.351 [Supervisor](INFO): Opening Config file at: Config/logger.cfg
2019-05-08T15:49:17.550Z,1557330557.550 [ComponentRegistry](DEBUG): Loaded Config Component "Config/logger
2019-05-08T15:49:17.551Z,1557330557.551 [Supervisor](INFO): Opening Config file at: Config/vehicle.cfg
2019-05-08T15:49:18.018Z,1557330558.018 [ComponentRegistry](DEBUG): Loaded Config Component "Config/vehicle
2019-05-08T15:49:18.019Z,1557330558.019 [Supervisor](INFO): Opening Config file at: Config/Navigation.cfg
2019-05-08T15:49:18.235Z,1557330558.235 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Navigation
2019-05-08T15:49:18.235Z,1557330558.235 [Supervisor](INFO): Opening Config file at: Config/BIT.cfg
2019-05-08T15:49:18.439Z,1557330558.439 [ComponentRegistry](DEBUG): Loaded Config Component "Config/BIT
2019-05-08T15:49:18.439Z,1557330558.439 [Supervisor](INFO): Opening Config file at: Config/Science.cfg
2019-05-08T15:49:18.831Z,1557330558.831 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Science
2019-05-08T15:49:18.832Z,1557330558.832 [Supervisor](INFO): Opening Config file at: Config/Control.cfg
2019-05-08T15:49:19.173Z,1557330559.173 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Control
2019-05-08T15:49:19.175Z,1557330559.175 [Supervisor](INFO): Looking for Config files in directory: Config/lrauv-pontus/
2019-05-08T15:49:19.176Z,1557330559.176 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/secure.cfg
2019-05-08T15:49:19.259Z,1557330559.259 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Sensor.cfg
2019-05-08T15:49:19.409Z,1557330559.409 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Servo.cfg
2019-05-08T15:49:19.519Z,1557330559.519 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Simulator.cfg
2019-05-08T15:49:19.604Z,1557330559.604 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/logger.cfg
2019-05-08T15:49:19.700Z,1557330559.700 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/vehicle.cfg
2019-05-08T15:49:19.885Z,1557330559.885 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Battery.cfg
2019-05-08T15:49:20.124Z,1557330560.124 [ComponentRegistry](DEBUG): Loaded Config Component "Config/Battery
2019-05-08T15:49:20.125Z,1557330560.125 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Navigation.cfg
2019-05-08T15:49:20.363Z,1557330560.363 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/BIT.cfg
2019-05-08T15:49:20.486Z,1557330560.486 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Science.cfg
2019-05-08T15:49:20.647Z,1557330560.647 [Supervisor](INFO): Opening Config file at: Config/lrauv-pontus/Control.cfg
2019-05-08T15:49:20.925Z,1557330560.925 [Supervisor](IMPORTANT): Reading configuration overrides from Data/persisted.cfg
2019-05-08T15:49:21.191Z,1557330561.191 [Module Loader](DEBUG): Loading Module at Modules/Control.so
2019-05-08T15:49:21.255Z,1557330561.255 [VerticalControl](DEBUG): Construct VerticalControl.
2019-05-08T15:49:21.368Z,1557330561.368 [VerticalControl] Loaded
2019-05-08T15:49:21.368Z,1557330561.368 [ComponentRegistry](DEBUG): SyncComponent "VerticalControl" handled in the control thread.
2019-05-08T15:49:21.368Z,1557330561.368 [HorizontalControl](DEBUG): Construct HorizontalControl.
2019-05-08T15:49:21.437Z,1557330561.437 [HorizontalControl] Loaded
2019-05-08T15:49:21.438Z,1557330561.438 [ComponentRegistry](DEBUG): SyncComponent "HorizontalControl" handled in the control thread.
2019-05-08T15:49:21.438Z,1557330561.438 [SpeedControl](DEBUG): Construct SpeedControl.
2019-05-08T15:49:21.444Z,1557330561.444 [SpeedControl] Loaded
2019-05-08T15:49:21.444Z,1557330561.444 [ComponentRegistry](DEBUG): SyncComponent "SpeedControl" handled in the control thread.
2019-05-08T15:49:21.445Z,1557330561.445 [LoopControl](DEBUG): Construct LoopControl.
2019-05-08T15:49:21.445Z,1557330561.445 [LoopControl] Loaded
2019-05-08T15:49:21.445Z,1557330561.445 [ComponentRegistry](DEBUG): SyncComponent "LoopControl" handled in the control thread.
2019-05-08T15:49:21.446Z,1557330561.446 [Module Loader](DEBUG): Loaded Module: Control (Contains the Control components, such as Depth, Heading, and Speed Control)
2019-05-08T15:49:21.446Z,1557330561.446 [Module Loader](DEBUG): Loading Module at Modules/Derivation.so
2019-05-08T15:49:21.485Z,1557330561.485 [DepthRateCalculator] Loaded
2019-05-08T15:49:21.485Z,1557330561.485 [ComponentRegistry](DEBUG): SyncComponent "DepthRateCalculator" handled in the control thread.
2019-05-08T15:49:21.491Z,1557330561.491 [PitchRateCalculator] Loaded
2019-05-08T15:49:21.491Z,1557330561.491 [ComponentRegistry](DEBUG): SyncComponent "PitchRateCalculator" handled in the control thread.
2019-05-08T15:49:21.507Z,1557330561.507 [SpeedCalculator] Loaded
2019-05-08T15:49:21.507Z,1557330561.507 [ComponentRegistry](DEBUG): SyncComponent "SpeedCalculator" handled in the control thread.
2019-05-08T15:49:21.527Z,1557330561.527 [TempGradientCalculator] Loaded
2019-05-08T15:49:21.528Z,1557330561.528 [ComponentRegistry](DEBUG): SyncComponent "TempGradientCalculator" handled in the control thread.
2019-05-08T15:49:21.533Z,1557330561.533 [YawRateCalculator] Loaded
2019-05-08T15:49:21.533Z,1557330561.533 [ComponentRegistry](DEBUG): SyncComponent "YawRateCalculator" handled in the control thread.
2019-05-08T15:49:21.562Z,1557330561.562 [ElevatorOffsetCalculator] Loaded
2019-05-08T15:49:21.562Z,1557330561.562 [ComponentRegistry](DEBUG): SyncComponent "ElevatorOffsetCalculator" handled in the control thread.
2019-05-08T15:49:21.562Z,1557330561.562 [Module Loader](DEBUG): Loaded Module: Derivation (Contains the base derivation components)
2019-05-08T15:49:21.563Z,1557330561.563 [Module Loader](DEBUG): Loading Module at Modules/Trigger.so
2019-05-08T15:49:21.588Z,1557330561.588 [Module Loader](DEBUG): Loaded Module: Trigger (Contains triggers for use in missions)
2019-05-08T15:49:21.589Z,1557330561.589 [Module Loader](DEBUG): Loading Module at Modules/Estimation.so
2019-05-08T15:49:21.656Z,1557330561.656 [Module Loader](DEBUG): Loaded Module: Estimation (Contains the base estimation components)
2019-05-08T15:49:21.657Z,1557330561.657 [Module Loader](DEBUG): Loading Module at Modules/Guidance.so
2019-05-08T15:49:21.931Z,1557330561.931 [Module Loader](DEBUG): Loaded Module: Guidance (Contains behaviors and commands)
2019-05-08T15:49:21.932Z,1557330561.932 [Module Loader](DEBUG): Loading Module at Modules/Simulator.so
2019-05-08T15:49:22.026Z,1557330562.026 [Module Loader](DEBUG): Loaded Module: Simulator (This is the module containing the Simulator)
2019-05-08T15:49:22.026Z,1557330562.026 [Module Loader](DEBUG): Loading Module at Modules/Sensor.so
2019-05-08T15:49:22.347Z,1557330562.347 [DataOverHttps] Loaded
2019-05-08T15:49:22.347Z,1557330562.347 [ComponentRegistry](DEBUG): Component "DataOverHttps" handled in its own thread.
2019-05-08T15:49:22.349Z,1557330562.349 [DataOverHttps ThreadHandler](DEBUG): Created PCaller Thread at 408C74E0
2019-05-08T15:49:22.349Z,1557330562.349 [DataOverHttps ThreadHandler](INFO): Protected caller Thread ID is 1349
2019-05-08T15:49:22.362Z,1557330562.362 [Depth_Keller] Loaded
2019-05-08T15:49:22.362Z,1557330562.362 [ComponentRegistry](DEBUG): SyncComponent "Depth_Keller" handled in the control thread.
2019-05-08T15:49:22.460Z,1557330562.460 [NAL9602] Loaded
2019-05-08T15:49:22.460Z,1557330562.460 [ComponentRegistry](DEBUG): SyncComponent "NAL9602" handled in the control thread.
2019-05-08T15:49:22.476Z,1557330562.476 [Onboard] Loaded
2019-05-08T15:49:22.476Z,1557330562.476 [ComponentRegistry](DEBUG): SyncComponent "Onboard" handled in the control thread.
2019-05-08T15:49:22.479Z,1557330562.479 [Radio_Surface] Loaded
2019-05-08T15:49:22.480Z,1557330562.480 [ComponentRegistry](DEBUG): Component "Radio_Surface" handled in its own thread.
2019-05-08T15:49:22.481Z,1557330562.481 [Radio_Surface ThreadHandler](DEBUG): Created PCaller Thread at 408F74E0
2019-05-08T15:49:22.481Z,1557330562.481 [Radio_Surface ThreadHandler](INFO): Protected caller Thread ID is 1350
2019-05-08T15:49:23.921Z,1557330563.921 [BPC1] Loaded
2019-05-08T15:49:23.921Z,1557330563.921 [ComponentRegistry](DEBUG): SyncComponent "BPC1" handled in the control thread.
2019-05-08T15:49:23.922Z,1557330563.922 [Module Loader](DEBUG): Loaded Module: Sensor (Contains the sensor components)
2019-05-08T15:49:23.922Z,1557330563.922 [Module Loader](DEBUG): Loading Module at Modules/Navigation.so
2019-05-08T15:49:24.024Z,1557330564.024 [DeadReckonUsingMultipleVelocitySources] Loaded
2019-05-08T15:49:24.024Z,1557330564.024 [ComponentRegistry](DEBUG): SyncComponent "DeadReckonUsingMultipleVelocitySources" handled in the control thread.
2019-05-08T15:49:24.045Z,1557330564.045 [NavChart] Loaded
2019-05-08T15:49:24.045Z,1557330564.045 [ComponentRegistry](DEBUG): SyncComponent "NavChart" handled in the control thread.
2019-05-08T15:49:24.049Z,1557330564.049 [UniversalFixResidualReporter] Loaded
2019-05-08T15:49:24.049Z,1557330564.049 [ComponentRegistry](DEBUG): SyncComponent "UniversalFixResidualReporter" handled in the control thread.
2019-05-08T15:49:24.050Z,1557330564.050 [Module Loader](DEBUG): Loaded Module: Navigation (Contains the base navigation components)
2019-05-08T15:49:24.050Z,1557330564.050 [Module Loader](DEBUG): Loading Module at Modules/BIT.so
2019-05-08T15:49:24.178Z,1557330564.178 [SBIT](DEBUG): Construct Startup Built In Test.
2019-05-08T15:49:24.189Z,1557330564.189 [SBIT] Loaded
2019-05-08T15:49:24.189Z,1557330564.189 [ComponentRegistry](DEBUG): SyncComponent "SBIT" handled in the control thread.
2019-05-08T15:49:24.190Z,1557330564.190 [IBIT](DEBUG): Construct Initiated Built In Test.
2019-05-08T15:49:24.201Z,1557330564.201 [IBIT] Loaded
2019-05-08T15:49:24.202Z,1557330564.202 [ComponentRegistry](DEBUG): SyncComponent "IBIT" handled in the control thread.
2019-05-08T15:49:24.205Z,1557330564.205 [CBIT](DEBUG): Construct Continuous Built In Test.
2019-05-08T15:49:24.340Z,1557330564.340 [CBIT] Loaded
2019-05-08T15:49:24.341Z,1557330564.341 [ComponentRegistry](DEBUG): SyncComponent "CBIT" handled in the control thread.
2019-05-08T15:49:24.341Z,1557330564.341 [Module Loader](DEBUG): Loaded Module: BIT (Contains the BuiltInTest components, such as C Built In Test)
2019-05-08T15:49:24.342Z,1557330564.342 [Module Loader](DEBUG): Loading Module at Modules/Servo.so
2019-05-08T15:49:24.441Z,1557330564.441 [BuoyancyServo] Loaded
2019-05-08T15:49:24.442Z,1557330564.442 [ComponentRegistry](DEBUG): SyncComponent "BuoyancyServo" handled in the control thread.
2019-05-08T15:49:24.453Z,1557330564.453 [ElevatorServo] Loaded
2019-05-08T15:49:24.453Z,1557330564.453 [ComponentRegistry](DEBUG): SyncComponent "ElevatorServo" handled in the control thread.
2019-05-08T15:49:24.464Z,1557330564.464 [MassServo] Loaded
2019-05-08T15:49:24.465Z,1557330564.465 [ComponentRegistry](DEBUG): SyncComponent "MassServo" handled in the control thread.
2019-05-08T15:49:24.476Z,1557330564.476 [RudderServo] Loaded
2019-05-08T15:49:24.476Z,1557330564.476 [ComponentRegistry](DEBUG): SyncComponent "RudderServo" handled in the control thread.
2019-05-08T15:49:24.486Z,1557330564.486 [ThrusterServo] Loaded
2019-05-08T15:49:24.487Z,1557330564.487 [ComponentRegistry](DEBUG): SyncComponent "ThrusterServo" handled in the control thread.
2019-05-08T15:49:24.487Z,1557330564.487 [Module Loader](DEBUG): Loaded Module: Servo (This is the module containing motor controllers)
2019-05-08T15:49:24.488Z,1557330564.488 [Module Loader](DEBUG): Loading Module at Modules/Sample.so
2019-05-08T15:49:24.500Z,1557330564.500 [Module Loader](DEBUG): Loaded Module: Sample (This is a Sample Module of Sample Components)
2019-05-08T15:49:24.501Z,1557330564.501 [Module Loader](DEBUG): Loading Module at Modules/Science.so
2019-05-08T15:49:24.740Z,1557330564.740 [CTD_NeilBrown] Loaded
2019-05-08T15:49:24.740Z,1557330564.740 [ComponentRegistry](DEBUG): Component "CTD_NeilBrown" handled in its own thread.
2019-05-08T15:49:24.742Z,1557330564.742 [CTD_NeilBrown ThreadHandler](DEBUG): Created PCaller Thread at 40A734E0
2019-05-08T15:49:24.742Z,1557330564.742 [CTD_NeilBrown ThreadHandler](INFO): Protected caller Thread ID is 1351
2019-05-08T15:49:24.757Z,1557330564.757 [PAR_Licor] Loaded
2019-05-08T15:49:24.757Z,1557330564.757 [ComponentRegistry](DEBUG): SyncComponent "PAR_Licor" handled in the control thread.
2019-05-08T15:49:24.804Z,1557330564.804 [WetLabsBB2FL] Loaded
2019-05-08T15:49:24.805Z,1557330564.805 [ComponentRegistry](DEBUG): Component "WetLabsBB2FL" handled in its own thread.
2019-05-08T15:49:24.806Z,1557330564.806 [WetLabsBB2FL ThreadHandler](DEBUG): Created PCaller Thread at 40AA34E0
2019-05-08T15:49:24.806Z,1557330564.806 [WetLabsBB2FL ThreadHandler](INFO): Protected caller Thread ID is 1352
2019-05-08T15:49:24.807Z,1557330564.807 [Module Loader](DEBUG): Loaded Module: Science (Contains the science components)
2019-05-08T15:49:24.810Z,1557330564.810 [ComponentRegistry](DEBUG): SyncComponent "MissionManager" handled in the control thread.
2019-05-08T15:49:24.811Z,1557330564.811 [ComponentRegistry](DEBUG): SyncComponent "Reporter" handled in the control thread.
2019-05-08T15:49:24.818Z,1557330564.818 [ComponentRegistry](DEBUG): Component "NavChartDb" handled in its own thread.
2019-05-08T15:49:24.819Z,1557330564.819 [NavChartDb ThreadHandler](DEBUG): Created PCaller Thread at 40AD34E0
2019-05-08T15:49:24.819Z,1557330564.819 [NavChartDb ThreadHandler](INFO): Protected caller Thread ID is 1353
2019-05-08T15:49:24.824Z,1557330564.824 [Supervisor](INFO): Main Thread ID is 1266
2019-05-08T15:49:24.824Z,1557330564.824 [Supervisor](DEBUG): Running supervisor.
2019-05-08T15:49:24.825Z,1557330564.825 [CommandLine ThreadHandler](INFO): Handler Thread ID is 1354
2019-05-08T15:49:24.827Z,1557330564.827 [controlThread ThreadHandler](INFO): Handler Thread ID is 1355
2019-05-08T15:49:24.827Z,1557330564.827 [controlThread](DEBUG): Initializing ControlThread
2019-05-08T15:49:24.828Z,1557330564.828 [VerticalControl](DEBUG): Initialize VerticalControlComponent.
2019-05-08T15:49:24.830Z,1557330564.830 [HorizontalControl](DEBUG): Initialize HorizontalControlComponent.
2019-05-08T15:49:24.831Z,1557330564.831 [SpeedControl](DEBUG): Initialize SpeedControlComponent.
2019-05-08T15:49:24.831Z,1557330564.831 [LoopControl](DEBUG): Initialize LoopControlComponent.
2019-05-08T15:49:24.831Z,1557330564.831 [DepthRateCalculator](DEBUG): Initializing DepthRateCalculator.
2019-05-08T15:49:24.832Z,1557330564.832 [PitchRateCalculator](DEBUG): Initializing PitchRateCalculator.
2019-05-08T15:49:24.832Z,1557330564.832 [SpeedCalculator](DEBUG): Initializing SpeedCalculator.
2019-05-08T15:49:24.832Z,1557330564.832 [TempGradientCalculator](DEBUG): Initializing TempGradientCalculator.
2019-05-08T15:49:24.833Z,1557330564.833 [YawRateCalculator](DEBUG): Initializing YawRateCalculator.
2019-05-08T15:49:24.833Z,1557330564.833 [ElevatorOffsetCalculator](DEBUG): Initializing ElevatorOffsetCalculator.
2019-05-08T15:49:24.838Z,1557330564.838 [NavChart](DEBUG): Initialize NavChart Navigation.
2019-05-08T15:49:24.838Z,1557330564.838 [UniversalFixResidualReporter](DEBUG): Initializing UniversalFixResidualReporter component.
2019-05-08T15:49:24.839Z,1557330564.839 [SBIT](INFO): Initialize SBIT Component.
2019-05-08T15:49:24.839Z,1557330564.839 [SBIT](IMPORTANT): git: 2019-05-01-6-g08bb213
2019-05-08T15:49:24.840Z,1557330564.840 [SBIT](INFO): git hash: 08bb2137fac00bb96d649b4144ef516361bafd54
2019-05-08T15:49:24.840Z,1557330564.840 [SBIT](IMPORTANT): Kernel Release: 2.6.27.8
2019-05-08T15:49:24.840Z,1557330564.840 [SBIT](IMPORTANT): Kernel Version:#1 PREEMPT Thu Feb 21 11:17:40 PST 2019
2019-05-08T15:49:24.841Z,1557330564.841 [SBIT](INFO): Beginning SBIT in 28.000000 seconds.
2019-05-08T15:49:24.842Z,1557330564.842 [IBIT](INFO): Initialize IBIT Component.
2019-05-08T15:49:24.843Z,1557330564.843 [CBIT](DEBUG): Initialize CBIT Component.
2019-05-08T15:49:24.844Z,1557330564.844 [logger ThreadHandler](INFO): Handler Thread ID is 1356
2019-05-08T15:49:24.857Z,1557330564.857 [CBIT](DEBUG): Initialized mux pins.
2019-05-08T15:49:24.857Z,1557330564.857 [CBIT](DEBUG): Initializing the watchdog timer.
2019-05-08T15:49:24.861Z,1557330564.861 [DataOverHttps ThreadHandler](INFO): Handler Thread ID is 1357
2019-05-08T15:49:24.862Z,1557330564.862 [DataOverHttps](DEBUG): dashIP=134.89.2.23 starts with a digit so assuming it is a numeric IP
2019-05-08T15:49:24.869Z,1557330564.869 [Radio_Surface ThreadHandler](INFO): Handler Thread ID is 1358
2019-05-08T15:49:24.877Z,1557330564.877 [CTD_NeilBrown ThreadHandler](INFO): Handler Thread ID is 1359
2019-05-08T15:49:24.881Z,1557330564.881 [CBIT](INFO): Last reboot was NOT due to watchdog timer.
2019-05-08T15:49:24.881Z,1557330564.881 [CBIT](DEBUG): Initializing heartbeat.
2019-05-08T15:49:24.889Z,1557330564.889 [WetLabsBB2FL ThreadHandler](INFO): Handler Thread ID is 1360
2019-05-08T15:49:24.890Z,1557330564.890 [WetLabsBB2FL](INFO): Powering down
2019-05-08T15:49:24.917Z,1557330564.917 [NavChartDb ThreadHandler](INFO): Handler Thread ID is 1361
2019-05-08T15:49:24.920Z,1557330564.920 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US1WC07M.000
2019-05-08T15:49:24.921Z,1557330564.921 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US1WC07M.000
2019-05-08T15:49:24.921Z,1557330564.921 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US2WC11M.000
2019-05-08T15:49:24.921Z,1557330564.921 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US2WC11M.000
2019-05-08T15:49:24.921Z,1557330564.921 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US3CA52M.000
2019-05-08T15:49:24.921Z,1557330564.921 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US3CA52M.000
2019-05-08T15:49:24.922Z,1557330564.922 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US4CA60M.000
2019-05-08T15:49:24.922Z,1557330564.922 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US4CA60M.000
2019-05-08T15:49:24.922Z,1557330564.922 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA50M.000
2019-05-08T15:49:24.922Z,1557330564.922 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA50M.000
2019-05-08T15:49:24.922Z,1557330564.922 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA61M.000
2019-05-08T15:49:24.922Z,1557330564.922 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA61M.000
2019-05-08T15:49:24.923Z,1557330564.923 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA62M.000
2019-05-08T15:49:24.923Z,1557330564.923 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA62M.000
2019-05-08T15:49:24.923Z,1557330564.923 [NavChartDb](INFO): Looking for Electronic Nav Chart file at: Resources/ElectronicNavigationCharts/US5CA83M.000
2019-05-08T15:49:24.923Z,1557330564.923 [NavChartDb](INFO): Already Loaded Electronic Nav Chart data from US5CA83M.000
2019-05-08T15:49:24.953Z,1557330564.953 [CBIT](DEBUG): Deactivating GF circuits.
2019-05-08T15:49:24.953Z,1557330564.953 [CBIT](DEBUG): Deactivating emergency mode.
2019-05-08T15:49:24.989Z,1557330564.989 [CBIT](DEBUG): Backplane powered.
2019-05-08T15:49:24.994Z,1557330564.994 [MissionManager](INFO): Loading Mission: Missions/Startup.xml
2019-05-08T15:49:25.007Z,1557330565.007 [Startup:A.GoToSurface](DEBUG): Construct GoToSurface.
2019-05-08T15:49:25.051Z,1557330565.051 [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-05-08T15:49:25.052Z,1557330565.052 [MissionManager](INFO): Loading Mission: Missions/Default.xml
2019-05-08T15:49:25.124Z,1557330565.124 [MissionManager](INFO): DefineArg Default.ElapsedSinceDefaultStarted = 0.000000 min
2019-05-08T15:49:25.133Z,1557330565.133 [Default:A.Wait](DEBUG): Construct Wait.
2019-05-08T15:49:25.135Z,1557330565.135 [Default:B.GoToSurface](DEBUG): Construct GoToSurface.
2019-05-08T15:49:25.157Z,1557330565.157 [Default:CheckIn:Read_Iridium:A_Timeout:A.Execute](DEBUG): Construct Execute.
2019-05-08T15:49:25.160Z,1557330565.160 [Default:CheckIn:C.Wait](DEBUG): Construct Wait.
2019-05-08T15:49:25.193Z,1557330565.193 [Default:E.Execute](DEBUG): Construct Execute.
2019-05-08T15:49:25.213Z,1557330565.213 [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-05-08T15:49:25.217Z,1557330565.217 [controlThread](DEBUG): Component order: CycleStarter,Depth_Keller,NAL9602,Onboard,BPC1,PAR_Licor,Depth_Keller,PAR_Licor,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-05-08T15:49:25.226Z,1557330565.226 [Depth_Keller](ERROR): Pressure reading out of range: 1925.893799 decibar
2019-05-08T15:49:25.273Z,1557330565.273 [Radio_Surface](INFO): Powering up
2019-05-08T15:49:25.349Z,1557330565.349 [DepthRateCalculator](ERROR): Depth measurement is not active
2019-05-08T15:49:25.413Z,1557330565.413 [BuoyancyServo](DEBUG): Initializing EZServoServo.
2019-05-08T15:49:25.415Z,1557330565.415 [BuoyancyServo](DEBUG): Initializing BuoyancyServo.
2019-05-08T15:49:25.416Z,1557330565.416 [ElevatorServo](DEBUG): Initializing EZServoServo.
2019-05-08T15:49:25.417Z,1557330565.417 [ElevatorServo](DEBUG): Initializing ElevatorServo.
2019-05-08T15:49:25.418Z,1557330565.418 [MassServo](DEBUG): Initializing EZServoServo.
2019-05-08T15:49:25.421Z,1557330565.421 [MassServo](DEBUG): Initializing MassServo.
2019-05-08T15:49:25.422Z,1557330565.422 [RudderServo](DEBUG): Initializing EZServoServo.
2019-05-08T15:49:25.425Z,1557330565.425 [RudderServo](DEBUG): Initializing RudderServo.
2019-05-08T15:49:25.426Z,1557330565.426 [ThrusterServo](DEBUG): Initializing EZServoServo.
2019-05-08T15:49:25.437Z,1557330565.437 [ThrusterServo](DEBUG): Initializing ThrusterServo.
2019-05-08T15:49:26.393Z,1557330566.393 [RudderServo](ERROR): Rudder initialization uart error serial timeout
2019-05-08T15:49:26.393Z,1557330566.393 [RudderServo](FAULT): Rudder failed to initialize
2019-05-08T15:49:26.393Z,1557330566.393 [RudderServo] Communications Fault, FailCount= 1
2019-05-08T15:49:26.393Z,1557330566.393 [RudderServo](ERROR): Communications Fault
2019-05-08T15:49:26.504Z,1557330566.504 [CBIT](ERROR): Communications Fault in component: RudderServo
2019-05-08T15:49:26.722Z,1557330566.722 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2019-05-08T15:49:26.722Z,1557330566.722 [RudderServo](INFO): Powering down
2019-05-08T15:49:27.375Z,1557330567.375 [RudderServo](DEBUG): Initializing EZServoServo.
2019-05-08T15:49:27.494Z,1557330567.494 [RudderServo](DEBUG): Initializing RudderServo.
2019-05-08T15:49:27.498Z,1557330567.498 [CBIT](INFO): Clearing failed state for component RudderServo
2019-05-08T15:49:27.498Z,1557330567.498 [RudderServo] No Fault, FailCount= 1
2019-05-08T15:49:36.710Z,1557330576.710 [DataOverHttps](INFO): setting available, lastComms_.elapsed()=0.004517
2019-05-08T15:49:52.847Z,1557330592.847 [NAL9602](INFO): Powering up NAL9602
2019-05-08T15:49:53.294Z,1557330593.294 [SBIT](IMPORTANT): Beginning Startup BIT
2019-05-08T15:49:53.298Z,1557330593.298 [CBIT](IMPORTANT): Beginning ground fault scan
2019-05-08T15:50:02.926Z,1557330602.926 [CommandLine](IMPORTANT): got command get PAR_Licor.multiplier
2019-05-08T15:50:02.927Z,1557330602.927 [CommandLine](IMPORTANT): PAR_Licor.multiplier 186.199997 umol/s/m2/uA
2019-05-08T15:50:04.345Z,1557330604.345 [CBIT](IMPORTANT): No ground fault detected
mA:
CHAN A0 (Batt): 0.001211
CHAN A1 (24V): 0.003534
CHAN A2 (12V): -0.006811
CHAN A3 (5V): -0.002363
CHAN B0 (3.3V): -0.000496
CHAN B1 (3.15aV): -0.000478
CHAN B2 (3.15bV): -0.000514
CHAN B3 (GND): 0.001901
OPEN: -0.000307
Full Scale Calc: 4.765 mA, -1.589 mA
2019-05-08T15:50:06.526Z,1557330606.526 [CommandLine](IMPORTANT): got command quit
2019-05-08T15:50:07.533Z,1557330607.533 [Supervisor](INFO): Stop Mission called by Supervisor::terminate
2019-05-08T15:50:07.533Z,1557330607.533 [CommandLine ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-08T15:50:07.533Z,1557330607.533 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-05-08T15:50:07.609Z,1557330607.609 [Supervisor](DEBUG): Uninitializing supervisor and starting cleanup.  Bye!
2019-05-08T15:50:07.609Z,1557330607.609 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-05-08T15:50:07.609Z,1557330607.609 [CommandLine](INFO): Join timeout helper Thread ID is 1376
2019-05-08T15:50:07.625Z,1557330607.625 [ComponentRegistry](INFO): Shutting down NavChartDb ThreadHandler
2019-05-08T15:50:07.625Z,1557330607.625 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-05-08T15:50:07.625Z,1557330607.625 [NavChartDb](INFO): Join timeout helper Thread ID is 1377
2019-05-08T15:50:08.347Z,1557330608.347 [NavChartDb ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-08T15:50:08.347Z,1557330608.347 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-05-08T15:50:08.361Z,1557330608.361 [ComponentRegistry](INFO): Shutting down WetLabsBB2FL ThreadHandler
2019-05-08T15:50:08.361Z,1557330608.361 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2019-05-08T15:50:08.361Z,1557330608.361 [WetLabsBB2FL](INFO): Join timeout helper Thread ID is 1378
2019-05-08T15:50:08.766Z,1557330608.766 [WetLabsBB2FL ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-08T15:50:08.766Z,1557330608.766 [WetLabsBB2FL](INFO): Powering down
2019-05-08T15:50:08.767Z,1557330608.767 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2019-05-08T15:50:08.781Z,1557330608.781 [ComponentRegistry](INFO): Shutting down CTD_NeilBrown ThreadHandler
2019-05-08T15:50:08.782Z,1557330608.782 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2019-05-08T15:50:08.783Z,1557330608.783 [CTD_NeilBrown](INFO): Join timeout helper Thread ID is 1379
2019-05-08T15:50:08.981Z,1557330608.981 [CTD_NeilBrown ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-08T15:50:08.981Z,1557330608.981 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2019-05-08T15:50:08.993Z,1557330608.993 [ComponentRegistry](INFO): Shutting down Radio_Surface ThreadHandler
2019-05-08T15:50:08.993Z,1557330608.993 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-05-08T15:50:08.993Z,1557330608.993 [Radio_Surface](INFO): Join timeout helper Thread ID is 1380
2019-05-08T15:50:09.309Z,1557330609.309 [Radio_Surface](INFO): Powering down
2019-05-08T15:50:09.310Z,1557330609.310 [Radio_Surface ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-08T15:50:09.310Z,1557330609.310 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-05-08T15:50:09.314Z,1557330609.314 [ComponentRegistry](INFO): Shutting down DataOverHttps ThreadHandler
2019-05-08T15:50:09.314Z,1557330609.314 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-05-08T15:50:09.314Z,1557330609.314 [DataOverHttps](INFO): Join timeout helper Thread ID is 1381
2019-05-08T15:50:09.345Z,1557330609.345 [DataOverHttps ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-08T15:50:09.349Z,1557330609.349 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-05-08T15:50:09.358Z,1557330609.358 [ComponentRegistry](INFO): Shutting down logger ThreadHandler
2019-05-08T15:50:09.358Z,1557330609.358 [logger ThreadHandler](INFO): Thread cancelled.
2019-05-08T15:50:09.358Z,1557330609.358 [logger](INFO): Join timeout helper Thread ID is 1382
2019-05-08T15:50:09.373Z,1557330609.373 [logger ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-08T15:50:09.374Z,1557330609.374 [logger ThreadHandler](INFO): Thread cancelled.
2019-05-08T15:50:09.385Z,1557330609.385 [ComponentRegistry](INFO): Shutting down CommandLine ThreadHandler
2019-05-08T15:50:09.386Z,1557330609.386 [CommandLine ThreadHandler](INFO): Thread cancelled.
2019-05-08T15:50:09.386Z,1557330609.386 [ComponentRegistry](INFO): Shutting down controlThread ThreadHandler
2019-05-08T15:50:09.386Z,1557330609.386 [controlThread ThreadHandler](INFO): Thread cancelled.
2019-05-08T15:50:09.386Z,1557330609.386 [controlThread](INFO): Join timeout helper Thread ID is 1383
2019-05-08T15:50:09.621Z,1557330609.621 [controlThread ThreadHandler](INFO): Uninitializing protected caller thread.
2019-05-08T15:50:09.621Z,1557330609.621 [controlThread](DEBUG): Uninitializing ControlThread
2019-05-08T15:50:09.622Z,1557330609.622 [NAL9602](INFO): Powering down
2019-05-08T15:50:09.624Z,1557330609.624 [DepthRateCalculator](DEBUG): Uninitializing DepthRateCalculator.
2019-05-08T15:50:09.625Z,1557330609.625 [ElevatorOffsetCalculator](DEBUG): Uninitializing ElevatorOffsetCalculator.
2019-05-08T15:50:09.625Z,1557330609.625 [NavChart](DEBUG): Uninitialize NavChart Navigation.
2019-05-08T15:50:09.626Z,1557330609.626 [MissionManager](INFO): Uninitializing Mission Default
2019-05-08T15:50:09.628Z,1557330609.628 [MissionManager](INFO): Uninitializing Mission Startup
2019-05-08T15:50:09.629Z,1557330609.629 [VerticalControl](DEBUG): Uninitialize VerticalControlComponent.
2019-05-08T15:50:09.629Z,1557330609.629 [HorizontalControl](DEBUG): Uninitialize HorizontalControlComponent.
2019-05-08T15:50:09.630Z,1557330609.630 [SpeedControl](DEBUG): Uninitialize SpeedControlComponent.
2019-05-08T15:50:09.630Z,1557330609.630 [LoopControl](DEBUG): Uninitialize LoopControlComponent.
2019-05-08T15:50:09.630Z,1557330609.630 [BuoyancyServo](DEBUG): Uninitialize Buoyancy Servo.
2019-05-08T15:50:09.630Z,1557330609.630 [BuoyancyServo](INFO): Powering down
2019-05-08T15:50:09.645Z,1557330609.645 [ElevatorServo](DEBUG): Uninitialize Elevator Servo.
2019-05-08T15:50:09.645Z,1557330609.645 [ElevatorServo](INFO): Powering down
2019-05-08T15:50:09.646Z,1557330609.646 [MassServo](DEBUG): Uninitialize Mass Servo.
2019-05-08T15:50:09.646Z,1557330609.646 [MassServo](INFO): Powering down
2019-05-08T15:50:09.647Z,1557330609.647 [RudderServo](DEBUG): Uninitialize Rudder Servo.
2019-05-08T15:50:09.647Z,1557330609.647 [RudderServo](INFO): Powering down
2019-05-08T15:50:09.647Z,1557330609.647 [ThrusterServo](DEBUG): Uninitialize Thruster Servo.
2019-05-08T15:50:09.648Z,1557330609.648 [ThrusterServo](INFO): Powering down
2019-05-08T15:50:09.648Z,1557330609.648 [SBIT](DEBUG): Uninitialize SBIT Component.
2019-05-08T15:50:09.649Z,1557330609.649 [IBIT](DEBUG): Uninitialize IBIT Component.
2019-05-08T15:50:09.649Z,1557330609.649 [CBIT](DEBUG): Uninitialize CBIT Component.
2019-05-08T15:50:09.649Z,1557330609.649 [CBIT](DEBUG): Powering off loads.
2019-05-08T15:50:09.661Z,1557330609.661 [CBIT](DEBUG): Disabling WDT.
2019-05-08T15:50:09.673Z,1557330609.673 [CBIT](DEBUG): Opening all GF detection circuits.
2019-05-08T15:50:09.673Z,1557330609.673 [controlThread ThreadHandler](INFO): Thread cancelled.
2019-05-08T15:50:09.758Z,1557330609.758 [Radio_Surface ThreadHandler](INFO): Thread cancelled.
2019-05-08T15:50:09.763Z,1557330609.763 [DataOverHttps ThreadHandler](INFO): Thread cancelled.
2019-05-08T15:50:10.168Z,1557330610.168 [WetLabsBB2FL ThreadHandler](INFO): Thread cancelled.
2019-05-08T15:50:10.171Z,1557330610.171 [CTD_NeilBrown ThreadHandler](INFO): Thread cancelled.
2019-05-08T15:50:10.180Z,1557330610.180 [NavChartDb ThreadHandler](INFO): Thread cancelled.
2019-05-08T15:50:10.233Z,1557330610.233 [logger ThreadHandler](INFO): Thread cancelled.