mirror of
https://github.com/OPCFoundation/UA-.NETStandard.git
synced 2026-10-20 00:31:32 +08:00
5a6bbcce1c
## Proposed changes
Request-path log messages in the client and server carry no session
context, which makes
them unusable for diagnosing an application that holds several sessions
at once — a
gateway, an aggregating client, or any host with more than one
connection. Lines like
PUBLISH #4711 SENT
NOTIFICATION RECEIVED: SubId=12, SeqNo=980
Server Call=Publish, Id=8123
interleave across sessions in one log file with nothing to separate
them. The same applies
on the server side to messages that name a monitored item but not its
subscription.
This adds `SessionId` — and `SubscriptionId` where the call site has one
— to the existing
source-generated log messages in the client and server request paths.
Scope is deliberately narrow. The change touches **message templates and
parameter lists
only**:
- no new log statements, no changes to log levels, event ids or event
names
- no public API change: every changed method lives in an `internal
static partial class
…Log` type
- no behavioural change beyond what is logged
11 source files and 1 test, +531/−259. 81 messages gain an id.
| Area | Files |
| --- | --- |
| Client | `Session/Session.cs`,
`Session/Subscription/ClassicSubscriptionEngine.cs`,
`Subscription/Classic/Subscription.cs`,
`Subscription/Classic/MonitoredItem.cs` |
| Server | `Server/StandardServer.cs`,
`Subscription/SubscriptionManager.cs`, `Subscription/Subscription.cs`,
`Subscription/SessionPublishQueue.cs`,
`Subscription/MonitoredItem/MonitoredItem.cs`,
`Subscription/MonitoredItem/QueueHandler/DataChangeQueueHandler.cs`,
`MonitoredItemQueueLog.cs` |
### Points worth a reviewer's attention
**Two legacy-contract events gain a field.**
`ClientEventSubscriptionState`
(`LegacySubscriptionStateId` / `"SubscriptionState"`) and
`ClientEventNotificationReceived`
(`LegacyNotificationReceivedId` / `"NotificationReceived"`) now carry
`SessionId`. Their
event ids, event names and levels are unchanged, and every property
`OpcUaClientCompatibilityLoggingTests` pins is still present — the test
is extended to pin
the new one as well. If you would rather the legacy-shaped events stay
byte-identical, say
so and I will drop the id from those two; the sibling non-legacy
messages at the same call
sites already carry it.
**`DEQUEUE VALUE` gains only `MonitoredItemId`, not a subscription id.**
Its message is
shared between `MonitoredItem` and `DataChangeQueueHandler`, and the
latter holds a
monitored item id but has no subscription or session in scope. The
message previously
identified nothing at all; adding the id it can actually supply seemed
better than
inventing a subscription id at one of the two call sites.
**`QUEUE OVERFLOW` in `SentMessageQueue` is left alone.** That class is
constructed with a
`Func<uint> subscriptionIdProvider` and no session, so there is no
session id to add. The
message already carries `SubId={SubscriptionId}`.
**Server trace states made consistent.** `Subscription.TraceState` has
four cases; `Deleted`
and `Config` already named their session, `Items` and
`Publish`/`Monitor` did not. All four
do now.
**One local added** in `Subscription.RestoreTriggeringAsync`: `ISession
session = Session;`
before the `foreach`. `Session?.SessionId` inside that loop does not
compile — `?.` is a
null test, so it resets the nullable flow state for `Session`, and the
`foreach` back-edge
carries that state to the top of the loop body, which makes the
pre-existing
`Session.SetTriggeringAsync(...)` a CS8602 error. Capturing the
reference once avoids
disturbing existing code and is more useful than `?.` anyway: it reports
the session the
call was actually made on rather than a blank.
**Publish responses are attributed to the session that sent the
request.** In
`ClassicSubscriptionEngine.OnPublishComplete` the added arguments read
the `sessionId`
parameter rather than `m_context.SessionId`, so a response arriving
after a reconnect is
still attributed to the session that produced it.
### Null-safety of the added arguments
Reviewed at every call site:
- Client `Subscription.Session` is `ISession?` and is cleared when a
subscription is removed
from its session, so those arguments are `Session?.SessionId` or read
from the captured
local. `[MemberNotNull]` on `VerifySession()` /
`VerifySessionAndSubscriptionState()`
satisfies the compiler but only describes the moment the guard returns,
not the state
after the following `await` — and several of these arguments sit in
`catch` blocks, where
an NRE would have replaced a `ServiceResultException` and escaped.
- Client `Session` derives `SessionId` from `SessionClient`, which is
non-nullable.
- Server `OperationContext.SessionId` and `Subscription.SessionId`
already return `default`
when there is no session, so those arguments cannot throw.
- Consequence worth knowing: when the server reaps expired
subscriptions,
`Subscription.DeleteAsync` synthesises an `OperationContext` with no
session, so
`SessionId` logs empty on that path. That is expected, not a defect.
## Related Issues
None — no existing issue covers this. Happy to open one for tracking if
you prefer.
## Types of changes
- [x] Enhancement (non-breaking change which adds functionality)
- [ ] Bugfix (non-breaking change which fixes an issue)
- [ ] Test enhancement (non-breaking change to increase test coverage)
- [ ] Breaking change (fix or feature that would cause existing
functionality to not work as expected, requires version increase of
Nuget packages)
- [ ] Documentation Update (if none of the other choices apply)
## Checklist
- [x] I have read the
[CONTRIBUTING](https://github.com/OPCFoundation/UA-.NETStandard/blob/master/CONTRIBUTING.md)
doc.
- [x] I have signed the
[CLA](https://opcfoundation.org/license/cla/ContributorLicenseAgreementv1.0.pdf).
- [x] I ran tests locally with my changes, all passed.
- [ ] I fixed all failing tests in the CI pipelines.
- [ ] I fixed all introduced issues with CodeQL and LGTM.
- [x] I have added necessary documentation (if appropriate).
`Opc.Ua.Client` and `Opc.Ua.Server` build clean for every target
framework
(net472, net48, netstandard2.1, net8.0, net9.0, net10.0) with
`--no-incremental`:
0 errors, 0 warnings under the repository's `TreatWarningsAsErrors`.
Local results, Release/net8.0:
| Suite | Result |
| --- | --- |
| `Opc.Ua.Server.Tests` | 0 failed, 4024 passed, 5 skipped |
| `Opc.Ua.Subscriptions.Classic.Tests` | 0 failed, 32 passed, 0 skipped
|
`Opc.Ua.Client.Tests` and `Opc.Ua.Sessions.Tests` are still running
here; I will post their
results as a comment rather than hold the PR for them.
The test output also confirms the placeholders bind at runtime, which
compilation alone does
not show — for example, from the transfer tests:
[Opc.Ua.Client.ClassicSubscriptionEngine] Publish #31,
Reconnecting=False,
Error: ... (BadNoSubscription), SessionId=ns=3;i=1187191890
No tests are added beyond the compatibility-test extension: the change
alters message
templates and arguments, which the suites otherwise do not assert on.
Happy to add coverage
if you would like a specific message pinned.
The CI and CodeQL boxes are left blank deliberately — per CONTRIBUTING
the pipelines do not
start for outside contributors until a maintainer comments `/azp run`,
so there is nothing
for me to act on yet.
## Further comments
**Why the generated log methods change signature.** With
`[LoggerMessage]` the message
template and its parameters are a single declaration, so adding an id to
a message
necessarily adds a parameter to the generated method. Every one of them
lives in an
`internal static partial class …Log` type, so none of it is public API.
**Scope is the classic session and subscription path.**
`ManagedSession`,
`DefaultSubscriptionEngine`, `MessageProcessor`,
`Subscription/SubscriptionManager.cs` and
`Subscription/MonitoredItemManager.cs` are untouched.
**Placeholders are appended rather than woven into existing message
text** so that log
scrapers matching on the leading part of a message keep working.
---------
Co-authored-by: Claude Opus 5 (1M context) <noreply@anthropic.com>
120 lines
5.2 KiB
C#
120 lines
5.2 KiB
C#
/* ========================================================================
|
|
* Copyright (c) 2005-2026 The OPC Foundation, Inc. All rights reserved.
|
|
*
|
|
* OPC Foundation MIT License 1.00
|
|
*
|
|
* Permission is hereby granted, free of charge, to any person
|
|
* obtaining a copy of this software and associated documentation
|
|
* files (the "Software"), to deal in the Software without
|
|
* restriction, including without limitation the rights to use,
|
|
* copy, modify, merge, publish, distribute, sublicense, and/or sell
|
|
* copies of the Software, and to permit persons to whom the
|
|
* Software is furnished to do so, subject to the following
|
|
* conditions:
|
|
*
|
|
* The above copyright notice and this permission notice shall be
|
|
* included in all copies or substantial portions of the Software.
|
|
* THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND,
|
|
* EXPRESS OR IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES
|
|
* OF MERCHANTABILITY, FITNESS FOR A PARTICULAR PURPOSE AND
|
|
* NONINFRINGEMENT. IN NO EVENT SHALL THE AUTHORS OR COPYRIGHT
|
|
* HOLDERS BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER LIABILITY,
|
|
* WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING
|
|
* FROM, OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR
|
|
* OTHER DEALINGS IN THE SOFTWARE.
|
|
*
|
|
* The complete license agreement can be found here:
|
|
* http://opcfoundation.org/License/MIT/1.00/
|
|
* ======================================================================*/
|
|
|
|
using System;
|
|
using System.Linq;
|
|
using Microsoft.Extensions.Logging;
|
|
using NUnit.Framework;
|
|
using Opc.Ua.Tests;
|
|
|
|
namespace Opc.Ua.Client.Tests
|
|
{
|
|
[TestFixture]
|
|
[Category("Logging")]
|
|
[Parallelizable]
|
|
public sealed class OpcUaClientCompatibilityLoggingTests
|
|
{
|
|
[Test]
|
|
public void ClientEventsRetainLegacyContracts()
|
|
{
|
|
using var provider = new RecordingLoggerProvider();
|
|
ITelemetryContext telemetry = DefaultTelemetry.Create(
|
|
builder => builder
|
|
.SetMinimumLevel(LogLevel.Trace)
|
|
.AddProvider(provider));
|
|
ILogger logger = telemetry.CreateLogger(ClientEventIds.LegacyCategoryName);
|
|
var lastNotificationTime = new DateTime(2026, 7, 19, 8, 30, 0, DateTimeKind.Utc);
|
|
var sessionId = new NodeId(4711u);
|
|
|
|
logger.ClientEventSubscriptionState(
|
|
"Publishing",
|
|
10,
|
|
lastNotificationTime,
|
|
3,
|
|
1000,
|
|
5,
|
|
true,
|
|
8,
|
|
sessionId);
|
|
logger.ClientEventNotification(42, "123");
|
|
logger.ClientEventNotificationReceived(10, 11, sessionId);
|
|
logger.ClientEventPublishStart(12, sessionId);
|
|
logger.ClientEventPublishStop(12, sessionId);
|
|
|
|
RecordedLogRecord subscription = AssertRecord(
|
|
provider,
|
|
ClientEventIds.LegacySubscriptionStateId,
|
|
"SubscriptionState");
|
|
Assert.That(subscription.Properties["Context"], Is.EqualTo("Publishing"));
|
|
Assert.That(subscription.Properties["Id"], Is.EqualTo(10u));
|
|
Assert.That(subscription.Properties, Contains.Key("LastNotificationTime"));
|
|
Assert.That(subscription.Message, Does.Contain("08:30:00"));
|
|
Assert.That(subscription.Properties["CurrentPublishingInterval"], Is.EqualTo(1000d));
|
|
Assert.That(subscription.Properties["CurrentKeepAliveCount"], Is.EqualTo(5u));
|
|
Assert.That(subscription.Properties["CurrentPublishingEnabled"], Is.True);
|
|
Assert.That(
|
|
subscription.Properties["SessionId"]?.ToString(),
|
|
Is.EqualTo(sessionId.ToString()));
|
|
|
|
RecordedLogRecord notification = AssertRecord(
|
|
provider,
|
|
ClientEventIds.LegacyNotificationId,
|
|
"Notification");
|
|
Assert.That(notification.Properties["ClientHandle"], Is.EqualTo(42));
|
|
Assert.That(notification.Properties["Value"], Is.EqualTo("123"));
|
|
|
|
RecordedLogRecord received = AssertRecord(
|
|
provider,
|
|
ClientEventIds.LegacyNotificationReceivedId,
|
|
"NotificationReceived");
|
|
Assert.That(received.Properties["SubscriptionId"], Is.EqualTo(10));
|
|
Assert.That(received.Properties["SequenceNumber"], Is.EqualTo(11));
|
|
Assert.That(
|
|
received.Properties["SessionId"]?.ToString(),
|
|
Is.EqualTo(sessionId.ToString()));
|
|
|
|
AssertRecord(provider, ClientEventIds.LegacyPublishStartId, "PublishStart");
|
|
AssertRecord(provider, ClientEventIds.LegacyPublishStopId, "PublishStop");
|
|
}
|
|
|
|
private static RecordedLogRecord AssertRecord(
|
|
RecordingLoggerProvider provider,
|
|
int eventId,
|
|
string eventName)
|
|
{
|
|
RecordedLogRecord record = provider.Records.Single(candidate =>
|
|
candidate.CategoryName == ClientEventIds.LegacyCategoryName &&
|
|
candidate.EventId.Id == eventId);
|
|
Assert.That(record.EventId.Name, Is.EqualTo(eventName));
|
|
Assert.That(record.LogLevel, Is.EqualTo(LogLevel.Trace));
|
|
return record;
|
|
}
|
|
}
|
|
}
|