crop_rec on steroids: 3K, 4K, 1080p48, full-resolution LiveView

[Danne]

FFmpeg domain, not mlv_dump. That changes stuff. Let me have a look.

[Danne]

Code: [Select]

-frames:vNot really working with -vcodec it seems and then we´re back to reencoding delays. Anyway. I trust these lines below. Been running a long time with wav files in Switch and before that .

Code: [Select]

frct=$(mlv_dump *"$MLV" | awk '/Processed/ { print $2; }')
FPS=$(mlv_dump *"$MLV" | awk '/Processed/ { print $6; }')     
trimmed=$(echo $frct/$FPS | bc -l | awk 'FNR == 1 {print}')

[a1ex]

Code: [Select]

$ time ffmpeg -i BLACK_4GB.MOV -frames:v 500 -vcodec copy -acodec copy x.mov -y -loglevel error -hide_banner
real 0m2.530s
user 0m0.420s
sys 0m1.296s

$ time ffmpeg -i BLACK_4GB.MOV -vframes 500 -vcodec copy -acodec copy y.mov -y -loglevel error -hide_banner
real 0m2.628s
user 0m0.448s
sys 0m1.296s

$ time ffmpeg -i BLACK_4GB.MOV -to 10 -vcodec copy -acodec copy z.mov -y -loglevel error -hide_banner
real 0m2.575s
user 0m0.480s
sys 0m1.252s

$ stat x.mov y.mov z.mov | grep Size
  Size: 483990897 Blocks: 945304     IO Block: 4096   regular file
  Size: 483990897 Blocks: 945296     IO Block: 4096   regular file
  Size: 484135017 Blocks: 945584     IO Block: 4096   regular file

$ ffprobe -i BLACK_4GB.MOV |& grep fps
    Stream #0:1(eng): Video: prores (apch / 0x68637061), yuv422p10le(bt709), 1920x1080, 384385 kb/s, SAR 1:1 DAR 16:9, 50 fps, 50 tbr, 5k tbn, 5k tbc (default)

$ vbindiff y.mov z.mov

-0000 0010: 71 74 20 20 00 00 00 08  77 69 64 65 1C D8 FD 8C  qt  .... wide....
+0000 0010: 71 74 20 20 00 00 00 08  77 69 64 65 1C DB 30 0C  qt  .... wide..0. 

