Learn how easy it is to sync an existing GitHub or Google Code repo to a SourceForge project! See Demo

Close

MP4Box very slow with files on a SD card

Help
Jan-E
2012-09-23
2013-06-05
1 2 > >> (Page 1 of 2)
  • Jan-E
    Jan-E
    2012-09-23

    Hi,

    In a project of ours a requirement is to transcode and join video files into 1 MP4-file solely on a SD card, with no use at all of the harddisk of the host PC (not even for temporary caches).

    Of course, MP4box seems the way to do the joining part. However it turns out to be terribly slow when working with files on a SD card. I have timed the differences between MP4box versus MEncoder for the joining and mp4creator for optimizing the moov atoms. MP4Box takes 1:20:34 hour, wheras MEncoder+mp4creator take 2:53 minutes.

    Background info:
    http://permalink.gmane.org/gmane.comp.video.mencoder.user/13023
    or the whole topic:
    http://comments.gmane.org/gmane.comp.video.mencoder.user/13007

    I quote a part of this topic:

    Because pictures say more than 1000 words:
    http://x32.elijst.nl/mp4mp4.htm

    The first screenshot shows the initial transcoding of the parts (between 50 and 70% CPU usage), then the joining by mencoder (25% CPU usage), followed by mp4creator -optimize (about 5% CPU usage).

    After that MP4box starts its job with somewhere around 1% CPU usage. I do not know what cause the spike at about 80% of the first shot, but it came in handy, bacause the same spike is on the left side of the second
    screenshot. On the second screenshot you'll see at the far right side the beginning of a small hill in the CPU usage. I deliberately caused that one myself, because the same hill is at about one third of the third screenshot.

    The two spikes on the right side of the third screenshot mark the beginning and the end of the last phase of MP4box: 'writing ISOM file'. Even that phase takes about twice the time mencoder+mp4creator need to
    join the files.

    Do you know what causes the slowness. Can it be overcome in some way? I even searched for tools to create and destroy a RAM disk from the command line on Windows, but could not find a suitable one. Optimizing using RAM would be the fastest, I guess. But can it be done somehow?

     
  • Jean Le Feuvre
    Jean Le Feuvre
    2012-09-28

    have you tried getting rid of all the progress report (-noprog switch) ?
    Wha is the command line you are using ?

     
  • Jan-E
    Jan-E
    2012-09-28

    Commandline:
    mp4box.exe -noprog -align-cat -cat janehrhardt_00000.opt.mp4 -cat janehrhardt_00001.opt.mp4
            -cat janehrhardt_00002.opt.mp4 -cat janehrhardt_00003.opt.mp4 -cat janehrhardt_00004.opt.mp4
            -cat janehrhardt_00005.opt.mp4 -new mp4concat-by-mp4box.mp4

    -noprog was not likely to help because it is not the screen that delays things, but disk access. I started the timing once again and arrived at the similar situation as screenshot 1 at http://x32.elijst.nl/mp4mp4.htm
    MP4Box is still busy appending janehrhardt_00003.opt.mp4, jusy like it was then.

     
  • Several questions just to understand precisely:
    1) Is MP4Box executed on the SD card, the system is on the SD card and /tmp is on the SD card either?
    2) did you run strace and a profiler to be sure that the disk is the limiting factor (or is it a guess)?
    3) if the disk is limiting because of the number of accesses, did you try to increase the fread() buffer by using the setvbuf() family functions?

    Romain

     
  • Jan-E
    Jan-E
    2012-09-28

    I interrupted the process because MP4Box was still busy appending janehrhardt_00003.opt.mp4 (which is the largest file:

    28/09/12  15:54           357.719 janehrhardt_00000.opt.mp4
    28/09/12  15:54           910.324 janehrhardt_00001.opt.mp4
    28/09/12  15:54           672.008 janehrhardt_00002.opt.mp4
    28/09/12  16:05       161.194.079 janehrhardt_00003.opt.mp4
    28/09/12  16:10        93.973.110 janehrhardt_00004.opt.mp4
    28/09/12  16:11        13.886.279 janehrhardt_00005.opt.mp4
                   6 File(s)    270.993.519 bytes
    

    It is clear that -noprog does not make any difference.

    28/09/12 15:54:34,29 start transcoding
    28/09/12 16:11:57,03 start knitting with mencoder
    28/09/12 16:14:15,53 start mp4creator -optimize
    28/09/12 16:14:46,29 optimized mp4concat-by-mencoder.mp4 ready
    28/09/12 16:14:46,29 start knitting with mp4box

    28/09/12 16:56:06,25 creating mp4concat-by-mp4box.mp4 interrupted

    The first of the 6 files is online at
    http://x32.elijst.nl/janehrhardt_00000.opt.mp4

    Jan

     
  • Jan-E
    Jan-E
    2012-09-28

    @Romain:
    1. Everything is on the SD card: mp4box.exe with the DLL's, the input files and the output files.
    2. I am sure it is the disk access, because when I was using -tmp %temp% the speed was already a lot quicker, because the intermediate txxx files were created on the hard disk. Even more quicker was creating the output file in %temp% and copying the output to SD. However our project prohibits us to use anything on the harddisk (and there are likely to be occasions when we even cannot reach the HD because of IT restrictions).
    3. increase the fread() buffer by using the setvbuf() family: I had already been sniffing in the Gpac sources to find the culprit. Can you give me a hint where I should adjust what?

     
  • Jan-E
    Jan-E
    2012-09-30

    My MP4Box.exe was compiled with VC9. To see if that would make any difference I recompiled rev4170 under MinGW with GCC 4.7.1. No dice, the same slow processing. And it did not make any difference to compile it as 32-bit or 64-bit binary. Any other ideas?

     
  • Jan-E
    Jan-E
    2012-09-30

    @Romain: you are probably right about the fread buffer. I had more or less the same problems with FFmpeg's qt-faststart. While copying the rest of the file it did this 1K at a time. I increased that to 32M and the execution time dropped from about 1600 seconds to 4 seconds:

    S:\SD_VIDEO\PRG001>e:\utils\qt-faststart.exe janehrhardt_00005.opt.mp4 5.mp4
    ftyp          0 32
    free         32 8
    mdat         40 13744391
    moov   13744431 141848
     patching stco atom...
     patching stco atom...
     writing ftyp atom...
     writing moov atom...
     copying rest of file...
    Execution time: 1576.259 s
    S:\SD_VIDEO\PRG001>\utils\qt-faststart.exe janehrhardt_00005.opt.mp4 5.mp4
    ftyp          0 32
    free         32 8
    mdat         40 13744391
    moov   13744431 141848
     patching stco atom...
     patching stco atom...
     writing ftyp atom...
     writing moov atom...
     copying rest of file...
    Execution time: 4.027 s
    

    qt-faststart was easy to debug as it is a single source file. It is above my head to make the same changes for MP4Box, but maybe you can.

     
  • Jan-E
    Jan-E
    2012-10-05

    Any news on this one? Can I be of help?

     
  • Hi Jan,

    If you think the slow processing comes from SD card accesses, you need to monitor them. I'd be very interested in your results. Once we have them we may be able to help you.

    Romain

     
  • Jan-E
    Jan-E
    2012-10-05

    I will try to do that, but it ain't easy under Windows. When I looked at qt-faststart, I discovered that it read and wrote the remainder of the file at 1K at a time. That was quite slow at a SD card. Just increasing the read and write operations from 1K at a time to 32M made qt-faststart 400 times faster. I looked around in the GPAC sources if I could increase it for MP4Box as well, but could not find where to do it.

     
  • Jan-E
    Jan-E
    2012-10-05

    Both were already installed on my system. I will try to gather some stats over the weekend.

     
  • Jan-E
    Jan-E
    2012-10-12

    No stats yet, but a comparison between MP4Box under Ubuntu 12.04 and Windows 7 Pro. I put Ubuntu on a USB-stick (using Pendrivelinux), compiled rev4182 and tried to -cat 3 MP4 files of 4 minutes each. Result:

    21:51:20-837412734
    Appending file 1.mp4
    No suitable destination track found - creating new one (type vide)
    Appending: |                    | (01/100)
    Appending: |                    | (02/100)
    <snip>
    Appending: |======              | (34/100)
    No suitable destination track found - creating new one (type soun)
    Appending: |=======             | (35/100)
    <snip>
    Appending: |=================== | (99/100)
                                                     
    Appending file 2.mp4
    Appending: |                    | (01/100)
    Appending: |                    | (02/100)
    <snip>
    Appending: |=================== | (99/100)
                                                     
    Appending file 3.mp4
    Appending: |                    | (01/100)
    Appending: |                    | (02/100)
    <snip>
    Appending: |=================== | (99/100)
                                                     
    Saving 123ubu.mp4: 0.500 secs Interleaving
    ISO File Writing: |                    | (01/100)
    ISO File Writing: |                    | (02/100)
    <snip>
    ISO File Writing: |=================== | (99/100)
                                                            
    21:51:24-306035868
    MP4Box - GPAC version 0.5.1-DEV-rev4182
    GPAC Copyright (c) Telecom ParisTech 2000-2012
    GPAC Configuration:  --static-mp4box
    Features: GPAC_DISABLE_3D
    

    3.5 seconds. The first time I wrote the timestamps to a log file, it apparently used some disk cache and did it within one second and I added nanoseconds to the stamps. Then Windows 7 Pro started from my HD, but the rev4182 binary and the input and output files on the same USB-stick.

    21:31:39,35 
    Appending file 1.mp4
    No suitable destination track found - creating new one (type vide)
    Appending: |                    | (01/100)
    Appending: |                    | (02/100)
    <snip>
    Appending: |======              | (34/100)
    No suitable destination track found - creating new one (type soun)
    Appending: |=======             | (35/100)
    <snip>
    Appending: |=================== | (99/100)
                                                     
    Appending file 2.mp4
    Appending: |                    | (01/100)
    Appending: |                    | (02/100)
    <snip>
    Appending: |=================== | (99/100)
                                                     
    Appending file 3.mp4
    Appending: |                    | (01/100)
    Appending: |                    | (02/100)
    <snip>
    Appending: |=================== | (99/100)
                                                     
    Saving 123win.mp4: 0.500 secs Interleaving
    ISO File Writing: |                    | (01/100)
    ISO File Writing: |                    | (02/100)
    <snip>
    ISO File Writing: |=================== | (99/100)
                                                            
    21:43:41,78 
    MP4Box - GPAC version 0.5.1-DEV-rev4182
    GPAC Copyright (c) Telecom ParisTech 2000-2012
    GPAC Configuration: --prefix=/mingw --extra-cflags='-m32 -I/mingw/include' --extra-ldflags='-m32 -L/mingw/lib' --static-mp4box
    Features: GPAC_DISABLE_3D
    

    12 minutes, i..e. about the same time as the duration of the 3 MP4-files I used as input. Sometimes (cache?) it did it in 7 minutes, but it never came near the 3.5 seconds of Ubuntu.

    Running the same test with input and output files on the HD:

    22:31:45,79 
    22:31:48,77
    

    3 seconds …

     
  • Jan-E
    Jan-E
    2012-10-12

    More timings. The USB-stick and SD cards standard open as 'Quick removal' on my Win7 PC. That means no write-caching. If I turn write caching on, the timing under Win7 becomes:

    22:41:01,68 
    22:41:17,92 
    16 seconds
    

    Same without write caching under Win XP Pro:

    22:49:42,37 
    23:01:59,96
    12 minutes
    

    And with write caching under XP Pro:

    23:10:01,68 
    23:11:17,03
    75 seconds
    

    As was clear from the qt-faststart equivalent, writing a lot of tiny parts of a file to a SD disk, that does not do write-caching, slows MP4Box to a crawl. I cannot influence the way our users access the SD cards, because this is a registry setting.

    @Romain in comment 4: it looks as fread() is not the problem. I am now thinking of using a custom fwrite() replacement that grabs all disk-writes and only writes them in large enough chunks. Do you know better ways to achieve the same?

    BTW: the commandline for Ubuntu / Windows is the same
    MP4Box -align-cat -cat 1.mp4 -cat 2.mp4 -cat 3.mp4 -new 123(ubu|win).mp4

     
  • Jan-E
    Jan-E
    2012-10-12

    This should be fairly simple because fwrite() only is used at two places in the whole GPAC source. Filedump.c might not be interesting, but src/utils/os_divers.c is the interesting one. I borrowed some your _WIN32_WCE error catching and added this right after the fwrite(ptr, size, nmemb, stream):

    fprintf(stderr, "Writing data: %d blocks to write and %d blocks written\n", nmemb, result);

    I ran the commandline again with  2>123win,txt and ended with a log file of more than 100000 (one hundred thousand) lines, stating:

    Writing data: 1 blocks to write and 1 blocks written

    100000 disk writes with no diskcaching! I have tracked down the cause…

     
  • Jan-E
    Jan-E
    2012-10-12

    Made the output somewhat more informative:

    fprintf(stderr, "Result %d of fwrite(%d, %d, %d, %d)\n", result, ptr, size, nmemb, stream);

    A part of the log file follows below. It should be possible to cache the fwrites in memory and only really write them, when (a) the stream changes or (b) a threshold of, say 32k, is reached.

    Would it be possible to implement this, maybe even with a extra -writecache option?

    Jan

    Result 1 of fwrite(9225680, 6969, 1, 1959274848)
    Result 1 of fwrite(9239584, 1562, 1, 1959274848)
    Result 1 of fwrite(9241568, 1945, 1, 1959274848)
    Result 1 of fwrite(9225680, 2410, 1, 1959274848)
    Result 1 of fwrite(9225680, 2531, 1, 1959274848)
    Result 1 of fwrite(9225680, 2335, 1, 1959274848)
    Result 1 of fwrite(9239584, 1442, 1, 1959274848)
    Result 1 of fwrite(9243936, 676, 1, 1959274848)
    Result 1 of fwrite(9243936, 491, 1, 1959274848)
    Result 1 of fwrite(9243936, 553, 1, 1959274848)
    Result 1 of fwrite(9243936, 657, 1, 1959274848)
    Result 1 of fwrite(9243936, 499, 1, 1959274848)
    Result 1 of fwrite(9243936, 633, 1, 1959274848)
    Result 1 of fwrite(9243936, 552, 1, 1959274848)
    Result 1 of fwrite(9243936, 628, 1, 1959274848)
    Result 1 of fwrite(9239584, 789, 1, 1959274848)
    Result 1 of fwrite(9239584, 1321, 1, 1959274848)
    Result 1 of fwrite(9241568, 1921, 1, 1959274848)
    Result 1 of fwrite(9239584, 752, 1, 1959274848)
    Result 1 of fwrite(9225680, 2149, 1, 1959274848)
    Result 1 of fwrite(9239584, 1051, 1, 1959274848)
    Result 1 of fwrite(9239584, 824, 1, 1959274848)
    Result 1 of fwrite(9241568, 1795, 1, 1959274848)
    Result 1 of fwrite(9243936, 557, 1, 1959274848)
    Result 1 of fwrite(9225680, 2683, 1, 1959274848)
    Result 1 of fwrite(9243936, 7178, 1, 1959274848)
    Result 1 of fwrite(9239584, 454, 1, 1959274848)
    Result 1 of fwrite(9225680, 2203, 1, 1959274848)
    Result 1 of fwrite(9239584, 113, 1, 1959274848)
    Result 1 of fwrite(9225680, 2692, 1, 1959274848)
    Result 1 of fwrite(9239584, 1183, 1, 1959274848)
    Result 1 of fwrite(9225680, 2148, 1, 1959274848)
    Result 1 of fwrite(9239584, 551, 1, 1959274848)
    Result 1 of fwrite(9239584, 288, 1, 1959274848)
    Result 1 of fwrite(9239584, 749, 1, 1959274848)
    Result 1 of fwrite(9239584, 580, 1, 1959274848)
    Result 1 of fwrite(9239584, 1011, 1, 1959274848)
    Result 1 of fwrite(9239584, 487, 1, 1959274848)
    Result 1 of fwrite(9239584, 392, 1, 1959274848)
    Result 1 of fwrite(9225680, 2535, 1, 1959274848)
    Result 1 of fwrite(9239584, 1395, 1, 1959274848)
    Result 1 of fwrite(9239584, 498, 1, 1959274848)
    Result 1 of fwrite(9239584, 188, 1, 1959274848)
    Result 1 of fwrite(9239584, 1017, 1, 1959274848)
    Result 1 of fwrite(9239584, 365, 1, 1959274848)
    Result 1 of fwrite(9241568, 1818, 1, 1959274848)
    Result 1 of fwrite(9239584, 189, 1, 1959274848)
    Result 1 of fwrite(9241568, 1792, 1, 1959274848)
    Result 1 of fwrite(9239584, 1190, 1, 1959274848)
    Result 1 of fwrite(9239584, 891, 1, 1959274848)
    Result 1 of fwrite(9243936, 8295, 1, 1959274848)
    Result 1 of fwrite(9239584, 201, 1, 1959274848)
    Result 1 of fwrite(9225680, 2385, 1, 1959274848)
    Result 1 of fwrite(9239584, 1313, 1, 1959274848)
    Result 1 of fwrite(9239584, 614, 1, 1959274848)
    Result 1 of fwrite(9241568, 1876, 1, 1959274848)
    Result 1 of fwrite(9239584, 1416, 1, 1959274848)
    Result 1 of fwrite(9225680, 2166, 1, 1959274848)
    Result 1 of fwrite(9241568, 1733, 1, 1959274848)
    Result 1 of fwrite(9225680, 3001, 1, 1959274848)
    Result 1 of fwrite(9225680, 2225, 1, 1959274848)
    Result 1 of fwrite(9225680, 2279, 1, 1959274848)
    Result 1 of fwrite(9225680, 3314, 1, 1959274848)
    Result 1 of fwrite(9241568, 1682, 1, 1959274848)
    Result 1 of fwrite(9239584, 795, 1, 1959274848)
    Result 1 of fwrite(9225680, 2297, 1, 1959274848)
    Result 1 of fwrite(9239584, 440, 1, 1959274848)
    Result 1 of fwrite(9225680, 2620, 1, 1959274848)
    Result 1 of fwrite(9239584, 1352, 1, 1959274848)
    Result 1 of fwrite(9241568, 1833, 1, 1959274848)
    Result 1 of fwrite(9225680, 2735, 1, 1959274848)
    Result 1 of fwrite(9239584, 1255, 1, 1959274848)
    Result 1 of fwrite(9225680, 2165, 1, 1959274848)
    Result 1 of fwrite(9241568, 1912, 1, 1959274848)
    Result 1 of fwrite(9239584, 1416, 1, 1959274848)
    Result 1 of fwrite(9243936, 8691, 1, 1959274848)
    Result 1 of fwrite(9239584, 809, 1, 1959274848)
    Result 1 of fwrite(9239584, 1547, 1, 1959274848)
    Result 1 of fwrite(9241568, 1698, 1, 1959274848)
    Result 1 of fwrite(9239584, 771, 1, 1959274848)
    Result 1 of fwrite(9239584, 1534, 1, 1959274848)
    Result 1 of fwrite(9239584, 1089, 1, 1959274848)
    Result 1 of fwrite(9239584, 1524, 1, 1959274848)
    Result 1 of fwrite(9239584, 100, 1, 1959274848)
    Result 1 of fwrite(9239584, 886, 1, 1959274848)
    Result 1 of fwrite(9239584, 1406, 1, 1959274848)
    Result 1 of fwrite(9239584, 1251, 1, 1959274848)
    Result 1 of fwrite(9239584, 835, 1, 1959274848)
    Result 1 of fwrite(9239584, 1425, 1, 1959274848)
    Result 1 of fwrite(9239584, 695, 1, 1959274848)
    Result 1 of fwrite(9241568, 1834, 1, 1959274848)
    Result 1 of fwrite(9225680, 2855, 1, 1959274848)
    Result 1 of fwrite(9241568, 1659, 1, 1959274848)
    Result 1 of fwrite(9239584, 370, 1, 1959274848)
    Result 1 of fwrite(9239584, 1233, 1, 1959274848)
    Result 1 of fwrite(9241568, 1816, 1, 1959274848)
    Result 1 of fwrite(9241568, 1666, 1, 1959274848)
    Result 1 of fwrite(9239584, 1320, 1, 1959274848)
    Result 1 of fwrite(9241568, 1631, 1, 1959274848)
    Result 1 of fwrite(9241568, 1683, 1, 1959274848)
    Result 1 of fwrite(9243936, 8507, 1, 1959274848)
    Result 1 of fwrite(9233472, 1680, 1, 1959274848)
    Result 1 of fwrite(9233472, 602, 1, 1959274848)
    Result 1 of fwrite(9233472, 1234, 1, 1959274848)
    Result 1 of fwrite(9233472, 546, 1, 1959274848)
    Result 1 of fwrite(9233472, 1094, 1, 1959274848)
    Result 1 of fwrite(9233472, 1814, 1, 1959274848)
    Result 1 of fwrite(9233472, 725, 1, 1959274848)
    Result 1 of fwrite(9233472, 1595, 1, 1959274848)
    Result 1 of fwrite(9233472, 479, 1, 1959274848)
    Result 1 of fwrite(9233472, 1608, 1, 1959274848)
    Result 1 of fwrite(9233472, 1252, 1, 1959274848)
    Result 1 of fwrite(9240800, 160, 1, 1959274848)
    Result 1 of fwrite(9233472, 1221, 1, 1959274848)
    Result 1 of fwrite(9233472, 956, 1, 1959274848)
    Result 1 of fwrite(9240800, 247, 1, 1959274848)
    Result 1 of fwrite(9233472, 1275, 1, 1959274848)
    Result 1 of fwrite(9233472, 1917, 1, 1959274848)
    Result 1 of fwrite(9233472, 921, 1, 1959274848)
    Result 1 of fwrite(9233472, 975, 1, 1959274848)
    Result 1 of fwrite(9233472, 589, 1, 1959274848)
    Result 1 of fwrite(9220344, 430, 1, 1959274848)
    Result 1 of fwrite(9233472, 838, 1, 1959274848)
    Result 1 of fwrite(9233472, 1661, 1, 1959274848)
    Result 1 of fwrite(9233472, 921, 1, 1959274848)
    Result 1 of fwrite(9241568, 8767, 1, 1959274848)
    Result 1 of fwrite(9233472, 840, 1, 1959274848)
    Result 1 of fwrite(9228688, 2080, 1, 1959274848)
    Result 1 of fwrite(9233472, 652, 1, 1959274848)
    Result 1 of fwrite(9233472, 1934, 1, 1959274848)
    Result 1 of fwrite(9233472, 914, 1, 1959274848)
    Result 1 of fwrite(9228688, 2086, 1, 1959274848)
    Result 1 of fwrite(9233472, 1330, 1, 1959274848)
    Result 1 of fwrite(9233472, 1037, 1, 1959274848)
    Result 1 of fwrite(9233472, 489, 1, 1959274848)
    Result 1 of fwrite(9233472, 843, 1, 1959274848)
    Result 1 of fwrite(9233472, 859, 1, 1959274848)
    Result 1 of fwrite(9233472, 500, 1, 1959274848)
    Result 1 of fwrite(9233472, 901, 1, 1959274848)
    Result 1 of fwrite(9233472, 1038, 1, 1959274848)
    Result 1 of fwrite(9240800, 135, 1, 1959274848)
    Result 1 of fwrite(9233472, 473, 1, 1959274848)
    Result 1 of fwrite(9233472, 1429, 1, 1959274848)
    Result 1 of fwrite(9240800, 262, 1, 1959274848)
    Result 1 of fwrite(9240800, 160, 1, 1959274848)
    Result 1 of fwrite(9240800, 155, 1, 1959274848)
    Result 1 of fwrite(9240800, 191, 1, 1959274848)
    Result 1 of fwrite(9233472, 1393, 1, 1959274848)
    Result 1 of fwrite(9220344, 396, 1, 1959274848)
    Result 1 of fwrite(9233472, 895, 1, 1959274848)
    Result 1 of fwrite(9241568, 9497, 1, 1959274848)
    Result 1 of fwrite(9251992, 625, 1, 1959274848)
    Result 1 of fwrite(9233472, 1004, 1, 1959274848)
    Result 1 of fwrite(9251992, 691, 1, 1959274848)
    Result 1 of fwrite(9239584, 449, 1, 1959274848)
    
     
  • Jan-E
    Jan-E
    2012-10-13

    I tried increasing the buffer by changing the 'return fopen (file_name, mode);' into

        FILE *pFile;
        pFile=fopen (file_name, mode);
        setvbuf ( pFile , NULL , _IOFBF , 16192 );
        return pFile;
    

    But that did not work (maybe because I did not use the right method or syntax).

    Then I checked if fread() was a problem by not fwriting anything at all. Of course, it gave an error in the last phase (saving), but the reading of the 3 input files took only 2 seconds. So the fwrite is really the problem.

    My C-knowledge stops here.

     
  • Jean Le Feuvre
    Jean Le Feuvre
    2012-10-14

    Actually the final interleaver in MP4Box does not use large fwrite chunks but rather write on a sample-by-sample, directly to disk. We would need a memory buffered IO stream mode here, I'll try to have a look at that.

     
  • Jan-E
    Jan-E
    2012-10-14

    OK, thanks. BTW: all phases are slow. Not only the final interleaving, but the 'appending file' phase too. The logpart above is taken from the very beginning, i.e. -catting the first file.

     
  • Just a few quick remarks/questions.

    First you may want to check the setvbuf() return value.

    How do you get the log on msg 17? Are there other traces about fseek calls, etc? When you say "did not work", do you mean you get the same log?

    setvbuf() has side effects: 1) it allocates a buffer and 2) it fills the buffer after each fseek() call.

    Romain

     
  • Jan-E
    Jan-E
    2012-10-14

    @Romain: the log file in msg 17 was created by adding this line directly after the fwrite statement in the gf_fwrite function in src/utils/os_divers.c

    fprintf(stderr, "Result %d of fwrite(%d, %d, %d, %d)\n", result, ptr, size, nmemb, stream);

    By catching the stderr output I discovered that over 100000 fwrite-statements were executed while executing -cat on 3 videos of 4 minutes each.

    setvbuf (pFile, NULL, _IOFBF, 16192) always returns a zero, which seems to imply that the buffer is correctly assigned to the file.

    "did not work": assigning a buffer to the opened file did not make any difference at all. Still 100000+ fwrite operations and the same slow timing. Additionally I have put a buffer on the tmpfile() in gf_temp_file_new. Result: 0, but still the slow timing.

    I did not track any fseek operations. because the fwrite was the cause of the trouble.

     
  • You should definitely use strace to see which fwrite leads a disk access.

    Romain

     
  • Jan-E
    Jan-E
    2012-10-14

    I checked that, using procmon. Every fwrite in the function gf_fwrite (src/utils/os_divers.c) leads to disk access. See the screenshot of procmon at http://elijst.nl/procmon.gif
    This corresponds with this part of my log files:

    Result 1 of fwrite(9774624, 701, 1, 1971267936) - Sun Oct 14 22:29:53 2012
    Result 1 of fwrite(9741448, 1809, 1, 1971267936) - Sun Oct 14 22:29:53 2012
    Result 1 of fwrite(9774624, 1134, 1, 1971267936) - Sun Oct 14 22:29:53 2012
    Result 1 of fwrite(9741448, 1922, 1, 1971267936) - Sun Oct 14 22:29:53 2012
    Result 1 of fwrite(9774624, 607, 1, 1971267936) - Sun Oct 14 22:29:53 2012
    Result 1 of fwrite(9741448, 1219, 1, 1971267936) - Sun Oct 14 22:29:53 2012
    Result 1 of fwrite(9741448, 1305, 1, 1971267936) - Sun Oct 14 22:29:53 2012
    Result 1 of fwrite(9774624, 1004, 1, 1971267936) - Sun Oct 14 22:29:53 2012
    

    So that is 100000+ disk writes for -catting 3 files of 4 minutes each. Every -cat takes about 17000 disk writes and almost 2 minutes (22:29:34 - 22:31:19 for 1.mp4). After that the 'Saving 123win.mp4: 0.500 secs Interleaving' phase generates another 50000 diskwrites and half a minute (22:34:56 - 22:35:27). The 6 minutes is faster than previous timings, because this was done on a Class 10 (30 MB/s) SD card.

    If I disable the fwrite in the function gf_fwrite and recompile MP4Box without fwriting anything at all, the function gf_fwrite is (of course) called 17000 times for every -cat, but processing is almost instantly.

     
  • Jan-E
    Jan-E
    2012-10-14

    With write-caching on the SD card enabled, you get something like this:
    http://elijst.nl/procmon2.gif
    The FAST IO DISALLOWED messages disappeared

    Still 100000 disk writes, but total processing takes 9 seconds (0:04:55,43 - 0:05:04,76). But sadly enough, I cannot manipulate the way our users access the SD cards. Changing system/registry settings are way beyond what the system administrators allow us to do.

     
1 2 > >> (Page 1 of 2)