server icon indicating copy to clipboard operation
server copied to clipboard

[Bug]: NC28: "SSL CA bundle not found" in the logs, calendar subscriptions not updated

Open tchernobog opened this issue 1 year ago • 0 comments

⚠️ This issue respects the following points: ⚠️

Bug description

Dear Maintainer,

since the upgrade from NC 27 to NC 28, my external iCal calendar subscriptions have stopped both updating AND showing. I tried also removing and re-adding them (and now of course there is no content at all).

The log keeps reporting errors in the form:

InvalidArgumentException SSL CA bundle not found: /tmp/oc_tmp_fIYjDE-.crt
[dav] Warning: Subscription 23 could not be refreshed due to a network error

Steps to reproduce

  1. Update to NC 28 from NC 27
  2. Subscribe to an iCal via HTTPs
  3. Look at the logs, entries not updated

Expected behavior

No warning in the logs about a missing SSL CA bundle.

Entries are correctly updated for calendar subscriptions.

Installation method

Community Web installer on a VPS or web space

Nextcloud Server version

28

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?

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?

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

Configuration report

{
    "system": {
        "debug": false,
        "instanceid": "***REMOVED SENSITIVE VALUE***",
        "datadirectory": "***REMOVED SENSITIVE VALUE***",
        "passwordsalt": "***REMOVED SENSITIVE VALUE***",
        "secret": "***REMOVED SENSITIVE VALUE***",
        "trusted_domains": [
            "nextcloud.montecristosoftware.eu"
        ],
        "dbtype": "pgsql",
        "version": "28.0.2.5",
        "overwrite.cli.url": "https:\/\/nextcloud.montecristosoftware.eu",
        "dbname": "***REMOVED SENSITIVE VALUE***",
        "dbhost": "***REMOVED SENSITIVE VALUE***",
        "dbport": "",
        "dbtableprefix": "oc_",
        "dbuser": "***REMOVED SENSITIVE VALUE***",
        "dbpassword": "***REMOVED SENSITIVE VALUE***",
        "htaccess.RewriteBase": "\/",
        "installed": true,
        "mail_from_address": "***REMOVED SENSITIVE VALUE***",
        "mail_smtpmode": "sendmail",
        "mail_sendmailmode": "smtp",
        "mail_domain": "***REMOVED SENSITIVE VALUE***",
        "mail_smtphost": "***REMOVED SENSITIVE VALUE***",
        "filelocking.enabled": true,
        "memcache.local": "\\OC\\Memcache\\Redis",
        "memcache.locking": "\\OC\\Memcache\\Redis",
        "redis": {
            "host": "***REMOVED SENSITIVE VALUE***",
            "port": 0,
            "timeout": 0
        },
        "maintenance": false,
        "maintenance_window_start": 1,
        "objectstore": {
            "class": "\\OC\\Files\\ObjectStore\\S3",
            "arguments": {
                "bucket": "montecristosoftware-nextcloud-data",
                "autocreate": true,
                "key": "***REMOVED SENSITIVE VALUE***",
                "secret": "***REMOVED SENSITIVE VALUE***",
                "hostname": "eu-central-1.linodeobjects.com",
                "region": "eu-central-1",
                "use_ssl": true,
                "port": 443
            }
        },
        "enable_previews": true,
        "preview_max_x": 2048,
        "preview_max_y": 2048,
        "preview_max_scale_factor": 2,
        "enabledPreviewProviders": [
            "OC\\Preview\\Image",
            "OC\\Preview\\Movie",
            "OC\\Preview\\TXT",
            "OC\\Preview\\PDF",
            "OC\\Preview\\Epub",
            "OC\\Preview\\Markdown",
            "OC\\Preview\\OpenDocument",
            "OC\\Preview\\MP3",
            "OC\\Preview\\HEIC",
            "OC\\Preview\\TIFF"
        ],
        "theme": "",
        "loglevel": 1,
        "log_type": "file",
        "syslog_tag": "nextcloud",
        "logfile": "\/home\/nextcloud\/nextcloud.log",
        "updater.release.channel": "beta",
        "default_phone_region": "DE",
        "twofactor_enforced": "false",
        "twofactor_enforced_groups": [
            "admin"
        ],
        "twofactor_enforced_excluded_groups": [],
        "memories.exiftool": "\/var\/www\/montecristosoftware\/nextcloud\/apps\/memories\/bin-ext\/exiftool-amd64-glibc",
        "memories.vod.path": "\/var\/www\/montecristosoftware\/nextcloud\/apps\/memories\/bin-ext\/go-vod-amd64",
        "memories.vod.ffmpeg": "\/usr\/bin\/ffmpeg",
        "memories.vod.ffprobe": "\/usr\/bin\/ffprobe",
        "memories.gis_type": 2,
        "app_install_overwrite": [
            "memories",
            "files_rightclick",
            "files_retention"
        ],
        "updater.secret": "***REMOVED SENSITIVE VALUE***"
    }
}

