[Dolphin][USB Storage] Dolphin's USB storage takes 16.54 seconds to be detected

RESOLVED WONTFIX

Status

P2
normal
RESOLVED WONTFIX
5 years ago
10 months ago

People

(Reporter: whsu, Assigned: lianxiang.zhou)

Tracking

({perf})

unspecified
ARM
Gonk (Firefox OS)

Firefox Tracking Flags

(blocking-b2g:-, b2g-v1.4 affected)

Details

(Whiteboard: [1.4-dolphin-test-run-2][c=progress p= s= u=][povb])

(Reporter)

Description

5 years ago
* Description:
  After enabling the USB storage of Dolphin device, it takes 16.54 seconds to be detected.
  Attach the Buri and Tarako's data. FYI.
  - Buri(v1.4) - 3.47 seconds
  - Tarako - 6.31 seconds

* Reproduction steps:
  1. Launch the settings app
  2. Go to "Storage" -> "Media storage"
  3. Toggle "Share using USB"
  4. Toggle "USB storage"
  5. Check how long will it be detected.

* Expected result:
  Result should be similar to/better than Tarako device.

* Actual result:
  USB storage takes 16.54 seconds to be detected.

* Reproduction build: V1.4 (Dolphin)
 - Gaia      5c9e1e4131d3ac8915ed88b72bb66dc7d97be6a0
 - Gecko     a9ee8ae4cca454deb67405fe07de84e713834e05
 - BuildID   20140707144650
 - Version   30.0
(Reporter)

Updated

5 years ago
blocking-b2g: --- → 1.4?
Whiteboard: [1.4-dolphin-test-run-2]
(Reporter)

Updated

5 years ago
Keywords: perf
(Reporter)

Comment 1

5 years ago
I saw the logs.
--- -- - --- -- - --- -- - --- -- - --- -- - --- -- - --- -- - --- -- -
I/AutoMounter(  111): Changing mode from 'Disable' to 'Enable'
D/Vold    (   95): Volume sdcard0 state changing 4 (Mounted) -> 5 (Unmounting)
D/gralloc.scx15(  111): alloc_device_alloc w:256, h:256, format:2 usage:0x133 start
D/gralloc.scx15(  111): the flag 0x4 and the vadress is 0xb114c000 and the size is 0x40000
D/gralloc.scx15(  111): alloc_device_alloc handle:0xaf89be80 end err is 0
D/WCND    (   97): is_cp2_alive_ok: open polling interface: /dev/spipe_wcn0, fd = 11
D/WCND    (   97): is_cp2_alive_ok: loop: /dev/spipe_wcn0 is OK
D/ENGPC   (  119): parse_event: event { 'change', '/devices/platform/sprd-battery.0/power_supply/battery', 'power_supply', '' }
D/ENGPC   (  131): parse_event: event { 'change', '/devices/platform/sprd-battery.0/power_supply/battery', 'power_supply', '' }
D/batterysrv(   98): write 25
D/batterysrv(   98):  to /productinfo/.save_capacity 
W/Vold    (   95): Failed to unmount /storage/sdcard0 (Device or resource busy, retries 9, action 0)
W/Vold    (   95): Failed to unmount /storage/sdcard0 (Device or resource busy, retries 8, action 0)
W/Vold    (   95): Failed to unmount /storage/sdcard0 (Device or resource busy, retries 7, action 0)
D/WCND    (   97): is_cp2_alive_ok: open polling interface: /dev/spipe_wcn0, fd = 11
D/WCND    (   97): is_cp2_alive_ok: loop: /dev/spipe_wcn0 is OK
W/Vold    (   95): Failed to unmount /storage/sdcard0 (Device or resource busy, retries 6, action 0)
W/Vold    (   95): Failed to unmount /storage/sdcard0 (Device or resource busy, retries 5, action 0)
W/Vold    (   95): Failed to unmount /storage/sdcard0 (Device or resource busy, retries 4, action 0)
W/Vold    (   95): Failed to unmount /storage/sdcard0 (Device or resource busy, retries 3, action 0)
D/WCND    (   97): is_cp2_alive_ok: open polling interface: /dev/spipe_wcn0, fd = 11
D/WCND    (   97): is_cp2_alive_ok: loop: /dev/spipe_wcn0 is OK
W/Vold    (   95): Failed to unmount /storage/sdcard0 (Device or resource busy, retries 2, action 1)
D/ENGPC   (  119): parse_event: event { 'remove', '/devices/virtual/bdi/0:24', 'bdi', '' }
D/ENGPC   (  131): parse_event: event { 'remove', '/devices/virtual/bdi/0:24', 'bdi', '' }
D/Vold    (   95): Volume sdcard0 state changing 5 (Unmounting) -> 1 (Idle-Unmounted)
I/AutoMounter(  111): UpdateState: Volume sdcard0 is nsIVolume::STATE_IDLE
I/AutoMounterSetting(  111): Changing status from 'Disabled' to 'Enabled'

--- -- - --- -- - --- -- - --- -- - --- -- - --- -- - --- -- - --- -- -
Is it a root cause?
- W/Vold    (   95): Failed to unmount /storage/sdcard0 (Device or resource busy, retries 6, action 0)

