[AMAGENTS-704] C Agent 5 returns 403, if you don't login immediately Created: 29/Jun/17  Updated: 27/Feb/20  Resolved: 27/Feb/20

Status: Closed
Project: OpenAM Agents
Component/s: Web Agents
Affects Version/s: 5.0.0.0
Fix Version/s: None

Type: Bug Priority: Major
Reporter: Richard Hruza Assignee: Unassigned
Resolution: Duplicate Votes: 0
Labels: 5.6-Wont-fix, 5.7-Candidate, AME, CURIE, QA-Agent5
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified
Environment:

Ubuntu 14.04 / Apache 2.4 / PA: Version: 5.0.0-SNAPSHOT, Revision: 0725088, Container: Apache 2.4 Linux 64bit/Linux, Build date: Jun 26 2017 16:50:07


Attachments: PNG File image-2019-05-20-15-00-25-037.png    
Issue Links:
Duplicate
duplicates AMAGENTS-2717 Timed out Login Session results in 40... In Review
is duplicated by AMAGENTS-2717 Timed out Login Session results in 40... In Review

 Description   

C Agent 5 returns 403, if you don't login immediately.

Steps to reproduce

1.) Create a policy, e.g for /index.html page
2.) Hit the index.html.
3.) You will be redirected to AM login page, on login page wait 1 min (for reproduction this issue is good to stay exactly one minute)
4.) After one minute login with user

Expected Result

You will see protected page

Observed Result

403 Forbidden
iPDP cookie under cookie domain is created, but OIDC iPDP token is not created.

