search

morincer / teamcity-plugin-saml

The plug-in adds ability to authenticate users by SAML-based SSO providers (like Okta, Onelogin etc.)
MIT License
24 stars 16 forks source link

SAML request is not authenticated due to errors: invalid_response #53

Closed LennyCastaneda closed 4 years ago

LennyCastaneda commented 4 years ago

I'm getting error when implementing SAML for our TeamCity Server running in our AWS account.

Where specifically is the logs for this SAML plugin stored? I checkted plugin logs and teamcity-server.log and there is nothing that logs this error (see screen shot below).

Then my next question is, if there is no logs that is created then that means an instance of this class SamlAuthenticationScheme was nevever created, hence no logging for it?

Thanks for your help in advance.

SAML login page error
morincer commented 4 years ago

Hi! If the plugin was not enabled - you won't see the Login with SSO button, so the scheme is definitely enabled. The plugin logs to teamcity-server.log so you should be able to see that. Anyway, you may try to enable debug logging (either global debug or for security only) in the Teamcity logging configuration (just log debug-all preset) and try again.

In any case please provide more information - like TC version and log file - invalid_response might have very broad set of possible reasons, 80% of them are wrong configuration.

LennyCastaneda commented 4 years ago

The plugin is enabled because as you can see in the screen shot the SAML button is visible.

How do I enable debug logging (global debug) in TeamCity configuration? is it in the UI administration?

On Thu, Aug 13, 2020 at 1:13 PM morincer notifications@github.com wrote:

Hi! If the plugin was not enabled - you won't see the Login with SSO button, so the scheme is definitely enabled. The plugin logs to teamcity-server.log so you should be able to see that. Anyway, you may try to enable debug logging (either global debug or for security only) in the Teamcity logging configuration (just log debug-all preset) and try again.

In any case please provide more information - like TC version and log file

  • invalid_response might have very broad set of possible reasons, 80% of them are wrong configuration.

— You are receiving this because you authored the thread. Reply to this email directly, view it on GitHub https://github.com/morincer/teamcity-plugin-saml/issues/53#issuecomment-673687624, or unsubscribe https://github.com/notifications/unsubscribe-auth/ACLPMRRKDBC5I7ZOSIKDP5DSARCQPANCNFSM4P6XRHCA .

--

Take care,

Lenny Castaneda C: 714-414-5823 O: 619-431-0039

LennyCastaneda commented 4 years ago

Below is what I see at the bottom of teamcit-auth.log

Presigned-Token Authentication] Authentication scheme is not enabled. ---What does this mean? Do I need to enable authentication scheme? If so, how do I do it?

[2020-08-13 21:06:17,745] DEBUG [th; https-jsse-nio-443-exec-73] - [Presigned-Token Authentication] Authentication scheme is not enabled. org.apache.catalina.connector.RequestFacade@126dda4 [2020-08-13 21:06:17,823] DEBUG [th; https-jsse-nio-443-exec-73] - Creating session 5EA1896E9F... (created: 2020-08-13 21:06:17.823, timeout: 3600s) [2020-08-13 21:06:17,823] DEBUG [th; https-jsse-nio-443-exec-73] - Matched authentication scheme: jetbrains.buildServer.auth.saml.plugin.SamlAuthenticationScheme, authResult: UNAUTHENTICATED [2020-08-13 21:06:17,823] DEBUG [th; https-jsse-nio-443-exec-73] - Responding with 401 HTTP status with message "SAML request is not authenticated due to errors: invalid_response", sending no WWW-Authenticate header in response [2020-08-13 21:06:17,917] DEBUG [th; https-jsse-nio-443-exec-65] - Processing request with no authorization header: GET '/app/saml/callback/%22/res/6114880409683721742.css', from client 10.24.82.90 (10.50.34.19:36776), no auth [2020-08-13 21:06:17,917] DEBUG [th; https-jsse-nio-443-exec-65] - [Presigned-Token Authentication] Authentication scheme is not enabled. org.apache.catalina.connector.RequestFacade@126dda4 [2020-08-13 21:06:17,917] DEBUG [th; https-jsse-nio-443-exec-65] - No scheme was matched [2020-08-13 21:06:17,917] DEBUG [th; https-jsse-nio-443-exec-65] - Processing unauthenticated request [2020-08-13 21:06:17,917] DEBUG [th; https-jsse-nio-443-exec-65] - Redirecting to login page [2020-08-13 21:06:17,932] DEBUG [th; https-jsse-nio-443-exec-78] - Processing request with no authorization header: GET '/app/saml/callback/%22/res/2319721761153202242.css', from client 10.24.82.90 (10.50.34.19:36776), no auth [2020-08-13 21:06:17,932] DEBUG [th; https-jsse-nio-443-exec-78] - [Presigned-Token Authentication] Authentication scheme is not enabled. org.apache.catalina.connector.RequestFacade@126dda4 [2020-08-13 21:06:17,932] DEBUG [th; https-jsse-nio-443-exec-78] - No scheme was matched [2020-08-13 21:06:17,932] DEBUG [th; https-jsse-nio-443-exec-78] - Processing unauthenticated request [2020-08-13 21:06:17,932] DEBUG [th; https-jsse-nio-443-exec-78] - Redirecting to login page [2020-08-13 21:06:17,995] DEBUG [th; https-jsse-nio-443-exec-78] - Processing request with no authorization header: GET '/app/saml/callback/%22/res/-3342039278521329535.css', from client 10.24.82.90 (10.50.34.19:36776), no auth [2020-08-13 21:06:17,995] DEBUG [th; https-jsse-nio-443-exec-78] - [Presigned-Token Authentication] Authentication scheme is not enabled. org.apache.catalina.connector.RequestFacade@14c0309 [2020-08-13 21:06:17,995] DEBUG [th; https-jsse-nio-443-exec-78] - No scheme was matched [2020-08-13 21:06:17,995] DEBUG [th; https-jsse-nio-443-exec-78] - Processing unauthenticated request [2020-08-13 21:06:17,995] DEBUG [th; https-jsse-nio-443-exec-78] - Redirecting to login page [2020-08-13 21:06:18,135] DEBUG [th; https-jsse-nio-443-exec-84] - Processing request with no authorization header: GET '/app/saml/callback/%22/res/-1503540342333606626.css', from client 10.24.82.90 (10.50.34.19:36950), no auth [2020-08-13 21:06:18,135] DEBUG [th; https-jsse-nio-443-exec-84] - [Presigned-Token Authentication] Authentication scheme is not enabled. org.apache.catalina.connector.RequestFacade@1800db1 [2020-08-13 21:06:18,135] DEBUG [th; https-jsse-nio-443-exec-84] - No scheme was matched [2020-08-13 21:06:18,135] DEBUG [th; https-jsse-nio-443-exec-84] - Processing unauthenticated request [2020-08-13 21:06:18,135] DEBUG [th; https-jsse-nio-443-exec-84] - Redirecting to login page [2020-08-13 21:06:22,589] DEBUG [th; https-jsse-nio-443-exec-91] - Processing request with no authorization header: POST '/app/saml/callback/?RelayState=https%3A%2F% 2Fteamcity-ssotest.pri.services-exchange.com%2Fapp%2Fsaml%2Flogin%2F&SAMLResponse=PHNhbWxwOlJlc3BvbnNlIFZlcnNpb249IjIuMCIgSUQ9IldxbWRqcU9nNzQ4R0hINkN3NG1yb2NHWFMtUyIgSXNzdWVJbnN0YW50PSIyMDIwLTA4LTEzVDIxOjA2OjIyLjM5MVoiIEluUmVzcG9uc2VUbz0iT05FTE9HSU5fZGFiZThlMGUtMTQ2MC00NmMxLWJhZjktYWJkMDhlNDYzZmQ4IiBEZXN0aW5hdGlvbj0iaHR0cHM6Ly90ZWFtY2l0eS1zc290ZXN0LnByaS5zZXJ2aWNlcy1leGNoYW5nZS5jb20vYXBwL3NhbWwvY2FsbGJhY2svIiB4bWxuczpzYW1scD0idXJuOm9hc2lzOm5hbWVzOnRj...', from client 10.24.82.90 (10.50.34.19:36778), no auth

On Thu, Aug 13, 2020 at 2:02 PM Lenny Castaneda lenny.castaneda@gmail.com wrote:

The plugin is enabled because as you can see in the screen shot the SAML button is visible.

How do I enable debug logging (global debug) in TeamCity configuration? is it in the UI administration?

On Thu, Aug 13, 2020 at 1:13 PM morincer notifications@github.com wrote:

Hi! If the plugin was not enabled - you won't see the Login with SSO button, so the scheme is definitely enabled. The plugin logs to teamcity-server.log so you should be able to see that. Anyway, you may try to enable debug logging (either global debug or for security only) in the Teamcity logging configuration (just log debug-all preset) and try again.

In any case please provide more information - like TC version and log file - invalid_response might have very broad set of possible reasons, 80% of them are wrong configuration.

— You are receiving this because you authored the thread. Reply to this email directly, view it on GitHub https://github.com/morincer/teamcity-plugin-saml/issues/53#issuecomment-673687624, or unsubscribe https://github.com/notifications/unsubscribe-auth/ACLPMRRKDBC5I7ZOSIKDP5DSARCQPANCNFSM4P6XRHCA .

--

Take care,

Lenny Castaneda C: 714-414-5823 O: 619-431-0039

--

Take care,

Lenny Castaneda C: 714-414-5823 O: 619-431-0039

morincer commented 4 years ago

Yes. you can change logging presets it in UI. https://www.jetbrains.com/help/teamcity/teamcity-server-logs.html

Please, provide full log (both teamcity-server and teamcity-auth), and screenshots of your TC SAML settings and same for your IdP settings (make sure no sensitive data, like private certificates are fully visible).

LennyCastaneda commented 4 years ago

I just tried sending you the logs but the attachedmebrs were too large for Github. Do you have a direct email I can forward to?

Take care,

Lenny Castaneda C: 714-414-5823 O: 619-431-0039

On Aug 14, 2020, at 12:58 AM, morincer notifications@github.com wrote:

 Yes. you can change logging presets it in UI. https://www.jetbrains.com/help/teamcity/teamcity-server-logs.html

Please, provide full log (both teamcity-server and teamcity-auth), and screenshots of your TC SAML settings and same for your IdP settings (make sure no sensitive data, like private certificates are fully visible).

— You are receiving this because you authored the thread. Reply to this email directly, view it on GitHub, or unsubscribe.

fatmcgav commented 4 years ago

I've just hit this same error, and after enabling some additional logging on com.onlogin.saml2.authn, I found this log line:

[2020-08-14 19:01:04,007]  ERROR - login.saml2.authn.SamlResponse - The response was received at http://ci.***.co/app/saml/callback instead of https://ci.***.co/app/saml/callback

When watching the Chrome network requests console, I spotted that the authn request goes out with a RelayState query param that has the URL with the http protocol.

So this got me looking through the code, and I traced it from https://github.com/morincer/teamcity-plugin-saml/blob/9e98fee9953a52940438f961f7451c41cc785e5b/saml-authentication-server/src/main/java/jetbrains/buildServer/auth/saml/plugin/SamlAuthenticationScheme.java#L88 to https://github.com/onelogin/java-saml/blob/26a29dad1a8603d47a9393980d9e7822064399f2/toolkit/src/main/java/com/onelogin/saml2/Auth.java#L417-L425 to https://github.com/onelogin/java-saml/blob/26a29dad1a8603d47a9393980d9e7822064399f2/toolkit/src/main/java/com/onelogin/saml2/servlet/ServletUtils.java#L54-L63

In our setup, TeamCity server is deployed on GKE using Nginx-ingress, sat behind a L3 GCP Load balancer. Looking at the Nginx config, it aligns with that defined in the TeamCity docs. I've also configured Tomcat to use the "RemoteIPValue" approach.

I'm wondering if maybe the call to auth.login() should specify returnTo value: https://github.com/onelogin/java-saml/blob/26a29dad1a8603d47a9393980d9e7822064399f2/toolkit/src/main/java/com/onelogin/saml2/Auth.java#L427-L439

That way, the RelayState value will always match the SSO Callback config.

@morincer Thoughts?

morincer commented 4 years ago

@LennyCastaneda ,I checked the logs you sent me and I don't see anything correlated to the SAML error. Would you please try again and and capture the logs at the moment right after the failure? Another option would be to disable strict mode in SAML and try doing the login.

@fatmcgav, oh, these load balancers. No, your error is (might be) different. Check the callback URL setting in SAML - it should match the one to which you receive SAML assertion. Otherwise, disable strict mode as well.

fatmcgav commented 4 years ago

oh, these load balancers. No, your error is (might be) different. Check the callback URL setting in SAML - it should match the one to which you receive SAML assertion. Otherwise, disable strict mode as well.

I did wonder about the OKTA side config aswell, but have been over it with a fine-toothed comb and all looks correct. I've even gone as far as logging the X-Forwarded-* headers in TeamCity pod, and they are all what I'd expect when it comes to URL and protocol, so a bit stumped. I'll give disabling strict mode a go, and see what that offers.

fatmcgav commented 4 years ago

So disabling strict mode got me in...

Are there any major negative effect or security implications from disabling?

fatmcgav commented 4 years ago

I've opened an issue upstream, as the recommendation appears to be to keep strict mode enabled for production usage.

Will see if they can suggest anything...

morincer commented 4 years ago

@fatmcgav , just noticed that you opened the issue in onelogin/java-saml project. I guess the issue is not in the library itself - it validates correctly (checks Request URL against supposed destination). Anyway, moving my comment here.

So, first things first. Are you able to provide the dump of the SAML request which TC receives? I need to check the request URL. And what URL is configured for the TC server (on the Settings - General page)? Internally, SAML authentication takes request's URL and compares it with configured callback URL. The plugin takes the base from TC configuration.

fatmcgav commented 4 years ago

Sure...

So the Authn request and response looks like this:

[2020-08-17 15:15:50,357]  DEBUG - login.saml2.authn.AuthnRequest - AuthNRequest --> <samlp:AuthnRequest xmlns:samlp="urn:oasis:names:tc:SAML:2.0:protocol" xmlns:saml="urn:oasis:names:tc:SAML:2.0:assertion" ID="ONELOGIN_078ef516-44b8-4a95-b74b-e130dd3d15a6" Version="2.0" IssueInstant="2020-08-17T15:15:50Z" Destination="https://elastic.okta.com/app/***/sso/saml" ProtocolBinding="urn:oasis:names:tc:SAML:2.0:bindings:HTTP-POST" AssertionConsumerServiceURL="https://ci.elastic.co/app/saml/callback/"><saml:Issuer>https://ci.elastic.co/teamcity-saml-plugin</saml:Issuer><samlp:NameIDPolicy Format="urn:oasis:names:tc:SAML:1.1:nameid-format:unspecified" AllowCreate="true" /></samlp:AuthnRequest>
[2020-08-17 15:15:51,384]  DEBUG - login.saml2.authn.SamlResponse - SAMLResponse invalid --> <?xml version="1.0" encoding="UTF-8"?><saml2p:Response Destination="https://ci.elastic.co/app/saml/callback" ID="id445423002592011161557787441" InResponseTo="ONELOGIN_078ef516-44b8-4a95-b74b-e130dd3d15a6" IssueInstant="2020-08-17T15:15:50.680Z" Version="2.0" xmlns:saml2p="urn:oasis:names:tc:SAML:2.0:protocol" xmlns:xs="http://www.w3.org/2001/XMLSchema"><saml2:Issuer Format="urn:oasis:names:tc:SAML:2.0:nameid-format:entity" xmlns:saml2="urn:oasis:names:tc:SAML:2.0:assertion">http://www.okta.com/exkf08ex6mXiOyQJd1t7</saml2:Issuer><ds:Signature xmlns:ds="http://www.w3.org/2000/09/xmldsig#"><ds:SignedInfo><ds:CanonicalizationMethod Algorithm="http://www.w3.org/2001/10/xml-exc-c14n#"/><ds:SignatureMethod Algorithm="http://www.w3.org/2001/04/xmldsig-more#rsa-sha256"/><ds:Reference URI="#id445423002592011161557787441"><ds:Transforms><ds:Transform Algorithm="http://www.w3.org/2000/09/xmldsig#enveloped-signature"/><ds:Transform Algorithm="http://www.w3.org/2001/10/xml-exc-c14n#"><ec:InclusiveNamespaces PrefixList="xs" xmlns:ec="http://www.w3.org/2001/10/xml-exc-c14n#"/></ds:Transform></ds:Transforms><ds:DigestMethod Algorithm="http://www.w3.org/2001/04/xmlenc#sha256"/><ds:DigestValue>jHFjOUe3G6Po6mM/EiZ4+g5IcVZJifakdHPTB4wL9Ts=</ds:DigestValue></ds:Reference></ds:SignedInfo><ds:SignatureValue>UakLgz3eRhS2BuADAKW+3Jnoya217lQAHHHz5BrGW2QtZlczj5exKxMJzpwqc2ykB1EEILCY2IUH/PtSvLa4S3P0U/929+AJ1MdDWWUt5JyVbhW3n+6zaewIWnmCNZZIPcHRzVA7tRXkL1WcNP7cZcNaiwyn3x0oTkmsFbcoie+gDW5brjbZwoX3hGEGJ1yyNn8GdiKgjI5bx/qgudk8cLJ1W2QW326QINtVlrLwm7nFnrucLzraeAmCU6J4QBTA5GdanPSSq08Z2ydHVDJfPD5fAJpgFiFPnSYg3HEkuBXmC6WOU3uXlLl1XvUhMZIfM0m51Tw9br2fFpLpxZ9aAA==</ds:SignatureValue><ds:KeyInfo><ds:X509Data><ds:X509Certificate>MIIDnjCCAoagAwIBAgIGAV2mxH3tMA0GCSqGSIb3DQEBCwUAMIGPMQswCQYDVQQGEwJVUzETMBEG
A1UECAwKQ2FsaWZvcm5pYTEWMBQGA1UEBwwNU2FuIEZyYW5jaXNjbzENMAsGA1UECgwET2t0YTEU
MBIGA1UECwwLU1NPUHJvdmlkZXIxEDAOBgNVBAMMB2VsYXN0aWMxHDAaBgkqhkiG9w0BCQEWDWlu
Zm9Ab2t0YS5jb20wHhcNMTcwODAzMDYyMzQxWhcNMjcwODAzMDYyNDQxWjCBjzELMAkGA1UEBhMC
VVMxEzARBgNVBAgMCkNhbGlmb3JuaWExFjAUBgNVBAcMDVNhbiBGcmFuY2lzY28xDTALBgNVBAoM
BE9rdGExFDASBgNVBAsMC1NTT1Byb3ZpZGVyMRAwDgYDVQQDDAdlbGFzdGljMRwwGgYJKoZIhvcN
AQkBFg1pbmZvQG9rdGEuY29tMIIBIjANBgkqhkiG9w0BAQEFAAOCAQ8AMIIBCgKCAQEAr7maEDT/
NRNygWJI7ZzOyc0eY4wzlvFTKKS5gCW3KshbyHdGD7Pg8wNMO1CJc5RvT/57Bupw1bCq5nDbneJN
FfVJzldK6jpmbtmE3ZY1eYUyIcC5+I5WqcmksF9Rb3dZ/hmSQ5tJt2uwFJ9HIWhOkPS3QP87EM8R
V9FoMrDuwdU2QFmvQwrbnnb5FchmJtY1QHSq557e4sub0apmzO2YEq+QdPQbEuwMh5uAYpFGccv4
z3IVgl3bP4fET/UUNGfU/Pf8ykI24giZ0tN8L9N2JeG9ptt/WfNRpZy2la72k6oam0GgJcexhjm4
E7SYpcRWpAKPH08D7FPNHncOPPM+mwIDAQABMA0GCSqGSIb3DQEBCwUAA4IBAQBPnjwbF73MYsOe
di5YRiFvbPApqUwnb1l0sPrIwfaA7LkiTYsNAvxKYjUyeLYnWhwHbfkjriTRSx2uVJ840uetgSdg
CwpXz3m852Cy/e2OcwuYHVYvo+G3Pj8tCtaC3wb/GAJJ4kybHvSLu95Qlzxfyxr/As7AzqwcY3b5
qNLfXLmAxz4uNmkmfA87Kviy5z+kTHfQX6DgxE0HQBZHdGTiCb05uFLgfg9S3RNmSOEf3BAkwBnL
t2z9rdPpspl6TU/m8akaML400AYMPVroYEQIoL/OTvev/A45l2WUbFhEPcCeYAh2gvHkj6seilTR
RLq5PHHRsD0c4c19I/F2q0jg</ds:X509Certificate></ds:X509Data></ds:KeyInfo></ds:Signature><saml2p:Status xmlns:saml2p="urn:oasis:names:tc:SAML:2.0:protocol"><saml2p:StatusCode Value="urn:oasis:names:tc:SAML:2.0:status:Success"/></saml2p:Status><saml2:Assertion ID="id445423002592816771869915072" IssueInstant="2020-08-17T15:15:50.680Z" Version="2.0" xmlns:saml2="urn:oasis:names:tc:SAML:2.0:assertion" xmlns:xs="http://www.w3.org/2001/XMLSchema"><saml2:Issuer Format="urn:oasis:names:tc:SAML:2.0:nameid-format:entity" xmlns:saml2="urn:oasis:names:tc:SAML:2.0:assertion">http://www.okta.com/exkf08ex6mXiOyQJd1t7</saml2:Issuer><ds:Signature xmlns:ds="http://www.w3.org/2000/09/xmldsig#"><ds:SignedInfo><ds:CanonicalizationMethod Algorithm="http://www.w3.org/2001/10/xml-exc-c14n#"/><ds:SignatureMethod Algorithm="http://www.w3.org/2001/04/xmldsig-more#rsa-sha256"/><ds:Reference URI="#id445423002592816771869915072"><ds:Transforms><ds:Transform Algorithm="http://www.w3.org/2000/09/xmldsig#enveloped-signature"/><ds:Transform Algorithm="http://www.w3.org/2001/10/xml-exc-c14n#"><ec:InclusiveNamespaces PrefixList="xs" xmlns:ec="http://www.w3.org/2001/10/xml-exc-c14n#"/></ds:Transform></ds:Transforms><ds:DigestMethod Algorithm="http://www.w3.org/2001/04/xmlenc#sha256"/><ds:DigestValue>9iBVy6chLS7ZyUyLQztjohMUj/At2RuGZ3HS5OE375I=</ds:DigestValue></ds:Reference></ds:SignedInfo><ds:SignatureValue>pC088xR0nmIep1L72gfT9EBEkeJ6DTbhy2JJBNQ82FbOzn2ACBD5CGZcztcl0cIcR+DJ5M87JdtEPs75343da20Vv8K0IB7hUhYe7ec5uJF9M/f2rq6NO4hnA2MnOZeN86e6hD58kiF3IQp3xKsf6WHuzPX5d5LeSu1UFtcKiiRS3xK1sCJW9zvPcDoqGJCdI5tNgLfKexFUjXrOU7adekz20FBWxFpLMYGWRiJSFPdA1UWDu8JzsapRkBPZ8EkHNa34OMhPtuchcR7FESn4skV7xgEtBtvbmK4JWeb+ZvX9y5r43occE7JjGuISX2XijoPvBCkSXmiUWQWDybp6LA==</ds:SignatureValue><ds:KeyInfo><ds:X509Data><ds:X509Certificate>MIIDnjCCAoagAwIBAgIGAV2mxH3tMA0GCSqGSIb3DQEBCwUAMIGPMQswCQYDVQQGEwJVUzETMBEG
A1UECAwKQ2FsaWZvcm5pYTEWMBQGA1UEBwwNU2FuIEZyYW5jaXNjbzENMAsGA1UECgwET2t0YTEU
MBIGA1UECwwLU1NPUHJvdmlkZXIxEDAOBgNVBAMMB2VsYXN0aWMxHDAaBgkqhkiG9w0BCQEWDWlu
Zm9Ab2t0YS5jb20wHhcNMTcwODAzMDYyMzQxWhcNMjcwODAzMDYyNDQxWjCBjzELMAkGA1UEBhMC
VVMxEzARBgNVBAgMCkNhbGlmb3JuaWExFjAUBgNVBAcMDVNhbiBGcmFuY2lzY28xDTALBgNVBAoM
BE9rdGExFDASBgNVBAsMC1NTT1Byb3ZpZGVyMRAwDgYDVQQDDAdlbGFzdGljMRwwGgYJKoZIhvcN
AQkBFg1pbmZvQG9rdGEuY29tMIIBIjANBgkqhkiG9w0BAQEFAAOCAQ8AMIIBCgKCAQEAr7maEDT/
NRNygWJI7ZzOyc0eY4wzlvFTKKS5gCW3KshbyHdGD7Pg8wNMO1CJc5RvT/57Bupw1bCq5nDbneJN
FfVJzldK6jpmbtmE3ZY1eYUyIcC5+I5WqcmksF9Rb3dZ/hmSQ5tJt2uwFJ9HIWhOkPS3QP87EM8R
V9FoMrDuwdU2QFmvQwrbnnb5FchmJtY1QHSq557e4sub0apmzO2YEq+QdPQbEuwMh5uAYpFGccv4
z3IVgl3bP4fET/UUNGfU/Pf8ykI24giZ0tN8L9N2JeG9ptt/WfNRpZy2la72k6oam0GgJcexhjm4
E7SYpcRWpAKPH08D7FPNHncOPPM+mwIDAQABMA0GCSqGSIb3DQEBCwUAA4IBAQBPnjwbF73MYsOe
di5YRiFvbPApqUwnb1l0sPrIwfaA7LkiTYsNAvxKYjUyeLYnWhwHbfkjriTRSx2uVJ840uetgSdg
CwpXz3m852Cy/e2OcwuYHVYvo+G3Pj8tCtaC3wb/GAJJ4kybHvSLu95Qlzxfyxr/As7AzqwcY3b5
qNLfXLmAxz4uNmkmfA87Kviy5z+kTHfQX6DgxE0HQBZHdGTiCb05uFLgfg9S3RNmSOEf3BAkwBnL
t2z9rdPpspl6TU/m8akaML400AYMPVroYEQIoL/OTvev/A45l2WUbFhEPcCeYAh2gvHkj6seilTR
RLq5PHHRsD0c4c19I/F2q0jg</ds:X509Certificate></ds:X509Data></ds:KeyInfo></ds:Signature><saml2:Subject xmlns:saml2="urn:oasis:names:tc:SAML:2.0:assertion"><saml2:NameID Format="urn:oasis:names:tc:SAML:1.1:nameid-format:emailAddress">gavin.williams@elastic.co</saml2:NameID><saml2:SubjectConfirmation Method="urn:oasis:names:tc:SAML:2.0:cm:bearer"><saml2:SubjectConfirmationData InResponseTo="ONELOGIN_078ef516-44b8-4a95-b74b-e130dd3d15a6" NotOnOrAfter="2020-08-17T15:20:50.680Z" Recipient="https://ci.elastic.co/app/saml/callback"/></saml2:SubjectConfirmation></saml2:Subject><saml2:Conditions NotBefore="2020-08-17T15:10:50.680Z" NotOnOrAfter="2020-08-17T15:20:50.680Z" xmlns:saml2="urn:oasis:names:tc:SAML:2.0:assertion"><saml2:AudienceRestriction><saml2:Audience>https://ci.elastic.co/teamcity-saml-plugin</saml2:Audience></saml2:AudienceRestriction></saml2:Conditions><saml2:AuthnStatement AuthnInstant="2020-08-17T12:24:55.751Z" SessionIndex="ONELOGIN_078ef516-44b8-4a95-b74b-e130dd3d15a6" xmlns:saml2="urn:oasis:names:tc:SAML:2.0:assertion"><saml2:AuthnContext><saml2:AuthnContextClassRef>urn:oasis:names:tc:SAML:2.0:ac:classes:PasswordProtectedTransport</saml2:AuthnContextClassRef></saml2:AuthnContext></saml2:AuthnStatement><saml2:AttributeStatement xmlns:saml2="urn:oasis:names:tc:SAML:2.0:assertion"><saml2:Attribute Name="fullname" NameFormat="urn:oasis:names:tc:SAML:2.0:attrname-format:unspecified"><saml2:AttributeValue xmlns:xs="http://www.w3.org/2001/XMLSchema" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xsi:type="xs:string">Gavin  Williams</saml2:AttributeValue></saml2:Attribute><saml2:Attribute Name="email" NameFormat="urn:oasis:names:tc:SAML:2.0:attrname-format:unspecified"><saml2:AttributeValue xmlns:xs="http://www.w3.org/2001/XMLSchema" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xsi:type="xs:string">gavin.williams@elastic.co</saml2:AttributeValue></saml2:Attribute></saml2:AttributeStatement></saml2:Assertion></saml2p:Response>
[2020-08-17 15:15:51,385]  ERROR - login.saml2.authn.SamlResponse - The response was received at http://ci.elastic.co/app/saml/callback instead of https://ci.elastic.co/app/saml/callback

And the TeamCity URL is configured as: image

Let me know if I can provide any more info...

morincer commented 4 years ago

I see that the authn request lists correct protocol, so seems LB spoils the raspberry. Did you try following the https://github.com/onelogin/java-saml#working-behind-load-balancer?

пн, 17 авг. 2020 г., 18:36 Gavin Williams notifications@github.com:

Sure...

So the Authn request and response looks like this:

[2020-08-17 15:15:50,357] DEBUG - login.saml2.authn.AuthnRequest - AuthNRequest --> https://ci.elastic.co/teamcity-saml-plugin</saml:Issuer></samlp:AuthnRequest> [2020-08-17 15:15:51,384] DEBUG - login.saml2.authn.SamlResponse - SAMLResponse invalid --> <?xml version="1.0" encoding="UTF-8"?>http://www.okta.com/exkf08ex6mXiOyQJd1t7</saml2:Issuer></ds:Transform></ds:Transforms>jHFjOUe3G6Po6mM/EiZ4+g5IcVZJifakdHPTB4wL9Ts=</ds:DigestValue></ds:Reference></ds:SignedInfo>UakLgz3eRhS2BuADAKW+3Jnoya217lQAHHHz5BrGW2QtZlczj5exKxMJzpwqc2ykB1EEILCY2IUH/PtSvLa4S3P0U/929+AJ1MdDWWUt5JyVbhW3n+6zaewIWnmCNZZIPcHRzVA7tRXkL1WcNP7cZcNaiwyn3x0oTkmsFbcoie+gDW5brjbZwoX3hGEGJ1yyNn8GdiKgjI5bx/qgudk8cLJ1W2QW326QINtVlrLwm7nFnrucLzraeAmCU6J4QBTA5GdanPSSq08Z2ydHVDJfPD5fAJpgFiFPnSYg3HEkuBXmC6WOU3uXlLl1XvUhMZIfM0m51Tw9br2fFpLpxZ9aAA==</ds:SignatureValue>MIIDnjCCAoagAwIBAgIGAV2mxH3tMA0GCSqGSIb3DQEBCwUAMIGPMQswCQYDVQQGEwJVUzETMBEG A1UECAwKQ2FsaWZvcm5pYTEWMBQGA1UEBwwNU2FuIEZyYW5jaXNjbzENMAsGA1UECgwET2t0YTEU MBIGA1UECwwLU1NPUHJvdmlkZXIxEDAOBgNVBAMMB2VsYXN0aWMxHDAaBgkqhkiG9w0BCQEWDWlu Zm9Ab2t0YS5jb20wHhcNMTcwODAzMDYyMzQxWhcNMjcwODAzMDYyNDQxWjCBjzELMAkGA1UEBhMC VVMxEzARBgNVBAgMCkNhbGlmb3JuaWExFjAUBgNVBAcMDVNhbiBGcmFuY2lzY28xDTALBgNVBAoM BE9rdGExFDASBgNVBAsMC1NTT1Byb3ZpZGVyMRAwDgYDVQQDDAdlbGFzdGljMRwwGgYJKoZIhvcN AQkBFg1pbmZvQG9rdGEuY29tMIIBIjANBgkqhkiG9w0BAQEFAAOCAQ8AMIIBCgKCAQEAr7maEDT/ NRNygWJI7ZzOyc0eY4wzlvFTKKS5gCW3KshbyHdGD7Pg8wNMO1CJc5RvT/57Bupw1bCq5nDbneJN FfVJzldK6jpmbtmE3ZY1eYUyIcC5+I5WqcmksF9Rb3dZ/hmSQ5tJt2uwFJ9HIWhOkPS3QP87EM8R V9FoMrDuwdU2QFmvQwrbnnb5FchmJtY1QHSq557e4sub0apmzO2YEq+QdPQbEuwMh5uAYpFGccv4 z3IVgl3bP4fET/UUNGfU/Pf8ykI24giZ0tN8L9N2JeG9ptt/WfNRpZy2la72k6oam0GgJcexhjm4 E7SYpcRWpAKPH08D7FPNHncOPPM+mwIDAQABMA0GCSqGSIb3DQEBCwUAA4IBAQBPnjwbF73MYsOe di5YRiFvbPApqUwnb1l0sPrIwfaA7LkiTYsNAvxKYjUyeLYnWhwHbfkjriTRSx2uVJ840uetgSdg CwpXz3m852Cy/e2OcwuYHVYvo+G3Pj8tCtaC3wb/GAJJ4kybHvSLu95Qlzxfyxr/As7AzqwcY3b5 qNLfXLmAxz4uNmkmfA87Kviy5z+kTHfQX6DgxE0HQBZHdGTiCb05uFLgfg9S3RNmSOEf3BAkwBnL t2z9rdPpspl6TU/m8akaML400AYMPVroYEQIoL/OTvev/A45l2WUbFhEPcCeYAh2gvHkj6seilTR RLq5PHHRsD0c4c19I/F2q0jg</ds:X509Certificate></ds:X509Data></ds:KeyInfo></ds:Signature></saml2p:Status>http://www.okta.com/exkf08ex6mXiOyQJd1t7</saml2:Issuer></ds:Transform></ds:Transforms>9iBVy6chLS7ZyUyLQztjohMUj/At2RuGZ3HS5OE375I=</ds:DigestValue></ds:Reference></ds:SignedInfo>pC088xR0nmIep1L72gfT9EBEkeJ6DTbhy2JJBNQ82FbOzn2ACBD5CGZcztcl0cIcR+DJ5M87JdtEPs75343da20Vv8K0IB7hUhYe7ec5uJF9M/f2rq6NO4hnA2MnOZeN86e6hD58kiF3IQp3xKsf6WHuzPX5d5LeSu1UFtcKiiRS3xK1sCJW9zvPcDoqGJCdI5tNgLfKexFUjXrOU7adekz20FBWxFpLMYGWRiJSFPdA1UWDu8JzsapRkBPZ8EkHNa34OMhPtuchcR7FESn4skV7xgEtBtvbmK4JWeb+ZvX9y5r43occE7JjGuISX2XijoPvBCkSXmiUWQWDybp6LA==</ds:SignatureValue>MIIDnjCCAoagAwIBAgIGAV2mxH3tMA0GCSqGSIb3DQEBCwUAMIGPMQswCQYDVQQGEwJVUzETMBEG A1UECAwKQ2FsaWZvcm5pYTEWMBQGA1UEBwwNU2FuIEZyYW5jaXNjbzENMAsGA1UECgwET2t0YTEU MBIGA1UECwwLU1NPUHJvdmlkZXIxEDAOBgNVBAMMB2VsYXN0aWMxHDAaBgkqhkiG9w0BCQEWDWlu Zm9Ab2t0YS5jb20wHhcNMTcwODAzMDYyMzQxWhcNMjcwODAzMDYyNDQxWjCBjzELMAkGA1UEBhMC VVMxEzARBgNVBAgMCkNhbGlmb3JuaWExFjAUBgNVBAcMDVNhbiBGcmFuY2lzY28xDTALBgNVBAoM BE9rdGExFDASBgNVBAsMC1NTT1Byb3ZpZGVyMRAwDgYDVQQDDAdlbGFzdGljMRwwGgYJKoZIhvcN AQkBFg1pbmZvQG9rdGEuY29tMIIBIjANBgkqhkiG9w0BAQEFAAOCAQ8AMIIBCgKCAQEAr7maEDT/ NRNygWJI7ZzOyc0eY4wzlvFTKKS5gCW3KshbyHdGD7Pg8wNMO1CJc5RvT/57Bupw1bCq5nDbneJN FfVJzldK6jpmbtmE3ZY1eYUyIcC5+I5WqcmksF9Rb3dZ/hmSQ5tJt2uwFJ9HIWhOkPS3QP87EM8R V9FoMrDuwdU2QFmvQwrbnnb5FchmJtY1QHSq557e4sub0apmzO2YEq+QdPQbEuwMh5uAYpFGccv4 z3IVgl3bP4fET/UUNGfU/Pf8ykI24giZ0tN8L9N2JeG9ptt/WfNRpZy2la72k6oam0GgJcexhjm4 E7SYpcRWpAKPH08D7FPNHncOPPM+mwIDAQABMA0GCSqGSIb3DQEBCwUAA4IBAQBPnjwbF73MYsOe di5YRiFvbPApqUwnb1l0sPrIwfaA7LkiTYsNAvxKYjUyeLYnWhwHbfkjriTRSx2uVJ840uetgSdg CwpXz3m852Cy/e2OcwuYHVYvo+G3Pj8tCtaC3wb/GAJJ4kybHvSLu95Qlzxfyxr/As7AzqwcY3b5 qNLfXLmAxz4uNmkmfA87Kviy5z+kTHfQX6DgxE0HQBZHdGTiCb05uFLgfg9S3RNmSOEf3BAkwBnL t2z9rdPpspl6TU/m8akaML400AYMPVroYEQIoL/OTvev/A45l2WUbFhEPcCeYAh2gvHkj6seilTR RLq5PHHRsD0c4c19I/F2q0jg</ds:X509Certificate></ds:X509Data></ds:KeyInfo></ds:Signature>gavin.williams@elastic.co</saml2:NameID></saml2:SubjectConfirmation></saml2:Subject>https://ci.elastic.co/teamcity-saml-plugin</saml2:Audience></saml2:AudienceRestriction></saml2:Conditions>urn:oasis:names:tc:SAML:2.0:ac:classes:PasswordProtectedTransport</saml2:AuthnContextClassRef></saml2:AuthnContext></saml2:AuthnStatement>Gavin Williams</saml2:AttributeValue></saml2:Attribute>gavin.williams@elastic.co</saml2:AttributeValue></saml2:Attribute></saml2:AttributeStatement></saml2:Assertion></saml2p:Response> [2020-08-17 15:15:51,385] ERROR - login.saml2.authn.SamlResponse - The response was received at http://ci.elastic.co/app/saml/callback instead of https://ci.elastic.co/app/saml/callback

And the TeamCity URL is configured as: [image: image] https://user-images.githubusercontent.com/2235170/90414361-97d99200-e0a7-11ea-85ee-caedd2ca34ff.png

Let me know if I can provide any more info...

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/morincer/teamcity-plugin-saml/issues/53#issuecomment-674952991, or unsubscribe https://github.com/notifications/unsubscribe-auth/AEA55RRDHBODJGNAV6R2PTDSBFE6FANCNFSM4P6XRHCA .

fatmcgav commented 4 years ago

