Closed Bug 1030007 Opened 6 years ago Closed 6 years ago

Huge frame drops observed while zoom in/out during Video recording

Categories

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

ARM
Gonk (Firefox OS)
defect
Not set

Tracking

(blocking-b2g:2.0+, firefox31 wontfix, firefox32 fixed, firefox33 fixed, b2g-v1.4 unaffected, b2g-v2.0 fixed, b2g-v2.1 fixed)

RESOLVED FIXED
2.0 S6 (18july)
blocking-b2g 2.0+
Tracking Status
firefox31 --- wontfix
firefox32 --- fixed
firefox33 --- fixed
b2g-v1.4 --- unaffected
b2g-v2.0 --- fixed
b2g-v2.1 --- fixed

People

(Reporter: vasanth, Assigned: aosmond)

References

()

Details

(Whiteboard: [caf priority: p2][CR 680341])

Attachments

(5 files, 4 obsolete files)

Pre requisite
-------------
This issue is only present in msm8610 (dual core version)
Use flame devices after disabling 3rd and 4th core.
adb shell stop mpdecision
adb shell "echo 0 > /sys/devices/system/cpu/cpu2/online"
adb shell "echo 0 > /sys/devices/system/cpu/cpu3/online"

Steps to reproduce
------------------
1.open Camcorder.
2.Enable below setprop command to observe the FPS flow.
adb shell setprop persist.debug.sf.showfps 1
3.Then run below command on command prompt to see FPS low.
adb logcat | grep "Video Frames Per Second"
4.start recording.
5.Zoom in/out while recording is going on.
6. Huge frames drops observed while zoom in/out during Video recording this leads to jerkiness on the preview as well as on recorded clips. FPS goes below 10 
7. Not reproducible in Android

FPS flow
--------
E/QCamera2HWI(  214): Video Frames Per Second: 0.8207
E/QCamera2HWI(  214): Video Frames Per Second: 1.9317
E/QCamera2HWI(  214): Video Frames Per Second: 9.8785
E/QCamera2HWI(  214): Video Frames Per Second: 3.5233
E/QCamera2HWI(  214): Video Frames Per Second: 1.3770
E/QCamera2HWI(  214): Video Frames Per Second: 2.4637

Analysis
--------
From Camera folks
-----------------
No free buffer left at camera HAL or framework side and thus we see video frame drops like below till we get buffer from encoder.

From encoder folks
------------------
The number of buffers given to encoder itself is less. So the middle part like Camera source might be holding the other buffers.

I see we have GonkCameraSource.cpp instead of stage fright's CameraSource.cpp
Could you guys try to reproduce this issue and debug recording zoom in/out from 
GonkCameraSource perspective?
blocking-b2g: --- → 2.0?
Whiteboard: [CR 680341] → [caf priority: p2][CR 680341]
Vasanth

Can we please provide numbers in comparison with 1.4?
Flags: needinfo?(vasanth)
Andrew,

Can you try reproducing this and investigate it on flame?

copying mikeh and sotaro too.

