CF CLI authentication issue


Klevenz, Stephan <stephan.klevenz@...>
 

Hi,

I am having a strange issue with the cf cli. Sometimes am doing a cf login and then a cf push immediately as a next step. Then push fails and reports "Authentication has expired. Please log back in to re-authenticate." The behavior is completely random. Automized app deployment triggered by CI jobs do fail very often.

I did an analysis of UAA logs and found the entries below. UAA means that the password of user has changed because of last modified date of user doesn't fit to issue date of token. Actually the user credentials are not changed. At least not by purpose.

The CF version is 198.

Do you have any hints what could cause this issue? Any reply is welcome.

Regards,
Stephan



[2015-06-16 13:00:52.885] uaa - 59331 [http-bio-8080-exec-1] .... DEBUG --- UaaTokenServices: User was last modified at 2015-06-16 12:58:52.302 refresh token was issued at Tue Jun 16 12:58:03 UTC 2015
[2015-06-16 13:00:52.885] uaa - 59331 [http-bio-8080-exec-1] .... DEBUG --- ExceptionHandlerExceptionResolver: Resolving exception from handler [public org.springframework.http.ResponseEntity<org.springframework.security.oauth2.common.OAuth2AccessToken> org.springframework.security.oauth2.provider.endpoint.TokenEndpoint.getAccessToken(java.security.Principal,java.util.Map<java.lang.String, java.lang.String>)]: error="invalid_token", error_description="Invalid refresh token (password changed): eyJhbGciOiJSUzI1NiJ9.eyJqdGkiOiIyZjlhNGU2Ny0yYjY2LTQwMTItYjk1NC1jODg3OTMxN2I5ZDkiLCJzdWIiOiJlNDMwNzY1NS1lMTc2LTQ5Y2YtOGI5Mi04YjUxYWQ5ZTVmZDUiLCJzY29wZSI6WyJzY2ltLnVzZXJpZHMiLCJjbG91ZF9jb250cm9sbGVyLndyaXRlIiwicGFzc3dvcmQud3JpdGUiLCJvcGVuaWQiLCJjbG91ZF9jb250cm9sbGVyLnJlYWQiXSwiaWF0IjoxNDM0NDU5NDgzLCJleHAiOjE0MzcwNTE0ODMsImNpZCI6ImNmIiwiaXNzIjoiaHR0cHM6Ly91YWEuY2YubmVvLm9uZGVtYW5kLmNvbS9vYXV0aC90b2tlbiIsImdyYW50X3R5cGUiOiJwYXNzd29yZCIsInVzZXJfbmFtZSI6IlAxNDQ1NTM4MTkyIiwidXNlcl9pZCI6ImU0MzA3NjU1LWUxNzYtNDljZi04YjkyLThiNTFhZDllNWZkNSIsImF1ZCI6WyJjZiIsInNjaW0iLCJjbG91ZF9jb250cm9sbGVyIiwicGFzc3dvcmQiLCJvcGVuaWQiXX0.sYmE3J5_IjYPRTnLYFT9dJ2p7nDR1WDMhvT95Anr8qWdDHTBp-tXLmPOZ17v66RuGcZhFAmYEmJMuW1ggBnuOQAB5lCKvvjINdlWdjKIxRlD24eLkGsqV_9ENUFIweIfKtYTAdmlXySqg47ZgZLotT9UVTtfD9BwI-NAZLBN6Ro"


Benjamin Black
 

Stephan,

Have you verified the clocks are in sync, perhaps using ntp, across all the
systems involved?


b


On Tue, Jun 16, 2015 at 8:42 AM, Klevenz, Stephan <stephan.klevenz(a)sap.com>
wrote:

Hi,

I am having a strange issue with the cf cli. Sometimes am doing a cf
login and then a cf push immediately as a next step. Then push fails and
reports "Authentication has expired. Please log back in to
re-authenticate." The behavior is completely random. Automized app
deployment triggered by CI jobs do fail very often.

I did an analysis of UAA logs and found the entries below. UAA means
that the password of user has changed because of last modified date of user
doesn't fit to issue date of token. Actually the user credentials are not
changed. At least not by purpose.

