server icon indicating copy to clipboard operation
server copied to clipboard
verified publisher icon nextcloud

[Bug]: DAV queries extremely slow with a specific user account

Open Ezwen opened this issue 3 years ago • 1 comments

⚠️ This issue respects the following points: ⚠️

  • [X] This is a bug, not a question or a configuration/webserver/proxy issue.
  • [X] This issue is not already reported on Github (I've searched it).
  • [X] Nextcloud Server is up to date. See Maintenance and Release Schedule for supported versions.
  • [X] Nextcloud Server is running on 64bit capable CPU, PHP and OS.
  • [X] I agree to follow Nextcloud's Code of Conduct.

Bug description

Using NC server 24.0.3.

A few weeks ago, I've started realizing that trying to access anything using DAV (files, contacts, calendar, etc.) on my main user account of my own Nextcloud instance was extremely slow : between 30 and 60 seconds per DAV query (to be compared with 1 second per DAV query for other user accounts). This happens regardless of the tool/app used to make the query (curl, Firefox, Joplin webdav sync, Evolution caldav sync, etc.).

Since the problem only occurs with a single user account, I have tried understanding what is different/wrong with this account, with no success. In particular:

  • There is nothing appearing in the logs when these slow DAV queries occur.
  • I have tried disabling 100% of my apps, but it did not change anything.
  • I have tried removing 75% of my user files and cleaning up the trash bin, but it did not change anything.
  • I have tried to export everything from the slow user account (files, contacts, all calendars, all app-specific data), then create a new user, and import everything into this new user account — thus yielding an account identical to the first one from a user standpoint, except for sharings which are lost in the import/export process. With this new "copy" of my user account, the DAV slowdown does not occur anymore, and DAV queries are back to their normal 1-second duration.

Therefore I believe there must be something wrong deep in my main user account, which disturbs and slows down the DAV server significantly. But I have yet to find the cause.

What I haven't tried (because I am not capable to): trying to find strange things about my old user account directly in the database.

Note that I have previously documented my problems in this thread: https://help.nextcloud.com/t/webdav-access-extremely-slow-while-regular-http-access-very-fast/142444

Steps to reproduce

These steps only apply on my Nextcloud instance.

  1. Run a simple DAV query as the "slow user" and measure how long it takes, eg.
time curl -X PROPFIND -H "Depth: 0" -u slowuser:password https://myinstance/remote.php/dav/files/slowuser/

Here an example of result in my case:

… XML that includes a "HTTP/1.1 200 OK" response…
________________________________________________________
Executed in   41.67 secs      fish           external
   usr time   44.38 millis  492.00 micros   43.89 millis
   sys time    5.30 millis  189.00 micros    5.11 millis

Expected behavior

I would expect the same speed as when I run a DAV query on a copy of the "slow user" (see the bug description for the context), for instance:

… XML that includes a "HTTP/1.1 200 OK" response…
________________________________________________________
Executed in    1.18 secs      fish           external
   usr time   61.02 millis    0.00 millis   61.02 millis
   sys time   16.60 millis    1.16 millis   15.44 millis

Installation method

Docker (official image)

Operating system

Debian

PHP engine version

8.0

Web server

Apache (behind Traefik)

Database engine version

MariaDB 10.8

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

Cannot try with fresh install (need existing user).

I will see how it goes after updating to 25.

Are you using the Nextcloud Server Encryption module?

No

What user-backends are you using?

Default user-backend (database)

Configuration report

{                                                      
    "system": {            
        "trusted_proxies": "***REMOVED SENSITIVE VALUE***", 
        "filelocking.enabled": true,
        "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                        
            }                                      
        ],
        "instanceid": "***REMOVED SENSITIVE VALUE***",
        "passwordsalt": "***REMOVED SENSITIVE VALUE***",
        "secret": "***REMOVED SENSITIVE VALUE***",
        "trusted_domains": [                        
            "nextcloud.bousse.fr",                                                                                     
            "cloud.enevned.fr"                                                                                         
        ],                                                                                                             
        "datadirectory": "***REMOVED SENSITIVE VALUE***",                                                              
        "overwrite.cli.url": "https:\/\/cloud.enevned.fr",
        "overwritehost": "cloud.enevned.fr",           
        "overwriteprotocol": "https",                  
        "dbtype": "mysql",                                                                                             
        "version": "24.0.3.2",                                                                                         
        "dbname": "***REMOVED SENSITIVE VALUE***",                                                                     
        "dbhost": "***REMOVED SENSITIVE VALUE***",                                                                     
        "dbport": "",                                                                                                  
        "dbtableprefix": "oc_",
        "dbuser": "***REMOVED SENSITIVE VALUE***",      
        "dbpassword": "***REMOVED SENSITIVE VALUE***",                                                                 
        "installed": true,
        "maintenance": false,                                                                                          
        "loglevel": 2,                                                                                                 
        "app_install_overwrite": [                                                                                     
            "calendar",                                                                                                
            "passwords"                  
        ],                        
        "mysql.utf8mb4": true,    
        "theme": "",              
        "default_phone_region": "FR",
        "mail_from_address": "***REMOVED SENSITIVE VALUE***",                                                          
        "mail_smtpmode": "smtp",                                                                                       
        "mail_sendmailmode": "smtp",
        "mail_domain": "***REMOVED SENSITIVE VALUE***",
        "mail_smtpauth": 1,
        "mail_smtphost": "***REMOVED SENSITIVE VALUE***",                                                              
        "mail_smtpsecure": "tls",   
        "mail_smtpname": "***REMOVED SENSITIVE VALUE***",
        "mail_smtppassword": "***REMOVED SENSITIVE VALUE***",                                                          
        "mail_smtpport": "587",
        "mail_smtpauthtype": "LOGIN",
        "allow_local_remote_servers": true,      
        "redis": {              
            "host": "***REMOVED SENSITIVE VALUE***",
            "port": 6379,
            "timeout": 0,
            "read_timeout": 0                           
        },                             
        "memcache.distributed": "\\OC\\Memcache\\Redis",
        "memcache.locking": "\\OC\\Memcache\\Redis"
    }     
}

List of activated Apps

Enabled:          
  - accessibility: 1.10.0
  - calendar: 3.4.2   
  - circles: 24.0.0
  - cloud_federation_api: 1.7.0
  - contacts: 4.2.0 
  - cookbook: 0.9.13  
  - dashboard: 7.4.0
  - dav: 1.22.0
  - federatedfilesharing: 1.14.0
  - files: 1.19.0
  - files_pdfviewer: 2.5.0
  - files_rightclick: 1.3.0
  - files_sharing: 1.16.2
  - files_trashbin: 1.14.0
  - files_versions: 1.17.0
  - files_videoplayer: 1.13.0
  - firstrunwizard: 2.13.0
  - lookup_server_connector: 1.12.0
  - news: 18.1.0
  - notes: 4.4.0
  - notifications: 2.12.0
  - oauth2: 1.12.0
  - photos: 1.6.0
  - previewgenerator: 5.0.0
  - privacy: 1.8.0
  - provisioning_api: 1.14.0
  - settings: 1.6.0
  - sharebymail: 1.14.0
  - tasks: 0.14.4
  - text: 3.5.1
  - twofactor_backupcodes: 1.13.0
  - user_migration: 1.1.0
  - viewer: 1.8.0
  - workflowengine: 2.6.0
Disabled:
  - activity: 2.16.0
  - admin_audit
  - comments: 1.14.0
  - contactsinteraction: 1.5.0
  - encryption
  - federation: 1.14.0
  - files_external: 1.16.1
  - logreader: 2.9.0
  - nextcloud_announcements: 1.13.0
  - password_policy: 1.14.0
  - passwords: 2022.6.20
  - recommendations: 1.3.0
  - richdocuments: 6.1.1
  - serverinfo: 1.14.0
  - support: 1.7.0
  - survey_client: 1.12.0
  - systemtags: 1.14.0
  - theming: 1.15.0
  - updatenotification: 1.1.1
  - user_ldap: 1.3.1
  - user_status: 1.4.0
  - weather_status: 1.4.0

Nextcloud Signing status

No errors have been found.

Nextcloud Logs

