occ log:watch crashes on messages that attach a trace

[iw0nderhow]

Steps to reproduce

1. Set debug => true in config.php
2. Start occ log:watch -vvv
3. Open a folder with more than 1000 files in it (in my case, >3000 files)

Expected behaviour

occ prints the error messages emitted.

Actual behaviour

occ crashes on messages that attach a Trace (.message.Trace), e.g. this one:

Show message

```json { "reqId": "ktbTTLCzWz2M3WUygv3o", "level": 3, "time": "2021-04-19T15:16:06+00:00", "remoteAddr": "1.2.3.4", "user": "christopher", "app": "core", "method": "PROPFIND", "url": "/remote.php/dav/files/christopher/Downloads/Archiv/", "message": { "Exception": "Doctrine\\DBAL\\Query\\QueryException", "Message": "More than 1000 expressions in a list are not allowed on Oracle.", "Code": 0, "Trace": [ { "file": "/var/www/html/lib/private/Comments/Manager.php", "line": 657, "function": "execute", "class": "OC\\DB\\QueryBuilder\\QueryBuilder", "type": "->" }, { "file": "/var/www/html/apps/dav/lib/Connector/Sabre/CommentPropertiesPlugin.php", "line": 89, "function": "getNumberOfUnreadCommentsForObjects", "class": "OC\\Comments\\Manager", "type": "->" }, { "file": "/var/www/html/apps/dav/lib/Connector/Sabre/CommentPropertiesPlugin.php", "line": 117, "function": "cacheDirectory", "class": "OCA\\DAV\\Connector\\Sabre\\CommentPropertiesPlugin", "type": "->" }, { "file": "/var/www/html/3rdparty/sabre/event/lib/WildcardEmitterTrait.php", "line": 89, "function": "handleGetProperties", "class": "OCA\\DAV\\Connector\\Sabre\\CommentPropertiesPlugin", "type": "->" }, { "file": "/var/www/html/3rdparty/sabre/dav/lib/DAV/Server.php", "line": 1052, "function": "emit", "class": "Sabre\\DAV\\Server", "type": "->" }, { "file": "/var/www/html/3rdparty/sabre/dav/lib/DAV/Server.php", "line": 984, "function": "getPropertiesByNode", "class": "Sabre\\DAV\\Server", "type": "->" }, { "file": "/var/www/html/3rdparty/sabre/dav/lib/DAV/Server.php", "line": 1661, "function": "getPropertiesIteratorForPath", "class": "Sabre\\DAV\\Server", "type": "->" }, { "file": "/var/www/html/3rdparty/sabre/dav/lib/DAV/Server.php", "line": 1646, "function": "writeMultiStatus", "class": "Sabre\\DAV\\Server", "type": "->" }, { "file": "/var/www/html/3rdparty/sabre/dav/lib/DAV/CorePlugin.php", "line": 346, "function": "generateMultiStatus", "class": "Sabre\\DAV\\Server", "type": "->" }, { "file": "/var/www/html/3rdparty/sabre/event/lib/WildcardEmitterTrait.php", "line": 89, "function": "httpPropFind", "class": "Sabre\\DAV\\CorePlugin", "type": "->" }, { "file": "/var/www/html/3rdparty/sabre/dav/lib/DAV/Server.php", "line": 472, "function": "emit", "class": "Sabre\\DAV\\Server", "type": "->" }, { "file": "/var/www/html/3rdparty/sabre/dav/lib/DAV/Server.php", "line": 253, "function": "invokeMethod", "class": "Sabre\\DAV\\Server", "type": "->" }, { "file": "/var/www/html/3rdparty/sabre/dav/lib/DAV/Server.php", "line": 321, "function": "start", "class": "Sabre\\DAV\\Server", "type": "->" }, { "file": "/var/www/html/apps/dav/lib/Server.php", "line": 332, "function": "exec", "class": "Sabre\\DAV\\Server", "type": "->" }, { "file": "/var/www/html/apps/dav/appinfo/v2/remote.php", "line": 35, "function": "exec", "class": "OCA\\DAV\\Server", "type": "->" }, { "file": "/var/www/html/remote.php", "line": 167, "args": [ "/var/www/html/apps/dav/appinfo/v2/remote.php" ], "function": "require_once" } ], "File": "/var/www/html/lib/private/DB/QueryBuilder/QueryBuilder.php", "Line": 268, "CustomMessage": "More than 1000 expressions in a list are not allowed on Oracle." }, "userAgent": "Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:87.0) Gecko/20100101 Firefox/87.0", "version": "21.0.1.1" } ```

