Add thread-safe logging and instrument metadata + cover worker

- New unitLog writes to ~/.config/.../mybookshelf.log with timestamps\n- unitmetadata: log tool paths, commands, exit codes, parsed results\n- unitCoverWorker: log worker lifecycle, enqueue, pdftoppm calls and outcomes\n- README: document logging location

README.md

@@ -26,3 +26,10 @@ On Fedora:
 On Arch:
 
 - `sudo pacman -S poppler unzip`
+
+## Logging
+
+- The app writes a debug log to your user config directory: `mybookshelf.log`.
+- Typical path on Linux: `~/.config/myBookShelf/mybookshelf.log`.
+- It records metadata extraction calls (pdfinfo/unzip) and cover generation calls (pdftoppm) with command lines, exit codes, and parsing results.
+- If covers/metadata still don’t work, please attach this log when filing an issue.

src/unitCoverWorker.pas

@@ -7,7 +7,7 @@ interface
 uses
   Classes, SysUtils, Process, LCLIntf, Graphics, Math,
   IntfGraphics, FPImage, FPReadPNG, FPReadJPEG, GraphType, LazCanvas,
-  Book, BookCollection, FileUtil;
+  Book, BookCollection, FileUtil, unitLog;
 
 { Call this once after loading your data: it scans the list and enqueues
   only the PDFs that still use the generic cover (i.e. ImagePath=''). }
@@ -75,6 +75,7 @@ begin
   // look for pdftoppm in PATH (Poppler utilities); fall back to bare name
   Converter := FindDefaultExecutablePath('pdftoppm');
   if Converter = '' then Converter := 'pdftoppm';
+  LogInfoFmt('pdftoppm tool: %s', [Converter]);
 
   OutBase := ChangeFileExt(PdfPath, ''); // /path/book.pdf -> /path/book
 
@@ -91,9 +92,11 @@ begin
       Proc.Parameters.Add(OutBase);
       Proc.Options := [poWaitOnExit];
       Proc.ShowWindow := swoHIDE;
+      LogDebugFmt('Running: %s -png -singlefile -f 1 -l 1 %s %s', [Proc.Executable, PdfPath, OutBase]);
       Proc.Execute;
+      LogDebugFmt('pdftoppm exit=%d', [Proc.ExitStatus]);
     except
-      // ignore execution failures; will return ''
+      on E: Exception do LogErrorFmt('pdftoppm failed: %s', [E.Message]);
     end;
   finally
     Proc.Free;
@@ -124,6 +127,7 @@ begin
         end;
         Png.Assign(Img);
         Png.SaveToFile(Result);
+        LogInfoFmt('Generated cover: %s', [Result]);
       finally
         Png.Free;
         Canvas.Free;
@@ -131,6 +135,10 @@ begin
         SrcImg.Free;
       end;
     end;
+  end
+  else
+  begin
+    LogWarnFmt('pdftoppm produced no output for: %s', [PdfPath]);
   end;
 end;
 
@@ -151,9 +159,13 @@ begin
   EnsureQueue;
   l := GPdfQueue.LockList;
   try
+    LogInfoFmt('Scanning list for missing PDF covers (count=%d)', [AList.Count]);
     for i := 0 to AList.Count - 1 do
       if IsPdf(AList.Books[i].FilePath) and HasGenericCover(AList.Books[i]) then
+      begin
         l.Add(AList.Books[i]);
+        LogDebugFmt('Enqueued for cover: %s', [AList.Books[i].FilePath]);
+      end;
   finally
     GPdfQueue.UnlockList;
   end;
@@ -169,7 +181,10 @@ begin
   l := GPdfQueue.LockList;
   try
     if l.IndexOf(B) < 0 then
+    begin
       l.Add(B);
+      LogDebugFmt('Enqueued single book for cover: %s', [B.FilePath]);
+    end;
   finally
     GPdfQueue.UnlockList;
   end;
@@ -186,6 +201,7 @@ begin
   end;
   if (GWorker = nil) then
   begin
+    LogInfo('Starting cover worker');
     GWorker := TCoverWorker.Create(True);
     GWorker.FreeOnTerminate := False; // we manage lifecycle explicitly
     GWorker.Start;
@@ -199,6 +215,7 @@ var
 begin
   if GWorker <> nil then
   begin
