978531 - [Camera][Madai][QRD] The preview is not available when reopening the camera

Status: VERIFIED FIXED

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

Description

[Diego Marcos [:dmarcos]]

Attachment: noPreview.MOV

Seen on a Nexus4

Steps to reproduce:

1. Open the camera
2. Exit the camera and go to the homescreen (by pressing home)
3. Repeat 1,2 multiple times. The preview is sometimes not available.

See attached video (problem at second 30)

Comment 1

[Diego Marcos [:dmarcos]]

Still reproduces on:

Gaia      a4238bb23a83f89853a360d4ae04313c1010eba6
Gecko     https://hg.mozilla.org/mozilla-central/rev/46041cc216fd
BuildID   20140313040203
Version   30.0a1

Comment 2

[Diego Marcos [:dmarcos]]

The error callback is called on this.mozCamera.setConfiguration(options, success, error);

The argument received on the callback is a string that says "FAILURE". No other information available

Comment 3

[David Flanagan [:djf]]

Would be interesting to know if this happens on other hardware and whether it is speed dependent. Does it only happen when switching quickly?

Comment 4

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

Attachment: Logcat of the issue occuring

GonkCameraControl doesn't have an instance of GonkCameraHardware.

03-18 17:56:44.601   881  2343 I Gecko   : Pushing camera parameters
03-18 17:56:44.601   881  2343 I Gecko   : virtual nsresult mozilla::nsGonkCameraControl::PushParametersImpl():868 : mCameraHw is null
03-18 17:56:44.601   881  2343 I Gecko   : nsresult mozilla::nsGonkCameraControl::SetConfigurationInternal(const mozilla::ICameraControl::Configuration&):219
03-18 17:56:44.601   881  2343 I Gecko   : virtual nsresult mozilla::nsGonkCameraControl::StopPreviewImpl():538 : mCameraHw is null
03-18 17:56:44.601   881  2343 I Gecko   : Camera control API failed at 8 with 0x80040111
03-18 17:56:44.611   881   881 I Gecko   : DOM OnHardwareStateChange(1)
03-18 17:56:44.621   881   881 I Gecko   : DOM OnError context=11, error='ErrorSetThumbnailSizeFailed'
03-18 17:56:44.621   881   881 I Gecko   : DOM OnError context=8, error='FAILURE'
03-18 17:56:44.641   881   881 E GeckoConsole: Content JS LOG at app://camera.gaiamobile.org/js/main.js:3750 in Camera.prototype.configure/error: Error configuring camera

Comment 5

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

Attachment: Logcat of the issue occuring

A log with more trace statements.

Here is the sequence of CameraControl API calls (and callbacks):

