Bug 1390844

Created attachment 1216337 [details]
picture

Created attachment 1216338 [details]
var log

Created attachment 1216339 [details]
engine log

The bug cannot be reproduced with the preceding build, add regression keyword

Juan, would you be so kind and suggest a way how to find out the connection between API requests and a failure in engine.log? I'm totally lost:/

I don't have a general recipe, but in this particular case the error is 401, unauthorized, so most probably the request didn't reach the API, it was rejected by the authentication layer. The last few lines of the engine.log file say this:

2016-11-02 11:36:44,386 ERROR [org.ovirt.engine.core.sso.utils.SsoUtils] (default task-22) [] OAuthException invalid_grant: The provided authorization grant for the auth code has expired
2016-11-02 11:36:44,387 ERROR [org.ovirt.engine.core.aaa.filters.SsoRestApiAuthFilter] (default task-27) [] Cannot authenticate using authentication Headers: invalid_grant: The provided authorization grant for the auth code has expired

That confirms that there is some kind of authentication problem, but as there are no more details or stack trace I can't say anything else. The web server access log can help, as we could see more details of the request that the client is sending.

Wei, do you still have the logs of the RHV machine, in particular /var/log/httpd/ssl_access_log. Can you share it? If possible clean that log, reproduce the problem, and attach it.

Ravi, any idea of what can be causing this authentication failure?

Looking a bit more into this I see in cockpit-ovirt.log that the host is requesting an authentication token:

11/01/2016 04:33:28 PM http_call: 'https://rhevm-40-1.englab.nay.redhat.com/ovirt-engine/sso/oauth/token?grant_type=urn:ovirt:params:oauth:grant-type:http&scope=ovirt-app-api',
  method:GET, user:admin@internal, headers:{'Accept': 'application/json'}
11/01/2016 04:33:28 PM http_call status_code: 200
11/01/2016 04:33:28 PM build_result, code: 0, message: "Done", content: True
11/01/2016 04:33:28 PM result: {"status": {"message": "Done", "code": 0}, "content": {"access_token": "2e2WcqgH9LWpCiTM3groh2K5T2y1hw7i-R_Oj1KKAghWgkht48S1uCcQKrCXprRXHzJr2q26Elj3pXk7ZUgU_g", "scope": "ovirt-app-api ovirt-ext=token-info:authz-search ovirt-ext=token-info:public-authz-search ovirt-ext=token-info:validate", "token_type": "bearer", "exp": 1125248176}}

Note the value of the "exp" attribute of the result, 1125248176, in theory that is a date in the past:

  Date date = new Date(1125248176L);
  System.out.println(date);

Produces:

  Wed Jan 14 01:34:08 CET 1970

Is that correct Ravi? There may be a problem with conversion from long to int here:

  https://github.com/oVirt/ovirt-engine/blob/master/backend/manager/modules/enginesso/src/main/java/org/ovirt/engine/core/sso/utils/SsoUtils.java#L403

Then, several hours later, is using it to request the list of virtual machines, and it fails, apparently because the token is expired:

11/02/2016 11:21:54 AM http_call: 'https://rhevm-40-1.englab.nay.redhat.com/ovirt-engine/api/vms',
  method:GET, user:None, headers:{'Authorization': 'Bearer 2e2WcqgH9LWpCiTM3groh2K5T2y1hw7i-R_Oj1KKAghWgkht48S1uCcQKrCXprRXHzJr2q26Elj3pXk7ZUgU_g', 'Accept': 'application/json'}
11/02/2016 11:21:54 AM http_call status_code: 401

Shouldn't cockpit detect this and renew the SSO token?

From the cockpit logs this is what I see.

User authenticated and acquired token at 11/01/2016 04:33:28 PM 
last successful access was done at 11/01/2016 04:49:23 PM. The successful access includes getAllVmsList.
There is a period of inactivity and then at 11/02/2016 11:21:52 AM, the same token is being used to fetch vms and it fails.

The session has been purged from SSO and engine side due to inactivity. Cockpit needs re-authenticate and acquire a new session.

What about the value of the "exp" attribute of the authentication result? Is it correct?

*** This bug has been marked as a duplicate of bug 1389251 ***

Yes there is an issue with the cast to int, will submit a separate patch for that

This bug report has Keywords: Regression or TestBlocker.
Since no regressions or test blockers are allowed between releases, it is also being identified as a blocker for this release. Please resolve ASAP.

Unfortunately there was a bit noise about this bug, but the real issue is described in Comment 8, cockpit acquired a token, but after some this toked expired, so cockpit need to get new token.

not a regression really. The token is not refreshed so once it expires it breaks.

Right, token renewal needs to be implemented.

The bug was not addressed in time for 4.1. Postponing to 4.2

"Virtual Machines" (the VDSM part) of cockpit-ovirt has been removed for ovirt 4.2 (https://gerrit.ovirt.org/#/c/80442/ ), I propose to close this bug.

Removed in 4.2

Change "Resolution" from "NOTABUT" to "WONTFIX" since it is an effective bug in 4.1.