TCIS.Logging 1.0.8-rc.7

TCIS.Logging

The core library providing foundational abstractions and infrastructure for the Logging system across all TCIS applications.

🌟 Overview

TCIS.Logging serves as the standard logging framework, integrated with IWorkContext to capture user and trace information, while utilizing a Channel mechanism for high-performance, asynchronous (non-blocking) logging.

📦 Installation

Install the package via NuGet or .NET CLI:

dotnet add package TCIS.Logging

⚙️ Configuration (appsettings.json)

You can configure the queue limit for the Background Logging Process:

{
  "TLogSettings": {
    "MaxQueueSize": 10000,
    "SiteCode": "HP9"
  }
}

SiteCode (tuỳ chọn) là nhãn application.site_code dự phòng cho bản ghi không có WorkContext — consumer Kafka/Wolverine, hosted service, log của framework. Nó không nạp vào WorkContext và không ảnh hưởng cách ly dữ liệu; WorkContext.Tenant.SiteCode luôn thắng khi có giá trị. Pod chạy nhiều site thì không đặt. Biến môi trường tương ứng: TLogSettings__SiteCode.

Giới hạn dung lượng data.parameters / data.result

{
  "TLogSettings": {
    "ParameterSize": 2048,
    "ResponseSize": 1000
  }
}

Hai ngưỡng này độc lập nhau; hạ ParameterSize không ảnh hưởng ResponseSize.

Chỉ ghi một số field của data.result (whitelist)

Mặc định data.result ghi cả đối tượng trả về. Muốn chỉ giữ vài field:

{
  "TLogSettings": {
    "ResultIncludeFields": ["id", "code", "cd"],
    "ResultIncludeFieldsByMethod": {
      "OrderService": ["id", "status"],
      "OrderService.Get": ["id"],
      "Repo`1.Get": ["*"]
    },
    "ResultFilterMaxItems": 1000
  }
}

Quy tắc khớp:

• Duyệt vét cạn mọi tầng object/list lồng nhau tới tận lá (object → list → object → list…), với N phần tử bất kỳ; không dừng ở tầng 1 hay ở phần tử đầu.
• Tên field so qua chuẩn hoá: user_id, userId, UserId tương đương, không phân biệt hoa thường.
• Field khớp được giữ nguyên cả giá trị: nếu nó là object/list thì giữ nguyên cả cây bên trong.
• Field không khớp mà chứa object/list thì đi sâu tiếp; nhánh không còn field nào bị bỏ. Phần tử list không có field nào khớp bị bỏ khỏi list; phần tử scalar trong list bị bỏ.
• Che dữ liệu nhạy cảm luôn thắng: password/token… vẫn thành *** kể cả khi nằm trong field được giữ.
• Lọc chạy trước ResponseSize và trước ResponseSummary (whitelist chạy trước; ResponseSummary.ExcludedFields là blacklist chạy sau, áp trên phần đã giữ). Không còn field nào khớp thì data.result bỏ trống.
• Chỉ áp cho TLogInterceptor (AOP, package TCIS.Logging.Autofac). TLogWriter, ControllerLoggingFilter, TGrpcClientInterceptor/TGrpcServerInterceptor chưa lọc.
• Kết quả được cache theo phương thức của lớp hiện thực lúc gọi lần đầu; đổi cấu hình lúc đang chạy không có hiệu lực với phương thức đã gọi.

Field ra [MASKING_FAILED]

Bước che theo nội dung (JWT, Bearer, email, số điện thoại…) dùng regex có timeout 1 giây đo bằng đồng hồ thật. Khi che một field thất bại, field đó bị thay bằng [MASKING_FAILED] (fail-closed: thà mất giá trị còn hơn lộ dữ liệu). Timeout được thử lại một lần: tiến trình bị treo tạm thời (GC, CPU throttle, thread pool đói) làm cả chuỗi ngắn cũng timeout, lần thử lại sẽ qua; regex thật sự chạy quá lâu sẽ timeout lần nữa và vẫn fail-closed. Gặp [MASKING_FAILED] thì tìm bản ghi WARN [log-record-masker] Mask: masking failed cùng service để xem loại lỗi.

Chẩn đoán treo (LogInvocationStart, SlowCallThreshold)

