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

1 Timer callback failed with LCB_ERR_BUCKET_NOT_FOUND

    XMLWordPrintable

Details

    • Untriaged
    • 1
    • Unknown

    Description

      Build: 7.0.0-4454

      Test: Rebalance multiple kv nodes

      ./testrunner -i /tmp/testexec.120861.ini -p get-cbcollect-info=True,GROUP=bucket_op,skip_log_scan=False,bucket_storage=couchstore -t eventing.eventing_rebalance_collection.EventingRebalanceCollection.test_eventing_rebalance_with_multiple_kv_nodes,doc-per-day=5,dataset=default,nodes_init=5,services_init=kv-kv-kv-eventing-index:n1ql,groups=simple,reset_services=True,GROUP=bucket_op,doc-per-day=20,java_sdk_client=True
       
      Exception: duplicated data in destination bucket which is not expected. Current : 1 Expected : 0  dcp_backlog : 0  TIMERS_IN_PAST : 0 lcb_exceptions : {'172.23.122.117': {}} 

      Seeing Timer callback failed on 172.23.122.117

      {
              "dcp_feed_boundary": "everything",
              "event_processing_stats": {
                  "adhoc_timer_response_received": 12,
                  "agg_messages_sent_to_worker": 109370,
                  "agg_queue_memory": 0,
                  "agg_queue_memory_cap": 53477376,
                  "agg_queue_size": 0,
                  "agg_queue_size_cap": 100000,
                  "agg_timer_feedback_queue_cap": 500,
                  "dcp_deletion": 97933,
                  "dcp_deletion_sent_to_worker": 41338,
                  "dcp_mutation": 221975,
                  "dcp_mutation_sent_to_worker": 58596,
                  "dcp_snapshot": 183630,
                  "dcp_stream_req_counter": 8318,
                  "dcp_stream_req_err_counter": 5304,
                  "dcp_streamend": 1460,
                  "dcp_streamreq": 3014,
                  "dcp_system_event": 10240,
                  "execution_stats": 1096,
                  "failure_stats": 1096,
                  "latency_stats": 1096,
                  "lcb_exception_stats": 1096,
                  "log_level": 1,
                  "num_processed_events": 99934,
                  "processed_events_size": 63702196,
                  "thr_count": 1,
                  "thr_map": 1,
                  "timer_events": 80640,
                  "timer_responses_received": 80640,
                  "v8_init": 1,
                  "v8_load": 1
              },
              "events_remaining": {
                  "dcp_backlog": 0
              },
              "execution_stats": {
                  "agg_queue_memory": 0,
                  "agg_queue_size": 0,
                  "curl": {
                      "delete": 0,
                      "get": 0,
                      "head": 0,
                      "post": 0,
                      "put": 0
                  },
                  "curl_success_count": 0,
                  "dcp_delete_msg_counter": 41338,
                  "dcp_delete_parse_failure": 0,
                  "dcp_mutation_msg_counter": 58596,
                  "dcp_mutation_parse_failure": 0,
                  "enqueued_dcp_delete_msg_counter": 41338,
                  "enqueued_dcp_mutation_msg_counter": 58596,
                  "enqueued_timer_msg_counter": 0,
                  "feedback_queue_size": 0,
                  "filtered_dcp_delete_counter": 0,
                  "filtered_dcp_mutation_counter": 19294,
                  "lcb_retry_failure": 0,
                  "messages_parsed": 109361,
                  "num_processed_events": 99934,
                  "on_delete_failure": 0,
                  "on_delete_success": 40320,
                  "on_update_failure": 0,
                  "on_update_success": 40320,
                  "processed_events_size": 63702196,
                  "timer_callback_failure": 1,
                  "timer_callback_success": 80639,
                  "timer_cancel_counter": 0,
                  "timer_create_counter": 80640,
                  "timer_create_failure": 0,
                  "timer_msg_counter": 80640,
                  "timer_responses_sent": 0,
                  "timestamp": {
                      "84204": "2021-02-13T06:57:27Z"
                  },
                  "uv_msg_parse_failure": 0,
                  "uv_try_write_failure_counter": 0
              },
              "failure_stats": {
                  "app_worker_setting_events_lost": 0,
                  "bkt_ops_cas_mismatch_count": 0,
                  "bucket_op_exception_count": 1,
                  "checkpoint_failure_count": 0,
                  "curl_failure_count": 0,
                  "curl_max_resp_size_exceeded": 0,
                  "curl_non_200_response": 0,
                  "curl_timeout_count": 0,
                  "dcp_events_lost": 0,
                  "debugger_events_lost": 0,
                  "delete_events_lost": 0,
                  "mutation_events_lost": 0,
                  "n1ql_op_exception_count": 0,
                  "timeout_count": 0,
                  "timer_callback_missing_counter": 0,
                  "timer_context_size_exceeded_counter": 0,
                  "timer_events_lost": 0,
                  "timestamp": {
                      "84204": "2021-02-13T06:57:27Z"
                  },
                  "v8worker_events_lost": 0
              },
              "function_id": 1452344633,
              "function_name": "timers",
              "gocb_creds_request_counter": 133,
              "internal_vb_distribution_stats": {
                  "worker_timers_0": "[0-1023]"
              },
              "latency_percentile_stats": {
                  "100": 511900,
                  "50": 1300,
                  "80": 1800,
                  "90": 2400,
                  "95": 3500,
                  "99": 9800
              },
              "lcb_creds_request_counter": 80787,
              "lcb_exception_stats": {
                  "210": 1
              },
              "metastore_stats": {
                  "metastore_delete_err": 0,
                  "metastore_deletes": 0,
                  "metastore_not_found": 0,
                  "metastore_scan": 0,
                  "metastore_scan_due": 0,
                  "metastore_scan_err": 0,
                  "metastore_set": 0,
                  "metastore_set_err": 0
              } 

      Attachments

        1. test-1.log
          358 kB
        2. test.log
          269 kB
        3. test_logs.txt
          818 kB
        4. cbcollect_info_ns_1@172.23.106.67_20210311-185048,ns_server.eventing.log
          25.49 MB
        5. 172.23.123.62-20210212-2302-diag.zip
          33.47 MB
        6. 172.23.123.61-20210212-2302-diag.zip
          34.60 MB
        7. 172.23.123.44-20210222-1750-diag.zip
          24.16 MB
        8. 172.23.123.42-20210222-1750-diag.zip
          37.02 MB
        9. 172.23.122.97-20210212-2302-diag.zip
          44.00 MB
        10. 172.23.122.90-20210212-2302-diag.zip
          39.23 MB
        11. 172.23.122.82-20210212-2302-diag.zip
          28.21 MB
        12. 172.23.122.180-20210222-1750-diag.zip
          27.04 MB
        13. 172.23.122.134-20210222-1750-diag.zip
          16.82 MB
        14. 172.23.122.133-20210222-1750-diag.zip
          24.12 MB
        15. 172.23.122.132-20210222-1750-diag.zip
          20.63 MB
        16. 172.23.122.131-20210222-1750-diag.zip
          20.47 MB
        17. 172.23.122.130-20210222-1750-diag.zip
          10.73 MB
        18. 172.23.122.118-20210212-2302-diag.zip
          20.81 MB
        19. 172.23.122.117-20210212-2302-diag.zip
          23.08 MB
        20. 172.23.122.116-20210212-2302-diag.zip
          6.73 MB
        21. 172.23.106.81-20210405-1727-diag.zip
          6.65 MB
        22. 172.23.106.81-20210311-1050-diag.zip
          6.53 MB
        23. 172.23.106.80-20210405-1727-diag.zip
          8.27 MB
        24. 172.23.106.80-20210311-1050-diag.zip
          9.44 MB
        25. 172.23.106.79-20210405-1727-diag.zip
          8.34 MB
        26. 172.23.106.79-20210311-1050-diag.zip
          9.60 MB
        27. 172.23.106.78-20210405-1727-diag.zip
          8.33 MB
        28. 172.23.106.78-20210311-1050-diag.zip
          9.58 MB
        29. 172.23.106.77-20210405-1727-diag.zip
          8.43 MB
        30. 172.23.106.77-20210311-1050-diag.zip
          9.70 MB
        31. 172.23.106.76-20210405-1727-diag.zip
          8.72 MB
        32. 172.23.106.76-20210311-1050-diag.zip
          9.97 MB
        33. 172.23.106.75-20210405-1727-diag.zip
          10.23 MB
        34. 172.23.106.75-20210311-1050-diag.zip
          11.57 MB
        35. 172.23.106.74-20210405-1727-diag.zip
          11.28 MB
        36. 172.23.106.74-20210311-1050-diag.zip
          13.22 MB
        37. 172.23.106.73-20210405-1727-diag.zip
          10.05 MB
        38. 172.23.106.73-20210311-1050-diag.zip
          11.59 MB
        39. 172.23.106.67-20210405-1727-diag.zip
          9.30 MB
        40. 172.23.106.67-20210311-1050-diag.zip
          10.96 MB
        41. 172.23.106.64-20210405-1727-diag.zip
          9.60 MB
        42. 172.23.106.64-20210311-1050-diag.zip
          13.39 MB
        43. 172.23.106.6-20210214-2147-diag.zip
          18.31 MB
        44. 172.23.104.249-20210214-2147-diag.zip
          20.65 MB
        45. 172.23.104.248-20210214-2147-diag.zip
          8.53 MB
        46. 172.23.104.247-20210214-2147-diag.zip
          6.56 MB
        47. 172.23.104.246-20210214-2147-diag.zip
          20.86 MB
        48. 172.23.104.245-20210214-2147-diag.zip
          9.54 MB
        49. 172.23.104.243-20210214-2147-diag.zip
          18.61 MB
        50. 172.23.104.237-20210214-2147-diag.zip
          21.46 MB

        Issue Links

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

          Activity

            chanabasappa.ghali Chanabasappa Ghali added a comment - - edited

            Matt Ingenthron while running with toy build 12746following exceptions are found and same is communicated to dev team with logs.
            ERROR: test_rebalance_in_with_different_topologies (eventing.eventing_rebalance_collection.EventingRebalanceCollection)
            ----------------------------------------------------------------------
            Traceback (most recent call last):
            File "pytests/eventing/eventing_rebalance_collection.py", line 403, in test_rebalance_in_with_different_topologies
            self.verify_doc_count_collections("src_bucket.scope_1.coll_1", self.docs_per_day * self.num_docs * 2)
            File "./pytests/eventing/eventing_base.py", line 1047, in verify_doc_count_collections
            actual_count, expected_count, total_dcp_backlog, timers_in_past, lcb))
            Exception: missing data in destination bucket. Current : 63710 Expected : 80640 dcp_backlog : 0 TIMERS_IN_PAST : 0 lcb_exceptions : {'172.23.108.238': {}, '172.23.108.239': {}, '172.23.108.46': {}}----------------------------------------------------------------------
            Ran 1 test in 1833.389s

            ======================================================================
            ERROR: test_killing_eventing_processes_during_eventing_rebalance (eventing.eventing_rebalance.EventingRebalance)
            ----------------------------------------------------------------------
            Traceback (most recent call last):
            File "pytests/eventing/eventing_rebalance.py", line 1391, in test_killing_eventing_processes_during_eventing_rebalance
            self.verify_eventing_results(self.function_name, 0, skip_stats_validation=True)
            File "./pytests/eventing/eventing_base.py", line 377, in verify_eventing_results
            timers_in_past,lcb))
            Exception: duplicated data in destination bucket which is not expected. Current : 22452 Expected : 0 dcp_backlog : 0 TIMERS_IN_PAST : 0 lcb_exceptions : {'172.23.97.220':

            {'12009': 960327, '405': 960327}

            , '172.23.97.221': {'12009': 667824, '405': 667824}, '172.23.97.222': {}}

            ----------------------------------------------------------------------
            Ran 1 test in 1580.318s

            chanabasappa.ghali Chanabasappa Ghali added a comment - - edited Matt Ingenthron  while running with toy build 12746following exceptions are found and same is communicated to dev team with logs. ERROR: test_rebalance_in_with_different_topologies (eventing.eventing_rebalance_collection.EventingRebalanceCollection) ---------------------------------------------------------------------- Traceback (most recent call last): File "pytests/eventing/eventing_rebalance_collection.py", line 403, in test_rebalance_in_with_different_topologies self.verify_doc_count_collections("src_bucket.scope_1.coll_1", self.docs_per_day * self.num_docs * 2) File "./pytests/eventing/eventing_base.py", line 1047, in verify_doc_count_collections actual_count, expected_count, total_dcp_backlog, timers_in_past, lcb)) Exception: missing data in destination bucket. Current : 63710 Expected : 80640 dcp_backlog : 0 TIMERS_IN_PAST : 0 lcb_exceptions : {'172.23.108.238': {}, '172.23.108.239': {}, '172.23.108.46': {}}---------------------------------------------------------------------- Ran 1 test in 1833.389s ====================================================================== ERROR: test_killing_eventing_processes_during_eventing_rebalance (eventing.eventing_rebalance.EventingRebalance) ---------------------------------------------------------------------- Traceback (most recent call last): File "pytests/eventing/eventing_rebalance.py", line 1391, in test_killing_eventing_processes_during_eventing_rebalance self.verify_eventing_results(self.function_name, 0, skip_stats_validation=True) File "./pytests/eventing/eventing_base.py", line 377, in verify_eventing_results timers_in_past,lcb)) Exception: duplicated data in destination bucket which is not expected. Current : 22452 Expected : 0 dcp_backlog : 0 TIMERS_IN_PAST : 0 lcb_exceptions : {'172.23.97.220': {'12009': 960327, '405': 960327} , '172.23.97.221': {'12009': 667824, '405': 667824}, '172.23.97.222': {}} ---------------------------------------------------------------------- Ran 1 test in 1580.318s

            Chanabasappa Ghali, looks like it is a query engine issue. Error 405 is LCB_ERR_DML_FAILURE and we don't retry it automatically. This error was introduced because of MB-44328.

            avsej Sergey Avseyev added a comment - Chanabasappa Ghali , looks like it is a query engine issue. Error 405 is LCB_ERR_DML_FAILURE and we don't retry it automatically. This error was introduced because of MB-44328 .
            vikas.chaudhary Vikas Chaudhary added a comment - - edited

            Sergey Avseyev Not seeing the issue on toy http://latestbuilds.service.couchbase.com/builds/latestbuilds/couchbase-server/toybuilds/12746/ . But we have ns-server issue with the toys?

             

            cc: Ankit Prabhu Vinayaka Kamath can you confirm?

            vikas.chaudhary Vikas Chaudhary added a comment - - edited Sergey Avseyev  Not seeing the issue on toy  http://latestbuilds.service.couchbase.com/builds/latestbuilds/couchbase-server/toybuilds/12746/  . But we have ns-server issue with the toys?   cc: Ankit Prabhu Vinayaka Kamath  can you confirm?

            Vikas Chaudhary manifest changes are merged. Next build should have changes with libcouchbase 3.1.2

            ankit.prabhu Ankit Prabhu added a comment - Vikas Chaudhary manifest changes are merged. Next build should have changes with libcouchbase 3.1.2

            Verified with build 7.0.0-5043, issue not observed. Hence closing the issue

            chanabasappa.ghali Chanabasappa Ghali added a comment - Verified with build 7.0.0-5043, issue not observed. Hence closing the issue

            People

              vikas.chaudhary Vikas Chaudhary
              vikas.chaudhary Vikas Chaudhary
              Votes:
              0 Vote for this issue
              Watchers:
              15 Start watching this issue

              Dates

                Created:
                Updated:
                Resolved:

                Gerrit Reviews

                  There are no open Gerrit changes

                  PagerDuty