Uploaded image for project: 'Java Couchbase JVM Core'
  1. Java Couchbase JVM Core
  2. JVMCBC-545

improve logging on socket connect timeout

    XMLWordPrintable

Details

    • Improvement
    • Resolution: Fixed
    • Major
    • 1.5.9
    • None
    • Core
    • None
    • 1

    Description

      If a connection cannot be established, the log message is along the lines of:

      [5/31/18 11:48:45:495 MST] 0000009f SystemOut     O 11:48:45.492 [RxComputationScheduler-9] WARN  c.c.client.core.endpoint.Endpoint - [][KeyValueEndpoint]: Socket connect took longer than specified timeout..

      Unfortunately, that does not identify the host/port or the timeout. Looking at the code, the underlying exception does return a string, but we don't include that in our log message. Also, we don't log the configured timeout, if any. It'd be great to improve this with more context.

      A full log message from an environment where it's not understood what's happening at the moment is:

      [5/31/18 11:48:45:495 MST] 0000009f SystemOut     O 11:48:45.492 [RxComputationScheduler-9] WARN  c.c.client.core.endpoint.Endpoint - [][KeyValueEndpoint]: Socket connect took longer than specified timeout..
      		 
      [5/31/18 11:48:45:496 MST] 000000a0 SystemOut     O 11:48:45.492 [RxComputationScheduler-10] WARN  c.c.client.core.endpoint.Endpoint - [][KeyValueEndpoint]: Socket connect took longer than specified timeout..
      		 
      [5/31/18 11:48:45:498 MST] 000001d3 SystemOut     O 11:48:45.492 [RxComputationScheduler-20] WARN  c.c.client.core.endpoint.Endpoint - [][KeyValueEndpoint]: Socket connect took longer than specified timeout..
      		 
      [5/31/18 11:48:45:500 MST] 0000009f SystemOut     O 11:48:45.496 [RxComputationScheduler-9] WARN  c.c.client.core.endpoint.Endpoint - [][KeyValueEndpoint]: Could not connect to endpoint, retrying with delay 4096 MILLISECONDS: com.couchbase.client.deps.io.netty.channel.ConnectTimeoutException: Connect callback did not return, hit safeguarding timeout.
      		 
      [5/31/18 11:48:45:502 MST] 000001d4 SystemOut     O 11:48:45.495 [RxComputationScheduler-21] WARN  c.c.client.core.endpoint.Endpoint - [][KeyValueEndpoint]: Could not connect to endpoint, retrying with delay 4096 MILLISECONDS: com.couchbase.client.deps.io.netty.channel.ConnectTimeoutException: Connect callback did not return, hit safeguarding timeout.
      		 
      [5/31/18 11:48:45:504 MST] 000000a0 SystemOut     O 11:48:45.498 [RxComputationScheduler-10] WARN  c.c.client.core.endpoint.Endpoint - [][KeyValueEndpoint]: Could not connect to endpoint, retrying with delay 4096 MILLISECONDS: com.couchbase.client.deps.io.netty.channel.ConnectTimeoutException: Connect callback did not return, hit safeguarding timeout.
      		 
      [5/31/18 11:48:45:506 MST] 000001d3 SystemOut     O 11:48:45.500 [RxComputationScheduler-20] WARN  c.c.client.core.endpoint.Endpoint - [][KeyValueEndpoint]: Could not connect to endpoint, retrying with delay 4096 MILLISECONDS: com.couchbase.client.deps.io.netty.channel.ConnectTimeoutException: Connect callback did not return, hit safeguarding timeout.
      		 
      [5/31/18 11:48:52:778 MST] 000000a1 SystemOut     O 11:48:52.777 [RxComputationScheduler-11] WARN  c.c.client.core.endpoint.Endpoint - [][KeyValueEndpoint]: Socket connect took longer than specified timeout..
      		 
      [5/31/18 11:48:52:780 MST] 000001d5 SystemOut     O 11:48:52.777 [RxComputationScheduler-22] WARN  c.c.client.core.endpoint.Endpoint - [][KeyValueEndpoint]: Socket connect took longer than specified timeout..
      		 
      [5/31/18 11:48:52:782 MST] 000000a2 SystemOut     O 11:48:52.778 [RxComputationScheduler-12] WARN  c.c.client.core.endpoint.Endpoint - [][KeyValueEndpoint]: Socket connect took longer than specified timeout..
      		 
      [5/31/18 11:48:52:783 MST] 000001d6 SystemOut     O 11:48:52.777 [RxComputationScheduler-23] WARN  c.c.client.core.endpoint.Endpoint - [][KeyValueEndpoint]: Socket connect took longer than specified timeout..
      		 
      [5/31/18 11:48:52:785 MST] 000000a1 SystemOut     O 11:48:52.780 [RxComputationScheduler-11] WARN  c.c.client.core.endpoint.Endpoint - [][KeyValueEndpoint]: Could not connect to endpoint, retrying with delay 4096 MILLISECONDS: com.couchbase.client.deps.io.netty.channel.ConnectTimeoutException: Connect callback did not return, hit safeguarding timeout.
      		 
      [5/31/18 11:48:52:787 MST] 000001d5 SystemOut     O 11:48:52.781 [RxComputationScheduler-22] WARN  c.c.client.core.endpoint.Endpoint - [][KeyValueEndpoint]: Could not connect to endpoint, retrying with delay 4096 MILLISECONDS: com.couchbase.client.deps.io.netty.channel.ConnectTimeoutException: Connect callback did not return, hit safeguarding timeout.
      		 
      [5/31/18 11:48:52:788 MST] 000000a2 SystemOut     O 11:48:52.783 [RxComputationScheduler-12] WARN  c.c.client.core.endpoint.Endpoint - [][KeyValueEndpoint]: Could not connect to endpoint, retrying with delay 4096 MILLISECONDS: com.couchbase.client.deps.io.netty.channel.ConnectTimeoutException: Connect callback did not return, hit safeguarding timeout.
      		 
      [5/31/18 11:48:52:790 MST] 000001d6 SystemOut     O 11:48:52.785 [RxComputationScheduler-23] WARN  c.c.client.core.endpoint.Endpoint - [][KeyValueEndpoint]: Could not connect to endpoint, retrying with delay 4096 MILLISECONDS: com.couchbase.client.deps.io.netty.channel.ConnectTimeoutException: Connect callback did not return, hit safeguarding timeout.

      Attachments

        For Gerrit Dashboard: JVMCBC-545
        # Subject Branch Project Status CR V
        95151,3 JVMCBC-545 Improve logging on Endpoint master couchbase-jvm-core Status: MERGED +2 +1
        95223,2 JVMCBC-545 Improve logging on Endpoint release15 couchbase-jvm-core Status: MERGED +2 +1

        Activity

          People

            subhashni Subhashni Balakrishnan (Inactive)
            ingenthr Matt Ingenthron
            Votes:
            0 Vote for this issue
            Watchers:
            1 Start watching this issue

            Dates

              Created:
              Updated:
              Resolved:

              Gerrit Reviews

                There are no open Gerrit changes

                PagerDuty