GNOME Bugzilla – Bug 590114
rendering never finishes
Last modified: 2009-08-28 12:14:06 UTC
I wanted to created a simple slide show with some music. I used Jpeg photos and two mp3 tracks. A used piTiVi to cut the last mp3 was cut because it was to long. I clicked render and changed to 720p (because that's my laptops resolution). It showed the progress bar and said it would take 10 minutes or so. For the first 6 minutes or so the progress bar progressed, the time left decreased as expected and the preview switched between the photos as it rendered them. Then the progress bar stoped progressing, the time left started to increase and the preview stopped changing. I left it like this four 40 minutes before I gave up. I then tried several more times, and each time the same thing happened although not in the same place. Sometimes it stoped near or right at the beginning other times it nearly finished but I was never actually able to finish the rendering.
i know everyone thinks their bug is critical. However I believe this one actually is as not being able to render makes the who application useless.
Daniel, could you run pitivi as follows and reproduce your issue ? GST_DEBUG=2,gnl*:5,*ERR*:5 PITIVI_DEBUG=5 pitivi > log 2>&1 And then attach the resulting 'log' file (compressed).
Created attachment 139472 [details] log file here is the log file as was requested this time it didn't even get as far as saying how long it would take.
Created attachment 140006 [details] this one got to about 95% log for attempt in v0.13.1.3 which still has the bug (obviously) got 95% percent though pictures are 3648 x 2736 jpegs there are 59 of them + two mp3's the second is cut using the razor tool, length is 00:05:09.000
I believe this is fixed in pitivi now. Daniel, could you try to grab pitivi from git as described in http://pitivi.org/wiki/Git_Instructions and try again?
Ran from git when I tried to start the rendering it crashed immediately with the following message in the terminal. AttributeError: 'module' object has no attribute 'Element' Fatal Python error: PyEval_SaveThread: NULL tstate Aborted I not sure if I'm doing something wrong but that seems worse then before.
I experienced that python segfault yesterday when trying to test bug fixes, but I think they pushed a commit that fixes it overnight. Try again?
Yes, that segfault is now fixed. Daniel: Can you try pitivi git again ? Hopefully this is the last one :)
Tested with latest GIT Still not fixed. It got about 75% thru before it stopped progressing and the time remaining started increasing... until I stopped it. so still not fixed.
Something similar happened here, too. I tried to make a simple video (5 minutes) from a few avi (divx I think) files, a few jpeg pictures and an mp3 audio file. I've set audio fading in-out between the scenes, to make everything a little smoother. Pitivi 0.13.2 always hanged sometime through the rendering, with the time remaining increasing. Pitivi git did the same. I tried the debugging command line I read here, and nothing really happened, I'll post the results. The weird part is that I tried to downgrade to pitivi-0.13.1, which doesn't allow volume adjustments; an error showed up, but the rendering completed!
Created attachment 141165 [details] pitivi git, rendering an ogg-theora video
Created attachment 141166 [details] pitivi 0.13.1, rendering correctly
The reason why the rendering doesn't advance in the log from comment #11 is that the gnlsource (gnlsource22 in this case) doesn't properly ghost the internal element source pad.... and therefore the composition waits forever for a source which never ends. It refuses to ghost the source pad in element_pad_added_cb because pendingblock is TRUE... but the controlled pad is non-existent. This is because the check in gnlsource.c:pad_removed_cb is racy. It checks for the presence of the ghostpad and whether the target of the ghostpad is the pad being removed... but the ghosting of the pad happens only when there's data flowing through that pad.
I just pushed a fix to gnonlin git : -------------------------------- commit 79b0699a3a483c9de92782a78350d2257b2c8611 Author: Edward Hervey <bilboed@bilboed.com> Date: Mon Aug 24 12:08:45 2009 +0200 gnlsource: Make the pad removal code non-racy. Previously we were checking whether (1) there was a ghostpad and (2) whether the target was the pad being removed. The problem was that the following racyness can happen: 1. A pad gets added and controlled 2. The pad gets removed before having outputted any data (and therefore the ghostpad isn't created). 3. There's no ghostpad... and therefore we don't properly reset ourselves. ----------------------------------- For those comfortable enough with using git... can you try reproducing this issue ?
Created attachment 141543 [details] pitivi git, gnonlin git I tried pitivi git and gnonlin git, but the rendering (ogg-theora) stopped at about 30%, right before the second video item. The same happened yesterday with gnonlin 0.10.12, is there anything else I should download via git instead of using gentoo versions?
Tommaso, could you reproduce it with the following debugging categories : GST_DEBUG=2,gnl*:5,*ERR*:5,python:5,mad:5,*parse:5,theoraenc:5,vorbisenc:5 PITIVI_DEBUG=5 pitivi > log 2>&1
Created attachment 141614 [details] pitivi git, gnonlin git, second take, part 1 Wow, that's 60 megabytes of log, good luck :-) I had to split it in three parts because bzip compresses it up to 2.6 megabytes, and the limit is only 1. I hope it still can be read. I did a 'git pull' on gnonlin and pitivi before doing this test, the result is pretty much the same in terms of percentage of successful rendering.
Created attachment 141615 [details] pitivi git, gnonlin git, second take, part 2
Created attachment 141616 [details] pitivi git, gnonlin git, second take, part 3
60mbytes is nothing when it comes to gstreamer debug logs :) Anyway, this is great, hopefully it has the info I need to pinpoint exactly what the issue is. Will investigate this later on.
After some investigation I'm seeing the following: The source pad for the 6th audio source isn't outputting anything ! That's the source which starts at 2:25.75 and ends at 2:59.50. It seems to be an AVI file with raw audio in it. Tommaso, could you try the following things: * Open your project, put the playhead just before the 6th audio source and play the timeline. Does it play the audio part ? Does it hang ? * Open your project again, put the playhead IN the 6th audio source and play the timeline. Does it play the audio part ? Does it hang ? * Finally, Could you provide me a debug log with the following debugging categories: GST_DEBUG=2,gnl*:5,*ERR*:5,python:5,theoraenc:5,vorbisenc:5,avi*:4 PITIVI_DEBUG=5 pitivi > log 2>&1 And only attach the last 25% of the logs (which is where the hang is happening). Oh, and also don't properly shutdown pitivi, but just CTRL-C it from the terminal when you see the hang.
Daniel, if you've still got that failing rendering project, could you try creating the following debug log of the hang ? GST_DEBUG=2,gnl*:5,*ERR*:5,python:5 PITIVI_DEBUG=5 pitivi > log 2>&1
Created attachment 141626 [details] pitivi git, gnonlin git, third take, tail Just for the record: - the fourth audio source is a video file taken with my camera - the fifth audio source is an mp3 which plays when a jpg image is shown - the sixth audio source is a video file taken with my camera. I tried what you asked: - playing from the fifth source didn't make any sound on the fifth or sixth source - playing from the fourth source made that play the correct audio but the fifth and sixth source didn't. I then double-clicked on the source files on the left, and they played correctly; I went back to the timeline, and it played smoothly across the transitions 4->5 and 5->6, as it should do. In any case it never hanged or stopped.
ok... we're getting closer. This time... I'm gonna need the full debug logs :) GST_DEBUG=5 PITIVI_DEBUG=5 pitivi > log 2>&1 It's going to slow down pitivi quite a bit. So be sure the timeline is *really* stalled before CTRL-C'ing it. Same drill, I'll only need the tail. Basically events/buffers are being discarded and I need to figure out why. Hopefully it's a python/pitivi only issue...
Tommaso, you're also welcome to join the #pitivi channel on irc.freenode.net where we could fix these issues with less back-and-forth :)
Created attachment 141635 [details] pitivi git, gnonlin git, fifth take I tried the rendering with the debug level you asked, Edward, but the log came out to be 7.2 GB, so there was no way to send it. Moreover, the rendering completed for the first time ever :-D On IRC I've been told to generate a new one with GST_DEBUG=2,gnl*:5,*ERR*:5,python:5,GST_CAT_SCHEDULING:5 PITIVI_DEBUG=5 pitivi > log 2>&1 and here it is.
Created attachment 141639 [details] at 34 seconds left error in message box
sorry error was GStreamer encountered a general stream error. gstbasesrc.c(2378): gst_base_src_loop (): /GstPipeline:pipeline1/GstBin:bin3/GnlComposition:gnlcomposition2/GnlSource:gnlsource63/GstBin:picture-P3020318.JPG/GstBin:bin65/pitivi+elements+singledecodebin+SingleDecodeBin:pitivi+elements+singledecodebin+singledecodebin60/GstFileSrc:urisrc: streaming task paused, reason error (-5) this was when using gnonlin from git and pitivi from git
Created attachment 141643 [details] project file
Daniel, The reason why it's failing for you is because... it can't allocate any more data (?!?!?!) : gstbuffer.c:337:gst_buffer_try_new_and_alloc: failed to allocate 14971392 bytes That's not exactly the same issue as what you were seeing previously as far as I can tell.
Regarding Tommaso's issue... after much deeper investigation, the "internal-audioconvert" sink pad connected after singledecodebin is flushing for some reason. I haven't got enough log to figure out the exact reason but there can be only two: 1. audioconvert wasn't set to READY/PAUSED/PLAYING ... resulting in the pads not being activated (and therefore flushing) 2. a flush-start event was sent through audioconvert.
Edward, Does that indicate that my laptop doesn't have enough ram (my laptop has 2 gig) or is it a bug. I can run with my system monitor going and observe the ram usage tonight if that helps?
Daniel if you have 2G, then it's likely a bug somewhere in pitivi or in the libraries we use. But then it's probably a completely separate bug.
Created attachment 141738 [details] original problem This one stopped with about 4 minutes left. And the time started to count up. It didn't have the message box error. I did monitor the memory usage. before opening the project I was using 700 MB after opening project was using 1 GB, then as it rendered the memory usage gradually went up when it stopped rendering it was using 1.8 GB. So I would have used up all 2 GB before I finished rendering if it had not stopped. This was pitivi from git and gnonlin from git Log file was two big so I divided it into two, next file coming soon.
Created attachment 141741 [details] part 2
Created attachment 141751 [details] [review] tentative fix So, i think state changes are a bit funny, since sinks are not linked so the usual topo sort doesn't help much. This patch makes sure that audio elements have the correct state.
One thing at a time: 1 - with the latest "tentative fix" *it works*. I have been able to render my video twice without any debug lines; this obviously doesn't mean I'm sure the problem is solved, but it's been the first time so far. 2 - while the rendering works with ogg/theora/vorbis, it doesn't work with mp4, this is the error I get: gstavidemux.c(4163): gst_avi_demux_loop (): /GstPipeline:pipeline1/GstBin:bin3/GnlComposition:gnlcomposition2/GnlSource:gnlsource5/GstBin:bin7/pitivi+elements+singledecodebin+SingleDecodeBin:pitivi+elements+singledecodebin+singledecodebin2/GstAviDemux:avidemux28: streaming stopped, reason error The rendering is working even with a flv output. I'll do some more testing in the next days.
Sorry, my mistake, flv encoding doesn't even produce an output file! This is the backtrace I get on the console: Traceback (most recent call last):
+ Trace 217171
self.addRecordAction()
self.renderaction.activate()
self._ensurePipelineObjects()
self.pipeline.getBinForFactoryStream(producer, automake=True)
bin = stream_entry.bin = factory.makeBin(stream)
bin = self._makeBin(input_stream)
rb = self.renderfactory.makeBin()
b2 = EncoderFactory(setting).makeBin()
mod.link(enc)
Regarding the memory problem, I need to correct my statement earlier about having 2 GB of memory I actually have 3 GB (System Monitor shows 2.9) (approx maximum addressable in a 32 bit system). It fails at about 2.1 GB total usage so I still should have 800 MB of free ram not to mention GBs of page file. If I am running out of memory its a limitation of the allocation mechanism and not because I'm actually out of memory. pitivi using more then a GB of memory seems excessive, specially for something that is essentially just a slide show with music. I assume that once a photo has been rendered to the file it can be flushed from memory. So only one photo needs to be in memory at a time plus the MP3 so 30 MB should be more then enough to store that. Then you might have some intermediate in memory data formats for rendering.. (I don't know how it works) so double it to 60 MB. Now I don't really know how your rendering works so I'm probably way off the mark here but what I'm trying to say is over a GB used for rendering is crazy. My guess is you have some major memory leaks. Or you are loading into and keeping in memory stuff you don't need yet or have already finished with. The suggestion that I should have a smaller project seems a little strange as a 5 minute slide show with 59 pictures does not seem like an unreasonably large project to me.
@tommaso: thank you for confirming that the fix works. I'll take a loot at mp4 now. @daniel: thank you too for the help with this bug. Regarding the high memory consumption, as I said it's most likely another bug. As such, it should be debugged and fixed. The suggestion to try with a smaller project, was in order to help me debug the _first_ bug, the hang Tommaso was experiencing as well.
commit bb96b020e6a4aeaca8e1253e349f9614e961338c Author: Alessandro Decina <alessandro.d@gmail.com> Date: Wed Aug 26 14:44:35 2009 +0200 SourceFactory: make sure audio elements reach the right state before dataflo w starts. Finally fixes #590114.
Shouldn't we make sure that almost every output codec renders correctly before closing this bug as fixed?
No, this was a specific bug in pitivi which is independent from the output format. Other output formats may not work, but for different reasons and we should open separate bugs for those.
Do you want the high memory problem raised as a separate bug so it can be tracked debugged and fixed?
yes please
Raised a bug for the high memory usage issue Bug 593377