845522 - Slow rendering: loop of « Freeing buffer » & « Allocated buffer » may affect power usage

Status: RESOLVED WORKSFORME

(Firefox OS Graveyard :: General, defect, P4)

Description

[Nicolas B. Pierron [:nbp] {away}]

STR:
 - Open octane benchmark in the browser, add it as a home screen bookmark.
 - Start the home screen bookmark

Expected:
 - The page should show-up immediately.

Seen:
 - White background and the following loop of messages in the logcat:

D/memalloc(  109): /dev/pmem: Allocated buffer base:0x4af0a000 size:40960 offset:1269760 fd:122
D/memalloc(  109): /dev/pmem: Freeing buffer base:0x4b054000 size:40960 offset:1351680 fd:131

D/memalloc(  109): /dev/pmem: Allocated buffer base:0x4af0a000 size:40960 offset:1351680 fd:131
D/memalloc(  109): /dev/pmem: Freeing buffer base:0x4b040000 size:40960 offset:1269760 fd:122
D/memalloc(  109): /dev/pmem: Allocated buffer base:0x4af0a000 size:40960 offset:1269760 fd:122
D/memalloc(  109): /dev/pmem: Freeing buffer base:0x4b054000 size:40960 offset:1351680 fd:131

D/memalloc(  109): /dev/pmem: Allocated buffer base:0x4af0a000 size:40960 offset:1351680 fd:131
D/memalloc(  109): /dev/pmem: Freeing buffer base:0x4b036000 size:40960 offset:1228800 fd:126
D/memalloc(  109): /dev/pmem: Allocated buffer base:0x4af0a000 size:40960 offset:1228800 fd:126
D/memalloc(  109): /dev/pmem: Freeing buffer base:0x4b040000 size:40960 offset:1269760 fd:122
D/memalloc(  109): /dev/pmem: Allocated buffer base:0x4af0a000 size:40960 offset:1269760 fd:122
D/memalloc(  109): /dev/pmem: Freeing buffer base:0x4b054000 size:40960 offset:1351680 fd:131

D/memalloc(  109): /dev/pmem: Allocated buffer base:0x4af0a000 size:40960 offset:1351680 fd:131
D/memalloc(  109): /dev/pmem: Freeing buffer base:0x4b036000 size:40960 offset:1228800 fd:126
D/memalloc(  109): /dev/pmem: Allocated buffer base:0x4af0a000 size:40960 offset:1228800 fd:126
D/memalloc(  109): /dev/pmem: Freeing buffer base:0x4b054000 size:40960 offset:1351680 fd:131

D/memalloc(  109): /dev/pmem: Allocated buffer base:0x4af0a000 size:40960 offset:1351680 fd:131
D/memalloc(  109): /dev/pmem: Freeing buffer base:0x4b040000 size:40960 offset:1269760 fd:122
D/memalloc(  109): /dev/pmem: Allocated buffer base:0x4af0a000 size:40960 offset:1269760 fd:122
D/memalloc(  109): /dev/pmem: Freeing buffer base:0x4b054000 size:40960 offset:1351680 fd:131

D/memalloc(  109): /dev/pmem: Allocated buffer base:0x4af0a000 size:40960 offset:1351680 fd:131
D/memalloc(  109): /dev/pmem: Freeing buffer base:0x4b040000 size:40960 offset:1269760 fd:122
D/memalloc(  109): /dev/pmem: Allocated buffer base:0x4af0a000 size:40960 offset:1269760 fd:122
D/memalloc(  109): /dev/pmem: Freeing buffer base:0x4b036000 size:40960 offset:1228800 fd:126
D/memalloc(  109): /dev/pmem: Allocated buffer base:0x4af0a000 size:40960 offset:1228800 fd:126
D/memalloc(  109): /dev/pmem: Freeing buffer base:0x4b054000 size:40960 offset:1351680 fd:131

D/memalloc(  109): /dev/pmem: Allocated buffer base:0x4af0a000 size:40960 offset:1351680 fd:131
D/memalloc(  109): /dev/pmem: Freeing buffer base:0x4b040000 size:40960 offset:1269760 fd:122
D/memalloc(  109): /dev/pmem: Allocated buffer base:0x4af0a000 size:40960 offset:1269760 fd:122
D/memalloc(  109): /dev/pmem: Freeing buffer base:0x4b054000 size:40960 offset:1351680 fd:131

