[Bug]: NC 29 Transaction took 4.4144649505615s

[AndyXheli]

⚠️ This issue respects the following points: ⚠️

• This is a bug, not a question or a configuration/webserver/proxy issue.
• This issue is not already reported on Github OR Nextcloud Community Forum (I've searched it).
• Nextcloud Server is up to date. See Maintenance and Release Schedule for supported versions.
• I agree to follow Nextcloud's Code of Conduct.

Bug description

Since i upgraded to NC 29 RC1 in seeing alot of Transaction took 4.4144649505615s is this normal ?

Steps to reproduce

N/A

Expected behavior

N/A

Installation method

Community Web installer on a VPS or web space

Nextcloud Server version

29

Operating system

Debian/Ubuntu

PHP engine version

PHP 8.3

Web server

Apache (supported)

Database engine version

MariaDB

Is this bug present after an update or on a fresh install?

Upgraded to a MAJOR version (ex. 22 to 23)

Are you using the Nextcloud Server Encryption module?

Encryption is Disabled

What user-backends are you using?

• Default user-backend (database)
• LDAP/ Active Directory
• SSO - SAML
• Other

Configuration report

No response

List of activated Apps

No response

Nextcloud Signing status

No response

Nextcloud Logs

{"reqId":"wSm2YsKUgk8ZPzWQ17z1","level":2,"time":"2024-04-02T10:10:23-05:00","remoteAddr":"","user":"--","app":"no app in context","method":"","url":"--","message":"Transaction took 4.4144649505615s","userAgent":"--","version":"29.0.0.14","exception":{"Exception":"Exception","Message":"Transaction took 4.4144649505615s","Code":0,"Trace":[{"file":"/var/www/nextcloud/lib/private/DB/ConnectionAdapter.php","line":154,"function":"commit","class":"OC\\DB\\Connection","type":"->"},{"file":"/var/www/nextcloud/apps/suspicious_login/lib/Service/ETLService.php","line":148,"function":"commit","class":"OC\\DB\\ConnectionAdapter","type":"->"},{"file":"/var/www/nextcloud/apps/suspicious_login/lib/BackgroundJob/ETLJob.php","line":51,"function":"extractAndTransform","class":"OCA\\SuspiciousLogin\\Service\\ETLService","type":"->"},{"file":"/var/www/nextcloud/lib/public/BackgroundJob/Job.php","line":80,"function":"run","class":"OCA\\SuspiciousLogin\\BackgroundJob\\ETLJob","type":"->"},{"file":"/var/www/nextcloud/lib/public/BackgroundJob/TimedJob.php","line":102,"function":"start","class":"OCP\\BackgroundJob\\Job","type":"->"},{"file":"/var/www/nextcloud/lib/public/BackgroundJob/TimedJob.php","line":92,"function":"start","class":"OCP\\BackgroundJob\\TimedJob","type":"->"},{"file":"/var/www/nextcloud/cron.php","line":176,"function":"execute","class":"OCP\\BackgroundJob\\TimedJob","type":"->"}],"File":"/var/www/nextcloud/lib/private/DB/Connection.php","Line":691,"message":"Transaction took 4.4144649505615s","exception":[],"CustomMessage":"Transaction took 4.4144649505615s"},"id":"660c2dc473947"}

Additional info

No response

[solracsf]

It is "normal" because of #42345
It's a warning (not an error) that logs DB transactions that took >1s to execute. Also:

can be a good indicator for code paths that might need rework to avoid long locks or could cause potential deadlock scenarios

Short answer: nothing to worry about, already the previous behavior but was not logged; this new log line can help developpers write better code.

[AndyXheli]

Cool thank you for explaining this! I'll close this since is not an issue.

[nmbgeek]

I believe this is still an issue and would be better logged as a "debug" or "info" if it is really just to help developers to write better code. Instead I get warnings on my overview page and have to scroll through 100s of these "warnings" to make sure there aren't other actual warnings.

[AndyXheli]

I would agree can the devs sent this as info or debug

[ChristophWurst]

I believe this is still an issue and would be better logged as a "debug" or "info" if it is really just to help developers to write better code.

Not necessarily. Some of the slow transactions only show on production due to higher amount of data and/or load. There is value to the logs outside development environment.