New issue
Advanced search Search tips

Issue 844198 link

Starred by 2 users
Status: WontFix
Owner:
joelhockey@chromium.org
Closed: Jun 2018
Cc:
sdantul...@chromium.org
slangley@chromium.org
mkarkada@chromium.org
dhadd...@chromium.org
avkodipelli@chromium.org
Components:
EstimatedDays: ----
NextAction: ----
OS: Chrome
Pri: 1
Type: Bug-Regression



Sign in to add a comment

Seen extra folder(Recovered files from google Drive) at /Downloads

Project Member Reported by abod...@chromium.org, May 17 2018 
Chrome OS 10684.0.0, 68.0.3432.0
Please specify Cr-* of the system to which this bug/feature applies (add
the label below).

Steps To Reproduce:
(1)Perform AU M67 to M68 
(2)login to user account and open file.app 
(3)

Expected Result:

Actual Result:
Seen extra folder(Recovered files from google Drive) at /Downloads

Feedback report: https://listnr.corp.google.com/product/208/report/85452207303

How frequently does this problem reproduce? (Always, sometimes, hard to
reproduce?)

What is the impact to the user, and is there a workaround? If so, what is
it?

Please provide any additional information below. Attach a screen shot or
log if possible.

For graphics-related bugs, please copy/paste the contents of the about:gpu
page at the end of this report.

chrome://drive-internal Event log
--------------------------------------------------------------------------


