Add OpenTelemetry, performance metrics, and broaden logging + tests

Observability:
- New FuchsTelemetry (ActivitySource + Meter) defining business counters
  (invoices/reminders/reports rendered, emails/sms sent+failed, MT940 rows,
  MFR calls) and duration histograms (PDF render, report render, email send).
- Program.cs wires OpenTelemetry tracing (ASP.NET Core, HttpClient, SqlClient,
  app source) and metrics (ASP.NET Core, HttpClient, runtime, app meter).
  OTLP export is enabled only when Fuchs:Telemetry:OtlpEndpoint is set, so a
  missing collector never affects the app; disable via Fuchs:Telemetry:Enabled.

Instrumentation + logging:
- Services (Pdf, Invoice, Reminder, Report, Com, Banking, Widget, MfrFactory)
  now emit spans, record metrics, and log entry/result/timing/errors.
- Added dispatch + key-action logging to the previously silent handlers
  (Banking, Reminder, Reports, Requests).

Tests (137 total, +10):
- ProcessWebComServiceTests with a stub HttpMessageHandler cover success
  (API 200), failure (API 500, invalid email, empty mobile), disabled mode,
  the base64 attachment payload contract, and metric emission via MeterListener.

Co-Authored-By: Claude Opus 4.8 <noreply@anthropic.com>

Fuchs/Services/BankingService.cs

@@ -1,4 +1,6 @@
 using System.Data;
+using System.Diagnostics;
+using Fuchs.Observability;
 using Microsoft.Extensions.Logging;
 using programmersdigest.MT940Parser;
 
@@ -27,6 +29,8 @@ public class BankingService : IBankingService
 
     public DataTable ParseToDatatable(Stream stream, DataTable? schemaDatatable = null)
     {
+        using var act = FuchsTelemetry.StartActivity("banking.mt940.parse");
+        var sw = Stopwatch.StartNew();
         var tbl = schemaDatatable?.Clone() ?? BuildDefaultSchema();
 
         void SetNfo(DataRow nr, string key, object? value)
@@ -94,6 +98,10 @@ public class BankingService : IBankingService
         }
 
         tbl.AcceptChanges();
+        sw.Stop();
+        FuchsTelemetry.Mt940RowsParsed.Add(tbl.Rows.Count);
+        act?.SetTag("fuchs.banking.rows", tbl.Rows.Count);
+        _logger.LogInformation("MT940 parsed {Rows} transaction lines in {Ms} ms", tbl.Rows.Count, sw.ElapsedMilliseconds);
         return tbl;
     }
 

Fuchs/Services/FuchsPdfService.cs

@@ -1,4 +1,6 @@
-using Fuchs.intranet;
+using System.Diagnostics;
+using Fuchs.intranet;
+using Fuchs.Observability;
 using Microsoft.Extensions.Logging;
 using MigraDoc.DocumentObjectModel;
 
@@ -6,7 +8,8 @@ namespace Fuchs.Services;
 
 /// <summary>
 /// PDF service implementation. Delegates to <see cref="FuchsPdf"/> static methods
