summaryrefslogtreecommitdiff
path: root/libs/ardour
diff options
context:
space:
mode:
Diffstat (limited to 'libs/ardour')
-rw-r--r--libs/ardour/audio_diskstream.cc8
-rw-r--r--libs/ardour/butler.cc38
-rw-r--r--libs/ardour/session_process.cc6
3 files changed, 34 insertions, 18 deletions
diff --git a/libs/ardour/audio_diskstream.cc b/libs/ardour/audio_diskstream.cc
index fefc1c235c..538faebc4f 100644
--- a/libs/ardour/audio_diskstream.cc
+++ b/libs/ardour/audio_diskstream.cc
@@ -513,6 +513,8 @@ AudioDiskstream::process (BufferSet& bufs, framepos_t transport_frame, pframes_t
framecnt_t total = chaninfo->capture_vector.len[0] + chaninfo->capture_vector.len[1];
if (rec_nframes > total) {
+ DEBUG_TRACE (DEBUG::Butler, string_compose ("%1 overrun in %2, rec_nframes = %3 total space = %4\n",
+ pthread_self(), name(), rec_nframes, total));
DiskOverrun ();
return -1;
}
@@ -619,6 +621,8 @@ AudioDiskstream::process (BufferSet& bufs, framepos_t transport_frame, pframes_t
if (necessary_samples > total) {
cerr << _name << " Need " << necessary_samples << " total = " << total << endl;
cerr << "underrun for " << _name << endl;
+ DEBUG_TRACE (DEBUG::Butler, string_compose ("%1 underrun in %2, rec_nframes = %3 total space = %4\n",
+ pthread_self(), name(), rec_nframes, total));
DiskUnderrun ();
return -1;
@@ -1394,7 +1398,7 @@ AudioDiskstream::do_flush (RunContext /*context*/, bool force_flush)
error << string_compose(_("AudioDiskstream %1: cannot write to disk"), id()) << endmsg;
return -1;
}
-
+
(*chan)->capture_buf->increment_read_ptr (to_write);
(*chan)->curr_capture_cnt += to_write;
@@ -1407,6 +1411,8 @@ AudioDiskstream::do_flush (RunContext /*context*/, bool force_flush)
to_write = min ((framecnt_t)(disk_io_chunk_frames - to_write), (framecnt_t) vector.len[1]);
+ DEBUG_TRACE (DEBUG::Butler, string_compose ("%1 additional write of %2\n", name(), to_write));
+
if ((*chan)->write_source->write (vector.buf[1], to_write) != to_write) {
error << string_compose(_("AudioDiskstream %1: cannot write to disk"), id()) << endmsg;
return -1;
diff --git a/libs/ardour/butler.cc b/libs/ardour/butler.cc
index 5d4c47d557..424312a8a4 100644
--- a/libs/ardour/butler.cc
+++ b/libs/ardour/butler.cc
@@ -137,6 +137,7 @@ Butler::terminate_thread ()
{
if (have_thread) {
void* status;
+ DEBUG_TRACE (DEBUG::Butler, string_compose ("%1: ask butler to quit @ %2\n", pthread_self(), g_get_monotonic_time()));
queue_request (Request::Quit);
pthread_join (thread, &status);
}
@@ -172,7 +173,7 @@ Butler::wait_for_requests ()
break;
}
- DEBUG_TRACE (DEBUG::Butler, string_compose ("%1: butler awake at @ %2", pthread_self(), g_get_monotonic_time()));
+ DEBUG_TRACE (DEBUG::Butler, string_compose ("%1: butler awake at @ %2\n", pthread_self(), g_get_monotonic_time()));
if (pfd[0].revents & ~POLLIN) {
error << string_compose (_("Error on butler thread request pipe: fd=%1 err=%2"), pfd[0].fd, pfd[0].revents) << endmsg;
@@ -287,10 +288,6 @@ Butler::thread_work ()
RouteList rl_with_auditioner = *rl;
rl_with_auditioner.push_back (_session.the_auditioner());
-// for (i = dsl->begin(); i != dsl->end(); ++i) {
-// cerr << "BEFORE " << (*i)->name() << ": pb = " << (*i)->playback_buffer_load() << " cp = " << (*i)->capture_buffer_load() << endl;
-// }
-
for (i = rl_with_auditioner.begin(); !transport_work_requested() && should_run && i != rl_with_auditioner.end(); ++i) {
boost::shared_ptr<Track> tr = boost::dynamic_pointer_cast<Track> (*i);
@@ -306,7 +303,7 @@ Butler::thread_work ()
DEBUG_TRACE (DEBUG::Butler, string_compose ("butler skips inactive track %1\n", tr->name()));
continue;
}
- DEBUG_TRACE (DEBUG::Butler, string_compose ("butler refills %1\n", tr->name()));
+ DEBUG_TRACE (DEBUG::Butler, string_compose ("butler refills %1, playback load = %2\n", tr->name(), tr->playback_buffer_load()));
switch (tr->do_refill ()) {
case 0:
DEBUG_TRACE (DEBUG::Butler, string_compose ("\ttrack refill done %1\n", tr->name()));
@@ -319,6 +316,7 @@ Butler::thread_work ()
default:
error << string_compose(_("Butler read ahead failure on dstream %1"), (*i)->name()) << endmsg;
+ std::cerr << string_compose(_("Butler read ahead failure on dstream %1"), (*i)->name()) << std::endl;
break;
}
@@ -346,20 +344,27 @@ Butler::thread_work ()
/* note that we still try to flush diskstreams attached to inactive routes
*/
- DEBUG_TRACE (DEBUG::Butler, string_compose ("butler flushes track %1\n", tr->name()));
- switch (tr->do_flush (ButlerContext)) {
+ gint64 before, after;
+ int ret;
+
+ DEBUG_TRACE (DEBUG::Butler, string_compose ("butler flushes track %1 capture load %2\n", tr->name(), tr->capture_buffer_load()));
+ before = g_get_monotonic_time ();
+ ret = tr->do_flush (ButlerContext);
+ after = g_get_monotonic_time ();
+ switch (ret) {
case 0:
- DEBUG_TRACE (DEBUG::Butler, string_compose ("\tflush complete for %1\n", tr->name()));
+ DEBUG_TRACE (DEBUG::Butler, string_compose ("\tflush complete for %1, %2 usecs\n", tr->name(), after - before));
break;
case 1:
- DEBUG_TRACE (DEBUG::Butler, string_compose ("\tflush not finished for %1\n", tr->name()));
+ DEBUG_TRACE (DEBUG::Butler, string_compose ("\tflush not finished for %1, %2 usecs\n", tr->name(), after - before));
disk_work_outstanding = true;
break;
default:
err++;
error << string_compose(_("Butler write-behind failure on dstream %1"), (*i)->name()) << endmsg;
+ std::cerr << string_compose(_("Butler write-behind failure on dstream %1"), (*i)->name()) << std::endl;
/* don't break - try to flush all streams in case they
are split across disks.
*/
@@ -394,13 +399,12 @@ Butler::thread_work ()
Glib::Threads::Mutex::Lock lm (request_lock);
if (should_run && (disk_work_outstanding || transport_work_requested())) {
-// for (DiskstreamList::iterator i = dsl->begin(); i != dsl->end(); ++i) {
-// cerr << "AFTER " << (*i)->name() << ": pb = " << (*i)->playback_buffer_load() << " cp = " << (*i)->capture_buffer_load() << endl;
-// }
-
+ DEBUG_TRACE (DEBUG::Butler, string_compose ("at end, should run %1 disk work %2 transport work %3 ... goto restart\n",
+ should_run, disk_work_outstanding, transport_work_requested()));
goto restart;
}
+ DEBUG_TRACE (DEBUG::Butler, string_compose ("%1: butler signals pause @ %2\n", pthread_self(), g_get_monotonic_time()));
paused.signal();
}
@@ -433,7 +437,7 @@ Butler::queue_request (Request::Type r)
void
Butler::summon ()
{
- DEBUG_TRACE (DEBUG::Butler, string_compose ("%1: summon butler to run @ %2", pthread_self(), g_get_monotonic_time()));
+ DEBUG_TRACE (DEBUG::Butler, string_compose ("%1: summon butler to run @ %2\n", pthread_self(), g_get_monotonic_time()));
queue_request (Request::Run);
}
@@ -441,7 +445,7 @@ void
Butler::stop ()
{
Glib::Threads::Mutex::Lock lm (request_lock);
- DEBUG_TRACE (DEBUG::Butler, string_compose ("%1: asking butler to stop @ %2", pthread_self(), g_get_monotonic_time()));
+ DEBUG_TRACE (DEBUG::Butler, string_compose ("%1: asking butler to stop @ %2\n", pthread_self(), g_get_monotonic_time()));
queue_request (Request::Pause);
paused.wait(request_lock);
}
@@ -450,7 +454,7 @@ void
Butler::wait_until_finished ()
{
Glib::Threads::Mutex::Lock lm (request_lock);
- DEBUG_TRACE (DEBUG::Butler, string_compose ("%1: waiting for butler to finish @ %2", pthread_self(), g_get_monotonic_time()));
+ DEBUG_TRACE (DEBUG::Butler, string_compose ("%1: waiting for butler to finish @ %2\n", pthread_self(), g_get_monotonic_time()));
queue_request (Request::Pause);
paused.wait(request_lock);
}
diff --git a/libs/ardour/session_process.cc b/libs/ardour/session_process.cc
index efe9ffb351..8d94fbb064 100644
--- a/libs/ardour/session_process.cc
+++ b/libs/ardour/session_process.cc
@@ -248,6 +248,12 @@ Session::get_track_statistics ()
g_atomic_int_set (&_playback_load, (uint32_t) floor (pworst * 100.0f));
g_atomic_int_set (&_capture_load, (uint32_t) floor (cworst * 100.0f));
+ if (cworst < 0.4 || pworst < 0.4) {
+ GTimeVal now;
+ g_get_current_time (&now);
+ std::cerr << g_time_val_to_iso8601 (&now) << " *** WARNING *** CAPTURE BUFFERS (WORST): " << cworst << "PLAYBACK BUFFERS (WORST): " << pworst << endl;
+ }
+
if (actively_recording()) {
set_dirty();
}
generated by cgit v1.2.3 (git 2.39.1) at 2024-06-22 21:01:46 +0000