fix: enable debug logging and improve DCL sync observability

- Fix logger bug where debug level (0) was treated as falsy
  - Change `||` to `??` in config.js to properly handle log level 0
  - Debug logs now work correctly when LOG_LEVEL=debug

- Add server startup logging
  - Log port, environment, and log level on server start
  - Helps verify configuration is loaded correctly

- Add DCL API request debug logging
  - Log full API request parameters when LOG_LEVEL=debug
  - API key is redacted (shows first/last 4 chars only)
  - Helps troubleshoot DCL sync issues

- Update CLAUDE.md documentation
  - Add Logging section with log levels and configuration
  - Document debug logging feature for DCL service
  - Add this fix to Recent Commits section

Note: .env file added locally with LOG_LEVEL=debug (not committed)

Co-Authored-By: Claude Sonnet 4.5 <noreply@anthropic.com>
This commit is contained in:
2026-01-18 07:02:52 +01:00
parent 27d2ef14ef
commit 223461f536
8 changed files with 424 additions and 116 deletions

View File

@@ -58,6 +58,17 @@ export async function fetchQSOsFromDCL(dclApiKey, sinceDate = null) {
requestBody.qsl_since = dateStr;
}
// Debug log request parameters (redact API key)
logger.debug('DCL API request parameters', {
url: DCL_API_URL,
method: 'POST',
key: dclApiKey ? `${dclApiKey.substring(0, 4)}...${dclApiKey.substring(dclApiKey.length - 4)}` : null,
limit: requestBody.limit,
qsl_since: requestBody.qsl_since,
qso_since: requestBody.qso_since,
cnf_only: requestBody.cnf_only,
});
try {
const controller = new AbortController();
const timeoutId = setTimeout(() => controller.abort(), REQUEST_TIMEOUT);

View File

@@ -19,20 +19,21 @@ export const JobStatus = {
const activeJobs = new Map();
/**
* Enqueue a new LoTW sync job
* Enqueue a new sync job
* @param {number} userId - User ID
* @param {string} jobType - Type of job ('lotw_sync' or 'dcl_sync')
* @returns {Promise<Object>} Job object with ID
*/
export async function enqueueJob(userId) {
logger.debug('Enqueueing LoTW sync job', { userId });
export async function enqueueJob(userId, jobType = 'lotw_sync') {
logger.debug('Enqueueing sync job', { userId, jobType });
// Check for existing active job
const existingJob = await getUserActiveJob(userId);
// Check for existing active job of the same type
const existingJob = await getUserActiveJob(userId, jobType);
if (existingJob) {
logger.debug('Existing active job found', { jobId: existingJob.id });
logger.debug('Existing active job found', { jobId: existingJob.id, jobType });
return {
success: false,
error: 'A LoTW sync job is already running or pending for this user',
error: `A ${jobType} job is already running or pending for this user`,
existingJob: existingJob.id,
};
}
@@ -42,16 +43,16 @@ export async function enqueueJob(userId) {
.insert(syncJobs)
.values({
userId,
type: 'lotw_sync',
type: jobType,
status: JobStatus.PENDING,
createdAt: new Date(),
})
.returning();
logger.info('Job created', { jobId: job.id, userId });
logger.info('Job created', { jobId: job.id, userId, jobType });
// Start processing asynchronously (don't await)
processJobAsync(job.id, userId).catch((error) => {
processJobAsync(job.id, userId, jobType).catch((error) => {
logger.error(`Job processing error`, { jobId: job.id, error: error.message });
});
@@ -68,15 +69,14 @@ export async function enqueueJob(userId) {
}
/**
* Process a LoTW sync job asynchronously
* Process a sync job asynchronously
* @param {number} jobId - Job ID
* @param {number} userId - User ID
* @param {string} jobType - Type of job ('lotw_sync' or 'dcl_sync')
*/
async function processJobAsync(jobId, userId) {
async function processJobAsync(jobId, userId, jobType) {
const jobPromise = (async () => {
try {
// Import dynamically to avoid circular dependency
const { syncQSOs } = await import('./lotw.service.js');
const { getUserById } = await import('./auth.service.js');
// Update status to running
@@ -85,37 +85,72 @@ async function processJobAsync(jobId, userId) {
startedAt: new Date(),
});
// Get user credentials
const user = await getUserById(userId);
if (!user || !user.lotwUsername || !user.lotwPassword) {
await updateJob(jobId, {
status: JobStatus.FAILED,
completedAt: new Date(),
error: 'LoTW credentials not configured',
let result;
if (jobType === 'dcl_sync') {
// Get user credentials
const user = await getUserById(userId);
if (!user || !user.dclApiKey) {
await updateJob(jobId, {
status: JobStatus.FAILED,
completedAt: new Date(),
error: 'DCL credentials not configured',
});
return null;
}
// Get last QSL date for incremental sync
const { getLastDCLQSLDate, syncQSOs: syncDCLQSOs } = await import('./dcl.service.js');
const lastQSLDate = await getLastDCLQSLDate(userId);
const sinceDate = lastQSLDate || new Date('2000-01-01');
if (lastQSLDate) {
logger.info(`Job ${jobId}: DCL incremental sync`, { since: sinceDate.toISOString().split('T')[0] });
} else {
logger.info(`Job ${jobId}: DCL full sync`);
}
// Update job progress
await updateJobProgress(jobId, {
message: 'Fetching QSOs from DCL...',
step: 'fetch',
});
return null;
}
// Get last QSL date for incremental sync
const { getLastLoTWQSLDate } = await import('./lotw.service.js');
const lastQSLDate = await getLastLoTWQSLDate(userId);
const sinceDate = lastQSLDate || new Date('2000-01-01');
if (lastQSLDate) {
logger.info(`Job ${jobId}: Incremental sync`, { since: sinceDate.toISOString().split('T')[0] });
// Execute the sync
result = await syncDCLQSOs(userId, user.dclApiKey, sinceDate, jobId);
} else {
logger.info(`Job ${jobId}: Full sync`);
// LoTW sync (default)
const user = await getUserById(userId);
if (!user || !user.lotwUsername || !user.lotwPassword) {
await updateJob(jobId, {
status: JobStatus.FAILED,
completedAt: new Date(),
error: 'LoTW credentials not configured',
});
return null;
}
// Get last QSL date for incremental sync
const { getLastLoTWQSLDate, syncQSOs } = await import('./lotw.service.js');
const lastQSLDate = await getLastLoTWQSLDate(userId);
const sinceDate = lastQSLDate || new Date('2000-01-01');
if (lastQSLDate) {
logger.info(`Job ${jobId}: LoTW incremental sync`, { since: sinceDate.toISOString().split('T')[0] });
} else {
logger.info(`Job ${jobId}: LoTW full sync`);
}
// Update job progress
await updateJobProgress(jobId, {
message: 'Fetching QSOs from LoTW...',
step: 'fetch',
});
// Execute the sync
result = await syncQSOs(userId, user.lotwUsername, user.lotwPassword, sinceDate, jobId);
}
// Update job progress
await updateJobProgress(jobId, {
message: 'Fetching QSOs from LoTW...',
step: 'fetch',
});
// Execute the sync
const result = await syncQSOs(userId, user.lotwUsername, user.lotwPassword, sinceDate, jobId);
// Update job as completed
await updateJob(jobId, {
status: JobStatus.COMPLETED,
@@ -197,9 +232,10 @@ export async function getJobStatus(jobId) {
/**
* Get user's active job (pending or running)
* @param {number} userId - User ID
* @param {string} jobType - Optional job type filter
* @returns {Promise<Object|null>} Active job or null
*/
export async function getUserActiveJob(userId) {
export async function getUserActiveJob(userId, jobType = null) {
const conditions = [
eq(syncJobs.userId, userId),
or(
@@ -208,6 +244,10 @@ export async function getUserActiveJob(userId) {
),
];
if (jobType) {
conditions.push(eq(syncJobs.type, jobType));
}
const [job] = await db
.select()
.from(syncJobs)