Skip to content
This repository was archived by the owner on Nov 22, 2018. It is now read-only.

Commit 25dbfaf

Browse files
TratcherTratcher
committed
#189 Reduce noise for load and commit logs.
1 parent 0f71fde commit 25dbfaf

File tree

4 files changed

+392
-25
lines changed

4 files changed

+392
-25
lines changed

‎src/Microsoft.AspNetCore.Session/DistributedSession.cs

+59-17
Original file line numberDiff line numberDiff line change
@@ -198,47 +198,64 @@ private void Load()
198198
}
199199

200200
// This will throw if called directly and a failure occurs. The user is expected to handle the failures.
201-
public async Task LoadAsync(CancellationToken cancellationToken = default(CancellationToken))
201+
public async Task LoadAsync(CancellationToken cancellationToken = default)
202202
{
203-
cancellationToken.ThrowIfCancellationRequested();
204203
if (!_loaded)
205204
{
206205
using (var timeout = new CancellationTokenSource(_ioTimeout))
207206
{
208207
var cts = CancellationTokenSource.CreateLinkedTokenSource(timeout.Token, cancellationToken);
209-
var data = await _cache.GetAsync(_sessionKey, cts.Token);
210-
if (data != null)
208+
try
211209
{
212-
Deserialize(new MemoryStream(data));
210+
cts.Token.ThrowIfCancellationRequested();
211+
var data = await _cache.GetAsync(_sessionKey, cts.Token);
212+
if (data != null)
213+
{
214+
Deserialize(new MemoryStream(data));
215+
}
216+
else if (!_isNewSessionKey)
217+
{
218+
_logger.AccessingExpiredSession(_sessionKey);
219+
}
213220
}
214-
else if (!_isNewSessionKey)
221+
catch (OperationCanceledException oex)
215222
{
216-
_logger.AccessingExpiredSession(_sessionKey);
223+
if (timeout.Token.IsCancellationRequested)
224+
{
225+
_logger.SessionLoadingTimeout();
226+
throw new OperationCanceledException("Timed out loading the session.", oex, timeout.Token);
227+
}
228+
throw;
217229
}
218230
}
219231
_isAvailable = true;
220232
_loaded = true;
221233
}
222234
}
223235

