[stable29] fix(session): Log when session_* calls are slow

[backportbot]

Backport of PR #46106

[ArtificialOwl]

I have a strange behavior when installing a fresh 29.0.5 (same with its rc1), but not on 30, and reverting this PR fixes the issue...

during the setup on the web interface with mysql, after the creation of the database, the migration steps are not done on the mysql but a sqlite file is generated. Meaning that no tables are created on the mysql, and the instance ends up with a 500 as the config.php is configured to run with mysql.

my first though was that the system config is lost when calling MigrationService

@artonge ? can you do some more test with a 29.0.5 patched to revert this PR, as you were also able to reproduce the issue on your side ?

[nickvergessen]

And do you end up with a log files that has a slow session?

[artonge]

@ArtificialOwl I confirm that without this PR, the 29.0.5 installation works fine.

[ArtificialOwl]

And do you end up with a log files that has a slow session?

No, log is pretty empty:

{
"reqId": "N81UAnSq2tYZv6K7hNuZ",
"level": 3,
"time": "2024-08-27T10:14:49+00:00",
"remoteAddr": "127.0.0.1",
"user": "--",
"app": "PHP",
"method": "GET",
"url": "/",
"message": "fopen(/home/maxence/sites/nc29/nextcloud/config/config.php): Failed to open stream: No such file or directory at /home/maxence/sites/nc29/nextcloud/lib/private/Config.php#221",
"userAgent": "Mozilla/5.0 (X11; Linux x86_64; rv:129.0) Gecko/20100101 Firefox/129.0",
"version": "",
"data": {
"app": "PHP"
}
}
{
"reqId": "l215nn0eG2gnh464TUEt",
"level": 2,
"time": "2024-08-27T10:23:46+00:00",
"remoteAddr": "127.0.0.1",
"user": "--",
"app": "no app in context",
"method": "GET",
"url": "/index.php/apps/files/preview-service-worker.js",
"message": "Host nc29.local was not connected to because it violates local access rules",
"userAgent": "Mozilla/5.0 (X11; Linux x86_64; rv:129.0) Gecko/20100101 Firefox/129.0",
"version": "29.0.5.1",
"data": []
}
{
"reqId": "l215nn0eG2gnh464TUEt",
"level": 2,
"time": "2024-08-27T10:23:46+00:00",
"remoteAddr": "127.0.0.1",
"user": "--",
"app": "no app in context",
"method": "GET",
"url": "/index.php/apps/files/preview-service-worker.js",
"message": "Host nc29.local was not connected to because it violates local access rules",
"userAgent": "Mozilla/5.0 (X11; Linux x86_64; rv:129.0) Gecko/20100101 Firefox/129.0",
"version": "29.0.5.1",
"data": []
}

[nickvergessen]

Can you comment out:
https://github.com/nextcloud/server/pull/47105/files#diff-54c4c5113a473ed7e0e92e55a0d2183061aa584d8ded1ac46ba6529320a0670eR224-R239

TO see if the log of the slow session is causing it?

[ArtificialOwl]

the issue seems to come when calling call logger() in https://github.com/nextcloud/server/pull/47105/files#diff-a7caddabaf7f36c861258dd85df0ef44d7d5f58851e534252be4cc7a7d842fa4R454 with value 'core'

If I filter the value 'core' in this condition https://github.com/nextcloud/server/blob/master/lib/public/Log/functions.php#L44, the installation process is fine

[ArtificialOwl]

#47521

[joshtrichards]

This showed up over the weekend with Docker installs: nextcloud/docker#2283