Thanks erikchen@ Can you give me the Canary version?

63.0.3218.0 (Official Build) canary (64-bit)

The '1' in "ChromeMethodBFE: 20::GetChildren::1" is the errno - which I believe is EPERM on macOS. I'm also seeing "FFmpegDemuxer: open context failed". FFmpegGlue::OpenContext also does file I/O, so can also fail due to a permissions problem.

Do you see anything else strange in your logs? I don't see any spikes in UMA on WebCore.IndexedDB.LevelDBOpenErrors.

Attached full log.

Deleted: log_766896.txt 398 KB

log_766896.txt 398 KB View Download

Thx for the log Erik. I tried Canary (63.0.3221.0) on a Mac, and so far (with three profiles) am getting no errors - of course.

1) Can you reproduce this?
2) Does "/Users/erikchen/Library/Application Support/Google/Chrome Canary/Profile 3/IndexedDB/https_docs.google.com_0.indexeddb.leveldb" look like a valid directory? Can you manually create a file in that dir?
3) Any security software on that machine?

1) Not sure yet. Haven't restarted
2) Yes and yes.
3) Corp machine, nothing else special.

OK - if you can repro, or encounter on another machine please update this bug. Given that UMA stats are flat in Canary I'm going to wait for further updates.

Scanning through my logs from today, I saw:
"""
[39075:543399:1006/175245.965734:ERROR:leveldb_database.cc(319)] Failed to open LevelDB database from /Users/erikchen/Library/Application Support/Google/Chrome Canary/Profile 3/IndexedDB/https_docs.google.com_0.indexeddb.leveldb,IO error: /Users/erikchen/Library/Application Support/Google/Chrome Canary/Profile 3/IndexedDB/https_docs.google.com_0.indexeddb.leveldb: Could not open/read directory (ChromeMethodBFE: 20::GetChildren::1)
[39075:543399:1006/175245.966133:ERROR:indexed_db_backing_store.cc(1433)] Unable to open backing store, not trying to recover - IO error: /Users/erikchen/Library/Application Support/Google/Chrome Canary/Profile 3/IndexedDB/https_docs.google.com_0.indexeddb.leveldb: Could not open/read directory (ChromeMethodBFE: 20::GetChildren::1)
"""

Note: The number 1 that I mentioned in #c4 is not EPERM. It's really a base::File::Error and 1 => FILE_ERROR_FAILED (generic error). The PlatformFile.UnknownErrors.Posix UMA is logged for all values that are mapped to FILE_ERROR_FAILED.

The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/19d869ca41dd59b376cc0e3b07c616faeacd2062

commit 19d869ca41dd59b376cc0e3b07c616faeacd2062
Author: Chris Mumford <cmumford@chromium.org>
Date: Wed Oct 11 17:08:36 2017

leveldb: Adding VLOGs to GetDirectoryEntries.

Adding (possibly temporary) verbose error logs to GetDirectoryEntries
to help identify the source of errors on some clients.

