improve debug-logging for authentication

backend/src/federation/authenticateCommunities.ts

@@ -1,11 +1,13 @@
 import { Community as DbCommunity } from '@entity/Community'
 import { FederatedCommunity as DbFederatedCommunity } from '@entity/FederatedCommunity'
+import { v4 as uuidv4, validate as validateUUID, version as versionUUID } from 'uuid'
 
 import { CONFIG } from '@/config'
 // eslint-disable-next-line camelcase
 import { AuthenticationClient as V1_0_AuthenticationClient } from '@/federation/client/1_0/AuthenticationClient'
 import { backendLogger as logger } from '@/server/logger'
 
+
 import { OpenConnectionArgs } from './client/1_0/model/OpenConnectionArgs'
 import { AuthenticationClientFactory } from './client/AuthenticationClientFactory'
 
@@ -18,7 +20,19 @@ export async function startCommunityAuthentication(
     apiVersion: CONFIG.FEDERATION_BACKEND_SEND_ON_API,
   })
   const foreignCom = await DbCommunity.findOneByOrFail({ publicKey: foreignFedCom.publicKey })
-  if (foreignCom && foreignCom.communityUuid === null && foreignCom.authenticatedAt === null) {
+  logger.debug(
+    'Authentication: started for foreignFedCom:',
+    foreignFedCom.endPoint,
+    foreignFedCom.publicKey.toString('hex'),
+  )
+  // check if communityUuid is a valid v4Uuid and not still a temporary onetimecode
+  if (
+    foreignCom &&
+    ((foreignCom.communityUuid === null && foreignCom.authenticatedAt === null) ||
+      (foreignCom.communityUuid !== null &&
+        !validateUUID(foreignCom.communityUuid) &&
+        versionUUID(foreignCom.communityUuid) !== 4))
+  ) {
     try {
       const client = AuthenticationClientFactory.getInstance(foreignFedCom)
       // eslint-disable-next-line camelcase

backend/src/federation/client/1_0/AuthenticationClient.ts

@@ -26,7 +26,11 @@ export class AuthenticationClient {
   }
 
   async openConnection(args: OpenConnectionArgs): Promise<boolean | undefined> {
-    logger.debug('Authentication: openConnection with endpoint', this.endpoint)
+    logger.debug(
+      `Authentication: openConnection at ${this.endpoint} for args:`,
+      args.url,
+      Buffer.from(args.publicKey, 'hex').toString(),
+    )
     try {
       // eslint-disable-next-line @typescript-eslint/no-unsafe-assignment
       const { data } = await this.client.rawRequest(openConnection, { args })

federation/src/graphql/api/1_0/resolver/AuthenticationResolver.ts

@@ -18,15 +18,23 @@ export class AuthenticationResolver {
     @Arg('data')
     args: OpenConnectionArgs,
   ): Promise<boolean> {
-    logger.debug(`Authentication: openConnection() via apiVersion=1_0 ...`, args)
+    logger.debug(
+      `Authentication: openConnection() via apiVersion=1_0 ...`,
+      args.url,
+      Buffer.from(args.publicKey, 'hex').toString(),
+    )
 
     // first find with args.publicKey the community, which starts openConnection request
     const requestedCom = await DbCommunity.findOneBy({
       publicKey: Buffer.from(args.publicKey),
     })
     if (!requestedCom) {
-      throw new LogError(`unknown requesting community with publicKey`, args.publicKey)
+      throw new LogError(
+        `unknown requesting community with publicKey`,
+        Buffer.from(args.publicKey, 'hex').toString(),
+      )
     }
+    logger.debug(`Authentication: found requestedCom:`, requestedCom)
     // no await to respond immediatly and invoke callback-request asynchron
     void startOpenConnectionCallback(args, requestedCom, CONFIG.FEDERATION_API)
     return true
@@ -41,10 +49,12 @@ export class AuthenticationResolver {
     // TODO decrypt args.url with homeCom.privateKey and verify signing with callbackFedCom.publicKey
     const endPoint = args.url.slice(0, args.url.lastIndexOf('/'))
     const apiVersion = args.url.slice(args.url.lastIndexOf('/'), args.url.length)
+    logger.debug(`Authentication: search fedCom per:`, endPoint, apiVersion)
     const callbackFedCom = await DbFedCommunity.findOneBy({ endPoint, apiVersion })
     if (!callbackFedCom) {
       throw new LogError(`unknown callback community with url`, args.url)
     }
+    logger.debug(`Authentication: found fedCom and start authentication:`, callbackFedCom)
     // no await to respond immediatly and invoke authenticate-request asynchron
     void startAuthentication(args.oneTimeCode, callbackFedCom)
     return true

federation/src/graphql/api/1_0/util/authenticateCommunity.ts

@@ -16,9 +16,9 @@ export async function startOpenConnectionCallback(
   api: string,
 ): Promise<void> {
   logger.debug(
-    `Authentication: startOpenConnectionRedirect()...`,
-    args.publicKey,
+    `Authentication: startOpenConnectionCallback() with:`,
     args.url,
+    Buffer.from(args.publicKey, 'hex').toString(),
     requestedCom,
   )
   try {
@@ -31,6 +31,7 @@ export async function startOpenConnectionCallback(
     // store oneTimeCode in requestedCom.community_uuid as authenticate-request-identifier
     requestedCom.communityUuid = oneTimeCode.toString()
     await DbCommunity.save(requestedCom)
+    logger.debug(`Authentication: stored oneTimeCode in requestedCom:`, requestedCom)
 
     const client = AuthenticationClientFactory.getInstance(homeFedCom)
     // eslint-disable-next-line camelcase
@@ -41,14 +42,15 @@ export async function startOpenConnectionCallback(
       callbackArgs.url = homeFedCom.endPoint.endsWith('/')
         ? homeFedCom.endPoint
         : homeFedCom.endPoint + '/' + homeFedCom.apiVersion
+      logger.debug(`Authentication: start openConnectionCallback with args:`, callbackArgs)
       if (await client.openConnectionCallback(callbackArgs)) {
-        logger.debug('Authentication: startOpenConnectionRedirect() successful:', callbackArgs)
+        logger.debug('Authentication: startOpenConnectionCallback() successful:', callbackArgs)
       } else {
-        logger.error('Authentication: startOpenConnectionRedirect() failed:', callbackArgs)
+        logger.error('Authentication: startOpenConnectionCallback() failed:', callbackArgs)
       }
     }
   } catch (err) {
-    logger.error('Authentication: error in startOpenConnectionRedirect:', err)
+    logger.error('Authentication: error in startOpenConnectionCallback:', err)
   }
 }
 
@@ -74,15 +76,20 @@ export async function startAuthentication(
       if (homeCom.communityUuid) {
         authenticationArgs.uuid = homeCom.communityUuid
       }
-      logger.debug(`Authentication: vor authenticate()...`, authenticationArgs)
+      logger.debug(`Authentication: invoke authenticate() with:`, authenticationArgs)
       const fedComUuid = await client.authenticate(authenticationArgs)
-      logger.debug(`Authentication: nach authenticate()...`, fedComUuid)
+      logger.debug(`Authentication: response of authenticate():`, fedComUuid)
       if (fedComUuid !== null) {
-        // TODO decrypt fedComUuid with callbackFedCom.publicKey
+        logger.debug(
+          `Authentication: received communityUUid for callbackFedCom:`,
+          fedComUuid,
+          callbackFedCom,
+        )
         const callbackCom = await DbCommunity.findOneByOrFail({
           foreign: true,
           publicKey: callbackFedCom.publicKey,
         })
+        // TODO decrypt fedComUuid with callbackFedCom.publicKey
         callbackCom.communityUuid = fedComUuid
         callbackCom.authenticatedAt = new Date()
         await DbCommunity.save(callbackCom)