From 4807266ebc176c5aa3434c8f8297ed2b31159194 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Carlos=20Mart=C3=ADn?= Date: Tue, 21 Apr 2015 18:21:31 +0200 Subject: [PATCH] Feature #3737: Use DDEBUG and DDDEBUG log levels in the scheduler --- src/log/Log.cc | 2 +- src/scheduler/etc/sched.conf | 10 ++- src/scheduler/src/pool/HostPoolXML.cc | 24 +++---- .../src/pool/VirtualMachinePoolXML.cc | 64 ++++++++++--------- src/scheduler/src/sched/Scheduler.cc | 53 ++++++++------- 5 files changed, 88 insertions(+), 65 deletions(-) diff --git a/src/log/Log.cc b/src/log/Log.cc index af59acea20..d9fcc10ecc 100644 --- a/src/log/Log.cc +++ b/src/log/Log.cc @@ -40,7 +40,7 @@ /* -------------------------------------------------------------------------- */ /* -------------------------------------------------------------------------- */ -const char Log::error_names[] ={ 'E', 'W', 'I', 'D' }; +const char Log::error_names[] ={ 'E', 'W', 'I', 'D', 'D', 'D' }; unsigned int Log::zone_id = 0; diff --git a/src/scheduler/etc/sched.conf b/src/scheduler/etc/sched.conf index a0770977f7..ac3d24fab2 100644 --- a/src/scheduler/etc/sched.conf +++ b/src/scheduler/etc/sched.conf @@ -53,7 +53,15 @@ # - system: defines the logging system: # file to log in the sched.log file # syslog to use the syslog facilities -# - debug_level: 0 = ERROR, 1 = WARNING, 2 = INFO, 3 = DEBUG +# - debug_level: +# 0 = ERROR +# 1 = WARNING +# 2 = INFO +# 3 = DEBUG Includes general scheduling information (default) +# 4 = DDEBUG Includes time taken for each step +# 5 = DDDEBUG Includes detailed information about the scheduling +# decision, such as VM requirements, Host ranking for +# each VM, etc. This will impact the performance #******************************************************************************* MESSAGE_SIZE = 1073741824 diff --git a/src/scheduler/src/pool/HostPoolXML.cc b/src/scheduler/src/pool/HostPoolXML.cc index 73e32d19bc..df026290ea 100644 --- a/src/scheduler/src/pool/HostPoolXML.cc +++ b/src/scheduler/src/pool/HostPoolXML.cc @@ -25,19 +25,21 @@ int HostPoolXML::set_up() if ( rc == 0 ) { - -#ifdef SCHEDDEBUG - oss << "Discovered Hosts (enabled):" << endl; - - map::iterator it; - - for (it=objects.begin();it!=objects.end();it++) + if (NebulaLog::log_level() >= Log::DDDEBUG) { - oss << " " << it->first; + oss << "Discovered Hosts (enabled):" << endl; + + map::iterator it; + + for (it=objects.begin();it!=objects.end();it++) + { + oss << " " << it->first; + } + } + else + { + oss << "Discovered " << objects.size() << " enabled hosts."; } -#else - oss << "Discovered " << objects.size() << " enabled hosts."; -#endif NebulaLog::log("HOST",Log::DEBUG,oss); } diff --git a/src/scheduler/src/pool/VirtualMachinePoolXML.cc b/src/scheduler/src/pool/VirtualMachinePoolXML.cc index e6a0f63243..083f5757f3 100644 --- a/src/scheduler/src/pool/VirtualMachinePoolXML.cc +++ b/src/scheduler/src/pool/VirtualMachinePoolXML.cc @@ -31,42 +31,46 @@ int VirtualMachinePoolXML::set_up() return -2; } -#ifdef SCHEDDEBUG - oss << "Pending/rescheduling VM and capacity requirements:" << endl; - - oss << right << setw(8) << "VM" << " " - << right << setw(4) << "CPU" << " " - << right << setw(11) << "Memory" << " " - << right << setw(11) << "System DS" << " " - << " Image DS" - << endl << setw(60) << setfill('-') << "-" << setfill(' '); - - for (map::iterator it=objects.begin();it!=objects.end();it++) + if (NebulaLog::log_level() >= Log::DDDEBUG) { - int cpu, mem; - long long disk; + oss << "Pending/rescheduling VM and capacity requirements:" << endl; - VirtualMachineXML * vm = static_cast(it->second); + oss << right << setw(8) << "VM" << " " + << right << setw(4) << "CPU" << " " + << right << setw(11) << "Memory" << " " + << right << setw(11) << "System DS" << " " + << " Image DS" + << endl << setw(60) << setfill('-') << "-" << setfill(' '); - vm->get_requirements(cpu, mem, disk); - - oss << endl - << right << setw(8) << it->first << " " - << right << setw(4) << cpu << " " - << right << setw(11) << mem << " " - << right << setw(11) << disk << " "; - - map ds_usage = vm->get_storage_usage(); - - for (map::const_iterator ds_it = ds_usage.begin(); - ds_it != ds_usage.end(); ds_it++) + for (map::iterator it=objects.begin();it!=objects.end();it++) { - oss << " DS " << ds_it->first << ": " << ds_it->second << " "; + int cpu, mem; + long long disk; + + VirtualMachineXML * vm = static_cast(it->second); + + vm->get_requirements(cpu, mem, disk); + + oss << endl + << right << setw(8) << it->first << " " + << right << setw(4) << cpu << " " + << right << setw(11) << mem << " " + << right << setw(11) << disk << " "; + + map ds_usage = vm->get_storage_usage(); + + for (map::const_iterator ds_it = ds_usage.begin(); + ds_it != ds_usage.end(); ds_it++) + { + oss << " DS " << ds_it->first << ": " << ds_it->second << " "; + } } } -#else - oss << "Found " << objects.size() << " pending/rescheduling VMs."; -#endif + else + { + oss << "Found " << objects.size() << " pending/rescheduling VMs."; + } + NebulaLog::log("VM",Log::DEBUG,oss); } diff --git a/src/scheduler/src/sched/Scheduler.cc b/src/scheduler/src/sched/Scheduler.cc index f718df25b5..24ad5c6337 100644 --- a/src/scheduler/src/sched/Scheduler.cc +++ b/src/scheduler/src/sched/Scheduler.cc @@ -51,7 +51,7 @@ static double profile(bool start, const string& message="") if (!message.empty()) { - NebulaLog::log("SCHED", Log::INFO, message); + NebulaLog::log("SCHED", Log::DDEBUG, message); } return 0; @@ -66,8 +66,8 @@ static double profile(bool start, const string& message="") { ostringstream oss; - oss << message << " Total time: " << t << "s"; - NebulaLog::log("SCHED", Log::INFO, oss); + oss << message << " Total time: " << one_util::float_to_str(t) << "s"; + NebulaLog::log("SCHED", Log::DDEBUG, oss); } return t; @@ -186,7 +186,7 @@ void Scheduler::start() value = log->vector_value("DEBUG_LEVEL"); ilevel = atoi(value.c_str()); - if (0 <= ilevel && ilevel <= 3 ) + if (Log::ERROR <= ilevel && ilevel <= Log::DDDEBUG) { clevel = static_cast(ilevel); } @@ -955,28 +955,29 @@ void Scheduler::match_schedule() ostringstream oss; oss << "Match Making statistics:\n" - << "\tNumber of VMs: " << pending_vms.size() << endl - << "\tTotal time: " << time(0) - stime << "s" << endl - << "\tTotal Match time: " << total_match_time << "s" << endl - << "\tTotal Ranking Time: " << total_rank_time << "s"; + << "\tNumber of VMs: \t\t" << pending_vms.size() << endl + << "\tTotal time: \t\t" << one_util::float_to_str(time(0) - stime) << "s" << endl + << "\tTotal Match time: \t" << one_util::float_to_str(total_match_time) << "s" << endl + << "\tTotal Ranking time: \t" << one_util::float_to_str(total_rank_time) << "s"; - NebulaLog::log("SCHED", Log::DEBUG, oss); + NebulaLog::log("SCHED", Log::DDEBUG, oss); -#ifdef SCHEDDEBUG - ostringstream oss; - - oss << "Scheduling Results:" << endl; - - for (map::const_iterator vm_it=pending_vms.begin(); - vm_it != pending_vms.end(); vm_it++) + if (NebulaLog::log_level() >= Log::DDDEBUG) { - vm = static_cast(vm_it->second); + ostringstream oss; - oss << *vm; + oss << "Scheduling Results:" << endl; + + for (map::const_iterator vm_it=pending_vms.begin(); + vm_it != pending_vms.end(); vm_it++) + { + vm = static_cast(vm_it->second); + + oss << *vm; + } + + NebulaLog::log("SCHED", Log::DDDEBUG, oss); } - - NebulaLog::log("SCHED", Log::DEBUG, oss); -#endif } /* -------------------------------------------------------------------------- */ @@ -1000,6 +1001,8 @@ void Scheduler::dispatch() map host_vms; pair::iterator, bool> rc; + map::const_iterator vm_it; + vector::const_reverse_iterator i, j; const map pending_vms = vmpool->get_objects(); @@ -1011,7 +1014,7 @@ void Scheduler::dispatch() // Dispatch each VM till we reach the dispatch limit //-------------------------------------------------------------------------- - for (map::const_iterator vm_it=pending_vms.begin(); + for (vm_it = pending_vms.begin(); vm_it != pending_vms.end() && ( dispatch_limit <= 0 || dispatched_vms < dispatch_limit ); vm_it++) @@ -1185,6 +1188,12 @@ void Scheduler::dispatch() } } + if (vm_it != pending_vms.end()) + { + dss << endl << "MAX_DISPATCH limit of " << dispatch_limit << " reached, " + << std::distance(vm_it, pending_vms.end()) << " VMs were not dispatched"; + } + NebulaLog::log("SCHED", Log::DEBUG, dss); }