The web log interface, however, works.

Server configuration

Operating system: Ubuntu 20.04

Web server: Apache 2.4.41-4ubuntu3.1

Database: MariaDB 1:10.3.25-0ubuntu0.20.04.1

PHP version: 8.0.3 (from deb.sury.org)

Nextcloud version: 21.0.1

Where did you install Nextcloud from: ZIP package (continuously upgraded from ~v13)

List of activated apps:

Enabled:
  - accessibility: 1.7.0
  - activity: 2.14.3
  - admin_audit: 1.11.0
  - apporder: 0.12.0
  - audioplayer: 3.1.0
  - bookmarks: 4.1.0
  - bruteforcesettings: 2.1.0
  - calendar: 2.2.0
  - camerarawpreviews: 0.7.10
  - checksum: 1.1.2
  - cloud_federation_api: 1.4.0
  - comments: 1.11.0
  - contacts: 3.5.1
  - contactsinteraction: 1.2.0
  - dashboard: 7.1.0
  - data_request: 1.8.0
  - dav: 1.17.1
  - drawio: 1.0.0
  - dropit: 0.4.0
  - event_update_notification: 1.2.0
  - external: 3.8.1
  - extract: 1.3.1
  - federatedfilesharing: 1.11.0
  - federation: 1.11.0
  - files: 1.16.0
  - files_automatedtagging: 1.11.0
  - files_downloadactivity: 1.10.0
  - files_external: 1.12.0
  - files_linkeditor: 1.1.5
  - files_markdown: 2.3.3
  - files_pdfviewer: 2.1.0
  - files_readmemd: 1.2.0
  - files_rightclick: 1.0.0
  - files_sharing: 1.13.1
  - files_texteditor: 2.10.0
  - files_trashbin: 1.11.0
  - files_versions: 1.14.0
  - files_videoplayer: 1.10.0
  - firstrunwizard: 2.10.0
  - gpxmotion: 0.1.0
  - groupfolders: 9.0.0
  - guests: 2.0.0
  - integration_mastodon: 1.0.0
  - logreader: 2.6.0
  - lookup_server_connector: 1.9.0
  - maps: 0.1.8
  - metadata: 0.13.0
  - news: 15.3.2
  - nextcloud_announcements: 1.10.0
  - notes: 4.0.4
  - notifications: 2.9.0
  - notify_push: 0.1.7
  - oauth2: 1.9.0
  - ocdownloader: 1.7.11
  - password_policy: 1.11.0
  - phonetrack: 0.6.7
  - photos: 1.3.0
  - previewgenerator: 3.1.1
  - privacy: 1.5.0
  - provisioning_api: 1.11.0
  - qownnotesapi: 20.9.0
  - ransomware_protection: 1.10.0
  - recommendations: 1.0.0
  - richdocuments: 4.0.4
  - serverinfo: 1.11.0
  - settings: 1.3.0
  - sharebymail: 1.11.0
  - side_menu: 1.23.1
  - socialsharing_email: 2.2.0
  - spreed: 11.1.2
  - support: 1.4.0
  - survey_client: 1.9.0
  - systemtags: 1.11.0
  - tasks: 0.13.6
  - telephoneprovider: 1.0.3
  - text: 3.2.0
  - theming: 1.12.0
  - twofactor_backupcodes: 1.10.0
  - twofactor_nextcloud_notification: 3.1.2
  - twofactor_totp: 6.0.0
  - twofactor_webauthn: 0.2.9
  - updatenotification: 1.11.0
  - user_status: 1.1.1
  - viewer: 1.5.0
  - weather_status: 1.1.0
  - workflow_script: 1.6.0
  - workflowengine: 2.3.0
Disabled:
  - announcementcenter
  - audioplayer_editor
  - cospend
  - encryption
  - flowupload
  - fulltextsearch
  - issuetemplate
  - twofactor_admin
  - user_ldap

Nextcloud configuration:

{
    "system": {
        "instanceid": "***REMOVED SENSITIVE VALUE***",
        "passwordsalt": "***REMOVED SENSITIVE VALUE***",
        "secret": "***REMOVED SENSITIVE VALUE***",
        "trusted_domains": [
            "7 values removed here"
        ],
        "datadirectory": "***REMOVED SENSITIVE VALUE***",
        "overwrite.cli.url": "https:\/\/host",
        "htaccess.RewriteBase": "\/",
        "dbtype": "mysql",
        "version": "21.0.1.1",
        "dbname": "***REMOVED SENSITIVE VALUE***",
        "dbhost": "***REMOVED SENSITIVE VALUE***",
        "dbport": "",
        "dbtableprefix": "oc_",
        "dbuser": "***REMOVED SENSITIVE VALUE***",
        "dbpassword": "***REMOVED SENSITIVE VALUE***",
        "installed": true,
        "mail_smtpmode": "smtp",
        "mail_smtpauthtype": "LOGIN",
        "memcache.local": "\\OC\\Memcache\\APCu",
        "filelocking.enabled": true,
        "memcache.locking": "\\OC\\Memcache\\Redis",
        "redis": {
            "host": "***REMOVED SENSITIVE VALUE***",
            "port": 0,
            "timeout": 0
        },
        "loglevel": 1,
        "mail_smtpsecure": "ssl",
        "maintenance": false,
        "theme": "",
        "mysql.utf8mb4": true,
        "updater.release.channel": "stable",
        "enable_previews": true,
        "enabledPreviewProviders": [
            "OC\\Preview\\BMP",
            "OC\\Preview\\GIF",
            "OC\\Preview\\HEIC",
            "OC\\Preview\\JPEG",
            "OC\\Preview\\MarkDown",
            "OC\\Preview\\MP3",
            "OC\\Preview\\PNG",
            "OC\\Preview\\TXT",
            "OC\\Preview\\XBitmap",
            "OC\\Preview\\OpenDocument",
            "OC\\Preview\\Krita",
            "OC\\Preview\\Movie",
            "OC\\Preview\\TIFF",
            "OC\\Preview\\Font",
            "OC\\Preview\\PDF",
            "OC\\Preview\\MSOffice2007"
        ],
        "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***",
        "data-fingerprint": "492f75b5a90a929e7bff3609193fb862",
        "app_install_overwrite": [
            "dropit",
            "files_texteditor",
            "telephoneprovider",
            "keeporsweep",
            "files_readmemd"
        ],
        "default_phone_region": "DE",
        "trusted_proxies": "***REMOVED SENSITIVE VALUE***",
        "debug": true
    }
}

Client configuration

Browser: Firefox 87.0

Operating system: Windows 10 20H2

Logs

Output of occ log:watch

An unhandled exception has been thrown:
TypeError: array_map(): Argument #2 ($array) must be of type array, null given in /var/www/html/apps/logreader/lib/Log/Formatter.php:62
Stack trace:
#0 /var/www/html/apps/logreader/lib/Log/Formatter.php(62): array_map()
#1 /var/www/html/apps/logreader/lib/Log/Formatter.php(45): OCA\LogReader\Log\Formatter->formatTraceLine()
#2 [internal function]: OCA\LogReader\Log\Formatter->OCA\LogReader\Log\{closure}()
#3 /var/www/html/apps/logreader/lib/Log/Formatter.php(46): array_map()
#4 /var/www/html/apps/logreader/lib/Log/Formatter.php(34): OCA\LogReader\Log\Formatter->formatException()
#5 /var/www/html/apps/logreader/lib/Command/Watch.php(113): OCA\LogReader\Log\Formatter->formatMessage()
#6 /var/www/html/apps/logreader/lib/Command/Watch.php(99): OCA\LogReader\Command\Watch->printItem()
#7 /var/www/html/apps/bookmarks/vendor/symfony/console/Command/Command.php(255): OCA\LogReader\Command\Watch->execute()
#8 /var/www/html/core/Command/Base.php(169): Symfony\Component\Console\Command\Command->run()
#9 /var/www/html/apps/bookmarks/vendor/symfony/console/Application.php(1009): OC\Core\Command\Base->run()
#10 /var/www/html/apps/bookmarks/vendor/symfony/console/Application.php(273): Symfony\Component\Console\Application->doRunCommand()
#11 /var/www/html/apps/bookmarks/vendor/symfony/console/Application.php(149): Symfony\Component\Console\Application->doRun()
#12 /var/www/html/lib/private/Console/Application.php(215): Symfony\Component\Console\Application->run()
#13 /var/www/html/console.php(100): OC\Console\Application->run()
#14 /var/www/html/occ(11): require_once('...')
#15 {main}

[yamanq]

I believe #457 should fix this issue. It's caused by some trace items missing the 'args' key.

[come-nc]

@iw0nderhow Can you confirm this is fixed? Can we close this?

[iw0nderhow]

I've browsed around my instance a bit and haven't seen occ crash yet. Looks like this is fixed.