-/// while providing a DI-friendly injectable wrapper.
+/// while providing a DI-friendly injectable wrapper, structured logging and
+/// render-duration metrics.
 /// </summary>
 public class FuchsPdfService : IPdfService
 {
@@ -16,30 +19,94 @@ public class FuchsPdfService : IPdfService
     {
         _logger = logger;
         FuchsPdf.SetLicense();
+        _logger.LogDebug("FuchsPdfService initialised (PDF license applied).");
     }
 
     public Task<Document> WriteLetterAsync(FuchsPdf.FdsTextBlocks textBlocks, bool draft)
     {
+        _logger.LogDebug("WriteLetterAsync draft={Draft}", draft);
         return FuchsPdf.WriteLetter(textBlocks, draft, FuchsPdf.DeCulture);
     }
 
     public void ApplyInvoice(Document doc, FuchsPdf.FdsTextBlocks textBlocks,
         FdsInvoiceData invoice, bool draft = false)
     {
+        _logger.LogDebug("ApplyInvoice id={Id} draft={Draft}", invoice.Id, draft);
         FuchsPdf.ApplyInvoice(doc, textBlocks, invoice, draft);
     }
 
     public void ApplyReminder(Document doc, FuchsPdf.FdsTextBlocks textBlocks,
         FdsReminderData reminder, bool draft = false)
     {
+        _logger.LogDebug("ApplyReminder id={Id} draft={Draft}", reminder.Id, draft);
         FuchsPdf.ApplyReminder(doc, textBlocks, reminder, draft);
     }
 
-    public byte[] DocToPdfBytes(Document doc) => FuchsPdf.DocToPdfBytes(doc);
+    public byte[] DocToPdfBytes(Document doc)
+    {
+        var sw = Stopwatch.StartNew();
+        using var act = FuchsTelemetry.StartActivity("pdf.render");
+        try
+        {
+            byte[] bytes = FuchsPdf.DocToPdfBytes(doc);
+            sw.Stop();
+            FuchsTelemetry.PdfRenderDuration.Record(sw.Elapsed.TotalMilliseconds,
+                new KeyValuePair<string, object?>("operation", "pdf"));
+            act?.SetTag("fuchs.pdf.bytes", bytes.Length);
+            _logger.LogDebug("DocToPdfBytes rendered {Bytes} bytes in {Ms} ms", bytes.Length, sw.ElapsedMilliseconds);
+            return bytes;
+        }
+        catch (Exception ex)
+        {
+            sw.Stop();
+            act?.SetStatus(ActivityStatusCode.Error, ex.Message);
+            _logger.LogError(ex, "DocToPdfBytes failed after {Ms} ms", sw.ElapsedMilliseconds);
+            throw;
+        }
+    }
 
-    public Task<OCORE.pdf._pdf.ImageCollection> DocToImageCollectionAsync(Document doc) =>
-        FuchsPdf.DocToImageCollection(doc);
+    public async Task<OCORE.pdf._pdf.ImageCollection> DocToImageCollectionAsync(Document doc)
+    {
+        var sw = Stopwatch.StartNew();
+        using var act = FuchsTelemetry.StartActivity("pdf.render.images");
+        try
+        {
+            var col = await FuchsPdf.DocToImageCollection(doc);
+            sw.Stop();
+            FuchsTelemetry.PdfRenderDuration.Record(sw.Elapsed.TotalMilliseconds,
+                new KeyValuePair<string, object?>("operation", "images"));
+            act?.SetTag("fuchs.pdf.pages", col.TotalPages);
+            _logger.LogDebug("DocToImageCollectionAsync rendered {Pages} pages in {Ms} ms", col.TotalPages, sw.ElapsedMilliseconds);
+            return col;
+        }
+        catch (Exception ex)
+        {
+            sw.Stop();
+            act?.SetStatus(ActivityStatusCode.Error, ex.Message);
+            _logger.LogError(ex, "DocToImageCollectionAsync failed after {Ms} ms", sw.ElapsedMilliseconds);
+            throw;
+        }
+    }
 
-    public Task<OCORE.pdf._pdf.ImageCollection> BytesToImageCollectionAsync(byte[] pdfBytes) =>
-        FuchsPdf.BytesToImageCollection(pdfBytes);
+    public async Task<OCORE.pdf._pdf.ImageCollection> BytesToImageCollectionAsync(byte[] pdfBytes)
+    {
+        var sw = Stopwatch.StartNew();
+        using var act = FuchsTelemetry.StartActivity("pdf.bytes.images");
+        try
+        {
+            var col = await FuchsPdf.BytesToImageCollection(pdfBytes);
+            sw.Stop();
+            FuchsTelemetry.PdfRenderDuration.Record(sw.Elapsed.TotalMilliseconds,
+                new KeyValuePair<string, object?>("operation", "bytes-images"));
+            _logger.LogDebug("BytesToImageCollectionAsync rendered {Pages} pages in {Ms} ms", col.TotalPages, sw.ElapsedMilliseconds);
+            return col;
+        }
+        catch (Exception ex)
+        {
+            sw.Stop();
+            act?.SetStatus(ActivityStatusCode.Error, ex.Message);
+            _logger.LogError(ex, "BytesToImageCollectionAsync failed after {Ms} ms", sw.ElapsedMilliseconds);
+            throw;
+        }
+    }
 }