+    LogInfo('Stopping cover worker');
     GWorker.Terminate;
     // Process synchronize calls while waiting to avoid potential deadlock
     while not GWorker.Finished do
@@ -207,6 +224,7 @@ begin
       Sleep(5);
     end;
     FreeAndNil(GWorker);
+    LogInfo('Cover worker stopped');
   end;
   if GPdfQueue <> nil then
   begin
@@ -242,6 +260,7 @@ var
   Img: String;
 begin
   // drain the queue
+  LogInfo('Worker loop started');
   while not Terminated do
   begin
     // Pop one item
@@ -258,7 +277,10 @@ begin
     end;
 
     if B = nil then
+    begin
+      LogInfo('Queue empty, exiting worker');
       Break; // queue empty → exit thread
+    end;
 
     // Skip if it no longer needs a cover
     if not (IsPdf(B.FilePath) and HasGenericCover(B)) then
@@ -268,6 +290,7 @@ begin
     end;
 
     // Generate cover (background thread)
+    LogInfoFmt('Generating cover for: %s', [B.FilePath]);
     Img := GeneratePdfCover(B.FilePath, B.Cover.Width, B.Cover.Height);
 
     if (Img <> '') and FileExists(Img) then
@@ -275,10 +298,13 @@ begin
       // Pass data to main thread via fields + Synchronize
       FApplyBook := B;
       FApplyImg  := Img;
+      LogDebugFmt('Applying cover: %s', [Img]);
       Synchronize(@DoApplyCover);
       FApplyBook := nil;
       FApplyImg  := '';
-    end;
+    end
+    else
+      LogWarnFmt('Cover generation produced no file for: %s', [B.FilePath]);
 
     Sleep(5); // be nice to the UI event loop
   end;

src/unitLog.pas

@@ -0,0 +1,76 @@
+unit unitLog;
+
+{$mode objfpc}{$H+}
+
+interface
+
+procedure LogDebug(const Msg: string);
+procedure LogInfo(const Msg: string);
+procedure LogWarn(const Msg: string);
+procedure LogError(const Msg: string);
+procedure LogDebugFmt(const Fmt: string; const Args: array of const);
+procedure LogInfoFmt(const Fmt: string; const Args: array of const);
+procedure LogWarnFmt(const Fmt: string; const Args: array of const);
+procedure LogErrorFmt(const Fmt: string; const Args: array of const);
+
+implementation
+
+uses
+  SysUtils, LazFileUtils, SyncObjs;
+
+var
+  LogLock: TRTLCriticalSection;
+
+function LogFilePath: string;
+var dir: string;
+begin
+  dir := IncludeTrailingPathDelimiter(GetAppConfigDirUTF8(False));
+  if not DirectoryExistsUTF8(dir) then CreateDirUTF8(dir);
+  Result := dir + 'mybookshelf.log';
+end;
+
+procedure WriteLine(const Level, Msg: string);
+var
+  f: TextFile;
+  path: string;
+begin
+  path := LogFilePath;
+  EnterCriticalSection(LogLock);
+  try
+    AssignFile(f, path);
+    try
+      if FileExistsUTF8(path) then
+        Append(f)
+      else
+        Rewrite(f);
+      try
+        WriteLn(f, FormatDateTime('yyyy-mm-dd hh:nn:ss.zzz', Now), ' [', Level, '] ', Msg);
+      finally
+        CloseFile(f);
+      end;
+    except
+      // swallow logging errors
+    end;
+  finally
+    LeaveCriticalSection(LogLock);
+  end;
+end;
+
+procedure LogDebug(const Msg: string); begin WriteLine('DEBUG', Msg); end;
+procedure LogInfo(const Msg: string);  begin WriteLine('INFO',  Msg); end;
+procedure LogWarn(const Msg: string);  begin WriteLine('WARN',  Msg); end;
+procedure LogError(const Msg: string); begin WriteLine('ERROR', Msg); end;
+
+procedure LogDebugFmt(const Fmt: string; const Args: array of const); begin LogDebug(Format(Fmt, Args)); end;
+procedure LogInfoFmt(const Fmt: string; const Args: array of const);  begin LogInfo(Format(Fmt, Args)); end;
+procedure LogWarnFmt(const Fmt: string; const Args: array of const);  begin LogWarn(Format(Fmt, Args)); end;
+procedure LogErrorFmt(const Fmt: string; const Args: array of const); begin LogError(Format(Fmt, Args)); end;
+
+initialization
+  InitCriticalSection(LogLock);
+
+finalization
+  DoneCriticalSection(LogLock);
+
+end.
+

