0002274: Rendering 2-pass VOB reports crast at end of 2nd pass put, file appears okay

(0007141)
johnedstone (reporter)
2011-08-06 14:12

All four steps listed on http://www.kdenlive.org/bug-reports [^] are okay

mlt-0.6.2_4

I realize that my kdenlive is not the most recent, 0.8. So, if this is not reproducible on 0.8, I'll wait for the port to be released. Do you know, though, is this an error I can ignore?
Thanks

(0007204)
johnedstone (reporter)
2011-08-15 22:29

So, here's what's in /var/log/messages

kernel: pid 2218 (melt), uid 1001: exited on signal 11

And, I removed kdenlive (pkg_deinstall -R kdenlive), including mlt, and and reinstalled (make install clean ) the error still persists.

(0007218)
ttill (developer)
2011-08-25 20:33

I am able to reproduce using latest versions.

(0007248)
johnedstone (reporter)
2011-08-30 04:43

Upgraded ffmpeg to latest in ports, and the problem persists, i.e. still there.

Upgraded with this sequence
----------------------------
pkgdb -F;portsclean -DD;portsclean -C;portsnap fetch update
portupgrade -a -e -v -l /var/tmp/portupgrade_log_file

Current versions
----------------
pkg_info -XI '^(kdenlive|ffmpeg|mlt|fluxbox)-' |awk '{print $1}'
ffmpeg-0.7.3,1
fluxbox-1.3.1
kdenlive-0.7.8_2
mlt-0.6.2_4

(0007249)
johnedstone (reporter)
2011-08-30 05:32

More interesting information
-----------------------------
I ran melt from the command line, together with truss

truss melt ~/kdenlive/projects/crash_test.kdenlive in=0 out=311 -profile dv_ntsc -consumer avformat:/home/ejstone34/kdenlive/untitled.vob progress=1 f=dvd vcodec=mpeg2video acodec=ac3 s=720x480 b=6000k maxrate=9000k minrate=0 bufsize=1835008 mux_packet_s=2048 mux_rate=10080000 ab=192k ar=48000 g=18 me_range=63 trellis=1 profile=dv_ntsc pass=1

and then

truss melt ~/kdenlive/projects/crash_test.kdenlive in=0 out=311 -profile dv_ntsc -consumer avformat:/home/ejstone34/kdenlive/untitled.vob progress=1 f=dvd vcodec=mpeg2video acodec=ac3 s=720x480 b=6000k maxrate=9000k minrate=0 bufsize=1835008 mux_packet_s=2048 mux_rate=10080000 ab=192k ar=48000 g=18 me_range=63 trellis=1 profile=dv_ntsc pass=2

And near the end of the truss, on the second pass, look at this:
-------------------------------
lstat("/export/non_export/home/ejstone34/x264_2pass.log",0x7fffffbfe870) ERR#2 'No such file or directory'
lstat("/export/non_export/home/ejstone34/x264_2pass.log.temp",0x7fffffbfe870) ERR#2 'No such file or directory'
lstat("/export/non_export/home/ejstone34/x264_2pass.log.mbtree",0x7fffffbfe870) ERR#2 'No such file or directory'

and then a little later
-----------------------
write(2,"\n",1) ERR#9 'Bad file descriptor'

and then at the end
-------------------
SIGNAL 11 (SIGSEGV)
process exit, rval = 0

So, what strikes me as odd is why is it looking for x264_2pass.log?
This file doesn't exist, and is not part of the process, I don't think.

Right before all of these errors, it removes the correct log file created from the first pass, and then goes into the above errors. This makes me think its working, but bailing on these last lines.

Line right before the errors is:
----------------------------------
unlink("/home/ejstone34/kdenlive/untitled.vob_2pass.log") = 0 (0x0)

(0007250)
ddennedy (developer)
2011-08-30 05:54

The fact that it tries to remove x264 logs is not the source of the error. You are witnessing a coding shortcut - not bothering to check codec in use when cleaning pass 2 - just delete extra files that _might_ have been created. The only real problem that can cause is when you have a melt encode occurring within the same directory.

I do not think any of your truss output shows anything definitively.
I will try to reproduce vob 2 pass with ffmpeg 0.7.3 and mlt git head.

(0007251)
ddennedy (developer)
2011-08-30 06:45