Fuchs/Services/FuchsReportService.cs

@@ -1,4 +1,6 @@
+using System.Diagnostics;
 using Fuchs.intranet;
+using Fuchs.Observability;
 using Microsoft.AspNetCore.Mvc;
 using Microsoft.Data.SqlClient;
 using Microsoft.Extensions.Logging;
@@ -69,6 +71,12 @@ public class FuchsReportService : IReportService
         }
         bool ciForce = prms.TryGetValue("cache", out var ca) && ca.ToLower() == "0";
 
+        var sw = Stopwatch.StartNew();
+        using var act = FuchsTelemetry.StartActivity("report.process");
+        act?.SetTag("fuchs.report.fn", tgt);
+        act?.SetTag("fuchs.report.id", report);
+        _logger.LogInformation("Report request fnc={Fnc} report={Report} tgt={Tgt} cache={Cache} user={User}",
+            fnc, report, tgt, ciCache, userAccountId);
         try
         {
             switch (tgt)
@@ -119,9 +127,18 @@ public class FuchsReportService : IReportService
         }
         catch (Exception ex)
         {
+            act?.SetStatus(ActivityStatusCode.Error, ex.Message);
             _logger.LogError(ex, "Report processing failed fnc={Fnc} report={Report} tgt={Tgt}", fnc, report, tgt);
             return new StatusCodeResult(500);
         }
+        finally
+        {
+            sw.Stop();
+            FuchsTelemetry.ReportRenderDuration.Record(sw.Elapsed.TotalMilliseconds,
+                new KeyValuePair<string, object?>("fn", tgt));
+            FuchsTelemetry.ReportsRendered.Add(1, new KeyValuePair<string, object?>("fn", tgt));
+            _logger.LogDebug("Report request completed tgt={Tgt} report={Report} in {Ms} ms", tgt, report, sw.ElapsedMilliseconds);
+        }
     }
 
     private static void ApplyReload(FuchsHtmlPage page, IDictionary<string, string> prms, int ciRefresh)

Fuchs/Services/FuchsWidgetService.cs

@@ -1,4 +1,5 @@
 using Fuchs.intranet;
+using Fuchs.Observability;
 using Microsoft.AspNetCore.Http;
 using Microsoft.AspNetCore.Mvc;
 using Microsoft.Extensions.Logging;