{"reqId":"pPCAYiGSkR4IUxZsDrf8","level":2,"time":"2022-08-03T14:27:18+00:00","remoteAddr":"172.19.0.2","user":"--","app":"core","method":"PROPFIND","url":"/remote.php/dav/files/slowuser/","message":"Login failed: 'test3' (Remote IP: '172.19.0.2')","userAgent":"curl/7.82.0","version":"24.0.3.2","data":{"app":"core"}}
{"reqId":"7lRXQtkjLmI3R81M3Wea","level":2,"time":"2022-08-03T14:28:18+00:00","remoteAddr":"172.19.0.2","user":"--","app":"core","method":"PROPFIND","url":"/remote.php/dav/files/slowuser/","message":"Login failed: 'test3' (Remote IP: '172.19.0.2')","userAgent":"curl/7.82.0","version":"24.0.3.2","data":{"app":"core"}}
{"reqId":"ERvIL7kijkGFzrCjurJ7","level":2,"time":"2022-08-03T14:28:34+00:00","remoteAddr":"172.19.0.2","user":"--","app":"core","method":"PROPFIND","url":"/remote.php/dav/files/slowuser/","message":"Login failed: 'test3' (Remote IP: '172.19.0.2')","userAgent":"curl/7.82.0","version":"24.0.3.2","data":{"app":"core"}}
{"reqId":"2LDa4OBYuV7yaqPHO42n","level":3,"time":"2022-08-03T14:33:01+00:00","remoteAddr":"","user":"--","app":"PHP","method":"","url":"--","message":"Undefined array key \"Romance Standard Time\" at /var/www/html/apps/dav/lib/UserMigration/CalendarMigrator.php#302","userAgent":"--","version":"24.0.3.2","exception":{"Exception":"Error","Message":"Undefined array key \"Romance Standard Time\" at /var/www/html/apps/dav/lib/UserMigration/CalendarMigrator.php#302","Code":0,"Trace":[{"file":"/var/www/html/apps/dav/lib/UserMigration/CalendarMigrator.php","line":302,"function":"onError","class":"OC\\Log\\ErrorHandler","type":"::","args":[2,"Undefined array key \"Romance Standard Time\"","/var/www/html/apps/dav/lib/UserMigration/CalendarMigrator.php",302]},{"function":"OCA\\DAV\\UserMigration\\{closure}","class":"OCA\\DAV\\UserMigration\\CalendarMigrator","type":"->","args":["*** sensitive parameters replaced ***"]},{"file":"/var/www/html/apps/dav/lib/UserMigration/CalendarMigrator.php","line":302,"function":"array_map","args":[{"__class__":"Closure"},["*** sensitive parameters replaced ***"]]},{"file":"/var/www/html/apps/dav/lib/UserMigration/CalendarMigrator.php","line":330,"function":"getTimezonesForComponent","class":"OCA\\DAV\\UserMigration\\CalendarMigrator","type":"->","args":[{"__class__":"Sabre\\VObject\\Component\\VCalendar","name":"VCALENDAR","parent":null},{"__class__":"Sabre\\VObject\\Component\\VEvent","name":"VEVENT","parent":{"__class__":"Sabre\\VObject\\Component\\VCalendar","name":"VCALENDAR","parent":null}}]},{"file":"/var/www/html/apps/dav/lib/UserMigration/CalendarMigrator.php","line":416,"function":"getRequiredImportComponents","class":"OCA\\DAV\\UserMigration\\CalendarMigrator","type":"->","args":[{"__class__":"Sabre\\VObject\\Component\\VCalendar","name":"VCALENDAR","parent":null},{"__class__":"Sabre\\VObject\\Component\\VEvent","name":"VEVENT","parent":{"__class__":"Sabre\\VObject\\Component\\VCalendar","name":"VCALENDAR","parent":null}}]},{"file":"/var/www/html/apps/dav/lib/UserMigration/CalendarMigrator.php","line":480,"function":"importCalendar","class":"OCA\\DAV\\UserMigration\\CalendarMigrator","type":"->","args":[{"__class__":"OC\\User\\User"},"defaultcalendar.ics","defaultcalendar",{"__class__":"Sabre\\VObject\\Component\\VCalendar","name":"VCALENDAR","parent":null},{"__class__":"Symfony\\Component\\Console\\Output\\NullOutput"}]},{"file":"/var/www/html/custom_apps/user_migration/lib/Service/UserMigrationService.php","line":250,"function":"import","class":"OCA\\DAV\\UserMigration\\CalendarMigrator","type":"->","args":[{"__class__":"OC\\User\\User"},{"__class__":"OCA\\UserMigration\\UserFolderImportSource"},{"__class__":"Symfony\\Component\\Console\\Output\\NullOutput"}]},{"file":"/var/www/html/custom_apps/user_migration/lib/BackgroundJob/UserImportJob.php","line":100,"function":"import","class":"OCA\\UserMigration\\Service\\UserMigrationService","type":"->","args":[{"__class__":"OCA\\UserMigration\\UserFolderImportSource"},{"__class__":"OC\\User\\User"}]},{"file":"/var/www/html/lib/public/BackgroundJob/Job.php","line":79,"function":"run","class":"OCA\\UserMigration\\BackgroundJob\\UserImportJob","type":"->","args":[[1]]},{"file":"/var/www/html/lib/public/BackgroundJob/QueuedJob.php","line":47,"function":"execute","class":"OCP\\BackgroundJob\\Job","type":"->","args":[{"__class__":"OC\\BackgroundJob\\JobList"},{"__class__":"OC\\Log"}]},{"file":"/var/www/html/cron.php","line":151,"function":"execute","class":"OCP\\BackgroundJob\\QueuedJob","type":"->","args":[{"__class__":"OC\\BackgroundJob\\JobList"},{"__class__":"OC\\Log"}]}],"File":"/var/www/html/lib/private/Log/ErrorHandler.php","Line":92,"CustomMessage":"--"}}
{"reqId":"2LDa4OBYuV7yaqPHO42n","level":3,"time":"2022-08-03T14:34:16+00:00","remoteAddr":"","user":"--","app":"PHP","method":"","url":"--","message":"Undefined array key \"/freeassociation.sourceforge.net/Europe/Paris\" at /var/www/html/apps/dav/lib/UserMigration/CalendarMigrator.php#302","userAgent":"--","version":"24.0.3.2","exception":{"Exception":"Error","Message":"Undefined array key \"/freeassociation.sourceforge.net/Europe/Paris\" at /var/www/html/apps/dav/lib/UserMigration/CalendarMigrator.php#302","Code":0,"Trace":[{"file":"/var/www/html/apps/dav/lib/UserMigration/CalendarMigrator.php","line":302,"function":"onError","class":"OC\\Log\\ErrorHandler","type":"::","args":[2,"Undefined array key \"/freeassociation.sourceforge.net/Europe/Paris\"","/var/www/html/apps/dav/lib/UserMigration/CalendarMigrator.php",302]},{"function":"OCA\\DAV\\UserMigration\\{closure}","class":"OCA\\DAV\\UserMigration\\CalendarMigrator","type":"->","args":["*** sensitive parameters replaced ***"]},{"file":"/var/www/html/apps/dav/lib/UserMigration/CalendarMigrator.php","line":302,"function":"array_map","args":[{"__class__":"Closure"},["Europe/Paris","*** sensitive parameters replaced ***"]]},{"file":"/var/www/html/apps/dav/lib/UserMigration/CalendarMigrator.php","line":330,"function":"getTimezonesForComponent","class":"OCA\\DAV\\UserMigration\\CalendarMigrator","type":"->","args":[{"__class__":"Sabre\\VObject\\Component\\VCalendar","name":"VCALENDAR","parent":null},{"__class__":"Sabre\\VObject\\Component\\VEvent","name":"VEVENT","parent":{"__class__":"Sabre\\VObject\\Component\\VCalendar","name":"VCALENDAR","parent":null}}]},{"file":"/var/www/html/apps/dav/lib/UserMigration/CalendarMigrator.php","line":416,"function":"getRequiredImportComponents","class":"OCA\\DAV\\UserMigration\\CalendarMigrator","type":"->","args":[{"__class__":"Sabre\\VObject\\Component\\VCalendar","name":"VCALENDAR","parent":null},{"__class__":"Sabre\\VObject\\Component\\VEvent","name":"VEVENT","parent":{"__class__":"Sabre\\VObject\\Component\\VCalendar","name":"VCALENDAR","parent":null}}]},{"file":"/var/www/html/apps/dav/lib/UserMigration/CalendarMigrator.php","line":480,"function":"importCalendar","class":"OCA\\DAV\\UserMigration\\CalendarMigrator","type":"->","args":[{"__class__":"OC\\User\\User"},"mandragot-admin.ics","mandragot-admin",{"__class__":"Sabre\\VObject\\Component\\VCalendar","name":"VCALENDAR","parent":null},{"__class__":"Symfony\\Component\\Console\\Output\\NullOutput"}]},{"file":"/var/www/html/custom_apps/user_migration/lib/Service/UserMigrationService.php","line":250,"function":"import","class":"OCA\\DAV\\UserMigration\\CalendarMigrator","type":"->","args":[{"__class__":"OC\\User\\User"},{"__class__":"OCA\\UserMigration\\UserFolderImportSource"},{"__class__":"Symfony\\Component\\Console\\Output\\NullOutput"}]},{"file":"/var/www/html/custom_apps/user_migration/lib/BackgroundJob/UserImportJob.php","line":100,"function":"import","class":"OCA\\UserMigration\\Service\\UserMigrationService","type":"->","args":[{"__class__":"OCA\\UserMigration\\UserFolderImportSource"},{"__class__":"OC\\User\\User"}]},{"file":"/var/www/html/lib/public/BackgroundJob/Job.php","line":79,"function":"run","class":"OCA\\UserMigration\\BackgroundJob\\UserImportJob","type":"->","args":[[1]]},{"file":"/var/www/html/lib/public/BackgroundJob/QueuedJob.php","line":47,"function":"execute","class":"OCP\\BackgroundJob\\Job","type":"->","args":[{"__class__":"OC\\BackgroundJob\\JobList"},{"__class__":"OC\\Log"}]},{"file":"/var/www/html/cron.php","line":151,"function":"execute","class":"OCP\\BackgroundJob\\QueuedJob","type":"->","args":[{"__class__":"OC\\BackgroundJob\\JobList"},{"__class__":"OC\\Log"}]}],"File":"/var/www/html/lib/private/Log/ErrorHandler.php","Line":92,"CustomMessage":"--"}}
{"reqId":"WL5F9rykqwaTco3NDCKQ","level":3,"time":"2022-08-03T14:35:34+00:00","remoteAddr":"172.19.0.2","user":"test3","app":"index","method":"POST","url":"/apps/news/feeds","message":"An exception occurred while executing a query: SQLSTATE[HY000]: General error: 1364 Field 'title' doesn't have a default value","userAgent":"Mozilla/5.0 (X11; Linux x86_64; rv:102.0) Gecko/20100101 Firefox/102.0","version":"24.0.3.2","exception":{"Exception":"OC\\DB\\Exceptions\\DbalException","Message":"An exception occurred while executing a query: SQLSTATE[HY000]: General error: 1364 Field 'title' doesn't have a default value","Code":1364,"Trace":[{"file":"/var/www/html/lib/private/DB/QueryBuilder/QueryBuilder.php","line":329,"function":"wrap","class":"OC\\DB\\Exceptions\\DbalException","type":"::","args":[{"__class__":"Doctrine\\DBAL\\Exception\\NotNullConstraintViolationException"}]},{"file":"/var/www/html/lib/public/AppFramework/Db/QBMapper.php","line":139,"function":"executeStatement","class":"OC\\DB\\QueryBuilder\\QueryBuilder","type":"->","args":[]},{"file":"/var/www/html/custom_apps/news/lib/Db/NewsMapperV2.php","line":76,"function":"insert","class":"OCP\\AppFramework\\Db\\QBMapper","type":"->","args":[{"__class__":"OCA\\News\\Db\\Feed","items":[],"id":null}]},{"file":"/var/www/html/custom_apps/news/lib/Service/FeedServiceV2.php","line":235,"function":"insert","class":"OCA\\News\\Db\\NewsMapperV2","type":"->","args":[{"__class__":"OCA\\News\\Db\\Feed","items":[],"id":null}]},{"file":"/var/www/html/custom_apps/news/lib/Controller/FeedController.php","line":176,"function":"create","class":"OCA\\News\\Service\\FeedServiceV2","type":"->","args":["test3","http://www.mirionmalle.com/feeds/posts/default?alt=rss",14,false,null,null,null,true]},{"file":"/var/www/html/lib/private/AppFramework/Http/Dispatcher.php","line":225,"function":"create","class":"OCA\\News\\Controller\\FeedController","type":"->","args":["http://www.mirionmalle.com/feeds/posts/default?alt=rss",14,null,null,null,true]},{"file":"/var/www/html/lib/private/AppFramework/Http/Dispatcher.php","line":133,"function":"executeController","class":"OC\\AppFramework\\Http\\Dispatcher","type":"->","args":[{"__class__":"OCA\\News\\Controller\\FeedController"},"create"]},{"file":"/var/www/html/lib/private/AppFramework/App.php","line":172,"function":"dispatch","class":"OC\\AppFramework\\Http\\Dispatcher","type":"->","args":[{"__class__":"OCA\\News\\Controller\\FeedController"},"create"]},{"file":"/var/www/html/lib/private/Route/Router.php","line":298,"function":"main","class":"OC\\AppFramework\\App","type":"::","args":["OCA\\News\\Controller\\FeedController","create",{"__class__":"OC\\AppFramework\\DependencyInjection\\DIContainer"},["news.feed.create"]]},{"file":"/var/www/html/lib/base.php","line":1023,"function":"match","class":"OC\\Route\\Router","type":"->","args":["/apps/news/feeds"]},{"file":"/var/www/html/index.php","line":36,"function":"handleRequest","class":"OC","type":"::","args":[]}],"File":"/var/www/html/lib/private/DB/Exceptions/DbalException.php","Line":71,"Previous":{"Exception":"Doctrine\\DBAL\\Exception\\NotNullConstraintViolationException","Message":"An exception occurred while executing a query: SQLSTATE[HY000]: General error: 1364 Field 'title' doesn't have a default value","Code":1364,"Trace":[{"file":"/var/www/html/3rdparty/doctrine/dbal/src/Connection.php","line":1780,"function":"convert","class":"Doctrine\\DBAL\\Driver\\API\\MySQL\\ExceptionConverter","type":"->","args":[{"__class__":"Doctrine\\DBAL\\Driver\\PDO\\Exception"},{"__class__":"Doctrine\\DBAL\\Query"}]},{"file":"/var/www/html/3rdparty/doctrine/dbal/src/Connection.php","line":1719,"function":"handleDriverException","class":"Doctrine\\DBAL\\Connection","type":"->","args":[{"__class__":"Doctrine\\DBAL\\Driver\\PDO\\Exception"},{"__class__":"Doctrine\\DBAL\\Query"}]},{"file":"/var/www/html/3rdparty/doctrine/dbal/src/Connection.php","line":1173,"function":"convertExceptionDuringQuery","class":"Doctrine\\DBAL\\Connection","type":"->","args":[{"__class__":"Doctrine\\DBAL\\Driver\\PDO\\Exception"},"INSERT INTO `oc_news_feeds` (`url_hash`, `url`, `location`, `added`, `favicon_link`, `folder_id`, `user_id`, `last_modified`) VALUES(?, ?, ?, ?, ?, ?, ?, ?)",["db0bf4b4ee1a367134d4c7fdfd1c7226","http://www.mirionmalle.com/feeds/posts/default?alt=rss","http://www.mirionmalle.com/feeds/posts/default?alt=rss",1659537334,"http://www.mirionmalle.com/favicon.ico","And 3 more entries, set log level to debug to see all entries"],[2,2,2,1,2,"And 3 more entries, set log level to debug to see all entries"]]},{"file":"/var/www/html/lib/private/DB/Connection.php","line":294,"function":"executeStatement","class":"Doctrine\\DBAL\\Connection","type":"->","args":["INSERT INTO `oc_news_feeds` (`url_hash`, `url`, `location`, `added`, `favicon_link`, `folder_id`, `user_id`, `last_modified`) VALUES(?, ?, ?, ?, ?, ?, ?, ?)",["db0bf4b4ee1a367134d4c7fdfd1c7226","http://www.mirionmalle.com/feeds/posts/default?alt=rss","http://www.mirionmalle.com/feeds/posts/default?alt=rss",1659537334,"http://www.mirionmalle.com/favicon.ico","And 3 more entries, set log level to debug to see all entries"],[2,2,2,1,2,"And 3 more entries, set log level to debug to see all entries"]]},{"file":"/var/www/html/3rdparty/doctrine/dbal/src/Query/QueryBuilder.php","line":354,"function":"executeStatement","class":"OC\\DB\\Connection","type":"->","args":["INSERT INTO `oc_news_feeds` (`url_hash`, `url`, `location`, `added`, `favicon_link`, `folder_id`, `user_id`, `last_modified`) VALUES(:dcValue1, :dcValue2, :dcValue3, :dcValue4, :dcValue5, :dcValue6, :dcValue7, :dcValue8)",["db0bf4b4ee1a367134d4c7fdfd1c7226","http://www.mirionmalle.com/feeds/posts/default?alt=rss","http://www.mirionmalle.com/feeds/posts/default?alt=rss",1659537334,"http://www.mirionmalle.com/favicon.ico","And 3 more entries, set log level to debug to see all entries"],[2,2,2,1,2,"And 3 more entries, set log level to debug to see all entries"]]},{"file":"/var/www/html/lib/private/DB/QueryBuilder/QueryBuilder.php","line":281,"function":"execute","class":"Doctrine\\DBAL\\Query\\QueryBuilder","type":"->","args":[]},{"file":"/var/www/html/lib/private/DB/QueryBuilder/QueryBuilder.php","line":327,"function":"execute","class":"OC\\DB\\QueryBuilder\\QueryBuilder","type":"->","args":[]},{"file":"/var/www/html/lib/public/AppFramework/Db/QBMapper.php","line":139,"function":"executeStatement","class":"OC\\DB\\QueryBuilder\\QueryBuilder","type":"->","args":[]},{"file":"/var/www/html/custom_apps/news/lib/Db/NewsMapperV2.php","line":76,"function":"insert","class":"OCP\\AppFramework\\Db\\QBMapper","type":"->","args":[{"__class__":"OCA\\News\\Db\\Feed","items":[],"id":null}]},{"file":"/var/www/html/custom_apps/news/lib/Service/FeedServiceV2.php","line":235,"function":"insert","class":"OCA\\News\\Db\\NewsMapperV2","type":"->","args":[{"__class__":"OCA\\News\\Db\\Feed","items":[],"id":null}]},{"file":"/var/www/html/custom_apps/news/lib/Controller/FeedController.php","line":176,"function":"create","class":"OCA\\News\\Service\\FeedServiceV2","type":"->","args":["test3","http://www.mirionmalle.com/feeds/posts/default?alt=rss",14,false,null,null,null,true]},{"file":"/var/www/html/lib/private/AppFramework/Http/Dispatcher.php","line":225,"function":"create","class":"OCA\\News\\Controller\\FeedController","type":"->","args":["http://www.mirionmalle.com/feeds/posts/default?alt=rss",14,null,null,null,true]},{"file":"/var/www/html/lib/private/AppFramework/Http/Dispatcher.php","line":133,"function":"executeController","class":"OC\\AppFramework\\Http\\Dispatcher","type":"->","args":[{"__class__":"OCA\\News\\Controller\\FeedController"},"create"]},{"file":"/var/www/html/lib/private/AppFramework/App.php","line":172,"function":"dispatch","class":"OC\\AppFramework\\Http\\Dispatcher","type":"->","args":[{"__class__":"OCA\\News\\Controller\\FeedController"},"create"]},{"file":"/var/www/html/lib/private/Route/Router.php","line":298,"function":"main","class":"OC\\AppFramework\\App","type":"::","args":["OCA\\News\\Controller\\FeedController","create",{"__class__":"OC\\AppFramework\\DependencyInjection\\DIContainer"},["news.feed.create"]]},{"file":"/var/www/html/lib/base.php","line":1023,"function":"match","class":"OC\\Route\\Router","type":"->","args":["/apps/news/feeds"]},{"file":"/var/www/html/index.php","line":36,"function":"handleRequest","class":"OC","type":"::","args":[]}],"File":"/var/www/html/3rdparty/doctrine/dbal/src/Driver/API/MySQL/ExceptionConverter.php","Line":111,"Previous":{"Exception":"Doctrine\\DBAL\\Driver\\PDO\\Exception","Message":"SQLSTATE[HY000]: General error: 1364 Field 'title' doesn't have a default value","Code":1364,"Trace":[{"file":"/var/www/html/3rdparty/doctrine/dbal/src/Driver/PDO/Statement.php","line":94,"function":"new","class":"Doctrine\\DBAL\\Driver\\PDO\\Exception","type":"::","args":[{"__class__":"PDOException","errorInfo":["HY000",1364,"Field 'title' doesn't have a default value"]}]},{"file":"/var/www/html/3rdparty/doctrine/dbal/src/Connection.php","line":1163,"function":"execute","class":"Doctrine\\DBAL\\Driver\\PDO\\Statement","type":"->","args":[]},{"file":"/var/www/html/lib/private/DB/Connection.php","line":294,"function":"executeStatement","class":"Doctrine\\DBAL\\Connection","type":"->","args":["INSERT INTO `oc_news_feeds` (`url_hash`, `url`, `location`, `added`, `favicon_link`, `folder_id`, `user_id`, `last_modified`) VALUES(?, ?, ?, ?, ?, ?, ?, ?)",["db0bf4b4ee1a367134d4c7fdfd1c7226","http://www.mirionmalle.com/feeds/posts/default?alt=rss","http://www.mirionmalle.com/feeds/posts/default?alt=rss",1659537334,"http://www.mirionmalle.com/favicon.ico","And 3 more entries, set log level to debug to see all entries"],[2,2,2,1,2,"And 3 more entries, set log level to debug to see all entries"]]},{"file":"/var/www/html/3rdparty/doctrine/dbal/src/Query/QueryBuilder.php","line":354,"function":"executeStatement","class":"OC\\DB\\Connection","type":"->","args":["INSERT INTO `oc_news_feeds` (`url_hash`, `url`, `location`, `added`, `favicon_link`, `folder_id`, `user_id`, `last_modified`) VALUES(:dcValue1, :dcValue2, :dcValue3, :dcValue4, :dcValue5, :dcValue6, :dcValue7, :dcValue8)",["db0bf4b4ee1a367134d4c7fdfd1c7226","http://www.mirionmalle.com/feeds/posts/default?alt=rss","http://www.mirionmalle.com/feeds/posts/default?alt=rss",1659537334,"http://www.mirionmalle.com/favicon.ico","And 3 more entries, set log level to debug to see all entries"],[2,2,2,1,2,"And 3 more entries, set log level to debug to see all entries"]]},{"file":"/var/www/html/lib/private/DB/QueryBuilder/QueryBuilder.php","line":281,"function":"execute","class":"Doctrine\\DBAL\\Query\\QueryBuilder","type":"->","args":[]},{"file":"/var/www/html/lib/private/DB/QueryBuilder/QueryBuilder.php","line":327,"function":"execute","class":"OC\\DB\\QueryBuilder\\QueryBuilder","type":"->","args":[]},{"file":"/var/www/html/lib/public/AppFramework/Db/QBMapper.php","line":139,"function":"executeStatement","class":"OC\\DB\\QueryBuilder\\QueryBuilder","type":"->","args":[]},{"file":"/var/www/html/custom_apps/news/lib/Db/NewsMapperV2.php","line":76,"function":"insert","class":"OCP\\AppFramework\\Db\\QBMapper","type":"->","args":[{"__class__":"OCA\\News\\Db\\Feed","items":[],"id":null}]},{"file":"/var/www/html/custom_apps/news/lib/Service/FeedServiceV2.php","line":235,"function":"insert","class":"OCA\\News\\Db\\NewsMapperV2","type":"->","args":[{"__class__":"OCA\\News\\Db\\Feed","items":[],"id":null}]},{"file":"/var/www/html/custom_apps/news/lib/Controller/FeedController.php","line":176,"function":"create","class":"OCA\\News\\Service\\FeedServiceV2","type":"->","args":["test3","http://www.mirionmalle.com/feeds/posts/default?alt=rss",14,false,null,null,null,true]},{"file":"/var/www/html/lib/private/AppFramework/Http/Dispatcher.php","line":225,"function":"create","class":"OCA\\News\\Controller\\FeedController","type":"->","args":["http://www.mirionmalle.com/feeds/posts/default?alt=rss",14,null,null,null,true]},{"file":"/var/www/html/lib/private/AppFramework/Http/Dispatcher.php","line":133,"function":"executeController","class":"OC\\AppFramework\\Http\\Dispatcher","type":"->","args":[{"__class__":"OCA\\News\\Controller\\FeedController"},"create"]},{"file":"/var/www/html/lib/private/AppFramework/App.php","line":172,"function":"dispatch","class":"OC\\AppFramework\\Http\\Dispatcher","type":"->","args":[{"__class__":"OCA\\News\\Controller\\FeedController"},"create"]},{"file":"/var/www/html/lib/private/Route/Router.php","line":298,"function":"main","class":"OC\\AppFramework\\App","type":"::","args":["OCA\\News\\Controller\\FeedController","create",{"__class__":"OC\\AppFramework\\DependencyInjection\\DIContainer"},["news.feed.create"]]},{"file":"/var/www/html/lib/base.php","line":1023,"function":"match","class":"OC\\Route\\Router","type":"->","args":["/apps/news/feeds"]},{"file":"/var/www/html/index.php","line":36,"function":"handleRequest","class":"OC","type":"::","args":[]}],"File":"/var/www/html/3rdparty/doctrine/dbal/src/Driver/PDO/Exception.php","Line":26,"Previous":{"Exception":"PDOException","Message":"SQLSTATE[HY000]: General error: 1364 Field 'title' doesn't have a default value","Code":"HY000","Trace":[{"file":"/var/www/html/3rdparty/doctrine/dbal/src/Driver/PDO/Statement.php","line":92,"function":"execute","class":"PDOStatement","type":"->","args":[null]},{"file":"/var/www/html/3rdparty/doctrine/dbal/src/Connection.php","line":1163,"function":"execute","class":"Doctrine\\DBAL\\Driver\\PDO\\Statement","type":"->","args":[]},{"file":"/var/www/html/lib/private/DB/Connection.php","line":294,"function":"executeStatement","class":"Doctrine\\DBAL\\Connection","type":"->","args":["INSERT INTO `oc_news_feeds` (`url_hash`, `url`, `location`, `added`, `favicon_link`, `folder_id`, `user_id`, `last_modified`) VALUES(?, ?, ?, ?, ?, ?, ?, ?)",["db0bf4b4ee1a367134d4c7fdfd1c7226","http://www.mirionmalle.com/feeds/posts/default?alt=rss","http://www.mirionmalle.com/feeds/posts/default?alt=rss",1659537334,"http://www.mirionmalle.com/favicon.ico","And 3 more entries, set log level to debug to see all entries"],[2,2,2,1,2,"And 3 more entries, set log level to debug to see all entries"]]},{"file":"/var/www/html/3rdparty/doctrine/dbal/src/Query/QueryBuilder.php","line":354,"function":"executeStatement","class":"OC\\DB\\Connection","type":"->","args":["INSERT INTO `oc_news_feeds` (`url_hash`, `url`, `location`, `added`, `favicon_link`, `folder_id`, `user_id`, `last_modified`) VALUES(:dcValue1, :dcValue2, :dcValue3, :dcValue4, :dcValue5, :dcValue6, :dcValue7, :dcValue8)",["db0bf4b4ee1a367134d4c7fdfd1c7226","http://www.mirionmalle.com/feeds/posts/default?alt=rss","http://www.mirionmalle.com/feeds/posts/default?alt=rss",1659537334,"http://www.mirionmalle.com/favicon.ico","And 3 more entries, set log level to debug to see all entries"],[2,2,2,1,2,"And 3 more entries, set log level to debug to see all entries"]]},{"file":"/var/www/html/lib/private/DB/QueryBuilder/QueryBuilder.php","line":281,"function":"execute","class":"Doctrine\\DBAL\\Query\\QueryBuilder","type":"->","args":[]},{"file":"/var/www/html/lib/private/DB/QueryBuilder/QueryBuilder.php","line":327,"function":"execute","class":"OC\\DB\\QueryBuilder\\QueryBuilder","type":"->","args":[]},{"file":"/var/www/html/lib/public/AppFramework/Db/QBMapper.php","line":139,"function":"executeStatement","class":"OC\\DB\\QueryBuilder\\QueryBuilder","type":"->","args":[]},{"file":"/var/www/html/custom_apps/news/lib/Db/NewsMapperV2.php","line":76,"function":"insert","class":"OCP\\AppFramework\\Db\\QBMapper","type":"->","args":[{"__class__":"OCA\\News\\Db\\Feed","items":[],"id":null}]},{"file":"/var/www/html/custom_apps/news/lib/Service/FeedServiceV2.php","line":235,"function":"insert","class":"OCA\\News\\Db\\NewsMapperV2","type":"->","args":[{"__class__":"OCA\\News\\Db\\Feed","items":[],"id":null}]},{"file":"/var/www/html/custom_apps/news/lib/Controller/FeedController.php","line":176,"function":"create","class":"OCA\\News\\Service\\FeedServiceV2","type":"->","args":["test3","http://www.mirionmalle.com/feeds/posts/default?alt=rss",14,false,null,null,null,true]},{"file":"/var/www/html/lib/private/AppFramework/Http/Dispatcher.php","line":225,"function":"create","class":"OCA\\News\\Controller\\FeedController","type":"->","args":["http://www.mirionmalle.com/feeds/posts/default?alt=rss",14,null,null,null,true]},{"file":"/var/www/html/lib/private/AppFramework/Http/Dispatcher.php","line":133,"function":"executeController","class":"OC\\AppFramework\\Http\\Dispatcher","type":"->","args":[{"__class__":"OCA\\News\\Controller\\FeedController"},"create"]},{"file":"/var/www/html/lib/private/AppFramework/App.php","line":172,"function":"dispatch","class":"OC\\AppFramework\\Http\\Dispatcher","type":"->","args":[{"__class__":"OCA\\News\\Controller\\FeedController"},"create"]},{"file":"/var/www/html/lib/private/Route/Router.php","line":298,"function":"main","class":"OC\\AppFramework\\App","type":"::","args":["OCA\\News\\Controller\\FeedController","create",{"__class__":"OC\\AppFramework\\DependencyInjection\\DIContainer"},["news.feed.create"]]},{"file":"/var/www/html/lib/base.php","line":1023,"function":"match","class":"OC\\Route\\Router","type":"->","args":["/apps/news/feeds"]},{"file":"/var/www/html/index.php","line":36,"function":"handleRequest","class":"OC","type":"::","args":[]}],"File":"/var/www/html/3rdparty/doctrine/dbal/src/Driver/PDO/Statement.php","Line":92}}},"CustomMessage":"--"}}
{"reqId":"vFB9NX0hLdQ7ahyQ2ota","level":2,"time":"2022-08-03T14:35:37+00:00","remoteAddr":"172.19.0.2","user":"test3","app":"news","method":"POST","url":"/apps/news/feeds","message":"http://explosm.net/rss.php read error : Client error: `GET http://explosm.net/rss.php` resulted in a `404 Not Found` response:\n<!DOCTYPE html><html><head><meta name=\"viewport\" content=\"width=device-width\"/><meta charSet=\"utf-8\"/><script src=\"https (truncated...)\n","userAgent":"Mozilla/5.0 (X11; Linux x86_64; rv:102.0) Gecko/20100101 Firefox/102.0","version":"24.0.3.2","data":{"app":"news"}}
{"reqId":"e9fGnTBBph1GT0dLoWVN","level":3,"time":"2022-08-03T14:39:30+00:00","remoteAddr":"172.19.0.2","user":"test3","app":"index","method":"GET","url":"/apps/cookbook/","message":"An exception occurred while executing a query: SQLSTATE[23000]: Integrity constraint violation: 1062 Duplicate entry '1027225-test3' for key 'names_recipe_idx'","userAgent":"Mozilla/5.0 (X11; Linux x86_64; rv:102.0) Gecko/20100101 Firefox/102.0","version":"24.0.3.2","exception":{"Exception":"Doctrine\\DBAL\\Exception\\UniqueConstraintViolationException","Message":"An exception occurred while executing a query: SQLSTATE[23000]: Integrity constraint violation: 1062 Duplicate entry '1027225-test3' for key 'names_recipe_idx'","Code":1062,"Trace":[{"file":"/var/www/html/3rdparty/doctrine/dbal/src/Connection.php","line":1780,"function":"convert","class":"Doctrine\\DBAL\\Driver\\API\\MySQL\\ExceptionConverter","type":"->","args":[{"__class__":"Doctrine\\DBAL\\Driver\\PDO\\Exception"},{"__class__":"Doctrine\\DBAL\\Query"}]},{"file":"/var/www/html/3rdparty/doctrine/dbal/src/Connection.php","line":1719,"function":"handleDriverException","class":"Doctrine\\DBAL\\Connection","type":"->","args":[{"__class__":"Doctrine\\DBAL\\Driver\\PDO\\Exception"},{"__class__":"Doctrine\\DBAL\\Query"}]},{"file":"/var/www/html/3rdparty/doctrine/dbal/src/Connection.php","line":1173,"function":"convertExceptionDuringQuery","class":"Doctrine\\DBAL\\Connection","type":"->","args":[{"__class__":"Doctrine\\DBAL\\Driver\\PDO\\Exception"},"INSERT INTO `oc_cookbook_names` (`recipe_id`, `user_id`, `name`) VALUES(?, ?, ?)",[1027225,"test3","Babka vegan \u00e0 la cannelle"],["integer","string"]]},{"file":"/var/www/html/lib/private/DB/Connection.php","line":294,"function":"executeStatement","class":"Doctrine\\DBAL\\Connection","type":"->","args":["INSERT INTO `oc_cookbook_names` (`recipe_id`, `user_id`, `name`) VALUES(?, ?, ?)",[1027225,"test3","Babka vegan \u00e0 la cannelle"],["integer","string"]]},{"file":"/var/www/html/3rdparty/doctrine/dbal/src/Query/QueryBuilder.php","line":354,"function":"executeStatement","class":"OC\\DB\\Connection","type":"->","args":["INSERT INTO `oc_cookbook_names` (`recipe_id`, `user_id`, `name`) VALUES(:id, :userid, :name)",["test3",1027225,"Babka vegan \u00e0 la cannelle"],["integer","string"]]},{"file":"/var/www/html/lib/private/DB/QueryBuilder/QueryBuilder.php","line":281,"function":"execute","class":"Doctrine\\DBAL\\Query\\QueryBuilder","type":"->","args":[]},{"file":"/var/www/html/custom_apps/cookbook/lib/Db/RecipeDb.php","line":466,"function":"execute","class":"OC\\DB\\QueryBuilder\\QueryBuilder","type":"->","args":[]},{"file":"/var/www/html/custom_apps/cookbook/lib/Service/DbCacheService.php","line":236,"function":"insertRecipes","class":"OCA\\Cookbook\\Db\\RecipeDb","type":"->","args":[[["http://schema.org","Recipe","Babka vegan \u00e0 la cannelle",["Person","deliacious"],"Une babka 100% v\u00e9g\u00e9tale, \u00e0 la cannelle. On obtient une brioche parfum\u00e9e, avec des parties caram\u00e9lis\u00e9es par la cassonade.","And 17 more entries, set log level to debug to see all entries"],[1027226,"Brownie au chocolat (Tree House)","","http://doyouspeakvegan.blogspot.com/2011/11/brownie-au-chocolat.html","https://4.bp.blogspot.com/-qjYjq29fOKI/WANjN4B9yVI/AAAAAAAAFG8/wpIgYXrq1QISG-ULIBjYjLvIUawR_tiswCLcB/s640/Brownies%2B2.JPG","And 14 more entries, set log level to debug to see all entries"],["http://schema.org","Recipe",[],"2021-12-29T10:04:23+0000",false,"And 16 more entries, set log level to debug to see all entries"],["http://schema.org","Recipe",["Person","Emilie"],"2019-01-11T18:54:18+00:00",["American"],"And 22 more entries, set log level to debug to see all entries"],["http://schema.org","Recipe","2017-06-15T15:58:55.000Z",[],"2022-01-22T12:07:17+0000","And 17 more entries, set log level to debug to see all entries"],"And 9 more entries, set log level to debug to see all entries"],"test3"]},{"file":"/var/www/html/custom_apps/cookbook/lib/Service/DbCacheService.php","line":96,"function":"applyDbReceipeChanges","class":"OCA\\Cookbook\\Service\\DbCacheService","type":"->","args":[]},{"file":"/var/www/html/custom_apps/cookbook/lib/Service/DbCacheService.php","line":63,"function":"carryOutUpdate","class":"OCA\\Cookbook\\Service\\DbCacheService","type":"->","args":[]},{"file":"/var/www/html/custom_apps/cookbook/lib/Service/DbCacheService.php","line":386,"function":"updateCache","class":"OCA\\Cookbook\\Service\\DbCacheService","type":"->","args":["*** sensitive parameters replaced ***"]},{"file":"/var/www/html/custom_apps/cookbook/lib/Service/DbCacheService.php","line":375,"function":"checkSearchIndexUpdate","class":"OCA\\Cookbook\\Service\\DbCacheService","type":"->","args":[]},{"file":"/var/www/html/custom_apps/cookbook/lib/Controller/MainController.php","line":87,"function":"triggerCheck","class":"OCA\\Cookbook\\Service\\DbCacheService","type":"->","args":[]},{"file":"/var/www/html/lib/private/AppFramework/Http/Dispatcher.php","line":225,"function":"index","class":"OCA\\Cookbook\\Controller\\MainController","type":"->","args":[]},{"file":"/var/www/html/lib/private/AppFramework/Http/Dispatcher.php","line":133,"function":"executeController","class":"OC\\AppFramework\\Http\\Dispatcher","type":"->","args":[{"__class__":"OCA\\Cookbook\\Controller\\MainController"},"index"]},{"file":"/var/www/html/lib/private/AppFramework/App.php","line":172,"function":"dispatch","class":"OC\\AppFramework\\Http\\Dispatcher","type":"->","args":[{"__class__":"OCA\\Cookbook\\Controller\\MainController"},"index"]},{"file":"/var/www/html/lib/private/Route/Router.php","line":298,"function":"main","class":"OC\\AppFramework\\App","type":"::","args":["OCA\\Cookbook\\Controller\\MainController","index",{"__class__":"OC\\AppFramework\\DependencyInjection\\DIContainer"},["cookbook.main.index"]]},{"file":"/var/www/html/lib/base.php","line":1023,"function":"match","class":"OC\\Route\\Router","type":"->","args":["/apps/cookbook/"]},{"file":"/var/www/html/index.php","line":36,"function":"handleRequest","class":"OC","type":"::","args":[]}],"File":"/var/www/html/3rdparty/doctrine/dbal/src/Driver/API/MySQL/ExceptionConverter.php","Line":60,"Previous":{"Exception":"Doctrine\\DBAL\\Driver\\PDO\\Exception","Message":"SQLSTATE[23000]: Integrity constraint violation: 1062 Duplicate entry '1027225-test3' for key 'names_recipe_idx'","Code":1062,"Trace":[{"file":"/var/www/html/3rdparty/doctrine/dbal/src/Driver/PDO/Statement.php","line":94,"function":"new","class":"Doctrine\\DBAL\\Driver\\PDO\\Exception","type":"::","args":[{"__class__":"PDOException","errorInfo":["23000",1062,"Duplicate entry '1027225-test3' for key 'names_recipe_idx'"]}]},{"file":"/var/www/html/3rdparty/doctrine/dbal/src/Connection.php","line":1163,"function":"execute","class":"Doctrine\\DBAL\\Driver\\PDO\\Statement","type":"->","args":[]},{"file":"/var/www/html/lib/private/DB/Connection.php","line":294,"function":"executeStatement","class":"Doctrine\\DBAL\\Connection","type":"->","args":["INSERT INTO `oc_cookbook_names` (`recipe_id`, `user_id`, `name`) VALUES(?, ?, ?)",[1027225,"test3","Babka vegan \u00e0 la cannelle"],["integer","string"]]},{"file":"/var/www/html/3rdparty/doctrine/dbal/src/Query/QueryBuilder.php","line":354,"function":"executeStatement","class":"OC\\DB\\Connection","type":"->","args":["INSERT INTO `oc_cookbook_names` (`recipe_id`, `user_id`, `name`) VALUES(:id, :userid, :name)",["test3",1027225,"Babka vegan \u00e0 la cannelle"],["integer","string"]]},{"file":"/var/www/html/lib/private/DB/QueryBuilder/QueryBuilder.php","line":281,"function":"execute","class":"Doctrine\\DBAL\\Query\\QueryBuilder","type":"->","args":[]},{"file":"/var/www/html/custom_apps/cookbook/lib/Db/RecipeDb.php","line":466,"function":"execute","class":"OC\\DB\\QueryBuilder\\QueryBuilder","type":"->","args":[]},{"file":"/var/www/html/custom_apps/cookbook/lib/Service/DbCacheService.php","line":236,"function":"insertRecipes","class":"OCA\\Cookbook\\Db\\RecipeDb","type":"->","args":[[["http://schema.org","Recipe","Babka vegan \u00e0 la cannelle",["Person","deliacious"],"Une babka 100% v\u00e9g\u00e9tale, \u00e0 la cannelle. On obtient une brioche parfum\u00e9e, avec des parties caram\u00e9lis\u00e9es par la cassonade.","And 17 more entries, set log level to debug to see all entries"],[1027226,"Brownie au chocolat (Tree House)","","http://doyouspeakvegan.blogspot.com/2011/11/brownie-au-chocolat.html","https://4.bp.blogspot.com/-qjYjq29fOKI/WANjN4B9yVI/AAAAAAAAFG8/wpIgYXrq1QISG-ULIBjYjLvIUawR_tiswCLcB/s640/Brownies%2B2.JPG","And 14 more entries, set log level to debug to see all entries"],["http://schema.org","Recipe",[],"2021-12-29T10:04:23+0000",false,"And 16 more entries, set log level to debug to see all entries"],["http://schema.org","Recipe",["Person","Emilie"],"2019-01-11T18:54:18+00:00",["American"],"And 22 more entries, set log level to debug to see all entries"],["http://schema.org","Recipe","2017-06-15T15:58:55.000Z",[],"2022-01-22T12:07:17+0000","And 17 more entries, set log level to debug to see all entries"],"And 9 more entries, set log level to debug to see all entries"],"test3"]},{"file":"/var/www/html/custom_apps/cookbook/lib/Service/DbCacheService.php","line":96,"function":"applyDbReceipeChanges","class":"OCA\\Cookbook\\Service\\DbCacheService","type":"->","args":[]},{"file":"/var/www/html/custom_apps/cookbook/lib/Service/DbCacheService.php","line":63,"function":"carryOutUpdate","class":"OCA\\Cookbook\\Service\\DbCacheService","type":"->","args":[]},{"file":"/var/www/html/custom_apps/cookbook/lib/Service/DbCacheService.php","line":386,"function":"updateCache","class":"OCA\\Cookbook\\Service\\DbCacheService","type":"->","args":["*** sensitive parameters replaced ***"]},{"file":"/var/www/html/custom_apps/cookbook/lib/Service/DbCacheService.php","line":375,"function":"checkSearchIndexUpdate","class":"OCA\\Cookbook\\Service\\DbCacheService","type":"->","args":[]},{"file":"/var/www/html/custom_apps/cookbook/lib/Controller/MainController.php","line":87,"function":"triggerCheck","class":"OCA\\Cookbook\\Service\\DbCacheService","type":"->","args":[]},{"file":"/var/www/html/lib/private/AppFramework/Http/Dispatcher.php","line":225,"function":"index","class":"OCA\\Cookbook\\Controller\\MainController","type":"->","args":[]},{"file":"/var/www/html/lib/private/AppFramework/Http/Dispatcher.php","line":133,"function":"executeController","class":"OC\\AppFramework\\Http\\Dispatcher","type":"->","args":[{"__class__":"OCA\\Cookbook\\Controller\\MainController"},"index"]},{"file":"/var/www/html/lib/private/AppFramework/App.php","line":172,"function":"dispatch","class":"OC\\AppFramework\\Http\\Dispatcher","type":"->","args":[{"__class__":"OCA\\Cookbook\\Controller\\MainController"},"index"]},{"file":"/var/www/html/lib/private/Route/Router.php","line":298,"function":"main","class":"OC\\AppFramework\\App","type":"::","args":["OCA\\Cookbook\\Controller\\MainController","index",{"__class__":"OC\\AppFramework\\DependencyInjection\\DIContainer"},["cookbook.main.index"]]},{"file":"/var/www/html/lib/base.php","line":1023,"function":"match","class":"OC\\Route\\Router","type":"->","args":["/apps/cookbook/"]},{"file":"/var/www/html/index.php","line":36,"function":"handleRequest","class":"OC","type":"::","args":[]}],"File":"/var/www/html/3rdparty/doctrine/dbal/src/Driver/PDO/Exception.php","Line":26,"Previous":{"Exception":"PDOException","Message":"SQLSTATE[23000]: Integrity constraint violation: 1062 Duplicate entry '1027225-test3' for key 'names_recipe_idx'","Code":"23000","Trace":[{"file":"/var/www/html/3rdparty/doctrine/dbal/src/Driver/PDO/Statement.php","line":92,"function":"execute","class":"PDOStatement","type":"->","args":[null]},{"file":"/var/www/html/3rdparty/doctrine/dbal/src/Connection.php","line":1163,"function":"execute","class":"Doctrine\\DBAL\\Driver\\PDO\\Statement","type":"->","args":[]},{"file":"/var/www/html/lib/private/DB/Connection.php","line":294,"function":"executeStatement","class":"Doctrine\\DBAL\\Connection","type":"->","args":["INSERT INTO `oc_cookbook_names` (`recipe_id`, `user_id`, `name`) VALUES(?, ?, ?)",[1027225,"test3","Babka vegan \u00e0 la cannelle"],["integer","string"]]},{"file":"/var/www/html/3rdparty/doctrine/dbal/src/Query/QueryBuilder.php","line":354,"function":"executeStatement","class":"OC\\DB\\Connection","type":"->","args":["INSERT INTO `oc_cookbook_names` (`recipe_id`, `user_id`, `name`) VALUES(:id, :userid, :name)",["test3",1027225,"Babka vegan \u00e0 la cannelle"],["integer","string"]]},{"file":"/var/www/html/lib/private/DB/QueryBuilder/QueryBuilder.php","line":281,"function":"execute","class":"Doctrine\\DBAL\\Query\\QueryBuilder","type":"->","args":[]},{"file":"/var/www/html/custom_apps/cookbook/lib/Db/RecipeDb.php","line":466,"function":"execute","class":"OC\\DB\\QueryBuilder\\QueryBuilder","type":"->","args":[]},{"file":"/var/www/html/custom_apps/cookbook/lib/Service/DbCacheService.php","line":236,"function":"insertRecipes","class":"OCA\\Cookbook\\Db\\RecipeDb","type":"->","args":[[["http://schema.org","Recipe","Babka vegan \u00e0 la cannelle",["Person","deliacious"],"Une babka 100% v\u00e9g\u00e9tale, \u00e0 la cannelle. On obtient une brioche parfum\u00e9e, avec des parties caram\u00e9lis\u00e9es par la cassonade.","And 17 more entries, set log level to debug to see all entries"],[1027226,"Brownie au chocolat (Tree House)","","http://doyouspeakvegan.blogspot.com/2011/11/brownie-au-chocolat.html","https://4.bp.blogspot.com/-qjYjq29fOKI/WANjN4B9yVI/AAAAAAAAFG8/wpIgYXrq1QISG-ULIBjYjLvIUawR_tiswCLcB/s640/Brownies%2B2.JPG","And 14 more entries, set log level to debug to see all entries"],["http://schema.org","Recipe",[],"2021-12-29T10:04:23+0000",false,"And 16 more entries, set log level to debug to see all entries"],["http://schema.org","Recipe",["Person","Emilie"],"2019-01-11T18:54:18+00:00",["American"],"And 22 more entries, set log level to debug to see all entries"],["http://schema.org","Recipe","2017-06-15T15:58:55.000Z",[],"2022-01-22T12:07:17+0000","And 17 more entries, set log level to debug to see all entries"],"And 9 more entries, set log level to debug to see all entries"],"test3"]},{"file":"/var/www/html/custom_apps/cookbook/lib/Service/DbCacheService.php","line":96,"function":"applyDbReceipeChanges","class":"OCA\\Cookbook\\Service\\DbCacheService","type":"->","args":[]},{"file":"/var/www/html/custom_apps/cookbook/lib/Service/DbCacheService.php","line":63,"function":"carryOutUpdate","class":"OCA\\Cookbook\\Service\\DbCacheService","type":"->","args":[]},{"file":"/var/www/html/custom_apps/cookbook/lib/Service/DbCacheService.php","line":386,"function":"updateCache","class":"OCA\\Cookbook\\Service\\DbCacheService","type":"->","args":["*** sensitive parameters replaced ***"]},{"file":"/var/www/html/custom_apps/cookbook/lib/Service/DbCacheService.php","line":375,"function":"checkSearchIndexUpdate","class":"OCA\\Cookbook\\Service\\DbCacheService","type":"->","args":[]},{"file":"/var/www/html/custom_apps/cookbook/lib/Controller/MainController.php","line":87,"function":"triggerCheck","class":"OCA\\Cookbook\\Service\\DbCacheService","type":"->","args":[]},{"file":"/var/www/html/lib/private/AppFramework/Http/Dispatcher.php","line":225,"function":"index","class":"OCA\\Cookbook\\Controller\\MainController","type":"->","args":[]},{"file":"/var/www/html/lib/private/AppFramework/Http/Dispatcher.php","line":133,"function":"executeController","class":"OC\\AppFramework\\Http\\Dispatcher","type":"->","args":[{"__class__":"OCA\\Cookbook\\Controller\\MainController"},"index"]},{"file":"/var/www/html/lib/private/AppFramework/App.php","line":172,"function":"dispatch","class":"OC\\AppFramework\\Http\\Dispatcher","type":"->","args":[{"__class__":"OCA\\Cookbook\\Controller\\MainController"},"index"]},{"file":"/var/www/html/lib/private/Route/Router.php","line":298,"function":"main","class":"OC\\AppFramework\\App","type":"::","args":["OCA\\Cookbook\\Controller\\MainController","index",{"__class__":"OC\\AppFramework\\DependencyInjection\\DIContainer"},["cookbook.main.index"]]},{"file":"/var/www/html/lib/base.php","line":1023,"function":"match","class":"OC\\Route\\Router","type":"->","args":["/apps/cookbook/"]},{"file":"/var/www/html/index.php","line":36,"function":"handleRequest","class":"OC","type":"::","args":[]}],"File":"/var/www/html/3rdparty/doctrine/dbal/src/Driver/PDO/Statement.php","Line":92}},"CustomMessage":"--"}}
{"reqId":"hiFB78PcF6D5GzqKPsq4","level":3,"time":"2022-08-03T14:46:04+00:00","remoteAddr":"172.19.0.2","user":"slowuser","app":"PHP","method":"GET","url":"/ocs/v2.php/cloud/users/details?offset=0&limit=25&search=","message":"disk_free_space(): No such file or directory at /var/www/html/lib/private/Files/Storage/Local.php#395","userAgent":"Mozilla/5.0 (X11; Linux x86_64; rv:102.0) Gecko/20100101 Firefox/102.0","version":"24.0.3.2","exception":{"Exception":"Error","Message":"disk_free_space(): No such file or directory at /var/www/html/lib/private/Files/Storage/Local.php#395","Code":0,"Trace":[{"function":"onError","class":"OC\\Log\\ErrorHandler","type":"::","args":[2,"disk_free_space(): No such file or directory","/var/www/html/lib/private/Files/Storage/Local.php",395]},{"file":"/var/www/html/lib/private/Files/Storage/Local.php","line":395,"function":"disk_free_space","args":["/var/www/html/data/test2"]},{"file":"/var/www/html/lib/private/Files/Storage/Wrapper/Wrapper.php","line":334,"function":"free_space","class":"OC\\Files\\Storage\\Local","type":"->","args":["files"]},{"file":"/var/www/html/lib/private/legacy/OC_Helper.php","line":545,"function":"free_space","class":"OC\\Files\\Storage\\Wrapper\\Wrapper","type":"->","args":["files"]},{"file":"/var/www/html/apps/provisioning_api/lib/Controller/AUserData.php","line":248,"function":"getStorageInfo","class":"OC_Helper","type":"::","args":["/"]},{"file":"/var/www/html/apps/provisioning_api/lib/Controller/AUserData.php","line":149,"function":"fillStorageInfo","class":"OCA\\Provisioning_API\\Controller\\AUserData","type":"->","args":["test2"]},{"file":"/var/www/html/apps/provisioning_api/lib/Controller/UsersController.php","line":205,"function":"getUserData","class":"OCA\\Provisioning_API\\Controller\\AUserData","type":"->","args":["test2"]},{"file":"/var/www/html/lib/private/AppFramework/Http/Dispatcher.php","line":225,"function":"getUsersDetails","class":"OCA\\Provisioning_API\\Controller\\UsersController","type":"->","args":["",25,0]},{"file":"/var/www/html/lib/private/AppFramework/Http/Dispatcher.php","line":133,"function":"executeController","class":"OC\\AppFramework\\Http\\Dispatcher","type":"->","args":[{"__class__":"OCA\\Provisioning_API\\Controller\\UsersController"},"getUsersDetails"]},{"file":"/var/www/html/lib/private/AppFramework/App.php","line":172,"function":"dispatch","class":"OC\\AppFramework\\Http\\Dispatcher","type":"->","args":[{"__class__":"OCA\\Provisioning_API\\Controller\\UsersController"},"getUsersDetails"]},{"file":"/var/www/html/lib/private/Route/Router.php","line":298,"function":"main","class":"OC\\AppFramework\\App","type":"::","args":["OCA\\Provisioning_API\\Controller\\UsersController","getUsersDetails",{"__class__":"OC\\AppFramework\\DependencyInjection\\DIContainer"},["ocs.provisioning_api.Users.getUsersDetails"]]},{"file":"/var/www/html/ocs/v1.php","line":62,"function":"match","class":"OC\\Route\\Router","type":"->","args":["/ocsapp/cloud/users/details"]},{"file":"/var/www/html/ocs/v2.php","line":23,"args":["/var/www/html/ocs/v1.php"],"function":"require_once"}],"File":"/var/www/html/lib/private/Log/ErrorHandler.php","Line":92,"CustomMessage":"--"}}

