diff --git a/libs/ardour/butler.cc b/libs/ardour/butler.cc index 7fb6c6ee39..2a31403a1f 100644 --- a/libs/ardour/butler.cc +++ b/libs/ardour/butler.cc @@ -273,7 +273,7 @@ Butler::thread_work () RouteList rl_with_auditioner = *rl; rl_with_auditioner.push_back (_session.the_auditioner ()); - DEBUG_TRACE (DEBUG::Butler, string_compose ("butler starts refill loop, twr = %1\n", transport_work_requested ())); + DEBUG_TRACE (DEBUG::Butler, string_compose ("butler starts refill loop, twr = %1\n", should_do_transport_work.load ())); std::shared_ptr tl = _session.io_tasklist (); @@ -413,8 +413,8 @@ Butler::flush_tracks_to_disk_normal (std::shared_ptr rl, uint32 void Butler::schedule_transport_work () { - DEBUG_TRACE (DEBUG::Butler, "requesting more transport work\n"); should_do_transport_work.fetch_add (1); + DEBUG_TRACE (DEBUG::Butler, string_compose ("requesting more transport work (now %1)\n", should_do_transport_work.load ())); summon (); } diff --git a/libs/ardour/disk_reader.cc b/libs/ardour/disk_reader.cc index 05255066fe..5210b13028 100644 --- a/libs/ardour/disk_reader.cc +++ b/libs/ardour/disk_reader.cc @@ -115,7 +115,7 @@ DiskReader::add_channel_to (std::shared_ptr c, uint32_t how_many) { while (how_many--) { c->push_back (new ReaderChannelInfo (_session.butler ()->audio_playback_buffer_size (), loop_fade_length)); - DEBUG_TRACE (DEBUG::DiskIO, string_compose ("%1: new reader channel, write space = %2 read = %3\n", + DEBUG_TRACE (DEBUG::DiskIO, string_compose ("'%1': new reader channel, write space = %2 read = %3\n", name (), c->back ()->rbuf->write_space (), c->back ()->rbuf->read_space ())); @@ -422,7 +422,7 @@ DiskReader::run (BufferSet& bufs, samplepos_t start_sample, samplepos_t end_samp #ifndef NDEBUG // not rt-safe to print here cerr << "underrun for " << _name << " Available samples: " << available << " required: " << disk_samples_to_consume << endl; #endif - DEBUG_TRACE (DEBUG::Butler, string_compose ("%1 underrun in %2, total space = %3 vs %4\n", DEBUG_THREAD_SELF, name (), available, disk_samples_to_consume)); + DEBUG_TRACE (DEBUG::DiskIO, string_compose ("'%1': underrun in thread %2, available = %3 need = %4\n", owner ()->name (), DEBUG_THREAD_SELF, available, disk_samples_to_consume)); DEBUG_TRACE (DEBUG::AudioCacheRefill, string_compose ("DR '%1' underrun have %2 need %3 samples at pos %4\n", name (), available, disk_samples_to_consume, std::setprecision (3), std::fixed, @@ -503,13 +503,14 @@ midi: if (!c->empty ()) { if (_slaved) { if (c->front ()->rbuf->write_space () >= c->front ()->rbuf->bufsize () / 2) { - DEBUG_TRACE (DEBUG::Butler, string_compose ("%1: slaved, write space = %2 of %3\n", name (), c->front ()->rbuf->write_space (), c->front ()->rbuf->bufsize ())); + DEBUG_TRACE (DEBUG::DiskIO, string_compose ("'%1': slaved, write space = %2 of %3\n", + _owner->name (), c->front ()->rbuf->write_space (), c->front ()->rbuf->bufsize ())); butler_required = true; } } else { if ((samplecnt_t)c->front ()->rbuf->write_space () >= _chunk_samples) { - DEBUG_TRACE (DEBUG::Butler, string_compose ("%1: write space = %2 chunk size = %3\n", name (), c->front ()->rbuf->write_space (), - _chunk_samples)); + DEBUG_TRACE (DEBUG::DiskIO, string_compose ("%1: write space = %2 chunk size = %3\n", + _owner->name (), c->front ()->rbuf->write_space (), _chunk_samples)); butler_required = true; } } @@ -524,7 +525,7 @@ midi: } if (_need_butler) { - DEBUG_TRACE (DEBUG::Butler, string_compose ("%1 reader run, needs butler = %2\n", name (), _need_butler)); + DEBUG_TRACE (DEBUG::DiskIO, string_compose ("'%1' reader run, needs butler = %2\n", _owner->name (), _need_butler)); } } @@ -560,7 +561,7 @@ DiskReader::pending_overwrite () const void DiskReader::set_pending_overwrite (OverwriteReason why) { - DEBUG_TRACE (DEBUG::DiskIO, string_compose ("%1 set_pending_overwrite because %2%3%4\n", owner ()->name (), std::hex, why, std::dec)); + DEBUG_TRACE (DEBUG::DiskIO, string_compose ("'%1': set_pending_overwrite because %2%3%4)\n", owner ()->name (), std::hex, why, std::dec)); std::shared_ptr c = channels.reader (); /* called from audio thread, so we can use the read ptr and playback sample as we wish */ @@ -699,6 +700,8 @@ DiskReader::overwrite_existing_audio () const size_t to_overwrite = c->front ()->rbuf->overwritable_at (overwrite_offset); + DEBUG_TRACE (DEBUG::DiskIO, string_compose ("'%1': overwrite_existing_audio at %2 offset = %2 to_ovrwrt = %3\n", owner ()->name (), overwrite_sample, overwrite_offset, to_overwrite)); + chunk1_offset = overwrite_offset; chunk1_cnt = min (c->front ()->rbuf->bufsize () - (size_t)overwrite_offset, to_overwrite); @@ -763,7 +766,7 @@ DiskReader::overwrite_existing_audio () } if (!rci->initialized) { - DEBUG_TRACE (DEBUG::DiskIO, string_compose ("Init ReaderChannel '%1' overwriting at: %2, avail: %3\n", name (), overwrite_sample, chan->rbuf->read_space ())); + DEBUG_TRACE (DEBUG::DiskIO, string_compose ("'1': Init ReaderChannel overwriting at: %2, avail: %3\n", name (), overwrite_sample, chan->rbuf->read_space ())); if (chan->rbuf->read_space () > 0) { rci->initialized = true; } @@ -807,7 +810,7 @@ DiskReader::overwrite_existing_buffers () { /* called from butler thread */ - DEBUG_TRACE (DEBUG::DiskIO, string_compose ("%1 overwriting existing buffers at %2 (because %3%4%5\n", owner ()->name (), overwrite_sample, std::hex, _pending_overwrite.load (), std::dec)); + DEBUG_TRACE (DEBUG::DiskIO, string_compose ("'%1': overwriting existing buffers at %2 (because %3%4%5)\n", owner ()->name (), overwrite_sample, std::hex, _pending_overwrite.load (), std::dec)); bool ret = true; @@ -823,6 +826,7 @@ DiskReader::overwrite_existing_buffers () } } + DEBUG_TRACE (DEBUG::DiskIO, string_compose ("'%1': Clear _pending_overwrite\n", owner ()->name ())); _pending_overwrite.store (OverwriteReason (0)); return ret; @@ -863,7 +867,7 @@ DiskReader::seek (samplepos_t sample, bool complete_refill) } } - DEBUG_TRACE (DEBUG::DiskIO, string_compose ("DiskReader::seek %1 %2 -> %3 refill=%4 pending_overwrite = %5\n", + DEBUG_TRACE (DEBUG::DiskIO, string_compose ("'%1': seek %2 -> %3 refill = %4 pending_overwrite = %5\n", owner ()->name (), playback_sample, sample, complete_refill, _pending_overwrite.load ())); _pending_overwrite.store (OverwriteReason (0)); @@ -1194,7 +1198,7 @@ DiskReader::refill_audio (Sample* sum_buffer, Sample* mixdown_buffer, float* gai samplecnt_t total_space = c->front ()->rbuf->write_space (); if (total_space == 0) { - DEBUG_TRACE (DEBUG::DiskIO, string_compose ("%1: no space to refill\n", name ())); + DEBUG_TRACE (DEBUG::DiskIO, string_compose ("'%1': no space to refill\n", name ())); /* nowhere to write to */ return 0; } @@ -1219,7 +1223,7 @@ DiskReader::refill_audio (Sample* sum_buffer, Sample* mixdown_buffer, float* gai * the playback buffer is empty. */ - DEBUG_TRACE (DEBUG::DiskIO, string_compose ("%1: space to refill %2 vs. chunk %3 (speed = %4)\n", name (), total_space, _chunk_samples, _session.transport_speed ())); + DEBUG_TRACE (DEBUG::DiskIO, string_compose ("'%1': space to refill %2 vs. chunk %3 (speed = %4)\n", name (), total_space, _chunk_samples, _session.transport_speed ())); if ((total_space < _chunk_samples) && fabs (_session.transport_speed ()) < 2.0f) { return 0; } @@ -1230,7 +1234,7 @@ DiskReader::refill_audio (Sample* sum_buffer, Sample* mixdown_buffer, float* gai */ if (_slaved && total_space < (samplecnt_t) (c->front ()->rbuf->bufsize () / 2)) { - DEBUG_TRACE (DEBUG::DiskIO, string_compose ("%1: not enough to refill while slaved\n", this)); + DEBUG_TRACE (DEBUG::DiskIO, string_compose ("'%1': not enough to refill while slaved\n", this)); return 0; } @@ -1288,7 +1292,7 @@ DiskReader::refill_audio (Sample* sum_buffer, Sample* mixdown_buffer, float* gai /* now back to samples */ samplecnt_t samples_to_read = byte_size_for_read / (bits_per_sample / 8); - DEBUG_TRACE (DEBUG::DiskIO, string_compose ("%1: will refill %2 channels with %3 samples\n", name (), c->size (), total_space)); + DEBUG_TRACE (DEBUG::DiskIO, string_compose ("'%1': will refill %2 channels with %3 samples\n", name (), c->size (), total_space)); samplepos_t file_sample_tmp = fsa; @@ -1334,7 +1338,7 @@ DiskReader::refill_audio (Sample* sum_buffer, Sample* mixdown_buffer, float* gai } } if (!rci->initialized) { - DEBUG_TRACE (DEBUG::DiskIO, string_compose (" -- Init ReaderChannel '%1' read: %2 samples, at: %4, avail: %5\n", name (), to_read, file_sample_tmp, rci->rbuf->read_space ())); + DEBUG_TRACE (DEBUG::DiskIO, string_compose ("'%1' Init ReaderChannel read: %2 samples, at: %4, avail: %5\n", name (), to_read, file_sample_tmp, rci->rbuf->read_space ())); rci->initialized = true; } } diff --git a/libs/ardour/session_transport.cc b/libs/ardour/session_transport.cc index a6472b46da..47e92791cb 100644 --- a/libs/ardour/session_transport.cc +++ b/libs/ardour/session_transport.cc @@ -674,7 +674,7 @@ Session::butler_completed_transport_work () ENSURE_PROCESS_THREAD; PostTransportWork ptw = post_transport_work (); - DEBUG_TRACE (DEBUG::Transport, string_compose ("Butler done, RT cleanup for %1\n", enum_2_string (ptw))); + DEBUG_TRACE (DEBUG::Butler, string_compose ("Butler done, RT cleanup for %1\n", enum_2_string (ptw))); if (ptw & PostTransportAudition) { if (auditioner && auditioner->auditioning()) { @@ -1149,7 +1149,7 @@ Session::butler_transport_work (bool have_process_lock) uint64_t before = g_get_monotonic_time(); #endif - DEBUG_TRACE (DEBUG::Transport, string_compose ("Butler transport work, todo = [%1] (0x%3%4%5) at %2\n", enum_2_string (ptw), before, std::hex, ptw, std::dec)); + DEBUG_TRACE (DEBUG::Butler, string_compose ("Butler transport work, todo = [%1] (0x%3%4%5) twr = %6 @ %2\n", enum_2_string (ptw), before, std::hex, ptw, std::dec, on_entry)); if (ptw & PostTransportAdjustPlaybackBuffering) { /* need to prevent concurrency with ARDOUR::Reader::run(), @@ -1203,9 +1203,8 @@ Session::butler_transport_work (bool have_process_lock) } } - if (will_locate) { - DEBUG_TRACE (DEBUG::Transport, string_compose ("nonrealtime locate invoked from BTW (butler has done %1, rtlocs %2)\n", butler, rtlocates)); + DEBUG_TRACE (DEBUG::Butler, string_compose ("nonrealtime locate invoked from BTW (butler has done %1, rtlocs %2)\n", butler, rtlocates)); non_realtime_locate (); } @@ -1226,7 +1225,7 @@ Session::butler_transport_work (bool have_process_lock) (void) PBD::atomic_dec_and_test (_butler->should_do_transport_work); - DEBUG_TRACE (DEBUG::Transport, string_compose (X_("Butler transport work all done after %1 usecs @ %2 ptw %3 trw = %4\n"), g_get_monotonic_time() - before, _transport_sample, enum_2_string (post_transport_work()), _butler->transport_work_requested())); + DEBUG_TRACE (DEBUG::Butler, string_compose (X_("Butler transport work all done after %1 usecs tsp = %2 ptw [%3] trw = %4\n"), g_get_monotonic_time() - before, _transport_sample, enum_2_string (post_transport_work()), _butler->should_do_transport_work.load ())); } void