I reproduced it. It is crashing due to the following line I commented out in this diff. (It actually occurs when the consumer object is closed and all properties closed. It crashes on when free-ing the _logbuffer property. The logbuffer is allocated just above with av_malloc. So, it is not yet clear why.

diff --git a/src/modules/avformat/consumer_avformat.c b/src/modules/avformat/consumer_avformat.c
index 179815c..3cd64d9 100644
--- a/src/modules/avformat/consumer_avformat.c
+++ b/src/modules/avformat/consumer_avformat.c
@@ -851,7 +851,7 @@ static AVStream *add_video_stream( mlt_consumer consumer, AVFormatContext *oc, A
                         fclose( f );
                         logbuffer[size] = '\0';
                         c->stats_in = logbuffer;
- mlt_properties_set_data( properties, "_logbuffer", logbuffer, 0, ( mlt_destructor )av_free, NULL );
+// mlt_properties_set_data( properties, "_logbuffer", logbuffer, size, ( mlt_destructor )av_free, NULL );
                     }
                 }
             }

(0007252)
ddennedy (developer)
2011-08-30 07:18

Here is the fix I committed:

diff --git a/src/modules/avformat/consumer_avformat.c b/src/modules/avformat/consumer_avformat.c
index 179815c..5741d5c 100644
--- a/src/modules/avformat/consumer_avformat.c
+++ b/src/modules/avformat/consumer_avformat.c
@@ -851,7 +851,6 @@ static AVStream *add_video_stream( mlt_consumer consumer, AVFormatContext *oc, A
                         fclose( f );
                         logbuffer[size] = '\0';
                         c->stats_in = logbuffer;
- mlt_properties_set_data( properties, "_logbuffer", logbuffer, 0, ( mlt_destructor )av_free, NULL );
                     }
                 }
             }
@@ -951,6 +950,7 @@ void close_video(AVFormatContext *oc, AVStream *st)
     if ( st && st->codec )
     {
         avformat_lock();
+ av_freep( &st->codec->stats_in );
         avcodec_close(st->codec);
         avformat_unlock();
     }

(0007253)
ddennedy (developer)
2011-08-30 07:19

Fixed in mlt git commit 31948b. Thank you for reporting it with good information.

Issue History
Date Modified	Username	Field	Change
2011-08-04 17:04	johnedstone	New Issue
2011-08-06 14:10	johnedstone	File Added: test_file_kdenlive.txt
2011-08-06 14:12	johnedstone	Note Added: 0007141
2011-08-15 22:29	johnedstone	Note Added: 0007204
2011-08-25 20:33	ttill	Note Added: 0007218
2011-08-25 20:33	ttill	Assigned To	=> ddennedy
2011-08-25 20:33	ttill	Status	new => assigned
2011-08-30 04:43	johnedstone	Note Added: 0007248
2011-08-30 05:32	johnedstone	Note Added: 0007249
2011-08-30 05:54	ddennedy	Note Added: 0007250
2011-08-30 06:45	ddennedy	Note Added: 0007251
2011-08-30 07:18	ddennedy	Note Added: 0007252
2011-08-30 07:19	ddennedy	Note Added: 0007253
2011-08-30 07:19	ddennedy	Status	assigned => resolved
2011-08-30 07:19	ddennedy	Fixed in Version	=> Recent git
2011-08-30 07:19	ddennedy	Resolution	open => fixed
2011-10-31 15:23	j-b-m	Fixed in Version	Recent git => 0.8.2
2011-11-01 18:56	j-b-m	Status	resolved => closed

Notes
(0007141) johnedstone (reporter) 2011-08-06 14:12	All four steps listed on http://www.kdenlive.org/bug-reports [^] are okay mlt-0.6.2_4 I realize that my kdenlive is not the most recent, 0.8. So, if this is not reproducible on 0.8, I'll wait for the port to be released. Do you know, though, is this an error I can ignore? Thanks

(0007204) johnedstone (reporter) 2011-08-15 22:29	So, here's what's in /var/log/messages kernel: pid 2218 (melt), uid 1001: exited on signal 11 And, I removed kdenlive (pkg_deinstall -R kdenlive), including mlt, and and reinstalled (make install clean ) the error still persists.

(0007218) ttill (developer) 2011-08-25 20:33	I am able to reproduce using latest versions.

(0007248) johnedstone (reporter) 2011-08-30 04:43	Upgraded ffmpeg to latest in ports, and the problem persists, i.e. still there. Upgraded with this sequence ---------------------------- pkgdb -F;portsclean -DD;portsclean -C;portsnap fetch update portupgrade -a -e -v -l /var/tmp/portupgrade_log_file Current versions ---------------- pkg_info -XI '^(kdenlive\|ffmpeg\|mlt\|fluxbox)-' \|awk '{print $1}' ffmpeg-0.7.3,1 fluxbox-1.3.1 kdenlive-0.7.8_2 mlt-0.6.2_4