Additional info

Accessing files from the browser, without a DAV query, is always very fast, even with the "slow user".

Ezwen avatar Aug 03 '22 15:08 Ezwen

Note: I struggled with the Github issue interface to send logs, so I only managed to send a couple of the last lines. I have already looked into them though, and nothing relevant appears before/during/after the slow queries (as related above).

Ezwen avatar Aug 03 '22 15:08 Ezwen

Problem still present with 24.0.4

Ezwen avatar Aug 13 '22 06:08 Ezwen

Hello, i have a similar situation. Mei Folder with images has 450gb and i have to wait after clicking the photos app at least 30 seconds until it gehts the first page displayes, the debugging browser tools displays the most time on remote.php/dav (nginx). with other users with similar data amount the photos app is going up imediately.

apg1980 avatar Aug 16 '22 10:08 apg1980

I have the same issue on my install (Nextcloud 24.0.x on Synology NAS). And I did all the steps listed in the initial post with the same result.

strenker avatar Aug 29 '22 11:08 strenker

The slowness of DAV interface is pretty strange. I have NC 24.0.4 on Synology NAS with only 1 user, 3 Windows PC clients (running Owncloud client) and 1 Android Phone (with direct DAV connection via Mixplorer). Everything works smoothly and suddenly from today, none of those devices can get connect to my NC server.