Log AOP (TLogInterceptor) chỉ ghi khi Proceed() trả về (trong finally). Một lời gọi treo — chờ DB, lock, HTTP không timeout — vì thế không để lại bản ghi nào. Hai tuỳ chọn trong TLogSettings bù chỗ này:

{
  "TLogSettings": {
    "LogInvocationStart": true,
    "InvocationStartLevel": "INFO",
    "SlowCallThreshold": "00:00:30"
  }
}

Cơ chế và giới hạn:

• Một sweeper dùng chung (một Timer, chu kỳ 1 giây, tạo lười) quét các lời gọi đang chạy — độ phân giải ~1 giây, không phải mili giây; không tạo Timer cho từng lời gọi. WARN bắn đúng một lần, không lặp theo bội số ngưỡng.
• Ngữ cảnh (WorkContext, Activity) được chụp trên thread gọi lúc bắt đầu nên WARN vẫn mang đúng transaction/user dù sweeper chạy ở thread khác. WARN không bắn sau khi hàm đã hoàn tất; hàm xong trước ngưỡng thì không có WARN.
• Hàm chạy lâu một cách hợp lệ (job, export) sẽ sinh WARN: loại chúng bằng ExcludeClasses/ExcludeMethods (đường bị loại không đăng ký sổ đang chạy). Khuyến nghị bật SlowCallThreshold cho API đồng bộ, không bật toàn cục mù quáng.
• Cách đọc log: thấy WARN ... still running mà chưa có bản ghi kết thúc cùng event.id ⇒ lời gọi đã vào hàm và đang treo. Phạm vi: cả ba đường — hàm đồng bộ, Task, Task<T>; chỉ TLogInterceptor (controller/gRPC không có).
• Giới hạn khi thread pool cạn: sweeper chạy trên thread pool. Đúng lúc thread pool bị bão hoà (thường đi kèm treo) callback có thể bị trễ hoặc không chạy, khi đó không có WARN — không có WARN chưa chứng minh là không treo.
• event.id dùng chung cho started/WARN/kết thúc. Nếu pipeline phía sau (Filebeat/Logstash/ES ingest) đặt _id hoặc dedupe theo event.id, bản ghi kết thúc sẽ đè bản ghi treo. Thư viện không dùng event.id làm khoá chống trùng (dùng RecordId riêng cho spool/biên nhận). Đã kiểm trên Kibana UAT ngày 21/10/2026 (data view tcis-logs*, gồm các service eBerth): _id khác event.id ở mọi bản ghi lấy mẫu, nên ở đó không bị đè. Kết quả này phụ thuộc cấu hình pipeline của từng môi trường — môi trường khác (production, cụm khác) thì kiểm lại bằng cách so _id với event.id của một bản ghi trong Discover (tab JSON), hoặc bật thử một service rồi tìm theo event.id: thấy 2 bản ghi (started + kết thúc) là không bị đè.

Điều tra nhanh một service nghi bị treo ở Proceed()

Cấu hình đọc lúc khởi động (IOptions): đổi xong phải restart service đó. Mỗi service có appsettings riêng nên chỉ bật cho service đang nghi ngờ.

{
  "TLogSettings": {
    "SlowCallThreshold": "00:00:10"
  }
}

1. Bước 1 — chỉ cần SlowCallThreshold (ghi WARN nên không phải hạ min level, chi phí thấp). Thấy WARN ... still running mà chưa có bản ghi kết thúc cùng event.id ⇒ lời gọi đã vào hàm và đang treo; kết luận "API chưa được gọi" là sai. Hàm chạy lâu hợp lệ gây ồn thì thêm vào ExcludeMethods/ExcludeClasses.
2. Bước 2 — nếu cần biết mọi lời gọi có vào hàm hay không, thêm "LogInvocationStart": true và "InvocationStartLevel": "INFO" (hoặc giữ DEBUG và hạ min level bằng Dynamic Log Level). Nặng hơn: mỗi lời gọi được log thêm một bản ghi, chỉ bật trong lúc điều tra rồi tắt.
3. Điều tra xong: bỏ hai khoá trên và restart.

🚀 Usage

In Program.cs, add the Logging service to the DI container:

using TCIS.Logging.Extensions;

var builder = WebApplication.CreateBuilder(args);

// Method 1: Read from IConfiguration (default section: "TLogSettings")
builder.Services.AddTLogging(builder.Configuration);

// Method 2: Configure via Action
builder.Services.AddTLogging(options => 
{
    options.MaxQueueSize = 5000;
});

// (Optional) Add Console Sink to display formatted logs in Development
if (builder.Environment.IsDevelopment())
{
    builder.Services.AddTCISConsoleSink();
}

💡 Basic Example

Use ILogWriter (do not use ILogger directly from Microsoft Logging to comply with TCIS rules) in your services:

using TCIS.Logging.Abstractions.Abstractions;

public class MyService
{
    private readonly ILogWriter _logger;
    private const string Provider = "my-service";

    public MyService(ILogWriter logger)
    {
        _logger = logger;
    }

    public async Task DoWorkAsync()
    {
        _logger.LogInformation(
            $"[{Provider}] DoWorkAsync: Processing data...", 
            nameof(DoWorkAsync), 
            new { Step = 1, Data = "Sample" }
        );
    }
}

Gửi log về Log Collector

AddTLogCollector (namespace TCIS.Logging.Extensions) thêm hai thành phần, độc lập với nhau:

1. Outbox (CollectorOutboxSink) — mỗi bản ghi (mọi level) được ghi một dòng NDJSON xuống đĩa; đây là ranh giới bền.
2. Shipper (CollectorShipper, hosted service) — đọc outbox theo lô và POST {Endpoint}/api/logs/{TenantId}/{Group}/batch với header X-Client-Id, X-Client-Secret (URL phân biệt hoa thường). Không chạy trên UI/request thread.

services.AddTLogCollector(configuration);                       // section "LogCollector"
services.AddTLogCollector(o => { o.Endpoint = new Uri("https://logcollector.example/"); /* ... */ });

{
  "LogCollector": {
    "Endpoint": "https://logcollector.example/",
    "TenantId": "<tenant-id>",
    "Group": "<group>",
    "ClientId": "<client-id>",
    "ClientSecret": "<client-secret>"
  }
}

Giảm tải collector khi nhiều máy cùng gửi

Collector có hàng đợi bounded (đầy ⇒ 429). Ba cơ chế ở shipper giảm số request mà không đổi thứ tự, checkpoint theo byte-offset hay at-least-once:

• Gom lô (BatchLinger, MinBatchItems). Máy ít log không còn POST 1–2 bản ghi mỗi 2 s: sau khi outbox đã gửi hết, lần POST kế tiếp chỉ xảy ra khi bản ghi chờ đầu tiên đã đợi đủ BatchLinger, hoặc đủ MinBatchItems bản ghi, hoặc byte chờ đạt 80 % MaxBatchBytes. Số liệu "chờ bao lâu / bao nhiêu" do outbox đếm lúc ghi (chính xác cho bản ghi của process hiện tại; segment của process/phiên khác trong cùng thư mục được nhặt bằng một lần đọc outbox mỗi BatchLinger). Backlog có sẵn lúc khởi động (phiên trước, sau sự cố) gửi ngay.
• ERROR/FATAL là khẩn. Có bản ghi ERROR/FATAL được ghi vào outbox (qua ILogWriter hay ILogger/Serilog) ⇒ POST trong ~2 s như trước; lô gồm cả các bản ghi đứng trước nó (thứ tự outbox giữ nguyên).
• Dừng host / crash bỏ qua gom lô. Host dừng thì shipper gửi nốt ngay trong ShutdownSendBudget, không chờ linger, không giãn nhịp (chi tiết ở "Dừng host" dưới). Đường crash đồng bộ chỉ đưa bản ghi xuống đĩa (fsync); bản ghi FATAL là khẩn nên shipper gửi ngay nếu process còn sống, nếu không thì gửi ngay ở lần khởi động sau (backlog).
• Giãn nhịp xả backlog (MinBatchInterval). Sau một lô 202 mà outbox vẫn còn, shipper chờ MinBatchInterval rồi mới claim lô kế tiếp — sau sự cố, cả đội máy xả backlog lô 1 000 bản ghi không còn bắn liên tục. Với {siteCode}, các đoạn khác đích trong cùng một lô đã claim vẫn gửi liền; chỉ giãn giữa các lần claim.
• Retry-After. Phản hồi đang đi backoff (429, 503, 5xx, 202 từ chối một phần…) có Retry-After (số giây hoặc HTTP-date) ⇒ chờ max(backoff lũy thừa, Retry-After × (1 + 0–20 %)) — jitter chỉ lệch lên để không thử lại sớm hơn yêu cầu mà cả đội vẫn không dồn về một mốc; phần Retry-After kẹp trần 30 phút. Giá trị hỏng/âm/đã qua ⇒ backoff thường. Mỗi lần có Retry-After để lại một dòng chẩn đoán shipper (không có secret).

