mirror of
https://github.com/bookorbit/bookorbit.git
synced 2026-11-03 00:11:37 -06:00
feat: standardize logging with some initial logs
This commit is contained in:
neon
@@ -1,6 +1,7 @@
|
||||
<script setup lang="ts">
|
||||
import { computed, onMounted, ref, watch } from 'vue'
|
||||
import { ChevronDown, Loader2, RefreshCw, Sparkles, Star } from 'lucide-vue-next'
|
||||
import { toast } from 'vue-sonner'
|
||||
import type { BookDetail } from '@projectx/types'
|
||||
import { FORMAT_TO_GROUP } from '@projectx/types'
|
||||
import { Tooltip, TooltipContent, TooltipTrigger } from '@/components/ui/tooltip'
|
||||
@@ -113,6 +114,12 @@ const { refreshing: autoFilling, previewRefresh } = useRefreshMetadata()
|
||||
async function autoFill() {
|
||||
const preview = await previewRefresh(props.book.id)
|
||||
if (!preview) return
|
||||
|
||||
if (Object.keys(preview).length === 0) {
|
||||
toast.info('No new metadata found')
|
||||
return
|
||||
}
|
||||
|
||||
if (preview.title != null) form.title = preview.title
|
||||
if (preview.subtitle != null) form.subtitle = preview.subtitle
|
||||
if (preview.description != null) form.description = preview.description
|
||||
@@ -159,7 +166,7 @@ async function autoFill() {
|
||||
<!-- Right: Form -->
|
||||
<div class="flex-1 min-w-0 space-y-3">
|
||||
<!-- Action bar -->
|
||||
<div class="flex items-center justify-between min-h-[2rem]">
|
||||
<div class="flex items-center justify-between min-h-8">
|
||||
<p v-if="error" class="text-sm text-destructive">{{ error }}</p>
|
||||
<span v-else />
|
||||
<div class="flex gap-2">
|
||||
@@ -268,7 +275,7 @@ async function autoFill() {
|
||||
|
||||
<!-- Series | Index | Publisher -->
|
||||
<div class="flex flex-wrap gap-3">
|
||||
<div class="flex-1 min-w-[140px] space-y-1">
|
||||
<div class="flex-1 min-w-35 space-y-1">
|
||||
<label class="text-xs font-medium text-muted-foreground uppercase tracking-wider">Series</label>
|
||||
<input
|
||||
v-model="form.seriesName"
|
||||
@@ -286,7 +293,7 @@ async function autoFill() {
|
||||
@input="setFloatField('seriesIndex', $event)"
|
||||
/>
|
||||
</div>
|
||||
<div class="flex-1 min-w-[120px] space-y-1">
|
||||
<div class="flex-1 min-w-30 space-y-1">
|
||||
<label class="text-xs font-medium text-muted-foreground uppercase tracking-wider">Publisher</label>
|
||||
<input
|
||||
v-model="form.publisher"
|
||||
@@ -326,7 +333,7 @@ async function autoFill() {
|
||||
@input="setIntField('pageCount', $event)"
|
||||
/>
|
||||
</div>
|
||||
<div class="flex-1 min-w-[90px] space-y-1">
|
||||
<div class="flex-1 min-w-22.5 space-y-1">
|
||||
<label class="text-xs font-medium text-muted-foreground uppercase tracking-wider">ISBN-13</label>
|
||||
<input
|
||||
v-model="form.isbn13"
|
||||
@@ -334,7 +341,7 @@ async function autoFill() {
|
||||
maxlength="13"
|
||||
/>
|
||||
</div>
|
||||
<div class="flex-1 min-w-[85px] space-y-1">
|
||||
<div class="flex-1 min-w-21.25 space-y-1">
|
||||
<label class="text-xs font-medium text-muted-foreground uppercase tracking-wider">ISBN-10</label>
|
||||
<input
|
||||
v-model="form.isbn10"
|
||||
@@ -365,7 +372,7 @@ async function autoFill() {
|
||||
<div class="space-y-1">
|
||||
<label class="text-xs font-medium text-muted-foreground uppercase tracking-wider">Provider IDs</label>
|
||||
<div class="rounded-lg border border-border bg-muted/30 p-3 flex gap-3 overflow-x-auto">
|
||||
<div v-for="{ field, label } in providerIdFields" :key="field" class="space-y-1 min-w-[120px] flex-1">
|
||||
<div v-for="{ field, label } in providerIdFields" :key="field" class="space-y-1 min-w-30 flex-1">
|
||||
<label class="text-xs font-medium text-muted-foreground uppercase tracking-wider">{{ label }}</label>
|
||||
<input
|
||||
v-model="form[field]"
|
||||
|
||||
@@ -95,6 +95,8 @@ export class AuthService {
|
||||
})
|
||||
.returning({ id: schema.users.id, username: schema.users.username, name: schema.users.name });
|
||||
|
||||
this.logger.log(`[auth.register] [success] user=${user.id} username=${user.username}`);
|
||||
|
||||
this.auditEvents.emit(AUDIT_EVENT, {
|
||||
userId: user.id,
|
||||
actorUsername: user.username,
|
||||
@@ -152,9 +154,11 @@ export class AuthService {
|
||||
})
|
||||
.returning({
|
||||
id: schema.users.id,
|
||||
username: schema.users.username,
|
||||
tokenVersion: schema.users.tokenVersion,
|
||||
});
|
||||
|
||||
this.logger.log(`[auth.setup] [success] admin=${user.username}`);
|
||||
return user;
|
||||
});
|
||||
|
||||
@@ -164,6 +168,7 @@ export class AuthService {
|
||||
async login(dto: LoginDto, reply: FastifyReply, ip?: string) {
|
||||
const user = await this.userService.findByUsername(dto.username);
|
||||
if (!user || !user.active || !(await compare(dto.password, user.passwordHash))) {
|
||||
this.logger.warn(`[auth.login] [fail] user=${dto.username} ip=${ip ?? 'unknown'} reason="Invalid credentials"`);
|
||||
this.auditEvents.emit(AUDIT_EVENT, {
|
||||
userId: null,
|
||||
actorUsername: 'system',
|
||||
@@ -180,6 +185,8 @@ export class AuthService {
|
||||
this.setRefreshCookie(reply, rawRefreshToken);
|
||||
this.setAccessCookie(reply, accessToken);
|
||||
|
||||
this.logger.log(`[auth.login] [success] user=${user.id} username=${user.username}`);
|
||||
|
||||
this.auditEvents.emit(AUDIT_EVENT, {
|
||||
userId: user.id,
|
||||
actorUsername: user.username,
|
||||
@@ -225,16 +232,21 @@ export class AuthService {
|
||||
where: eq(schema.refreshTokens.tokenHash, tokenHash),
|
||||
});
|
||||
|
||||
if (!row) throw new UnauthorizedException();
|
||||
if (!row) {
|
||||
this.logger.warn(`[auth.refresh] [fail] reason="Token not found"`);
|
||||
throw new UnauthorizedException();
|
||||
}
|
||||
|
||||
// Reuse of a revoked token → theft signal, revoke all user sessions
|
||||
if (row.revokedAt) {
|
||||
this.logger.warn(`[auth.refresh] [fail] user=${row.userId} reason="Token revoked - reuse attempt"`);
|
||||
await this.db.delete(schema.refreshTokens).where(eq(schema.refreshTokens.userId, row.userId));
|
||||
this.clearRefreshCookie(reply);
|
||||
throw new UnauthorizedException();
|
||||
}
|
||||
|
||||
if (row.expiresAt < new Date()) {
|
||||
this.logger.warn(`[auth.refresh] [fail] user=${row.userId} reason="Token expired"`);
|
||||
this.clearRefreshCookie(reply);
|
||||
throw new UnauthorizedException();
|
||||
}
|
||||
@@ -245,6 +257,7 @@ export class AuthService {
|
||||
const userForToken = await this.db.query.users.findFirst({ where: eq(schema.users.id, row.userId) });
|
||||
if (!userForToken) throw new UnauthorizedException();
|
||||
if (!userForToken.active) {
|
||||
this.logger.warn(`[auth.refresh] [fail] user=${row.userId} reason="Account disabled"`);
|
||||
this.clearRefreshCookie(reply);
|
||||
this.clearAccessCookie(reply);
|
||||
throw new UnauthorizedException('Account disabled');
|
||||
@@ -266,6 +279,7 @@ export class AuthService {
|
||||
const row = await this.db.query.refreshTokens.findFirst({ where: eq(schema.refreshTokens.tokenHash, tokenHash) });
|
||||
if (row) {
|
||||
userId = row.userId;
|
||||
this.logger.log(`[auth.logout] [success] user=${row.userId}`);
|
||||
await Promise.all([
|
||||
this.userService.incrementTokenVersion(row.userId),
|
||||
this.db.update(schema.refreshTokens).set({ revokedAt: new Date() }).where(eq(schema.refreshTokens.id, row.id)),
|
||||
|
||||
@@ -158,18 +158,54 @@ export class AuthorsService {
|
||||
}
|
||||
|
||||
async searchMetadata(dto: ListAuthorMetadataDto): Promise<AuthorMetadataCandidate[]> {
|
||||
return this.authorMetadataFetchService.search(
|
||||
{
|
||||
name: dto.q,
|
||||
region: dto.region,
|
||||
limit: dto.limit,
|
||||
},
|
||||
{ keys: dto.providers },
|
||||
const event = 'author.search_metadata';
|
||||
const startedAt = Date.now();
|
||||
this.logger.log(
|
||||
`[${event}] [start] query=${JSON.stringify(dto.q)} region=${dto.region ?? 'default'} limit=${dto.limit ?? 0} providerCount=${dto.providers?.length ?? 0} - author metadata search started`,
|
||||
);
|
||||
try {
|
||||
const result = await this.authorMetadataFetchService.search(
|
||||
{
|
||||
name: dto.q,
|
||||
region: dto.region,
|
||||
limit: dto.limit,
|
||||
},
|
||||
{ keys: dto.providers },
|
||||
);
|
||||
this.logger.log(
|
||||
`[${event}] [end] query=${JSON.stringify(dto.q)} durationMs=${Date.now() - startedAt} resultCount=${result.length} - author metadata search completed`,
|
||||
);
|
||||
return result;
|
||||
} catch (err) {
|
||||
const errorClass = err instanceof Error ? err.name : 'Error';
|
||||
const errorMessage = (err instanceof Error ? err.message : String(err)).replace(/"/g, '\\"');
|
||||
this.logger.warn(
|
||||
`[${event}] [fail] query=${JSON.stringify(dto.q)} durationMs=${Date.now() - startedAt} errorClass=${errorClass} error="${errorMessage}" - author metadata search failed`,
|
||||
);
|
||||
throw err;
|
||||
}
|
||||
}
|
||||
|
||||
async lookupMetadata(dto: LookupAuthorMetadataDto): Promise<AuthorMetadataCandidate | null> {
|
||||
return this.authorMetadataFetchService.lookupById(dto.provider, dto.id, dto.region);
|
||||
const event = 'author.lookup_metadata';
|
||||
const startedAt = Date.now();
|
||||
this.logger.log(
|
||||
`[${event}] [start] provider=${dto.provider} providerId=${JSON.stringify(dto.id)} region=${dto.region ?? 'default'} - author metadata lookup started`,
|
||||
);
|
||||
try {
|
||||
const result = await this.authorMetadataFetchService.lookupById(dto.provider, dto.id, dto.region);
|
||||
this.logger.log(
|
||||
`[${event}] [end] provider=${dto.provider} providerId=${JSON.stringify(dto.id)} durationMs=${Date.now() - startedAt} found=${result != null} - author metadata lookup completed`,
|
||||
);
|
||||
return result;
|
||||
} catch (err) {
|
||||
const errorClass = err instanceof Error ? err.name : 'Error';
|
||||
const errorMessage = (err instanceof Error ? err.message : String(err)).replace(/"/g, '\\"');
|
||||
this.logger.warn(
|
||||
`[${event}] [fail] provider=${dto.provider} providerId=${JSON.stringify(dto.id)} durationMs=${Date.now() - startedAt} errorClass=${errorClass} error="${errorMessage}" - author metadata lookup failed`,
|
||||
);
|
||||
throw err;
|
||||
}
|
||||
}
|
||||
|
||||
streamMetadata(dto: ListAuthorMetadataDto): Observable<AuthorMetadataCandidate> {
|
||||
@@ -258,93 +294,152 @@ export class AuthorsService {
|
||||
}
|
||||
|
||||
async update(user: RequestUser, authorId: number, dto: UpdateAuthorDto): Promise<AuthorDetail> {
|
||||
await this.assertMutationAccess(user, [authorId]);
|
||||
const event = 'author.update';
|
||||
const startedAt = Date.now();
|
||||
this.logger.log(`[${event}] [start] userId=${user.id} authorId=${authorId} - author update started`);
|
||||
try {
|
||||
await this.assertMutationAccess(user, [authorId]);
|
||||
|
||||
const values: Parameters<AuthorsRepository['updateAuthorById']>[1] = {};
|
||||
const values: Parameters<AuthorsRepository['updateAuthorById']>[1] = {};
|
||||
|
||||
if ('name' in dto) {
|
||||
const name = dto.name?.trim();
|
||||
if (!name) throw new BadRequestException('name cannot be empty');
|
||||
values.name = name;
|
||||
if ('name' in dto) {
|
||||
const name = dto.name?.trim();
|
||||
if (!name) throw new BadRequestException('name cannot be empty');
|
||||
values.name = name;
|
||||
}
|
||||
|
||||
if ('sortName' in dto) {
|
||||
values.sortName = dto.sortName?.trim() || null;
|
||||
}
|
||||
|
||||
if ('description' in dto) {
|
||||
values.description = dto.description?.trim() || null;
|
||||
}
|
||||
|
||||
const fieldNames = Object.keys(values);
|
||||
if (fieldNames.length === 0) {
|
||||
const detail = await this.findOne(user, authorId);
|
||||
this.logger.log(
|
||||
`[${event}] [end] userId=${user.id} authorId=${authorId} durationMs=${Date.now() - startedAt} fields=none noChange=true - author update completed`,
|
||||
);
|
||||
return detail;
|
||||
}
|
||||
|
||||
const updated = await this.authorsRepo.updateAuthorById(authorId, values);
|
||||
if (!updated) throw new NotFoundException('Author not found');
|
||||
if (values.name !== undefined) {
|
||||
await this.enrichmentOrchestrator.schedule(authorId, 'author_rename');
|
||||
}
|
||||
const detail = await this.findOne(user, authorId);
|
||||
this.logger.log(
|
||||
`[${event}] [end] userId=${user.id} authorId=${authorId} durationMs=${Date.now() - startedAt} fields=${fieldNames.join(',')} noChange=false - author update completed`,
|
||||
);
|
||||
return detail;
|
||||
} catch (err) {
|
||||
const errorClass = err instanceof Error ? err.name : 'Error';
|
||||
const errorMessage = (err instanceof Error ? err.message : String(err)).replace(/"/g, '\\"');
|
||||
this.logger.warn(
|
||||
`[${event}] [fail] userId=${user.id} authorId=${authorId} durationMs=${Date.now() - startedAt} errorClass=${errorClass} error="${errorMessage}" - author update failed`,
|
||||
);
|
||||
throw err;
|
||||
}
|
||||
|
||||
if ('sortName' in dto) {
|
||||
values.sortName = dto.sortName?.trim() || null;
|
||||
}
|
||||
|
||||
if ('description' in dto) {
|
||||
values.description = dto.description?.trim() || null;
|
||||
}
|
||||
|
||||
if (Object.keys(values).length === 0) {
|
||||
return this.findOne(user, authorId);
|
||||
}
|
||||
|
||||
const updated = await this.authorsRepo.updateAuthorById(authorId, values);
|
||||
if (!updated) throw new NotFoundException('Author not found');
|
||||
if (values.name !== undefined) {
|
||||
await this.enrichmentOrchestrator.schedule(authorId, 'author_rename');
|
||||
}
|
||||
this.logger.log(`author.update userId=${user.id} authorId=${authorId} fields=${Object.keys(values).join(',')}`);
|
||||
|
||||
return this.findOne(user, authorId);
|
||||
}
|
||||
|
||||
async merge(user: RequestUser, dto: MergeAuthorsDto): Promise<MergeAuthorsResult> {
|
||||
if (!this.isSuperuser(user)) {
|
||||
throw new ForbiddenException('Only superusers can merge authors');
|
||||
}
|
||||
|
||||
const uniqueSourceIds = [...new Set(dto.sourceAuthorIds)].filter((id) => id !== dto.targetAuthorId);
|
||||
if (uniqueSourceIds.length === 0) {
|
||||
throw new BadRequestException('sourceAuthorIds must include at least one author different from targetAuthorId');
|
||||
}
|
||||
|
||||
const allAuthorIds = [dto.targetAuthorId, ...uniqueSourceIds];
|
||||
await this.assertMutationAccess(user, allAuthorIds);
|
||||
|
||||
const affectedBookCount = await this.authorsRepo.countDistinctBooks(uniqueSourceIds);
|
||||
await this.authorsRepo.mergeAuthors(dto.targetAuthorId, uniqueSourceIds);
|
||||
await this.enrichmentOrchestrator.schedule(dto.targetAuthorId, 'author_merge_target');
|
||||
const event = 'author.merge';
|
||||
const startedAt = Date.now();
|
||||
this.logger.log(
|
||||
`author.merge userId=${user.id} targetAuthorId=${dto.targetAuthorId} sourceAuthorIds=${uniqueSourceIds.join(',')} affectedBookCount=${affectedBookCount}`,
|
||||
`[${event}] [start] userId=${user.id} targetAuthorId=${dto.targetAuthorId} sourceCount=${dto.sourceAuthorIds.length} - author merge started`,
|
||||
);
|
||||
const target = await this.findOne(user, dto.targetAuthorId);
|
||||
try {
|
||||
if (!this.isSuperuser(user)) {
|
||||
throw new ForbiddenException('Only superusers can merge authors');
|
||||
}
|
||||
|
||||
return {
|
||||
target,
|
||||
mergedAuthorIds: uniqueSourceIds,
|
||||
affectedBookCount,
|
||||
};
|
||||
const uniqueSourceIds = [...new Set(dto.sourceAuthorIds)].filter((id) => id !== dto.targetAuthorId);
|
||||
if (uniqueSourceIds.length === 0) {
|
||||
throw new BadRequestException('sourceAuthorIds must include at least one author different from targetAuthorId');
|
||||
}
|
||||
|
||||
const allAuthorIds = [dto.targetAuthorId, ...uniqueSourceIds];
|
||||
await this.assertMutationAccess(user, allAuthorIds);
|
||||
|
||||
const affectedBookCount = await this.authorsRepo.countDistinctBooks(uniqueSourceIds);
|
||||
await this.authorsRepo.mergeAuthors(dto.targetAuthorId, uniqueSourceIds);
|
||||
await this.enrichmentOrchestrator.schedule(dto.targetAuthorId, 'author_merge_target');
|
||||
const target = await this.findOne(user, dto.targetAuthorId);
|
||||
|
||||
this.logger.log(
|
||||
`[${event}] [end] userId=${user.id} targetAuthorId=${dto.targetAuthorId} durationMs=${Date.now() - startedAt} mergedCount=${uniqueSourceIds.length} affectedBookCount=${affectedBookCount} - author merge completed`,
|
||||
);
|
||||
return {
|
||||
target,
|
||||
mergedAuthorIds: uniqueSourceIds,
|
||||
affectedBookCount,
|
||||
};
|
||||
} catch (err) {
|
||||
const errorClass = err instanceof Error ? err.name : 'Error';
|
||||
const errorMessage = (err instanceof Error ? err.message : String(err)).replace(/"/g, '\\"');
|
||||
this.logger.warn(
|
||||
`[${event}] [fail] userId=${user.id} targetAuthorId=${dto.targetAuthorId} durationMs=${Date.now() - startedAt} errorClass=${errorClass} error="${errorMessage}" - author merge failed`,
|
||||
);
|
||||
throw err;
|
||||
}
|
||||
}
|
||||
|
||||
async delete(user: RequestUser, dto: DeleteAuthorsDto): Promise<{ deletedAuthorIds: number[]; affectedBookCount: number }> {
|
||||
if (!this.isSuperuser(user)) {
|
||||
throw new ForbiddenException('Only superusers can delete authors');
|
||||
const event = 'author.delete';
|
||||
const startedAt = Date.now();
|
||||
this.logger.log(`[${event}] [start] userId=${user.id} count=${dto.authorIds.length} - author delete started`);
|
||||
try {
|
||||
if (!this.isSuperuser(user)) {
|
||||
throw new ForbiddenException('Only superusers can delete authors');
|
||||
}
|
||||
|
||||
const authorIds = [...new Set(dto.authorIds)];
|
||||
await this.assertMutationAccess(user, authorIds);
|
||||
|
||||
const affectedBookCount = await this.authorsRepo.countDistinctBooks(authorIds);
|
||||
await this.authorsRepo.deleteAuthors(authorIds);
|
||||
this.logger.log(
|
||||
`[${event}] [end] userId=${user.id} durationMs=${Date.now() - startedAt} deletedCount=${authorIds.length} affectedBookCount=${affectedBookCount} - author delete completed`,
|
||||
);
|
||||
|
||||
return {
|
||||
deletedAuthorIds: authorIds,
|
||||
affectedBookCount,
|
||||
};
|
||||
} catch (err) {
|
||||
const errorClass = err instanceof Error ? err.name : 'Error';
|
||||
const errorMessage = (err instanceof Error ? err.message : String(err)).replace(/"/g, '\\"');
|
||||
this.logger.warn(
|
||||
`[${event}] [fail] userId=${user.id} count=${dto.authorIds.length} durationMs=${Date.now() - startedAt} errorClass=${errorClass} error="${errorMessage}" - author delete failed`,
|
||||
);
|
||||
throw err;
|
||||
}
|
||||
|
||||
const authorIds = [...new Set(dto.authorIds)];
|
||||
await this.assertMutationAccess(user, authorIds);
|
||||
|
||||
const affectedBookCount = await this.authorsRepo.countDistinctBooks(authorIds);
|
||||
await this.authorsRepo.deleteAuthors(authorIds);
|
||||
this.logger.log(`author.delete userId=${user.id} authorIds=${authorIds.join(',')} affectedBookCount=${affectedBookCount}`);
|
||||
|
||||
return {
|
||||
deletedAuthorIds: authorIds,
|
||||
affectedBookCount,
|
||||
};
|
||||
}
|
||||
|
||||
async refreshEnrichment(user: RequestUser, authorId: number): Promise<AuthorDetail> {
|
||||
await this.assertMutationAccess(user, [authorId]);
|
||||
const event = 'author.refresh_enrichment';
|
||||
const startedAt = Date.now();
|
||||
this.logger.log(`[${event}] [start] userId=${user.id} authorId=${authorId} - author enrichment refresh started`);
|
||||
try {
|
||||
await this.assertMutationAccess(user, [authorId]);
|
||||
|
||||
const result = await this.refreshEnrichmentInternal(authorId);
|
||||
|
||||
this.logger.log(
|
||||
`author.enrichment.refresh userId=${user.id} authorId=${authorId} provider=${result.provider ?? 'none'} descriptionUpdated=${result.descriptionUpdated} imageUpdated=${result.imageUpdated}`,
|
||||
);
|
||||
return this.findOne(user, authorId);
|
||||
const result = await this.refreshEnrichmentInternal(authorId);
|
||||
const detail = await this.findOne(user, authorId);
|
||||
this.logger.log(
|
||||
`[${event}] [end] userId=${user.id} authorId=${authorId} durationMs=${Date.now() - startedAt} provider=${result.provider ?? 'none'} descriptionUpdated=${result.descriptionUpdated} imageUpdated=${result.imageUpdated} - author enrichment refresh completed`,
|
||||
);
|
||||
return detail;
|
||||
} catch (err) {
|
||||
const errorClass = err instanceof Error ? err.name : 'Error';
|
||||
const errorMessage = (err instanceof Error ? err.message : String(err)).replace(/"/g, '\\"');
|
||||
this.logger.warn(
|
||||
`[${event}] [fail] userId=${user.id} authorId=${authorId} durationMs=${Date.now() - startedAt} errorClass=${errorClass} error="${errorMessage}" - author enrichment refresh failed`,
|
||||
);
|
||||
throw err;
|
||||
}
|
||||
}
|
||||
|
||||
async getThumbnailPath(user: RequestUser, authorId: number): Promise<string | null> {
|
||||
@@ -362,55 +457,78 @@ export class AuthorsService {
|
||||
user: RequestUser,
|
||||
onProgress?: (event: { authorId: number; updated: boolean; imageUpdated?: boolean; imageUrl?: string | null; error?: string }) => void,
|
||||
): Promise<{ processed: number; failed: number; updated: number }> {
|
||||
const uniqueAuthorIds = [...new Set(authorIds)];
|
||||
if (uniqueAuthorIds.length === 0) {
|
||||
return { processed: 0, failed: 0, updated: 0 };
|
||||
}
|
||||
const event = 'author.bulk_refresh_metadata';
|
||||
const startedAt = Date.now();
|
||||
this.logger.log(`[${event}] [start] userId=${user.id} count=${authorIds.length} - bulk author metadata refresh started`);
|
||||
try {
|
||||
const uniqueAuthorIds = [...new Set(authorIds)];
|
||||
if (uniqueAuthorIds.length === 0) {
|
||||
this.logger.log(
|
||||
`[${event}] [end] userId=${user.id} count=0 durationMs=${Date.now() - startedAt} processed=0 updated=0 failed=0 - bulk author metadata refresh completed`,
|
||||
);
|
||||
return { processed: 0, failed: 0, updated: 0 };
|
||||
}
|
||||
|
||||
await this.assertMutationAccess(user, uniqueAuthorIds);
|
||||
await this.assertMutationAccess(user, uniqueAuthorIds);
|
||||
|
||||
let processed = 0;
|
||||
let failed = 0;
|
||||
let updated = 0;
|
||||
let processed = 0;
|
||||
let failed = 0;
|
||||
let updated = 0;
|
||||
let callbackInterrupted = false;
|
||||
|
||||
for (let index = 0; index < uniqueAuthorIds.length; index += 1) {
|
||||
const authorId = uniqueAuthorIds[index]!;
|
||||
let didUpdate = false;
|
||||
let imageUpdated = false;
|
||||
let imageUrl: string | null | undefined;
|
||||
let errorMessage: string | undefined;
|
||||
for (let index = 0; index < uniqueAuthorIds.length; index += 1) {
|
||||
const authorId = uniqueAuthorIds[index]!;
|
||||
let didUpdate = false;
|
||||
let imageUpdated = false;
|
||||
let imageUrl: string | null | undefined;
|
||||
let errorMessage: string | undefined;
|
||||
|
||||
try {
|
||||
const result = await this.refreshEnrichmentInternal(authorId);
|
||||
didUpdate = result.descriptionUpdated || result.imageUpdated;
|
||||
imageUpdated = result.imageUpdated;
|
||||
if (imageUpdated) {
|
||||
imageUrl = await this.authorImageStorage.getThumbnailUrlIfExists(authorId);
|
||||
try {
|
||||
const result = await this.refreshEnrichmentInternal(authorId);
|
||||
didUpdate = result.descriptionUpdated || result.imageUpdated;
|
||||
imageUpdated = result.imageUpdated;
|
||||
if (imageUpdated) {
|
||||
imageUrl = await this.authorImageStorage.getThumbnailUrlIfExists(authorId);
|
||||
}
|
||||
if (didUpdate) {
|
||||
updated += 1;
|
||||
}
|
||||
} catch (error) {
|
||||
failed += 1;
|
||||
const itemErrorClass = error instanceof Error ? error.name : 'Error';
|
||||
errorMessage = error instanceof Error ? error.message : 'Failed to refresh metadata';
|
||||
const itemError = errorMessage.replace(/"/g, '\\"');
|
||||
this.logger.warn(
|
||||
`[${event}] [fail] userId=${user.id} authorId=${authorId} durationMs=${Date.now() - startedAt} errorClass=${itemErrorClass} error="${itemError}" - author metadata refresh item failed`,
|
||||
);
|
||||
}
|
||||
if (didUpdate) {
|
||||
updated += 1;
|
||||
|
||||
processed += 1;
|
||||
try {
|
||||
onProgress?.({ authorId, updated: didUpdate, imageUpdated, imageUrl, error: errorMessage });
|
||||
} catch {
|
||||
// callback threw (e.g. client disconnected) — stop the loop
|
||||
callbackInterrupted = true;
|
||||
break;
|
||||
}
|
||||
|
||||
if (index < uniqueAuthorIds.length - 1) {
|
||||
await this.sleep(this.getBulkAudnexusDelayMs());
|
||||
}
|
||||
} catch (error) {
|
||||
failed += 1;
|
||||
errorMessage = error instanceof Error ? error.message : 'Failed to refresh metadata';
|
||||
this.logger.warn(`author.enrichment.bulk authorId=${authorId} error=${JSON.stringify(errorMessage)}`);
|
||||
}
|
||||
|
||||
processed += 1;
|
||||
try {
|
||||
onProgress?.({ authorId, updated: didUpdate, imageUpdated, imageUrl, error: errorMessage });
|
||||
} catch {
|
||||
// callback threw (e.g. client disconnected) — stop the loop
|
||||
break;
|
||||
}
|
||||
|
||||
if (index < uniqueAuthorIds.length - 1) {
|
||||
await this.sleep(this.getBulkAudnexusDelayMs());
|
||||
}
|
||||
this.logger.log(
|
||||
`[${event}] [end] userId=${user.id} count=${uniqueAuthorIds.length} durationMs=${Date.now() - startedAt} processed=${processed} updated=${updated} failed=${failed} callbackInterrupted=${callbackInterrupted} - bulk author metadata refresh completed`,
|
||||
);
|
||||
return { processed, failed, updated };
|
||||
} catch (err) {
|
||||
const errorClass = err instanceof Error ? err.name : 'Error';
|
||||
const errorMessage = (err instanceof Error ? err.message : String(err)).replace(/"/g, '\\"');
|
||||
this.logger.warn(
|
||||
`[${event}] [fail] userId=${user.id} count=${authorIds.length} durationMs=${Date.now() - startedAt} errorClass=${errorClass} error="${errorMessage}" - bulk author metadata refresh failed`,
|
||||
);
|
||||
throw err;
|
||||
}
|
||||
|
||||
this.logger.log(`author.enrichment.bulk userId=${user.id} processed=${processed} updated=${updated} failed=${failed}`);
|
||||
return { processed, failed, updated };
|
||||
}
|
||||
|
||||
private async resolveLibraryIds(user: RequestUser, scopedLibraryId?: number): Promise<number[]> {
|
||||
|
||||
@@ -66,12 +66,12 @@ export class AudnexusAuthorMetadataProvider implements IdentifiableAuthorMetadat
|
||||
|
||||
private async fetchJson<T>(url: string): Promise<T | null> {
|
||||
const startedAt = Date.now();
|
||||
this.logger.log(`[audnexus] fetch.start method=GET`);
|
||||
this.logger.log(`[audnexus] [start] method=GET`);
|
||||
try {
|
||||
const res = await fetch(url, { signal: AbortSignal.timeout(REQUEST_TIMEOUT_MS) });
|
||||
if (!res.ok) {
|
||||
const retryAfterMs = parseRetryAfterMs(res.headers.get('retry-after'));
|
||||
const message = `[audnexus] fetch.fail method=GET status=${res.status} durationMs=${Date.now() - startedAt} message="non-ok response"`;
|
||||
const message = `[audnexus] [fail] method=GET status=${res.status} durationMs=${Date.now() - startedAt} message="non-ok response"`;
|
||||
this.logger.warn(message);
|
||||
throw new AuthorMetadataProviderError(message, {
|
||||
httpStatus: res.status,
|
||||
@@ -80,15 +80,15 @@ export class AudnexusAuthorMetadataProvider implements IdentifiableAuthorMetadat
|
||||
});
|
||||
}
|
||||
const body = (await res.json()) as T;
|
||||
this.logger.log(`[audnexus] fetch.end method=GET status=${res.status} durationMs=${Date.now() - startedAt}`);
|
||||
this.logger.log(`[audnexus] [end] method=GET status=${res.status} durationMs=${Date.now() - startedAt}`);
|
||||
return body;
|
||||
} catch (error) {
|
||||
if (error instanceof AuthorMetadataProviderError) {
|
||||
throw error;
|
||||
}
|
||||
const message = error instanceof Error ? error.message : 'unknown error';
|
||||
this.logger.warn(`[audnexus] fetch.fail method=GET durationMs=${Date.now() - startedAt} message="${message}"`);
|
||||
throw new AuthorMetadataProviderError(`[audnexus] fetch.fail method=GET durationMs=${Date.now() - startedAt} message="${message}"`, {
|
||||
this.logger.warn(`[audnexus] [fail] method=GET durationMs=${Date.now() - startedAt} message="${message}"`);
|
||||
throw new AuthorMetadataProviderError(`[audnexus] [fail] method=GET durationMs=${Date.now() - startedAt} message="${message}"`, {
|
||||
transient: true,
|
||||
});
|
||||
}
|
||||
|
||||
@@ -207,7 +207,7 @@ export class BookMetadataFetchOrchestratorService implements OnApplicationBootst
|
||||
.calculateAndSave(bookId)
|
||||
.catch((err: Error) => this.logger.warn(`book-metadata-fetch score recalc failed for book ${bookId}: ${err.message}`));
|
||||
|
||||
this.logger.debug(`book-metadata-fetch.done bookId=${bookId}`);
|
||||
this.logger.debug(`[book.metadata_fetch] [end] bookId=${bookId} - metadata fetch completed`);
|
||||
await this.queueRepo.markDone(bookId);
|
||||
this.session.sessionDone++;
|
||||
this.session.currentItemName = null;
|
||||
@@ -215,7 +215,9 @@ export class BookMetadataFetchOrchestratorService implements OnApplicationBootst
|
||||
} catch (error) {
|
||||
const message = error instanceof Error ? error.message : String(error);
|
||||
const httpStatus = extractHttpStatus(error);
|
||||
this.logger.warn(`book-metadata-fetch.failed bookId=${bookId} status=${httpStatus ?? 'none'} message=${message.slice(0, 200)}`);
|
||||
this.logger.warn(
|
||||
`[book.metadata_fetch] [fail] bookId=${bookId} status=${httpStatus ?? 'none'} error="${message.slice(0, 200)}" - metadata fetch failed`,
|
||||
);
|
||||
await this.queueRepo.markFailed(bookId, message, httpStatus);
|
||||
this.session.currentItemName = null;
|
||||
await this.emitStatus();
|
||||
|
||||
@@ -287,98 +287,157 @@ export class BookService {
|
||||
}
|
||||
|
||||
async deleteBooks(bookIds: number[], user: RequestUser): Promise<void> {
|
||||
if (bookIds.length === 0) return;
|
||||
const rows = await this.bookRepo.findLibraryIdsByBookIds(bookIds);
|
||||
const uniqueLibraryIds = [...new Set(rows.map((r) => r.libraryId))];
|
||||
const isSuperuser = this.isSuperuser(user);
|
||||
await Promise.all(uniqueLibraryIds.map((libId) => this.libraryService.verifyUserAccess(user.id, libId, isSuperuser)));
|
||||
const files = await this.bookRepo.findAllFilesByBookIds(bookIds);
|
||||
await this.bookRepo.deleteByIds(bookIds);
|
||||
for (const { id: bookId } of rows) {
|
||||
const coverDir = join(this.booksPath, 'covers', String(bookId));
|
||||
rm(coverDir, { recursive: true, force: true }).catch((err: Error) =>
|
||||
this.logger.warn(`Failed to delete cover dir ${coverDir}: ${err.message}`),
|
||||
const event = 'book.delete_books';
|
||||
const startedAt = Date.now();
|
||||
this.logger.log(`[${event}] [start] count=${bookIds.length} userId=${user.id} - delete books started`);
|
||||
try {
|
||||
if (bookIds.length === 0) {
|
||||
this.logger.log(`[${event}] [end] count=0 durationMs=${Date.now() - startedAt} deletedBooks=0 deletedFiles=0 - delete books completed`);
|
||||
return;
|
||||
}
|
||||
const rows = await this.bookRepo.findLibraryIdsByBookIds(bookIds);
|
||||
const uniqueLibraryIds = [...new Set(rows.map((r) => r.libraryId))];
|
||||
const isSuperuser = this.isSuperuser(user);
|
||||
await Promise.all(uniqueLibraryIds.map((libId) => this.libraryService.verifyUserAccess(user.id, libId, isSuperuser)));
|
||||
const files = await this.bookRepo.findAllFilesByBookIds(bookIds);
|
||||
await this.bookRepo.deleteByIds(bookIds);
|
||||
for (const { id: bookId } of rows) {
|
||||
const coverDir = join(this.booksPath, 'covers', String(bookId));
|
||||
rm(coverDir, { recursive: true, force: true }).catch((err: Error) =>
|
||||
this.logger.warn(`Failed to delete cover dir ${coverDir}: ${err.message}`),
|
||||
);
|
||||
}
|
||||
for (const { absolutePath } of files) {
|
||||
rm(absolutePath, { force: true }).catch((err: Error) => this.logger.warn(`Failed to delete book file ${absolutePath}: ${err.message}`));
|
||||
}
|
||||
this.logger.log(
|
||||
`[${event}] [end] count=${bookIds.length} durationMs=${Date.now() - startedAt} deletedBooks=${rows.length} deletedFiles=${files.length} - delete books completed`,
|
||||
);
|
||||
}
|
||||
for (const { absolutePath } of files) {
|
||||
rm(absolutePath, { force: true }).catch((err: Error) => this.logger.warn(`Failed to delete book file ${absolutePath}: ${err.message}`));
|
||||
} catch (err) {
|
||||
const errorClass = err instanceof Error ? err.name : 'Error';
|
||||
const errorMessage = (err instanceof Error ? err.message : String(err)).replace(/"/g, '\\"');
|
||||
this.logger.warn(
|
||||
`[${event}] [fail] count=${bookIds.length} userId=${user.id} durationMs=${Date.now() - startedAt} errorClass=${errorClass} error="${errorMessage}" - delete books failed`,
|
||||
);
|
||||
throw err;
|
||||
}
|
||||
}
|
||||
|
||||
async updateMetadata(id: number, dto: UpdateBookMetadataDto, user: RequestUser): Promise<BookDetailDto> {
|
||||
await this.verifyBookAccess(id, user);
|
||||
const event = 'book.update_metadata';
|
||||
const startedAt = Date.now();
|
||||
this.logger.log(`[${event}] [start] bookId=${id} userId=${user.id} - metadata update started`);
|
||||
try {
|
||||
await this.verifyBookAccess(id, user);
|
||||
|
||||
const scalarFields: Parameters<BookRepository['updateMetadataFields']>[1] = {};
|
||||
if ('title' in dto) scalarFields.title = dto.title ?? null;
|
||||
if ('subtitle' in dto) scalarFields.subtitle = dto.subtitle ?? null;
|
||||
if ('description' in dto) scalarFields.description = dto.description ?? null;
|
||||
if ('publisher' in dto) scalarFields.publisher = dto.publisher ?? null;
|
||||
if ('publishedYear' in dto) scalarFields.publishedYear = dto.publishedYear ?? null;
|
||||
if ('language' in dto) scalarFields.language = dto.language ?? null;
|
||||
if ('pageCount' in dto) scalarFields.pageCount = dto.pageCount ?? null;
|
||||
if ('seriesName' in dto) scalarFields.seriesName = dto.seriesName ?? null;
|
||||
if ('seriesIndex' in dto) scalarFields.seriesIndex = dto.seriesIndex ?? null;
|
||||
if ('isbn10' in dto) scalarFields.isbn10 = dto.isbn10 ?? null;
|
||||
if ('isbn13' in dto) scalarFields.isbn13 = dto.isbn13 ?? null;
|
||||
if ('rating' in dto) scalarFields.rating = dto.rating ?? null;
|
||||
if ('googleBooksId' in dto) scalarFields.googleBooksId = dto.googleBooksId ?? null;
|
||||
if ('goodreadsId' in dto) scalarFields.goodreadsId = dto.goodreadsId ?? null;
|
||||
if ('amazonId' in dto) scalarFields.amazonId = dto.amazonId ?? null;
|
||||
if ('hardcoverId' in dto) scalarFields.hardcoverId = dto.hardcoverId ?? null;
|
||||
if ('openLibraryId' in dto) scalarFields.openLibraryId = dto.openLibraryId ?? null;
|
||||
if ('itunesId' in dto) scalarFields.itunesId = dto.itunesId ?? null;
|
||||
if ('audibleId' in dto) scalarFields.audibleId = dto.audibleId ?? null;
|
||||
if ('durationSeconds' in dto) scalarFields.durationSeconds = dto.durationSeconds ?? null;
|
||||
if ('abridged' in dto) scalarFields.abridged = dto.abridged ?? false;
|
||||
if ('comicvineId' in dto) scalarFields.comicvineId = dto.comicvineId ?? null;
|
||||
const scalarFields: Parameters<BookRepository['updateMetadataFields']>[1] = {};
|
||||
if ('title' in dto) scalarFields.title = dto.title ?? null;
|
||||
if ('subtitle' in dto) scalarFields.subtitle = dto.subtitle ?? null;
|
||||
if ('description' in dto) scalarFields.description = dto.description ?? null;
|
||||
if ('publisher' in dto) scalarFields.publisher = dto.publisher ?? null;
|
||||
if ('publishedYear' in dto) scalarFields.publishedYear = dto.publishedYear ?? null;
|
||||
if ('language' in dto) scalarFields.language = dto.language ?? null;
|
||||
if ('pageCount' in dto) scalarFields.pageCount = dto.pageCount ?? null;
|
||||
if ('seriesName' in dto) scalarFields.seriesName = dto.seriesName ?? null;
|
||||
if ('seriesIndex' in dto) scalarFields.seriesIndex = dto.seriesIndex ?? null;
|
||||
if ('isbn10' in dto) scalarFields.isbn10 = dto.isbn10 ?? null;
|
||||
if ('isbn13' in dto) scalarFields.isbn13 = dto.isbn13 ?? null;
|
||||
if ('rating' in dto) scalarFields.rating = dto.rating ?? null;
|
||||
if ('googleBooksId' in dto) scalarFields.googleBooksId = dto.googleBooksId ?? null;
|
||||
if ('goodreadsId' in dto) scalarFields.goodreadsId = dto.goodreadsId ?? null;
|
||||
if ('amazonId' in dto) scalarFields.amazonId = dto.amazonId ?? null;
|
||||
if ('hardcoverId' in dto) scalarFields.hardcoverId = dto.hardcoverId ?? null;
|
||||
if ('openLibraryId' in dto) scalarFields.openLibraryId = dto.openLibraryId ?? null;
|
||||
if ('itunesId' in dto) scalarFields.itunesId = dto.itunesId ?? null;
|
||||
if ('audibleId' in dto) scalarFields.audibleId = dto.audibleId ?? null;
|
||||
if ('durationSeconds' in dto) scalarFields.durationSeconds = dto.durationSeconds ?? null;
|
||||
if ('abridged' in dto) scalarFields.abridged = dto.abridged ?? false;
|
||||
if ('comicvineId' in dto) scalarFields.comicvineId = dto.comicvineId ?? null;
|
||||
|
||||
if (Object.keys(scalarFields).length > 0) {
|
||||
scalarFields.updatedAt = new Date();
|
||||
await this.bookRepo.updateMetadataFields(id, scalarFields);
|
||||
}
|
||||
const scalarFieldCount = Object.keys(scalarFields).length;
|
||||
if (scalarFieldCount > 0) {
|
||||
scalarFields.updatedAt = new Date();
|
||||
await this.bookRepo.updateMetadataFields(id, scalarFields);
|
||||
}
|
||||
|
||||
if (dto.comicMetadata) {
|
||||
await this.comicMetadataService.upsert(id, dto.comicMetadata);
|
||||
}
|
||||
if (dto.comicMetadata) {
|
||||
await this.comicMetadataService.upsert(id, dto.comicMetadata);
|
||||
}
|
||||
|
||||
if (dto.authors !== undefined) {
|
||||
await this.metadataService.replaceAuthors(
|
||||
id,
|
||||
dto.authors.map((name) => ({ name, sortName: null })),
|
||||
if (dto.authors !== undefined) {
|
||||
await this.metadataService.replaceAuthors(
|
||||
id,
|
||||
dto.authors.map((name) => ({ name, sortName: null })),
|
||||
);
|
||||
}
|
||||
if (dto.narrators !== undefined) {
|
||||
await this.narratorService.replaceForBook(id, dto.narrators);
|
||||
}
|
||||
if (dto.genres !== undefined) {
|
||||
await this.metadataService.replaceGenres(id, dto.genres);
|
||||
}
|
||||
if (dto.tags !== undefined) {
|
||||
await this.metadataService.replaceTags(id, dto.tags);
|
||||
}
|
||||
|
||||
this.embedder?.embedBook(id).catch((err: Error) => this.logger.warn(`Embedding failed for book ${id}: ${err.message}`));
|
||||
this.fileWriteService?.scheduleWrite(id, 'auto', user.id);
|
||||
this.scoreService.calculateAndSave(id).catch((err: Error) => this.logger.warn(`Score calculation failed for book ${id}: ${err.message}`));
|
||||
const detail = await this.getDetail(id, user);
|
||||
this.logger.log(
|
||||
`[${event}] [end] bookId=${id} durationMs=${Date.now() - startedAt} scalarFields=${scalarFieldCount} authorsUpdated=${dto.authors !== undefined} narratorsUpdated=${dto.narrators !== undefined} genresUpdated=${dto.genres !== undefined} tagsUpdated=${dto.tags !== undefined} comicMetadataUpdated=${dto.comicMetadata !== undefined} - metadata update completed`,
|
||||
);
|
||||
return detail;
|
||||
} catch (err) {
|
||||
const errorClass = err instanceof Error ? err.name : 'Error';
|
||||
const errorMessage = (err instanceof Error ? err.message : String(err)).replace(/"/g, '\\"');
|
||||
this.logger.warn(
|
||||
`[${event}] [fail] bookId=${id} userId=${user.id} durationMs=${Date.now() - startedAt} errorClass=${errorClass} error="${errorMessage}" - metadata update failed`,
|
||||
);
|
||||
throw err;
|
||||
}
|
||||
if (dto.narrators !== undefined) {
|
||||
await this.narratorService.replaceForBook(id, dto.narrators);
|
||||
}
|
||||
if (dto.genres !== undefined) {
|
||||
await this.metadataService.replaceGenres(id, dto.genres);
|
||||
}
|
||||
if (dto.tags !== undefined) {
|
||||
await this.metadataService.replaceTags(id, dto.tags);
|
||||
}
|
||||
|
||||
this.embedder?.embedBook(id).catch((err: Error) => this.logger.warn(`Embedding failed for book ${id}: ${err.message}`));
|
||||
this.fileWriteService?.scheduleWrite(id, 'auto', user.id);
|
||||
this.scoreService.calculateAndSave(id).catch((err: Error) => this.logger.warn(`Score calculation failed for book ${id}: ${err.message}`));
|
||||
return this.getDetail(id, user);
|
||||
}
|
||||
|
||||
async embedAll(): Promise<{ queued: number }> {
|
||||
const bookIds = await this.bookRepo.findAllIds();
|
||||
this.runEmbeddings(bookIds).catch((err: Error) => this.logger.error(`Embed-all failed: ${err.message}`));
|
||||
return { queued: bookIds.length };
|
||||
const event = 'book.embed_all';
|
||||
const startedAt = Date.now();
|
||||
this.logger.log(`[${event}] [start] - embed all started`);
|
||||
try {
|
||||
const bookIds = await this.bookRepo.findAllIds();
|
||||
void this.runEmbeddings(bookIds);
|
||||
this.logger.log(`[${event}] [end] durationMs=${Date.now() - startedAt} queued=${bookIds.length} - embed all completed`);
|
||||
return { queued: bookIds.length };
|
||||
} catch (err) {
|
||||
const errorClass = err instanceof Error ? err.name : 'Error';
|
||||
const errorMessage = (err instanceof Error ? err.message : String(err)).replace(/"/g, '\\"');
|
||||
this.logger.warn(`[${event}] [fail] durationMs=${Date.now() - startedAt} errorClass=${errorClass} error="${errorMessage}" - embed all failed`);
|
||||
throw err;
|
||||
}
|
||||
}
|
||||
|
||||
private async runEmbeddings(bookIds: number[]): Promise<void> {
|
||||
const BATCH = 10;
|
||||
for (let i = 0; i < bookIds.length; i += BATCH) {
|
||||
await Promise.all(
|
||||
bookIds
|
||||
.slice(i, i + BATCH)
|
||||
.map((id) => this.embedder?.embedBook(id).catch((err: Error) => this.logger.warn(`Failed to embed book ${id}: ${err.message}`))),
|
||||
const event = 'book.run_embeddings';
|
||||
const startedAt = Date.now();
|
||||
const batch = 10;
|
||||
this.logger.log(`[${event}] [start] totalBooks=${bookIds.length} batchSize=${batch} - embeddings run started`);
|
||||
try {
|
||||
for (let i = 0; i < bookIds.length; i += batch) {
|
||||
await Promise.all(
|
||||
bookIds
|
||||
.slice(i, i + batch)
|
||||
.map((id) => this.embedder?.embedBook(id).catch((err: Error) => this.logger.warn(`Failed to embed book ${id}: ${err.message}`))),
|
||||
);
|
||||
}
|
||||
this.logger.log(
|
||||
`[${event}] [end] totalBooks=${bookIds.length} durationMs=${Date.now() - startedAt} processed=${bookIds.length} - embeddings run completed`,
|
||||
);
|
||||
} catch (err) {
|
||||
const errorClass = err instanceof Error ? err.name : 'Error';
|
||||
const errorMessage = (err instanceof Error ? err.message : String(err)).replace(/"/g, '\\"');
|
||||
this.logger.warn(
|
||||
`[${event}] [fail] totalBooks=${bookIds.length} durationMs=${Date.now() - startedAt} errorClass=${errorClass} error="${errorMessage}" - embeddings run failed`,
|
||||
);
|
||||
}
|
||||
this.logger.log(`Embeddings complete: ${bookIds.length} books processed`);
|
||||
}
|
||||
|
||||
async getProgress(userId: number, fileId: number, user: RequestUser) {
|
||||
@@ -473,87 +532,109 @@ export class BookService {
|
||||
}
|
||||
|
||||
async refreshMetadata(id: number, preview: boolean, user: RequestUser): Promise<BookDetailDto | ResolvedMetadataFields> {
|
||||
const found = await this.bookRepo.findById(id);
|
||||
if (!found) throw new NotFoundException(`Book ${id} not found`);
|
||||
const event = 'book.refresh_metadata';
|
||||
const startedAt = Date.now();
|
||||
this.logger.log(`[${event}] [start] bookId=${id} userId=${user.id} preview=${preview} - refresh metadata started`);
|
||||
try {
|
||||
const found = await this.bookRepo.findById(id);
|
||||
if (!found) throw new NotFoundException(`Book ${id} not found`);
|
||||
|
||||
const { book, authorRows, genreRows } = found;
|
||||
await this.libraryService.verifyUserAccess(user.id, book.books.libraryId, this.isSuperuser(user));
|
||||
const meta = book.book_metadata;
|
||||
const { book, authorRows, genreRows } = found;
|
||||
await this.libraryService.verifyUserAccess(user.id, book.books.libraryId, this.isSuperuser(user));
|
||||
const meta = book.book_metadata;
|
||||
|
||||
const providerIds = this.collectExistingProviderIds(meta ?? {});
|
||||
const providerIds = this.collectExistingProviderIds(meta ?? {});
|
||||
|
||||
const searchParams: MetadataSearchParams = {
|
||||
title: meta?.title ?? undefined,
|
||||
author: authorRows[0]?.name ?? undefined,
|
||||
isbn: meta?.isbn13 ?? meta?.isbn10 ?? undefined,
|
||||
existingProviderIds: providerIds,
|
||||
isAudiobook: (meta?.durationSeconds !== null && meta?.durationSeconds !== undefined) || !!meta?.audibleId,
|
||||
maxCandidatesPerProvider: 1,
|
||||
};
|
||||
const searchParams: MetadataSearchParams = {
|
||||
title: meta?.title ?? undefined,
|
||||
author: authorRows[0]?.name ?? undefined,
|
||||
isbn: meta?.isbn13 ?? meta?.isbn10 ?? undefined,
|
||||
existingProviderIds: providerIds,
|
||||
isAudiobook: (meta?.durationSeconds !== null && meta?.durationSeconds !== undefined) || !!meta?.audibleId,
|
||||
maxCandidatesPerProvider: 1,
|
||||
};
|
||||
|
||||
const existingFields: Partial<Record<MetadataField, unknown>> = {
|
||||
title: meta?.title,
|
||||
subtitle: meta?.subtitle,
|
||||
description: meta?.description,
|
||||
authors: authorRows.map((a) => a.name),
|
||||
publisher: meta?.publisher,
|
||||
publishedYear: meta?.publishedYear,
|
||||
language: meta?.language,
|
||||
pageCount: meta?.pageCount,
|
||||
seriesName: meta?.seriesName,
|
||||
seriesIndex: meta?.seriesIndex,
|
||||
genres: genreRows.map((g) => g.name),
|
||||
cover: meta?.coverSource,
|
||||
duration: meta?.durationSeconds ?? undefined,
|
||||
abridged: meta?.abridged ?? undefined,
|
||||
};
|
||||
const existingFields: Partial<Record<MetadataField, unknown>> = {
|
||||
title: meta?.title,
|
||||
subtitle: meta?.subtitle,
|
||||
description: meta?.description,
|
||||
authors: authorRows.map((a) => a.name),
|
||||
publisher: meta?.publisher,
|
||||
publishedYear: meta?.publishedYear,
|
||||
language: meta?.language,
|
||||
pageCount: meta?.pageCount,
|
||||
seriesName: meta?.seriesName,
|
||||
seriesIndex: meta?.seriesIndex,
|
||||
genres: genreRows.map((g) => g.name),
|
||||
cover: meta?.coverSource,
|
||||
duration: meta?.durationSeconds ?? undefined,
|
||||
abridged: meta?.abridged ?? undefined,
|
||||
};
|
||||
|
||||
const { resolved, providerIds: resolvedProviderIds } = await this.pipeline.runWithSources(searchParams, existingFields, book.books.libraryId);
|
||||
const { resolved, providerIds: resolvedProviderIds } = await this.pipeline.runWithSources(searchParams, existingFields, book.books.libraryId);
|
||||
|
||||
if (preview) {
|
||||
const previewResult: ResolvedMetadataFields & {
|
||||
googleBooksId?: string;
|
||||
goodreadsId?: string;
|
||||
amazonId?: string;
|
||||
hardcoverId?: string;
|
||||
openLibraryId?: string;
|
||||
itunesId?: string;
|
||||
audibleId?: string;
|
||||
comicvineId?: string;
|
||||
} = { ...resolved };
|
||||
this.applyResolvedProviderIds(previewResult, resolvedProviderIds);
|
||||
return previewResult;
|
||||
if (preview) {
|
||||
const previewResult: ResolvedMetadataFields & {
|
||||
googleBooksId?: string;
|
||||
goodreadsId?: string;
|
||||
amazonId?: string;
|
||||
hardcoverId?: string;
|
||||
openLibraryId?: string;
|
||||
itunesId?: string;
|
||||
audibleId?: string;
|
||||
comicvineId?: string;
|
||||
} = { ...resolved };
|
||||
this.applyResolvedProviderIds(previewResult, resolvedProviderIds);
|
||||
this.logger.log(
|
||||
`[${event}] [end] bookId=${id} preview=true durationMs=${Date.now() - startedAt} resolvedFields=${Object.keys(previewResult).length} - refresh metadata completed`,
|
||||
);
|
||||
return previewResult;
|
||||
}
|
||||
|
||||
const r = resolved as Record<string, unknown>;
|
||||
const dto: UpdateBookMetadataDto = {};
|
||||
if (r.title !== undefined) dto.title = r.title as string | null;
|
||||
if (r.subtitle !== undefined) dto.subtitle = r.subtitle as string | null;
|
||||
if (r.description !== undefined) dto.description = r.description as string | null;
|
||||
if (r.authors !== undefined) dto.authors = r.authors as string[];
|
||||
if (r.genres !== undefined) dto.genres = r.genres as string[];
|
||||
if (r.publisher !== undefined) dto.publisher = r.publisher as string | null;
|
||||
if (r.publishedYear !== undefined) dto.publishedYear = r.publishedYear as number | null;
|
||||
if (r.language !== undefined) dto.language = r.language as string | null;
|
||||
if (r.pageCount !== undefined) dto.pageCount = r.pageCount as number | null;
|
||||
if (r.seriesName !== undefined) dto.seriesName = r.seriesName as string | null;
|
||||
if (r.seriesIndex !== undefined) dto.seriesIndex = r.seriesIndex as number | null;
|
||||
if (r.duration !== undefined) dto.durationSeconds = r.duration as number | null;
|
||||
if (r.abridged !== undefined) dto.abridged = r.abridged as boolean | null;
|
||||
if (r.comicMetadata !== undefined) dto.comicMetadata = r.comicMetadata as UpdateBookMetadataDto['comicMetadata'];
|
||||
this.applyResolvedProviderIds(dto, resolvedProviderIds);
|
||||
|
||||
const updatedFields = Object.keys(dto).length;
|
||||
let detail: BookDetailDto | undefined;
|
||||
if (updatedFields > 0) {
|
||||
detail = await this.updateMetadata(id, dto, user);
|
||||
}
|
||||
|
||||
let coverDownloaded = false;
|
||||
if (resolved.coverUrl) {
|
||||
await this.metadataService.downloadAndSaveCover(resolved.coverUrl, id);
|
||||
detail = await this.getDetail(id, user);
|
||||
coverDownloaded = true;
|
||||
}
|
||||
|
||||
const result = detail ?? (await this.getDetail(id, user));
|
||||
this.logger.log(
|
||||
`[${event}] [end] bookId=${id} preview=false durationMs=${Date.now() - startedAt} updatedFields=${updatedFields} coverDownloaded=${coverDownloaded} - refresh metadata completed`,
|
||||
);
|
||||
return result;
|
||||
} catch (err) {
|
||||
const errorClass = err instanceof Error ? err.name : 'Error';
|
||||
const errorMessage = (err instanceof Error ? err.message : String(err)).replace(/"/g, '\\"');
|
||||
this.logger.warn(
|
||||
`[${event}] [fail] bookId=${id} userId=${user.id} preview=${preview} durationMs=${Date.now() - startedAt} errorClass=${errorClass} error="${errorMessage}" - refresh metadata failed`,
|
||||
);
|
||||
throw err;
|
||||
}
|
||||
|
||||
const r = resolved as Record<string, unknown>;
|
||||
const dto: UpdateBookMetadataDto = {};
|
||||
if (r.title !== undefined) dto.title = r.title as string | null;
|
||||
if (r.subtitle !== undefined) dto.subtitle = r.subtitle as string | null;
|
||||
if (r.description !== undefined) dto.description = r.description as string | null;
|
||||
if (r.authors !== undefined) dto.authors = r.authors as string[];
|
||||
if (r.genres !== undefined) dto.genres = r.genres as string[];
|
||||
if (r.publisher !== undefined) dto.publisher = r.publisher as string | null;
|
||||
if (r.publishedYear !== undefined) dto.publishedYear = r.publishedYear as number | null;
|
||||
if (r.language !== undefined) dto.language = r.language as string | null;
|
||||
if (r.pageCount !== undefined) dto.pageCount = r.pageCount as number | null;
|
||||
if (r.seriesName !== undefined) dto.seriesName = r.seriesName as string | null;
|
||||
if (r.seriesIndex !== undefined) dto.seriesIndex = r.seriesIndex as number | null;
|
||||
if (r.duration !== undefined) dto.durationSeconds = r.duration as number | null;
|
||||
if (r.abridged !== undefined) dto.abridged = r.abridged as boolean | null;
|
||||
if (r.comicMetadata !== undefined) dto.comicMetadata = r.comicMetadata as UpdateBookMetadataDto['comicMetadata'];
|
||||
this.applyResolvedProviderIds(dto, resolvedProviderIds);
|
||||
|
||||
let detail: BookDetailDto | undefined;
|
||||
if (Object.keys(dto).length > 0) {
|
||||
detail = await this.updateMetadata(id, dto, user);
|
||||
}
|
||||
|
||||
if (resolved.coverUrl) {
|
||||
await this.metadataService.downloadAndSaveCover(resolved.coverUrl, id);
|
||||
detail = await this.getDetail(id, user);
|
||||
}
|
||||
|
||||
return detail ?? this.getDetail(id, user);
|
||||
}
|
||||
|
||||
async bulkRefreshMetadata(
|
||||
@@ -561,26 +642,44 @@ export class BookService {
|
||||
user: RequestUser,
|
||||
onProgress?: (bookId: number) => void,
|
||||
): Promise<{ processed: number; failed: number }> {
|
||||
if (bookIds.length === 0) return { processed: 0, failed: 0 };
|
||||
const rows = await this.bookRepo.findLibraryIdsByBookIds(bookIds);
|
||||
const uniqueLibraryIds = [...new Set(rows.map((r) => r.libraryId))];
|
||||
const isSuperuser = this.isSuperuser(user);
|
||||
await Promise.all(uniqueLibraryIds.map((libId) => this.libraryService.verifyUserAccess(user.id, libId, isSuperuser)));
|
||||
|
||||
let processed = 0;
|
||||
let failed = 0;
|
||||
for (const id of bookIds) {
|
||||
try {
|
||||
await this.refreshMetadata(id, false, user);
|
||||
processed++;
|
||||
onProgress?.(id);
|
||||
} catch (err) {
|
||||
this.logger.warn(`Bulk metadata refresh failed for book ${id}: ${err instanceof Error ? err.message : String(err)}`);
|
||||
failed++;
|
||||
onProgress?.(id);
|
||||
const event = 'book.bulk_refresh_metadata';
|
||||
const startedAt = Date.now();
|
||||
this.logger.log(`[${event}] [start] count=${bookIds.length} userId=${user.id} - bulk refresh metadata started`);
|
||||
try {
|
||||
if (bookIds.length === 0) {
|
||||
this.logger.log(`[${event}] [end] count=0 durationMs=${Date.now() - startedAt} processed=0 failed=0 - bulk refresh metadata completed`);
|
||||
return { processed: 0, failed: 0 };
|
||||
}
|
||||
const rows = await this.bookRepo.findLibraryIdsByBookIds(bookIds);
|
||||
const uniqueLibraryIds = [...new Set(rows.map((r) => r.libraryId))];
|
||||
const isSuperuser = this.isSuperuser(user);
|
||||
await Promise.all(uniqueLibraryIds.map((libId) => this.libraryService.verifyUserAccess(user.id, libId, isSuperuser)));
|
||||
|
||||
let processed = 0;
|
||||
let failed = 0;
|
||||
for (const id of bookIds) {
|
||||
try {
|
||||
await this.refreshMetadata(id, false, user);
|
||||
processed++;
|
||||
onProgress?.(id);
|
||||
} catch (err) {
|
||||
this.logger.warn(`Bulk metadata refresh failed for book ${id}: ${err instanceof Error ? err.message : String(err)}`);
|
||||
failed++;
|
||||
onProgress?.(id);
|
||||
}
|
||||
}
|
||||
this.logger.log(
|
||||
`[${event}] [end] count=${bookIds.length} durationMs=${Date.now() - startedAt} processed=${processed} failed=${failed} - bulk refresh metadata completed`,
|
||||
);
|
||||
return { processed, failed };
|
||||
} catch (err) {
|
||||
const errorClass = err instanceof Error ? err.name : 'Error';
|
||||
const errorMessage = (err instanceof Error ? err.message : String(err)).replace(/"/g, '\\"');
|
||||
this.logger.warn(
|
||||
`[${event}] [fail] count=${bookIds.length} userId=${user.id} durationMs=${Date.now() - startedAt} errorClass=${errorClass} error="${errorMessage}" - bulk refresh metadata failed`,
|
||||
);
|
||||
throw err;
|
||||
}
|
||||
return { processed, failed };
|
||||
}
|
||||
|
||||
async bulkReExtractCover(
|
||||
@@ -588,54 +687,88 @@ export class BookService {
|
||||
user: RequestUser,
|
||||
onProgress?: (bookId: number) => void,
|
||||
): Promise<{ processed: number; updated: number }> {
|
||||
if (bookIds.length === 0) return { processed: 0, updated: 0 };
|
||||
const rows = await this.bookRepo.findLibraryIdsByBookIds(bookIds);
|
||||
const uniqueLibraryIds = [...new Set(rows.map((r) => r.libraryId))];
|
||||
const isSuperuser = this.isSuperuser(user);
|
||||
await Promise.all(uniqueLibraryIds.map((libId) => this.libraryService.verifyUserAccess(user.id, libId, isSuperuser)));
|
||||
|
||||
const files = await this.bookRepo.findPrimaryFilesByBookIds(bookIds);
|
||||
const filesByBookId = new Map(files.map((f) => [f.bookId, f]));
|
||||
|
||||
let processed = 0;
|
||||
let updated = 0;
|
||||
for (const id of bookIds) {
|
||||
const file = filesByBookId.get(id);
|
||||
if (!file) continue;
|
||||
processed++;
|
||||
const saved = await this.metadataService.refreshCoverForBook(id, file.absolutePath, file.format ?? '');
|
||||
if (saved) {
|
||||
updated++;
|
||||
const event = 'book.bulk_reextract_cover';
|
||||
const startedAt = Date.now();
|
||||
this.logger.log(`[${event}] [start] count=${bookIds.length} userId=${user.id} - bulk re-extract cover started`);
|
||||
try {
|
||||
if (bookIds.length === 0) {
|
||||
this.logger.log(`[${event}] [end] count=0 durationMs=${Date.now() - startedAt} processed=0 updated=0 - bulk re-extract cover completed`);
|
||||
return { processed: 0, updated: 0 };
|
||||
}
|
||||
onProgress?.(id);
|
||||
const rows = await this.bookRepo.findLibraryIdsByBookIds(bookIds);
|
||||
const uniqueLibraryIds = [...new Set(rows.map((r) => r.libraryId))];
|
||||
const isSuperuser = this.isSuperuser(user);
|
||||
await Promise.all(uniqueLibraryIds.map((libId) => this.libraryService.verifyUserAccess(user.id, libId, isSuperuser)));
|
||||
|
||||
const files = await this.bookRepo.findPrimaryFilesByBookIds(bookIds);
|
||||
const filesByBookId = new Map(files.map((f) => [f.bookId, f]));
|
||||
|
||||
let processed = 0;
|
||||
let updated = 0;
|
||||
for (const id of bookIds) {
|
||||
const file = filesByBookId.get(id);
|
||||
if (!file) continue;
|
||||
processed++;
|
||||
const saved = await this.metadataService.refreshCoverForBook(id, file.absolutePath, file.format ?? '');
|
||||
if (saved) {
|
||||
updated++;
|
||||
}
|
||||
onProgress?.(id);
|
||||
}
|
||||
this.logger.log(
|
||||
`[${event}] [end] count=${bookIds.length} durationMs=${Date.now() - startedAt} processed=${processed} updated=${updated} - bulk re-extract cover completed`,
|
||||
);
|
||||
return { processed, updated };
|
||||
} catch (err) {
|
||||
const errorClass = err instanceof Error ? err.name : 'Error';
|
||||
const errorMessage = (err instanceof Error ? err.message : String(err)).replace(/"/g, '\\"');
|
||||
this.logger.warn(
|
||||
`[${event}] [fail] count=${bookIds.length} userId=${user.id} durationMs=${Date.now() - startedAt} errorClass=${errorClass} error="${errorMessage}" - bulk re-extract cover failed`,
|
||||
);
|
||||
throw err;
|
||||
}
|
||||
return { processed, updated };
|
||||
}
|
||||
|
||||
async getExportFiles(bookIds: number[], user: RequestUser, allFormats: boolean): Promise<{ absolutePath: string; zipPath: string }[]> {
|
||||
if (bookIds.length === 0) throw new BadRequestException('No books selected');
|
||||
const rows = await this.bookRepo.findLibraryIdsByBookIds(bookIds);
|
||||
const uniqueLibraryIds = [...new Set(rows.map((r) => r.libraryId))];
|
||||
const isSuperuser = this.isSuperuser(user);
|
||||
await Promise.all(uniqueLibraryIds.map((libId) => this.libraryService.verifyUserAccess(user.id, libId, isSuperuser)));
|
||||
const event = 'book.get_export_files';
|
||||
const startedAt = Date.now();
|
||||
this.logger.log(`[${event}] [start] count=${bookIds.length} userId=${user.id} allFormats=${allFormats} - get export files started`);
|
||||
try {
|
||||
if (bookIds.length === 0) throw new BadRequestException('No books selected');
|
||||
const rows = await this.bookRepo.findLibraryIdsByBookIds(bookIds);
|
||||
const uniqueLibraryIds = [...new Set(rows.map((r) => r.libraryId))];
|
||||
const isSuperuser = this.isSuperuser(user);
|
||||
await Promise.all(uniqueLibraryIds.map((libId) => this.libraryService.verifyUserAccess(user.id, libId, isSuperuser)));
|
||||
|
||||
const files = allFormats ? await this.bookRepo.findAllFilesByBookIds(bookIds) : await this.bookRepo.findPrimaryFilesByBookIds(bookIds);
|
||||
const [pattern, metadataRows] = await Promise.all([
|
||||
this.appSettings.getDownloadPattern(),
|
||||
this.bookRepo.findPatternMetadataByBookIds([...new Set(files.map((f) => f.bookId))]),
|
||||
]);
|
||||
const metadataByBookId = new Map(metadataRows.map((row) => [row.bookId, row]));
|
||||
const usedPaths = new Set<string>();
|
||||
const files = allFormats ? await this.bookRepo.findAllFilesByBookIds(bookIds) : await this.bookRepo.findPrimaryFilesByBookIds(bookIds);
|
||||
const [pattern, metadataRows] = await Promise.all([
|
||||
this.appSettings.getDownloadPattern(),
|
||||
this.bookRepo.findPatternMetadataByBookIds([...new Set(files.map((f) => f.bookId))]),
|
||||
]);
|
||||
const metadataByBookId = new Map(metadataRows.map((row) => [row.bookId, row]));
|
||||
const usedPaths = new Set<string>();
|
||||
|
||||
return files.map((file) => {
|
||||
const tokens = this.buildDownloadPatternTokens(file.absolutePath, file.format, metadataByBookId.get(file.bookId));
|
||||
const resolvedPath = resolveUploadPath(pattern || BookService.DEFAULT_DOWNLOAD_PATTERN, tokens, tokens.extension);
|
||||
const fallbackFilename = basename(file.absolutePath);
|
||||
const rawZipPath = resolvedPath ?? fallbackFilename;
|
||||
const safeZipPath = this.sanitizeZipPath(rawZipPath, fallbackFilename);
|
||||
const zipPath = this.makeUniqueZipPath(safeZipPath, usedPaths);
|
||||
return { absolutePath: file.absolutePath, zipPath };
|
||||
});
|
||||
const result = files.map((file) => {
|
||||
const tokens = this.buildDownloadPatternTokens(file.absolutePath, file.format, metadataByBookId.get(file.bookId));
|
||||
const resolvedPath = resolveUploadPath(pattern || BookService.DEFAULT_DOWNLOAD_PATTERN, tokens, tokens.extension);
|
||||
const fallbackFilename = basename(file.absolutePath);
|
||||
const rawZipPath = resolvedPath ?? fallbackFilename;
|
||||
const safeZipPath = this.sanitizeZipPath(rawZipPath, fallbackFilename);
|
||||
const zipPath = this.makeUniqueZipPath(safeZipPath, usedPaths);
|
||||
return { absolutePath: file.absolutePath, zipPath };
|
||||
});
|
||||
this.logger.log(
|
||||
`[${event}] [end] count=${bookIds.length} durationMs=${Date.now() - startedAt} files=${result.length} allFormats=${allFormats} - get export files completed`,
|
||||
);
|
||||
return result;
|
||||
} catch (err) {
|
||||
const errorClass = err instanceof Error ? err.name : 'Error';
|
||||
const errorMessage = (err instanceof Error ? err.message : String(err)).replace(/"/g, '\\"');
|
||||
this.logger.warn(
|
||||
`[${event}] [fail] count=${bookIds.length} userId=${user.id} allFormats=${allFormats} durationMs=${Date.now() - startedAt} errorClass=${errorClass} error="${errorMessage}" - get export files failed`,
|
||||
);
|
||||
throw err;
|
||||
}
|
||||
}
|
||||
|
||||
async getDetail(id: number, user: RequestUser): Promise<BookDetailDto> {
|
||||
|
||||
@@ -1,4 +1,4 @@
|
||||
import { BadRequestException, Injectable } from '@nestjs/common';
|
||||
import { BadRequestException, Injectable, Logger } from '@nestjs/common';
|
||||
|
||||
import type { RequestUser } from '../../common/types/request-user';
|
||||
import type { EmailProvider } from '../../db/schema';
|
||||
@@ -13,6 +13,8 @@ export interface ResolvedSmtp {
|
||||
|
||||
@Injectable()
|
||||
export class EmailProviderResolver {
|
||||
private readonly logger = new Logger(EmailProviderResolver.name);
|
||||
|
||||
constructor(
|
||||
private readonly providerService: EmailProviderService,
|
||||
private readonly preferencesService: EmailPreferencesService,
|
||||
@@ -20,12 +22,16 @@ export class EmailProviderResolver {
|
||||
|
||||
async resolve(user: RequestUser, requestedProviderId?: number | null): Promise<ResolvedSmtp> {
|
||||
if (requestedProviderId !== null && requestedProviderId !== undefined) {
|
||||
return this.fromProvider(await this.providerService.getProviderWithDecryptedPassword(requestedProviderId, user));
|
||||
const provider = await this.providerService.getProviderWithDecryptedPassword(requestedProviderId, user);
|
||||
this.logger.debug(`[email.provider] [resolved] id=${provider.id} host=${provider.host} (requested)`);
|
||||
return this.fromProvider(provider);
|
||||
}
|
||||
|
||||
const prefs = await this.preferencesService.getForUser(user.id);
|
||||
if (prefs?.defaultProviderId !== null && prefs?.defaultProviderId !== undefined) {
|
||||
return this.fromProvider(await this.providerService.getProviderWithDecryptedPassword(prefs.defaultProviderId, user));
|
||||
const provider = await this.providerService.getProviderWithDecryptedPassword(prefs.defaultProviderId, user);
|
||||
this.logger.debug(`[email.provider] [resolved] id=${provider.id} host=${provider.host} (default)`);
|
||||
return this.fromProvider(provider);
|
||||
}
|
||||
|
||||
throw new BadRequestException('No email provider configured. Add a provider in email settings.');
|
||||
|
||||
@@ -42,6 +42,9 @@ export class EmailSendOrchestrator {
|
||||
) {}
|
||||
|
||||
async send(dto: SendBookDto, user: RequestUser): Promise<{ queued: number }> {
|
||||
this.logger.log(
|
||||
`[email.send] [start] user=${user.id} books=${dto.bookIds.length} recipients=${(dto.recipientIds?.length ?? 0) + (dto.groupIds?.length ?? 0)}`,
|
||||
);
|
||||
const tasks = await this.buildTasks(dto, user);
|
||||
if (tasks.length === 0) throw new BadRequestException('No recipients specified');
|
||||
|
||||
@@ -55,10 +58,12 @@ export class EmailSendOrchestrator {
|
||||
}
|
||||
}
|
||||
|
||||
this.logger.log(`[email.send] [queued] user=${user.id} total=${queued}`);
|
||||
return { queued };
|
||||
}
|
||||
|
||||
async resend(logEntryId: number, user: RequestUser): Promise<{ queued: number }> {
|
||||
this.logger.log(`[email.resend] [start] user=${user.id} logEntry=${logEntryId}`);
|
||||
const logEntry = await this.sendLogService.getForResend(logEntryId, user);
|
||||
if (!logEntry.bookId || !logEntry.toEmail) {
|
||||
throw new BadRequestException('Cannot resend: original book or recipient is missing');
|
||||
@@ -98,6 +103,7 @@ export class EmailSendOrchestrator {
|
||||
}
|
||||
|
||||
async quickSend(bookId: number, user: RequestUser): Promise<{ queued: number }> {
|
||||
this.logger.log(`[email.quick-send] [start] user=${user.id} book=${bookId}`);
|
||||
const prefs = await this.preferencesService.getForUser(user.id);
|
||||
if (!prefs?.defaultRecipientId) {
|
||||
throw new BadRequestException('No default recipient configured. Set one in email settings.');
|
||||
@@ -204,10 +210,10 @@ export class EmailSendOrchestrator {
|
||||
});
|
||||
|
||||
await this.sendLogService.markSent(logId);
|
||||
this.logger.log(`Email sent: log#${logId} to ${task.recipientEmail}`);
|
||||
this.logger.log(`[email.dispatch] [success] log=${logId} to=${task.recipientEmail}`);
|
||||
} catch (err) {
|
||||
const errorMessage = err instanceof Error ? err.message : String(err);
|
||||
this.logger.warn(`Send failed for log#${logId} (attempt ${attemptCount + 1}): ${errorMessage}`);
|
||||
this.logger.warn(`[email.dispatch] [retry] log=${logId} attempt=${attemptCount + 1} error="${errorMessage}"`);
|
||||
|
||||
const { isFinal } = await this.sendLogService.markFailed(logId, errorMessage, attemptCount);
|
||||
|
||||
@@ -215,7 +221,7 @@ export class EmailSendOrchestrator {
|
||||
const delayMs = SEND_RETRY_DELAYS_MS[attemptCount] ?? 0;
|
||||
setTimeout(() => void this.dispatchSend(logId, smtpConfig, task, file, subject, bodyText, attemptCount + 1), delayMs);
|
||||
} else {
|
||||
this.logger.error(`Send permanently failed for log#${logId} to ${task.recipientEmail}`);
|
||||
this.logger.error(`[email.dispatch] [fail] log=${logId} to=${task.recipientEmail} error="${errorMessage}"`);
|
||||
}
|
||||
}
|
||||
}
|
||||
|
||||
@@ -56,8 +56,10 @@ export class SystemMailService {
|
||||
text: this.buildResetText(name, resetUrl),
|
||||
html: this.buildResetHtml(name, resetUrl),
|
||||
});
|
||||
this.logger.log(`[system-mail.password-reset] [success] to=${to}`);
|
||||
} catch (err) {
|
||||
this.logger.error('Failed to send password reset email', err);
|
||||
const errorMessage = err instanceof Error ? err.message : String(err);
|
||||
this.logger.error(`[system-mail.password-reset] [fail] to=${to} error="${errorMessage}"`);
|
||||
}
|
||||
}
|
||||
|
||||
|
||||
@@ -87,7 +87,7 @@ export class MetadataFetchPipeline {
|
||||
const active: MetadataProviderKey[] = [];
|
||||
for (const key of keys) {
|
||||
if (this.throttleTracker.isThrottled(key)) {
|
||||
this.logger.warn(`[${key}] throttled - skipping metadata fetch for this run`);
|
||||
this.logger.warn(`[${key}] [throttle] - skipping metadata fetch for this run`);
|
||||
} else {
|
||||
active.push(key);
|
||||
}
|
||||
|
||||
@@ -73,7 +73,7 @@ export class MetadataFetchService {
|
||||
} catch (err) {
|
||||
if (err instanceof ProviderThrottleError) {
|
||||
const hint = err.retryAfterSeconds != null ? `${err.retryAfterSeconds}s (Retry-After header)` : 'scheduled backoff';
|
||||
this.logger.warn(`[${p.key}] throttled by provider - ${hint}`);
|
||||
this.logger.warn(`[${p.key}] [throttle] hint="${hint}" - provider throttled`);
|
||||
this.throttleTracker.record(p.key, err.retryAfterSeconds);
|
||||
}
|
||||
return [];
|
||||
|
||||
@@ -25,7 +25,7 @@ export class ProviderThrottleTracker {
|
||||
const until = Date.now() + seconds * 1000;
|
||||
this.throttledUntil.set(key, until);
|
||||
this.backoffLevel.set(key, level + 1);
|
||||
this.logger.log(`[${key}] cooldown set until ${new Date(until).toISOString()} (${seconds}s, level ${level + 1})`);
|
||||
this.logger.log(`[${key}] [cooldown] until=${new Date(until).toISOString()} seconds=${seconds} level=${level + 1} - cooldown set`);
|
||||
}
|
||||
|
||||
isThrottled(key: MetadataProviderKey): boolean {
|
||||
@@ -38,7 +38,7 @@ export class ProviderThrottleTracker {
|
||||
this.throttledUntil.delete(key);
|
||||
this.backoffLevel.delete(key);
|
||||
if (wasThrottled) {
|
||||
this.logger.log(`[${key}] throttle cleared after successful fetch`);
|
||||
this.logger.log(`[${key}] [cooldown] - throttle cleared`);
|
||||
}
|
||||
}
|
||||
|
||||
|
||||
@@ -93,29 +93,29 @@ export class AmazonProvider implements IdentifiableProvider {
|
||||
private async fetchHtml(url: string, cookie = '', op: 'search' | 'lookup' = 'search', query?: string, providerId?: string): Promise<string | null> {
|
||||
const headers: HeadersInit = cookie ? { ...HEADERS, cookie } : HEADERS;
|
||||
const startedAt = Date.now();
|
||||
this.logger.log(`[amazon] fetch.start op=${op}${query ? ` query="${query}"` : ''}${providerId ? ` providerId="${providerId}"` : ''}`);
|
||||
this.logger.log(`[amazon] [start] op=${op}${query ? ` query="${query}"` : ''}${providerId ? ` providerId="${providerId}"` : ''}`);
|
||||
try {
|
||||
const res = await fetchWithThrottle(url, { headers, signal: AbortSignal.timeout(15_000) });
|
||||
if (!res.ok) {
|
||||
this.logger.warn(
|
||||
`[amazon] fetch.fail op=${op}${query ? ` query="${query}"` : ''}${providerId ? ` providerId="${providerId}"` : ''} status=${res.status} durationMs=${Date.now() - startedAt} message="non-ok response"`,
|
||||
`[amazon] [fail] op=${op}${query ? ` query="${query}"` : ''}${providerId ? ` providerId="${providerId}"` : ''} status=${res.status} durationMs=${Date.now() - startedAt} message="non-ok response"`,
|
||||
);
|
||||
return null;
|
||||
}
|
||||
const html = await res.text();
|
||||
this.logger.log(
|
||||
`[amazon] fetch.end op=${op}${query ? ` query="${query}"` : ''}${providerId ? ` providerId="${providerId}"` : ''} status=${res.status} durationMs=${Date.now() - startedAt}`,
|
||||
`[amazon] [end] op=${op}${query ? ` query="${query}"` : ''}${providerId ? ` providerId="${providerId}"` : ''} status=${res.status} durationMs=${Date.now() - startedAt}`,
|
||||
);
|
||||
return html;
|
||||
} catch (err) {
|
||||
if (err instanceof ProviderThrottleError) {
|
||||
this.logger.warn(
|
||||
`[amazon] fetch.fail op=${op}${query ? ` query="${query}"` : ''}${providerId ? ` providerId="${providerId}"` : ''} durationMs=${Date.now() - startedAt} message="throttled"`,
|
||||
`[amazon] [fail] op=${op}${query ? ` query="${query}"` : ''}${providerId ? ` providerId="${providerId}"` : ''} durationMs=${Date.now() - startedAt} message="throttled"`,
|
||||
);
|
||||
throw err;
|
||||
}
|
||||
this.logger.warn(
|
||||
`[amazon] fetch.fail op=${op}${query ? ` query="${query}"` : ''}${providerId ? ` providerId="${providerId}"` : ''} durationMs=${Date.now() - startedAt} message="${err instanceof Error ? err.message : String(err)}"`,
|
||||
`[amazon] [fail] op=${op}${query ? ` query="${query}"` : ''}${providerId ? ` providerId="${providerId}"` : ''} durationMs=${Date.now() - startedAt} message="${err instanceof Error ? err.message : String(err)}"`,
|
||||
);
|
||||
return null;
|
||||
}
|
||||
|
||||
@@ -34,29 +34,29 @@ export class AudibleProvider implements IdentifiableProvider {
|
||||
url.searchParams.set('response_groups', 'product_desc,media,product_attrs,series,product_plan_details,category_ladders');
|
||||
const requestUrl = url.toString();
|
||||
const startedAt = Date.now();
|
||||
this.logger.log(`[audible] fetch.start op=search query="${query}"`);
|
||||
this.logger.log(`[audible] [start] op=search query="${query}"`);
|
||||
|
||||
try {
|
||||
const res = await fetchWithThrottle(requestUrl, { signal: AbortSignal.timeout(10_000) });
|
||||
if (!res.ok) {
|
||||
this.logger.warn(
|
||||
`[audible] fetch.fail op=search query="${query}" status=${res.status} durationMs=${Date.now() - startedAt} message="non-ok response"`,
|
||||
`[audible] [fail] op=search query="${query}" status=${res.status} durationMs=${Date.now() - startedAt} message="non-ok response"`,
|
||||
);
|
||||
return [];
|
||||
}
|
||||
const body = (await res.json()) as AudibleSearchResponse;
|
||||
const results = (body.products ?? []).map(mapAudibleProduct);
|
||||
this.logger.log(
|
||||
`[audible] fetch.end op=search query="${query}" status=${res.status} resultCount=${results.length} durationMs=${Date.now() - startedAt}`,
|
||||
`[audible] [end] op=search query="${query}" status=${res.status} resultCount=${results.length} durationMs=${Date.now() - startedAt}`,
|
||||
);
|
||||
return results;
|
||||
} catch (err) {
|
||||
if (err instanceof ProviderThrottleError) {
|
||||
this.logger.warn(`[audible] fetch.fail op=search query="${query}" durationMs=${Date.now() - startedAt} message="throttled"`);
|
||||
this.logger.warn(`[audible] [fail] op=search query="${query}" durationMs=${Date.now() - startedAt} message="throttled"`);
|
||||
throw err;
|
||||
}
|
||||
this.logger.error(
|
||||
`[audible] fetch.fail op=search query="${query}" durationMs=${Date.now() - startedAt} message="${err instanceof Error ? err.message : String(err)}"`,
|
||||
`[audible] [fail] op=search query="${query}" durationMs=${Date.now() - startedAt} message="${err instanceof Error ? err.message : String(err)}"`,
|
||||
);
|
||||
return [];
|
||||
}
|
||||
@@ -71,29 +71,29 @@ export class AudibleProvider implements IdentifiableProvider {
|
||||
url.searchParams.set('response_groups', 'product_desc,media,product_attrs,series,product_plan_details,category_ladders');
|
||||
const requestUrl = url.toString();
|
||||
const startedAt = Date.now();
|
||||
this.logger.log(`[audible] fetch.start op=lookup providerId="${providerId}"`);
|
||||
this.logger.log(`[audible] [start] op=lookup providerId="${providerId}"`);
|
||||
|
||||
try {
|
||||
const res = await fetchWithThrottle(requestUrl, { signal: AbortSignal.timeout(10_000) });
|
||||
if (!res.ok) {
|
||||
this.logger.warn(
|
||||
`[audible] fetch.fail op=lookup providerId="${providerId}" status=${res.status} durationMs=${Date.now() - startedAt} message="non-ok response"`,
|
||||
`[audible] [fail] op=lookup providerId="${providerId}" status=${res.status} durationMs=${Date.now() - startedAt} message="non-ok response"`,
|
||||
);
|
||||
return null;
|
||||
}
|
||||
const body = (await res.json()) as { product: AudibleSearchResponse['products'][0] };
|
||||
const result = body.product ? mapAudibleProduct(body.product) : null;
|
||||
this.logger.log(
|
||||
`[audible] fetch.end op=lookup providerId="${providerId}" status=${res.status} found=${result != null} durationMs=${Date.now() - startedAt}`,
|
||||
`[audible] [end] op=lookup providerId="${providerId}" status=${res.status} found=${result != null} durationMs=${Date.now() - startedAt}`,
|
||||
);
|
||||
return result;
|
||||
} catch (err) {
|
||||
if (err instanceof ProviderThrottleError) {
|
||||
this.logger.warn(`[audible] fetch.fail op=lookup providerId="${providerId}" durationMs=${Date.now() - startedAt} message="throttled"`);
|
||||
this.logger.warn(`[audible] [fail] op=lookup providerId="${providerId}" durationMs=${Date.now() - startedAt} message="throttled"`);
|
||||
throw err;
|
||||
}
|
||||
this.logger.error(
|
||||
`[audible] fetch.fail op=lookup providerId="${providerId}" durationMs=${Date.now() - startedAt} message="${err instanceof Error ? err.message : String(err)}"`,
|
||||
`[audible] [fail] op=lookup providerId="${providerId}" durationMs=${Date.now() - startedAt} message="${err instanceof Error ? err.message : String(err)}"`,
|
||||
);
|
||||
return null;
|
||||
}
|
||||
|
||||
@@ -60,31 +60,29 @@ export class AudnexusProvider implements MetadataProvider {
|
||||
url.searchParams.set('response_groups', AUDIBLE_RESPONSE_GROUPS);
|
||||
const requestUrl = url.toString();
|
||||
const startedAt = Date.now();
|
||||
this.logger.log(`[audnexus] fetch.start op=resolve-asin method=GET query="${query}"`);
|
||||
this.logger.log(`[audnexus] [start] op=resolve-asin method=GET query="${query}"`);
|
||||
|
||||
try {
|
||||
const res = await fetchWithThrottle(requestUrl, { signal: AbortSignal.timeout(10_000) });
|
||||
if (!res.ok) {
|
||||
this.logger.warn(
|
||||
`[audnexus] fetch.fail op=resolve-asin method=GET query="${query}" status=${res.status} durationMs=${Date.now() - startedAt} message="non-ok response"`,
|
||||
`[audnexus] [fail] op=resolve-asin method=GET query="${query}" status=${res.status} durationMs=${Date.now() - startedAt} message="non-ok response"`,
|
||||
);
|
||||
return null;
|
||||
}
|
||||
const body = (await res.json()) as AudibleSearchResponse;
|
||||
const asin = body.products?.[0]?.asin?.trim() || null;
|
||||
this.logger.log(
|
||||
`[audnexus] fetch.end op=resolve-asin method=GET query="${query}" status=${res.status} found=${asin != null} durationMs=${Date.now() - startedAt}`,
|
||||
`[audnexus] [end] op=resolve-asin method=GET query="${query}" status=${res.status} found=${asin != null} durationMs=${Date.now() - startedAt}`,
|
||||
);
|
||||
return asin;
|
||||
} catch (err) {
|
||||
if (err instanceof ProviderThrottleError) {
|
||||
this.logger.warn(
|
||||
`[audnexus] fetch.fail op=resolve-asin method=GET query="${query}" durationMs=${Date.now() - startedAt} message="throttled"`,
|
||||
);
|
||||
this.logger.warn(`[audnexus] [fail] op=resolve-asin method=GET query="${query}" durationMs=${Date.now() - startedAt} message="throttled"`);
|
||||
throw err;
|
||||
}
|
||||
this.logger.error(
|
||||
`[audnexus] fetch.fail op=resolve-asin method=GET query="${query}" durationMs=${Date.now() - startedAt} message="${err instanceof Error ? err.message : String(err)}"`,
|
||||
`[audnexus] [fail] op=resolve-asin method=GET query="${query}" durationMs=${Date.now() - startedAt} message="${err instanceof Error ? err.message : String(err)}"`,
|
||||
);
|
||||
return null;
|
||||
}
|
||||
@@ -95,8 +93,8 @@ export class AudnexusProvider implements MetadataProvider {
|
||||
const chaptersUrl = `${BASE_URL}/books/${asin}/chapters`;
|
||||
const bookStartedAt = Date.now();
|
||||
const chaptersStartedAt = Date.now();
|
||||
this.logger.log(`[audnexus] fetch.start op=lookup-book method=GET providerId="${asin}"`);
|
||||
this.logger.log(`[audnexus] fetch.start op=lookup-chapters method=GET providerId="${asin}"`);
|
||||
this.logger.log(`[audnexus] [start] op=lookup-book method=GET providerId="${asin}"`);
|
||||
this.logger.log(`[audnexus] [start] op=lookup-chapters method=GET providerId="${asin}"`);
|
||||
|
||||
try {
|
||||
const [bookRes, chaptersRes] = await Promise.all([
|
||||
@@ -108,21 +106,21 @@ export class AudnexusProvider implements MetadataProvider {
|
||||
|
||||
if (!bookRes.ok) {
|
||||
this.logger.warn(
|
||||
`[audnexus] fetch.fail op=lookup-book method=GET providerId="${asin}" status=${bookRes.status} durationMs=${Date.now() - bookStartedAt} message="non-ok response"`,
|
||||
`[audnexus] [fail] op=lookup-book method=GET providerId="${asin}" status=${bookRes.status} durationMs=${Date.now() - bookStartedAt} message="non-ok response"`,
|
||||
);
|
||||
return null;
|
||||
}
|
||||
this.logger.log(
|
||||
`[audnexus] fetch.end op=lookup-book method=GET providerId="${asin}" status=${bookRes.status} durationMs=${Date.now() - bookStartedAt}`,
|
||||
`[audnexus] [end] op=lookup-book method=GET providerId="${asin}" status=${bookRes.status} durationMs=${Date.now() - bookStartedAt}`,
|
||||
);
|
||||
|
||||
if (!chaptersRes.ok) {
|
||||
this.logger.warn(
|
||||
`[audnexus] fetch.fail op=lookup-chapters method=GET providerId="${asin}" status=${chaptersRes.status} durationMs=${Date.now() - chaptersStartedAt} message="non-ok response"`,
|
||||
`[audnexus] [fail] op=lookup-chapters method=GET providerId="${asin}" status=${chaptersRes.status} durationMs=${Date.now() - chaptersStartedAt} message="non-ok response"`,
|
||||
);
|
||||
} else {
|
||||
this.logger.log(
|
||||
`[audnexus] fetch.end op=lookup-chapters method=GET providerId="${asin}" status=${chaptersRes.status} durationMs=${Date.now() - chaptersStartedAt}`,
|
||||
`[audnexus] [end] op=lookup-chapters method=GET providerId="${asin}" status=${chaptersRes.status} durationMs=${Date.now() - chaptersStartedAt}`,
|
||||
);
|
||||
}
|
||||
|
||||
@@ -133,12 +131,12 @@ export class AudnexusProvider implements MetadataProvider {
|
||||
} catch (err) {
|
||||
if (err instanceof ProviderThrottleError) {
|
||||
this.logger.warn(
|
||||
`[audnexus] fetch.fail op=lookup-asin method=GET providerId="${asin}" durationMs=${Date.now() - bookStartedAt} message="throttled"`,
|
||||
`[audnexus] [fail] op=lookup-asin method=GET providerId="${asin}" durationMs=${Date.now() - bookStartedAt} message="throttled"`,
|
||||
);
|
||||
throw err;
|
||||
}
|
||||
this.logger.error(
|
||||
`[audnexus] fetch.fail op=lookup-asin method=GET providerId="${asin}" durationMs=${Date.now() - bookStartedAt} message="${err instanceof Error ? err.message : String(err)}"`,
|
||||
`[audnexus] [fail] op=lookup-asin method=GET providerId="${asin}" durationMs=${Date.now() - bookStartedAt} message="${err instanceof Error ? err.message : String(err)}"`,
|
||||
);
|
||||
return null;
|
||||
}
|
||||
|
||||
@@ -95,7 +95,7 @@ export class ComicVineClient {
|
||||
private async get<T>(url: URL): Promise<T | null> {
|
||||
await this.rateLimiter.throttle();
|
||||
const startedAt = Date.now();
|
||||
this.logger.log(`[comicvine] fetch.start method=GET`);
|
||||
this.logger.log(`[comicvine] [start] method=GET`);
|
||||
|
||||
try {
|
||||
const res = await fetchWithThrottle(url, {
|
||||
@@ -104,27 +104,27 @@ export class ComicVineClient {
|
||||
});
|
||||
|
||||
if (res.status === 420) {
|
||||
this.logger.warn(`[comicvine] fetch.fail method=GET status=420 durationMs=${Date.now() - startedAt} message="throttled"`);
|
||||
this.logger.warn(`[comicvine] [fail] method=GET status=420 durationMs=${Date.now() - startedAt} message="throttled"`);
|
||||
throw new ProviderThrottleError();
|
||||
}
|
||||
|
||||
if (!res.ok) {
|
||||
this.logger.warn(`[comicvine] fetch.fail method=GET status=${res.status} durationMs=${Date.now() - startedAt} message="non-ok response"`);
|
||||
this.logger.warn(`[comicvine] [fail] method=GET status=${res.status} durationMs=${Date.now() - startedAt} message="non-ok response"`);
|
||||
return null;
|
||||
}
|
||||
|
||||
const body = (await res.json()) as ComicVineApiResponse<T>;
|
||||
if (body.status_code !== 1) {
|
||||
this.logger.warn(`[comicvine] fetch.fail method=GET status=${res.status} durationMs=${Date.now() - startedAt} message="${body.error}"`);
|
||||
this.logger.warn(`[comicvine] [fail] method=GET status=${res.status} durationMs=${Date.now() - startedAt} message="${body.error}"`);
|
||||
return null;
|
||||
}
|
||||
|
||||
const resultCount = Array.isArray(body.results) ? body.results.length : body.results ? 1 : 0;
|
||||
this.logger.log(`[comicvine] fetch.end method=GET status=${res.status} resultCount=${resultCount} durationMs=${Date.now() - startedAt}`);
|
||||
this.logger.log(`[comicvine] [end] method=GET status=${res.status} resultCount=${resultCount} durationMs=${Date.now() - startedAt}`);
|
||||
return body.results;
|
||||
} catch (err) {
|
||||
if (err instanceof ProviderThrottleError) throw err;
|
||||
this.logger.warn(`[comicvine] fetch.fail method=GET durationMs=${Date.now() - startedAt} message="${(err as Error).message}"`);
|
||||
this.logger.warn(`[comicvine] [fail] method=GET durationMs=${Date.now() - startedAt} message="${(err as Error).message}"`);
|
||||
return null;
|
||||
}
|
||||
}
|
||||
|
||||
@@ -78,29 +78,29 @@ export class GoodreadsProvider implements IdentifiableProvider {
|
||||
|
||||
private async fetchHtml(url: string, op: 'search' | 'search-by-isbn' | 'lookup', query?: string, providerId?: string): Promise<string | null> {
|
||||
const startedAt = Date.now();
|
||||
this.logger.log(`[goodreads] fetch.start op=${op}${query ? ` query="${query}"` : ''}${providerId ? ` providerId="${providerId}"` : ''}`);
|
||||
this.logger.log(`[goodreads] [start] op=${op}${query ? ` query="${query}"` : ''}${providerId ? ` providerId="${providerId}"` : ''}`);
|
||||
try {
|
||||
const res = await fetchWithThrottle(url, { headers: HEADERS, signal: AbortSignal.timeout(15_000) });
|
||||
if (!res.ok) {
|
||||
this.logger.warn(
|
||||
`[goodreads] fetch.fail op=${op}${query ? ` query="${query}"` : ''}${providerId ? ` providerId="${providerId}"` : ''} status=${res.status} durationMs=${Date.now() - startedAt} message="non-ok response"`,
|
||||
`[goodreads] [fail] op=${op}${query ? ` query="${query}"` : ''}${providerId ? ` providerId="${providerId}"` : ''} status=${res.status} durationMs=${Date.now() - startedAt} message="non-ok response"`,
|
||||
);
|
||||
return null;
|
||||
}
|
||||
const html = await res.text();
|
||||
this.logger.log(
|
||||
`[goodreads] fetch.end op=${op}${query ? ` query="${query}"` : ''}${providerId ? ` providerId="${providerId}"` : ''} status=${res.status} durationMs=${Date.now() - startedAt}`,
|
||||
`[goodreads] [end] op=${op}${query ? ` query="${query}"` : ''}${providerId ? ` providerId="${providerId}"` : ''} status=${res.status} durationMs=${Date.now() - startedAt}`,
|
||||
);
|
||||
return html;
|
||||
} catch (err) {
|
||||
if (err instanceof ProviderThrottleError) {
|
||||
this.logger.warn(
|
||||
`[goodreads] fetch.fail op=${op}${query ? ` query="${query}"` : ''}${providerId ? ` providerId="${providerId}"` : ''} durationMs=${Date.now() - startedAt} message="throttled"`,
|
||||
`[goodreads] [fail] op=${op}${query ? ` query="${query}"` : ''}${providerId ? ` providerId="${providerId}"` : ''} durationMs=${Date.now() - startedAt} message="throttled"`,
|
||||
);
|
||||
throw err;
|
||||
}
|
||||
this.logger.warn(
|
||||
`[goodreads] fetch.fail op=${op}${query ? ` query="${query}"` : ''}${providerId ? ` providerId="${providerId}"` : ''} durationMs=${Date.now() - startedAt} message="${err instanceof Error ? err.message : String(err)}"`,
|
||||
`[goodreads] [fail] op=${op}${query ? ` query="${query}"` : ''}${providerId ? ` providerId="${providerId}"` : ''} durationMs=${Date.now() - startedAt} message="${err instanceof Error ? err.message : String(err)}"`,
|
||||
);
|
||||
return null;
|
||||
}
|
||||
|
||||
@@ -34,29 +34,29 @@ export class GoogleProvider implements IdentifiableProvider {
|
||||
if (!enabled) return null;
|
||||
const url = this.buildUrl(`/volumes/${providerId}`, {}, apiKey);
|
||||
const startedAt = Date.now();
|
||||
this.logger.log(`[google] fetch.start op=lookup providerId="${providerId}"`);
|
||||
this.logger.log(`[google] [start] op=lookup providerId="${providerId}"`);
|
||||
|
||||
try {
|
||||
const res = await fetchWithThrottle(url, { signal: AbortSignal.timeout(10_000) });
|
||||
if (!res.ok) {
|
||||
this.logger.warn(
|
||||
`[google] fetch.fail op=lookup providerId="${providerId}" status=${res.status} durationMs=${Date.now() - startedAt} message="non-ok response"`,
|
||||
`[google] [fail] op=lookup providerId="${providerId}" status=${res.status} durationMs=${Date.now() - startedAt} message="non-ok response"`,
|
||||
);
|
||||
return null;
|
||||
}
|
||||
const item = (await res.json()) as GoogleVolumeItem;
|
||||
const mapped = mapGoogleVolume(item);
|
||||
this.logger.log(
|
||||
`[google] fetch.end op=lookup providerId="${providerId}" status=${res.status} found=${mapped != null} durationMs=${Date.now() - startedAt}`,
|
||||
`[google] [end] op=lookup providerId="${providerId}" status=${res.status} found=${mapped != null} durationMs=${Date.now() - startedAt}`,
|
||||
);
|
||||
return mapped;
|
||||
} catch (err) {
|
||||
if (err instanceof ProviderThrottleError) {
|
||||
this.logger.warn(`[google] fetch.fail op=lookup providerId="${providerId}" durationMs=${Date.now() - startedAt} message="throttled"`);
|
||||
this.logger.warn(`[google] [fail] op=lookup providerId="${providerId}" durationMs=${Date.now() - startedAt} message="throttled"`);
|
||||
throw err;
|
||||
}
|
||||
this.logger.warn(
|
||||
`[google] fetch.fail op=lookup providerId="${providerId}" durationMs=${Date.now() - startedAt} message="${err instanceof Error ? err.message : String(err)}"`,
|
||||
`[google] [fail] op=lookup providerId="${providerId}" durationMs=${Date.now() - startedAt} message="${err instanceof Error ? err.message : String(err)}"`,
|
||||
);
|
||||
throw err;
|
||||
}
|
||||
@@ -73,29 +73,29 @@ export class GoogleProvider implements IdentifiableProvider {
|
||||
private async fetchVolumes(query: string, apiKey: string): Promise<MetadataCandidate[]> {
|
||||
const url = this.buildUrl('/volumes', { q: query, maxResults: '10', printType: 'books' }, apiKey);
|
||||
const startedAt = Date.now();
|
||||
this.logger.log(`[google] fetch.start op=search query="${query}"`);
|
||||
this.logger.log(`[google] [start] op=search query="${query}"`);
|
||||
|
||||
try {
|
||||
const res = await fetchWithThrottle(url, { signal: AbortSignal.timeout(10_000) });
|
||||
if (!res.ok) {
|
||||
this.logger.warn(
|
||||
`[google] fetch.fail op=search query="${query}" status=${res.status} durationMs=${Date.now() - startedAt} message="non-ok response"`,
|
||||
`[google] [fail] op=search query="${query}" status=${res.status} durationMs=${Date.now() - startedAt} message="non-ok response"`,
|
||||
);
|
||||
return [];
|
||||
}
|
||||
const body = (await res.json()) as GoogleBooksResponse;
|
||||
const items = (body.items ?? []).map(mapGoogleVolume);
|
||||
this.logger.log(
|
||||
`[google] fetch.end op=search query="${query}" status=${res.status} resultCount=${items.length} durationMs=${Date.now() - startedAt}`,
|
||||
`[google] [end] op=search query="${query}" status=${res.status} resultCount=${items.length} durationMs=${Date.now() - startedAt}`,
|
||||
);
|
||||
return items;
|
||||
} catch (err) {
|
||||
if (err instanceof ProviderThrottleError) {
|
||||
this.logger.warn(`[google] fetch.fail op=search query="${query}" durationMs=${Date.now() - startedAt} message="throttled"`);
|
||||
this.logger.warn(`[google] [fail] op=search query="${query}" durationMs=${Date.now() - startedAt} message="throttled"`);
|
||||
throw err;
|
||||
}
|
||||
this.logger.warn(
|
||||
`[google] fetch.fail op=search query="${query}" durationMs=${Date.now() - startedAt} message="${err instanceof Error ? err.message : String(err)}"`,
|
||||
`[google] [fail] op=search query="${query}" durationMs=${Date.now() - startedAt} message="${err instanceof Error ? err.message : String(err)}"`,
|
||||
);
|
||||
throw err;
|
||||
}
|
||||
|
||||
@@ -112,7 +112,7 @@ export class HardcoverClient {
|
||||
): Promise<T | null> {
|
||||
await this.rateLimiter.throttle();
|
||||
const startedAt = Date.now();
|
||||
this.logger.log(`[hardcover] fetch.start op=${op} method=POST`);
|
||||
this.logger.log(`[hardcover] [start] op=${op} method=POST`);
|
||||
|
||||
try {
|
||||
const res = await fetchWithThrottle(GRAPHQL_ENDPOINT, {
|
||||
@@ -127,20 +127,20 @@ export class HardcoverClient {
|
||||
|
||||
if (!res.ok) {
|
||||
this.logger.warn(
|
||||
`[hardcover] fetch.fail op=${op} method=POST status=${res.status} durationMs=${Date.now() - startedAt} message="non-ok response"`,
|
||||
`[hardcover] [fail] op=${op} method=POST status=${res.status} durationMs=${Date.now() - startedAt} message="non-ok response"`,
|
||||
);
|
||||
return null;
|
||||
}
|
||||
|
||||
const body = (await res.json()) as T;
|
||||
this.logger.log(`[hardcover] fetch.end op=${op} method=POST status=${res.status} durationMs=${Date.now() - startedAt}`);
|
||||
this.logger.log(`[hardcover] [end] op=${op} method=POST status=${res.status} durationMs=${Date.now() - startedAt}`);
|
||||
return body;
|
||||
} catch (err) {
|
||||
if (err instanceof ProviderThrottleError) {
|
||||
this.logger.warn(`[hardcover] fetch.fail op=${op} method=POST durationMs=${Date.now() - startedAt} message="throttled"`);
|
||||
this.logger.warn(`[hardcover] [fail] op=${op} method=POST durationMs=${Date.now() - startedAt} message="throttled"`);
|
||||
throw err;
|
||||
}
|
||||
this.logger.warn(`[hardcover] fetch.fail op=${op} method=POST durationMs=${Date.now() - startedAt} message="${(err as Error).message}"`);
|
||||
this.logger.warn(`[hardcover] [fail] op=${op} method=POST durationMs=${Date.now() - startedAt} message="${(err as Error).message}"`);
|
||||
return null;
|
||||
}
|
||||
}
|
||||
|
||||
@@ -35,13 +35,13 @@ export class ITunesProvider implements IdentifiableProvider {
|
||||
url.searchParams.set('limit', '10');
|
||||
const requestUrl = url.toString();
|
||||
const startedAt = Date.now();
|
||||
this.logger.log(`[itunes] fetch.start op=search query="${query}"`);
|
||||
this.logger.log(`[itunes] [start] op=search query="${query}"`);
|
||||
|
||||
try {
|
||||
const res = await fetchWithThrottle(requestUrl, { signal: AbortSignal.timeout(10_000) });
|
||||
if (!res.ok) {
|
||||
this.logger.warn(
|
||||
`[itunes] fetch.fail op=search query="${query}" status=${res.status} durationMs=${Date.now() - startedAt} message="non-ok response"`,
|
||||
`[itunes] [fail] op=search query="${query}" status=${res.status} durationMs=${Date.now() - startedAt} message="non-ok response"`,
|
||||
);
|
||||
return [];
|
||||
}
|
||||
@@ -58,16 +58,16 @@ export class ITunesProvider implements IdentifiableProvider {
|
||||
.filter((r): r is MetadataCandidate => r !== null);
|
||||
|
||||
this.logger.log(
|
||||
`[itunes] fetch.end op=search query="${query}" status=${res.status} resultCount=${results.length} durationMs=${Date.now() - startedAt}`,
|
||||
`[itunes] [end] op=search query="${query}" status=${res.status} resultCount=${results.length} durationMs=${Date.now() - startedAt}`,
|
||||
);
|
||||
return results;
|
||||
} catch (err) {
|
||||
if (err instanceof ProviderThrottleError) {
|
||||
this.logger.warn(`[itunes] fetch.fail op=search query="${query}" durationMs=${Date.now() - startedAt} message="throttled"`);
|
||||
this.logger.warn(`[itunes] [fail] op=search query="${query}" durationMs=${Date.now() - startedAt} message="throttled"`);
|
||||
throw err;
|
||||
}
|
||||
this.logger.error(
|
||||
`[itunes] fetch.fail op=search query="${query}" durationMs=${Date.now() - startedAt} message="${err instanceof Error ? err.message : String(err)}"`,
|
||||
`[itunes] [fail] op=search query="${query}" durationMs=${Date.now() - startedAt} message="${err instanceof Error ? err.message : String(err)}"`,
|
||||
);
|
||||
return [];
|
||||
}
|
||||
@@ -81,13 +81,13 @@ export class ITunesProvider implements IdentifiableProvider {
|
||||
url.searchParams.set('id', providerId);
|
||||
const requestUrl = url.toString();
|
||||
const startedAt = Date.now();
|
||||
this.logger.log(`[itunes] fetch.start op=lookup providerId="${providerId}"`);
|
||||
this.logger.log(`[itunes] [start] op=lookup providerId="${providerId}"`);
|
||||
|
||||
try {
|
||||
const res = await fetchWithThrottle(requestUrl, { signal: AbortSignal.timeout(10_000) });
|
||||
if (!res.ok) {
|
||||
this.logger.warn(
|
||||
`[itunes] fetch.fail op=lookup providerId="${providerId}" status=${res.status} durationMs=${Date.now() - startedAt} message="non-ok response"`,
|
||||
`[itunes] [fail] op=lookup providerId="${providerId}" status=${res.status} durationMs=${Date.now() - startedAt} message="non-ok response"`,
|
||||
);
|
||||
return null;
|
||||
}
|
||||
@@ -101,16 +101,16 @@ export class ITunesProvider implements IdentifiableProvider {
|
||||
}
|
||||
}
|
||||
this.logger.log(
|
||||
`[itunes] fetch.end op=lookup providerId="${providerId}" status=${res.status} found=${result != null} durationMs=${Date.now() - startedAt}`,
|
||||
`[itunes] [end] op=lookup providerId="${providerId}" status=${res.status} found=${result != null} durationMs=${Date.now() - startedAt}`,
|
||||
);
|
||||
return result;
|
||||
} catch (err) {
|
||||
if (err instanceof ProviderThrottleError) {
|
||||
this.logger.warn(`[itunes] fetch.fail op=lookup providerId="${providerId}" durationMs=${Date.now() - startedAt} message="throttled"`);
|
||||
this.logger.warn(`[itunes] [fail] op=lookup providerId="${providerId}" durationMs=${Date.now() - startedAt} message="throttled"`);
|
||||
throw err;
|
||||
}
|
||||
this.logger.error(
|
||||
`[itunes] fetch.fail op=lookup providerId="${providerId}" durationMs=${Date.now() - startedAt} message="${err instanceof Error ? err.message : String(err)}"`,
|
||||
`[itunes] [fail] op=lookup providerId="${providerId}" durationMs=${Date.now() - startedAt} message="${err instanceof Error ? err.message : String(err)}"`,
|
||||
);
|
||||
return null;
|
||||
}
|
||||
|
||||
@@ -33,24 +33,24 @@ export class OpenLibraryProvider implements IdentifiableProvider {
|
||||
|
||||
const url = `${BASE_URL}/search.json?${query}`;
|
||||
const startedAt = Date.now();
|
||||
this.logger.log(`[open-library] fetch.start op=search`);
|
||||
this.logger.log(`[open-library] [start] op=search`);
|
||||
try {
|
||||
const res = await fetchWithThrottle(url, { signal: AbortSignal.timeout(10_000) });
|
||||
if (!res.ok) {
|
||||
this.logger.warn(`[open-library] fetch.fail op=search status=${res.status} durationMs=${Date.now() - startedAt} message="non-ok response"`);
|
||||
this.logger.warn(`[open-library] [fail] op=search status=${res.status} durationMs=${Date.now() - startedAt} message="non-ok response"`);
|
||||
return [];
|
||||
}
|
||||
|
||||
const body = (await res.json()) as OpenLibrarySearchResponse;
|
||||
const items = body.docs.map(mapOpenLibraryDoc);
|
||||
this.logger.log(`[open-library] fetch.end op=search status=${res.status} resultCount=${items.length} durationMs=${Date.now() - startedAt}`);
|
||||
this.logger.log(`[open-library] [end] op=search status=${res.status} resultCount=${items.length} durationMs=${Date.now() - startedAt}`);
|
||||
return items;
|
||||
} catch (err) {
|
||||
if (err instanceof ProviderThrottleError) {
|
||||
this.logger.warn(`[open-library] fetch.fail op=search durationMs=${Date.now() - startedAt} message="throttled"`);
|
||||
this.logger.warn(`[open-library] [fail] op=search durationMs=${Date.now() - startedAt} message="throttled"`);
|
||||
} else {
|
||||
this.logger.warn(
|
||||
`[open-library] fetch.fail op=search durationMs=${Date.now() - startedAt} message="${err instanceof Error ? err.message : String(err)}"`,
|
||||
`[open-library] [fail] op=search durationMs=${Date.now() - startedAt} message="${err instanceof Error ? err.message : String(err)}"`,
|
||||
);
|
||||
}
|
||||
throw err;
|
||||
@@ -62,12 +62,12 @@ export class OpenLibraryProvider implements IdentifiableProvider {
|
||||
if (!enabled) return null;
|
||||
const url = `${BASE_URL}/works/${providerId}.json`;
|
||||
const startedAt = Date.now();
|
||||
this.logger.log(`[open-library] fetch.start op=lookup providerId="${providerId}"`);
|
||||
this.logger.log(`[open-library] [start] op=lookup providerId="${providerId}"`);
|
||||
try {
|
||||
const res = await fetchWithThrottle(url, { signal: AbortSignal.timeout(10_000) });
|
||||
if (!res.ok) {
|
||||
this.logger.warn(
|
||||
`[open-library] fetch.fail op=lookup providerId="${providerId}" status=${res.status} durationMs=${Date.now() - startedAt} message="non-ok response"`,
|
||||
`[open-library] [fail] op=lookup providerId="${providerId}" status=${res.status} durationMs=${Date.now() - startedAt} message="non-ok response"`,
|
||||
);
|
||||
return null;
|
||||
}
|
||||
@@ -76,7 +76,7 @@ export class OpenLibraryProvider implements IdentifiableProvider {
|
||||
const mapped = mapOpenLibraryWork(work);
|
||||
if (mapped.genres?.length) {
|
||||
this.logger.log(
|
||||
`[open-library] fetch.end op=lookup providerId="${providerId}" status=${res.status} found=true durationMs=${Date.now() - startedAt}`,
|
||||
`[open-library] [end] op=lookup providerId="${providerId}" status=${res.status} found=true durationMs=${Date.now() - startedAt}`,
|
||||
);
|
||||
return mapped;
|
||||
}
|
||||
@@ -84,15 +84,15 @@ export class OpenLibraryProvider implements IdentifiableProvider {
|
||||
const searchGenres = await this.lookupGenresByWorkId(providerId);
|
||||
const result = searchGenres?.length ? { ...mapped, genres: searchGenres } : mapped;
|
||||
this.logger.log(
|
||||
`[open-library] fetch.end op=lookup providerId="${providerId}" status=${res.status} found=${result != null} durationMs=${Date.now() - startedAt}`,
|
||||
`[open-library] [end] op=lookup providerId="${providerId}" status=${res.status} found=${result != null} durationMs=${Date.now() - startedAt}`,
|
||||
);
|
||||
return result;
|
||||
} catch (err) {
|
||||
if (err instanceof ProviderThrottleError) {
|
||||
this.logger.warn(`[open-library] fetch.fail op=lookup providerId="${providerId}" durationMs=${Date.now() - startedAt} message="throttled"`);
|
||||
this.logger.warn(`[open-library] [fail] op=lookup providerId="${providerId}" durationMs=${Date.now() - startedAt} message="throttled"`);
|
||||
} else {
|
||||
this.logger.warn(
|
||||
`[open-library] fetch.fail op=lookup providerId="${providerId}" durationMs=${Date.now() - startedAt} message="${err instanceof Error ? err.message : String(err)}"`,
|
||||
`[open-library] [fail] op=lookup providerId="${providerId}" durationMs=${Date.now() - startedAt} message="${err instanceof Error ? err.message : String(err)}"`,
|
||||
);
|
||||
}
|
||||
throw err;
|
||||
@@ -120,12 +120,12 @@ export class OpenLibraryProvider implements IdentifiableProvider {
|
||||
});
|
||||
const url = `${BASE_URL}/search.json?${query}`;
|
||||
const startedAt = Date.now();
|
||||
this.logger.log(`[open-library] fetch.start op=lookup-genres providerId="${providerId}"`);
|
||||
this.logger.log(`[open-library] [start] op=lookup-genres providerId="${providerId}"`);
|
||||
try {
|
||||
const res = await fetchWithThrottle(url, { signal: AbortSignal.timeout(10_000) });
|
||||
if (!res.ok) {
|
||||
this.logger.warn(
|
||||
`[open-library] fetch.fail op=lookup-genres providerId="${providerId}" status=${res.status} durationMs=${Date.now() - startedAt} message="non-ok response"`,
|
||||
`[open-library] [fail] op=lookup-genres providerId="${providerId}" status=${res.status} durationMs=${Date.now() - startedAt} message="non-ok response"`,
|
||||
);
|
||||
return undefined;
|
||||
}
|
||||
@@ -133,7 +133,7 @@ export class OpenLibraryProvider implements IdentifiableProvider {
|
||||
const body = (await res.json()) as Partial<OpenLibrarySearchResponse>;
|
||||
if (!Array.isArray(body.docs) || body.docs.length === 0) {
|
||||
this.logger.log(
|
||||
`[open-library] fetch.end op=lookup-genres providerId="${providerId}" status=${res.status} resultCount=0 durationMs=${Date.now() - startedAt}`,
|
||||
`[open-library] [end] op=lookup-genres providerId="${providerId}" status=${res.status} resultCount=0 durationMs=${Date.now() - startedAt}`,
|
||||
);
|
||||
return undefined;
|
||||
}
|
||||
@@ -141,17 +141,17 @@ export class OpenLibraryProvider implements IdentifiableProvider {
|
||||
const doc = body.docs.find((d) => d.key === key);
|
||||
const genres = this.extractSubjectGenres(doc);
|
||||
this.logger.log(
|
||||
`[open-library] fetch.end op=lookup-genres providerId="${providerId}" status=${res.status} resultCount=${genres?.length ?? 0} durationMs=${Date.now() - startedAt}`,
|
||||
`[open-library] [end] op=lookup-genres providerId="${providerId}" status=${res.status} resultCount=${genres?.length ?? 0} durationMs=${Date.now() - startedAt}`,
|
||||
);
|
||||
return genres;
|
||||
} catch (err) {
|
||||
if (err instanceof ProviderThrottleError) {
|
||||
this.logger.warn(
|
||||
`[open-library] fetch.fail op=lookup-genres providerId="${providerId}" durationMs=${Date.now() - startedAt} message="throttled"`,
|
||||
`[open-library] [fail] op=lookup-genres providerId="${providerId}" durationMs=${Date.now() - startedAt} message="throttled"`,
|
||||
);
|
||||
} else {
|
||||
this.logger.warn(
|
||||
`[open-library] fetch.fail op=lookup-genres providerId="${providerId}" durationMs=${Date.now() - startedAt} message="${err instanceof Error ? err.message : String(err)}"`,
|
||||
`[open-library] [fail] op=lookup-genres providerId="${providerId}" durationMs=${Date.now() - startedAt} message="${err instanceof Error ? err.message : String(err)}"`,
|
||||
);
|
||||
}
|
||||
throw err;
|
||||
|
||||
@@ -31,7 +31,9 @@ export class FileEventProcessorService {
|
||||
|
||||
if (!shouldReevaluate) {
|
||||
await this.scannerRepo.deleteBookFile(file.id);
|
||||
this.logger.log(`Book ${file.bookId} non-selected file removed: ${absolutePath}`);
|
||||
this.logger.log(
|
||||
`[scanner.file_event.unlink] [end] libraryId=${libraryId} bookId=${file.bookId} path="${absolutePath.replace(/"/g, '\\"')}" action=remove_non_selected - non-selected file removed`,
|
||||
);
|
||||
return { type: 'noop' };
|
||||
}
|
||||
|
||||
@@ -44,7 +46,9 @@ export class FileEventProcessorService {
|
||||
// If the file was truly deleted (not renamed), the next full scan will prune it.
|
||||
await this.scannerRepo.updateBookPrimaryFile(file.bookId, null);
|
||||
await this.scannerRepo.markBooksAsMissing([file.bookId]);
|
||||
this.logger.log(`Book ${file.bookId} marked missing — selected content file removed: ${absolutePath}`);
|
||||
this.logger.log(
|
||||
`[scanner.file_event.unlink] [end] libraryId=${libraryId} bookId=${file.bookId} path="${absolutePath.replace(/"/g, '\\"')}" action=mark_missing_selected_removed - selected content file removed`,
|
||||
);
|
||||
return { type: 'book-missing', libraryId, bookIds: [file.bookId] };
|
||||
}
|
||||
|
||||
@@ -55,7 +59,9 @@ export class FileEventProcessorService {
|
||||
|
||||
const winner = this.pickPrimaryFile(remainingContent, formatPriority);
|
||||
await this.scannerRepo.updateBookPrimaryFile(file.bookId, winner?.id ?? null);
|
||||
this.logger.log(`Book ${file.bookId} selected ${winner?.format ?? 'unknown'} as primary — ${absolutePath} removed`);
|
||||
this.logger.log(
|
||||
`[scanner.file_event.unlink] [end] libraryId=${libraryId} bookId=${file.bookId} path="${absolutePath.replace(/"/g, '\\"')}" action=reselect_primary format=${winner?.format ?? 'unknown'} - primary file re-selected`,
|
||||
);
|
||||
return { type: 'book-restored', libraryId, bookIds: [file.bookId] };
|
||||
}
|
||||
|
||||
@@ -68,7 +74,9 @@ export class FileEventProcessorService {
|
||||
|
||||
await this.scannerRepo.markBooksAsMissing(bookIds);
|
||||
|
||||
this.logger.log(`${bookIds.length} book(s) marked missing — folder removed: ${absolutePath}`);
|
||||
this.logger.log(
|
||||
`[scanner.file_event.unlink_dir] [end] libraryId=${libraryId} path="${absolutePath.replace(/"/g, '\\"')}" missingCount=${bookIds.length} - books marked missing for removed folder`,
|
||||
);
|
||||
return { type: 'book-missing', libraryId, bookIds };
|
||||
}
|
||||
|
||||
@@ -91,7 +99,9 @@ export class FileEventProcessorService {
|
||||
await this.scannerRepo.updateBookFile(existing.file.id, this.statToFileInfo(fileStat));
|
||||
await this.refreshPrimaryFile(book.id, book.libraryId);
|
||||
await this.scannerRepo.markBooksAsPresent([book.id]);
|
||||
this.logger.log(`Book ${book.id} restored — file returned: ${absolutePath}`);
|
||||
this.logger.log(
|
||||
`[scanner.file_event.create] [end] libraryId=${book.libraryId} bookId=${book.id} path="${absolutePath.replace(/"/g, '\\"')}" action=restore_existing_file - book restored`,
|
||||
);
|
||||
return { type: 'book-restored', libraryId: book.libraryId, bookIds: [book.id] };
|
||||
}
|
||||
|
||||
@@ -112,7 +122,9 @@ export class FileEventProcessorService {
|
||||
|
||||
await this.refreshPrimaryFile(book.id, book.libraryId);
|
||||
await this.scannerRepo.markBooksAsPresent([book.id]);
|
||||
this.logger.log(`Book ${book.id} restored — file returned: ${absolutePath}`);
|
||||
this.logger.log(
|
||||
`[scanner.file_event.create] [end] libraryId=${book.libraryId} bookId=${book.id} path="${absolutePath.replace(/"/g, '\\"')}" action=restore_new_file_row - book restored`,
|
||||
);
|
||||
return { type: 'book-restored', libraryId: book.libraryId, bookIds: [book.id] };
|
||||
}
|
||||
|
||||
@@ -120,17 +132,37 @@ export class FileEventProcessorService {
|
||||
}
|
||||
|
||||
async reconcileMissingBooks(libraryIds: number[]): Promise<FileEventResult[]> {
|
||||
const missing = await this.scannerRepo.findMissingBooksForLibraries(libraryIds);
|
||||
if (missing.length === 0) return [];
|
||||
const event = 'scanner.file_event.reconcile_missing';
|
||||
const startedAt = Date.now();
|
||||
this.logger.log(`[${event}] [start] libraryCount=${libraryIds.length} - missing book reconcile started`);
|
||||
try {
|
||||
const missing = await this.scannerRepo.findMissingBooksForLibraries(libraryIds);
|
||||
if (missing.length === 0) {
|
||||
this.logger.log(
|
||||
`[${event}] [end] libraryCount=${libraryIds.length} durationMs=${Date.now() - startedAt} candidateCount=0 restoredCount=0 - missing book reconcile completed`,
|
||||
);
|
||||
return [];
|
||||
}
|
||||
|
||||
const results: FileEventResult[] = [];
|
||||
const results: FileEventResult[] = [];
|
||||
|
||||
for (const book of missing) {
|
||||
const result = await this.tryRestoreBook(book as { id: number; libraryId: number; libraryFolderId: number; folderPath: string });
|
||||
if (result.type !== 'noop') results.push(result);
|
||||
for (const book of missing) {
|
||||
const result = await this.tryRestoreBook(book as { id: number; libraryId: number; libraryFolderId: number; folderPath: string });
|
||||
if (result.type !== 'noop') results.push(result);
|
||||
}
|
||||
|
||||
this.logger.log(
|
||||
`[${event}] [end] libraryCount=${libraryIds.length} durationMs=${Date.now() - startedAt} candidateCount=${missing.length} restoredCount=${results.length} - missing book reconcile completed`,
|
||||
);
|
||||
return results;
|
||||
} catch (err) {
|
||||
const errorClass = err instanceof Error ? err.name : 'Error';
|
||||
const errorMessage = (err instanceof Error ? err.message : String(err)).replace(/"/g, '\\"');
|
||||
this.logger.warn(
|
||||
`[${event}] [fail] libraryCount=${libraryIds.length} durationMs=${Date.now() - startedAt} errorClass=${errorClass} error="${errorMessage}" - missing book reconcile failed`,
|
||||
);
|
||||
throw err;
|
||||
}
|
||||
|
||||
return results;
|
||||
}
|
||||
|
||||
private async tryRestoreBook(book: { id: number; libraryId: number; libraryFolderId: number; folderPath: string }): Promise<FileEventResult> {
|
||||
@@ -157,7 +189,9 @@ export class FileEventProcessorService {
|
||||
|
||||
await this.scannerRepo.updateBookPrimaryFile(book.id, winner?.id ?? null);
|
||||
await this.scannerRepo.markBooksAsPresent([book.id]);
|
||||
this.logger.log(`Book ${book.id} restored — file returned: ${winner?.absolutePath ?? existingContent[0].absolutePath}`);
|
||||
this.logger.log(
|
||||
`[scanner.file_event.restore_missing] [end] libraryId=${book.libraryId} bookId=${book.id} path="${(winner?.absolutePath ?? existingContent[0].absolutePath).replace(/"/g, '\\"')}" - missing book restored`,
|
||||
);
|
||||
return { type: 'book-restored', libraryId: book.libraryId, bookIds: [book.id] };
|
||||
}
|
||||
|
||||
@@ -179,7 +213,9 @@ export class FileEventProcessorService {
|
||||
}
|
||||
|
||||
await this.scannerRepo.markBooksAsPresent([file.bookId]);
|
||||
this.logger.log(`Book ${file.bookId} moved: ${file.absolutePath} → ${newAbsolutePath}`);
|
||||
this.logger.log(
|
||||
`[scanner.file_event.move] [end] libraryId=${libraryId} bookId=${file.bookId} from="${file.absolutePath.replace(/"/g, '\\"')}" to="${newAbsolutePath.replace(/"/g, '\\"')}" - moved file detected`,
|
||||
);
|
||||
return { type: 'book-moved', libraryId, bookIds: [file.bookId] };
|
||||
}
|
||||
|
||||
@@ -209,7 +245,9 @@ export class FileEventProcessorService {
|
||||
}
|
||||
|
||||
if (movedBookIds.length === 0 || !libraryId) return { type: 'noop' };
|
||||
this.logger.log(`${movedBookIds.length} book(s) moved: folder appeared: ${dirPath}`);
|
||||
this.logger.log(
|
||||
`[scanner.file_event.move_dir] [end] libraryId=${libraryId} dirPath="${dirPath.replace(/"/g, '\\"')}" movedCount=${movedBookIds.length} - moved books detected in directory`,
|
||||
);
|
||||
return { type: 'book-moved', libraryId, bookIds: movedBookIds };
|
||||
}
|
||||
|
||||
@@ -242,7 +280,9 @@ export class FileEventProcessorService {
|
||||
}
|
||||
|
||||
if (restoredIds.length > 0) {
|
||||
this.logger.log(`${restoredIds.length} book(s) restored: folder returned: ${absolutePath}`);
|
||||
this.logger.log(
|
||||
`[scanner.file_event.create_dir] [end] libraryId=${libraryId} path="${absolutePath.replace(/"/g, '\\"')}" restoredCount=${restoredIds.length} - books restored for returned folder`,
|
||||
);
|
||||
return { type: 'book-restored', libraryId, bookIds: restoredIds };
|
||||
}
|
||||
}
|
||||
|
||||
@@ -35,75 +35,157 @@ export class FileWatcherService implements OnApplicationBootstrap, OnModuleDestr
|
||||
) {}
|
||||
|
||||
async onApplicationBootstrap(): Promise<void> {
|
||||
const watchedLibraries = await this.db.select().from(libraries).where(eq(libraries.watch, true));
|
||||
for (const lib of watchedLibraries) {
|
||||
const folders = await this.db.select().from(libraryFolders).where(eq(libraryFolders.libraryId, lib.id));
|
||||
await this.startWatcher(
|
||||
lib.id,
|
||||
folders.map((f) => f.path),
|
||||
);
|
||||
}
|
||||
const event = 'scanner.watcher.bootstrap';
|
||||
const startedAt = Date.now();
|
||||
this.logger.log(`[${event}] [start] - watcher bootstrap started`);
|
||||
try {
|
||||
const watchedLibraries = await this.db.select().from(libraries).where(eq(libraries.watch, true));
|
||||
for (const lib of watchedLibraries) {
|
||||
const folders = await this.db.select().from(libraryFolders).where(eq(libraryFolders.libraryId, lib.id));
|
||||
await this.startWatcher(
|
||||
lib.id,
|
||||
folders.map((f) => f.path),
|
||||
);
|
||||
}
|
||||
|
||||
this.reconcileTimer = setInterval(() => {
|
||||
this.reconcile().catch((err) => this.logger.error(`Reconcile error: ${(err as Error).message}`));
|
||||
}, RECONCILE_MS);
|
||||
this.reconcileTimer = setInterval(() => {
|
||||
this.reconcile().catch((err) => {
|
||||
const errorClass = err instanceof Error ? err.name : 'Error';
|
||||
const errorMessage = (err instanceof Error ? err.message : String(err)).replace(/"/g, '\\"');
|
||||
this.logger.error(`[scanner.watcher.reconcile] [fail] errorClass=${errorClass} error="${errorMessage}" - reconcile failed`);
|
||||
});
|
||||
}, RECONCILE_MS);
|
||||
this.logger.log(
|
||||
`[${event}] [end] durationMs=${Date.now() - startedAt} watchedLibraryCount=${watchedLibraries.length} - watcher bootstrap completed`,
|
||||
);
|
||||
} catch (err) {
|
||||
const errorClass = err instanceof Error ? err.name : 'Error';
|
||||
const errorMessage = (err instanceof Error ? err.message : String(err)).replace(/"/g, '\\"');
|
||||
this.logger.warn(
|
||||
`[${event}] [fail] durationMs=${Date.now() - startedAt} errorClass=${errorClass} error="${errorMessage}" - watcher bootstrap failed`,
|
||||
);
|
||||
throw err;
|
||||
}
|
||||
}
|
||||
|
||||
async onModuleDestroy(): Promise<void> {
|
||||
if (this.reconcileTimer) clearInterval(this.reconcileTimer);
|
||||
for (const entry of this.pendingTimers.values()) clearTimeout(entry.timer);
|
||||
this.pendingTimers.clear();
|
||||
for (const timer of this.pendingFolderScanTimers.values()) clearTimeout(timer);
|
||||
this.pendingFolderScanTimers.clear();
|
||||
for (const subs of this.subscriptions.values()) {
|
||||
for (const sub of subs) await sub.unsubscribe();
|
||||
const event = 'scanner.watcher.destroy';
|
||||
const startedAt = Date.now();
|
||||
this.logger.log(`[${event}] [start] activeWatchers=${this.subscriptions.size} - watcher destroy started`);
|
||||
try {
|
||||
if (this.reconcileTimer) clearInterval(this.reconcileTimer);
|
||||
for (const entry of this.pendingTimers.values()) clearTimeout(entry.timer);
|
||||
this.pendingTimers.clear();
|
||||
for (const timer of this.pendingFolderScanTimers.values()) clearTimeout(timer);
|
||||
this.pendingFolderScanTimers.clear();
|
||||
for (const subs of this.subscriptions.values()) {
|
||||
for (const sub of subs) await sub.unsubscribe();
|
||||
}
|
||||
this.subscriptions.clear();
|
||||
this.logger.log(`[${event}] [end] durationMs=${Date.now() - startedAt} - watcher destroy completed`);
|
||||
} catch (err) {
|
||||
const errorClass = err instanceof Error ? err.name : 'Error';
|
||||
const errorMessage = (err instanceof Error ? err.message : String(err)).replace(/"/g, '\\"');
|
||||
this.logger.warn(
|
||||
`[${event}] [fail] durationMs=${Date.now() - startedAt} errorClass=${errorClass} error="${errorMessage}" - watcher destroy failed`,
|
||||
);
|
||||
throw err;
|
||||
}
|
||||
this.subscriptions.clear();
|
||||
}
|
||||
|
||||
private async reconcile(): Promise<void> {
|
||||
const event = 'scanner.watcher.reconcile';
|
||||
const startedAt = Date.now();
|
||||
const libraryIds = [...this.subscriptions.keys()];
|
||||
if (libraryIds.length === 0) return;
|
||||
|
||||
const results = await this.processor.reconcileMissingBooks(libraryIds);
|
||||
for (const result of results) {
|
||||
if (result.type === 'book-restored') {
|
||||
this.gateway.emitBookRestored({ libraryId: result.libraryId, bookIds: result.bookIds });
|
||||
this.logger.log(`[${event}] [start] libraryCount=${libraryIds.length} - reconcile started`);
|
||||
try {
|
||||
const results = await this.processor.reconcileMissingBooks(libraryIds);
|
||||
for (const result of results) {
|
||||
if (result.type === 'book-restored') {
|
||||
this.gateway.emitBookRestored({ libraryId: result.libraryId, bookIds: result.bookIds });
|
||||
}
|
||||
}
|
||||
this.logger.log(
|
||||
`[${event}] [end] libraryCount=${libraryIds.length} durationMs=${Date.now() - startedAt} resultCount=${results.length} - reconcile completed`,
|
||||
);
|
||||
} catch (err) {
|
||||
const errorClass = err instanceof Error ? err.name : 'Error';
|
||||
const errorMessage = (err instanceof Error ? err.message : String(err)).replace(/"/g, '\\"');
|
||||
this.logger.warn(
|
||||
`[${event}] [fail] libraryCount=${libraryIds.length} durationMs=${Date.now() - startedAt} errorClass=${errorClass} error="${errorMessage}" - reconcile failed`,
|
||||
);
|
||||
throw err;
|
||||
}
|
||||
}
|
||||
|
||||
async startWatcher(libraryId: number, paths: string[]): Promise<void> {
|
||||
await this.stopWatcher(libraryId);
|
||||
if (paths.length === 0) return;
|
||||
const event = 'scanner.watcher.start';
|
||||
const startedAt = Date.now();
|
||||
this.logger.log(`[${event}] [start] libraryId=${libraryId} pathCount=${paths.length} - watcher start requested`);
|
||||
try {
|
||||
await this.stopWatcher(libraryId);
|
||||
if (paths.length === 0) {
|
||||
this.logger.log(`[${event}] [end] libraryId=${libraryId} durationMs=${Date.now() - startedAt} pathCount=0 - watcher start completed`);
|
||||
return;
|
||||
}
|
||||
|
||||
const { subscribe } = await import('@parcel/watcher');
|
||||
const subs: AsyncSubscription[] = [];
|
||||
const { subscribe } = await import('@parcel/watcher');
|
||||
const subs: AsyncSubscription[] = [];
|
||||
|
||||
for (const path of paths) {
|
||||
const sub = await subscribe(path, (err, events) => {
|
||||
if (err) {
|
||||
this.logger.warn(`Watcher error for library ${libraryId}: ${err.message}`);
|
||||
return;
|
||||
}
|
||||
for (const event of events) {
|
||||
if (event.type === 'delete' || event.type === 'create') {
|
||||
this.schedule(event.type, event.path, libraryId);
|
||||
for (const path of paths) {
|
||||
const sub = await subscribe(path, (err, events) => {
|
||||
if (err) {
|
||||
this.logger.warn(
|
||||
`[${event}] [fail] libraryId=${libraryId} path="${path.replace(/"/g, '\\"')}" errorClass=${err.name ?? 'Error'} error="${err.message.replace(/"/g, '\\"')}" - watcher callback error`,
|
||||
);
|
||||
return;
|
||||
}
|
||||
}
|
||||
});
|
||||
subs.push(sub);
|
||||
}
|
||||
for (const event of events) {
|
||||
if (event.type === 'delete' || event.type === 'create') {
|
||||
this.schedule(event.type, event.path, libraryId);
|
||||
}
|
||||
}
|
||||
});
|
||||
subs.push(sub);
|
||||
}
|
||||
|
||||
this.subscriptions.set(libraryId, subs);
|
||||
this.logger.log(`Watching ${paths.length} folder(s) for library ${libraryId}`);
|
||||
this.subscriptions.set(libraryId, subs);
|
||||
this.logger.log(
|
||||
`[${event}] [end] libraryId=${libraryId} durationMs=${Date.now() - startedAt} pathCount=${paths.length} - watcher start completed`,
|
||||
);
|
||||
} catch (err) {
|
||||
const errorClass = err instanceof Error ? err.name : 'Error';
|
||||
const errorMessage = (err instanceof Error ? err.message : String(err)).replace(/"/g, '\\"');
|
||||
this.logger.warn(
|
||||
`[${event}] [fail] libraryId=${libraryId} pathCount=${paths.length} durationMs=${Date.now() - startedAt} errorClass=${errorClass} error="${errorMessage}" - watcher start failed`,
|
||||
);
|
||||
throw err;
|
||||
}
|
||||
}
|
||||
|
||||
async stopWatcher(libraryId: number): Promise<void> {
|
||||
const existing = this.subscriptions.get(libraryId);
|
||||
if (!existing) return;
|
||||
for (const sub of existing) await sub.unsubscribe();
|
||||
this.subscriptions.delete(libraryId);
|
||||
const event = 'scanner.watcher.stop';
|
||||
const startedAt = Date.now();
|
||||
this.logger.log(`[${event}] [start] libraryId=${libraryId} - watcher stop requested`);
|
||||
try {
|
||||
const existing = this.subscriptions.get(libraryId);
|
||||
if (!existing) {
|
||||
this.logger.log(`[${event}] [end] libraryId=${libraryId} durationMs=${Date.now() - startedAt} hadWatcher=false - watcher stop completed`);
|
||||
return;
|
||||
}
|
||||
for (const sub of existing) await sub.unsubscribe();
|
||||
this.subscriptions.delete(libraryId);
|
||||
this.logger.log(`[${event}] [end] libraryId=${libraryId} durationMs=${Date.now() - startedAt} hadWatcher=true - watcher stop completed`);
|
||||
} catch (err) {
|
||||
const errorClass = err instanceof Error ? err.name : 'Error';
|
||||
const errorMessage = (err instanceof Error ? err.message : String(err)).replace(/"/g, '\\"');
|
||||
this.logger.warn(
|
||||
`[${event}] [fail] libraryId=${libraryId} durationMs=${Date.now() - startedAt} errorClass=${errorClass} error="${errorMessage}" - watcher stop failed`,
|
||||
);
|
||||
throw err;
|
||||
}
|
||||
}
|
||||
|
||||
private scheduleFolderScan(filePath: string, libraryId: number): void {
|
||||
@@ -122,7 +204,11 @@ export class FileWatcherService implements OnApplicationBootstrap, OnModuleDestr
|
||||
if (existing) clearTimeout(existing.timer);
|
||||
const timer = setTimeout(() => {
|
||||
this.pendingTimers.delete(path);
|
||||
this.process(type, path, libraryId).catch((err) => this.logger.error(`Failed to process ${type} for ${path}: ${(err as Error).message}`));
|
||||
this.process(type, path, libraryId).catch((err) =>
|
||||
this.logger.error(
|
||||
`[scanner.watcher.process_event] [fail] libraryId=${libraryId} type=${type} path="${path.replace(/"/g, '\\"')}" errorClass=${err instanceof Error ? err.name : 'Error'} error="${(err instanceof Error ? err.message : String(err)).replace(/"/g, '\\"')}" - file event processing failed`,
|
||||
),
|
||||
);
|
||||
}, DEBOUNCE_MS);
|
||||
this.pendingTimers.set(path, { timer, type, libraryId });
|
||||
}
|
||||
|
||||
@@ -33,15 +33,17 @@ export class ScanGateway implements OnGatewayConnection, OnGatewayDisconnect {
|
||||
const user = await this.authService.validateUser(payload.sub, payload.ver);
|
||||
if (!user) throw new Error('User not found or token revoked');
|
||||
(client.data as Record<string, unknown>).user = user;
|
||||
this.logger.debug(`WS connected: user=${user.id} socket=${client.id}`);
|
||||
this.logger.debug(`[scanner.ws_connection] [start] userId=${user.id} socketId=${client.id} - websocket connected`);
|
||||
} catch (err) {
|
||||
this.logger.warn(`WS rejected: ${(err as Error).message} socket=${client.id}`);
|
||||
this.logger.warn(
|
||||
`[scanner.ws_connection] [fail] socketId=${client.id} errorClass=${err instanceof Error ? err.name : 'Error'} error="${(err instanceof Error ? err.message : String(err)).replace(/"/g, '\\"')}" - websocket rejected`,
|
||||
);
|
||||
client.disconnect();
|
||||
}
|
||||
}
|
||||
|
||||
handleDisconnect(client: Socket): void {
|
||||
this.logger.debug(`WS disconnected: socket=${client.id}`);
|
||||
this.logger.debug(`[scanner.ws_connection] [end] socketId=${client.id} - websocket disconnected`);
|
||||
}
|
||||
|
||||
@SubscribeMessage('subscribe:library')
|
||||
|
||||
@@ -40,73 +40,132 @@ export class ScannerService implements OnApplicationBootstrap {
|
||||
}
|
||||
|
||||
async startScan(libraryId: number, triggeredBy: 'manual' | 'watcher' | 'schedule'): Promise<{ jobId: number }> {
|
||||
if (this.scanJobStore.isRunning(libraryId)) {
|
||||
throw new ConflictException(`A scan is already running for library ${libraryId}`);
|
||||
const event = 'scanner.start_scan';
|
||||
const startedAt = Date.now();
|
||||
this.logger.log(`[${event}] [start] libraryId=${libraryId} triggeredBy=${triggeredBy} - scan start requested`);
|
||||
try {
|
||||
if (this.scanJobStore.isRunning(libraryId)) {
|
||||
throw new ConflictException(`A scan is already running for library ${libraryId}`);
|
||||
}
|
||||
|
||||
const [folders, settings] = await Promise.all([
|
||||
this.scannerRepo.findLibraryFolders(libraryId),
|
||||
this.scannerRepo.findLibrarySettings(libraryId),
|
||||
]);
|
||||
if (folders.length === 0) throw new NotFoundException(`Library ${libraryId} has no folders`);
|
||||
|
||||
const allowedFormats = settings?.allowedFormats ?? [];
|
||||
const formatPriority = settings?.formatPriority ?? DEFAULT_FORMAT_PRIORITY;
|
||||
const excludePatterns = settings?.excludePatterns ?? [];
|
||||
|
||||
const job = await this.scannerRepo.createScanJob(libraryId, triggeredBy);
|
||||
|
||||
this.scanJobStore.create(job.id, libraryId, 0);
|
||||
this.emitFromStore(libraryId, job.id, 'running');
|
||||
|
||||
this.runScan(libraryId, job.id, folders, allowedFormats, formatPriority, excludePatterns).catch((err) => {
|
||||
const errorClass = err instanceof Error ? err.name : 'Error';
|
||||
const errorMessage = (err instanceof Error ? err.message : String(err)).replace(/"/g, '\\"');
|
||||
this.logger.error(
|
||||
`[scanner.run_scan] [fail] libraryId=${libraryId} jobId=${job.id} errorClass=${errorClass} error="${errorMessage}" - scan job crashed unexpectedly`,
|
||||
);
|
||||
});
|
||||
|
||||
this.logger.log(
|
||||
`[${event}] [end] libraryId=${libraryId} triggeredBy=${triggeredBy} durationMs=${Date.now() - startedAt} jobId=${job.id} - scan start accepted`,
|
||||
);
|
||||
return { jobId: job.id };
|
||||
} catch (err) {
|
||||
const errorClass = err instanceof Error ? err.name : 'Error';
|
||||
const errorMessage = (err instanceof Error ? err.message : String(err)).replace(/"/g, '\\"');
|
||||
this.logger.warn(
|
||||
`[${event}] [fail] libraryId=${libraryId} triggeredBy=${triggeredBy} durationMs=${Date.now() - startedAt} errorClass=${errorClass} error="${errorMessage}" - scan start failed`,
|
||||
);
|
||||
throw err;
|
||||
}
|
||||
|
||||
const [folders, settings] = await Promise.all([this.scannerRepo.findLibraryFolders(libraryId), this.scannerRepo.findLibrarySettings(libraryId)]);
|
||||
if (folders.length === 0) throw new NotFoundException(`Library ${libraryId} has no folders`);
|
||||
|
||||
const allowedFormats = settings?.allowedFormats ?? [];
|
||||
const formatPriority = settings?.formatPriority ?? DEFAULT_FORMAT_PRIORITY;
|
||||
const excludePatterns = settings?.excludePatterns ?? [];
|
||||
|
||||
const job = await this.scannerRepo.createScanJob(libraryId, triggeredBy);
|
||||
|
||||
this.scanJobStore.create(job.id, libraryId, 0);
|
||||
this.emitFromStore(libraryId, job.id, 'running');
|
||||
|
||||
this.runScan(libraryId, job.id, folders, allowedFormats, formatPriority, excludePatterns).catch((err) =>
|
||||
this.logger.error(`Scan job ${job.id} crashed unexpectedly: ${(err as Error).message}`),
|
||||
);
|
||||
|
||||
return { jobId: job.id };
|
||||
}
|
||||
|
||||
async refreshCovers(libraryId: number): Promise<{ queued: number }> {
|
||||
const rows = await this.scannerRepo.findPrimaryBookFilesByLibrary(libraryId);
|
||||
const candidates = rows.filter((r) => r.format && METADATA_FORMATS.has(r.format));
|
||||
const total = candidates.length;
|
||||
const event = 'scanner.refresh_covers';
|
||||
const startedAt = Date.now();
|
||||
this.logger.log(`[${event}] [start] libraryId=${libraryId} - cover refresh started`);
|
||||
try {
|
||||
const rows = await this.scannerRepo.findPrimaryBookFilesByLibrary(libraryId);
|
||||
const candidates = rows.filter((r) => r.format && METADATA_FORMATS.has(r.format));
|
||||
const total = candidates.length;
|
||||
const backgroundStartedAt = Date.now();
|
||||
|
||||
this.scanGateway.emitCoverRefreshProgress({ libraryId, processed: 0, total, status: 'running' });
|
||||
this.scanGateway.emitCoverRefreshProgress({ libraryId, processed: 0, total, status: 'running' });
|
||||
|
||||
(async () => {
|
||||
let processed = 0;
|
||||
for (const row of candidates) {
|
||||
const refreshed = await this.metadataService.refreshCoverForBook(row.bookId, row.absolutePath, row.format!);
|
||||
processed++;
|
||||
if (refreshed) {
|
||||
this.scanGateway.emitCoverRefreshed({ bookId: row.bookId, libraryId } satisfies CoverRefreshedEvent);
|
||||
(async () => {
|
||||
let processed = 0;
|
||||
let refreshedCount = 0;
|
||||
for (const row of candidates) {
|
||||
const refreshed = await this.metadataService.refreshCoverForBook(row.bookId, row.absolutePath, row.format!);
|
||||
processed++;
|
||||
if (refreshed) {
|
||||
refreshedCount++;
|
||||
this.scanGateway.emitCoverRefreshed({ bookId: row.bookId, libraryId } satisfies CoverRefreshedEvent);
|
||||
}
|
||||
this.scanGateway.emitCoverRefreshProgress({
|
||||
libraryId,
|
||||
processed,
|
||||
total,
|
||||
status: processed < total ? 'running' : 'completed',
|
||||
} satisfies CoverRefreshProgressEvent);
|
||||
}
|
||||
this.scanGateway.emitCoverRefreshProgress({
|
||||
libraryId,
|
||||
processed,
|
||||
total,
|
||||
status: processed < total ? 'running' : 'completed',
|
||||
} satisfies CoverRefreshProgressEvent);
|
||||
}
|
||||
})().catch((err) => this.logger.warn(`Cover refresh crashed for library ${libraryId}: ${(err as Error).message}`));
|
||||
this.logger.log(
|
||||
`[${event}] [end] libraryId=${libraryId} durationMs=${Date.now() - backgroundStartedAt} queued=${total} processed=${processed} refreshed=${refreshedCount} - cover refresh completed`,
|
||||
);
|
||||
})().catch((err) => {
|
||||
const errorClass = err instanceof Error ? err.name : 'Error';
|
||||
const errorMessage = (err instanceof Error ? err.message : String(err)).replace(/"/g, '\\"');
|
||||
this.logger.warn(
|
||||
`[${event}] [fail] libraryId=${libraryId} durationMs=${Date.now() - backgroundStartedAt} errorClass=${errorClass} error="${errorMessage}" - cover refresh crashed`,
|
||||
);
|
||||
});
|
||||
|
||||
return { queued: total };
|
||||
this.logger.log(`[${event}] [end] libraryId=${libraryId} durationMs=${Date.now() - startedAt} queued=${total} - cover refresh queued`);
|
||||
return { queued: total };
|
||||
} catch (err) {
|
||||
const errorClass = err instanceof Error ? err.name : 'Error';
|
||||
const errorMessage = (err instanceof Error ? err.message : String(err)).replace(/"/g, '\\"');
|
||||
this.logger.warn(
|
||||
`[${event}] [fail] libraryId=${libraryId} durationMs=${Date.now() - startedAt} errorClass=${errorClass} error="${errorMessage}" - cover refresh failed`,
|
||||
);
|
||||
throw err;
|
||||
}
|
||||
}
|
||||
|
||||
startScanAsync(libraryId: number): void {
|
||||
if (this.scanJobStore.isRunning(libraryId)) return;
|
||||
this.startScan(libraryId, 'manual').catch((err) =>
|
||||
this.logger.error(`Auto-scan failed to start for library ${libraryId}: ${(err as Error).message}`),
|
||||
this.logger.error(
|
||||
`[scanner.start_scan] [fail] libraryId=${libraryId} triggeredBy=manual errorClass=${err instanceof Error ? err.name : 'Error'} error="${(err instanceof Error ? err.message : String(err)).replace(/"/g, '\\"')}" - auto-scan failed to start`,
|
||||
),
|
||||
);
|
||||
}
|
||||
|
||||
scanBookFolderAsync(filePath: string, libraryId: number): void {
|
||||
this.scanBookFolder(filePath, libraryId).catch((err) =>
|
||||
this.logger.error(`Targeted folder scan failed for ${filePath}: ${(err as Error).message}`),
|
||||
this.logger.error(
|
||||
`[scanner.scan_book_folder] [fail] libraryId=${libraryId} filePath="${filePath.replace(/"/g, '\\"')}" errorClass=${err instanceof Error ? err.name : 'Error'} error="${(err instanceof Error ? err.message : String(err)).replace(/"/g, '\\"')}" - targeted folder scan failed`,
|
||||
),
|
||||
);
|
||||
}
|
||||
|
||||
private async scanBookFolder(filePath: string, libraryId: number): Promise<void> {
|
||||
const event = 'scanner.scan_book_folder';
|
||||
const startedAt = Date.now();
|
||||
this.logger.log(`[${event}] [start] libraryId=${libraryId} filePath="${filePath.replace(/"/g, '\\"')}" - targeted folder scan started`);
|
||||
const allFolders = await this.scannerRepo.findLibraryFolders(libraryId);
|
||||
const libraryFolder = allFolders.find((f) => filePath.startsWith(f.path + sep));
|
||||
if (!libraryFolder) return;
|
||||
if (!libraryFolder) {
|
||||
this.logger.log(
|
||||
`[${event}] [end] libraryId=${libraryId} filePath="${filePath.replace(/"/g, '\\"')}" durationMs=${Date.now() - startedAt} matchedLibraryFolder=false - targeted folder scan completed`,
|
||||
);
|
||||
return;
|
||||
}
|
||||
|
||||
const bookFolder = dirname(filePath);
|
||||
|
||||
@@ -114,6 +173,9 @@ export class ScannerService implements OnApplicationBootstrap {
|
||||
// walk the entire root — treat it as a full scan instead.
|
||||
if (bookFolder === libraryFolder.path) {
|
||||
this.startScanAsync(libraryId);
|
||||
this.logger.log(
|
||||
`[${event}] [end] libraryId=${libraryId} filePath="${filePath.replace(/"/g, '\\"')}" durationMs=${Date.now() - startedAt} promotedToFullScan=true - targeted folder scan completed`,
|
||||
);
|
||||
return;
|
||||
}
|
||||
|
||||
@@ -144,13 +206,24 @@ export class ScannerService implements OnApplicationBootstrap {
|
||||
|
||||
let candidate: BookCandidate | null;
|
||||
try {
|
||||
candidate = await buildSingleBookCandidate(resolvedBookFolder, libraryFolder.path, excludePatterns, (msg) => this.logger.warn(msg));
|
||||
candidate = await buildSingleBookCandidate(resolvedBookFolder, libraryFolder.path, excludePatterns, (msg) =>
|
||||
this.logger.warn(
|
||||
`[scanner.walk_candidates] [fail] libraryId=${libraryId} path="${resolvedBookFolder.replace(/"/g, '\\"')}" error="${msg.replace(/"/g, '\\"')}" - candidate walk warning`,
|
||||
),
|
||||
);
|
||||
} catch (err) {
|
||||
this.logger.warn(`Cannot walk ${resolvedBookFolder}: ${err instanceof Error ? err.message : String(err)}`);
|
||||
this.logger.warn(
|
||||
`[${event}] [fail] libraryId=${libraryId} filePath="${filePath.replace(/"/g, '\\"')}" durationMs=${Date.now() - startedAt} errorClass=${err instanceof Error ? err.name : 'Error'} error="${(err instanceof Error ? err.message : String(err)).replace(/"/g, '\\"')}" - cannot walk target folder`,
|
||||
);
|
||||
return;
|
||||
}
|
||||
|
||||
if (!candidate) return;
|
||||
if (!candidate) {
|
||||
this.logger.log(
|
||||
`[${event}] [end] libraryId=${libraryId} filePath="${filePath.replace(/"/g, '\\"')}" durationMs=${Date.now() - startedAt} candidateFound=false - targeted folder scan completed`,
|
||||
);
|
||||
return;
|
||||
}
|
||||
|
||||
const allowed = allowedFormats.length > 0 ? new Set(allowedFormats) : null;
|
||||
if (allowed) {
|
||||
@@ -158,7 +231,12 @@ export class ScannerService implements OnApplicationBootstrap {
|
||||
const { role, format } = classifyFile(f.absolutePath);
|
||||
return role !== 'content' || (format !== null && allowed.has(format));
|
||||
});
|
||||
if (!filtered.some((f) => classifyFile(f.absolutePath).role === 'content')) return;
|
||||
if (!filtered.some((f) => classifyFile(f.absolutePath).role === 'content')) {
|
||||
this.logger.log(
|
||||
`[${event}] [end] libraryId=${libraryId} filePath="${filePath.replace(/"/g, '\\"')}" durationMs=${Date.now() - startedAt} candidateFound=true skippedByAllowedFormats=true - targeted folder scan completed`,
|
||||
);
|
||||
return;
|
||||
}
|
||||
candidate = { ...candidate, files: filtered };
|
||||
}
|
||||
|
||||
@@ -180,7 +258,9 @@ export class ScannerService implements OnApplicationBootstrap {
|
||||
|
||||
const result = await this.processCandidate(candidate, libraryId, libraryFolder.id, bookByFolderPath, fileByPath, fileByIno, formatPriority);
|
||||
|
||||
this.logger.log(`Targeted scan of ${basename(resolvedBookFolder)}: added=${result.added}, updated=${result.updated}`);
|
||||
this.logger.log(
|
||||
`[${event}] [end] libraryId=${libraryId} filePath="${filePath.replace(/"/g, '\\"')}" durationMs=${Date.now() - startedAt} folder="${basename(resolvedBookFolder).replace(/"/g, '\\"')}" added=${result.added} updated=${result.updated} - targeted folder scan completed`,
|
||||
);
|
||||
}
|
||||
|
||||
private async runScan(
|
||||
@@ -191,7 +271,9 @@ export class ScannerService implements OnApplicationBootstrap {
|
||||
formatPriority: string[],
|
||||
excludePatterns: string[],
|
||||
): Promise<void> {
|
||||
this.logger.log(`Scan job ${jobId} started for library ${libraryId}`);
|
||||
const event = 'scanner.run_scan';
|
||||
const startedAt = Date.now();
|
||||
this.logger.log(`[${event}] [start] libraryId=${libraryId} jobId=${jobId} folderCount=${folders.length} - scan job started`);
|
||||
|
||||
type FolderWork = {
|
||||
id: number;
|
||||
@@ -210,9 +292,15 @@ export class ScannerService implements OnApplicationBootstrap {
|
||||
for (const folder of folders) {
|
||||
let candidates: BookCandidate[] = [];
|
||||
try {
|
||||
candidates = await findBookCandidates(folder.path, excludePatterns, (msg) => this.logger.warn(msg));
|
||||
candidates = await findBookCandidates(folder.path, excludePatterns, (msg) =>
|
||||
this.logger.warn(
|
||||
`[scanner.walk_candidates] [fail] libraryId=${libraryId} path="${folder.path.replace(/"/g, '\\"')}" error="${msg.replace(/"/g, '\\"')}" - candidate walk warning`,
|
||||
),
|
||||
);
|
||||
} catch (err) {
|
||||
this.logger.warn(`Cannot walk ${folder.path}: ${err instanceof Error ? err.message : String(err)}`);
|
||||
this.logger.warn(
|
||||
`[${event}] [fail] libraryId=${libraryId} jobId=${jobId} path="${folder.path.replace(/"/g, '\\"')}" durationMs=${Date.now() - startedAt} errorClass=${err instanceof Error ? err.name : 'Error'} error="${(err instanceof Error ? err.message : String(err)).replace(/"/g, '\\"')}" - cannot walk folder`,
|
||||
);
|
||||
}
|
||||
|
||||
if (allowed) {
|
||||
@@ -250,7 +338,9 @@ export class ScannerService implements OnApplicationBootstrap {
|
||||
}
|
||||
|
||||
await this.scannerRepo.completeScanJob(jobId, totals);
|
||||
this.logger.log(`Scan job ${jobId} completed — ${JSON.stringify(totals)}`);
|
||||
this.logger.log(
|
||||
`[${event}] [end] libraryId=${libraryId} jobId=${jobId} durationMs=${Date.now() - startedAt} addedCount=${totals.addedCount} updatedCount=${totals.updatedCount} missingCount=${totals.missingCount} - scan job completed`,
|
||||
);
|
||||
this.scanJobStore.increment(libraryId, { added: totals.addedCount, updated: totals.updatedCount });
|
||||
this.emitFromStore(libraryId, jobId, 'completed');
|
||||
} catch (err) {
|
||||
@@ -258,7 +348,9 @@ export class ScannerService implements OnApplicationBootstrap {
|
||||
await this.scannerRepo.failScanJob(jobId, message).catch(() => {
|
||||
// Job row may have been cascade-deleted if library was deleted.
|
||||
});
|
||||
this.logger.error(`Scan job ${jobId} failed: ${message}`);
|
||||
this.logger.error(
|
||||
`[${event}] [fail] libraryId=${libraryId} jobId=${jobId} durationMs=${Date.now() - startedAt} errorClass=${err instanceof Error ? err.name : 'Error'} error="${message.replace(/"/g, '\\"')}" - scan job failed`,
|
||||
);
|
||||
this.emitFromStore(libraryId, jobId, 'failed', message);
|
||||
} finally {
|
||||
this.scanJobStore.delete(libraryId);
|
||||
@@ -274,49 +366,66 @@ export class ScannerService implements OnApplicationBootstrap {
|
||||
jobId: number,
|
||||
formatPriority: string[],
|
||||
): Promise<ScanCounts> {
|
||||
const counts: ScanCounts = { addedCount: 0, updatedCount: 0, missingCount: 0 };
|
||||
|
||||
const bookByFolderPath = new Map<string, { id: number; status: string; folderPath: string }>(
|
||||
knownBooks.map((b) => [b.folderPath, { id: b.id, status: b.status, folderPath: b.folderPath }]),
|
||||
const event = 'scanner.scan_folder_candidates';
|
||||
const startedAt = Date.now();
|
||||
this.logger.log(
|
||||
`[${event}] [start] libraryId=${libraryId} jobId=${jobId} libraryFolderId=${libraryFolderId} candidateCount=${candidates.length} - folder candidate scan started`,
|
||||
);
|
||||
const fileByPath = new Map<
|
||||
string,
|
||||
{ id: number; bookId: number; ino: number; sizeBytes: number | null; mtime: Date | null; hash: string | null }
|
||||
>(knownFiles.map((f) => [f.absolutePath, { id: f.id, bookId: f.bookId, ino: f.ino, sizeBytes: f.sizeBytes, mtime: f.mtime, hash: f.hash }]));
|
||||
const fileByIno = new Map<number, { id: number; bookId: number; absolutePath: string }>(
|
||||
knownFiles.map((f) => [f.ino, { id: f.id, bookId: f.bookId, absolutePath: f.absolutePath }]),
|
||||
);
|
||||
const seenBookIds = new Set<number>();
|
||||
try {
|
||||
const counts: ScanCounts = { addedCount: 0, updatedCount: 0, missingCount: 0 };
|
||||
|
||||
for (let i = 0; i < candidates.length; i += BATCH_SIZE) {
|
||||
const batch = candidates.slice(i, i + BATCH_SIZE);
|
||||
|
||||
const results = await Promise.all(
|
||||
batch.map((c) => this.processCandidate(c, libraryId, libraryFolderId, bookByFolderPath, fileByPath, fileByIno, formatPriority)),
|
||||
const bookByFolderPath = new Map<string, { id: number; status: string; folderPath: string }>(
|
||||
knownBooks.map((b) => [b.folderPath, { id: b.id, status: b.status, folderPath: b.folderPath }]),
|
||||
);
|
||||
const fileByPath = new Map<
|
||||
string,
|
||||
{ id: number; bookId: number; ino: number; sizeBytes: number | null; mtime: Date | null; hash: string | null }
|
||||
>(knownFiles.map((f) => [f.absolutePath, { id: f.id, bookId: f.bookId, ino: f.ino, sizeBytes: f.sizeBytes, mtime: f.mtime, hash: f.hash }]));
|
||||
const fileByIno = new Map<number, { id: number; bookId: number; absolutePath: string }>(
|
||||
knownFiles.map((f) => [f.ino, { id: f.id, bookId: f.bookId, absolutePath: f.absolutePath }]),
|
||||
);
|
||||
const seenBookIds = new Set<number>();
|
||||
|
||||
for (const r of results) {
|
||||
seenBookIds.add(r.bookId);
|
||||
counts.addedCount += r.added;
|
||||
counts.updatedCount += r.updated;
|
||||
for (let i = 0; i < candidates.length; i += BATCH_SIZE) {
|
||||
const batch = candidates.slice(i, i + BATCH_SIZE);
|
||||
|
||||
const results = await Promise.all(
|
||||
batch.map((c) => this.processCandidate(c, libraryId, libraryFolderId, bookByFolderPath, fileByPath, fileByIno, formatPriority)),
|
||||
);
|
||||
|
||||
for (const r of results) {
|
||||
seenBookIds.add(r.bookId);
|
||||
counts.addedCount += r.added;
|
||||
counts.updatedCount += r.updated;
|
||||
}
|
||||
|
||||
const entry = this.scanJobStore.increment(libraryId, { processed: batch.length });
|
||||
if (entry && this.scanJobStore.shouldEmit(entry)) {
|
||||
this.emitFromStore(libraryId, jobId, 'running');
|
||||
this.scanJobStore.markEmitted(entry);
|
||||
}
|
||||
}
|
||||
|
||||
const entry = this.scanJobStore.increment(libraryId, { processed: batch.length });
|
||||
if (entry && this.scanJobStore.shouldEmit(entry)) {
|
||||
this.emitFromStore(libraryId, jobId, 'running');
|
||||
this.scanJobStore.markEmitted(entry);
|
||||
const missingIds = knownBooks.filter((b) => !seenBookIds.has(b.id)).map((b) => b.id);
|
||||
if (missingIds.length > 0) {
|
||||
await this.scannerRepo.markBooksAsMissing(missingIds);
|
||||
counts.missingCount += missingIds.length;
|
||||
this.scanJobStore.increment(libraryId, { missing: missingIds.length });
|
||||
this.scanGateway.emitBookMissing({ libraryId, bookIds: missingIds } satisfies BookMissingEvent);
|
||||
}
|
||||
}
|
||||
|
||||
const missingIds = knownBooks.filter((b) => !seenBookIds.has(b.id)).map((b) => b.id);
|
||||
if (missingIds.length > 0) {
|
||||
await this.scannerRepo.markBooksAsMissing(missingIds);
|
||||
counts.missingCount += missingIds.length;
|
||||
this.scanJobStore.increment(libraryId, { missing: missingIds.length });
|
||||
this.scanGateway.emitBookMissing({ libraryId, bookIds: missingIds } satisfies BookMissingEvent);
|
||||
this.logger.log(
|
||||
`[${event}] [end] libraryId=${libraryId} jobId=${jobId} libraryFolderId=${libraryFolderId} durationMs=${Date.now() - startedAt} addedCount=${counts.addedCount} updatedCount=${counts.updatedCount} missingCount=${counts.missingCount} - folder candidate scan completed`,
|
||||
);
|
||||
return counts;
|
||||
} catch (err) {
|
||||
const errorClass = err instanceof Error ? err.name : 'Error';
|
||||
const errorMessage = (err instanceof Error ? err.message : String(err)).replace(/"/g, '\\"');
|
||||
this.logger.warn(
|
||||
`[${event}] [fail] libraryId=${libraryId} jobId=${jobId} libraryFolderId=${libraryFolderId} durationMs=${Date.now() - startedAt} errorClass=${errorClass} error="${errorMessage}" - folder candidate scan failed`,
|
||||
);
|
||||
throw err;
|
||||
}
|
||||
|
||||
return counts;
|
||||
}
|
||||
|
||||
private async processCandidate(
|
||||
@@ -331,8 +440,6 @@ export class ScannerService implements OnApplicationBootstrap {
|
||||
const counts = { added: 0, updated: 0 };
|
||||
const fileCounts: ScanCounts = { addedCount: 0, updatedCount: 0, missingCount: 0 };
|
||||
|
||||
this.logger.log(`Processing: ${basename(candidate.folderPath)} (${candidate.files.length} file${candidate.files.length !== 1 ? 's' : ''})`);
|
||||
|
||||
const book = await this.upsertBook(candidate, libraryId, libraryFolderId, bookByFolderPath, fileCounts);
|
||||
counts.added += fileCounts.addedCount;
|
||||
counts.updated += fileCounts.updatedCount;
|
||||
@@ -355,7 +462,9 @@ export class ScannerService implements OnApplicationBootstrap {
|
||||
const { format, role: classifiedRole } = classifyFile(fileStat.absolutePath);
|
||||
|
||||
if (classifiedRole === 'content' && fileStat.sizeBytes === 0) {
|
||||
this.logger.warn(`Zero-byte content file skipped: ${fileStat.absolutePath}`);
|
||||
this.logger.warn(
|
||||
`[scanner.process_file] [fail] bookId=${book.id} path="${fileStat.absolutePath.replace(/"/g, '\\"')}" reason=zero_byte_content - content file skipped`,
|
||||
);
|
||||
continue;
|
||||
}
|
||||
|
||||
@@ -367,7 +476,9 @@ export class ScannerService implements OnApplicationBootstrap {
|
||||
try {
|
||||
processResult = await this.processFile(fileStat, format, role, sortOrder, book.id, libraryFolderId, fileByPath, fileByIno, fileCount);
|
||||
} catch (err) {
|
||||
this.logger.warn(`Failed to process file ${fileStat.absolutePath}: ${err instanceof Error ? err.message : String(err)}`);
|
||||
this.logger.warn(
|
||||
`[scanner.process_file] [fail] bookId=${book.id} path="${fileStat.absolutePath.replace(/"/g, '\\"')}" errorClass=${err instanceof Error ? err.name : 'Error'} error="${(err instanceof Error ? err.message : String(err)).replace(/"/g, '\\"')}" - file processing failed`,
|
||||
);
|
||||
continue;
|
||||
}
|
||||
|
||||
@@ -386,7 +497,9 @@ export class ScannerService implements OnApplicationBootstrap {
|
||||
await this.metadataService.extractAndSave(book.id, fileStat.absolutePath, format);
|
||||
nonAudioMetadataExtracted = true;
|
||||
} catch (err) {
|
||||
this.logger.warn(`Metadata extraction failed for ${fileStat.absolutePath}: ${err instanceof Error ? err.message : String(err)}`);
|
||||
this.logger.warn(
|
||||
`[scanner.extract_metadata] [fail] bookId=${book.id} path="${fileStat.absolutePath.replace(/"/g, '\\"')}" format=${format} errorClass=${err instanceof Error ? err.name : 'Error'} error="${(err instanceof Error ? err.message : String(err)).replace(/"/g, '\\"')}" - metadata extraction failed`,
|
||||
);
|
||||
}
|
||||
}
|
||||
}
|
||||
@@ -416,7 +529,9 @@ export class ScannerService implements OnApplicationBootstrap {
|
||||
try {
|
||||
await this.metadataService.extractAndSave(book.id, first.absolutePath, first.format);
|
||||
} catch (err) {
|
||||
this.logger.warn(`Audio metadata extraction failed for ${first.absolutePath}: ${err instanceof Error ? err.message : String(err)}`);
|
||||
this.logger.warn(
|
||||
`[scanner.extract_audio_metadata] [fail] bookId=${book.id} path="${first.absolutePath.replace(/"/g, '\\"')}" format=${first.format} errorClass=${err instanceof Error ? err.name : 'Error'} error="${(err instanceof Error ? err.message : String(err)).replace(/"/g, '\\"')}" - audio metadata extraction failed`,
|
||||
);
|
||||
}
|
||||
}
|
||||
|
||||
@@ -427,7 +542,9 @@ export class ScannerService implements OnApplicationBootstrap {
|
||||
try {
|
||||
await this.metadataService.extractAudioFileDuration(book.id, audioFile.absolutePath);
|
||||
} catch (err) {
|
||||
this.logger.warn(`Audio duration extraction failed for ${audioFile.absolutePath}: ${err instanceof Error ? err.message : String(err)}`);
|
||||
this.logger.warn(
|
||||
`[scanner.extract_audio_duration] [fail] bookId=${book.id} path="${audioFile.absolutePath.replace(/"/g, '\\"')}" errorClass=${err instanceof Error ? err.name : 'Error'} error="${(err instanceof Error ? err.message : String(err)).replace(/"/g, '\\"')}" - audio duration extraction failed`,
|
||||
);
|
||||
}
|
||||
}),
|
||||
);
|
||||
@@ -435,10 +552,11 @@ export class ScannerService implements OnApplicationBootstrap {
|
||||
try {
|
||||
await this.metadataService.aggregateAudioDuration(book.id);
|
||||
} catch (err) {
|
||||
this.logger.warn(`Audio duration aggregation failed for book ${book.id}: ${err instanceof Error ? err.message : String(err)}`);
|
||||
this.logger.warn(
|
||||
`[scanner.aggregate_audio_duration] [fail] bookId=${book.id} errorClass=${err instanceof Error ? err.name : 'Error'} error="${(err instanceof Error ? err.message : String(err)).replace(/"/g, '\\"')}" - audio duration aggregation failed`,
|
||||
);
|
||||
}
|
||||
}
|
||||
|
||||
return { bookId: book.id, ...counts };
|
||||
}
|
||||
|
||||
@@ -467,7 +585,9 @@ export class ScannerService implements OnApplicationBootstrap {
|
||||
counts.updatedCount++;
|
||||
}
|
||||
bookByFolderPath.set(candidate.folderPath, { ...survivor, folderPath: candidate.folderPath });
|
||||
this.logger.log(`Merged ${virtualChildren.length} stem-split book(s) into book ${survivor.id}: ${basename(candidate.folderPath)}`);
|
||||
this.logger.log(
|
||||
`[scanner.upsert_book] [end] libraryId=${libraryId} bookId=${survivor.id} folder="${candidate.folderPath.replace(/"/g, '\\"')}" mergedCount=${virtualChildren.length} action=merge_stem_split - stem-split books merged`,
|
||||
);
|
||||
return { ...survivor, folderPath: candidate.folderPath };
|
||||
}
|
||||
|
||||
@@ -480,7 +600,11 @@ export class ScannerService implements OnApplicationBootstrap {
|
||||
counts.addedCount++;
|
||||
this.autoFetchOrchestrator
|
||||
?.scheduleIfEligible(book.id, libraryId, 'event_import')
|
||||
.catch((err: Error) => this.logger.warn(`book-metadata-fetch schedule failed for book ${book.id}: ${err.message}`));
|
||||
.catch((err: Error) =>
|
||||
this.logger.warn(
|
||||
`[scanner.upsert_book] [fail] libraryId=${libraryId} bookId=${book.id} action=schedule_metadata_fetch errorClass=${err.name} error="${err.message.replace(/"/g, '\\"')}" - metadata fetch schedule failed`,
|
||||
),
|
||||
);
|
||||
return book;
|
||||
}
|
||||
|
||||
@@ -499,7 +623,9 @@ export class ScannerService implements OnApplicationBootstrap {
|
||||
const siblingIds = virtualSiblings.map((b) => b.id);
|
||||
await this.scannerRepo.markBooksAsMissing(siblingIds);
|
||||
this.scanGateway.emitBookMissing({ libraryId, bookIds: siblingIds });
|
||||
this.logger.log(`Drained ${virtualSiblings.length} virtual sibling(s) into book ${existing.id}: ${basename(candidate.folderPath)}`);
|
||||
this.logger.log(
|
||||
`[scanner.upsert_book] [end] libraryId=${libraryId} bookId=${existing.id} folder="${candidate.folderPath.replace(/"/g, '\\"')}" drainedCount=${virtualSiblings.length} action=drain_virtual_siblings - virtual siblings drained`,
|
||||
);
|
||||
}
|
||||
|
||||
return existing;
|
||||
@@ -565,7 +691,9 @@ export class ScannerService implements OnApplicationBootstrap {
|
||||
} catch (err) {
|
||||
const code = (err as NodeJS.ErrnoException).code;
|
||||
if (code === 'ENOENT' || code === 'EACCES') {
|
||||
this.logger.debug(`File no longer accessible, skipping: ${fileStat.absolutePath}`);
|
||||
this.logger.debug(
|
||||
`[scanner.process_file] [end] bookId=${bookId} path="${fileStat.absolutePath.replace(/"/g, '\\"')}" action=skip_inaccessible - file no longer accessible`,
|
||||
);
|
||||
return { isNew: false, reassigned: false, fileId: null };
|
||||
}
|
||||
throw err;
|
||||
|
||||
@@ -105,7 +105,7 @@ describe('UploadProcessorService', () => {
|
||||
metadataService.extractAndSave.mockRejectedValue(new Error('upstream failed'));
|
||||
|
||||
service.extractMetadataAsync(9, '/tmp/a.epub', 'epub');
|
||||
await Promise.resolve();
|
||||
await new Promise((resolve) => setImmediate(resolve));
|
||||
|
||||
expect(metadataService.extractAndSave).toHaveBeenCalledWith(9, '/tmp/a.epub', 'epub');
|
||||
expect(warn).toHaveBeenCalledWith(expect.stringContaining('upstream failed'));
|
||||
|
||||
@@ -78,8 +78,14 @@ export class UploadProcessorService {
|
||||
extractMetadataAsync(bookId: number, absolutePath: string, format: string): void {
|
||||
if (!METADATA_FORMATS.has(format)) return;
|
||||
|
||||
this.logger.debug(`[upload.metadata] [start] book=${bookId} format=${format}`);
|
||||
this.metadataService
|
||||
.extractAndSave(bookId, absolutePath, format)
|
||||
.catch((err: Error) => this.logger.warn(`Metadata extraction failed for uploaded book ${bookId}: ${err.message}`));
|
||||
.then(() => {
|
||||
this.logger.debug(`[upload.metadata] [success] book=${bookId}`);
|
||||
})
|
||||
.catch((err: Error) => {
|
||||
this.logger.warn(`[upload.metadata] [fail] book=${bookId} error="${err.message}"`);
|
||||
});
|
||||
}
|
||||
}
|
||||
|
||||
@@ -1,4 +1,4 @@
|
||||
import { BadRequestException, ConflictException, Inject, Injectable, NotFoundException } from '@nestjs/common';
|
||||
import { BadRequestException, ConflictException, Inject, Injectable, Logger, NotFoundException } from '@nestjs/common';
|
||||
import { access as fsAccess } from 'fs/promises';
|
||||
import { basename, dirname, extname, join } from 'path';
|
||||
import { Readable } from 'stream';
|
||||
@@ -25,6 +25,8 @@ type Db = NodePgDatabase<typeof schema>;
|
||||
|
||||
@Injectable()
|
||||
export class UploadService {
|
||||
private readonly logger = new Logger(UploadService.name);
|
||||
|
||||
constructor(
|
||||
@Inject(DB) private readonly db: Db,
|
||||
private readonly appSettings: AppSettingsService,
|
||||
@@ -35,6 +37,7 @@ export class UploadService {
|
||||
) {}
|
||||
|
||||
async upload(libraryId: number, folderId: number | undefined, rawFilename: string, fileStream: Readable, user: RequestUser): Promise<UploadResult> {
|
||||
this.logger.log(`[upload.request] [start] user=${user.id} file="${rawFilename}"`);
|
||||
const isSuperuser = user.isSuperuser;
|
||||
|
||||
const library = await this.findLibraryOrFail(libraryId);
|
||||
@@ -63,8 +66,11 @@ export class UploadService {
|
||||
|
||||
this.processor.extractMetadataAsync(bookId, absolutePath, format);
|
||||
|
||||
this.logger.log(`[upload.request] [success] user=${user.id} book=${bookId} format=${format} size=${sizeBytes}`);
|
||||
return { bookId, filename: basename(absolutePath), format, sizeBytes };
|
||||
} catch (err) {
|
||||
const errorMessage = err instanceof Error ? err.message : String(err);
|
||||
this.logger.error(`[upload.request] [fail] user=${user.id} file="${rawFilename}" error="${errorMessage}"`);
|
||||
await this.storage.cleanup(tempPath);
|
||||
throw err;
|
||||
}
|
||||
|
||||
Reference in New Issue
Block a user