1140597 - [DeviceStorage] GetVolumeByName('sdcard') failed

Status: RESOLVED FIXED

(Core :: DOM: Device Interfaces, defect, P1)

Description

[Justin D'Arcangelo [:justindarc]]

Unable to import apps/addons using navigator.mozApps.mgmt.import():

// Retrieve the new tempfile.
var getRequest = sdcard.get(APP_OR_ADDON_FILENAME);
getRequest.onsuccess = () => {
  var addonFile = getRequest.result;

  // Import the app/addon using the tempfile.
  navigator.mozApps.mgmt.import(addonFile)
    .then((addon) => {
      resolve(addon);
    })
    .catch((error) => {
      reject(error);
    });
};

The above code results in the following output in the logcat:

I/Gecko   ( 1590): ##### DeviceStorage: GetVolumeByName('sdcard') failed
I/Gecko   ( 1590): ##### DeviceStorage: GetVolumeByName('sdcard') failed
I/Gecko   ( 1590): ##### DeviceStorage: GetVolumeByName('sdcard') failed

Comment 1

[Justin D'Arcangelo [:justindarc]]

Setting NI? for Dave since he knows DeviceStorage.

Comment 2

[Doug Sherk (:drs) (inactive)]

This is busted on both Flame and Aries, at the very least.

Comment 3

[Dave Hylands [:dhylands]]

My preliminary investigation seems to indicate that the ##### DeviceStorage: GetVolumeByName('sdcard') failed messages are coming from the preallocated process.

Could you verify that this is the case for you? (i.e. the 1590 in the error message corresponds to the preallocated process).

What's happening is that when device storage successfully adds or removes a file, it winds up sending out a file-watcher-update notification.

The ##### DeviceStorage: GetVolumeByName('sdcard') failed error messages that I saw were happening when the preallocated process receives the file-watcher-update.

So I need to figure out a way to get the preallocated process to ignore these messages, but I'm pretty sure that this is not causing any problems other than chewing some CPU cycles.

Comment 4

[Justin D'Arcangelo [:justindarc]]

(In reply to Dave Hylands [:dhylands] from comment #3)
> My preliminary investigation seems to indicate that the ##### DeviceStorage:
> GetVolumeByName('sdcard') failed messages are coming from the preallocated
> process.
> 
> Could you verify that this is the case for you? (i.e. the 1590 in the error
> message corresponds to the preallocated process).
> 
> What's happening is that when device storage successfully adds or removes a
> file, it winds up sending out a file-watcher-update notification.
> 
> The ##### DeviceStorage: GetVolumeByName('sdcard') failed error messages
> that I saw were happening when the preallocated process receives the
> file-watcher-update.
> 
> So I need to figure out a way to get the preallocated process to ignore
> these messages, but I'm pretty sure that this is not causing any problems
> other than chewing some CPU cycles.

Confirmed. Getting the following errors logged in logcat:

I/Gecko   (17902): ##### DeviceStorage: GetVolumeByName('sdcard') failed
I/Gecko   (17902): ##### DeviceStorage: GetVolumeByName('sdcard') failed
I/Gecko   (17902): ##### DeviceStorage: GetVolumeByName('sdcard') failed

Then, b2g-ps shows the following:

APPLICATION    SEC USER     PID   PPID  VSIZE  RSS     WCHAN    PC         NAME
b2g              0 root      293   1     260440 87776 ffffffff 00000000 S /system/b2g/b2g
(Nuwa)           0 root      552   293   66952  22940 ffffffff 00000000 S /system/b2g/b2g
Homescreen       2 u0_a1117  1117  552   89768  30076 ffffffff 00000000 S /system/b2g/b2g
Built-in Keyboa  2 u0_a1292  1292  293   90196  31936 ffffffff 00000000 S /system/b2g/plugin-container
Smart Collectio  2 u0_a1462  1462  552   75964  28200 ffffffff 00000000 S /system/b2g/b2g
FM Radio         2 u0_a2020  2020  552   97168  30108 ffffffff 00000000 S /system/b2g/b2g
(Preallocated a  2 u0_a17902 17902 552   71120  18376 ffffffff 00000000 S /system/b2g/b2g

Comment 5

[Dave Hylands [:dhylands]]

Attachment: Don't try and process DS notifications if the process isn't using DS.

Prevents a process which doesn't use device storage from trying to process device storage file update events.

Comment 6

[Alphan Chen [:alchen]]

Comment on attachment 8574979 [details] [diff] [review]
Don't try and process DS notifications if the process isn't using DS.

Review of attachment 8574979 [details] [diff] [review]:
-----------------------------------------------------------------

Hi Dave,
I checked the patch. 
There is no concern for this patch.

In my understanding, the error log should be happened when the process receive DS notification.
So process which isn't using DS will hit this problem.
What is the relationship between this problem and the symptom of this bug (Unable to import apps/addons using navigator.mozApps.mgmt.import())?

::: dom/ipc/ContentChild.cpp
@@ +2221,2 @@
>      nsRefPtr<DeviceStorageFile> dsf = new DeviceStorageFile(aStorageType, aStorageName, aPath);
>  

> I/Gecko   ( 1590): ##### DeviceStorage: GetVolumeByName('sdcard') failed
Is the error log happened on this line?

Comment 7

[Dave Hylands [:dhylands]]

(In reply to Alphan Chen [:Alphan] from comment #6)
> Comment on attachment 8574979 [details] [diff] [review]
> Don't try and process DS notifications if the process isn't using DS.
> 
> Review of attachment 8574979 [details] [diff] [review]:
> -----------------------------------------------------------------
> 
> Hi Dave,
> I checked the patch. 
> There is no concern for this patch.
> 
> In my understanding, the error log should be happened when the process
> receive DS notification.
> So process which isn't using DS will hit this problem.
> What is the relationship between this problem and the symptom of this bug
> (Unable to import apps/addons using navigator.mozApps.mgmt.import())?

I don't think that this bug is related. I think that importing addons uses device storage and caused the "##### DeviceStorage: GetVolumeByName('sdcard')" messages.

So this patch addresses the "##### DeviceStorage: GetVolumeByName('sdcard')" messages which were showing up and shouldn't have.

> ::: dom/ipc/ContentChild.cpp
> @@ +2221,2 @@
> >      nsRefPtr<DeviceStorageFile> dsf = new DeviceStorageFile(aStorageType, aStorageName, aPath);
> >  
> 
> > I/Gecko   ( 1590): ##### DeviceStorage: GetVolumeByName('sdcard') failed
> Is the error log happened on this line?

Yeah - In this particular scenario, its the preallocated app which displaying the error messages. And its happening because the preallocated app doesn't yet know what the list of volumes is. So any attempt to instantiate a DeviceStorageFile object will fail.

Once the preallocated app is converted into a real app, it will be given a list of volumes. The particular notification means that some app updated a file on device storage and is telling the other apps about it.

Until an app uses device storage, there isn't any need to process these events.

Comment 8

[Alphan Chen [:alchen]]

Comment on attachment 8574979 [details] [diff] [review]
Don't try and process DS notifications if the process isn't using DS.

Review of attachment 8574979 [details] [diff] [review]:
-----------------------------------------------------------------

It looks good for me.

Comment 9

[Dave Hylands [:dhylands]]

https://hg.mozilla.org/integration/b2g-inbound/rev/d93c07e6bcd2

Comment 10

[Dave Hylands [:dhylands]]

Backed out: https://hg.mozilla.org/integration/b2g-inbound/rev/7b56591efd68

seems to be causing: https://treeherder.mozilla.org/logviewer.html#?job_id=1604377&repo=b2g-inbound

Comment 11

[Pulsebot]

https://hg.mozilla.org/integration/b2g-inbound/rev/f7f06b74b198

Comment 12

[Dave Hylands [:dhylands]]

Original patch was too aggressive.

Try run with updated patch:
https://treeherder.mozilla.org/#/jobs?repo=try&revision=bd7abeb3d389

Comment 13

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/mozilla-central/rev/f7f06b74b198