224-
public async Task CommitAsync(CancellationToken cancellationToken = default(CancellationToken))
236+
public async Task CommitAsync(CancellationToken cancellationToken = default)
225237
{
226-
cancellationToken.ThrowIfCancellationRequested();
227238
using (var timeout = new CancellationTokenSource(_ioTimeout))
228239
{
229240
var cts = CancellationTokenSource.CreateLinkedTokenSource(timeout.Token, cancellationToken);
230241
if (_isModified)
231242
{
232243
if (_logger.IsEnabled(LogLevel.Information))
233244
{
245+
// This operation is only so we can log if the session already existed.
246+
// Log and ignore failures.
234247
try
235248
{
249+
cts.Token.ThrowIfCancellationRequested();
236250
var data = await _cache.GetAsync(_sessionKey, cts.Token);
237251
if (data == null)
238252
{
239253
_logger.SessionStarted(_sessionKey, Id);
240254
}
241255
}
256+
catch (OperationCanceledException)
257+
{
258+
}
242259
catch (Exception exception)
243260
{
244261
_logger.SessionCacheReadException(_sessionKey, exception);
@@ -248,17 +265,42 @@ private void Load()
248265
var stream = new MemoryStream();
249266
Serialize(stream);
250267

251-
await _cache.SetAsync(
252-
_sessionKey,
253-
stream.ToArray(),
254-
new DistributedCacheEntryOptions().SetSlidingExpiration(_idleTimeout),
255-
cts.Token);
256-
_isModified = false;
257-
_logger.SessionStored(_sessionKey, Id, _store.Count);
268+
try
269+
{
270+
cts.Token.ThrowIfCancellationRequested();
271+
await _cache.SetAsync(
272+
_sessionKey,
273+
stream.ToArray(),
274+
new DistributedCacheEntryOptions().SetSlidingExpiration(_idleTimeout),
275+
cts.Token);
276+
_isModified = false;
277+
_logger.SessionStored(_sessionKey, Id, _store.Count);
278+
}
279+
catch (OperationCanceledException oex)
280+
{
281+
if (timeout.Token.IsCancellationRequested)
282+
{
283+
_logger.SessionCommitTimeout();
284+
throw new OperationCanceledException("Timed out committing the session.", oex, timeout.Token);
285+
}
286+
throw;
287+
}
258288
}
259289
else
260290
{
261-
await _cache.RefreshAsync(_sessionKey, cts.Token);
291+
try
292+
{
293+
await _cache.RefreshAsync(_sessionKey, cts.Token);
294+
}
295+
catch (OperationCanceledException oex)
296+
{
297+
if (timeout.Token.IsCancellationRequested)
298+
{
299+
_logger.SessionRefreshTimeout();
300+
throw new OperationCanceledException("Timed out refreshing the session.", oex, timeout.Token);
301+
}
302+
throw;
303+
}
262304
}
263305
}
264306
}

‎src/Microsoft.AspNetCore.Session/LoggingExtensions.cs

+51-1
Original file line numberDiff line numberDiff line change
@@ -14,6 +14,11 @@ internal static class LoggingExtensions
1414
private static Action<ILogger, string, string, int, Exception> _sessionStored;
1515
private static Action<ILogger, string, Exception> _sessionCacheReadException;
1616
private static Action<ILogger, Exception> _errorUnprotectingCookie;
17+
private static Action<ILogger, Exception> _sessionLoadingTimeout;
18+
private static Action<ILogger, Exception> _sessionCommitTimeout;
19+
private static Action<ILogger, Exception> _sessionCommitCanceled;
20+
private static Action<ILogger, Exception> _sessionRefreshTimeout;
21+
private static Action<ILogger, Exception> _sessionRefreshCanceled;
1722

1823
static LoggingExtensions()
1924
{
@@ -23,7 +28,7 @@ static LoggingExtensions()
2328
formatString: "Error closing the session.");
2429
_accessingExpiredSession = LoggerMessage.Define<string>(
2530
eventId: 2,
26-
logLevel: LogLevel.Warning,
31+
logLevel: LogLevel.Information,
2732
formatString: "Accessing expired session, Key:{sessionKey}");
2833
_sessionStarted = LoggerMessage.Define<string, string>(
2934
eventId: 3,
@@ -45,6 +50,26 @@ static LoggingExtensions()
4550
eventId: 7,
4651
logLevel: LogLevel.Warning,
4752
formatString: "Error unprotecting the session cookie.");
53+
_sessionLoadingTimeout = LoggerMessage.Define(
54+
eventId: 8,
55+
logLevel: LogLevel.Warning,
56+
formatString: "Loading the session timed out.");
57+
_sessionCommitTimeout = LoggerMessage.Define(
58+
eventId: 10,
59+
logLevel: LogLevel.Warning,
60+
formatString: "Committing the session timed out.");
61+
_sessionCommitCanceled = LoggerMessage.Define(
62+
eventId: 11,
63+
logLevel: LogLevel.Information,
64+
formatString: "Committing the session was canceled.");
65+
_sessionRefreshTimeout = LoggerMessage.Define(
66+
eventId: 12,
67+
logLevel: LogLevel.Warning,
68+
formatString: "Refreshing the session timed out.");
69+
_sessionRefreshCanceled = LoggerMessage.Define(
70+
eventId: 13,
71+
logLevel: LogLevel.Information,
72+
formatString: "Refreshing the session was canceled.");
4873
}
4974

5075
public static void ErrorClosingTheSession(this ILogger logger, Exception exception)
@@ -81,5 +106,30 @@ public static void ErrorUnprotectingSessionCookie(this ILogger logger, Exception
81106
{
82107
_errorUnprotectingCookie(logger, exception);
83108
}
109+
110+
public static void SessionLoadingTimeout(this ILogger logger)
111+
{
112+
_sessionLoadingTimeout(logger, null);
113+
}
114+
115+
public static void SessionCommitTimeout(this ILogger logger)
116+
{
117+
_sessionCommitTimeout(logger, null);
118+
}
119+
120+
public static void SessionCommitCanceled(this ILogger logger)
121+
{
122+
_sessionCommitCanceled(logger, null);
123+
}
124+
125+
public static void SessionRefreshTimeout(this ILogger logger)
126+
{
127+
_sessionRefreshTimeout(logger, null);
128+
}
129+
130+
public static void SessionRefreshCanceled(this ILogger logger)
131+
{
132+
_sessionRefreshCanceled(logger, null);
133+
}
84134
}
85135
}

‎src/Microsoft.AspNetCore.Session/SessionMiddleware.cs

+4
Original file line numberDiff line numberDiff line change
@@ -116,6 +116,10 @@ public async Task Invoke(HttpContext context)
116116
{
117117
await feature.Session.CommitAsync(context.RequestAborted);
118118
}
119+
catch (OperationCanceledException)
120+
{
121+
_logger.SessionCommitCanceled();
122+
}
119123
catch (Exception ex)
120124
{
121125
_logger.ErrorClosingTheSession(ex);

0 commit comments

Comments
 (0)