@@ -31,17 +32,24 @@ public class FuchsWidgetService : IWidgetService
     public async Task<IActionResult> GetWidgetAsync(string widgetId, string userAccountId,
         DatabaseSecurity dbSec, HttpRequest request)
     {
+        using var act = FuchsTelemetry.StartActivity("widget.get");
+        act?.SetTag("fuchs.widget.id", widgetId);
+        _logger.LogDebug("GetWidgetAsync widget={WidgetId} user={User}", widgetId, userAccountId);
         try
         {
-            return widgetId.ToLower() switch
+            var result = widgetId.ToLower() switch
             {
                 "my"  => await HandleWidgetMy(userAccountId, dbSec),
                 "one" => await HandleWidgetOne(userAccountId, dbSec, request),
                 _     => await HandleWidgetGeneric(widgetId, userAccountId, dbSec)
             };
+            _logger.LogDebug("GetWidgetAsync widget={WidgetId} result={Result} user={User}",
+                widgetId, result.GetType().Name, userAccountId);
+            return result;
         }
         catch (Exception ex)
         {
+            act?.SetStatus(System.Diagnostics.ActivityStatusCode.Error, ex.Message);
             _logger.LogError(ex, "Widget error for {WidgetId}, user {UserAccountId}", widgetId, userAccountId);
             return new StatusCodeResult(500);
         }

Fuchs/Services/InvoiceService.cs

@@ -1,5 +1,7 @@
 using System.Data;
+using System.Diagnostics;
 using Fuchs.intranet;
+using Fuchs.Observability;
 using Microsoft.Data.SqlClient;
 using Microsoft.Extensions.Logging;
 using MigraDoc.DocumentObjectModel;
@@ -33,8 +35,9 @@ public class InvoiceService : IInvoiceService
 
     public async Task<FdsInvoiceData> LoadInvoiceAsync(string id, string userAccountId, DatabaseSecurity dbSec)
     {
+        _logger.LogDebug("LoadInvoiceAsync id={Id} user={User}", id, userAccountId);
         var inv = new FdsInvoiceData();
-        if (string.IsNullOrEmpty(id)) return inv;
+        if (string.IsNullOrEmpty(id)) { _logger.LogWarning("LoadInvoiceAsync called with empty id (user={User})", userAccountId); return inv; }
 
         var pl = new List<SqlParameter>
         {
@@ -51,13 +54,15 @@ public class InvoiceService : IInvoiceService
 
         inv.InvoiceRegistration = new GenericObjectDictionary(dset.Table("inv").FirstRow.toObjectDictionary());
         inv.IsDraft = inv.InvoiceRegistration.getItem("IsFinal", false) is not true;
+        _logger.LogDebug("LoadInvoiceAsync loaded id={Id} draft={Draft}", inv.Id, inv.IsDraft);
         return inv;
     }
 
     public async Task<FdsInvoiceData> RegisterInvoiceAsync(FdsInvoiceData invoice, bool change, string invId,
         string userAccountId, DatabaseSecurity dbSec)
     {
-        if (invoice.NewValues == null) return invoice;
+        _logger.LogInformation("RegisterInvoiceAsync change={Change} invId={InvId} user={User}", change, invId, userAccountId);
+        if (invoice.NewValues == null) { _logger.LogWarning("RegisterInvoiceAsync: no form values supplied (user={User})", userAccountId); return invoice; }
 
         var pl = new List<SqlParameter> { SQL_VarChar("@authuser", userAccountId) };
         pl.AddRange(invoice.BuildInvoiceParams(change, invId));
@@ -88,11 +93,16 @@ public class InvoiceService : IInvoiceService
             _logger.LogError("RegisterInvoiceAsync sql exception: {Ex}", invdset.Exception);
 
         invoice.InvoiceRegistration = new GenericObjectDictionary(invdset.Table("inv").FirstRow.toObjectDictionary());
+        _logger.LogInformation("RegisterInvoiceAsync registered id={Id} (change={Change})", invoice.Id, change);
         return invoice;
     }
 
     public Document GenerateInvoicePdf(FdsInvoiceData invoice, bool draft)
     {
+        using var act = FuchsTelemetry.StartActivity("invoice.render");
+        act?.SetTag("fuchs.invoice.id", invoice.Id);
+        act?.SetTag("fuchs.invoice.draft", draft);
+        _logger.LogDebug("GenerateInvoicePdf id={Id} draft={Draft}", invoice.Id, draft);
         var reg = invoice.InvoiceRegistration;
         var tb = new FuchsPdf.FdsTextBlocks
         {
@@ -108,6 +118,7 @@ public class InvoiceService : IInvoiceService
         var doc = _pdf.WriteLetterAsync(tb, draft).GetAwaiter().GetResult();
         doc.Info.Title = reg?.getString("InvoiceTitle") ?? "";
         _pdf.ApplyInvoice(doc, tb, invoice, draft);
+        FuchsTelemetry.InvoicesRendered.Add(1, new KeyValuePair<string, object?>("draft", draft));
         return doc;
     }
 

Fuchs/Services/MfrClientFactory.cs

@@ -1,22 +1,28 @@
-using Microsoft.Extensions.Logging;
+using Fuchs.Observability;
+using Microsoft.Extensions.Logging;
 
 namespace Fuchs.Services;
 
 /// <summary>
 /// Factory implementation for <see cref="fds.FdsMfrClient"/>.
-/// Centralizes MFR client creation and supplies logger from DI.
+/// Centralizes MFR client creation, supplies the logger from DI, and counts
+/// client instantiations as a proxy for MFR ERP interactions.
 /// </summary>
 public class MfrClientFactory : IMfrClientFactory
 {
     private readonly ILoggerFactory _loggerFactory;
+    private readonly ILogger<MfrClientFactory> _logger;
 
     public MfrClientFactory(ILoggerFactory loggerFactory)
     {
         _loggerFactory = loggerFactory;
+        _logger = loggerFactory.CreateLogger<MfrClientFactory>();
     }
 
     public fds.FdsMfrClient Create()
     {
+        FuchsTelemetry.MfrCalls.Add(1);
+        _logger.LogDebug("Creating new FdsMfrClient instance.");
         return new fds.FdsMfrClient(_loggerFactory);
     }
 }

Fuchs/Services/ProcessWebComService.cs

@@ -1,6 +1,8 @@
-using System.Net.Http.Headers;
+using System.Diagnostics;
+using System.Net.Http.Headers;
 using System.Text;
 using Fuchs.intranet;
+using Fuchs.Observability;
 using Microsoft.Data.SqlClient;
 using Microsoft.Extensions.Logging;
 using Microsoft.Extensions.Options;
@@ -43,9 +45,13 @@ public class ProcessWebComService : IComService
     public async Task<bool> SendEmailAsync(string reference, string subject, string html,
         string email, string name, Dictionary<string, byte[]>? attachments = null)
     {
+        using var act = FuchsTelemetry.StartActivity("email.send");
+        act?.SetTag("fuchs.email.ref", reference);
         if (!IsValidEmail(email))
         {
             _logger.LogWarning("SendEmailAsync: invalid email address '{Email}' for ref {Reference}", email, reference);
+            FuchsTelemetry.EmailsFailed.Add(1, new KeyValuePair<string, object?>("reason", "invalid-email"));
+            act?.SetStatus(ActivityStatusCode.Error, "invalid-email");
             return false;
         }
 
@@ -57,12 +63,14 @@ public class ProcessWebComService : IComService
                 "[ComService DISABLED] Would send email ref={Reference} subject='{Subject}' to={Email}",
                 reference, subject, email);
             await WriteAuditLogAsync(reference, "", "", default, false, ["Service disabled – email not sent"]);
+            FuchsTelemetry.EmailsFailed.Add(1, new KeyValuePair<string, object?>("reason", "disabled"));
             return false;
         }
 
         bool success = false;
         string messageId = "";
         var errors = new List<string>();
+        var sw = Stopwatch.StartNew();
 
         try
         {
@@ -105,9 +113,18 @@ public class ProcessWebComService : IComService
         catch (Exception ex)
         {
             errors.Add("Beim Versenden ist ein Fehler aufgetreten.");
+            act?.SetStatus(ActivityStatusCode.Error, ex.Message);
             _logger.LogError(ex, "SendEmailAsync failed for {Reference}", reference);
         }
 
+        sw.Stop();
+        FuchsTelemetry.EmailSendDuration.Record(sw.Elapsed.TotalMilliseconds,
+            new KeyValuePair<string, object?>("success", success));
+        if (success) FuchsTelemetry.EmailsSent.Add(1);
+        else         FuchsTelemetry.EmailsFailed.Add(1, new KeyValuePair<string, object?>("reason", "api-error"));
+        _logger.LogInformation("SendEmailAsync ref={Reference} success={Success} in {Ms} ms",
+            reference, success, sw.ElapsedMilliseconds);
+
         await WriteAuditLogAsync(reference, messageId, "", success ? DateTime.UtcNow : default, success, errors);
         return success;
     }
@@ -138,7 +155,12 @@ public class ProcessWebComService : IComService
             };
 
             var (ok, responseBody) = await PostToApiAsync("push_com", payload);
-            if (ok) return true;
+            if (ok)
+            {
+                FuchsTelemetry.SmsSent.Add(1);
+                _logger.LogInformation("SendSmsAsync sent to {Mobile}", mobile);
+                return true;
+            }
 
             _logger.LogWarning("SendSmsAsync API error for {Mobile}: {Body}", mobile, responseBody);
             return false;

Fuchs/Services/ReminderService.cs

@@ -1,5 +1,7 @@
 using System.Data;
+using System.Diagnostics;
 using Fuchs.intranet;
+using Fuchs.Observability;
 using Microsoft.Data.SqlClient;
 using Microsoft.Extensions.Logging;
 using MigraDoc.DocumentObjectModel;
@@ -33,8 +35,9 @@ public class ReminderService : IReminderService
 
     public async Task<FdsReminderData> LoadReminderAsync(string id, string userAccountId, DatabaseSecurity dbSec)
     {
+        _logger.LogDebug("LoadReminderAsync id={Id} user={User}", id, userAccountId);
         var rem = new FdsReminderData();
-        if (string.IsNullOrEmpty(id)) return rem;
+        if (string.IsNullOrEmpty(id)) { _logger.LogWarning("LoadReminderAsync called with empty id (user={User})", userAccountId); return rem; }
 
         var pl = new List<SqlParameter>
         {
@@ -57,7 +60,8 @@ public class ReminderService : IReminderService
     public async Task<FdsReminderData> RegisterReminderAsync(FdsReminderData reminder, bool change, string remId,
         string userAccountId, DatabaseSecurity dbSec)
     {
-        if (reminder.Rem == null || reminder.Rem.Count == 0) return reminder;
+        _logger.LogInformation("RegisterReminderAsync change={Change} remId={RemId} user={User}", change, remId, userAccountId);
+        if (reminder.Rem == null || reminder.Rem.Count == 0) { _logger.LogWarning("RegisterReminderAsync: no form values supplied (user={User})", userAccountId); return reminder; }
 
         var pl = new List<SqlParameter>
         {
@@ -85,11 +89,16 @@ public class ReminderService : IReminderService
             _logger.LogError("RegisterReminderAsync sql exception: {Ex}", remdset.Exception);
 
         reminder.ReminderRegistration = new GenericObjectDictionary(remdset.Table("rem").FirstRow.toObjectDictionary());
+        _logger.LogInformation("RegisterReminderAsync registered id={Id}", reminder.Id);
         return reminder;
     }
 
     public Document GenerateReminderPdf(FdsReminderData reminder, bool draft)
     {
+        using var act = FuchsTelemetry.StartActivity("reminder.render");
+        act?.SetTag("fuchs.reminder.id", reminder.Id);
+        act?.SetTag("fuchs.reminder.draft", draft);
+        _logger.LogDebug("GenerateReminderPdf id={Id} draft={Draft}", reminder.Id, draft);
         var tb = new FuchsPdf.FdsTextBlocks
         {
             AdminRef        = "",
@@ -112,6 +121,7 @@ public class ReminderService : IReminderService
         var doc = _pdf.WriteLetterAsync(tb, draft).GetAwaiter().GetResult();
         doc.Info.Title = reminder.ReminderTitle;
         _pdf.ApplyReminder(doc, tb, reminder, draft);
+        FuchsTelemetry.RemindersRendered.Add(1, new KeyValuePair<string, object?>("draft", draft));
         return doc;
     }