List of activated Apps

Enabled:
  - activity: 2.20.0
  - admin_audit: 1.18.0
  - bruteforcesettings: 2.8.0
  - calendar: 4.6.4
  - circles: 28.0.0-dev
  - cloud_federation_api: 1.11.0
  - comments: 1.18.0
  - contacts: 5.5.1
  - contactsinteraction: 1.9.0
  - cookbook: 0.11.0
  - dashboard: 7.8.0
  - dav: 1.29.1
  - deck: 1.12.1
  - federatedfilesharing: 1.18.0
  - federation: 1.18.0
  - files: 2.0.0
  - files_external: 1.20.0
  - files_pdfviewer: 2.9.0
  - files_reminders: 1.1.0
  - files_sharing: 1.20.0
  - files_trashbin: 1.18.0
  - files_versions: 1.21.0
  - firstrunwizard: 2.17.0
  - gpxpod: 5.0.15
  - logreader: 2.13.0
  - lookup_server_connector: 1.16.0
  - mail: 3.5.5
  - maps: 1.3.1
  - memories: 6.2.2
  - nextcloud_announcements: 1.17.0
  - notes: 4.9.2
  - notifications: 2.16.0
  - oauth2: 1.16.3
  - password_policy: 1.18.0
  - photos: 2.4.0
  - previewgenerator: 5.4.0
  - privacy: 1.12.0
  - provisioning_api: 1.18.0
  - recognize: 6.1.0-beta.2
  - recommendations: 2.0.0
  - related_resources: 1.3.0
  - serverinfo: 1.18.0
  - settings: 1.10.1
  - sharebymail: 1.18.0
  - side_menu: 3.11.5
  - spreed: 18.0.3
  - support: 1.11.0
  - survey_client: 1.16.0
  - systemtags: 1.18.0
  - text: 3.9.1
  - theming: 2.3.0
  - timemanager: 0.3.11
  - twofactor_backupcodes: 1.17.0
  - twofactor_totp: 10.0.0-beta.2
  - updatenotification: 1.18.0
  - user_status: 1.8.1
  - viewer: 2.2.0
  - weather_status: 1.8.0
  - workflowengine: 2.10.0
Disabled:
  - encryption: 2.16.0 (installed 2.12.0)
  - suspicious_login: 6.0.0 (installed 4.3.0)
  - user_ldap: 1.19.0

Nextcloud Signing status

No errors have been found.

Nextcloud Logs