Agent Debug log
2017-06-29 07:20:54.773 +0100   DEBUG [0x7f1e00b27700:5666][source/request.c:249] setup_request_data():
2017-06-29 07:20:54.774 +0100   DEBUG [0x7f1e00b27700:5666][source/request.c:271] setup_request_data(): client ip: 172.25.1.224
2017-06-29 07:20:54.774 +0100   DEBUG [0x7f1e00b27700:5666][source/request.c:309] setup_request_data(): client hostname: (empty)
2017-06-29 07:20:54.774 +0100   DEBUG [0x7f1e00b27700:5666][source/request.c:317] setup_request_data(): original request url: http://riso-ubuntu14.test.forgerock.com/index.html
2017-06-29 07:20:54.774 +0100   DEBUG [0x7f1e00b27700:5666][source/request.c:397] setup_request_data(): 
method: GET 
original url: http://riso-ubuntu14.test.forgerock.com/index.html
proto: http
host: riso-ubuntu14.test.forgerock.com
port: 80
path: /index.html
query: 
complete: http://riso-ubuntu14.test.forgerock.com:80/index.html
overridden: http://riso-ubuntu14.test.forgerock.com:80/index.html
pathinfo: 
normalized (pathinfo removed): (empty)
overridden (pathinfo removed): (empty)
2017-06-29 07:20:54.774 +0100   DEBUG [0x7f1e00b27700:5666][source/request.c:421] validate_url():
2017-06-29 07:20:54.774 +0100   DEBUG [0x7f1e00b27700:5666][source/request.c:433] validate_url(): request url validation feature is not enabled
2017-06-29 07:20:54.774 +0100   DEBUG [0x7f1e00b27700:5666][source/request.c:442] validate_fqdn_access():
2017-06-29 07:20:54.774 +0100   DEBUG [0x7f1e00b27700:5666][source/request.c:445] validate_fqdn_access(): feature is not enabled
2017-06-29 07:20:54.774 +0100   DEBUG [0x7f1e00b27700:5666][source/request.c:544] handle_not_enforced(): application logout url feature is not enabled
2017-06-29 07:20:54.774 +0100   DEBUG [0x7f1e00b27700:5666][source/request.c:684] handle_not_enforced(): not enforced client ip validation feature is not enabled
2017-06-29 07:20:54.774 +0100   DEBUG [0x7f1e00b27700:5666][source/request.c:687] handle_not_enforced(): validating http://riso-ubuntu14.test.forgerock.com:80/index.html
2017-06-29 07:20:54.774 +0100   DEBUG [0x7f1e00b27700:5666][source/request.c:763] handle_not_enforced(): not enforced url validation feature is not enabled
2017-06-29 07:20:54.774 +0100   DEBUG [0x7f1e00b27700:5666][source/request.c:808] handle_not_enforced(): extended not enforced url validation feature is not enabled
2017-06-29 07:20:54.774 +0100   DEBUG [0x7f1e00b27700:5666][source/request.c:811] handle_not_enforced(): http://riso-ubuntu14.test.forgerock.com:80/index.html is enforced
2017-06-29 07:20:54.774 +0100   DEBUG [0x7f1e00b27700:5666][source/request.c:952] validate_policy(): for http://riso-ubuntu14.test.forgerock.com:80/index.html (ignoring pathinfo: no), entry status: not found
2017-06-29 07:20:54.774 +0100   DEBUG [0x7f1e00b27700:5666][source/request.c:1987] handle_exit(): (entry status: invalid session)
2017-06-29 07:20:54.774 +0100   DEBUG [0x7f1e00b27700:5666][source/request.c:1574] do_cookie_set_generic(): iPlanetDirectoryPro=;Max-Age=0;Expires=Thu, 01-Jan-1970 00:00:01 GMT;Path=/
2017-06-29 07:20:54.776 +0100   DEBUG [0x7f1e00b27700:5666][source/utility.c:1551] get_valid_openam_url(): active OpenAM service url: http://perf-openam.internal.forgerock.com:8080/openam (0)
2017-06-29 07:20:54.777 +0100   DEBUG [0x7f1e00b27700:5666][source/apache/agent.c:736] amagent_auth_handler(): exit status: redirect (1)
2017-06-29 07:21:59.610 +0100   DEBUG [0x7f1dbd3aa700:5556][source/request.c:249] setup_request_data():
2017-06-29 07:21:59.610 +0100   DEBUG [0x7f1dbd3aa700:5556][source/request.c:271] setup_request_data(): client ip: 172.25.1.224
2017-06-29 07:21:59.610 +0100   DEBUG [0x7f1dbd3aa700:5556][source/request.c:309] setup_request_data(): client hostname: (empty)
2017-06-29 07:21:59.610 +0100   DEBUG [0x7f1dbd3aa700:5556][source/request.c:317] setup_request_data(): original request url: http://riso-ubuntu14.test.forgerock.com/agent/cdsso-oauth2
2017-06-29 07:21:59.611 +0100   DEBUG [0x7f1dbd3aa700:5556][source/request.c:397] setup_request_data(): 
method: POST 
original url: http://riso-ubuntu14.test.forgerock.com/agent/cdsso-oauth2
proto: http
host: riso-ubuntu14.test.forgerock.com
port: 80
path: /agent/cdsso-oauth2
query: 
complete: http://riso-ubuntu14.test.forgerock.com:80/agent/cdsso-oauth2
overridden: http://riso-ubuntu14.test.forgerock.com:80/agent/cdsso-oauth2
pathinfo: /cdsso-oauth2
normalized (pathinfo removed): http://riso-ubuntu14.test.forgerock.com:80/agent
overridden (pathinfo removed): (empty)
2017-06-29 07:21:59.611 +0100   DEBUG [0x7f1dbd3aa700:5556][source/request.c:232] this is an oauth2 authn post
2017-06-29 07:21:59.611 +0100   DEBUG [0x7f1dbd3aa700:5556][source/request.c:408] setup_request_data(): URL is an authorisation response

