Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

user_ldap sync job hammers server #15171

Closed
landryb opened this issue Apr 19, 2019 · 36 comments
Closed

user_ldap sync job hammers server #15171

landryb opened this issue Apr 19, 2019 · 36 comments
Labels
0. Needs triage Pending check for reproducibility or if it fits our roadmap bug needs info stale Ticket or PR with no recent activity

Comments

@landryb
Copy link

landryb commented Apr 19, 2019

Using nc 15.0.7 & user_ldap/user_cas in a multi-tenant setup:

  • 2 loadbalanced nextcloud instances
  • sharing datadir via nfs and hitting the same sql db
  • each of them connecting to a distinct ldap server in a multi-master configuration

environment: php 7.2/debian/postgresql/nginx.

the 'master' nextcloud instance hammers the server every 15mn, querying (afaict) all users/groups separately, which generates 40mb/day in the server logs, and feels very wrong.

this is not an issue dependant on the multi-tenant setup, as a similar single-instance setup (dev instance with a copy of the ldap) shows the same behaviour.

i have ~1200 users & ~ 800 groups, set ldap paging size to 500, tried bumping background_sync_interval (which defaulted to 1800, ie 30mn ?) to 36000 without success.

every 15mn, the server receives in 10/20s between -500 & 2500 queries/operations on a single connection, coming from nextcloud.

Apr 19 08:00:02 db2 slapd[23155]: conn=26230 op=0 BIND dn="" method=128
Apr 19 08:00:15 db2 slapd[23155]: conn=26230 op=1262 UNBIND
Apr 19 08:15:01 db2 slapd[23155]: conn=26232 op=0 BIND dn="" method=128
Apr 19 08:15:14 db2 slapd[23155]: conn=26232 op=1223 UNBIND
Apr 19 08:30:01 db2 slapd[23155]: conn=26234 op=0 BIND dn="" method=128
Apr 19 08:30:06 db2 slapd[23155]: conn=26234 op=561 UNBIND
Apr 19 08:45:02 db2 slapd[23155]: conn=26238 op=0 BIND dn="" method=128
Apr 19 08:45:16 db2 slapd[23155]: conn=26239 op=0 BIND dn="" method=128
Apr 19 08:45:19 db2 slapd[23155]: conn=26238 op=1262 UNBIND
Apr 19 08:45:19 db2 slapd[23155]: conn=26239 op=2906 UNBIND
Apr 19 09:00:02 db2 slapd[23155]: conn=26242 op=0 BIND dn="" method=128
Apr 19 09:00:15 db2 slapd[23155]: conn=26242 op=1223 UNBIND
Apr 19 09:15:02 db2 slapd[23155]: conn=26243 op=0 BIND dn="" method=128
Apr 19 09:15:07 db2 slapd[23155]: conn=26243 op=511 UNBIND

that seems completely unnecessary, and bogus.

the redacted config of user_ldap is the following:

    "apps": {
        "user_ldap": {
            "enabled": "yes",
            "installed_version": "1.5.0",
            "types": "authentication",
            "s01ldap_user_display_name_2": "mail",
            "s01ldap_base_groups": "ou=orgs,dc=domain,dc=tld",
            "s01ldap_login_filter": "(&(objectclass=inetOrgPerson)(uid=%uid))",
            "s01ldap_group_filter_mode": "1",
            "s01ldap_base_users": "ou=users,dc=domain,dc=tld",
            "s01ldap_userfilter_objectclass": "inetOrgPerson",
            "s01ldap_userlist_filter": "(objectClass=inetOrgPerson)",
            "s01ldap_configuration_active": "1",
            "s01use_memberof_to_detect_membership": "1",
            "s01ldap_loginfilter_username": "1",
            "s01ldap_group_filter": "(objectClass=groupOfMembers)",
            "s01ldap_paging_size": "500",
            "s01ldap_group_member_assoc_attribute": "member",
            "s01ldap_user_filter_mode": "1",
            "s01ldap_groupfilter_objectclass": "groupOfMembers",
            "s01ldap_base": "ou=users,dc=domain,dc=tld",
            "s01ldap_display_name": "uid",
            "s01ldap_host": "db2",
            "s01ldap_group_display_name": "cn",
            "s01ldap_expert_username_attr": "uid",
            "background_sync_offset": "500",
            "background_sync_interval": "36150",
            "background_sync_prefix": "s01",
            "s01ldap_port": "389",
            "s01ldap_cache_ttl": "600",
            "s01_lastChange": "1555633806",
            "cleanUpJobOffset": "1000"
        }
    }

