Changed every LOG_VERBOSE in std::cout for better debug

- Couldn't make LOG_VERBOSE work ( tried to compile in debug and set log verbose at beginning of the main() )
This commit is contained in:
Joachim
2020-04-03 13:26:11 +02:00
parent 7943d4e5d0
commit 9fbc37c4b0

View File

@ -213,7 +213,7 @@ public:
, isActive(true) , isActive(true)
#endif #endif
{ {
CV_LOG_VERBOSE(NULL, 1, "MainThread: initializing new worker: " << id); std::cout << "MainThread: initializing new worker: " << id << std::endl;
int res = pthread_mutex_init(&mutex, NULL); int res = pthread_mutex_init(&mutex, NULL);
if (res != 0) if (res != 0)
{ {
@ -228,6 +228,8 @@ public:
return; return;
} }
#endif #endif
// ESP32 DEBUG
printf("Creating pthread!\n");
res = pthread_create(&posix_thread, NULL, thread_loop_wrapper, (void*)this); res = pthread_create(&posix_thread, NULL, thread_loop_wrapper, (void*)this);
if (res != 0) if (res != 0)
{ {
@ -241,7 +243,7 @@ public:
~WorkerThread() ~WorkerThread()
{ {
CV_LOG_VERBOSE(NULL, 1, "MainThread: destroy worker thread: " << id); std::cout << "MainThread: destroy worker thread: " << id << std::endl;
if (is_created) if (is_created)
{ {
if (!stop_thread) if (!stop_thread)
@ -284,7 +286,7 @@ public:
nstripes((unsigned)nstripes_), nstripes((unsigned)nstripes_),
is_completed(false) is_completed(false)
{ {
CV_LOG_VERBOSE(NULL, 5, "ParallelJob::ParallelJob(" << (void*)this << ")"); std::cout << "ParallelJob::ParallelJob(" << (void*)this << ")" << std::endl;
current_task.store(0, std::memory_order_relaxed); current_task.store(0, std::memory_order_relaxed);
active_thread_count.store(0, std::memory_order_relaxed); active_thread_count.store(0, std::memory_order_relaxed);
completed_thread_count.store(0, std::memory_order_relaxed); completed_thread_count.store(0, std::memory_order_relaxed);
@ -293,7 +295,7 @@ public:
~ParallelJob() ~ParallelJob()
{ {
CV_LOG_VERBOSE(NULL, 5, "ParallelJob::~ParallelJob(" << (void*)this << ")"); std::cout << "ParallelJob::~ParallelJob(" << (void*)this << ")" << std::endl;
} }
unsigned execute(bool is_worker_thread) unsigned execute(bool is_worker_thread)
@ -353,7 +355,7 @@ public:
void WorkerThread::thread_body() void WorkerThread::thread_body()
{ {
(void)cv::utils::getThreadID(); // notify OpenCV about new thread (void)cv::utils::getThreadID(); // notify OpenCV about new thread
CV_LOG_VERBOSE(NULL, 5, "Thread: new thread: " << id); std::cout << "Thread: new thread: " << id << std::endl;
bool allow_active_wait = true; bool allow_active_wait = true;
@ -363,7 +365,7 @@ void WorkerThread::thread_body()
while (!stop_thread) while (!stop_thread)
{ {
CV_LOG_VERBOSE(NULL, 5, "Thread: ... loop iteration: allow_active_wait=" << allow_active_wait << " has_wake_signal=" << has_wake_signal); std::cout << "Thread: ... loop iteration: allow_active_wait=" << allow_active_wait << " has_wake_signal=" << has_wake_signal << std::endl;
if (allow_active_wait && CV_WORKER_ACTIVE_WAIT > 0) if (allow_active_wait && CV_WORKER_ACTIVE_WAIT > 0)
{ {
allow_active_wait = false; allow_active_wait = false;
@ -383,7 +385,7 @@ void WorkerThread::thread_body()
#endif #endif
while (!has_wake_signal) // to handle spurious wakeups while (!has_wake_signal) // to handle spurious wakeups
{ {
//CV_LOG_VERBOSE(NULL, 5, "Thread: wait (sleep) ..."); //std::cout << "Thread: wait (sleep) ...");
#if defined(CV_USE_GLOBAL_WORKERS_COND_VAR) #if defined(CV_USE_GLOBAL_WORKERS_COND_VAR)
pthread_cond_wait(&thread_pool.cond_thread_wake, &mutex); pthread_cond_wait(&thread_pool.cond_thread_wake, &mutex);
#else #else
@ -391,13 +393,13 @@ void WorkerThread::thread_body()
pthread_cond_wait(&cond_thread_wake, &mutex); pthread_cond_wait(&cond_thread_wake, &mutex);
isActive = true; isActive = true;
#endif #endif
CV_LOG_VERBOSE(NULL, 5, "Thread: wake ... (has_wake_signal=" << has_wake_signal << " stop_thread=" << stop_thread << ")") std::cout << "Thread: wake ... (has_wake_signal=" << has_wake_signal << " stop_thread=" << stop_thread << ")" << std::endl;
} }
#ifdef CV_PROFILE_THREADS #ifdef CV_PROFILE_THREADS
stat.threadWake = getTickCount(); stat.threadWake = getTickCount();
#endif #endif
CV_LOG_VERBOSE(NULL, 5, "Thread: checking for new job"); std::cout << "Thread: checking for new job" << std::endl;
if (CV_WORKER_ACTIVE_WAIT_THREADS_LIMIT == 0) if (CV_WORKER_ACTIVE_WAIT_THREADS_LIMIT == 0)
allow_active_wait = true; allow_active_wait = true;
Ptr<ParallelJob> j_ptr; swap(j_ptr, job); Ptr<ParallelJob> j_ptr; swap(j_ptr, job);
@ -409,11 +411,11 @@ void WorkerThread::thread_body()
ParallelJob* j = j_ptr; ParallelJob* j = j_ptr;
if (j) if (j)
{ {
CV_LOG_VERBOSE(NULL, 5, "Thread: job size=" << j->range.size() << " done=" << j->current_task); std::cout << "Thread: job size=" << j->range.size() << " done=" << j->current_task << std::endl;
if (j->current_task < j->range.size()) if (j->current_task < j->range.size())
{ {
int other = j->active_thread_count.fetch_add(1, std::memory_order_seq_cst); int other = j->active_thread_count.fetch_add(1, std::memory_order_seq_cst);
CV_LOG_VERBOSE(NULL, 5, "Thread: processing new job (with " << other << " other threads)"); CV_UNUSED(other); std::cout << "Thread: processing new job (with " << other << " other threads)" << std::endl; CV_UNUSED(other);
#ifdef CV_PROFILE_THREADS #ifdef CV_PROFILE_THREADS
stat.threadExecuteStart = getTickCount(); stat.threadExecuteStart = getTickCount();
stat.executedTasks = j->execute(true); stat.executedTasks = j->execute(true);
@ -429,7 +431,7 @@ void WorkerThread::thread_body()
if (active >= CV_WORKER_ACTIVE_WAIT_THREADS_LIMIT && (id & 1) == 0) // turn off a half of threads if (active >= CV_WORKER_ACTIVE_WAIT_THREADS_LIMIT && (id & 1) == 0) // turn off a half of threads
allow_active_wait = false; allow_active_wait = false;
} }
CV_LOG_VERBOSE(NULL, 5, "Thread: completed job processing: " << active << " " << completed); std::cout << "Thread: completed job processing: " << active << " " << completed << std::endl;
if (active == completed) if (active == completed)
{ {
bool need_signal = !j->is_completed; bool need_signal = !j->is_completed;
@ -437,7 +439,7 @@ void WorkerThread::thread_body()
j = NULL; j_ptr.release(); j = NULL; j_ptr.release();
if (need_signal) if (need_signal)
{ {
CV_LOG_VERBOSE(NULL, 5, "Thread: job finished => notifying the main thread"); std::cout << "Thread: job finished => notifying the main thread" << std::endl;
pthread_mutex_lock(&thread_pool.mutex_notify); // to avoid signal miss due pre-check condition pthread_mutex_lock(&thread_pool.mutex_notify); // to avoid signal miss due pre-check condition
// empty // empty
pthread_mutex_unlock(&thread_pool.mutex_notify); pthread_mutex_unlock(&thread_pool.mutex_notify);
@ -447,7 +449,7 @@ void WorkerThread::thread_body()
} }
else else
{ {
CV_LOG_VERBOSE(NULL, 5, "Thread: no free job tasks"); std::cout << "Thread: no free job tasks" << std::endl;
} }
} }
} }
@ -486,7 +488,8 @@ bool ThreadPool::reconfigure_(unsigned new_threads_count)
if (new_threads_count < threads.size()) if (new_threads_count < threads.size())
{ {
CV_LOG_VERBOSE(NULL, 1, "MainThread: reduce worker pool: " << threads.size() << " => " << new_threads_count);
std::cout << "MainThread: reduce worker pool: " << threads.size() << " => " << new_threads_count << std::endl;
std::vector< Ptr<WorkerThread> > release_threads(threads.size() - new_threads_count); std::vector< Ptr<WorkerThread> > release_threads(threads.size() - new_threads_count);
for (size_t i = new_threads_count; i < threads.size(); ++i) for (size_t i = new_threads_count; i < threads.size(); ++i)
{ {
@ -502,7 +505,7 @@ bool ThreadPool::reconfigure_(unsigned new_threads_count)
std::swap(threads[i], release_threads[i - new_threads_count]); std::swap(threads[i], release_threads[i - new_threads_count]);
} }
#if defined(CV_USE_GLOBAL_WORKERS_COND_VAR) #if defined(CV_USE_GLOBAL_WORKERS_COND_VAR)
CV_LOG_VERBOSE(NULL, 1, "MainThread: notify worker threads about termination..."); std::cout << "MainThread: notify worker threads about termination...");
pthread_cond_broadcast(&cond_thread_wake); // wake all threads pthread_cond_broadcast(&cond_thread_wake); // wake all threads
#endif #endif
threads.resize(new_threads_count); threads.resize(new_threads_count);
@ -511,7 +514,7 @@ bool ThreadPool::reconfigure_(unsigned new_threads_count)
} }
else else
{ {
CV_LOG_VERBOSE(NULL, 1, "MainThread: upgrade worker pool: " << threads.size() << " => " << new_threads_count); std::cout << "MainThread: upgrade worker pool: " << threads.size() << " => " << new_threads_count << std::endl;
for (size_t i = threads.size(); i < new_threads_count; ++i) for (size_t i = threads.size(); i < new_threads_count; ++i)
{ {
threads.push_back(Ptr<WorkerThread>(new WorkerThread(*this, (unsigned)i))); // spawn more threads threads.push_back(Ptr<WorkerThread>(new WorkerThread(*this, (unsigned)i))); // spawn more threads
@ -533,7 +536,7 @@ ThreadPool::~ThreadPool()
void ThreadPool::run(const Range& range, const ParallelLoopBody& body, double nstripes) void ThreadPool::run(const Range& range, const ParallelLoopBody& body, double nstripes)
{ {
CV_LOG_VERBOSE(NULL, 1, "MainThread: new parallel job: num_threads=" << num_threads << " range=" << range.size() << " nstripes=" << nstripes << " job=" << (void*)job); std::cout << "MainThread: new parallel job: num_threads=" << num_threads << " range=" << range.size() << " nstripes=" << nstripes << " job=" << (void*)job << std::endl;
#ifdef CV_PROFILE_THREADS #ifdef CV_PROFILE_THREADS
jobSubmitTime = getTickCount(); jobSubmitTime = getTickCount();
threads_stat[0].reset(); threads_stat[0].reset();
@ -555,11 +558,11 @@ void ThreadPool::run(const Range& range, const ParallelLoopBody& body, double ns
reconfigure_(num_threads - 1); reconfigure_(num_threads - 1);
{ {
CV_LOG_VERBOSE(NULL, 1, "MainThread: initialize parallel job: " << range.size()); std::cout << "MainThread: initialize parallel job: " << range.size() << std::endl;
job = Ptr<ParallelJob>(new ParallelJob(*this, range, body, nstripes)); job = Ptr<ParallelJob>(new ParallelJob(*this, range, body, nstripes));
pthread_mutex_unlock(&mutex); pthread_mutex_unlock(&mutex);
CV_LOG_VERBOSE(NULL, 5, "MainThread: wake worker threads..."); std::cout << "MainThread: wake worker threads..." << std::endl;
for (size_t i = 0; i < threads.size(); ++i) for (size_t i = 0; i < threads.size(); ++i)
{ {
WorkerThread& thread = *(threads[i].get()); WorkerThread& thread = *(threads[i].get());
@ -610,7 +613,7 @@ void ThreadPool::run(const Range& range, const ParallelLoopBody& body, double ns
#ifdef CV_PROFILE_THREADS #ifdef CV_PROFILE_THREADS
threads_stat[0].threadWake = getTickCount(); threads_stat[0].threadWake = getTickCount();
#endif #endif
CV_LOG_VERBOSE(NULL, 5, "MainThread: wake worker threads... (done)"); std::cout << "MainThread: wake worker threads... (done)" << std::endl;
{ {
ParallelJob& j = *(this->job); ParallelJob& j = *(this->job);
@ -622,11 +625,11 @@ void ThreadPool::run(const Range& range, const ParallelLoopBody& body, double ns
j.execute(false); j.execute(false);
#endif #endif
CV_Assert(j.current_task >= j.range.size()); CV_Assert(j.current_task >= j.range.size());
CV_LOG_VERBOSE(NULL, 5, "MainThread: complete self-tasks: " << j.active_thread_count << " " << j.completed_thread_count); std::cout << "MainThread: complete self-tasks: " << j.active_thread_count << " " << j.completed_thread_count << std::endl;
if (job->is_completed || j.active_thread_count == 0) if (job->is_completed || j.active_thread_count == 0)
{ {
job->is_completed = true; job->is_completed = true;
CV_LOG_VERBOSE(NULL, 5, "MainThread: no WIP worker threads"); std::cout << "MainThread: no WIP worker threads" << std::endl;
} }
else else
{ {
@ -636,7 +639,7 @@ void ThreadPool::run(const Range& range, const ParallelLoopBody& body, double ns
{ {
if (job->is_completed) if (job->is_completed)
{ {
CV_LOG_VERBOSE(NULL, 5, "MainThread: job finalize (active wait) " << j.active_thread_count << " " << j.completed_thread_count); std::cout << "MainThread: job finalize (active wait) " << j.active_thread_count << " " << j.completed_thread_count << std::endl;
break; break;
} }
if (CV_ACTIVE_WAIT_PAUSE_LIMIT > 0 && (i < CV_ACTIVE_WAIT_PAUSE_LIMIT || (i & 1))) if (CV_ACTIVE_WAIT_PAUSE_LIMIT > 0 && (i < CV_ACTIVE_WAIT_PAUSE_LIMIT || (i & 1)))
@ -647,18 +650,18 @@ void ThreadPool::run(const Range& range, const ParallelLoopBody& body, double ns
} }
if (!job->is_completed) if (!job->is_completed)
{ {
CV_LOG_VERBOSE(NULL, 5, "MainThread: prepare wait " << j.active_thread_count << " " << j.completed_thread_count); std::cout << "MainThread: prepare wait " << j.active_thread_count << " " << j.completed_thread_count << std::endl;
pthread_mutex_lock(&mutex_notify); pthread_mutex_lock(&mutex_notify);
for (;;) for (;;)
{ {
if (job->is_completed) if (job->is_completed)
{ {
CV_LOG_VERBOSE(NULL, 5, "MainThread: job finalize (wait) " << j.active_thread_count << " " << j.completed_thread_count); std::cout << "MainThread: job finalize (wait) " << j.active_thread_count << " " << j.completed_thread_count << std::endl;
break; break;
} }
CV_LOG_VERBOSE(NULL, 5, "MainThread: wait completion (sleep) ..."); std::cout << "MainThread: wait completion (sleep) ..." << std::endl;
pthread_cond_wait(&cond_thread_task_complete, &mutex_notify); pthread_cond_wait(&cond_thread_task_complete, &mutex_notify);
CV_LOG_VERBOSE(NULL, 5, "MainThread: wake"); std::cout << "MainThread: wake" << std::endl;
} }
pthread_mutex_unlock(&mutex_notify); pthread_mutex_unlock(&mutex_notify);
} }
@ -675,7 +678,7 @@ void ThreadPool::run(const Range& range, const ParallelLoopBody& body, double ns
if (job) if (job)
{ {
pthread_mutex_lock(&mutex); pthread_mutex_lock(&mutex);
CV_LOG_VERBOSE(NULL, 5, "MainThread: job release"); std::cout << "MainThread: job release" << std::endl;
CV_Assert(job->is_completed); CV_Assert(job->is_completed);
job.release(); job.release();
pthread_mutex_unlock(&mutex); pthread_mutex_unlock(&mutex);