View Issue Details

IDProjectCategoryView StatusLast Update
0002628ardourbugspublic2011-09-28 16:22
Reportercolinf Assigned Tocth103  
PrioritynormalSeveritycrashReproducibilitysometimes
Status closedResolutionfixed 
Product VersionSVN/2.0-ongoing 
Target Version2.8.12Fixed in Version2.8.12 
Summary0002628: [PATCH] incorrect crossfades created, causes crash
DescriptionYesterday, for the first time ever, Ardour crashed while I was actually recording a take. It did it three times, at exactly the same point in the same session.

It was reproducible enough for me to get it to crash in the debugger as well, which I did another three times. The backtraces are attached, but they don't point conclusively to anything that I can see.

Anyway, I'll upload the session file too. To reproduce:
 - open record-crash.ardour
 - record-enable 'josie whistle' track (probably other tracks too, but I haven't tried yet)
 - start recording
 - when the transport reaches 00:02:56:27 or thereabouts, Ardour SEGVs.
TagsNo tags attached.

Activities

2009-04-09 12:53

 

2009-04-09 12:53

 

2009-04-09 12:54

 

2009-04-09 12:54

 

record-crash.ardour (368,667 bytes)

colinf

2009-04-09 14:14

updater   ~0005868

Actually, it doesn't have to be recording to crash with this session: I just tried exporting to .wav and it fell over at (as far as I can see) the same place.

Rebuilding with scons DEBUG=1 now to see if I can get any better backtraces...

colinf

2009-04-09 15:01

updater   ~0005869

I've narrowed down the cause of the crash in this session to something on the concertina track: probably the crossfade. Removing all of the other tracks & busses and exporting causes a crash in exactly the same place.

Uploading a stripped-down session file in a moment...

2009-04-09 15:01

 

colinf

2009-04-09 16:31

updater   ~0005870

This now smells like a memory corruption bug to me: the time of the crash seems to move around as I make small changes to the session, and Ardour also sometimes crashes on positioning the play-head, saving etc. after loading the session.

2009-04-09 19:38

 

valgrind.log (198,825 bytes)

colinf

2009-04-09 20:07

updater   ~0005873

Hah, caught it with arval.

Attached valgrind.log from exporting a file from a session which consistently crashes. It looks like the crossfade buffer is being overrun by 4 bytes.

Could this be related to the fix for 0001737?

colinf

2009-04-10 10:35

updater   ~0005879

I tried reverted the changes to crossfade.cc from svn r4720, which were the fix for bug 0001737, but it appears to make no difference, so my hunch about that fix was wrong.

colinf

2009-04-12 17:58

updater   ~0005892

It looks like spurious Crossfade objects sometimes get created for two regions where the end of the first lies outside the second, and/or the beginning of the second lies outside the first. When this happens, read_at() can be called on one of the regions with nonsensical parameters, leading to it overrunning its buf parameter, with predictably undesirable results.

I've somehow managed to create several sessions now with this error, though I don't have a simple recipe to reproduce it yet. It seems to only happen when there is a full crossfade in a track.

Anyway, I'm attaching a patch that checks that the regions cover the crossfade before rendering it: obviously this doesn't address the root bug, but it at least lets me open & use the sessions where this has happened without crashing Ardour.

The patch also adds some checks on the return value of sscanf in the Crossfade::set_state (const XMLNode& node) function, to avoid valgrind warning about "Conditional jump or move depends on uninitialised value(s)". I don't believe this is actually related to the bug, but it's probably a worthwhile improvement anyway.

2009-04-12 18:00

 

check-for-bogus-crossfades.patch (2,278 bytes)   
Index: libs/ardour/crossfade.cc
===================================================================
--- libs/ardour/crossfade.cc	(revision 4972)
+++ libs/ardour/crossfade.cc	(working copy)
@@ -307,6 +307,27 @@
 		
 	}
 