can of course provide more details if needed, and can try any kind of workaround in poking at the app config...

@landryb landryb added 0. Needs triage Pending check for reproducibility or if it fits our roadmap bug labels Apr 19, 2019
@landryb
Copy link
Author

landryb commented Apr 19, 2019

The 15mn are of course coming from the occ cron interval, but from my understanding user_ldap shouldnt query the complete DIT at every cron run..

@kesselb
Copy link
Contributor

kesselb commented Jan 17, 2020

cc @nextcloud/ldap

@blizzz
Copy link
Member

blizzz commented Jan 31, 2020

I don't think it is any of LDAP backenda own job. They wouldn't run that often and especially not fetch everything completely. Does it still happen on a recent Nc version? Could you provide the Nextcloud log?

@landryb
Copy link
Author

landryb commented Jan 31, 2020

It still happens on 18.0 yes, i have a 20Mb slapd log every day, with ~15000 lines logged at every cron run for something like 15s.

sure the log is huge because my slapd is in verbose mode, but that clearly show that nextcloud is making ~ 4700 ldap queries at each cron run, querying separately uid, member, gidnumber & primarygrouptoken for each ldap org then cn/dn for each user (i have ~ 800 orgs and ~1200 users) - i'm not sure though its querying for the complete list of users/orgs at each run but that still feel bogus.

What kind of nextcloud log do you want, just one with debug enabled ? can i just enable debugging on the ldap bits ?

@blizzz
Copy link
Member

blizzz commented Jan 31, 2020

The nextcloud.log from the data folder. I am mostly interested in the trigger, not the symptom. You could set 'loglevel' => 0, in the config php to collect DEBUG-level message (revert it after you collected info for an incident).

Alternatively you enforce DEBUG only for cron:

'log.condition' => [
        'apps' => ['cron'],
],

Perhaps collect the data over 3 cycles to narrow down the candidates.

@landryb
Copy link
Author

landryb commented Jan 31, 2020

of course the 1.2Mb nextcloud.log is full of sensitive information (dn, user list, group list, etc), should i look for something specific in it ? otherwise i'll look at anonymising it.. or can send it out of band.
it looks like this..