{"reqId":"WtXUyAsjlKw8Fi6I5OIJ","level":2,"time":"2024-02-01T21:01:22+00:00","remoteAddr":"","user":"--","app":"dav","method":"","url":"--","message":"Subscription 24 could not be refreshed due to a network error","userAgent":"--","version":"28.0.2.5","exception":{"Exception":"InvalidArgumentException","Message":"SSL CA bundle not found: /tmp/oc_tmp_fIYjDE-.crt","Code":0,"Trace":[{"file":"/var/www/montecristosoftware/nextcloud/3rdparty/guzzlehttp/guzzle/src/Handler/CurlFactory.php","line":59,"function":"applyHandlerOptions","class":"GuzzleHttp\\Handler\\CurlFactory","type":"->"},{"file":"/var/www/montecristosoftware/nextcloud/3rdparty/guzzlehttp/guzzle/src/Handler/CurlHandler.php","line":43,"function":"create","class":"GuzzleHttp\\Handler\\CurlFactory","type":"->","args":["*** sensitive parameters replaced ***"]},{"file":"/var/www/montecristosoftware/nextcloud/3rdparty/guzzlehttp/guzzle/src/Handler/Proxy.php","line":28,"function":"__invoke","class":"GuzzleHttp\\Handler\\CurlHandler","type":"->"},{"file":"/var/www/montecristosoftware/nextcloud/3rdparty/guzzlehttp/guzzle/src/Handler/Proxy.php","line":48,"function":"GuzzleHttp\\Handler\\{closure}","class":"GuzzleHttp\\Handler\\Proxy","type":"::","args":["*** sensitive parameters replaced ***"]},{"file":"/var/www/montecristosoftware/nextcloud/3rdparty/guzzlehttp/guzzle/src/Middleware.php","line":256,"function":"GuzzleHttp\\Handler\\{closure}","class":"GuzzleHttp\\Handler\\Proxy","type":"::","args":["*** sensitive parameters replaced ***"]},{"file":"/var/www/montecristosoftware/nextcloud/3rdparty/guzzlehttp/guzzle/src/Middleware.php","line":240,"function":"GuzzleHttp\\{closure}","class":"GuzzleHttp\\Middleware","type":"::","args":["*** sensitive parameters replaced ***"]},{"file":"/var/www/montecristosoftware/nextcloud/3rdparty/guzzlehttp/guzzle/src/PrepareBodyMiddleware.php","line":35,"function":"GuzzleHttp\\{closure}","class":"GuzzleHttp\\Middleware","type":"::","args":["*** sensitive parameters replaced ***"]},{"file":"/var/www/montecristosoftware/nextcloud/3rdparty/guzzlehttp/guzzle/src/Middleware.php","line":31,"function":"__invoke","class":"GuzzleHttp\\PrepareBodyMiddleware","type":"->"},{"file":"/var/www/montecristosoftware/nextcloud/3rdparty/guzzlehttp/guzzle/src/RedirectMiddleware.php","line":71,"function":"GuzzleHttp\\{closure}","class":"GuzzleHttp\\Middleware","type":"::","args":["*** sensitive parameters replaced ***"]},{"file":"/var/www/montecristosoftware/nextcloud/3rdparty/guzzlehttp/guzzle/src/Middleware.php","line":63,"function":"__invoke","class":"GuzzleHttp\\RedirectMiddleware","type":"->"},{"file":"/var/www/montecristosoftware/nextcloud/3rdparty/guzzlehttp/guzzle/src/HandlerStack.php","line":75,"function":"GuzzleHttp\\{closure}","class":"GuzzleHttp\\Middleware","type":"::","args":["*** sensitive parameters replaced ***"]},{"file":"/var/www/montecristosoftware/nextcloud/3rdparty/guzzlehttp/guzzle/src/Client.php","line":331,"function":"__invoke","class":"GuzzleHttp\\HandlerStack","type":"->"},{"file":"/var/www/montecristosoftware/nextcloud/3rdparty/guzzlehttp/guzzle/src/Client.php","line":168,"function":"transfer","class":"GuzzleHttp\\Client","type":"->"},{"file":"/var/www/montecristosoftware/nextcloud/3rdparty/guzzlehttp/guzzle/src/Client.php","line":187,"function":"requestAsync","class":"GuzzleHttp\\Client","type":"->","args":["*** sensitive parameters replaced ***"]},{"file":"/var/www/montecristosoftware/nextcloud/lib/private/Http/Client/Client.php","line":230,"function":"request","class":"GuzzleHttp\\Client","type":"->"},{"file":"/var/www/montecristosoftware/nextcloud/apps/dav/lib/CalDAV/WebcalCaching/RefreshWebcalService.php","line":214,"function":"get","class":"OC\\Http\\Client\\Client","type":"->"},{"file":"/var/www/montecristosoftware/nextcloud/apps/dav/lib/CalDAV/WebcalCaching/RefreshWebcalService.php","line":86,"function":"queryWebcalFeed","class":"OCA\\DAV\\CalDAV\\WebcalCaching\\RefreshWebcalService","type":"->"},{"file":"/var/www/montecristosoftware/nextcloud/apps/dav/lib/BackgroundJob/RefreshWebcalJob.php","line":115,"function":"refreshSubscription","class":"OCA\\DAV\\CalDAV\\WebcalCaching\\RefreshWebcalService","type":"->"},{"file":"/var/www/montecristosoftware/nextcloud/lib/public/BackgroundJob/Job.php","line":81,"function":"run","class":"OCA\\DAV\\BackgroundJob\\RefreshWebcalJob","type":"->"},{"file":"/var/www/montecristosoftware/nextcloud/lib/public/BackgroundJob/Job.php","line":67,"function":"start","class":"OCP\\BackgroundJob\\Job","type":"->"},{"file":"/var/www/montecristosoftware/nextcloud/apps/dav/lib/BackgroundJob/RefreshWebcalJob.php","line":108,"function":"execute","class":"OCP\\BackgroundJob\\Job","type":"->"},{"file":"/var/www/montecristosoftware/nextcloud/cron.php","line":152,"function":"execute","class":"OCA\\DAV\\BackgroundJob\\RefreshWebcalJob","type":"->"}],"File":"/var/www/montecristosoftware/nextcloud/3rdparty/guzzlehttp/guzzle/src/Handler/CurlFactory.php","Line":363,"message":"Subscription 24 could not be refreshed due to a network error","exception":[],"CustomMessage":"Subscription 24 could not be refreshed due to a network error"},"id":"65bc07091a75b"}

