v20 / private-groups: can't decrypt add-member, some times.

[cryptix]

I started testing the go-ssb private groups implementation against this one and am running into a weird bug where in about 10% of runs, my side can't use the DM key that is on the invite message. The rest of the time it works fine.

I haven't yet managed to dump the inputs to the key derivation to see what's exactly going wrong but here are some code snippets and reproduction steps:

        // javascript creates the group and invites the go-bot (testBot)
	sbot.tribes.create({}, (err, data) => {
		const { groupId } = data
		t.comment(groupId)

		function mkMsg(msg) { // helper to create a bunch of messages
			return function(cb) { sbot.publish(msg, cb) }
		}
		n = 24 
		let msgs = []
		for (var i = n; i>0; i--) {
			msgs.push(mkMsg({type:"test", text:"foo", i:i, "recps": [groupId]}))
		}
		msgs.push(mkMsg({type: 'contact', contact: claireRef, following: true}))
		msgs.push(mkMsg({type: 'contact', contact: testBob, following: true}))
		
		let welcome = { text: 'this is a test group' }
		sbot.tribes.invite(groupId, [testBob, claireRef], welcome, (err, msg) => {
			t.error(err, 'invite worked')
			
			// post a public hint to guide the go-bot to the invite (kludge until re-indexing is in)
			msgs.push(mkMsg({type: 'test-hint', invite: msg.key, groupId}))

			parallel(msgs, (err, results) => { // publish all the test messages
				t.error(err, "parallel of publish")
				t.equal(msgs.length, results.length, "message count")
				run() // connect to the go-side and sync
			})
		})
	}) // tribes.create

To reproduce you need to have Go installed, preferebly 1.14 at least.

git clone https://github.com/cryptoscope/ssb go-ssb
cd go-ssb/tests
git checkout private-groups-4
npm ci
go test -run GroupsJSCreate -count 30 -failfast

(The flag -count n just means "run this N times", 10 usually has been enough to show this on my box.)

A passing testrun looks like this:

...
TAP version 13
# TestGroupsJSCreate2
# sbot spawned, running before
# %/Ay/0O2u94QwebyXvT7vP039YIZ9FcovbThcgFXf2ug=.cloaked
ok 1 invite worked
ok 2 parallel of publish
ok 3 message count
# dialing:net:127.0.0.1:33987~shs:y1yHvVTAMBnNtwEPOkHjm3JCN8GVI07bVIyb+auuuZI=
ok 4 connected
level=debug t=1.847452668s feedmanager=(MISSING) event=gossiptx n=2 fr=<@y1yH.ed25519>
level=debug t=1.850913608s plugin=gossip event="feed fetch workers filled" n=1
level=debug t=1.912452341s plugin=gossip event=gossiprx fr=<@440H.ed25519> latest=0 received=29 took=65.368884ms
level=debug t=1.912509658s plugin=gossip event="workers done" err=null
level=debug t=1.912522552s plugin=gossip remote=<@440H.ed25519> event=gossiprx msg="hops fetch done" count=2 took=111.139418ms
# closed sbot

1..4
# tests 4
# pass  4

# ok

JS Sbot process returned
debug: no root?!
0 message in tangle
TAP version 13
# claire
# sbot spawned, running before
# dialing:net:127.0.0.1:33987~shs:y1yHvVTAMBnNtwEPOkHjm3JCN8GVI07bVIyb+auuuZI=
ok 1 connected
level=debug t=7.431606481s feedmanager=(MISSING) event=gossiptx n=3 fr=<@y1yH.ed25519>
level=debug t=7.433477833s feedmanager=(MISSING) event=gossiptx n=29 fr=<@440H.ed25519>
level=debug t=7.440671314s plugin=gossip event="feed fetch workers filled" n=1
level=debug t=7.45321103s plugin=gossip event="workers done" err=null
level=debug t=7.453245518s plugin=gossip remote=<@oM77.ed25519> event=gossiprx msg="hops fetch done" count=2 took=71.104807ms
ok 2 received and read hello group msg
ok 3 got the add-member msg
ok 4 correct text on group reply from bob
# closed sbot