2017-06-29 07:21:59.612 +0100   DEBUG [0x7f1dbd3aa700:5556][source/request.c:1987] handle_exit(): (entry status: authentication post)
2017-06-29 07:21:59.616 +0100   DEBUG [0x7f1dbd3aa700:5556][source/request_body.c:82] create_post_body(): created file /tmp/7f388acc-53ce-eb4f-902d-77862ad689d2
2017-06-29 07:21:59.617 +0100   DEBUG [0x7f1dbd3aa700:5556][source/apache/agent.c:498] get_request_body(): processed 1144 bytes to /tmp/7f388acc-53ce-eb4f-902d-77862ad689d2
2017-06-29 07:21:59.618 +0100   DEBUG [0x7f1dbd3aa700:5556][source/request_body.c:116] close_post_body(): reading body content to memory
2017-06-29 07:21:59.619 +0100 WARNING [0x7f1dbd3aa700:5556] convert_request_after_authn_post(): unable to retrieve pre-authentication request data
2017-06-29 07:21:59.619 +0100   DEBUG [0x7f1dbd3aa700:5556][source/apache/agent.c:736] amagent_auth_handler(): exit status: forbidden (3)
2017-06-29 07:21:59.714 +0100   DEBUG [0x7f1e01b29700:5556][source/request.c:249] setup_request_data():
2017-06-29 07:21:59.714 +0100   DEBUG [0x7f1e01b29700:5556][source/request.c:271] setup_request_data(): client ip: 172.25.1.224
2017-06-29 07:21:59.714 +0100   DEBUG [0x7f1e01b29700:5556][source/request.c:309] setup_request_data(): client hostname: (empty)
2017-06-29 07:21:59.714 +0100   DEBUG [0x7f1e01b29700:5556][source/request.c:317] setup_request_data(): original request url: http://riso-ubuntu14.test.forgerock.com/agent/cdsso-oauth2
2017-06-29 07:21:59.715 +0100   DEBUG [0x7f1e01b29700:5556][source/request.c:397] setup_request_data(): 
method: GET 
original url: http://riso-ubuntu14.test.forgerock.com/agent/cdsso-oauth2
proto: http
host: riso-ubuntu14.test.forgerock.com
port: 80
path: /agent/cdsso-oauth2
query: 
complete: http://riso-ubuntu14.test.forgerock.com:80/agent/cdsso-oauth2
overridden: http://riso-ubuntu14.test.forgerock.com:80/agent/cdsso-oauth2
pathinfo: /cdsso-oauth2
normalized (pathinfo removed): http://riso-ubuntu14.test.forgerock.com:80/agent
overridden (pathinfo removed): (empty)
2017-06-29 07:21:59.715 +0100   DEBUG [0x7f1e01b29700:5556][source/request.c:232] this is an oauth2 authn post
2017-06-29 07:21:59.715 +0100   DEBUG [0x7f1e01b29700:5556][source/request.c:408] setup_request_data(): URL is an authorisation response