18:26:55 ➜  bug978531  grep -rn "mozilla::nsDOMCameraControl::" log02.txt 
14:03-18 18:22:04.669  2808  2808 I Gecko   : mozilla::nsDOMCameraControl::nsDOMCameraControl(uint32_t, const mozilla::dom::CameraConfiguration&, mozilla::dom::GetCameraCallback*, mozilla::dom::CameraErrorCallback*, nsPIDOMWindow*):160 : this=0xb2bdfda0
34:03-18 18:22:04.849  2808  2808 I Gecko   : void mozilla::nsDOMCameraControl::OnHardwareStateChange(mozilla::CameraControlListener::HardwareState):1062 : this=0xb2bdfda0
36:03-18 18:22:04.849  2808  2808 I Gecko   : void mozilla::nsDOMCameraControl::OnPreviewStateChange(mozilla::CameraControlListener::PreviewState):1116 : this=0xb2bdfda0
73:03-18 18:22:05.020  2808  2808 I Gecko   : void mozilla::nsDOMCameraControl::OnConfigurationChange(mozilla::nsDOMCameraControl::DOMCameraConfiguration*):1205 : this=0xb2bdfda0
80:03-18 18:22:05.020  2808  2808 I Gecko   : void mozilla::nsDOMCameraControl::OnHardwareStateChange(mozilla::CameraControlListener::HardwareState):1062 : this=0xb2bdfda0
83:03-18 18:22:05.030  2808  2808 I Gecko   : already_AddRefed<mozilla::dom::CameraCapabilities> mozilla::nsDOMCameraControl::Capabilities():738 : this=0xb2bdfda0
224:03-18 18:22:05.070  2808  2808 I Gecko   : void mozilla::nsDOMCameraControl::SetOnShutter(mozilla::dom::CameraShutterCallback*):666 : this=0xb2bdfda0
225:03-18 18:22:05.070  2808  2808 I Gecko   : void mozilla::nsDOMCameraControl::SetOnRecorderStateChange(mozilla::dom::CameraRecorderStateChange*):692 : this=0xb2bdfda0
270:03-18 18:22:05.130  2808  2808 I Gecko   : void mozilla::nsDOMCameraControl::SetWhiteBalanceMode(const nsAString_internal&, mozilla::ErrorResult&):373 : this=0xb2bdfda0
272:03-18 18:22:05.130  2808  2808 I Gecko   : void mozilla::nsDOMCameraControl::SetFlashMode(const nsAString_internal&, mozilla::ErrorResult&):403 : this=0xb2bdfda0
274:03-18 18:22:05.130  2808  2808 I Gecko   : void mozilla::nsDOMCameraControl::SetIsoMode(const nsAString_internal&, mozilla::ErrorResult&):433 : this=0xb2bdfda0
276:03-18 18:22:05.130  2808  2808 I Gecko   : void mozilla::nsDOMCameraControl::SetSceneMode(const nsAString_internal&, mozilla::ErrorResult&):388 : this=0xb2bdfda0
278:03-18 18:22:05.130  2808  2808 I Gecko   : void mozilla::nsDOMCameraControl::SetPictureSize(JSContext*, JS::Handle<JS::Value>, mozilla::ErrorResult&):533 : this=0xb2bdfda0
280:03-18 18:22:05.130  2808  2808 I Gecko   : JS::Value mozilla::nsDOMCameraControl::GetPictureSize(JSContext*, mozilla::ErrorResult&):518 : this=0xb2bdfda0
281:03-18 18:22:05.130  2808  2808 I Gecko   : void mozilla::nsDOMCameraControl::SetThumbnailSize(JSContext*, JS::Handle<JS::Value>, mozilla::ErrorResult&):563 : this=0xb2bdfda0
283:03-18 18:22:05.130  2808  2808 I Gecko   : void mozilla::nsDOMCameraControl::SetConfiguration(const mozilla::dom::CameraConfiguration&, const mozilla::dom::Optional<mozilla::dom::OwningNonNull<mozilla::dom::CameraSetConfigurationCallback> >&, const mozilla::dom::Optional<mozilla::dom::OwningNonNull<mozilla::dom::CameraErrorCallback> >&, mozilla::ErrorResult&):859 : this=0xb2bdfda0
298:03-18 18:22:05.410  2808  2808 I Gecko   : void mozilla::nsDOMCameraControl::OnPreviewStateChange(mozilla::CameraControlListener::PreviewState):1116 : this=0xb2bdfda0
350:03-18 18:22:05.780  2808  2808 I Gecko   : void mozilla::nsDOMCameraControl::OnPreviewStateChange(mozilla::CameraControlListener::PreviewState):1116 : this=0xb2bdfda0
356:03-18 18:22:05.840  2808  2808 I Gecko   : void mozilla::nsDOMCameraControl::OnConfigurationChange(mozilla::nsDOMCameraControl::DOMCameraConfiguration*):1205 : this=0xb2bdfda0
465:03-18 18:22:06.001  2808  2808 I Gecko   : void mozilla::nsDOMCameraControl::OnPreviewStateChange(mozilla::CameraControlListener::PreviewState):1116 : this=0xb2bdfda0
1004:03-18 18:22:08.223  2808  2808 I Gecko   : void mozilla::nsDOMCameraControl::ReleaseHardware(const mozilla::dom::Optional<mozilla::dom::OwningNonNull<mozilla::dom::CameraReleaseCallback> >&, const mozilla::dom::Optional<mozilla::dom::OwningNonNull<mozilla::dom::CameraErrorCallback> >&, mozilla::ErrorResult&):998 : this=0xb2bdfda0
1063:03-18 18:22:08.253  2808  2808 I Gecko   : void mozilla::nsDOMCameraControl::OnPreviewStateChange(mozilla::CameraControlListener::PreviewState):1116 : this=0xb2bdfda0
1111:03-18 18:22:08.353  2808  2808 I Gecko   : void mozilla::nsDOMCameraControl::SetOnShutter(mozilla::dom::CameraShutterCallback*):666 : this=0xb2bdfda0
1112:03-18 18:22:08.353  2808  2808 I Gecko   : void mozilla::nsDOMCameraControl::SetOnRecorderStateChange(mozilla::dom::CameraRecorderStateChange*):692 : this=0xb2bdfda0
1113:03-18 18:22:08.363  2808  2808 I Gecko   : void mozilla::nsDOMCameraControl::SetWhiteBalanceMode(const nsAString_internal&, mozilla::ErrorResult&):373 : this=0xb2bdfda0
1117:03-18 18:22:08.363  2808  2808 I Gecko   : void mozilla::nsDOMCameraControl::SetFlashMode(const nsAString_internal&, mozilla::ErrorResult&):403 : this=0xb2bdfda0
1121:03-18 18:22:08.363  2808  2808 I Gecko   : void mozilla::nsDOMCameraControl::SetIsoMode(const nsAString_internal&, mozilla::ErrorResult&):433 : this=0xb2bdfda0
1125:03-18 18:22:08.363  2808  2808 I Gecko   : void mozilla::nsDOMCameraControl::SetSceneMode(const nsAString_internal&, mozilla::ErrorResult&):388 : this=0xb2bdfda0
1129:03-18 18:22:08.363  2808  2808 I Gecko   : void mozilla::nsDOMCameraControl::SetPictureSize(JSContext*, JS::Handle<JS::Value>, mozilla::ErrorResult&):533 : this=0xb2bdfda0
1132:03-18 18:22:08.373  2808  2808 I Gecko   : JS::Value mozilla::nsDOMCameraControl::GetPictureSize(JSContext*, mozilla::ErrorResult&):518 : this=0xb2bdfda0
1133:03-18 18:22:08.373  2808  2808 I Gecko   : void mozilla::nsDOMCameraControl::SetThumbnailSize(JSContext*, JS::Handle<JS::Value>, mozilla::ErrorResult&):563 : this=0xb2bdfda0
1139:03-18 18:22:08.373  2808  2808 I Gecko   : void mozilla::nsDOMCameraControl::SetConfiguration(const mozilla::dom::CameraConfiguration&, const mozilla::dom::Optional<mozilla::dom::OwningNonNull<mozilla::dom::CameraSetConfigurationCallback> >&, const mozilla::dom::Optional<mozilla::dom::OwningNonNull<mozilla::dom::CameraErrorCallback> >&, mozilla::ErrorResult&):859 : this=0xb2bdfda0
1151:03-18 18:22:08.373  2808  2808 I Gecko   : void mozilla::nsDOMCameraControl::OnHardwareStateChange(mozilla::CameraControlListener::HardwareState):1062 : this=0xb2bdfda0
1153:03-18 18:22:08.373  2808  2808 I Gecko   : void mozilla::nsDOMCameraControl::OnError(mozilla::CameraControlListener::CameraErrorContext, const nsAString_internal&):1308 : this=0xb2bdfda0
1155:03-18 18:22:08.373  2808  2808 I Gecko   : void mozilla::nsDOMCameraControl::OnError(mozilla::CameraControlListener::CameraErrorContext, const nsAString_internal&):1308 : this=0xb2bdfda0