:"--","app":"no app in context","method":"","url":"--","message":"Deprecated event type for OCA\\User_LDAP\\User\\User::postLDAPBackendAdded: null","userAgent":"--","version":"18.0.0.10"}
:"--","app":"cron","method":"","url":"--","message":"Run OCA\\Files_Sharing\\DeleteOrphanedSharesJob job with ID 8","userAgent":"--","version":"18.0.0.10"}
:"--","app":"DeleteOrphanedSharesJob","method":"","url":"--","message":"0 orphaned share(s) deleted","userAgent":"--","version":"18.0.0.10"}
:"--","app":"cron","method":"","url":"--","message":"Finished OCA\\Files_Sharing\\DeleteOrphanedSharesJob job with ID 8 in 0 seconds","userAgent":"--","version":"18.0.0.10"}
:"--","app":"cron","method":"","url":"--","message":"Run OCA\\Talk\\BackgroundJob\\RemoveEmptyRooms job with ID 50","userAgent":"--","version":"18.0.0.10"}
:"--","app":"cron","method":"","url":"--","message":"Finished OCA\\Talk\\BackgroundJob\\RemoveEmptyRooms job with ID 50 in 0 seconds","userAgent":"--","version":"18.0.0.10"}
:"--","app":"cron","method":"","url":"--","message":"Run OCA\\Files\\BackgroundJob\\ScanFiles job with ID 11","userAgent":"--","version":"18.0.0.10"}
:"--","app":"user_ldap","method":"","url":"--","message":"getUsers: Options: search  limit 500 offset 1500 Filter: (&(objectClass=inetOrgPerson)(uid=*)(uid=*))","userAgent":"--","version":"18.0.0.10"}
:"--","app":"user_ldap","method":"","url":"--","message":"initializing paged search for  Filter (&(objectClass=inetOrgPerson)(uid=*)(uid=*)) base Array\n(\n    [0] => ou=users,XXXXXX\n)\n attr Array\n(\n    [0] => entryuuid\n    [1] => nsuniqueid\n    [2] => objectguid\n    [3] 
=> guid\n    [4] => ipauniqueid\n    [5] => dn\n    [6] => uid\n    [7] => samaccountname\n    [8] => memberof\n    [9] => mail\n)\n limit 500 offset 1500","userAgent":"--","version":"18.0.0.10"}
:"--","app":"user_ldap","method":"","url":"--","message":"initializing paged search for  Filter (&(objectClass=inetOrgPerson)(uid=*)(uid=*)) base Array\n(\n    [0] => ou=users,XXXXXX\n)\n attr Array\n(\n    [0] => entryuuid\n    [1] => nsuniqueid\n    [2] => objectguid\n    [3] 
=> guid\n    [4] => ipauniqueid\n    [5] => dn\n    [6] => uid\n    [7] => samaccountname\n    [8] => memberof\n    [9] => mail\n)\n limit 500 offset 1000","userAgent":"--","version":"18.0.0.10"}
:"--","app":"user_ldap","method":"","url":"--","message":"initializing paged search for  Filter (&(objectClass=inetOrgPerson)(uid=*)(uid=*)) base Array\n(\n    [0] => ou=users,XXXXXX\n)\n attr Array\n(\n    [0] => entryuuid\n    [1] => nsuniqueid\n    [2] => objectguid\n    [3] 
=> guid\n    [4] => ipauniqueid\n    [5] => dn\n    [6] => uid\n    [7] => samaccountname\n    [8] => memberof\n    [9] => mail\n)\n limit 500 offset 500","userAgent":"--","version":"18.0.0.10"}
:"--","app":"user_ldap","method":"","url":"--","message":"initializing paged search for  Filter (&(objectClass=inetOrgPerson)(uid=*)(uid=*)) base Array\n(\n    [0] => ou=users,XXXXXX\n)\n attr Array\n(\n    [0] => entryuuid\n    [1] => nsuniqueid\n    [2] => objectguid\n    [3] 
=> guid\n    [4] => ipauniqueid\n    [5] => dn\n    [6] => uid\n    [7] => samaccountname\n    [8] => memberof\n    [9] => mail\n)\n limit 500 offset 0","userAgent":"--","version":"18.0.0.10"}
:"--","app":"user_ldap","method":"","url":"--","message":"Ready for a paged search","userAgent":"--","version":"18.0.0.10"}
:"--","app":"user_ldap","method":"","url":"--","message":"Ready for a paged search","userAgent":"--","version":"18.0.0.10"}
:"--","app":"user_ldap","method":"","url":"--","message":"Ready for a paged search","userAgent":"--","version":"18.0.0.10"}
:"--","app":"no app in context","method":"","url":"--","message":{"Exception":"Exception","Message":"No paged search possible, Limit 500 Offset 1500","Code":0,"Trace":[{"file":"/data/web/www/nextcloud/apps/user_ldap/lib/Access.php","line":1178,"function":"initPagedSearch","class
":"OCA\\User_LDAP\\Access","type":"->","args":["(&(objectClass=inetOrgPerson)(uid=*)(uid=*))",["ou=users,XXXXXX"],["entryuuid","nsuniqueid","objectguid","guid","ipauniqueid","dn","uid","samaccountname","memberof","mail"],500,1500]},{"file":"/data/web/www/nextcloud/apps/user_ldap
/lib/Access.php","line":1338,"function":"executeSearch","class":"OCA\\User_LDAP\\Access","type":"->","args":["(&(objectClass=inetOrgPerson)(uid=*)(uid=*))",["ou=users,XXXXXX"],["entryuuid","nsuniqueid","objectguid","guid","ipauniqueid","dn","uid","samaccountname","memberof","mai
l"],500,"1500"]},{"file":"/data/web/www/nextcloud/apps/user_ldap/lib/Access.php","line":1023,"function":"search","class":"OCA\\User_LDAP\\Access","type":"->","args":["(&(objectClass=inetOrgPerson)(uid=*)(uid=*))",["ou=users,XXXXXX"],["entryuuid","nsuniqueid","objectguid","guid",
"ipauniqueid","dn","uid","samaccountname","memberof","mail"],500,"1500"]},{"file":"/data/web/www/nextcloud/apps/user_ldap/lib/Access.php","line":916,"function":"searchUsers","class":"OCA\\User_LDAP\\Access","type":"->","args":["(&(objectClass=inetOrgPerson)(uid=*)(uid=*))",["ent
ryuuid","nsuniqueid","objectguid","guid","ipauniqueid","dn","uid","samaccountname","memberof","mail"],500,"1500"]},{"file":"/data/web/www/nextcloud/apps/user_ldap/lib/User_LDAP.php","line":274,"function":"fetchListOfUsers","class":"OCA\\User_LDAP\\Access","type":"->","args":["(&
(objectClass=inetOrgPerson)(uid=*)(uid=*))",["entryuuid","nsuniqueid","objectguid","guid","ipauniqueid","dn","uid","samaccountname","memberof","mail"],500,"1500"]},{"file":"/data/web/www/nextcloud/apps/user_ldap/lib/User_Proxy.php","line":165,"function":"getUsers","class":"OCA\\
User_LDAP\\User_LDAP","type":"->","args":["",500,"1500"]},{"file":"/data/web/www/nextcloud/lib/private/User/Manager.php","line":246,"function":"getUsers","class":"OCA\\User_LDAP\\User_Proxy","type":"->","args":["",500,"1500"]},{"file":"/data/web/www/nextcloud/apps/files/lib/Back
groundJob/ScanFiles.php","line":100,"function":"search","class":"OC\\User\\Manager","type":"->","args":["",500,"1500"]},{"file":"/data/web/www/nextcloud/lib/private/BackgroundJob/Job.php","line":61,"function":"run","class":"OCA\\Files\\BackgroundJob\\ScanFiles","type":"->","args
":[null]},{"file":"/data/web/www/nextcloud/lib/private/BackgroundJob/TimedJob.php","line":55,"function":"execute","class":"OC\\BackgroundJob\\Job","type":"->","args":[{"__class__":"OC\\BackgroundJob\\JobList"},{"__class__":"OC\\Log"}]},{"file":"/data/web/www/nextcloud/cron.php",
"line":125,"function":"execute","class":"OC\\BackgroundJob\\TimedJob","type":"->","args":[{"__class__":"OC\\BackgroundJob\\JobList"},{"__class__":"OC\\Log"}]}],"File":"/data/web/www/nextcloud/apps/user_ldap/lib/Access.php","Line":2084,"CustomMessage":"--"},"userAgent":"--","vers
ion":"18.0.0.10"}
:"--","app":"user_ldap","method":"","url":"--","message":"Paged search was not available","userAgent":"--","version":"18.0.0.10"}
:"--","app":"user_ldap","method":"","url":"--","message":"getUsers: 0 Users found","userAgent":"--","version":"18.0.0.10"}
:"--","app":"user_ldap","method":"","url":"--","message":"getUsers: Options: search  limit 500 offset  Filter: (&(objectClass=inetOrgPerson)(uid=*)(uid=*))","userAgent":"--","version":"18.0.0.10"}
:"--","app":"user_ldap","method":"","url":"--","message":"initializing paged search for  Filter (&(objectClass=inetOrgPerson)(uid=*)(uid=*)) base Array\n(\n    [0] => ou=users,XXXXXX\n)\n attr Array\n(\n    [0] => entryuuid\n    [1] => nsuniqueid\n    [2] => objectguid\n    [3] 
=> guid\n    [4] => ipauniqueid\n    [5] => dn\n    [6] => uid\n    [7] => samaccountname\n    [8] => memberof\n    [9] => mail\n)\n limit 500 offset 0","userAgent":"--","version":"18.0.0.10"}
:"--","app":"user_ldap","method":"","url":"--","message":"Ready for a paged search","userAgent":"--","version":"18.0.0.10"}
:"--","app":"user_ldap","method":"","url":"--","message":"getUsers: 500 Users found","userAgent":"--","version":"18.0.0.10"}
:"--","app":"user_ldap","method":"","url":"--","message":"initializing paged search for  Filter (objectClass=inetOrgPerson) base Array\n(\n    [0] => uid=admin,ou=users,XXXXXX\n)\n attr Array\n(\n    [0] => \n)\n limit 500 offset 0","userAgent":"--","version":"18.0.0.10"}
:"--","app":"user_ldap","method":"","url":"--","message":"Ready for a paged search","userAgent":"--","version":"18.0.0.10"}
:"--","app":"user_ldap","method":"","url":"--","message":"readAttribute: uid=admin,ou=users,XXXXXX found","userAgent":"--","version":"18.0.0.10"}
:"--","app":"user_ldap","method":"","url":"--","message":"initializing paged search for  Filter objectClass=* base Array\n(\n    [0] => uid=admin,ou=users,XXXXXX\n)\n attr Array\n(\n    [0] => primarygroupid\n)\n limit 500 offset 0","userAgent":"--","version":"18.0.0.10"}
:"--","app":"user_ldap","method":"","url":"--","message":"Ready for a paged search","userAgent":"--","version":"18.0.0.10"}
:"--","app":"user_ldap","method":"","url":"--","message":"Requested attribute primarygroupid not found for uid=admin,ou=users,XXXXXX","userAgent":"--","version":"18.0.0.10"}
:"--","app":"user_ldap","method":"","url":"--","message":"initializing paged search for  Filter objectClass=* base Array\n(\n    [0] => uid=admin,ou=users,XXXXXX\n)\n attr Array\n(\n    [0] => gidnumber\n)\n limit 500 offset 0","userAgent":"--","version":"18.0.0.10"}
:"--","app":"user_ldap","method":"","url":"--","message":"Ready for a paged search","userAgent":"--","version":"18.0.0.10"}
:"--","app":"user_ldap","method":"","url":"--","message":"Requested attribute gidnumber not found for uid=admin,ou=users,XXXXXX","userAgent":"--","version":"18.0.0.10"}
:"--","app":"user_ldap","method":"","url":"--","message":"initializing paged search for  Filter member=uid=admin,ou=users,XXXXXX base Array\n(\n    [0] => ou=orgs,XXXXXX\n)\n attr Array\n(\n    [0] => cn\n    [1] => dn\n)\n limit 500 offset 0","userAgent":"--","version":"18.0.0.
10"}
...
:"--","app":"OC\\Files\\Cache\\Scanner","method":"","url":"--","message":"!!! Path '' is not accessible or present !!!","userAgent":"--","version":"18.0.0.10"}
:"--","app":"user_ldap","method":"","url":"--","message":"initializing paged search for  Filter (objectClass=inetOrgPerson) base Array\n(\n    [0] => uid=USER1,ou=users,XXXXXX\n)\n attr Array\n(\n    [0] => \n)\n limit 500 offset 0","userAgent":"--","version":"18.0.0.10"}
:"--","app":"user_ldap","method":"","url":"--","message":"Ready for a paged search","userAgent":"--","version":"18.0.0.10"}
:"--","app":"user_ldap","method":"","url":"--","message":"readAttribute: uid=USER1,ou=users,XXXXXX found","userAgent":"--","version":"18.0.0.10"}
:"--","app":"user_ldap","method":"","url":"--","message":"initializing paged search for  Filter member=uid=USER1,ou=users,XXXXXX base Array\n(\n    [0] => ou=orgs,XXXXXX\n)\n attr Array\n(\n    [0] => cn\n    [1] => dn\n)\n limit 500 offset 0","userAgent":"--","version":"18
.0.0.10"}
:"--","app":"user_ldap","method":"","url":"--","message":"Ready for a paged search","userAgent":"--","version":"18.0.0.10"}
:"--","app":"user_ldap","method":"","url":"--","message":"initializing paged search for  Filter (objectClass=groupOfMembers) base Array\n(\n    [0] => cn=ORG1,ou=orgs,XXXXXX\n)\n attr Array\n(\n    [0] => \n)\n limit 500 offset 0","userAgent":"--","version":"18.0.0.10"}
:"--","app":"user_ldap","method":"","url":"--","message":"Ready for a paged search","userAgent":"--","version":"18.0.0.10"}
:"--","app":"user_ldap","method":"","url":"--","message":"readAttribute: cn=ORG1,ou=orgs,XXXXXX found","userAgent":"--","version":"18.0.0.10"}
:"--","app":"OC\\Files\\Cache\\Scanner","method":"","url":"--","message":"!!! Path '' is not accessible or present !!!","userAgent":"--","version":"18.0.0.10"}
:"--","app":"cron","method":"","url":"--","message":"Finished OCA\\Files\\BackgroundJob\\ScanFiles job with ID 11 in 9 seconds","userAgent":"--","version":"18.0.0.10"}
:"--","app":"cron","method":"","url":"--","message":"Run OC\\Authentication\\Token\\DefaultTokenCleanupJob job with ID 16","userAgent":"--","version":"18.0.0.10"}
:"--","app":"cron","method":"","url":"--","message":"Invalidating session tokens older than 2020-01-30T13:28:03+00:00","userAgent":"--","version":"18.0.0.10"}
:"--","app":"cron","method":"","url":"--","message":"Invalidating remembered session tokens older than 2020-01-16T13:28:03+00:00","userAgent":"--","version":"18.0.0.10"}
:"--","app":"cron","method":"","url":"--","message":"Invalidating session tokens older than 2020-01-30T13:28:03+00:00","userAgent":"--","version":"18.0.0.10"}
:"--","app":"cron","method":"","url":"--","message":"Invalidating remembered session tokens older than 2020-01-16T13:28:03+00:00","userAgent":"--","version":"18.0.0.10"}
:"--","app":"cron","method":"","url":"--","message":"Finished OC\\Authentication\\Token\\DefaultTokenCleanupJob job with ID 16 in 0 seconds","userAgent":"--","version":"18.0.0.10"}
:"--","app":"cron","method":"","url":"--","message":"Run OC\\Log\\Rotate job with ID 17","userAgent":"--","version":"18.0.0.10"}
:"--","app":"cron","method":"","url":"--","message":"Finished OC\\Log\\Rotate job with ID 17 in 0 seconds","userAgent":"--","version":"18.0.0.10"}
:"--","app":"cron","method":"","url":"--","message":"Run OCA\\DAV\\BackgroundJob\\EventReminderJob job with ID 5","userAgent":"--","version":"18.0.0.10"}
:"--","app":"cron","method":"","url":"--","message":"Finished OCA\\DAV\\BackgroundJob\\EventReminderJob job with ID 5 in 0 seconds","userAgent":"--","version":"18.0.0.10"}
:"--","app":"cron","method":"","url":"--","message":"Run OCA\\Files\\BackgroundJob\\CleanupDirectEditingTokens job with ID 14","userAgent":"--","version":"18.0.0.10"}
:"--","app":"cron","method":"","url":"--","message":"Finished OCA\\Files\\BackgroundJob\\CleanupDirectEditingTokens job with ID 14 in 0 seconds","userAgent":"--","version":"18.0.0.10"}
:"--","app":"cron","method":"","url":"--","message":"Run OCA\\Talk\\BackgroundJob\\ExpireSignalingMessage job with ID 49","userAgent":"--","version":"18.0.0.10"}
:"--","app":"cron","method":"","url":"--","message":"Finished OCA\\Talk\\BackgroundJob\\ExpireSignalingMessage job with ID 49 in 0 seconds","userAgent":"--","version":"18.0.0.10"}
:"--","app":"cron","method":"","url":"--","message":"Run OCA\\Files\\BackgroundJob\\CleanupFileLocks job with ID 13","userAgent":"--","version":"18.0.0.10"}
:"--","app":"cron","method":"","url":"--","message":"Finished OCA\\Files\\BackgroundJob\\CleanupFileLocks job with ID 13 in 0 seconds","userAgent":"--","version":"18.0.0.10"}

that 'pagedsearch' thing looks weird as the remote slapd supports that feature.

@blizzz
Copy link
Member

blizzz commented Feb 4, 2020

It seems to be the OCA\Files\BackgroundJob\ScanFiles job, but I cannot tell for sure as the request ID is missing. What is interesting is that Options: search limit 500 offset 1500 Filter were requested out of nothing. The paged search will fail as it has to start with 0 (unless this is from a different request). Could you check whether the mentioned job and the LDAP messages have the same request id?

@landryb
Copy link
Author

landryb commented Feb 4, 2020

yeah sorry maybe i stripped too many things.. both things have indeed the same request id

{"reqId":"BDpdXcSJHz9XoVbZFwaB","level":0,"time":"2020-01-31T13:27:54+00:00","remoteAddr":"","user":"--","app":"cron","method":"","url":"--","message":"Run OCA\\Files\\BackgroundJob\\ScanFiles job with ID 11",
"userAgent":"--","version":"18.0.0.10"}
...
{"reqId":"BDpdXcSJHz9XoVbZFwaB","level":0,"time":"2020-01-31T13:27:54+00:00","remoteAddr":"","user":"--","app":"no app in context","method":"","url":"--","message":{"Exception":"Exception","Message":"No paged 
search possible, Limit 500 Offset 1500","Code":0,"Trace":[{"file":"/data/web/www/nextcloud/apps/user_ldap/lib/Access.php","line":1178,"function":"initPagedSearch","class":"OCA\\User_LDAP\\Access"

@alinmear
Copy link

alinmear commented Apr 9, 2020

On our site we have a ldap cluster with several thousand groups and users. Every time the cron.php gets triggered we can monitor several thousand queries against our ldap infrastructure which nearly leads to 2 million queries a day:

image

The Nexctcloud seems to create a query for each object it can read with the object dn as basedn for the query and the group- or user-filter as ldap search filter:

e.g.

  • ldap_base: cn=****, ou=****, ou=****, .....
  • ldap_filter: <groupfilter/userfilter>

@skjnldsv
Copy link
Member

Any workaround in sight @landryb or @alinmear ?
Any one you figure things out of this?

@alinmear
Copy link

alinmear commented Apr 15, 2020

The group memberships for each user are determined using the following search:

initializing paged search for Filter uniqueMember=...,dc=<>,dc=<> base Array ( [0] => ...,dc=<>,dc=<> ) attr Array ( [0] => cn [1] => dn ) limit 500 offset 0

There is no restriction that if no nested groups are used, the group filter can be added immediately. A search according to the following pattern is triggered for each person's membership:

initializing paged search for Filter <groupFilter> attr Array ( [0] => cn ) limit 500 offset 0

The current implementation is written in such a way that it gets along well with small or nested ldap structures, but not that well with large structures of users with lots of non nested group memberships.

@blizzz
Copy link
Member

blizzz commented Apr 15, 2020

@alinmear maybe you're interested to test #19919

@alinmear
Copy link

@blizzz thank you for you contribution. Your changes would not fix the problems described in this case. there still will be a query for each group a user is member of, based on his/her dn, filtering will take place afterwards:

https://github.com/nextcloud/server/pull/19919/files#diff-994e1d45c127dc64e57744e2bf2eff3dR792

@ghost

This comment has been minimized.

@ghost ghost added the stale Ticket or PR with no recent activity label May 21, 2020
@blizzz blizzz removed the stale Ticket or PR with no recent activity label May 22, 2020
@ghost

This comment has been minimized.

@ghost ghost added the stale Ticket or PR with no recent activity label Jun 21, 2020
@landryb
Copy link
Author

landryb commented Jun 29, 2020

problem still happens - it's not because no more comments are happening that it should be closed :)

@ghost ghost removed the stale Ticket or PR with no recent activity label Jun 29, 2020
@ghost

This comment has been minimized.

@ghost ghost added the stale Ticket or PR with no recent activity label Aug 9, 2020
@ghost ghost closed this as completed Aug 23, 2020
@landryb

This comment has been minimized.

@ghost

This comment has been minimized.

@ghost ghost added the stale Ticket or PR with no recent activity label Oct 24, 2020
@landryb

This comment has been minimized.

@ghost ghost removed the stale Ticket or PR with no recent activity label Oct 26, 2020
@ghost ghost added the stale Ticket or PR with no recent activity label Nov 25, 2020
@ghost ghost closed this as completed Dec 9, 2020
@dariodsa
Copy link

This issue is still alive.

@solracsf solracsf reopened this Apr 25, 2021
@ghost ghost removed the stale Ticket or PR with no recent activity label Apr 25, 2021
@nextcloud nextcloud deleted a comment Apr 25, 2021
@szaimen
Copy link
Contributor

szaimen commented Jul 2, 2021

Is this Issue still valid in NC21.0.3? If not, please close this issue. Thanks! :)

@landryb
Copy link
Author

landryb commented Jul 5, 2021

the problem is still present in stable21.

@szaimen
Copy link
Contributor

szaimen commented Jul 6, 2021

How did you install your Nextcloud? Could you please fill out the issue template? Thanks!

@landryb
Copy link
Author

landryb commented Jul 6, 2021

the setup hasnt much changed since the original comment, running nextcloud from a git clone of the stable21 branch of the repo, with some apps not present in the repo also cloned from the stable21 branch - On debian buster, with php 7.3 & nginx.

For other reasons I've raised the default query size limit on the openldap side to 3000 entries (so that the full DIT can be fetched in a single query, as that value defaults to 500 serverside), i would be happy to provide more details if you have particular questions.

I have debug enabled on the ldap server, and at every cron run there are about 25k lines in the logs, all coming from user_ldap queries.

@ghost
Copy link

ghost commented Aug 5, 2021

This issue has been automatically marked as stale because it has not had recent activity and seems to be missing some essential information. It will be closed if no further activity occurs. Thank you for your contributions.

@ghost ghost added the stale Ticket or PR with no recent activity label Aug 5, 2021
@ghost ghost closed this as completed Aug 19, 2021
@landryb
Copy link
Author

landryb commented Aug 19, 2021

dammit bot.

@landryb
Copy link
Author

landryb commented Jan 24, 2022

can someone with enough edit rights reopen this issue ? i've upgraded a testing instance from 21 to 23, and i still have ~4300 ldap queries at each cron run, with ~1500 users & ~1000 groups.

@alinmear
Copy link

We are currently using 22.2.3. Still same situation. Problem as already stated above unchanged.

@blizzz blizzz reopened this Jan 25, 2022
@ghost ghost removed the stale Ticket or PR with no recent activity label Jan 25, 2022
@ghost
Copy link

ghost commented Feb 24, 2022

This issue has been automatically marked as stale because it has not had recent activity and seems to be missing some essential information. It will be closed if no further activity occurs. Thank you for your contributions.

@ghost ghost added the stale Ticket or PR with no recent activity label Feb 24, 2022
@ghost ghost closed this as completed Mar 10, 2022
@landryb
Copy link
Author

landryb commented Mar 10, 2022

dammit bots.

@dariodsa
Copy link

dariodsa commented Mar 10, 2022 via email

@cociweb
Copy link

cociweb commented Oct 25, 2022

Is it still an issue? Maybe I also suffer from it on v25

This issue was closed.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
0. Needs triage Pending check for reproducibility or if it fits our roadmap bug needs info stale Ticket or PR with no recent activity
Projects
None yet
Development

No branches or pull requests