(0007249) johnedstone (reporter) 2011-08-30 05:32	More interesting information ----------------------------- I ran melt from the command line, together with truss truss melt ~/kdenlive/projects/crash_test.kdenlive in=0 out=311 -profile dv_ntsc -consumer avformat:/home/ejstone34/kdenlive/untitled.vob progress=1 f=dvd vcodec=mpeg2video acodec=ac3 s=720x480 b=6000k maxrate=9000k minrate=0 bufsize=1835008 mux_packet_s=2048 mux_rate=10080000 ab=192k ar=48000 g=18 me_range=63 trellis=1 profile=dv_ntsc pass=1 and then truss melt ~/kdenlive/projects/crash_test.kdenlive in=0 out=311 -profile dv_ntsc -consumer avformat:/home/ejstone34/kdenlive/untitled.vob progress=1 f=dvd vcodec=mpeg2video acodec=ac3 s=720x480 b=6000k maxrate=9000k minrate=0 bufsize=1835008 mux_packet_s=2048 mux_rate=10080000 ab=192k ar=48000 g=18 me_range=63 trellis=1 profile=dv_ntsc pass=2 And near the end of the truss, on the second pass, look at this: ------------------------------- lstat("/export/non_export/home/ejstone34/x264_2pass.log",0x7fffffbfe870) ERR#2 'No such file or directory' lstat("/export/non_export/home/ejstone34/x264_2pass.log.temp",0x7fffffbfe870) ERR#2 'No such file or directory' lstat("/export/non_export/home/ejstone34/x264_2pass.log.mbtree",0x7fffffbfe870) ERR#2 'No such file or directory' and then a little later ----------------------- write(2,"\n",1) ERR#9 'Bad file descriptor' and then at the end ------------------- SIGNAL 11 (SIGSEGV) process exit, rval = 0 So, what strikes me as odd is why is it looking for x264_2pass.log? This file doesn't exist, and is not part of the process, I don't think. Right before all of these errors, it removes the correct log file created from the first pass, and then goes into the above errors. This makes me think its working, but bailing on these last lines. Line right before the errors is: ---------------------------------- unlink("/home/ejstone34/kdenlive/untitled.vob_2pass.log") = 0 (0x0)

(0007250) ddennedy (developer) 2011-08-30 05:54	The fact that it tries to remove x264 logs is not the source of the error. You are witnessing a coding shortcut - not bothering to check codec in use when cleaning pass 2 - just delete extra files that _might_ have been created. The only real problem that can cause is when you have a melt encode occurring within the same directory. I do not think any of your truss output shows anything definitively. I will try to reproduce vob 2 pass with ffmpeg 0.7.3 and mlt git head.

(0007251) ddennedy (developer) 2011-08-30 06:45	I reproduced it. It is crashing due to the following line I commented out in this diff. (It actually occurs when the consumer object is closed and all properties closed. It crashes on when free-ing the _logbuffer property. The logbuffer is allocated just above with av_malloc. So, it is not yet clear why. diff --git a/src/modules/avformat/consumer_avformat.c b/src/modules/avformat/consumer_avformat.c index 179815c..3cd64d9 100644 --- a/src/modules/avformat/consumer_avformat.c +++ b/src/modules/avformat/consumer_avformat.c @@ -851,7 +851,7 @@ static AVStream add_video_stream( mlt_consumer consumer, AVFormatContext oc, A fclose( f ); logbuffer[size] = '\0'; c->stats_in = logbuffer; - mlt_properties_set_data( properties, "_logbuffer", logbuffer, 0, ( mlt_destructor )av_free, NULL ); +// mlt_properties_set_data( properties, "_logbuffer", logbuffer, size, ( mlt_destructor )av_free, NULL ); } } }

(0007252) ddennedy (developer) 2011-08-30 07:18	Here is the fix I committed: diff --git a/src/modules/avformat/consumer_avformat.c b/src/modules/avformat/consumer_avformat.c index 179815c..5741d5c 100644 --- a/src/modules/avformat/consumer_avformat.c +++ b/src/modules/avformat/consumer_avformat.c @@ -851,7 +851,6 @@ static AVStream add_video_stream( mlt_consumer consumer, AVFormatContext oc, A fclose( f ); logbuffer[size] = '\0'; c->stats_in = logbuffer; - mlt_properties_set_data( properties, "_logbuffer", logbuffer, 0, ( mlt_destructor )av_free, NULL ); } } } @@ -951,6 +950,7 @@ void close_video(AVFormatContext oc, AVStream st) if ( st && st->codec ) { avformat_lock(); + av_freep( &st->codec->stats_in ); avcodec_close(st->codec); avformat_unlock(); }

(0007253) ddennedy (developer) 2011-08-30 07:19	Fixed in mlt git commit 31948b. Thank you for reporting it with good information.

Relationships