Additional info

I have had a look into apps/dav/lib/CalDAV/WebcalCaching/RefreshWebcalService.php and tried to force "verify" => true among the parameters set in queryWebcalFeed. I guess somehow a string is instead provided? Where would it come from? This silenced the error in the logs.

Entries still don't seem to appear in the app. But this might be a separate issue, possibly related to https://github.com/nextcloud/server/issues/42464.

As per https://github.com/nextcloud/server/issues/42464#issuecomment-1891017392, please note that I am indeed using S3 (the Linode / Akamai variant, based on MinIO).

However, now after forcing verify to true, running e.g. occ background-job:execute --force-execute 88304 (the right OCA\DAV\BackgroundJob\RefreshWebcalJob for my user and calendar) I can see the entries PostgreSQL database are updated:

# select * from oc_calendarsubscriptions;
 id |         uri          |          principaluri          |  etc. etc.
 23 | outlookoffice365com  | principals/users/matteo  | etc. etc.

# select id, uri, cast(to_timestamp(lastmodified) as timestamp) from oc_calendarobjects where calendarid = 23 order by lastmodified desc limit 10;
    id    |                   uri                    |    to_timestamp     
----------+------------------------------------------+---------------------
 38909355 | 79b28d04-11e1-4811-bdd2-eb356856c9bf.ics | 2024-02-01 22:28:03
 38909358 | d129f326-b733-4bfc-90e4-ccef417b42f3.ics | 2024-02-01 22:28:03
 38909352 | 9d0e3dfb-fdb4-4438-8207-7279fcb21737.ics | 2024-02-01 22:28:03
 38909354 | 2f59adaa-f467-4e42-85e5-8fec2367f861.ics | 2024-02-01 22:28:03

I hope I got the idea around the SQL right.

tchernobog avatar Feb 01 '24 21:02 tchernobog