Uploaded image for project: 'Couchbase Server'
  1. Couchbase Server
  2. MB-48655

DCP client with { or } in the name doesn't log DCP messages in memcached log

    XMLWordPrintable

Details

    • Bug
    • Status: Closed
    • Major
    • Resolution: Fixed
    • 6.6.2, 7.0.0, 6.6.3, 7.0.2, 7.0.1
    • 7.1.0
    • couchbase-bucket
    • None
    • Triaged
    • 1
    • Unknown

    Description

      Observed that the kafka DCP connector connected, created a DCP producer and associated streams, yet none of this activity was logged.

      This occurs because the DCP name chosen includes "{" and "}" and that fails to log

      This is an issue for 6 and 7 but appears fixed in 7.1

      Attachments

        Issue Links

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

          Activity

            jwalker Jim Walker added a comment -

            Reproduce with 6.6.3 and the following name

            eq_dcpq:{"i":"540AA7A2EA8ED9FE/D6558E4C4AA86D91","a":"kafka-connector/4.0.6 (test-couchbase-source) java-dcp-client/0.34.0 Java/17 (Homebrew; OpenJDK 64-Bit Server VM; 17+0) OS (Mac OS X; 10.15.7; x86_64)"}
            

            I see no stream request messages, but do have a connector and some backfill messages (logged with EP_LOG_INFO)

            jwalker Jim Walker added a comment - Reproduce with 6.6.3 and the following name eq_dcpq:{"i":"540AA7A2EA8ED9FE/D6558E4C4AA86D91","a":"kafka-connector/4.0.6 (test-couchbase-source) java-dcp-client/0.34.0 Java/17 (Homebrew; OpenJDK 64-Bit Server VM; 17+0) OS (Mac OS X; 10.15.7; x86_64)"} I see no stream request messages, but do have a connector and some backfill messages (logged with EP_LOG_INFO)
            jwalker Jim Walker added a comment -

            The kafka name which becomes the log prefix for the DCP logging upsets spdlog, in babysitter

            [*** LOG ERROR ***] [2021-09-29 09:32:00] [travel-sample.139713464761872] invalid format string
            

            jwalker Jim Walker added a comment - The kafka name which becomes the log prefix for the DCP logging upsets spdlog, in babysitter [*** LOG ERROR ***] [2021-09-29 09:32:00] [travel-sample.139713464761872] invalid format string
            jwalker Jim Walker added a comment -

            Not yet reproducible in master (currently have a neo checkout), this could be fixed in a recent spdlog/fmtlib - to be confirmed

            jwalker Jim Walker added a comment - Not yet reproducible in master (currently have a neo checkout), this could be fixed in a recent spdlog/fmtlib - to be confirmed
            jwalker Jim Walker added a comment -

            Tested following names (using dcpdrain)

            • jim
            • {jim}
            • jim}
            • {jim

            So the use of { means we fail to log

            jwalker Jim Walker added a comment - Tested following names (using dcpdrain) jim { jim } jim } { jim So the use of { means we fail to log
            jwalker Jim Walker added a comment -

            7.0 fails as well, more detail in babysitter

            [ns_server:info,2021-09-29T10:41:47.352Z,babysitter_of_ns_1@cb.local:<0.129.0>:ns_port_server:log:221]memcached<0.129.0>: [*** LOG ERROR ***] [2021-09-29 10:41:47] [travel-sample.139658720304192] unmatched '}' in format string
            

            jwalker Jim Walker added a comment - 7.0 fails as well, more detail in babysitter [ns_server:info,2021-09-29T10:41:47.352Z,babysitter_of_ns_1@cb.local:<0.129.0>:ns_port_server:log:221]memcached<0.129.0>: [*** LOG ERROR ***] [2021-09-29 10:41:47] [travel-sample.139658720304192] unmatched '}' in format string
            jwalker Jim Walker added a comment -

            Fine in 7.1 (neo checked 7.1.0-1378)

            jwalker Jim Walker added a comment - Fine in 7.1 (neo checked 7.1.0-1378)
            drigby Dave Rigby added a comment -

            Bumping to major - for the versions which this affects; does cause issues in understanding what the DCP client is doing.

            drigby Dave Rigby added a comment - Bumping to major - for the versions which this affects; does cause issues in understanding what the DCP client is doing.
            drigby Dave Rigby added a comment -

            "Fixed" in Neo (the code in that area has changed and the '{' is escaped correctly). Resolving as this doesn't meet the criteria for backporting to previous releases.

            drigby Dave Rigby added a comment - "Fixed" in Neo (the code in that area has changed and the '{' is escaped correctly). Resolving as this doesn't meet the criteria for backporting to previous releases.
            ritam.sharma Ritam Sharma added a comment -

            Arunkumar Senthilnathan - Can one of your team member validate it from Kafka.

            ritam.sharma Ritam Sharma added a comment - Arunkumar Senthilnathan  - Can one of your team member validate it from Kafka.

            Verified with Enterprise Edition 7.1.0 build 2534 and we can see the Kafka DCP logs now:

            2022-03-28T08:09:20.758038-07:00 WARNING 80: (travel-sample) DCP (Producer) eq_dcpq:"i":"0B4C9109E91C764F/E5685E7FE807F790","a":"kafka-connector/4.1.6 (test-couchbase-source) java-dcp-client/0.40.0 Java/17.0.2 (Oracle Corporation; OpenJDK 64-Bit Server VM; 17.0.2+8-86) OS (Mac OS" - (vb:63) Stream closing, sent until seqno 963 remaining items 0, reason: The stream closed early because the conn was disconnected
            2022-03-28T08:09:21.560752-07:00 INFO 82: (travel-sample) DCP (Producer) eq_dcpq:"i":"0B4C9109E91C764F/81DE1ED0CEDBEE0C","a":"kafka-connector/4.1.6 (test-couchbase-source) java-dcp-client/0.40.0 Java/17.0.2 (Oracle Corporation; OpenJDK 64-Bit Server VM; 17.0.2+8-86) OS (Mac OS" - Destroying connection. Created 33 s ago. Paused 301 times, for 32 s total. Details: {"Initializing": {"count":1, "duration":"146 us"},"ReadyListEmpty": {"count":300, "duration":"32 s"}}
            2022-03-28T08:09:21.560787-07:00 INFO 80: (travel-sample) DCP (Producer) eq_dcpq:"i":"0B4C9109E91C764F/E5685E7FE807F790","a":"kafka-connector/4.1.6 (test-couchbase-source) java-dcp-client/0.40.0 Java/17.0.2 (Oracle Corporation; OpenJDK 64-Bit Server VM; 17.0.2+8-86) OS (Mac OS" - Destroying connection. Created 33 s ago. Paused 279 times, for 31 s total. Details: {"Initializing": {"count":1, "duration":"16 us"},"ReadyListEmpty": {"count":278, "duration":"31 s"}}

            praneeth.bokka Praneeth Bokka added a comment - Verified with Enterprise Edition 7.1.0 build 2534 and we can see the Kafka DCP logs now: 2022-03-28T08:09:20.758038-07:00 WARNING 80: (travel-sample) DCP (Producer) eq_dcpq:"i":"0B4C9109E91C764F/E5685E7FE807F790","a":"kafka-connector/4.1.6 (test-couchbase-source) java-dcp-client/0.40.0 Java/17.0.2 (Oracle Corporation; OpenJDK 64-Bit Server VM; 17.0.2+8-86) OS (Mac OS" - (vb:63) Stream closing, sent until seqno 963 remaining items 0, reason: The stream closed early because the conn was disconnected 2022-03-28T08:09:21.560752-07:00 INFO 82: (travel-sample) DCP (Producer) eq_dcpq:"i":"0B4C9109E91C764F/81DE1ED0CEDBEE0C","a":"kafka-connector/4.1.6 (test-couchbase-source) java-dcp-client/0.40.0 Java/17.0.2 (Oracle Corporation; OpenJDK 64-Bit Server VM; 17.0.2+8-86) OS (Mac OS" - Destroying connection. Created 33 s ago. Paused 301 times, for 32 s total. Details: {"Initializing": {"count":1, "duration":"146 us"},"ReadyListEmpty": {"count":300, "duration":"32 s"}} 2022-03-28T08:09:21.560787-07:00 INFO 80: (travel-sample) DCP (Producer) eq_dcpq:"i":"0B4C9109E91C764F/E5685E7FE807F790","a":"kafka-connector/4.1.6 (test-couchbase-source) java-dcp-client/0.40.0 Java/17.0.2 (Oracle Corporation; OpenJDK 64-Bit Server VM; 17.0.2+8-86) OS (Mac OS" - Destroying connection. Created 33 s ago. Paused 279 times, for 31 s total. Details: {"Initializing": {"count":1, "duration":"16 us"},"ReadyListEmpty": {"count":278, "duration":"31 s"}}

            People

              praneeth.bokka Praneeth Bokka
              jwalker Jim Walker
              Votes:
              0 Vote for this issue
              Watchers:
              8 Start watching this issue

              Dates

                Created:
                Updated:
                Resolved:

                Gerrit Reviews

                  There are no open Gerrit changes

                  PagerDuty