Files homepage only "Some of the configured external mount points are not connected." (mobile app&sync work)

icebrian · May 4, 2019, 10:15pm

Update: So issue is still present. Just wanted to add that if I right click on external storage and open in a new windows, then I can browser my external storage just fine, it’s just opening directly on the homepage that is not possible.

Not sure if issue is reproducible or not as I have not been able to solve it. Basically, I was on a new computer syncing directories from an SMB external storage, as I have done previsouly, on my working owncloud installation.

There was one file in particular that was always getting an invalid checksum error, so I tried via the web interface to rename the file to something else. This operation failed with a (if not mistaken) “file is in use”. After this error the web interafce was no longer able to access the external storage and shows a red line over the storage and a “Some of the configured external mount points are not connected. Please click on the red row(s) for more information” message.

If I access the Settings, my SMB share show’s up as green. If I test via any other method, I am able to connect to the SMB share. Also, syncronization and mobile app is still working exactly as before and if I login with a diferent user, with whom the external storage is shared, the storage is accessible and working as expected.

This allows me to conclude that there is nothing wrong with the SMB share, or the External Storage configuration, but something in specific happened to my user that when accessing via the web interface is always reporting the storage as inacessible.

Expected behaviour

External storage share should be accessible via the web interface.

Actual behaviour

I get a “Some of the configured external mount points are not connected. Please click on the red row(s) for more information” when SMB shares is working just fine, mobile app works just fine, and any other user with access to same external storage, also works just fine.

Server configuration

Operating system: Debian 9.9

Web server: nginx 1.10.3-1

Database: mysql 10.1.38

PHP version: 7.0.33

ownCloud version: 10.0.10

Updated from an older ownCloud or fresh install: updated from 10.0.9

Where did you install ownCloud from:

Signing status (ownCloud 9.0 and above):

Login as admin user into your ownCloud and access 
http://example.com/index.php/settings/integrity/failed 
paste the results into https://gist.github.com/ and puth the link here.

No errors have been found.

The content of config/config.php:

``
If you have access to your command line run e.g.:
sudo -u www-data php occ config:list system
from within your ownCloud installation folder

{
“system”: {
“instanceid”: “oc3f5t7a9fff”,
“passwordsalt”: “REMOVED SENSITIVE VALUE”,
“secret”: “REMOVED SENSITIVE VALUE”,
“trusted_domains”: [
“mydomain”
],
“datadirectory”: “/var/www/owncloud/data”,
“overwrite.cli.url”: “https://mydomain/owncloud”,
“dbtype”: “mysql”,
“version”: “10.0.10.4”,
“dbname”: “owncloud”,
“dbhost”: “localhost”,
“dbtableprefix”: “oc_”,
“mysql.utf8mb4”: true,
“dbuser”: “REMOVED SENSITIVE VALUE”,
“dbpassword”: “REMOVED SENSITIVE VALUE”,
“logtimezone”: “UTC”,
“installed”: true,
“memcache.local”: “\OC\Memcache\Redis”,
“redis”: {
“host”: “/var/run/redis/redis.sock”,
“port”: 0,
“dbindex”: 0
},
“memcache.locking”: “\OC\Memcache\Redis”,
“mail_domain”: “REMOVED SENSITIVE VALUE”,
“mail_from_address”: “REMOVED SENSITIVE VALUE”,
“mail_smtpmode”: “smtp”,
“mail_smtpauthtype”: “LOGIN”,
“mail_smtpauth”: 1,
“mail_smtphost”: “REMOVED SENSITIVE VALUE”,
“mail_smtpport”: “465”,
“mail_smtpname”: “REMOVED SENSITIVE VALUE”,
“mail_smtppassword”: “REMOVED SENSITIVE VALUE”,
“mail_smtpsecure”: “ssl”,
“loglevel”: 2,
“maintenance”: false,
“updater.secret”: “REMOVED SENSITIVE VALUE”
}
}
List of activated apps:

If you have access to your command line run e.g.:
sudo -u www-data php occ app:list
from within your ownCloud installation folder.

Enabled:

configreport: 0.1.1
dav: 0.4.0
federatedfilesharing: 0.3.1
files: 1.5.1
files_external: 0.7.1
files_pdfviewer: 0.11.0
files_sharing: 0.11.0
files_trashbin: 0.9.1
files_versions: 1.3.0
files_videoplayer: 0.9.8
gallery: 16.1.1
market: 0.2.5
notifications: 0.3.5
passman: 2.1.4
provisioning_api: 0.5.0
systemtags: 0.3.0
updatenotification: 0.2.1

Are you using external storage, if yes which one: local/smb/sftp/…
Yes, SMB

Are you using encryption: yes/no
yes

Client configuration

Browser: Chrom, Firefox and Edge

Operating system: Windows

Logs

Web server error log

Nothing logged besides access log when error ocurrs

ownCloud log (data/owncloud.log)