Thanks
Hema
Flags: needinfo?(aosmond)
blocking-b2g: 2.0? → 2.0+
(In reply to Preeti Raghunath(:Preeti) from comment #1)
> Vasanth
> 
> Can we please provide numbers in comparison with 1.4?

Same issue happens in 1.4 as well. FPS goes below 10 leads to jerkiness on the preview as well as on recorded clips
Without Zoom In/Out FPS is around ~30
Flags: needinfo?(vasanth)
I was able to reproduce last night on Flame. We have architectural differences in how we handle the preview display compared to Android, which may be causing additional overhead. As found empirically, it appears there are up to 9 media buffers outstanding from the camera driver and we stop receiving new data until old is processed; during the zoom, it looks like encoding falls behind (presumably due to lack of CPU cycles) which is why we start dropping frames at the camera driver layer. Testing is complicated by yesterday's build crashing when attempting to watch a recorded video, and today's build's zoom does nothing. Exploring some changes in gecko to see if a workaround is possible (at least for the actual recording, preview may be harder).
Flags: needinfo?(aosmond)
Andrew: if you think you can continue to make progress on this, please assign it to yourself. Otherwise, let Hema know so we can find an assignee. As a blocker, we don't want to let it go without an owner.

Vasanth: does this bug go away if you just use a smaller video size? We default to recording very large videos, and it may simply be a matter of not having enough CPU power to handle that on the device you are using.

Try uncommenting these lines in apps/camera/js/config/config.js:

      // {
      //   key: 'recorderProfiles'
      // },

That should give you a choice of video resolutions in the camera settings menu. Then, empirically you can determine what the maximum size is that works well enough for your device. This may simply be a matter of doing device-specific build-time configuration so that we record at a size that devices can comfortably handle.

Setting needinfo for Diego, too, because he knows more about how to configure the video resolution.
Flags: needinfo?(vasanth)
Flags: needinfo?(dmarcos)
Flags: needinfo?(aosmond)
Assignee: nobody → aosmond
Flags: needinfo?(aosmond)
Target Milestone: --- → 2.0 S5 (4july)
(In reply to David Flanagan [:djf] from comment #5)
> Vasanth: does this bug go away if you just use a smaller video size? 
Nope. Able to reproduce with lowest resolution as well. (qcif 176x144)
Flags: needinfo?(vasanth)
Andrew/Mike any update on this?
Flags: needinfo?(mhabicher)
Flags: needinfo?(aosmond)
Preliminary testing on a change I made shows that by slowing down pushing frames into the preview when it is flooded helps with the buffers running out observed in the lower levels of the camera by the vendor. However although even we do not appear to run out of buffers, I do not perceive the recorded video to be significantly smoother than before.

We do appear to be much more aggressive in the degree to which one gesture can change the zoom as compared to BB/iPhone (I assume Android is similar, no reference phone on hand). Pinch to zoom in/out appears to have a maximum increment on those devices, where we can jump from the minimum to the maximum with a sufficiently quick gesture. I am now exploring rate limiting this to see if that has the desired effect on the fluidness of the video.

Vasanth: Would it be possible to get a brief video showing the zoom in/out behavior you expect to make sure I am reproducing/visualizing the issue properly? And if at all possible, a debug log showing the zoom parameter changes over time?
Flags: needinfo?(vasanth)
Flags: needinfo?(mhabicher)
Flags: needinfo?(aosmond)
Vasanth: To clarify, I was looking for the debug log / actual recorded video produced by Android, not by Firefox OS (although a recorded video from the latter couldn't hurt ;)).
(In reply to Andrew Osmond [:aosmond] from comment #8)
> We do appear to be much more aggressive in the degree to which one gesture
> can change the zoom as compared to BB/iPhone (I assume Android is similar,
> no reference phone on hand). Pinch to zoom in/out appears to have a maximum
> increment on those devices, where we can jump from the minimum to the
> maximum with a sufficiently quick gesture. I am now exploring rate limiting
> this to see if that has the desired effect on the fluidness of the video.

Andrew: Let me know if you think this would help mitigate the problem. I can probably throw together a gaia patch for this relatively quickly.
Attached file pull-request (master)
Andrew: This is a patch for throttling the repetitive speed in which we call the `zoom` setter attribute on the Camera Control API. This should only allow for 1 call every 150ms (roughly 6 calls per second).
Attachment #8449495 - Flags: feedback?(aosmond)
Attached patch Throttle preview frame, v1 (obsolete) — Splinter Review
There will have to be a follow up fix to this one resolving an unrelated crash which appears to be caused by slightly different timing resulting in this change (unless somebody sees a flaw breaking the OmxDecoder destructor :)).
Attachment #8449706 - Flags: review?(mhabicher)
Comment on attachment 8449495 [details] [review]
pull-request (master)

jdarcangelo, looks good and works well; this will need to be committed along with my fix when ready although obviously they can be put in separately safely.
Attachment #8449495 - Flags: feedback?(aosmond) → feedback+
Vasanth -- can you please try out this patch and see if it helps.
Flags: needinfo?(vasanth)
Comment on attachment 8449495 [details] [review]
pull-request (master)

Flagging Diego for formal review.
Attachment #8449495 - Flags: review?(dmarcos)
Attached patch Throttle preview frame, v2 (obsolete) — Splinter Review
Fix aforementioned crash after stopping recording, fix how we did not reset the rate limiting after recording was done.
Attachment #8449706 - Attachment is obsolete: true
Attachment #8449706 - Flags: review?(mhabicher)
Attachment #8449733 - Flags: review?(mhabicher)
Comment on attachment 8449706 [details] [diff] [review]
Throttle preview frame, v1

Review of attachment 8449706 [details] [diff] [review]:
-----------------------------------------------------------------

r- largely due to nits and style issues. Also, a question about holding mMutex before reading mInvalidatePending.

::: dom/camera/CameraControlImpl.cpp
@@ +254,5 @@
> +  // This function runs on neither the Main Thread nor the Camera Thread.
> +  RwLockAutoEnterRead lock(mListenerLock);
> +
> +  DOM_CAMERA_LOGI("OnRateLimitPreview: %d\n",
> +    aLimit);

This can all go on one line.

::: dom/camera/CameraPreviewMediaStream.cpp
@@ +118,5 @@
> +CameraPreviewMediaStream::Invalidate()
> +{
> +  MutexAutoLock lock(mMutex);
> +  --mInvalidatePending;
> +  for (uint32_t i = 0; i < mVideoOutputs.Length(); ++i) {

Instead of uint32_t, you should use <mVideoOutputs type>::size_type.

@@ +123,5 @@
> +    VideoFrameContainer* output = mVideoOutputs[i];
> +    output->Invalidate();
> +  }
> +}
> + 

nit: extra whitespace.

@@ +135,3 @@
>  CameraPreviewMediaStream::SetCurrentFrame(const gfxIntSize& aIntrinsicSize, Image* aImage)
>  {
> +  if (mInvalidatePending > 0) {

Should this function hold mMutex before reading mInvalidatePending et al?

@@ +135,5 @@
>  CameraPreviewMediaStream::SetCurrentFrame(const gfxIntSize& aIntrinsicSize, Image* aImage)
>  {
> +  if (mInvalidatePending > 0) {
> +    if (mRateLimit || mInvalidatePending > MAX_INVALIDATE_PENDING) {
> +      DOM_CAMERA_LOGW("Discard preview frame %d, invalidates pending %d", ++mDiscardedFrames, mInvalidatePending);

nit: wrap this line at some suitable place--it's getting a bit long.

Also, put the increment of mDiscardedFrames on its own line, instead of in the macro.

@@ +138,5 @@
> +    if (mRateLimit || mInvalidatePending > MAX_INVALIDATE_PENDING) {
> +      DOM_CAMERA_LOGW("Discard preview frame %d, invalidates pending %d", ++mDiscardedFrames, mInvalidatePending);
> +      return;
> +    } else {
> +      DOM_CAMERA_LOGI("Update preview frame, invalidates pending %d", mInvalidatePending);

"Update preview frame, %d invalidation(s) pending\n"

@@ +147,5 @@
> +  {
> +    MutexAutoLock lock(mMutex);
> +
> +    TimeStamp now = TimeStamp::Now();
> +    for (uint32_t i = 0; i < mVideoOutputs.Length(); ++i) {

Please make this use ::size_type as well.

@@ +154,5 @@
> +    }
> +
> +    if (mFrameCallback) {
> +      mFrameCallback->OnNewFrame(aIntrinsicSize, aImage);
> +    }

This conditional block is a hook for WebRTC. You might want to ping jesup to let him know the behaviour is going to change in this patch.

::: dom/camera/CameraPreviewMediaStream.h
@@ +16,5 @@
>    virtual void OnNewFrame(const gfxIntSize& aIntrinsicSize, layers::Image* aImage) = 0;
>  };
>  
>  /**
> + * This is a stream for camera preview.

Nice. :)

::: dom/camera/DOMCameraControl.h
@@ +213,5 @@
>    //  with it.
>    DOMCameraControlListener* mListener;
>  
>    // our viewfinder stream
> +  nsRefPtr<CameraPreviewMediaStream> mInput;

Did this used to leak?

::: dom/camera/GonkCameraControl.h
@@ +56,4 @@
>    void OnNewPreviewFrame(layers::TextureClient* aBuffer);
>    void OnRecorderEvent(int msg, int ext1, int ext2);
>    void OnSystemError(CameraControlListener::SystemContext aWhere, nsresult aError);
>   

nit: extra whitespace

::: dom/camera/GonkCameraHwMgr.cpp
@@ +46,5 @@
>  
>  void
> +GonkCameraHardware::OnRateLimitPreview(bool aLimit)
> +{
> +  ::OnRateLimitPreview(mTarget, aLimit);

:: not required.

::: dom/camera/GonkCameraSource.cpp
@@ +688,5 @@
>  }
>  
>  void GonkCameraSource::dataCallbackTimestamp(int64_t timestampUs,
>          int32_t msgType, const sp<IMemory> &data) {
> +    bool rateLimit, prevRateLimit;

Please put these declarations on separate lines.

@@ +729,5 @@
> +        }
> +        ++mNumFramesReceived;
> +
> +        // If a backlog is building up in the receive queue, we are likely
> +        // resource constrained and we need to throttle 

nit: trailing whitespace.

@@ +731,5 @@
> +
> +        // If a backlog is building up in the receive queue, we are likely
> +        // resource constrained and we need to throttle 
> +        prevRateLimit = mRateLimit;
> +        rateLimit = mRateLimit = mFramesReceived.empty();

Ugh, separate lines, please!
Attachment #8449706 - Attachment is obsolete: false
(In reply to Andrew Osmond [:aosmond] from comment #14)

> jdarcangelo, looks good and works well; this will need to be committed along
> with my fix when ready although obviously they can be put in separately
> safely.

Justin, your change is to rate-limit zoom calls, right? That's probably a good approach to get this fixed, but I think long-term it makes more sense to make the WebAPI do the rate-limiting.
Flags: needinfo?(jdarcangelo)
Attached patch Throttle preview frame, v3 (obsolete) — Splinter Review
Fix nits, save the not-needing-:: since it gives a compiler error without. Made additional changes requested offline, namely removing the frame callback since it is no longer used.
Attachment #8449706 - Attachment is obsolete: true
Attachment #8449733 - Attachment is obsolete: true
Attachment #8449733 - Flags: review?(mhabicher)
Attachment #8449789 - Flags: review?(mhabicher)
(In reply to Mike Habicher [:mikeh] from comment #19)
> (In reply to Andrew Osmond [:aosmond] from comment #14)
> 
> > jdarcangelo, looks good and works well; this will need to be committed along
> > with my fix when ready although obviously they can be put in separately
> > safely.
> 
> Justin, your change is to rate-limit zoom calls, right? That's probably a
> good approach to get this fixed, but I think long-term it makes more sense
> to make the WebAPI do the rate-limiting.

Yes, all this patch is doing is rate-limiting the `zoom` setter attribute. It would probably be good to handle it from the WebAPI if possible.
Flags: needinfo?(jdarcangelo)
Comment on attachment 8449789 [details] [diff] [review]
Throttle preview frame, v3

Review of attachment 8449789 [details] [diff] [review]:
-----------------------------------------------------------------

r+ from me with nits below fixed; but I'd like cpearce to okay the MediaOmxReader change.

::: content/media/omx/MediaOmxReader.cpp
@@ +78,5 @@
> +{
> +  ReleaseMediaResources();
> +  nsCOMPtr<nsIRunnable> event =
> +    NS_NewRunnableMethod(this, &MediaOmxReader::ReleaseDecoder);
> +  NS_DispatchToMainThread(event);

cpearce, is it okay that this might change the order in which ReleaseDecoder() is called?

::: dom/camera/CameraPreviewMediaStream.cpp
@@ +122,5 @@
> +    VideoFrameContainer* output = mVideoOutputs[i];
> +    output->Invalidate();
> +  }
> +}
> + 

nit: still an extra space on line 126.

@@ +141,5 @@
> +        ++mDiscardedFrames;
> +        DOM_CAMERA_LOGW("Discard preview frame %d, %d invalidation(s) pending",
> +          mDiscardedFrames, mInvalidatePending);
> +        return;
> +      } else {

Drop the else case, please, since the block above returns.

::: dom/camera/GonkCameraControl.cpp
@@ +1680,5 @@
>    nsRefPtr<RecorderProfileManager> profileMgr = GetGonkRecorderProfileManager();
>    return profileMgr.forget();
>  }
>  
> +void nsGonkCameraControl::OnRateLimitPreview(bool aLimit)

nit:

void
nsGonkCamera...
{
  ...
}

::: dom/camera/GonkCameraSource.cpp
@@ +587,5 @@
>      }
>      stopCameraRecording();
> +    if (mRateLimit) {
> +      mRateLimit = false;
> +      mCameraHw->OnRateLimitPreview(mRateLimit);

nit: just make this ->OnRateLimitPreview(false).
Attachment #8449789 - Flags: review?(mhabicher)
Attachment #8449789 - Flags: review?(cpearce)
Attachment #8449789 - Flags: review+
(In reply to Mike Habicher [:mikeh] from comment #22)
> Comment on attachment 8449789 [details] [diff] [review]
> Throttle preview frame, v3
> 
> Review of attachment 8449789 [details] [diff] [review]:
> -----------------------------------------------------------------
> 
> r+ from me with nits below fixed; but I'd like cpearce to okay the
> MediaOmxReader change.
> 
> ::: content/media/omx/MediaOmxReader.cpp
> @@ +78,5 @@
> > +{
> > +  ReleaseMediaResources();
> > +  nsCOMPtr<nsIRunnable> event =
> > +    NS_NewRunnableMethod(this, &MediaOmxReader::ReleaseDecoder);
> > +  NS_DispatchToMainThread(event);
> 
> cpearce, is it okay that this might change the order in which
> ReleaseDecoder() is called?

That won't change the order in which ReleaseMediaResources() and OMXDecoder::ReleaseDecoder() are called, it will just make ReleaseDecoder be called later, on the main thread. Why is this change needed? Why can't we shutdown OMXDecoder on the decode thread?
(In reply to Chris Pearce (:cpearce) from comment #23)
> That won't change the order in which ReleaseMediaResources() and
> OMXDecoder::ReleaseDecoder() are called, it will just make ReleaseDecoder be
> called later, on the main thread. Why is this change needed? Why can't we
> shutdown OMXDecoder on the decode thread?

Chris, with my change I end up hitting an assert failure a lot, which expected OMXDecoder to be freed on the main thread...since I don't believe I've made any changes directly, I assumed I've changed the thread scheduling enough to uncover a latent race condition.

I've attached a stack trace of the assert; hopefully that helps in evaluating if what I did is correct for all cases and not just my tests :).
Comment on attachment 8449789 [details] [diff] [review]
Throttle preview frame, v3

Review of attachment 8449789 [details] [diff] [review]:
-----------------------------------------------------------------

Guess I'd better r+ it then. Thanks for the stack trace.
Attachment #8449789 - Flags: review?(cpearce) → review+
Fix final nits requested.

try: https://tbpl.mozilla.org/?tree=Try&rev=43bc73c35e78
Attachment #8449789 - Attachment is obsolete: true
Attachment #8449939 - Flags: review+
(In reply to Andrew Osmond [:aosmond] from comment #26)
> Created attachment 8449939 [details] [diff] [review]
> Throttle preview frame, v3.1

Thanks Andrew & Justin!
Could you please provide a patch for mozilla/v2.0 branch which I can test?
Also did you guys verify fps is increased in Flame devices with 2 core as mentioned in description?
Flags: needinfo?(jdarcangelo)
Flags: needinfo?(aosmond)
Removed the OMXDecoder changes as it does not look like the bits that impacted me were promoted.
Flags: needinfo?(aosmond)
Second try to actually run the emulator tests: https://tbpl.mozilla.org/?tree=Try&rev=7024b592ca44
Status: NEW → ASSIGNED
(In reply to vasanth from comment #27)
> (In reply to Andrew Osmond [:aosmond] from comment #26)
> > Created attachment 8449939 [details] [diff] [review]
> > Throttle preview frame, v3.1
> 
> Thanks Andrew & Justin!
> Could you please provide a patch for mozilla/v2.0 branch which I can test?
> Also did you guys verify fps is increased in Flame devices with 2 core as
> mentioned in description?

Vasanth, my flame only had two cores in the first place, but I did verify the FPS and run "stop mpdecision".
Attach the correct patch this time. The previously attached patch came from bug 1030821 which is also required on v2.0 if you want to actually zoom in and out, if it hasn't been pushed into that branch yet when you test.
Attachment #8450317 - Attachment is obsolete: true
Comment on attachment 8449495 [details] [review]
pull-request (master)

I put it on hold until further clarification:

1. I see some duplication of functionality: Two timers created to solve the same issue. I might be missing something.
2. We should unit these changes.
Attachment #8449495 - Flags: review?(dmarcos) → review-
Flags: needinfo?(dmarcos)
Checkin requested for throttle preview frame patch.
Keywords: checkin-needed
(In reply to Andrew Osmond [:aosmond] from comment #31)
> Created attachment 8450354 [details] [diff] [review]
> Throttle preview frame, v1.1 for v2.0

Hi Andrew,

This patch has improved the FPS during zoom in/out(~13 now, ~7 before), 
however still the preview/recorded video is not as smooth as Android

Some reasons could be,
1. Average FPS (without Zoom in/out) it self has degraded from 1.4 to 2.0. (~25 now, ~30 before)
Do you guys seeing this?
2. Android uses Fixed FPS mode whereas FFOS uses Auto FPS mode, where FPS varies more?
3. Getting better FPS when hardware composer is disabled. Something to do with HwC? (~15)
Flags: needinfo?(vasanth)
Comment on attachment 8449495 [details] [review]
pull-request (master)

Diego: I've updated the patch so that we're only throttling in one place. Not sure what I was thinking the first time around, this makes much more sense! :-/
Attachment #8449495 - Flags: review- → review?(dmarcos)
Oops updating missing tracking flags to ensure my 2.0 targeted patch (Throttle preview frame, v1.1 for v2.0) is marked for landing.
Per https://wiki.mozilla.org/Release_Management/B2G_Landing, the standard procedure is for fixes to land on mozilla-central first, then get uplifted. Also, the bug queries on that page cover uplifts, so please don't set checkin-needed additionally as it just clutters up other bug queries.
Attachment #8449495 - Flags: review?(dmarcos) → review+
Comment on attachment 8449495 [details] [review]
pull-request (master)

Landed on master:

https://github.com/mozilla-b2g/gaia/commit/5ddc778a7eb4deaf139471c9518a7065c1a774d4

I think we need to also land on v2.0?
https://hg.mozilla.org/mozilla-central/rev/387df8864e0d
Status: ASSIGNED → RESOLVED
Closed: 6 years ago
Resolution: --- → FIXED
Target Milestone: 2.0 S5 (4july) → 2.0 S6 (18july)
Flags: in-moztrap?(bzumwalt)
New test case needs to be written to address bug.
QA Whiteboard: [QAnalyst-Triage?]
Flags: needinfo?(ktucker)
Test case added in moztrap:

https://moztrap.mozilla.org/manage/case/14355/
QA Whiteboard: [QAnalyst-Triage?] → [QAnalyst-Triage+]
Flags: needinfo?(ktucker)
Flags: in-moztrap?(bzumwalt)
Flags: in-moztrap+
Flags: needinfo?(jdarcangelo)
You need to log in before you can comment on or make changes to this bug.