Dừng host: gửi nốt outbox

Shipper là hosted service: khi host dừng (generic host / ASP.NET Core / worker, IIS qua TLoggingHost.RunFramework, desktop qua Dispose), StopAsync của nó:

1. dừng vòng lặp nền;
2. chờ pipeline xả vào outbox mọi bản ghi đã vào hàng đợi tới lúc đó (vd. ghi trong ApplicationStopping) — tối đa nửa ngân sách. Host dừng hosted service theo thứ tự ngược đăng ký; processor của TCIS.Logging thường dừng sau shipper (adapter ASP.NET Core và host IIS/desktop luôn đặt nó đầu danh sách), nên lúc shipper dừng hàng đợi có thể vẫn còn bản ghi;
3. gửi nốt phần còn lại của outbox trong ngân sách còn lại, bỏ qua BatchLinger/MinBatchInterval.

Tổng thời gian ≤ ShutdownSendBudget và dừng ngay khi host hết ShutdownTimeout (token của host bị huỷ); không bao giờ ném. Chưa cấu hình gửi, hoặc đang bị chặn (401/403, Retry-After) ⇒ không chờ, không gửi. Collector chết/treo ⇒ trả về trong ngân sách. Phần chưa gửi nằm yên trên đĩa, gửi ở lần chạy sau, kèm một dòng chẩn đoán [CollectorShipper] Stop: ….

Giới hạn: bản ghi sinh sau lúc shipper dừng — log lúc dừng của hosted service dừng sau nó (đăng ký trước nó), request ASP.NET Core còn đang xử lý khi shipper đã dừng, dòng "stopped" của chính processor — nằm lại outbox cho lần chạy sau. Host desktop gửi thêm một lần sau khi mọi hosted service đã dừng (chung ngân sách); generic host/IIS thì không. Muốn log lúc dừng của hosted service app cũng được gửi nốt: đăng ký theo thứ tự AddTLogging → AddTLogCollector → AddHostedService của app (IIS: gọi AddTLogCollector trong callback của RunFramework là đã đúng thứ tự này). Container / pod có ổ tạm (outbox mất khi xoá container): đặt OutboxDirectory lên volume bền, hoặc giảm BatchLinger (vd. 00:00:02) để lượng bản ghi đang gom lô lúc dừng nhỏ.

Phía gateway (Kong trước collector), nên bật thêm plugin rate-limiting theo consumer (mỗi client collector một consumer) trả 429 kèm Retry-After: một máy hỏng/vòng lặp log không chiếm hết hàng đợi collector của cả đội, còn shipper tự lùi đúng thời gian gateway yêu cầu.

Đích theo site của từng bản ghi — {siteCode}

TenantId và Group nhận placeholder {siteCode} (không phân biệt hoa thường; toàn bộ hoặc một phần giá trị, vd "desktop-{siteCode}"). Ví dụ client collector riêng của TTOS — POST {Endpoint}/api/logs/ttos/{siteCode}/batch:

"LogCollector": { "Endpoint": "http://collector-host", "TenantId": "ttos", "Group": "{siteCode}", "ClientId": "ttos", "ClientSecret": "" }