I see that the authn request lists correct protocol, so seems LB spoils the raspberry. Did you try following the onelogin/java-saml#working-behind-load-balancer? пн, 17 авг. 2020 г., 18:36 Gavin Williams notifications@github.com:

Ah, good spot... Setting the values on the Connector seems to have worked... It feels a bit extreme though, considering the fact that Tomcat should be able to handle the X-Forwarded headers by now...

Thanks for the pointer though - I'll try and update some docs to make this more obvious...

morincer commented 4 years ago

@LennyCastaneda , checked the logs you've sent me - not much I can see there, seems like the logging you collected is not enough. I will try to setup a sample logging preset profile so you can just enable it and collect whatever we need - stay tuned.
Also I created another new feature ticket (#54) which will allow to enable additional logging output for the plugin itself - but it will take a while to implement.

morincer commented 4 years ago

Hi @LennyCastaneda , please find attached the logging preset - please install it, activate, try to make the login again and send the teamcity-auth.log

debug-auth-saml.zip This is a copy of debug-auth preset with one additional category set to debug

LennyCastaneda commented 4 years ago

Thank you!!

Take care,

Lenny Castaneda C: 714-414-5823 O: 619-431-0039

On Aug 18, 2020, at 6:14 AM, morincer notifications@github.com wrote:

 Hi @LennyCastaneda , please find attached the logging preset - please install it, activate, try to make the login again and send the teamcity-auth.log

debug-auth-saml.zip This is a copy of debug-auth preset with one additional category set to debug

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub, or unsubscribe.

LennyCastaneda commented 4 years ago

Here is the new auth log after upload the zip you sent and re-trying the SAML authentication.

On Wed, Aug 19, 2020 at 10:42 AM Lenny Castaneda lenny.castaneda@gmail.com wrote:

I uploaded to the debug-aith-saml.zip you sent me and attached the logs after trying to login via SAML.

Let me know if you see anything in there that can pinpoint the problem.

Thanks again for your help.

On Tue, Aug 18, 2020 at 6:31 AM Lenny Castaneda lenny.castaneda@gmail.com wrote:

Thank you!!

Take care,

Lenny Castaneda C: 714-414-5823 O: 619-431-0039

On Aug 18, 2020, at 6:14 AM, morincer notifications@github.com wrote:



Hi @LennyCastaneda https://github.com/LennyCastaneda , please find attached the logging preset - please install it, activate, try to make the login again and send the teamcity-auth.log

debug-auth-saml.zip https://github.com/morincer/teamcity-plugin-saml/files/5090561/debug-auth-saml.zip This is a copy of debug-auth preset with one additional category set to debug

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/morincer/teamcity-plugin-saml/issues/53#issuecomment-675471187, or unsubscribe https://github.com/notifications/unsubscribe-auth/ACLPMRSF5PYEFQNZNIG3MCDSBJ5DFANCNFSM4P6XRHCA .

--

Take care,

Lenny Castaneda C: 714-414-5823 O: 619-431-0039

--

Take care,

Lenny Castaneda C: 714-414-5823 O: 619-431-0039

morincer commented 4 years ago

@LennyCastaneda , I don't see any attachment.

LennyCastaneda commented 4 years ago

Below are the copies of logs after I uploaded the zip you sent me and retried the SAML login.

Let me know if any of this pinpoints why SAML auth is not working for me.

Thanks for your help in advance.

TeamCity-server log:

InputData{myQueue=65, myRunningBuilds=0, myAgents=0} [2020-08-18 20:27:33,837] DEBUG - jetbrains.buildServer.SERVER - Compatible/can run on agents for: Queued build {item id=2941, promotion=Build promotion {promotion id=2941, configuration={id=Ngf_Api_CloudHubPoc_IntegrationBuilds, internal id=bt112}}} are: [], already distributed agents: [], inputData: InputData{myQueue=65, myRunningBuilds=0, myAgents=0} [2020-08-18 20:27:33,837] DEBUG - jetbrains.buildServer.SERVER - Compatible/can run on agents for: Queued build {item id=2941, promotion=Build promotion {promotion id=2941, configuration={id=Ngf_Api_CloudHubPoc_IntegrationBuilds, internal id=bt112}}} are: [], already distributed agents: [], inputData: InputData{myQueue=65, myRunningBuilds=0, myAgents=0} [2020-08-18 20:27:33,837] DEBUG - jetbrains.buildServer.SERVER - Compatible/can run on agents for: Queued build {item id=2944, promotion=Build promotion {promotion id=2944, configuration={id=Ngf_Ui_NgfnexUi_IntegrationBuilds, internal id=bt92}}} are: [], already distributed agents: [], inputData: InputData{myQueue=65, myRunningBuilds=0, myAgents=0} [2020-08-18 20:27:33,837] DEBUG - jetbrains.buildServer.SERVER - Compatible/can run on agents for: Queued build {item id=2944, promotion=Build promotion {promotion id=2944, configuration={id=Ngf_Ui_NgfnexUi_IntegrationBuilds, internal id=bt92}}} are: [], already distributed agents: [], inputData: InputData{myQueue=65, myRunningBuilds=0, myAgents=0} [2020-08-18 20:27:33,853] DEBUG - ver.web.ResponseFragmentFilter - Request finished: 14c0309/18be3d0 [2020-08-18 20:27:35,666] DEBUG - l.PeriodicChangesLoaderContext - Loading current repository state for VCS root 'VcsRootBitBucket' [2020-08-18 20:27:35,666] DEBUG - l.PeriodicChangesLoaderContext - Loading current repository state for VCS root 'VcsRootBitBucket' [2020-08-18 20:27:36,041] DEBUG - serverSide.impl.BuildQueueImpl - Queued builds selected for merge operation (personal and starting builds excluded): bt92 (promo id: 2933), bt97 (promo id: 2932), bt92 (promo id: 2671), bt92 (promo id: 2666), bt92 (promo id: 2609), bt92 (promo id: 2612), bt92 (promo id: 2613), bt92 (promo id: 2614), bt92 (promo id: 2617), bt92 (promo id: 2618), bt92 (promo id: 2665), bt92 (promo id: 2661), bt92 (promo id: 2662), bt21 (promo id: 2663), bt17 (promo id: 2931), bt92 (promo id: 2868), bt92 (promo id: 2677), bt92 (promo id: 2862), bt92 (promo id: 2767), bt92 (promo id: 2768), bt92 (promo id: 2769), bt92 (promo id: 2772), bt92 (promo id: 2773), bt92 (promo id: 2774), bt92 (promo id: 2777), bt92 (promo id: 2776), bt92 (promo id: 2861), bt92 (promo id: 2863), bt92 (promo id: 2864), bt92 (promo id: 2872), bt92 (promo id: 2874), bt92 (promo id: 2877), bt92 (promo id: 2878), bt92 (promo id: 2881), bt92 (promo id: 2883), bt92 (promo id: 2884), bt92 (promo id: 2885), bt92 (promo id: 2889), bt92 (promo id: 2890), bt92 (promo id: 2894), bt92 (promo id: 2895), bt92 (promo id: 2896), bt92 (promo id: 2897), bt92 (promo id: 2906), bt92 (promo id: 2910), bt92 (promo id: 2914), bt92 (promo id: 2915), bt92 (promo id: 2920), bt92 (promo id: 2917), bt92 (promo id: 2919), bt92 (promo id: 2925), bt92 (promo id: 2926), bt92 (promo id: 2927), bt106 (promo id: 2928), bt92 (promo id: 2934), bt92 (promo id: 2943), bt92 (promo id: 2942), bt92 (promo id: 2937), bt92 (promo id: 2940), bt92 (promo id: 2939), bt92 (promo id: 2944), [2020-08-18 20:27:36,041] DEBUG - serverSide.impl.BuildQueueImpl - None of the queued builds can be merged [2020-08-18 20:27:36,041] DEBUG - jetbrains.buildServer.SERVER - Compatible/can run on agents for: Queued build {item id=2933, promotion=Build promotion {promotion id=2933, configuration={id=Ngf_Ui_NgfnexUi_IntegrationBuilds, internal id=bt92}}} are: [], already distributed agents: [], inputData: InputData{myQueue=65, myRunningBuilds=0, myAgents=0} [2020-08-18 20:27:36,041] DEBUG - jetbrains.buildServer.SERVER - Compatible/can run on agents for: Queued build {item id=2933, promotion=Build promotion {promotion id=2933, configuration={id=Ngf_Ui_NgfnexUi_IntegrationBuilds, internal id=bt92}}} are: [], already distributed agents: [], inputData: InputData{myQueue=65, myRunningBuilds=0, myAgents=0} [2020-08-18 20:27:36,041] DEBUG - jetbrains.buildServer.SERVER - Compatible/can run on agents for: Queued build {item id=2932, promotion=Build promotion {promotion id=2932, configuration={id=Ngf_Ui_NgfnexUi_ReleaseBuilds, internal id=bt97}}} are: [], already distributed agents: [], inputData: InputData{myQueue=65, myRunningBuilds=0, myAgents=0} [2020-08-18 20:27:36,041] DEBUG - jetbrains.buildServer.SERVER - Compatible/can run on agents for: Queued build {item id=2932, promotion=Build promotion {promotion id=2932, configuration={id=Ngf_Ui_NgfnexUi_ReleaseBuilds, internal id=bt97}}} are: [], already distributed agents: [], inputData: InputData{myQueue=65, myRunningBuilds=0, myAgents=0} [2020-08-18 20:27:36,041] DEBUG - jetbrains.buildServer.SERVER - Compatible/can run on agents for: Queued build {item id=2671, promotion=Build promotion {promotion id=2671, configuration={id=Ngf_Ui_NgfnexUi_IntegrationBuilds, internal id=bt92}}} are: [], already distributed agents: [], inputData: InputData{myQueue=65, myRunningBuilds=0, myAgents=0} [2020-08-18 20:27:36,041] DEBUG - jetbrains.buildServer.SERVER - Compatible/can run on agents for: Queued build {item id=2671, promotion=Build promotion {promotion id=2671, configuration={id=Ngf_Ui_NgfnexUi_IntegrationBuilds, internal id=bt92}}} are: [], already distributed agents: [], inputData: InputData{myQueue=65, myRunningBuilds=0, myAgents=0} [2020-08-18 20:27:36,041] DEBUG - jetbrains.buildServer.SERVER - Compatible/can run on agents for: Queued build {item id=2666, promotion=Build promotion {promotion id=2666, configuration={id=Ngf_Ui_NgfnexUi_IntegrationBuilds, internal id=bt92}}} are: [], already distributed agents: [], inputData: InputData{myQueue=65, myRunningBuilds=0, myAgents=0} [2020-08-18 20:27:36,041] DEBUG - jetbrains.buildServer.SERVER - Compatible/can run on agents for: Queued build {item id=2666, promotion=Build promotion {promotion id=2666, configuration={id=Ngf_Ui_NgfnexUi_IntegrationBuilds, internal id=bt92}}} are: [], already distributed agents: [], inputData: InputData{myQueue=65, myRunningBuilds=0, myAgents=0} [2020-08-18 20:27:36,041] DEBUG - jetbrains.buildServer.SERVER - Compatible/can run on agents for: Queued build {item id=2609, promotion=Build promotion {promotion id=2609, configuration={id=Ngf_Ui_NgfnexUi_IntegrationBuilds, internal id=bt92}}} are: [], already distributed agents: [], inputData: InputData{myQueue=65, myRunningBuilds=0, myAgents=0} [2020-08-18 20:27:36,041] DEBUG - jetbrains.buildServer.SERVER - Compatible/can run on agents for: Queued build {item id=2609, promotion=Build promotion {promotion id=2609, configuration={id=Ngf_Ui_NgfnexUi_IntegrationBuilds, internal id=bt92}}} are: [], already distributed agents: [], inputData: InputData{myQueue=65, myRunningBuilds=0, myAgents=0} [2020-08-18 20:27:36,041] DEBUG - jetbrains.buildServer.SERVER - Compatible/can run on agents for: Queued build {item id=2612, promotion=Build promotion {promotion id=2612, configuration={id=Ngf_Ui_NgfnexUi_IntegrationBuilds, internal id=bt92}}} are: [], already distributed agents: [], inputData: InputData{myQueue=65, myRunningBuilds=0, myAgents=0} [2020-08-18 20:27:36,041] DEBUG - jetbrains.buildServer.SERVER - Compatible/can run on agents for: Queued build {item id=2612, promotion=Build promotion {promotion id=2612, configuration={id=Ngf_Ui_NgfnexUi_IntegrationBuilds, internal id=bt92}}} are: [], already distributed agents: [], inputData: InputData{myQueue=65, myRunningBuilds=0, myAgents=0} [2020-08-18 20:27:36,041] DEBUG - jetbrains.buildServer.SERVER - Compatible/can run on agents for: Queued build {item id=2613, promotion=Build promotion {promotion id=2613, configuration={id=Ngf_Ui_NgfnexUi_IntegrationBuilds, internal id=bt92}}} are: [], already distributed agents: [], inputData: InputData{myQueue=65, myRunningBuilds=0, myAgents=0}

TeamCity Auth Logs

[2020-08-18 20:27:51,898] DEBUG [th; https-jsse-nio-443-exec-99] - Responding with 401 HTTP status with message "Unauthorized", sending header in response: WWW-Authenticate: Basic realm="TeamCity", Bearer realm="TeamCity" [2020-08-18 20:27:53,133] DEBUG [h; https-jsse-nio-443-exec-108] - Processing request with no authorization header: GET '/', from client 10.50.34.19:3756, user-agent "ELB-HealthChecker/2.0", no auth [2020-08-18 20:27:53,133] DEBUG [h; https-jsse-nio-443-exec-108] - [Presigned-Token Authentication] Authentication scheme is not enabled. org.apache.catalina.connector.RequestFacade@14c0309 [2020-08-18 20:27:53,133] DEBUG [h; https-jsse-nio-443-exec-108] - No scheme was matched [2020-08-18 20:27:53,133] DEBUG [h; https-jsse-nio-443-exec-108] - Processing unauthenticated request [2020-08-18 20:27:53,133] DEBUG [h; https-jsse-nio-443-exec-108] - Responding with 401 HTTP status with message "Unauthorized", sending header in response: WWW-Authenticate: Basic realm="TeamCity", Bearer realm="TeamCity" [2020-08-18 20:28:01,414] INFO [5}; https-jsse-nio-443-exec-94] - Terminating current session from request. Requested by 'lecastan' (Lenny Castaneda) {id=5} [2020-08-18 20:28:01,414] DEBUG [5}; https-jsse-nio-443-exec-94] - Terminating current session from request. Requested by 'lecastan' (Lenny Castaneda) {id=5}. Request dump: POST '/ajax.html?logout=1', from client 10.24.100.238 (10.50.32.107:37182), authenticated as 'lecastan' (Lenny Castaneda) {id=5} [2020-08-18 20:28:01,414] DEBUG [5}; https-jsse-nio-443-exec-94] - Terminating session of user [2020-08-18 20:28:01,414] DEBUG [5}; https-jsse-nio-443-exec-94] - Notifying logout listeners that session 73008FE72E2DAB17E2149116C4419722 is logged out [2020-08-18 20:28:21,523] DEBUG [h; https-jsse-nio-443-exec-106] - Processing request with no authorization header: GET '/', from client 10.50.32.107:37420, user-agent "ELB-HealthChecker/2.0", no auth [2020-08-18 20:28:21,523] DEBUG [h; https-jsse-nio-443-exec-106] - [Presigned-Token Authentication] Authentication scheme is not enabled. org.apache.catalina.connector.RequestFacade@1305b42 [2020-08-18 20:28:21,523] DEBUG [h; https-jsse-nio-443-exec-106] - No scheme was matched [2020-08-18 20:28:21,523] DEBUG [h; https-jsse-nio-443-exec-106] - Processing unauthenticated request [2020-08-18 20:28:21,523] DEBUG [h; https-jsse-nio-443-exec-106] - Responding with 401 HTTP status with message "Unauthorized", sending header in response: WWW-Authenticate: Basic realm="TeamCity", Bearer realm="TeamCity" [2020-08-18 20:28:21,914] DEBUG [h; https-jsse-nio-443-exec-100] - Processing request with no authorization header: GET '/', from client 10.50.31.69:56132, user-agent "ELB-HealthChecker/2.0", no auth [2020-08-18 20:28:21,914] DEBUG [h; https-jsse-nio-443-exec-100] - [Presigned-Token Authentication] Authentication scheme is not enabled. org.apache.catalina.connector.RequestFacade@1305b42 [2020-08-18 20:28:21,914] DEBUG [h; https-jsse-nio-443-exec-100] - No scheme was matched [2020-08-18 20:28:21,914] DEBUG [h; https-jsse-nio-443-exec-100] - Processing unauthenticated request [2020-08-18 20:28:21,914] DEBUG [h; https-jsse-nio-443-exec-100] - Responding with 401 HTTP status with message "Unauthorized", sending header in response: WWW-Authenticate: Basic realm="TeamCity", Bearer realm="TeamCity" [2020-08-18 20:28:23,164] DEBUG [h; https-jsse-nio-443-exec-108] - Processing request with no authorization header: GET '/', from client 10.50.34.19:3768, user-agent "ELB-HealthChecker/2.0", no auth [2020-08-18 20:28:23,164] DEBUG [h; https-jsse-nio-443-exec-108] - [Presigned-Token Authentication] Authentication scheme is not enabled. org.apache.catalina.connector.RequestFacade@1305b42 [2020-08-18 20:28:23,164] DEBUG [h; https-jsse-nio-443-exec-108] - No scheme was matched [2020-08-18 20:28:23,164] DEBUG [h; https-jsse-nio-443-exec-108] - Processing unauthenticated request [2020-08-18 20:28:23,164] DEBUG [h; https-jsse-nio-443-exec-108] - Responding with 401 HTTP status with message "Unauthorized", sending header in response: WWW-Authenticate: Basic realm="TeamCity", Bearer realm="TeamCity" [2020-08-18 20:28:27,992] DEBUG [th; https-jsse-nio-443-exec-94] - Processing request with no authorization header: POST '/app/saml/callback/?RelayState=https%3A%2F%2Fteamcity-ssotest.pri.services-exchange.com%2Fapp%2Fsaml%2Flogin%2F&SAMLResponse=PHNhbWxwOlJlc3BvbnNlIFZlcnNpb249IjIuMCIgSUQ9ImdBUTJhQ3I4WUhLcHVTTFM5NzRPdjNUQWluZiIgSXNzdWVJbnN0YW50PSIyMDIwLTA4LTE4VDIwOjI4OjI3Ljc2MFoiIEluUmVzcG9uc2VUbz0iT05FTE9HSU5fODA4Y2U3NDktODc5MC00ZTc2LTkwNTQtZGMzNGIxNjllMjM2IiBEZXN0aW5hdGlvbj0iaHR0cHM6Ly90ZWFtY2l0eS1zc290ZXN0LnByaS5zZXJ2aWNlcy1leGNoYW5nZS5jb20vYXBwL3NhbWwvY2FsbGJhY2svIiB4bWxuczpzYW1scD0idXJuOm9hc2lzOm5hbWVzOnRj...', from client 10.24.100.238 (10.50.32.107:37182), no auth [2020-08-18 20:28:27,992] DEBUG [th; https-jsse-nio-443-exec-94] - [Presigned-Token Authentication] Authentication scheme is not enabled. org.apache.catalina.connector.RequestFacade@1305b42 [2020-08-18 20:28:28,040] DEBUG [th; https-jsse-nio-443-exec-94] - Creating session 4EFF4F7B69... (created: 2020-08-18 20:28:28.040, timeout: 3600s) [2020-08-18 20:28:28,040] DEBUG [th; https-jsse-nio-443-exec-94] - Matched authentication scheme: jetbrains.buildServer.auth.saml.plugin.SamlAuthenticationScheme, authResult: UNAUTHENTICATED [2020-08-18 20:28:28,040] DEBUG [th; https-jsse-nio-443-exec-94] - Responding with 401 HTTP status with message "SAML request is not authenticated due to errors: invalid_response", sending no WWW-Authenticate header in response [2020-08-18 20:28:28,148] DEBUG [h; https-jsse-nio-443-exec-101] - Processing request with no authorization header: GET '/app/saml/callback/%22/res/6114880409683721742.css', from client 10.24.100.238 (10.50.32.107:37182), no auth [2020-08-18 20:28:28,148] DEBUG [h; https-jsse-nio-443-exec-101] - [Presigned-Token Authentication] Authentication scheme is not enabled. org.apache.catalina.connector.RequestFacade@1305b42 [2020-08-18 20:28:28,148] DEBUG [h; https-jsse-nio-443-exec-101] - No scheme was matched [2020-08-18 20:28:28,148] DEBUG [h; https-jsse-nio-443-exec-101] - Processing unauthenticated request [2020-08-18 20:28:28,148] DEBUG [h; https-jsse-nio-443-exec-101] - Redirecting to login page [2020-08-18 20:28:28,164] DEBUG [h; https-jsse-nio-443-exec-101] - Processing request with no authorization header: GET '/app/saml/callback/%22/res/2319721761153202242.css', from client 10.24.100.238 (10.50.32.107:37408), no auth [2020-08-18 20:28:28,164] DEBUG [h; https-jsse-nio-443-exec-101] - [Presigned-Token Authentication] Authentication scheme is not enabled. org.apache.catalina.connector.RequestFacade@1305b42 [2020-08-18 20:28:28,164] DEBUG [h; https-jsse-nio-443-exec-101] - No scheme was matched [2020-08-18 20:28:28,164] DEBUG [h; https-jsse-nio-443-exec-101] - Processing unauthenticated request [2020-08-18 20:28:28,164] DEBUG [h; https-jsse-nio-443-exec-101] - Redirecting to login page [2020-08-18 20:28:28,367] DEBUG [h; https-jsse-nio-443-exec-107] - Processing request with no authorization header: GET '/app/saml/callback/%22/res/-1503540342333606626.css', from client 10.24.100.238 (10.50.32.107:37436), no auth [2020-08-18 20:28:28,367] DEBUG [h; https-jsse-nio-443-exec-107] - [Presigned-Token Authentication] Authentication scheme is not enabled. org.apache.catalina.connector.RequestFacade@14c0309 [2020-08-18 20:28:28,367] DEBUG [h; https-jsse-nio-443-exec-107] - No scheme was matched [2020-08-18 20:28:28,367] DEBUG [h; https-jsse-nio-443-exec-107] - Processing unauthenticated request [2020-08-18 20:28:28,367] DEBUG [h; https-jsse-nio-443-exec-107] - Redirecting to login page [2020-08-18 20:28:28,367] DEBUG [h; https-jsse-nio-443-exec-107] - Processing request with no authorization header: GET '/app/saml/callback/%22/res/-3342039278521329535.css', from client 10.24.100.238 (10.50.32.107:37428), no auth [2020-08-18 20:28:28,367] DEBUG [h; https-jsse-nio-443-exec-107] - [Presigned-Token Authentication] Authentication scheme is not enabled. org.apache.catalina.connector.RequestFacade@14c0309 [2020-08-18 20:28:28,367] DEBUG [h; https-jsse-nio-443-exec-107] - No scheme was matched [2020-08-18 20:28:28,367] DEBUG [h; https-jsse-nio-443-exec-107] - Processing unauthenticated request [2020-08-18 20:28:28,367] DEBUG [h; https-jsse-nio-443-exec-107] - Redirecting to login page [2020-08-18 20:28:37,929] DEBUG [th; https-jsse-nio-443-exec-89] - Destroying session 4EFF4F7B69... (created: 2020-08-18 20:28:28.040, timeout: 3600s, last accessed: 2020-08-18 20:28:28.914) [2020-08-18 20:28:37,929] DEBUG [th; https-jsse-nio-443-exec-89] - Creating session 61B080617B... (created: 2020-08-18 20:28:37.929, timeout: 3600s) [2020-08-18 20:28:37,929] DEBUG [th; https-jsse-nio-443-exec-89] - Processing login attempt for user "lecastan" [2020-08-18 20:28:37,961] INFO [th; https-jsse-nio-443-exec-89] - Successful login for user 'lecastan' (Lenny Castaneda) {id=5} with auth module "LDAP" for session 61B080617B... (new, created: 2020-08-18 20:28:37.929, timeout: 3600s) while processing request POST '/loginSubmit.html;TCSESSIONID=4EFF4F7B699363703B1F5BD1731492D1?username=lecastan&remember=true&_remember=&submitLogin=Log%20in&publicKey=00a3c18eb540a64d861f1ff25322261746fcae71b3e9b03eff62ad616a15c9332207436770634604c7a7e421331dba11c1551afbfd23c752b2bb91e919e88264e45c48865537ca931c6a6bde620ef0396a94b3d1568ca9ebfe85585713e106cc0cec50a1e55c7fe5378884aeba848d1b4dd9170a66f66f9b2a045896f1ac859bfb&encryptedPassword=495ec0a307fa9c4ec485fe3da69e362e8e8b257506bc7c1ccec45e1f1ae2bee1323ed8b78da37e17f68...', from client 10.24.100.238 (10.50.32.107:37424), authenticated as 'lecastan' (Lenny Castaneda) {id=5} [2020-08-18 20:28:37,976] DEBUG [th; https-jsse-nio-443-exec-89] - Setting new RememberMe cookie for user 'lecastan' (Lenny Castaneda) {id=5}, value: '1615921765^5#-8543439349608328290'(timeout: 1209600s) for request POST '/loginSubmit.html;TCSESSIONID=4EFF4F7B699363703B1F5BD1731492D1?username=lecastan&remember=true&_remember=&submitLogin=Log%20in&publicKey=00a3c18eb540a64d861f1ff25322261746fcae71b3e9b03eff62ad616a15c9332207436770634604c7a7e421331dba11c1551afbfd23c752b2bb91e919e88264e45c48865537ca931c6a6bde620ef0396a94b3d1568ca9ebfe85585713e106cc0cec50a1e55c7fe5378884aeba848d1b4dd9170a66f66f9b2a045896f1ac859bfb&encryptedPassword=495ec0a307fa9c4ec485fe3da69e362e8e8b257506bc7c1ccec45e1f1ae2bee1323ed8b78da37e17f68...', from client 10.24.100.238 (10.50.32.107:37424), authenticated as 'lecastan' (Lenny Castaneda) {id=5} [2020-08-18 20:28:51,508] DEBUG [h; https-jsse-nio-443-exec-112] - Processing request with no authorization header: GET '/', from client 10.50.32.107:37464, user-agent "ELB-HealthChecker/2.0", no auth [2020-08-18 20:28:51,508] DEBUG [h; https-jsse-nio-443-exec-112] - [Presigned-Token Authentication] Authentication scheme is not enabled. org.apache.catalina.connector.RequestFacade@14c0309 [2020-08-18 20:28:51,508] DEBUG [h; https-jsse-nio-443-exec-112] - No scheme was matched [2020-08-18 20:28:51,508] DEBUG [h; https-jsse-nio-443-exec-112] - Processing unauthenticated request [2020-08-18 20:28:51,508] DEBUG [h; https-jsse-nio-443-exec-112] - Responding with 401 HTTP status with message "Unauthorized", sending header in response: WWW-Authenticate: Basic realm="TeamCity", Bearer realm="TeamCity" [2020-08-18 20:28:51,929] DEBUG [h; https-jsse-nio-443-exec-102] - Processing request with no authorization header: GET '/', from client 10.50.31.69:56140, user-agent "ELB-HealthChecker/2.0", no auth [2020-08-18 20:28:51,929] DEBUG [h; https-jsse-nio-443-exec-102] - [Presigned-Token Authentication] Authentication scheme is not enabled. org.apache.catalina.connector.RequestFacade@14c0309 [2020-08-18 20:28:51,929] DEBUG [h; https-jsse-nio-443-exec-102] - No scheme was matched [2020-08-18 20:28:51,929] DEBUG [h; https-jsse-nio-443-exec-102] - Processing unauthenticated request [2020-08-18 20:28:51,929] DEBUG [h; https-jsse-nio-443-exec-102] - Responding with 401 HTTP status with message "Unauthorized", sending header in response: WWW-Authenticate: Basic realm="TeamCity", Bearer realm="TeamCity" [2020-08-18 20:28:53,179] DEBUG [h; https-jsse-nio-443-exec-108] - Processing request with no authorization header: GET '/', from client 10.50.34.19:3786, user-agent "ELB-HealthChecker/2.0", no auth [2020-08-18 20:28:53,179] DEBUG [h; https-jsse-nio-443-exec-108] - [Presigned-Token Authentication] Authentication scheme is not enabled. org.apache.catalina.connector.RequestFacade@14c0309 [2020-08-18 20:28:53,179] DEBUG [h; https-jsse-nio-443-exec-108] - No scheme was matched [2020-08-18 20:28:53,179] DEBUG [h; https-jsse-nio-443-exec-108] - Processing unauthenticated request [2020-08-18 20:28:53,179] DEBUG [h; https-jsse-nio-443-exec-108] - Responding with 401 HTTP status with message "Unauthorized", sending header in response: WWW-Authenticate: Basic realm="TeamCity", Bearer realm="TeamCity"

