search

couchbase / sync_gateway

Manages access and synchronization between Couchbase Lite and Couchbase Server
https://www.couchbase.com/products/sync-gateway
Other
446 stars 138 forks source link

Known sporadically failing integration tests #3539

Closed tleyden closed 6 years ago

tleyden commented 6 years ago

This was spun out of https://github.com/couchbase/sync_gateway/issues/3422

First mentioned in https://github.com/couchbase/sync_gateway/pull/3417#issuecomment-379120229 and https://github.com/couchbase/sync_gateway/pull/3466#issuecomment-382538139

tleyden commented 6 years ago

TestBulkDocsChangeToRoleAccess

In http://uberjenkins.sc.couchbase.com/view/Build/job/sync-gateway-integration-master/576/consoleFull, which was run against a feature branch feature/issue_3422_gsi_timeout, it's failing with:

=== RUN   TestBulkDocsChangeToRoleAccess
_time=2018-05-03T17:48:24.405-07:00 _level=INFO _msg=Using plain authentication for user test_data_bucket 
_time=2018-05-03T17:48:29.704-07:00 _level=INFO _msg=Using plain authentication for user test_data_bucket 

    api_test.go:1268
    map[string]interface{}{"rev": "1-f120ccb33c0a6ef43ef202ade28f98ef", "id": "bulk2"}) 

    expected: map[string]interface {}{"rev":"1-f120ccb33c0a6ef43ef202ade28f98ef", "id":"bulk2"}
         got: map[string]interface {}{"id":"bulk2", "reason":"missing channel access", "status":403, "error":"forbidden"}
--- FAIL: TestBulkDocsChangeToRoleAccess (6.20s)
    assert.go:31:
tleyden commented 6 years ago

TestN1qlFilterExpression

In http://uberjenkins.sc.couchbase.com/view/Build/job/sync-gateway-integration-master/587/console:

NOTE: this is on a feature branch feature/issue_3422_gsi_timeout

2018-05-04T14:37:28.175-07:00 [WRN] RetryLoop for GetIndexMeta for index testIndex_filtered_value giving up after 26 attempts -- base.RetryLoop() at util.go:342
goroutine 935 [running]:
runtime/debug.Stack(0xc4201a8648, 0x9f4d00, 0xc4201a8630)
    /root/.gvm/gos/go1.8.5/src/runtime/debug/stack.go:24 +0x79
runtime/debug.PrintStack()
    /root/.gvm/gos/go1.8.5/src/runtime/debug/stack.go:16 +0x22
github.com/couchbase/sync_gateway/base.assertNoError(0xc42052c5b0, 0xe180a0, 0xc4201a8650, 0xae5ccd, 0x1d)
    /var/jenkins/workspace/sync-gateway-integration-master/godeps/src/github.com/couchbase/sync_gateway/base/set_test.go:113 +0x3d
github.com/couchbase/sync_gateway/base.TestN1qlFilterExpression(0xc42052c5b0)
    /var/jenkins/workspace/sync-gateway-integration-master/godeps/src/github.com/couchbase/sync_gateway/base/bucket_n1ql_test.go:157 +0x4a0
testing.tRunner(0xc42052c5b0, 0xafc338)
    /root/.gvm/gos/go1.8.5/src/testing/testing.go:657 +0x96
created by testing.(*T).Run
    /root/.gvm/gos/go1.8.5/src/testing/testing.go:697 +0x2ca
--- FAIL: TestN1qlFilterExpression (309.12s)
    set_test.go:114: Error validating index online: RetryLoop for GetIndexMeta for index testIndex_filtered_value giving up after 26 attempts
tleyden commented 6 years ago

TestViewQueryUserAccess

Failed in http://uberjenkins.sc.couchbase.com/view/Build/job/sync-gateway-integration-master/604/consoleFull

=== RUN   TestViewQueryUserAccess
2018-05-08 20:16:14.464762 I | Dropping index sg_roleAccess_x1...
2018-05-08 20:16:14.465009 I | Dropping index sg_channels_x1...
2018-05-08 20:16:14.465062 I | Dropping index sg_tombstones_x1...
2018-05-08 20:16:14.465126 I | Dropping index sg_syncDocs_x1...
2018-05-08 20:16:14.465201 I | Dropping index sg_access_x1...
2018-05-08 20:16:14.465299 I | Dropping index sg_allDocs_x1...
2018-05-08 20:16:14.714001 I | ...successfully dropped index sg_roleAccess_x1
2018-05-08 20:16:15.051713 I | ...successfully dropped index sg_tombstones_x1
2018-05-08 20:16:15.308320 I | ...successfully dropped index sg_channels_x1
2018-05-08 20:16:15.540885 I | ...successfully dropped index sg_allDocs_x1
2018-05-08 20:16:15.879153 I | ...successfully dropped index sg_syncDocs_x1
2018-05-08 20:16:16.041955 I | ...successfully dropped index sg_access_x1
2018-05-08 20:16:16.042001 I | Flushing bucket test_data_bucket
_time=2018-05-08T20:17:01.072-07:00 _level=INFO _msg=Using plain authentication for user test_data_bucket 
--- FAIL: TestViewQueryUserAccess (47.05s)
    changes_api_test.go:2051: Unexpected error: Got response code: 500 from view call.  Expected 200.