The CF version is 198.

Do you have any hints what could cause this issue? Any reply is welcome.

Regards,
Stephan



*[2015-06-16 13:00:52.885] uaa - 59331 [http-bio-8080-exec-1] ....
DEBUG --- UaaTokenServices: User was last modified at 2015-06-16
12:58:52.302 refresh token was issued at Tue Jun 16 12:58:03 UTC 2015*
*[2015-06-16 13:00:52.885] uaa - 59331 [http-bio-8080-exec-1] .... DEBUG
--- ExceptionHandlerExceptionResolver: Resolving exception from handler
[public
org.springframework.http.ResponseEntity<org.springframework.security.oauth2.common.OAuth2AccessToken>
org.springframework.security.oauth2.provider.endpoint.TokenEndpoint.getAccessToken(java.security.Principal,java.util.Map<java.lang.String,
java.lang.String>)]: error="invalid_token", error_description="Invalid
refresh token (password changed):
eyJhbGciOiJSUzI1NiJ9.eyJqdGkiOiIyZjlhNGU2Ny0yYjY2LTQwMTItYjk1NC1jODg3OTMxN2I5ZDkiLCJzdWIiOiJlNDMwNzY1NS1lMTc2LTQ5Y2YtOGI5Mi04YjUxYWQ5ZTVmZDUiLCJzY29wZSI6WyJzY2ltLnVzZXJpZHMiLCJjbG91ZF9jb250cm9sbGVyLndyaXRlIiwicGFzc3dvcmQud3JpdGUiLCJvcGVuaWQiLCJjbG91ZF9jb250cm9sbGVyLnJlYWQiXSwiaWF0IjoxNDM0NDU5NDgzLCJleHAiOjE0MzcwNTE0ODMsImNpZCI6ImNmIiwiaXNzIjoiaHR0cHM6Ly91YWEuY2YubmVvLm9uZGVtYW5kLmNvbS9vYXV0aC90b2tlbiIsImdyYW50X3R5cGUiOiJwYXNzd29yZCIsInVzZXJfbmFtZSI6IlAxNDQ1NTM4MTkyIiwidXNlcl9pZCI6ImU0MzA3NjU1LWUxNzYtNDljZi04YjkyLThiNTFhZDllNWZkNSIsImF1ZCI6WyJjZiIsInNjaW0iLCJjbG91ZF9jb250cm9sbGVyIiwicGFzc3dvcmQiLCJvcGVuaWQiXX0.sYmE3J5_IjYPRTnLYFT9dJ2p7nDR1WDMhvT95Anr8qWdDHTBp-tXLmPOZ17v66RuGcZhFAmYEmJMuW1ggBnuOQAB5lCKvvjINdlWdjKIxRlD24eLkGsqV_9ENUFIweIfKtYTAdmlXySqg47ZgZLotT9UVTtfD9BwI-NAZLBN6Ro"*


_______________________________________________
cf-dev mailing list
cf-dev(a)lists.cloudfoundry.org
https://lists.cloudfoundry.org/mailman/listinfo/cf-dev


Madhura Bhave
 

Hi Stephan,

Could you send us the entire log for the UAA?

Madhura

On Tue, Jun 16, 2015 at 9:04 AM, Benjamin Black <bblack(a)pivotal.io> wrote:

Stephan,

Have you verified the clocks are in sync, perhaps using ntp, across all
the systems involved?


b


On Tue, Jun 16, 2015 at 8:42 AM, Klevenz, Stephan <stephan.klevenz(a)sap.com
wrote:
Hi,

I am having a strange issue with the cf cli. Sometimes am doing a cf
login and then a cf push immediately as a next step. Then push fails and
reports "Authentication has expired. Please log back in to
re-authenticate." The behavior is completely random. Automized app
deployment triggered by CI jobs do fail very often.

I did an analysis of UAA logs and found the entries below. UAA means
that the password of user has changed because of last modified date of user
doesn't fit to issue date of token. Actually the user credentials are not
changed. At least not by purpose.

The CF version is 198.

Do you have any hints what could cause this issue? Any reply is welcome.

