Skip to content

Commit 823af36

Browse files
StephenHidemStephenHidem
authored
Merge pull request #50 from StephenHidem/45-improve-logging
45 improve logging
2 parents 461be3a + 55af3e4 commit 823af36

37 files changed

+516
-126
lines changed

‎AntPlus.Extensions.Hosting/AntCollection.cs

+8-11
Original file line numberDiff line numberDiff line change
@@ -2,6 +2,7 @@
22
using Microsoft.Extensions.Logging;
33
using Microsoft.Extensions.Options;
44
using SmallEarthTech.AntPlus.DeviceProfiles;
5+
using SmallEarthTech.AntPlus.Extensions.Logging;
56
using SmallEarthTech.AntRadioInterface;
67
using System;
78
using System.Collections.ObjectModel;
@@ -45,7 +46,6 @@ public AntCollection(IServiceProvider services, IAntRadio antRadio, ILogger<AntC
4546
_antRadio = antRadio;
4647
_logger = logger;
4748
_timeout = options.Value;
48-
_logger.LogInformation("Created AntCollection");
4949
}
5050

5151
/// <summary>
@@ -54,6 +54,7 @@ public AntCollection(IServiceProvider services, IAntRadio antRadio, ILogger<AntC
5454
/// <returns>Task of type void</returns>
5555
public async Task StartScanning()
5656
{
57+
_logger.LogMethodEntry();
5758
_channels = await _antRadio.InitializeContinuousScanMode();
5859
_sendMessageChannel = new SendMessageChannel(_channels.Skip(1).ToArray(), _logger);
5960
_channels[0].ChannelResponse += MessageHandler;
@@ -67,6 +68,7 @@ public async Task StartScanning()
6768
/// <param name="e">The ANT response.</param>
6869
private void MessageHandler(object? sender, AntResponse e)
6970
{
71+
_logger.LogAntResponse(LogLevel.Trace, e);
7072
if (e.ChannelId != null && e.Payload != null)
7173
{
7274
// see if the device is in the collection
@@ -87,10 +89,7 @@ private void MessageHandler(object? sender, AntResponse e)
8789
}
8890
else
8991
{
90-
_logger.LogCritical("ChannelId is null. Channel # = {ChannelNum}, Response ID = {Response}, Payload = {Payload}.",
91-
e.ChannelNumber,
92-
(MessageId)e.ResponseId,
93-
e.Payload != null ? BitConverter.ToString(e.Payload) : "Null");
92+
_logger.LogUnhandledAntResponse(e);
9493
}
9594
}
9695

@@ -100,15 +99,14 @@ private void DeviceOffline(object? sender, EventArgs e)
10099
device.DeviceWentOffline -= DeviceOffline;
101100
_ = Remove(device);
102101
}
103-
104102
/// <summary>Adds the specified <see cref="AntDevice"/> to the end of the collection.</summary>
105103
/// <param name="item">The <see cref="AntDevice"/>.</param>
106104
public new void Add(AntDevice item)
107105
{
108106
lock (CollectionLock)
109107
{
108+
_logger.LogAntCollectionChange(item);
110109
base.Add(item);
111-
_logger.LogDebug("{Device} added.", item);
112110
}
113111
}
114112

@@ -119,9 +117,8 @@ private void DeviceOffline(object? sender, EventArgs e)
119117
{
120118
lock (CollectionLock)
121119
{
122-
bool result = base.Remove(item);
123-
_logger.LogDebug("{Device} remove. Result = {Result}", item, result);
124-
return result;
120+
_logger.LogAntCollectionChange(item);
121+
return base.Remove(item);
125122
}
126123
}
127124

@@ -163,9 +160,9 @@ d.ServiceKey is byte key &&
163160
/// </summary>
164161
public void Dispose()
165162
{
163+
_logger.LogMethodEntry();
166164
if (_channels != null)
167165
{
168-
_logger.LogDebug("AntCollection: Dispose");
169166
_channels[0].ChannelResponse -= MessageHandler;
170167
foreach (IAntChannel item in _channels)
171168
{

‎AntPlus.Extensions.Hosting/Hosting.csproj

+2-2
Original file line numberDiff line numberDiff line change
@@ -16,11 +16,11 @@
1616
<EmbedUntrackedSources>true</EmbedUntrackedSources>
1717
<PackageIcon>PackageLogo.png</PackageIcon>
1818
<PackageReadmeFile>readme.md</PackageReadmeFile>
19-
<PackageReleaseNotes>Bugfix: Issue #39. Clears msssage in ANT radio hardware when SendExtAcknowledgedDataAsync timesout.</PackageReleaseNotes>
19+
<PackageReleaseNotes>Updated logging ANT+ logging extensions.</PackageReleaseNotes>
2020
<PackageLicenseExpression>MIT</PackageLicenseExpression>
2121
<IncludeSymbols>True</IncludeSymbols>
2222
<SymbolPackageFormat>snupkg</SymbolPackageFormat>
23-
<AssemblyVersion>1.1.2.0</AssemblyVersion>
23+
<AssemblyVersion>1.2.0.0</AssemblyVersion>
2424
<Version>$(VersionPrefix)$(AssemblyVersion)</Version>
2525
<PackageProjectUrl>https://stephenhidem.github.io/AntPlus</PackageProjectUrl>
2626
<RepositoryUrl>https://github.com/StephenHidem/AntPlus</RepositoryUrl>

‎AntPlus.Extensions.Hosting/SendMessageChannel.cs

+3-4
Original file line numberDiff line numberDiff line change
@@ -1,4 +1,5 @@
11
using Microsoft.Extensions.Logging;
2+
using SmallEarthTech.AntPlus.Extensions.Logging;
23
using SmallEarthTech.AntRadioInterface;
34
using System;
45
using System.Threading;
@@ -85,11 +86,11 @@ public Task<MessagingReturnCode> SendExtAcknowledgedDataAsync(ChannelId channelI
8586
.ContinueWith(antecedent =>
8687
{
8788
int index = antecedent.Result;
88-
_logger.LogDebug("SendExtAcknowledgedDataAsync: Channel index = {ChannelIndex}, channel ID = 0x{ChannelId:X8}, data = {Data}", index, channelId.Id, BitConverter.ToString(data));
89+
_logger.LogSendAcknowledgedMessage(index, channelId.Id, data, null);
8990
_channels[index].SendExtAcknowledgedDataAsync(channelId, data, ackWaitTime)
9091
.ContinueWith(innerAntecedent =>
9192
{
92-
_logger.LogDebug("SendExtAcknowledgedDataAsync: Channel index = {ChannelIndex}, channel ID = 0x{ChannelId:X8}, result = {Result}", index, channelId.Id, innerAntecedent.Result);
93+
_logger.LogSendAcknowledgedMessage(index, channelId.Id, data, innerAntecedent.Result);
9394
lock (_channelLock)
9495
{
9596
// unassign then assign the channel to reset the channel if the result is timeout
@@ -128,10 +129,8 @@ private Task<int> GetAvailableChannelIndexAsync()
128129
// find an available channel
129130
while ((i = Array.FindIndex(_busyFlags, flag => !flag)) == -1)
130131
{
131-
_logger.LogDebug("GetAvailableChannelIndexAsync: All channels are busy");
132132
Monitor.Wait(_channelLock);
133133
}
134-
_logger.LogDebug("GetAvailableChannelIndexAsync: _busyFlags = {BusyFlags}, channel index = {ChannelIndex}", _busyFlags, i);
135134
_busyFlags[i] = true;
136135
}
137136
return i;

‎AntPlus.UnitTests/DeviceProfiles/BicyclePower/CrankTorqueFrequencySensorTests.cs

+8-6
Original file line numberDiff line numberDiff line change
@@ -20,6 +20,7 @@ public CrankTorqueFrequencySensorTests()
2020
_mockRepository = new MockRepository(MockBehavior.Default);
2121
_mockAntChannel = _mockRepository.Create<IAntChannel>();
2222
_mockLogger = _mockRepository.Create<ILogger<CrankTorqueFrequencySensor>>();
23+
_mockLogger.Setup(l => l.IsEnabled(It.IsAny<LogLevel>())).Returns(true);
2324
_crankTorqueFrequencySensor = new CrankTorqueFrequencySensor(new ChannelId(0), _mockAntChannel.Object, _mockLogger.Object, 2000);
2425
}
2526

@@ -134,10 +135,11 @@ public void ParseCTFMessage_SameUpdateEventCountAndTorqueTicks_NoCalculations()
134135
}
135136

136137
[Theory]
137-
[InlineData(new byte[] { 0x01, 0xFF, 0xFF, 0xFF, 0xFF, 0xFF, 0x11, 0x22 }, "Unknown calibration data page")]
138-
[InlineData(new byte[] { 0x01, 0x10, 0xFF, 0xFF, 0xFF, 0xFF, 0x11, 0x22 }, "Unknown CTF ID")]
139-
[InlineData(new byte[] { 0x01, 0x10, 0xAC, 0xFF, 0xFF, 0xFF, 0x11, 0x22 }, "Unknown CTF acknowledged ID")]
140-
public void ParseUnknownCTFDefinedId_LogsWarning(byte[] dataPage, string message)
138+
[InlineData(new byte[] { 0x01, 0xFF, 0xFF, 0xFF, 0xFF, 0xFF, 0x11, 0x22 }, 3001)]
139+
[InlineData(new byte[] { 0x01, 0x10, 0xFF, 0xFF, 0xFF, 0xFF, 0x11, 0x22 }, 3001)]
140+
[InlineData(new byte[] { 0x01, 0x10, 0xAC, 0xFF, 0xFF, 0xFF, 0x11, 0x22 }, 3001)]
141+
[InlineData(new byte[] { 0x02, 0x10, 0xAC, 0xFF, 0xFF, 0xFF, 0x11, 0x22 }, 3000)]
142+
public void ParseUnknownCTFDefinedId_LogsWarning(byte[] dataPage, int eventId)
141143
{
142144
// Arrange
143145

@@ -148,8 +150,8 @@ public void ParseUnknownCTFDefinedId_LogsWarning(byte[] dataPage, string message
148150
_mockLogger.Verify(
149151
m => m.Log(
150152
LogLevel.Warning,
151-
It.IsAny<EventId>(),
152-
It.Is<It.IsAnyType>((v, t) => v.ToString().Contains(message)),
153+
It.Is<EventId>(v => v.Id == eventId),
154+
It.Is<It.IsAnyType>((v, t) => v.ToString().Contains("Unknown data page")),
153155
null,
154156
It.IsAny<Func<It.IsAnyType, Exception, string>>()),
155157
Times.Once);

‎AntPlus/AntDevice.cs

+7-14
Original file line numberDiff line numberDiff line change
@@ -1,6 +1,7 @@
11
using CommunityToolkit.Mvvm.ComponentModel;
22
using Microsoft.Extensions.Logging;
33
using SmallEarthTech.AntPlus.DeviceProfiles;
4+
using SmallEarthTech.AntPlus.Extensions.Logging;
45
using SmallEarthTech.AntRadioInterface;
56
using System;
67
using System.IO;
@@ -74,7 +75,7 @@ protected AntDevice(ChannelId channelId, IAntChannel antChannel, ILogger logger,
7475
_logger = logger;
7576
_deviceTimeout = timeout;
7677
_timeoutTimer = new Timer(TimeoutCallback, null, _deviceTimeout, Timeout.Infinite);
77-
_logger.LogInformation("Created {AntDevice}: deviceTimeout = {Timeout}ms", ToString(), _deviceTimeout);
78+
_logger.LogAntDeviceState(this, _deviceTimeout);
7879
}
7980

8081
/// <summary>
@@ -98,22 +99,21 @@ protected AntDevice(ChannelId channelId, IAntChannel antChannel, ILogger logger,
9899
_deviceTimeout = (int)timeoutOptions.Timeout;
99100
}
100101
_timeoutTimer = new Timer(TimeoutCallback, null, _deviceTimeout, Timeout.Infinite);
101-
_logger.LogInformation("Created {AntDevice}: deviceTimeout = {Timeout}ms", ToString(), _deviceTimeout);
102+
_logger.LogAntDeviceState(this, _deviceTimeout);
102103
}
103104

104105
private void TimeoutCallback(object state)
105106
{
106-
_logger.LogDebug("TimeoutCallback {AntDevice}: deviceTimeout = {Timeout}ms", ToString(), _deviceTimeout);
107-
Dispose();
108107
Offline = true;
108+
Dispose();
109109
DeviceWentOffline?.Invoke(this, new EventArgs());
110110
}
111111

112112
/// <summary>Parses the specified data page.</summary>
113113
/// <param name="dataPage">The received data page.</param>
114114
public virtual void Parse(byte[] dataPage)
115115
{
116-
_logger.LogTrace("Device Number = {DeviceNumber}, Page = {Page}", ChannelId.DeviceNumber, BitConverter.ToString(dataPage));
116+
_logger.LogDataPage(LogLevel.Trace, dataPage);
117117
_ = _timeoutTimer?.Change(_deviceTimeout, Timeout.Infinite);
118118
}
119119

@@ -144,9 +144,7 @@ public async Task<MessagingReturnCode> RequestDataPage<T>(T page, byte descripto
144144
}
145145
else
146146
{
147-
ArgumentException ex = new ArgumentException("Invalid data page requested.", nameof(page));
148-
_logger.LogError(ex, "AntDevice {AntDevice}", ToString());
149-
throw ex;
147+
throw new ArgumentException("Invalid data page requested.", nameof(page));
150148
}
151149
}
152150

@@ -156,18 +154,13 @@ public async Task<MessagingReturnCode> RequestDataPage<T>(T page, byte descripto
156154
public async Task<MessagingReturnCode> SendExtAcknowledgedMessage(byte[] message)
157155
{
158156
MessagingReturnCode ret = await _antChannel.SendExtAcknowledgedDataAsync(ChannelId, message, (uint)_deviceTimeout);
159-
160-
if (ret != MessagingReturnCode.Pass)
161-
{
162-
_logger.LogWarning("{AntDevice}: {Func} failed with error {Error}.", ToString(), "SendExtAcknowledgedDataAsync", ret);
163-
}
164157
return ret;
165158
}
166159

167160
/// <inheritdoc/>
168161
public void Dispose()
169162
{
170-
_logger.LogDebug("Disposed {AntDevice}", ToString());
163+
_logger.LogAntDeviceState(this, _deviceTimeout);
171164
_timeoutTimer?.Dispose();
172165
_timeoutTimer = null;
173166
}

‎AntPlus/AntDeviceCollection.cs

+7-9
Original file line numberDiff line numberDiff line change
@@ -5,6 +5,7 @@
55
using SmallEarthTech.AntPlus.DeviceProfiles.BicyclePower;
66
using SmallEarthTech.AntPlus.DeviceProfiles.BikeSpeedAndCadence;
77
using SmallEarthTech.AntPlus.DeviceProfiles.FitnessEquipment;
8+
using SmallEarthTech.AntPlus.Extensions.Logging;
89
using SmallEarthTech.AntRadioInterface;
910
using System;
1011
using System.Collections.ObjectModel;
@@ -62,7 +63,6 @@ public AntDeviceCollection(IAntRadio antRadio, ILoggerFactory loggerFactory, int
6263
_loggerFactory = loggerFactory ?? NullLoggerFactory.Instance;
6364
_logger = _loggerFactory.CreateLogger<AntDeviceCollection>();
6465
_timeout = antDeviceTimeout;
65-
_logger.LogInformation("Created AntDeviceCollection: antDeviceTimeout = {0}", antDeviceTimeout);
6666
}
6767

6868
/// <summary>
@@ -71,13 +71,15 @@ public AntDeviceCollection(IAntRadio antRadio, ILoggerFactory loggerFactory, int
7171
/// <returns>Task of type void</returns>
7272
public async Task StartScanning()
7373
{
74+
_logger.LogMethodEntry();
7475
_channels = await _antRadio.InitializeContinuousScanMode();
7576
_sendMessageChannel = new SendMessageChannel(_channels.Skip(1).ToArray(), _logger);
7677
_channels[0].ChannelResponse += MessageHandler;
7778
}
7879

7980
private void MessageHandler(object sender, AntResponse e)
8081
{
82+
_logger.LogAntResponse(LogLevel.Trace, e);
8183
if (e.ChannelId != null && e.Payload != null)
8284
{
8385
// see if the device is in the collection
@@ -95,10 +97,7 @@ private void MessageHandler(object sender, AntResponse e)
9597
}
9698
else
9799
{
98-
_logger.LogCritical("ChannelId or Payload is null. Channel # = {ChannelNum}, Response ID = {Response}, Payload = {Payload}.",
99-
e.ChannelNumber,
100-
(MessageId)e.ResponseId,
101-
e.Payload != null ? BitConverter.ToString(e.Payload) : "Null");
100+
_logger.LogUnhandledAntResponse(e);
102101
}
103102
}
104103

@@ -115,8 +114,8 @@ private void DeviceOffline(object sender, EventArgs e)
115114
{
116115
lock (CollectionLock)
117116
{
117+
_logger.LogAntCollectionChange(item);
118118
base.Add(item);
119-
_logger.LogDebug("{Device} added.", item);
120119
}
121120
}
122121

@@ -127,9 +126,8 @@ private void DeviceOffline(object sender, EventArgs e)
127126
{
128127
lock (CollectionLock)
129128
{
130-
bool result = base.Remove(item);
131-
_logger.LogDebug("{Device} remove. Result = {Result}", item, result);
132-
return result;
129+
_logger.LogAntCollectionChange(item);
130+
return base.Remove(item);
133131
}
134132
}
135133

‎AntPlus/AntPlus.csproj

+1-1
Original file line numberDiff line numberDiff line change
@@ -28,7 +28,7 @@
2828
</PropertyGroup>
2929

3030
<PropertyGroup>
31-
<LangVersion>8.0</LangVersion>
31+
<LangVersion>9.0</LangVersion>
3232
<Nullable>enable</Nullable>
3333
</PropertyGroup>
3434

‎AntPlus/CommonDataPages.cs

+14-15
Original file line numberDiff line numberDiff line change
@@ -1,5 +1,6 @@
11
using CommunityToolkit.Mvvm.ComponentModel;
22
using Microsoft.Extensions.Logging;
3+
using SmallEarthTech.AntPlus.Extensions.Logging;
34
using System;
45
using System.Globalization;
56
using System.Linq;
@@ -296,15 +297,17 @@ public enum SubPage
296297
/// <summary>Gets the computed data field 2. Returns NaN if this is not a valid subpage.</summary>
297298
public double ComputedDataField2 { get; }
298299

299-
internal SubfieldDataPage(byte[] dataPage)
300+
internal SubfieldDataPage(byte[] dataPage, ILogger logger)
300301
{
301302
Subpage1 = (SubPage)dataPage[2];
302303
Subpage2 = (SubPage)dataPage[3];
303-
ComputedDataField1 = ParseSubfieldData(Subpage1, BitConverter.ToInt16(dataPage, 4));
304-
ComputedDataField2 = ParseSubfieldData(Subpage2, BitConverter.ToInt16(dataPage, 6));
304+
ComputedDataField1 = double.NaN;
305+
ComputedDataField2 = double.NaN;
306+
ComputedDataField1 = ParseSubfieldData(Subpage1, BitConverter.ToInt16(dataPage, 4), logger);
307+
ComputedDataField2 = ParseSubfieldData(Subpage2, BitConverter.ToInt16(dataPage, 6), logger);
305308
}
306309

307-
private static double ParseSubfieldData(SubPage page, short value)
310+
private double ParseSubfieldData(SubPage page, short value, ILogger logger)
308311
{
309312
double retVal = double.NaN;
310313
switch (page)
@@ -333,8 +336,11 @@ private static double ParseSubfieldData(SubPage page, short value)
333336
case SubPage.MaximumOperatingTemperature:
334337
retVal = value * 0.01;
335338
break;
339+
case SubPage.Invalid:
340+
break;
336341
default:
337-
throw new ArgumentOutOfRangeException(nameof(page), page, "Invalid subpage.");
342+
logger.LogUnknownDataPage<SubPage>((byte)page, Array.Empty<byte>());
343+
break;
338344
}
339345
return retVal;
340346
}
@@ -433,26 +439,19 @@ public void ParseCommonDataPage(byte[] dataPage)
433439
TimeAndDate = new DateTime(2000 + dataPage[7], dataPage[6], dataPage[5] & 0x1F, dataPage[4], dataPage[3], dataPage[2], DateTimeKind.Utc);
434440
break;
435441
case CommonDataPage.SubfieldData:
436-
try
437-
{
438-
SubfieldData = new SubfieldDataPage(dataPage);
439-
}
440-
catch (ArgumentOutOfRangeException ex)
441-
{
442-
_logger.LogError(ex, "{Func}: Invalid subfield data page. Page = {Page}", nameof(ParseCommonDataPage), BitConverter.ToString(dataPage));
443-
}
442+
SubfieldData = new SubfieldDataPage(dataPage, _logger);
444443
break;
445444
case CommonDataPage.MemoryLevel:
446445
MemoryLevel = new MemoryLevelPage(dataPage);
447446
break;
448447
case CommonDataPage.PairedDevices:
449-
_logger.LogWarning("{Func}: Paired devices data page not implemented. Page = {Page}", nameof(ParseCommonDataPage), BitConverter.ToString(dataPage));
448+
_logger.LogIgnoredDataPage<CommonDataPage>(dataPage);
450449
break;
451450
case CommonDataPage.ErrorDescription:
452451
ErrorDescription = new ErrorDescriptionPage(dataPage);
453452
break;
454453
default:
455-
_logger.LogWarning("{Func}: Unknown data page. Page = {Page}", nameof(ParseCommonDataPage), BitConverter.ToString(dataPage));
454+
_logger.LogUnknownDataPage(dataPage);
456455
break;
457456
}
458457
}

0 commit comments

Comments
 (0)