diff options
Diffstat (limited to 'src/components/application_manager/src/request_controller.cc')
| -rw-r--r-- | src/components/application_manager/src/request_controller.cc | 238 |
1 files changed, 109 insertions, 129 deletions
diff --git a/src/components/application_manager/src/request_controller.cc b/src/components/application_manager/src/request_controller.cc index 1273abe513..d2db9fced2 100644 --- a/src/components/application_manager/src/request_controller.cc +++ b/src/components/application_manager/src/request_controller.cc @@ -44,7 +44,7 @@ namespace request_controller { using namespace sync_primitives; -CREATE_LOGGERPTR_GLOBAL(logger_, "RequestController") +SDL_CREATE_LOG_VARIABLE("RequestController") RequestController::RequestController(const RequestControlerSettings& settings) : pool_state_(UNDEFINED) @@ -57,13 +57,13 @@ RequestController::RequestController(const RequestControlerSettings& settings) , timer_stop_flag_(false) , is_low_voltage_(false) , settings_(settings) { - LOG4CXX_AUTO_TRACE(logger_); + SDL_LOG_AUTO_TRACE(); InitializeThreadpool(); timer_.Start(0, timer::kSingleShot); } RequestController::~RequestController() { - LOG4CXX_AUTO_TRACE(logger_); + SDL_LOG_AUTO_TRACE(); { sync_primitives::AutoLock auto_lock(timer_lock); timer_stop_flag_ = true; @@ -76,7 +76,7 @@ RequestController::~RequestController() { } void RequestController::InitializeThreadpool() { - LOG4CXX_AUTO_TRACE(logger_); + SDL_LOG_AUTO_TRACE(); // TODO(DK): Consider lazy loading threads instead of creating all at once pool_state_ = TPoolState::STARTED; char name[50]; @@ -84,16 +84,16 @@ void RequestController::InitializeThreadpool() { snprintf(name, sizeof(name) / sizeof(name[0]), "AM Pool %d", i); pool_.push_back(threads::CreateThread(name, new Worker(this))); pool_[i]->Start(); - LOG4CXX_DEBUG(logger_, "Request thread initialized: " << name); + SDL_LOG_DEBUG("Request thread initialized: " << name); } } void RequestController::DestroyThreadpool() { - LOG4CXX_AUTO_TRACE(logger_); + SDL_LOG_AUTO_TRACE(); { AutoLock auto_lock(mobile_request_list_lock_); pool_state_ = TPoolState::STOPPED; - LOG4CXX_DEBUG(logger_, "Broadcasting STOP signal to all threads..."); + SDL_LOG_DEBUG("Broadcasting STOP signal to all threads..."); cond_var_.Broadcast(); // notify all threads we are shutting down } for (size_t i = 0; i < pool_.size(); i++) { @@ -107,9 +107,9 @@ void RequestController::DestroyThreadpool() { RequestController::TResult RequestController::CheckPosibilitytoAdd( const RequestPtr request, const mobile_apis::HMILevel::eType level) { - LOG4CXX_AUTO_TRACE(logger_); + SDL_LOG_AUTO_TRACE(); if (!CheckPendingRequestsAmount(settings_.pending_requests_amount())) { - LOG4CXX_ERROR(logger_, "Too many pending request"); + SDL_LOG_ERROR("Too many pending request"); return RequestController::TOO_MANY_PENDING_REQUESTS; } @@ -117,18 +117,17 @@ RequestController::TResult RequestController::CheckPosibilitytoAdd( request_tracker_.Track(request->connection_key(), level); if (TrackResult::kNoneLevelMaxRequestsExceeded == track_result) { - LOG4CXX_ERROR(logger_, "Too many application requests in hmi level NONE"); + SDL_LOG_ERROR("Too many application requests in hmi level NONE"); return RequestController::NONE_HMI_LEVEL_MANY_REQUESTS; } if (TrackResult::kMaxRequestsExceeded == track_result) { - LOG4CXX_ERROR(logger_, "Too many application requests"); + SDL_LOG_ERROR("Too many application requests"); return RequestController::TOO_MANY_REQUESTS; } if (IsLowVoltage()) { - LOG4CXX_ERROR(logger_, - "Impossible to add request due to Low Voltage is active"); + SDL_LOG_ERROR("Impossible to add request due to Low Voltage is active"); return RequestController::INVALID_DATA; } @@ -137,41 +136,38 @@ RequestController::TResult RequestController::CheckPosibilitytoAdd( bool RequestController::CheckPendingRequestsAmount( const uint32_t& pending_requests_amount) { - LOG4CXX_AUTO_TRACE(logger_); + SDL_LOG_AUTO_TRACE(); if (pending_requests_amount > 0) { const size_t pending_requests_size = mobile_request_list_.size(); const bool available_to_add = pending_requests_amount > pending_requests_size; if (!available_to_add) { - LOG4CXX_WARN(logger_, - "Pending requests count " << pending_requests_size + SDL_LOG_WARN("Pending requests count " << pending_requests_size << " exceed application limit " << pending_requests_amount); } return available_to_add; } - LOG4CXX_DEBUG(logger_, "CheckPendingRequestsAmount disabled"); + SDL_LOG_DEBUG("CheckPendingRequestsAmount disabled"); return true; } RequestController::TResult RequestController::addMobileRequest( const RequestPtr request, const mobile_apis::HMILevel::eType& hmi_level) { - LOG4CXX_AUTO_TRACE(logger_); + SDL_LOG_AUTO_TRACE(); if (!request) { - LOG4CXX_ERROR(logger_, "Null Pointer request"); + SDL_LOG_ERROR("Null Pointer request"); cond_var_.NotifyOne(); return INVALID_DATA; } - LOG4CXX_DEBUG( - logger_, - "correlation_id : " << request->correlation_id() - << "connection_key : " << request->connection_key()); + SDL_LOG_DEBUG("correlation_id : " << request->correlation_id() + << "connection_key : " + << request->connection_key()); RequestController::TResult result = CheckPosibilitytoAdd(request, hmi_level); if (SUCCESS == result) { AutoLock auto_lock_list(mobile_request_list_lock_); mobile_request_list_.push_back(request); - LOG4CXX_DEBUG(logger_, - "Waiting for execution: " << mobile_request_list_.size()); + SDL_LOG_DEBUG("Waiting for execution: " << mobile_request_list_.size()); // wake up one thread that is waiting for a task to be available } cond_var_.NotifyOne(); @@ -180,13 +176,13 @@ RequestController::TResult RequestController::addMobileRequest( RequestController::TResult RequestController::addHMIRequest( const RequestPtr request) { - LOG4CXX_AUTO_TRACE(logger_); + SDL_LOG_AUTO_TRACE(); if (request.use_count() == 0) { - LOG4CXX_ERROR(logger_, "HMI request pointer is invalid"); + SDL_LOG_ERROR("HMI request pointer is invalid"); return RequestController::INVALID_DATA; } - LOG4CXX_DEBUG(logger_, " correlation_id : " << request->correlation_id()); + SDL_LOG_DEBUG(" correlation_id : " << request->correlation_id()); const uint64_t timeout_in_mseconds = static_cast<uint64_t>(request->default_timeout()); @@ -194,30 +190,28 @@ RequestController::TResult RequestController::addHMIRequest( std::make_shared<HMIRequestInfo>(request, timeout_in_mseconds); if (0 == timeout_in_mseconds) { - LOG4CXX_DEBUG(logger_, - "Default timeout was set to 0." - "RequestController will not track timeout of this request."); + SDL_LOG_DEBUG( + "Default timeout was set to 0." + "RequestController will not track timeout of this request."); } if (IsLowVoltage()) { - LOG4CXX_ERROR(logger_, - "Impossible to add request due to Low Voltage is active"); + SDL_LOG_ERROR("Impossible to add request due to Low Voltage is active"); return RequestController::INVALID_DATA; } waiting_for_response_.Add(request_info_ptr); - LOG4CXX_DEBUG(logger_, - "Waiting for response count:" << waiting_for_response_.Size()); + SDL_LOG_DEBUG("Waiting for response count:" << waiting_for_response_.Size()); NotifyTimer(); return RequestController::SUCCESS; } void RequestController::addNotification(const RequestPtr ptr) { - LOG4CXX_AUTO_TRACE(logger_); + SDL_LOG_AUTO_TRACE(); if (IsLowVoltage()) { - LOG4CXX_ERROR( - logger_, "Impossible to add notification due to Low Voltage is active"); + SDL_LOG_ERROR( + "Impossible to add notification due to Low Voltage is active"); return; } notification_list_.push_back(ptr); @@ -225,30 +219,29 @@ void RequestController::addNotification(const RequestPtr ptr) { void RequestController::removeNotification( const commands::Command* notification) { - LOG4CXX_AUTO_TRACE(logger_); + SDL_LOG_AUTO_TRACE(); std::list<RequestPtr>::iterator it = notification_list_.begin(); for (; notification_list_.end() != it;) { if (it->get() == notification) { notification_list_.erase(it++); - LOG4CXX_DEBUG(logger_, "Notification removed"); + SDL_LOG_DEBUG("Notification removed"); return; } else { ++it; } } - LOG4CXX_DEBUG(logger_, "Cannot find notification"); + SDL_LOG_DEBUG("Cannot find notification"); } void RequestController::TerminateRequest(const uint32_t correlation_id, const uint32_t connection_key, const int32_t function_id, bool force_terminate) { - LOG4CXX_AUTO_TRACE(logger_); - LOG4CXX_DEBUG(logger_, - "correlation_id = " - << correlation_id << " connection_key = " << connection_key - << " function_id = " << function_id - << " force_terminate = " << force_terminate); + SDL_LOG_AUTO_TRACE(); + SDL_LOG_DEBUG("correlation_id = " + << correlation_id << " connection_key = " << connection_key + << " function_id = " << function_id + << " force_terminate = " << force_terminate); { AutoLock auto_lock(duplicate_message_count_lock_); auto dup_it = duplicate_message_count_.find(correlation_id); @@ -257,9 +250,9 @@ void RequestController::TerminateRequest(const uint32_t correlation_id, if (0 == duplicate_message_count_[correlation_id]) { duplicate_message_count_.erase(dup_it); } - LOG4CXX_DEBUG(logger_, - "Ignoring termination request due to duplicate correlation " - "ID being sent"); + SDL_LOG_DEBUG( + "Ignoring termination request due to duplicate correlation " + "ID being sent"); return; } } @@ -267,17 +260,17 @@ void RequestController::TerminateRequest(const uint32_t correlation_id, RequestInfoPtr request = waiting_for_response_.Find(connection_key, correlation_id); if (!request) { - LOG4CXX_WARN(logger_, "Request was not found in waiting_for_response"); + SDL_LOG_WARN("Request was not found in waiting_for_response"); return; } if (request->request()->function_id() != function_id) { - LOG4CXX_ERROR(logger_, "Request and response function_id's don't match"); + SDL_LOG_ERROR("Request and response function_id's don't match"); return; } if (force_terminate || request->request()->AllowedToTerminate()) { waiting_for_response_.RemoveRequest(request); } else { - LOG4CXX_WARN(logger_, "Request was not terminated"); + SDL_LOG_WARN("Request was not terminated"); } NotifyTimer(); } @@ -285,21 +278,20 @@ void RequestController::TerminateRequest(const uint32_t correlation_id, void RequestController::OnMobileResponse(const uint32_t mobile_correlation_id, const uint32_t connection_key, const int32_t function_id) { - LOG4CXX_AUTO_TRACE(logger_); + SDL_LOG_AUTO_TRACE(); TerminateRequest(mobile_correlation_id, connection_key, function_id); } void RequestController::OnHMIResponse(const uint32_t correlation_id, const int32_t function_id) { - LOG4CXX_AUTO_TRACE(logger_); + SDL_LOG_AUTO_TRACE(); TerminateRequest(correlation_id, RequestInfo::HmiConnectionKey, function_id); } void RequestController::terminateWaitingForExecutionAppRequests( const uint32_t& app_id) { - LOG4CXX_AUTO_TRACE(logger_); - LOG4CXX_DEBUG(logger_, - "app_id: " << app_id << "Waiting for execution" + SDL_LOG_AUTO_TRACE(); + SDL_LOG_DEBUG("app_id: " << app_id << "Waiting for execution" << mobile_request_list_.size()); AutoLock auto_lock(mobile_request_list_lock_); std::list<RequestPtr>::iterator request_it = mobile_request_list_.begin(); @@ -311,22 +303,20 @@ void RequestController::terminateWaitingForExecutionAppRequests( ++request_it; } } - LOG4CXX_DEBUG(logger_, - "Waiting for execution " << mobile_request_list_.size()); + SDL_LOG_DEBUG("Waiting for execution " << mobile_request_list_.size()); } void RequestController::terminateWaitingForResponseAppRequests( const uint32_t& app_id) { - LOG4CXX_AUTO_TRACE(logger_); + SDL_LOG_AUTO_TRACE(); waiting_for_response_.RemoveByConnectionKey(app_id); - LOG4CXX_DEBUG( - logger_, "Waiting for response count : " << waiting_for_response_.Size()); + SDL_LOG_DEBUG( + "Waiting for response count : " << waiting_for_response_.Size()); } void RequestController::terminateAppRequests(const uint32_t& app_id) { - LOG4CXX_AUTO_TRACE(logger_); - LOG4CXX_DEBUG(logger_, - "app_id : " << app_id + SDL_LOG_AUTO_TRACE(); + SDL_LOG_DEBUG("app_id : " << app_id << "Requests waiting for execution count : " << mobile_request_list_.size() << "Requests waiting for response count : " @@ -338,32 +328,31 @@ void RequestController::terminateAppRequests(const uint32_t& app_id) { } void RequestController::terminateAllHMIRequests() { - LOG4CXX_AUTO_TRACE(logger_); + SDL_LOG_AUTO_TRACE(); terminateWaitingForResponseAppRequests(RequestInfo::HmiConnectionKey); } void RequestController::terminateAllMobileRequests() { - LOG4CXX_AUTO_TRACE(logger_); + SDL_LOG_AUTO_TRACE(); waiting_for_response_.RemoveMobileRequests(); - LOG4CXX_DEBUG(logger_, "Mobile Requests waiting for response cleared"); + SDL_LOG_DEBUG("Mobile Requests waiting for response cleared"); AutoLock waiting_execution_auto_lock(mobile_request_list_lock_); mobile_request_list_.clear(); - LOG4CXX_DEBUG(logger_, "Mobile Requests waiting for execution cleared"); + SDL_LOG_DEBUG("Mobile Requests waiting for execution cleared"); NotifyTimer(); } void RequestController::updateRequestTimeout(const uint32_t& app_id, const uint32_t& correlation_id, const uint32_t& new_timeout) { - LOG4CXX_AUTO_TRACE(logger_); + SDL_LOG_AUTO_TRACE(); - LOG4CXX_DEBUG(logger_, - "app_id : " << app_id + SDL_LOG_DEBUG("app_id : " << app_id << " mobile_correlation_id : " << correlation_id << " new_timeout : " << new_timeout); - LOG4CXX_DEBUG(logger_, - "New_timeout is NULL. RequestCtrl will " - "not manage this request any more"); + SDL_LOG_DEBUG( + "New_timeout is NULL. RequestCtrl will " + "not manage this request any more"); RequestInfoPtr request_info = waiting_for_response_.Find(app_id, correlation_id); @@ -372,40 +361,37 @@ void RequestController::updateRequestTimeout(const uint32_t& app_id, request_info->updateTimeOut(new_timeout); waiting_for_response_.Add(request_info); NotifyTimer(); - LOG4CXX_INFO(logger_, - "Timeout updated for " - << " app_id: " << app_id << " correlation_id: " - << correlation_id << " new_timeout (ms): " << new_timeout); + SDL_LOG_INFO("Timeout updated for " + << " app_id: " << app_id << " correlation_id: " + << correlation_id << " new_timeout (ms): " << new_timeout); } else { - LOG4CXX_ERROR(logger_, - "Can't find request with " - << " app_id: " << app_id - << " correlation_id: " << correlation_id); + SDL_LOG_ERROR("Can't find request with " + << " app_id: " << app_id + << " correlation_id: " << correlation_id); } } void RequestController::OnLowVoltage() { - LOG4CXX_AUTO_TRACE(logger_); + SDL_LOG_AUTO_TRACE(); is_low_voltage_ = true; } void RequestController::OnWakeUp() { - LOG4CXX_AUTO_TRACE(logger_); + SDL_LOG_AUTO_TRACE(); terminateAllHMIRequests(); terminateAllMobileRequests(); is_low_voltage_ = false; - LOG4CXX_DEBUG(logger_, "Terminate old requests done"); + SDL_LOG_DEBUG("Terminate old requests done"); } bool RequestController::IsLowVoltage() { - LOG4CXX_TRACE(logger_, "result: " << is_low_voltage_); + SDL_LOG_TRACE("result: " << is_low_voltage_); return is_low_voltage_; } void RequestController::TimeoutThread() { - LOG4CXX_AUTO_TRACE(logger_); - LOG4CXX_DEBUG( - logger_, + SDL_LOG_AUTO_TRACE(); + SDL_LOG_DEBUG( "ENTER Waiting fore response count: " << waiting_for_response_.Size()); sync_primitives::AutoLock auto_lock(timer_lock); while (!timer_stop_flag_) { @@ -416,54 +402,49 @@ void RequestController::TimeoutThread() { continue; } if (!probably_expired->isExpired()) { - LOG4CXX_DEBUG(logger_, - "Timeout for " - << (RequestInfo::HMIRequest == - probably_expired->request_type() - ? "HMI" - : "Mobile") - << " request id: " << probably_expired->requestId() - << " connection_key: " << probably_expired->app_id() - << " NOT expired"); + SDL_LOG_DEBUG("Timeout for " + << (RequestInfo::HMIRequest == + probably_expired->request_type() + ? "HMI" + : "Mobile") + << " request id: " << probably_expired->requestId() + << " connection_key: " << probably_expired->app_id() + << " NOT expired"); const date_time::TimeDuration current_time = date_time::getCurrentTime(); const date_time::TimeDuration end_time = probably_expired->end_time(); if (current_time < end_time) { const uint32_t msecs = static_cast<uint32_t>(date_time::getmSecs(end_time - current_time)); - LOG4CXX_DEBUG(logger_, "Sleep for " << msecs << " millisecs"); + SDL_LOG_DEBUG("Sleep for " << msecs << " millisecs"); timer_condition_.WaitFor(auto_lock, msecs); } continue; } - LOG4CXX_INFO(logger_, - "Timeout for " - << (RequestInfo::HMIRequest == - probably_expired->request_type() - ? "HMI" - : "Mobile") - << " request id: " << probably_expired->requestId() - << " connection_key: " << probably_expired->app_id() - << " is expired"); + SDL_LOG_INFO("Timeout for " + << (RequestInfo::HMIRequest == probably_expired->request_type() + ? "HMI" + : "Mobile") + << " request id: " << probably_expired->requestId() + << " connection_key: " << probably_expired->app_id() + << " is expired"); const uint32_t experied_request_id = probably_expired->requestId(); const uint32_t experied_app_id = probably_expired->app_id(); probably_expired->request()->onTimeOut(); if (RequestInfo::HmiConnectionKey == probably_expired->app_id()) { - LOG4CXX_DEBUG(logger_, - "Erase HMI request: " << probably_expired->requestId()); + SDL_LOG_DEBUG("Erase HMI request: " << probably_expired->requestId()); waiting_for_response_.RemoveRequest(probably_expired); } probably_expired = waiting_for_response_.FrontWithNotNullTimeout(); if (probably_expired) { if (experied_request_id == probably_expired->requestId() && experied_app_id == probably_expired->app_id()) { - LOG4CXX_DEBUG(logger_, "Expired request wasn't removed"); + SDL_LOG_DEBUG("Expired request wasn't removed"); break; } } } - LOG4CXX_DEBUG( - logger_, + SDL_LOG_DEBUG( "EXIT Waiting for response count : " << waiting_for_response_.Size()); } @@ -473,7 +454,7 @@ RequestController::Worker::Worker(RequestController* requestController) RequestController::Worker::~Worker() {} void RequestController::Worker::threadMain() { - LOG4CXX_AUTO_TRACE(logger_); + SDL_LOG_AUTO_TRACE(); AutoLock auto_lock(thread_lock_); while (!stop_flag_) { // Try to pick a request @@ -483,9 +464,9 @@ void RequestController::Worker::threadMain() { (request_controller_->mobile_request_list_.empty())) { // Wait until there is a task in the queue // Unlock mutex while wait, then lock it back when signaled - LOG4CXX_INFO(logger_, "Unlocking and waiting"); + SDL_LOG_INFO("Unlocking and waiting"); request_controller_->cond_var_.Wait(auto_lock); - LOG4CXX_INFO(logger_, "Signaled and locking"); + SDL_LOG_INFO("Signaled and locking"); } // If the thread was shutdown, return from here @@ -494,7 +475,7 @@ void RequestController::Worker::threadMain() { } if (request_controller_->mobile_request_list_.empty()) { - LOG4CXX_WARN(logger_, "Mobile request list is empty"); + SDL_LOG_WARN("Mobile request list is empty"); break; } @@ -526,15 +507,15 @@ void RequestController::Worker::threadMain() { } continue; } - LOG4CXX_DEBUG(logger_, "timeout_in_mseconds " << timeout_in_mseconds); + SDL_LOG_DEBUG("timeout_in_mseconds " << timeout_in_mseconds); if (0 != timeout_in_mseconds) { request_controller_->NotifyTimer(); } else { - LOG4CXX_DEBUG(logger_, - "Default timeout was set to 0. " - "RequestController will not track timeout " - "of this request."); + SDL_LOG_DEBUG( + "Default timeout was set to 0. " + "RequestController will not track timeout " + "of this request."); } AutoUnlock unlock(auto_lock); @@ -542,10 +523,9 @@ void RequestController::Worker::threadMain() { // execute if ((false == request_controller_->IsLowVoltage()) && request_ptr->CheckPermissions() && init_res) { - LOG4CXX_DEBUG(logger_, - "Execute MobileRequest corr_id = " - << request_info_ptr->requestId() - << " with timeout: " << timeout_in_mseconds); + SDL_LOG_DEBUG("Execute MobileRequest corr_id = " + << request_info_ptr->requestId() + << " with timeout: " << timeout_in_mseconds); request_ptr->Run(); } } @@ -558,7 +538,7 @@ void RequestController::Worker::exitThreadMain() { } void RequestController::NotifyTimer() { - LOG4CXX_AUTO_TRACE(logger_); + SDL_LOG_AUTO_TRACE(); timer_condition_.NotifyOne(); } |