{"reqId":"AV1Esm6DpN1nkuDlNOOD","level":3,"time":"2019-05-04T20:32:46+00:00","remoteAddr":"192.168.1.229","user":"myuser","app":"files_external","method":"PUT","url":"\/owncloud\/apps\/files_external\/globalstorages\/1","message":"Exception: {\"Exception\":\"OCP\\\\Files\\\\StorageNotAvailableException\",\"Message\":\"\\\/\",\"Code\":113,\"Trace\":\"#0 \\\/var\\\/www\\\/owncloud\\\/apps\\\/files_external\\\/lib\\\/Lib\\\/Storage\\\/SMB.php(321): OCA\\\\Files_External\\\\Lib\\\\Storage\\\\SMB->getFileInfo('\\\/')\\n#1 \\\/var\\\/www\\\/owncloud\\\/lib\\\/private\\\/Files\\\/Storage\\\/Common.php(440): OCA\\\\Files_External\\\\Lib\\\\Storage\\\\SMB->stat('')\\n#2 \\\/var\\\/www\\\/owncloud\\\/apps\\\/files_external\\\/lib\\\/Lib\\\/Storage\\\/SMB.php(713): OC\\\\Files\\\\Storage\\\\Common->test()\\n#3 \\\/var\\\/www\\\/owncloud\\\/lib\\\/private\\\/Files\\\/External\\\/LegacyUtil.php(205): OCA\\\\Files_External\\\\Lib\\\\Storage\\\\SMB->test(false, true)\\n#4 \\\/var\\\/www\\\/owncloud\\\/apps\\\/files_external\\\/lib\\\/Controller\\\/StoragesController.php(254): OC\\\\Files\\\\External\\\\LegacyUtil::getBackendStatus('\\\\\\\\OCA\\\\\\\\Files_Exte...', Array, false, true)\\n#5 \\\/var\\\/www\\\/owncloud\\\/apps\\\/files_external\\\/lib\\\/Controller\\\/GlobalStoragesController.php(186): OCA\\\\Files_External\\\\Controller\\\\StoragesController->updateStorageStatus(Object(OC\\\\Files\\\\External\\\\StorageConfig), true)\\n#6 \\\/var\\\/www\\\/owncloud\\\/lib\\\/private\\\/AppFramework\\\/Http\\\/Dispatcher.php(153): OCA\\\\Files_External\\\\Controller\\\\GlobalStoragesController->update(1, 'storage', 'smb', 'password::passw...', Array, Array, Array, Array, 100, true)\\n#7 \\\/var\\\/www\\\/owncloud\\\/lib\\\/private\\\/AppFramework\\\/Http\\\/Dispatcher.php(85): OC\\\\AppFramework\\\\Http\\\\Dispatcher->executeController(Object(OCA\\\\Files_External\\\\Controller\\\\GlobalStoragesController), 'update')\\n#8 \\\/var\\\/www\\\/owncloud\\\/lib\\\/private\\\/AppFramework\\\/App.php(100): OC\\\\AppFramework\\\\Http\\\\Dispatcher->dispatch(Object(OCA\\\\Files_External\\\\Controller\\\\GlobalStoragesController), 'update')\\n#9 \\\/var\\\/www\\\/owncloud\\\/lib\\\/private\\\/AppFramework\\\/Routing\\\/RouteActionHandler.php(46): OC\\\\AppFramework\\\\App::main('OCA\\\\\\\\Files_Exter...', 'update', Object(OC\\\\AppFramework\\\\DependencyInjection\\\\DIContainer), Array)\\n#10 \\\/var\\\/www\\\/owncloud\\\/lib\\\/private\\\/Route\\\/Router.php(342): OC\\\\AppFramework\\\\Routing\\\\RouteActionHandler->__invoke(Array)\\n#11 \\\/var\\\/www\\\/owncloud\\\/lib\\\/base.php(909): OC\\\\Route\\\\Router->match('\\\/apps\\\/files_ext...')\\n#12 \\\/var\\\/www\\\/owncloud\\\/index.php(54): OC::handleRequest()\\n#13 {main}\",\"File\":\"\\\/var\\\/www\\\/owncloud\\\/apps\\\/files_external\\\/lib\\\/Lib\\\/Storage\\\/SMB.php\",\"Line\":175}"}

jvillafanez · May 8, 2019, 8:00am

Log says “StorageNotAvailableException”. The code 113 implies a “no route to host” error.
It seems you have an unstable connection, or maybe the SMB server can only handle one connection at a time.

icebrian · May 8, 2019, 6:22pm

Thanks for your reply, however I don’t think that is the case. The host is accessible and working, in fact sync is still working as expected and as before. If for example I change the working directory by changing the “dir” option in the url to something such as “?dir=/storage/Backups” I can navigate just fine. The issue is only present when at the “?dir=/” level and only for a specifc user.

If I test additional connections via SMB, via more phones, etc, there are no problems. My SMB server is on a QNAP NAS with 5 HDD’s in a RAID 5 configuration.

My set-up has been with this NAS and OwnCloud for years now. The only diference is that initially I ran owncloud on the NAS itself, but due to lack of upgrades I eventually moved Owncloud over to a raspberrypi in order to control things more closely.

Never had any issues for over 1 or 2 years up till now. I am still convinved this is some sort of cache error. Something that owncloud stored somewhere and because of that is still identifying the external storage as inacessible, when I know for a fact that is not true.

jvillafanez · May 9, 2019, 7:25am

If you can reproduce the issue consistently, you can try to enable more logs: set the log level to debug and include the smb.logging.enable => true in the config.php file. Note that it will generate lot of logs, so it isn’t recommended to have it enabled for a long time.

