nextcloud / logreader

📜 Log reader for Nextcloud
56 stars 27 forks source link

[Bug]: Duplicate log messages in frontend and from occ log in NC29 #1236

Closed jmechnich closed 4 months ago

jmechnich commented 4 months ago

⚠️ This issue respects the following points: ⚠️

Bug description

After upgrading from NC 28.0.4 to NC 29, I noticed the following:

The contents of nextcloud.log is not identical to the output of ./occ log:tail or https://server.tld/settings/admin/logging. The browser output sorts the messages by timestamp, so the order is slightly different.

More specifically, log messages from the last two hours are duplicated (the time frame is just an estimate but apparently it is not a constant number of entries).

~$ jq -r '. | {time,message} | join(" ")' < /var/log/nextcloud/nextcloud.log | tail -8
2024-04-27T16:52:28+02:00 Transaction took 1.1706590652466s
2024-04-27T17:46:21+02:00 Error while running background job OCA\GroupFolders\BackgroundJob\ExpireGroupVersions (id: 81, arguments: null)
2024-04-27T18:46:36+02:00 Error while running background job OCA\GroupFolders\BackgroundJob\ExpireGroupVersions (id: 81, arguments: null)
2024-04-27T19:46:44+02:00 Error while running background job OCA\GroupFolders\BackgroundJob\ExpireGroupVersions (id: 81, arguments: null)
~$ sudo -u www-data /var/www/nextcloud/occ log:tail -r | jq -r '. | {time,message} | join(" ")' | tail -8
2024-04-27T16:52:28+02:00 Transaction took 1.1706590652466s
2024-04-27T17:46:21+02:00 Error while running background job OCA\GroupFolders\BackgroundJob\ExpireGroupVersions (id: 81, arguments: null)
2024-04-27T18:46:36+02:00 Error while running background job OCA\GroupFolders\BackgroundJob\ExpireGroupVersions (id: 81, arguments: null)
2024-04-27T19:46:44+02:00 Error while running background job OCA\GroupFolders\BackgroundJob\ExpireGroupVersions (id: 81, arguments: null)
2024-04-27T18:46:36+02:00 Error while running background job OCA\GroupFolders\BackgroundJob\ExpireGroupVersions (id: 81, arguments: null)
2024-04-27T19:46:44+02:00 Error while running background job OCA\GroupFolders\BackgroundJob\ExpireGroupVersions (id: 81, arguments: null)

browser_logging

Steps to reproduce

  1. Dump last few log entries directly from logfile: jq -r '. | {time,message} | join(" ")' < nextcloud.log | tail -8
  2. Dump last few log entries using occ: ./occ log:tail -r | jq -r '. | {time,message} | join(" ")' | tail -8
  3. Open https://server.tld/settings/admin/logging
  4. Compare

Expected behavior

Log messages in log file, printed by occ log:tail and in /settings/admin/logging are identical.

Installation method

Community Manual installation with Archive

Nextcloud Server version

29

Operating system

Debian/Ubuntu

PHP engine version

PHP 8.2

Web server

Nginx

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?

Configuration report

