From a6da437c5cf74c6fb598d42f23a33fca400c04aa Mon Sep 17 00:00:00 2001
From: Rom Walton <romw@romwnet.org>
Date: Fri, 6 Dec 2013 12:05:11 -0500
Subject: [PATCH] VBOX: Do not log about missing snapshots during cleanup VBOX:
Only log about relevant settings during a status report VBOX: County an empty
output response in is_system_ready() query as a failure.
---
samples/vboxwrapper/vbox.cpp | 195 +++++++++++++++-------------
samples/vboxwrapper/vbox.h | 11 +-
samples/vboxwrapper/vboxwrapper.cpp | 135 ++++++++++---------
win_build/vboxwrapper.vcxproj | 8 +-
4 files changed, 192 insertions(+), 157 deletions(-)
diff --git a/samples/vboxwrapper/vbox.cpp b/samples/vboxwrapper/vbox.cpp
index f1e482e024..707db448e9 100644
--- a/samples/vboxwrapper/vbox.cpp
+++ b/samples/vboxwrapper/vbox.cpp
@@ -199,10 +199,6 @@ int VBOX_VM::initialize() {
vboxwrapper_msg_prefix(buf, sizeof(buf))
);
}
-
- // Launch vboxsvc before any vboxmanage command can be executed.
- launch_vboxsvc();
-
#else
// putenv does not copy its input buffer, so we must use setenv
if (setenv("VBOX_USER_HOME", const_cast<char*>(virtualbox_home_directory.c_str()), 1)) {
@@ -407,9 +403,10 @@ int VBOX_VM::register_vm() {
fprintf(
stderr,
- "%s Registering VM. (%s) \n",
+ "%s Registering VM. (%s, slot#%d) \n",
vboxwrapper_msg_prefix(buf, sizeof(buf)),
- vm_name.c_str()
+ vm_name.c_str(),
+ aid.slot
);
@@ -1046,18 +1043,20 @@ int VBOX_VM::start() {
command += " --type headless";
}
retval = vbm_popen(command, output, "start VM", true, false, 0);
- if (retval) return retval;
// Wait for up to 5 minutes for the VM to switch states. A system
// under load can take a while. Since the poll function can wait for up
// to 45 seconds to execute a command we need to make this time based instead
// of interation based.
- timeout = dtime() + 300;
- do {
- poll(false);
- if (online) break;
- boinc_sleep(1.0);
- } while (timeout >= dtime());
+ if (!retval) {
+ timeout = dtime() + 300;
+ do {
+ poll(false);
+ if (online) break;
+ boinc_sleep(1.0);
+ } while (timeout >= dtime());
+ if (timeout <= dtime()) retval = ERR_TIMEOUT;
+ }
if (online) {
fprintf(
@@ -1066,10 +1065,16 @@ int VBOX_VM::start() {
vboxwrapper_msg_prefix(buf, sizeof(buf))
);
retval = BOINC_SUCCESS;
+ } else if (ERR_TIMEOUT == retval) {
+ fprintf(
+ stderr,
+ "%s VM did not start within 5 minutes.\n",
+ vboxwrapper_msg_prefix(buf, sizeof(buf))
+ );
} else {
fprintf(
stderr,
- "%s VM did not start within 5 minutes, aborting job.\n",
+ "%s VM failed to start.\n",
vboxwrapper_msg_prefix(buf, sizeof(buf))
);
retval = ERR_EXEC;
@@ -1246,7 +1251,10 @@ int VBOX_VM::cleanupsnapshots(bool delete_active) {
// Enumerate snapshot(s)
command = "snapshot \"" + vm_name + "\" ";
command += "list ";
- retval = vbm_popen(command, output, "enumerate snapshot(s)");
+
+ // Only log the error if we are not attempting to deregister the VM.
+ // delete_active is only set to true when we are deregistering the VM.
+ retval = vbm_popen(command, output, "enumerate snapshot(s)", !delete_active, false, 0);
if (retval) return retval;
// Output should look a little like this:
@@ -1284,7 +1292,9 @@ int VBOX_VM::cleanupsnapshots(bool delete_active) {
command += uuid;
command += "\" ";
- vbm_popen(command, output, "delete stale snapshot", true, false, 0);
+ // Only log the error if we are not attempting to deregister the VM.
+ // delete_active is only set to true when we are deregistering the VM.
+ vbm_popen(command, output, "delete stale snapshot", !delete_active, false, 0);
}
eol_prev_pos = eol_pos + 1;
@@ -1364,21 +1374,28 @@ void VBOX_VM::dumphypervisorlogs() {
bool VBOX_VM::is_system_ready(std::string& message) {
string command;
string output;
- bool rc = true;
+ int retval;
+ bool rc = false;
command = "list hostinfo ";
- if (vbm_popen(command, output, "host info") == 0) {
+ retval = vbm_popen(command, output, "host info");
+ if (BOINC_SUCCESS == retval) {
+ rc = true;
+ }
- if (output.find("Processor count:") == string::npos) {
- message = "Communication with VM Hypervisor failed.";
- rc = false;
- }
+ if (output.size() == 0) {
+ message = "Communication with VM Hypervisor failed. (Possibly Out of Memory).";
+ rc = false;
+ }
- if (output.find("WARNING: The vboxdrv kernel module is not loaded.") != string::npos) {
- message = "Please update/recompile VirtualBox kernel drivers.";
- rc = false;
- }
+ if (output.find("Processor count:") == string::npos) {
+ message = "Communication with VM Hypervisor failed.";
+ rc = false;
+ }
+ if (output.find("WARNING: The vboxdrv kernel module is not loaded.") != string::npos) {
+ message = "Please update/recompile VirtualBox kernel drivers.";
+ rc = false;
}
return rc;
@@ -1557,7 +1574,7 @@ int VBOX_VM::get_slot_directory(string& dir) {
return 0;
}
-int VBOX_VM::get_network_bytes_sent(double& sent) {
+int VBOX_VM::get_vm_network_bytes_sent(double& sent) {
string command;
string output;
string counter_value;
@@ -1592,7 +1609,7 @@ int VBOX_VM::get_network_bytes_sent(double& sent) {
return 0;
}
-int VBOX_VM::get_network_bytes_received(double& received) {
+int VBOX_VM::get_vm_network_bytes_received(double& received) {
string command;
string output;
string counter_value;
@@ -1628,65 +1645,6 @@ int VBOX_VM::get_network_bytes_received(double& received) {
return 0;
}
-int VBOX_VM::get_system_log(string& log) {
- string slot_directory;
- string virtualbox_system_log_src;
- string virtualbox_system_log_dst;
- string::iterator iter;
- char buf[256];
- int retval = 0;
-
- // Where should we copy temp files to?
- get_slot_directory(slot_directory);
-
- // Locate and read log file
- virtualbox_system_log_src = virtualbox_home_directory + "/VBoxSVC.log";
- virtualbox_system_log_dst = slot_directory + "/VBoxSVC.log";
-
- if (boinc_file_exists(virtualbox_system_log_src.c_str())) {
- // Skip having to deal with various forms of file locks by just making a temp
- // copy of the log file.
- boinc_copy(virtualbox_system_log_src.c_str(), virtualbox_system_log_dst.c_str());
-
- // Keep only the last 16k if it is larger than that.
- read_file_string(virtualbox_system_log_dst.c_str(), log, 16384, true);
-
-#ifdef _WIN32
- // Remove \r from the log spew
- iter = log.begin();
- while (iter != log.end()) {
- if (*iter == '\r') {
- iter = log.erase(iter);
- } else {
- ++iter;
- }
- }
-#endif
-
- if (log.size() >= 16384) {
- // Look for the next whole line of text.
- iter = log.begin();
- while (iter != log.end()) {
- if (*iter == '\n') {
- log.erase(iter);
- break;
- }
- iter = log.erase(iter);
- }
- }
- } else {
- fprintf(
- stderr,
- "%s Could not find the Hypervisor System Log at '%s'.\n",
- vboxwrapper_msg_prefix(buf, sizeof(buf)),
- virtualbox_system_log_src.c_str()
- );
- retval = ERR_NOT_FOUND;
- }
-
- return retval;
-}
-
int VBOX_VM::get_vm_process_id(int& process_id) {
string command;
string output;
@@ -1822,6 +1780,65 @@ int VBOX_VM::get_remote_desktop_port() {
return 0;
}
+int VBOX_VM::get_system_log(string& log) {
+ string slot_directory;
+ string virtualbox_system_log_src;
+ string virtualbox_system_log_dst;
+ string::iterator iter;
+ char buf[256];
+ int retval = 0;
+
+ // Where should we copy temp files to?
+ get_slot_directory(slot_directory);
+
+ // Locate and read log file
+ virtualbox_system_log_src = virtualbox_home_directory + "/VBoxSVC.log";
+ virtualbox_system_log_dst = slot_directory + "/VBoxSVC.log";
+
+ if (boinc_file_exists(virtualbox_system_log_src.c_str())) {
+ // Skip having to deal with various forms of file locks by just making a temp
+ // copy of the log file.
+ boinc_copy(virtualbox_system_log_src.c_str(), virtualbox_system_log_dst.c_str());
+
+ // Keep only the last 16k if it is larger than that.
+ read_file_string(virtualbox_system_log_dst.c_str(), log, 16384, true);
+
+#ifdef _WIN32
+ // Remove \r from the log spew
+ iter = log.begin();
+ while (iter != log.end()) {
+ if (*iter == '\r') {
+ iter = log.erase(iter);
+ } else {
+ ++iter;
+ }
+ }
+#endif
+
+ if (log.size() >= 16384) {
+ // Look for the next whole line of text.
+ iter = log.begin();
+ while (iter != log.end()) {
+ if (*iter == '\n') {
+ log.erase(iter);
+ break;
+ }
+ iter = log.erase(iter);
+ }
+ }
+ } else {
+ fprintf(
+ stderr,
+ "%s Could not find the Hypervisor System Log at '%s'.\n",
+ vboxwrapper_msg_prefix(buf, sizeof(buf)),
+ virtualbox_system_log_src.c_str()
+ );
+ retval = ERR_NOT_FOUND;
+ }
+
+ return retval;
+}
+
// Enable the network adapter if a network connection is required.
// NOTE: Network access should never be allowed if the code running in a
// shared directory or the VM image itself is NOT signed. Doing so
@@ -2152,7 +2169,7 @@ int VBOX_VM::vbm_popen_raw(string& arguments, string& output, unsigned int timeo
size_t errcode_start;
size_t errcode_end;
string errcode;
- int retval = 0;
+ int retval = BOINC_SUCCESS;
// Launch vboxsvc in case it was shutdown for being idle
launch_vboxsvc();
@@ -2321,8 +2338,6 @@ CLEANUP:
sscanf(errcode.c_str(), "%x", &retval);
}
-
- retval = 0;
}
#endif
diff --git a/samples/vboxwrapper/vbox.h b/samples/vboxwrapper/vbox.h
index d77105eb9e..c808b77fd0 100644
--- a/samples/vboxwrapper/vbox.h
+++ b/samples/vboxwrapper/vbox.h
@@ -147,13 +147,14 @@ struct VBOX_VM {
int get_install_directory(std::string& dir);
int get_slot_directory(std::string& dir);
- int get_network_bytes_sent(double& sent);
- int get_network_bytes_received(double& received);
- int get_system_log(std::string& log);
- int get_vm_process_id(int& process_id);
- int get_vm_exit_code(unsigned long& exit_code);
int get_port_forwarding_port();
int get_remote_desktop_port();
+ int get_vm_network_bytes_sent(double& sent);
+ int get_vm_network_bytes_received(double& received);
+ int get_vm_process_id(int& process_id);
+ int get_vm_exit_code(unsigned long& exit_code);
+
+ int get_system_log(std::string& log);
int set_network_access(bool enabled);
int set_cpu_usage(int percentage);
diff --git a/samples/vboxwrapper/vboxwrapper.cpp b/samples/vboxwrapper/vboxwrapper.cpp
index 34948605cb..6432b7ccce 100644
--- a/samples/vboxwrapper/vboxwrapper.cpp
+++ b/samples/vboxwrapper/vboxwrapper.cpp
@@ -428,7 +428,7 @@ int main(int argc, char** argv) {
//
fprintf(
stderr,
- "%s vboxwrapper(%s): starting\n",
+ "%s %s: starting\n",
vboxwrapper_msg_prefix(buf, sizeof(buf)),
argv[0]
);
@@ -653,82 +653,76 @@ int main(int argc, char** argv) {
retval = vm.run(elapsed_time);
if (retval) {
// All failure to start error are unrecoverable by default
- bool unrecoverable_error = true;
- char* temp_reason = (char*)"";
- int temp_delay = 300;
+ bool unrecoverable_error = true;
+ bool dump_hypervisor_logs = false;
+ string error_reason;
+ char* temp_reason = (char*)"";
+ int temp_delay = 300;
- fprintf(
- stderr,
- "%s VM failed to start.\n",
- vboxwrapper_msg_prefix(buf, sizeof(buf))
- );
if (vm.is_logged_failure_vm_extensions_disabled()) {
- fprintf(
- stderr,
- "%s NOTE: BOINC has detected that your computer's processor supports hardware acceleration for\n"
+ error_reason =
+ " NOTE: BOINC has detected that your computer's processor supports hardware acceleration for\n"
" virtual machines but the hypervisor failed to successfully launch with this feature enabled.\n"
" This means that the hardware acceleration feature has been disabled in the computer's BIOS.\n"
" Please enable this feature in your computer's BIOS.\n"
" Intel calls it 'VT-x'\n"
" AMD calls it 'AMD-V'\n"
" More information can be found here: http://en.wikipedia.org/wiki/X86_virtualization\n"
- " Error Code: ERR_CPU_VM_EXTENSIONS_DISABLED\n",
- vboxwrapper_msg_prefix(buf, sizeof(buf))
- );
+ " Error Code: ERR_CPU_VM_EXTENSIONS_DISABLED\n";
} else if (vm.is_logged_failure_vm_extensions_in_use()) {
- fprintf(
- stderr,
- "%s NOTE: VirtualBox hypervisor reports that another hypervisor has locked the hardware acceleration\n"
+ error_reason =
+ " NOTE: VirtualBox hypervisor reports that another hypervisor has locked the hardware acceleration\n"
" for virtual machines feature in exclusive mode. You'll either need to reconfigure the other hypervisor\n"
" to not use the feature exclusively or just let BOINC run this project in software emulation mode.\n"
- " Error Code: ERR_CPU_VM_EXTENSIONS_DISABLED\n",
- vboxwrapper_msg_prefix(buf, sizeof(buf))
- );
+ " Error Code: ERR_CPU_VM_EXTENSIONS_DISABLED\n";
} else if (vm.is_logged_failure_vm_extensions_not_supported()) {
- fprintf(
- stderr,
- "%s NOTE: VirtualBox has reported an improperly configured virtual machine. It was configured to require\n"
+ error_reason =
+ " NOTE: VirtualBox has reported an improperly configured virtual machine. It was configured to require\n"
" hardware acceleration for virtual machines, but your processor does not support the required feature.\n"
- " Please report this issue to the project so that it can be addresssed.\n",
- vboxwrapper_msg_prefix(buf, sizeof(buf))
- );
+ " Please report this issue to the project so that it can be addresssed.\n";
} else if (vm.is_logged_failure_host_out_of_memory()) {
- fprintf(
- stderr,
- "%s NOTE: VirtualBox has failed to allocate enough memory to start the configured virtual machine.\n"
- " This might be a temporary problem and so this job will be rescheduled for another time.\n",
- vboxwrapper_msg_prefix(buf, sizeof(buf))
- );
+ error_reason =
+ " NOTE: VirtualBox has failed to allocate enough memory to start the configured virtual machine.\n"
+ " This might be a temporary problem and so this job will be rescheduled for another time.\n";
unrecoverable_error = false;
temp_reason = (char*)"VM Hypervisor was unable to allocate enough memory to start VM.";
} else if (ERR_NOT_EXITED == retval) {
- fprintf(
- stderr,
- "%s NOTE: VM was already running.\n"
+ error_reason =
+ " NOTE: VM was already running.\n"
" BOINC will be notified that it needs to clean up the environment.\n"
- " This might be a temporary problem and so this job will be rescheduled for another time.\n",
- vboxwrapper_msg_prefix(buf, sizeof(buf))
- );
+ " This might be a temporary problem and so this job will be rescheduled for another time.\n";
unrecoverable_error = false;
temp_reason = (char*)"VM environment needed to be cleaned up.";
} else if (vm.is_virtualbox_error_recoverable(retval)) {
- fprintf(
- stderr,
- "%s NOTE: VM session lock error encountered.\n"
+ error_reason =
+ " NOTE: VM session lock error encountered.\n"
" BOINC will be notified that it needs to clean up the environment.\n"
- " This might be a temporary problem and so this job will be rescheduled for another time.\n",
- vboxwrapper_msg_prefix(buf, sizeof(buf))
- );
+ " This might be a temporary problem and so this job will be rescheduled for another time.\n";
unrecoverable_error = false;
temp_reason = (char*)"VM environment needed to be cleaned up.";
} else {
- vm.dumphypervisorlogs();
+ dump_hypervisor_logs = true;
}
if (unrecoverable_error) {
// Attempt to cleanup the VM and exit.
vm.cleanup();
write_checkpoint(elapsed_time, vm);
+
+ if (error_reason.size()) {
+ fprintf(
+ stderr,
+ "%s\n"
+ "%s",
+ vboxwrapper_msg_prefix(buf, sizeof(buf)),
+ error_reason.c_str()
+ );
+ }
+
+ if (dump_hypervisor_logs) {
+ vm.dumphypervisorlogs();
+ }
+
boinc_finish(retval);
} else {
// if the VM is already running notify BOINC about the process ID so it can
@@ -749,6 +743,16 @@ int main(int argc, char** argv) {
// Give the BOINC API time to report the pid to BOINC.
boinc_sleep(5.0);
+ if (error_reason.size()) {
+ fprintf(
+ stderr,
+ "%s\n"
+ "%s",
+ vboxwrapper_msg_prefix(buf, sizeof(buf)),
+ error_reason.c_str()
+ );
+ }
+
// Exit and let BOINC clean up the rest.
boinc_temporary_exit(temp_delay, temp_reason);
}
@@ -885,25 +889,40 @@ int main(int argc, char** argv) {
if ((elapsed_time - last_status_report_time) >= 6000.0) {
last_status_report_time = elapsed_time;
- if (aid.global_prefs.daily_xfer_limit_mb) {
+ if (vm.job_duration) {
fprintf(
stderr,
- "%s Status Report: Job Duration: '%f', Elapsed Time: '%f', Network Bytes Sent (Total): '%f', Network Bytes Received (Total): '%f'\n",
+ "%s Status Report: Job Duration: '%f'\n",
vboxwrapper_msg_prefix(buf, sizeof(buf)),
- vm.job_duration,
- elapsed_time,
- bytes_sent,
- bytes_received
+ vm.job_duration
);
- } else {
+ }
+ if (elapsed_time) {
fprintf(
stderr,
- "%s Status Report: Job Duration: '%f', Elapsed Time: '%f'\n",
+ "%s Status Report: Elapsed Time: '%f'\n",
vboxwrapper_msg_prefix(buf, sizeof(buf)),
- vm.job_duration,
- elapsed_time
+ vm.job_duration
);
}
+ if (aid.global_prefs.daily_xfer_limit_mb) {
+ if (vm.job_duration) {
+ fprintf(
+ stderr,
+ "%s Status Report: Network Bytes Sent (Total): '%f'\n",
+ vboxwrapper_msg_prefix(buf, sizeof(buf)),
+ bytes_sent
+ );
+ }
+ if (elapsed_time) {
+ fprintf(
+ stderr,
+ "%s Status Report: Network Bytes Received (Total): '%f'\n",
+ vboxwrapper_msg_prefix(buf, sizeof(buf)),
+ bytes_received
+ );
+ }
+ }
}
// Checkpoint
@@ -999,12 +1018,12 @@ int main(int argc, char** argv) {
if (net_usage_timer <= 0) {
net_usage_timer = 600;
double sent, received;
- retval = vm.get_network_bytes_sent(sent);
+ retval = vm.get_vm_network_bytes_sent(sent);
if (!retval && (sent != bytes_sent)) {
bytes_sent = sent;
report_net_usage = true;
}
- retval = vm.get_network_bytes_received(received);
+ retval = vm.get_vm_network_bytes_received(received);
if (!retval && (received != bytes_received)) {
bytes_received = received;
report_net_usage = true;
diff --git a/win_build/vboxwrapper.vcxproj b/win_build/vboxwrapper.vcxproj
index 7ccbff0eba..e09bfe5576 100644
--- a/win_build/vboxwrapper.vcxproj
+++ b/win_build/vboxwrapper.vcxproj
@@ -128,12 +128,12 @@
</ResourceCompile>
<Link>
<AdditionalDependencies>libcmt.lib;libcpmt.lib;kernel32.lib;user32.lib;gdi32.lib;ole32.lib;wsock32.lib;psapi.lib;%(AdditionalDependencies)</AdditionalDependencies>
- <OutputFile>.\Build\$(Platform)\$(Configuration)\vboxwrapper_26050_windows_intelx86.exe</OutputFile>
+ <OutputFile>.\Build\$(Platform)\$(Configuration)\vboxwrapper_26051_windows_intelx86.exe</OutputFile>
<SuppressStartupBanner>true</SuppressStartupBanner>
<IgnoreAllDefaultLibraries>true</IgnoreAllDefaultLibraries>
<DelayLoadDLLs>%(DelayLoadDLLs)</DelayLoadDLLs>
<GenerateDebugInformation>true</GenerateDebugInformation>
- <ProgramDatabaseFile>.\Build\$(Platform)\$(Configuration)\vboxwrapper_26050_windows_intelx86.pdb</ProgramDatabaseFile>
+ <ProgramDatabaseFile>.\Build\$(Platform)\$(Configuration)\vboxwrapper_26051_windows_intelx86.pdb</ProgramDatabaseFile>
<SubSystem>Windows</SubSystem>
<TargetMachine>MachineX86</TargetMachine>
</Link>
@@ -177,12 +177,12 @@
</ResourceCompile>
<Link>
<AdditionalDependencies>libcmt.lib;libcpmt.lib;kernel32.lib;user32.lib;gdi32.lib;ole32.lib;wsock32.lib;psapi.lib;%(AdditionalDependencies)</AdditionalDependencies>
- <OutputFile>.\Build\$(Platform)\$(Configuration)\vboxwrapper_26050_windows_x86_64.exe</OutputFile>
+ <OutputFile>.\Build\$(Platform)\$(Configuration)\vboxwrapper_26051_windows_x86_64.exe</OutputFile>
<SuppressStartupBanner>true</SuppressStartupBanner>
<IgnoreAllDefaultLibraries>true</IgnoreAllDefaultLibraries>
<DelayLoadDLLs>%(DelayLoadDLLs)</DelayLoadDLLs>
<GenerateDebugInformation>true</GenerateDebugInformation>
- <ProgramDatabaseFile>.\Build\$(Platform)\$(Configuration)\vboxwrapper_26050_windows_x86_64.pdb</ProgramDatabaseFile>
+ <ProgramDatabaseFile>.\Build\$(Platform)\$(Configuration)\vboxwrapper_26051_windows_x86_64.pdb</ProgramDatabaseFile>
<SubSystem>Windows</SubSystem>
<TargetMachine>MachineX64</TargetMachine>
</Link>
--
GitLab