View Issue Details
ID | Project | Category | View Status | Date Submitted | Last Update |
---|---|---|---|---|---|
0004098 | ardour | bugs | public | 2011-06-06 19:35 | 2012-10-20 19:07 |
Reporter | realhangman | Assigned To | SaBer | ||
Priority | urgent | Severity | major | Reproducibility | always |
Status | closed | Resolution | fixed | ||
Product Version | 3.0-alpha5 | ||||
Target Version | 3.0 | ||||
Summary | 0004098: Export delay compensation does not work properly | ||||
Description | As In A3 rev. 9608, Ardour does not compensate the latency correctly. If you use e.g. 2048 frames and export something via "file -> export", the exported file will start 2048 frames too early, or whatever frames you used. Have a look at http://septimbears.de/A3-rev-9609delay-compensation.jpg: The upper track was exported with 64 frames, the lower with 2048 (A3 was closed in between, jackd killed and started with the new frames/period). The lower track starts too early. | ||||
Tags | compensation, delay, export, latency | ||||
|
Happens with Jack 1.9.7. Still the same in A3 rev. 10208. The problem also existed for a short time in A2-svn, in a pre version Paul sent to the mailing list, but was fixed for the final 2.8.12 release. Maybe the same fix can be used for A3? |
|
I hoped that it would be resolved with jack 1.9.8 like in 0004312, but it's still an issue. A3 rev 11378 |
|
This is still an issue in beta5 |
|
Same problem - Ardour beta5, with either jackd-0.122.0 or jackdmp-1.9.8. Actually the problem sits deeper. For period-sizes < 255 the offset is erratic (both jack1 and jack2) and not necessarily a power of two (e.g. 192 samples) I have not yet been able to establish a pattern. With jack-1.9.8 using the dummy driver in synchronous mode and the master output connected to system:playback*, export behaves correctly -- until the period-size is changed that is. system:playback_1 port latency = 1024 frames port playback latency = [ 1024 1024 ] frames port capture latency = [ 0 0 ] frames jackd 0.122's "dummy" driver reports zero latency for the port and the exported sound is always ahead of time. |
|
To track this down, I attach a small session. It has two short beeps at exactly 00:00:01:00 and 00:00:02:00 and is 3 sec long. The session comes with a tiny tool that prints the time of the first non-zero audio-sample. (firstNZsample.c) cd /tmp tar xjf /path/to/xtest.tar.bz2 cd xtest gcc -o firstNZsample firstNZsample.c -lsndfile ardour3 xtest.ardour & # export session to /tmp/Session.wav ./firstNZsample /tmp/Session.wav When running jackd-1.9.8 with -p 1024 the output of firstNZsample is First non-zero sample: 46977 (chn:1) Offset to 1sec in audio-samples 1023 It is off by one sample (-1023 instead of -1024) because ardour adds a short fade-in to the audio-sample at 00:00:01:00). |
2012-07-25 16:55
|
|
|
I found the problem, but I'm no closer to fixing it: AudioEngine::process_callback() is executed (at least once) after starting the transport and before jack enters freewheeling mode. Thus, when Session::process_export_fw() is called the first time to save audio-data, the transport has already moved on. The first N * jack_period_size audio-frames are lost and not included in the exported session. Debug trace created with attached patch (a3_svn13072-debug_export_transport.diff) and annotated afterwards DEBUG::Transport: Normal PROCESS @1172 ; +1024 frames # AudioEngine::process_callback() DEBUG::Transport: Normal PROCESS @1172 ; +1024 frames DEBUG::Transport: Normal PROCESS @1172 ; +1024 frames DEBUG::Transport: Export START @0 # Session::start_audio_export() DEBUG::Transport: @ 0 Set transport speed to 1, abort = 0 clear_state = 0, current = 0 as_default 0 DEBUG::Transport: start_transport DEBUG::Transport: send TSC4 with speed = 1 DEBUG::Transport: Butler transport work, todo = DEBUG::Transport: Butler transport work all done DEBUG::Transport: Normal PROCESS @0 ; +1024 frames # AudioEngine::process_callback() DEBUG::Transport: Freewheel PROCESS @1024 ; +1024 frames # AudioEngine::process_callback() DEBUG::Transport: Export transport @1024 # Session::process_export_fw() DEBUG::Transport: Freewheel PROCESS @2048 ; +1024 frames DEBUG::Transport: Export transport @2048 DEBUG::Transport: Freewheel PROCESS @3072 ; +1024 frames ... |
|
To further complicate matters: the port-latency is only updated in the cycle after jack enters freewheeling mode. Although in my simple session this is a NOOP. Continuing output from above: DEBUG::Transport: Export transport @3072 DEBUG::Latency: GET PORT asec440/audio_in 1 capture PRIVATE latency now [0 - 0] DEBUG::Latency: port asec440 has CAPTURE latency of 1024 - use DEBUG::Latency: asec440: max CAPTURE latency from 1 ports = 1024 DEBUG::Transport: Freewheel PROCESS @4096 ; +1024 frames DEBUG::Transport: Export transport @4096 DEBUG::Latency: JACK latency callback: CAPTURE DEBUG::Latency: asec440/audio_in 1: not connected to anything DEBUG::Latency: asec440/audio_in 1: final connected latency range [ 0 .. 0 ] DEBUG::Latency: SET PORT asec440/audio_in 1 capture PRIVATE latency now [0 - 0] DEBUG::Latency: SET PORT asec440/audio_in 1 CAPTURE PUBLIC latency now [0 - 0] DEBUG::Latency: SET PORT asec440/audio_out 1 capture PRIVATE latency now [0 - 0] DEBUG::Latency: SET PORT asec440/audio_out 1 CAPTURE PUBLIC latency now [0 - 0] DEBUG::Latency: SET PORT asec440/audio_out 2 capture PRIVATE latency now [0 - 0] DEBUG::Latency: SET PORT asec440/audio_out 2 CAPTURE PUBLIC latency now [0 - 0] DEBUG::Latency: master/audio_in 1: 1 connections to check for latency range DEBUG::Latency: GET PORT asec440/audio_out 1 capture PRIVATE latency now [0 - 0] DEBUG::Latency: master/audio_in 1 <-LOCAL-> ardour:asec440/audio_out 1 : latter has latency range 0 .. 0 DEBUG::Latency: master/audio_in 1: final connected latency range [ 0 .. 0 ] DEBUG::Latency: master/audio_in 2: 1 connections to check for latency range DEBUG::Latency: GET PORT asec440/audio_out 2 capture PRIVATE latency now [0 - 0] DEBUG::Latency: master/audio_in 2 <-LOCAL-> ardour:asec440/audio_out 2 : latter has latency range 0 .. 0 DEBUG::Latency: master/audio_in 2: final connected latency range [ 0 .. 0 ] DEBUG::Latency: SET PORT master/audio_in 1 capture PRIVATE latency now [0 - 0] DEBUG::Latency: SET PORT master/audio_in 1 CAPTURE PUBLIC latency now [0 - 0] DEBUG::Latency: SET PORT master/audio_in 2 capture PRIVATE latency now [0 - 0] DEBUG::Latency: SET PORT master/audio_in 2 CAPTURE PUBLIC latency now [0 - 0] DEBUG::Latency: SET PORT master/audio_out 1 capture PRIVATE latency now [0 - 0] DEBUG::Latency: SET PORT master/audio_out 1 CAPTURE PUBLIC latency now [0 - 0] DEBUG::Latency: SET PORT master/audio_out 2 capture PRIVATE latency now [0 - 0] DEBUG::Latency: SET PORT master/audio_out 2 CAPTURE PUBLIC latency now [0 - 0] DEBUG::Latency: Set public port latencies to 0 DEBUG::Latency: SET PORT asec440/audio_in 1 CAPTURE PUBLIC latency now [0 - 0] DEBUG::Latency: SET PORT asec440/audio_out 1 CAPTURE PUBLIC latency now [0 - 0] DEBUG::Latency: SET PORT asec440/audio_out 2 CAPTURE PUBLIC latency now [0 - 0] DEBUG::Latency: SET PORT master/audio_in 1 CAPTURE PUBLIC latency now [0 - 0] DEBUG::Latency: SET PORT master/audio_in 2 CAPTURE PUBLIC latency now [0 - 0] DEBUG::Latency: SET PORT master/audio_out 1 CAPTURE PUBLIC latency now [0 - 0] DEBUG::Latency: SET PORT master/audio_out 2 CAPTURE PUBLIC latency now [0 - 0] DEBUG::Latency: GET PORT asec440/audio_in 1 capture PRIVATE latency now [0 - 0] DEBUG::Latency: asec440: max CAPTURE latency from 1 ports = 0 DEBUG::Latency: GET PORT master/audio_in 1 capture PRIVATE latency now [0 - 0] DEBUG::Latency: GET PORT master/audio_in 2 capture PRIVATE latency now [0 - 0] DEBUG::Latency: master: max CAPTURE latency from 2 ports = 0 DEBUG::Latency: Worst input latency: 0 DEBUG::Latency: GET PORT asec440/audio_in 1 capture PRIVATE latency now [0 - 0] DEBUG::Latency: asec440: max CAPTURE latency from 1 ports = 0 DEBUG::Latency: JACK latency callback: DONE DEBUG::Transport: Freewheel PROCESS @5120 ; +1024 frames DEBUG::Transport: Export transport @5120 DEBUG::Latency: JACK latency callback: PLAYBACK DEBUG::Latency: master/audio_out 1: not connected to anything DEBUG::Latency: master/audio_out 1: final connected latency range [ 0 .. 0 ] DEBUG::Latency: master/audio_out 2: not connected to anything DEBUG::Latency: master/audio_out 2: final connected latency range [ 0 .. 0 ] DEBUG::Latency: SET PORT master/audio_out 1 playback PRIVATE latency now [0 - 0] DEBUG::Latency: SET PORT master/audio_out 1 PLAYBACK PUBLIC latency now [0 - 0] DEBUG::Latency: SET PORT master/audio_out 2 playback PRIVATE latency now [0 - 0] DEBUG::Latency: SET PORT master/audio_out 2 PLAYBACK PUBLIC latency now [0 - 0] DEBUG::Latency: SET PORT master/audio_in 1 playback PRIVATE latency now [0 - 0] DEBUG::Transport: Freewheel PROCESS @6144 ; +1024 frames DEBUG::Transport: Export transport @6144 DEBUG::Latency: SET PORT master/audio_in 1 PLAYBACK PUBLIC latency now [0 - 0] DEBUG::Latency: SET PORT master/audio_in 2 playback PRIVATE latency now [0 - 0] DEBUG::Latency: SET PORT master/audio_in 2 PLAYBACK PUBLIC latency now [0 - 0] DEBUG::Latency: asec440/audio_out 1: 1 connections to check for latency range DEBUG::Latency: GET PORT master/audio_in 1 playback PRIVATE latency now [0 - 0] DEBUG::Latency: asec440/audio_out 1 <-LOCAL-> ardour:master/audio_in 1 : latter has latency range 0 .. 0 DEBUG::Latency: asec440/audio_out 1: final connected latency range [ 0 .. 0 ] DEBUG::Latency: asec440/audio_out 2: 1 connections to check for latency range DEBUG::LatencyDEBUG::Transport: Freewheel PROCESS @7168 ; +1024 frames DEBUG::Transport: Export transport @7168 : GET PORT master/audio_in 2 playback PRIVATE latency now [0 - 0] DEBUG::Latency: asec440/audio_out 2 <-LOCAL-> ardour:master/audio_in 2 : latter has latency range 0 .. 0 DEBUG::Latency: asec440/audio_out 2: final connected latency range [ 0 .. 0 ] DEBUG::Latency: SET PORT asec440/audio_out 1 playback PRIVATE latency now [0 - 0] DEBUG::Latency: SET PORT asec440/audio_out 1 PLAYBACK PUBLIC latency now [0 - 0] DEBUG::Latency: SET PORT asec440/audio_out 2 playback PRIVATE latency now [0 - 0] DEBUG::Latency: SET PORT asec440/audio_out 2 PLAYBACK PUBLIC latency now [0 - 0] DEBUG::Latency: SET PORT asec440/audio_in 1 playback PRIVATE latency now [0 - 0] DEBUG::Latency: SET PORT asec440/audio_in 1 PLAYBACK PUBLIC latency now [0 - 0] DEBUG::Latency: Set public port latencies to 0 DEBUG::Latency: SET PORT master/audio_in 1 PLAYBACK PUBLIC latency now [0 - 0] DEBUG::Latency: SET PORT master/audio_in 2 PLAYBACK PUBLIC latency now [0 - 0] DEBUG::Latency: SET PORT master/audio_out 1 PLAYBACK PUBLIC latency now [0 - 0] DEBUG::Latency: SET PORT master/audio_out 2 PLAYBACK PUBLIC latency now [0 - 0] DEBUG::Latency: SET PORT asec440/audio_in 1 PLAYBACK PUBLIC latency now [0 - 0] DEBUG::Latency: SET PORT asec440/audio_out 1 PLAYBACK PUBLIC latency now [0 - 0] DEBUG::Latency: SET PORT asec440/audio_out 2 PLAYBACK PUBLIC latency now [0 - 0] DEBUG::Latency: GET PORT asec440/audio_out 1 playback PRIVATE latency now [0 - 0] DEBUG::Latency: GET PORT asec440/audio_out 2 playback PRIVATE latency now [0 - 0] DEBUG::Latency: asec440: max PLAYBACK latency from 2 ports = 0 DEBUG::Latency: GET PORT master/audio_out 1 playback PRIVATE latency now [0 - 0] DEBUG::Latency: GET PORT master/audio_out 2 playback PRIVATE latency now [0 - 0] DEBUG::Latency: master: max PLAYBACK latency from 2 ports = 0 DEBUG::Latency: Worst output latency: 0 DEBUG::Latency: asec440: internal signal latency = 0 DEBUG::Latency: master: internal signal latency = 0 DEBUG::Latency: asec440: compensate for maximum latency of 0,given own latency of 0, using initial delay of 0 DEBUG::Latency: master: compensate for maximum latency of 0,given own latency of 0, using initial delay of 0 DEBUG::Latency: JACK latency callback: DONE DEBUG::Transport: Freewheel PROCESS @8192 ; +1024 frames DEBUG::Transport: Export transport @8192 DEBUG::Transport: Freewheel PROCESS @9216 ; +1024 frames DEBUG::Transport: Export transport @9216 DEBUG::Transport: Freewheel PROCESS @10240 ; +1024 frames ... |
2012-07-25 20:15
|
a3_svn13072-debug_export_transport.diff (1,982 bytes)
diff --git a/libs/ardour/audioengine.cc b/libs/ardour/audioengine.cc index 004ba33..c4801b7 100644 --- a/libs/ardour/audioengine.cc +++ b/libs/ardour/audioengine.cc @@ -48,6 +48,7 @@ #include "ardour/port.h" #include "ardour/process_thread.h" #include "ardour/session.h" +#include "ardour/debug.h" #include "i18n.h" @@ -544,12 +545,14 @@ AudioEngine::process_callback (pframes_t nframes) if (_freewheeling && !Freewheel.empty()) { /* emit the Freewheel signal and stop freewheeling in the event of trouble */ + DEBUG_TRACE (DEBUG::Transport, string_compose ("Freewheel PROCESS @%1 ; +%2 frames\n", _session->_transport_frame, nframes)); boost::optional<int> r = Freewheel (nframes); if (r.get_value_or (0)) { jack_set_freewheel (_priv_jack, false); } } else { + DEBUG_TRACE (DEBUG::Transport, string_compose ("Normal PROCESS @%1 ; +%2 frames\n", _session->_transport_frame, nframes)); MIDI::Manager::instance()->cycle_start(nframes); if (_session) { diff --git a/libs/ardour/session_export.cc b/libs/ardour/session_export.cc index acb23ae..362a315 100644 --- a/libs/ardour/session_export.cc +++ b/libs/ardour/session_export.cc @@ -31,6 +31,7 @@ #include "ardour/process_thread.h" #include "ardour/session.h" #include "ardour/track.h" +#include "ardour/debug.h" #include "i18n.h" @@ -145,6 +146,7 @@ Session::start_audio_export (framepos_t position) since then has re-awakened it. */ + DEBUG_TRACE (DEBUG::Transport, string_compose ("Export START @%1\n", _transport_frame)); set_transport_speed (1.0, false); butler_transport_work (); g_atomic_int_set (&_butler->should_do_transport_work, 0); @@ -194,6 +196,7 @@ int Session::process_export_fw (pframes_t nframes) { _engine.main_thread()->get_buffers (); + DEBUG_TRACE (DEBUG::Transport, string_compose ("Export transport @%1 \n", _transport_frame)); process_export (nframes); _engine.main_thread()->drop_buffers (); return 0; |
|
I managed to come up with a practical fix. Idea: start the transport in the process_export_fw() callback and ignore all audio before that. It's not nice, but it works and does not need any fancy thread synchronization mechanism. Cheers! robin PS. maybe the new flag '_export_started' can be consolidated with '_export_rolling' somehow. I did not walk all possible call-graphs but currently it can't because there's a possibility that an abort signal arrives simultaneously with the first process_export_fw() callback -- at least Session::process_export() would need to be updated somehow. |
2012-07-25 21:40
|
a3_svn13072-export_transport_fix.diff (1,628 bytes)
diff --git a/libs/ardour/ardour/session.h b/libs/ardour/ardour/session.h index 780c68f..0464fbe 100644 --- a/libs/ardour/ardour/session.h +++ b/libs/ardour/ardour/session.h @@ -964,6 +964,7 @@ class Session : public PBD::StatefulDestructible, public PBD::ScopedConnectionLi framepos_t post_export_position; bool _exporting; + bool _export_started; bool _export_rolling; boost::shared_ptr<ExportHandler> export_handler; diff --git a/libs/ardour/session_export.cc b/libs/ardour/session_export.cc index acb23ae..244daeb 100644 --- a/libs/ardour/session_export.cc +++ b/libs/ardour/session_export.cc @@ -106,6 +106,7 @@ Session::start_audio_export (framepos_t position) { if (!_exporting) { pre_export (); + _export_started = false; } /* We're about to call Track::seek, so the butler must have finished everything @@ -145,11 +146,6 @@ Session::start_audio_export (framepos_t position) since then has re-awakened it. */ - set_transport_speed (1.0, false); - butler_transport_work (); - g_atomic_int_set (&_butler->should_do_transport_work, 0); - post_transport (); - /* we are ready to go ... */ if (!_engine.connected()) { @@ -193,6 +189,16 @@ Session::process_export (pframes_t nframes) int Session::process_export_fw (pframes_t nframes) { + + if (!_export_started) { + _export_started=true; + set_transport_speed (1.0, false); + butler_transport_work (); + g_atomic_int_set (&_butler->should_do_transport_work, 0); + post_transport (); + return 0; + } + _engine.main_thread()->get_buffers (); process_export (nframes); _engine.main_thread()->drop_buffers (); |
|
Still an issue in SVN 13265, I think this is very release-critical. |
|
should be fixed in rev13305. Works here. realhangman, please confirm and close. |
|
Wow, Yes!!! I can confirm this, great work! Thanks! |
|
fix confirmed. closing issue. |
Date Modified | Username | Field | Change |
---|---|---|---|
2011-06-06 19:35 | realhangman | New Issue | |
2011-06-07 21:41 | cth103 | cost | => 0.00 |
2011-06-07 21:41 | cth103 | Target Version | => 3.0-beta1 |
2011-08-12 22:27 | realhangman | Tag Attached: delay | |
2011-08-12 22:27 | realhangman | Tag Attached: latency | |
2011-08-12 22:27 | realhangman | Tag Attached: compensation | |
2011-08-12 22:27 | realhangman | Tag Attached: export | |
2011-10-14 11:23 | realhangman | Note Added: 0011688 | |
2011-11-14 20:31 | cth103 | Target Version | 3.0-beta1 => 3.0-beta2 |
2012-01-10 20:46 | cth103 | Target Version | 3.0-beta2 => 3.0-beta3 |
2012-02-02 16:50 | realhangman | Note Added: 0012749 | |
2012-02-14 17:20 | paul | Target Version | 3.0-beta3 => 3.0 beta4 |
2012-05-23 15:09 | cth103 | Target Version | 3.0 beta4 => 3.0 |
2012-07-23 23:47 | realhangman | Note Added: 0013912 | |
2012-07-25 16:38 | x42 | Note Added: 0013927 | |
2012-07-25 16:40 | x42 | Note Edited: 0013927 | |
2012-07-25 16:54 | x42 | Note Added: 0013928 | |
2012-07-25 16:55 | x42 | File Added: xtest.tar.bz2 | |
2012-07-25 16:59 | x42 | Note Edited: 0013928 | |
2012-07-25 20:13 | x42 | Note Added: 0013929 | |
2012-07-25 20:14 | x42 | Note Added: 0013930 | |
2012-07-25 20:15 | x42 | File Added: a3_svn13072-debug_export_transport.diff | |
2012-07-25 20:44 | x42 | Note Edited: 0013929 | |
2012-07-25 21:40 | x42 | Note Added: 0013931 | |
2012-07-25 21:40 | x42 | File Added: a3_svn13072-export_transport_fix.diff | |
2012-10-16 14:03 | realhangman | Note Added: 0014070 | |
2012-10-17 22:13 | oofus | Assigned To | => SaBer |
2012-10-17 22:13 | oofus | Status | new => assigned |
2012-10-17 22:16 | oofus | Priority | normal => urgent |
2012-10-19 20:42 | x42 | Note Added: 0014109 | |
2012-10-19 20:42 | x42 | Status | assigned => resolved |
2012-10-19 20:42 | x42 | Resolution | open => fixed |
2012-10-20 18:26 | realhangman | Note Added: 0014115 | |
2012-10-20 19:07 | x42 | Note Added: 0014116 | |
2012-10-20 19:07 | x42 | Status | resolved => closed |