#include "analyse_audio_job.h"
#include "audio_content.h"
#include "compose.hpp"
+#include "dcpomatic_log.h"
#include "film.h"
#include "player.h"
#include "playlist.h"
, _ebur128 (new AudioFilterGraph (film->audio_frame_rate(), film->audio_channels()))
#endif
{
+ LOG_DEBUG_AUDIO_ANALYSIS_NC("AnalyseAudioJob::AnalyseAudioJob");
+
#ifdef DCPOMATIC_HAVE_EBUR128_PATCHED_FFMPEG
_filters.push_back (new Filter ("ebur128", "ebur128", "audio", "ebur128=peak=true"));
_ebur128->setup (_filters);
void
AnalyseAudioJob::run ()
{
+ LOG_DEBUG_AUDIO_ANALYSIS_NC("AnalyseAudioJob::run");
+
shared_ptr<Player> player (new Player(_film, _playlist));
player->set_ignore_video ();
player->set_ignore_text ();
}
if (has_any_audio) {
+ LOG_DEBUG_AUDIO_ANALYSIS("Seeking to %1", to_string(_start));
player->seek (_start, true);
_done = 0;
+ LOG_DEBUG_AUDIO_ANALYSIS("Starting loop for playlist of length %1", to_string(length));
while (!player->pass ()) {}
}
+ LOG_DEBUG_AUDIO_ANALYSIS_NC("Loop complete");
+
vector<AudioAnalysis::PeakTime> sample_peak;
for (int i = 0; i < _film->audio_channels(); ++i) {
sample_peak.push_back (
_analysis->set_leqm (_leqm->leq_m());
_analysis->write (_path);
+ LOG_DEBUG_AUDIO_ANALYSIS_NC("Job finished");
set_progress (1);
set_state (FINISHED_OK);
}
void
AnalyseAudioJob::analyse (shared_ptr<const AudioBuffers> b, DCPTime time)
{
+ LOG_DEBUG_AUDIO_ANALYSIS("Received %1 frames at %2", b->frames(), to_string(time));
DCPOMATIC_ASSERT (time >= _start);
#ifdef DCPOMATIC_HAVE_EBUR128_PATCHED_FFMPEG
DCPTime const length = _playlist->length (_film);
set_progress ((time.seconds() - _start.seconds()) / (length.seconds() - _start.seconds()));
+ LOG_DEBUG_AUDIO_ANALYSIS_NC("Frames processed");
}
#define LOG_DISK_NC(...) dcpomatic_log->log(__VA_ARGS__, LogEntry::TYPE_DISK);
#define LOG_DEBUG_PLAYER(...) dcpomatic_log->log(String::compose(__VA_ARGS__), LogEntry::TYPE_DEBUG_PLAYER);
#define LOG_DEBUG_PLAYER_NC(...) dcpomatic_log->log(__VA_ARGS__, LogEntry::TYPE_DEBUG_PLAYER);
+#define LOG_DEBUG_AUDIO_ANALYSIS(...) dcpomatic_log->log(String::compose(__VA_ARGS__), LogEntry::TYPE_DEBUG_AUDIO_ANALYSIS);
+#define LOG_DEBUG_AUDIO_ANALYSIS_NC(...) dcpomatic_log->log(__VA_ARGS__, LogEntry::TYPE_DEBUG_AUDIO_ANALYSIS);
+
int const LogEntry::TYPE_DEBUG_VIDEO_VIEW = 0x080;
int const LogEntry::TYPE_DISK = 0x100;
int const LogEntry::TYPE_DEBUG_PLAYER = 0x200;
+int const LogEntry::TYPE_DEBUG_AUDIO_ANALYSIS = 0x400;
using std::string;
static const int TYPE_DEBUG_VIDEO_VIEW; ///< real-time video viewing (i.e. "playback")
static const int TYPE_DISK;
static const int TYPE_DEBUG_PLAYER; ///< the Player class
+ static const int TYPE_DEBUG_AUDIO_ANALYSIS; ///< audio analysis job
explicit LogEntry (int type);
virtual ~LogEntry () {}
if (_suspended) {
/* We can't pass in this state */
+ LOG_DEBUG_PLAYER_NC ("Player is suspended");
return false;
}
switch (which) {
case CONTENT:
{
+ LOG_DEBUG_PLAYER ("Calling pass() on %1", earliest_content->content->path(0));
earliest_content->done = earliest_content->decoder->pass ();
shared_ptr<DCPContent> dcp = dynamic_pointer_cast<DCPContent>(earliest_content->content);
if (dcp && !_play_referenced && dcp->reference_audio()) {
break;
case SILENT:
{
+ LOG_DEBUG_PLAYER ("Emit silence for gap at %1", to_string(_silent.position()));
DCPTimePeriod period (_silent.period_at_position());
if (_last_audio_time) {
/* Sometimes the thing that happened last finishes fractionally before
pull_to = _silent.position();
}
+ LOG_DEBUG_PLAYER("Emitting audio up to %1", to_string(pull_to));
list<pair<shared_ptr<AudioBuffers>, DCPTime> > audio = _audio_merger.pull (pull_to);
for (list<pair<shared_ptr<AudioBuffers>, DCPTime> >::iterator i = audio.begin(); i != audio.end(); ++i) {
if (_last_audio_time && i->second < *_last_audio_time) {
/* Time of the first frame we will emit */
DCPTime const time = content_video_to_dcp (piece, video.frame);
+ LOG_DEBUG_PLAYER("Received video frame %1 at %2", video.frame, to_string(time));
/* Discard if it's before the content's period or the last accurate seek. We can't discard
if it's after the content's period here as in that case we still need to fill any gap between
/* Compute time in the DCP */
DCPTime time = resampled_audio_to_dcp (piece, content_audio.frame);
+ LOG_DEBUG_PLAYER("Received audio frame %1 at %2", content_audio.frame, to_string(time));
+
/* And the end of this block in the DCP */
DCPTime end = time + DCPTime::from_frames(content_audio.audio->frames(), rfr);
Player::seek (DCPTime time, bool accurate)
{
boost::mutex::scoped_lock lm (_mutex);
+ LOG_DEBUG_PLAYER("Seek to %1 (%2accurate)", to_string(time), accurate ? "" : "in");
if (_suspended) {
/* We can't seek in this state */
, _log_debug_threed (0)
, _log_debug_encode (0)
, _log_debug_email (0)
+ , _log_debug_video_view (0)
+ , _log_debug_player (0)
+ , _log_debug_audio_analysis (0)
{}
private:
t->Add (_log_debug_encode, 1, wxEXPAND | wxALL);
_log_debug_email = new CheckBox (_panel, _("Debug: email sending"));
t->Add (_log_debug_email, 1, wxEXPAND | wxALL);
+ _log_debug_video_view = new CheckBox (_panel, _("Debug: video view"));
+ t->Add (_log_debug_video_view, 1, wxEXPAND | wxALL);
+ _log_debug_player = new CheckBox (_panel, _("Debug: player"));
+ t->Add (_log_debug_player, 1, wxEXPAND | wxALL);
+ _log_debug_audio_analysis = new CheckBox (_panel, _("Debug: audio analysis"));
+ t->Add (_log_debug_audio_analysis, 1, wxEXPAND | wxALL);
table->Add (t, 0, wxALL, 6);
}
_log_debug_threed->Bind (wxEVT_CHECKBOX, boost::bind (&AdvancedPage::log_changed, this));
_log_debug_encode->Bind (wxEVT_CHECKBOX, boost::bind (&AdvancedPage::log_changed, this));
_log_debug_email->Bind (wxEVT_CHECKBOX, boost::bind (&AdvancedPage::log_changed, this));
+ _log_debug_video_view->Bind (wxEVT_CHECKBOX, boost::bind (&AdvancedPage::log_changed, this));
+ _log_debug_player->Bind (wxEVT_CHECKBOX, boost::bind (&AdvancedPage::log_changed, this));
+ _log_debug_audio_analysis->Bind (wxEVT_CHECKBOX, boost::bind (&AdvancedPage::log_changed, this));
#ifdef DCPOMATIC_WINDOWS
_win32_console->Bind (wxEVT_CHECKBOX, boost::bind (&AdvancedPage::win32_console_changed, this));
#endif
checked_set (_log_debug_threed, config->log_types() & LogEntry::TYPE_DEBUG_THREED);
checked_set (_log_debug_encode, config->log_types() & LogEntry::TYPE_DEBUG_ENCODE);
checked_set (_log_debug_email, config->log_types() & LogEntry::TYPE_DEBUG_EMAIL);
+ checked_set (_log_debug_video_view, config->log_types() & LogEntry::TYPE_DEBUG_VIDEO_VIEW);
+ checked_set (_log_debug_player, config->log_types() & LogEntry::TYPE_DEBUG_PLAYER);
+ checked_set (_log_debug_audio_analysis, config->log_types() & LogEntry::TYPE_DEBUG_AUDIO_ANALYSIS);
checked_set (_frames_in_memory_multiplier, config->frames_in_memory_multiplier());
#ifdef DCPOMATIC_WINDOWS
checked_set (_win32_console, config->win32_console());
if (_log_debug_email->GetValue ()) {
types |= LogEntry::TYPE_DEBUG_EMAIL;
}
+ if (_log_debug_video_view->GetValue()) {
+ types |= LogEntry::TYPE_DEBUG_VIDEO_VIEW;
+ }
+ if (_log_debug_player->GetValue()) {
+ types |= LogEntry::TYPE_DEBUG_PLAYER;
+ }
+ if (_log_debug_audio_analysis->GetValue()) {
+ types |= LogEntry::TYPE_DEBUG_AUDIO_ANALYSIS;
+ }
Config::instance()->set_log_types (types);
}
wxCheckBox* _log_debug_threed;
wxCheckBox* _log_debug_encode;
wxCheckBox* _log_debug_email;
+ wxCheckBox* _log_debug_video_view;
+ wxCheckBox* _log_debug_player;
+ wxCheckBox* _log_debug_audio_analysis;
#ifdef DCPOMATIC_WINDOWS
wxCheckBox* _win32_console;
#endif