In any case, if the error is still a “no route to host”, I don’t think ownCloud can do anything about it. It’s the underlying library the one that it’s reporting the error, so either the libsmbclient library has a bug, or the SMB server is reporting a wrong error, or there is another component causing problems.

icebrian · May 9, 2019, 1:46pm

Once again thanks! I’ve added SMB logging and enabled debug level.

After that I saved all the log output when reloading the Files Homepage in Owncloud webinterface. In turn I also disabled any sync clients and left the webpage open for a while as it seems there are regular writes to the log.

You can access the log here: https://gist.github.com/icebrian/f422ae35f00e361e81dc3243857efc92

Can you see anything relevant in the logs?

jvillafanez · May 10, 2019, 6:57am

Just a couple of things:

It seems you’re using the wrapped connector. It’s highly recommended to use the native one. You’ll need to install the php-libsmbclient library and make sure it’s usable from both the web server and cli.
```
{"reqId":"DibZMPxS0Ex9CRwFwphM","level":0,"time":"2019-05-09T13:30:47+00:00","remoteAddr":"192.168.1.229","user":"icebrian","app":"smb","method":"PROPFIND","url":"\/owncloud\/remote.php\/webdav\/","message":"using Icewind\\SMB\\Wrapped\\Share for the connection"}
```
That entry will change, so it should be easy to know if you’re using the native connector or not.
I don’t see you’re accessing to the storage. Maybe you’re using cached information. Try making a change inside the SMB server, in the folder that is mapped as root in ownCloud.

icebrian · May 10, 2019, 11:08am

Have broken down my reply in a series of tests.

So after adding the php-smbclient, I then proceeded to refresh the Files homepage and this is the log output:

gist.github.com

https://gist.github.com/icebrian/9eda95394f3778ce20fac69708bba1ea

Files homepage refresh

{"reqId":"e09fWGQJ5OIkrfuQULkj","level":0,"time":"2019-05-10T10:31:08+00:00","remoteAddr":"167.220.197.125","user":"icebrian","app":"OC\\User\\Session::validateToken","method":"GET","url":"\/owncloud\/apps\/files\/?dir=\/&fileid=3","message":"token 3f0b8ea87f264ecb17f53a8fa181cde07b82b2ea0f1304b58782d9d4740a52420949329734ebc63bae18f94c7c65d562472efc5a7f867f4b67dd17ff0f5ff3c3 with token id 1891 found, validating"}
{"reqId":"e09fWGQJ5OIkrfuQULkj","level":0,"time":"2019-05-10T10:31:08+00:00","remoteAddr":"167.220.197.125","user":"icebrian","app":"OC\\User\\Session::validateToken","method":"GET","url":"\/owncloud\/apps\/files\/?dir=\/&fileid=3","message":"token 3f0b8ea87f264ecb17f53a8fa181cde07b82b2ea0f1304b58782d9d4740a52420949329734ebc63bae18f94c7c65d562472efc5a7f867f4b67dd17ff0f5ff3c3 with token id 1891 found, validating"}
{"reqId":"e09fWGQJ5OIkrfuQULkj","level":0,"time":"2019-05-10T10:31:08+00:00","remoteAddr":"167.220.197.125","user":"icebrian","app":"OC\\User\\Session::validateToken","method":"GET","url":"\/owncloud\/apps\/files\/?dir=\/&fileid=3","message":"token 3f0b8ea87f264ecb17f53a8fa181cde07b82b2ea0f1304b58782d9d4740a52420949329734ebc63bae18f94c7c65d562472efc5a7f867f4b67dd17ff0f5ff3c3 with token id 1891 found, validating"}
{"reqId":"e09fWGQJ5OIkrfuQULkj","level":0,"time":"2019-05-10T10:31:08+00:00","remoteAddr":"167.220.197.125","user":"icebrian","app":"smb","method":"GET","url":"\/owncloud\/apps\/files\/?dir=\/&fileid=3","message":"enter: __construct({\"host\":\"192.168.1.50\",\"share\":\"storage\",\"root\":\"\",\"domain\":\"\",\"user\":\"icebrian\",\"password\":\"***removed***\"})"}
{"reqId":"e09fWGQJ5OIkrfuQULkj","level":0,"time":"2019-05-10T10:31:08+00:00","remoteAddr":"167.220.197.125","user":"icebrian","app":"smb","method":"GET","url":"\/owncloud\/apps\/files\/?dir=\/&fileid=3","message":"using Icewind\\SMB\\Native\\NativeShare for the connection"}
{"reqId":"e09fWGQJ5OIkrfuQULkj","level":0,"time":"2019-05-10T10:31:08+00:00","remoteAddr":"167.220.197.125","user":"icebrian","app":"smb","method":"GET","url":"\/owncloud\/apps\/files\/?dir=\/&fileid=3","message":"leave: __construct, getId:smb::icebrian@192.168.1.50\/\/storage\/\/"}
{"reqId":"9QbBFNPdypzQtS67MwUm","level":0,"time":"2019-05-10T10:31:08+00:00","remoteAddr":"167.220.197.125","user":"icebrian","app":"OC\\User\\Session::validateToken","method":"GET","url":"\/owncloud\/apps\/files\/?dir=\/","message":"token 3f0b8ea87f264ecb17f53a8fa181cde07b82b2ea0f1304b58782d9d4740a52420949329734ebc63bae18f94c7c65d562472efc5a7f867f4b67dd17ff0f5ff3c3 with token id 1891 found, validating"}
{"reqId":"9QbBFNPdypzQtS67MwUm","level":0,"time":"2019-05-10T10:31:08+00:00","remoteAddr":"167.220.197.125","user":"icebrian","app":"OC\\User\\Session::validateToken","method":"GET","url":"\/owncloud\/apps\/files\/?dir=\/","message":"token 3f0b8ea87f264ecb17f53a8fa181cde07b82b2ea0f1304b58782d9d4740a52420949329734ebc63bae18f94c7c65d562472efc5a7f867f4b67dd17ff0f5ff3c3 with token id 1891 found, validating"}
{"reqId":"9QbBFNPdypzQtS67MwUm","level":0,"time":"2019-05-10T10:31:08+00:00","remoteAddr":"167.220.197.125","user":"icebrian","app":"OC\\User\\Session::validateToken","method":"GET","url":"\/owncloud\/apps\/files\/?dir=\/","message":"token 3f0b8ea87f264ecb17f53a8fa181cde07b82b2ea0f1304b58782d9d4740a52420949329734ebc63bae18f94c7c65d562472efc5a7f867f4b67dd17ff0f5ff3c3 with token id 1891 found, validating"}
{"reqId":"9QbBFNPdypzQtS67MwUm","level":0,"time":"2019-05-10T10:31:08+00:00","remoteAddr":"167.220.197.125","user":"icebrian","app":"smb","method":"GET","url":"\/owncloud\/apps\/files\/?dir=\/","message":"enter: __construct({\"host\":\"192.168.1.50\",\"share\":\"storage\",\"root\":\"\",\"domain\":\"\",\"user\":\"icebrian\",\"password\":\"***removed***\"})"}

This file has been truncated. show original

As you can see, the message now referes to the Native client, however issue is still present.

In regards to accessing the storage, the reason I didn’t was because, when trying to do so via the File Homepage I simply get a pop-up with the message “There was an error with message: Empty response from the server. Do you want to review mount point config in admin settings page?” and a YES/NO possiblity. During the click/operation, no log is generated.Here is a screenshot:

To try and log myself accessing the storage, what I did was, right click on the External Storage and selected “Open in a New Tab”. When I do this, I am once again able to browse the storage. If I do so here is the log output:

gist.github.com

https://gist.github.com/icebrian/4933864b5d8f74b7768361ef62988456

Storage Navigating

{"reqId":"W7ynuo4ScqNZgxA5yGhm","level":0,"time":"2019-05-10T10:34:23+00:00","remoteAddr":"167.220.197.125","user":"icebrian","app":"OC\\User\\Session::validateToken","method":"GET","url":"\/owncloud\/index.php\/apps\/files?dir=\/\/storage","message":"token 3f0b8ea87f264ecb17f53a8fa181cde07b82b2ea0f1304b58782d9d4740a52420949329734ebc63bae18f94c7c65d562472efc5a7f867f4b67dd17ff0f5ff3c3 with token id 1891 found, validating"}
{"reqId":"W7ynuo4ScqNZgxA5yGhm","level":0,"time":"2019-05-10T10:34:23+00:00","remoteAddr":"167.220.197.125","user":"icebrian","app":"OC\\User\\Session::validateToken","method":"GET","url":"\/owncloud\/index.php\/apps\/files?dir=\/\/storage","message":"token 3f0b8ea87f264ecb17f53a8fa181cde07b82b2ea0f1304b58782d9d4740a52420949329734ebc63bae18f94c7c65d562472efc5a7f867f4b67dd17ff0f5ff3c3 with token id 1891 found, validating"}
{"reqId":"W7ynuo4ScqNZgxA5yGhm","level":0,"time":"2019-05-10T10:34:23+00:00","remoteAddr":"167.220.197.125","user":"icebrian","app":"OC\\User\\Session::validateToken","method":"GET","url":"\/owncloud\/index.php\/apps\/files?dir=\/\/storage","message":"token 3f0b8ea87f264ecb17f53a8fa181cde07b82b2ea0f1304b58782d9d4740a52420949329734ebc63bae18f94c7c65d562472efc5a7f867f4b67dd17ff0f5ff3c3 with token id 1891 found, validating"}
{"reqId":"W7ynuo4ScqNZgxA5yGhm","level":0,"time":"2019-05-10T10:34:23+00:00","remoteAddr":"167.220.197.125","user":"icebrian","app":"smb","method":"GET","url":"\/owncloud\/index.php\/apps\/files?dir=\/\/storage","message":"enter: __construct({\"host\":\"192.168.1.50\",\"share\":\"storage\",\"root\":\"\",\"domain\":\"\",\"user\":\"icebrian\",\"password\":\"***removed***\"})"}
{"reqId":"W7ynuo4ScqNZgxA5yGhm","level":0,"time":"2019-05-10T10:34:23+00:00","remoteAddr":"167.220.197.125","user":"icebrian","app":"smb","method":"GET","url":"\/owncloud\/index.php\/apps\/files?dir=\/\/storage","message":"using Icewind\\SMB\\Native\\NativeShare for the connection"}
{"reqId":"W7ynuo4ScqNZgxA5yGhm","level":0,"time":"2019-05-10T10:34:23+00:00","remoteAddr":"167.220.197.125","user":"icebrian","app":"smb","method":"GET","url":"\/owncloud\/index.php\/apps\/files?dir=\/\/storage","message":"leave: __construct, getId:smb::icebrian@192.168.1.50\/\/storage\/\/"}
{"reqId":"rzRGGomQIKcTVScPCRKX","level":0,"time":"2019-05-10T10:34:23+00:00","remoteAddr":"167.220.197.125","user":"icebrian","app":"OC\\User\\Session::validateToken","method":"GET","url":"\/owncloud\/core\/js\/oc.js?v=c4ffe6f204ac9a7c81d0a27afec18752","message":"token 3f0b8ea87f264ecb17f53a8fa181cde07b82b2ea0f1304b58782d9d4740a52420949329734ebc63bae18f94c7c65d562472efc5a7f867f4b67dd17ff0f5ff3c3 with token id 1891 found, validating"}
{"reqId":"rzRGGomQIKcTVScPCRKX","level":0,"time":"2019-05-10T10:34:23+00:00","remoteAddr":"167.220.197.125","user":"icebrian","app":"OC\\User\\Session::validateToken","method":"GET","url":"\/owncloud\/core\/js\/oc.js?v=c4ffe6f204ac9a7c81d0a27afec18752","message":"token 3f0b8ea87f264ecb17f53a8fa181cde07b82b2ea0f1304b58782d9d4740a52420949329734ebc63bae18f94c7c65d562472efc5a7f867f4b67dd17ff0f5ff3c3 with token id 1891 found, validating"}
{"reqId":"rzRGGomQIKcTVScPCRKX","level":0,"time":"2019-05-10T10:34:23+00:00","remoteAddr":"167.220.197.125","user":"icebrian","app":"OC\\User\\Session::validateToken","method":"GET","url":"\/owncloud\/core\/js\/oc.js?v=c4ffe6f204ac9a7c81d0a27afec18752","message":"token 3f0b8ea87f264ecb17f53a8fa181cde07b82b2ea0f1304b58782d9d4740a52420949329734ebc63bae18f94c7c65d562472efc5a7f867f4b67dd17ff0f5ff3c3 with token id 1891 found, validating"}
{"reqId":"rzRGGomQIKcTVScPCRKX","level":0,"time":"2019-05-10T10:34:24+00:00","remoteAddr":"167.220.197.125","user":"icebrian","app":"smb","method":"GET","url":"\/owncloud\/core\/js\/oc.js?v=c4ffe6f204ac9a7c81d0a27afec18752","message":"enter: __construct({\"host\":\"192.168.1.50\",\"share\":\"storage\",\"root\":\"\",\"domain\":\"\",\"user\":\"icebrian\",\"password\":\"***removed***\"})"}

This file has been truncated. show original

I then tested adding files, first creating a new file on a client machine, my own Windows machine name “New Text Document.txt”, here are two output, the log file first then the screenshot:

gist.github.com

https://gist.github.com/icebrian/8cf9ad242e10453e56f80f5603d3a023

New File on Remote Machine (sync via client)

{"reqId":"e8935924-5693-4776-ac1f-6050f6427d8f","level":0,"time":"2019-05-10T10:37:09+00:00","remoteAddr":"167.220.197.125","user":"icebrian","app":"OC\\Authentication\\Token\\DefaultTokenProvider::updateToken","method":"PROPFIND","url":"\/owncloud\/remote.php\/dav\/files\/icebrian\/","message":"updating token 1897, last check is now 1557482166"}
{"reqId":"e8935924-5693-4776-ac1f-6050f6427d8f","level":0,"time":"2019-05-10T10:37:09+00:00","remoteAddr":"167.220.197.125","user":"icebrian","app":"OC\\Authentication\\Token\\DefaultTokenProvider::getToken","method":"PROPFIND","url":"\/owncloud\/remote.php\/dav\/files\/icebrian\/","message":"token 64234499f056b12ac02dd41dc6211dde8135aba71b8931ab1d913bfc1a2c581effc4e8367660aecea59d88e1ba710ca9ae2bbf585bc914c3169f67db2a0f9f91 does not exist"}
{"reqId":"e8935924-5693-4776-ac1f-6050f6427d8f","level":0,"time":"2019-05-10T10:37:09+00:00","remoteAddr":"167.220.197.125","user":"icebrian","app":"smb","method":"PROPFIND","url":"\/owncloud\/remote.php\/dav\/files\/icebrian\/","message":"enter: __construct({\"host\":\"192.168.1.50\",\"share\":\"storage\",\"root\":\"\",\"domain\":\"\",\"user\":\"icebrian\",\"password\":\"***removed***\"})"}
{"reqId":"e8935924-5693-4776-ac1f-6050f6427d8f","level":0,"time":"2019-05-10T10:37:09+00:00","remoteAddr":"167.220.197.125","user":"icebrian","app":"smb","method":"PROPFIND","url":"\/owncloud\/remote.php\/dav\/files\/icebrian\/","message":"using Icewind\\SMB\\Native\\NativeShare for the connection"}
{"reqId":"e8935924-5693-4776-ac1f-6050f6427d8f","level":0,"time":"2019-05-10T10:37:09+00:00","remoteAddr":"167.220.197.125","user":"icebrian","app":"smb","method":"PROPFIND","url":"\/owncloud\/remote.php\/dav\/files\/icebrian\/","message":"leave: __construct, getId:smb::icebrian@192.168.1.50\/\/storage\/\/"}
{"reqId":"bZMKztTcxxQ1LfAQ2VKn","level":0,"time":"2019-05-10T10:37:09+00:00","remoteAddr":"167.220.197.125","user":"icebrian","app":"OC\\User\\Session::validateToken","method":"GET","url":"\/owncloud\/ocs\/v2.php\/apps\/notifications\/api\/v1\/notifications?format=json","message":"token 3f0b8ea87f264ecb17f53a8fa181cde07b82b2ea0f1304b58782d9d4740a52420949329734ebc63bae18f94c7c65d562472efc5a7f867f4b67dd17ff0f5ff3c3 with token id 1891 found, validating"}
{"reqId":"bZMKztTcxxQ1LfAQ2VKn","level":0,"time":"2019-05-10T10:37:09+00:00","remoteAddr":"167.220.197.125","user":"icebrian","app":"OC\\User\\Session::checkTokenCredentials","method":"GET","url":"\/owncloud\/ocs\/v2.php\/apps\/notifications\/api\/v1\/notifications?format=json","message":"checking credentials for token 3f0b8ea87f264ecb17f53a8fa181cde07b82b2ea0f1304b58782d9d4740a52420949329734ebc63bae18f94c7c65d562472efc5a7f867f4b67dd17ff0f5ff3c3 with token id 1891, last check at 1557484329 was more than 5 min ago"}
{"reqId":"bZMKztTcxxQ1LfAQ2VKn","level":0,"time":"2019-05-10T10:37:09+00:00","remoteAddr":"167.220.197.125","user":"icebrian","app":"OC\\Authentication\\Token\\DefaultTokenProvider::updateToken","method":"GET","url":"\/owncloud\/ocs\/v2.php\/apps\/notifications\/api\/v1\/notifications?format=json","message":"updating token 1891, last check is now 1557484629"}
{"reqId":"bZMKztTcxxQ1LfAQ2VKn","level":0,"time":"2019-05-10T10:37:09+00:00","remoteAddr":"167.220.197.125","user":"icebrian","app":"OC\\Authentication\\Token\\DefaultTokenProvider::updateTokenActivity","method":"GET","url":"\/owncloud\/ocs\/v2.php\/apps\/notifications\/api\/v1\/notifications?format=json","message":"updating activity of token 1891 to 1557484629"}
{"reqId":"bZMKztTcxxQ1LfAQ2VKn","level":0,"time":"2019-05-10T10:37:09+00:00","remoteAddr":"167.220.197.125","user":"icebrian","app":"OC\\User\\Session::validateToken","method":"GET","url":"\/owncloud\/ocs\/v2.php\/apps\/notifications\/api\/v1\/notifications?format=json","message":"token 3f0b8ea87f264ecb17f53a8fa181cde07b82b2ea0f1304b58782d9d4740a52420949329734ebc63bae18f94c7c65d562472efc5a7f867f4b67dd17ff0f5ff3c3 with token id 1891 found, validating"}