On Wed, Aug 19, 2020 at 10:57 AM Mail Delivery Subsystem < mailer-daemon@googlemail.com> wrote:

Message too large Your message couldn't be delivered to reply@reply.github.com because it exceeds the size limit. Try reducing the message size and resending. The response from the remote server was: 552 5.3.4 Message size exceeds fixed limit

---------- Forwarded message ---------- From: Lenny Castaneda lenny.castaneda@gmail.com To: "morincer/teamcity-plugin-saml" reply@reply.github.com Cc: Bcc: Date: Wed, 19 Aug 2020 10:57:41 -0700 Subject: Re: [morincer/teamcity-plugin-saml] SAML request is not authenticated due to errors: invalid_response (#53) ----- Message truncated -----

Show Quoted Content

On Wed, Aug 19, 2020 at 10:57 AM Mail Delivery Subsystem mailer-daemon@googlemail.com wrote:

Message too large Your message couldn't be delivered to reply@reply.github.com because it exceeds the size limit. Try reducing the message size and resending. The response from the remote server was: 552 5.3.4 Message size exceeds fixed limit

---------- Forwarded message ---------- From: Lenny Castaneda lenny.castaneda@gmail.com To: "morincer/teamcity-plugin-saml" reply@reply.github.com Cc: Bcc: Date: Wed, 19 Aug 2020 10:57:41 -0700 Subject: Re: [morincer/teamcity-plugin-saml] SAML request is not authenticated due to errors: invalid_response (#53) ----- Message truncated -----

Take care,

Lenny Castaneda C: 714-414-5823 O: 619-431-0039

On Aug 19, 2020, at 11:06 PM, morincer notifications@github.com wrote:

 @LennyCastaneda , I don't see any attachment.

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub, or unsubscribe.

morincer commented 4 years ago

Hi Lenny,

I still don't see what I'm expecting to see. Did you install and enable the logging preset correctly? I have described steps to do it in https://github.com/morincer/teamcity-plugin-saml#additional-logging - would you please make sure that the preset is installed and switched on correctly?

чт, 20 авг. 2020 г. в 16:11, Lenny Castaneda notifications@github.com:

Below are the copies of logs after I uploaded the zip you sent me and retried the SAML login.

Let me know if any of this pinpoints why SAML auth is not working for me.

Thanks for your help in advance.

TeamCity-server log:

InputData{myQueue=65, myRunningBuilds=0, myAgents=0} [2020-08-18 20:27:33,837] DEBUG - jetbrains.buildServer.SERVER - Compatible/can run on agents for: Queued build {item id=2941, promotion=Build promotion {promotion id=2941, configuration={id=Ngf_Api_CloudHubPoc_IntegrationBuilds, internal id=bt112}}} are: [], already distributed agents: [], inputData: InputData{myQueue=65, myRunningBuilds=0, myAgents=0} [2020-08-18 20:27:33,837] DEBUG - jetbrains.buildServer.SERVER - Compatible/can run on agents for: Queued build {item id=2941, promotion=Build promotion {promotion id=2941, configuration={id=Ngf_Api_CloudHubPoc_IntegrationBuilds, internal id=bt112}}} are: [], already distributed agents: [], inputData: InputData{myQueue=65, myRunningBuilds=0, myAgents=0} [2020-08-18 20:27:33,837] DEBUG - jetbrains.buildServer.SERVER - Compatible/can run on agents for: Queued build {item id=2944, promotion=Build promotion {promotion id=2944, configuration={id=Ngf_Ui_NgfnexUi_IntegrationBuilds, internal id=bt92}}} are: [], already distributed agents: [], inputData: InputData{myQueue=65, myRunningBuilds=0, myAgents=0} [2020-08-18 20:27:33,837] DEBUG - jetbrains.buildServer.SERVER - Compatible/can run on agents for: Queued build {item id=2944, promotion=Build promotion {promotion id=2944, configuration={id=Ngf_Ui_NgfnexUi_IntegrationBuilds, internal id=bt92}}} are: [], already distributed agents: [], inputData: InputData{myQueue=65, myRunningBuilds=0, myAgents=0} [2020-08-18 20:27:33,853] DEBUG - ver.web.ResponseFragmentFilter - Request finished: 14c0309/18be3d0 [2020-08-18 20:27:35,666] DEBUG - l.PeriodicChangesLoaderContext - Loading current repository state for VCS root 'VcsRootBitBucket' [2020-08-18 20:27:35,666] DEBUG - l.PeriodicChangesLoaderContext - Loading current repository state for VCS root 'VcsRootBitBucket' [2020-08-18 20:27:36,041] DEBUG - serverSide.impl.BuildQueueImpl - Queued builds selected for merge operation (personal and starting builds excluded): bt92 (promo id: 2933), bt97 (promo id: 2932), bt92 (promo id: 2671), bt92 (promo id: 2666), bt92 (promo id: 2609), bt92 (promo id: 2612), bt92 (promo id: 2613), bt92 (promo id: 2614), bt92 (promo id: 2617), bt92 (promo id: 2618), bt92 (promo id: 2665), bt92 (promo id: 2661), bt92 (promo id: 2662), bt21 (promo id: 2663), bt17 (promo id: 2931), bt92 (promo id: 2868), bt92 (promo id: 2677), bt92 (promo id: 2862), bt92 (promo id: 2767), bt92 (promo id: 2768), bt92 (promo id: 2769), bt92 (promo id: 2772), bt92 (promo id: 2773), bt92 (promo id: 2774), bt92 (promo id: 2777), bt92 (promo id: 2776), bt92 (promo id: 2861), bt92 (promo id: 2863), bt92 (promo id: 2864), bt92 (promo id: 2872), bt92 (promo id: 2874), bt92 (promo id: 2877), bt92 (promo id: 2878), bt92 (promo id: 2881), bt92 (promo id: 2883), bt92 (promo id: 2884), bt92 (promo id: 2885), bt92 (promo id: 2889), bt92 (promo id: 2890), bt92 (promo id: 2894), bt92 (promo id: 2895), bt92 (promo id: 2896), bt92 (promo id: 2897), bt92 (promo id: 2906), bt92 (promo id: 2910), bt92 (promo id: 2914), bt92 (promo id: 2915), bt92 (promo id: 2920), bt92 (promo id: 2917), bt92 (promo id: 2919), bt92 (promo id: 2925), bt92 (promo id: 2926), bt92 (promo id: 2927), bt106 (promo id: 2928), bt92 (promo id: 2934), bt92 (promo id: 2943), bt92 (promo id: 2942), bt92 (promo id: 2937), bt92 (promo id: 2940), bt92 (promo id: 2939), bt92 (promo id: 2944), [2020-08-18 20:27:36,041] DEBUG - serverSide.impl.BuildQueueImpl - None of the queued builds can be merged [2020-08-18 20:27:36,041] DEBUG - jetbrains.buildServer.SERVER - Compatible/can run on agents for: Queued build {item id=2933, promotion=Build promotion {promotion id=2933, configuration={id=Ngf_Ui_NgfnexUi_IntegrationBuilds, internal id=bt92}}} are: [], already distributed agents: [], inputData: InputData{myQueue=65, myRunningBuilds=0, myAgents=0} [2020-08-18 20:27:36,041] DEBUG - jetbrains.buildServer.SERVER - Compatible/can run on agents for: Queued build {item id=2933, promotion=Build promotion {promotion id=2933, configuration={id=Ngf_Ui_NgfnexUi_IntegrationBuilds, internal id=bt92}}} are: [], already distributed agents: [], inputData: InputData{myQueue=65, myRunningBuilds=0, myAgents=0} [2020-08-18 20:27:36,041] DEBUG - jetbrains.buildServer.SERVER - Compatible/can run on agents for: Queued build {item id=2932, promotion=Build promotion {promotion id=2932, configuration={id=Ngf_Ui_NgfnexUi_ReleaseBuilds, internal id=bt97}}} are: [], already distributed agents: [], inputData: InputData{myQueue=65, myRunningBuilds=0, myAgents=0} [2020-08-18 20:27:36,041] DEBUG - jetbrains.buildServer.SERVER - Compatible/can run on agents for: Queued build {item id=2932, promotion=Build promotion {promotion id=2932, configuration={id=Ngf_Ui_NgfnexUi_ReleaseBuilds, internal id=bt97}}} are: [], already distributed agents: [], inputData: InputData{myQueue=65, myRunningBuilds=0, myAgents=0} [2020-08-18 20:27:36,041] DEBUG - jetbrains.buildServer.SERVER - Compatible/can run on agents for: Queued build {item id=2671, promotion=Build promotion {promotion id=2671, configuration={id=Ngf_Ui_NgfnexUi_IntegrationBuilds, internal id=bt92}}} are: [], already distributed agents: [], inputData: InputData{myQueue=65, myRunningBuilds=0, myAgents=0} [2020-08-18 20:27:36,041] DEBUG - jetbrains.buildServer.SERVER - Compatible/can run on agents for: Queued build {item id=2671, promotion=Build promotion {promotion id=2671, configuration={id=Ngf_Ui_NgfnexUi_IntegrationBuilds, internal id=bt92}}} are: [], already distributed agents: [], inputData: InputData{myQueue=65, myRunningBuilds=0, myAgents=0} [2020-08-18 20:27:36,041] DEBUG - jetbrains.buildServer.SERVER - Compatible/can run on agents for: Queued build {item id=2666, promotion=Build promotion {promotion id=2666, configuration={id=Ngf_Ui_NgfnexUi_IntegrationBuilds, internal id=bt92}}} are: [], already distributed agents: [], inputData: InputData{myQueue=65, myRunningBuilds=0, myAgents=0} [2020-08-18 20:27:36,041] DEBUG - jetbrains.buildServer.SERVER - Compatible/can run on agents for: Queued build {item id=2666, promotion=Build promotion {promotion id=2666, configuration={id=Ngf_Ui_NgfnexUi_IntegrationBuilds, internal id=bt92}}} are: [], already distributed agents: [], inputData: InputData{myQueue=65, myRunningBuilds=0, myAgents=0} [2020-08-18 20:27:36,041] DEBUG - jetbrains.buildServer.SERVER - Compatible/can run on agents for: Queued build {item id=2609, promotion=Build promotion {promotion id=2609, configuration={id=Ngf_Ui_NgfnexUi_IntegrationBuilds, internal id=bt92}}} are: [], already distributed agents: [], inputData: InputData{myQueue=65, myRunningBuilds=0, myAgents=0} [2020-08-18 20:27:36,041] DEBUG - jetbrains.buildServer.SERVER - Compatible/can run on agents for: Queued build {item id=2609, promotion=Build promotion {promotion id=2609, configuration={id=Ngf_Ui_NgfnexUi_IntegrationBuilds, internal id=bt92}}} are: [], already distributed agents: [], inputData: InputData{myQueue=65, myRunningBuilds=0, myAgents=0} [2020-08-18 20:27:36,041] DEBUG - jetbrains.buildServer.SERVER - Compatible/can run on agents for: Queued build {item id=2612, promotion=Build promotion {promotion id=2612, configuration={id=Ngf_Ui_NgfnexUi_IntegrationBuilds, internal id=bt92}}} are: [], already distributed agents: [], inputData: InputData{myQueue=65, myRunningBuilds=0, myAgents=0} [2020-08-18 20:27:36,041] DEBUG - jetbrains.buildServer.SERVER - Compatible/can run on agents for: Queued build {item id=2612, promotion=Build promotion {promotion id=2612, configuration={id=Ngf_Ui_NgfnexUi_IntegrationBuilds, internal id=bt92}}} are: [], already distributed agents: [], inputData: InputData{myQueue=65, myRunningBuilds=0, myAgents=0} [2020-08-18 20:27:36,041] DEBUG - jetbrains.buildServer.SERVER - Compatible/can run on agents for: Queued build {item id=2613, promotion=Build promotion {promotion id=2613, configuration={id=Ngf_Ui_NgfnexUi_IntegrationBuilds, internal id=bt92}}} are: [], already distributed agents: [], inputData: InputData{myQueue=65, myRunningBuilds=0, myAgents=0}

TeamCity Auth Logs

[2020-08-18 20:27:51,898] DEBUG [th; https-jsse-nio-443-exec-99] - Responding with 401 HTTP status with message "Unauthorized", sending header in response: WWW-Authenticate: Basic realm="TeamCity", Bearer realm="TeamCity" [2020-08-18 20:27:53,133] DEBUG [h; https-jsse-nio-443-exec-108] - Processing request with no authorization header: GET '/', from client 10.50.34.19:3756, user-agent "ELB-HealthChecker/2.0", no auth [2020-08-18 20:27:53,133] DEBUG [h; https-jsse-nio-443-exec-108] - [Presigned-Token Authentication] Authentication scheme is not enabled. org.apache.catalina.connector.RequestFacade@14c0309 [2020-08-18 20:27:53,133] DEBUG [h; https-jsse-nio-443-exec-108] - No scheme was matched [2020-08-18 20:27:53,133] DEBUG [h; https-jsse-nio-443-exec-108] - Processing unauthenticated request [2020-08-18 20:27:53,133] DEBUG [h; https-jsse-nio-443-exec-108] - Responding with 401 HTTP status with message "Unauthorized", sending header in response: WWW-Authenticate: Basic realm="TeamCity", Bearer realm="TeamCity" [2020-08-18 20:28:01,414] INFO [5}; https-jsse-nio-443-exec-94] - Terminating current session from request. Requested by 'lecastan' (Lenny Castaneda) {id=5} [2020-08-18 20:28:01,414] DEBUG [5}; https-jsse-nio-443-exec-94] - Terminating current session from request. Requested by 'lecastan' (Lenny Castaneda) {id=5}. Request dump: POST '/ajax.html?logout=1', from client 10.24.100.238 (10.50.32.107:37182), authenticated as 'lecastan' (Lenny Castaneda) {id=5} [2020-08-18 20:28:01,414] DEBUG [5}; https-jsse-nio-443-exec-94] - Terminating session of user [2020-08-18 20:28:01,414] DEBUG [5}; https-jsse-nio-443-exec-94] - Notifying logout listeners that session 73008FE72E2DAB17E2149116C4419722 is logged out [2020-08-18 20:28:21,523] DEBUG [h; https-jsse-nio-443-exec-106] - Processing request with no authorization header: GET '/', from client 10.50.32.107:37420, user-agent "ELB-HealthChecker/2.0", no auth [2020-08-18 20:28:21,523] DEBUG [h; https-jsse-nio-443-exec-106] - [Presigned-Token Authentication] Authentication scheme is not enabled. org.apache.catalina.connector.RequestFacade@1305b42 [2020-08-18 20:28:21,523] DEBUG [h; https-jsse-nio-443-exec-106] - No scheme was matched [2020-08-18 20:28:21,523] DEBUG [h; https-jsse-nio-443-exec-106] - Processing unauthenticated request [2020-08-18 20:28:21,523] DEBUG [h; https-jsse-nio-443-exec-106] - Responding with 401 HTTP status with message "Unauthorized", sending header in response: WWW-Authenticate: Basic realm="TeamCity", Bearer realm="TeamCity" [2020-08-18 20:28:21,914] DEBUG [h; https-jsse-nio-443-exec-100] - Processing request with no authorization header: GET '/', from client 10.50.31.69:56132, user-agent "ELB-HealthChecker/2.0", no auth [2020-08-18 20:28:21,914] DEBUG [h; https-jsse-nio-443-exec-100] - [Presigned-Token Authentication] Authentication scheme is not enabled. org.apache.catalina.connector.RequestFacade@1305b42 [2020-08-18 20:28:21,914] DEBUG [h; https-jsse-nio-443-exec-100] - No scheme was matched [2020-08-18 20:28:21,914] DEBUG [h; https-jsse-nio-443-exec-100] - Processing unauthenticated request [2020-08-18 20:28:21,914] DEBUG [h; https-jsse-nio-443-exec-100] - Responding with 401 HTTP status with message "Unauthorized", sending header in response: WWW-Authenticate: Basic realm="TeamCity", Bearer realm="TeamCity" [2020-08-18 20:28:23,164] DEBUG [h; https-jsse-nio-443-exec-108] - Processing request with no authorization header: GET '/', from client 10.50.34.19:3768, user-agent "ELB-HealthChecker/2.0", no auth [2020-08-18 20:28:23,164] DEBUG [h; https-jsse-nio-443-exec-108] - [Presigned-Token Authentication] Authentication scheme is not enabled. org.apache.catalina.connector.RequestFacade@1305b42 [2020-08-18 20:28:23,164] DEBUG [h; https-jsse-nio-443-exec-108] - No scheme was matched [2020-08-18 20:28:23,164] DEBUG [h; https-jsse-nio-443-exec-108] - Processing unauthenticated request [2020-08-18 20:28:23,164] DEBUG [h; https-jsse-nio-443-exec-108] - Responding with 401 HTTP status with message "Unauthorized", sending header in response: WWW-Authenticate: Basic realm="TeamCity", Bearer realm="TeamCity" [2020-08-18 20:28:27,992] DEBUG [th; https-jsse-nio-443-exec-94] - Processing request with no authorization header: POST '/app/saml/callback/?RelayState=https%3A%2F% 2Fteamcity-ssotest.pri.services-exchange.com%2Fapp%2Fsaml%2Flogin%2F&SAMLResponse=PHNhbWxwOlJlc3BvbnNlIFZlcnNpb249IjIuMCIgSUQ9ImdBUTJhQ3I4WUhLcHVTTFM5NzRPdjNUQWluZiIgSXNzdWVJbnN0YW50PSIyMDIwLTA4LTE4VDIwOjI4OjI3Ljc2MFoiIEluUmVzcG9uc2VUbz0iT05FTE9HSU5fODA4Y2U3NDktODc5MC00ZTc2LTkwNTQtZGMzNGIxNjllMjM2IiBEZXN0aW5hdGlvbj0iaHR0cHM6Ly90ZWFtY2l0eS1zc290ZXN0LnByaS5zZXJ2aWNlcy1leGNoYW5nZS5jb20vYXBwL3NhbWwvY2FsbGJhY2svIiB4bWxuczpzYW1scD0idXJuOm9hc2lzOm5hbWVzOnRj...', from client 10.24.100.238 (10.50.32.107:37182), no auth [2020-08-18 20:28:27,992] DEBUG [th; https-jsse-nio-443-exec-94] - [Presigned-Token Authentication] Authentication scheme is not enabled. org.apache.catalina.connector.RequestFacade@1305b42 [2020-08-18 20:28:28,040] DEBUG [th; https-jsse-nio-443-exec-94] - Creating session 4EFF4F7B69... (created: 2020-08-18 20:28:28.040, timeout: 3600s) [2020-08-18 20:28:28,040] DEBUG [th; https-jsse-nio-443-exec-94] - Matched authentication scheme: jetbrains.buildServer.auth.saml.plugin.SamlAuthenticationScheme, authResult: UNAUTHENTICATED [2020-08-18 20:28:28,040] DEBUG [th; https-jsse-nio-443-exec-94] - Responding with 401 HTTP status with message "SAML request is not authenticated due to errors: invalid_response", sending no WWW-Authenticate header in response [2020-08-18 20:28:28,148] DEBUG [h; https-jsse-nio-443-exec-101] - Processing request with no authorization header: GET '/app/saml/callback/%22/res/6114880409683721742.css', from client 10.24.100.238 (10.50.32.107:37182), no auth [2020-08-18 20:28:28,148] DEBUG [h; https-jsse-nio-443-exec-101] - [Presigned-Token Authentication] Authentication scheme is not enabled. org.apache.catalina.connector.RequestFacade@1305b42 [2020-08-18 20:28:28,148] DEBUG [h; https-jsse-nio-443-exec-101] - No scheme was matched [2020-08-18 20:28:28,148] DEBUG [h; https-jsse-nio-443-exec-101] - Processing unauthenticated request [2020-08-18 20:28:28,148] DEBUG [h; https-jsse-nio-443-exec-101] - Redirecting to login page [2020-08-18 20:28:28,164] DEBUG [h; https-jsse-nio-443-exec-101] - Processing request with no authorization header: GET '/app/saml/callback/%22/res/2319721761153202242.css', from client 10.24.100.238 (10.50.32.107:37408), no auth [2020-08-18 20:28:28,164] DEBUG [h; https-jsse-nio-443-exec-101] - [Presigned-Token Authentication] Authentication scheme is not enabled. org.apache.catalina.connector.RequestFacade@1305b42 [2020-08-18 20:28:28,164] DEBUG [h; https-jsse-nio-443-exec-101] - No scheme was matched [2020-08-18 20:28:28,164] DEBUG [h; https-jsse-nio-443-exec-101] - Processing unauthenticated request [2020-08-18 20:28:28,164] DEBUG [h; https-jsse-nio-443-exec-101] - Redirecting to login page [2020-08-18 20:28:28,367] DEBUG [h; https-jsse-nio-443-exec-107] - Processing request with no authorization header: GET '/app/saml/callback/%22/res/-1503540342333606626.css', from client 10.24.100.238 (10.50.32.107:37436), no auth [2020-08-18 20:28:28,367] DEBUG [h; https-jsse-nio-443-exec-107] - [Presigned-Token Authentication] Authentication scheme is not enabled. org.apache.catalina.connector.RequestFacade@14c0309 [2020-08-18 20:28:28,367] DEBUG [h; https-jsse-nio-443-exec-107] - No scheme was matched [2020-08-18 20:28:28,367] DEBUG [h; https-jsse-nio-443-exec-107] - Processing unauthenticated request [2020-08-18 20:28:28,367] DEBUG [h; https-jsse-nio-443-exec-107] - Redirecting to login page [2020-08-18 20:28:28,367] DEBUG [h; https-jsse-nio-443-exec-107] - Processing request with no authorization header: GET '/app/saml/callback/%22/res/-3342039278521329535.css', from client 10.24.100.238 (10.50.32.107:37428), no auth [2020-08-18 20:28:28,367] DEBUG [h; https-jsse-nio-443-exec-107] - [Presigned-Token Authentication] Authentication scheme is not enabled. org.apache.catalina.connector.RequestFacade@14c0309 [2020-08-18 20:28:28,367] DEBUG [h; https-jsse-nio-443-exec-107] - No scheme was matched [2020-08-18 20:28:28,367] DEBUG [h; https-jsse-nio-443-exec-107] - Processing unauthenticated request [2020-08-18 20:28:28,367] DEBUG [h; https-jsse-nio-443-exec-107] - Redirecting to login page [2020-08-18 20:28:37,929] DEBUG [th; https-jsse-nio-443-exec-89] - Destroying session 4EFF4F7B69... (created: 2020-08-18 20:28:28.040, timeout: 3600s, last accessed: 2020-08-18 20:28:28.914) [2020-08-18 20:28:37,929] DEBUG [th; https-jsse-nio-443-exec-89] - Creating session 61B080617B... (created: 2020-08-18 20:28:37.929, timeout: 3600s) [2020-08-18 20:28:37,929] DEBUG [th; https-jsse-nio-443-exec-89] - Processing login attempt for user "lecastan" [2020-08-18 20:28:37,961] INFO [th; https-jsse-nio-443-exec-89] - Successful login for user 'lecastan' (Lenny Castaneda) {id=5} with auth module "LDAP" for session 61B080617B... (new, created: 2020-08-18 20:28:37.929, timeout: 3600s) while processing request POST '/loginSubmit.html;TCSESSIONID=4EFF4F7B699363703B1F5BD1731492D1?username=lecastan&remember=true&_remember=&submitLogin=Log%20in&publicKey=00a3c18eb540a64d861f1ff25322261746fcae71b3e9b03eff62ad616a15c9332207436770634604c7a7e421331dba11c1551afbfd23c752b2bb91e919e88264e45c48865537ca931c6a6bde620ef0396a94b3d1568ca9ebfe85585713e106cc0cec50a1e55c7fe5378884aeba848d1b4dd9170a66f66f9b2a045896f1ac859bfb&encryptedPassword=495ec0a307fa9c4ec485fe3da69e362e8e8b257506bc7c1ccec45e1f1ae2bee1323ed8b78da37e17f68...', from client 10.24.100.238 (10.50.32.107:37424), authenticated as 'lecastan' (Lenny Castaneda) {id=5} [2020-08-18 20:28:37,976] DEBUG [th; https-jsse-nio-443-exec-89] - Setting new RememberMe cookie for user 'lecastan' (Lenny Castaneda) {id=5}, value: '1615921765^5#-8543439349608328290'(timeout: 1209600s) for request POST '/loginSubmit.html;TCSESSIONID=4EFF4F7B699363703B1F5BD1731492D1?username=lecastan&remember=true&_remember=&submitLogin=Log%20in&publicKey=00a3c18eb540a64d861f1ff25322261746fcae71b3e9b03eff62ad616a15c9332207436770634604c7a7e421331dba11c1551afbfd23c752b2bb91e919e88264e45c48865537ca931c6a6bde620ef0396a94b3d1568ca9ebfe85585713e106cc0cec50a1e55c7fe5378884aeba848d1b4dd9170a66f66f9b2a045896f1ac859bfb&encryptedPassword=495ec0a307fa9c4ec485fe3da69e362e8e8b257506bc7c1ccec45e1f1ae2bee1323ed8b78da37e17f68...', from client 10.24.100.238 (10.50.32.107:37424), authenticated as 'lecastan' (Lenny Castaneda) {id=5} [2020-08-18 20:28:51,508] DEBUG [h; https-jsse-nio-443-exec-112] - Processing request with no authorization header: GET '/', from client 10.50.32.107:37464, user-agent "ELB-HealthChecker/2.0", no auth [2020-08-18 20:28:51,508] DEBUG [h; https-jsse-nio-443-exec-112] - [Presigned-Token Authentication] Authentication scheme is not enabled. org.apache.catalina.connector.RequestFacade@14c0309 [2020-08-18 20:28:51,508] DEBUG [h; https-jsse-nio-443-exec-112] - No scheme was matched [2020-08-18 20:28:51,508] DEBUG [h; https-jsse-nio-443-exec-112] - Processing unauthenticated request [2020-08-18 20:28:51,508] DEBUG [h; https-jsse-nio-443-exec-112] - Responding with 401 HTTP status with message "Unauthorized", sending header in response: WWW-Authenticate: Basic realm="TeamCity", Bearer realm="TeamCity" [2020-08-18 20:28:51,929] DEBUG [h; https-jsse-nio-443-exec-102] - Processing request with no authorization header: GET '/', from client 10.50.31.69:56140, user-agent "ELB-HealthChecker/2.0", no auth [2020-08-18 20:28:51,929] DEBUG [h; https-jsse-nio-443-exec-102] - [Presigned-Token Authentication] Authentication scheme is not enabled. org.apache.catalina.connector.RequestFacade@14c0309 [2020-08-18 20:28:51,929] DEBUG [h; https-jsse-nio-443-exec-102] - No scheme was matched [2020-08-18 20:28:51,929] DEBUG [h; https-jsse-nio-443-exec-102] - Processing unauthenticated request [2020-08-18 20:28:51,929] DEBUG [h; https-jsse-nio-443-exec-102] - Responding with 401 HTTP status with message "Unauthorized", sending header in response: WWW-Authenticate: Basic realm="TeamCity", Bearer realm="TeamCity" [2020-08-18 20:28:53,179] DEBUG [h; https-jsse-nio-443-exec-108] - Processing request with no authorization header: GET '/', from client 10.50.34.19:3786, user-agent "ELB-HealthChecker/2.0", no auth [2020-08-18 20:28:53,179] DEBUG [h; https-jsse-nio-443-exec-108] - [Presigned-Token Authentication] Authentication scheme is not enabled. org.apache.catalina.connector.RequestFacade@14c0309 [2020-08-18 20:28:53,179] DEBUG [h; https-jsse-nio-443-exec-108] - No scheme was matched [2020-08-18 20:28:53,179] DEBUG [h; https-jsse-nio-443-exec-108] - Processing unauthenticated request [2020-08-18 20:28:53,179] DEBUG [h; https-jsse-nio-443-exec-108] - Responding with 401 HTTP status with message "Unauthorized", sending header in response: WWW-Authenticate: Basic realm="TeamCity", Bearer realm="TeamCity"