src/unitmetadata.pas

@@ -15,7 +15,7 @@ function ExtractBookMetadata(const FileName: String; out Title, Authors: String)
 implementation
 
 uses
-  Process, DOM, XMLRead, LazUTF8, StrUtils, LazFileUtils;
+  Process, DOM, XMLRead, LazUTF8, StrUtils, LazFileUtils, unitLog;
 
 function ExtractPDFMetadata(const FileName: String; out Title, Authors: String): Boolean;
 var
@@ -31,6 +31,7 @@ begin
   Authors := '';
   exe := FindDefaultExecutablePath('pdfinfo');
   if exe = '' then exe := 'pdfinfo';
+  LogInfoFmt('pdfinfo tool: %s', [exe]);
   proc := TProcess.Create(nil);
   sl := TStringList.Create;
   env := TStringList.Create;
@@ -45,8 +46,10 @@ begin
       proc.Parameters.Add(FileName);
       proc.Options := [poWaitOnExit, poUsePipes];
       proc.ShowWindow := swoHide;
+      LogDebugFmt('Running: %s %s', [proc.Executable, FileName]);
       proc.Execute;
       sl.LoadFromStream(proc.Output);
+      LogDebugFmt('pdfinfo exit=%d, output lines=%d', [proc.ExitStatus, sl.Count]);
       for i := 0 to sl.Count - 1 do
       begin
         line := sl[i];
@@ -56,7 +59,10 @@ begin
           Authors := Trim(Copy(line, Pos(':', line) + 1, MaxInt));
       end;
       Result := (Title <> '') or (Authors <> '');
+      LogInfoFmt('PDF metadata parsed: title="%s" authors="%s" result=%s',
+        [Title, Authors, BoolToStr(Result, True)]);
     except
+      on E: Exception do LogErrorFmt('pdfinfo failed: %s', [E.Message]);
       Result := False;
     end;
   finally
@@ -83,6 +89,7 @@ begin
   Authors := '';
   exe := FindDefaultExecutablePath('unzip');
   if exe = '' then exe := 'unzip';
+  LogInfoFmt('unzip tool: %s', [exe]);
   // list files
   proc := TProcess.Create(nil);
   sl := TStringList.Create;
@@ -97,8 +104,10 @@ begin
       proc.Parameters.Add(FileName);
       proc.Options := [poWaitOnExit, poUsePipes];
       proc.ShowWindow := swoHide;
+      LogDebugFmt('Running: %s -Z1 %s', [proc.Executable, FileName]);
       proc.Execute;
       sl.LoadFromStream(proc.Output);
+      LogDebugFmt('unzip -Z1 exit=%d, lines=%d', [proc.ExitStatus, sl.Count]);
       opfPath := '';
       for i := 0 to sl.Count - 1 do
       begin
@@ -110,6 +119,7 @@ begin
         end;
       end;
     except
+      on E: Exception do LogErrorFmt('unzip -Z1 failed: %s', [E.Message]);
       opfPath := '';
     end;
   finally
@@ -133,10 +143,12 @@ begin
       proc.Parameters.Add(opfPath);
       proc.Options := [poWaitOnExit, poUsePipes];
       proc.ShowWindow := swoHide;
+      LogDebugFmt('Running: %s -p %s %s', [proc.Executable, FileName, opfPath]);
       proc.Execute;
       stream.CopyFrom(proc.Output, 0);
       stream.Position := 0;
     except
+      on E: Exception do LogErrorFmt('unzip -p failed: %s', [E.Message]);
       stream.Size := 0;
     end;
   finally
@@ -147,6 +159,7 @@ begin
     try
       ReadXMLFile(xml, stream);
     except
+      on E: Exception do LogErrorFmt('ReadXML OPF failed: %s', [E.Message]);
       Exit(False);
     end;
     try
@@ -173,6 +186,8 @@ begin
     stream.Free;
   end;
   Result := (Title <> '') or (Authors <> '');
+  LogInfoFmt('EPUB metadata parsed: title="%s" authors="%s" result=%s',
+    [Title, Authors, BoolToStr(Result, True)]);
 end;
 
 function ExtractBookMetadata(const FileName: String; out Title, Authors: String): Boolean;