From 1d6066d3f018212b637ab02b0c80505ca94cca57 Mon Sep 17 00:00:00 2001 From: Aarnav Tale Date: Wed, 2 Oct 2024 13:33:39 -0400 Subject: [PATCH] feat(TALE-33): add debug logging with DEBUG env --- app/integration/docker.ts | 11 ++++++++++- app/integration/kubernetes.ts | 18 +++++++++++++++++- app/integration/proc.ts | 7 ++++++- app/utils/config/headplane.ts | 30 ++++++++++++++++++++++++++++-- app/utils/config/headscale.ts | 7 +++++++ app/utils/headscale.ts | 13 +++++++++++++ app/utils/log.ts | 6 ++++++ app/utils/oidc.ts | 2 +- 8 files changed, 88 insertions(+), 6 deletions(-) diff --git a/app/integration/docker.ts b/app/integration/docker.ts index 92371ac..e4926a8 100644 --- a/app/integration/docker.ts +++ b/app/integration/docker.ts @@ -24,6 +24,7 @@ export default createIntegration({ isAvailable: async (context) => { // Check for the HEADSCALE_CONTAINER environment variable first // to avoid unnecessary fetching of the Docker socket + log.debug('INTG', 'Checking Docker integration availability') context.container = process.env.HEADSCALE_CONTAINER ?.trim() .toLowerCase() @@ -76,7 +77,8 @@ export default createIntegration({ url.pathname, ) await access(url.pathname, constants.R_OK) - } catch { + } catch (error) { + log.debug('INTG', 'Failed to access Docker socket: %s', error) log.error('INTG', 'Failed to access Docker socket: %s', path, ) @@ -100,6 +102,12 @@ export default createIntegration({ let attempts = 0 while (attempts <= context.maxAttempts) { + log.debug( + 'INTG', 'Restarting container: %s (attempt %d)', + context.container, + attempts, + ) + const response = await context.client.request({ method: 'POST', path: `/v1.30/containers/${context.container}/restart`, @@ -123,6 +131,7 @@ export default createIntegration({ attempts = 0 while (attempts <= context.maxAttempts) { try { + log.debug('INTG', 'Checking Headscale status (attempt %d)', attempts) await pull('v1', '') return } catch (error) { diff --git a/app/integration/kubernetes.ts b/app/integration/kubernetes.ts index ccca0db..f630e15 100644 --- a/app/integration/kubernetes.ts +++ b/app/integration/kubernetes.ts @@ -26,6 +26,7 @@ export default createIntegration({ const svcRoot = Config.SERVICEACCOUNT_ROOT try { + log.debug('INTG', 'Checking Kubernetes service account at %s', svcRoot) const files = await readdir(svcRoot) if (files.length === 0) { log.error('INTG', 'Kubernetes service account not found') @@ -39,6 +40,7 @@ export default createIntegration({ Config.SERVICEACCOUNT_NAMESPACE_PATH, ] + log.debug('INTG', 'Looking for %s', expectedFiles.join(', ')) if (!expectedFiles.every(file => mappedFiles.has(file))) { log.error('INTG', 'Malformed Kubernetes service account') return false @@ -48,6 +50,7 @@ export default createIntegration({ return false } + log.debug('INTG', 'Reading Kubernetes service account at %s', svcRoot) const namespace = await readFile( Config.SERVICEACCOUNT_NAMESPACE_PATH, 'utf8', @@ -68,7 +71,13 @@ export default createIntegration({ return false } + log.debug('INTG', 'Checking Kubernetes pod %s in namespace %s', + pod, + namespace, + ) + try { + log.debug('INTG', 'Attempgin to get cluster KubeConfig') const kc = new KubeConfig() kc.loadFromCluster() @@ -91,6 +100,7 @@ export default createIntegration({ kCoreV1Api.basePath, ) + log.debug('INTG', 'Reading pod info for %s', pod) const { response, body } = await kCoreV1Api.readNamespacedPod( pod, namespace, @@ -103,6 +113,7 @@ export default createIntegration({ return false } + log.debug('INTG', 'Got pod info: %o', body.spec) const shared = body.spec?.shareProcessNamespace if (shared === undefined) { log.error( @@ -127,6 +138,7 @@ export default createIntegration({ } } + log.debug('INTG', 'Looking for namespaced process in /proc') const dir = resolve('/proc') try { const subdirs = await readdir(dir) @@ -139,11 +151,14 @@ export default createIntegration({ const path = join('/proc', dir, 'cmdline') try { + log.debug('INTG', 'Reading %s', path) const data = await readFile(path, 'utf8') if (data.includes('headscale')) { return pid } - } catch {} + } catch (error) { + log.debug('INTG', 'Failed to read %s: %s', path, error) + } }) const results = await Promise.allSettled(promises) @@ -155,6 +170,7 @@ export default createIntegration({ } } + log.debug('INTG', 'Found Headscale processes: %o', pids) if (pids.length > 1) { log.error('INTG', 'Found %d Headscale processes: %s', pids.length, diff --git a/app/integration/proc.ts b/app/integration/proc.ts index 64c3628..fc56f84 100644 --- a/app/integration/proc.ts +++ b/app/integration/proc.ts @@ -22,6 +22,7 @@ export default createIntegration({ return false } + log.debug('INTG', 'Checking /proc for Headscale process') const dir = resolve('/proc') try { const subdirs = await readdir(dir) @@ -34,11 +35,14 @@ export default createIntegration({ const path = join('/proc', dir, 'cmdline') try { + log.debug('INTG', 'Reading %s', path) const data = await readFile(path, 'utf8') if (data.includes('headscale')) { return pid } - } catch {} + } catch (error) { + log.error('INTG', 'Failed to read %s: %s', path, error) + } }) const results = await Promise.allSettled(promises) @@ -50,6 +54,7 @@ export default createIntegration({ } } + log.debug('INTG', 'Found Headscale processes: %o', pids) if (pids.length > 1) { log.error('INTG', 'Found %d Headscale processes: %s', pids.length, diff --git a/app/utils/config/headplane.ts b/app/utils/config/headplane.ts index 6987bcd..d0e1e36 100644 --- a/app/utils/config/headplane.ts +++ b/app/utils/config/headplane.ts @@ -13,6 +13,7 @@ import { HeadscaleConfig, loadConfig } from '~/utils/config/headscale' import log from '~/utils/log' export interface HeadplaneContext { + debug: boolean headscaleUrl: string cookieSecret: string integration: IntegrationFactory | undefined @@ -38,6 +39,12 @@ export async function loadContext(): Promise { return context } + const debug = process.env.DEBUG === 'true' + if (debug) { + log.info('CTXT', 'Debug mode is enabled! Logs will spam a lot.') + log.info('CTXT', 'Please disable debug mode in production.') + } + const path = resolve(process.env.CONFIG_FILE ?? '/etc/headscale/config.yaml') const { config, contextData } = await checkConfig(path) @@ -60,6 +67,7 @@ export async function loadContext(): Promise { } context = { + debug, headscaleUrl, cookieSecret, integration: await loadIntegration(), @@ -80,10 +88,13 @@ export async function loadContext(): Promise { } async function checkConfig(path: string) { + log.debug('CTXT', 'Checking config at %s', path) + let config: HeadscaleConfig | undefined try { config = await loadConfig(path) } catch { + log.debug('CTXT', 'Config at %s failed to load', path) return { config: undefined, contextData: { @@ -95,9 +106,12 @@ async function checkConfig(path: string) { let write = false try { + log.debug('CTXT', 'Checking write access to %s', path) await access(path, constants.W_OK) write = true - } catch {} + } catch { + log.debug('CTXT', 'No write access to %s', path) + } return { config, @@ -109,7 +123,12 @@ async function checkConfig(path: string) { } async function checkOidc(config?: HeadscaleConfig) { + log.debug('CTXT', 'Checking OIDC configuration') + const disableKeyLogin = process.env.DISABLE_API_KEY_LOGIN === 'true' + log.debug('CTXT', 'API Key Login Enabled: %s', !disableKeyLogin) + + log.debug('CTXT', 'Checking ROOT_API_KEY and falling back to API_KEY') const rootKey = process.env.ROOT_API_KEY ?? process.env.API_KEY if (!rootKey) { throw new Error('ROOT_API_KEY or API_KEY not set') @@ -119,6 +138,10 @@ async function checkOidc(config?: HeadscaleConfig) { let client = process.env.OIDC_CLIENT_ID let secret = process.env.OIDC_CLIENT_SECRET + log.debug('CTXT', 'Checking OIDC environment variables') + log.debug('CTXT', 'Issuer: %s', issuer) + log.debug('CTXT', 'Client: %s', client) + if ( (issuer ?? client ?? secret) && !(issuer && client && secret) @@ -143,6 +166,7 @@ async function checkOidc(config?: HeadscaleConfig) { secret = config.oidc?.client_secret if (!secret && config.oidc?.client_secret_path) { + log.debug('CTXT', 'Trying to read OIDC client secret from %s', config.oidc.client_secret_path) try { const data = await readFile( config.oidc.client_secret_path, @@ -152,7 +176,9 @@ async function checkOidc(config?: HeadscaleConfig) { if (data && data.length > 0) { secret = data.trim() } - } catch {} + } catch { + log.error('CTXT', 'Failed to read OIDC client secret from %s', config.oidc.client_secret_path) + } } } diff --git a/app/utils/config/headscale.ts b/app/utils/config/headscale.ts index d3455a8..be9b333 100644 --- a/app/utils/config/headscale.ts +++ b/app/utils/config/headscale.ts @@ -187,10 +187,12 @@ export async function loadConfig(path?: string) { throw new Error('Path is required to lazy load config') } + log.debug('CFGX', 'Loading Headscale configuration from %s', path) const data = await readFile(path, 'utf8') configYaml = parseDocument(data) if (process.env.HEADSCALE_CONFIG_UNSTRICT === 'true') { + log.debug('CFGX', 'Loaded Headscale configuration in non-strict mode') const loaded = configYaml.toJSON() as Record config = { ...loaded, @@ -249,8 +251,10 @@ export async function loadConfig(path?: string) { } try { + log.debug('CFGX', 'Attempting to parse Headscale configuration') config = await HeadscaleConfig.parseAsync(configYaml.toJSON()) } catch (error) { + log.debug('CFGX', 'Failed to load Headscale configuration') if (error instanceof z.ZodError) { log.error('CFGX', 'Recieved invalid configuration file') log.error('CFGX', 'The following schema issues were found:') @@ -279,7 +283,9 @@ export async function patchConfig(partial: Record) { throw new Error('Config not loaded') } + log.debug('CFGX', 'Patching Headscale configuration') for (const [key, value] of Object.entries(partial)) { + log.debug('CFGX', 'Patching %s with %s', key, value) // If the key is something like `test.bar."foo.bar"`, then we treat // the foo.bar as a single key, and not as two keys, so that needs // to be split correctly. @@ -321,5 +327,6 @@ export async function patchConfig(partial: Record) { : (await HeadscaleConfig.parseAsync(configYaml.toJSON())) const path = resolve(process.env.CONFIG_FILE ?? '/etc/headscale/config.yaml') + log.debug('CFGX', 'Writing patched configuration to %s', path) await writeFile(path, configYaml.toString(), 'utf8') } diff --git a/app/utils/headscale.ts b/app/utils/headscale.ts index 6d34ce5..003bba7 100644 --- a/app/utils/headscale.ts +++ b/app/utils/headscale.ts @@ -1,4 +1,5 @@ import { loadContext } from './config/headplane' +import log from './log' export class HeadscaleError extends Error { status: number @@ -20,6 +21,8 @@ export class FatalError extends Error { export async function pull(url: string, key: string) { const context = await loadContext() const prefix = context.headscaleUrl + + log.debug('APIC', 'GET %s', `${prefix}/api/${url}`) const response = await fetch(`${prefix}/api/${url}`, { headers: { Authorization: `Bearer ${key}`, @@ -27,6 +30,7 @@ export async function pull(url: string, key: string) { }) if (!response.ok) { + log.debug('APIC', 'GET %s failed with status %d', `${prefix}/api/${url}`, response.status) throw new HeadscaleError(await response.text(), response.status) } @@ -36,6 +40,8 @@ export async function pull(url: string, key: string) { export async function post(url: string, key: string, body?: unknown) { const context = await loadContext() const prefix = context.headscaleUrl + + log.debug('APIC', 'POST %s', `${prefix}/api/${url}`) const response = await fetch(`${prefix}/api/${url}`, { method: 'POST', body: body ? JSON.stringify(body) : undefined, @@ -45,6 +51,7 @@ export async function post(url: string, key: string, body?: unknown) { }) if (!response.ok) { + log.debug('APIC', 'POST %s failed with status %d', `${prefix}/api/${url}`, response.status) throw new HeadscaleError(await response.text(), response.status) } @@ -54,6 +61,8 @@ export async function post(url: string, key: string, body?: unknown) { export async function put(url: string, key: string, body?: unknown) { const context = await loadContext() const prefix = context.headscaleUrl + + log.debug('APIC', 'PUT %s', `${prefix}/api/${url}`) const response = await fetch(`${prefix}/api/${url}`, { method: 'PUT', body: body ? JSON.stringify(body) : undefined, @@ -63,6 +72,7 @@ export async function put(url: string, key: string, body?: unknown) { }) if (!response.ok) { + log.debug('APIC', 'PUT %s failed with status %d', `${prefix}/api/${url}`, response.status) throw new HeadscaleError(await response.text(), response.status) } @@ -72,6 +82,8 @@ export async function put(url: string, key: string, body?: unknown) { export async function del(url: string, key: string) { const context = await loadContext() const prefix = context.headscaleUrl + + log.debug('APIC', 'DELETE %s', `${prefix}/api/${url}`) const response = await fetch(`${prefix}/api/${url}`, { method: 'DELETE', headers: { @@ -80,6 +92,7 @@ export async function del(url: string, key: string) { }) if (!response.ok) { + log.debug('APIC', 'DELETE %s failed with status %d', `${prefix}/api/${url}`, response.status) throw new HeadscaleError(await response.text(), response.status) } diff --git a/app/utils/log.ts b/app/utils/log.ts index b9c4775..ce1f7a1 100644 --- a/app/utils/log.ts +++ b/app/utils/log.ts @@ -10,6 +10,12 @@ export default { error: (category: string, message: string, ...args: unknown[]) => { defaultLog('ERRO', category, message, ...args) }, + + debug: (category: string, message: string, ...args: unknown[]) => { + if (process.env.DEBUG === 'true') { + defaultLog('DEBG', category, message, ...args) + } + } } function defaultLog( diff --git a/app/utils/oidc.ts b/app/utils/oidc.ts index 4b2482d..9b25f18 100644 --- a/app/utils/oidc.ts +++ b/app/utils/oidc.ts @@ -2,7 +2,7 @@ import { redirect } from '@remix-run/node' import { authorizationCodeGrantRequest, calculatePKCECodeChallenge, - type Client, + Client, discoveryRequest, generateRandomCodeVerifier, generateRandomNonce,