On Wed, Aug 19, 2020 at 10:57 AM Mail Delivery Subsystem < mailer-daemon@googlemail.com> wrote:

Message too large Your message couldn't be delivered to reply@reply.github.com because it exceeds the size limit. Try reducing the message size and resending. The response from the remote server was: 552 5.3.4 Message size exceeds fixed limit

---------- Forwarded message ---------- From: Lenny Castaneda lenny.castaneda@gmail.com To: "morincer/teamcity-plugin-saml" reply@reply.github.com Cc: Bcc: Date: Wed, 19 Aug 2020 10:57:41 -0700 Subject: Re: [morincer/teamcity-plugin-saml] SAML request is not authenticated due to errors: invalid_response (#53) ----- Message truncated -----

Show Quoted Content

On Wed, Aug 19, 2020 at 10:57 AM Mail Delivery Subsystem < mailer-daemon@googlemail.com> wrote:

Message too large Your message couldn't be delivered to reply@reply.github.com because it exceeds the size limit. Try reducing the message size and resending. The response from the remote server was: 552 5.3.4 Message size exceeds fixed limit

---------- Forwarded message ---------- From: Lenny Castaneda lenny.castaneda@gmail.com To: "morincer/teamcity-plugin-saml" reply@reply.github.com Cc: Bcc: Date: Wed, 19 Aug 2020 10:57:41 -0700 Subject: Re: [morincer/teamcity-plugin-saml] SAML request is not authenticated due to errors: invalid_response (#53) ----- Message truncated -----

Take care,

Lenny Castaneda C: 714-414-5823 O: 619-431-0039

On Aug 19, 2020, at 11:06 PM, morincer notifications@github.com wrote:

 @LennyCastaneda , I don't see any attachment.

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub, or unsubscribe.

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/morincer/teamcity-plugin-saml/issues/53#issuecomment-677655721, or unsubscribe https://github.com/notifications/unsubscribe-auth/AEA55RU3LYJOF4BGTSAF6CLSBUOIXANCNFSM4P6XRHCA .

LennyCastaneda commented 4 years ago

Hi Morincer,

I made sure I uploaded the xml file you sent me to the TC (Server Administration -> Diagnostics -> Logging Presets tab) and then switching logging profile to debug-auth-saml (see screen shot below).

See attached log files as well.

[image: Screen Shot 2020-08-20 at 12.29.28 PM.png]

On Thu, Aug 20, 2020 at 6:58 AM morincer notifications@github.com wrote:

Hi Lenny,

I still don't see what I'm expecting to see. Did you install and enable the logging preset correctly? I have described steps to do it in https://github.com/morincer/teamcity-plugin-saml#additional-logging - would you please make sure that the preset is installed and switched on correctly?

чт, 20 авг. 2020 г. в 16:11, Lenny Castaneda notifications@github.com:

Below are the copies of logs after I uploaded the zip you sent me and retried the SAML login.

Let me know if any of this pinpoints why SAML auth is not working for me.

Thanks for your help in advance.

TeamCity-server log:

InputData{myQueue=65, myRunningBuilds=0, myAgents=0} [2020-08-18 20:27:33,837] DEBUG - jetbrains.buildServer.SERVER - Compatible/can run on agents for: Queued build {item id=2941, promotion=Build promotion {promotion id=2941, configuration={id=Ngf_Api_CloudHubPoc_IntegrationBuilds, internal id=bt112}}} are: [], already distributed agents: [], inputData: InputData{myQueue=65, myRunningBuilds=0, myAgents=0} [2020-08-18 20:27:33,837] DEBUG - jetbrains.buildServer.SERVER - Compatible/can run on agents for: Queued build {item id=2941, promotion=Build promotion {promotion id=2941, configuration={id=Ngf_Api_CloudHubPoc_IntegrationBuilds, internal id=bt112}}} are: [], already distributed agents: [], inputData: InputData{myQueue=65, myRunningBuilds=0, myAgents=0} [2020-08-18 20:27:33,837] DEBUG - jetbrains.buildServer.SERVER - Compatible/can run on agents for: Queued build {item id=2944, promotion=Build promotion {promotion id=2944, configuration={id=Ngf_Ui_NgfnexUi_IntegrationBuilds, internal id=bt92}}} are: [], already distributed agents: [], inputData: InputData{myQueue=65, myRunningBuilds=0, myAgents=0} [2020-08-18 20:27:33,837] DEBUG - jetbrains.buildServer.SERVER - Compatible/can run on agents for: Queued build {item id=2944, promotion=Build promotion {promotion id=2944, configuration={id=Ngf_Ui_NgfnexUi_IntegrationBuilds, internal id=bt92}}} are: [], already distributed agents: [], inputData: InputData{myQueue=65, myRunningBuilds=0, myAgents=0} [2020-08-18 20:27:33,853] DEBUG - ver.web.ResponseFragmentFilter - Request finished: 14c0309/18be3d0 [2020-08-18 20:27:35,666] DEBUG - l.PeriodicChangesLoaderContext - Loading current repository state for VCS root 'VcsRootBitBucket' [2020-08-18 20:27:35,666] DEBUG - l.PeriodicChangesLoaderContext - Loading current repository state for VCS root 'VcsRootBitBucket' [2020-08-18 20:27:36,041] DEBUG - serverSide.impl.BuildQueueImpl - Queued builds selected for merge operation (personal and starting builds excluded): bt92 (promo id: 2933), bt97 (promo id: 2932), bt92 (promo id: 2671), bt92 (promo id: 2666), bt92 (promo id: 2609), bt92 (promo id: 2612), bt92 (promo id: 2613), bt92 (promo id: 2614), bt92 (promo id: 2617), bt92 (promo id: 2618), bt92 (promo id: 2665), bt92 (promo id: 2661), bt92 (promo id: 2662), bt21 (promo id: 2663), bt17 (promo id: 2931), bt92 (promo id: 2868), bt92 (promo id: 2677), bt92 (promo id: 2862), bt92 (promo id: 2767), bt92 (promo id: 2768), bt92 (promo id: 2769), bt92 (promo id: 2772), bt92 (promo id: 2773), bt92 (promo id: 2774), bt92 (promo id: 2777), bt92 (promo id: 2776), bt92 (promo id: 2861), bt92 (promo id: 2863), bt92 (promo id: 2864), bt92 (promo id: 2872), bt92 (promo id: 2874), bt92 (promo id: 2877), bt92 (promo id: 2878), bt92 (promo id: 2881), bt92 (promo id: 2883), bt92 (promo id: 2884), bt92 (promo id: 2885), bt92 (promo id: 2889), bt92 (promo id: 2890), bt92 (promo id: 2894), bt92 (promo id: 2895), bt92 (promo id: 2896), bt92 (promo id: 2897), bt92 (promo id: 2906), bt92 (promo id: 2910), bt92 (promo id: 2914), bt92 (promo id: 2915), bt92 (promo id: 2920), bt92 (promo id: 2917), bt92 (promo id: 2919), bt92 (promo id: 2925), bt92 (promo id: 2926), bt92 (promo id: 2927), bt106 (promo id: 2928), bt92 (promo id: 2934), bt92 (promo id: 2943), bt92 (promo id: 2942), bt92 (promo id: 2937), bt92 (promo id: 2940), bt92 (promo id: 2939), bt92 (promo id: 2944), [2020-08-18 20:27:36,041] DEBUG - serverSide.impl.BuildQueueImpl - None of the queued builds can be merged [2020-08-18 20:27:36,041] DEBUG - jetbrains.buildServer.SERVER - Compatible/can run on agents for: Queued build {item id=2933, promotion=Build promotion {promotion id=2933, configuration={id=Ngf_Ui_NgfnexUi_IntegrationBuilds, internal id=bt92}}} are: [], already distributed agents: [], inputData: InputData{myQueue=65, myRunningBuilds=0, myAgents=0} [2020-08-18 20:27:36,041] DEBUG - jetbrains.buildServer.SERVER - Compatible/can run on agents for: Queued build {item id=2933, promotion=Build promotion {promotion id=2933, configuration={id=Ngf_Ui_NgfnexUi_IntegrationBuilds, internal id=bt92}}} are: [], already distributed agents: [], inputData: InputData{myQueue=65, myRunningBuilds=0, myAgents=0} [2020-08-18 20:27:36,041] DEBUG - jetbrains.buildServer.SERVER - Compatible/can run on agents for: Queued build {item id=2932, promotion=Build promotion {promotion id=2932, configuration={id=Ngf_Ui_NgfnexUi_ReleaseBuilds, internal id=bt97}}} are: [], already distributed agents: [], inputData: InputData{myQueue=65, myRunningBuilds=0, myAgents=0} [2020-08-18 20:27:36,041] DEBUG - jetbrains.buildServer.SERVER - Compatible/can run on agents for: Queued build {item id=2932, promotion=Build promotion {promotion id=2932, configuration={id=Ngf_Ui_NgfnexUi_ReleaseBuilds, internal id=bt97}}} are: [], already distributed agents: [], inputData: InputData{myQueue=65, myRunningBuilds=0, myAgents=0} [2020-08-18 20:27:36,041] DEBUG - jetbrains.buildServer.SERVER - Compatible/can run on agents for: Queued build {item id=2671, promotion=Build promotion {promotion id=2671, configuration={id=Ngf_Ui_NgfnexUi_IntegrationBuilds, internal id=bt92}}} are: [], already distributed agents: [], inputData: InputData{myQueue=65, myRunningBuilds=0, myAgents=0} [2020-08-18 20:27:36,041] DEBUG - jetbrains.buildServer.SERVER - Compatible/can run on agents for: Queued build {item id=2671, promotion=Build promotion {promotion id=2671, configuration={id=Ngf_Ui_NgfnexUi_IntegrationBuilds, internal id=bt92}}} are: [], already distributed agents: [], inputData: InputData{myQueue=65, myRunningBuilds=0, myAgents=0} [2020-08-18 20:27:36,041] DEBUG - jetbrains.buildServer.SERVER - Compatible/can run on agents for: Queued build {item id=2666, promotion=Build promotion {promotion id=2666, configuration={id=Ngf_Ui_NgfnexUi_IntegrationBuilds, internal id=bt92}}} are: [], already distributed agents: [], inputData: InputData{myQueue=65, myRunningBuilds=0, myAgents=0} [2020-08-18 20:27:36,041] DEBUG - jetbrains.buildServer.SERVER - Compatible/can run on agents for: Queued build {item id=2666, promotion=Build promotion {promotion id=2666, configuration={id=Ngf_Ui_NgfnexUi_IntegrationBuilds, internal id=bt92}}} are: [], already distributed agents: [], inputData: InputData{myQueue=65, myRunningBuilds=0, myAgents=0} [2020-08-18 20:27:36,041] DEBUG - jetbrains.buildServer.SERVER - Compatible/can run on agents for: Queued build {item id=2609, promotion=Build promotion {promotion id=2609, configuration={id=Ngf_Ui_NgfnexUi_IntegrationBuilds, internal id=bt92}}} are: [], already distributed agents: [], inputData: InputData{myQueue=65, myRunningBuilds=0, myAgents=0} [2020-08-18 20:27:36,041] DEBUG - jetbrains.buildServer.SERVER - Compatible/can run on agents for: Queued build {item id=2609, promotion=Build promotion {promotion id=2609, configuration={id=Ngf_Ui_NgfnexUi_IntegrationBuilds, internal id=bt92}}} are: [], already distributed agents: [], inputData: InputData{myQueue=65, myRunningBuilds=0, myAgents=0} [2020-08-18 20:27:36,041] DEBUG - jetbrains.buildServer.SERVER - Compatible/can run on agents for: Queued build {item id=2612, promotion=Build promotion {promotion id=2612, configuration={id=Ngf_Ui_NgfnexUi_IntegrationBuilds, internal id=bt92}}} are: [], already distributed agents: [], inputData: InputData{myQueue=65, myRunningBuilds=0, myAgents=0} [2020-08-18 20:27:36,041] DEBUG - jetbrains.buildServer.SERVER - Compatible/can run on agents for: Queued build {item id=2612, promotion=Build promotion {promotion id=2612, configuration={id=Ngf_Ui_NgfnexUi_IntegrationBuilds, internal id=bt92}}} are: [], already distributed agents: [], inputData: InputData{myQueue=65, myRunningBuilds=0, myAgents=0} [2020-08-18 20:27:36,041] DEBUG - jetbrains.buildServer.SERVER - Compatible/can run on agents for: Queued build {item id=2613, promotion=Build promotion {promotion id=2613, configuration={id=Ngf_Ui_NgfnexUi_IntegrationBuilds, internal id=bt92}}} are: [], already distributed agents: [], inputData: InputData{myQueue=65, myRunningBuilds=0, myAgents=0}

TeamCity Auth Logs

[2020-08-18 20:27:51,898] DEBUG [th; https-jsse-nio-443-exec-99] - Responding with 401 HTTP status with message "Unauthorized", sending header in response: WWW-Authenticate: Basic realm="TeamCity", Bearer realm="TeamCity" [2020-08-18 20:27:53,133] DEBUG [h; https-jsse-nio-443-exec-108] - Processing request with no authorization header: GET '/', from client 10.50.34.19:3756, user-agent "ELB-HealthChecker/2.0", no auth [2020-08-18 20:27:53,133] DEBUG [h; https-jsse-nio-443-exec-108] - [Presigned-Token Authentication] Authentication scheme is not enabled. org.apache.catalina.connector.RequestFacade@14c0309 [2020-08-18 20:27:53,133] DEBUG [h; https-jsse-nio-443-exec-108] - No scheme was matched [2020-08-18 20:27:53,133] DEBUG [h; https-jsse-nio-443-exec-108] - Processing unauthenticated request [2020-08-18 20:27:53,133] DEBUG [h; https-jsse-nio-443-exec-108] - Responding with 401 HTTP status with message "Unauthorized", sending header in response: WWW-Authenticate: Basic realm="TeamCity", Bearer realm="TeamCity" [2020-08-18 20:28:01,414] INFO [5}; https-jsse-nio-443-exec-94] - Terminating current session from request. Requested by 'lecastan' (Lenny Castaneda) {id=5} [2020-08-18 20:28:01,414] DEBUG [5}; https-jsse-nio-443-exec-94] - Terminating current session from request. Requested by 'lecastan' (Lenny Castaneda) {id=5}. Request dump: POST '/ajax.html?logout=1', from client 10.24.100.238 (10.50.32.107:37182), authenticated as 'lecastan' (Lenny Castaneda) {id=5} [2020-08-18 20:28:01,414] DEBUG [5}; https-jsse-nio-443-exec-94] - Terminating session of user [2020-08-18 20:28:01,414] DEBUG [5}; https-jsse-nio-443-exec-94] - Notifying logout listeners that session 73008FE72E2DAB17E2149116C4419722 is logged out [2020-08-18 20:28:21,523] DEBUG [h; https-jsse-nio-443-exec-106] - Processing request with no authorization header: GET '/', from client 10.50.32.107:37420, user-agent "ELB-HealthChecker/2.0", no auth [2020-08-18 20:28:21,523] DEBUG [h; https-jsse-nio-443-exec-106] - [Presigned-Token Authentication] Authentication scheme is not enabled. org.apache.catalina.connector.RequestFacade@1305b42 [2020-08-18 20:28:21,523] DEBUG [h; https-jsse-nio-443-exec-106] - No scheme was matched [2020-08-18 20:28:21,523] DEBUG [h; https-jsse-nio-443-exec-106] - Processing unauthenticated request [2020-08-18 20:28:21,523] DEBUG [h; https-jsse-nio-443-exec-106] - Responding with 401 HTTP status with message "Unauthorized", sending header in response: WWW-Authenticate: Basic realm="TeamCity", Bearer realm="TeamCity" [2020-08-18 20:28:21,914] DEBUG [h; https-jsse-nio-443-exec-100] - Processing request with no authorization header: GET '/', from client 10.50.31.69:56132, user-agent "ELB-HealthChecker/2.0", no auth [2020-08-18 20:28:21,914] DEBUG [h; https-jsse-nio-443-exec-100] - [Presigned-Token Authentication] Authentication scheme is not enabled. org.apache.catalina.connector.RequestFacade@1305b42 [2020-08-18 20:28:21,914] DEBUG [h; https-jsse-nio-443-exec-100] - No scheme was matched [2020-08-18 20:28:21,914] DEBUG [h; https-jsse-nio-443-exec-100] - Processing unauthenticated request [2020-08-18 20:28:21,914] DEBUG [h; https-jsse-nio-443-exec-100] - Responding with 401 HTTP status with message "Unauthorized", sending header in response: WWW-Authenticate: Basic realm="TeamCity", Bearer realm="TeamCity" [2020-08-18 20:28:23,164] DEBUG [h; https-jsse-nio-443-exec-108] - Processing request with no authorization header: GET '/', from client 10.50.34.19:3768, user-agent "ELB-HealthChecker/2.0", no auth [2020-08-18 20:28:23,164] DEBUG [h; https-jsse-nio-443-exec-108] - [Presigned-Token Authentication] Authentication scheme is not enabled. org.apache.catalina.connector.RequestFacade@1305b42 [2020-08-18 20:28:23,164] DEBUG [h; https-jsse-nio-443-exec-108] - No scheme was matched [2020-08-18 20:28:23,164] DEBUG [h; https-jsse-nio-443-exec-108] - Processing unauthenticated request [2020-08-18 20:28:23,164] DEBUG [h; https-jsse-nio-443-exec-108] - Responding with 401 HTTP status with message "Unauthorized", sending header in response: WWW-Authenticate: Basic realm="TeamCity", Bearer realm="TeamCity" [2020-08-18 20:28:27,992] DEBUG [th; https-jsse-nio-443-exec-94] - Processing request with no authorization header: POST '/app/saml/callback/?RelayState=https%3A%2F% 2Fteamcity-ssotest.pri.services-exchange.com %2Fapp%2Fsaml%2Flogin%2F&SAMLResponse=PHNhbWxwOlJlc3BvbnNlIFZlcnNpb249IjIuMCIgSUQ9ImdBUTJhQ3I4WUhLcHVTTFM5NzRPdjNUQWluZiIgSXNzdWVJbnN0YW50PSIyMDIwLTA4LTE4VDIwOjI4OjI3Ljc2MFoiIEluUmVzcG9uc2VUbz0iT05FTE9HSU5fODA4Y2U3NDktODc5MC00ZTc2LTkwNTQtZGMzNGIxNjllMjM2IiBEZXN0aW5hdGlvbj0iaHR0cHM6Ly90ZWFtY2l0eS1zc290ZXN0LnByaS5zZXJ2aWNlcy1leGNoYW5nZS5jb20vYXBwL3NhbWwvY2FsbGJhY2svIiB4bWxuczpzYW1scD0idXJuOm9hc2lzOm5hbWVzOnRj...', from client 10.24.100.238 (10.50.32.107:37182), no auth [2020-08-18 20:28:27,992] DEBUG [th; https-jsse-nio-443-exec-94] - [Presigned-Token Authentication] Authentication scheme is not enabled. org.apache.catalina.connector.RequestFacade@1305b42 [2020-08-18 20:28:28,040] DEBUG [th; https-jsse-nio-443-exec-94] - Creating session 4EFF4F7B69... (created: 2020-08-18 20:28:28.040, timeout: 3600s) [2020-08-18 20:28:28,040] DEBUG [th; https-jsse-nio-443-exec-94] - Matched authentication scheme: jetbrains.buildServer.auth.saml.plugin.SamlAuthenticationScheme, authResult: UNAUTHENTICATED [2020-08-18 20:28:28,040] DEBUG [th; https-jsse-nio-443-exec-94] - Responding with 401 HTTP status with message "SAML request is not authenticated due to errors: invalid_response", sending no WWW-Authenticate header in response [2020-08-18 20:28:28,148] DEBUG [h; https-jsse-nio-443-exec-101] - Processing request with no authorization header: GET '/app/saml/callback/%22/res/6114880409683721742.css', from client 10.24.100.238 (10.50.32.107:37182), no auth [2020-08-18 20:28:28,148] DEBUG [h; https-jsse-nio-443-exec-101] - [Presigned-Token Authentication] Authentication scheme is not enabled. org.apache.catalina.connector.RequestFacade@1305b42 [2020-08-18 20:28:28,148] DEBUG [h; https-jsse-nio-443-exec-101] - No scheme was matched [2020-08-18 20:28:28,148] DEBUG [h; https-jsse-nio-443-exec-101] - Processing unauthenticated request [2020-08-18 20:28:28,148] DEBUG [h; https-jsse-nio-443-exec-101] - Redirecting to login page [2020-08-18 20:28:28,164] DEBUG [h; https-jsse-nio-443-exec-101] - Processing request with no authorization header: GET '/app/saml/callback/%22/res/2319721761153202242.css', from client 10.24.100.238 (10.50.32.107:37408), no auth [2020-08-18 20:28:28,164] DEBUG [h; https-jsse-nio-443-exec-101] - [Presigned-Token Authentication] Authentication scheme is not enabled. org.apache.catalina.connector.RequestFacade@1305b42 [2020-08-18 20:28:28,164] DEBUG [h; https-jsse-nio-443-exec-101] - No scheme was matched [2020-08-18 20:28:28,164] DEBUG [h; https-jsse-nio-443-exec-101] - Processing unauthenticated request [2020-08-18 20:28:28,164] DEBUG [h; https-jsse-nio-443-exec-101] - Redirecting to login page [2020-08-18 20:28:28,367] DEBUG [h; https-jsse-nio-443-exec-107] - Processing request with no authorization header: GET '/app/saml/callback/%22/res/-1503540342333606626.css', from client 10.24.100.238 (10.50.32.107:37436), no auth [2020-08-18 20:28:28,367] DEBUG [h; https-jsse-nio-443-exec-107] - [Presigned-Token Authentication] Authentication scheme is not enabled. org.apache.catalina.connector.RequestFacade@14c0309 [2020-08-18 20:28:28,367] DEBUG [h; https-jsse-nio-443-exec-107] - No scheme was matched [2020-08-18 20:28:28,367] DEBUG [h; https-jsse-nio-443-exec-107] - Processing unauthenticated request [2020-08-18 20:28:28,367] DEBUG [h; https-jsse-nio-443-exec-107] - Redirecting to login page [2020-08-18 20:28:28,367] DEBUG [h; https-jsse-nio-443-exec-107] - Processing request with no authorization header: GET '/app/saml/callback/%22/res/-3342039278521329535.css', from client 10.24.100.238 (10.50.32.107:37428), no auth [2020-08-18 20:28:28,367] DEBUG [h; https-jsse-nio-443-exec-107] - [Presigned-Token Authentication] Authentication scheme is not enabled. org.apache.catalina.connector.RequestFacade@14c0309 [2020-08-18 20:28:28,367] DEBUG [h; https-jsse-nio-443-exec-107] - No scheme was matched [2020-08-18 20:28:28,367] DEBUG [h; https-jsse-nio-443-exec-107] - Processing unauthenticated request [2020-08-18 20:28:28,367] DEBUG [h; https-jsse-nio-443-exec-107] - Redirecting to login page [2020-08-18 20:28:37,929] DEBUG [th; https-jsse-nio-443-exec-89] - Destroying session 4EFF4F7B69... (created: 2020-08-18 20:28:28.040, timeout: 3600s, last accessed: 2020-08-18 20:28:28.914) [2020-08-18 20:28:37,929] DEBUG [th; https-jsse-nio-443-exec-89] - Creating session 61B080617B... (created: 2020-08-18 20:28:37.929, timeout: 3600s) [2020-08-18 20:28:37,929] DEBUG [th; https-jsse-nio-443-exec-89] - Processing login attempt for user "lecastan" [2020-08-18 20:28:37,961] INFO [th; https-jsse-nio-443-exec-89] - Successful login for user 'lecastan' (Lenny Castaneda) {id=5} with auth module "LDAP" for session 61B080617B... (new, created: 2020-08-18 20:28:37.929, timeout: 3600s) while processing request POST

