[5001] Panic: runtime error: index out of range

n1ql

#1

Environment:
os:ubuntu 16.04
cbs: 5.5.1
cbl: 2.0 android(v7.0)
sg: 2.1.0-121

problem:
when I logined in from android app, the data don’t sync until reconnect wifi and login again, the data were synced.

sg logs:
the sg erro logs as following

2018-10-09T09:03:52.442+08:00 [INF] HTTP:  #1807: GET /kitchen/_blipsync (as GUEST)
2018-10-09T09:03:52.442+08:00 [INF] HTTP: #1807:     --> 401 Login required  (0.3 ms)
2018-10-09T09:03:52.459+08:00 [INF] HTTP:  #1808: GET /kitchen/_blipsync (as 7a40a944)
2018-10-09T09:03:52.460+08:00 [INF] HTTP+: #1808:     --> 101 [59604a51] Upgraded to BLIP+WebSocket protocol. User:7a40a944.  (0.0 ms)
2018-10-09T09:03:52.460+08:00 [INF] WS: [59604a51] Start BLIP/Websocket handler
2018-10-09T09:03:52.481+08:00 [INF] SyncMsg: [59604a51] #1: Type:getCheckpoint Client:cp-GxEUtPEvHS5WnhPuhtmWDPKyaQY= User:7a40a944
2018-10-09T09:03:52.495+08:00 [INF] SyncMsg: [59604a51] #2: Type:subChanges Since:10638 Continuous:true Filter:sync_gateway/bychannel Channels:7a40a944  User:7a40a944
2018-10-09T09:03:52.495+08:00 [INF] Sync: [59604a51] Sending changes since 10638. User:7a40a944
2018-10-09T09:03:52.495+08:00 [INF] Changes: MultiChangesFeed(channels: {7a40a944}, options: {Since:10638 Limit:0 Conflicts:false IncludeDocs:false Wait:true Continuous:tr
ue Terminator:0xc421000360 HeartbeatMs:0 TimeoutMs:0 ActiveOnly:false}) ...   (to 7a40a944)2018-10-09T09:03:52.496+08:00 [INF] Sync: [59604a51] Sent all changes to client. User:7a40a944
2018-10-09T09:03:52.505+08:00 [INF] SyncMsg: [59604a51] #3: Type:proposeChanges #Changes: 0 User:7a40a944
2018-10-09T09:04:21.151+08:00 [INF] Changes: MultiChangesFeed done   (to 7a40a944)
2018-10-09T09:04:28.925+08:00 [INF] HTTP:  #1809: GET /kitchen/_blipsync (as GUEST)
2018-10-09T09:04:28.925+08:00 [INF] HTTP: #1809:     --> 401 Login required  (0.4 ms)
2018-10-09T09:04:28.960+08:00 [INF] HTTP:  #1810: GET /kitchen/_blipsync (as 7a40a944)
2018-10-09T09:04:28.960+08:00 [INF] HTTP+: #1810:     --> 101 [31c29ab6] Upgraded to BLIP+WebSocket protocol. User:7a40a944.  (0.0 ms)
2018-10-09T09:04:28.960+08:00 [INF] WS: [31c29ab6] Start BLIP/Websocket handler
2018-10-09T09:04:29.000+08:00 [INF] SyncMsg: [31c29ab6] #1: Type:getCheckpoint Client:cp-FIcUXmRLRelJC9k3WlZJxsaNKg0= User:7a40a944
2018-10-09T09:04:29.000+08:00 [INF] SyncMsg: [31c29ab6] #1: Type:getCheckpoint   --> 404 missing Time:289.414¦Ìs User:7a40a944
2018-10-09T09:04:29.019+08:00 [INF] SyncMsg: [31c29ab6] #2: Type:proposeChanges #Changes: 1 User:7a40a944
2018-10-09T09:04:29.019+08:00 [INF] SyncMsg: [31c29ab6] #3: Type:subChanges Since:0 Continuous:true Filter:sync_gateway/bychannel Channels:7a40a944  User:7a40a944
2018-10-09T09:04:29.019+08:00 [INF] Sync: [31c29ab6] Sending changes since 0. User:7a40a944
2018-10-09T09:04:29.019+08:00 [INF] Changes: MultiChangesFeed(channels: {7a40a944}, options: {Since:0 Limit:0 Conflicts:false IncludeDocs:false Wait:true Continuous:true T
erminator:0xc4219f18c0 HeartbeatMs:0 TimeoutMs:0 ActiveOnly:false}) ...   (to 7a40a944)2018-10-09T09:04:29.020+08:00 [INF] Cache: getCachedChanges("7a40a944", 14:0) --> 50 changes valid from #10562
2018-10-09T09:04:29.020+08:00 [INF] Cache:   Querying 'channels' view for "7a40a944" (start=#1, end=#10562, limit=0)
2018-10-09T09:04:29.045+08:00 [INF] SyncMsg: [31c29ab6] #4: Type:rev Id:Employee.732b1a49-5448-49b1-bcd7-838f8c8f4167 Rev:1-61ab2aed9f9822be70580f296191358328ede1ce Sequen
ce:1  User:7a40a9442018-10-09T09:04:29.046+08:00 [INF] CRUD: 	Doc "Employee.732b1a49-5448-49b1-bcd7-838f8c8f4167" in channels "{7a40a944}"
2018-10-09T09:04:29.046+08:00 [INF] Access: Doc "Employee.732b1a49-5448-49b1-bcd7-838f8c8f4167" grants channel access: map[7a40a944:7a40a944:10639]
2018-10-09T09:04:29.047+08:00 [INF] CRUD: Stored doc "Employee.732b1a49-5448-49b1-bcd7-838f8c8f4167" / "1-61ab2aed9f9822be70580f296191358328ede1ce"
2018-10-09T09:04:29.047+08:00 [INF] Access: Rev "Employee.732b1a49-5448-49b1-bcd7-838f8c8f4167"/"1-61ab2aed9f9822be70580f296191358328ede1ce" invalidates channels of [7a40a
944]2018-10-09T09:04:29.047+08:00 [INF] Access: Invalidate access of "7a40a944"
2018-10-09T09:04:29.047+08:00 [INF] Auth: Saved _sync:user:7a40a944: &{roleImpl:{Name_:7a40a944 ExplicitChannels_: Channels_: Sequence_:15 PreviousChannels_: vbNo:<nil>} u
serImplBody:{Email_: Disabled_:false PasswordHash_:[36 50 97 36 49 48 36 69 53 69 119 50 85 69 113 48 47 97 57 104 85 113 47 86 82 55 82 67 46 107 75 88 110 75 111 85 54 97 118 108 82 113 122 112 50 102 102 85 50 90 114 105 121 104 119 116 89 53 85 97] OldPasswordHash_:<nil> ExplicitRoles_: RolesSince_: OldExplicitRoles_:[]} auth:0xc4240033e0 roles:[]}2018-10-09T09:04:29.049+08:00 [INF] Cache: Received #10639 after   2ms ("Employee.732b1a49-5448-49b1-bcd7-838f8c8f4167" / "1-61ab2aed9f9822be70580f296191358328ede1ce")
2018-10-09T09:04:29.055+08:00 [INF] Cache:     #10639 ==> channel "7a40a944"
2018-10-09T09:04:29.055+08:00 [INF] Cache:     #10639 ==> channel "*"
2018-10-09T09:04:29.055+08:00 [INF] Cache: getCachedChanges("7a40a944", 10638) --> 1 changes valid from #10639
2018-10-09T09:04:29.055+08:00 [INF] Changes: sending 1 change(s)
2018-10-09T09:04:29.055+08:00 [INF] Cache: getCachedChanges("7a40a944", 10638) --> 1 changes valid from #10639
2018-10-09T09:04:29.055+08:00 [INF] Changes: sending 1 change(s)
2018-10-09T09:04:29.055+08:00 [INF] Cache: getCachedChanges("7a40a944", 10638) --> 1 changes valid from #10639
2018-10-09T09:04:29.056+08:00 [INF] Changes: sending 1 change(s)
2018-10-09T09:04:29.056+08:00 [INF] Cache: Received #15 ("_user/7a40a944")
2018-10-09T09:04:29.064+08:00 [INF] WS: [3f7835a0] Error: receiveLoop exiting with WebSocket error: read tcp 10.141.18.242:4984->222.173.43.58:34532: read: connection rese
t by peer2018-10-09T09:04:29.064+08:00 [INF] WS: [3f7835a0] BLIP/Websocket Handler exited: read tcp 10.141.18.242:4984->222.173.43.58:34532: read: connection reset by peer
2018-10-09T09:04:29.064+08:00 [INF] HTTP: [3f7835a0] #1799:     --> BLIP+WebSocket connection error: read tcp 10.141.18.242:4984->222.173.43.58:34532: read: connection res
et by peer2018-10-09T09:04:29.064+08:00 [INF] Sync: [3f7835a0] Sent 1 changes to client, from seq 10639.  User:7a40a944
2018-10-09T09:04:29.064+08:00 [INF] Sync: [3f7835a0] Invalid response to 'changes' message: RPY#196 -- EOF.  User:7a40a944
2018-10-09T09:04:29.074+08:00 [INF] WS: [1302abd3] Error: receiveLoop exiting with WebSocket error: read tcp 10.141.18.242:4984->222.173.43.58:49574: read: connection rese
t by peer2018-10-09T09:04:29.074+08:00 [INF] WS: [1302abd3] BLIP/Websocket Handler exited: read tcp 10.141.18.242:4984->222.173.43.58:49574: read: connection reset by peer
2018-10-09T09:04:29.074+08:00 [INF] HTTP: [1302abd3] #1805:     --> BLIP+WebSocket connection error: read tcp 10.141.18.242:4984->222.173.43.58:49574: read: connection res
et by peer2018-10-09T09:04:29.074+08:00 [INF] Sync: [1302abd3] Sent 1 changes to client, from seq 10639.  User:7a40a944
2018-10-09T09:04:29.074+08:00 [INF] Sync: [1302abd3] Invalid response to 'changes' message: RPY#27 -- EOF.  User:7a40a944
2018-10-09T09:04:29.077+08:00 [INF] WS: [1cb29a33] Error: receiveLoop exiting with WebSocket error: read tcp 10.141.18.242:4984->222.173.43.58:49119: read: connection rese
t by peer2018-10-09T09:04:29.078+08:00 [INF] WS: [1cb29a33] BLIP/Websocket Handler exited: read tcp 10.141.18.242:4984->222.173.43.58:49119: read: connection reset by peer
2018-10-09T09:04:29.078+08:00 [INF] HTTP: [1cb29a33] #1801:     --> BLIP+WebSocket connection error: read tcp 10.141.18.242:4984->222.173.43.58:49119: read: connection res
et by peer2018-10-09T09:04:29.078+08:00 [INF] Sync: [1cb29a33] Sent 1 changes to client, from seq 10639.  User:7a40a944
2018-10-09T09:04:29.078+08:00 [INF] Sync: [1cb29a33] Invalid response to 'changes' message: RPY#326 -- EOF.  User:7a40a944
2018-10-09T09:04:29.267+08:00 [INF] Access: Computed channels for "7a40a944": !:1,7a40a944:14,7a40a944BaseData:14,7a40a944UserData2018:352
2018-10-09T09:04:29.267+08:00 [INF] Changes: MultiChangesFeed done   (to 7a40a944)
2018-10-09T09:04:29.272+08:00 [INF] Cache: Received #15 ("_user/7a40a944")
2018-10-09T09:04:29.284+08:00 [INF] Access: Computed channels for "7a40a944": !:1,7a40a944:14,7a40a944BaseData:14,7a40a944UserData2018:352
2018-10-09T09:04:29.288+08:00 [INF] Access: Computed channels for "7a40a944": !:1,7a40a944:14,7a40a944BaseData:14,7a40a944UserData2018:352
2018-10-09T09:04:29.288+08:00 [INF] Changes: MultiChangesFeed done   (to 7a40a944)
2018-10-09T09:04:29.307+08:00 [INF] SyncMsg: [31c29ab6] #5: Type:setCheckpoint Client:cp-FIcUXmRLRelJC9k3WlZJxsaNKg0=  User:7a40a944
2018-10-09T09:04:29.315+08:00 [INF] Access: Computed channels for "7a40a944": !:1,7a40a944:14,7a40a944BaseData:14,7a40a944UserData2018:352
2018-10-09T09:04:29.316+08:00 [INF] Changes: MultiChangesFeed done   (to 7a40a944)
2018-10-09T09:04:30.038+08:00 [WRN] Error when querying index using statement: [SELECT [op.name, LEAST(meta(`kitchen`).xattrs._sync.sequence, op.val.seq),IFMISSING(op.val.
rev,null),IFMISSING(op.val.del,null)][1] AS seq, [op.name, LEAST(meta(`kitchen`).xattrs._sync, op.val.seq),IFMISSING(op.val.rev,null),IFMISSING(op.val.del,null)][2] AS rRev, [op.name, LEAST(meta(`kitchen`).xattrs._sync, op.val.seq),IFMISSING(op.val.rev,null),IFMISSING(op.val.del,null)][3] AS rDel, meta(`kitchen`).xattrs._sync.rev AS rev, meta(`kitchen`).xattrs._sync.flags AS flags, META(`kitchen`).id AS id FROM `kitchen` UNNEST OBJECT_PAIRS(meta(`kitchen`).xattrs._sync.channels) AS op WHERE [op.name, LEAST(meta(`kitchen`).xattrs._sync.sequence, op.val.seq),IFMISSING(op.val.rev,null),IFMISSING(op.val.del,null)]  BETWEEN  [$channelName, $startSeq] AND [$channelName, $endSeq]] -- base.(*CouchbaseBucketGoCB).Query() at bucket_n1ql.go:632018-10-09T09:04:30.038+08:00 [INF] Query: N1QL Query("channels") took 1.017947623s
2018-10-09T09:04:30.038+08:00 [WRN] MultiChangesFeed got error reading changes feed "7a40a944": [5001] Panic: runtime error: index out of range -- db.(*Database).SimpleMul
tiChangesFeed.func1() at changes.go:4902018-10-09T09:04:30.038+08:00 [INF] Changes: MultiChangesFeed done   (to 7a40a944)


#2

@atom_yang, There are multiple reasons.

  1. can you make sure CBL is connected successfully with sync-gaetway ?

  2. Based on logs, I see 401 error which says that user entered wrong user name/password. Looks like you tried to disconnect wifi and reconnected wifi and then logged in again with right username and password.

  3. Also did you enable guest on sync gateway config? Can you remove guest and restart sync gateway and try with user name on android that you added in sync gateway config and see if you can have data without reconnecting wifi


#3

I don’t enable guest user on sg, and when I send the following request to sg:

curl -X GET -H "Cache-Control: no-cache"  "http://7a40a944:123456@127.0.0.1:4984/kitchen/_changes?feed=normal&include_docs=true&active_only=false"

I got the same error

2018-10-12T11:52:57.534+08:00 [WRN] Error when querying index using statement: [SELECT [op.name, LEAST(meta(`kitchen`).xattrs._sync.sequence, op.val.seq),IFMISSING(op.val.
rev,null),IFMISSING(op.val.del,null)][1] AS seq, [op.name, LEAST(meta(`kitchen`).xattrs._sync, op.val.seq),IFMISSING(op.val.rev,null),IFMISSING(op.val.del,null)][2] AS rRev, [op.name, LEAST(meta(`kitchen`).xattrs._sync, op.val.seq),IFMISSING(op.val.rev,null),IFMISSING(op.val.del,null)][3] AS rDel, meta(`kitchen`).xattrs._sync.rev AS rev, meta(`kitchen`).xattrs._sync.flags AS flags, META(`kitchen`).id AS id FROM `kitchen` UNNEST OBJECT_PAIRS(meta(`kitchen`).xattrs._sync.channels) AS op WHERE [op.name, LEAST(meta(`kitchen`).xattrs._sync.sequence, op.val.seq),IFMISSING(op.val.rev,null),IFMISSING(op.val.del,null)]  BETWEEN  [$channelName, $startSeq] AND [$channelName, $endSeq]] -- base.(*CouchbaseBucketGoCB).Query() at bucket_n1ql.go:632018-10-12T11:52:57.534+08:00 [INF] Query: N1QL Query("channels") took 792.853202ms
2018-10-12T11:52:57.534+08:00 [WRN] MultiChangesFeed got error reading changes feed "7a40a944": [5001] Panic: runtime error: index out of range -- db.(*Database).SimpleMul
tiChangesFeed.func1() at changes.go:4902018-10-12T11:52:57.534+08:00 [INF] Changes: MultiChangesFeed done   (to 7a40a944)

but at the same time, the following query with limit=500 parameter works

curl -X GET -H "Cache-Control: no-cache"  "http://7a40a944:123456@127.0.0.1:4984/kitchen/_changes?limit=500&feed=normal&include_docs=true&active_only=false"

#4

From this line:

2018-10-09T09:04:29.064+08:00 [INF] WS: [3f7835a0] Error: receiveLoop exiting with WebSocket error: read tcp 10.141.18.242:4984->222.173.43.58:34532: read: connection rese t by peer2018-10-09T09:04:29.064+08:00 [INF] WS: [3f7835a0] BLIP/Websocket Handler exited: read tcp 10.141.18.242:4984->222.173.43.58:34532: read: connection reset by peer

it looks like Couchbase Lite is closing the connection. Are there any logs on the Couchbase Lite side that indicate that the connection is being closed?


#5

On the Sync Gateway side, the error being logged when attempting to query the index is unexpected (even if client disconnection issue is probably unrelated). If you can file a github issue (https://github.com/couchbase/sync_gateway ) with as much repro information as possible, that would be appreciated.


#6

@atom_yang I filed https://github.com/couchbase/sync_gateway/issues/3798 if you want to update that ticket with steps to reproduce.