-1B78 3FA0: 85 09 FF B7 30 AE 5B FC  00 0E C4 00 69 63 70 66  ....0.[. ....icpf 
+1B78 3FA0: 85 09 FF B7 30 AE 5B FC  00 00 00 00 00 00 00 00  ....0.[. ........ 
...

Minor differences at the end of the file and in the header, but neither of these variants is re-encoding the file.

[Danne]

Interesting. Tried again and working. At least -vframes and -frames:v options, and with vcodec. Must have missed something before.

 

Code: [Select]

-0000 0010: 71 74 20 20 00 00 00 08  77 69 64 65 1C D8 FD 8C  qt  .... wide....
+0000 0010: 71 74 20 20 00 00 00 08  77 69 64 65 1C DB 30 0C  qt  .... wide..0.

-1B78 3FA0: 85 09 FF B7 30 AE 5B FC  00 0E C4 00 69 63 70 66  ....0.[. ....icpf
+1B78 3FA0: 85 09 FF B7 30 AE 5B FC  00 00 00 00 00 00 00 00  ....0.[. ........ 
I did some real life testing between my frame_count/fps solution and the -frames:v option. One anomaly is that last frame is prolonged(probably by ffmpeg due to audio sync/iframe etc). The prolonged last image is much longer with the -frames:v option.
Check files:
-frames:v
https://bitbucket.org/Dannephoto/magic-lantern/downloads/vframes.MOV

frame_count/fps
https://bitbucket.org/Dannephoto/magic-lantern/downloads/divisioned.MOV

Conclusion based on this very file only. -frames:v should be closer to perfect in theory but it isn´t? Or maybe I´m just lucky with a more crude number.

[budafilms]

Build August 26 - 5d3 1.1.3
Crop 3,5K 23,98 fps 14 bits Losless

Message when move joystick
Plenty of death pixel when zoom x5

[goldenchild9to5]

Man you guy's are working.. Loving the progress.

[Kharak]

I think there is a bug in the builds since 19th August with 50/60p 3x3.

I am getting some "Frame Jumps" I don't know how to explain it, but its like a frame will repeat it self 5-10 frames later. If that makes sense? At first I thought it was slow external drive causing it but I see it also after transcoding. It might happens only once in an MLV and sometimes 2-3 times. This bug might have been there all along, I think I have seen it "here and there" before, but very random, I will have to have a look at older takes from this summer. But since 19th almost every MLV has this problem.

I have not tried yet to cut the frames out, but not sure if this repeat frame overrides the one that "should have been in its place".

But then again it could also be the Converter, Danne's Batch script, I don't know. I cant see the footage until I have converted the MLV's to DNG.

At the moment, I am on crappy satellite internet again.. This Sat is extra bad, there will be no uploading, but might have some proper internet tomorrow and I will upload a MLV.

But I thought I atleast mention it now in case someone else experienced this and could chime in.

5D3 123. Aug 20th build. The shots I noticed this most on were shot a week ago. I have since then updated to 26th, but have not looked at anything I shot with 26th build. (no time)

[theBilalFakhouri]

Hey a1ex or somone knows the answer
why we can't use 12or 10bit lossless for 720p mode
Can you explain?
My camera canon 700d

[a1ex]

I have no idea, I don't even have a 700D...

https://www.chiark.greenend.org.uk/~sgtatham/bugs.html

Please provide feedback on what works, what not, what happens when it doesn't work. Same for EOS M.

If it's a regression (that is, if it used to work in some older build), regardless of what camera model or feature, please run "hg bisect" to identify the change that introduced the issue.

[RTI]

I get the "busy" message while the 5x crop and raw rec is on an (can't change apperture and shutter speed). In my memory it didn't happen on previous builds. I'm on the latest available Aug 26 5DIII123.

[Danne]

Read last 10-20 posts.
You can press menu button twice to get rid of the signal.

[RTI]

Read last 10-20 posts.
You can press menu button twice to get rid of the signal.

My bad, found it. Thank you.

[mr.smith]

When will the experimental build become nightly build?
and why is it still experimental?

[a1ex]

Answered on... the download page.

[mannfilm]

what is the difference between 1:1 crop and full frame?

[a1ex]

More about the BUSY screen:

* Tried applying the SRM_ClearBusy hack and manually block the full shutter event. Result: the camera ignores the event and stays in LiveView for about 2 seconds, then the MPU throws ERR80.

* Tried decoding the BUSY message (the one from UILOCK_SHUTTER) - it's complicated, they are different in each video mode. After getting it somewhat working, I've noticed it also blocks autofocus. Go figure...

* In the end, I've noticed that freeing one SRM buffer (and keeping the others allocated) appears to be a good compromise (even though it's still a hackish solution):
  - no BUSY screen
  - with N-1 buffers allocated from SRM, and nothing from Shoot memory, Canon firmware:
     - will still record H.264 (it will use the last buffer in this case)
     - will take a picture, then ERR70 (because it expects the SRM buffers to be freed in the same order as allocated)
     - will go outside LiveView and back, but will show BUSY on the screen
     - therefore, in this case, using the last SRM buffer is NOT safe
  - with the entire Shoot memory is allocated, and then N-1 buffers from SRM, Canon firmware is very unlikely to use the last buffer:
     - will not start recording H.264 (if the allocation was done in standby) -> ERR70 (timeout allocating memory).
     - will not stop recording H.264 (if the allocation was done while recording) -> lockup, ERR70 after 10-20 seconds (similar)
     - will not finish taking a picture (BUSY screen after capturing the exposure; will overwrite the additional SRM buffer)
     - will not enter H.264 playback mode from LiveView (black screen, Cannot playback movie after 10-20 seconds)
     - will enter CR2 playback mode from LiveView
     - will exit LiveView (to regular photo mode)
     - will enter Canon menu
     - all the failed actions from above will succeed as soon as we will deallocate our Shoot and SRM memory buffers (if done before the timeout)
     - with the exception of still photo capture, none of the above actions resulted in overwriting the additional SRM buffer
     - therefore, in this case, I believe using the last SRM buffer during LiveView is *probably* safe.

In any case, this method should be a lot safer than using the entire SRM memory after free (as in previous builds without the BUSY screen).

I also believe mlv_rec (in its current state) should now be usable on the current codebase (except maybe for full-res LiveView), as the memory management trickery has been moved into the memory backend.

BTW - if any of you has any clue on how to reproduce this bug, it will be very appreciated.

Forgot to mention - 700D and EOS M will need an extra constant (easy to find).

New build posted.

[dfort]

700D and EOS M will need an extra constant (easy to find).

SRM_BUFFER_SIZE ?

[Kharak]

Sorry. for the big file: 
https://mega.nz/#!pQwT0BQT!r2P1GdlBTgXBcQrx3g4Cqao_pVUO6TLv_cOxZt-zKmQ 751 MB

here is one example of the repeat frame.

And I can basically reproduce this all the time.

Frame 336 and 338 are the same.

[Danne]

Justy downloaded your file. It´s file 335 and 337 that are the same over here at least. Strange.

[Kharak]

That is weird, I went to check if I saw it wrong. But here it is 336 and 338.

I will reconvert the file and see if it changes again. How did you convert it ?

Maybe you could preview the MLV file itself with the MLVFS MLRawViewer thing?

[Danne]

Both in Switch and mlv_dump alone. I don´t think that is the problem.
If viewed in MlRawViewever it´s 336 and 338.

[Kharak]

Yes I was checking the DNG's in MLRawViewer.

[Danne]

Just tested latest crop_rec_4k build. The busy signal is gone! What an achievement. The camera is set free again .
So, what did I test. Decided to run a few MLV takes in 14bit-lossless 24fps and (5D mark III 1.1.3) with proxy recording on. This combo works great and continuously. My findings:
Short files are ok regarding metadata. Then I recorded a 3 minute MLV and suddenly metadata for processed frames weren´t to be found. I got this instead. Check the end. Anything obvious here?:

Code: [Select]

Reached end of chunk 1/3 after 2305 blocks
File Header (MLVI)
    Size        : 0x00000034
    Ver         : v2.0
    GUID        : 11411502559624145806
    FPS         : 23.976000
    File        : 1 / 0
    Frames Video: 2265
    Frames Audio: 0
    Class Video : 0x00000021
    Class Audio : 0x00000000
Block: RAWI
  Offset: 0x00000034
  Number: 1
    Size: 180
    Time: 0.756000 ms
    Res:  1920x1080
    raw_info:
      api_version      0x00000001
      height           1318
      width            2080
      pitch            3640
      frame_size       0x00493450
      bits_per_pixel   14
      black_level      2047
      white_level      16200
      active_area.y1   28
      active_area.x1   146
      active_area.y2   1318
      active_area.x2   2078
      exposure_bias    0, 0
      cfa_pattern      0x02010100
      calibration_ill  1
Got a new RAWI, throwing away average buffers etc.
Got a new RAWI, throwing away previous frame buffers etc.
mlv_dump(6212,0xa533e1c0) malloc: *** error for object 0x848000: pointer being realloc'd was not allocated
*** set a breakpoint in malloc_error_break to debug
Abort trap: 6

Checking in mlv_dump.c code:
               

Code: [Select]

int frame_size = MAX(bit_depth, block_hdr.raw_info.bits_per_pixel) * block_hdr.raw_info.height * block_hdr.raw_info.width / 8;
               
                /* resolution change, old data will be thrown away */
                if(frame_arith_buffer)
                {
                    print_msg(MSG_INFO, "Got a new RAWI, throwing away average buffers etc.\n");
                    free(frame_arith_buffer);
                }
               
                if(prev_frame_buffer)
                {
                    print_msg(MSG_INFO, "Got a new RAWI, throwing away previous frame buffers etc.\n");
                    free(prev_frame_buffer);
                }

[a1ex]

Does it help if you disable SRM memory?

If yes, try this change:

Code: [Select]

--- a/src/exmem.c
+++ b/src/exmem.c
@@ -444,1 +444,1 @@
-            if (shoot_full_suite)
+            if (0)


[Danne]

*UPDATE
Most of this post was due to a buggy version of mlv_dump I was using from my own ml-dng branch.

Disabling SRM memory doesn´t help. I see though that end chunk is shown so could grep for those for now if needed.

With srm ON:

Code: [Select]

Reached end of chunk 1/3 after 2309 blocks
Got a new RAWI, throwing away average buffers etc.
Got a new RAWI, throwing away previous frame buffers etc.
mlv_dump(12500,0xa533e1c0) malloc: *** error for object 0x887000: pointer being realloc'd was not allocated
*** set a breakpoint in malloc_error_break to debug
Abort trap: 6
With srm OFF:

Code: [Select]

Reached end of chunk 1/2 after 2308 blocks
Got a new RAWI, throwing away average buffers etc.
Got a new RAWI, throwing away previous frame buffers etc.
mlv_dump(11467,0xa533e1c0) malloc: *** error for object 0x895000: pointer being realloc'd was not allocated
*** set a breakpoint in malloc_error_break to debug
Abort trap: 6
And maybe I should count the actual dng files processed from the MLV file when syncing MOV proxies. Not sure that all files are always extracted. Maybe:

Code: [Select]

$(find *.dng | wc -l)

* Checked some more. The MOV is way longer than the MLV file. It´s like the MLV file stops in the middle of the recording. MOV is maybe twice the length in a three minute clip.

*august 26th build is giving away the same error

* Error also occurs when not recording proxy with 14bit-lossless mode.

* testing mlv_rec. Notice mlv_play.mo isn´t compaitble with mlv_rec (tc_symbols)

*the *** set a breakpoint in malloc_error_break  doesn´t happen with regular mlv_rec, only mlv_lite


*UPDATE
Tested with mlv_dump compiled in crop_rec_4k branch(ran my own ml-dng version before, sorry:

Code: [Select]

Reached end of chunk 1/3 after 2305 blocks
Got a new RAWI, throwing away average buffers etc.
Got a new RAWI, throwing away previous frame buffers etc.

Reached end of chunk 2/3 after 2278 blocks
Got a new RAWI, throwing away average buffers etc.
Got a new RAWI, throwing away previous frame buffers etc.

Reached end of chunk 3/3 after 296 blocks
Processed 4839 video frames at 23.98 FPS (201.83 s)

*mlv_dump_on steroids processes all dng files! Go figure...
I ran:

Code: [Select]

mlv_dump_on_steroids --relaxed --dng Input.MLV Same command didn´t work with crop_rec_4k mlv_dump


*Started looking at my own version of mlv_dump and it seemed I had some old version included. Not sure how that was possible. I updated to this:
https://bitbucket.org/Dannephoto/magic-lantern/branch/ml-dng-unified_11c
And all was working again.

*Conclusion
Messy testing but mlv_rec recording seems fine. Crop_rec_4k mlv_dump version seems broken since it can´t convert any MLV file I tested. Goes into segmentation fault 11.