diff --git a/apps/sdk-api/src/controllers/event.controller.ts b/apps/sdk-api/src/controllers/event.controller.ts index 9d220409..e4af6950 100644 --- a/apps/sdk-api/src/controllers/event.controller.ts +++ b/apps/sdk-api/src/controllers/event.controller.ts @@ -1,3 +1,4 @@ +import { logger, logInfo } from '@/utils/logger'; import { getClientIp, parseIp } from '@/utils/parseIp'; import { getReferrerWithQuery, parseReferrer } from '@/utils/parseReferrer'; import { isUserAgentSet, parseUserAgent } from '@/utils/parseUserAgent'; @@ -61,6 +62,21 @@ function isSameDomain(url1: string | undefined, url2: string | undefined) { } } +async function withTiming(name: string, promise: T) { + try { + const start = Date.now(); + const res = await promise; + const end = Date.now(); + if (end - start > 1000) { + logInfo(`${name} took too long: ${end - start}ms`); + } + return res; + } catch (error) { + logger.error(error, `Failed to execute ${name}`); + throw error; + } +} + export async function postEvent( request: FastifyRequest<{ Body: PostEventPayload; @@ -109,8 +125,11 @@ export async function postEvent( const isServerEvent = !ip && !origin && !isUserAgentSet(ua); if (isServerEvent) { - const [event] = await getEvents( - `SELECT * FROM events WHERE name = 'screen_view' AND profile_id = '${profileId}' AND project_id = '${projectId}' ORDER BY created_at DESC LIMIT 1` + const [event] = await withTiming( + 'Get last event (server-event)', + getEvents( + `SELECT * FROM events WHERE name = 'screen_view' AND profile_id = '${profileId}' AND project_id = '${projectId}' ORDER BY created_at DESC LIMIT 1` + ) ); eventsQueue.add('event', { @@ -153,10 +172,10 @@ export async function postEvent( return reply.status(200).send(''); } - const [geo, eventsJobs] = await Promise.all([ - parseIp(ip), - eventsQueue.getJobs(['delayed']), - ]); + const [geo, eventsJobs] = await withTiming( + 'Get geo and job from queue', + Promise.all([parseIp(ip), eventsQueue.getJobs(['delayed'])]) + ); // find session_end job const sessionEndJobCurrentDeviceId = findJobByPrefix( @@ -200,8 +219,11 @@ export async function postEvent( ); } - const [sessionStartEvent] = await getEvents( - `SELECT * FROM events WHERE name = 'session_start' AND device_id = '${deviceId}' AND project_id = '${projectId}' ORDER BY created_at DESC LIMIT 1` + const [sessionStartEvent] = await withTiming( + 'Get session start event', + getEvents( + `SELECT * FROM events WHERE name = 'session_start' AND device_id = '${deviceId}' AND project_id = '${projectId}' ORDER BY created_at DESC LIMIT 1` + ) ); request.log.info( @@ -272,26 +294,36 @@ export async function postEvent( }, 'duration is wrong' ); + } else { + // Skip update duration if it's wrong + // Seems like request is not in right order + await withTiming( + 'Update previous job with duration', + job.updateData({ + type: 'createEvent', + payload: { + ...prevEvent, + duration, + }, + }) + ); } - await job.updateData({ - type: 'createEvent', - payload: { - ...prevEvent, - duration, - }, - }); - await job.promote(); + + await withTiming('Promote previous job', job.promote()); } } if (createSessionStart) { // We do not need to queue session_start - await createEvent({ - ...payload, - name: 'session_start', - // @ts-expect-error - createdAt: toISOString(getTime(payload.createdAt) - 100), - }); + await withTiming( + 'Create session start event', + createEvent({ + ...payload, + name: 'session_start', + // @ts-expect-error + createdAt: toISOString(getTime(payload.createdAt) - 100), + }) + ); } const options: JobsOptions = {}; @@ -302,13 +334,16 @@ export async function postEvent( request.log.info(payload, 'queue event'); // Queue current event - eventsQueue.add( - 'event', - { - type: 'createEvent', - payload, - }, - options + await withTiming( + 'Add current to event queue', + eventsQueue.add( + 'event', + { + type: 'createEvent', + payload, + }, + options + ) ); reply.status(202).send(deviceId); diff --git a/apps/sdk-api/src/utils/parseIp.ts b/apps/sdk-api/src/utils/parseIp.ts index 1ccc22b2..b0acd4eb 100644 --- a/apps/sdk-api/src/utils/parseIp.ts +++ b/apps/sdk-api/src/utils/parseIp.ts @@ -1,5 +1,7 @@ import type { FastifyRequest } from 'fastify'; +import { logger } from './logger'; + interface RemoteIpLookupResponse { country: string | undefined; city: string | undefined; @@ -41,7 +43,9 @@ export async function parseIp(ip?: string): Promise { } try { - const geo = await fetch(`${process.env.GEO_IP_HOST}/${ip}`); + const geo = await fetch(`${process.env.GEO_IP_HOST}/${ip}`, { + signal: AbortSignal.timeout(2000), + }); const res = (await geo.json()) as RemoteIpLookupResponse; return { @@ -51,7 +55,7 @@ export async function parseIp(ip?: string): Promise { continent: res.continent, }; } catch (e) { - console.log('Failed to parse ip', e); + logger.error('Failed to fetch geo location for ip', e); return geo; } }