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

[System Test][XDCR] Execution timed out error observed in longevity

    XMLWordPrintable

Details

    • Bug
    • Resolution: Fixed
    • Major
    • 7.1.0
    • 7.1.0
    • XDCR
    • Untriaged
    • 1
    • No

    Description

      7.1.0-1997

      Test:
      -test tests/integration/neo/test_neo_couchstore_milestone4.yml -scope tests/integration/neo/scope_couchstore.yml
      Scale 3
      Iteration 2

      Following error observed in .97.119:

      2022-01-06T13:46:13.228-08:00 ERRO GOXDCR.Adminport: Unable to generate req or resp reqPeriodicPush deSerialize err: Invalid input given
      		 
      2022-01-06T13:46:13.505-08:00 INFO GOXDCR.AdminPort: doPostPeerToPeerRequest from 172.23.97.119:8091
      		 
      2022-01-06T13:46:13.507-08:00 ERRO GOXDCR.Adminport: Unable to generate req or resp reqPeriodicPush deSerialize err: Invalid input given
      		 
      2022-01-06T13:46:13.539-08:00 INFO GOXDCR.StatsMgr: 359ef7647a2373f3e2fa231784c521cf/default/remote total_docs=75086829, docs_processed=75086481, changes_left=348
      		 
      2022-01-06T13:46:13.976-08:00 INFO GOXDCR.AdminPort: doPostPeerToPeerRequest from 172.23.97.119:8091
      		 
      2022-01-06T13:46:13.979-08:00 ERRO GOXDCR.Adminport: Unable to generate req or resp reqPeriodicPush deSerialize err: Invalid input given
      		 
      2022-01-06T13:46:14.540-08:00 INFO GOXDCR.StatsMgr: 359ef7647a2373f3e2fa231784c521cf/default/remote total_docs=75087171, docs_processed=75086829, changes_left=342
      		 
      2022-01-06T13:46:14.869-08:00 INFO GOXDCR.AdminPort: doPostPeerToPeerRequest from 172.23.97.119:8091
      		 
      2022-01-06T13:46:14.871-08:00 ERRO GOXDCR.Adminport: Unable to generate req or resp reqPeriodicPush deSerialize err: Invalid input given
      		 
      2022-01-06T13:46:15.545-08:00 INFO GOXDCR.StatsMgr: 359ef7647a2373f3e2fa231784c521cf/default/remote total_docs=75087503, docs_processed=75087171, changes_left=332
      		 
      2022-01-06T13:46:16.542-08:00 INFO GOXDCR.StatsMgr: 359ef7647a2373f3e2fa231784c521cf/default/remote total_docs=75087819, docs_processed=75087503, changes_left=316
      		 
      2022-01-06T13:46:16.554-08:00 INFO GOXDCR.AdminPort: doPostPeerToPeerRequest from 172.23.97.119:8091
      		 
      2022-01-06T13:46:16.558-08:00 ERRO GOXDCR.Adminport: Unable to generate req or resp reqPeriodicPush deSerialize err: Invalid input given
      		 
      2022-01-06T13:46:17.539-08:00 INFO GOXDCR.StatsMgr: 359ef7647a2373f3e2fa231784c521cf/default/remote total_docs=75088131, docs_processed=75087819, changes_left=312
      		 
      2022-01-06T13:46:17.631-08:00 ERRO GOXDCR.P2PManager: Request type 0 to 172.23.104.5:8091 with opaque 4089839616 timed out
      		 
      2022-01-06T13:46:17.795-08:00 ERRO GOXDCR.P2PManager: Request type 0 to 172.23.97.121:8091 with opaque 3407544320 timed out
      		 
      2022-01-06T13:46:18.041-08:00 INFO GOXDCR.ResourceMgr: Resource Manager State = overallTP: 166 highTP: 166 highExist: true lowExist: false backlogExist: true maxTP: 166 highTPNeeded: 116883140 highTokens: 0 maxTokens: 0 lowTPLimit: 0 calibration: None dcpAction: Reset processCpu: 0 idleCpu: 68
      		 
      2022-01-06T13:46:18.042-08:00 INFO GOXDCR.ResourceMgr: backlogCount=818, noBacklogCount=0 extraQuota=false cpuNotMaxedCount=0 throughputDropCount=0
      		 
      2022-01-06T13:46:18.042-08:00 INFO GOXDCR.ResourceMgr: DcpPriorityMap=map[]
      		 
      ongoingReplMap=map[359ef7647a2373f3e2fa231784c521cf/bucket4/bucket4:true 359ef7647a2373f3e2fa231784c521cf/bucket8/bucket8:true 359ef7647a2373f3e2fa231784c521cf/bucket9/bucket9:true 359ef7647a2373f3e2fa231784c521cf/default/remote:true backfill_359ef7647a2373f3e2fa231784c521cf/bucket4/bucket4:true backfill_359ef7647a2373f3e2fa231784c521cf/bucket8/bucket8:true backfill_359ef7647a2373f3e2fa231784c521cf/bucket9/bucket9:true]
      		 
      2022-01-06T13:46:18.145-08:00 ERRO GOXDCR.P2PManager: Request type 0 to 172.23.97.121:8091 with opaque 2106392576 timed out
      		 
      2022-01-06T13:46:18.540-08:00 INFO GOXDCR.StatsMgr: 359ef7647a2373f3e2fa231784c521cf/default/remote total_docs=75088447, docs_processed=75088131, changes_left=316
      		 
      2022-01-06T13:46:18.706-08:00 ERRO GOXDCR.P2PManager: Request type 0 to 172.23.97.121:8091 with opaque 2060386304 timed out
      		 
      2022-01-06T13:46:18.777-08:00 INFO GOXDCR.TopoChangeDet: Executing Action timed out
      		 
      2022-01-06T13:46:18.777-08:00 INFO GOXDCR.TopoChangeDet: ****************************
      		 
      2022-01-06T13:46:18.777-08:00 ERRO GOXDCR.GenericSupervisor: PipelineSupervisor_359ef7647a2373f3e2fa231784c521cf/bucket4/bucket4 Received error report : Execution timed out
      		 
      . errors_seen=map[TopoChangeDet:Execution timed out]
      		 
      2022-01-06T13:46:18.777-08:00 INFO GOXDCR.ReplMgr: Supervisor PipelineSupervisor_359ef7647a2373f3e2fa231784c521cf/bucket4/bucket4 of type *supervisor.GenericSupervisor reported errors map[TopoChangeDet:Execution timed out]
      		 
      2022-01-06T13:46:18.777-08:00 INFO GOXDCR.GenericSupervisor: Executing Action timed out
      		 
      2022-01-06T13:46:18.777-08:00 INFO GOXDCR.GenericSupervisor: ****************************
      		 
      2022-01-06T13:46:18.777-08:00 INFO GOXDCR.StatsMgr: Executing Action timed out
      		 
      2022-01-06T13:46:18.777-08:00 INFO GOXDCR.StatsMgr: ****************************
      		 
      2022-01-06T13:46:18.777-08:00 INFO GOXDCR.GenericSupervisor: PipelineSupervisor_359ef7647a2373f3e2fa231784c521cf/bucket4/bucket4 Received error report : Subscribing to bucketTopologySvc: Execution timed out, but error is ignored. pipeline_state=5
      		 
       errors_seen=map[TopoChangeDet:Execution timed out]
      		 
      2022-01-06T13:46:18.777-08:00 INFO GOXDCR.PipelineMgr: PipelineOpSerializer 359ef7647a2373f3e2fa231784c521cf/bucket4/bucket4 handling job: Job for 359ef7647a2373f3e2fa231784c521cf/bucket4/bucket4 Type: PipelineUpdate 
      2022-01-06T13:46:18.777-08:00 INFO GOXDCR.PipelineMgr: Replication status is updated with error(s) r.update_err_ch : TopoChangeDet : Execution timed out, current status=name={359ef7647a2373f3e2fa231784c521cf/bucket4/bucket4}, status={Pending}, errors={[{"time":"2022-01-06T13:46:18.777652402-08:00","errMsg":"TopoChangeDet : Execution timed out"}]}, oldProgress={Pipeline is running}, progress={Received error report : Execution timed out}, oldBackfillProgress={Pipeline has been stopped}, backfillProgress={Start backfill pipeline construction}

      Error shows up in UI as well - also observing this in the UI logs around the same time:

      Backfill 359ef7647a2373f3e2fa231784c521cf/bucket4/bucket4 was not able to be loaded correctly. It has since been re-initialized and a thorough backfill has been raised to recover any missing data

      Not sure if they are related though

      Logs:
      url : https://cb-jira.s3.us-east-2.amazonaws.com/logs/systestmon-1641507604/collectinfo-2022-01-06T222006-ns_1%40172.23.104.137.zip
      url : https://cb-jira.s3.us-east-2.amazonaws.com/logs/systestmon-1641507604/collectinfo-2022-01-06T222006-ns_1%40172.23.104.155.zip
      url : https://cb-jira.s3.us-east-2.amazonaws.com/logs/systestmon-1641507604/collectinfo-2022-01-06T222006-ns_1%40172.23.104.157.zip
      url : https://cb-jira.s3.us-east-2.amazonaws.com/logs/systestmon-1641507604/collectinfo-2022-01-06T222006-ns_1%40172.23.104.5.zip
      url : https://cb-jira.s3.us-east-2.amazonaws.com/logs/systestmon-1641507604/collectinfo-2022-01-06T222006-ns_1%40172.23.104.67.zip
      url : https://cb-jira.s3.us-east-2.amazonaws.com/logs/systestmon-1641507604/collectinfo-2022-01-06T222006-ns_1%40172.23.104.69.zip
      url : https://cb-jira.s3.us-east-2.amazonaws.com/logs/systestmon-1641507604/collectinfo-2022-01-06T222006-ns_1%40172.23.104.70.zip
      url : https://cb-jira.s3.us-east-2.amazonaws.com/logs/systestmon-1641507604/collectinfo-2022-01-06T222006-ns_1%40172.23.105.107.zip
      url : https://cb-jira.s3.us-east-2.amazonaws.com/logs/systestmon-1641507604/collectinfo-2022-01-06T222006-ns_1%40172.23.105.111.zip
      url : https://cb-jira.s3.us-east-2.amazonaws.com/logs/systestmon-1641507604/collectinfo-2022-01-06T222006-ns_1%40172.23.105.168.zip
      url : https://cb-jira.s3.us-east-2.amazonaws.com/logs/systestmon-1641507604/collectinfo-2022-01-06T222006-ns_1%40172.23.106.100.zip
      url : https://cb-jira.s3.us-east-2.amazonaws.com/logs/systestmon-1641507604/collectinfo-2022-01-06T222006-ns_1%40172.23.106.188.zip
      url : https://cb-jira.s3.us-east-2.amazonaws.com/logs/systestmon-1641507604/collectinfo-2022-01-06T222006-ns_1%40172.23.108.103.zip
      url : https://cb-jira.s3.us-east-2.amazonaws.com/logs/systestmon-1641507604/collectinfo-2022-01-06T222006-ns_1%40172.23.120.107.zip
      url : https://cb-jira.s3.us-east-2.amazonaws.com/logs/systestmon-1641507604/collectinfo-2022-01-06T222006-ns_1%40172.23.120.245.zip
      url : https://cb-jira.s3.us-east-2.amazonaws.com/logs/systestmon-1641507604/collectinfo-2022-01-06T222006-ns_1%40172.23.121.117.zip
      url : https://cb-jira.s3.us-east-2.amazonaws.com/logs/systestmon-1641507604/collectinfo-2022-01-06T222006-ns_1%40172.23.123.28.zip
      url : https://cb-jira.s3.us-east-2.amazonaws.com/logs/systestmon-1641507604/collectinfo-2022-01-06T222006-ns_1%40172.23.96.148.zip
      url : https://cb-jira.s3.us-east-2.amazonaws.com/logs/systestmon-1641507604/collectinfo-2022-01-06T222006-ns_1%40172.23.96.251.zip
      url : https://cb-jira.s3.us-east-2.amazonaws.com/logs/systestmon-1641507604/collectinfo-2022-01-06T222006-ns_1%40172.23.96.252.zip
      url : https://cb-jira.s3.us-east-2.amazonaws.com/logs/systestmon-1641507604/collectinfo-2022-01-06T222006-ns_1%40172.23.96.253.zip
      url : https://cb-jira.s3.us-east-2.amazonaws.com/logs/systestmon-1641507604/collectinfo-2022-01-06T222006-ns_1%40172.23.97.119.zip
      url : https://cb-jira.s3.us-east-2.amazonaws.com/logs/systestmon-1641507604/collectinfo-2022-01-06T222006-ns_1%40172.23.97.121.zip
      url : https://cb-jira.s3.us-east-2.amazonaws.com/logs/systestmon-1641507604/collectinfo-2022-01-06T222006-ns_1%40172.23.97.122.zip
      url : https://cb-jira.s3.us-east-2.amazonaws.com/logs/systestmon-1641507604/collectinfo-2022-01-06T222006-ns_1%40172.23.97.239.zip
      url : https://cb-jira.s3.us-east-2.amazonaws.com/logs/systestmon-1641507604/collectinfo-2022-01-06T222006-ns_1%40172.23.98.135.zip
      url : https://cb-jira.s3.us-east-2.amazonaws.com/logs/systestmon-1641507604/collectinfo-2022-01-06T222006-ns_1%40172.23.99.20.zip
      url : https://cb-jira.s3.us-east-2.amazonaws.com/logs/systestmon-1641507604/collectinfo-2022-01-06T222006-ns_1%40172.23.99.21.zip
      url : https://cb-jira.s3.us-east-2.amazonaws.com/logs/systestmon-1641507604/collectinfo-2022-01-06T222006-ns_1%40172.23.99.25.zip

      Attachments

        For Gerrit Dashboard: MB-50279
        # Subject Branch Project Status CR V
        168405,2 MB-50279: send notifications in parallel to lock contention if mulitple channels are stuck master goxdcr Status: MERGED +2 +1

        Activity

          People

            arunkumar Arunkumar Senthilnathan (Inactive)
            arunkumar Arunkumar Senthilnathan (Inactive)
            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