Uploaded image for project: 'Couchbase C client library libcouchbase'
  1. Couchbase C client library libcouchbase
  2. CCBC-641

improve the logging for view requests.

    XMLWordPrintable

    Details

    • Type: Improvement
    • Status: Resolved
    • Priority: Major
    • Resolution: Fixed
    • Affects Version/s: 2.5.3
    • Fix Version/s: 2.6.2
    • Component/s: library
    • Security Level: Public
    • Labels:
      None

      Description

      With log level 5 I was hoping to see the full url that the view query was making against the node , as I wanted to reproduce this in my browser.

      The only message we get is:

      5ms [I0] {50f} [ERROR] (http-io - L:158) <127.0.0.1:8092>Got parser error while parsing HTTP stream
      

      Here are the full logs:

      0ms [I0] {50f} [INFO] (instance - L:374) Version=2.5.1, Changeset=54ea1fa2e7bd5fef34450d09f2677bb53b6e62ea
      0ms [I0] {50f} [INFO] (instance - L:375) Effective connection string: http://127.0.0.1/default. Bucket=default
      0ms [I0] {50f} [DEBUG] (instance - L:65) Adding host 127.0.0.1:8091 to initial HTTP bootstrap list
      0ms [I0] {50f} [DEBUG] (instance - L:65) Adding host 127.0.0.1:11210 to initial CCCP bootstrap list
      0ms [I0] {50f} [DEBUG] (confmon - L:89) Preparing providers (this may be called multiple times)
      0ms [I0] {50f} [DEBUG] (confmon - L:99) Provider FILE is DISABLED
      0ms [I0] {50f} [DEBUG] (confmon - L:96) Provider CCCP is ENABLED
      0ms [I0] {50f} [DEBUG] (confmon - L:96) Provider HTTP is ENABLED
      0ms [I0] {50f} [DEBUG] (confmon - L:99) Provider MCRAW is DISABLED
      0ms [I0] {50f} [TRACE] (confmon - L:292) Start refresh requested
      0ms [I0] {50f} [TRACE] (confmon - L:271) Current provider is CCCP
      0ms [I0] {50f} [INFO] (cccp - L:118) Requesting connection to node 127.0.0.1:11210 for CCCP configuration
      0ms [I0] {50f} [DEBUG] (lcbio_mgr - L:416) <127.0.0.1:11210> (HE=0x7f941b025400) Creating new connection because none are available in the pool
      0ms [I0] {50f} [DEBUG] (lcbio_mgr - L:321) <127.0.0.1:11210> (HE=0x7f941b025400) Starting connection on I=0x7f941a723910
      0ms [I0] {50f} [INFO] (connection - L:450) <127.0.0.1:11210> (SOCK=0x7f941a723a30) Starting. Timeout=2000000us
      1ms [I0] {50f} [TRACE] (connection - L:267) <127.0.0.1:11210> (SOCK=0x7f941a723a30) Got event handler for new connection
      1ms [I0] {50f} [TRACE] (connection - L:314) <127.0.0.1:11210> (SOCK=0x7f941a723a30) Scheduling asynchronous watch for socket.
      1ms [I0] {50f} [TRACE] (connection - L:267) <127.0.0.1:11210> (SOCK=0x7f941a723a30) Got event handler for new connection
      1ms [I0] {50f} [INFO] (connection - L:116) <127.0.0.1:11210> (SOCK=0x7f941a723a30) Connected 
      1ms [I0] {50f} [DEBUG] (connection - L:123) <127.0.0.1:11210> (SOCK=0x7f941a723a30) Successfuly set TCP_NODELAY
      1ms [I0] {50f} [DEBUG] (lcbio_mgr - L:271) <127.0.0.1:11210> (HE=0x7f941b025400) Received result for I=0x7f941a723910,C=0x7f941a723a30; E=0x0
      1ms [I0] {50f} [DEBUG] (lcbio_mgr - L:223) <127.0.0.1:11210> (HE=0x7f941b025400) Assigning R=0x7f941a723710 SOCKET=0x7f941a723a30
      1ms [I0] {50f} [DEBUG] (ioctx - L:101) <127.0.0.1:11210> (CTX=0x7f941a723ff0,unknown) Pairing with SOCK=0x7f941a723a30
      1ms [I0] {50f} [DEBUG] (negotiation - L:355) <127.0.0.1:11210> (SASLREQ=0x7f941a723850) Found feature 0x3 (TCP NODELAY)
      1ms [I0] {50f} [DEBUG] (ioctx - L:151) <127.0.0.1:11210> (CTX=0x7f941a723ff0,sasl) Destroying. PND=0,ENT=1,SORC=1
      1ms [I0] {50f} [DEBUG] (ioctx - L:101) <127.0.0.1:11210> (CTX=0x7f941b9003b0,unknown) Pairing with SOCK=0x7f941a723a30
      2ms [I0] {50f} [DEBUG] (ioctx - L:151) <127.0.0.1:11210> (CTX=0x7f941b9003b0,bc_cccp) Destroying. PND=0,ENT=1,SORC=1
      2ms [I0] {50f} [INFO] (lcbio_mgr - L:491) <127.0.0.1:11210> (HE=0x7f941b025400) Placing socket back into the pool. I=0x7f941a723910,C=0x7f941a723a30
      2ms [I0] {50f} [INFO] (confmon - L:174) Setting new configuration. Received via CCCP
      2ms [I0] {50f} [DEBUG] (bootstrap - L:55) Instance configured!
      2ms [I0] {50f} [DEBUG] (confmon - L:89) Preparing providers (this may be called multiple times)
      2ms [I0] {50f} [DEBUG] (confmon - L:99) Provider FILE is DISABLED
      2ms [I0] {50f} [DEBUG] (confmon - L:96) Provider CCCP is ENABLED
      2ms [I0] {50f} [DEBUG] (confmon - L:99) Provider HTTP is DISABLED
      2ms [I0] {50f} [DEBUG] (confmon - L:99) Provider MCRAW is DISABLED
      2ms [I0] {50f} [DEBUG] (lcbio_mgr - L:416) <127.0.0.1:8092> (HE=0x7f941d000000) Creating new connection because none are available in the pool
      2ms [I0] {50f} [DEBUG] (lcbio_mgr - L:321) <127.0.0.1:8092> (HE=0x7f941d000000) Starting connection on I=0x7f941bb01340
      2ms [I0] {50f} [INFO] (connection - L:450) <127.0.0.1:8092> (SOCK=0x7f941bb01460) Starting. Timeout=75000000us
      2ms [I0] {50f} [TRACE] (connection - L:267) <127.0.0.1:8092> (SOCK=0x7f941bb01460) Got event handler for new connection
      2ms [I0] {50f} [TRACE] (connection - L:314) <127.0.0.1:8092> (SOCK=0x7f941bb01460) Scheduling asynchronous watch for socket.
      2ms [I0] {50f} [TRACE] (connection - L:267) <127.0.0.1:8092> (SOCK=0x7f941bb01460) Got event handler for new connection
      2ms [I0] {50f} [INFO] (connection - L:116) <127.0.0.1:8092> (SOCK=0x7f941bb01460) Connected 
      2ms [I0] {50f} [DEBUG] (connection - L:123) <127.0.0.1:8092> (SOCK=0x7f941bb01460) Successfuly set TCP_NODELAY
      2ms [I0] {50f} [DEBUG] (lcbio_mgr - L:271) <127.0.0.1:8092> (HE=0x7f941d000000) Received result for I=0x7f941bb01340,C=0x7f941bb01460; E=0x0
      2ms [I0] {50f} [DEBUG] (lcbio_mgr - L:223) <127.0.0.1:8092> (HE=0x7f941d000000) Assigning R=0x7f941bb01140 SOCKET=0x7f941bb01460
      2ms [I0] {50f} [DEBUG] (ioctx - L:101) <127.0.0.1:8092> (CTX=0x7f941b800270,unknown) Pairing with SOCK=0x7f941bb01460
      5ms [I0] {50f} [ERROR] (http-io - L:158) <127.0.0.1:8092>Got parser error while parsing HTTP stream
      5ms [I0] {50f} [TRACE] (confmon - L:292) Start refresh requested
      5ms [I0] {50f} [DEBUG] (ioctx - L:151) <127.0.0.1:8092> (CTX=0x7f941b800270,mgmt/capi) Destroying. PND=0,ENT=1,SORC=1
      PHP Fatal error:  Uncaught exception 'CouchbaseException' with message 'Data received on socket was not in the expected format' in [CouchbaseNative]/CouchbaseBucket.class.php:282
      

        Attachments

        No reviews matched the request. Check your Options in the drop-down menu of this sections header.

          Activity

          Hide
          mnunberg Mark Nunberg (Inactive) added a comment -

          I think this is a good suggestion, but PHP should allow you to print out the query that is being generated, rather than lcb itself. I remember in the php 1.x SDK I implemented a function which did exactly that: generated the query string and returned it (taking the same inputs as the query function itself).

          Show
          mnunberg Mark Nunberg (Inactive) added a comment - I think this is a good suggestion, but PHP should allow you to print out the query that is being generated, rather than lcb itself. I remember in the php 1.x SDK I implemented a function which did exactly that: generated the query string and returned it (taking the same inputs as the query function itself).
          Hide
          mnunberg Mark Nunberg (Inactive) added a comment -

          We might add logging of all URLs eventually..

          Show
          mnunberg Mark Nunberg (Inactive) added a comment - We might add logging of all URLs eventually..

            People

            • Assignee:
              mnunberg Mark Nunberg (Inactive)
              Reporter:
              pvarley Patrick Varley
            • Votes:
              0 Vote for this issue
              Watchers:
              2 Start watching this issue

              Dates

              • Created:
                Updated:
                Resolved:

                Gerrit Reviews

                There are no open Gerrit changes

                  PagerDuty

                  Error rendering 'com.pagerduty.jira-server-plugin:PagerDuty'. Please contact your Jira administrators.