Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
11 changes: 4 additions & 7 deletions core/src/Microsoft.Teams.Bot.Core/BotApplication.cs
Original file line number Diff line number Diff line change
Expand Up @@ -46,7 +46,7 @@ public BotApplication(ConversationClient conversationClient, UserTokenClient use
MiddleWare = new TurnMiddleware();
_conversationClient = conversationClient;
_userTokenClient = userTokenClient;
logger.LogInformation("Started {ThisType} listener for AppID:{AppId} with SDK version {SdkVersion}", this.GetType().Name, options.AppId, Version);
logger.LogInformationGuarded("Started {ThisType} listener for AppID:{AppId} with SDK version {SdkVersion}", GetType().Name, options.AppId, Version);
}


Expand Down Expand Up @@ -89,16 +89,13 @@ public virtual async Task ProcessAsync(HttpContext httpContext, CancellationToke

CoreActivity activity = await CoreActivity.FromJsonStreamAsync(httpContext.Request.Body, cancellationToken).ConfigureAwait(false) ?? throw new InvalidOperationException("Invalid Activity");

_logger.LogInformation("Activity received: Type={Type} Id={Id} ServiceUrl={ServiceUrl} MSCV={MSCV}",
_logger.LogInformationGuarded("Activity received: Type={Type} Id={Id} ServiceUrl={ServiceUrl} MSCV={MSCV}",
activity.Type,
activity.Id,
activity.ServiceUrl,
httpContext.Request.GetCorrelationVector());

if (_logger.IsEnabled(LogLevel.Trace))
{
_logger.LogTrace("Received activity: {Activity}", activity.ToJson());
}
_logger.LogTraceGuarded("Received activity: {Activity}", activity.ToJson());

// TODO: Replace with structured scope data, ensure it works with OpenTelemetry and other logging providers
using (_logger.BeginScope("ActivityType={ActivityType} ActivityId={ActivityId} ServiceUrl={ServiceUrl} MSCV={MSCV}",
Expand All @@ -116,7 +113,7 @@ public virtual async Task ProcessAsync(HttpContext httpContext, CancellationToke
}
finally
{
_logger.LogInformation("Finished processing activity: Id={Id}", activity.Id);
_logger.LogInformationGuarded("Finished processing activity: Id={Id}", activity.Id);
}
}
}
Expand Down
32 changes: 16 additions & 16 deletions core/src/Microsoft.Teams.Bot.Core/ConversationClient.cs
Original file line number Diff line number Diff line change
Expand Up @@ -68,11 +68,11 @@ public virtual async Task<SendActivityResponse> SendActivityAsync(CoreActivity a
url += url.Contains('?', StringComparison.Ordinal) ? "&isTargetedActivity=true" : "?isTargetedActivity=true";
}

logger?.LogInformation("Sending activity to {Url}", url);
logger.LogInformationGuarded("Sending activity to {Url}", url);

string body = activity.ToJson();

logger?.LogTrace("Outgoing Activity :\r {Activity}", body);
logger.LogTraceGuarded("Outgoing Activity :\r {Activity}", body);

return (await _botHttpClient.SendAsync<SendActivityResponse>(
HttpMethod.Post,
Expand Down Expand Up @@ -108,7 +108,7 @@ public virtual async Task<UpdateActivityResponse> UpdateActivityAsync(string con

string body = activity.ToJson();

logger.LogTrace("Updating activity at {Url}: {Activity}", url, body);
logger.LogTraceGuarded("Updating activity at {Url}: {Activity}", url, body);

return (await _botHttpClient.SendAsync<UpdateActivityResponse>(
HttpMethod.Put,
Expand Down Expand Up @@ -142,7 +142,7 @@ public virtual async Task<UpdateActivityResponse> UpdateTargetedActivityAsync(st

string body = activity.ToJson();

logger.LogTrace("Updating targeted activity at {Url}: {Activity}", url, body);
logger.LogTraceGuarded("Updating targeted activity at {Url}: {Activity}", url, body);

return (await _botHttpClient.SendAsync<UpdateActivityResponse>(
HttpMethod.Put,
Expand Down Expand Up @@ -205,7 +205,7 @@ public async Task DeleteActivityAsync(string conversationId, string activityId,
url += "?isTargetedActivity=true";
}

logger.LogTrace("Deleting activity at {Url}", url);
logger.LogTraceGuarded("Deleting activity at {Url}", url);

await _botHttpClient.SendAsync(
HttpMethod.Delete,
Expand Down Expand Up @@ -258,7 +258,7 @@ public virtual async Task<IList<ConversationAccount>> GetConversationMembersAsyn

string url = $"{serviceUrl.ToString().TrimEnd('/')}/v3/conversations/{Uri.EscapeDataString(conversationId)}/members";

logger.LogTrace("Getting conversation members from {Url}", url);
logger.LogTraceGuarded("Getting conversation members from {Url}", url);

return (await _botHttpClient.SendAsync<IList<ConversationAccount>>(
HttpMethod.Get,
Expand Down Expand Up @@ -292,7 +292,7 @@ public virtual async Task<T> GetConversationMemberAsync<T>(string conversationId

string url = $"{serviceUrl.ToString().TrimEnd('/')}/v3/conversations/{Uri.EscapeDataString(conversationId)}/members/{Uri.EscapeDataString(userId)}";

logger.LogTrace("Getting conversation members from {Url}", url);
logger.LogTraceGuarded("Getting conversation member from {Url}", url);

return (await _botHttpClient.SendAsync<T>(
HttpMethod.Get,
Expand Down Expand Up @@ -322,7 +322,7 @@ public virtual async Task<GetConversationsResponse> GetConversationsAsync(Uri se
url += $"?continuationToken={Uri.EscapeDataString(continuationToken)}";
}

logger.LogTrace("Getting conversations from {Url}", url);
logger.LogTraceGuarded("Getting conversations from {Url}", url);

return (await _botHttpClient.SendAsync<GetConversationsResponse>(
HttpMethod.Get,
Expand Down Expand Up @@ -351,7 +351,7 @@ public virtual async Task<IList<ConversationAccount>> GetActivityMembersAsync(st

string url = $"{serviceUrl.ToString().TrimEnd('/')}/v3/conversations/{Uri.EscapeDataString(conversationId)}/activities/{Uri.EscapeDataString(activityId)}/members";

logger.LogTrace("Getting activity members from {Url}", url);
logger.LogTraceGuarded("Getting activity members from {Url}", url);

return (await _botHttpClient.SendAsync<IList<ConversationAccount>>(
HttpMethod.Get,
Expand Down Expand Up @@ -380,7 +380,7 @@ public virtual async Task<CreateConversationResponse> CreateConversationAsync(Co

string paramsJson = JsonSerializer.Serialize(parameters, _jsonSerializerOptions);

logger.LogTrace("Creating conversation at {Url} with parameters: {Parameters}", url, paramsJson);
logger.LogTraceGuarded("Creating conversation at {Url} with parameters: {Parameters}", url, paramsJson);

return (await _botHttpClient.SendAsync<CreateConversationResponse>(
HttpMethod.Post,
Expand Down Expand Up @@ -423,7 +423,7 @@ public virtual async Task<PagedMembersResult> GetConversationPagedMembersAsync(s
url += $"?{string.Join("&", queryParams)}";
}

logger.LogTrace("Getting paged conversation members from {Url}", url);
logger.LogTraceGuarded("Getting paged conversation members from {Url}", url);

return (await _botHttpClient.SendAsync<PagedMembersResult>(
HttpMethod.Get,
Expand Down Expand Up @@ -453,7 +453,7 @@ public virtual async Task DeleteConversationMemberAsync(string conversationId, s

string url = $"{serviceUrl.ToString().TrimEnd('/')}/v3/conversations/{Uri.EscapeDataString(conversationId)}/members/{Uri.EscapeDataString(memberId)}";

logger.LogTrace("Deleting conversation member at {Url}", url);
logger.LogTraceGuarded("Deleting conversation member at {Url}", url);

await _botHttpClient.SendAsync(
HttpMethod.Delete,
Expand Down Expand Up @@ -484,7 +484,7 @@ public virtual async Task<SendConversationHistoryResponse> SendConversationHisto
string url = $"{serviceUrl.ToString().TrimEnd('/')}/v3/conversations/{Uri.EscapeDataString(conversationId)}/activities/history";

string transcriptJson = JsonSerializer.Serialize(transcript, _jsonSerializerOptions);
logger.LogTrace("Sending conversation history to {Url}: {Transcript}", url, transcriptJson);
logger.LogTraceGuarded("Sending conversation history to {Url}: {Transcript}", url, transcriptJson);

return (await _botHttpClient.SendAsync<SendConversationHistoryResponse>(
HttpMethod.Post,
Expand Down Expand Up @@ -515,7 +515,7 @@ public virtual async Task<UploadAttachmentResponse> UploadAttachmentAsync(string
string url = $"{serviceUrl.ToString().TrimEnd('/')}/v3/conversations/{Uri.EscapeDataString(conversationId)}/attachments";

string attachmentDataJson = JsonSerializer.Serialize(attachmentData, _jsonSerializerOptions);
logger.LogTrace("Uploading attachment to {Url}: {AttachmentData}", url, attachmentDataJson);
logger.LogTraceGuarded("Uploading attachment to {Url}: {AttachmentData}", url, attachmentDataJson);

return (await _botHttpClient.SendAsync<UploadAttachmentResponse>(
HttpMethod.Post,
Expand Down Expand Up @@ -546,7 +546,7 @@ public async Task AddReactionAsync(string conversationId, string activityId, str

string url = $"{serviceUrl.ToString().TrimEnd('/')}/v3/conversations/{Uri.EscapeDataString(conversationId)}/activities/{Uri.EscapeDataString(activityId)}/reactions/{Uri.EscapeDataString(reactionType)}";

logger.LogTrace("Adding reaction at {Url}", url);
logger.LogTraceGuarded("Adding reaction at {Url}", url);

await _botHttpClient.SendAsync(
HttpMethod.Put,
Expand Down Expand Up @@ -577,7 +577,7 @@ public async Task DeleteReactionAsync(string conversationId, string activityId,

string url = $"{serviceUrl.ToString().TrimEnd('/')}/v3/conversations/{Uri.EscapeDataString(conversationId)}/activities/{Uri.EscapeDataString(activityId)}/reactions/{Uri.EscapeDataString(reactionType)}";

logger.LogTrace("Deleting reaction at {Url}", url);
logger.LogTraceGuarded("Deleting reaction at {Url}", url);

await _botHttpClient.SendAsync(
HttpMethod.Delete,
Expand Down
8 changes: 1 addition & 7 deletions core/src/Microsoft.Teams.Bot.Core/GlobalSuppressions.cs
Original file line number Diff line number Diff line change
Expand Up @@ -3,12 +3,6 @@

using System.Diagnostics.CodeAnalysis;

[assembly: SuppressMessage("Performance",
"CA1873:Avoid potentially expensive logging",
Justification = "<Pending>",
Scope = "namespaceanddescendants",
Target = "~N:Microsoft.Teams.Bot.Core")]

[assembly: SuppressMessage("Performance",
"CA1848:Use the LoggerMessage delegates",
Justification = "<Pending>",
Expand All @@ -23,6 +17,6 @@

[assembly: SuppressMessage("Usage",
"CA2227:Collection properties should be read only",
Justification = "<Pending>",
Justification = "Required for serialization",
Scope = "namespaceanddescendants",
Target = "~N:Microsoft.Teams.Bot.Core")]
6 changes: 5 additions & 1 deletion core/src/Microsoft.Teams.Bot.Core/Hosting/JwtExtensions.cs
Original file line number Diff line number Diff line change
Expand Up @@ -208,7 +208,11 @@ private static AuthenticationBuilder AddTeamsJwtBearer(this AuthenticationBuilde
{
OnTokenValidated = context =>
{
GetLogger(context.HttpContext, logger).LogDebug("Token validated for scheme: {Scheme}", schemeName);
GetLogger(context.HttpContext, logger);
if (logger?.IsEnabled(LogLevel.Debug) == true)
{
logger?.LogDebug("Token validated for scheme: {Scheme}", schemeName);
}
return Task.CompletedTask;
},
OnForbidden = context =>
Expand Down
3 changes: 2 additions & 1 deletion core/src/Microsoft.Teams.Bot.Core/Http/BotHttpClient.cs
Original file line number Diff line number Diff line change
Expand Up @@ -8,6 +8,7 @@
using System.Text.Json;
using Microsoft.AspNetCore.WebUtilities;
using Microsoft.Extensions.Logging;
using Microsoft.Teams.Bot.Core;
using Microsoft.Teams.Bot.Core.Hosting;

namespace Microsoft.Teams.Bot.Core.Http;
Expand Down Expand Up @@ -45,7 +46,7 @@ public class BotHttpClient(HttpClient httpClient, ILogger? logger = null)

using HttpRequestMessage request = CreateRequest(method, url, body, options);

logger?.LogTrace("Sending HTTP {Method} request to {Url} with body: {Body}", method, url, body);
logger.LogTraceGuarded("Sending HTTP {Method} request to {Url} with body: {Body}", method, url, body);

using HttpResponseMessage response = await httpClient.SendAsync(request, cancellationToken).ConfigureAwait(false);

Expand Down
75 changes: 75 additions & 0 deletions core/src/Microsoft.Teams.Bot.Core/LoggerExtensions.cs
Original file line number Diff line number Diff line change
@@ -0,0 +1,75 @@
// Copyright (c) Microsoft Corporation.
// Licensed under the MIT License.

using Microsoft.Extensions.Logging;

namespace Microsoft.Teams.Bot.Core;

#pragma warning disable CA2254 // Template should be a static expression - by design, these are guarded wrappers
internal static class LoggerExtensions
{
public static void LogInformationGuarded(this ILogger? logger, string message)
{
if (logger?.IsEnabled(LogLevel.Information) == true)
{
logger.LogInformation(message);
}
}

public static void LogInformationGuarded<T0>(this ILogger? logger, string message, T0 arg0)
{
if (logger?.IsEnabled(LogLevel.Information) == true)
{
logger.LogInformation(message, arg0);
}
}

public static void LogInformationGuarded<T0, T1, T2>(this ILogger? logger, string message, T0 arg0, T1 arg1, T2 arg2)
{
if (logger?.IsEnabled(LogLevel.Information) == true)
{
logger.LogInformation(message, arg0, arg1, arg2);
}
}

public static void LogInformationGuarded<T0, T1, T2, T3>(this ILogger? logger, string message, T0 arg0, T1 arg1, T2 arg2, T3 arg3)
{
if (logger?.IsEnabled(LogLevel.Information) == true)
{
logger.LogInformation(message, arg0, arg1, arg2, arg3);
}
}

public static void LogTraceGuarded(this ILogger? logger, string message)
{
if (logger?.IsEnabled(LogLevel.Trace) == true)
{
logger.LogTrace(message);
}
}

public static void LogTraceGuarded<T0>(this ILogger? logger, string message, T0 arg0)
{
if (logger?.IsEnabled(LogLevel.Trace) == true)
{
logger.LogTrace(message, arg0);
}
}

public static void LogTraceGuarded<T0, T1>(this ILogger? logger, string message, T0 arg0, T1 arg1)
{
if (logger?.IsEnabled(LogLevel.Trace) == true)
{
logger.LogTrace(message, arg0, arg1);
}
}

public static void LogTraceGuarded<T0, T1, T2>(this ILogger? logger, string message, T0 arg0, T1 arg1, T2 arg2)
{
if (logger?.IsEnabled(LogLevel.Trace) == true)
{
logger.LogTrace(message, arg0, arg1, arg2);
}
}
}
#pragma warning restore CA2254
19 changes: 13 additions & 6 deletions core/src/Microsoft.Teams.Bot.Core/UserTokenClient.cs
Original file line number Diff line number Diff line change
Expand Up @@ -51,8 +51,8 @@ public virtual async Task<GetTokenStatusResult[]> GetTokenStatusAsync(string use
{
queryParams.Add("include", include);
}
_logger.LogInformationGuarded("Calling API endpoint: {Endpoint}", "api/usertoken/GetTokenStatus");

_logger.LogInformation("Calling API endpoint: {Endpoint}", "api/usertoken/GetTokenStatus");
IList<GetTokenStatusResult>? result = await _botHttpClient.SendAsync<IList<GetTokenStatusResult>>(
HttpMethod.Get,
_apiEndpoint,
Expand Down Expand Up @@ -93,7 +93,8 @@ public virtual async Task<GetTokenStatusResult[]> GetTokenStatusAsync(string use
queryParams.Add("code", code);
}

_logger.LogInformation("Calling API endpoint: {Endpoint}", "api/usertoken/GetToken");
_logger.LogInformationGuarded("Calling API endpoint: {Endpoint}", "api/usertoken/GetToken");

return await _botHttpClient.SendAsync<GetTokenResult>(
HttpMethod.Get,
_apiEndpoint,
Expand Down Expand Up @@ -136,7 +137,9 @@ public virtual async Task<GetSignInResourceResult> GetSignInResource(string user
queryParams.Add("finalRedirect", finalRedirect);
}

_logger.LogInformation("Calling API endpoint: {Endpoint}", "api/botsignin/GetSignInResource");
_logger.LogInformationGuarded("Calling API endpoint: {Endpoint}", "api/botsignin/GetSignInResource");


return (await _botHttpClient.SendAsync<GetSignInResourceResult>(
HttpMethod.Get,
_apiEndpoint,
Expand Down Expand Up @@ -169,7 +172,8 @@ public virtual async Task<GetTokenResult> ExchangeTokenAsync(string userId, stri
token = exchangeToken
};

_logger.LogInformation("Calling API endpoint: {Endpoint}", "api/usertoken/exchange");
_logger.LogInformationGuarded("Calling API endpoint: {Endpoint}", "api/usertoken/exchange");

return (await _botHttpClient.SendAsync<GetTokenResult>(
HttpMethod.Post,
_apiEndpoint,
Expand Down Expand Up @@ -205,7 +209,9 @@ public virtual async Task SignOutUserAsync(string userId, string? connectionName
queryParams.Add("channelId", channelId);
}

_logger.LogInformation("Calling API endpoint: {Endpoint}", "api/usertoken/SignOut");
_logger.LogInformationGuarded("Calling API endpoint: {Endpoint}", "api/usertoken/SignOut");


await _botHttpClient.SendAsync(
HttpMethod.Delete,
_apiEndpoint,
Expand Down Expand Up @@ -235,7 +241,8 @@ public virtual async Task<IDictionary<string, GetTokenResult>> GetAadTokensAsync
resourceUrls = resourceUrls ?? []
};

_logger.LogInformation("Calling API endpoint with POST: {Endpoint}", "api/usertoken/GetAadTokens");
_logger.LogInformationGuarded("Calling API endpoint with POST: {Endpoint}", "api/usertoken/GetAadTokens");

return (await _botHttpClient.SendAsync<Dictionary<string, GetTokenResult>>(
HttpMethod.Post,
_apiEndpoint,
Expand Down
Loading