Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

[BUG] Support Needed: [invalid_token_response] -> OAuth 2.0 Access Token Response: 401 Unauthorized: [no body] #20823

Closed
2 tasks done
BillyBolton opened this issue Apr 20, 2021 · 7 comments
Closed
2 tasks done

[BUG] Support Needed: [invalid_token_response] -> OAuth 2.0 Access Token Response: 401 Unauthorized: [no body] #20823

BillyBolton opened this issue Apr 20, 2021 · 7 comments
Assignees
@stliu @yiliuTo
Labels
azure-spring All azure-spring related issues azure-spring-aad Spring active directory related issues. Client This issue points to a problem in the data-plane of the library. customer-reported Issues that are reported by GitHub users external to the Azure organization. question The issue doesn't require a change to the product in order to be resolved. Most issues start as that

Comments

@BillyBolton
Copy link

Query/Question
Capture
I keep getting the error: "Login with OAuth 2.0 - [invalid_token_response] An error occurred while attempting to retrieve the OAuth 2.0 Access Token Response: 401 Unauthorized: [no body]" when I try to access my front-end app. (I'm just trying to make sure the sign-on works correctly for now. I've followed Azure Spring Boot Sample Active Directory Web App and can use my AAD keys there and everything works as expected, but when I try to do the same on mine, I get the error. Error occurs on all endpoints, whether they are @PreAuthorize(hasRole('ROLE_someRole')") or not.

Here are some logs for when the error occurs. It's long but I'm having trouble debugging -- hoping someone else can catch something. I can see that I'm getting a 401 UNAUTHORIZED response but I'm unclear why.

Please let me know if any other information might be needed.

21-04-20 10:47:53.807  INFO 12772 --- [  restartedMain] org.example.Application                  : Started Application in 3.907 seconds (JVM running for 4.413)
2021-04-20 10:47:53.855 DEBUG 12772 --- [  restartedMain] o.s.boot.devtools.restart.Restarter      : Creating new Restarter for thread Thread[main,5,main]
2021-04-20 10:47:53.855 DEBUG 12772 --- [  restartedMain] o.s.boot.devtools.restart.Restarter      : Immediately restarting application
2021-04-20 10:47:53.855 DEBUG 12772 --- [  restartedMain] o.s.boot.devtools.restart.Restarter      : Created RestartClassLoader org.springframework.boot.devtools.restart.classloader.RestartClassLoader@d1eccae
2021-04-20 10:47:53.855 DEBUG 12772 --- [  restartedMain] o.s.boot.devtools.restart.Restarter      : Starting application org.example.Application with URLs [file:/home/wbolton/Desktop/dev/tdd-playwright-example/site/build/classes/java/main/, file:/home/wbolton/Desktop/dev/tdd-playwright-example/site/build/resources/main/]
2021-04-20 10:47:57.867 DEBUG 12772 --- [o-8080-Acceptor] o.apache.tomcat.util.threads.LimitLatch  : Counting up[http-nio-8080-Acceptor] latch=1
2021-04-20 10:47:57.883 DEBUG 12772 --- [nio-8080-exec-1] o.a.coyote.http11.Http11InputBuffer      : Before fill(): [true], parsingRequestLine: [true], parsingRequestLinePhase: [0], parsingRequestLineStart: [0], byteBuffer.position() [0]
2021-04-20 10:47:57.884 DEBUG 12772 --- [nio-8080-exec-1] o.a.tomcat.util.net.SocketWrapperBase    : Socket: [org.apache.tomcat.util.net.NioEndpoint$NioSocketWrapper@2eccef06:org.apache.tomcat.util.net.NioChannel@4ce0d7b0:java.nio.channels.SocketChannel[connected local=/127.0.0.1:8080 remote=/127.0.0.1:50892]], Read from buffer: [0]
2021-04-20 10:47:57.884 DEBUG 12772 --- [nio-8080-exec-1] org.apache.tomcat.util.net.NioEndpoint   : Socket: [org.apache.tomcat.util.net.NioEndpoint$NioSocketWrapper@2eccef06:org.apache.tomcat.util.net.NioChannel@4ce0d7b0:java.nio.channels.SocketChannel[connected local=/127.0.0.1:8080 remote=/127.0.0.1:50892]], Read direct from socket: [359]
2021-04-20 10:47:57.884 DEBUG 12772 --- [nio-8080-exec-1] o.a.coyote.http11.Http11InputBuffer      : Received [GET /group1 HTTP/1.1
Host: localhost:8080
User-Agent: Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:87.0) Gecko/20100101 Firefox/87.0
Accept: text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,*/*;q=0.8
Accept-Language: en-CA,en-US;q=0.7,en;q=0.3
Accept-Encoding: gzip, deflate
DNT: 1
Connection: keep-alive
Upgrade-Insecure-Requests: 1

]
2021-04-20 10:47:57.896 DEBUG 12772 --- [nio-8080-exec-1] org.apache.tomcat.util.http.Parameters   : Set query string encoding to UTF-8
2021-04-20 10:47:57.898 DEBUG 12772 --- [nio-8080-exec-1] o.a.c.authenticator.AuthenticatorBase    : Security checking request GET /group1
2021-04-20 10:47:57.899 DEBUG 12772 --- [nio-8080-exec-1] org.apache.catalina.realm.RealmBase      :   No applicable constraints defined
2021-04-20 10:47:57.904 DEBUG 12772 --- [nio-8080-exec-1] o.a.c.a.jaspic.AuthConfigFactoryImpl     : Loading persistent provider registrations from [/tmp/tomcat.8080.4233635627085168867/conf/jaspic-providers.xml]
2021-04-20 10:47:57.904 DEBUG 12772 --- [nio-8080-exec-1] o.a.c.authenticator.AuthenticatorBase    : Not subject to any constraint
2021-04-20 10:47:57.908  INFO 12772 --- [nio-8080-exec-1] o.a.c.c.C.[Tomcat].[localhost].[/]       : Initializing Spring DispatcherServlet 'dispatcherServlet'
2021-04-20 10:47:57.908  INFO 12772 --- [nio-8080-exec-1] o.s.web.servlet.DispatcherServlet        : Initializing Servlet 'dispatcherServlet'
2021-04-20 10:47:57.908 DEBUG 12772 --- [nio-8080-exec-1] o.s.web.servlet.DispatcherServlet        : Detected StandardServletMultipartResolver
2021-04-20 10:47:57.908 DEBUG 12772 --- [nio-8080-exec-1] o.s.web.servlet.DispatcherServlet        : Detected AcceptHeaderLocaleResolver
2021-04-20 10:47:57.909 DEBUG 12772 --- [nio-8080-exec-1] o.s.web.servlet.DispatcherServlet        : Detected FixedThemeResolver
2021-04-20 10:47:57.909 DEBUG 12772 --- [nio-8080-exec-1] o.s.web.servlet.DispatcherServlet        : Detected org.springframework.web.servlet.view.DefaultRequestToViewNameTranslator@45062f67
2021-04-20 10:47:57.910 DEBUG 12772 --- [nio-8080-exec-1] o.s.web.servlet.DispatcherServlet        : Detected org.springframework.web.servlet.support.SessionFlashMapManager@695a240c
2021-04-20 10:47:57.910 DEBUG 12772 --- [nio-8080-exec-1] o.s.web.servlet.DispatcherServlet        : enableLoggingRequestDetails='true': request parameters and headers will be shown which may lead to unsafe logging of potentially sensitive data
2021-04-20 10:47:57.910  INFO 12772 --- [nio-8080-exec-1] o.s.web.servlet.DispatcherServlet        : Completed initialization in 2 ms
2021-04-20 10:47:57.916 DEBUG 12772 --- [nio-8080-exec-1] o.s.security.web.FilterChainProxy        : Securing GET /group1
2021-04-20 10:47:57.919 DEBUG 12772 --- [nio-8080-exec-1] s.s.w.c.SecurityContextPersistenceFilter : Set SecurityContextHolder to empty SecurityContext
2021-04-20 10:47:57.922 DEBUG 12772 --- [nio-8080-exec-1] o.s.s.w.a.AnonymousAuthenticationFilter  : Set SecurityContextHolder to anonymous SecurityContext
2021-04-20 10:47:57.929 DEBUG 12772 --- [nio-8080-exec-1] o.s.s.w.a.i.FilterSecurityInterceptor    : Failed to authorize filter invocation [GET /group1] with attributes [authenticated]
2021-04-20 10:47:57.938 DEBUG 12772 --- [nio-8080-exec-1] org.apache.tomcat.util.http.Parameters   : Set encoding to UTF-8
2021-04-20 10:47:57.943 DEBUG 12772 --- [nio-8080-exec-1] o.s.s.w.s.HttpSessionRequestCache        : Saved request http://localhost:8080/group1 to session
2021-04-20 10:47:57.944 DEBUG 12772 --- [nio-8080-exec-1] s.w.a.DelegatingAuthenticationEntryPoint : Trying to match using And [Not [RequestHeaderRequestMatcher [expectedHeaderName=X-Requested-With, expectedHeaderValue=XMLHttpRequest]], Not [And [Or [Ant [pattern='/login'], Ant [pattern='/favicon.ico']], And [Not [RequestHeaderRequestMatcher [expectedHeaderName=X-Requested-With, expectedHeaderValue=XMLHttpRequest]], MediaTypeRequestMatcher [contentNegotiationStrategy=org.springframework.web.accept.ContentNegotiationManager@24b4aab5, matchingMediaTypes=[application/xhtml+xml, image/*, text/html, text/plain], useEquals=false, ignoredMediaTypes=[*/*]]]]]]
2021-04-20 10:47:57.944 DEBUG 12772 --- [nio-8080-exec-1] s.w.a.DelegatingAuthenticationEntryPoint : Match found! Executing org.springframework.security.web.authentication.LoginUrlAuthenticationEntryPoint@4ddf2cd1
2021-04-20 10:47:57.945 DEBUG 12772 --- [nio-8080-exec-1] o.s.s.web.DefaultRedirectStrategy        : Redirecting to http://localhost:8080/oauth2/authorization/azure
2021-04-20 10:47:57.946 DEBUG 12772 --- [nio-8080-exec-1] w.c.HttpSessionSecurityContextRepository : Did not store empty SecurityContext
2021-04-20 10:47:57.947 DEBUG 12772 --- [nio-8080-exec-1] s.s.w.c.SecurityContextPersistenceFilter : Cleared SecurityContextHolder to complete request
2021-04-20 10:47:57.953 DEBUG 12772 --- [nio-8080-exec-1] o.a.coyote.http11.Http11InputBuffer      : Before fill(): [true], parsingRequestLine: [true], parsingRequestLinePhase: [0], parsingRequestLineStart: [0], byteBuffer.position() [0]
2021-04-20 10:47:57.953 DEBUG 12772 --- [nio-8080-exec-1] o.a.tomcat.util.net.SocketWrapperBase    : Socket: [org.apache.tomcat.util.net.NioEndpoint$NioSocketWrapper@2eccef06:org.apache.tomcat.util.net.NioChannel@4ce0d7b0:java.nio.channels.SocketChannel[connected local=/127.0.0.1:8080 remote=/127.0.0.1:50892]], Read from buffer: [0]
2021-04-20 10:47:57.953 DEBUG 12772 --- [nio-8080-exec-1] org.apache.tomcat.util.net.NioEndpoint   : Socket: [org.apache.tomcat.util.net.NioEndpoint$NioSocketWrapper@2eccef06:org.apache.tomcat.util.net.NioChannel@4ce0d7b0:java.nio.channels.SocketChannel[connected local=/127.0.0.1:8080 remote=/127.0.0.1:50892]], Read direct from socket: [0]
2021-04-20 10:47:57.954 DEBUG 12772 --- [nio-8080-exec-1] o.a.coyote.http11.Http11InputBuffer      : Received []
2021-04-20 10:47:57.954 DEBUG 12772 --- [nio-8080-exec-1] o.apache.coyote.http11.Http11Processor   : Socket: [org.apache.tomcat.util.net.NioEndpoint$NioSocketWrapper@2eccef06:org.apache.tomcat.util.net.NioChannel@4ce0d7b0:java.nio.channels.SocketChannel[connected local=/127.0.0.1:8080 remote=/127.0.0.1:50892]], Status in: [OPEN_READ], State out: [OPEN]
2021-04-20 10:47:57.954 DEBUG 12772 --- [nio-8080-exec-1] org.apache.tomcat.util.net.NioEndpoint   : Registered read interest for [org.apache.tomcat.util.net.NioEndpoint$NioSocketWrapper@2eccef06:org.apache.tomcat.util.net.NioChannel@4ce0d7b0:java.nio.channels.SocketChannel[connected local=/127.0.0.1:8080 remote=/127.0.0.1:50892]]
2021-04-20 10:47:57.961 DEBUG 12772 --- [nio-8080-exec-2] o.a.coyote.http11.Http11InputBuffer      : Before fill(): [true], parsingRequestLine: [true], parsingRequestLinePhase: [0], parsingRequestLineStart: [0], byteBuffer.position() [0]
2021-04-20 10:47:57.961 DEBUG 12772 --- [nio-8080-exec-2] o.a.tomcat.util.net.SocketWrapperBase    : Socket: [org.apache.tomcat.util.net.NioEndpoint$NioSocketWrapper@2eccef06:org.apache.tomcat.util.net.NioChannel@4ce0d7b0:java.nio.channels.SocketChannel[connected local=/127.0.0.1:8080 remote=/127.0.0.1:50892]], Read from buffer: [0]
2021-04-20 10:47:57.961 DEBUG 12772 --- [nio-8080-exec-2] org.apache.tomcat.util.net.NioEndpoint   : Socket: [org.apache.tomcat.util.net.NioEndpoint$NioSocketWrapper@2eccef06:org.apache.tomcat.util.net.NioChannel@4ce0d7b0:java.nio.channels.SocketChannel[connected local=/127.0.0.1:8080 remote=/127.0.0.1:50892]], Read direct from socket: [432]
2021-04-20 10:47:57.961 DEBUG 12772 --- [nio-8080-exec-2] o.a.coyote.http11.Http11InputBuffer      : Received [GET /oauth2/authorization/azure HTTP/1.1
Host: localhost:8080
User-Agent: Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:87.0) Gecko/20100101 Firefox/87.0
Accept: text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,*/*;q=0.8
Accept-Language: en-CA,en-US;q=0.7,en;q=0.3
Accept-Encoding: gzip, deflate
DNT: 1
Connection: keep-alive
Cookie: JSESSIONID=98234D4AEB6646AE6D6C923EFD2A6563
Upgrade-Insecure-Requests: 1

]
2021-04-20 10:47:57.962 DEBUG 12772 --- [nio-8080-exec-2] o.a.t.util.http.Rfc6265CookieProcessor   : Cookies: Parsing b[]: JSESSIONID=98234D4AEB6646AE6D6C923EFD2A6563
2021-04-20 10:47:57.964 DEBUG 12772 --- [nio-8080-exec-2] o.a.catalina.connector.CoyoteAdapter     :  Requested cookie session id is 98234D4AEB6646AE6D6C923EFD2A6563
2021-04-20 10:47:57.964 DEBUG 12772 --- [nio-8080-exec-2] o.a.c.authenticator.AuthenticatorBase    : Security checking request GET /oauth2/authorization/azure
2021-04-20 10:47:57.964 DEBUG 12772 --- [nio-8080-exec-2] org.apache.catalina.realm.RealmBase      :   No applicable constraints defined
2021-04-20 10:47:57.964 DEBUG 12772 --- [nio-8080-exec-2] o.a.c.authenticator.AuthenticatorBase    : Not subject to any constraint
2021-04-20 10:47:57.965 DEBUG 12772 --- [nio-8080-exec-2] o.s.security.web.FilterChainProxy        : Securing GET /oauth2/authorization/azure
2021-04-20 10:47:57.965 DEBUG 12772 --- [nio-8080-exec-2] s.s.w.c.SecurityContextPersistenceFilter : Set SecurityContextHolder to empty SecurityContext
2021-04-20 10:47:57.966 DEBUG 12772 --- [nio-8080-exec-2] org.apache.tomcat.util.http.Parameters   : Set encoding to UTF-8
2021-04-20 10:47:57.970 DEBUG 12772 --- [nio-8080-exec-2] o.s.s.web.DefaultRedirectStrategy        : Redirecting to https://login.microsoftonline.com/07d020b6-d78f-40cb-b6c7-98eab8c29a94/oauth2/v2.0/authorize?response_type=code&client_id=8ff48ac1-1ddf-479d-ac5a-5db407c70c50&scope=openid%20profile%20offline_access%20https://graph.microsoft.com/User.Read%20https://graph.microsoft.com/Directory.Read.All&state=12kVGn6KTHLBgbT3TG-Z_RWuw3NPYzUZdRXuRAwdLHk%3D&redirect_uri=http://localhost:8080/login/oauth2/code/&nonce=uCdUZInSTZHCYHNVZepln8AHE9i2_DC3OhbOV87aCUA
2021-04-20 10:47:57.971 DEBUG 12772 --- [nio-8080-exec-2] w.c.HttpSessionSecurityContextRepository : Did not store empty SecurityContext
2021-04-20 10:47:57.971 DEBUG 12772 --- [nio-8080-exec-2] s.s.w.c.SecurityContextPersistenceFilter : Cleared SecurityContextHolder to complete request
2021-04-20 10:47:57.972 DEBUG 12772 --- [nio-8080-exec-2] o.a.coyote.http11.Http11InputBuffer      : Before fill(): [true], parsingRequestLine: [true], parsingRequestLinePhase: [0], parsingRequestLineStart: [0], byteBuffer.position() [0]
2021-04-20 10:47:57.972 DEBUG 12772 --- [nio-8080-exec-2] o.a.tomcat.util.net.SocketWrapperBase    : Socket: [org.apache.tomcat.util.net.NioEndpoint$NioSocketWrapper@2eccef06:org.apache.tomcat.util.net.NioChannel@4ce0d7b0:java.nio.channels.SocketChannel[connected local=/127.0.0.1:8080 remote=/127.0.0.1:50892]], Read from buffer: [0]
2021-04-20 10:47:57.972 DEBUG 12772 --- [nio-8080-exec-2] org.apache.tomcat.util.net.NioEndpoint   : Socket: [org.apache.tomcat.util.net.NioEndpoint$NioSocketWrapper@2eccef06:org.apache.tomcat.util.net.NioChannel@4ce0d7b0:java.nio.channels.SocketChannel[connected local=/127.0.0.1:8080 remote=/127.0.0.1:50892]], Read direct from socket: [0]
2021-04-20 10:47:57.973 DEBUG 12772 --- [nio-8080-exec-2] o.a.coyote.http11.Http11InputBuffer      : Received []
2021-04-20 10:47:57.973 DEBUG 12772 --- [nio-8080-exec-2] o.apache.coyote.http11.Http11Processor   : Socket: [org.apache.tomcat.util.net.NioEndpoint$NioSocketWrapper@2eccef06:org.apache.tomcat.util.net.NioChannel@4ce0d7b0:java.nio.channels.SocketChannel[connected local=/127.0.0.1:8080 remote=/127.0.0.1:50892]], Status in: [OPEN_READ], State out: [OPEN]
2021-04-20 10:47:57.973 DEBUG 12772 --- [nio-8080-exec-2] org.apache.tomcat.util.net.NioEndpoint   : Registered read interest for [org.apache.tomcat.util.net.NioEndpoint$NioSocketWrapper@2eccef06:org.apache.tomcat.util.net.NioChannel@4ce0d7b0:java.nio.channels.SocketChannel[connected local=/127.0.0.1:8080 remote=/127.0.0.1:50892]]
2021-04-20 10:48:07.535 DEBUG 12772 --- [nio-8080-exec-3] o.a.coyote.http11.Http11InputBuffer      : Before fill(): [true], parsingRequestLine: [true], parsingRequestLinePhase: [0], parsingRequestLineStart: [0], byteBuffer.position() [0]
2021-04-20 10:48:07.535 DEBUG 12772 --- [nio-8080-exec-3] o.a.tomcat.util.net.SocketWrapperBase    : Socket: [org.apache.tomcat.util.net.NioEndpoint$NioSocketWrapper@2eccef06:org.apache.tomcat.util.net.NioChannel@4ce0d7b0:java.nio.channels.SocketChannel[connected local=/127.0.0.1:8080 remote=/127.0.0.1:50892]], Read from buffer: [0]
2021-04-20 10:48:07.535 DEBUG 12772 --- [nio-8080-exec-3] org.apache.tomcat.util.net.NioEndpoint   : Socket: [org.apache.tomcat.util.net.NioEndpoint$NioSocketWrapper@2eccef06:org.apache.tomcat.util.net.NioChannel@4ce0d7b0:java.nio.channels.SocketChannel[connected local=/127.0.0.1:8080 remote=/127.0.0.1:50892]], Read direct from socket: [1391]
2021-04-20 10:48:07.535 DEBUG 12772 --- [nio-8080-exec-3] o.a.coyote.http11.Http11InputBuffer      : Received [GET /login/oauth2/code/?code=0.AXwAtiDQB4_Xy0C2x5jquMKalMGK9I_fHZ1HrFpdtAfHDFB8AAA.AQABAAIAAAD--DLA3VO7QrddgJg7Wevrt_1lFOOrXECTBHr8gH9JaDkxsfw47DKf3474jgMpjTlUSau8yVU4I48mBuhuaPltnJrW8e7ZTp8bHzir4HRbL_aJfjYCpJO3fMFevDFcnElc08hFPFVHBbTgDN9n0oTu712bmxB-D3TeD36aghpJ18IapVsYKiIjcA99oSPcZ6ddChHmjCoNfC_0KyPJKBvHB5MRlnMHf9tR_w0jDqftFhr9NFZZFfcNm113F5oGzWkT7OOe8vzHNk9Z9vLzFvstu_LjVTKtvs7ZaiYEZ5076AgfwwB_GbUMzUsXB9sdr82q47yZijfsOa04vcCofTmgPZUACoCglDViymFLqWdRkIVh6VenjGvZXkdvpxCuUVj2vaIXsLLZDGPJ_COEBbKdQoByWlIFFfzRIedc_2UXCilBq5F_K-9Srwa3Hrpbk48nP7rk43yzeHhBer89O61bw8vLlMk9IMmoEMbSe78ie3rM_IYs_s2OXKgQUzysIxqxgLYkQ_wjioPRjdKC9sL4xykSX8vyyp1OsLZLywTd9QNxChUhlfaCfrAxl60f2Goc9aM2TVizA5Oy8iFkCOb59ywWRyVoTCv23SmV7ge6xpQZuoWCv0yjsuHYRIRWB6HwEe8X4ld1ljPNmVf7oDK-PrLCYfJyloVdXHsIufnR7bD2V0dMZNmnWufarx_8XX8UmPyPpVwLB2mxJ5I6Ykv52H8K8edyitc53tHa6BXufIYI-BiiLZsExuPhHDUpiFb4Tm1eES2OH5au494PGVuSIAA&state=12kVGn6KTHLBgbT3TG-Z_RWuw3NPYzUZdRXuRAwdLHk%3d&session_state=ab1ee51e-7a6a-4aa9-96dc-0b7e383de098 HTTP/1.1
Host: localhost:8080
User-Agent: Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:87.0) Gecko/20100101 Firefox/87.0
Accept: text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,*/*;q=0.8
Accept-Language: en-CA,en-US;q=0.7,en;q=0.3
Accept-Encoding: gzip, deflate
DNT: 1
Connection: keep-alive
Cookie: JSESSIONID=98234D4AEB6646AE6D6C923EFD2A6563
Upgrade-Insecure-Requests: 1

]
2021-04-20 10:48:07.536 DEBUG 12772 --- [nio-8080-exec-3] o.a.t.util.http.Rfc6265CookieProcessor   : Cookies: Parsing b[]: JSESSIONID=98234D4AEB6646AE6D6C923EFD2A6563
2021-04-20 10:48:07.536 DEBUG 12772 --- [nio-8080-exec-3] o.a.catalina.connector.CoyoteAdapter     :  Requested cookie session id is 98234D4AEB6646AE6D6C923EFD2A6563
2021-04-20 10:48:07.536 DEBUG 12772 --- [nio-8080-exec-3] o.a.c.authenticator.AuthenticatorBase    : Security checking request GET /login/oauth2/code/
2021-04-20 10:48:07.537 DEBUG 12772 --- [nio-8080-exec-3] org.apache.catalina.realm.RealmBase      :   No applicable constraints defined
2021-04-20 10:48:07.537 DEBUG 12772 --- [nio-8080-exec-3] o.a.c.authenticator.AuthenticatorBase    : Not subject to any constraint
2021-04-20 10:48:07.537 DEBUG 12772 --- [nio-8080-exec-3] o.s.security.web.FilterChainProxy        : Securing GET /login/oauth2/code/?code=0.AXwAtiDQB4_Xy0C2x5jquMKalMGK9I_fHZ1HrFpdtAfHDFB8AAA.AQABAAIAAAD--DLA3VO7QrddgJg7Wevrt_1lFOOrXECTBHr8gH9JaDkxsfw47DKf3474jgMpjTlUSau8yVU4I48mBuhuaPltnJrW8e7ZTp8bHzir4HRbL_aJfjYCpJO3fMFevDFcnElc08hFPFVHBbTgDN9n0oTu712bmxB-D3TeD36aghpJ18IapVsYKiIjcA99oSPcZ6ddChHmjCoNfC_0KyPJKBvHB5MRlnMHf9tR_w0jDqftFhr9NFZZFfcNm113F5oGzWkT7OOe8vzHNk9Z9vLzFvstu_LjVTKtvs7ZaiYEZ5076AgfwwB_GbUMzUsXB9sdr82q47yZijfsOa04vcCofTmgPZUACoCglDViymFLqWdRkIVh6VenjGvZXkdvpxCuUVj2vaIXsLLZDGPJ_COEBbKdQoByWlIFFfzRIedc_2UXCilBq5F_K-9Srwa3Hrpbk48nP7rk43yzeHhBer89O61bw8vLlMk9IMmoEMbSe78ie3rM_IYs_s2OXKgQUzysIxqxgLYkQ_wjioPRjdKC9sL4xykSX8vyyp1OsLZLywTd9QNxChUhlfaCfrAxl60f2Goc9aM2TVizA5Oy8iFkCOb59ywWRyVoTCv23SmV7ge6xpQZuoWCv0yjsuHYRIRWB6HwEe8X4ld1ljPNmVf7oDK-PrLCYfJyloVdXHsIufnR7bD2V0dMZNmnWufarx_8XX8UmPyPpVwLB2mxJ5I6Ykv52H8K8edyitc53tHa6BXufIYI-BiiLZsExuPhHDUpiFb4Tm1eES2OH5au494PGVuSIAA&state=12kVGn6KTHLBgbT3TG-Z_RWuw3NPYzUZdRXuRAwdLHk%3d&session_state=ab1ee51e-7a6a-4aa9-96dc-0b7e383de098
2021-04-20 10:48:07.537 DEBUG 12772 --- [nio-8080-exec-3] s.s.w.c.SecurityContextPersistenceFilter : Set SecurityContextHolder to empty SecurityContext
2021-04-20 10:48:07.537 DEBUG 12772 --- [nio-8080-exec-3] org.apache.tomcat.util.http.Parameters   : Set encoding to UTF-8
2021-04-20 10:48:07.538 DEBUG 12772 --- [nio-8080-exec-3] org.apache.tomcat.util.http.Parameters   : Decoding query null UTF-8
2021-04-20 10:48:07.538 DEBUG 12772 --- [nio-8080-exec-3] org.apache.tomcat.util.http.Parameters   : Start processing with input [code=0.AXwAtiDQB4_Xy0C2x5jquMKalMGK9I_fHZ1HrFpdtAfHDFB8AAA.AQABAAIAAAD--DLA3VO7QrddgJg7Wevrt_1lFOOrXECTBHr8gH9JaDkxsfw47DKf3474jgMpjTlUSau8yVU4I48mBuhuaPltnJrW8e7ZTp8bHzir4HRbL_aJfjYCpJO3fMFevDFcnElc08hFPFVHBbTgDN9n0oTu712bmxB-D3TeD36aghpJ18IapVsYKiIjcA99oSPcZ6ddChHmjCoNfC_0KyPJKBvHB5MRlnMHf9tR_w0jDqftFhr9NFZZFfcNm113F5oGzWkT7OOe8vzHNk9Z9vLzFvstu_LjVTKtvs7ZaiYEZ5076AgfwwB_GbUMzUsXB9sdr82q47yZijfsOa04vcCofTmgPZUACoCglDViymFLqWdRkIVh6VenjGvZXkdvpxCuUVj2vaIXsLLZDGPJ_COEBbKdQoByWlIFFfzRIedc_2UXCilBq5F_K-9Srwa3Hrpbk48nP7rk43yzeHhBer89O61bw8vLlMk9IMmoEMbSe78ie3rM_IYs_s2OXKgQUzysIxqxgLYkQ_wjioPRjdKC9sL4xykSX8vyyp1OsLZLywTd9QNxChUhlfaCfrAxl60f2Goc9aM2TVizA5Oy8iFkCOb59ywWRyVoTCv23SmV7ge6xpQZuoWCv0yjsuHYRIRWB6HwEe8X4ld1ljPNmVf7oDK-PrLCYfJyloVdXHsIufnR7bD2V0dMZNmnWufarx_8XX8UmPyPpVwLB2mxJ5I6Ykv52H8K8edyitc53tHa6BXufIYI-BiiLZsExuPhHDUpiFb4Tm1eES2OH5au494PGVuSIAA&state=12kVGn6KTHLBgbT3TG-Z_RWuw3NPYzUZdRXuRAwdLHk%3d&session_state=ab1ee51e-7a6a-4aa9-96dc-0b7e383de098]
2021-04-20 10:48:07.544 DEBUG 12772 --- [nio-8080-exec-3] o.s.web.client.RestTemplate              : HTTP POST https://login.microsoftonline.com/07d020b6-d78f-40cb-b6c7-98eab8c29a94/oauth2/v2.0/token
2021-04-20 10:48:07.545 DEBUG 12772 --- [nio-8080-exec-3] o.s.web.client.RestTemplate              : Accept=[application/json, application/*+json]
2021-04-20 10:48:07.545 DEBUG 12772 --- [nio-8080-exec-3] o.s.web.client.RestTemplate              : Writing [{grant_type=[authorization_code], code=[0.AXwAtiDQB4_Xy0C2x5jquMKalMGK9I_fHZ1HrFpdtAfHDFB8AAA.AQABAAIAAAD--DLA3VO7QrddgJg7Wevrt_1lFOOrXECTBHr8gH9JaDkxsfw47DKf3474jgMpjTlUSau8yVU4I48mBuhuaPltnJrW8e7ZTp8bHzir4HRbL_aJfjYCpJO3fMFevDFcnElc08hFPFVHBbTgDN9n0oTu712bmxB-D3TeD36aghpJ18IapVsYKiIjcA99oSPcZ6ddChHmjCoNfC_0KyPJKBvHB5MRlnMHf9tR_w0jDqftFhr9NFZZFfcNm113F5oGzWkT7OOe8vzHNk9Z9vLzFvstu_LjVTKtvs7ZaiYEZ5076AgfwwB_GbUMzUsXB9sdr82q47yZijfsOa04vcCofTmgPZUACoCglDViymFLqWdRkIVh6VenjGvZXkdvpxCuUVj2vaIXsLLZDGPJ_COEBbKdQoByWlIFFfzRIedc_2UXCilBq5F_K-9Srwa3Hrpbk48nP7rk43yzeHhBer89O61bw8vLlMk9IMmoEMbSe78ie3rM_IYs_s2OXKgQUzysIxqxgLYkQ_wjioPRjdKC9sL4xykSX8vyyp1OsLZLywTd9QNxChUhlfaCfrAxl60f2Goc9aM2TVizA5Oy8iFkCOb59ywWRyVoTCv23SmV7ge6xpQZuoWCv0yjsuHYRIRWB6HwEe8X4ld1ljPNmVf7oDK-PrLCYfJyloVdXHsIufnR7bD2V0dMZNmnWufarx_8XX8UmPyPpVwLB2mxJ5I6Ykv52H8K8edyitc53tHa6BXufIYI-BiiLZsExuPhHDUpiFb4Tm1eES2OH5au494PGVuSIAA], redirect_uri=[http://localhost:8080/login/oauth2/code/], scope=[openid profile offline_access https://graph.microsoft.com/User.Read https://graph.microsoft.com/Directory.Read.All]}] as "application/x-www-form-urlencoded;charset=UTF-8"
2021-04-20 10:48:07.779 DEBUG 12772 --- [nio-8080-exec-3] s.n.www.protocol.http.HttpURLConnection  : sun.net.www.MessageHeader@e7e0a0f11 pairs: {POST /07d020b6-d78f-40cb-b6c7-98eab8c29a94/oauth2/v2.0/token HTTP/1.1: null}{Accept: application/json;charset=UTF-8}{x-client-SKU: az-sp-aad}{x-client-VER: unknown}{client-request-id: b2f4c6cb-2f0e-4b87-9d12-780bf8645a98}{Content-Type: application/x-www-form-urlencoded;charset=UTF-8}{Authorization: Basic OGZmNDhhYzEtMWRkZi00NzlkLWFjNWEtNWRiNDA3YzcwYzUwOkFiQ2RFZkdoSWpLbE1uT3BRclN0VXZXeFl6PT1DN1pkSE9uQmlfLV9EUUo2SjR5aGItSi5UU0o2akxzOTJS}{User-Agent: Java/11.0.9.1}{Host: login.microsoftonline.com}{Connection: keep-alive}{Content-Length: 1099}
2021-04-20 10:48:07.991 DEBUG 12772 --- [nio-8080-exec-3] s.n.www.protocol.http.HttpURLConnection  : sun.net.www.MessageHeader@4fb2abde17 pairs: {null: HTTP/1.1 401 Unauthorized}{Cache-Control: no-store, no-cache}{Pragma: no-cache}{Content-Type: application/json; charset=utf-8}{Expires: -1}{Strict-Transport-Security: max-age=31536000; includeSubDomains}{X-Content-Type-Options: nosniff}{P3P: CP="DSP CUR OTPi IND OTRi ONL FIN"}{client-request-id: b2f4c6cb-2f0e-4b87-9d12-780bf8645a98}{x-ms-request-id: c4f06d31-6a72-48cf-afc7-5ca48e4ce800}{x-ms-ests-server: 2.1.11654.13 - NCUS ProdSlices}{x-ms-clitelem: 1,7000215,0,,}{Set-Cookie: fpc=Avg99E9qJixItn6DLnepjld-V78pAQAAAKfgENgOAAAA; expires=Thu, 20-May-2021 14:48:07 GMT; path=/; secure; HttpOnly; SameSite=None}{Set-Cookie: x-ms-gateway-slice=estsfd; path=/; secure; samesite=none; httponly}{Set-Cookie: stsservicecookie=estsfd; path=/; secure; samesite=none; httponly}{Date: Tue, 20 Apr 2021 14:48:07 GMT}{Content-Length: 471}
2021-04-20 10:48:07.992 DEBUG 12772 --- [nio-8080-exec-3] o.s.web.client.RestTemplate              : Response 401 UNAUTHORIZED
2021-04-20 10:48:07.995 DEBUG 12772 --- [nio-8080-exec-3] .s.a.DefaultAuthenticationEventPublisher : No event was found for the exception org.springframework.security.oauth2.core.OAuth2AuthenticationException
2021-04-20 10:48:07.995 DEBUG 12772 --- [nio-8080-exec-3] o.s.s.web.DefaultRedirectStrategy        : Redirecting to /login?error
2021-04-20 10:48:07.996 DEBUG 12772 --- [nio-8080-exec-3] w.c.HttpSessionSecurityContextRepository : Did not store empty SecurityContext
2021-04-20 10:48:07.996 DEBUG 12772 --- [nio-8080-exec-3] s.s.w.c.SecurityContextPersistenceFilter : Cleared SecurityContextHolder to complete request
2021-04-20 10:48:07.997 DEBUG 12772 --- [nio-8080-exec-3] o.a.coyote.http11.Http11InputBuffer      : Before fill(): [true], parsingRequestLine: [true], parsingRequestLinePhase: [0], parsingRequestLineStart: [0], byteBuffer.position() [0]
2021-04-20 10:48:07.998 DEBUG 12772 --- [nio-8080-exec-3] o.a.tomcat.util.net.SocketWrapperBase    : Socket: [org.apache.tomcat.util.net.NioEndpoint$NioSocketWrapper@2eccef06:org.apache.tomcat.util.net.NioChannel@4ce0d7b0:java.nio.channels.SocketChannel[connected local=/127.0.0.1:8080 remote=/127.0.0.1:50892]], Read from buffer: [0]
2021-04-20 10:48:07.998 DEBUG 12772 --- [nio-8080-exec-3] org.apache.tomcat.util.net.NioEndpoint   : Socket: [org.apache.tomcat.util.net.NioEndpoint$NioSocketWrapper@2eccef06:org.apache.tomcat.util.net.NioChannel@4ce0d7b0:java.nio.channels.SocketChannel[connected local=/127.0.0.1:8080 remote=/127.0.0.1:50892]], Read direct from socket: [0]
2021-04-20 10:48:07.998 DEBUG 12772 --- [nio-8080-exec-3] o.a.coyote.http11.Http11InputBuffer      : Received []
2021-04-20 10:48:07.998 DEBUG 12772 --- [nio-8080-exec-3] o.apache.coyote.http11.Http11Processor   : Socket: [org.apache.tomcat.util.net.NioEndpoint$NioSocketWrapper@2eccef06:org.apache.tomcat.util.net.NioChannel@4ce0d7b0:java.nio.channels.SocketChannel[connected local=/127.0.0.1:8080 remote=/127.0.0.1:50892]], Status in: [OPEN_READ], State out: [OPEN]
2021-04-20 10:48:07.998 DEBUG 12772 --- [nio-8080-exec-3] org.apache.tomcat.util.net.NioEndpoint   : Registered read interest for [org.apache.tomcat.util.net.NioEndpoint$NioSocketWrapper@2eccef06:org.apache.tomcat.util.net.NioChannel@4ce0d7b0:java.nio.channels.SocketChannel[connected local=/127.0.0.1:8080 remote=/127.0.0.1:50892]]
2021-04-20 10:48:08.004 DEBUG 12772 --- [nio-8080-exec-4] o.a.coyote.http11.Http11InputBuffer      : Before fill(): [true], parsingRequestLine: [true], parsingRequestLinePhase: [0], parsingRequestLineStart: [0], byteBuffer.position() [0]
2021-04-20 10:48:08.004 DEBUG 12772 --- [nio-8080-exec-4] o.a.tomcat.util.net.SocketWrapperBase    : Socket: [org.apache.tomcat.util.net.NioEndpoint$NioSocketWrapper@2eccef06:org.apache.tomcat.util.net.NioChannel@4ce0d7b0:java.nio.channels.SocketChannel[connected local=/127.0.0.1:8080 remote=/127.0.0.1:50892]], Read from buffer: [0]
2021-04-20 10:48:08.004 DEBUG 12772 --- [nio-8080-exec-4] org.apache.tomcat.util.net.NioEndpoint   : Socket: [org.apache.tomcat.util.net.NioEndpoint$NioSocketWrapper@2eccef06:org.apache.tomcat.util.net.NioChannel@4ce0d7b0:java.nio.channels.SocketChannel[connected local=/127.0.0.1:8080 remote=/127.0.0.1:50892]], Read direct from socket: [417]
2021-04-20 10:48:08.004 DEBUG 12772 --- [nio-8080-exec-4] o.a.coyote.http11.Http11InputBuffer      : Received [GET /login?error HTTP/1.1
Host: localhost:8080
User-Agent: Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:87.0) Gecko/20100101 Firefox/87.0
Accept: text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,*/*;q=0.8
Accept-Language: en-CA,en-US;q=0.7,en;q=0.3
Accept-Encoding: gzip, deflate
DNT: 1
Connection: keep-alive
Cookie: JSESSIONID=98234D4AEB6646AE6D6C923EFD2A6563
Upgrade-Insecure-Requests: 1

]
2021-04-20 10:48:08.005 DEBUG 12772 --- [nio-8080-exec-4] o.a.t.util.http.Rfc6265CookieProcessor   : Cookies: Parsing b[]: JSESSIONID=98234D4AEB6646AE6D6C923EFD2A6563
2021-04-20 10:48:08.005 DEBUG 12772 --- [nio-8080-exec-4] o.a.catalina.connector.CoyoteAdapter     :  Requested cookie session id is 98234D4AEB6646AE6D6C923EFD2A6563
2021-04-20 10:48:08.005 DEBUG 12772 --- [nio-8080-exec-4] o.a.c.authenticator.AuthenticatorBase    : Security checking request GET /login
2021-04-20 10:48:08.005 DEBUG 12772 --- [nio-8080-exec-4] org.apache.catalina.realm.RealmBase      :   No applicable constraints defined
2021-04-20 10:48:08.005 DEBUG 12772 --- [nio-8080-exec-4] o.a.c.authenticator.AuthenticatorBase    : Not subject to any constraint
2021-04-20 10:48:08.006 DEBUG 12772 --- [nio-8080-exec-4] o.s.security.web.FilterChainProxy        : Securing GET /login?error
2021-04-20 10:48:08.006 DEBUG 12772 --- [nio-8080-exec-4] s.s.w.c.SecurityContextPersistenceFilter : Set SecurityContextHolder to empty SecurityContext
2021-04-20 10:48:08.012 DEBUG 12772 --- [nio-8080-exec-4] w.c.HttpSessionSecurityContextRepository : Did not store empty SecurityContext
2021-04-20 10:48:08.013 DEBUG 12772 --- [nio-8080-exec-4] s.s.w.c.SecurityContextPersistenceFilter : Cleared SecurityContextHolder to complete request
2021-04-20 10:48:08.015 DEBUG 12772 --- [nio-8080-exec-4] o.a.coyote.http11.Http11InputBuffer      : Before fill(): [true], parsingRequestLine: [true], parsingRequestLinePhase: [0], parsingRequestLineStart: [0], byteBuffer.position() [0]
2021-04-20 10:48:08.015 DEBUG 12772 --- [nio-8080-exec-4] o.a.tomcat.util.net.SocketWrapperBase    : Socket: [org.apache.tomcat.util.net.NioEndpoint$NioSocketWrapper@2eccef06:org.apache.tomcat.util.net.NioChannel@4ce0d7b0:java.nio.channels.SocketChannel[connected local=/127.0.0.1:8080 remote=/127.0.0.1:50892]], Read from buffer: [0]
2021-04-20 10:48:08.015 DEBUG 12772 --- [nio-8080-exec-4] org.apache.tomcat.util.net.NioEndpoint   : Socket: [org.apache.tomcat.util.net.NioEndpoint$NioSocketWrapper@2eccef06:org.apache.tomcat.util.net.NioChannel@4ce0d7b0:java.nio.channels.SocketChannel[connected local=/127.0.0.1:8080 remote=/127.0.0.1:50892]], Read direct from socket: [0]
2021-04-20 10:48:08.015 DEBUG 12772 --- [nio-8080-exec-4] o.a.coyote.http11.Http11InputBuffer      : Received []
2021-04-20 10:48:08.015 DEBUG 12772 --- [nio-8080-exec-4] o.apache.coyote.http11.Http11Processor   : Socket: [org.apache.tomcat.util.net.NioEndpoint$NioSocketWrapper@2eccef06:org.apache.tomcat.util.net.NioChannel@4ce0d7b0:java.nio.channels.SocketChannel[connected local=/127.0.0.1:8080 remote=/127.0.0.1:50892]], Status in: [OPEN_READ], State out: [OPEN]
2021-04-20 10:48:08.015 DEBUG 12772 --- [nio-8080-exec-4] org.apache.tomcat.util.net.NioEndpoint   : Registered read interest for [org.apache.tomcat.util.net.NioEndpoint$NioSocketWrapper@2eccef06:org.apache.tomcat.util.net.NioChannel@4ce0d7b0:java.nio.channels.SocketChannel[connected local=/127.0.0.1:8080 remote=/127.0.0.1:50892]]
2021-04-20 10:48:08.339 DEBUG 12772 --- [nio-8080-exec-5] o.a.coyote.http11.Http11InputBuffer      : Before fill(): [true], parsingRequestLine: [true], parsingRequestLinePhase: [0], parsingRequestLineStart: [0], byteBuffer.position() [0]
2021-04-20 10:48:08.339 DEBUG 12772 --- [nio-8080-exec-5] o.a.tomcat.util.net.SocketWrapperBase    : Socket: [org.apache.tomcat.util.net.NioEndpoint$NioSocketWrapper@2eccef06:org.apache.tomcat.util.net.NioChannel@4ce0d7b0:java.nio.channels.SocketChannel[connected local=/127.0.0.1:8080 remote=/127.0.0.1:50892]], Read from buffer: [0]
2021-04-20 10:48:08.339 DEBUG 12772 --- [nio-8080-exec-5] org.apache.tomcat.util.net.NioEndpoint   : Socket: [org.apache.tomcat.util.net.NioEndpoint$NioSocketWrapper@2eccef06:org.apache.tomcat.util.net.NioChannel@4ce0d7b0:java.nio.channels.SocketChannel[connected local=/127.0.0.1:8080 remote=/127.0.0.1:50892]], Read direct from socket: [371]
2021-04-20 10:48:08.339 DEBUG 12772 --- [nio-8080-exec-5] o.a.coyote.http11.Http11InputBuffer      : Received [GET /favicon.ico HTTP/1.1
Host: localhost:8080
User-Agent: Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:87.0) Gecko/20100101 Firefox/87.0
Accept: image/webp,*/*
Accept-Language: en-CA,en-US;q=0.7,en;q=0.3
Accept-Encoding: gzip, deflate
DNT: 1
Connection: keep-alive
Referer: http://localhost:8080/login?error
Cookie: JSESSIONID=98234D4AEB6646AE6D6C923EFD2A6563

]
2021-04-20 10:48:08.340 DEBUG 12772 --- [nio-8080-exec-5] o.a.t.util.http.Rfc6265CookieProcessor   : Cookies: Parsing b[]: JSESSIONID=98234D4AEB6646AE6D6C923EFD2A6563
2021-04-20 10:48:08.340 DEBUG 12772 --- [nio-8080-exec-5] o.a.catalina.connector.CoyoteAdapter     :  Requested cookie session id is 98234D4AEB6646AE6D6C923EFD2A6563
2021-04-20 10:48:08.340 DEBUG 12772 --- [nio-8080-exec-5] o.a.c.authenticator.AuthenticatorBase    : Security checking request GET /favicon.ico
2021-04-20 10:48:08.340 DEBUG 12772 --- [nio-8080-exec-5] org.apache.catalina.realm.RealmBase      :   No applicable constraints defined
2021-04-20 10:48:08.341 DEBUG 12772 --- [nio-8080-exec-5] o.a.c.authenticator.AuthenticatorBase    : Not subject to any constraint
2021-04-20 10:48:08.341 DEBUG 12772 --- [nio-8080-exec-5] o.s.security.web.FilterChainProxy        : Securing GET /favicon.ico
2021-04-20 10:48:08.341 DEBUG 12772 --- [nio-8080-exec-5] s.s.w.c.SecurityContextPersistenceFilter : Set SecurityContextHolder to empty SecurityContext
2021-04-20 10:48:08.342 DEBUG 12772 --- [nio-8080-exec-5] o.s.s.w.a.AnonymousAuthenticationFilter  : Set SecurityContextHolder to anonymous SecurityContext
2021-04-20 10:48:08.342 DEBUG 12772 --- [nio-8080-exec-5] o.s.s.w.a.i.FilterSecurityInterceptor    : Failed to authorize filter invocation [GET /favicon.ico] with attributes [authenticated]
2021-04-20 10:48:08.343 DEBUG 12772 --- [nio-8080-exec-5] s.w.a.DelegatingAuthenticationEntryPoint : Trying to match using And [Not [RequestHeaderRequestMatcher [expectedHeaderName=X-Requested-With, expectedHeaderValue=XMLHttpRequest]], Not [And [Or [Ant [pattern='/login'], Ant [pattern='/favicon.ico']], And [Not [RequestHeaderRequestMatcher [expectedHeaderName=X-Requested-With, expectedHeaderValue=XMLHttpRequest]], MediaTypeRequestMatcher [contentNegotiationStrategy=org.springframework.web.accept.ContentNegotiationManager@24b4aab5, matchingMediaTypes=[application/xhtml+xml, image/*, text/html, text/plain], useEquals=false, ignoredMediaTypes=[*/*]]]]]]
2021-04-20 10:48:08.343 DEBUG 12772 --- [nio-8080-exec-5] s.w.a.DelegatingAuthenticationEntryPoint : No match found. Using default entry point org.springframework.security.web.authentication.LoginUrlAuthenticationEntryPoint@336a8721
2021-04-20 10:48:08.343 DEBUG 12772 --- [nio-8080-exec-5] o.s.s.web.DefaultRedirectStrategy        : Redirecting to http://localhost:8080/login
2021-04-20 10:48:08.343 DEBUG 12772 --- [nio-8080-exec-5] w.c.HttpSessionSecurityContextRepository : Did not store empty SecurityContext
2021-04-20 10:48:08.343 DEBUG 12772 --- [nio-8080-exec-5] s.s.w.c.SecurityContextPersistenceFilter : Cleared SecurityContextHolder to complete request
2021-04-20 10:48:08.344 DEBUG 12772 --- [nio-8080-exec-5] o.a.coyote.http11.Http11InputBuffer      : Before fill(): [true], parsingRequestLine: [true], parsingRequestLinePhase: [0], parsingRequestLineStart: [0], byteBuffer.position() [0]
2021-04-20 10:48:08.344 DEBUG 12772 --- [nio-8080-exec-5] o.a.tomcat.util.net.SocketWrapperBase    : Socket: [org.apache.tomcat.util.net.NioEndpoint$NioSocketWrapper@2eccef06:org.apache.tomcat.util.net.NioChannel@4ce0d7b0:java.nio.channels.SocketChannel[connected local=/127.0.0.1:8080 remote=/127.0.0.1:50892]], Read from buffer: [0]
2021-04-20 10:48:08.344 DEBUG 12772 --- [nio-8080-exec-5] org.apache.tomcat.util.net.NioEndpoint   : Socket: [org.apache.tomcat.util.net.NioEndpoint$NioSocketWrapper@2eccef06:org.apache.tomcat.util.net.NioChannel@4ce0d7b0:java.nio.channels.SocketChannel[connected local=/127.0.0.1:8080 remote=/127.0.0.1:50892]], Read direct from socket: [0]
2021-04-20 10:48:08.344 DEBUG 12772 --- [nio-8080-exec-5] o.a.coyote.http11.Http11InputBuffer      : Received []
2021-04-20 10:48:08.344 DEBUG 12772 --- [nio-8080-exec-5] o.apache.coyote.http11.Http11Processor   : Socket: [org.apache.tomcat.util.net.NioEndpoint$NioSocketWrapper@2eccef06:org.apache.tomcat.util.net.NioChannel@4ce0d7b0:java.nio.channels.SocketChannel[connected local=/127.0.0.1:8080 remote=/127.0.0.1:50892]], Status in: [OPEN_READ], State out: [OPEN]
2021-04-20 10:48:08.344 DEBUG 12772 --- [nio-8080-exec-5] org.apache.tomcat.util.net.NioEndpoint   : Registered read interest for [org.apache.tomcat.util.net.NioEndpoint$NioSocketWrapper@2eccef06:org.apache.tomcat.util.net.NioChannel@4ce0d7b0:java.nio.channels.SocketChannel[connected local=/127.0.0.1:8080 remote=/127.0.0.1:50892]]
2021-04-20 10:48:08.350 DEBUG 12772 --- [nio-8080-exec-6] o.a.coyote.http11.Http11InputBuffer      : Before fill(): [true], parsingRequestLine: [true], parsingRequestLinePhase: [0], parsingRequestLineStart: [0], byteBuffer.position() [0]
2021-04-20 10:48:08.351 DEBUG 12772 --- [nio-8080-exec-6] o.a.tomcat.util.net.SocketWrapperBase    : Socket: [org.apache.tomcat.util.net.NioEndpoint$NioSocketWrapper@2eccef06:org.apache.tomcat.util.net.NioChannel@4ce0d7b0:java.nio.channels.SocketChannel[connected local=/127.0.0.1:8080 remote=/127.0.0.1:50892]], Read from buffer: [0]
2021-04-20 10:48:08.351 DEBUG 12772 --- [nio-8080-exec-6] org.apache.tomcat.util.net.NioEndpoint   : Socket: [org.apache.tomcat.util.net.NioEndpoint$NioSocketWrapper@2eccef06:org.apache.tomcat.util.net.NioChannel@4ce0d7b0:java.nio.channels.SocketChannel[connected local=/127.0.0.1:8080 remote=/127.0.0.1:50892]], Read direct from socket: [365]
2021-04-20 10:48:08.351 DEBUG 12772 --- [nio-8080-exec-6] o.a.coyote.http11.Http11InputBuffer      : Received [GET /login HTTP/1.1
Host: localhost:8080
User-Agent: Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:87.0) Gecko/20100101 Firefox/87.0
Accept: image/webp,*/*
Accept-Language: en-CA,en-US;q=0.7,en;q=0.3
Accept-Encoding: gzip, deflate
Referer: http://localhost:8080/login?error
DNT: 1
Connection: keep-alive
Cookie: JSESSIONID=98234D4AEB6646AE6D6C923EFD2A6563

]
2021-04-20 10:48:08.351 DEBUG 12772 --- [nio-8080-exec-6] o.a.t.util.http.Rfc6265CookieProcessor   : Cookies: Parsing b[]: JSESSIONID=98234D4AEB6646AE6D6C923EFD2A6563
2021-04-20 10:48:08.352 DEBUG 12772 --- [nio-8080-exec-6] o.a.catalina.connector.CoyoteAdapter     :  Requested cookie session id is 98234D4AEB6646AE6D6C923EFD2A6563
2021-04-20 10:48:08.352 DEBUG 12772 --- [nio-8080-exec-6] o.a.c.authenticator.AuthenticatorBase    : Security checking request GET /login
2021-04-20 10:48:08.352 DEBUG 12772 --- [nio-8080-exec-6] org.apache.catalina.realm.RealmBase      :   No applicable constraints defined
2021-04-20 10:48:08.352 DEBUG 12772 --- [nio-8080-exec-6] o.a.c.authenticator.AuthenticatorBase    : Not subject to any constraint
2021-04-20 10:48:08.353 DEBUG 12772 --- [nio-8080-exec-6] o.s.security.web.FilterChainProxy        : Securing GET /login
2021-04-20 10:48:08.353 DEBUG 12772 --- [nio-8080-exec-6] s.s.w.c.SecurityContextPersistenceFilter : Set SecurityContextHolder to empty SecurityContext
2021-04-20 10:48:08.353 DEBUG 12772 --- [nio-8080-exec-6] w.c.HttpSessionSecurityContextRepository : Did not store empty SecurityContext
2021-04-20 10:48:08.353 DEBUG 12772 --- [nio-8080-exec-6] s.s.w.c.SecurityContextPersistenceFilter : Cleared SecurityContextHolder to complete request
2021-04-20 10:48:08.354 DEBUG 12772 --- [nio-8080-exec-6] o.a.coyote.http11.Http11InputBuffer      : Before fill(): [true], parsingRequestLine: [true], parsingRequestLinePhase: [0], parsingRequestLineStart: [0], byteBuffer.position() [0]
2021-04-20 10:48:08.355 DEBUG 12772 --- [nio-8080-exec-6] o.a.tomcat.util.net.SocketWrapperBase    : Socket: [org.apache.tomcat.util.net.NioEndpoint$NioSocketWrapper@2eccef06:org.apache.tomcat.util.net.NioChannel@4ce0d7b0:java.nio.channels.SocketChannel[connected local=/127.0.0.1:8080 remote=/127.0.0.1:50892]], Read from buffer: [0]
2021-04-20 10:48:08.355 DEBUG 12772 --- [nio-8080-exec-6] org.apache.tomcat.util.net.NioEndpoint   : Socket: [org.apache.tomcat.util.net.NioEndpoint$NioSocketWrapper@2eccef06:org.apache.tomcat.util.net.NioChannel@4ce0d7b0:java.nio.channels.SocketChannel[connected local=/127.0.0.1:8080 remote=/127.0.0.1:50892]], Read direct from socket: [0]
2021-04-20 10:48:08.355 DEBUG 12772 --- [nio-8080-exec-6] o.a.coyote.http11.Http11InputBuffer      : Received []
2021-04-20 10:48:08.355 DEBUG 12772 --- [nio-8080-exec-6] o.apache.coyote.http11.Http11Processor   : Socket: [org.apache.tomcat.util.net.NioEndpoint$NioSocketWrapper@2eccef06:org.apache.tomcat.util.net.NioChannel@4ce0d7b0:java.nio.channels.SocketChannel[connected local=/127.0.0.1:8080 remote=/127.0.0.1:50892]], Status in: [OPEN_READ], State out: [OPEN]
2021-04-20 10:48:08.355 DEBUG 12772 --- [nio-8080-exec-6] org.apache.tomcat.util.net.NioEndpoint   : Registered read interest for [org.apache.tomcat.util.net.NioEndpoint$NioSocketWrapper@2eccef06:org.apache.tomcat.util.net.NioChannel@4ce0d7b0:java.nio.channels.SocketChannel[connected local=/127.0.0.1:8080 remote=/127.0.0.1:50892]]
<===========--> 90% EXECUTING [22s]

Why is this not a Bug or a feature Request?
Cloning the repository from the Azure Spring Boot Sample Active Directory Web App and using the client id, keys, etc., for my AAD setup works as expected.

Setup (please complete the following information if applicable):

  • OS: Ubuntu 20.10
  • IDE : Terminal
  • Version of the Library used:
    Using Gradle:
compile "com.azure:azure-core:1.15.0"
compile "com.azure.spring:azure-spring-boot-starter-active-directory:3.4.0"
compile "org.springframework.boot:spring-boot-starter-web"
compile "org.springframework.boot:spring-boot-starter-thymeleaf"
compile "org.springframework.boot:spring-boot-starter-security"
compile "org.springframework.security:spring-security-oauth2-client"
compile "org.springframework.security:spring-security-oauth2-jose"
compile "org.thymeleaf.extras:thymeleaf-extras-springsecurity5"

Information Checklist
Kindly make sure that you have added all the following information above and checkoff the required fields otherwise we will treat the issuer as an incomplete report

  • Query Added
  • Setup information Added
@ghost ghost added needs-triage Workflow: This is a new issue that needs to be triaged to the appropriate team. customer-reported Issues that are reported by GitHub users external to the Azure organization. question The issue doesn't require a change to the product in order to be resolved. Most issues start as that labels Apr 20, 2021
@joshfree joshfree added azure-spring All azure-spring related issues azure-spring-aad Spring active directory related issues. Client This issue points to a problem in the data-plane of the library. labels Apr 26, 2021
@ghost ghost removed the needs-triage Workflow: This is a new issue that needs to be triaged to the appropriate team. label Apr 26, 2021
@joshfree
Copy link
Member

@stliu PTAL

@BillyBolton BillyBolton changed the title [QUERY] Support Needed: [invalid_token_response] -> OAuth 2.0 Access Token Response: 401 Unauthorized: [no body] [BUG] Support Needed: [invalid_token_response] -> OAuth 2.0 Access Token Response: 401 Unauthorized: [no body] Apr 26, 2021
@yiliuTo
Copy link
Member

yiliuTo commented Apr 27, 2021 •
edited
Loading

Hi @BillyBolton , sorry for the late response, we will look into it soon. Besides, considering that our sample can work as expected with your credentials, could you provide another sample project which can reproduce the issue you mentioned?

Currently from the error log, we could see that your App failed to acqurie token from AAD, so please first make sure your credentials info (tetant-id, client-id, client-secret and groups) in src/resources/application.xml are correct, and also the scopes your app is requesting have been configured (if admin consent is required, please grant it) in Azure Portal.

If there is nothing wrong with your configuration, I think a sample project that can reproduce your issue can help us debug your app and figure out its token request. Also, if possible, would you like to share the Manifest of your App registration (for concerns about info leakage, a test App is welcome) in Azure Portal which could help us to check your application configuration?

@BillyBolton
Copy link
Author

BillyBolton commented Apr 27, 2021 •
edited
Loading

Hi there, @yiliuTo. Here is a sample project that replicates the issue, including a dummy account to test the authentication with. All the details are in the ReadMe.

I was able to solve the issue of a no body token response. Indeed, it was a credential issue -- a small typo... However I'm receiving a redirect issue now. This issue occurred both in my project, and the MS sample when I converted it from Maven to Gradle.

The error I receive is:

2021-04-27 16:30:37.684 DEBUG 34013 --- [nio-8080-exec-3] o.s.web.client.RestTemplate              : HTTP GET https://login.microsoftonline.com/07d020b6-d78f-40cb-b6c7-98eab8c29a94/discovery/v2.0/keys
2021-04-27 16:30:37.685 DEBUG 34013 --- [nio-8080-exec-3] o.s.web.client.RestTemplate              : Accept=[text/plain, application/json, application/*+json, */*]
2021-04-27 16:30:37.757 DEBUG 34013 --- [nio-8080-exec-3] o.s.web.client.RestTemplate              : Response 200 OK
2021-04-27 16:30:37.757 DEBUG 34013 --- [nio-8080-exec-3] o.s.web.client.RestTemplate              : Reading to [java.lang.String] as "application/json;charset=utf-8"
2021-04-27 16:30:37.765 DEBUG 34013 --- [nio-8080-exec-3] w.c.HttpSessionSecurityContextRepository : Did not store empty SecurityContext
2021-04-27 16:30:37.765 DEBUG 34013 --- [nio-8080-exec-3] s.s.w.c.SecurityContextPersistenceFilter : Cleared SecurityContextHolder to complete request
2021-04-27 16:30:37.771 ERROR 34013 --- [nio-8080-exec-3] o.a.c.c.C.[.[.[/].[dispatcherServlet]    : Servlet.service() for servlet [dispatcherServlet] in context with path [] threw exception [Filter execution threw an exception] with root cause

java.lang.NoSuchMethodError: 'net.minidev.json.JSONObject com.nimbusds.jose.Header.toJSONObject()'


[... etc]

Capture
This error looks similar to #14898.
implementation "com.nimbusds:nimbus-jose-jwt:8.20"

Is there a more recent fix for this other than the work around mentioned in that issue? I'm curious why this extra dependency is needed just when converting from a Maven to Gradle setup. If this is indeed a Gradle specific work-around, should it be included in the documentation?

Thank you in advance for your help. I've been looking at this for weeks! I can't wait to get this up and running. 🙂

@yiliuTo
Copy link
Member

yiliuTo commented Apr 28, 2021 •
edited
Loading

Hi @BillyBolton thanks for your detailed information.

I noticed that in your build.gradle, the spring boot you selected is 2.4.2. And according to spring-boot-dependencies: 2.4.2, its nimbus-jose-jwt.version is 9.1.3 which has conflicts with the one 8.20.2 in our starter. Also I noticed in your build.gradle, you specify the version of some spring boot libraries as 2.4.3, so if the actual expected Spring Boot is 2.4.3, I suggest you changing its bom version because in 2.4.3 the nimbus-jose-jwt is 8.20.2, which can resolve the dependency conflict together.

Also, for your question

Is there a more recent fix for this other than the work around mentioned in that issue?

We currently haven't fixed the breaking changes of nimbus.

I'm curious why this extra dependency is needed just when converting from a Maven to Gradle setup.

In our sample , the spring boot parent is 2.4.5 which brings in nimbus of 8.20.2. Thus the version conflict is avoided when you try our sample.

Besides, as I read your build.gradle, I noticed that you have imported 3 of our starters:

com.microsoft.azure:azure-active-directory-spring-boot-starter:2.2.1
com.azure.spring:azure-spring-boot-starter-active-directory:3.3.0
com.azure.spring:azure-spring-boot-starter:3.3.0

May I know why you use 2 versions of the active directory starters(aad starter for short)? Also, for 3.3.0, if you just need the aad starter, you can remove com.azure.spring:azure-spring-boot-starter:3.3.0.

@BillyBolton
Copy link
Author

Hi @yiliuTo,

Thank you for the response. I've been playing around with multiple MS tutorials so I must have had some duplicate dependencies there. Thanks for catching that.

You've been a great help. Thanks again for your support. 💯

@yiliuTo
Copy link
Member

yiliuTo commented Apr 29, 2021

Hi @BillyBolton , I am so glad that I could help. And just a reminder, don't forget to update your credentials or delete that test account as they are now exposed in your repo.

azure-sdk pushed a commit to azure-sdk/azure-sdk-for-java that referenced this issue Sep 29, 2022
CodeGen from PR 20823 in Azure/azure-rest-api-specs
f95ba18 
[Hub Generated] Review request for Microsoft.DataProtection to add version preview/2022-09-01-preview (Azure#20823)

* Adds base for updating Microsoft.DataProtection from version stable/2022-05-01 to version 2022-09-01-preview

* Updates readme

* Updates API version in new specs and examples

* Changes for SecuritySettings

* Adding immutabilitySettings

* Adding extension routing API

* type change for retentionDurationInDays

* DppResourceGuardProxy operations and related definitions

* prettier fix

* fixing default block position in resourceguardproxy operations

* Added description for SoftDelete enum

* fixing description

* Reverting enum description

* fixing json

* adding back enum value description

Co-authored-by: Srinivas Charan Madu <smadu@microsoft.com>
@venkatthotakura5288
Copy link

hi @BillyBolton , Now i am getting the same error , can you please share the sample project that is working state . It would help alot . My mail : Venkat.Thotakura@almullaexchange.com

@github-actions github-actions bot locked and limited conversation to collaborators Jun 29, 2023
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Assignees

@stliu stliu

@yiliuTo yiliuTo

Labels
azure-spring All azure-spring related issues azure-spring-aad Spring active directory related issues. Client This issue points to a problem in the data-plane of the library. customer-reported Issues that are reported by GitHub users external to the Azure organization. question The issue doesn't require a change to the product in order to be resolved. Most issues start as that
Projects
Spring Cloud Azure
Archived in project
Milestone
No milestone
Development

No branches or pull requests
5 participants
@stliu @joshfree @venkatthotakura5288 @BillyBolton @yiliuTo