Bug:  766896 
Change-Id: Id278838a8277e8a9659e13590044b0c294a740f5
Reviewed-on: https://chromium-review.googlesource.com/710639
Reviewed-by: Joshua Bell <jsbell@chromium.org>
Commit-Queue: Chris Mumford <cmumford@chromium.org>
Cr-Commit-Position: refs/heads/master@{#508009}
[modify] https://crrev.com/19d869ca41dd59b376cc0e3b07c616faeacd2062/third_party/leveldatabase/env_chromium.cc

erikchen@: Some logging was added, and is in 63.0.3238.0. Can you reproduce this logging enabled?

The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/49330779ef21d72c982db7c95c82bf7b02aa1f52

commit 49330779ef21d72c982db7c95c82bf7b02aa1f52
Author: Chris Mumford <cmumford@chromium.org>
Date: Wed Oct 18 02:48:00 2017

Map ENFILE error to FILE_ERROR_TOO_MANY_OPENED.

File::OSErrorToFileError() was only mapping EMFILE to
FILE_ERROR_TOO_MANY_OPENED. Mapping ENFILE is one less FILE_ERROR_FAILED
returned.

Will not fix  issue 766896 , but might produce better logs.

Bug:  766896 
Change-Id: I2c2a0fafe15b0415da1c65cfe9b6f13cafe38206
Reviewed-on: https://chromium-review.googlesource.com/706545
Reviewed-by: Lei Zhang <thestig@chromium.org>
Commit-Queue: Chris Mumford <cmumford@chromium.org>
Cr-Commit-Position: refs/heads/master@{#509666}
[modify] https://crrev.com/49330779ef21d72c982db7c95c82bf7b02aa1f52/base/files/file_posix.cc

Got the debug log from erikchen@ it contained "Error 32 listing entries...". 32 is EPIPE - "Broken pipe".

mark: Assistance requested with understanding the macOS filesystem.

We're getting a reproducible issue on my corp, MBP, 10.12.6, Chrome Canary. Chris added additional logging. We're seeing the following line:

"""
138652 [38084:305951:1017/134404.177591:VERBOSE1:env_chromium.cc(160)] Error 32 listing entries in "/Users/erikchen/Library/Application Support/Google/Chrome Canary/Profile 2/IndexedDB/https_www.google.com_0.indexeddb.leveldb"
"""
from here in the code: https://cs.chromium.org/chromium/src/third_party/leveldatabase/env_chromium.cc?q=env_chromium.cc&sq=package:chromium&dr&l=163

This suggests we're getting an EPIPE from a call to readdir(). [actually, this could technically also be coming from result->push_back(FilePath::FromUTF8Unsafe(dent->d_name));, but that seems less likely - chris, can you update the logging for us to confirm this?].

No permissions issues:
"""
ls -alh  "/Users/erikchen/Library/Application Support/Google/Chrome Canary/Profile 2/IndexedDB/https_www.google.com_0.indexeddb.leveldb"
total 1288
drwx------@  8 erikchen  eng   272B Oct 19 17:24 .
drwx------@ 13 erikchen  eng   442B Sep 22 02:54 ..
-rw-------@  1 erikchen  eng   627K Oct 19 17:24 000003.log
-rw-------@  1 erikchen  eng    16B Mar  7  2017 CURRENT
-rw-------@  1 erikchen  eng     0B Mar  7  2017 LOCK
-rw-------@  1 erikchen  eng   424B Oct 19 17:24 LOG
-rw-------@  1 erikchen  eng   424B Oct 19 17:12 LOG.old
-rw-------@  1 erikchen  eng    23B Mar  7  2017 MANIFEST-000001
"""

Appears locally mounted:
"""
df -l  "/Users/erikchen/Library/Application Support/Google/Chrome Canary/Profile 2/IndexedDB/https_www.google.com_0.indexeddb.leveldb"
Filesystem 512-blocks      Used Available Capacity iused      ifree %iused  Mounted on
/dev/disk1  974770480 704531840 269726640    73% 5594205 4289373074    0%   /
"""

A small test program shows that this logic should work:
"""
  1 #include <stdio.h>                                                                                                                                  
  2 #include <dirent.h>                                                             
  3 #include <errno.h>                                                              
  4                                                                                 
  5 int main() {                                                                    
  6   DIR* dir = opendir("/Users/erikchen/Library/Application Support/Google/Chrome Canary/Profile 2/IndexedDB/https_www.google.com_0.indexeddb.leveldb"    );
  7   struct dirent* dent;                                                          
  8   while ((dent = readdir(dir))) {                                               
  9     fprintf(stderr, "%s\n", dent->d_name);                                      
 10   }                                                                             
 11   fprintf(stderr, "errno: %d", errno);                                          
 12   closedir(dir);                                                                
 13                                                                                 
 14                                                                                 
 15   return 0;                                                                     
 16 }                                                                               
~           


.
..
000003.log
CURRENT
LOCK
LOG
LOG.old
MANIFEST-000001
"""

Looking at the source for XNU, I only see EPIPE as a possible error for NFS file systems, and as far as I can tell, this directory is locally mounted. Thoughts?

The output from your test program doesn’t match the program in that I don’t see it outputting any errno value.

The code in env_chromium.cc is invalid. Remove the “errno = 0” on line 145 and change line 155 to:

  while ((errno = 0, dent = readdir(dir)) != nullptr)

Even ignoring the issue you raise about errno perhaps reflecting an error other than readdir()’s, errno is also invalid coming out of a successful readdir() and even opendir().

If you still see EPIPE or any other unexpected error after the code is corrected, then we can talk again.

The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/bd8384efe5d33c92b6dd620140c2972ba9851fad

commit bd8384efe5d33c92b6dd620140c2972ba9851fad
Author: Chris Mumford <cmumford@chromium.org>
Date: Wed Oct 25 16:38:42 2017

leveldb: Better handling of errno in GetDirectoryEntries.

Resetting before every call to readdir(2) will effectively ignore errno
if set by other library functions.

Bug:  766896 
Change-Id: I0592db543adb2081d97066f1c62d9599c549c24e
Reviewed-on: https://chromium-review.googlesource.com/736317
Reviewed-by: Erik Chen <erikchen@chromium.org>
Commit-Queue: Chris Mumford <cmumford@chromium.org>
Cr-Commit-Position: refs/heads/master@{#511484}
[modify] https://crrev.com/bd8384efe5d33c92b6dd620140c2972ba9851fad/third_party/leveldatabase/env_chromium.cc

erikchen@ The above change (#c18) is in 64.0.3250.0. Can you update and try to repro?

It looks like http://crrev.com/c/736317 had a positive impact. erikchen@ has seen no errors in the past several days, and the FAILED bucket count in LevelDBEnv.IDB.IOError.BFE.GetChildren has dropped substantially.

Requesting permission to merge the following CL's into M63:

  1) http://crrev.com/c/706545
  2) http://crrev.com/c/736317

The bug is marked as P3 or Feature. It should not be merged as M63 is in beta. 
Please contact the approriate milestone owner if you have questions.
Owners: cmasso@(Android), cmasso@(iOS), gkihumba@(ChromeOS), govind@(Desktop)

For more details visit https://www.chromium.org/issue-tracking/autotriage - Your friendly Sheriffbot

Some more detail on the merge request in #c20. This bug potentially affects POSIX platforms (i.e. not Windows), but is most obvious on macOS. The failure rate on macOS (stable) has increased fivefold since Sept 21st.

The two fixes are small and low risk. The first classifies errno=ENFILE as FILE_ERROR_TOO_MANY_OPENED where before it would be FILE_ERROR_FAILED. Nowhere does in leveldb/IDB are either of those two errors explicitly handled. This change will only improve the UMA logging of PlatformFile.UnknownErrors.Posix.

The second change only clears errno before calling readdir. This change was reviewed by three Chrome developers and IMO is safe for a merge to M63.

The Canary charts for LevelDBEnv.IDB.IOError.BFE.GetChildren are spikey due to the small number of Canary clients, but I believe the worst case scenario this change won't fix the problem.

Approving merge to M63 branch for cls listed at #20 based on comment #22 and per internal email thread. Please merge ASAP. Thank you.

The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/0c437c9c12b40e5241296710d8923929ef1f7f82

commit 0c437c9c12b40e5241296710d8923929ef1f7f82
Author: Chris Mumford <cmumford@chromium.org>
Date: Fri Nov 03 19:19:24 2017

Map ENFILE error to FILE_ERROR_TOO_MANY_OPENED.

File::OSErrorToFileError() was only mapping EMFILE to
FILE_ERROR_TOO_MANY_OPENED. Mapping ENFILE is one less FILE_ERROR_FAILED
returned.

Will not fix  issue 766896 , but might produce better logs.

TBR=cmumford@chromium.org

(cherry picked from commit 49330779ef21d72c982db7c95c82bf7b02aa1f52)

Bug:  766896 
Change-Id: I2c2a0fafe15b0415da1c65cfe9b6f13cafe38206
Reviewed-on: https://chromium-review.googlesource.com/706545
Reviewed-by: Lei Zhang <thestig@chromium.org>
Commit-Queue: Chris Mumford <cmumford@chromium.org>
Cr-Original-Commit-Position: refs/heads/master@{#509666}
Reviewed-on: https://chromium-review.googlesource.com/753997
Reviewed-by: Chris Mumford <cmumford@chromium.org>
Cr-Commit-Position: refs/branch-heads/3239@{#368}
Cr-Branched-From: adb61db19020ed8ecee5e91b1a0ea4c924ae2988-refs/heads/master@{#508578}
[modify] https://crrev.com/0c437c9c12b40e5241296710d8923929ef1f7f82/base/files/file_posix.cc

The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/82c823752fab12cd90c200130b05da66e8b0698b

commit 82c823752fab12cd90c200130b05da66e8b0698b
Author: Chris Mumford <cmumford@chromium.org>
Date: Fri Nov 03 19:24:41 2017

leveldb: Better handling of errno in GetDirectoryEntries.

Resetting before every call to readdir(2) will effectively ignore errno
if set by other library functions.

TBR=cmumford@chromium.org

(cherry picked from commit bd8384efe5d33c92b6dd620140c2972ba9851fad)

Bug:  766896 
Change-Id: I0592db543adb2081d97066f1c62d9599c549c24e
Reviewed-on: https://chromium-review.googlesource.com/736317
Reviewed-by: Erik Chen <erikchen@chromium.org>
Commit-Queue: Chris Mumford <cmumford@chromium.org>
Cr-Original-Commit-Position: refs/heads/master@{#511484}
Reviewed-on: https://chromium-review.googlesource.com/753285
Reviewed-by: Chris Mumford <cmumford@chromium.org>
Cr-Commit-Position: refs/branch-heads/3239@{#369}
Cr-Branched-From: adb61db19020ed8ecee5e91b1a0ea4c924ae2988-refs/heads/master@{#508578}
[modify] https://crrev.com/82c823752fab12cd90c200130b05da66e8b0698b/third_party/leveldatabase/env_chromium.cc

Both CL's merged into M63. Thx govind@

UMA logs looking good. Please reopen if issue encountered again.