Comment 2

5 years ago
HiJames: Is it possible that logging is writing to sd card? Can you find one to study why it takes so long to umount sd card. thanks!
Flags: needinfo?(james.zhang)
Maybe it cause by slog, lianxiang, can you check this log?
Assignee: nobody → lianxiang.zhou
status-b2g-v1.4: --- → affected
Flags: needinfo?(james.zhang) → needinfo?(lianxiang.zhou)
(Assignee)

Comment 4

4 years ago
I/VolumeManager(  113): Volume sdcard0: changing state from Mounted to Unmounting (4 observers)
E/        (  873): check_available_volume: statfs /storage/sdcard0 return err! [107]
I/Vold    (   95): /mnt/secure/asec sucessfully unmounted
W/Vold    (   95): Failed to unmount /storage/sdcard0 (Device or resource busy, retries 9, action 0)
E/ProcessKiller(   95): Process /system/bin/slog (873) has open file /storage/sdcard0/slog/2014-07-29-06-30-05/kernel/0-kernel-06-30-06.log
W/Vold    (   95): Failed to unmount /storage/sdcard0 (Device or resource busy, retries 8, action 0)
E/ProcessKiller(   95): Process /system/bin/slog (873) has open file /storage/sdcard0/slog/2014-07-29-06-30-05/kernel/0-kernel-06-30-06.log
W/Vold    (   95): Failed to unmount /storage/sdcard0 (Device or resource busy, retries 7, action 0)
E/ProcessKiller(   95): Process /system/bin/slog (873) has open file /storage/sdcard0/slog/2014-07-29-06-30-05/kernel/0-kernel-06-30-06.log
W/Vold    (   95): Failed to unmount /storage/sdcard0 (Device or resource busy, retries 6, action 0)
E/ProcessKiller(   95): Process /system/bin/slog (873) has open file /storage/sdcard0/slog/2014-07-29-06-30-05/kernel/0-kernel-06-30-06.log
E/        (  873): check_available_volume: statfs /storage/sdcard0 return err! [107]
W/Vold    (   95): Failed to unmount /storage/sdcard0 (Device or resource busy, retries 5, action 0)
E/ProcessKiller(   95): Process /system/bin/slog (873) has open file /storage/sdcard0/slog/2014-07-29-06-30-05/kernel/0-kernel-06-30-06.log
W/Vold    (   95): Failed to unmount /storage/sdcard0 (Device or resource busy, retries 4, action 0)
E/ProcessKiller(   95): Process /system/bin/slog (873) has open file /storage/sdcard0/slog/2014-07-29-06-30-05/kernel/0-kernel-06-30-06.log
W/Vold    (   95): Failed to unmount /storage/sdcard0 (Device or resource busy, retries 3, action 0)
E/ProcessKiller(   95): Process /system/bin/slog (873) has open file /storage/sdcard0/slog/2014-07-29-06-30-05/kernel/0-kernel-06-30-06.log
W/Vold    (   95): Failed to unmount /storage/sdcard0 (Device or resource busy, retries 2, action 1)
E/ProcessKiller(   95): Process /system/bin/slog (873) has open file /storage/sdcard0/slog/2014-07-29-06-30-05/kernel/0-kernel-06-30-06.log
I/Vold    (   95): /storage/sdcard0 sucessfully unmounted
I/Vold    (   95): /mnt/media_rw/sdcard0 sucessfully unmounted
I/Vold    (   95): /mnt/media_rw/sdcard0 unmounted successfully
-----------
I got the above log, it shows that the the slog block the umount.
There is no retry after I stop slog.

It will take usleep(1000*1000) every retry, so those retries will take about 10s.
Maybe the Umount function is too soft to kill it until retry 8 or 9 times.

"stop slog" can avoid the long wait.
Flags: needinfo?(lianxiang.zhou)
Status: NEW → ASSIGNED
Whiteboard: [1.4-dolphin-test-run-2] → [1.4-dolphin-test-run-2][c=progress p= s= u=1.4]
please ensure slog is disabled when shipping
blocking-b2g: 1.4? → -
Flags: needinfo?(lianxiang.zhou)
Whiteboard: [1.4-dolphin-test-run-2][c=progress p= s= u=1.4] → [1.4-dolphin-test-run-2][c=progress p= s= u=1.4][povb]
(Assignee)

Comment 6

4 years ago
(In reply to Wayne Chang [:wchang] from comment #5)
> please ensure slog is disabled when shipping

There's no slog on the user version.
Flags: needinfo?(lianxiang.zhou)

Comment 7

4 years ago
So should this bug be closed without fixed?

Updated

4 years ago
Priority: -- → P2
Whiteboard: [1.4-dolphin-test-run-2][c=progress p= s= u=1.4][povb] → [1.4-dolphin-test-run-2][c=progress p= s= u=][povb]

Comment 8

10 months ago
Firefox OS is not being worked on
Status: ASSIGNED → RESOLVED
Last Resolved: 10 months ago
Resolution: --- → WONTFIX
You need to log in before you can comment on or make changes to this bug.