2018-05-17T14:14:38.985: [info] Push notification is registered
2018-05-17T14:14:38.985: [info] Drive mount point is added
2018-05-17T14:14:40.433: [info] fileManagerPrivate.getPreferences succeeded.
2018-05-17T14:14:40.434: [info] fileManagerPrivate.getPreferences succeeded.
2018-05-17T14:14:40.550: [info] Push notification is disabled
2018-05-17T14:14:40.737: [info] Push notification is disabled
2018-05-17T14:14:40.875: [info] fileManagerPrivate.getDriveConnectionState succeeded.
2018-05-17T14:14:40.940: [info] fileManagerPrivate.getVolumeMetadataList[9] succeeded. (results: '[/home/chronos/u-6575088695a0999a6b7019e85eea27a489479a17/Downloads, /special/drive-6575088695a0999a6b7019e85eea27a489479a17]', 2 mount points)
2018-05-17T14:14:40.959: [info] fileManagerPrivate.getPreferences succeeded.
2018-05-17T14:14:40.959: [info] fileManagerPrivate.getPreferences succeeded.
2018-05-17T14:14:40.959: [info] fileManagerPrivate.getDriveConnectionState succeeded.
2018-05-17T14:14:40.961: [info] fileManagerPrivate.getDriveConnectionState succeeded.
2018-05-17T14:14:41.228: [info] Job queued: TYPE_GET_ABOUT_RESOURCE STATE_NONE [1] - METADATA_QUEUE pending: 1, running: 0
2018-05-17T14:14:41.228: [info] Job started: TYPE_GET_ABOUT_RESOURCE STATE_RUNNING [1] - METADATA_QUEUE pending: 0, running: 1
2018-05-17T14:14:41.472: [info] fileManagerPrivate.getDriveConnectionState succeeded.
2018-05-17T14:14:42.058: [info] fileManagerPrivate.getVolumeMetadataList[0] succeeded. (results: '[/home/chronos/u-6575088695a0999a6b7019e85eea27a489479a17/Downloads, /special/drive-6575088695a0999a6b7019e85eea27a489479a17]', 2 mount points)
2018-05-17T14:14:42.100: [info] Job done: TYPE_GET_ABOUT_RESOURCE STATE_RUNNING [1] => HTTP_SUCCESS (elapsed time: 872ms) - METADATA_QUEUE pending: 0, running: 0
2018-05-17T14:14:42.100: [info] Job queued: TYPE_GET_ALL_RESOURCE_LIST STATE_NONE [2] - METADATA_QUEUE pending: 1, running: 0
2018-05-17T14:14:42.100: [info] Job started: TYPE_GET_ALL_RESOURCE_LIST STATE_RUNNING [2] - METADATA_QUEUE pending: 0, running: 1
2018-05-17T14:14:43.304: [info] Job done: TYPE_GET_ALL_RESOURCE_LIST STATE_RUNNING [2] => HTTP_SUCCESS (elapsed time: 1204ms) - METADATA_QUEUE pending: 0, running: 0
2018-05-17T14:14:43.311: [info] Job queued: TYPE_GET_REMAINING_FILE_LIST STATE_NONE [3] - METADATA_QUEUE pending: 1, running: 0
2018-05-17T14:14:43.311: [info] Job started: TYPE_GET_REMAINING_FILE_LIST STATE_RUNNING [3] - METADATA_QUEUE pending: 0, running: 1
2018-05-17T14:14:43.488: [info] Push notification is enabled
2018-05-17T14:14:44.957: [info] Job done: TYPE_GET_REMAINING_FILE_LIST STATE_RUNNING [3] => HTTP_SUCCESS (elapsed time: 1645ms) - METADATA_QUEUE pending: 0, running: 0
2018-05-17T14:14:44.960: [info] Job queued: TYPE_GET_REMAINING_FILE_LIST STATE_NONE [4] - METADATA_QUEUE pending: 1, running: 0
2018-05-17T14:14:44.960: [info] Job started: TYPE_GET_REMAINING_FILE_LIST STATE_RUNNING [4] - METADATA_QUEUE pending: 0, running: 1
2018-05-17T14:14:46.781: [info] Job done: TYPE_GET_REMAINING_FILE_LIST STATE_RUNNING [4] => HTTP_SUCCESS (elapsed time: 1820ms) - METADATA_QUEUE pending: 0, running: 0
2018-05-17T14:14:46.783: [info] Job queued: TYPE_GET_REMAINING_FILE_LIST STATE_NONE [5] - METADATA_QUEUE pending: 1, running: 0
2018-05-17T14:14:46.783: [info] Job started: TYPE_GET_REMAINING_FILE_LIST STATE_RUNNING [5] - METADATA_QUEUE pending: 0, running: 1
2018-05-17T14:14:48.615: [info] Job done: TYPE_GET_REMAINING_FILE_LIST STATE_RUNNING [5] => HTTP_SUCCESS (elapsed time: 1831ms) - METADATA_QUEUE pending: 0, running: 0
2018-05-17T14:14:48.619: [info] Job queued: TYPE_GET_REMAINING_FILE_LIST STATE_NONE [6] - METADATA_QUEUE pending: 1, running: 0
2018-05-17T14:14:48.620: [info] Job started: TYPE_GET_REMAINING_FILE_LIST STATE_RUNNING [6] - METADATA_QUEUE pending: 0, running: 1
2018-05-17T14:14:49.853: [info] Job done: TYPE_GET_REMAINING_FILE_LIST STATE_RUNNING [6] => HTTP_SUCCESS (elapsed time: 1234ms) - METADATA_QUEUE pending: 0, running: 0
2018-05-17T14:14:49.855: [info] Job queued: TYPE_GET_REMAINING_FILE_LIST STATE_NONE [7] - METADATA_QUEUE pending: 1, running: 0
2018-05-17T14:14:49.856: [info] Job started: TYPE_GET_REMAINING_FILE_LIST STATE_RUNNING [7] - METADATA_QUEUE pending: 0, running: 1
2018-05-17T14:14:49.957: [info] CWS OAuth token fetch succeeded.
2018-05-17T14:14:49.976: [info] fileManagerPrivate.getPreferences succeeded.
2018-05-17T14:14:50.003: [info] fileManagerPrivate.getPreferences succeeded.
2018-05-17T14:14:50.005: [info] fileManagerPrivate.getPreferences succeeded.
2018-05-17T14:14:50.068: [info] fileManagerPrivate.getPreferences succeeded.
2018-05-17T14:14:50.321: [info] Fast-fetch start: local_id: fe9ca1c5-5b55-44d4-a0a8-5e5d22fcf3a4, resource_id: 0ADor1sb7dJnyUk9PVA, changestamp: 34674; Server changestamp: 34674
2018-05-17T14:14:50.321: [info] Job queued: TYPE_GET_RESOURCE_LIST_IN_DIRECTORY STATE_NONE [8] - METADATA_QUEUE pending: 1, running: 1
2018-05-17T14:14:50.322: [info] Job started: TYPE_GET_RESOURCE_LIST_IN_DIRECTORY STATE_RUNNING [8] - METADATA_QUEUE pending: 0, running: 2
2018-05-17T14:14:50.820: [info] Job done: TYPE_GET_REMAINING_FILE_LIST STATE_RUNNING [7] => HTTP_SUCCESS (elapsed time: 964ms) - METADATA_QUEUE pending: 0, running: 1
2018-05-17T14:14:50.822: [info] Job queued: TYPE_GET_REMAINING_FILE_LIST STATE_NONE [9] - METADATA_QUEUE pending: 1, running: 1
2018-05-17T14:14:50.822: [info] Job started: TYPE_GET_REMAINING_FILE_LIST STATE_RUNNING [9] - METADATA_QUEUE pending: 0, running: 2
2018-05-17T14:14:50.825: [info] Job done: TYPE_GET_RESOURCE_LIST_IN_DIRECTORY STATE_RUNNING [8] => HTTP_SUCCESS (elapsed time: 503ms) - METADATA_QUEUE pending: 0, running: 1
2018-05-17T14:14:50.848: [info] Fast-fetch complete: local_id: fe9ca1c5-5b55-44d4-a0a8-5e5d22fcf3a4, resource_id: 0ADor1sb7dJnyUk9PVA, changestamp: 34674 => FILE_ERROR_OK
2018-05-17T14:14:51.421: [info] Job done: TYPE_GET_REMAINING_FILE_LIST STATE_RUNNING [9] => HTTP_SUCCESS (elapsed time: 599ms) - METADATA_QUEUE pending: 0, running: 0
2018-05-17T14:14:51.423: [info] Apply change lists (is delta: 0)
2018-05-17T14:14:52.240: [info] Change lists applied (elapsed time: 817ms)
2018-05-17T14:15:25.641: [info] fileManagerPrivate.getVolumeMetadataList[0] succeeded. (results: '[/home/chronos/u-6575088695a0999a6b7019e85eea27a489479a17/Downloads, /special/drive-6575088695a0999a6b7019e85eea27a489479a17]', 2 mount points)
2018-05-17T14:15:38.986: [info] Received Drive update notification. Will check for update.
2018-05-17T14:15:38.986: [info] Job queued: TYPE_GET_ABOUT_RESOURCE STATE_NONE [10] - METADATA_QUEUE pending: 1, running: 0
2018-05-17T14:15:38.986: [info] Job started: TYPE_GET_ABOUT_RESOURCE STATE_RUNNING [10] - METADATA_QUEUE pending: 0, running: 1
2018-05-17T14:15:38.986: [info] Checking for updates
2018-05-17T14:15:39.167: [info] Job done: TYPE_GET_ABOUT_RESOURCE STATE_RUNNING [10] => HTTP_SUCCESS (elapsed time: 180ms) - METADATA_QUEUE pending: 0, running: 0
2018-05-17T14:15:39.167: [info] About resource updated to: 34674
2018-05-17T14:15:45.899: [info] fileManagerPrivate.getPreferences succeeded.
2018-05-17T14:15:45.900: [info] fileManagerPrivate.getPreferences succeeded.
2018-05-17T14:15:45.900: [info] fileManagerPrivate.getPreferences succeeded.
2018-05-17T14:15:45.900: [info] fileManagerPrivate.getPreferences succeeded.
2018-05-17T14:15:45.900: [info] fileManagerPrivate.getPreferences succeeded.
2018-05-17T14:16:10.734: [info] fileManagerPrivate.getVolumeMetadataList[0] succeeded. (results: '[/home/chronos/u-6575088695a0999a6b7019e85eea27a489479a17/Downloads, /special/drive-6575088695a0999a6b7019e85eea27a489479a17]', 2 mount points)
2018-05-17T14:17:44.493: [info] fileManagerPrivate.getVolumeMetadataList[0] succeeded. (results: '[/home/chronos/u-6575088695a0999a6b7019e85eea27a489479a17/Downloads, /special/drive-6575088695a0999a6b7019e85eea27a489479a17]', 2 mount points)
debug-logs_20180517-142132.tgz
797 KB Download