In http://uberjenkins.sc.couchbase.com/view/Build/job/sync-gateway-integration-master/685/parameters/

2018-05-18T16:08:59.234-07:00 [INF] HTTP:  #004: PUT http://localhost/db/doc3 (as GUEST)
2018-05-18T16:08:59.236-07:00 [INF] HTTP:  #005: GET http://localhost/db/_design/foo/_view/bar?stale=false (as ADMIN)
2018-05-18T16:08:59.236-07:00 [INF] HTTP: JSON view "foo"/"bar" - opts map[stale:false]
2018-05-18T16:08:59.281-07:00 [INF] HTTP: #005:     --> 500 Internal error: unknown_error - view_undefined  (45.5 ms)
--- FAIL: TestViewQueryUserAccess (31.94s)
    changes_api_test.go:2176: Unexpected error: Got response code: 500 from view call.  Expected 200.
FAIL
tleyden commented 6 years ago

TestAccessFunctionDb

In http://uberjenkins.sc.couchbase.com/view/Build/job/sync-gateway-integration-master/607/consoleFull

2018-05-08T20:37:15.878-07:00 [INF] Cache:     #1 ==> channel "*"
2018-05-08T20:37:20.590-07:00 [INF] Cache: Received #2 after   0ms ("doc2" / "1-38f57cfe0248c43005f25dd85c996e29")
2018-05-08T20:37:20.590-07:00 [INF] Cache:     #2 ==> channel "*"

    database_test.go:1120
    assert.DeepEquals(t, user.Channels(), expected) 

    expected: channels.TimedSet{"Hulu":channels.VbSequence{VbNo:(*uint16)(nil), Sequence:0x1}, "Netflix":channels.VbSequence{VbNo:(*uint16)(nil), Sequence:0x1}, "!":channels.VbSequence{VbNo:(*uint16)(nil), Sequence:0x1}}
         got: channels.TimedSet{"!":channels.VbSequence{VbNo:(*uint16)(nil), Sequence:0x1}, "Netflix":channels.VbSequence{VbNo:(*uint16)(nil), Sequence:0x1}}

    database_test.go:1123
    assert.DeepEquals(t, user.InheritedChannels(), expected)    

    expected: channels.TimedSet{"Hulu":channels.VbSequence{VbNo:(*uint16)(nil), Sequence:0x1}, "Netflix":channels.VbSequence{VbNo:(*uint16)(nil), Sequence:0x1}, "!":channels.VbSequence{VbNo:(*uint16)(nil), Sequence:0x1}, "CrunchyRoll":channels.VbSequence{VbNo:(*uint16)(nil), Sequence:0x2}}
         got: channels.TimedSet{"!":channels.VbSequence{VbNo:(*uint16)(nil), Sequence:0x1}, "Netflix":channels.VbSequence{VbNo:(*uint16)(nil), Sequence:0x1}}
2018-05-08T20:37:21.349-07:00 [WRN] Error closing GoCB bucket: connection shut down. -- base.(*CouchbaseBucketGoCB).Close() at bucket_gocb.go:2230
--- FAIL: TestAccessFunctionDb (9.36s)
    assert.go:31: 
    assert.go:31:

Re-run in repeat loop in http://uberjenkins.sc.couchbase.com/view/Build/job/sync-gateway-integration-master/618/

tleyden commented 6 years ago

TestChannelView

http://uberjenkins.sc.couchbase.com/view/Build/job/sync-gateway-integration-master/628/console

2018-05-10T08:25:51.138-07:00 [INF] Initializing changes cache for database db with sequence: 0
2018-05-10T08:25:51.225-07:00 [INF] Using metadata purge interval of 3.00 days for tombstone compaction.
2018-05-10 08:25:51.247164 I | Create doc 1...
2018-05-10 08:25:51.344782 I | View query returned entry: seq: 1 docid: doc1 revid: 1-67394b90ffbe4b9fabfee5d906fec339 vbno: 0 type: 0

    database_test.go:1448
    assert.True(t, len(entries) == 1)   
2018-05-10T08:25:51.345-07:00 [WRN] Error closing GoCB bucket: connection shut down. -- base.(*CouchbaseBucketGoCB).Close() at bucket_gocb.go:2246
--- FAIL: TestChannelView (6.13s)
    assert.go:31:

Another failure case:

https://gist.github.com/tleyden/e240d0e9732bfc14b4e648a93946ba5b

2018-05-15 18:42:19.561674 I | View Query returned entry (0): seq: 1 docid: doc1 revid: 1-cb0c9a22be0e5a1b01084ec019defa81 vbno: 0 type: 0
2018-05-15 18:42:19.561684 I | View Query returned entry (1): seq: 2 docid: alpha revid: 2-5f3b46c249f293a7cbfb0b05e77be754 vbno: 0 type: 0

    database_test.go:1451
    assert.Equals(t, len(entries), 1)

    expected: 1
         got: 2

