Closed Bug 1041853 Opened 11 years ago Closed 11 years ago

when camera running in monkey test several hours,the screen fixed,Physical key invalid and Computer does not recognize the device

Categories

(Firefox OS Graveyard :: Gaia::Camera, defect)

ARM
Gonk (Firefox OS)
defect
Not set
major

Tracking

(blocking-b2g:1.4+, b2g-v1.4 fixed, b2g-v2.0 wontfix, b2g-v2.1 wontfix)

RESOLVED FIXED
blocking-b2g 1.4+
Tracking Status
b2g-v1.4 --- fixed
b2g-v2.0 --- wontfix
b2g-v2.1 --- wontfix

People

(Reporter: ben.song, Assigned: GaryChen)

References

Details

Attachments

(6 files)

No description provided.
This log is about monkey test,when it runs several hours,the screen is fixed,at the same time the Physical key is invalid and computer does not recognize the device. By analyzing the log,I find when lowmemorykiller appears,someone app will be destroy,but in the last,when lowmemorykiller appears and here Only the camera application,however it have not been destroy.This happens a lot of times,camera app still exists.So it Occupied more and more memory that this occurs. In addition,i find some operations of camera memory still execute while camera app has been killed.Before open camera app,the memory consumption is not obvious,but after that the consume Increasing
Flags: needinfo?(ttsai)
Flags: needinfo?(kkuo)
06-28 15:27:05.710 845 845 E GeckoConsole: Content JS LOG at app://system.gaiamobile.org/js/app_window.js:795 in aw_debug: [Dump: AppWindow][Camera][31810.961] Handling mozbrowserasyncscroll event... 06-28 15:27:05.720 845 879 D gralloc.scx15: alloc_device_free buffer_handle_t:0xa90fc760 start 06-28 15:27:05.720 845 879 D gralloc.scx15: alloc_device_free buffer_handle_t:0xa90fc760 flags:0x4 start 06-28 15:27:05.720 845 879 D gralloc.scx15: alloc_device_free the vadress 0xabe4d000 size of 0x190500 will be free 06-28 15:27:05.720 845 879 D gralloc.scx15: alloc_device_free end 06-28 15:27:05.720 845 879 D gralloc.scx15: alloc_device_free buffer_handle_t:0xa90fc1c0 start 06-28 15:27:05.720 845 879 D gralloc.scx15: alloc_device_free buffer_handle_t:0xa90fc1c0 flags:0x4 start 06-28 15:27:05.720 845 879 D gralloc.scx15: alloc_device_free the vadress 0xabfde000 size of 0x190500 will be free 06-28 15:27:05.720 845 879 D gralloc.scx15: alloc_device_free end 06-28 15:27:05.770 31800 31800 I Gecko : --> _setActive: function cp_setActive(elt) 06-28 15:27:05.790 845 879 D gralloc.scx15: alloc_device_free buffer_handle_t:0xa90fca00 start 06-28 15:27:05.790 845 879 D gralloc.scx15: alloc_device_free buffer_handle_t:0xa90fca00 flags:0x4 start 06-28 15:27:05.790 845 879 D gralloc.scx15: alloc_device_free the vadress 0xab08d000 size of 0x172c80 will be free 06-28 15:27:05.790 845 879 D gralloc.scx15: alloc_device_free end 06-28 15:27:05.790 845 879 D gralloc.scx15: alloc_device_free buffer_handle_t:0xa90fc8e0 start 06-28 15:27:05.790 845 879 D gralloc.scx15: alloc_device_free buffer_handle_t:0xa90fc8e0 flags:0x4 start 06-28 15:27:05.790 845 879 D gralloc.scx15: alloc_device_free the vadress 0xabcda000 size of 0x172c80 will be free 06-28 15:27:05.790 845 879 D gralloc.scx15: alloc_device_free end 06-28 15:27:05.860 31800 31800 I Gecko : --> _setActive: function cp_setActive(elt) 06-28 15:27:05.870 31800 31800 I Gecko : onTouchEnd: function cp_onTouchEnd(evt) this._finishPanning() 06-28 15:27:05.870 31800 31800 I Gecko : --> handleEvent: function cp_handleEvent,this.onTouchEnd(evt) 06-28 15:27:05.870 845 879 D gralloc.scx15: alloc_device_free buffer_handle_t:0xa97a22e0 start 06-28 15:27:05.870 845 879 D gralloc.scx15: alloc_device_free buffer_handle_t:0xa97a22e0 flags:0x4 start 06-28 15:27:05.870 845 879 D gralloc.scx15: alloc_device_free the vadress 0xa7cc7000 size of 0x1338c00 will be free 06-28 15:27:05.880 845 879 D gralloc.scx15: alloc_device_free end 06-28 15:27:06.320 845 879 D gralloc.scx15: alloc_device_alloc w:480, h:854, format:1 usage:0x133 start 06-28 15:27:06.320 845 879 D gralloc.scx15: the flag 0x4 and the vadress is 0xabfde000 and the size is 0x190500 06-28 15:27:06.320 845 879 D gralloc.scx15: alloc_device_alloc handle:0xa90fc160 end err is 0 06-28 15:27:06.320 845 879 D gralloc.scx15: alloc_device_alloc w:480, h:854, format:1 usage:0x133 start 06-28 15:27:06.330 845 879 D gralloc.scx15: the flag 0x4 and the vadress is 0xabe4d000 and the size is 0x190500 06-28 15:27:06.330 845 879 D gralloc.scx15: alloc_device_alloc handle:0xa90fc700 end err is 0 06-28 15:27:06.340 845 879 D gralloc.scx15: alloc_device_free buffer_handle_t:0xa90fcb80 start 06-28 15:27:06.340 845 879 D gralloc.scx15: alloc_device_free buffer_handle_t:0xa90fcb80 flags:0x4 start 06-28 15:27:06.340 845 879 D gralloc.scx15: alloc_device_free the vadress 0xac9de000 size of 0x190500 will be free 06-28 15:27:06.340 845 879 D gralloc.scx15: alloc_device_free end 06-28 15:27:06.370 845 879 D gralloc.scx15: alloc_device_alloc w:3888, h:2916, format:1 usage:0x133 start 06-28 15:27:07.500 845 879 D gralloc.scx15: the flag 0x4 and the vadress is 0xa64c0000 and the size is 0x2b3fb00 06-28 15:27:07.520 845 879 D gralloc.scx15: alloc_device_alloc handle:0xa90011c0 end err is 0 06-28 15:27:07.550 32040 32040 D refnotify: Enter RefNotify main 06-28 15:27:07.550 32040 32040 D refnotify: Enter RefNotify main td_flag 1 06-28 15:27:07.560 32040 32040 E refnotify: RefNotify open /dev/spipe_td8 failed, error: No such file or directory 06-28 15:27:07.570 845 879 D gralloc.scx15: alloc_device_alloc w:3888, h:2916, format:1 usage:0x133 start
06-28 15:27:10.443 <6>[31945.272070] c0 [ pid ] uid tgid total_vm rss nr_ptes swapents oom_score_adj name 06-28 15:27:10.443 <6>[31945.272116] c0 [ 83] 0 83 132 32 3 24 -941 ueventd 06-28 15:27:10.443 <6>[31945.272132] c0 [ 94] 0 94 358 27 4 8 -941 healthd 06-28 15:27:10.443 <6>[31945.272145] c0 [ 95] 1000 95 252 1 3 24 -941 servicemanager 06-28 15:27:10.443 <6>[31945.272157] c0 [ 96] 0 96 1149 0 4 86 -941 vold 06-28 15:27:10.443 <6>[31945.272171] c0 [ 97] 1000 97 1521 0 5 34 -941 modemd 06-28 15:27:10.443 <6>[31945.272183] c0 [ 98] 1000 98 1071 0 4 52 -941 wcnd 06-28 15:27:10.443 <6>[31945.272195] c0 [ 99] 0 99 90 0 3 6 -941 batterysrv 06-28 15:27:10.443 <6>[31945.272208] c0 [ 100] 1001 100 230 0 3 26 -941 rilproxy 06-28 15:27:10.443 <6>[31945.272221] c0 [ 101] 1001 101 230 0 3 26 -941 rilproxy 06-28 15:27:10.443 <6>[31945.272233] c0 [ 103] 0 103 2411 0 7 87 -941 netd 06-28 15:27:10.443 <6>[31945.272245] c0 [ 104] 0 104 259 0 3 31 -941 debuggerd 06-28 15:27:10.443 <6>[31945.272258] c0 [ 105] 0 105 346 0 3 50 -941 rild 06-28 15:27:10.443 <6>[31945.272270] c0 [ 106] 1013 106 8507 1 24 480 -941 mediaserver 06-28 15:27:10.443 <6>[31945.272283] c0 [ 107] 1012 107 250 0 3 35 -941 installd 06-28 15:27:10.443 <6>[31945.272296] c0 [ 108] 1017 108 821 1 4 80 -941 keystore 06-28 15:27:10.443 <6>[31945.272309] c0 [ 109] 0 109 824 1 4 40 -941 Binder_2 06-28 15:27:10.443 <6>[31945.272321] c0 [ 110] 0 110 1080 1 4 41 -941 Binder_2 06-28 15:27:10.782 <6>[31945.272334] c0 [ 112] 1001 112 230 0 3 25 -941 rilproxy 06-28 15:27:10.782 <6>[31945.272347] c0 [ 115] 0 115 540 0 3 38 -941 refnotify 06-28 15:27:10.782 <6>[31945.272360] c0 [ 117] 0 117 265 0 3 30 -941 srtd 06-28 15:27:10.782 <6>[31945.272372] c0 [ 118] 0 118 381 1 3 48 -941 engmoded 06-28 15:27:10.782 <6>[31945.272385] c0 [ 120] 2000 120 233 1 3 29 -941 sh 06-28 15:27:10.782 <6>[31945.272397] c0 [ 123] 0 123 265 0 3 31 -941 srtd 06-28 15:27:10.782 <6>[31945.272410] c0 [ 130] 1000 130 7466 0 17 139 -941 phoneserver 06-28 15:27:10.782 <6>[31945.272423] c0 [ 133] 0 133 2481 0 7 166 -941 engpc 06-28 15:27:10.782 <6>[31945.272436] c0 [ 139] 0 139 1029 0 4 528 -941 nvitemd 06-28 15:27:10.782 <6>[31945.272448] c0 [ 179] 0 179 1957 0 7 150 -941 engpc 06-28 15:27:10.782 <6>[31945.272462] c0 [ 436] 1023 436 629 0 4 112 -941 sdcard 06-28 15:27:10.782 <6>[31945.272475] c0 [ 443] 0 443 1149 36 6 17 -941 adbd 06-28 15:27:10.782 <6>[31945.272487] c0 [ 584] 0 584 1246 0 6 105 -941 slog 06-28 15:27:10.782 <6>[31945.272500] c0 [ 759] 1001 759 2683 1 8 76 -941 rild_sp 06-28 15:27:10.782 <6>[31945.272512] c0 [ 760] 1001 760 2682 1 8 74 -941 rild_sp 06-28 15:27:10.782 <6>[31945.343151] c0 [ 845] 0 845 58853 68 132 16758 0 b2g 06-28 15:27:10.782 <6>[31945.343177] c0 [ 896] 0 896 13033 0 29 2303 0 (Nuwa) 06-28 15:27:10.782 <6>[31945.343191] c0 [26396] 36396 26396 17162 2 38 3391 134 Calendar 06-28 15:27:10.782 <6>[31945.343207] c0 [31633] 0 31633 215 5 4 19 0 orng 06-28 15:27:10.782 <6>[31945.343222] c0 [31800] 41800 31800 39568 49 86 4556 134 Camera
Hi! Is this from Dolphin device? -- Keven
Flags: needinfo?(kkuo)
ben.song, which device are you testing on?
Flags: needinfo?(ben.song)
(In reply to pcheng from comment #5) > ben.song, which device are you testing on? v1.4 dolphin 7715
Flags: needinfo?(ben.song)
(In reply to Keven Kuo [:kkuo] from comment #4) > Hi! > > Is this from Dolphin device? > > -- > Keven Hi Keven Kuo, yes,it is.
Based on log analysis, the problem is due to the camera or gallery loaded with high-definition picture, the pixel value is 3888 * 2916, so that the system will assign the pictures a piece of memory: w: 3888, h: 2916 memory, but this memory is in lowmemory state therefore need to close camera applications, and its closed is applied in response to a mozBrowsererror event, but this time the event did not respond, so the phone is in a state of suspended. Now we should analysis the limit of high definition pictures in camera and gallery app.
Flags: needinfo?(ttsai)
I find the limit of image pixel size of Dophin is hard to change and other methods for reduce the cosuming of zooming pictures are not avaliable.But The big memory consuming of zooming pictures could cause camera and gallery be killed and even screen of the device be fixed and not inoperable.
Flags: needinfo?(pcheng)
Flags: needinfo?(kkuo)
Rachelle, could you please help assign?
Flags: needinfo?(pcheng) → needinfo?(ryang)
Hi Ben.Song, what is the physical key? do you mean camera key? Thanks.
Flags: needinfo?(ryang) → needinfo?(ben.song)
(In reply to Rachelle Yang [:ryang][ryang@mozilla.com] from comment #11) > Hi Ben.Song, what is the physical key? do you mean camera key? > Thanks. Hi Rachelle, The physical key what I mean contains sleep button,home button,volumnUp button and volumnDown button,thanks.
Flags: needinfo?(ben.song)
Please help to push this issue sovle , Thanks.
Flags: needinfo?(ryang)
Depends on: 997051
Depends on: 998228
Can you try the same device/sprd/sp6821a_gonk/camera.json as tarako? camera.json { "maxImagePixelSize": 2097152, "maxSnapshotPixelSize": 1920000, "maxGifImageFileSize": 1048576, "maxPickPixelSize": 480000, "maxEditPixelSize": 480000 }
Hi thomas, To modify the file of camera.json could restrict maxFileSize value of pictures,but not maxPixelSize value.For In gaia,the limiting value of maxPixelSize of JPEG type pictures would be expanded 50 times.So the limit would has less effect.
(In reply to thomas tsai from comment #14) > Can you try the same device/sprd/sp6821a_gonk/camera.json as tarako? > camera.json > { > "maxImagePixelSize": 2097152, > "maxSnapshotPixelSize": 1920000, > "maxGifImageFileSize": 1048576, > "maxPickPixelSize": 480000, > "maxEditPixelSize": 480000 > } Hi thomas, To modify the file of camera.json could restrict maxFileSize value of pictures,but not maxPixelSize value.For In gaia,the limiting value of maxPixelSize of JPEG type pictures would be expanded 50 times.So the limit would has less effect.
(In reply to ben.song from comment #9) > I find the limit of image pixel size of Dophin is hard to change and other > methods for reduce the cosuming of zooming pictures are not avaliable.But > The big memory consuming of zooming pictures could cause camera and gallery > be killed and even screen of the device be fixed and not inoperable. so we need the patch on bug 997051 for 1.4
(In reply to Evelyn Hung [:evelyn] from comment #17) > (In reply to ben.song from comment #9) > > I find the limit of image pixel size of Dophin is hard to change and other > > methods for reduce the cosuming of zooming pictures are not avaliable.But > > The big memory consuming of zooming pictures could cause camera and gallery > > be killed and even screen of the device be fixed and not inoperable. > > so we need the patch on bug 997051 for 1.4 OK,but the code has been different from 1.3 and if or not we would expand several times the pixel limit when the picture type is JPEG.
> { > "maxImagePixelSize": 2097152, > "maxSnapshotPixelSize": 1920000, > "maxGifImageFileSize": 1048576, > "maxPickPixelSize": 480000, > "maxEditPixelSize": 480000 > } To telling more about this config file: 1. we may need to uplift bug 997051 to enable "maxImagePixelSize" in open.html 2. we may need to uplift bug 995148 to enable "maxGifImageFileSize" in app and open.html 3. we may need to uplift bug 989290 to enable "maxPickPixelSize" in app 4. we may need to uplift bug 998095 to enable "maxEditPixelSize" in app Hope that helps.
Depends on: 995148, 989290, 998095
[Blocking Requested - why for this release]: for passing monkey test. I don't know if this is a blocker, but we need to uplift a few patches(described in comment 19) so we can better configure picture size handled by these media apps.
blocking-b2g: --- → 1.4?
blocking-b2g: 1.4? → 1.4+
(In reply to John Hu [:johnhu][:johu][:醬糊小弟] from comment #19) > > { > > "maxImagePixelSize": 2097152, > > "maxSnapshotPixelSize": 1920000, > > "maxGifImageFileSize": 1048576, > > "maxPickPixelSize": 480000, > > "maxEditPixelSize": 480000 > > } > > To telling more about this config file: > 1. we may need to uplift bug 997051 to enable "maxImagePixelSize" in > open.html > 2. we may need to uplift bug 995148 to enable "maxGifImageFileSize" in app > and open.html > 3. we may need to uplift bug 989290 to enable "maxPickPixelSize" in app > 4. we may need to uplift bug 998095 to enable "maxEditPixelSize" in app > > Hope that helps. Hi all, After checking the code base on 1.4[1], I found only "maxGifImageFileSize" missed on it. So I just uplifted bug 995148 master patch[2], in this patch we use "maxUnknownImageFileSize" instead of "maxGifImageFileSize" on master branch. I think it should be nice to align code base with master so I prefer to use "maxUnknownImageFileSize". [1] https://github.com/mozilla-b2g/gaia/blob/v1.4/apps/gallery/build/build.js [2] https://bugzilla.mozilla.org/show_bug.cgi?id=995148#c32
Gary, I am assigning this to you since you are helping with it. Thank you!
Assignee: nobody → gchen
Hi all, After discussing with John Hu, we also need 'maxGifImageFileSize' so I added it back. Waiting for TPBL passing then we can land it.
Patch is on the way. Thanks!
Flags: needinfo?(ryang)
Status: NEW → RESOLVED
Closed: 11 years ago
Resolution: --- → FIXED
Flags: needinfo?(kkuo)
Are other branches unaffected?
status-b2g-v2.0: --- → ?
status-b2g-v2.1: --- → ?
Flags: needinfo?(gchen)
only for v1.4
Flags: needinfo?(gchen)
If 2.0/2.1 need support 256MB device, I suggest you land this patch. I think we will kick off dolphin 2.0 or 2.1 project.
Hi Rachelle and Evelyn, As James Zhang mentioned, do we need to uplift this patch on 2.0 or 2.1 project? Please help me to make a decision for this, thanks.
Flags: needinfo?(ryang)
Flags: needinfo?(ehung)
bug 997051 - already on master per its comment 7. It should be in 2.0 too bug 995148 - need another fix per comment 30. Please open a follow up for it. bug 989290 - need a follow up per comment 77? bug 998095 - can't infer it's status from comments. I think these questions should go to app owner to be took into their plan on master (v2.1). As we stands on partner support side, we won't touch them until the branch is really associated with a device or project.
Flags: needinfo?(ehung)
Setting the statuses to wontfix so they don't show up on my "needs uplift" queries. Feel free to set them back to affected if the decision is made to land these on v2.0/v2.1.
patch is landed on 1.4.
Flags: needinfo?(ryang)
Flags: in-moztrap?(smiko)
NO STR is present to create test case to address bug.
QA Whiteboard: [QAnalyst-Triage?]
Flags: needinfo?(ktucker)
QA Whiteboard: [QAnalyst-Triage?] → [QAnalyst-Triage+]
Flags: needinfo?(ktucker)
Flags: in-moztrap?(smiko)
Flags: in-moztrap-
Hi GaryChen, In recent monkey test,this problem has be reproduced,and I find some log in main log: 08-18 08:01:17.740 803 835 D gralloc.scx15: alloc_device_alloc w:2916, h:3888, format:1 usage:0x133 start 08-18 08:01:18.230 803 835 D gralloc.scx15: the flag 0x4 and the vadress is 0xa4ec0000 and the size is 0x2b3fb00 08-18 08:01:18.300 803 835 D gralloc.scx15: alloc_device_alloc handle:0xa8602220 end err is 0 08-18 08:01:18.500 803 835 D gralloc.scx15: alloc_device_alloc w:2916, h:3888, format:1 usage:0x133 start 08-18 08:01:22.300 12687 12691 I GonkMemoryPressure: Checking to see if memory pressure is over. 08-18 08:01:22.320 803 822 I GonkMemoryPressure: Checking to see if memory pressure is over. 08-18 08:01:22.320 803 822 I GonkMemoryPressure: Memory pressure is over. 08-18 08:01:22.320 12687 12691 I GonkMemoryPressure: Memory pressure is over. And I want to know which operation would allocate the memory of w:2916, h:3888 for I could not find the place,thanks.
Flags: needinfo?(gchen)
As I know, camera apps would not allocate these strange width and heigh. Hi Vliu, Can you help on this issue? Thanks.
Flags: needinfo?(gchen) → needinfo?(vliu)
(In reply to ben.song from comment #34) > Hi GaryChen, > > In recent monkey test,this problem has be reproduced,and I find some log > in main log: > 08-18 08:01:17.740 803 835 D gralloc.scx15: alloc_device_alloc w:2916, > h:3888, format:1 usage:0x133 start > 08-18 08:01:18.230 803 835 D gralloc.scx15: the flag 0x4 and the vadress > is 0xa4ec0000 and the size is 0x2b3fb00 > 08-18 08:01:18.300 803 835 D gralloc.scx15: alloc_device_alloc > handle:0xa8602220 end err is 0 > 08-18 08:01:18.500 803 835 D gralloc.scx15: alloc_device_alloc w:2916, > h:3888, format:1 usage:0x133 start > 08-18 08:01:22.300 12687 12691 I GonkMemoryPressure: Checking to see if > memory pressure is over. > 08-18 08:01:22.320 803 822 I GonkMemoryPressure: Checking to see if > memory pressure is over. > 08-18 08:01:22.320 803 822 I GonkMemoryPressure: Memory pressure is over. > 08-18 08:01:22.320 12687 12691 I GonkMemoryPressure: Memory pressure is over. > > And I want to know which operation would allocate the memory of w:2916, > h:3888 for I could not find the place,thanks. Does the case you meant for camera preview? AFSIK I know Camera assigns width/heigh of each buffer here. https://hg.mozilla.org/releases/mozilla-b2g30_v1_4/file/100e718553cd/widget/gonk/nativewindow/GonkBufferQueueKK.cpp#l402
Flags: needinfo?(vliu)
Attached file main-log
Hi GaryChen,Vincent, In this main log this problem happens and the device is out of memory.Through my analysis, the origin of this problem is the allocation of two pieces memory.
Flags: needinfo?(vliu)
Flags: needinfo?(gchen)
I think Danny can look into it more deeper.
Flags: needinfo?(vliu)
(In reply to ben.song from comment #37) > Created attachment 8486347 [details] > main-log > > Hi GaryChen,Vincent, > > In this main log this problem happens and the device is out of > memory.Through my analysis, the origin of this problem is the allocation of > two pieces memory. Hi Ben, something need your support to clarify. 1. Is the symptom you met this time same as tilte? 2. Do you have any kernel log or sysdump for further analysis? This case should be system hang and PC cannot recognize device, we suspected there is deadlock that caused by memory allocation. Generally, b2g memory allocation won't cause this kind of problems, so we might need your help to provide kernel related information to address the problem. Moreover, jtag will be a good tool to debug when adb doesn't work. For memory pressure event, it's normal when cache is lower than 14MB, b2g and linux kernel both have policies to handle low memory cases.
Flags: needinfo?(ben.song)
Attached file kernel-log.zip
Hi Danny, This comment is kernel log of the problem.And I have met this problem same as tilte twice.I hve used crash tools to handle sysdump files,but some problem appear like this: crash: read error: kernel virtual address: c056ae14 type: "cpu_possible_mask" Thanks.
Flags: needinfo?(ben.song) → needinfo?(dliang)
(In reply to ben.song from comment #40) > Created attachment 8486987 [details] > kernel-log.zip > > Hi Danny, > > This comment is kernel log of the problem.And I have met this problem > same as tilte twice.I hve used crash tools to handle sysdump files,but some > problem appear like this: > > crash: read error: kernel virtual address: c056ae14 type: > "cpu_possible_mask" > > Thanks. Hi Ben, The kernel log you attached looks like after reboot, it doesn't match logcat, could you attach the correct one? For the crash error, I think you can find help to Ying.xu or James because I know they can parse sysdump well.
Flags: needinfo?(dliang) → needinfo?(ben.song)
(In reply to Danny Liang [:dliang] from comment #41) > (In reply to ben.song from comment #40) > > Created attachment 8486987 [details] > > kernel-log.zip > > > > Hi Danny, > > > > This comment is kernel log of the problem.And I have met this problem > > same as tilte twice.I hve used crash tools to handle sysdump files,but some > > problem appear like this: > > > > crash: read error: kernel virtual address: c056ae14 type: > > "cpu_possible_mask" > > > > Thanks. > > Hi Ben, > The kernel log you attached looks like after reboot, it doesn't match > logcat, could you attach the correct one? > For the crash error, I think you can find help to Ying.xu or James because I > know they can parse sysdump well. Hi Danny, The kernel log which in Comment 40 is the correct one certainly.It is the one before reboot and at the end of it out_of_memory appears. For the crash error,I would find help to others but I think the sysdump probabily has been broken.
Flags: needinfo?(ben.song)
Ben, you are right, I found the correct timestamp of kernel log in comment 40. Please help to answer following questions. Below is the end of logcat, log stop at 08-18 08:01:22 08-18 08:01:17.740 803 835 D gralloc.scx15: alloc_device_alloc handle:0xa8602fa0 end err is 0 08-18 08:01:17.740 803 835 D gralloc.scx15: alloc_device_alloc w:2916, h:3888, format:1 usage:0x133 start 08-18 08:01:18.230 803 835 D gralloc.scx15: the flag 0x4 and the vadress is 0xa4ec0000 and the size is 0x2b3fb00 08-18 08:01:18.300 803 835 D gralloc.scx15: alloc_device_alloc handle:0xa8602220 end err is 0 08-18 08:01:18.500 803 835 D gralloc.scx15: alloc_device_alloc w:2916, h:3888, format:1 usage:0x133 start 08-18 08:01:22.300 12687 12691 I GonkMemoryPressure: Checking to see if memory pressure is over. 08-18 08:01:22.320 803 822 I GonkMemoryPressure: Checking to see if memory pressure is over. 08-18 08:01:22.320 803 822 I GonkMemoryPressure: Memory pressure is over. 08-18 08:01:22.320 12687 12691 I GonkMemoryPressure: Memory pressure is over. In kernel log, I found OOM at 08:01:22, it killed camera and but something weird here: 08-18 08:01:22.465 <4>[19208.310669] c0 Compositor invoked oom-killer: gfp_mask=0x282d2, order=0, oom_score_adj=0 ... 08-18 08:01:22.465 <4>[19208.311101] c0 Normal: 196*4kB (M) 6*8kB (R) 45*16kB (MR) 9*32kB (R) 0*64kB 0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 1*4096kB (C) = 5936kB ... 08-18 08:01:22.465 <4>[19208.311161] c0 Free swap = 85788kB 08-18 08:01:22.465 <4>[19208.311167] c0 Total swap = 204796kB Free memory is enough but oom has been triggered ---- (Question 1) By kernel log, it showed kernel is alive till 08-20 12:01:03 but no log from 08-18 11:09:02 to 08-20 12:00:56. I also found some call stack might be related to adbd, could you have member to check if it's normal? ---- (Question 2) 08-18 11:09:02.170 <4>[30468.027318] c0 __SPRD__ALLOC__ONE__: buffer for order = 2 empty; free = 5, used = 5, sys = 319; peak = 5, total = 5; Call Stack: 08-18 11:09:02.170 <4>[30468.027343] c0 Process Name: sh, Process Pid: 13190, Parent Name: adbd, Parent Pid: 696 08-18 11:09:02.170 <4>[30468.027360] c0 CPU: 0 PID: 13190 Comm: sh Tainted: G W O 3.10.17-00008-g384185e #1 08-18 11:09:02.170 <4>[30468.027403] c0 [<c0013a1c>] (unwind_backtrace+0x0/0x11c) from [<c0012174>] (show_stack+0x10/0x14) 08-18 11:09:02.170 <4>[30468.027425] c0 [<c0012174>] (show_stack+0x10/0x14) from [<c0035b58>] (sprd_alloc_one+0x184/0x1a4) 08-18 11:09:02.170 <4>[30468.027443] c0 [<c0035b58>] (sprd_alloc_one+0x184/0x1a4) from [<c0036024>] (sprd_page_alloc+0x3c/0x68) 08-18 11:09:02.170 <4>[30468.027465] c0 [<c0036024>] (sprd_page_alloc+0x3c/0x68) from [<c00a14bc>] (__alloc_pages_nodemask+0x5bc/0x7a4) 08-18 11:09:02.170 <4>[30468.027485] c0 [<c00a14bc>] (__alloc_pages_nodemask+0x5bc/0x7a4) from [<c00a16b4>] (__get_free_pages+0x10/0x24) 08-18 11:09:02.170 <4>[30468.027505] c0 [<c00a16b4>] (__get_free_pages+0x10/0x24) from [<c0019360>] (pgd_alloc+0x14/0xdc) 08-18 11:09:02.170 <4>[30468.027524] c0 [<c0019360>] (pgd_alloc+0x14/0xdc) from [<c0036340>] (mm_init.isra.49+0x94/0xd4) 08-18 11:09:02.170 <4>[30468.027546] c0 [<c0036340>] (mm_init.isra.49+0x94/0xd4) from [<c00d5d8c>] (do_execve+0x1c8/0x4b8) 08-18 11:09:02.170 <4>[30468.027565] c0 [<c00d5d8c>] (do_execve+0x1c8/0x4b8) from [<c00d62a0>] (SyS_execve+0x30/0x44) 08-18 11:09:02.170 <4>[30468.027585] c0 [<c00d62a0>] (SyS_execve+0x30/0x44) from [<c000f440>] (ret_fast_syscall+0x0/0x30) Is it easy to reproduce? If yes, it will be useful to have a complete sysdump for analysis next time.
Flags: needinfo?(ben.song)
(In reply to Danny Liang [:dliang] from comment #43) > Ben, you are right, I found the correct timestamp of kernel log in comment > 40. Please help to answer following questions. > > Below is the end of logcat, log stop at 08-18 08:01:22 > > 08-18 08:01:17.740 803 835 D gralloc.scx15: alloc_device_alloc > handle:0xa8602fa0 end err is 0 > 08-18 08:01:17.740 803 835 D gralloc.scx15: alloc_device_alloc w:2916, > h:3888, format:1 usage:0x133 start > 08-18 08:01:18.230 803 835 D gralloc.scx15: the flag 0x4 and the vadress > is 0xa4ec0000 and the size is 0x2b3fb00 > 08-18 08:01:18.300 803 835 D gralloc.scx15: alloc_device_alloc > handle:0xa8602220 end err is 0 > 08-18 08:01:18.500 803 835 D gralloc.scx15: alloc_device_alloc w:2916, > h:3888, format:1 usage:0x133 start > 08-18 08:01:22.300 12687 12691 I GonkMemoryPressure: Checking to see if > memory pressure is over. > 08-18 08:01:22.320 803 822 I GonkMemoryPressure: Checking to see if > memory pressure is over. > 08-18 08:01:22.320 803 822 I GonkMemoryPressure: Memory pressure is over. > 08-18 08:01:22.320 12687 12691 I GonkMemoryPressure: Memory pressure is over. > > In kernel log, I found OOM at 08:01:22, it killed camera and but something > weird here: > > 08-18 08:01:22.465 <4>[19208.310669] c0 Compositor invoked oom-killer: > gfp_mask=0x282d2, order=0, oom_score_adj=0 > ... > 08-18 08:01:22.465 <4>[19208.311101] c0 Normal: 196*4kB (M) 6*8kB (R) > 45*16kB (MR) 9*32kB (R) 0*64kB 0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB > 1*4096kB (C) = 5936kB > ... > 08-18 08:01:22.465 <4>[19208.311161] c0 Free swap = 85788kB > 08-18 08:01:22.465 <4>[19208.311167] c0 Total swap = 204796kB > > Free memory is enough but oom has been triggered ---- (Question 1) > > By kernel log, it showed kernel is alive till 08-20 12:01:03 but no log from > 08-18 11:09:02 to 08-20 12:00:56. I also found some call stack might be > related to adbd, could you have member to check if it's normal? ---- > (Question 2) > > 08-18 11:09:02.170 <4>[30468.027318] c0 __SPRD__ALLOC__ONE__: buffer for > order = 2 empty; free = 5, used = 5, sys = 319; peak = 5, total = 5; Call > Stack: > 08-18 11:09:02.170 <4>[30468.027343] c0 Process Name: sh, Process Pid: > 13190, Parent Name: adbd, Parent Pid: 696 > 08-18 11:09:02.170 <4>[30468.027360] c0 CPU: 0 PID: 13190 Comm: sh Tainted: > G W O 3.10.17-00008-g384185e #1 > 08-18 11:09:02.170 <4>[30468.027403] c0 [<c0013a1c>] > (unwind_backtrace+0x0/0x11c) from [<c0012174>] (show_stack+0x10/0x14) > 08-18 11:09:02.170 <4>[30468.027425] c0 [<c0012174>] (show_stack+0x10/0x14) > from [<c0035b58>] (sprd_alloc_one+0x184/0x1a4) > 08-18 11:09:02.170 <4>[30468.027443] c0 [<c0035b58>] > (sprd_alloc_one+0x184/0x1a4) from [<c0036024>] (sprd_page_alloc+0x3c/0x68) > 08-18 11:09:02.170 <4>[30468.027465] c0 [<c0036024>] > (sprd_page_alloc+0x3c/0x68) from [<c00a14bc>] > (__alloc_pages_nodemask+0x5bc/0x7a4) > 08-18 11:09:02.170 <4>[30468.027485] c0 [<c00a14bc>] > (__alloc_pages_nodemask+0x5bc/0x7a4) from [<c00a16b4>] > (__get_free_pages+0x10/0x24) > 08-18 11:09:02.170 <4>[30468.027505] c0 [<c00a16b4>] > (__get_free_pages+0x10/0x24) from [<c0019360>] (pgd_alloc+0x14/0xdc) > 08-18 11:09:02.170 <4>[30468.027524] c0 [<c0019360>] (pgd_alloc+0x14/0xdc) > from [<c0036340>] (mm_init.isra.49+0x94/0xd4) > 08-18 11:09:02.170 <4>[30468.027546] c0 [<c0036340>] > (mm_init.isra.49+0x94/0xd4) from [<c00d5d8c>] (do_execve+0x1c8/0x4b8) > 08-18 11:09:02.170 <4>[30468.027565] c0 [<c00d5d8c>] (do_execve+0x1c8/0x4b8) > from [<c00d62a0>] (SyS_execve+0x30/0x44) > 08-18 11:09:02.170 <4>[30468.027585] c0 [<c00d62a0>] (SyS_execve+0x30/0x44) > from [<c000f440>] (ret_fast_syscall+0x0/0x30) > > Is it easy to reproduce? If yes, it will be useful to have a complete > sysdump for analysis next time. Hi Danny, I ask the QA and find the problem not reproduce after we updated the monkey script.But I can offer another main log, kernel log,sysdump file.I find this problem always happens at the end of camera app.
Flags: needinfo?(ben.song)
Attached file kernel-log2.zip
Attached file main-log2.zip
Hi(In reply to ben.song from comment #44) > (In reply to Danny Liang [:dliang] from comment #43) > > Ben, you are right, I found the correct timestamp of kernel log in comment > > 40. Please help to answer following questions. > > > > Below is the end of logcat, log stop at 08-18 08:01:22 > > > > 08-18 08:01:17.740 803 835 D gralloc.scx15: alloc_device_alloc > > handle:0xa8602fa0 end err is 0 > > 08-18 08:01:17.740 803 835 D gralloc.scx15: alloc_device_alloc w:2916, > > h:3888, format:1 usage:0x133 start > > 08-18 08:01:18.230 803 835 D gralloc.scx15: the flag 0x4 and the vadress > > is 0xa4ec0000 and the size is 0x2b3fb00 > > 08-18 08:01:18.300 803 835 D gralloc.scx15: alloc_device_alloc > > handle:0xa8602220 end err is 0 > > 08-18 08:01:18.500 803 835 D gralloc.scx15: alloc_device_alloc w:2916, > > h:3888, format:1 usage:0x133 start > > 08-18 08:01:22.300 12687 12691 I GonkMemoryPressure: Checking to see if > > memory pressure is over. > > 08-18 08:01:22.320 803 822 I GonkMemoryPressure: Checking to see if > > memory pressure is over. > > 08-18 08:01:22.320 803 822 I GonkMemoryPressure: Memory pressure is over. > > 08-18 08:01:22.320 12687 12691 I GonkMemoryPressure: Memory pressure is over. > > > > In kernel log, I found OOM at 08:01:22, it killed camera and but something > > weird here: > > > > 08-18 08:01:22.465 <4>[19208.310669] c0 Compositor invoked oom-killer: > > gfp_mask=0x282d2, order=0, oom_score_adj=0 > > ... > > 08-18 08:01:22.465 <4>[19208.311101] c0 Normal: 196*4kB (M) 6*8kB (R) > > 45*16kB (MR) 9*32kB (R) 0*64kB 0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB > > 1*4096kB (C) = 5936kB > > ... > > 08-18 08:01:22.465 <4>[19208.311161] c0 Free swap = 85788kB > > 08-18 08:01:22.465 <4>[19208.311167] c0 Total swap = 204796kB > > > > Free memory is enough but oom has been triggered ---- (Question 1) > > > > By kernel log, it showed kernel is alive till 08-20 12:01:03 but no log from > > 08-18 11:09:02 to 08-20 12:00:56. I also found some call stack might be > > related to adbd, could you have member to check if it's normal? ---- > > (Question 2) > > > > 08-18 11:09:02.170 <4>[30468.027318] c0 __SPRD__ALLOC__ONE__: buffer for > > order = 2 empty; free = 5, used = 5, sys = 319; peak = 5, total = 5; Call > > Stack: > > 08-18 11:09:02.170 <4>[30468.027343] c0 Process Name: sh, Process Pid: > > 13190, Parent Name: adbd, Parent Pid: 696 > > 08-18 11:09:02.170 <4>[30468.027360] c0 CPU: 0 PID: 13190 Comm: sh Tainted: > > G W O 3.10.17-00008-g384185e #1 > > 08-18 11:09:02.170 <4>[30468.027403] c0 [<c0013a1c>] > > (unwind_backtrace+0x0/0x11c) from [<c0012174>] (show_stack+0x10/0x14) > > 08-18 11:09:02.170 <4>[30468.027425] c0 [<c0012174>] (show_stack+0x10/0x14) > > from [<c0035b58>] (sprd_alloc_one+0x184/0x1a4) > > 08-18 11:09:02.170 <4>[30468.027443] c0 [<c0035b58>] > > (sprd_alloc_one+0x184/0x1a4) from [<c0036024>] (sprd_page_alloc+0x3c/0x68) > > 08-18 11:09:02.170 <4>[30468.027465] c0 [<c0036024>] > > (sprd_page_alloc+0x3c/0x68) from [<c00a14bc>] > > (__alloc_pages_nodemask+0x5bc/0x7a4) > > 08-18 11:09:02.170 <4>[30468.027485] c0 [<c00a14bc>] > > (__alloc_pages_nodemask+0x5bc/0x7a4) from [<c00a16b4>] > > (__get_free_pages+0x10/0x24) > > 08-18 11:09:02.170 <4>[30468.027505] c0 [<c00a16b4>] > > (__get_free_pages+0x10/0x24) from [<c0019360>] (pgd_alloc+0x14/0xdc) > > 08-18 11:09:02.170 <4>[30468.027524] c0 [<c0019360>] (pgd_alloc+0x14/0xdc) > > from [<c0036340>] (mm_init.isra.49+0x94/0xd4) > > 08-18 11:09:02.170 <4>[30468.027546] c0 [<c0036340>] > > (mm_init.isra.49+0x94/0xd4) from [<c00d5d8c>] (do_execve+0x1c8/0x4b8) > > 08-18 11:09:02.170 <4>[30468.027565] c0 [<c00d5d8c>] (do_execve+0x1c8/0x4b8) > > from [<c00d62a0>] (SyS_execve+0x30/0x44) > > 08-18 11:09:02.170 <4>[30468.027585] c0 [<c00d62a0>] (SyS_execve+0x30/0x44) > > from [<c000f440>] (ret_fast_syscall+0x0/0x30) > > > > Is it easy to reproduce? If yes, it will be useful to have a complete > > sysdump for analysis next time. > Hi Danny, > > I ask the QA and find the problem not reproduce after we updated the > monkey script.But I can offer another main log, kernel log,sysdump file.I > find this problem always happens at the end of camera app. Hi Ben, Can we file another new bug for tracking this issue? Seems this is not relative to camera app. Thanks.
Flags: needinfo?(gchen)
(In reply to GaryChen [:GaryChen][:PYChen][:陳柏宇] from comment #47) > Hi(In reply to ben.song from comment #44) > > (In reply to Danny Liang [:dliang] from comment #43) > > > Ben, you are right, I found the correct timestamp of kernel log in comment > > > 40. Please help to answer following questions. > > > > > > Below is the end of logcat, log stop at 08-18 08:01:22 > > > > > > 08-18 08:01:17.740 803 835 D gralloc.scx15: alloc_device_alloc > > > handle:0xa8602fa0 end err is 0 > > > 08-18 08:01:17.740 803 835 D gralloc.scx15: alloc_device_alloc w:2916, > > > h:3888, format:1 usage:0x133 start > > > 08-18 08:01:18.230 803 835 D gralloc.scx15: the flag 0x4 and the vadress > > > is 0xa4ec0000 and the size is 0x2b3fb00 > > > 08-18 08:01:18.300 803 835 D gralloc.scx15: alloc_device_alloc > > > handle:0xa8602220 end err is 0 > > > 08-18 08:01:18.500 803 835 D gralloc.scx15: alloc_device_alloc w:2916, > > > h:3888, format:1 usage:0x133 start > > > 08-18 08:01:22.300 12687 12691 I GonkMemoryPressure: Checking to see if > > > memory pressure is over. > > > 08-18 08:01:22.320 803 822 I GonkMemoryPressure: Checking to see if > > > memory pressure is over. > > > 08-18 08:01:22.320 803 822 I GonkMemoryPressure: Memory pressure is over. > > > 08-18 08:01:22.320 12687 12691 I GonkMemoryPressure: Memory pressure is over. > > > > > > In kernel log, I found OOM at 08:01:22, it killed camera and but something > > > weird here: > > > > > > 08-18 08:01:22.465 <4>[19208.310669] c0 Compositor invoked oom-killer: > > > gfp_mask=0x282d2, order=0, oom_score_adj=0 > > > ... > > > 08-18 08:01:22.465 <4>[19208.311101] c0 Normal: 196*4kB (M) 6*8kB (R) > > > 45*16kB (MR) 9*32kB (R) 0*64kB 0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB > > > 1*4096kB (C) = 5936kB > > > ... > > > 08-18 08:01:22.465 <4>[19208.311161] c0 Free swap = 85788kB > > > 08-18 08:01:22.465 <4>[19208.311167] c0 Total swap = 204796kB > > > > > > Free memory is enough but oom has been triggered ---- (Question 1) > > > > > > By kernel log, it showed kernel is alive till 08-20 12:01:03 but no log from > > > 08-18 11:09:02 to 08-20 12:00:56. I also found some call stack might be > > > related to adbd, could you have member to check if it's normal? ---- > > > (Question 2) > > > > > > 08-18 11:09:02.170 <4>[30468.027318] c0 __SPRD__ALLOC__ONE__: buffer for > > > order = 2 empty; free = 5, used = 5, sys = 319; peak = 5, total = 5; Call > > > Stack: > > > 08-18 11:09:02.170 <4>[30468.027343] c0 Process Name: sh, Process Pid: > > > 13190, Parent Name: adbd, Parent Pid: 696 > > > 08-18 11:09:02.170 <4>[30468.027360] c0 CPU: 0 PID: 13190 Comm: sh Tainted: > > > G W O 3.10.17-00008-g384185e #1 > > > 08-18 11:09:02.170 <4>[30468.027403] c0 [<c0013a1c>] > > > (unwind_backtrace+0x0/0x11c) from [<c0012174>] (show_stack+0x10/0x14) > > > 08-18 11:09:02.170 <4>[30468.027425] c0 [<c0012174>] (show_stack+0x10/0x14) > > > from [<c0035b58>] (sprd_alloc_one+0x184/0x1a4) > > > 08-18 11:09:02.170 <4>[30468.027443] c0 [<c0035b58>] > > > (sprd_alloc_one+0x184/0x1a4) from [<c0036024>] (sprd_page_alloc+0x3c/0x68) > > > 08-18 11:09:02.170 <4>[30468.027465] c0 [<c0036024>] > > > (sprd_page_alloc+0x3c/0x68) from [<c00a14bc>] > > > (__alloc_pages_nodemask+0x5bc/0x7a4) > > > 08-18 11:09:02.170 <4>[30468.027485] c0 [<c00a14bc>] > > > (__alloc_pages_nodemask+0x5bc/0x7a4) from [<c00a16b4>] > > > (__get_free_pages+0x10/0x24) > > > 08-18 11:09:02.170 <4>[30468.027505] c0 [<c00a16b4>] > > > (__get_free_pages+0x10/0x24) from [<c0019360>] (pgd_alloc+0x14/0xdc) > > > 08-18 11:09:02.170 <4>[30468.027524] c0 [<c0019360>] (pgd_alloc+0x14/0xdc) > > > from [<c0036340>] (mm_init.isra.49+0x94/0xd4) > > > 08-18 11:09:02.170 <4>[30468.027546] c0 [<c0036340>] > > > (mm_init.isra.49+0x94/0xd4) from [<c00d5d8c>] (do_execve+0x1c8/0x4b8) > > > 08-18 11:09:02.170 <4>[30468.027565] c0 [<c00d5d8c>] (do_execve+0x1c8/0x4b8) > > > from [<c00d62a0>] (SyS_execve+0x30/0x44) > > > 08-18 11:09:02.170 <4>[30468.027585] c0 [<c00d62a0>] (SyS_execve+0x30/0x44) > > > from [<c000f440>] (ret_fast_syscall+0x0/0x30) > > > > > > Is it easy to reproduce? If yes, it will be useful to have a complete > > > sysdump for analysis next time. > > Hi Danny, > > > > I ask the QA and find the problem not reproduce after we updated the > > monkey script.But I can offer another main log, kernel log,sysdump file.I > > find this problem always happens at the end of camera app. > > Hi Ben, > Can we file another new bug for tracking this issue? > Seems this is not relative to camera app. > > Thanks. Hi GaryChen, OK,I have do it,thanks.
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: