[Bug]: SQL errors generated by background job OC\\Preview\\BackgroundCleanupJob #42540
Comments
timwalls
added
0. Needs triage
|
It looks like the relevant code is here: server/lib/private/Preview/BackgroundCleanupJob.php Lines 137 to 159 in 4119695 This code has been around for awhile (added in #19214). I would think we'd rather want to cast the fileId (to a varchar/string) if anything here, but I haven't looked closely. I'm kind of baffled this hasn't come up before. Seems it would break preview cleanup entirely. Not going to poke at today, but noting for the future/in case someone else is so inclined.
Oh, this specifically came up in 27.1.5 but not before? 🤔 |
|
Yep, casting
|
To be fair, it doesn't really have any functional impact (unless you're wondering where disk space is going and don't notice the preview directory never gets smaller I guess.) I only noticed it because I saw the errors in my PostgreSQL logs, there was no other indication.
I can't guarantee that, unfortunately. I didn't notice before, and I did notice more or less right after, but that might well just have been because after I was paying attention to logfiles more than I otherwise would have been. |
# cd /var/www/html/data/appdata_oc1042kcyi8o/preview
# find . -name 2048-1152-max.png -print
./6/5/4/5/1/6/d/6178/2048-1152-max.png
./6/5/b/0/d/f/2/6174/2048-1152-max.png
./6/4/f/f/7/9/8/6197/2048-1152-max.png
./6/4/f/f/7/9/8/6197/@eaDir/2048-1152-max.png
./a/f/5/b/a/f/5/6194/2048-1152-max.png
./f/1/6/9/b/1/a/6196/2048-1152-max.png
./f/9/1/c/e/b/5/6192/2048-1152-max.png
./f/c/1/f/0/7/3/6176/2048-1152-max.png
./4/c/5/a/9/9/8/6182/2048-1152-max.png
./4/c/c/b/2/d/6/6173/2048-1152-max.png
./0/3/c/8/7/4/a/6195/2048-1152-max.png
./2/4/b/f/d/e/4/6193/2048-1152-max.png
./7/8/7/3/b/6/6/6181/2048-1152-max.png
./b/5/d/3/a/d/8/6171/2048-1152-max.png
./3/d/3/6/c/0/7/6179/2048-1152-max.png
./c/5/e/f/8/3/1/6172/2048-1152-max.png
./c/8/0/d/9/b/a/6175/2048-1152-max.png
./d/f/f/a/2/3/e/6180/2048-1152-max.png
./d/9/8/c/1/5/4/6177/2048-1152-max.pngSeveral :-). (That path with @eadir in it looks weird though...) I can't remember when I disabled preview generation, should have mentioned that it was only a couple of weeks ago I think. So it's reasonable that there are some in there waiting to get cleared up... |
Afaik there is no automated removal of existing previews when you turn off previews. |
Ah, yes, I wasn't implying cause and effect - just explaining why there are preview files there even though I have turned off preview generation. |
This comment was marked as outdated.
This comment was marked as outdated.
|
So I decided to look at this one a bit again today, but I can't reproduce it at all. Tried it across v27/v28/v29 (tried against both postgres and mysql). No stack trace generated and previews appear to be getting cleaned up properly. Which sort of makes sense because people's logs would be filled with this and this is still the only report. Though I still expected this to be really easy to reproduce based on the code. Still a mystery for now. |
|
I've started seeing this in my NextCloud logs, in case that helps. 😅 All of the errors appear to be related to an empty EDIT: It's possible this has been spammed in my logs for a long time, and I only just noticed when a newer NextCloud version started giving warnings in the overview page if you have a lot of warning messages. (The default log level being set to debug means you don't see warning messages if you just look without filtering anything.) I only have the last month of logs (due to debug log spam) and it seems that the error has been there for the past month at least. |
|
Ah, interesting. The previews are organized in folders, and the folder name is the fileid of the source file. Apparently, you cannot cast MariaDB is less strict and the query does not fail; however, it fails a bit later when we pass a File instance to a function that expects a folder. I'm afraid, you need a different way to exclude the preview folder. |
Bug description
I recently upgraded my NextCloud instance to 27.1.5; since then I’ve started seeing SQL errors in my PostgreSQL logs like this:
These happen roughly once an hour, which suggests it’s something being called in a cronjob.
It doesn’t look like a data error per-se; the query is just wrong - the oc_filecache.name field is a varchar, and this query seems to try to cast that to an integer. I’m not a PostgreSQL expert though, maybe that’s a thing that’s supposed to be possible :-).
I checked the nextcloud server log, and the errors appear to originate in OC\Preview\BackgroundCleanupJob; I've snipped (
[...]) this down to the interesting bits to meet the ticket length limit, but a full row is pasted in the 'logs' section:It is possibly worth noting - but maybe not relevant - that I actually have previews disabled on my server, with a config file:
Steps to reproduce
Uprage to Nexcloud 27.1.5. Pay attention to the PostgreSQL logs.
Installation details
Installed in K8s using the https://nextcloud.github.io/helm/ helm chart.
Operating System: Linux 5.15.0-91-generic x86_64
Database:
Type: pgsql
Version: PostgreSQL 14.10 (Debian 14.10-1.pgdg120+1) on x86_64-pc-linux-gnu, compiled by gcc (Debian 12.2.0-14) 12.2.0, 64-bit
Size: 60.7 MB
PHP
Version: 8.2.14
Memory limit: 512 MB
Max execution time: 3600
Upload max size: 512 MB
Extensions: Core, date, libxml, openssl, pcre, sqlite3, zlib, ctype, curl, dom, fileinfo, filter, ftp, hash, iconv, json, mbstring, SPL, session, PDO, pdo_sqlite, standard, posix, random, Reflection, Phar, SimpleXML, tokenizer, xml, xmlreader, xmlwriter, mysqlnd, apache2handler, apcu, bcmath, exif, gd, gmp, imagick, intl, ldap, memcached, pcntl, pdo_mysql, pdo_pgsql, redis, sodium, sysvsem, zip, Zend OPcache
Expected behavior
No errors :-).
Installation method
None
Nextcloud Server version
27
Operating system
Debian/Ubuntu
PHP engine version
PHP 8.2
Web server
Apache (supported)
Database engine version
PostgreSQL
Is this bug present after an update or on a fresh install?
Updated from a MINOR version (ex. 22.1 to 22.2)
Are you using the Nextcloud Server Encryption module?
Encryption is Disabled
What user-backends are you using?
Configuration report
{ "system": { "htaccess.RewriteBase": "\/", "memcache.local": "\\OC\\Memcache\\APCu", "apps_paths": [ { "path": "\/var\/www\/html\/apps", "url": "\/apps", "writable": false }, { "path": "\/var\/www\/html\/custom_apps", "url": "\/custom_apps", "writable": true } ], "passwordsalt": "***REMOVED SENSITIVE VALUE***", "secret": "***REMOVED SENSITIVE VALUE***", "trusted_domains": [ "***REMOVED SENSITIVE VALUE***", "***REMOVED SENSITIVE VALUE***", "192.168.0.193" ], "datadirectory": "***REMOVED SENSITIVE VALUE***", "dbtype": "pgsql", "version": "27.1.5.1", "overwrite.cli.url": "http:\/\/localhost", "dbname": "***REMOVED SENSITIVE VALUE***", "dbhost": "***REMOVED SENSITIVE VALUE***", "dbport": "", "dbtableprefix": "oc_", "dbuser": "***REMOVED SENSITIVE VALUE***", "dbpassword": "***REMOVED SENSITIVE VALUE***", "installed": true, "instanceid": "***REMOVED SENSITIVE VALUE***", "trusted_proxies": "***REMOVED SENSITIVE VALUE***", "mail_smtpmode": "smtp", "mail_sendmailmode": "smtp", "mail_from_address": "***REMOVED SENSITIVE VALUE***", "mail_domain": "***REMOVED SENSITIVE VALUE***", "mail_smtphost": "***REMOVED SENSITIVE VALUE***", "mail_smtpport": "465", "mail_smtpauth": 1, "mail_smtpname": "***REMOVED SENSITIVE VALUE***", "mail_smtppassword": "***REMOVED SENSITIVE VALUE***", "mail_smtpsecure": "ssl", "enable_previews": false, "memcache.distributed": "\\OC\\Memcache\\Redis", "memcache.locking": "\\OC\\Memcache\\Redis", "redis": { "host": "***REMOVED SENSITIVE VALUE***", "port": "6379" }, "loglevel": 2, "maintenance": false, "filesystem_check_changes": 1 } }List of activated Apps
Nextcloud Signing status
Nextcloud Logs
{"reqId":"TKCZTJhd8MGHOcfBjffV","level":3,"time":"2024-01-01T05:00:01+00:00","remoteAddr":"","user":"--","app":"core","method":"","url":"--","message":"Error while running background job (class: OC\\Preview\\BackgroundCleanupJob, arguments: )","userAgent":"--","version":"27.1.5.1","exception":{"Exception":"Doctrine\\DBAL\\Exception\\DriverException","Message":"An exception occurred while executing a query: SQLSTATE[22P02]: Invalid text representation: 7 ERROR: invalid input syntax for type integer: \"2048-1152-max.png\"","Code":7,"Trace":[{"file":"/var/www/html/3rdparty/doctrine/dbal/src/Connection.php","line":1814,"function":"convert","class":"Doctrine\\DBAL\\Driver\\API\\PostgreSQL\\ExceptionConverter","type":"->","args":[["Doctrine\\DBAL\\Driver\\PDO\\Exception"],["Doctrine\\DBAL\\Query"]]},{"file":"/var/www/html/3rdparty/doctrine/dbal/src/Connection.php","line":1749,"function":"handleDriverException","class":"Doctrine\\DBAL\\Connection","type":"->","args":[["Doctrine\\DBAL\\Driver\\PDO\\Exception"],["Doctrine\\DBAL\\Query"]]},{"file":"/var/www/html/3rdparty/doctrine/dbal/src/Connection.php","line":1055,"function":"convertExceptionDuringQuery","class":"Doctrine\\DBAL\\Connection","type":"->","args":[["Doctrine\\DBAL\\Driver\\PDO\\Exception"],"SELECT \"a\".\"name\" FROM \"oc_filecache\" \"a\" LEFT JOIN \"oc_filecache\" \"b\" ON CAST(\"a\".\"name\" AS INT) = \"b\".\"fileid\" WHERE (\"a\".\"storage\" = ?) AND (\"b\".\"fileid\" IS NULL) AND (\"a\".\"path\" LIKE ?) AND (\"a\".\"mimetype\" = ?)",[2,"appdata\\_oc1042kcyi8o/preview/_/_/_/_/_/_/_/%",2],[2,2,2]]},{"file":"/var/www/html/lib/private/DB/Connection.php","line":262,"function":"executeQuery","class":"Doctrine\\DBAL\\Connection","type":"->","args":["SELECT \"a\".\"name\" FROM \"oc_filecache\" \"a\" LEFT JOIN \"oc_filecache\" \"b\" ON CAST(\"a\".\"name\" AS INT) = \"b\".\"fileid\" WHERE (\"a\".\"storage\" = ?) AND (\"b\".\"fileid\" IS NULL) AND (\"a\".\"path\" LIKE ?) AND (\"a\".\"mimetype\" = ?)",[2,"appdata\\_oc1042kcyi8o/preview/_/_/_/_/_/_/_/%",2],[2,2,2],null]},{"file":"/var/www/html/3rdparty/doctrine/dbal/src/Query/QueryBuilder.php","line":345,"function":"executeQuery","class":"OC\\DB\\Connection","type":"->","args":["SELECT \"a\".\"name\" FROM \"oc_filecache\" \"a\" LEFT JOIN \"oc_filecache\" \"b\" ON CAST(\"a\".\"name\" AS INT) = \"b\".\"fileid\" WHERE (\"a\".\"storage\" = :dcValue1) AND (\"b\".\"fileid\" IS NULL) AND (\"a\".\"path\" LIKE :dcValue2) AND (\"a\".\"mimetype\" = :dcValue3)",[2,"appdata\\_oc1042kcyi8o/preview/_/_/_/_/_/_/_/%",2],[2,2,2]]},{"file":"/var/www/html/lib/private/DB/QueryBuilder/QueryBuilder.php","line":280,"function":"execute","class":"Doctrine\\DBAL\\Query\\QueryBuilder","type":"->","args":[]},{"file":"/var/www/html/lib/private/Preview/BackgroundCleanupJob.php","line":165,"function":"execute","class":"OC\\DB\\QueryBuilder\\QueryBuilder","type":"->","args":[]},{"file":"/var/www/html/lib/private/Preview/BackgroundCleanupJob.php","line":80,"function":"getNewPreviewLocations","class":"OC\\Preview\\BackgroundCleanupJob","type":"->","args":[]},{"file":"/var/www/html/lib/private/Preview/BackgroundCleanupJob.php","line":66,"function":"getDeletedFiles","class":"OC\\Preview\\BackgroundCleanupJob","type":"->","args":[]},{"file":"/var/www/html/lib/public/BackgroundJob/Job.php","line":81,"function":"run","class":"OC\\Preview\\BackgroundCleanupJob","type":"->","args":[null]},{"file":"/var/www/html/lib/public/BackgroundJob/TimedJob.php","line":103,"function":"start","class":"OCP\\BackgroundJob\\Job","type":"->","args":[["OC\\BackgroundJob\\JobList"]]},{"file":"/var/www/html/lib/public/BackgroundJob/TimedJob.php","line":93,"function":"start","class":"OCP\\BackgroundJob\\TimedJob","type":"->","args":[["OC\\BackgroundJob\\JobList"]]},{"file":"/var/www/html/cron.php","line":152,"function":"execute","class":"OCP\\BackgroundJob\\TimedJob","type":"->","args":[["OC\\BackgroundJob\\JobList"],["OC\\Log"]]}],"File":"/var/www/html/3rdparty/doctrine/dbal/src/Driver/API/PostgreSQL/ExceptionConverter.php","Line":91,"Previous":{"Exception":"Doctrine\\DBAL\\Driver\\PDO\\Exception","Message":"SQLSTATE[22P02]: Invalid text representation: 7 ERROR: invalid input syntax for type integer: \"2048-1152-max.png\"","Code":7,"Trace":[{"file":"/var/www/html/3rdparty/doctrine/dbal/src/Driver/PDO/Statement.php","line":103,"function":"new","class":"Doctrine\\DBAL\\Driver\\PDO\\Exception","type":"::","args":[["PDOException",["22P02",7,"ERROR: invalid input syntax for type integer: \"2048-1152-max.png\""]]]},{"file":"/var/www/html/3rdparty/doctrine/dbal/src/Connection.php","line":1045,"function":"execute","class":"Doctrine\\DBAL\\Driver\\PDO\\Statement","type":"->","args":[]},{"file":"/var/www/html/lib/private/DB/Connection.php","line":262,"function":"executeQuery","class":"Doctrine\\DBAL\\Connection","type":"->","args":["SELECT \"a\".\"name\" FROM \"oc_filecache\" \"a\" LEFT JOIN \"oc_filecache\" \"b\" ON CAST(\"a\".\"name\" AS INT) = \"b\".\"fileid\" WHERE (\"a\".\"storage\" = ?) AND (\"b\".\"fileid\" IS NULL) AND (\"a\".\"path\" LIKE ?) AND (\"a\".\"mimetype\" = ?)",[2,"appdata\\_oc1042kcyi8o/preview/_/_/_/_/_/_/_/%",2],[2,2,2],null]},{"file":"/var/www/html/3rdparty/doctrine/dbal/src/Query/QueryBuilder.php","line":345,"function":"executeQuery","class":"OC\\DB\\Connection","type":"->","args":["SELECT \"a\".\"name\" FROM \"oc_filecache\" \"a\" LEFT JOIN \"oc_filecache\" \"b\" ON CAST(\"a\".\"name\" AS INT) = \"b\".\"fileid\" WHERE (\"a\".\"storage\" = :dcValue1) AND (\"b\".\"fileid\" IS NULL) AND (\"a\".\"path\" LIKE :dcValue2) AND (\"a\".\"mimetype\" = :dcValue3)",[2,"appdata\\_oc1042kcyi8o/preview/_/_/_/_/_/_/_/%",2],[2,2,2]]},{"file":"/var/www/html/lib/private/DB/QueryBuilder/QueryBuilder.php","line":280,"function":"execute","class":"Doctrine\\DBAL\\Query\\QueryBuilder","type":"->","args":[]},{"file":"/var/www/html/lib/private/Preview/BackgroundCleanupJob.php","line":165,"function":"execute","class":"OC\\DB\\QueryBuilder\\QueryBuilder","type":"->","args":[]},{"file":"/var/www/html/lib/private/Preview/BackgroundCleanupJob.php","line":80,"function":"getNewPreviewLocations","class":"OC\\Preview\\BackgroundCleanupJob","type":"->","args":[]},{"file":"/var/www/html/lib/private/Preview/BackgroundCleanupJob.php","line":66,"function":"getDeletedFiles","class":"OC\\Preview\\BackgroundCleanupJob","type":"->","args":[]},{"file":"/var/www/html/lib/public/BackgroundJob/Job.php","line":81,"function":"run","class":"OC\\Preview\\BackgroundCleanupJob","type":"->","args":[null]},{"file":"/var/www/html/lib/public/BackgroundJob/TimedJob.php","line":103,"function":"start","class":"OCP\\BackgroundJob\\Job","type":"->","args":[["OC\\BackgroundJob\\JobList"]]},{"file":"/var/www/html/lib/public/BackgroundJob/TimedJob.php","line":93,"function":"start","class":"OCP\\BackgroundJob\\TimedJob","type":"->","args":[["OC\\BackgroundJob\\JobList"]]},{"file":"/var/www/html/cron.php","line":152,"function":"execute","class":"OCP\\BackgroundJob\\TimedJob","type":"->","args":[["OC\\BackgroundJob\\JobList"],["OC\\Log"]]}],"File":"/var/www/html/3rdparty/doctrine/dbal/src/Driver/PDO/Exception.php","Line":30,"Previous":{"Exception":"PDOException","Message":"SQLSTATE[22P02]: Invalid text representation: 7 ERROR: invalid input syntax for type integer: \"2048-1152-max.png\"","Code":"22P02","Trace":[{"file":"/var/www/html/3rdparty/doctrine/dbal/src/Driver/PDO/Statement.php","line":101,"function":"execute","class":"PDOStatement","type":"->","args":[null]},{"file":"/var/www/html/3rdparty/doctrine/dbal/src/Connection.php","line":1045,"function":"execute","class":"Doctrine\\DBAL\\Driver\\PDO\\Statement","type":"->","args":[]},{"file":"/var/www/html/lib/private/DB/Connection.php","line":262,"function":"executeQuery","class":"Doctrine\\DBAL\\Connection","type":"->","args":["SELECT \"a\".\"name\" FROM \"oc_filecache\" \"a\" LEFT JOIN \"oc_filecache\" \"b\" ON CAST(\"a\".\"name\" AS INT) = \"b\".\"fileid\" WHERE (\"a\".\"storage\" = ?) AND (\"b\".\"fileid\" IS NULL) AND (\"a\".\"path\" LIKE ?) AND (\"a\".\"mimetype\" = ?)",[2,"appdata\\_oc1042kcyi8o/preview/_/_/_/_/_/_/_/%",2],[2,2,2],null]},{"file":"/var/www/html/3rdparty/doctrine/dbal/src/Query/QueryBuilder.php","line":345,"function":"executeQuery","class":"OC\\DB\\Connection","type":"->","args":["SELECT \"a\".\"name\" FROM \"oc_filecache\" \"a\" LEFT JOIN \"oc_filecache\" \"b\" ON CAST(\"a\".\"name\" AS INT) = \"b\".\"fileid\" WHERE (\"a\".\"storage\" = :dcValue1) AND (\"b\".\"fileid\" IS NULL) AND (\"a\".\"path\" LIKE :dcValue2) AND (\"a\".\"mimetype\" = :dcValue3)",[2,"appdata\\_oc1042kcyi8o/preview/_/_/_/_/_/_/_/%",2],[2,2,2]]},{"file":"/var/www/html/lib/private/DB/QueryBuilder/QueryBuilder.php","line":280,"function":"execute","class":"Doctrine\\DBAL\\Query\\QueryBuilder","type":"->","args":[]},{"file":"/var/www/html/lib/private/Preview/BackgroundCleanupJob.php","line":165,"function":"execute","class":"OC\\DB\\QueryBuilder\\QueryBuilder","type":"->","args":[]},{"file":"/var/www/html/lib/private/Preview/BackgroundCleanupJob.php","line":80,"function":"getNewPreviewLocations","class":"OC\\Preview\\BackgroundCleanupJob","type":"->","args":[]},{"file":"/var/www/html/lib/private/Preview/BackgroundCleanupJob.php","line":66,"function":"getDeletedFiles","class":"OC\\Preview\\BackgroundCleanupJob","type":"->","args":[]},{"file":"/var/www/html/lib/public/BackgroundJob/Job.php","line":81,"function":"run","class":"OC\\Preview\\BackgroundCleanupJob","type":"->","args":[null]},{"file":"/var/www/html/lib/public/BackgroundJob/TimedJob.php","line":103,"function":"start","class":"OCP\\BackgroundJob\\Job","type":"->","args":[["OC\\BackgroundJob\\JobList"]]},{"file":"/var/www/html/lib/public/BackgroundJob/TimedJob.php","line":93,"function":"start","class":"OCP\\BackgroundJob\\TimedJob","type":"->","args":[["OC\\BackgroundJob\\JobList"]]},{"file":"/var/www/html/cron.php","line":152,"function":"execute","class":"OCP\\BackgroundJob\\TimedJob","type":"->","args":[["OC\\BackgroundJob\\JobList"],["OC\\Log"]]}],"File":"/var/www/html/3rdparty/doctrine/dbal/src/Driver/PDO/Statement.php","Line":101}},"message":"Error while running background job (class: OC\\Preview\\BackgroundCleanupJob, arguments: )","exception":{},"CustomMessage":"Error while running background job (class: OC\\Preview\\BackgroundCleanupJob, arguments: )"}}Additional info
No response
The text was updated successfully, but these errors were encountered: