A Shared folder is not displaying all of the data to users - lots of errors in owncloud log

[gig13]

Steps to reproduce

WIP

Expected behaviour

Sharing a folder with other users should allow all users to see the entire folder. The owner of the data should also be able to view all of the content in the folder via the desktop client, web interface or via mobile apps

Actual behaviour

Most of the content from a shared folder appears to have disappeared when viewing from the web interface, desktop client or via the mobile apps. When checking the ownCloud server, the data still resides in the users directory.

Server configuration

Operating system: Ubuntu -- see config report
https://s3.owncloud.com/owncloud/index.php/apps/files?dir=%2FShared%2Fowncloud%2Fsupport%2Fgithub-issues%2Fcore%2F17640

Web server: Apache 2.2

Database: PostgreSQL

PHP version: 5.4.42

ownCloud version: 8.0.5

Updated from an older ownCloud or fresh install: Updated

List of activated apps: See report config on s3

The content of config/config.php:
see report config on s3

Are you using external storage, if yes which one: NO

Are you using encryption: yes/no

Are you using an external user-backend, if yes which one: OpenLDAP

LDAP configuration

See s3 report config
https://s3.owncloud.com/owncloud/index.php/apps/files?dir=%2FShared%2Fowncloud%2Fsupport%2Fgithub-issues%2Fcore%2F17640

Client configuration

Browser: Internet Explorer

Operating system: Windows

Logs

ownCloud log (data/owncloud.log)

See s3 -- https://s3.owncloud.com/owncloud/index.php/apps/files?dir=%2FShared%2Fowncloud%2Fsupport%2Fgithub-issues%2Fcore%2F17640

Lots of these errors:

{"reqId":"8ebb786130164e097a9912b4cb7f02a8","remoteAddr":"123456789","app":"PHP","message":"Illegal offset type in isset or empty at \/x\/a\/owncloud-8.0.5\/lib\/private\/user\/database.php#184","level":3,"time":"2015-07-14T10:54:38+00:00"}
{"reqId":"8ebb786130164e097a9912b4cb7f02a8","remoteAddr":"123456789","app":"PHP","message":"Array to string conversion at \/x\/a\/owncloud-8.0.5\/apps\/user_ldap\/user_ldap.php#195","level":3,"time":"2015-07-14T10:54:38+00:00"}

[gig13]

@bboule @MorrisJobke

[PVince81]

Do you mean that neither the owner nor the recipients can see the missing files ?

Do the missing files have anything in particular ? Were they more recent ? Or alphabetically at the end of the list while the visible files were at the beginning ?

[gig13]

@PVince81
Yes it is not shown for the share owner and recipients.

Bad directories:

ls -l trusef/
total 44
drwxr-xr-x  2 www-data www-data 4096 Jul 13 14:37 Call Reports - IRS
drwxr-xr-x  2 www-data www-data 4096 Jul 13 14:57 Call Reports - Ldn 
drwxr-xr-x  2 www-data www-data 4096 Jul 13 14:57 HEAT MAP & account details gathered 
drwxr-xr-x  2 www-data www-data 4096 Jul 13 14:45 Infrastructure 
drwxr-xr-x 13 www-data www-data 4096 Jul 13 14:57 Marketing Material 
drwxr-xr-x  3 www-data www-data 4096 Jul 13 15:31 NDAs 
drwxr-xr-x  2 www-data www-data 4096 Jul 13 15:31 Onboarding 
drwxr-xr-x  3 www-data www-data 4096 Jul 13 15:31 Operations
drwxr-xr-x  3 www-data www-data 4096 Jul 13 15:32 Product 
drwxr-xr-x  7 www-data www-data 4096 Jul 13 15:32 Registration and Tech Onboarding docs - Latest 
drwxr-xr-x  4 www-data www-data 4096 Jul 13 14:59 Registration Forms COMPLETED

Good Directories:

ls -la new_truesef/
total 200
drwxr-xr-x 29 www-data www-data  4096 Jun  4 19:11 .
drwxr-xr-x 27 www-data www-data  4096 Jul 14 00:37 ..
-rw-r--r--  1 www-data www-data   883 Aug 19  2014 2014-08-19--12-57-52_christian_argiroff_Book1.csv
drwxr-xr-x  2 www-data www-data  4096 Apr 12 20:42 Account Details TEST 
drwxr-xr-x  4 www-data www-data  4096 Apr 17 21:22 Account History - Sales 
drwxr-xr-x  2 www-data www-data  4096 Apr 12 20:42 Billing 
drwxr-xr-x  3 www-data www-data 32768 Jun 30 21:17 Call Reports - IRS 
drwxr-xr-x  2 www-data www-data  4096 Jun 17 15:41 Call Reports - Ldn 
drwxr-xr-x 25 www-data www-data  4096 Feb 25 14:18 Client Versions and Environments
-rw-r--r--  1 www-data www-data   169 Feb 11  2014 Custom_Routes_Import-NOM.csv
drwxr-xr-x  2 www-data www-data  4096 Jun 17 15:41 DCM - SEF Questionnaire's
-rw-r--r--  1 www-data www-data    47 Mar 20  2014 .dropbox
drwxr-xr-x  2 www-data www-data  4096 Jun 22 17:22 Expenses 
drwxr-xr-x  5 www-data www-data  4096 Mar 25  2014 FIX Gateway Drafts 
drwxr-xr-x  2 www-data www-data  4096 Apr 12 20:42 HEAT MAP & account details gathered 
drwxr-xr-x  2 www-data www-data  4096 Mar 25  2014 Incidents 
drwxr-xr-x 10 www-data www-data  4096 Jun 17 15:41 Infrastructure 
drwxr-xr-x  2 www-data www-data  4096 Apr 12 20:42 Internal Reports 
drwxr-xr-x 28 www-data www-data 12288 Jul  7 16:51 Marketing Material 
drwxr-xr-x  5 www-data www-data  4096 Apr 12 20:43 NDAs 
drwxr-xr-x  2 www-data www-data  4096 Jul  1 15:00 Onboarding 
drwxr-xr-x  4 www-data www-data  4096 Apr 12 20:44 Operations 
drwxr-xr-x  3 www-data www-data  4096 Oct  2  2014 Product 
drwxr-xr-x  2 www-data www-data 20480 Mar 25  2014 ProductXML 
drwxr-xr-x  3 www-data www-data  4096 Apr 12 20:44 Proof of Concept (DCM & PTC)
drwxr-xr-x  2 www-data www-data  4096 Jun  4 19:11 Reg Forms without completed PA's and account details gathered 
drwxr-xr-x 13 www-data www-data  4096 Jun  4 19:13 Registration and Tech Onboarding docs - Latest 
drwxr-xr-x  4 www-data www-data  4096 May  7 12:46 Registration Forms COMPLETED
-rw-r--r--  1 www-data www-data 17780 Oct  1  2013 Smart Ticket Concepts version 2.docx 
drwxr-xr-x  2 www-data www-data  4096 Mar 25  2014 trueEX Org. Chart 
drwxr-xr-x  4 www-data www-data  4096 Feb 19 21:09 trueEX Rules and Protocols 
drwxr-xr-x  2 www-data www-data  4096 Jun 17 16:07 Volume Reports
drwxr-xr-x  2 www-data www-data  4096 Jun 17 16:07 Website Responses

[PVince81]

@gig13 Does it mean the files also disappeared from the server ? So they did not only disappear from the web UI or the clients. Are the missing folders in the trashbin (under "files_trashbin" of the owner on the server)

Does this happen for many different shares or just that one ? Does it happen for newly created shares ?

So far the only thing that comes to mind is that a concurrent operation happened (possibly renaming a parent folder) on an already shared folder and maybe that caused disappearance of the files.

[gig13]

@PVince81
They did not disappear from the server. Just this one share was impacted, but it is the main share for all users. New shares are not impacted.

Any idea what those errors are in the log ("Array to string conversion at ..." and "Illegal offset type in isset or empty at ..."?

[gig13]

@PVince81
Correction!! -- The files did disappear from the server, a backup was restored for that directory.

Other symptoms:

• The desktop client shows lots of "The system cannot find the file specified" messages.
• A files:scan was run and these messages still appear

Going to obtain additional logs, the directory disappeared between last Friday and this Monday (7/10-7/13)

[gig13]

@PVince81
Latest long on s3 -- owncloud.log.1.gz -- 20150710 until 20150712 log info

[PVince81]

@icewind1991 @schiesbn please help. Thanks.

[gig13]

@icewind1991 @schiesbn @bboule
Any updates?

[bboule]

@cmonteroluque Can we get someone to help out on this one? The temperature is rising and we need to help the user understand the situation! Any help would be appreciated.

[gig13]

@cmonteroluque
ping

[gig13]

@bboule
ping?

[PVince81]

Looking at the two listings: #17640 (comment):
The good ones have very different dates, which looks more realistic / correct.
Then look at The "bad directories", they all have the same day in the date "July 13th". Note that timestamp of folders are not preserved during sync, only the ones from files. This means that someone/something might have uploaded/reuploaded these folders when they went missing.
So one theory is that the folder was actually completely empty, but one sync client decided to reupload all the folders, or only reuploaded a few.
Maybe someone is using selective sync and only picked these specific folders, which could explain why only these were reuploaded instead of all of them.

Now for the other symptoms:

• there is a share folder containing the files listed above
• at some point, some folders disappeared from the listing but the files still exist in that directory on the server under "data/$user/files/.../trusef".
• something to check: see if the folders appear properly in oc_filecache: select * from oc_filecache where path like '%trusef%' order by path. I suspect that oc_filecache doesn't match whatever is on disk.
• a file scan should fix the discrepancy between file cache and on-disk data. But the scan did not make the folders reappear ? Re-checking oc_filecache after doing the scan should have they appear.

It would be useful to find out what exactly was done to cause the folders to disappear. Did it happen suddenly ?

Some things that could be tried to gather more clues:

1. check oc_filecache entries for the "trusef" folder as advised above before and after rescan
2. Testing scan without sync client interference:
   a) prepare a downtime and set the server to "maintenance" mode or "singleuser" mode. The goal is to exclude all sync clients from connecting to prevent interfering.
   b) Run the files:scan as before and save the listed output, see whether the listing contains the missing folders
   c) After that, check the web UI and see if the folders can be accessed again
   d) Check oc_filecache to find out if the folders were reindexed properly.

[PVince81]

@gig13 hinted to me that the share might be an orphaned share, which might or might not explain the strange behavior above. Let's check if that's the case:

1. select * from oc_share where file_target like '%trusef%';. This will show the share entries related to it.
2. Pick the value from the "item_source" column from the first row, for example 46. Then: select * from oc_filecache f, oc_storages s where f.storage=s.numeric_id and f.fileid=46; (replace 46 with the correct value).
3. Check the "id" column, it should be something like "home::someuser" (if it was shared by admin, it might be "home::admin".

Another suspicious thing is the "Array" entry:

# select * from oc_storages where id like 'local::%';
id | numeric_id
---------------------------------------+------------
local::/x/a/owncloud-enterprise/data/ | 5
local::/x/a/owncloud/data/ | 24
local::/x/a/owncloud/data/Array/ | 83

I will check the logs for further clues.

[PVince81]

I found this in the logs:

{"reqId":"84d97d595757faea82e17fd65f6e24a3","remoteAddr":"REMOVED","app":"files","message":" Backends provided no user object for Array","level":3,"time":"2015-07-12T23:58:22+00:00"}
{"reqId":"89c58def6af19f2e711c0503d4c6ddf7","remoteAddr":"REMOVED","app":"files","message":" Backends provided no user object for Array","level":3,"time":"2015-07-12T23:58:22+00:00"}
{"reqId":"84b3654d27a821a830156da54027f638","remoteAddr":"REMOVED","app":"files","message":" Backends provided no user object for Array","level":3,"time":"2015-07-12T23:58:22+00:00"}

Notice that the timestamp is from July 12th midnight, shortly before the reupload happens on July 13th as noticed in the listing: #17640 (comment).

The log entries mention a user called "Array" which explains the bogus storage entries.

Now the question is what on LDAP could cause that ? @butonic @MorrisJobke @blizzz

[PVince81]

Could this be a case of unavailable LDAP server ?
Since this is close to midnight, maybe the server was rebooted ? (possibly something to ask @gig13)

[PVince81]

More happens a bit later:

{"reqId":"4df2dde46e795c9562569697fafa4386","remoteAddr":"x.x.x.27","app":"files","message":" Backends provided no user object for Array","level":3,"time":"2015-07-14T00:34:47+00:00"}
{"reqId":"baa09693f66b5b7c7d4374eb7517b1fb","remoteAddr":"x.x.x.27","app":"files","message":" Backends provided no user object for Array","level":3,"time":"2015-07-14T00:34:47+00:00"}
{"reqId":"7c09ca16d78564559689b9fabf9b9848","remoteAddr":"x.x.x.27","app":"files","message":" Backends provided no user object for Array","level":3,"time":"2015-07-14T00:34:47+00:00"}
{"reqId":"8590b5c45ac31e99760db5e74b45116d","remoteAddr":"x.x.x.194","app":"sharing_log","message":"User 'root' unshared their folder (\/Shared\/trusef) with group 'GROUP1'","level":1,"time":"2015-07-14T00:36:07+00:00"}
{"reqId":"78de04207442e6cac2d86950b510b029","remoteAddr":"x.x.x.194","app":"sharing_log","message":"User 'root' unshared their folder (\/Shared\/trusef) with group 'GROUP2'","level":1,"time":"2015-07-14T00:36:08+00:00"}
{"reqId":"1d85b0981fd333511efe87238a0a9847","remoteAddr":"x.x.x.194","app":"files","message":" Backends provided no user object for Array","level":3,"time":"2015-07-14T00:36:08+00:00"}
{"reqId":"1d85b0981fd333511efe87238a0a9847","remoteAddr":"x.x.x.194","app":"sharing_log","message":"User 'root' unshared their folder (\/Shared\/trusef) with group 'GROUP3'","level":1,"time":"2015-07-14T00:36:08+00:00"}
{"reqId":"083841b73863be223be962b33df5871d","remoteAddr":"x.x.x.194","app":"sharing_log","message":"User 'root' unshared their folder (\/Shared\/trusef) with user 'USER1'","level":1,"time":"2015-07-14T00:36:11+00:00"}
{"reqId":"7fd33f13ca3c74304be757c3bcb4bc2e","remoteAddr":"x.x.x.194","app":"sharing_log","message":"User 'root' unshared their folder (\/Shared\/trusef) with user 'USER2'","level":1,"time":"2015-07-14T00:36:12+00:00"}
{"reqId":"45947716fa0238eff1c73b72507ae16e","remoteAddr":"x.x.x.194","app":"sharing_log","message":"User 'root' unshared their folder (\/Shared\/trusef) with user 'USER3'","level":1,"time":"2015-07-14T00:36:12+00:00"}

I replaced the group names and user names with placeholders here.

Basically it looks like several different requests from the same IP unshared the folder "trusef" from everybody, groups and users. Not sure why.

Open questions:

• what caused "Array" to be passed as user ? how does the code behave when a user is not found ? (if I remember well some protection was added recently for such error cases with LDAP)
• what caused the "unshare from all" operation and why is it from different client requests ?
• why did the folder appear empty for recipients instead of just disappearing completely ?

[PVince81]

This is the place in the code where the message is logged: https://github.com/owncloud/core/blob/v8.0.5/lib/private/files/filesystem.php#L346
It means that something before that is passing Array as an user.

[PVince81]

I think the reboot theory is wrong.
The "Backends provided no user object for Array" and also numerous "Array to string conversion at /x/a/owncloud-8.0.5/apps/user_ldap/user_ldap.php#195" message already appeared a few days before.

@gig13 did they mention the exact date when it started happening, if not July 13th ?

[PVince81]

We don't have stack traces, but here we can see how the warnings are thrown in different places in the code, which can help trace how the bogus array was passed around:

{"reqId":"db5a187fa24a35077a61717595b29fa0","remoteAddr":"REMOVED","app":"PHP","message":"Array to string conversion at \/x\/a\/owncloud-8.0.5\/apps\/user_ldap\/group_ldap.php#477","level":3,"time":"2015-07-12T07:00:18+00:00"}
{"reqId":"db5a187fa24a35077a61717595b29fa0","remoteAddr":"REMOVED","app":"PHP","message":"Illegal offset type in isset or empty at \/x\/a\/owncloud-8.0.5\/lib\/private\/user\/manager.php#109","level":3,"time":"2015-07-12T07:00:18+00:00"}
{"reqId":"db5a187fa24a35077a61717595b29fa0","remoteAddr":"REMOVED","app":"PHP","message":"Illegal offset type in isset or empty at \/x\/a\/owncloud-8.0.5\/lib\/private\/user\/database.php#184","level":3,"time":"2015-07-12T07:00:18+00:00"}
{"reqId":"db5a187fa24a35077a61717595b29fa0","remoteAddr":"REMOVED","app":"PHP","message":"Array to string conversion at \/x\/a\/owncloud-8.0.5\/3rdparty\/doctrine\/dbal\/lib\/Doctrine\/DBAL\/Driver\/PDOStatement.php#91","level":3,"time":"2015-07-12T07:00:18+00:00"}
{"reqId":"db5a187fa24a35077a61717595b29fa0","remoteAddr":"REMOVED","app":"PHP","message":"Illegal offset type in isset or empty at \/x\/a\/owncloud-8.0.5\/lib\/private\/user\/database.php#225","level":3,"time":"2015-07-12T07:00:18+00:00"}
{"reqId":"db5a187fa24a35077a61717595b29fa0","remoteAddr":"REMOVED","app":"PHP","message":"Array to string conversion at \/x\/a\/owncloud-8.0.5\/apps\/user_ldap\/user_ldap.php#194","level":3,"time":"2015-07-12T07:00:18+00:00"}
{"reqId":"db5a187fa24a35077a61717595b29fa0","remoteAddr":"REMOVED","app":"PHP","message":"Illegal offset type in isset or empty at \/x\/a\/owncloud-8.0.5\/apps\/user_ldap\/lib\/user\/manager.php#178","level":3,"time":"2015-07-12T07:00:18+00:00"}
{"reqId":"db5a187fa24a35077a61717595b29fa0","remoteAddr":"REMOVED","app":"PHP","message":"Illegal offset type in isset or empty at \/x\/a\/owncloud-8.0.5\/apps\/user_ldap\/lib\/user\/manager.php#180","level":3,"time":"2015-07-12T07:00:18+00:00"}
{"reqId":"db5a187fa24a35077a61717595b29fa0","remoteAddr":"REMOVED","app":"PHP","message":"ldap_explode_dn() expects parameter 1 to be string, array given at \/x\/a\/owncloud-8.0.5\/apps\/user_ldap\/lib\/ldap.php#254","level":3,"time":"2015-07-12T07:00:18+00:00"}
{"reqId":"db5a187fa24a35077a61717595b29fa0","remoteAddr":"REMOVED","app":"PHP","message":"Illegal offset type in isset or empty at \/x\/a\/owncloud-8.0.5\/lib\/private\/allconfig.php#332","level":3,"time":"2015-07-12T07:00:18+00:00"}
{"reqId":"db5a187fa24a35077a61717595b29fa0","remoteAddr":"REMOVED","app":"PHP","message":"Array to string conversion at \/x\/a\/owncloud-8.0.5\/3rdparty\/doctrine\/dbal\/lib\/Doctrine\/DBAL\/Driver\/PDOStatement.php#91","level":3,"time":"2015-07-12T07:00:18+00:00"}
{"reqId":"db5a187fa24a35077a61717595b29fa0","remoteAddr":"REMOVED","app":"PHP","message":"Illegal offset type at \/x\/a\/owncloud-8.0.5\/lib\/private\/allconfig.php#345","level":3,"time":"2015-07-12T07:00:18+00:00"}
{"reqId":"db5a187fa24a35077a61717595b29fa0","remoteAddr":"REMOVED","app":"PHP","message":"Array to string conversion at \/x\/a\/owncloud-8.0.5\/3rdparty\/doctrine\/dbal\/lib\/Doctrine\/DBAL\/Driver\/PDOStatement.php#91","level":3,"time":"2015-07-12T07:00:18+00:00"}
{"reqId":"db5a187fa24a35077a61717595b29fa0","remoteAddr":"REMOVED","app":"PHP","message":"Array to string conversion at \/x\/a\/owncloud-8.0.5\/apps\/user_ldap\/user_ldap.php#201","level":3,"time":"2015-07-12T07:00:18+00:00"}
{"reqId":"db5a187fa24a35077a61717595b29fa0","remoteAddr":"REMOVED","app":"PHP","message":"Array to string conversion at \/x\/a\/owncloud-8.0.5\/apps\/user_ldap\/user_ldap.php#203","level":3,"time":"2015-07-12T07:00:18+00:00"}
{"reqId":"db5a187fa24a35077a61717595b29fa0","remoteAddr":"REMOVED","app":"PHP","message":"Illegal offset type in isset or empty at \/x\/a\/owncloud-8.0.5\/lib\/private\/user\/manager.php#109","level":3,"time":"2015-07-12T07:00:19+00:00"}
{"reqId":"db5a187fa24a35077a61717595b29fa0","remoteAddr":"REMOVED","app":"PHP","message":"Illegal offset type in isset or empty at \/x\/a\/owncloud-8.0.5\/lib\/private\/user\/database.php#184","level":3,"time":"2015-07-12T07:00:19+00:00"}
{"reqId":"db5a187fa24a35077a61717595b29fa0","remoteAddr":"REMOVED","app":"PHP","message":"Array to string conversion at \/x\/a\/owncloud-8.0.5\/3rdparty\/doctrine\/dbal\/lib\/Doctrine\/DBAL\/Driver\/PDOStatement.php#91","level":3,"time":"2015-07-12T07:00:19+00:00"}
{"reqId":"db5a187fa24a35077a61717595b29fa0","remoteAddr":"REMOVED","app":"PHP","message":"Illegal offset type in isset or empty at \/x\/a\/owncloud-8.0.5\/lib\/private\/user\/database.php#225","level":3,"time":"2015-07-12T07:00:19+00:00"}
{"reqId":"db5a187fa24a35077a61717595b29fa0","remoteAddr":"REMOVED","app":"PHP","message":"Array to string conversion at \/x\/a\/owncloud-8.0.5\/apps\/user_ldap\/user_ldap.php#194","level":3,"time":"2015-07-12T07:00:19+00:00"}
{"reqId":"db5a187fa24a35077a61717595b29fa0","remoteAddr":"REMOVED","app":"PHP","message":"Array to string conversion at \/x\/a\/owncloud-8.0.5\/apps\/user_ldap\/user_ldap.php#195","level":3,"time":"2015-07-12T07:00:19+00:00"}
{"reqId":"db5a187fa24a35077a61717595b29fa0","remoteAddr":"REMOVED","app":"files","message":" Backends provided no user object for Array","level":3,"time":"2015-07-12T07:00:19+00:00"}

[blizzz]

Are you using an external user-backend, if yes which one: OpenLDAP

Looking at the config, this smells very very much like AD.

[PVince81]

I looked again at the suspicious "Unshare" actions. Since they all have a different request ID, I guess maybe it was done on purpose by the admin through the share dialog, which AFAIK sends a separate request for each action. Maybe the shared folder was already broken and the admin decided to try to unshare and reshare it. I didn't find any entries for the "share again" case, it might have happened later, so not sure.

Still trying to find any connection with the LDAP issue.

[PVince81]

Something to investigate: why would a sync client reupload files (from selective sync) into the empty shared folder ? Normally if a folder is suddenly empty, the desktop client would rather delete the local files to match the server.

[blizzz]

The LDAP issues are likely (not 100% sure - there are some similarities including an identical origin, and the original report was against OC 7) a duplicate of #13533 which will be fixed with 8.0.6.

[PVince81]

Had a quick chat with @ogoffart and it seems that either:

1. the client saw no files on the server and showed the "delete files or keep ?" dialog and the user clicked "keep"
   or
2. the client detected that the folders selected for selective sync were missing and reinited the DB and/or showed the dialog too (to be confirmed)

I checked the server logs and did not see entries that would delete folders in the "trusef" shared folder. Also I did not find any entries that show a reupload, but maybe that happened in another timeframe not visible in the logs. I also checked if the "trusef" folder was reshared again but did not find any log entries.

So far the disappearance of files in the "trusef" folder are still unexplained.

[MorrisJobke]

The LDAP issues are likely (not 100% sure - there are some similarities including an identical origin, and the original report was against OC 7) a duplicate of #13533 which will be fixed with 8.0.6.

This is also fixed in 7.0.6

[gig13]

@MorrisJobke
Results of "select * from oc_filecache where path like '%trusef%' order by path" in query1.out.gz on s3

No results for: select * from oc_share where file_target like '%trusef%';"

No user named Array.

TO DO TOMORROW: filescan in maint mode

[PVince81]

@gig13 thanks for the info. No results means the share is gone. This fits with what I saw in the log where the admin user "root" manually deleted the shares.
I still wonder why he didn't recreate the share afterwards ?

[blizzz]

@blizzz Does the command line tool share the same cache with the webserver for user info and LDAP connections?

Depends… If APCu is used it needs to be enabled for cli explicitely. IIRC in OC 7 that was not enforced and web UI could run with it and CLI without.

If we want to retry on ldap failure we need to do the retry in the ldap backend itself

So we would need to try to connect to LDAP and insert a delay (which could add up to a 60s timeout).

@gig13 please note that it is possible to run occ files:scan for a specific user: ./occ files:scan user_id.
Not sure if it must be the user id or ldap id.

Always ownCloud's user id.

[gig13]

@PVince81
The occ scan would not run even for a single user. Will try again....

[MorrisJobke]

The occ scan would not run even for a single user. Will try again....

Then this instance has actually a problem to connect to LDAP ...

[bboule]

@gig13 @MorrisJobke Do we think the issue here is LDAP related? Just want to understand the path forward on this issue?

[gig13]

@bboule
I am not sure of the occ dependency, but there have not been complaints regarding LDAP connectivity. I even provided large database dumps, thinking this may be corrupt database tables.

[bboule]

@MorrisJobke @blizzz is there any additional information we can provide to help identify this issue and possible fix?

[gig13]

@bboule
Ping -- any help here?

[MorrisJobke]

@blizzz @PVince81 Do you have any additional ideas? 😢

[PVince81]

Not sure, it seems to be a mix of different issues.

I'd say first would be to aim at making occ files:scan work again so that the missing files can be displayed again. Then if they happen to disappear again randomly, try and find out why and whether it's related to the random LDAP failings.

[MorrisJobke]

@blizzz Can we get more details why the connection is lost? Is there anything logged or is this all we can get?

[blizzz]

Can we get more details why the connection is lost? Is there anything logged or is this all we can get?

Not from our side, unfortunately.

The occ scan would not run even for a single user. Will try again....

@gig13 some output we can look at?

How does their LDAP/AD landscape look like? Maybe Proxy?

Do we have log output from the scan command attempts?

Meanwhile, was there an update attempted. As mentioned (#17640 (comment)), at least part of the LDAP issues were fixed with 8.0.6

[gig13]

@blizzz
The scan was listed above

> I ran the file scan and it exited after some time with this:
>
> Scanning folder /alex/cache
>
>
>
> [OC\ServerNotAvailableException]
> Lost connection to LDAP server.
>
>
>
> files:scan [-p|--path="..."] [-q|--quiet] [--all] [user_id1] ... [user_idN]

LDAP info is in the config report on s3.

[blizzz]

LDAP info is in the config report on s3.

But not the information is asked about. Unless I oversaw it, then point me please.

[gig13]

@blizzz
What are you looking for? If there is a proxy being used?
They have upgraded several times and the issues never go away. And without being able to perform a file:scan how can this every be reconciled?

I even provided an entire database dump on s3 -- so you can review the tables. What else do you need?

[gig13]

@blizzz @bboule
Any updates?

[blizzz]

What are you looking for? If there is a proxy being used?

How their LDAP setup is. Are they having just one server, everything is talking to, or are there LDAP slaves and their OC servers is talking to one, or are there many LDAP servers and OC connects with one of them via proxy, or somehow else?

They have upgraded several times and the issues never go away.

So they are now on 8.0.6 or 8.0.8?

Do we have log output from the scan command attempts (ideally with logging set to DEBUG level)? In none of the provided log files i can find anything about Lost connection to LDAP server.

[gig13]

@blizzz

They are on 8.0.6

The ldap server is on the same subnet on the same switch as the owncloud
server. It also serves all my users in the office and is monitored, and
there have been no alerts.

also i tried running it again and php spins at 100% for a really long time
trying to process thumbnails:

Scanning file /root/thumbnails/407681/36-36.png
Scanning folder /root/thumbnails/407684
Scanning file /root/thumbnails/407684/36-36.png
Scanning folder /root/thumbnails/415194
Scanning file /root/thumbnails/415194/36-36.png
Scanning folder /root/thumbnails/407674
Scanning file /root/thumbnails/407674/36-36.png
Scanning folder /root/thumbnails/414044
Scanning file /root/thumbnails/414044/36-36.png
Scanning folder /root/thumbnails/6913
Scanning file /root/thumbnails/6913/36-36.png
Scanning folder /root/thumbnails/405362
Scanning file /root/thumbnails/405362/36-36.png
Scanning folder /root/thumbnails/6911
Scanning file /root/thumbnails/6911/36-36.png

[PVince81]

I can't help with "LDAP temporarily unavailable" issues and @blizzz is sick this week.

Ideal would be to have the "files:scan" for the "trusef" user complete and then see whether the file disappearance case occurs again.

It is likely that the problem will not appear again due to recent fixes related to LDAP not being available while syncing. In the past, an unavailable LDAP server could make the user's home folder appear empty to the outside and make the sync client believe that the files were gone.

It is likely that when some users saw the sync client's dialog "all files are gone, do you want to keep or delete", they clicked "keep", which caused their sync client to reupload the files they had locally, which explains why the folders all have a more recent timestamp. The reason why not all the files are there is likely to be because that user used selective sync, so didn't have all the files locally.

From what I understood from @blizzz and @MorrisJobke is that now in the newer OC 8 versions this situation cannot happen any more, because now an unavailable LDAP server will throw an error to the outside (503 service unavailable) instead of exposing an empty folder.

Now to confirm this we need to find a way to make the "files:scan" of the user "trusef" finish properly, and then let the system run as normal. After the scan all files should be visible again.

[MorrisJobke]

From what I understood from @blizzz and @MorrisJobke is that now in the newer OC 8 versions this situation cannot happen any more, because now an unavailable LDAP server will throw an error to the outside (503 service unavailable) instead of exposing an empty folder.

This is what we think. And it's not that unlikely.

@gig13 Is there any chance to get this instance upgrade to at least 8.0.6 and run the files:scan again?

[gig13]

@MorrisJobke
They are on 8.0.6 and have attempted the files scan

[MorrisJobke]

They are on 8.0.6 and have attempted the files scan

Oh. Sorry. Just read it above.

@PVince81 Then it seems that it is still another issue with the filesystem setup. cc @icewind1991

[PVince81]

So I guess the missing folders are still missing now ?

Now thinking of it, the output @gig13 gave here #17640 (comment) is directly from the data folder. So if the missing folders aren't there, a rescan will not help.

The folders will have to be restored manually by moving/copying them from "new_trusef".

[MorrisJobke]

This is an old log, but maybe it's still present. And it looks somehow fishy.

{"reqId":"c8fc413304cfaf11504ed47f6b6588b1","remoteAddr":"10.10.162.27","app":"PHP","message":"Illegal offset type in isset or empty at \/x\/a\/owncloud-8.0.5\/lib\/private\/user\/manager.php#109","level":3,"time":"2015-07-12T06:49:18+00:00"}
{"reqId":"c8fc413304cfaf11504ed47f6b6588b1","remoteAddr":"10.10.162.27","app":"PHP","message":"Illegal offset type in isset or empty at \/x\/a\/owncloud-8.0.5\/lib\/private\/user\/database.php#184","level":3,"time":"2015-07-12T06:49:18+00:00"}
{"reqId":"c8fc413304cfaf11504ed47f6b6588b1","remoteAddr":"10.10.162.27","app":"PHP","message":"Array to string conversion at \/x\/a\/owncloud-8.0.5\/3rdparty\/doctrine\/dbal\/lib\/Doctrine\/DBAL\/Driver\/PDOStatement.php#91","level":3,"time":"2015-07-12T06:49:18+00:00"}
{"reqId":"c8fc413304cfaf11504ed47f6b6588b1","remoteAddr":"10.10.162.27","app":"PHP","message":"Illegal offset type in isset or empty at \/x\/a\/owncloud-8.0.5\/lib\/private\/user\/database.php#225","level":3,"time":"2015-07-12T06:49:18+00:00"}
{"reqId":"c8fc413304cfaf11504ed47f6b6588b1","remoteAddr":"10.10.162.27","app":"PHP","message":"Array to string conversion at \/x\/a\/owncloud-8.0.5\/apps\/user_ldap\/user_ldap.php#194","level":3,"time":"2015-07-12T06:49:18+00:00"}
{"reqId":"c8fc413304cfaf11504ed47f6b6588b1","remoteAddr":"10.10.162.27","app":"PHP","message":"Array to string conversion at \/x\/a\/owncloud-8.0.5\/apps\/user_ldap\/user_ldap.php#195","level":3,"time":"2015-07-12T06:49:18+00:00"}

[PVince81]

Regarding the "Array to string conversion", see #17640 (comment), still not clear why an Array was returned instead of the user object. Could be due to the user not existing or another bug. There is a chance that it might be fixed already, see #17640 (comment)

[MorrisJobke]

Okay. Just had a screen sharing session.

As it turned out this was a leftover from old filesystem setups. The folders were actually present in the data dir (and showed up as non shared in the "Shared" folder). This was quite confusing in the first time. What now is done:

• cleanup those leftover folders (most of them are completely empty and are just the structure of the old shared folder, that is not shared anymore) in the data dir
• run a filescan to let owncloud recognize the changed filesystem
• clients should clean up the folders on the desktop PCs

Case closed. :)