{
    "system": {
        "instanceid": "***REMOVED SENSITIVE VALUE***",
        "passwordsalt": "***REMOVED SENSITIVE VALUE***",
        "secret": "***REMOVED SENSITIVE VALUE***",
        "trusted_domains": [
            "***REMOVED SENSITIVE VALUE MANUALLY***"
        ],
        "datadirectory": "***REMOVED SENSITIVE VALUE***",
        "dbtype": "mysql",
        "version": "29.0.0.19",
        "overwrite.cli.url": "***REMOVED SENSITIVE VALUE MANUALLY***",
        "dbname": "***REMOVED SENSITIVE VALUE***",
        "dbhost": "***REMOVED SENSITIVE VALUE***",
        "dbport": "",
        "dbtableprefix": "oc_",
        "mysql.utf8mb4": true,
        "dbuser": "***REMOVED SENSITIVE VALUE***",
        "dbpassword": "***REMOVED SENSITIVE VALUE***",
        "installed": true,
        "mail_from_address": "***REMOVED SENSITIVE VALUE***",
        "mail_smtpmode": "smtp",
        "mail_domain": "***REMOVED SENSITIVE VALUE***",
        "mail_smtpauthtype": "LOGIN",
        "mail_smtpauth": 1,
        "mail_smtphost": "***REMOVED SENSITIVE VALUE***",
        "mail_smtpport": "587",
        "mail_smtpname": "***REMOVED SENSITIVE VALUE***",
        "mail_smtppassword": "***REMOVED SENSITIVE VALUE***",
        "memcache.local": "\\OC\\Memcache\\APCu",
        "memcache.distributed": "\\OC\\Memcache\\Redis",
        "redis": {
            "host": "***REMOVED SENSITIVE VALUE***",
            "port": 6379,
            "timeout": 1.5,
            "password": "***REMOVED SENSITIVE VALUE***",
            "dbindex": 0
        },
        "memcache.locking": "\\OC\\Memcache\\Redis",
        "maintenance": false,
        "theme": "",
        "log_type": "file",
        "logfile": "\/var\/log\/nextcloud\/nextcloud.log",
        "loglevel": 2,
        "logtimezone": "Europe\/Berlin",
        "updater.release.channel": "stable",
        "app_install_overwrite": [
            "calendar",
            "groupfolders",
            "ojsxc",
            "richdocuments",
            "richdocumentscode",
            "gpxpod",
            "video_converter",
            "files_markdown",
            "impersonate",
            "drawio"
        ],
        "debug": false,
        "default_phone_region": "de",
        "mail_sendmailmode": "smtp",
        "maintenance_window_start": 1,
        "trashbin_retention_obligation": "auto, 30",
        "enable_previews": true,
        "enabledPreviewProviders": [
            "OC\\Preview\\PNG",
            "OC\\Preview\\JPEG",
            "OC\\Preview\\GIF",
            "OC\\Preview\\HEIC",
            "OC\\Preview\\BMP",
            "OC\\Preview\\XBitmap",
            "OC\\Preview\\MP3",
            "OC\\Preview\\TXT",
            "OC\\Preview\\MarkDown",
            "OC\\Preview\\OpenDocument",
            "OC\\Preview\\Krita",
            "OC\\Preview\\TIFF"
        ]
    }
}

List of activated Apps

Enabled:
  - activity: 2.21.1
  - admin_audit: 1.19.0
  - bookmarks: 13.1.3
  - bruteforcesettings: 2.9.0
  - calendar: 4.7.1
  - circles: 29.0.0-dev
  - cloud_federation_api: 1.12.0
  - collectives: 2.10.1
  - comments: 1.19.0
  - contacts: 6.0.0
  - contactsinteraction: 1.10.0
  - dav: 1.30.1
  - drawio: 3.0.2
  - federatedfilesharing: 1.19.0
  - federation: 1.19.0
  - files: 2.1.0
  - files_downloadlimit: 2.0.0
  - files_external: 1.21.0
  - files_markdown: 2.4.1
  - files_pdfviewer: 2.10.0
  - files_reminders: 1.2.0
  - files_sharing: 1.21.0
  - files_trashbin: 1.19.0
  - files_versions: 1.22.0
  - firstrunwizard: 2.18.0
  - gpxpod: 5.0.18
  - groupfolders: 16.0.6
  - impersonate: 1.16.0
  - logreader: 2.14.0
  - lookup_server_connector: 1.17.0
  - nextcloud_announcements: 1.18.0
  - notes: 4.10.0
  - notifications: 2.17.0
  - oauth2: 1.17.0
  - password_policy: 1.19.0
  - photos: 2.5.0
  - polls: 7.0.3
  - privacy: 1.13.0
  - provisioning_api: 1.19.0
  - recommendations: 2.1.0
  - related_resources: 1.4.0
  - richdocuments: 8.4.0
  - richdocumentscode: 24.4.103
  - serverinfo: 1.19.0
  - settings: 1.12.0
  - sharebymail: 1.19.0
  - spreed: 19.0.0
  - support: 1.12.0
  - survey_client: 1.17.0
  - systemtags: 1.19.0
  - text: 3.10.0
  - theming: 2.4.0
  - twofactor_backupcodes: 1.18.0
  - twofactor_totp: 11.0.0-dev
  - twofactor_webauthn: 1.4.0
  - updatenotification: 1.19.1
  - user_status: 1.9.0
  - viewer: 2.3.0
  - weather_status: 1.9.0
  - workflowengine: 2.11.0

Nextcloud Signing status

No errors have been found.

Nextcloud Logs

See description.

Additional info

The errors present in the logs are caused by a missing release update for group folders reported here.

jmechnich commented 4 months ago

I just realized that this might actually be an issue with https://github.com/nextcloud/logreader/...

jmechnich commented 4 months ago

Yeah, nextcloud/logreader@32f93c28276564df9defa67469685092cb87f87f broke stuff. Could someone move this issue to nextcloud/logreader?

Thanks in advance and sorry for the noise!