'/loginSubmit.html;TCSESSIONID=4EFF4F7B699363703B1F5BD1731492D1?username=lecastan&remember=true&_remember=&submitLogin=Log%20in&publicKey=00a3c18eb540a64d861f1ff25322261746fcae71b3e9b03eff62ad616a15c9332207436770634604c7a7e421331dba11c1551afbfd23c752b2bb91e919e88264e45c48865537ca931c6a6bde620ef0396a94b3d1568ca9ebfe85585713e106cc0cec50a1e55c7fe5378884aeba848d1b4dd9170a66f66f9b2a045896f1ac859bfb&encryptedPassword=495ec0a307fa9c4ec485fe3da69e362e8e8b257506bc7c1ccec45e1f1ae2bee1323ed8b78da37e17f68...', from client 10.24.100.238 (10.50.32.107:37424), authenticated as 'lecastan' (Lenny Castaneda) {id=5} [2020-08-18 20:28:37,976] DEBUG [th; https-jsse-nio-443-exec-89] - Setting new RememberMe cookie for user 'lecastan' (Lenny Castaneda) {id=5}, value: '1615921765^5#-8543439349608328290'(timeout: 1209600s) for request POST

'/loginSubmit.html;TCSESSIONID=4EFF4F7B699363703B1F5BD1731492D1?username=lecastan&remember=true&_remember=&submitLogin=Log%20in&publicKey=00a3c18eb540a64d861f1ff25322261746fcae71b3e9b03eff62ad616a15c9332207436770634604c7a7e421331dba11c1551afbfd23c752b2bb91e919e88264e45c48865537ca931c6a6bde620ef0396a94b3d1568ca9ebfe85585713e106cc0cec50a1e55c7fe5378884aeba848d1b4dd9170a66f66f9b2a045896f1ac859bfb&encryptedPassword=495ec0a307fa9c4ec485fe3da69e362e8e8b257506bc7c1ccec45e1f1ae2bee1323ed8b78da37e17f68...', from client 10.24.100.238 (10.50.32.107:37424), authenticated as 'lecastan' (Lenny Castaneda) {id=5} [2020-08-18 20:28:51,508] DEBUG [h; https-jsse-nio-443-exec-112] - Processing request with no authorization header: GET '/', from client 10.50.32.107:37464, user-agent "ELB-HealthChecker/2.0", no auth [2020-08-18 20:28:51,508] DEBUG [h; https-jsse-nio-443-exec-112] - [Presigned-Token Authentication] Authentication scheme is not enabled. org.apache.catalina.connector.RequestFacade@14c0309 [2020-08-18 20:28:51,508] DEBUG [h; https-jsse-nio-443-exec-112] - No scheme was matched [2020-08-18 20:28:51,508] DEBUG [h; https-jsse-nio-443-exec-112] - Processing unauthenticated request [2020-08-18 20:28:51,508] DEBUG [h; https-jsse-nio-443-exec-112] - Responding with 401 HTTP status with message "Unauthorized", sending header in response: WWW-Authenticate: Basic realm="TeamCity", Bearer realm="TeamCity" [2020-08-18 20:28:51,929] DEBUG [h; https-jsse-nio-443-exec-102] - Processing request with no authorization header: GET '/', from client 10.50.31.69:56140, user-agent "ELB-HealthChecker/2.0", no auth [2020-08-18 20:28:51,929] DEBUG [h; https-jsse-nio-443-exec-102] - [Presigned-Token Authentication] Authentication scheme is not enabled. org.apache.catalina.connector.RequestFacade@14c0309 [2020-08-18 20:28:51,929] DEBUG [h; https-jsse-nio-443-exec-102] - No scheme was matched [2020-08-18 20:28:51,929] DEBUG [h; https-jsse-nio-443-exec-102] - Processing unauthenticated request [2020-08-18 20:28:51,929] DEBUG [h; https-jsse-nio-443-exec-102] - Responding with 401 HTTP status with message "Unauthorized", sending header in response: WWW-Authenticate: Basic realm="TeamCity", Bearer realm="TeamCity" [2020-08-18 20:28:53,179] DEBUG [h; https-jsse-nio-443-exec-108] - Processing request with no authorization header: GET '/', from client 10.50.34.19:3786, user-agent "ELB-HealthChecker/2.0", no auth [2020-08-18 20:28:53,179] DEBUG [h; https-jsse-nio-443-exec-108] - [Presigned-Token Authentication] Authentication scheme is not enabled. org.apache.catalina.connector.RequestFacade@14c0309 [2020-08-18 20:28:53,179] DEBUG [h; https-jsse-nio-443-exec-108] - No scheme was matched [2020-08-18 20:28:53,179] DEBUG [h; https-jsse-nio-443-exec-108] - Processing unauthenticated request [2020-08-18 20:28:53,179] DEBUG [h; https-jsse-nio-443-exec-108] - Responding with 401 HTTP status with message "Unauthorized", sending header in response: WWW-Authenticate: Basic realm="TeamCity", Bearer realm="TeamCity"