2017-06-29 07:21:59.715 +0100   DEBUG [0x7f1e01b29700:5556][source/request.c:1987] handle_exit(): (entry status: authentication post)
2017-06-29 07:21:59.715 +0100 WARNING [0x7f1e01b29700:5556] create_post_body(): unable to determine Content-Length header value
2017-06-29 07:21:59.716 +0100   DEBUG [0x7f1e01b29700:5556][source/request_body.c:82] create_post_body(): created file /tmp/70fe6756-84a6-c34a-8dc4-85f322f4c95b
2017-06-29 07:21:59.716 +0100   DEBUG [0x7f1e01b29700:5556][source/apache/agent.c:498] get_request_body(): processed 0 bytes to /tmp/70fe6756-84a6-c34a-8dc4-85f322f4c95b
2017-06-29 07:21:59.717 +0100   DEBUG [0x7f1e01b29700:5556][source/request_body.c:116] close_post_body(): reading body content to memory
2017-06-29 07:21:59.717 +0100 WARNING [0x7f1e01b29700:5556] convert_request_after_authn_post(): unable to parse authentication response
2017-06-29 07:21:59.718 +0100   DEBUG [0x7f1e01b29700:5556][source/apache/agent.c:736] amagent_auth_handler(): exit status: forbidden (3)
2017-06-29 07:21:59.770 +0100   DEBUG [0x7f1e03d14700:5556][source/request.c:249] setup_request_data():
2017-06-29 07:21:59.771 +0100   DEBUG [0x7f1e03d14700:5556][source/request.c:271] setup_request_data(): client ip: 172.25.1.224
2017-06-29 07:21:59.771 +0100   DEBUG [0x7f1e03d14700:5556][source/request.c:309] setup_request_data(): client hostname: (empty)
2017-06-29 07:21:59.771 +0100   DEBUG [0x7f1e03d14700:5556][source/request.c:317] setup_request_data(): original request url: http://riso-ubuntu14.test.forgerock.com/favicon.ico
2017-06-29 07:21:59.771 +0100   DEBUG [0x7f1e03d14700:5556][source/request.c:397] setup_request_data(): 
method: GET 
original url: http://riso-ubuntu14.test.forgerock.com/favicon.ico
proto: http
host: riso-ubuntu14.test.forgerock.com
port: 80
path: /favicon.ico
query: 
complete: http://riso-ubuntu14.test.forgerock.com:80/favicon.ico
overridden: http://riso-ubuntu14.test.forgerock.com:80/favicon.ico
pathinfo: 
normalized (pathinfo removed): (empty)
overridden (pathinfo removed): (empty)
2017-06-29 07:21:59.771 +0100   DEBUG [0x7f1e03d14700:5556][source/request.c:421] validate_url():
2017-06-29 07:21:59.771 +0100   DEBUG [0x7f1e03d14700:5556][source/request.c:433] validate_url(): request url validation feature is not enabled
2017-06-29 07:21:59.771 +0100   DEBUG [0x7f1e03d14700:5556][source/request.c:442] validate_fqdn_access():
2017-06-29 07:21:59.771 +0100   DEBUG [0x7f1e03d14700:5556][source/request.c:445] validate_fqdn_access(): feature is not enabled
2017-06-29 07:21:59.771 +0100   DEBUG [0x7f1e03d14700:5556][source/request_auth.c:264] header  (0)
2017-06-29 07:21:59.771 +0100   DEBUG [0x7f1e03d14700:5556][source/request_auth.c:270] JWT 
2017-06-29 07:21:59.771 +0100   DEBUG [0x7f1e03d14700:5556][source/request_auth.c:273] unable to parse token: JWT 
2017-06-29 07:21:59.771 +0100   DEBUG [0x7f1e03d14700:5556][source/request.c:544] handle_not_enforced(): application logout url feature is not enabled
2017-06-29 07:21:59.771 +0100   DEBUG [0x7f1e03d14700:5556][source/request.c:684] handle_not_enforced(): not enforced client ip validation feature is not enabled
2017-06-29 07:21:59.771 +0100   DEBUG [0x7f1e03d14700:5556][source/request.c:687] handle_not_enforced(): validating http://riso-ubuntu14.test.forgerock.com:80/favicon.ico
2017-06-29 07:21:59.771 +0100   DEBUG [0x7f1e03d14700:5556][source/request.c:763] handle_not_enforced(): not enforced url validation feature is not enabled
2017-06-29 07:21:59.771 +0100   DEBUG [0x7f1e03d14700:5556][source/request.c:808] handle_not_enforced(): extended not enforced url validation feature is not enabled
2017-06-29 07:21:59.771 +0100   DEBUG [0x7f1e03d14700:5556][source/request.c:811] handle_not_enforced(): http://riso-ubuntu14.test.forgerock.com:80/favicon.ico is enforced
2017-06-29 07:21:59.771 +0100   DEBUG [0x7f1e03d14700:5556][source/request.c:952] validate_policy(): for http://riso-ubuntu14.test.forgerock.com:80/favicon.ico (ignoring pathinfo: no), entry status: not found
2017-06-29 07:21:59.771 +0100   DEBUG [0x7f1e03d14700:5556][source/request.c:1987] handle_exit(): (entry status: invalid session)
2017-06-29 07:21:59.771 +0100   DEBUG [0x7f1e03d14700:5556][source/request.c:1574] do_cookie_set_generic(): iPlanetDirectoryPro=;Max-Age=0;Expires=Thu, 01-Jan-1970 00:00:01 GMT;Path=/
2017-06-29 07:21:59.773 +0100   DEBUG [0x7f1e03d14700:5556][source/utility.c:1551] get_valid_openam_url(): active OpenAM service url: http://perf-openam.internal.forgerock.com:8080/openam (0)
2017-06-29 07:21:59.773 +0100   DEBUG [0x7f1e03d14700:5556][source/apache/agent.c:736] amagent_auth_handler(): exit status: redirect (1)


 Comments   
