PHP Fatal error: Uncaught Error: Call to a member function getName() on null in ...owncloud/apps/files_external/lib/Lib/Storage/SMB.php:115

Matt_Gott · September 16, 2019, 2:29pm

Expected behaviour

Successful Syncing of about 500 files with Desktop Client.

Actual behaviour

When syncing files to an SMB Share on OC Server the Sync stopps with errors.
When trying to access the files via WEB GUI it also failes to download / view by PDF Plugin.
After some time (1-4 Minutes) everything is accessable again.

It seem the error accoucs on heavy sync load of SMB connection, while desktop client is syncing.

I set up the Server with Default encryption module = on.

Steps to reproduce

create an external store connect (smb share) using username/ password
syncing files via win10x64 desktop client

Server configuration

Operating system: Ubuntu 18.04 LTS

Web server: Apache

Database: Mysql 5.7

PHP version: 7.2.19

ownCloud version: 10.2.1

Storage backend (external storage):
SMB share, Smbclient Version (2:4.7.6+dfsg~ubuntu-0ubuntu2.11)

Client configuration

Client version: 2.5.4 (11415)

Operating system: WIn10x64

OS language: German

Qt version used by client package (Linux only, see also Settings dialog): n/a

Client package (From ownCloud or distro) (Linux only):

Installation path of client:

Logs

