search

aspnet / Identity

[Archived] ASP.NET Core Identity is the membership system for building ASP.NET Core web applications, including membership, login, and user data. Project moved to https://github.com/aspnet/AspNetCore
Apache License 2.0
1.97k stars 871 forks source link

Test failure: CheckPasswordSignInReturnsLockedOutWhenLockedOut #2036

Closed aspnet-hello closed 5 years ago

aspnet-hello commented 5 years ago

This issue was made automatically. If there is a problem contact ryanbrandenburg.

This test failed with the following error:

Assert.Contains() Failure
Not found: User c4300a7f-ddac-4f6c-ad44-128536c1ffb9 is currently locked out.
In value:  
   at Microsoft.AspNetCore.Identity.Test.SignInManagerTest.CheckPasswordSignInReturnsLockedOutWhenLockedOut() in /_/test/Identity.Test/SignInManagerTest.cs:line 166
--- End of stack trace from previous location where exception was thrown ---

Other tests within that build may have failed with a similar message, but they are not listed here. Check the link above for more info.

This test failed on master.

CC Eilon

aspnet-hello commented 5 years ago

This comment was made automatically. If there is a problem contact ryanbrandenburg.

Please use this workflow to address this flaky test issue, including checking applicable checkboxes and filling in the applicable "TODO" entries:

aspnet-hello commented 5 years ago

This comment was made automatically. If there is a problem contact ryanbrandenburg.

There were 1 failures with about the same error on master at 1:50:55 PM:

There were 2 failures with about the same error on master at 1:50:55 PM:

There were 2 failures with about the same error on master at 1:50:55 PM:

There were 2 failures with about the same error on master at 1:51:12 PM:

aspnet-hello commented 5 years ago

This comment was made automatically. If there is a problem contact ryanbrandenburg.

There were 2 failures with about the same error on master at 1:50:55 PM:

There were 2 failures with about the same error on master at 1:50:54 PM:

There were 2 failures with about the same error on master at 1:50:54 PM:

There were 2 failures with about the same error on master at 4:29:07 PM:

There were 2 failures with about the same error on master at 4:29:05 PM:

There were 2 failures with about the same error on master at 3:38:37 PM:

There were 2 failures with about the same error on master at 4:29:54 PM:

There were 2 failures with about the same error on master at 4:52:01 PM:

There were 2 failures with about the same error on master at 4:59:15 PM:

There were 2 failures with about the same error on master at 4:57:20 PM:

There were 2 failures with about the same error on master at 12:21:33 PM:

There were 2 failures with about the same error on master at 12:21:33 PM:

There were 2 failures with about the same error on master at 2:07:13 PM:

There were 2 failures with about the same error on master at 12:21:26 PM:

There were 2 failures with about the same error on master at 2:07:16 PM:

There were 2 failures with about the same error on master at 12:21:30 PM:

There were 2 failures with about the same error on master at 12:21:31 PM:

There were 2 failures with about the same error on master at 12:21:31 PM:

There were 2 failures with about the same error on master at 2:07:10 PM:

Eilon commented 5 years ago

@HaoK please investigate.

HaoK commented 5 years ago

Weird this isn't failing for me locally in master, but its definitely failing on all ci builds right now, @ajcvickers has anything changed in EF recently? The submodules updated before these tests started failing were:

EntityFrameworkCore => 647aed13836f1f4f0d3c3d7f6a9a0165826e3e6a
Logging => cc90113f450182d472ae155767ff388fc92698e8
Mvc => 13cf754425c6120ac0b062dd51da2b89ac161dc2
Razor => 4d44639a51643223d5eb4ca317e201845c79d0c3
HaoK commented 5 years ago

Okay so something has regressed that has caused the logging mocks to fail @BrennanConroy has something changed in logging recently?

This mock logger code hasn't changed since 1.0 probably, but it appears to no longer get called from a log warning:

   // Actual log code which is indeed getting hit:
  Logger.LogWarning(3, "User {userId} is currently locked out.", await UserManager.GetUserIdAsync(user));

  // Mock code which is no longer getting invoked which is recording calls to a string
        public static Mock<ILogger<T>> MockILogger<T>(StringBuilder logStore = null) where T : class
        {
            logStore = logStore ?? LogMessage;
            var logger = new Mock<ILogger<T>>();
            logger.Setup(x => x.Log(It.IsAny<LogLevel>(), It.IsAny<EventId>(), It.IsAny<object>(),
                It.IsAny<Exception>(), It.IsAny<Func<object, Exception, string>>()))
                .Callback((LogLevel logLevel, EventId eventId, object state, Exception exception, Func<object, Exception, string> formatter) =>
                {
                    if (formatter == null)
                    {
                        logStore.Append(state.ToString());
                    }
                    else
                    {
                        logStore.Append(formatter(state, exception));
                    }
                    logStore.Append(" ");
                });
            logger.Setup(x => x.BeginScope(It.IsAny<object>())).Callback((object state) =>
                {
                    logStore.Append(state.ToString());
                    logStore.Append(" ");
                });
            logger.Setup(x => x.IsEnabled(LogLevel.Debug)).Returns(true);
            logger.Setup(x => x.IsEnabled(LogLevel.Warning)).Returns(true);

            return logger;
        }
pakrym commented 5 years ago

We started using structs as TState in ILogger.Log() and logger.Setup(x => x.Log(It.IsAny<LogLevel>(), It.IsAny<EventId>(), It.IsAny<object>(), doesn't get invoked when T is struct.

I've fixed this for kestrel: https://github.com/aspnet/KestrelHttpServer/pull/3066

ajcvickers commented 5 years ago

@pakrym Isn't this a breaking change?

pakrym commented 5 years ago

In what way?

HaoK commented 5 years ago

@ajcvickers are you ok if I just remove this mocking entirely? There is limited value in verifying these log messages, we already have tests verifying that the proper results are being returned, and we are only checking it in 5 tests anyways

pakrym commented 5 years ago

There is a great alternative to mocking - LoggedTest base class that not only provides TestSink with the list of all messages logged but also forwards them to xunit test output.

For example this is how kestrel asserts log messages: https://github.com/aspnet/KestrelHttpServer/blob/d29e410b035a3fe7db0d4625ee37cd6cb76e40d3/test/Kestrel.Transport.FunctionalTests/RequestTests.cs#L684

ajcvickers commented 5 years ago

@HaoK I'm fine with that. I was just concerned the production code consuming logs might be assuming that TState is not a struct and breaking in the same way. If that's not a worry, then no problem.

pakrym commented 5 years ago

It's somewhat possible, but it was the entire purpose of having TState was to be able to pass structs without boxing. Seems like an safe enough change for 3.0 milestone.

cc @Eilon

ajcvickers commented 5 years ago

Oh, if this if for 3.0 then no problem at all. :-)

aspnet-hello commented 5 years ago

This comment was made automatically. If there is a problem contact ryanbrandenburg.

There were 2 failures with about the same error on master at 3:03:03 PM:

There were 2 failures with about the same error on master at 3:24:32 PM:

There were 2 failures with about the same error on master at 3:32:40 PM:

There were 2 failures with about the same error on master at 3:29:02 PM:

HaoK commented 5 years ago

Was fixed by https://github.com/aspnet/Identity/commit/1fde1cc0616f6972ac18540529ac840968853631