Comment by Pilar Gomez [X] (Inactive) [ 03/Oct/17 ]

Error:

Forbidden

You don't have permission to access /agent/cdsso-oauth2 on this server.
Comment by Pilar Gomez [X] (Inactive) [ 03/Oct/17 ]

This happens with Apache but not with NGINX

Comment by Albert Ayoub [ 29/May/18 ]

I can reproduce similar problem 

Comment by Albert Ayoub [ 29/May/18 ]

Hi Pilar , 

I am able to reproduce similar issue

If you can access https://dev.frdpcloud.com

I will send you username and password in email 

Comment by Pilar Gomez [X] (Inactive) [ 30/May/18 ]

This bug has been reopened and needs to be re-triaged

Comment by edwardb [ 06/Feb/19 ]

Could be issue if complex authentication flow: May need to investigate and document

Comment by edwardb [ 15/Feb/19 ]

triage: Would be nicer if we redirect to login rather than 403 but need to investigate but not a bug. If we can show that parameter change works with this. Then we can close and create a new improvement for the redirect rather than 403.

Comment by Jeremy Cocks [ 20/May/19 ]

Think this bug sort of exaggerates the issue. There isn't a lot of visibility on the workaround, or what things have been set too. We know this is a problem out of the box, maybe it is something that needs to be documented a bit better (or put into KB form, but i want to try and avoid having too many KBs).

It is important to note that the tx-auth cookie TTL (PRE_AUTHN_CACHE_TTL) is hardcoded to 5minutes by default, wherein PDP being enabled and setting the PDP post cache TTL to something below, means the tx-auth cookie inherits it's value, that means it should get around this issue.

com.sun.identity.agents.config.postdata.preserve.enable=true
com.sun.identity.agents.config.postcache.entry.lifetime=30

If there is another problem wherein the above does not solve the issue, please add the use case so we can collate the types of factors causing this problem.

Comment by Daniel Franke [ 20/May/19 ]

Setting postcache lifetime does not solve the problem here.

But the profile attribute cookie max age seems to be used also fo tx-auth cookie maxage:

com.sun.identity.agents.config.profile.attribute.cookie.maxage

When setting this value to 6666, the agent-authn-tx cookie max age is set to 1,9 hrs

Question is: Who has used this value without documenting it.....

Comment by Jeremy Cocks [ 20/May/19 ]

Correct. There does need to be some cohesion over these property explanation so there isn't some confusion. This 403 issue with idle time is a popular one in support. profile.attribute.cookie.maxage is for session / profile / policy attribute cookies from what i am aware,, however yes, unless i am lost in some sort of ambiguity around the settings, stepping through this today showed my findings in accordance with Frank.

Comment by Alex Levin [ 27/Feb/20 ]

Closing as initial text is not accurate any more - see AMAGENTS-2717 for ongoing issues/work in this area

Generated at Sun May 09 08:45:15 UTC 2021 using Jira 8.16.0#816000-sha1:a455b91378454416b49bbc88d03e653cb9815ed5.