diff --git a/ts/challenge.ts b/ts/challenge.ts index b1f3f2bee..fb702ff8f 100644 --- a/ts/challenge.ts +++ b/ts/challenge.ts @@ -18,38 +18,40 @@ import { parseRetryAfterWithDefault } from './util/parseRetryAfter'; import { clearTimeoutIfNecessary } from './util/clearTimeoutIfNecessary'; import { getEnvironment, Environment } from './environment'; import type { StorageInterface } from './types/Storage.d'; +import * as Errors from './types/errors'; import { HTTPError } from './textsecure/Errors'; import type { SendMessageChallengeData } from './textsecure/Errors'; import * as log from './logging/log'; -export type ChallengeResponse = { - readonly captcha: string; -}; +export type ChallengeResponse = Readonly<{ + captcha: string; +}>; -export type IPCRequest = { - readonly seq: number; -}; +export type IPCRequest = Readonly<{ + seq: number; + reason: string; +}>; -export type IPCResponse = { - readonly seq: number; - readonly data: ChallengeResponse; -}; +export type IPCResponse = Readonly<{ + seq: number; + data: ChallengeResponse; +}>; -type Handler = { - readonly token: string | undefined; +type Handler = Readonly<{ + token: string | undefined; resolve(response: ChallengeResponse): void; reject(error: Error): void; -}; +}>; -export type ChallengeData = { - readonly type: 'recaptcha'; - readonly token: string; - readonly captcha: string; -}; +export type ChallengeData = Readonly<{ + type: 'recaptcha'; + token: string; + captcha: string; +}>; -export type Options = { - readonly storage: Pick; +export type Options = Readonly<{ + storage: Pick; requestChallenge(request: IPCRequest): void; @@ -63,17 +65,33 @@ export type Options = { onChallengeFailed(retryAfter?: number): void; expireAfter?: number; -}; +}>; export const STORAGE_KEY = 'challenge:conversations'; export type RegisteredChallengeType = Readonly<{ conversationId: string; createdAt: number; + reason: string; retryAt?: number; token?: string; }>; +type SolveOptionsType = Readonly<{ + token: string; + reason: string; +}>; + +export type MaybeSolveOptionsType = Readonly<{ + conversationId: string; + reason: string; +}>; + +export type RequestCaptchaOptionsType = Readonly<{ + reason: string; + token?: string; +}>; + const DEFAULT_EXPIRE_AFTER = 24 * 3600 * 1000; // one day const CAPTCHA_URL = 'https://signalcaptchas.org/challenge/generate.html'; const CAPTCHA_STAGING_URL = @@ -181,7 +199,7 @@ export class ChallengeHandler { await this.startAllQueues(); } - public maybeSolve(conversationId: string): void { + public maybeSolve({ conversationId, reason }: MaybeSolveOptionsType): void { const challenge = this.registeredConversations.get(conversationId); if (!challenge) { return; @@ -192,7 +210,7 @@ export class ChallengeHandler { } if (challenge.token) { - this.solve(challenge.token); + this.solve({ reason, token: challenge.token }); } } @@ -200,10 +218,11 @@ export class ChallengeHandler { challenge: RegisteredChallengeType, data?: SendMessageChallengeData ): Promise { - const { conversationId } = challenge; + const { conversationId, reason } = challenge; + const logId = `challenge(${reason})`; if (this.isRegistered(conversationId)) { - log.info(`challenge: conversation ${conversationId} already registered`); + log.info(`${logId}: conversation ${conversationId} already registered`); return; } @@ -212,9 +231,7 @@ export class ChallengeHandler { // Challenge is already retryable - start the queue if (shouldStartQueue(challenge)) { - log.info( - `challenge: starting conversation ${conversationId} immediately` - ); + log.info(`${logId}: starting conversation ${conversationId} immediately`); await this.startQueue(conversationId); return; } @@ -234,27 +251,25 @@ export class ChallengeHandler { }, waitTime) ); log.info( - `challenge: tracking ${conversationId} with waitTime=${waitTime}` + `${logId}: tracking ${conversationId} with waitTime=${waitTime}` ); } else { - log.info(`challenge: tracking ${conversationId} with no waitTime`); + log.info(`${logId}: tracking ${conversationId} with no waitTime`); } if (data && !data.options?.includes('recaptcha')) { - log.error( - `challenge: unexpected options ${JSON.stringify(data.options)}` - ); + log.error(`${logId}: unexpected options ${JSON.stringify(data.options)}`); } if (!challenge.token) { const dataString = JSON.stringify(data); log.error( - `challenge: ${conversationId} is waiting; no token in data ${dataString}` + `${logId}: ${conversationId} is waiting; no token in data ${dataString}` ); return; } - this.solve(challenge.token); + this.solve({ token: challenge.token, reason }); } public onResponse(response: IPCResponse): void { @@ -279,8 +294,11 @@ export class ChallengeHandler { await this.persist(); } - public async requestCaptcha(token = ''): Promise { - const request: IPCRequest = { seq: this.seq }; + public async requestCaptcha({ + reason, + token = '', + }: RequestCaptchaOptionsType): Promise { + const request: IPCRequest = { seq: this.seq, reason }; this.seq += 1; this.options.requestChallenge(request); @@ -335,12 +353,12 @@ export class ChallengeHandler { this.options.startQueue(conversationId); } - private async solve(token: string): Promise { + private async solve({ reason, token }: SolveOptionsType): Promise { this.solving += 1; this.options.setChallengeStatus('required'); this.challengeToken = token; - const captcha = await this.requestCaptcha(token); + const captcha = await this.requestCaptcha({ reason, token }); // Another `.solve()` has completed earlier than us if (this.challengeToken === undefined) { @@ -353,7 +371,7 @@ export class ChallengeHandler { this.options.setChallengeStatus('pending'); - log.info('challenge: sending challenge to server'); + log.info(`challenge(${reason}): sending challenge to server`); try { await this.sendChallengeResponse({ @@ -362,13 +380,16 @@ export class ChallengeHandler { captcha, }); } catch (error) { - log.error(`challenge: challenge failure, error: ${error && error.stack}`); + log.error( + `challenge(${reason}): challenge failure, error:`, + Errors.toLogFormat(error) + ); this.options.setChallengeStatus('required'); this.solving -= 1; return; } - log.info('challenge: challenge success. force sending'); + log.info(`challenge(${reason}): challenge success. force sending`); this.options.setChallengeStatus('idle'); diff --git a/ts/components/StandaloneRegistration.tsx b/ts/components/StandaloneRegistration.tsx index 9beb027c2..87e507c7f 100644 --- a/ts/components/StandaloneRegistration.tsx +++ b/ts/components/StandaloneRegistration.tsx @@ -133,7 +133,9 @@ export const StandaloneRegistration = ({ setError('Captcha handler is not ready!'); return; } - const token = await window.Signal.challengeHandler.requestCaptcha(); + const token = await window.Signal.challengeHandler.requestCaptcha({ + reason: 'standalone registration', + }); try { requestVerification(type, number, token); diff --git a/ts/jobs/conversationJobQueue.ts b/ts/jobs/conversationJobQueue.ts index 3aa4c6db7..3ede93885 100644 --- a/ts/jobs/conversationJobQueue.ts +++ b/ts/jobs/conversationJobQueue.ts @@ -157,12 +157,15 @@ export class ConversationJobQueue extends JobQueue { data: Readonly, insert?: (job: ParsedJob) => Promise ): Promise> { - const { conversationId } = data; + const { conversationId, type } = data; strictAssert( window.Signal.challengeHandler, 'conversationJobQueue.add: Missing challengeHandler!' ); - window.Signal.challengeHandler.maybeSolve(conversationId); + window.Signal.challengeHandler.maybeSolve({ + conversationId, + reason: `conversationJobQueue.add(${conversationId}, ${type})`, + }); return super.add(data, insert); } @@ -382,6 +385,9 @@ export class ConversationJobQueue extends JobQueue { createdAt: Date.now(), retryAt: toProcess.retryAt, token: toProcess.data?.token, + reason: + 'conversationJobQueue.run(' + + `${conversation.idForLogging()}, ${type}, ${timestamp})`, }, toProcess.data ); diff --git a/ts/main/challengeMain.ts b/ts/main/challengeMain.ts index e38ff25fe..e1f210098 100644 --- a/ts/main/challengeMain.ts +++ b/ts/main/challengeMain.ts @@ -1,10 +1,10 @@ // Copyright 2021 Signal Messenger, LLC // SPDX-License-Identifier: AGPL-3.0-only -/* eslint-disable no-console */ import type { IpcMainEvent } from 'electron'; import { ipcMain as ipc } from 'electron'; +import * as log from '../logging/log'; import type { IPCRequest, IPCResponse, ChallengeResponse } from '../challenge'; export class ChallengeMainHandler { @@ -19,6 +19,12 @@ export class ChallengeMainHandler { const { handlers } = this; this.handlers = []; + + log.info( + 'challengeMain.handleCaptcha: sending captcha response to ' + + `${handlers.length} handlers`, + response + ); for (const resolve of handlers) { resolve(response); } @@ -28,13 +34,17 @@ export class ChallengeMainHandler { event: IpcMainEvent, request: IPCRequest ): Promise { - console.log('Received challenge request, waiting for response'); + const logId = `challengeMain.onRequest(${request.reason})`; + log.info(`${logId}: received challenge request, waiting for response`); + + const start = Date.now(); const data = await new Promise(resolve => { this.handlers.push(resolve); }); - console.log('Sending challenge response', data); + const duration = Date.now() - start; + log.info(`${logId}: got response after ${duration}ms`); const ipcResponse: IPCResponse = { seq: request.seq, diff --git a/ts/test-both/challenge_test.ts b/ts/test-both/challenge_test.ts index d3b4a3bbd..a10139e03 100644 --- a/ts/test-both/challenge_test.ts +++ b/ts/test-both/challenge_test.ts @@ -56,6 +56,7 @@ describe('ChallengeHandler', () => { token: '1', retryAt: NOW + DEFAULT_RETRY_AFTER, createdAt: NOW - SECOND, + reason: 'test', ...options, }; }; diff --git a/ts/textsecure/Errors.ts b/ts/textsecure/Errors.ts index 801017313..7ae40acb9 100644 --- a/ts/textsecure/Errors.ts +++ b/ts/textsecure/Errors.ts @@ -144,10 +144,10 @@ export class SendMessageNetworkError extends ReplayableError { } } -export type SendMessageChallengeData = { - readonly token?: string; - readonly options?: ReadonlyArray; -}; +export type SendMessageChallengeData = Readonly<{ + token?: string; + options?: ReadonlyArray; +}>; export class SendMessageChallengeError extends ReplayableError { public identifier: string;