+
+	/*
+	 * Sometimes a Crossfade is created that doesn't correspont to a real 
+	 * overlap between regions. Obviously this shouldn't happen, but 
+	 * somehow it does, so check here that the crossfade lies within both
+	 * the _in and _out regions to avoid read_at() below going crazy.
+	 */
+
+	if (_out->coverage(start, start+to_write-1) == OverlapNone) {
+		cerr << "out region is outside crossfade: "
+		     << _out->name() << " => " << _in->name()
+		     << endl;
+		return 0;
+	}
+	if (_in->coverage(start, start+to_write-1) == OverlapNone) {
+		cerr << "in region is outside crossfade: "
+		     << _out->name() << " => " << _in->name()
+		     << endl;
+		return 0;
+	}
+
 	offset = start - _position;
 
 	/* Prevent data from piling up inthe crossfade buffers when reading a transparent region */
@@ -716,10 +737,13 @@
 	nframes_t val;
 
 	if ((prop = node.property ("position")) != 0) {
-		sscanf (prop->value().c_str(), "%" PRIu32, &val);
-		if (val != _position) {
-			_position = val;
-			what_changed = Change (what_changed | PositionChanged);
+		if (sscanf (prop->value().c_str(), "%" PRIu32, &val) == 1) {
+			if (val != _position) {
+				_position = val;
+				what_changed = Change (what_changed | PositionChanged);
+			}
+		} else {
+			warning << _("can't read value from crossfade position property") << endmsg;
 		}
 	} else {
 		warning << _("old-style crossfade information - no position information") << endmsg;
@@ -756,12 +780,14 @@
 
 	if ((prop = node.property ("length")) != 0) {
 
-		sscanf (prop->value().c_str(), "%" PRIu32, &val);
-		if (val != _length) {
-			_length = atol (prop->value().c_str());
-			what_changed = Change (what_changed | LengthChanged);
+		if (sscanf (prop->value().c_str(), "%" PRIu32, &val) == 1) {
+			if (val != _length) {
+				_length = atol (prop->value().c_str());
+				what_changed = Change (what_changed | LengthChanged);
+			}
+		} else {
+			warning << _("can't read value from crossfade length property") << endmsg;		
 		}
-
 	} else {
 		
 		/* XXX this branch is legacy code from before

colinf

2009-05-05 18:49

updater   ~0005975

I'm seeing 'bogus' Crossfade objects in a lot of my session files with check-for-bogus-crossfades.patch applied: I think that setting layering mode to 'Most Recently Added is Higher' may be the cause.

colinf

2010-09-08 12:11

updater   ~0009017

Finally found a simple recipe that seems to reproduce this:

* record a region
* select and copy a shorter section of the region with the range tool
* paste the copy over and completely within the original region
* split the original region somewhere underneath the new region

Bam! With my patch applied, I then get the "in region is outside crossfade: Audio 1-1.2 => Audio 1-1.3" message. I presume without this patch I'd see the original crash.

P.S.: Is there any way I can edit the bug description here? I'd like to give this one a better description now I've tracked it down.

paul

2010-09-24 12:36

administrator   ~0009156

how do you split the original region when its under the new region? when i tried this with all 3 layering models by putting the original region on top explicitly, your patch's message was not triggered ....

colinf

2010-09-25 10:16

updater   ~0009161

Last edited: 2010-09-25 11:22

I'm not at my computer at the moment, so I might have forgotten something, but AFAIR what I did was:

* layering mode "most recently added is higher"
* edit point is playhead
* link region/track selection is off
* short crossfades
* create two regions as above
* click on exposed part of lower region to select it
* position playhead within upper region
* press 'S' to split lower (selected) region

I think the crash (or error output) happens as the butler pre-reads audio from disc, so if the bogus crossfade is created more than 5 seconds from the playhead you won't see the error until you roll the transport past it. As far as I can tell, the crossfade is created at the end of the upper region: I only tried the recipe above with quite short (<5 sec) regions.

paul

2010-09-26 14:31

administrator   ~0009171

i've been able to generate the error messages, but i'm not sure you understood the semantics for ::read_at(). its not required that the crossfade be within the time range for which ::read_at() is called, so there is nothing wrong with, for example, this case:

in region is outside crossfade: Audio 1-2.4 => Audio 1-2.5 read at 68900 + 33386 ( 102285 ) in = 0 ... 50795

(i added some extra output). the "in" region covers the range 0..50795. The ::read_at() range is 68900 .. 102285 ... the crossfade had ::read_at() called upon it, and should have just handled this by doing nothing (since it doesn't cover the read_at range at all.

paul

2010-09-26 14:32

administrator   ~0009172

that said, the code in AudioPlaylist::read looks like this:

    for (Crossfades::iterator i = _crossfades.begin(); i != _crossfades.end(); ++i) {
        if ((*i)->coverage (start, end) != OverlapNone) {
            relevant_xfades[(*i)->upper_layer()].push_back (*i);
        }
    }


so one would not expect an xfade that doesn't exist within the read range to be actually read.

more investigation required ....

paul

2010-09-26 15:10

administrator   ~0009173

pretty sure from using valgrind that this is a red herring. there is memory corruption,however. looking at that now.

paul

2010-09-26 15:54

administrator   ~0009174

my ability to reproduce the valgrind errors has gone ...

colinf

2010-09-27 15:42

updater   ~0009177

Last edited: 2010-09-27 20:01

AudioRegion::read_at() (in audioregion.cc line 543) says:
    /* precondition: caller has verified that we cover the desired section */

and it was in the calls to _out->read_at() or _in->read_at() in Crossfade::read_at() that I saw the crash when that precondition wasn't satisfied, so I think that checking that the crossfade overlaps the in and out regions is probably the right thing.

[EDIT] Sorry, what I meant to say was that the memory corruption that eventually caused the crash for me happened in the calls to _in->read_at() or _out->read_at(). It was over a year ago...

colinf

2011-07-29 18:40

updater   ~0011234

Last edited: 2011-07-29 19:03

I still have the changes attached here as check-for-bogus-crossfades.patch in my working copy of A2, and I still see the messages they output from time to time. I know the patch isn't a fix, but it did prevent ardour crashing in these circumstances in my experience, so is it worth considering something like this for 2.8.12?

Obviously fixing whatever causes the bogus crossfades in the first place would be ideal, but it would probably take me a very long time, and it's also not enough to avoid problems with saved sessions containing such bogus crossfades.

2011-07-29 18:44

 

assert-read_at-is-in-range.patch (781 bytes)   
Index: libs/ardour/audioregion.cc
===================================================================
--- libs/ardour/audioregion.cc	(revision 9941)
+++ libs/ardour/audioregion.cc	(working copy)
@@ -541,6 +541,7 @@
 	}
 
 	/* precondition: caller has verified that we cover the desired section */
+	assert(coverage(position, position+cnt-1) != OverlapNone);
 
 	if (position < _position) {
 		internal_offset = 0;
@@ -1171,6 +1172,13 @@
 {
 	/* as above, but the shift was from the front */
 
+	// can't do this, events is protected...
+	//
+	// if (_envelope.events.empty()) {
+	// 	cerr << "AudioRegion._envelope.events.empty() is TRUE, setting envelope to default\n";
+	// 	set_default_envelope();
+	// }
+
 	_envelope.truncate_start (_length);
 
 	if (_flags & RightOfSplit) {

colinf

2011-07-29 19:02

updater   ~0011236

I made a patch to test my understanding of what's actually going wrong here, attached as assert-read_at-is-in-range.patch. It's not meant to be applied. Please ignore the (unrelated) second hunk in there, which is left-over from looking into something unrelated: sorry!

However, with the assert in the assert in libs/ardour/audioregion.cc in place and removing the changes from libs/ardour/crossfade.cc, following the recipe above triggers the assertion.

So, my questions are:

 - is that assert a valid expression of the precondition in the comment above?
 - if it is, what are the consequences of violating that precondition?
 - without the assert, I see messages like "SndFileSource: @ 406765 could not read 319251 within udio 1-1.wav (No Error.) (len = 726016)". There's no 'udio 1-1.wav' in my test session, but there is an 'Audio 1-1.wav'. Is that a sign that something has scribbled on memory it shouldn't, or is it to be expected?

colinf

2011-09-15 14:40

updater   ~0011525

Looks like the last two (valgrind warning fix) hunks of check-for-bogus-crossfades.patch got applied ages ago already: thanks!

However, I can still reliably provoke a crash with a2.8.12-beta and the record-crash.ardour session file attached above (it actually now trips an assert() rather than a SEGV, but it's still a repeatable crash: I can upload a backtrace if anyone wants). Applying the first hunk of check-for-bogus-crossfades.patch reliably prevents the crash for me.

Any chance of this being fixed in 2.8.12?

paul

2011-09-21 17:50

administrator   ~0011558

first chunk committed as rev 10111

cth103

2011-09-28 11:35

administrator   ~0011593

I believe this was all resolved in 2.8.12.

colinf

2011-09-28 16:22

updater   ~0011604

Crash fixed in 2.8.12. Thank you!

Issue History

Date Modified Username Field Change
2009-04-09 12:52 colinf New Issue
2009-04-09 12:53 colinf File Added: hare-crash-while-recording-1.log
2009-04-09 12:53 colinf File Added: hare-crash-while-recording-2.log
2009-04-09 12:54 colinf File Added: hare-crash-while-recording-3.log
2009-04-09 12:54 colinf File Added: record-crash.ardour
2009-04-09 14:14 colinf Note Added: 0005868
2009-04-09 15:01 colinf Note Added: 0005869
2009-04-09 15:01 colinf File Added: ardour-crossfade-crash.ardour
2009-04-09 16:31 colinf Note Added: 0005870
2009-04-09 19:38 colinf File Added: valgrind.log
2009-04-09 20:07 colinf Note Added: 0005873
2009-04-10 10:35 colinf Note Added: 0005879
2009-04-12 17:58 colinf Note Added: 0005892
2009-04-12 18:00 colinf File Added: check-for-bogus-crossfades.patch
2009-05-05 18:49 colinf Note Added: 0005975
2010-04-24 10:28 cth103 Category bugs => bugs2
2010-04-24 10:31 cth103 Category bugs2 => bugs
2010-09-08 12:11 colinf Note Added: 0009017
2010-09-20 21:14 cth103 cost => 0.00
2010-09-20 21:14 cth103 Target Version => 2.8.12
2010-09-20 21:14 cth103 Summary Crash while recording (SEGV) => [PATCH] Crash while recording (SEGV)
2010-09-24 12:29 paul Summary [PATCH] Crash while recording (SEGV) => [PATCH] incorrect crossfades created, causes crash
2010-09-24 12:36 paul Note Added: 0009156
2010-09-25 10:16 colinf Note Added: 0009161
2010-09-25 11:22 colinf Note Edited: 0009161
2010-09-26 14:31 paul Note Added: 0009171
2010-09-26 14:32 paul Note Added: 0009172
2010-09-26 15:10 paul Note Added: 0009173
2010-09-26 15:54 paul Note Added: 0009174
2010-09-27 15:42 colinf Note Added: 0009177
2010-09-27 20:01 colinf Note Edited: 0009177
2011-07-29 18:40 colinf Note Added: 0011234
2011-07-29 18:44 colinf File Added: assert-read_at-is-in-range.patch
2011-07-29 19:02 colinf Note Added: 0011236
2011-07-29 19:03 colinf Note Edited: 0011234
2011-09-15 14:40 colinf Note Added: 0011525
2011-09-21 17:50 paul Note Added: 0011558
2011-09-28 11:35 cth103 Note Added: 0011593
2011-09-28 11:35 cth103 Status new => resolved
2011-09-28 11:35 cth103 Fixed in Version => 2.8.12
2011-09-28 11:35 cth103 Resolution open => fixed
2011-09-28 11:35 cth103 Assigned To => cth103
2011-09-28 16:22 colinf Note Added: 0011604
2011-09-28 16:22 colinf Status resolved => closed