Churchtools 3.100 sends a HTTP Response code 403 after Update

[DanielHamann]

I used this Wrapper over Dockerhub successfully for the past 6 months. With the 3.1 Update I first got the now fixed 500 Error but I am still stuck with an 403 Response. I obviously didn't change any permissions and double checked the API Access Token.

I use the Wrapper for authenticating Windows machines via Pgina and Remote Access via Authelia. Pgina is surprisingly able to authenticate users but can't authorize via groups anymore, Authelia can't authenticate users.
I'm not Self-Hosting ChurchTools. Is this an open Problem with SaaS Churchtools or does anyone else has this problem with the wrapper?

Error Log for the Group Authorization:
2023-08-03T11:31:35.548Z [DEBUG] churchtools - SEARCH base object: cn=test, ou=groups, o=churchtools scope: base
2023-08-03T11:31:35.548Z [DEBUG] churchtools - Filter: (uniquemember=cn=ttest,ou=users,o=churchtools)
2023-08-03T11:31:35.548Z [DEBUG] churchtools - Search for groups
2023-08-03T11:31:35.549Z [DEBUG] churchtools - Wait on Promise for cache key "rawData".
2023-08-03T11:31:35.549Z [DEBUG] churchtools - Wait on Promise for cache key "groups".
2023-08-03T11:31:35.558Z [DEBUG] churchtools - Assumed 1 page(s) of data for /api/groups, but had to load 0.
2023-08-03T11:31:35.558Z [DEBUG] churchtools - fetchGroups done
2023-08-03T11:31:35.561Z [DEBUG] churchtools - fetchGroupTypes done
2023-08-03T11:31:35.594Z [DEBUG] churchtools - Assumed 1 page(s) of data for /api/persons, which was correct.
2023-08-03T11:31:35.594Z [DEBUG] churchtools - fetchPersons done
2023-08-03T11:31:35.769Z [ERROR] churchtools - Error while retrieving groups:
HTTPError: Response code 403 ()
at Request. (file:///app/node_modules/got/dist/source/as-promise/index.js:86:42)
at Object.onceWrapper (node:events:629:26)
at Request.emit (node:events:526:35)
at Request._onResponseBase (file:///app/node_modules/got/dist/source/core/index.js:726:22)
at process.processTicksAndRejections (node:internal/process/task_queues:95:5)
at async Request._onResponse (file:///app/node_modules/got/dist/source/core/index.js:768:13)

Error Log for the User Authentication:
2023-08-03T11:41:33.712Z [DEBUG] churchtools - Admin bind DN: cn=root, ou=users, o=churchtools
2023-08-03T11:41:33.712Z [DEBUG] churchtools - Admin bind successful
2023-08-03T11:41:33.714Z [DEBUG] churchtools - SEARCH base object: ou=users, o=churchtools scope: sub
2023-08-03T11:41:33.714Z [DEBUG] churchtools - Filter: (&(|(uid=ttest)(mail=ttest))(objectclass=person))
2023-08-03T11:41:33.714Z [DEBUG] churchtools - Search for users
2023-08-03T11:41:33.715Z [DEBUG] churchtools - Wait on Promise for cache key "rawData".
2023-08-03T11:41:33.715Z [DEBUG] churchtools - Wait on Promise for cache key "users".
2023-08-03T11:41:33.980Z [DEBUG] churchtools - Assumed 1 page(s) of data for /api/groups, but had to load 0.
2023-08-03T11:41:33.980Z [DEBUG] churchtools - fetchGroups done
2023-08-03T11:41:33.984Z [ERROR] churchtools - Error while retrieving users:
HTTPError: Response code 403 ()
at Request. (file:///app/node_modules/got/dist/source/as-promise/index.js:86:42)
at Object.onceWrapper (node:events:629:26)
at Request.emit (node:events:526:35)
at Request._onResponseBase (file:///app/node_modules/got/dist/source/core/index.js:726:22)
at process.processTicksAndRejections (node:internal/process/task_queues:95:5)
at async Request._onResponse (file:///app/node_modules/got/dist/source/core/index.js:768:13)
2023-08-03T11:41:33.984Z [DEBUG] churchtools - fetchGroupTypes done
2023-08-03T11:41:34.013Z [DEBUG] churchtools - Assumed 1 page(s) of data for /api/persons, which was correct.
2023-08-03T11:41:34.013Z [DEBUG] churchtools - fetchPersons done

[a-schild]

Have you read the thread in the ct forum about this?
You will need the 3.2 release of ctldap or patch the ct installation

[DanielHamann]

I am on the latest version as published on Dockerhub. It's not the same 500 Error as mentioned here, when you are on a previous version. As i'm using the SaaS version of Churchtools I can't patch my CT installation and hopefully are on the latest version.

[DanielHamann]

After some trial and error I think I can narrow it down to the pagination:
As displayed in the log the wrapper tries to assume the pages of data for the groups but can't load any:
2023-08-03T11:41:33.980Z [DEBUG] churchtools - Assumed 1 page(s) of data for /api/groups, but had to load 0.

I get this error with all accounts besides the admin account. If I try to authenticate the admin user or look up group memberships of the admin user I get the expected response:
2023-08-08T11:57:40.353Z [DEBUG] churchtools - Assumed 1 page(s) of data for /api/groups, which was correct.

@milux I read your comments on the forum post for the 3.1 Version Announcement. Is there by any chance anything missing on your dockerhub image or do you have any idea?

[milux]

After some trial and error I think I can narrow it down to the pagination: As displayed in the log the wrapper tries to assume the pages of data for the groups but can't load any: 2023-08-03T11:41:33.980Z [DEBUG] churchtools - Assumed 1 page(s) of data for /api/groups, but had to load 0.

I get this error with all accounts besides the admin account. If I try to authenticate the admin user or look up group memberships of the admin user I get the expected response: 2023-08-08T11:57:40.353Z [DEBUG] churchtools - Assumed 1 page(s) of data for /api/groups, which was correct.

@milux I read your comments on the forum post for the 3.1 Version Announcement. Is there by any chance anything missing on your dockerhub image or do you have any idea?

Hi, sorry for the long delay.
I think we experience the same issue.
I assume it's caused by a bug in ChurchTools when a wrong/outdated cookie is stored, although the passed token is valid. ctldap typically recovers after a restart from this, at least for us.
I will implement a workaround ASAP.

[milux]

@djschilling Could you please also fix this on your side?
Outdated cookie should be renewed instead of throwing an error.

[milux]

I implemented a recovery strategy that clears the cookies and retries the request. 🤞
Docker containers are available, source update and CHANGELOG update to follow soon.

[DanielHamann]

Thank you for the fix. Just as an information: I still get the 403 Error in the log but can successfully authenticate groups now.

[milux]

Thank you for the fix. Just as an information: I still get the 403 Error in the log but can successfully authenticate groups now.

Could it be that it's just debug output followed by messages that indicate retrial?
If not, please post a suitable excerpt of your log (personal details removed, of course), so I can see what's the matter.

[DanielHamann]

The output displays the retrials but still throws the same error as before. Bus as I said it still works after that.

[milux]

Started looking deeper into this this morning.
It turns out that the ChurchTools API has a massive problem with parallel requests when using a single CookieJar for cookie storage. My assumption is that CT confuses itself because it seems to regenerate session IDs (see https://www.php.net/manual/en/function.session-regenerate-id.php), so most of the IDs won't be valid after the first ones have been stored.
To keep the benefits of sessions, I now use a pool of CookieJars in ctldap 3.1.1. This appears to have resolved the issue.

The code that clears the Jar in case of a HTTP 403 is still in place, because that may still happen when session times out.

@DanielHamann Can you please confirm it's working now as it should?

@djschilling You should really take a look into this. Session handling of CT is terribly flawed for parallel requests, and invalid sessions seem to lead to 403 responses instead of automatic recovery.

[DanielHamann]

Thank you for the fix. Looks really promising. I tried it with mail and user id authentication and it worked on the first try (didn't work on 3.1.0 on all first tries).
Also it's seems to be faster as my OpenID Client doesn't throw warnings for response times anymore.

[milux]

Nice! I will close this issue then, please comment if you observe a regression.