All clients (Windows and Android) shows "connection timeout".

My NC use postgresql as database and Redis as cache. Other configurations are similiar to the OP.

lssong99 avatar Sep 08 '22 15:09 lssong99

Just found out that if you delete all authtoken in database, then login slow issue is resolved immediatly!

go to your database command line interface, then issue

delete from oc_authtoken where login_name = 'USER_NAME';

then all the slow login issue will get resolved. You need to run this time-to-time since it will increase by time.

It seems if you use several device to login, then you will get a lot of those authtoken and they are all invalided, but process then will slow down the whole login process.

They are safe to remove since all desktop client will just regenerate this based on your login crendential.

I believe it's a bug in NC's authtoken management system by not removing aged token from database. Someone may need to look into this....

lssong99 avatar Sep 08 '22 17:09 lssong99

Problem of brute force deletion of records from oc_authtoken is that all the clients which use manually generated auth tokens (NC Desktop Client or Android NC Client and Android DavX5 when authenticated through the NC App) cause so much failed login attempts that it took 30 Minutes in my home network subnet to be completely locked out from NC at all.

Before You delete user records from oc_authtoken switch off or disconnect all client apps from the network. Then start one by one to re-authenticate your apps and clients (DavX5 Sync-Clients on Android require complete storage reset plus deletion of the nextcloud account from the app it synced before)