Regards,
Stephan



*[2015-06-16 13:00:52.885] uaa - 59331 [http-bio-8080-exec-1] ....
DEBUG --- UaaTokenServices: User was last modified at 2015-06-16
12:58:52.302 refresh token was issued at Tue Jun 16 12:58:03 UTC 2015*
*[2015-06-16 13:00:52.885] uaa - 59331 [http-bio-8080-exec-1] .... DEBUG
--- ExceptionHandlerExceptionResolver: Resolving exception from handler
[public
org.springframework.http.ResponseEntity<org.springframework.security.oauth2.common.OAuth2AccessToken>
org.springframework.security.oauth2.provider.endpoint.TokenEndpoint.getAccessToken(java.security.Principal,java.util.Map<java.lang.String,
java.lang.String>)]: error="invalid_token", error_description="Invalid
refresh token (password changed):
eyJhbGciOiJSUzI1NiJ9.eyJqdGkiOiIyZjlhNGU2Ny0yYjY2LTQwMTItYjk1NC1jODg3OTMxN2I5ZDkiLCJzdWIiOiJlNDMwNzY1NS1lMTc2LTQ5Y2YtOGI5Mi04YjUxYWQ5ZTVmZDUiLCJzY29wZSI6WyJzY2ltLnVzZXJpZHMiLCJjbG91ZF9jb250cm9sbGVyLndyaXRlIiwicGFzc3dvcmQud3JpdGUiLCJvcGVuaWQiLCJjbG91ZF9jb250cm9sbGVyLnJlYWQiXSwiaWF0IjoxNDM0NDU5NDgzLCJleHAiOjE0MzcwNTE0ODMsImNpZCI6ImNmIiwiaXNzIjoiaHR0cHM6Ly91YWEuY2YubmVvLm9uZGVtYW5kLmNvbS9vYXV0aC90b2tlbiIsImdyYW50X3R5cGUiOiJwYXNzd29yZCIsInVzZXJfbmFtZSI6IlAxNDQ1NTM4MTkyIiwidXNlcl9pZCI6ImU0MzA3NjU1LWUxNzYtNDljZi04YjkyLThiNTFhZDllNWZkNSIsImF1ZCI6WyJjZiIsInNjaW0iLCJjbG91ZF9jb250cm9sbGVyIiwicGFzc3dvcmQiLCJvcGVuaWQiXX0.sYmE3J5_IjYPRTnLYFT9dJ2p7nDR1WDMhvT95Anr8qWdDHTBp-tXLmPOZ17v66RuGcZhFAmYEmJMuW1ggBnuOQAB5lCKvvjINdlWdjKIxRlD24eLkGsqV_9ENUFIweIfKtYTAdmlXySqg47ZgZLotT9UVTtfD9BwI-NAZLBN6Ro"*


_______________________________________________
cf-dev mailing list
cf-dev(a)lists.cloudfoundry.org
https://lists.cloudfoundry.org/mailman/listinfo/cf-dev

_______________________________________________
cf-dev mailing list
cf-dev(a)lists.cloudfoundry.org
https://lists.cloudfoundry.org/mailman/listinfo/cf-dev


Klevenz, Stephan <stephan.klevenz@...>
 

Hi Benjamin,

Sytems are synchronized by ntp. However, time of different machines differs by a few seconds (5-20s). I am not sure how accurate ntp time sync can be or should be.

Could that cause the issue?

Regards,
Stephan


Von: Benjamin Black
Antworten an: "Discussions about Cloud Foundry projects and the system overall."
Datum: Dienstag, 16. Juni 2015 18:04
An: "Discussions about Cloud Foundry projects and the system overall."
Betreff: Re: [cf-dev] CF CLI authentication issue

Stephan,

Have you verified the clocks are in sync, perhaps using ntp, across all the systems involved?


b

On Tue, Jun 16, 2015 at 8:42 AM, Klevenz, Stephan <stephan.klevenz(a)sap.com<mailto:stephan.klevenz(a)sap.com>> wrote:
Hi,

I am having a strange issue with the cf cli. Sometimes am doing a cf login and then a cf push immediately as a next step. Then push fails and reports "Authentication has expired. Please log back in to re-authenticate." The behavior is completely random. Automized app deployment triggered by CI jobs do fail very often.

I did an analysis of UAA logs and found the entries below. UAA means that the password of user has changed because of last modified date of user doesn't fit to issue date of token. Actually the user credentials are not changed. At least not by purpose.

The CF version is 198.

Do you have any hints what could cause this issue? Any reply is welcome.

Regards,
Stephan



[2015-06-16 13:00:52.885] uaa - 59331 [http-bio-8080-exec-1] .... DEBUG --- UaaTokenServices: User was last modified at 2015-06-16 12:58:52.302 refresh token was issued at Tue Jun 16 12:58:03 UTC 2015
[2015-06-16 13:00:52.885] uaa - 59331 [http-bio-8080-exec-1] .... DEBUG --- ExceptionHandlerExceptionResolver: Resolving exception from handler [public org.springframework.http.ResponseEntity<org.springframework.security.oauth2.common.OAuth2AccessToken> org.springframework.security.oauth2.provider.endpoint.TokenEndpoint.getAccessToken(java.security.Principal,java.util.Map<java.lang.String, java.lang.String>)]: error="invalid_token", error_description="Invalid refresh token (password changed): eyJhbGciOiJSUzI1NiJ9.eyJqdGkiOiIyZjlhNGU2Ny0yYjY2LTQwMTItYjk1NC1jODg3OTMxN2I5ZDkiLCJzdWIiOiJlNDMwNzY1NS1lMTc2LTQ5Y2YtOGI5Mi04YjUxYWQ5ZTVmZDUiLCJzY29wZSI6WyJzY2ltLnVzZXJpZHMiLCJjbG91ZF9jb250cm9sbGVyLndyaXRlIiwicGFzc3dvcmQud3JpdGUiLCJvcGVuaWQiLCJjbG91ZF9jb250cm9sbGVyLnJlYWQiXSwiaWF0IjoxNDM0NDU5NDgzLCJleHAiOjE0MzcwNTE0ODMsImNpZCI6ImNmIiwiaXNzIjoiaHR0cHM6Ly91YWEuY2YubmVvLm9uZGVtYW5kLmNvbS9vYXV0aC90b2tlbiIsImdyYW50X3R5cGUiOiJwYXNzd29yZCIsInVzZXJfbmFtZSI6IlAxNDQ1NTM4MTkyIiwidXNlcl9pZCI6ImU0MzA3NjU1LWUxNzYtNDljZi04YjkyLThiNTFhZDllNWZkNSIsImF1ZCI6WyJjZiIsInNjaW0iLCJjbG91ZF9jb250cm9sbGVyIiwicGFzc3dvcmQiLCJvcGVuaWQiXX0.sYmE3J5_IjYPRTnLYFT9dJ2p7nDR1WDMhvT95Anr8qWdDHTBp-tXLmPOZ17v66RuGcZhFAmYEmJMuW1ggBnuOQAB5lCKvvjINdlWdjKIxRlD24eLkGsqV_9ENUFIweIfKtYTAdmlXySqg47ZgZLotT9UVTtfD9BwI-NAZLBN6Ro"


_______________________________________________
cf-dev mailing list
cf-dev(a)lists.cloudfoundry.org<mailto:cf-dev(a)lists.cloudfoundry.org>
https://lists.cloudfoundry.org/mailman/listinfo/cf-dev


Benjamin Black
 

Stephan,

That's a lot of skew for ntp synchronized systems. I would expect them to
differ by less than a second. The problem you are having could be a result.


b


On Wed, Jun 17, 2015 at 8:51 AM, Klevenz, Stephan <stephan.klevenz(a)sap.com>
wrote:

Hi Benjamin,

Sytems are synchronized by ntp. However, time of different machines
differs by a few seconds (5-20s). I am not sure how accurate ntp time sync
can be or should be.

Could that cause the issue?

Regards,
Stephan


