Suspended
Suspended

Reputation: 1190

ffmpeg takes too long to start

I have this command in python script, in a loop:

ffmpeg -i somefile.mp4 -ss 00:03:12 -t 00:00:35 piece.mp4 -loglevel error -stats

It cuts out pieces of input file (-i). Input filename, as well as start time (-ss) and length of the piece I cut out (-t) varies, so it reads number of mp4 files and cuts out number of pieces from each one. During execution of the script it might be called around 100 times. My problem is that each time before it starts, there is a delay of 6-15 seconds and it adds up to significant time. How can I get it to start immediately?

Initially I thought it was process priority problem, but I noticed that even during the "pause", all processors work at 100%, so apparently some work is being done.

The script (process_videos.py):

import subprocess
import sys
import math
import time

class TF:
    """TimeFormatter class (TF).
This class' reason for being is to convert time in short
form, e.g. 1:33, 0:32, or 23 into long form accepted by
mp4cut function in bash, e.g. 00:01:22, 00:00:32, etc"""

def toLong(self, shrt):
    """Converts time to its long form"""
    sx = '00:00:00'
    ladd = 8 - len(shrt)
    n = sx[:ladd] + shrt
    return n

def toShort(self, lng):
    """Converts time to short form"""
    if lng[0] == '0' or lng[0] == ':':
        return self.toShort(lng[1:])
    else:
        return lng

def toSeconds(self, any_time):
    """Converts time to seconds"""
    if len(any_time) < 3:
        return int(any_time)
    tt = any_time.split(':')
    if len(any_time) < 6:            
        return int(tt[0])*60 + int(tt[1])
    return int(tt[0])*3600 + int(tt[1])*60 + int(tt[2])

def toTime(self, secsInt):
    """"""
    tStr = ''
    hrs, mins, secs = 0, 0, 0
    if secsInt >= 3600:
        hrs = math.floor(secsInt / 3600)
        secsInt = secsInt % 3600
    if secsInt >= 60:
        mins = math.floor(secsInt / 60)
        secsInt = secsInt % 60
    secs = secsInt
    return str(hrs).zfill(2) + ':' + str(mins).zfill(2) + ':' + str(secs).zfill(2)

def minus(self, t_start, t_end):
    """"""
    t_e = self.toSeconds(t_end)
    t_s = self.toSeconds(t_start)
    t_r = t_e - t_s
    hrs, mins, secs = 0, 0, 0
    if t_r >= 3600:
        hrs = math.floor(t_r / 3600)
        t_r = t_r - (hrs * 3600)
    if t_r >= 60:
        mins = math.floor(t_r / 60)
        t_r = t_r - (mins * 60)
    secs = t_r
    hrsf = str(hrs).zfill(2)
    minsf = str(mins).zfill(2)
    secsf = str(secs).zfill(2)
    t_fnl = hrsf + ':' + minsf + ':' + secsf
    return t_fnl