It appears to be possibly be index residue, since the command to run it was:

SG_TEST_BACKING_STORE=Couchbase SG_TEST_USE_XATTRS=true repeat 5 ./test.sh -v -run TestAccessOnTombstone$
SG_TEST_BACKING_STORE=Couchbase SG_TEST_USE_XATTRS=true repeat 5 ./test.sh -v -run TestAccessOnTombstone$
SG_TEST_BACKING_STORE=Couchbase SG_TEST_USE_XATTRS=true repeat 1 ./test.sh -v -run TestChannelView$

and TestAccessOnTombstone creates an alpha doc. Also, in my Couchbase bucket I only see a doc1, but no alpha doc.. and if it was due to unwanted/unexpected imports, then I'd expect to see an alpha doc as well.

Trying to directly query the index with:

SELECT meta(`test_data_bucket`).xattrs._sync.sequence AS seq, 
meta(`test_data_bucket`).xattrs._sync.rev AS rev, 
meta(`test_data_bucket`).xattrs._sync.flags AS flags, 
META(`test_data_bucket`).id AS id 
FROM `test_data_bucket`
WHERE meta(`test_data_bucket`).xattrs._sync.sequence >= 0 AND meta(`test_data_bucket`).xattrs._sync.sequence < 100 
AND META().id NOT LIKE '\\_sync:%'

only shows doc1.

Workaround idea:

tleyden commented 6 years ago

TestAllDocsChannelsAfterChannelMove

In http://uberjenkins.sc.couchbase.com/view/Build/job/sync-gateway-integration-master/632/parameters/

meta(`test_data_bucket`).xattrs._sync.rev as r, meta(`test_data_bucket`).xattrs._sync.sequence as s, meta(`test_data_bucket`).xattrs._sync.channels as c FROM `test_data_bucket` WHERE meta(`test_data_bucket`).xattrs._sync.sequence > 0 AND META(`test_data_bucket`).id NOT LIKE '\\_sync:%' AND meta(`test_data_bucket`).xattrs._sync IS NOT MISSING AND (meta(`test_data_bucket`).xattrs._sync.flags IS MISSING OR BITTEST(meta(`test_data_bucket`).xattrs._sync.flags,1) = false) ORDER BY META(`test_data_bucket`).id] -- base.(*CouchbaseBucketGoCB).Query() at bucket_n1ql.go:63
2018-05-10T12:57:03.639-07:00 [INF] HTTP: #002:     --> 500 Internal error: [5001] Panic: runtime error: index out of range  (2646.8 ms)
2018-05-10 12:57:03.639096 I | Admin response = {"rows":[
{"error":"Internal Server Error","reason":"Internal error: [5001] Panic: runtime error: index out of range"}

    api_test.go:2670
    assert.Equals(t, err, nil)  

    expected: <nil>
         got: &json.SyntaxError{msg:"unexpected end of JSON input", Offset:118}

    api_test.go:2671
    assert.Equals(t, len(allDocsResult.Rows), 1)    

    expected: 1
         got: 0
--- FAIL: TestAllDocsChannelsAfterChannelMove (7.09s)
    assert.go:31: 
    assert.go:31: 
panic: runtime error: index out of range [recovered]
    panic: runtime error: index out of range

goroutine 19 [running]:
testing.tRunner.func1(0xc4201da750)
    /root/.gvm/gos/go1.8.5/src/testing/testing.go:622 +0x29d
panic(0xcc5460, 0x142c060)
    /root/.gvm/gos/go1.8.5/src/runtime/panic.go:489 +0x2cf
github.com/couchbase/sync_gateway/rest.TestAllDocsChannelsAfterChannelMove(0xc4201da750)
    /var/jenkins/workspace/sync-gateway-integration-master/godeps/src/github.com/couchbase/sync_gateway/rest/api_test.go:2672 +0x18ec
testing.tRunner(0xc4201da750, 0xdfb400)
    /root/.gvm/gos/go1.8.5/src/testing/testing.go:657 +0x96
created by testing.(*T).Run
    /root/.gvm/gos/go1.8.5/src/testing/testing.go:697 +0x2ca
exit status 2
FAIL    github.com/couchbase/sync_gateway/rest  7.103s

However on the same branch, in http://uberjenkins.sc.couchbase.com/view/Build/job/sync-gateway-integration-master/637/parameters/, I was able to re-run the test 5 times w/ no failures.

tleyden commented 6 years ago

@adamcfraser nevermind, after digging further, I can see this isn't a sporadic failure. Deleting previous comments to keep it from coming up in repo issue searches

tleyden commented 6 years ago

Closing this issue, as the dev branch has no known sporadic failures.

Recent clean runs:

http://uberjenkins.sc.couchbase.com/view/Build/job/sync-gateway-integration-master/724/parameters/ http://uberjenkins.sc.couchbase.com/view/Build/job/sync-gateway-integration-master/723/parameters/