On Wed, Aug 19, 2020 at 10:57 AM Mail Delivery Subsystem < mailer-daemon@googlemail.com> wrote:

Message too large Your message couldn't be delivered to reply@reply.github.com because it exceeds the size limit. Try reducing the message size and resending. The response from the remote server was: 552 5.3.4 Message size exceeds fixed limit

---------- Forwarded message ---------- From: Lenny Castaneda lenny.castaneda@gmail.com To: "morincer/teamcity-plugin-saml" reply@reply.github.com Cc: Bcc: Date: Wed, 19 Aug 2020 10:57:41 -0700 Subject: Re: [morincer/teamcity-plugin-saml] SAML request is not authenticated due to errors: invalid_response (#53) ----- Message truncated -----

Show Quoted Content

On Wed, Aug 19, 2020 at 10:57 AM Mail Delivery Subsystem < mailer-daemon@googlemail.com> wrote:

Message too large Your message couldn't be delivered to reply@reply.github.com because it exceeds the size limit. Try reducing the message size and resending. The response from the remote server was: 552 5.3.4 Message size exceeds fixed limit

---------- Forwarded message ---------- From: Lenny Castaneda lenny.castaneda@gmail.com To: "morincer/teamcity-plugin-saml" reply@reply.github.com Cc: Bcc: Date: Wed, 19 Aug 2020 10:57:41 -0700 Subject: Re: [morincer/teamcity-plugin-saml] SAML request is not authenticated due to errors: invalid_response (#53) ----- Message truncated -----

Take care,

Lenny Castaneda C: 714-414-5823 O: 619-431-0039

On Aug 19, 2020, at 11:06 PM, morincer notifications@github.com wrote:

 @LennyCastaneda , I don't see any attachment.

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub, or unsubscribe.

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub < https://github.com/morincer/teamcity-plugin-saml/issues/53#issuecomment-677655721 , or unsubscribe < https://github.com/notifications/unsubscribe-auth/AEA55RU3LYJOF4BGTSAF6CLSBUOIXANCNFSM4P6XRHCA

.

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/morincer/teamcity-plugin-saml/issues/53#issuecomment-677682447, or unsubscribe https://github.com/notifications/unsubscribe-auth/ACLPMRWB57TDED57L3S5L7DSBUTYTANCNFSM4P6XRHCA .

--

Take care,

Lenny Castaneda C: 714-414-5823 O: 619-431-0039

LennyCastaneda commented 4 years ago

BTW my TeamCity version: Version 2020.1.1 (build 78657)

On Thu, Aug 20, 2020 at 12:31 PM Lenny Castaneda lenny.castaneda@gmail.com wrote:

Hi Morincer,

I made sure I uploaded the xml file you sent me to the TC (Server Administration -> Diagnostics -> Logging Presets tab) and then switching logging profile to debug-auth-saml (see screen shot below).

See attached log files as well.

[image: Screen Shot 2020-08-20 at 12.29.28 PM.png]

On Thu, Aug 20, 2020 at 6:58 AM morincer notifications@github.com wrote:

Hi Lenny,

I still don't see what I'm expecting to see. Did you install and enable the logging preset correctly? I have described steps to do it in https://github.com/morincer/teamcity-plugin-saml#additional-logging - would you please make sure that the preset is installed and switched on correctly?

чт, 20 авг. 2020 г. в 16:11, Lenny Castaneda notifications@github.com:

Below are the copies of logs after I uploaded the zip you sent me and retried the SAML login.

Let me know if any of this pinpoints why SAML auth is not working for me.

Thanks for your help in advance.

TeamCity-server log:

InputData{myQueue=65, myRunningBuilds=0, myAgents=0} [2020-08-18 20:27:33,837] DEBUG - jetbrains.buildServer.SERVER - Compatible/can run on agents for: Queued build {item id=2941, promotion=Build promotion {promotion id=2941, configuration={id=Ngf_Api_CloudHubPoc_IntegrationBuilds, internal id=bt112}}} are: [], already distributed agents: [], inputData: InputData{myQueue=65, myRunningBuilds=0, myAgents=0} [2020-08-18 20:27:33,837] DEBUG - jetbrains.buildServer.SERVER - Compatible/can run on agents for: Queued build {item id=2941, promotion=Build promotion {promotion id=2941, configuration={id=Ngf_Api_CloudHubPoc_IntegrationBuilds, internal id=bt112}}} are: [], already distributed agents: [], inputData: InputData{myQueue=65, myRunningBuilds=0, myAgents=0} [2020-08-18 20:27:33,837] DEBUG - jetbrains.buildServer.SERVER - Compatible/can run on agents for: Queued build {item id=2944, promotion=Build promotion {promotion id=2944, configuration={id=Ngf_Ui_NgfnexUi_IntegrationBuilds, internal id=bt92}}} are: [], already distributed agents: [], inputData: InputData{myQueue=65, myRunningBuilds=0, myAgents=0} [2020-08-18 20:27:33,837] DEBUG - jetbrains.buildServer.SERVER - Compatible/can run on agents for: Queued build {item id=2944, promotion=Build promotion {promotion id=2944, configuration={id=Ngf_Ui_NgfnexUi_IntegrationBuilds, internal id=bt92}}} are: [], already distributed agents: [], inputData: InputData{myQueue=65, myRunningBuilds=0, myAgents=0} [2020-08-18 20:27:33,853] DEBUG - ver.web.ResponseFragmentFilter - Request finished: 14c0309/18be3d0 [2020-08-18 20:27:35,666] DEBUG - l.PeriodicChangesLoaderContext - Loading current repository state for VCS root 'VcsRootBitBucket' [2020-08-18 20:27:35,666] DEBUG - l.PeriodicChangesLoaderContext - Loading current repository state for VCS root 'VcsRootBitBucket' [2020-08-18 20:27:36,041] DEBUG - serverSide.impl.BuildQueueImpl - Queued builds selected for merge operation (personal and starting builds excluded): bt92 (promo id: 2933), bt97 (promo id: 2932), bt92 (promo id: 2671), bt92 (promo id: 2666), bt92 (promo id: 2609), bt92 (promo id: 2612), bt92 (promo id: 2613), bt92 (promo id: 2614), bt92 (promo id: 2617), bt92 (promo id: 2618), bt92 (promo id: 2665), bt92 (promo id: 2661), bt92 (promo id: 2662), bt21 (promo id: 2663), bt17 (promo id: 2931), bt92 (promo id: 2868), bt92 (promo id: 2677), bt92 (promo id: 2862), bt92 (promo id: 2767), bt92 (promo id: 2768), bt92 (promo id: 2769), bt92 (promo id: 2772), bt92 (promo id: 2773), bt92 (promo id: 2774), bt92 (promo id: 2777), bt92 (promo id: 2776), bt92 (promo id: 2861), bt92 (promo id: 2863), bt92 (promo id: 2864), bt92 (promo id: 2872), bt92 (promo id: 2874), bt92 (promo id: 2877), bt92 (promo id: 2878), bt92 (promo id: 2881), bt92 (promo id: 2883), bt92 (promo id: 2884), bt92 (promo id: 2885), bt92 (promo id: 2889), bt92 (promo id: 2890), bt92 (promo id: 2894), bt92 (promo id: 2895), bt92 (promo id: 2896), bt92 (promo id: 2897), bt92 (promo id: 2906), bt92 (promo id: 2910), bt92 (promo id: 2914), bt92 (promo id: 2915), bt92 (promo id: 2920), bt92 (promo id: 2917), bt92 (promo id: 2919), bt92 (promo id: 2925), bt92 (promo id: 2926), bt92 (promo id: 2927), bt106 (promo id: 2928), bt92 (promo id: 2934), bt92 (promo id: 2943), bt92 (promo id: 2942), bt92 (promo id: 2937), bt92 (promo id: 2940), bt92 (promo id: 2939), bt92 (promo id: 2944), [2020-08-18 20:27:36,041] DEBUG - serverSide.impl.BuildQueueImpl - None of the queued builds can be merged [2020-08-18 20:27:36,041] DEBUG - jetbrains.buildServer.SERVER - Compatible/can run on agents for: Queued build {item id=2933, promotion=Build promotion {promotion id=2933, configuration={id=Ngf_Ui_NgfnexUi_IntegrationBuilds, internal id=bt92}}} are: [], already distributed agents: [], inputData: InputData{myQueue=65, myRunningBuilds=0, myAgents=0} [2020-08-18 20:27:36,041] DEBUG - jetbrains.buildServer.SERVER - Compatible/can run on agents for: Queued build {item id=2933, promotion=Build promotion {promotion id=2933, configuration={id=Ngf_Ui_NgfnexUi_IntegrationBuilds, internal id=bt92}}} are: [], already distributed agents: [], inputData: InputData{myQueue=65, myRunningBuilds=0, myAgents=0} [2020-08-18 20:27:36,041] DEBUG - jetbrains.buildServer.SERVER - Compatible/can run on agents for: Queued build {item id=2932, promotion=Build promotion {promotion id=2932, configuration={id=Ngf_Ui_NgfnexUi_ReleaseBuilds, internal id=bt97}}} are: [], already distributed agents: [], inputData: InputData{myQueue=65, myRunningBuilds=0, myAgents=0} [2020-08-18 20:27:36,041] DEBUG - jetbrains.buildServer.SERVER - Compatible/can run on agents for: Queued build {item id=2932, promotion=Build promotion {promotion id=2932, configuration={id=Ngf_Ui_NgfnexUi_ReleaseBuilds, internal id=bt97}}} are: [], already distributed agents: [], inputData: InputData{myQueue=65, myRunningBuilds=0, myAgents=0} [2020-08-18 20:27:36,041] DEBUG - jetbrains.buildServer.SERVER - Compatible/can run on agents for: Queued build {item id=2671, promotion=Build promotion {promotion id=2671, configuration={id=Ngf_Ui_NgfnexUi_IntegrationBuilds, internal id=bt92}}} are: [], already distributed agents: [], inputData: InputData{myQueue=65, myRunningBuilds=0, myAgents=0} [2020-08-18 20:27:36,041] DEBUG - jetbrains.buildServer.SERVER - Compatible/can run on agents for: Queued build {item id=2671, promotion=Build promotion {promotion id=2671, configuration={id=Ngf_Ui_NgfnexUi_IntegrationBuilds, internal id=bt92}}} are: [], already distributed agents: [], inputData: InputData{myQueue=65, myRunningBuilds=0, myAgents=0} [2020-08-18 20:27:36,041] DEBUG - jetbrains.buildServer.SERVER - Compatible/can run on agents for: Queued build {item id=2666, promotion=Build promotion {promotion id=2666, configuration={id=Ngf_Ui_NgfnexUi_IntegrationBuilds, internal id=bt92}}} are: [], already distributed agents: [], inputData: InputData{myQueue=65, myRunningBuilds=0, myAgents=0} [2020-08-18 20:27:36,041] DEBUG - jetbrains.buildServer.SERVER - Compatible/can run on agents for: Queued build {item id=2666, promotion=Build promotion {promotion id=2666, configuration={id=Ngf_Ui_NgfnexUi_IntegrationBuilds, internal id=bt92}}} are: [], already distributed agents: [], inputData: InputData{myQueue=65, myRunningBuilds=0, myAgents=0} [2020-08-18 20:27:36,041] DEBUG - jetbrains.buildServer.SERVER - Compatible/can run on agents for: Queued build {item id=2609, promotion=Build promotion {promotion id=2609, configuration={id=Ngf_Ui_NgfnexUi_IntegrationBuilds, internal id=bt92}}} are: [], already distributed agents: [], inputData: InputData{myQueue=65, myRunningBuilds=0, myAgents=0} [2020-08-18 20:27:36,041] DEBUG - jetbrains.buildServer.SERVER - Compatible/can run on agents for: Queued build {item id=2609, promotion=Build promotion {promotion id=2609, configuration={id=Ngf_Ui_NgfnexUi_IntegrationBuilds, internal id=bt92}}} are: [], already distributed agents: [], inputData: InputData{myQueue=65, myRunningBuilds=0, myAgents=0} [2020-08-18 20:27:36,041] DEBUG - jetbrains.buildServer.SERVER - Compatible/can run on agents for: Queued build {item id=2612, promotion=Build promotion {promotion id=2612, configuration={id=Ngf_Ui_NgfnexUi_IntegrationBuilds, internal id=bt92}}} are: [], already distributed agents: [], inputData: InputData{myQueue=65, myRunningBuilds=0, myAgents=0} [2020-08-18 20:27:36,041] DEBUG - jetbrains.buildServer.SERVER - Compatible/can run on agents for: Queued build {item id=2612, promotion=Build promotion {promotion id=2612, configuration={id=Ngf_Ui_NgfnexUi_IntegrationBuilds, internal id=bt92}}} are: [], already distributed agents: [], inputData: InputData{myQueue=65, myRunningBuilds=0, myAgents=0} [2020-08-18 20:27:36,041] DEBUG - jetbrains.buildServer.SERVER - Compatible/can run on agents for: Queued build {item id=2613, promotion=Build promotion {promotion id=2613, configuration={id=Ngf_Ui_NgfnexUi_IntegrationBuilds, internal id=bt92}}} are: [], already distributed agents: [], inputData: InputData{myQueue=65, myRunningBuilds=0, myAgents=0}

TeamCity Auth Logs

[2020-08-18 20:27:51,898] DEBUG [th; https-jsse-nio-443-exec-99] - Responding with 401 HTTP status with message "Unauthorized", sending header in response: WWW-Authenticate: Basic realm="TeamCity", Bearer realm="TeamCity" [2020-08-18 20:27:53,133] DEBUG [h; https-jsse-nio-443-exec-108] - Processing request with no authorization header: GET '/', from client 10.50.34.19:3756, user-agent "ELB-HealthChecker/2.0", no auth [2020-08-18 20:27:53,133] DEBUG [h; https-jsse-nio-443-exec-108] - [Presigned-Token Authentication] Authentication scheme is not enabled. org.apache.catalina.connector.RequestFacade@14c0309 [2020-08-18 20:27:53,133] DEBUG [h; https-jsse-nio-443-exec-108] - No scheme was matched [2020-08-18 20:27:53,133] DEBUG [h; https-jsse-nio-443-exec-108] - Processing unauthenticated request [2020-08-18 20:27:53,133] DEBUG [h; https-jsse-nio-443-exec-108] - Responding with 401 HTTP status with message "Unauthorized", sending header in response: WWW-Authenticate: Basic realm="TeamCity", Bearer realm="TeamCity" [2020-08-18 20:28:01,414] INFO [5}; https-jsse-nio-443-exec-94] - Terminating current session from request. Requested by 'lecastan' (Lenny Castaneda) {id=5} [2020-08-18 20:28:01,414] DEBUG [5}; https-jsse-nio-443-exec-94] - Terminating current session from request. Requested by 'lecastan' (Lenny Castaneda) {id=5}. Request dump: POST '/ajax.html?logout=1', from client 10.24.100.238 (10.50.32.107:37182), authenticated as 'lecastan' (Lenny Castaneda) {id=5} [2020-08-18 20:28:01,414] DEBUG [5}; https-jsse-nio-443-exec-94] - Terminating session of user [2020-08-18 20:28:01,414] DEBUG [5}; https-jsse-nio-443-exec-94] - Notifying logout listeners that session 73008FE72E2DAB17E2149116C4419722 is logged out [2020-08-18 20:28:21,523] DEBUG [h; https-jsse-nio-443-exec-106] - Processing request with no authorization header: GET '/', from client 10.50.32.107:37420, user-agent "ELB-HealthChecker/2.0", no auth [2020-08-18 20:28:21,523] DEBUG [h; https-jsse-nio-443-exec-106] - [Presigned-Token Authentication] Authentication scheme is not enabled. org.apache.catalina.connector.RequestFacade@1305b42 [2020-08-18 20:28:21,523] DEBUG [h; https-jsse-nio-443-exec-106] - No scheme was matched [2020-08-18 20:28:21,523] DEBUG [h; https-jsse-nio-443-exec-106] - Processing unauthenticated request [2020-08-18 20:28:21,523] DEBUG [h; https-jsse-nio-443-exec-106] - Responding with 401 HTTP status with message "Unauthorized", sending header in response: WWW-Authenticate: Basic realm="TeamCity", Bearer realm="TeamCity" [2020-08-18 20:28:21,914] DEBUG [h; https-jsse-nio-443-exec-100] - Processing request with no authorization header: GET '/', from client 10.50.31.69:56132, user-agent "ELB-HealthChecker/2.0", no auth [2020-08-18 20:28:21,914] DEBUG [h; https-jsse-nio-443-exec-100] - [Presigned-Token Authentication] Authentication scheme is not enabled. org.apache.catalina.connector.RequestFacade@1305b42 [2020-08-18 20:28:21,914] DEBUG [h; https-jsse-nio-443-exec-100] - No scheme was matched [2020-08-18 20:28:21,914] DEBUG [h; https-jsse-nio-443-exec-100] - Processing unauthenticated request [2020-08-18 20:28:21,914] DEBUG [h; https-jsse-nio-443-exec-100] - Responding with 401 HTTP status with message "Unauthorized", sending header in response: WWW-Authenticate: Basic realm="TeamCity", Bearer realm="TeamCity" [2020-08-18 20:28:23,164] DEBUG [h; https-jsse-nio-443-exec-108] - Processing request with no authorization header: GET '/', from client 10.50.34.19:3768, user-agent "ELB-HealthChecker/2.0", no auth [2020-08-18 20:28:23,164] DEBUG [h; https-jsse-nio-443-exec-108] - [Presigned-Token Authentication] Authentication scheme is not enabled. org.apache.catalina.connector.RequestFacade@1305b42 [2020-08-18 20:28:23,164] DEBUG [h; https-jsse-nio-443-exec-108] - No scheme was matched [2020-08-18 20:28:23,164] DEBUG [h; https-jsse-nio-443-exec-108] - Processing unauthenticated request [2020-08-18 20:28:23,164] DEBUG [h; https-jsse-nio-443-exec-108] - Responding with 401 HTTP status with message "Unauthorized", sending header in response: WWW-Authenticate: Basic realm="TeamCity", Bearer realm="TeamCity" [2020-08-18 20:28:27,992] DEBUG [th; https-jsse-nio-443-exec-94] - Processing request with no authorization header: POST '/app/saml/callback/?RelayState=https%3A%2F% 2Fteamcity-ssotest.pri.services-exchange.com %2Fapp%2Fsaml%2Flogin%2F&SAMLResponse=PHNhbWxwOlJlc3BvbnNlIFZlcnNpb249IjIuMCIgSUQ9ImdBUTJhQ3I4WUhLcHVTTFM5NzRPdjNUQWluZiIgSXNzdWVJbnN0YW50PSIyMDIwLTA4LTE4VDIwOjI4OjI3Ljc2MFoiIEluUmVzcG9uc2VUbz0iT05FTE9HSU5fODA4Y2U3NDktODc5MC00ZTc2LTkwNTQtZGMzNGIxNjllMjM2IiBEZXN0aW5hdGlvbj0iaHR0cHM6Ly90ZWFtY2l0eS1zc290ZXN0LnByaS5zZXJ2aWNlcy1leGNoYW5nZS5jb20vYXBwL3NhbWwvY2FsbGJhY2svIiB4bWxuczpzYW1scD0idXJuOm9hc2lzOm5hbWVzOnRj...', from client 10.24.100.238 (10.50.32.107:37182), no auth [2020-08-18 20:28:27,992] DEBUG [th; https-jsse-nio-443-exec-94] - [Presigned-Token Authentication] Authentication scheme is not enabled. org.apache.catalina.connector.RequestFacade@1305b42 [2020-08-18 20:28:28,040] DEBUG [th; https-jsse-nio-443-exec-94] - Creating session 4EFF4F7B69... (created: 2020-08-18 20:28:28.040, timeout: 3600s) [2020-08-18 20:28:28,040] DEBUG [th; https-jsse-nio-443-exec-94] - Matched authentication scheme: jetbrains.buildServer.auth.saml.plugin.SamlAuthenticationScheme, authResult: UNAUTHENTICATED [2020-08-18 20:28:28,040] DEBUG [th; https-jsse-nio-443-exec-94] - Responding with 401 HTTP status with message "SAML request is not authenticated due to errors: invalid_response", sending no WWW-Authenticate header in response [2020-08-18 20:28:28,148] DEBUG [h; https-jsse-nio-443-exec-101] - Processing request with no authorization header: GET '/app/saml/callback/%22/res/6114880409683721742.css', from client 10.24.100.238 (10.50.32.107:37182), no auth [2020-08-18 20:28:28,148] DEBUG [h; https-jsse-nio-443-exec-101] - [Presigned-Token Authentication] Authentication scheme is not enabled. org.apache.catalina.connector.RequestFacade@1305b42 [2020-08-18 20:28:28,148] DEBUG [h; https-jsse-nio-443-exec-101] - No scheme was matched [2020-08-18 20:28:28,148] DEBUG [h; https-jsse-nio-443-exec-101] - Processing unauthenticated request [2020-08-18 20:28:28,148] DEBUG [h; https-jsse-nio-443-exec-101] - Redirecting to login page [2020-08-18 20:28:28,164] DEBUG [h; https-jsse-nio-443-exec-101] - Processing request with no authorization header: GET '/app/saml/callback/%22/res/2319721761153202242.css', from client 10.24.100.238 (10.50.32.107:37408), no auth [2020-08-18 20:28:28,164] DEBUG [h; https-jsse-nio-443-exec-101] - [Presigned-Token Authentication] Authentication scheme is not enabled. org.apache.catalina.connector.RequestFacade@1305b42 [2020-08-18 20:28:28,164] DEBUG [h; https-jsse-nio-443-exec-101] - No scheme was matched [2020-08-18 20:28:28,164] DEBUG [h; https-jsse-nio-443-exec-101] - Processing unauthenticated request [2020-08-18 20:28:28,164] DEBUG [h; https-jsse-nio-443-exec-101] - Redirecting to login page [2020-08-18 20:28:28,367] DEBUG [h; https-jsse-nio-443-exec-107] - Processing request with no authorization header: GET '/app/saml/callback/%22/res/-1503540342333606626.css', from client 10.24.100.238 (10.50.32.107:37436), no auth [2020-08-18 20:28:28,367] DEBUG [h; https-jsse-nio-443-exec-107] - [Presigned-Token Authentication] Authentication scheme is not enabled. org.apache.catalina.connector.RequestFacade@14c0309 [2020-08-18 20:28:28,367] DEBUG [h; https-jsse-nio-443-exec-107] - No scheme was matched [2020-08-18 20:28:28,367] DEBUG [h; https-jsse-nio-443-exec-107] - Processing unauthenticated request [2020-08-18 20:28:28,367] DEBUG [h; https-jsse-nio-443-exec-107] - Redirecting to login page [2020-08-18 20:28:28,367] DEBUG [h; https-jsse-nio-443-exec-107] - Processing request with no authorization header: GET '/app/saml/callback/%22/res/-3342039278521329535.css', from client 10.24.100.238 (10.50.32.107:37428), no auth [2020-08-18 20:28:28,367] DEBUG [h; https-jsse-nio-443-exec-107] - [Presigned-Token Authentication] Authentication scheme is not enabled. org.apache.catalina.connector.RequestFacade@14c0309 [2020-08-18 20:28:28,367] DEBUG [h; https-jsse-nio-443-exec-107] - No scheme was matched [2020-08-18 20:28:28,367] DEBUG [h; https-jsse-nio-443-exec-107] - Processing unauthenticated request [2020-08-18 20:28:28,367] DEBUG [h; https-jsse-nio-443-exec-107] - Redirecting to login page [2020-08-18 20:28:37,929] DEBUG [th; https-jsse-nio-443-exec-89] - Destroying session 4EFF4F7B69... (created: 2020-08-18 20:28:28.040, timeout: 3600s, last accessed: 2020-08-18 20:28:28.914) [2020-08-18 20:28:37,929] DEBUG [th; https-jsse-nio-443-exec-89] - Creating session 61B080617B... (created: 2020-08-18 20:28:37.929, timeout: 3600s) [2020-08-18 20:28:37,929] DEBUG [th; https-jsse-nio-443-exec-89] - Processing login attempt for user "lecastan" [2020-08-18 20:28:37,961] INFO [th; https-jsse-nio-443-exec-89] - Successful login for user 'lecastan' (Lenny Castaneda) {id=5} with auth module "LDAP" for session 61B080617B... (new, created: 2020-08-18 20:28:37.929, timeout: 3600s) while processing request POST