def go_main():
    tf = TF()
    vid_n = 0
    arglen = len(sys.argv)
    if arglen == 2:
        with open(sys.argv[1], 'r') as f_in:
            lines = f_in.readlines()
            start = None
            end = None
            cnt = 0
            for line in lines:
                if line[:5] == 'BEGIN':
                    start = cnt
                if line[:3] == 'END':
                    end = cnt
                cnt += 1
            if start == None or end == None:
                print('Invalid file format. start = {}, end = {}'.format(start,end))
                return
            else:
                lines_r = lines[start+1:end]
                del lines
                print('videos to process: {}'.format(len(lines_r)))
                f_out_prefix = ""
                for vid in lines_r:
                     vid_n += 1
                    print('\nProcessing video {}/{}'.format(vid_n, len(lines_r)))
                    f_out_prefix = 'v' + str(vid_n) + '-'
                    dat = vid.split('!')[1:3]
                    title = dat[0]
                    dat_t = dat[1].split(',')
                    v_pieces = len(dat_t)
                    piece_n = 0
                    video_pieces = []
                    cmd1 = "echo -n \"\" > tmpfile"
                    subprocess.run(cmd1, shell=True)                    
                    print('  new tmpfile created')
                    for v_times in dat_t:
                        piece_n += 1
                        f_out = f_out_prefix + str(piece_n) + '.mp4'
                        video_pieces.append(f_out)
                        print('  piece filename {} added to video_pieces list'.format(f_out))
                        v_times_spl = v_times.split('-')
                        v_times_start = v_times_spl[0]
                        v_times_end = v_times_spl[1]
                        t_st = tf.toLong(v_times_start)
                        t_dur = tf.toTime(tf.toSeconds(v_times_end) - tf.toSeconds(v_times_start))
                        cmd3 = ["ffmpeg", "-i", title, "-ss", t_st, "-t", t_dur, f_out, "-loglevel", "error", "-stats"]
                        print('  cutting out piece {}/{} - {}'.format(piece_n, len(dat_t), t_dur))
                        subprocess.run(cmd3)
                    for video_piece_name in video_pieces:
                        cmd4 = "echo \"file " + video_piece_name + "\" >> tmpfile"
                        subprocess.run(cmd4, shell=True)
                        print('  filename {} added to tmpfile'.format(video_piece_name))
                    vname = f_out_prefix[:-1] + ".mp4"
                    print('  name of joined file: {}'.format(vname))
                    cmd5 = "ffmpeg -f concat -safe 0 -i tmpfile -c copy joined.mp4 -loglevel error -stats"
                    to_be_joined = " ".join(video_pieces)
                    print('  joining...')
                    join_cmd = subprocess.Popen(cmd5, shell=True)
                    join_cmd.wait()
                    print('  joined!')
                    cmd6 = "mv joined.mp4 " + vname
                    rename_cmd = subprocess.Popen(cmd6, shell=True)
                    rename_cmd.wait()
                    print('  File joined.mp4 renamed to {}'.format(vname))
                    cmd7 = "rm " + to_be_joined
                    rm_cmd = subprocess.Popen(cmd7, shell=True)
                    rm_cmd.wait()
                    print('rm command completed - pieces removed')
                cmd8 = "rm tmpfile"
                subprocess.run(cmd8, shell=True)
                print('tmpfile removed')
                print('All done')
    else:
        print('Incorrect number of arguments')

############################
if __name__ == '__main__':
    go_main()

process_videos.py is called from bash terminal like this:

$ python process_videos.py video_data   

video_data file has the following format:

BEGIN
!first_video.mp4!3-23,55-1:34,2:01-3:15,3:34-3:44!
!second_video.mp4!2-7,12-44,1:03-1:33!
END

My system details:

System:    Host: snowflake Kernel: 5.4.0-52-generic x86_64 bits: 64 Desktop: Gnome 3.28.4
           Distro: Ubuntu 18.04.5 LTS
Machine:   Device: desktop System: Gigabyte product: N/A serial: N/A
Mobo:      Gigabyte model: Z77-D3H v: x.x serial: N/A BIOS: American Megatrends v: F14 date: 05/31/2012
CPU:       Quad core Intel Core i5-3570 (-MCP-) cache: 6144 KB 
           clock speeds: max: 3800 MHz 1: 1601 MHz 2: 1601 MHz 3: 1601 MHz 4: 1602 MHz
Drives:    HDD Total Size: 1060.2GB (55.2% used)
           ID-1: /dev/sda model: ST31000524AS size: 1000.2GB
           ID-2: /dev/sdb model: Corsair_Force_GT size: 60.0GB
Partition: ID-1: / size: 366G used: 282G (82%) fs: ext4 dev: /dev/sda1
           ID-2: swap-1 size: 0.70GB used: 0.00GB (0%) fs: swap dev: /dev/sda5
Info:      Processes: 313 Uptime: 16:37 Memory: 3421.4/15906.9MB Client: Shell (bash) inxi: 2.3.56

UPDATE:

Following Charles' advice, I used performance sampling:

# perf record -a -g sleep 180

...and here's the report:

Samples: 74K of event 'cycles', Event count (approx.): 1043554519767
  Children      Self  Command          Shared Object
-   50.56%    45.86%  ffmpeg           libavcodec.so.57.107.100                                                                                
   - 3.10% 0x4489480000002825                                                                                                                  
       0.64% 0x7ffaf24b92f0                                                                                                                   
   - 2.12% 0x5f7369007265646f                                                                                                                  
       av_default_item_name                                                                                                                   
     1.39% 0                                                                                                                                   
-   44.48%    40.59%  ffmpeg           libx264.so.152                                                                                          
     5.78% x264_add8x8_idct_avx2.skip_prologue                                                                                                 
     3.13% x264_add8x8_idct_avx2.skip_prologue                                                                                                 
     2.91% x264_add8x8_idct_avx2.skip_prologue                                                                                                 
     2.31% x264_add8x8_idct_avx.skip_prologue                                                                                                  
     2.03% 0                                                                                                                                   
     1.78% 0x1                                                                                                                                 
     1.26% x264_add8x8_idct_avx2.skip_prologue                                                                                                 
     1.09% x264_add8x8_idct_avx.skip_prologue                                                                                                  
     1.06% x264_me_search_ref                                                                                                                  
     0.97% x264_add8x8_idct_avx.skip_prologue                                                                                                  
     0.60% x264_me_search_ref                                                                                                                  
-   38.01%     0.00%  ffmpeg           [unknown]                                                                                               
     4.10% 0                                                                                                                                   
   - 3.49% 0x4489480000002825                                                                                                                  
        0.70% 0x7ffaf24b92f0                                                                                                                   
        0.56% 0x7f273ae822f0                                                                                                                   
        0.50% 0x7f0c4768b2f0                                                                                                                   
   - 2.29% 0x5f7369007265646f                                                                                                                  
        av_default_item_name                                                                                                                   
     1.99% 0x1                                                                                                                                 
    10.13%    10.12%  ffmpeg           [kernel.kallsyms]                                                                                       
-    3.14%     0.73%  ffmpeg           libavutil.so.55.78.100                                                                                  
     2.34% av_default_item_name                                                                                                                
-    1.73%     0.21%  ffmpeg           libpthread-2.27.so                                                                                      
   - 0.70% pthread_cond_wait@@GLIBC_2.3.2                                                                                                      
      - 0.62% entry_SYSCALL_64_after_hwframe                                                                                                   
         - 0.62% do_syscall_64                                                                                                                 
            - 0.57% __x64_sys_futex                                                                                                            
                 0.52% do_futex                                                                                                                
     0.93%     0.89%  ffmpeg           libc-2.27.so                                                                                            
-    0.64%     0.64%  swapper          [kernel.kallsyms]                                                                                       
     0.63% secondary_startup_64                                                                                                                
     0.21%     0.18%  ffmpeg           libavfilter.so.6.107.100                                                                                
     0.20%     0.11%  ffmpeg           libavformat.so.57.83.100                                                                                
     0.12%     0.11%  ffmpeg           ffmpeg                                                                                                  
     0.11%     0.00%  gnome-terminal-  [unknown]                                                                                               
     0.09%     0.07%  ffmpeg           libm-2.27.so                                                                                            
     0.08%     0.07%  ffmpeg           ld-2.27.so                                                                                              
     0.04%     0.04%  gnome-terminal-  libglib-2.0.so.0.5600.4



Upvotes: 2

Views: 1962

Answers (1)

Ali Akbar
Ali Akbar

Reputation: 392

When you put -ss afer -i, mplayer will not use the keyframes to jump into the frame. ffmpeg will decode the video from the beginning of the video. That's where the 6-15 second delay with 100% CPU usage came from.

You can put -ss before the -i e.g:

ffmpeg -ss 00:03:12 -i somefile.mp4 -t 00:00:35 piece.mp4 -loglevel error -stats

This will make ffmpeg use the keyframes and directly jumps to the starting time.

Upvotes: 5

Related Questions