Comment 6

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

Easier to read version of comment 5 (file numbers from log file in square brackets):
- [14] getCamera() (invokes nsDOMCameraControl constructor)
- [34] callback onHardwareStateChange
- [36] callback onPreviewStateChange
- [73] callback onConfigurationChange --> picture mode, preview 1280x720
- [80] callback onHardwareStateChange --> hardware open
- [80] get camera capabilities
- [224] set onShutter
- [225] set onRecorderStateChange
- [270] set whiteBalanceMode
- [272] set flashMode
- [274] set isoMode
- [276] set sceneMode
- [278] set pictureSize
- [280] get pictureSize
- [281] set thumbnailSize
- [283] setConfiguration()
- [296] --- preview started ---
- [298] callback onPreviewStateChange --> started
- [346] --- preview paused ---
- [350] callback onPreviewStateChange --> paused
- [356] callback onConfigurationChange --> picture mode, preview 640x480
    ...this is in response to setConfiguration() [283]
- [464] --- preview started ---
- [465] callback onPreviewStateChange --> started
- [1004] release()
- [1015] --- preview stopped ---
- [1063] callback onPreviewStateChange --> stopped
- [1063] set onShutter
    ...not sure why this or any other setter is being called here
- [1112] set onRecorderStateChange
- [1113] set whiteBalanceMode
- [1117] set flashMode
- [1121] set isoMode
- [1125] set sceneMode
- [1129] set pictureSize
- [1132] get pictureSize
- [1133] set thumbnailSize
- [1139] setConfiguration()
- [1151] callback onHardwareStateChange --> closed
    ...this is in response to release() [1004]
