# Logging and tracing

ARX has no logger of its own and takes no logging package: every call is an activity and a measurement your application
already knows how to collect. This page shows how to log each call through ILogger, how to log the errors you catch,
and how to trace and measure calls with OpenTelemetry.

## What ARX records

Every public operation of every provider (Create, Retrieve, Update, Delete, their Multiple forms, Execute, the server
check) is one activity of the `ARX.SDK` ActivitySource and one measurement of the `ARX.SDK` Meter
(`ArxDiagnostics.SourceName`). A call that makes other calls inside it is counted once.

| What | Value |
|---|---|
| Activity name | The operation and the table: `Create account`, `RetrieveMultiple product` |
| Activity kind | Client |
| Tags | `db.system.name` (the database), `db.operation.name`, `db.collection.name` (the table), `arx.provider` |
| On failure | Status Error, `arx.error.code` (`ARX2002`), and `error.type`: the ARX code, `cancelled` for a cancelled call, or the type of any other exception |
| Metrics | `arx.operation.duration` (seconds) and `arx.operation.errors`, tagged with the database, operation, table and provider, and `error.type` on a failure |

Names are recorded, never the values a call sends or reads, so what ARX records is safe to keep in logs. Without a
listener, a call costs one check.

## Log every call through ILogger

An `ActivityListener` turns those activities into log lines. The "Log every call through ILogger" sample of each
provider has a class, `ArxCallLog`, to copy into your application: it listens to the `ARX.SDK` source and writes one
line per call to the `ILogger` you give it, Information when the call worked and Warning, with its ARX code, when it
failed:

```
Information: ARX Create account took 4.2 ms
Warning: ARX Update account failed with ARX2002 after 1.9 ms
```

Create it once, at startup, with your application's logger (`ILogger<T>` from dependency injection), and keep it for
the application's lifetime: disposing it stops the logging. The lines are structured (`{Call}`, `{Code}`,
`{Milliseconds}`), so a log store can filter and count them.

The samples, one per provider:
[PostgreSQL](https://arx.migslab.com/csharp/postgresql/create/create-advanced-9-log-every-call),
[SQL Server](https://arx.migslab.com/csharp/sql/create/create-advanced-9-log-every-call),
[MySQL](https://arx.migslab.com/csharp/mysql/create/create-advanced-9-log-every-call),
[MongoDB](https://arx.migslab.com/csharp/mongodb/create/create-advanced-6-log-every-call),
[DynamoDB](https://arx.migslab.com/csharp/dynamodb/create/create-advanced-6-log-every-call).

## Choose what to log

One line per call is useful while you develop, and a lot in production, where one request can make several calls.
Common choices:

- **Failures only**: the sample's `logSuccessfulCalls: false`. A call that worked writes nothing; one that failed
  writes its Warning.
- **Successful calls at Debug**: change `LogInformation` to `LogDebug`, and let the log level decide.
- **Slow calls**: write a successful call only when `activity.Duration` is over a threshold you choose.

Counting and timing every call is the metrics' job (below), not the log's.

## Log the errors you catch

Where your code catches an `ArxException`, log it with what it carries: `Code` (`ArxException.FormatCode(code)` gives
`ARX2002 RecordNotFound`), `Category`, `IsTransient`, `EntityName` and `AttributeName` where known, the database's own
code (`SqlState` or `NativeCode`), and the driver's exception as `InnerException`. ARX writes its messages without the
values sent, so `Message` can go to the log as it is. The driver's exception can quote them (MySQL and MongoDB repeat
a duplicate key's value), so log the message and the codes rather than the exception object, whose `ToString()` includes
the inner one:

```csharp
catch (ArxException exception) when (exception.Code == ArxErrorCode.UniqueViolation)
{
    logger.LogError("Renaming account {AccountId} failed: {Code} {NativeCode}, transient: {IsTransient}. {Message}",
        accountId, ArxException.FormatCode(exception.Code), exception.NativeCode, exception.IsTransient, exception.Message);
}
```

Pass the exception itself (`logger.LogError(exception, …)`) only where the values in it may be logged, for example in
development.

What each code means, and which ones to retry: [Errors in practice](errors-in-practice.md).

## Trace and measure with OpenTelemetry

With OpenTelemetry, add the source and the meter; ARX's calls then appear in your traces, under the request that made
them, and in your metrics:

```csharp
builder.Services.AddOpenTelemetry()
    .WithTracing(tracing => tracing.AddSource(ArxDiagnostics.SourceName))
    .WithMetrics(metrics => metrics.AddMeter(ArxDiagnostics.SourceName));
```

The "Set the service up for production" samples read the same activities and metrics with a plain `ActivityListener`
and `MeterListener`, without any package. More on running ARX in production:
[Running in production](running-in-production.md).

## The driver's own logging

Below ARX, each database driver has its own logging and diagnostics: Npgsql, Microsoft.Data.SqlClient, MySqlConnector,
the MongoDB driver and the AWS SDK. They see the statements sent and, in some, the parameter values when you turn that
on. Configure them as their own documentation says, and keep value logging off in production.

## Seeing the SQL ARX runs

ARX has no API that returns its SQL; the driver or the database shows it. Every value is a parameter (`$1`, `@p0`), so a
statement shows placeholders, and the values only where you turn their logging on.

**PostgreSQL**: Npgsql logs each command through `Microsoft.Extensions.Logging`, under the category `Npgsql.Command`, at
Debug level. Turn it on once, before the first connection:

```csharp
using Microsoft.Extensions.Logging;
using Npgsql;

NpgsqlLoggingConfiguration.InitializeLogging(
    LoggerFactory.Create(builder => builder.AddConsole().SetMinimumLevel(LogLevel.Debug)),
    parameterLoggingEnabled: false);   // true shows the values too: never in production
```

A create then logs, for example,
`Executing command: INSERT INTO "account" ("name", "city", "employee_count") VALUES ($1, $2, $3) RETURNING "id"`.
(`AddConsole` is in the `Microsoft.Extensions.Logging.Console` package.)

**SQL Server**: the statements are in the server's plan cache: `SELECT t.text FROM sys.dm_exec_query_stats s CROSS APPLY
sys.dm_exec_sql_text(s.sql_handle) t`, or capture them with an Extended Events session on `sql_batch_completed`.

**MySQL**: `performance_schema` keeps a digest per statement shape:
`SELECT DIGEST_TEXT, COUNT_STAR FROM performance_schema.events_statements_summary_by_digest ORDER BY LAST_SEEN DESC`.

**MongoDB**: the database profiler records the operations: `db.setProfilingLevel(2)`, then `db.system.profile.find()`
(set it back to 0 afterwards).

**DynamoDB**: there is no SQL; ARX sends the AWS API's requests (`PutItem`, `Query`, `TransactWriteItems`) through the
`IAmazonDynamoDB` client you create, so the AWS SDK's own logging shows them.