Client logfile: Output of owncloud --logwindow or owncloud --logfile log.txt
(On Windows using cmd.exe, you might need to first cd into the ownCloud directory)
(See also http://doc.owncloud.org/desktop/2.2/troubleshooting.html#client-logfile )
Web server error log:

[Mon Sep 16 15:55:50.732491 2019] [php7:error] [pid 13799] [client ----------------:5185] PHP Fatal error: Uncaught Error: Call to a member function getName() on null in /var/www/owncloud/apps/files_external/lib/Lib/Storage/SMB.php:115\nStack trace:\n#0 /var/www/owncloud/lib/private/Files/Storage/Common.php(671): OCA\Files_External\Lib\Storage\SMB->getId()\n#1 /var/www/owncloud/lib/private/Files/Storage/Wrapper/Wrapper.php(602): OC\Files\Storage\Common->releaseLock(‘xx/xxxxxxxxxx…’, 1, Object(OC\Lock\MemcacheLockingProvider))\n#2 /var/www/owncloud/lib/private/Files/Storage/Wrapper/Wrapper.php(602): OC\Files\Storage\Wrapper\Wrapper->releaseLock(‘BP/Businessplan…’, 1, Object(OC\Lock\MemcacheLockingProvider))\n#3 /var/www/owncloud/lib/private/Files/Storage/Wrapper/Wrapper.php(602): OC\Files\Storage\Wrapper\Wrapper->releaseLock(‘BP/Businessplan…’, 1, Object(OC\Lock\MemcacheLockingProvider))\n#4 /var/www/owncloud/lib/private/Files/Storage/Wrapper/Wrapper.php(602): OC\Files\Storage\Wrapper\Wrapper->releaseLock(‘xx/xxxxxxxxx…’, 1, Object(OC\Lock\MemcacheLockingProvider))\n#5 /var/www/owncloud/lib/private/Files/View in /var/www/owncloud/apps/files_external/lib/Lib/Storage/SMB.php on line 115

Server logfile: ownCloud log (data/owncloud.log):

{“reqId”:“d177f3a7-9736-4a8c-9775-8278e74f61a2”,“level”:4,“time”:“2019-09-16T13:57:31+00:00”,“remoteAddr”:“xxxxxxxxxxxx”,“user”:“xxxxxxxxx”,“app”:“webdav”,“method”:“GET”,“url”:"/remote.php/dav/files/xxxxxxxxxx/Axxxxxa%20xx-xx/Linkpartner/xxxxxx",“message”:“Exception: Can not decrypt this file, probably this is a shared file. Please ask the file owner to reshare the file with you.: {“Exception”:“OC\\Encryption\\Exceptions\\DecryptionFailedException”,“Message”:“Can not decrypt this file, probably this is a shared file. Please ask the file owner to reshare the file with you.”,“Code”:0,“Trace”:”#0 \/var\/www\/owncloud\/lib\/private\/Files\/Stream\/Encryption.php(454): OCA\\Encryption\\Crypto\\Encryption->decrypt(*** sensitive parameters replaced ***)\n#1 \/var\/www\/owncloud\/lib\/private\/Files\/Stream\/Encryption.php(289): OC\\Files\\Stream\\Encryption->readCache()\n#2 [internal function]: OC\\Files\\Stream\\Encryption->stream_read(8192)\n#3 \/var\/www\/owncloud\/apps\/files_external\/3rdparty\/icewind\/streams\/src\/Wrapper.php(83): fread(Resource id #77, 8192)\n#4 \/var\/www\/owncloud\/apps\/files_external\/3rdparty\/icewind\/streams\/src\/CallbackWrapper.php(91): Icewind\\Streams\\Wrapper->stream_read(8192)\n#5 [internal function]: Icewind\\Streams\\CallbackWrapper->stream_read(8192)\n#6 \/var\/www\/owncloud\/lib\/composer\/sabre\/http\/lib\/Sapi.php(80): stream_copy_to_stream(Resource id #80, Resource id #82, ‘26308’)\n#7 \/var\/www\/owncloud\/lib\/composer\/sabre\/dav\/lib\/DAV\/Server.php(498): Sabre\\HTTP\\Sapi::sendResponse(Object(Sabre\\HTTP\\Response))\n#8 \/var\/www\/owncloud\/lib\/composer\/sabre\/dav\/lib\/DAV\/Server.php(254): Sabre\\DAV\\Server->invokeMethod(Object(Sabre\\HTTP\\Request), Object(Sabre\\HTTP\\Response))\n#9 \/var\/www\/owncloud\/apps\/dav\/lib\/Server.php(294): Sabre\\DAV\\Server->exec()\n#10 \/var\/www\/owncloud\/apps\/dav\/appinfo\/v2\/remote.php(31): OCA\\DAV\\Server->exec()\n#11 \/var\/www\/owncloud\/remote.php(165): require_once(’\/var\/www\/ownclo…’)\n#12 {main}",“File”:"\/var\/www\/owncloud\/apps\/encryption\/lib\/Crypto\/Encryption.php",“Line”:366}"}

cdamken · September 16, 2019, 11:09pm

Your log files says:

{“reqId”:“d177f3a7-9736-4a8c-9775-8278e74f61a2”,“level”:4,“time”:“2019-09-16T13:57:31+00:00”,“remoteAddr”:“xxxxxxxxxxxx”,“user”:“xxxxxxxxx”,“app”:“webdav”,“method”:“GET”,“url”:"/remote.php/dav/files/xxxxxxxxxx/Axxxxxa%20xx-xx/Linkpartner/xxxxxx",“message”:“Exception: Can not decrypt this file, probably this is a shared file. Please ask the file owner to reshare the file with you.: {“Exception”:“OC\Encryption\Exceptions\DecryptionFailedException”,“Message”:“Can not decrypt this file, probably this is a shared file. Please ask the file owner to reshare the file with you.”,“Code”:0,“Trace”:”
#0 /var/www/owncloud/lib/private/Files/Stream/Encryption.php(454): OCA\Encryption\Crypto\Encryption->decrypt(*** sensitive parameters replaced ***)
#1 /var/www/owncloud/lib/private/Files/Stream/Encryption.php(289): OC\Files\Stream\Encryption->readCache()
#2 [internal function]: OC\Files\Stream\Encryption->stream_read(8192)
#3 /var/www/owncloud/apps/files_external/3rdparty/icewind/streams/src/Wrapper.php(83): fread(Resource id #77, 8192)
#4 /var/www/owncloud/apps/files_external/3rdparty/icewind/streams/src/CallbackWrapper.php(91): Icewind\Streams\Wrapper->stream_read(8192)
#5 [internal function]: Icewind\Streams\CallbackWrapper->stream_read(8192)
#6 /var/www/owncloud/lib/composer/sabre/http/lib/Sapi.php(80): stream_copy_to_stream(Resource id #80, Resource id #82, ‘26308’)
#7 /var/www/owncloud/lib/composer/sabre/dav/lib/DAV/Server.php(498): Sabre\HTTP\Sapi::sendResponse(Object(Sabre\HTTP\Response))
#8 /var/www/owncloud/lib/composer/sabre/dav/lib/DAV/Server.php(254): Sabre\DAV\Server->invokeMethod(Object(Sabre\HTTP\Request), Object(Sabre\HTTP\Response))
#9 /var/www/owncloud/apps/dav/lib/Server.php(294): Sabre\DAV\Server->exec()
#10 /var/www/owncloud/apps/dav/appinfo/v2/remote.php(31): OCA\DAV\Server->exec()
#11 /var/www/owncloud/remote.php(165): require_once(’/var/www/ownclo…’)
#12 {main}",“File”:"/var/www/owncloud/apps/encryption/lib/Crypto/Encryption.php",“Line”:366}"}

That means you are user-based encryption and the person who shared something with you (probably you were added to a group) have to reshare with you again.

The second log is with an our of difference:

[Mon Sep 16 15:55:50.732491 2019]
[php7:error]
[pid 13799]
[client ----------------:5185]
PHP Fatal error: Uncaught Error: Call to a member function getName() on null in /var/www/owncloud/apps/files_external/lib/Lib/Storage/SMB.php:115
Stack trace:
#0 /var/www/owncloud/lib/private/Files/Storage/Common.php(671): OCA\Files_External\Lib\Storage\SMB->getId()
#1 /var/www/owncloud/lib/private/Files/Storage/Wrapper/Wrapper.php(602): OC\Files\Storage\Common->releaseLock(‘xx/xxxxxxxxxx…’, 1, Object(OC\Lock\MemcacheLockingProvider))
#2 /var/www/owncloud/lib/private/Files/Storage/Wrapper/Wrapper.php(602): OC\Files\Storage\Wrapper\Wrapper->releaseLock(‘BP/Businessplan…’, 1, Object(OC\Lock\MemcacheLockingProvider))
#3 /var/www/owncloud/lib/private/Files/Storage/Wrapper/Wrapper.php(602): OC\Files\Storage\Wrapper\Wrapper->releaseLock(‘BP/Businessplan…’, 1, Object(OC\Lock\MemcacheLockingProvider))
#4 /var/www/owncloud/lib/private/Files/Storage/Wrapper/Wrapper.php(602): OC\Files\Storage\Wrapper\Wrapper->releaseLock(‘xx/xxxxxxxxx…’, 1, Object(OC\Lock\MemcacheLockingProvider))
#5 /var/www/owncloud/lib/private/Files/View in /var/www/owncloud/apps/files_external/lib/Lib/Storage/SMB.php on line 115

This looks like the file is used from another user, probably modified and that’s why the Memcache locks the file and The Uncaught Error, here probably means that is an error getting the credentials: https://github.com/owncloud/core/blob/v10.2.1/apps/files_external/lib/Lib/Storage/SMB.php#L115

Are other users getting the same information? Do you have Redis configured?

Greets,
Carlos

Matt_Gott · September 18, 2019, 12:05pm

Hey Carlos,

yes, other users get the same erros during Win10 Client sync.
The decryption error i see in the web clients as well. But after waiting some seconds and clicking through directorys the same file can decrypted and displayed (with PDF Viewer Plugin).

I acivated the serverside encryption with default encryption module.
Encryption type: Master Key

There are no shared directory or files (with OC Sharing feature).
I only created six external SMB/CFIS connections und six user groups and put user to these groups.
On each CFIS share i put the corresponding group to “available for”.

It seems it is a load or locking issue. But i dont know how to fix it.
Or is it nessesary to share the external storage (CFIS) again with a group oder user?

I´ve configured redis and Memcache.

owncloud/config/config.php:

  'memcache.local' => '\OC\Memcache\Redis',
    'redis' => [
             'host' => 'localhost',
             'port' => 6379,
               ],
  'memcache.locking' => '\OC\Memcache\Redis',

/var/log/redis/redis-server.log:

9078:C 18 Sep 13:51:58.053 * RDB: 0 MB of memory used by copy-on-write
925:M 18 Sep 13:51:58.150 * Background saving terminated with success
925:M 18 Sep 13:56:59.062 * 10 changes in 300 seconds. Saving...
925:M 18 Sep 13:56:59.063 * Background saving started by pid 10790
10790:C 18 Sep 13:56:59.066 * DB saved on disk
10790:C 18 Sep 13:56:59.066 * RDB: 0 MB of memory used by copy-on-write
925:M 18 Sep 13:56:59.163 * Background saving terminated with success
925:M 18 Sep 14:02:00.091 * 10 changes in 300 seconds. Saving...
925:M 18 Sep 14:02:00.091 * Background saving started by pid 12469
12469:C 18 Sep 14:02:00.094 * DB saved on disk
12469:C 18 Sep 14:02:00.094 * RDB: 0 MB of memory used by copy-on-write
925:M 18 Sep 14:02:00.192 * Background saving terminated with success
925:M 18 Sep 14:07:01.013 * 10 changes in 300 seconds. Saving...
925:M 18 Sep 14:07:01.014 * Background saving started by pid 14205
14205:C 18 Sep 14:07:01.016 * DB saved on disk
14205:C 18 Sep 14:07:01.017 * RDB: 0 MB of memory used by copy-on-write
925:M 18 Sep 14:07:01.114 * Background saving terminated with success