This file has been truncated. show original

(unfortunately can add more screenshot, will add in next reply)

As you can see. The file is picked up, synced and then shows up in the webinterface.

I then tested the same, but this time I created the new file directly on the NAS server which is serving the SMB share and again two outputs:

gist.github.com

https://gist.github.com/icebrian/e4a6e3ce848ab0df61cbebd46f70eac9

New File directly on NAS

{"reqId":"c7e9ee15-780c-4653-8a4b-1a123817b1aa","level":0,"time":"2019-05-10T10:51:47+00:00","remoteAddr":"167.220.197.125","user":"icebrian","app":"OC\\Authentication\\Token\\DefaultTokenProvider::updateToken","method":"PROPFIND","url":"\/owncloud\/remote.php\/dav\/files\/icebrian\/storage\/icebrian\/personal","message":"updating token 1897, last check is now 1557482166"}
{"reqId":"c7e9ee15-780c-4653-8a4b-1a123817b1aa","level":0,"time":"2019-05-10T10:51:47+00:00","remoteAddr":"167.220.197.125","user":"icebrian","app":"OC\\Authentication\\Token\\DefaultTokenProvider::getToken","method":"PROPFIND","url":"\/owncloud\/remote.php\/dav\/files\/icebrian\/storage\/icebrian\/personal","message":"token 64234499f056b12ac02dd41dc6211dde8135aba71b8931ab1d913bfc1a2c581effc4e8367660aecea59d88e1ba710ca9ae2bbf585bc914c3169f67db2a0f9f91 does not exist"}
{"reqId":"c7e9ee15-780c-4653-8a4b-1a123817b1aa","level":0,"time":"2019-05-10T10:51:47+00:00","remoteAddr":"167.220.197.125","user":"icebrian","app":"smb","method":"PROPFIND","url":"\/owncloud\/remote.php\/dav\/files\/icebrian\/storage\/icebrian\/personal","message":"enter: __construct({\"host\":\"192.168.1.50\",\"share\":\"storage\",\"root\":\"\",\"domain\":\"\",\"user\":\"icebrian\",\"password\":\"***removed***\"})"}
{"reqId":"c7e9ee15-780c-4653-8a4b-1a123817b1aa","level":0,"time":"2019-05-10T10:51:47+00:00","remoteAddr":"167.220.197.125","user":"icebrian","app":"smb","method":"PROPFIND","url":"\/owncloud\/remote.php\/dav\/files\/icebrian\/storage\/icebrian\/personal","message":"using Icewind\\SMB\\Native\\NativeShare for the connection"}
{"reqId":"c7e9ee15-780c-4653-8a4b-1a123817b1aa","level":0,"time":"2019-05-10T10:51:47+00:00","remoteAddr":"167.220.197.125","user":"icebrian","app":"smb","method":"PROPFIND","url":"\/owncloud\/remote.php\/dav\/files\/icebrian\/storage\/icebrian\/personal","message":"leave: __construct, getId:smb::icebrian@192.168.1.50\/\/storage\/\/"}
{"reqId":"c7e9ee15-780c-4653-8a4b-1a123817b1aa","level":0,"time":"2019-05-10T10:51:47+00:00","remoteAddr":"167.220.197.125","user":"icebrian","app":"smb","method":"PROPFIND","url":"\/owncloud\/remote.php\/dav\/files\/icebrian\/storage\/icebrian\/personal","message":"enter: hasUpdated(icebrian\/personal, 1557485481)"}
{"reqId":"c7e9ee15-780c-4653-8a4b-1a123817b1aa","level":0,"time":"2019-05-10T10:51:47+00:00","remoteAddr":"167.220.197.125","user":"icebrian","app":"smb","method":"PROPFIND","url":"\/owncloud\/remote.php\/dav\/files\/icebrian\/storage\/icebrian\/personal","message":"enter: stat(icebrian\/personal)"}
{"reqId":"c7e9ee15-780c-4653-8a4b-1a123817b1aa","level":0,"time":"2019-05-10T10:51:47+00:00","remoteAddr":"167.220.197.125","user":"icebrian","app":"smb","method":"PROPFIND","url":"\/owncloud\/remote.php\/dav\/files\/icebrian\/storage\/icebrian\/personal","message":"enter: getFileInfo(icebrian\/personal)"}
{"reqId":"c7e9ee15-780c-4653-8a4b-1a123817b1aa","level":0,"time":"2019-05-10T10:51:47+00:00","remoteAddr":"167.220.197.125","user":"icebrian","app":"smb","method":"PROPFIND","url":"\/owncloud\/remote.php\/dav\/files\/icebrian\/storage\/icebrian\/personal","message":"enter: buildPath(icebrian\/personal)"}
{"reqId":"c7e9ee15-780c-4653-8a4b-1a123817b1aa","level":0,"time":"2019-05-10T10:51:47+00:00","remoteAddr":"167.220.197.125","user":"icebrian","app":"smb","method":"PROPFIND","url":"\/owncloud\/remote.php\/dav\/files\/icebrian\/storage\/icebrian\/personal","message":"leave: buildPath, return '\/icebrian\/personal'"}