Connect to your nextcloud database and keep an eye on oc_bruteforce_attempts. Delete every few minutes all rows containing the affected users (to be found in column metadata), ip, or subnet (don't forget ipv6 entries if your client subnets make use of ipv6)

Expect 30 minutes of effort per device.

Maybe the following delete statement is a bit safer:

delete from oc_authtoken where login_name = 'USER_NAME' and (type = 0 or type = 2);

As of my guess type = 0 are auth tokens derived by password authentication (e.g. web browser sessions) and type = 2 are deleted apps whereas for type = 1 the auth token was manually initiated for apps which are able to read QR-Codes.

strenker avatar Sep 08 '22 21:09 strenker

Interesting, so the problem might be a duplicate of https://github.com/nextcloud/server/issues/27603 Looks like this fix https://github.com/nextcloud/server/pull/33375 was merged, and should be available in Nextcloud 25.

Let's see if the NC 25 release fixes the issue then :)

Ezwen avatar Sep 09 '22 11:09 Ezwen

It was backported to v24:

https://github.com/nextcloud/server/pull/33696

and got released with 24.0.5, still not sure if it fixes the problem....

Gomez avatar Sep 09 '22 12:09 Gomez

@Gomez Well spotted!

To try the backport, I've upgraded to 24.0.5, then manually executed cron.php… and I went from 439 down to 31 elements in the oc_authtoken table − very good start!

Then I've tried again a DAV query as in my OP:

Executed in    5.70 secs      fish           external
   usr time   67.66 millis    0.00 micros   67.66 millis
   sys time   12.79 millis  974.00 micros   11.81 millis

Success! With this cleanup in the table, I went from 41.67 secs to now 5.70 seconds… still a little slow to my taste, but hugely better!

Now all my DAV-based tools (calendars mostly) are working normally again, that's a huge relief.

Thank you very much @lssong99, @strenker and @Gomez for your findings and suggestions! With the fix now in the mainline code, I consider this close now.

Ezwen avatar Sep 09 '22 12:09 Ezwen

I can confirm that the delay is related to AD-communications. While the UI is irresponsive, the server is transfering data from Active Directory.

I've tried to force cache, but it looks as if it created it in a per-user basis, as if I switch account from admin, who basically shares stuff with everyone to a key user, another batch of connections are launched against AD and it takes ages to get that PROPFIND finished again.

I've increased the caching time of responses from AD in Nextcloud but it has little or no effect. How is it possible that catching these properties takes so long when NC creates a "replica" of the user-list in its own database tables?

Any tips in how to speed up this?

kpeiruza avatar Feb 12 '23 10:02 kpeiruza