Hundreds of odd oc_authtoken entries slow down performance for a user (BUG REPORT)

raid1 · June 3, 2021, 11:48pm

Nextcloud version: 21.0.2.1
Operating system and version: 4.19.0-16-amd64 #1 SMP Debian 4.19.181-1 (2021-03-19) x86_64 GNU/Linux
Apache or nginx version: Apache 2.4.38-3+deb10u4
PHP version (eg, 7.4): 2:7.3+69

The issue you are facing:

Since the update to NC 21 I noticed that my android app “foldersync” is syncing very slowly.
But on the phone of my wife it’s working as quickly as before.
After further investigating it I boiled it down to timing just a single curl call.
curl -X PROPFIND "https://SERVER/remote.php/webdav/Handy/DCIM/Camera/IMG_20210602_223758.jpg" -u andy
→ between 12-17 seconds
curl -s -X PROPFIND "https://SERVER/remote.php/webdav/Handy/DCIM/Camera/IMG_2021-0602_202145.jpg" -u user2
→ just 1-2 seconds
Foldersync uses many PROPFIND calls and therefore it takes several minutes to sync a directory with just a few files. The only difference I see between my wife’s account and mine: I have ~10000 files and she ~5000 files.

Is this the first time you’ve seen this error? (Y/N): Y

The output of your Nextcloud log in Admin > Logging:

Error	PHP	Module 'mbstring' already loaded at Unknown#0

(shows up every time when I call curl)

The output of your config.php file:

$CONFIG = array (
  'datadirectory' => '/var/www/nextcloud-data',
  'dbtype' => 'mysql',
  'version' => '21.0.2.1',
  'dbname' => 'XXXX',
  'dbhost' => 'localhost',
  'dbtableprefix' => 'oc_',
  'dbuser' => 'XXXXXXX',
  'dbpassword' => 'XXXXXXXXXX',
  'installed' => true,
  'instanceid' => 'YYYYYYYYYYYYY',
  'maintenance' => false,
  'loglevel' => 2,
  'theme' => '',
  'trusted_domains' => 
  array (
    0 => 'SERVERNAME.DE',
  ),
  'share_folder' => '/Shared',
  'defaultapp' => 'calendar',
  'trashbin_retention_obligation' => 'auto, 14',
  'versions_retention_obligation' => 'auto, 14',
  'default_language' => 'en',
  'default_phone_region' => 'DE',
  'secret' => 'XXXXXXXXXXXXXXXXX',
  'memcache.local' => '\\OC\\Memcache\\APCu',
  'mail_domain' => 'SERVERNAME.DE',
  'mail_smtpmode' => 'smtp',
  'mail_from_address' => 'no-reply',
  'updater.release.channel' => 'stable',
  'overwrite.cli.url' => 'https://cloud.SERVERNAME.DE',
  'blacklisted_files' => 
  array (
    0 => '._*',
    1 => '.DS_Store',
    2 => '.DS_STORE',
    3 => '.ds_store',
  ),
  'integrity.check.disabled' => true,
  'mysql.utf8mb4' => true,
  'mail_smtpauthtype' => 'LOGIN',
  'mail_sendmailmode' => 'smtp',
  'mail_smtphost' => 'mail.SERVERNAME.DE',
  'mail_smtpport' => '25',
  'mail_smtpauth' => 1,
  'mail_smtpsecure' => 'tls',
  'mail_smtpname' => 'webmaster@SERVERNAME.DE',
  'mail_smtppassword' => 'XXXXXXXX',
  'app_install_overwrite' => 
  array (
    0 => 'apporder',
    1 => 'calendar',
    2 => 'bookmarks',
  ),
  'has_rebuilt_cache' => true,
  'encryption.legacy_format_support' => false,
  'encryption.key_storage_migrated' => false,
)

The output of your Apache/nginx/system log in /var/log/____:

cloud.SERVERNAME.DE 1.2.3.4 - andy [04/Jun/2021:01:46:27 +0200] "PROPFIND /remote.php/webdav/Handy/DCIM/Camera/IMG_20210602_223758.jpg HTTP/1.1" 207 7881 "-" "curl/7.68.0"
cloud.SERVERNAME.DE 1.2.3.4 - user2 [04/Jun/2021:01:46:17 +0200] "PROPFIND /remote.php/webdav/Handy/DCIM/Camera/IMG_2021-0602_202145.jpg HTTP/1.1" 207 7868 "-" "curl/7.68.0"

wwe · June 10, 2021, 8:12pm

you have really good starting point - once one user works fast (at same time) the problem is not related to generic hardware shortage. I would suggest you compare the differences of the both users - maybe you have configured different application (my personal experience shows external storage extremely slow down the whole system)

raid1 · June 10, 2021, 9:05pm

Thanks for your answer!
I also think that it’s not a hardware but software problem.
Good point about external storage but I don’t use it - everything is local.

How do you suggest to compare the two users?

Thanks!

wwe · June 10, 2021, 9:15pm

you can login with both user and go through settings, apps, files - as long you don know what is the issue it’s hard to predict what to review… you could check the other side as well - if both users login on same client do you still see the difference in the speed?

raid1 · June 10, 2021, 9:21pm

Yes, I did the curl test on the same client.

The apps are the same for all users.
The settings very similar for these two users.
The files are different of course but I have no clue where to start here. If I could “deactivate” files temporarily but that’s not possible. Deleting is not an option because all the synced devices would delete them then, too. And some shares wouldn’t work.

Is there anything like a detailed debug view of the server? I could do an “strace” but which process would I choose?

raid1 · June 11, 2021, 8:14pm

If I turn on mysql verbose logging (set global general_log=1) I can see that there are many queries like this:
UPDATE oc_authtoken SET password = “…” WHERE id = ###

And:
Select count(*) FROM oc_authtoken WHERE (uid = “andy”);
returns 176 !

For the other user it’s just 13.

I think I have found the cause of the slowness now. But where are all these entries coming from?
Can I just delete them from the DB? What would happen then?

Still grateful for any hint! Thanks!

raid1 · June 11, 2021, 8:46pm

Well, I was brave and did a
DELETE from oc_authtoken where uid=‘andy’
(after making a backup of course)

Now the curl command needs less than a second! And Foldersync is lightning fast again, yeah!

I’ll have to see during the next days what side effects (except for the need to login anew) this has.

So, that makes me happy but leaves these doubts:

Where did all these DB lines come from?
Will they reappear after a while?
Why did they have no effect until the update to NC 21?

To me, this looks like a NC bug. What do you think?

raid1 · June 12, 2021, 9:28pm

Sorry to say that but this was not a permanent solution.
157 new(!) entries are back today. And everything is slow again.

Here is just a short part of it:

What can I do to stop this??? Please Help!

raid1 · June 19, 2021, 11:20pm

Is there anybody from the NC devs reading this forum?
Or is there better/preferred way to submit a bug report?

tflidd · June 20, 2021, 3:58pm

raid1 · June 22, 2021, 4:46pm

Thanks
→ Hundreds of odd oc_authtoken entries for a user slow down performance · Issue #27603 · nextcloud/server · GitHub