Von: Benjamin Black
Antworten an: "Discussions about Cloud Foundry projects and the system
overall."
Datum: Dienstag, 16. Juni 2015 18:04
An: "Discussions about Cloud Foundry projects and the system overall."
Betreff: Re: [cf-dev] CF CLI authentication issue

Stephan,

Have you verified the clocks are in sync, perhaps using ntp, across all
the systems involved?


b


On Tue, Jun 16, 2015 at 8:42 AM, Klevenz, Stephan <stephan.klevenz(a)sap.com
wrote:
Hi,

I am having a strange issue with the cf cli. Sometimes am doing a cf
login and then a cf push immediately as a next step. Then push fails and
reports "Authentication has expired. Please log back in to
re-authenticate." The behavior is completely random. Automized app
deployment triggered by CI jobs do fail very often.

I did an analysis of UAA logs and found the entries below. UAA means
that the password of user has changed because of last modified date of user
doesn't fit to issue date of token. Actually the user credentials are not
changed. At least not by purpose.

The CF version is 198.

Do you have any hints what could cause this issue? Any reply is welcome.

Regards,
Stephan



*[2015-06-16 13:00:52.885] uaa - 59331 [http-bio-8080-exec-1] ....
DEBUG --- UaaTokenServices: User was last modified at 2015-06-16
12:58:52.302 refresh token was issued at Tue Jun 16 12:58:03 UTC 2015*
*[2015-06-16 13:00:52.885] uaa - 59331 [http-bio-8080-exec-1] .... DEBUG
--- ExceptionHandlerExceptionResolver: Resolving exception from handler
[public
org.springframework.http.ResponseEntity<org.springframework.security.oauth2.common.OAuth2AccessToken>
org.springframework.security.oauth2.provider.endpoint.TokenEndpoint.getAccessToken(java.security.Principal,java.util.Map<java.lang.String,
java.lang.String>)]: error="invalid_token", error_description="Invalid
refresh token (password changed):
eyJhbGciOiJSUzI1NiJ9.eyJqdGkiOiIyZjlhNGU2Ny0yYjY2LTQwMTItYjk1NC1jODg3OTMxN2I5ZDkiLCJzdWIiOiJlNDMwNzY1NS1lMTc2LTQ5Y2YtOGI5Mi04YjUxYWQ5ZTVmZDUiLCJzY29wZSI6WyJzY2ltLnVzZXJpZHMiLCJjbG91ZF9jb250cm9sbGVyLndyaXRlIiwicGFzc3dvcmQud3JpdGUiLCJvcGVuaWQiLCJjbG91ZF9jb250cm9sbGVyLnJlYWQiXSwiaWF0IjoxNDM0NDU5NDgzLCJleHAiOjE0MzcwNTE0ODMsImNpZCI6ImNmIiwiaXNzIjoiaHR0cHM6Ly91YWEuY2YubmVvLm9uZGVtYW5kLmNvbS9vYXV0aC90b2tlbiIsImdyYW50X3R5cGUiOiJwYXNzd29yZCIsInVzZXJfbmFtZSI6IlAxNDQ1NTM4MTkyIiwidXNlcl9pZCI6ImU0MzA3NjU1LWUxNzYtNDljZi04YjkyLThiNTFhZDllNWZkNSIsImF1ZCI6WyJjZiIsInNjaW0iLCJjbG91ZF9jb250cm9sbGVyIiwicGFzc3dvcmQiLCJvcGVuaWQiXX0.sYmE3J5_IjYPRTnLYFT9dJ2p7nDR1WDMhvT95Anr8qWdDHTBp-tXLmPOZ17v66RuGcZhFAmYEmJMuW1ggBnuOQAB5lCKvvjINdlWdjKIxRlD24eLkGsqV_9ENUFIweIfKtYTAdmlXySqg47ZgZLotT9UVTtfD9BwI-NAZLBN6Ro"*


_______________________________________________
cf-dev mailing list
cf-dev(a)lists.cloudfoundry.org
https://lists.cloudfoundry.org/mailman/listinfo/cf-dev

_______________________________________________
cf-dev mailing list
cf-dev(a)lists.cloudfoundry.org
https://lists.cloudfoundry.org/mailman/listinfo/cf-dev