Comment 1 by abod...@chromium.org, May 18 2018

Cc: avkodipelli@chromium.org

Comment 2 by avkodipelli@chromium.org, May 18 2018 

Observed issue on Kip device after auto updated from beta(10575.40.0) to dev(10690.0.0).
Feedback report: 85453672596

Comment 3 by sashab@google.com, May 24 2018

Labels: -Pri-2 Pri-1
Owner: sashab@chromium.org
Status: Assigned (was: Untriaged)
This might be caused from having pending changes when an AU is triggered. I'll investigate further.

Comment 4 by joelhockey@chromium.org, May 25 2018

Owner: joelhockey@chromium.org

Comment 5 by joelhockey@chromium.org, Jun 7 2018 

I've browsed the code and seen that this happens when there is an error opening the metadata leveldb.

https://cs.chromium.org/chromium/src/components/drive/resource_metadata_storage.cc?l=671-706&rcl=323435f2b881bfc88276e2d3b3d5cacc7176a18a

https://cs.chromium.org/chromium/src/chrome/browser/chromeos/drive/drive_integration_service.cc?l=175-185&rcl=323435f2b881bfc88276e2d3b3d5cacc7176a18a

It looks like creating this directory is expected when there is an issue with the db.  I can't really comment on how errors usually happen with the DB.  I've never seen or heard of this problem before.

I'm not sure if there is much more that I can add here.  I expect this issue is WAI.

Comment 6 by joelhockey@chromium.org, Jun 7 2018 

I'll try today to replicate upgrading from 67 to 68.

abodeti@, do you recall any specific actions you had taken prior to upgrade?  Do you think it was possible that drive was in the middle of syncing new files when the upgrade happened, or something like that?

Comment 7 by joelhockey@chromium.org, Jun 8 2018 

I can reproduce the issue by having drive files syncing at the time of reboot.  I wait for the update ready icon, and then just before doing the reboot, I start syncing about 10 files from Downloads into Drive.  I see status in bottom left of the FilesApp that files are syncing, and then I click 'restart now to update'.

When I do not have drive files syncing, I do not see the directory.

Comment 8 by joelhockey@chromium.org, Jun 12 2018

Cc: slangley@chromium.org
Status: WontFix (was: Assigned)
I have talked with Stuart and this is expected behaviour for drive sync.  My attached screenshots show that I copied 6 files and 1 empty dir from SD card to Drive just before clicking update.  After update, drive had the 1 empty folder and 1 file.  The 'Downloads/Recovered files from Google Drive' folder has 5 of the files that were being synced including the 1 file that did successfully upload to Drive.  There was 1 file that was neither in Drive, nor in the recovered directory.
Screenshot 2018-06-12 at 11.09.14.png
280 KB View Download
►

Sign in to add a comment