… ending this way:

D/memalloc(  109): /dev/pmem: Freeing buffer base:0x4b040000 size:40960 offset:1269760 fd:122
D/memalloc(  109): /dev/pmem: Allocated buffer base:0x4af0a000 size:40960 offset:1269760 fd:122
D/memalloc(  109): /dev/pmem: Freeing buffer base:0x4b054000 size:40960 offset:1351680 fd:131
D/memalloc(  109): /dev/pmem: Allocated buffer base:0x4af0a000 size:614400 offset:1351680 fd:142 <-- ** diff **
D/memalloc( 1059): /dev/pmem: Mapped buffer base:0x44700000 size:1966080 offset:1351680 fd:27
D/memalloc(  109): /dev/pmem: Freeing buffer base:0x4b040000 size:40960 offset:1269760 fd:122
D/memalloc(  109): /dev/pmem: Freeing buffer base:0x4b036000 size:40960 offset:1228800 fd:126
D/memalloc(  109): /dev/pmem: Allocated buffer base:0x4af0a000 size:614400 offset:1966080 fd:122
D/memalloc( 1059): /dev/pmem: Mapped buffer base:0x44c00000 size:2580480 offset:1966080 fd:30

Note:
 - This STR is not the only one for reproducing this logcat result, I can also reproduce it on the gallery application while scrolling on a huge list of pictures.

Comment 1

[Lukas Blakk [:lsblakk] use ?needinfo]

We need more info here to make a call on tracking - what is the perf hit? what are our goals? Please prioritize this work within the perf improvements expected for v1.1 so we can make a decision on tracking with that in mind.

Comment 2

[Lukas Blakk [:lsblakk] use ?needinfo]

Follow up question re: gallery application scrolling - you can reproduce this logcat but what does the user see?  Slow scrolling, white screen or something else?

Comment 3

[Nicolas B. Pierron [:nbp] {away}]

(In reply to Lukas Blakk [:lsblakk] from comment #1)
> We need more info here to make a call on tracking - what is the perf hit?
> what are our goals? Please prioritize this work within the perf improvements
> expected for v1.1 so we can make a decision on tracking with that in mind.

perf hit, no noticeable perf hit.  I was mostly worried about the battery life at this point, because we should be idle instead of constantly doing this memory manipulation.

(In reply to Lukas Blakk [:lsblakk] from comment #2)
> Follow up question re: gallery application scrolling - you can reproduce
> this logcat but what does the user see?  Slow scrolling, white screen or
> something else?

It appears normal.

Comment 4

[Lukas Blakk [:lsblakk] use ?needinfo]

(In reply to Nicolas B. Pierron [:nbp] from comment #3)
> (In reply to Lukas Blakk [:lsblakk] from comment #2)
> > Follow up question re: gallery application scrolling - you can reproduce
> > this logcat but what does the user see?  Slow scrolling, white screen or
> > something else?
> 
> It appears normal.

In that case we don't see a reason to track this.

Comment 5

[Mike Lee [:mlee]]

Nicolas, what phone were you using and over how much time did these log messages occur.

Comment 6

[Nicolas B. Pierron [:nbp] {away}]

(In reply to Mike Lee [:mlee] from comment #5)
> Nicolas, what phone were you using and over how much time did these log
> messages occur.

I only tested that on Unagi's at the time. I have not tried to reproduce it since.  I cannot reproduce this issue with the STR provided in comment 0.

Comment 7

[Nicholas Nethercote [inactive]]

> I only tested that on Unagi's at the time. I have not tried to reproduce it
> since.  I cannot reproduce this issue with the STR provided in comment 0.

The last two sentences here appear to be contradictory. nbp, is this bug still relevant, or do you think it can be closed? Thanks.

Comment 8

[Nicolas B. Pierron [:nbp] {away}]

(In reply to Nicholas Nethercote [:njn] from comment #7)
> > I only tested that on Unagi's at the time. I have not tried to reproduce it
> > since.  I cannot reproduce this issue with the STR provided in comment 0.
> 
> The last two sentences here appear to be contradictory. nbp, is this bug
> still relevant, or do you think it can be closed? Thanks.

I meant I have not tried to reproduce it on the gallery application since, because all my photos got erased by the test infrastructures.