1..4
# tests 4
# pass  4

# ok

JS Sbot process returned
level=debug t=14.595833193s event="network listen loop exited"
level=debug t=14.595847898s event="sbot closing" msg="connections closed"
level=debug t=14.595867819s event="sbot closing" msg="waited for indexes to close"
level=info t=14.622994226s event="sbot closing" msg="closers closed"
PASS
ok  	go.cryptoscope.co/ssb/tests	14.656s

While a FAIL looks like this:

...
TAP version 13
# TestGroupsJSCreate26
# sbot spawned, running before
# %logwOSnlK4Ed5Ln7yIeZQngBND2DfAO4shD4FWkY/r4=.cloaked
ok 1 invite worked
ok 2 parallel of publish
ok 3 message count
# dialing:net:127.0.0.1:36115~shs:T49TcQ2SucVnRrm05IjQnXce5XBnLKyBeV5UUXnuG4M=
ok 4 connected
level=debug t=1.843719537s feedmanager=(MISSING) event=gossiptx n=2 fr=<@T49T.ed25519>
level=debug t=1.904555506s plugin=gossip event=gossiprx fr=<@Gilz.ed25519> latest=0 received=29 took=61.240747ms
level=debug t=1.904674253s plugin=gossip event="feed fetch workers filled" n=1
level=debug t=1.905678884s plugin=gossip event="workers done" err=null
level=debug t=1.905709246s plugin=gossip remote=<@Gilz.ed25519> event=gossiprx msg="hops fetch done" count=2 took=107.255921ms
# closed sbot

1..4
# tests 4
# pass  4

# ok

JS Sbot process returned
--- FAIL: TestGroupsJSCreate (7.02s)
    interop_test.go:129: go-sbot: @T49TcQ2SucVnRrm05IjQnXce5XBnLKyBeV5UUXnuG4M=.ed25519
    interop_test.go:205: JS claire:26 @mW5xFgOcXAhNSf4WW79tXfa8qSjEct4LTuWYcdNPyXs=.ed25519
    interop_test.go:205: JS TestGroupsJSCreate26:28 @GilzV125qfYQF2j+aEmzzVWX3kpAMpUKsSAVjJ+cvSQ=.ed25519
    privategroups_test.go:122: hint: %ylAp2L6voKJNuDwch7pwMAJNpyQxcLZcyyzxgxsBqjI=.sha256
    privategroups_test.go:129: 
        	Error Trace:	privategroups_test.go:129
        	Error:      	Received unexpected error:
        	           	box2: could not decrypt
        	Test:       	TestGroupsJSCreate
FAIL
exit status 1
FAIL	go.cryptoscope.co/ssb/tests	65.564s

where it blocks on line 129 here, an error from trying to decrypt the invite message which usually works all the other times.

[mixmix]

Heads up that box2 implementation is in modules ssbc/ssb-tribes (so this issue should perhaps live there).

This is strange. Would be interested to know what the error is with unboxing... Like how far do you get.

Notes/ thoughts :

1. the invite is encrypted to the shared groupKey, and the shared DMKey (for the new purple being added). Can you decrypt with the groupKey?
2. the encryption in each case depends on the id of the messages prior to it in the feed. I have seen problems in past (which I thought we fixed) when too many messages are published in parallel too fast. See if slowing down bulk publishing helps at all, there may be a race condition still. (this is why I asked in (1) if you can decrypt it still with the group key... see if the original js author can even open it?)

[mixmix]

3. Are you using ssb-db@20.3.0 And the ssb-tribes@0.4.1?

There were some fixes included in minor /patches which addressed some bulk publishing bugs

[stale]

Is this still relevant? If so, what is blocking it? Is there anything you can do to help move it forward?