'/loginSubmit.html;TCSESSIONID=4EFF4F7B699363703B1F5BD1731492D1?username=lecastan&remember=true&_remember=&submitLogin=Log%20in&publicKey=00a3c18eb540a64d861f1ff25322261746fcae71b3e9b03eff62ad616a15c9332207436770634604c7a7e421331dba11c1551afbfd23c752b2bb91e919e88264e45c48865537ca931c6a6bde620ef0396a94b3d1568ca9ebfe85585713e106cc0cec50a1e55c7fe5378884aeba848d1b4dd9170a66f66f9b2a045896f1ac859bfb&encryptedPassword=495ec0a307fa9c4ec485fe3da69e362e8e8b257506bc7c1ccec45e1f1ae2bee1323ed8b78da37e17f68...', from client 10.24.100.238 (10.50.32.107:37424), authenticated as 'lecastan' (Lenny Castaneda) {id=5} [2020-08-18 20:28:37,976] DEBUG [th; https-jsse-nio-443-exec-89] - Setting new RememberMe cookie for user 'lecastan' (Lenny Castaneda) {id=5}, value: '1615921765^5#-8543439349608328290'(timeout: 1209600s) for request POST

'/loginSubmit.html;TCSESSIONID=4EFF4F7B699363703B1F5BD1731492D1?username=lecastan&remember=true&_remember=&submitLogin=Log%20in&publicKey=00a3c18eb540a64d861f1ff25322261746fcae71b3e9b03eff62ad616a15c9332207436770634604c7a7e421331dba11c1551afbfd23c752b2bb91e919e88264e45c48865537ca931c6a6bde620ef0396a94b3d1568ca9ebfe85585713e106cc0cec50a1e55c7fe5378884aeba848d1b4dd9170a66f66f9b2a045896f1ac859bfb&encryptedPassword=495ec0a307fa9c4ec485fe3da69e362e8e8b257506bc7c1ccec45e1f1ae2bee1323ed8b78da37e17f68...', from client 10.24.100.238 (10.50.32.107:37424), authenticated as 'lecastan' (Lenny Castaneda) {id=5} [2020-08-18 20:28:51,508] DEBUG [h; https-jsse-nio-443-exec-112] - Processing request with no authorization header: GET '/', from client 10.50.32.107:37464, user-agent "ELB-HealthChecker/2.0", no auth [2020-08-18 20:28:51,508] DEBUG [h; https-jsse-nio-443-exec-112] - [Presigned-Token Authentication] Authentication scheme is not enabled. org.apache.catalina.connector.RequestFacade@14c0309 [2020-08-18 20:28:51,508] DEBUG [h; https-jsse-nio-443-exec-112] - No scheme was matched [2020-08-18 20:28:51,508] DEBUG [h; https-jsse-nio-443-exec-112] - Processing unauthenticated request [2020-08-18 20:28:51,508] DEBUG [h; https-jsse-nio-443-exec-112] - Responding with 401 HTTP status with message "Unauthorized", sending header in response: WWW-Authenticate: Basic realm="TeamCity", Bearer realm="TeamCity" [2020-08-18 20:28:51,929] DEBUG [h; https-jsse-nio-443-exec-102] - Processing request with no authorization header: GET '/', from client 10.50.31.69:56140, user-agent "ELB-HealthChecker/2.0", no auth [2020-08-18 20:28:51,929] DEBUG [h; https-jsse-nio-443-exec-102] - [Presigned-Token Authentication] Authentication scheme is not enabled. org.apache.catalina.connector.RequestFacade@14c0309 [2020-08-18 20:28:51,929] DEBUG [h; https-jsse-nio-443-exec-102] - No scheme was matched [2020-08-18 20:28:51,929] DEBUG [h; https-jsse-nio-443-exec-102] - Processing unauthenticated request [2020-08-18 20:28:51,929] DEBUG [h; https-jsse-nio-443-exec-102] - Responding with 401 HTTP status with message "Unauthorized", sending header in response: WWW-Authenticate: Basic realm="TeamCity", Bearer realm="TeamCity" [2020-08-18 20:28:53,179] DEBUG [h; https-jsse-nio-443-exec-108] - Processing request with no authorization header: GET '/', from client 10.50.34.19:3786, user-agent "ELB-HealthChecker/2.0", no auth [2020-08-18 20:28:53,179] DEBUG [h; https-jsse-nio-443-exec-108] - [Presigned-Token Authentication] Authentication scheme is not enabled. org.apache.catalina.connector.RequestFacade@14c0309 [2020-08-18 20:28:53,179] DEBUG [h; https-jsse-nio-443-exec-108] - No scheme was matched [2020-08-18 20:28:53,179] DEBUG [h; https-jsse-nio-443-exec-108] - Processing unauthenticated request [2020-08-18 20:28:53,179] DEBUG [h; https-jsse-nio-443-exec-108] - Responding with 401 HTTP status with message "Unauthorized", sending header in response: WWW-Authenticate: Basic realm="TeamCity", Bearer realm="TeamCity"

On Wed, Aug 19, 2020 at 10:57 AM Mail Delivery Subsystem < mailer-daemon@googlemail.com> wrote:

Message too large Your message couldn't be delivered to reply@reply.github.com because it exceeds the size limit. Try reducing the message size and resending. The response from the remote server was: 552 5.3.4 Message size exceeds fixed limit

---------- Forwarded message ---------- From: Lenny Castaneda lenny.castaneda@gmail.com To: "morincer/teamcity-plugin-saml" reply@reply.github.com Cc: Bcc: Date: Wed, 19 Aug 2020 10:57:41 -0700 Subject: Re: [morincer/teamcity-plugin-saml] SAML request is not authenticated due to errors: invalid_response (#53) ----- Message truncated -----

Show Quoted Content

On Wed, Aug 19, 2020 at 10:57 AM Mail Delivery Subsystem < mailer-daemon@googlemail.com> wrote:

Message too large Your message couldn't be delivered to reply@reply.github.com because it exceeds the size limit. Try reducing the message size and resending. The response from the remote server was: 552 5.3.4 Message size exceeds fixed limit

---------- Forwarded message ---------- From: Lenny Castaneda lenny.castaneda@gmail.com To: "morincer/teamcity-plugin-saml" reply@reply.github.com Cc: Bcc: Date: Wed, 19 Aug 2020 10:57:41 -0700 Subject: Re: [morincer/teamcity-plugin-saml] SAML request is not authenticated due to errors: invalid_response (#53) ----- Message truncated -----

Take care,

Lenny Castaneda C: 714-414-5823 O: 619-431-0039

On Aug 19, 2020, at 11:06 PM, morincer notifications@github.com wrote:

 @LennyCastaneda , I don't see any attachment.

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub, or unsubscribe.

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub < https://github.com/morincer/teamcity-plugin-saml/issues/53#issuecomment-677655721 , or unsubscribe < https://github.com/notifications/unsubscribe-auth/AEA55RU3LYJOF4BGTSAF6CLSBUOIXANCNFSM4P6XRHCA

.

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/morincer/teamcity-plugin-saml/issues/53#issuecomment-677682447, or unsubscribe https://github.com/notifications/unsubscribe-auth/ACLPMRWB57TDED57L3S5L7DSBUTYTANCNFSM4P6XRHCA .

--

Take care,

Lenny Castaneda C: 714-414-5823 O: 619-431-0039

--

Take care,

Lenny Castaneda C: 714-414-5823 O: 619-431-0039

morincer commented 4 years ago

Well, still I don't see the attachment - probably it's too big. Would you please zip your log and send me directly?

morincer commented 4 years ago

As analysis shows the reason for invalid request was wrong certificate setup (thus causing "signature validation failed" error) - when using a certificate from IdP metadata no issue is happening. Closing the defect for now.