This file has been truncated. show original

(unfortunately cant add more screenshots with add in second reply after this)

Again, as before, no issue with detecting, syncing and new file being reflected in webinterface.

Any ideas?

icebrian · May 10, 2019, 11:08am

icebrian · May 10, 2019, 11:09am

jvillafanez · May 10, 2019, 1:38pm

I see you’re uploading the file inside the NAS in “/icebrian/personal”. Could you try uploading a file in “/” (wherever that folder is located in the NAS) or “touch” that folder in order to change the mtime?

There is a test being made against the root folder of the external storage, which seems to be failing. That’s why you can’t access to the external storage from the web UI. Hopefully, forcing a change in the external root might recheck again the storage.

icebrian · May 10, 2019, 2:15pm

Before, just wanted to let you know, that I am currently no syncing my entire / or external drive. I have a SMB share, but only sync specific directoris within that share, such as the /icebrian/personal

I however add a new file at / this done directly at the NAS and this was the output:

gist.github.com

https://gist.github.com/icebrian/753cf0e5bc513e16970aa3cb0ec26e2d

NewFile at Root

{"reqId":"mKN9ftlPyRi3wHr6mylS","level":0,"time":"2019-05-10T14:10:11+00:00","remoteAddr":"167.220.197.125","user":"icebrian","app":"smb","method":"PROPFIND","url":"\/owncloud\/remote.php\/webdav\/storage","message":"leave: getFileInfo, return {}"}
{"reqId":"mKN9ftlPyRi3wHr6mylS","level":0,"time":"2019-05-10T14:10:11+00:00","remoteAddr":"167.220.197.125","user":"icebrian","app":"smb","method":"PROPFIND","url":"\/owncloud\/remote.php\/webdav\/storage","message":"leave: filetype, return 'dir'"}
{"reqId":"mKN9ftlPyRi3wHr6mylS","level":0,"time":"2019-05-10T14:10:11+00:00","remoteAddr":"167.220.197.125","user":"icebrian","app":"smb","method":"PROPFIND","url":"\/owncloud\/remote.php\/webdav\/storage","message":"enter: stat(Backups)"}
{"reqId":"mKN9ftlPyRi3wHr6mylS","level":0,"time":"2019-05-10T14:10:11+00:00","remoteAddr":"167.220.197.125","user":"icebrian","app":"smb","method":"PROPFIND","url":"\/owncloud\/remote.php\/webdav\/storage","message":"enter: getFileInfo(Backups)"}
{"reqId":"mKN9ftlPyRi3wHr6mylS","level":0,"time":"2019-05-10T14:10:11+00:00","remoteAddr":"167.220.197.125","user":"icebrian","app":"smb","method":"PROPFIND","url":"\/owncloud\/remote.php\/webdav\/storage","message":"enter: buildPath(Backups)"}
{"reqId":"mKN9ftlPyRi3wHr6mylS","level":0,"time":"2019-05-10T14:10:11+00:00","remoteAddr":"167.220.197.125","user":"icebrian","app":"smb","method":"PROPFIND","url":"\/owncloud\/remote.php\/webdav\/storage","message":"leave: buildPath, return '\/Backups'"}
{"reqId":"mKN9ftlPyRi3wHr6mylS","level":0,"time":"2019-05-10T14:10:11+00:00","remoteAddr":"167.220.197.125","user":"icebrian","app":"smb","method":"PROPFIND","url":"\/owncloud\/remote.php\/webdav\/storage","message":"stat cache hit for '\/Backups'"}
{"reqId":"mKN9ftlPyRi3wHr6mylS","level":0,"time":"2019-05-10T14:10:11+00:00","remoteAddr":"167.220.197.125","user":"icebrian","app":"smb","method":"PROPFIND","url":"\/owncloud\/remote.php\/webdav\/storage","message":"leave: getFileInfo, return {}"}
{"reqId":"mKN9ftlPyRi3wHr6mylS","level":0,"time":"2019-05-10T14:10:11+00:00","remoteAddr":"167.220.197.125","user":"icebrian","app":"smb","method":"PROPFIND","url":"\/owncloud\/remote.php\/webdav\/storage","message":"leave: stat, return {\"size\":0,\"mtime\":1515807636,\"type\":\"dir\"}"}
{"reqId":"mKN9ftlPyRi3wHr6mylS","level":0,"time":"2019-05-10T14:10:11+00:00","remoteAddr":"167.220.197.125","user":"icebrian","app":"smb","method":"PROPFIND","url":"\/owncloud\/remote.php\/webdav\/storage","message":"enter: filetype(NewFile_at_Root.txt)"}

