search

Azure / azure-sdk-for-java

This repository is for active development of the Azure SDK for Java. For consumers of the SDK we recommend visiting our public developer docs at https://docs.microsoft.com/java/azure/ or our versioned developer docs at https://azure.github.io/azure-sdk-for-java.
MIT License
2.34k stars 1.98k forks source link

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

Closed BillyBolton closed 3 years ago

BillyBolton commented 3 years ago

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):

joshfree commented 3 years ago

@stliu PTAL

yiliuTo commented 3 years ago

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 commented 3 years ago

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 https://github.com/Azure/azure-sdk-for-java/issues/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 commented 3 years ago

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 commented 3 years ago

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 commented 3 years ago

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.

venkatthotakura5288 commented 1 year ago

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