Fix / gossiping sent to soon results in not getting keys

Overall improovment of logs
This commit is contained in:
Valere 2020-03-13 11:57:43 +01:00
parent 8051d9e3be
commit b71d8185a2
14 changed files with 93 additions and 46 deletions

View file

@ -743,6 +743,7 @@ internal class DefaultCryptoService @Inject constructor(
}
private fun onSecretSendReceived(event: Event) {
Timber.i("## onSecretSend() : onSecretSendReceived ${event.content?.get("sender_key")}")
if (!event.isEncrypted()) {
// secret send messages must be encrypted
Timber.e("## onSecretSend() :Received unencrypted secret send event")
@ -765,30 +766,18 @@ internal class DefaultCryptoService @Inject constructor(
return
}
val deviceId = event.mxDecryptionResult?.payload?.get("sender_device") as? String
val device = deviceId?.let { cryptoStore.getUserDevice(event.senderId, it) }
if (device == null || !device.isVerified || device.isBlocked) {
// Ignore secret from untrusted session?
Timber.i("## onSecretSend() :Received secret from untrusted device $deviceId ")
return
}
when (existingRequest.secretName) {
SELF_SIGNING_KEY_SSSS_NAME -> {
if (device.trustLevel?.isLocallyVerified() == true) {
crossSigningService.onSecretSSKGossip(secretContent.secretValue)
return
}
}
USER_SIGNING_KEY_SSSS_NAME -> {
if (device.trustLevel?.isLocallyVerified() == true) {
cryptoStore.storePrivateKeysInfo(null, null, secretContent.secretValue)
}
crossSigningService.onSecretUSKGossip(secretContent.secretValue)
return
}
else -> {
// Ask to application layer?
Timber.v("## onSecretSend() : secret not handled by SDK")
}
}
}

View file

@ -361,13 +361,13 @@ internal class DeviceListManager @Inject constructor(private val cryptoStore: IM
// Handle cross signing keys update
val masterKey = response.masterKeys?.get(userId)?.toCryptoModel().also {
Timber.d("## CrossSigning : Got keys for $userId : MSK ${it?.unpaddedBase64PublicKey}")
Timber.v("## CrossSigning : Got keys for $userId : MSK ${it?.unpaddedBase64PublicKey}")
}
val selfSigningKey = response.selfSigningKeys?.get(userId)?.toCryptoModel()?.also {
Timber.d("## CrossSigning : Got keys for $userId : SSK ${it.unpaddedBase64PublicKey}")
Timber.v("## CrossSigning : Got keys for $userId : SSK ${it.unpaddedBase64PublicKey}")
}
val userSigningKey = response.userSigningKeys?.get(userId)?.toCryptoModel()?.also {
Timber.d("## CrossSigning : Got keys for $userId : USK ${it.unpaddedBase64PublicKey}")
Timber.v("## CrossSigning : Got keys for $userId : USK ${it.unpaddedBase64PublicKey}")
}
cryptoStore.storeUserCrossSigningKeys(
userId,

View file

@ -34,6 +34,7 @@ import im.vector.matrix.android.internal.util.MatrixCoroutineDispatchers
import im.vector.matrix.android.internal.worker.WorkerParamsFactory
import im.vector.matrix.android.internal.worker.startChain
import kotlinx.coroutines.CoroutineScope
import kotlinx.coroutines.delay
import kotlinx.coroutines.launch
import timber.log.Timber
import java.util.concurrent.TimeUnit
@ -75,6 +76,9 @@ internal class OutgoingGossipingRequestManager @Inject constructor(
fun sendSecretShareRequest(secretName: String, recipients: Map<String, List<String>>) {
cryptoCoroutineScope.launch(coroutineDispatchers.crypto) {
// A bit dirty, but for better stability give other party some time to mark
// devices trusted :/
delay(1500)
cryptoStore.getOrAddOutgoingSecretShareRequest(secretName, recipients)?.let {
// TODO check if there is already one that is being sent?
if (it.state == OutgoingGossipingRequestState.SENDING || it.state == OutgoingGossipingRequestState.SENT) {

View file

@ -301,7 +301,9 @@ internal class DefaultCrossSigningService @Inject constructor(
override fun onSecretSSKGossip(sskPrivateKey: String) {
Timber.i("## CrossSigning - onSecretSSKGossip")
val mxCrossSigningInfo = getMyCrossSigningKeys() ?: return
val mxCrossSigningInfo = getMyCrossSigningKeys() ?: return Unit.also {
Timber.e("## CrossSigning - onSecretSSKGossip() received secret but public key is not known")
}
sskPrivateKey.fromBase64()
.let { privateKeySeed ->
@ -311,9 +313,10 @@ internal class DefaultCrossSigningService @Inject constructor(
selfSigningPkSigning?.releaseSigning()
selfSigningPkSigning = pkSigning
Timber.i("## CrossSigning - Loading SSK success")
cryptoStore.storePrivateKeysInfo(null, null, sskPrivateKey)
cryptoStore.storeSSKPrivateKey(sskPrivateKey)
return
} else {
Timber.e("## CrossSigning - onSecretSSKGossip() private key do not match public key")
pkSigning.releaseSigning()
}
} catch (failure: Throwable) {
@ -324,19 +327,23 @@ internal class DefaultCrossSigningService @Inject constructor(
}
override fun onSecretUSKGossip(uskPrivateKey: String) {
val mxCrossSigningInfo = getMyCrossSigningKeys() ?: return
Timber.i("## CrossSigning - onSecretUSKGossip")
val mxCrossSigningInfo = getMyCrossSigningKeys() ?: return Unit.also {
Timber.e("## CrossSigning - onSecretUSKGossip() received secret but public key is not knwow ")
}
uskPrivateKey.fromBase64()
.let { privateKeySeed ->
val pkSigning = OlmPkSigning()
try {
if (pkSigning.initWithSeed(privateKeySeed) == mxCrossSigningInfo.selfSigningKey()?.unpaddedBase64PublicKey) {
if (pkSigning.initWithSeed(privateKeySeed) == mxCrossSigningInfo.userKey()?.unpaddedBase64PublicKey) {
userPkSigning?.releaseSigning()
userPkSigning = pkSigning
Timber.i("## CrossSigning - Loading USK success")
cryptoStore.storePrivateKeysInfo(null, uskPrivateKey, null)
cryptoStore.storeUSKPrivateKey(uskPrivateKey)
return
} else {
Timber.e("## CrossSigning - onSecretUSKGossip() private key do not match public key")
pkSigning.releaseSigning()
}
} catch (failure: Throwable) {
@ -444,7 +451,7 @@ internal class DefaultCrossSigningService @Inject constructor(
* Will not force a download of the key, but will verify signatures trust chain
*/
override fun checkUserTrust(otherUserId: String): UserTrustResult {
Timber.d("## CrossSigning checkUserTrust for $otherUserId")
Timber.v("## CrossSigning checkUserTrust for $otherUserId")
if (otherUserId == userId) {
return checkSelfTrust()
}
@ -799,7 +806,7 @@ internal class DefaultCrossSigningService @Inject constructor(
users.forEach {
cryptoStore.getUserDeviceList(it)?.forEach { device ->
val updatedTrust = checkDeviceTrust(it, device.deviceId, device.trustLevel?.isLocallyVerified() ?: false)
Timber.d("## CrossSigning - update trust for device ${device.deviceId} of user $otherUserId , verified=$updatedTrust")
Timber.v("## CrossSigning - update trust for device ${device.deviceId} of user $otherUserId , verified=$updatedTrust")
cryptoStore.setDeviceTrust(it, device.deviceId, updatedTrust.isCrossSignedVerified(), updatedTrust.isLocallyVerified())
}
}

View file

@ -398,6 +398,9 @@ internal interface IMXCryptoStore {
fun markMyMasterKeyAsLocallyTrusted(trusted: Boolean)
fun storePrivateKeysInfo(msk: String?, usk: String?, ssk: String?)
fun storeSSKPrivateKey(ssk: String?)
fun storeUSKPrivateKey(usk: String?)
fun getCrossSigningPrivateKeys(): PrivateKeysInfo?
fun setUserKeysAsTrusted(userId: String, trusted: Boolean = true)

View file

@ -371,7 +371,23 @@ internal class RealmCryptoStore @Inject constructor(
doRealmTransaction(realmConfiguration) { realm ->
realm.where<CryptoMetadataEntity>().findFirst()?.apply {
xSignMasterPrivateKey = msk
xSignUserPrivateKey = usk
xSignSelfSignedPrivateKey = ssk
}
}
}
override fun storeSSKPrivateKey(ssk: String?) {
doRealmTransaction(realmConfiguration) { realm ->
realm.where<CryptoMetadataEntity>().findFirst()?.apply {
xSignSelfSignedPrivateKey = ssk
}
}
}
override fun storeUSKPrivateKey(usk: String?) {
doRealmTransaction(realmConfiguration) { realm ->
realm.where<CryptoMetadataEntity>().findFirst()?.apply {
xSignUserPrivateKey = usk
}
}

View file

@ -60,7 +60,7 @@ internal class DefaultRoomVerificationUpdateTask @Inject constructor(
// TODO ignore initial sync or back pagination?
params.events.forEach { event ->
Timber.d("## SAS Verification live observer: received msgId: ${event.eventId} msgtype: ${event.type} from ${event.senderId}")
Timber.v("## SAS Verification live observer: received msgId: ${event.eventId} msgtype: ${event.type} from ${event.senderId}")
// If the request is in the future by more than 5 minutes or more than 10 minutes in the past,
// the message should be ignored by the receiver.

View file

@ -58,6 +58,13 @@ internal abstract class DefaultVerificationTransaction(
protected fun trust(canTrustOtherUserMasterKey: Boolean,
toVerifyDeviceIds: List<String>,
eventuallyMarkMyMasterKeyAsTrusted: Boolean) {
Timber.d("## Verification: trust ($otherUserId,$otherDeviceId) , verifiedDevices:$toVerifyDeviceIds, Mark myMSK trusted $eventuallyMarkMyMasterKeyAsTrusted")
// TODO what if the otherDevice is not in this list? and should we
toVerifyDeviceIds.forEach {
setDeviceVerified(otherUserId, it)
}
// If not me sign his MSK and upload the signature
if (canTrustOtherUserMasterKey) {
// we should trust this master key
@ -74,10 +81,6 @@ internal abstract class DefaultVerificationTransaction(
// Mark my keys as trusted locally
crossSigningService.markMyMasterKeyAsTrusted()
}
if (!crossSigningService.canCrossSign()) {
outgoingGossipingRequestManager.sendSecretShareRequest(SELF_SIGNING_KEY_SSSS_NAME, mapOf(userId to listOf(otherDeviceId ?: "*")))
outgoingGossipingRequestManager.sendSecretShareRequest(USER_SIGNING_KEY_SSSS_NAME, mapOf(userId to listOf(otherDeviceId ?: "*")))
}
}
}
@ -91,11 +94,13 @@ internal abstract class DefaultVerificationTransaction(
})
}
// TODO what if the otherDevice is not in this list? and should we
toVerifyDeviceIds.forEach {
setDeviceVerified(otherUserId, it)
transport.done(transactionId) {
if (otherUserId == userId) {
outgoingGossipingRequestManager.sendSecretShareRequest(SELF_SIGNING_KEY_SSSS_NAME, mapOf(userId to listOf(otherDeviceId ?: "*")))
outgoingGossipingRequestManager.sendSecretShareRequest(USER_SIGNING_KEY_SSSS_NAME, mapOf(userId to listOf(otherDeviceId ?: "*")))
}
}
transport.done(transactionId)
state = VerificationTxState.Verified
}

View file

@ -46,7 +46,8 @@ internal interface VerificationTransport {
otherUserDeviceId: String?,
code: CancelCode)
fun done(transactionId: String)
fun done(transactionId: String,
onDone: (() -> Unit)?)
/**
* Creates an accept message suitable for this transport

View file

@ -22,8 +22,8 @@ import androidx.work.ExistingWorkPolicy
import androidx.work.Operation
import androidx.work.WorkInfo
import im.vector.matrix.android.R
import im.vector.matrix.android.api.session.crypto.verification.ValidVerificationInfoRequest
import im.vector.matrix.android.api.session.crypto.verification.CancelCode
import im.vector.matrix.android.api.session.crypto.verification.ValidVerificationInfoRequest
import im.vector.matrix.android.api.session.crypto.verification.VerificationTxState
import im.vector.matrix.android.api.session.events.model.Content
import im.vector.matrix.android.api.session.events.model.Event
@ -107,7 +107,7 @@ internal class VerificationTransportRoomMessage(
// }, listenerExecutor)
val workLiveData = workManagerProvider.workManager
.getWorkInfosForUniqueWorkLiveData("${roomId}_VerificationWork")
.getWorkInfosForUniqueWorkLiveData(uniqueQueueName())
val observer = object : Observer<List<WorkInfo>> {
override fun onChanged(workInfoList: List<WorkInfo>?) {
@ -228,7 +228,8 @@ internal class VerificationTransportRoomMessage(
enqueueSendWork(workerParams)
}
override fun done(transactionId: String) {
override fun done(transactionId: String,
onDone: (() -> Unit)?) {
Timber.d("## SAS sending done for $transactionId")
val event = createEventAndLocalEcho(
type = EventType.KEY_VERIFICATION_DONE,
@ -244,7 +245,26 @@ internal class VerificationTransportRoomMessage(
sessionId = sessionId,
event = event
))
enqueueSendWork(workerParams)
val enqueueInfo = enqueueSendWork(workerParams)
val workLiveData = workManagerProvider.workManager
.getWorkInfosForUniqueWorkLiveData(uniqueQueueName())
val observer = object : Observer<List<WorkInfo>> {
override fun onChanged(workInfoList: List<WorkInfo>?) {
workInfoList
?.filter { it.state == WorkInfo.State.SUCCEEDED }
?.firstOrNull { it.id == enqueueInfo.second }
?.let { _ ->
onDone?.invoke()
workLiveData.removeObserver(this)
}
}
}
// TODO listen to DB to get synced info
GlobalScope.launch(Dispatchers.Main) {
workLiveData.observeForever(observer)
}
}
private fun enqueueSendWork(workerParams: Data): Pair<Operation, UUID> {
@ -254,10 +274,12 @@ internal class VerificationTransportRoomMessage(
.setBackoffCriteria(BackoffPolicy.LINEAR, 2_000L, TimeUnit.MILLISECONDS)
.build()
return workManagerProvider.workManager
.beginUniqueWork("${roomId}_VerificationWork", ExistingWorkPolicy.APPEND, workRequest)
.beginUniqueWork(uniqueQueueName(), ExistingWorkPolicy.APPEND, workRequest)
.enqueue() to workRequest.id
}
private fun uniqueQueueName() = "${roomId}_VerificationWork"
override fun createAccept(tid: String,
keyAgreementProtocol: String,
hash: String,

View file

@ -145,7 +145,7 @@ internal class VerificationTransportToDevice(
.executeBy(taskExecutor)
}
override fun done(transactionId: String) {
override fun done(transactionId: String, onDone: (() -> Unit)?) {
val otherUserId = tx?.otherUserId ?: return
val otherUserDeviceId = tx?.otherDeviceId ?: return
val cancelMessage = KeyVerificationDone(transactionId)
@ -155,6 +155,7 @@ internal class VerificationTransportToDevice(
.configureWith(SendToDeviceTask.Params(EventType.KEY_VERIFICATION_DONE, contentMap, transactionId)) {
this.callback = object : MatrixCallback<Unit> {
override fun onSuccess(data: Unit) {
onDone?.invoke()
Timber.v("## SAS verification [$transactionId] done")
}

View file

@ -184,13 +184,12 @@ internal class DefaultQrCodeVerificationTransaction(
// qrCodeData.sharedSecret will be used to send the start request
start(otherQrCodeData.sharedSecret)
// Trust the other user
trust(canTrustOtherUserMasterKey,
toVerifyDeviceIds.distinct(),
eventuallyMarkMyMasterKeyAsTrusted = true)
}
private fun start(remoteSecret: String) {
private fun start(remoteSecret: String, onDone: (() -> Unit)? = null) {
if (state != VerificationTxState.None) {
Timber.e("## Verification QR: start verification from invalid state")
// should I cancel??
@ -208,7 +207,7 @@ internal class DefaultQrCodeVerificationTransaction(
startMessage,
VerificationTxState.Started,
CancelCode.User,
null
onDone
)
}

View file

@ -238,7 +238,7 @@ internal class DefaultEventRelationsAggregationTask @Inject constructor(
forwardingCurve25519KeyChain = result.forwardingCurve25519KeyChain
)
} catch (e: MXCryptoError) {
Timber.w("Failed to decrypt e2e replace")
Timber.v("Failed to decrypt e2e replace")
// TODO -> we should keep track of this and retry, or aggregation will be broken
}
}

View file

@ -171,7 +171,7 @@ abstract class VectorBaseFragment : BaseMvRxFragment(), HasScreenInjector {
override fun invalidate() {
// no-ops by default
Timber.w("invalidate() method has not been implemented")
Timber.v("invalidate() method has not been implemented")
}
protected fun setArguments(args: Parcelable? = null) {