This file has been truncated. show original

I also touched the / dir. In the webinterface I saw my external storage was in state “Pending” then eventually reverted back to the space in use, but issue is unfortunately still present.

jvillafanez · May 14, 2019, 8:19am

Anything special about that SMB server? Could you check with a different SMB server (maybe a windows machine or a samba server)?

icebrian · May 14, 2019, 10:49am

Nothing special about it. It is being served by a QNAP NAS which has been serving the SMB fileserver for over 5 years now, always without a single problem.

Also, this same server is serving other SMB shares without a problem and keep in mind that this same share is available for other owncloud user’s.

I tried addind the same SMB share, with exactly the same configurations, being served by the QNAP NAS, but under s diferente name, so instead of “storage”, under “new_folder” and “new_folder2”, and as you can see in the screenshot, they are fine.

A quick fix will be deleting “storage” external drive and just using one of these new external drives may-be also then changing the name back to “storage” (not sure if issue will re-surface then) but that means that all my shares will be lost and probably having to re-create the sync’s on each client, something I would like to avoid.

Btw, I also tried changing the “storage” external drive name, but issue remains.

jvillafanez · May 14, 2019, 4:01pm

Could you take a screenshot of the mount point configuration in the settings page (just hide any personal information)? I’ll try to reproduce the issue with the same parameters

icebrian · May 14, 2019, 7:58pm

No problem (and thanks for your ongoing and continued support on this!). Basically IP is always the same. Username and Password are the same for “storage”, “new_folder” and “new_folder2”. “martamac” external storage uses diferente user/pass but resides on same NAS and is working as expected.

jvillafanez · May 15, 2019, 7:11am

It’s working for me. The only thing that I can come up with is a strange permission on the share or on the folder. SMB uses ACLs to control access, so maybe the ACL is preventing the user to access to the folder, but the user can access to the contents.

icebrian · May 15, 2019, 9:02am

But I am using the same user/pass for storage, new_folder and new_folder2 external drives. Also, on storage if I right click and open in new tab, I can browser the external drive with no problem. If it where ACL’s I would think that the entire drive would be inacessible and that syncing would not work, or the mobile app, which is not the case.

Also, I think that the only way to try and replicate, would be to try and reproduce the error I had, which would require a file that would fail syncing with an invalid checksum error and on that file one would try to rename via the webinterface. This is basically what I think might have caused this entire issue.

jvillafanez · May 15, 2019, 11:05am

Could you check if there is a concurrent connection limit in the SMB server? (https://forum.qnap.com/viewtopic.php?t=59853)

icebrian · May 15, 2019, 2:57pm

No “max connections” option in my smb.conf file on the QNAP NAS.

icebrian · May 15, 2019, 6:12pm

Well I finally decided to be a but more drastic and simply remove that specific configuration for the “storage” SMB external drive and re-create a new one. This meant re-scanning, re-syncing and re-creating all the shares I previously had created but, even thou it will take a while, the end result is a fixed problem!

This again leads me to conclude that the issue was never SMB related but something in OwnCloud, for that specific external drive configuration, broke. This meant a constant error message even thou there was none. May-be some sort of cache, flag, something that went wrong in the database, un-committed transaction, whatever, but am convinced it was not SMB related.