// Copyright (c) Microsoft Open Technologies, Inc. All rights reserved. // Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information. // this controls if the logs are written to the console. // they can be reviewed for general content. //#define _Verbose using System; using System.Collections.Generic; using System.Net.Http; using System.Security.Claims; using System.Threading.Tasks; using Microsoft.AspNet.Authentication.Notifications; using Microsoft.AspNet.Authentication.OpenIdConnect; using Microsoft.AspNet.Builder; using Microsoft.AspNet.DataProtection; using Microsoft.AspNet.Http; using Microsoft.AspNet.Http.Authentication; using Microsoft.AspNet.TestHost; using Microsoft.Framework.DependencyInjection; using Microsoft.Framework.Logging; using Microsoft.Framework.OptionsModel; using Microsoft.Framework.WebEncoders; using Microsoft.IdentityModel.Protocols; using Shouldly; using Xunit; namespace Microsoft.AspNet.Authentication.Tests.OpenIdConnect { /// /// These tests are designed to test OpenIdConnectAuthenticationHandler. /// public class OpenIdConnectHandlerTests { static List CompleteLogEntries; static Dictionary LogEntries; static OpenIdConnectHandlerTests() { LogEntries = new Dictionary() { { "OIDCH_0000:", LogLevel.Debug }, { "OIDCH_0001:", LogLevel.Debug }, { "OIDCH_0002:", LogLevel.Information }, { "OIDCH_0003:", LogLevel.Information }, { "OIDCH_0004:", LogLevel.Error }, { "OIDCH_0005:", LogLevel.Error }, { "OIDCH_0006:", LogLevel.Error }, { "OIDCH_0007:", LogLevel.Error }, { "OIDCH_0008:", LogLevel.Debug }, { "OIDCH_0009:", LogLevel.Debug }, { "OIDCH_0010:", LogLevel.Error }, { "OIDCH_0011:", LogLevel.Error }, { "OIDCH_0012:", LogLevel.Debug }, { "OIDCH_0013:", LogLevel.Debug }, { "OIDCH_0014:", LogLevel.Debug }, { "OIDCH_0015:", LogLevel.Debug }, { "OIDCH_0016:", LogLevel.Debug }, { "OIDCH_0017:", LogLevel.Error }, { "OIDCH_0018:", LogLevel.Debug }, { "OIDCH_0019:", LogLevel.Debug }, { "OIDCH_0020:", LogLevel.Debug }, { "OIDCH_0026:", LogLevel.Error }, }; BuildLogEntryList(); } /// /// Builds the complete list of log entries that are available in the runtime. /// private static void BuildLogEntryList() { CompleteLogEntries = new List(); foreach (var entry in LogEntries) { CompleteLogEntries.Add(new LogEntry { State = entry.Key, Level = entry.Value }); } } /// /// Sanity check that logging is filtering, hi / low water marks are checked /// [Fact] public void LoggingLevel() { var logger = new CustomLogger(LogLevel.Debug); logger.IsEnabled(LogLevel.Critical).ShouldBe(true); logger.IsEnabled(LogLevel.Debug).ShouldBe(true); logger.IsEnabled(LogLevel.Error).ShouldBe(true); logger.IsEnabled(LogLevel.Information).ShouldBe(true); logger.IsEnabled(LogLevel.Verbose).ShouldBe(true); logger.IsEnabled(LogLevel.Warning).ShouldBe(true); logger = new CustomLogger(LogLevel.Critical); logger.IsEnabled(LogLevel.Critical).ShouldBe(true); logger.IsEnabled(LogLevel.Debug).ShouldBe(false); logger.IsEnabled(LogLevel.Error).ShouldBe(false); logger.IsEnabled(LogLevel.Information).ShouldBe(false); logger.IsEnabled(LogLevel.Verbose).ShouldBe(false); logger.IsEnabled(LogLevel.Warning).ShouldBe(false); } /// /// Test produces expected logs. /// Each call to 'RunVariation' is configured with an and . /// The list of expected log entries is checked and any errors reported. /// captures the logs so they can be prepared. /// /// [Fact] public async Task AuthenticateCore() { //System.Diagnostics.Debugger.Launch(); var propertiesFormatter = new AuthenticationPropertiesFormater(); var protectedProperties = propertiesFormatter.Protect(new AuthenticationProperties()); var state = OpenIdConnectAuthenticationDefaults.AuthenticationPropertiesKey + "=" + UrlEncoder.Default.UrlEncode(protectedProperties); var code = Guid.NewGuid().ToString(); var message = new OpenIdConnectMessage { Code = code, State = state, }; var errors = new Dictionary>>(); var logsEntriesExpected = new int[] { 0, 1, 7, 14, 15 }; await RunVariation(LogLevel.Debug, message, CodeReceivedHandledOptions, errors, logsEntriesExpected); logsEntriesExpected = new int[] { 0, 1, 7, 14, 16 }; await RunVariation(LogLevel.Debug, message, CodeReceivedSkippedOptions, errors, logsEntriesExpected); logsEntriesExpected = new int[] { 0, 1, 7, 14 }; await RunVariation(LogLevel.Debug, message, DefaultOptions, errors, logsEntriesExpected); // each message below should return before processing the idtoken message.IdToken = "invalid_token"; logsEntriesExpected = new int[] { 0, 1, 2 }; await RunVariation(LogLevel.Debug, message, MessageReceivedHandledOptions, errors, logsEntriesExpected); logsEntriesExpected = new int[]{ 2 }; await RunVariation(LogLevel.Information, message, MessageReceivedHandledOptions, errors, logsEntriesExpected); logsEntriesExpected = new int[] { 0, 1, 3 }; await RunVariation(LogLevel.Debug, message, MessageReceivedSkippedOptions, errors, logsEntriesExpected); logsEntriesExpected = new int[] { 3 }; await RunVariation(LogLevel.Information, message, MessageReceivedSkippedOptions, errors, logsEntriesExpected); logsEntriesExpected = new int[] {0, 1, 7, 20, 8 }; await RunVariation(LogLevel.Debug, message, SecurityTokenReceivedHandledOptions, errors, logsEntriesExpected); logsEntriesExpected = new int[] {0, 1, 7, 20, 9 }; await RunVariation(LogLevel.Debug, message, SecurityTokenReceivedSkippedOptions, errors, logsEntriesExpected); #if _Verbose Console.WriteLine("\n ===== \n"); DisplayErrors(errors); #endif errors.Count.ShouldBe(0); } /// /// Tests that processes a messaage as expected. /// The test runs two independant paths: Using and /// /// for this variation /// the that has arrived /// the delegate used for setting the options. /// container for propogation of errors. /// the expected log entries /// a Task private async Task RunVariation(LogLevel logLevel, OpenIdConnectMessage message, Action action, Dictionary>> errors, int[] logsEntriesExpected) { var expectedLogs = PopulateLogEntries(logsEntriesExpected); string variation = action.Method.ToString().Substring(5, action.Method.ToString().IndexOf('(') - 5); #if _Verbose Console.WriteLine(Environment.NewLine + "=====" + Environment.NewLine + "Variation: " + variation + ", LogLevel: " + logLevel.ToString() + Environment.NewLine + Environment.NewLine + "Expected Logs: "); DisplayLogs(expectedLogs); Console.WriteLine(Environment.NewLine + "Logs using ConfigureOptions:"); #endif var form = new FormUrlEncodedContent(message.Parameters); var loggerFactory = new CustomLoggerFactory(logLevel); var server = CreateServer(new CustomConfigureOptions(action), loggerFactory); await server.CreateClient().PostAsync("http://localhost", form); CheckLogs(variation + ":ConfigOptions", loggerFactory.Logger.Logs, expectedLogs, errors); #if _Verbose Console.WriteLine(Environment.NewLine + "Logs using IOptions:"); #endif form = new FormUrlEncodedContent(message.Parameters); loggerFactory = new CustomLoggerFactory(logLevel); server = CreateServer(new Options(action), loggerFactory); await server.CreateClient().PostAsync("http://localhost", form); CheckLogs(variation + ":IOptions", loggerFactory.Logger.Logs, expectedLogs, errors); } /// /// Populates a list of expected log entries for a test variation. /// /// the index for the in CompleteLogEntries of interest. /// a that represents the expected entries for a test variation. private List PopulateLogEntries(int[] items) { var entries = new List(); foreach(var item in items) { entries.Add(CompleteLogEntries[item]); } return entries; } private void DisplayLogs(List logs) { foreach (var logentry in logs) { Console.WriteLine(logentry.ToString()); } } private void DisplayErrors(Dictionary>> errors) { if (errors.Count > 0) { foreach (var error in errors) { Console.WriteLine("Error in Variation: " + error.Key); foreach (var logError in error.Value) { Console.WriteLine("*Captured*, *Expected* : *" + (logError.Item1?.ToString() ?? "null") + "*, *" + (logError.Item2?.ToString() ?? "null") + "*"); } Console.WriteLine(Environment.NewLine); } } } /// /// Adds to errors if a variation if any are found. /// /// if this has been seen before, errors will be appended, test results are easier to understand if this is unique. /// these are the logs the runtime generated /// these are the errors that were expected /// the dictionary to record any errors private void CheckLogs(string variation, List capturedLogs, List expectedLogs, Dictionary>> errors) { var localErrors = new List>(); if (capturedLogs.Count >= expectedLogs.Count) { for (int i = 0; i < capturedLogs.Count; i++) { if (i + 1 > expectedLogs.Count) { localErrors.Add(new Tuple(capturedLogs[i], null)); } else { if (!TestUtilities.AreEqual(capturedLogs[i], expectedLogs[i])) { localErrors.Add(new Tuple(capturedLogs[i], expectedLogs[i])); } } } } else { for (int i = 0; i < expectedLogs.Count; i++) { if (i + 1 > capturedLogs.Count) { localErrors.Add(new Tuple(null, expectedLogs[i])); } else { if (!TestUtilities.AreEqual(expectedLogs[i], capturedLogs[i])) { localErrors.Add(new Tuple(capturedLogs[i], expectedLogs[i])); } } } } if (localErrors.Count != 0) { if (errors.ContainsKey(variation)) { foreach (var error in localErrors) { errors[variation].Add(error); } } else { errors[variation] = localErrors; } } } #region Configure Options private static void CodeReceivedHandledOptions(OpenIdConnectAuthenticationOptions options) { DefaultOptions(options); options.Notifications = new OpenIdConnectAuthenticationNotifications { AuthorizationCodeReceived = (notification) => { notification.HandleResponse(); return Task.FromResult(null); } }; } private static void CodeReceivedSkippedOptions(OpenIdConnectAuthenticationOptions options) { DefaultOptions(options); options.Notifications = new OpenIdConnectAuthenticationNotifications { AuthorizationCodeReceived = (notification) => { notification.SkipToNextMiddleware(); return Task.FromResult(null); } }; } private static void DefaultOptions(OpenIdConnectAuthenticationOptions options) { options.AuthenticationScheme = "OpenIdConnectHandlerTest"; options.ConfigurationManager = ConfigurationManager.DefaultStaticConfigurationManager; options.StateDataFormat = new AuthenticationPropertiesFormater(); } private static void MessageReceivedHandledOptions(OpenIdConnectAuthenticationOptions options) { DefaultOptions(options); options.Notifications = new OpenIdConnectAuthenticationNotifications { MessageReceived = (notification) => { notification.HandleResponse(); return Task.FromResult(null); } }; } private static void MessageReceivedSkippedOptions(OpenIdConnectAuthenticationOptions options) { DefaultOptions(options); options.Notifications = new OpenIdConnectAuthenticationNotifications { MessageReceived = (notification) => { notification.SkipToNextMiddleware(); return Task.FromResult(null); } }; } private static void SecurityTokenReceivedHandledOptions(OpenIdConnectAuthenticationOptions options) { DefaultOptions(options); options.Notifications = new OpenIdConnectAuthenticationNotifications { SecurityTokenReceived = (notification) => { notification.HandleResponse(); return Task.FromResult(null); } }; } private static void SecurityTokenReceivedSkippedOptions(OpenIdConnectAuthenticationOptions options) { DefaultOptions(options); options.Notifications = new OpenIdConnectAuthenticationNotifications { SecurityTokenReceived = (notification) => { notification.SkipToNextMiddleware(); return Task.FromResult(null); } }; } private static void SecurityTokenValidatedHandledOptions(OpenIdConnectAuthenticationOptions options) { DefaultOptions(options); options.Notifications = new OpenIdConnectAuthenticationNotifications { SecurityTokenValidated = (notification) => { notification.HandleResponse(); return Task.FromResult(null); } }; } private static void SecurityTokenValidatedSkippedOptions(OpenIdConnectAuthenticationOptions options) { DefaultOptions(options); options.Notifications = new OpenIdConnectAuthenticationNotifications { SecurityTokenValidated = (notification) => { notification.SkipToNextMiddleware(); return Task.FromResult(null); } }; } #endregion private static TestServer CreateServer(IOptions options, ILoggerFactory loggerFactory) { return TestServer.Create( app => { app.UseCustomOpenIdConnectAuthentication(options, loggerFactory); app.Use(async (context, next) => { await next(); }); }, services => { services.AddWebEncoders(); services.AddDataProtection(); } ); } private static TestServer CreateServer(CustomConfigureOptions configureOptions, ILoggerFactory loggerFactory) { return TestServer.Create( app => { app.UseCustomOpenIdConnectAuthentication(configureOptions, loggerFactory); app.Use(async (context, next) => { await next(); }); }, services => { services.AddWebEncoders(); services.AddDataProtection(); } ); } } /// /// Extension specifies as the middleware. /// public static class OpenIdConnectAuthenticationExtensions { /// /// Adds the into the ASP.NET runtime. /// /// The application builder /// Options which control the processing of the OpenIdConnect protocol and token validation. /// custom loggerFactory /// The application builder public static IApplicationBuilder UseCustomOpenIdConnectAuthentication(this IApplicationBuilder app, CustomConfigureOptions customConfigureOption, ILoggerFactory loggerFactory) { return app.UseMiddleware(customConfigureOption, loggerFactory); } /// /// Adds the into the ASP.NET runtime. /// /// The application builder /// Options which control the processing of the OpenIdConnect protocol and token validation. /// custom loggerFactory /// The application builder public static IApplicationBuilder UseCustomOpenIdConnectAuthentication(this IApplicationBuilder app, IOptions options, ILoggerFactory loggerFactory) { return app.UseMiddleware(options, loggerFactory); } } /// /// Provides a Facade over IOptions /// public class Options : IOptions { OpenIdConnectAuthenticationOptions _options; public Options(Action action) { _options = new OpenIdConnectAuthenticationOptions(); action(_options); } OpenIdConnectAuthenticationOptions IOptions.Options { get { return _options; } } /// /// For now returns _options /// /// configuration to return /// public OpenIdConnectAuthenticationOptions GetNamedOptions(string name) { return _options; } } public class CustomConfigureOptions : ConfigureOptions { public CustomConfigureOptions(Action action) : base(action) { } public override void Configure(OpenIdConnectAuthenticationOptions options, string name = "") { base.Configure(options, name); return; } } /// /// Used to control which methods are handled /// public class CustomOpenIdConnectAuthenticationHandler : OpenIdConnectAuthenticationHandler { public async Task BaseInitializeAsyncPublic(AuthenticationOptions options, HttpContext context, ILogger logger, IUrlEncoder encoder) { await base.BaseInitializeAsync(options, context, logger, encoder); } public override bool ShouldHandleScheme(string authenticationScheme) { return true; } public override void Challenge(ChallengeContext context) { } protected override void ApplyResponseChallenge() { } protected override async Task ApplyResponseChallengeAsync() { var redirectToIdentityProviderNotification = new RedirectToIdentityProviderNotification(Context, Options) { }; await Options.Notifications.RedirectToIdentityProvider(redirectToIdentityProviderNotification); } } /// /// Used to set as the AuthenticationHandler /// which can be configured to handle certain messages. /// public class CustomOpenIdConnectAuthenticationMiddleware : OpenIdConnectAuthenticationMiddleware { public CustomOpenIdConnectAuthenticationMiddleware( RequestDelegate next, IDataProtectionProvider dataProtectionProvider, ILoggerFactory loggerFactory, IUrlEncoder encoder, IOptions externalOptions, IOptions options, ConfigureOptions configureOptions = null ) : base(next, dataProtectionProvider, loggerFactory, encoder, externalOptions, options, configureOptions) { Logger = (loggerFactory as CustomLoggerFactory).Logger; } protected override AuthenticationHandler CreateHandler() { return new CustomOpenIdConnectAuthenticationHandler(); } } public class LogEntry { public LogEntry() { } public int EventId { get; set; } public Exception Exception { get; set; } public Func Formatter { get; set; } public LogLevel Level { get; set; } public object State { get; set; } public override string ToString() { if (Formatter != null) { return Formatter(this.State, this.Exception); } else { string message = (Formatter != null ? Formatter(State, Exception) : (State?.ToString() ?? "null")); message += ", LogLevel: " + Level.ToString(); message += ", EventId: " + EventId.ToString(); message += ", Exception: " + (Exception == null ? "null" : Exception.Message); return message; } } } public class CustomLogger : ILogger, IDisposable { LogLevel _logLevel = 0; public CustomLogger(LogLevel logLevel = LogLevel.Debug) { _logLevel = logLevel; } List logEntries = new List(); public IDisposable BeginScopeImpl(object state) { return this; } public void Dispose() { } public bool IsEnabled(LogLevel logLevel) { return (logLevel >= _logLevel); } public void Log(LogLevel logLevel, int eventId, object state, Exception exception, Func formatter) { if (IsEnabled(logLevel)) { logEntries.Add( new LogEntry { EventId = eventId, Exception = exception, Formatter = formatter, Level = logLevel, State = state, }); #if _Verbose Console.WriteLine(state?.ToString() ?? "state null"); #endif } } public List Logs { get { return logEntries; } } } public class CustomLoggerFactory : ILoggerFactory { CustomLogger _logger; LogLevel _logLevel = LogLevel.Debug; public CustomLoggerFactory(LogLevel logLevel) { _logLevel = logLevel; _logger = new CustomLogger(_logLevel); } public LogLevel MinimumLevel { get { return _logLevel; } set {_logLevel = value; } } public void AddProvider(ILoggerProvider provider) { } public ILogger CreateLogger(string categoryName) { return _logger; } public CustomLogger Logger { get { return _logger; } } } /// /// Processing a requires 'unprotecting' the state. /// This class side-steps that process. /// public class AuthenticationPropertiesFormater : ISecureDataFormat { public string Protect(AuthenticationProperties data) { return "protectedData"; } AuthenticationProperties ISecureDataFormat.Unprotect(string protectedText) { return new AuthenticationProperties(); } } /// /// Used to set up different configurations of metadata for different tests /// public class ConfigurationManager { /// /// Simple static empty manager. /// static public IConfigurationManager DefaultStaticConfigurationManager { get { return new StaticConfigurationManager(new OpenIdConnectConfiguration()); } } } }