- [1153] OnError : "ErrorSetThumbnailSizeFailed"
- [1155] OnError : "FAILURE"
    ...this is in response to setConfiguration[1139]

So the "FAILURE" is because setConfiguration() is being called on a CameraControl object that has released its underlying hardware and is now defunct. Looks like a race condition in the Camera app. The lack of a call to the nsDOMCameraControl constructor after release() is a clue that something has gone wrong here.

I obtained these results on a nexus-4 running:
- gecko: larch:328c2ee3ca75
- gaia: camera-new-features:092ced82a7c50841e7ef3c273700fc0efbd1e97d

Comment 7

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

Over to you guys.

Comment 8

[Diego Marcos [:dmarcos]]

Investigating this. Taking things out justin and wilsons plate.

Comment 9

[Wilson Page [:wilsonpage]]

Sound like a setting may be being altered which could have a `change:` callback firing that is trying to reconfigure the camera. 

I'm guessing this could easily be fixed by checking if mozCamera is attached or released before trying to configure it is any way.

Although, we are setting `this.mozCamera = null` after releasing, so not sure how we could still have an interface around to use...?

Comment 10

[Diego Marcos [:dmarcos]]

We don't any visibility over the life cycle of the nsDOMCameraControl object. We don't know where the nsDOMCameraControl constructor is called. 

I found what the issue but haven't found a solution yet. After clicking the home button the camera app calls release the current nsDOMCameraControl (The release call is asynchronous) When the camera is reopened we call mozCameras.getCamera to request a new nsDOMCameraControl. If the app is reopened quickly sometimes the previous release call hasn't finished and mozCameras.getCamera executes first. Then the release call is executed and we call setConfiguration over nsDOMCameraControl that has been released.

Apparently the release call deallocates/removes all the requested nsDOMCameraControls ant not only the one that the message/method was called on.

Comment 11

[Diego Marcos [:dmarcos]]

Attachment: Pull Request on camera-new-features

Comment 12

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

Comment on attachment 8394485 [details] [review]
Pull Request on camera-new-features

From Gecko-land, this looks good to me. I wonder if it's worth balling this logic into Gecko at some point, to save other camera apps the trouble.

Comment 14

[Diego Marcos [:dmarcos]]

Landed in camera-new-features:

https://github.com/dmarcos/gaia/commit/a844c5d785074900c9ffd7914ae7ce83ed73d614

Comment 15

[Hema Koka [:hema]]

Modification to the STR reproduces the same problem per Sameer from QC:



·         Open the gallery and press on the camera icon.

·         Hit home button.

·         Repeat “a” and “b” couple of times, we see the black screen.

Please test

Comment 16

[Diego Marcos [:dmarcos]]

This doesn't reproduce anymore. What device are they using, what version of gecko/gaia?

Comment 17

[Hema Koka [:hema]]

This is on QRD device (see STR from Qualcomm) -- we need to get the 2 QRDs up (having some issues at the moment) before we can reproduce and investigate this one

Comment 18

[David Flanagan [:djf]]

The STR in comment 15 are different than the original ones for this bug. Since it involves an activity, it is probably a dupe of the activity bug that Justin just fixed.

Comment 19

[Hema Koka [:hema]]

Please test with the build that has this bug fix in 988610

Comment 20

[David Flanagan [:djf]]

Bulk edit for camera bugs.

If earlier comments do not show how this bug landed to master, it probably landed as part of https://github.com/mozilla-b2g/gaia/pull/17599 which merged the camera-new-features branch into master.

This bug was uplifted from master to v1.4 as part of https://github.com/mozilla-b2g/gaia/commit/a8190d08e61316a86bba572ba8d894d081a20530

Comment 21

[sarsenyev]

The bug is no longer reproduces on 1.4 and master
No black screen appears when trying to render the preview, preview appears each time 

1.4 Environmental Variables:
Device: Buri 1.4 MOZ
BuildID: 20140407000203
Gaia: 86de7fcce674ef6196d68e7e23552d219a3d72db
Gecko: 6e028297be14
Version: 30.0a2
Firmware Version: v1.2-device.cfg


1.5 Environmental Variables:
Device: Buri 1.5 MOZ
BuildID: 20140407040202
Gaia: f1a98bfaa3ab2480945bd7018831fd56c61cdc24
Gecko: 5405d6f4e3c6
Version: 31.0a1
Firmware Version: v1.2-device.cfg