(http:// cần thêm "AllowInsecureHttp": true; secret không bao giờ ghi vào tài liệu/repo.)

• Giá trị thay = custom.application.site_code của chính bản ghi trong outbox (bản ghi có thể nằm từ phiên trước, nên không dùng WorkContext lúc gửi). Bản ghi không có site / rỗng ⇒ TLogSettings:SiteCode hiện hành ⇒ "unknown". Ký tự không hợp lệ trên URL được escape (Uri.EscapeDataString). Collector so khớp tenant/group phân biệt hoa thường.
• Một lô HTTP chỉ chứa các bản ghi liên tiếp cùng đích tính từ checkpoint; gặp bản ghi đích khác thì đoạn kết thúc, đoạn sau gửi đích mới — không sắp xếp lại, không bỏ qua nên thứ tự và at-least-once giữ nguyên. Site xen kẽ ⇒ lô nhỏ hơn.
• Placeholder khác ({foo}) hoặc ngoặc nhọn lẻ ⇒ CONFIG_LOG_COLLECTOR_PLACEHOLDER, shipper chờ tới khi sửa.
• Không có placeholder ⇒ hành vi cũ, một URL tĩnh.
• Collector trả 403 khi client đã xác thực nhưng tenant/group không có trong Tenants hoặc Clients:Allowed của nó ⇒ một WARN SEC_LOG_COLLECTOR_DESTINATION_DENIED nêu đích (vd 'ttos/HP9'), một lần cho mỗi đích. Gửi dừng toàn bộ AuthFailureRetry rồi thử lại (bản ghi đích khác phía sau cũng chờ — không bỏ, không chuyển đi); cấp quyền đích đó phía collector là gửi tiếp. Mỗi site TTOS có thể chọn phải có trong Tenants/Allowed của client.

Cấu hình có thể đến muộn: ICollectorConfiguration.Configure(o => …) (lấy từ DI) đè lên section LogCollector; app WinForms dùng TLog.ConfigureCollector (cùng đường này). ICollectorShipperStatus (Sent, Dropped, LastStatusCode, AuthBlocked, ClockSkewMs, Configured) cho chẩn đoán.

Đảm bảo và đánh đổi cần biết:

• At-least-once. Checkpoint chỉ tiến sau khi collector xác nhận ⇒ lỗi giữa chừng có thể gửi lặp, không mất.
• Trần outbox tính theo từng process. Nhiều process cùng ghi một thư mục chung có thể cùng vượt trần tạm thời cho tới lần đếm lại kế tiếp; mỗi process chỉ ghi segment của mình, không ghi đè nhau.
• Nhiều writer chung một thư mục outbox chạy đúng trên cả Windows lẫn Linux/container. Writer giữ khoá độc quyền {segment}.writer suốt đời segment; segment còn writer sống không bao giờ bị process/instance khác xoá hay viết lại khi dọn chỗ. Writer crash để lại file khoá không ai giữ ⇒ coi là đã chết, segment được gửi rồi dọn cùng khoá. Segment được gửi cũ trước theo mốc tạo ghi trong tên — outbox-{session}-{seq}.{yyyyMMddTHHmmssfffffffZ}.ndjson — không theo thời gian file của hệ thống (Linux không có birth time tin được); segment tên cũ outbox-{session}-{seq}.ndjson vẫn được gửi.
• Mất điện. Mỗi lần ghi chỉ Flush(false) (đã vào cache hệ điều hành — process sập hay Environment.Exit không mất); fsync chạy định kỳ ≤ 1 s, nên mất điện có thể mất tối đa chừng đó dòng cuối. File log cục bộ giữ bản ghi riêng.
• Throughput bị giới hạn bởi pipeline lõi (~150–200 bản ghi/s mỗi process); hàng đợi hấp thụ đợt tăng đột biến.
• Gửi bị chặn thì có dấu vết trong file log. 401 (sai/thiếu credentials, client bị khoá) ⇒ một WARN CONFIG_LOG_COLLECTOR_AUTH mỗi đợt bị chặn; 403 (đích không được phép) ⇒ một WARN SEC_LOG_COLLECTOR_DESTINATION_DENIED mỗi đích; không tới được collector liên tục > 10 phút ⇒ một WARN INFRA_LOG_COLLECTOR_UNREACHABLE cho tới khi gửi lại được (cả hai qua pipeline: file cục bộ + outbox). Chi tiết từng lần lỗi chỉ ở chẩn đoán khẩn cấp (stderr; host desktop: logs\diagnostics-*.log).