1036312 - Camera flash flashes when in background

Status: VERIFIED FIXED

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

Description

[Dale Harvey (:daleharvey)]

Just noticed this, on my flame dev device

1. Open Camera application
2. Turn phone screen off
3. Place device on its back on a desk

I am seeing the a flashing white light come from under the camera, if I kill the camera app it goes away

Comment 1

[Mike Habicher [:mikeh] (high bugzilla latency)]

I have confirmed this on:

Gaia      f71bf6ee534275a44ae3e475e9e2a5dfeebbc0ae
Gecko     https://hg.mozilla.org/integration/b2g-inbound/rev/e2402e271fb6
BuildID   20140709032231
Version   33.0a1
ro.build.version.incremental=108
ro.build.date=Tue Jun 10 19:40:40 CST 2014

Looking at the logcat, the preview is still running even when the camera is hidden (and ultimately when the screen goes to sleep).

justin, is the app calling .release() when it goes into the background?

Comment 3

[Justin D'Arcangelo [:justindarc]]

(In reply to Mike Habicher [:mikeh] from comment #1)
> I have confirmed this on:
> 
> Gaia      f71bf6ee534275a44ae3e475e9e2a5dfeebbc0ae
> Gecko     https://hg.mozilla.org/integration/b2g-inbound/rev/e2402e271fb6
> BuildID   20140709032231
> Version   33.0a1
> ro.build.version.incremental=108
> ro.build.date=Tue Jun 10 19:40:40 CST 2014
> 
> Looking at the logcat, the preview is still running even when the camera is
> hidden (and ultimately when the screen goes to sleep).
> 
> justin, is the app calling .release() when it goes into the background?

Yes, we are calling .release() when the app loses focus. I'm not able to reproduce with the latest Flame build anymore, but I think a couple days ago I did see this issue happen.

Gaia      0f9f11d0a6dadb3ea27160204bbe911c1ad69a6f
Gecko     https://hg.mozilla.org/mozilla-central/rev/196d05832e12
BuildID   20140709040203
Version   33.0a1
ro.build.version.incremental=109
ro.build.date=Mon Jun 16 16:51:29 CST 2014

Comment 4

[Soledad Penades [:sole] [:spenades]]

I just flashed the latest version of Gonk and Gaia on the Flame and started getting this cyclical flashing a few minutes ago. I had been testing the 'record' activity and locked the phone while the camera activity was displayed on the screen.

This happens with the phone locked *AND* resting on its back - I realised because the cable pulled it up a bit, enough to realise that something was flashing at me.

I rotated the phone so the screen would face the table but then I didn't get this flashing.

Logcat is going insane, this is just a bit of it:

D/GonkNativeWindow( 2008): GonkNativeWindow::returnBuffer
V/GonkConsumerBase( 2008): addReleaseFenceLocked: slot=5
V/GonkConsumerBase( 2008): releaseBufferLocked: slot=5
E/mm-camera(  392): msg_bus_post_msg: bus_msg type is not valid
E/mm-camera(  392): stats_port_event: Failure posting to the bus!
E/mm-camera(  392): msg_bus_post_msg: bus_msg type is not valid
E/mm-camera(  392): stats_port_event: Failure posting to the bus!
E/mm-camera(  392): msg_bus_post_msg: bus_msg type is not valid
E/mm-camera(  392): stats_port_event: Failure posting to the bus!
E/mm-camera(  392): port_isp_module_event: received AWB update event, identity = 0x10002
E/mm-camera(  392): msg_bus_post_msg: bus_msg type is not valid
E/mm-camera(  392): stats_port_event: Failure posting to the bus!
E/mm-camera(  392): msg_bus_post_msg: bus_msg type is not valid
E/mm-camera(  392): stats_port_event: Failure posting to the bus!
E/mm-camera(  392): c2d_thread_handle_process_buf_event:176 input buf index 9
E/mm-camera(  392): c2d_thread_handle_process_buf_event:188 input vaddr b54e4000
E/mm-camera(  392): c2d_thread_handle_process_buf_event:251 output buf index 8, buf size 462848
E/mm-camera(  392): isp_hw_proc_subdev_event:[Profile] before vfe_diag info
E/mm-camera(  392): isp_hw_proc_subdev_event:[Profile] after vfe_diag info
E/mm-camera(  392): msg_bus_post_msg: bus_msg type is not valid
E/mm-camera(  392): stats_port_event: Failure posting to the bus!
E/mm-camera(  392): msg_bus_post_msg: bus_msg type is not valid
E/mm-camera(  392): stats_port_event: Failure posting to the bus!
E/mm-camera(  392): msg_bus_post_msg: bus_msg type is not valid
E/mm-camera(  392): stats_port_event: Failure posting to the bus!
E/mm-camera(  392): msg_bus_post_msg: bus_msg type is not valid
E/mm-camera(  392): isp_ch_util_hw_notify_sof: meta dump data to bus error
E/mm-camera(  392): mct_stream_fill_metadata_v1:1119 Unsupported message type
E/mm-camera(  392): mct_stream_fill_metadata_v1:1119 Unsupported message type
E/mm-camera(  392): mct_stream_fill_metadata_v1:1119 Unsupported message type
E/mm-camera(  392): mct_stream_fill_metadata_v1:1119 Unsupported message type
E/mm-camera(  392): mct_stream_fill_metadata_v1:1119 Unsupported message type
E/mm-camera(  392): mct_stream_fill_metadata_v1:1119 Unsupported message type
D/mm-camera-intf(  280): mm_stream_read_msm_frame: VIDIOC_DQBUF buf_index 3, frame_idx 3875, stream type 7
D/QCamera2HWI(  280): static void qcamera::QCamera2HardwareInterface::metadata_stream_cb_routine(mm_camera_super_buf_t*, qcamera::QCameraStream*, void*): hdr_scene_data: 1 0 0.000000
E/QCamera2HWI(  280): int32_t qcamera::QCamera2HardwareInterface::processHDRData(cam_asd_hdr_scene_data_t) : hdr_scene_data: processHDRData: 0 0.000000
D/mm-camera-intf(  280): mm_stream_read_msm_frame: VIDIOC_DQBUF buf_index 8, frame_idx 3875, stream type 1
D/QCamera2HWI(  280): [KPI Perf] static void qcamera::QCamera2HardwareInterface::preview_stream_cb_routine(mm_camera_super_buf_t*, qcamera::QCameraStream*, void*) : BEGIN
V/GonkBufferQueue( 2008): queueBuffer: slot=8 time=0xc6cf78b82f9 crop=[0,0,640,480] tr=0 scale=SCALE_TO_WINDOW
V/GonkConsumerBase( 2008): onFrameAvailable
V/GonkConsumerBase( 2008): acquireBufferLocked: -> slot=8
V/GonkBufferQueue( 2008): dequeueBuffer: w=640 h=480 fmt=0x11 usage=0x40020000
V/GonkBufferQueue( 2008): dequeueBuffer: returning slot=0 buf=0xb18d2880 flags=0
D/QCamera2HWI(  280): [KPI Perf] static void qcamera::QCamera2HardwareInterface::preview_stream_cb_routine(mm_camera_super_buf_t*, qcamera::QCameraStream*, void*) : END
D/GonkNativeWindow( 2008): GonkNativeWindow::returnBuffer
V/GonkConsumerBase( 2008): addReleaseFenceLocked: slot=7
V/GonkConsumerBase( 2008): releaseBufferLocked: slot=7
E/AEC_PORT(  392): aec_port_save_update:real_gain:1.011719 linecnt:43 exp_idx:127 cur_luma:238 led_est:1
E/mm-camera(  392): msg_bus_post_msg: bus_msg type is not valid
E/mm-camera(  392): stats_port_event: Failure posting to the bus!
E/mm-camera(  392): msg_bus_post_msg: bus_msg type is not valid
E/mm-camera(  392): stats_port_event: Failure posting to the bus!
E/mm-camera(  392): msg_bus_post_msg: bus_msg type is not valid
E/mm-camera(  392): stats_port_event: Failure posting to the bus!
E/mm-camera(  392): port_isp_module_event: received AWB update event, identity = 0x10002
E/mm-camera(  392): msg_bus_post_msg: bus_msg type is not valid
E/mm-camera(  392): stats_port_event: Failure posting to the bus!
E/mm-camera(  392): msg_bus_post_msg: bus_msg type is not valid
E/mm-camera(  392): stats_port_event: Failure posting to the bus!
E/mm-camera(  392): isp_hw_proc_subdev_event:[Profile] before vfe_diag info
E/mm-camera(  392): isp_hw_proc_subdev_event:[Profile] after vfe_diag info
E/mm-camera(  392): msg_bus_post_msg: bus_msg type is not valid
E/mm-camera(  392): isp_ch_util_hw_notify_sof: meta dump data to bus error
E/mm-camera(  392): c2d_thread_handle_process_buf_event:176 input buf index 3
E/mm-camera(  392): c2d_thread_handle_process_buf_event:188 input vaddr b578a000
E/mm-camera(  392): c2d_thread_handle_process_buf_event:251 output buf index 1, buf size 462848
E/mm-camera(  392): mct_stream_fill_metadata_v1:1119 Unsupported message type
E/mm-camera(  392): mct_stream_fill_metadata_v1:1119 Unsupported message type
E/mm-camera(  392): mct_stream_fill_metadata_v1:1119 Unsupported message type
E/mm-camera(  392): mct_stream_fill_metadata_v1:1119 Unsupported message type
D/mm-camera-intf(  280): mm_stream_read_msm_frame: VIDIOC_DQBUF buf_index 4, frame_idx 3876, stream type 7
D/QCamera2HWI(  280): static void qcamera::QCamera2HardwareInterface::metadata_stream_cb_routine(mm_camera_super_buf_t*, qcamera::QCameraStream*, void*): hdr_scene_data: 1 0 0.000000
E/QCamera2HWI(  280): int32_t qcamera::QCamera2HardwareInterface::processHDRData(cam_asd_hdr_scene_data_t) : hdr_scene_data: processHDRData: 0 0.000000
E/mm-camera(  392): msg_bus_post_msg: bus_msg type is not valid
E/mm-camera(  392): stats_port_event: Failure posting to the bus!
E/mm-camera(  392): msg_bus_post_msg: bus_msg type is not valid
E/mm-camera(  392): stats_port_event: Failure posting to the bus!
E/mm-camera(  392): msg_bus_post_msg: bus_msg type is not valid
E/mm-camera(  392): stats_port_event: Failure posting to the bus!
E/AEC_PORT(  392): aec_port_save_update:real_gain:1.082031 linecnt:11 exp_idx:84 cur_luma:238 led_est:1
D/mm-camera-intf(  280): mm_stream_read_msm_frame: VIDIOC_DQBUF buf_index 1, frame_idx 3876, stream type 1
D/QCamera2HWI(  280): [KPI Perf] static void qcamera::QCamera2HardwareInterface::preview_stream_cb_routine(mm_camera_super_buf_t*, qcamera::QCameraStream*, void*) : BEGIN
V/GonkBufferQueue( 2008): queueBuffer: slot=1 time=0xc6cf9359ed6 crop=[0,0,640,480] tr=0 scale=SCALE_TO_WINDOW
V/GonkConsumerBase( 2008): onFrameAvailable
V/GonkConsumerBase( 2008): acquireBufferLocked: -> slot=1
V/GonkBufferQueue( 2008): dequeueBuffer: w=640 h=480 fmt=0x11 usage=0x40020000
V/GonkBufferQueue( 2008): dequeueBuffer: returning slot=6 buf=0xb18d2ba0 flags=0
D/QCamera2HWI(  280): [KPI Perf] static void qcamera::QCamera2HardwareInterface::preview_stream_cb_routine(mm_camera_super_buf_t*, qcamera::QCameraStream*, void*) : END
D/GonkNativeWindow( 2008): GonkNativeWindow::returnBuffer
V/GonkConsumerBase( 2008): addReleaseFenceLocked: slot=8
V/GonkConsumerBase( 2008): releaseBufferLocked: slot=8
E/mm-camera(  392): msg_bus_post_msg: bus_msg type is not valid
E/mm-camera(  392): stats_port_event: Failure posting to the bus!
E/mm-camera(  392): msg_bus_post_msg: bus_msg type is not valid
E/mm-camera(  392): stats_port_event: Failure posting to the bus!
E/mm-camera(  392): msg_bus_post_msg: bus_msg type is not valid
E/mm-camera(  392): stats_port_event: Failure posting to the bus!
^C

Comment 5

[Mike Habicher [:mikeh] (high bugzilla latency)]

(In reply to Soledad Penades [:sole] [:spenades] from comment #4)

> I rotated the phone so the screen would face the table but then I didn't get
> this flashing.

This is because the camera facing up gets enough light that the flash isn't necessarily to complete an auto-focus cycle.

> Logcat is going insane, this is just a bit of it:

This indicates the camera is still running.

Comment 6

[Mike Habicher [:mikeh] (high bugzilla latency)]

(In reply to Justin D'Arcangelo [:justindarc] from comment #3)

> Yes, we are calling .release() when the app loses focus. I'm not able to
> reproduce with the latest Flame build anymore, but I think a couple days ago
> I did see this issue happen.

I just tried this with:

Gonk      v122
Gaia      c329a67bafe60032820ab64b52c07c22eeff114e
Gecko     https://hg.mozilla.org/integration/b2g-inbound/rev/f17ba2374df6
BuildID   20140710065755
Version   33.0a1
ro.build.version.incremental=108
ro.build.date=Tue Jun 10 19:40:40 CST 2014

...and the flash is still going off, with the camera in the background, and the screen off.

Make sure the flash mode is set to "always on" instead of "auto".

Comment 7

[Soledad Penades [:sole] [:spenades]]

Attachment: Log with boot -> open camera -> lock phone sequence

https://www.youtube.com/watch?v=VrB-xib7Ck4

Boot2Gecko 2.1.0.0-prerelease
Build 20140709160202

I rebooted the phone, opened the Camera app, locked the phone.
After a while of being sitting on the table the flash starts flashing.

Comment 8

[Justin D'Arcangelo [:justindarc]]

(In reply to Mike Habicher [:mikeh] from comment #1)
> I have confirmed this on:
> 
> Gaia      f71bf6ee534275a44ae3e475e9e2a5dfeebbc0ae
> Gecko     https://hg.mozilla.org/integration/b2g-inbound/rev/e2402e271fb6
> BuildID   20140709032231
> Version   33.0a1
> ro.build.version.incremental=108
> ro.build.date=Tue Jun 10 19:40:40 CST 2014
> 
> Looking at the logcat, the preview is still running even when the camera is
> hidden (and ultimately when the screen goes to sleep).
> 
> justin, is the app calling .release() when it goes into the background?

Mike: Looks like we are calling .release(), but we're getting caught in some kinda event loop where we end up immediately re-initializing the camera when the app goes to the background. Working on a patch now.

Comment 9

[Justin D'Arcangelo [:justindarc]]

Attachment: pull-request (master)

Diego: Not sure what happened here. Almost looks like a leftover from a bad merge.

Mike: This fixes the issue for me. If you want to give it a try, go ahead :-)

Comment 10

[Diego Marcos [:dmarcos]]

Justin. I reviewed the patch. I r-ed it because I think the check "if (this.app.hidden) { return; }" should go in CameraController.prototype.onGalleryClosed to prevent the camera to be reloaded when hidding the app. The rest of the patch looks great.

Comment 12

[Justin D'Arcangelo [:justindarc]]

Comment on attachment 8453921 [details] [review]
pull-request (master)

Diego: Addressed your comment. Ready for re-review. Thanks!

Comment 14

[Diego Marcos [:dmarcos]]

Comment on attachment 8453921 [details] [review]
pull-request (master)

We need unit tests. Wilson made a patch for a duplicated bug of this one. We can reuse his unit tests.

https://github.com/mozilla-b2g/gaia/pull/21629/files#diff-bf7d18747e2bf3b24dde031e6db92221R454

Comment 15

[Justin D'Arcangelo [:justindarc]]

Comment on attachment 8453921 [details] [review]
pull-request (master)

Copied in the unit tests.

Comment 16

[Diego Marcos [:dmarcos]]

Comment on attachment 8453921 [details] [review]
pull-request (master)

Looks great now! Ship it!

Comment 17

[Justin D'Arcangelo [:justindarc]]

Landed on master:

https://github.com/mozilla-b2g/gaia/commit/255d8257c220c710d3f4bd6f850bf3aa9d35d64b

Comment 18

[Diego Marcos [:dmarcos]]

This guy has to be uplifted to 2.0. It fixes a regression introduced by bug 1024692

Comment 19

[Jason Smith [:jsmith]]

Ok.

Comment 20

[Ryan VanderMeulen [:RyanVM]]

v2.0: https://github.com/mozilla-b2g/gaia/commit/186dd6a92c57244073fe754a3e0c3a9136ccee51

Comment 21

[Shine(Leave from Mozilla)]

Attachment: video

This issue has been verified successfully on Flame 2.0 and 2.1
 See attachment: Verify_1036312.MP4
Reproducing rate: 0/5
Reproducing steps:
1.Launch Camera.
2.Turn phone screen off
3.Place device on its back on a desk
4.Press Power key to make screen lights up and press Power key to turn off screen.
5.Unlock screen.
6.Change to Flash On mode.
7.Repeat step 2~4
** The camera flash cannot flashes when in background.

Flame 2.0 build:
Gaia-Rev        8d1e868864c8a8f1e037685f0656d1da70d08c06
Gecko-Rev       https://hg.mozilla.org/releases/mozilla-b2g32_v2_0/rev/c756bd8bf3c3
Build-ID        20141202000201
Version         32.0

Flame 2.1 build:
Gaia-Rev        ccb49abe412c978a4045f0c75abff534372716c4
Gecko-Rev       https://hg.mozilla.org/releases/mozilla-b2g34_v2_1/rev/18fb67530b22
Build-ID        20141202001201
Version         34.0