VBOX: Introducing the replay and trace logs for vboxwrapper.

The replay log stores the commands that were executed in a near shell script state.  Ideally we should be able to use this to pass bugs back upstream to VirtualBox.

The trace log shows the date, time, thread id, command, return value, and output of the above commands.
This commit is contained in:
Rom Walton 2014-01-22 14:34:20 -05:00
parent 5778cd653f
commit 6cfdbf88f1
2 changed files with 69 additions and 23 deletions

View File

@ -276,7 +276,7 @@ void VBOX_VM::poll(bool log_state) {
command = "showvminfo \"" + vm_name + "\" ";
command += "--machinereadable ";
if (vbm_popen(command, output, "VM state", false, false) == 0) {
if (vbm_popen(command, output, "VM state", false, false, 45, false) == 0) {
vmstate_start = output.find("VMState=\"");
if (vmstate_start != string::npos) {
vmstate_start += 9;
@ -2291,6 +2291,7 @@ int VBOX_VM::launch_vboxsvc() {
);
}
vbm_trace(command, std::string(""), retval);
}
}
}
@ -2303,9 +2304,11 @@ int VBOX_VM::launch_vboxsvc() {
int VBOX_VM::launch_vboxvm() {
char buf[256];
char error_msg[256];
int retval = ERR_EXEC;
char cmdline[1024];
char* argv[5];
int argc;
std::string output;
int retval = ERR_EXEC;
// Construct the command line parameters
//
@ -2324,8 +2327,15 @@ int VBOX_VM::launch_vboxvm() {
argv[4] = NULL;
argc = 4;
strcpy(cmdline, "");
for (int i=0; i<argc; i++) {
strcat(cmdline, argv[i]);
if (i<argc-1) {
strcat(cmdline, " ");
}
}
#ifdef _WIN32
char cmdline[1024];
STARTUPINFO si;
PROCESS_INFORMATION pi;
SECURITY_ATTRIBUTES sa;
@ -2335,7 +2345,6 @@ int VBOX_VM::launch_vboxvm() {
DWORD dwCount = 0;
unsigned long ulExitCode = 0;
unsigned long ulExitTimeout = 0;
std::string output;
memset(&si, 0, sizeof(si));
memset(&pi, 0, sizeof(pi));
@ -2367,14 +2376,6 @@ int VBOX_VM::launch_vboxvm() {
si.hStdError = hWritePipe;
si.hStdInput = NULL;
strcpy(cmdline, "");
for (int i=0; i<argc; i++) {
strcat(cmdline, argv[i]);
if (i<argc-1) {
strcat(cmdline, " ");
}
}
// Execute command
if (!CreateProcess(
NULL,
@ -2456,12 +2457,13 @@ CLEANUP:
#else
int pid = fork();
if (-1 == pid) {
output = strerror(errno);
fprintf(
stderr,
"%s Status Report: Launching virtualbox.exe/vboxheadless.exe failed!.\n"
" Error: %s",
vboxwrapper_msg_prefix(buf, sizeof(buf)),
strerror(errno)
output.c_str()
);
retval = ERR_FORK;
} else if (0 == pid) {
@ -2474,6 +2476,8 @@ CLEANUP:
}
#endif
vbm_trace(std::string(cmdline), output, retval);
return retval;
}
@ -2493,15 +2497,18 @@ void VBOX_VM::sanitize_output(std::string& output) {
// If there are errors we can recover from, process them here.
//
int VBOX_VM::vbm_popen(string& arguments, string& output, const char* item, bool log_error, bool retry_failures, unsigned int timeout) {
int VBOX_VM::vbm_popen(string& command, string& output, const char* item, bool log_error, bool retry_failures, unsigned int timeout, bool log_trace) {
int retval = 0;
int retry_count = 0;
double sleep_interval = 1.0;
char buf[256];
string retry_notes;
// Initialize command line
command = "VBoxManage -q " + command;
do {
retval = vbm_popen_raw(arguments, output, timeout);
retval = vbm_popen_raw(command, output, timeout);
if (retval) {
// VirtualBox designed the concept of sessions to prevent multiple applications using
@ -2559,23 +2566,26 @@ int VBOX_VM::vbm_popen(string& arguments, string& output, const char* item, bool
fprintf(
stderr,
"%s Error in %s for VM: %d\nArguments:\n%s\nOutput:\n%s\n",
"%s Error in %s for VM: %d\nCommand:\n%s\nOutput:\n%s\n",
vboxwrapper_msg_prefix(buf, sizeof(buf)),
item,
retval,
arguments.c_str(),
command.c_str(),
output.c_str()
);
}
if (log_trace) {
vbm_trace(command, output, retval);
}
return retval;
}
// Execute the vbox manage application and copy the output to the buffer.
//
int VBOX_VM::vbm_popen_raw(string& arguments, string& output, unsigned int timeout) {
int VBOX_VM::vbm_popen_raw(string& command, string& output, unsigned int timeout) {
char buf[256];
string command;
size_t errcode_start;
size_t errcode_end;
string errcode;
@ -2584,9 +2594,6 @@ int VBOX_VM::vbm_popen_raw(string& arguments, string& output, unsigned int timeo
// Launch vboxsvc in case it was shutdown for being idle
launch_vboxsvc();
// Initialize command line
command = "VBoxManage -q " + arguments;
// Reset output buffer
output.clear();
@ -2755,3 +2762,30 @@ CLEANUP:
return retval;
}
void VBOX_VM::vbm_replay(std::string& command) {
FILE* f = fopen(REPLAYLOG_FILENAME, "a");
if (f) {
fprintf(f, "%s\n", command.c_str());
fclose(f);
}
}
void VBOX_VM::vbm_trace(std::string& command, std::string& output, int retval) {
vbm_replay(command);
char buf[256];
FILE* f = fopen(TRACELOG_FILENAME, "a");
if (f) {
fprintf(
f,
"%s\nCommand: %s\nExit Code: %d\nOutput:\n%s\n",
vboxwrapper_msg_prefix(buf, sizeof(buf)),
command.c_str(),
retval,
output.c_str()
);
fclose(f);
}
}

View File

@ -34,6 +34,11 @@
//
#define VBOXWRAPPER_ERR_RECOVERABLE -1000
// Vboxwrapper diagnostics
//
#define REPLAYLOG_FILENAME "vbox_replay.txt"
#define TRACELOG_FILENAME "vbox_trace.txt"
// raw floppy drive device
class FloppyIO;
@ -186,14 +191,21 @@ struct VBOX_VM {
int launch_vboxsvc();
int launch_vboxvm();
void sanitize_output(std::string& output);
int vbm_popen(
std::string& command, std::string& output, const char* item, bool log_error = true, bool retry_failures = true, unsigned int timeout = 45
std::string& command, std::string& output, const char* item, bool log_error = true, bool retry_failures = true, unsigned int timeout = 45, bool log_trace = true
);
int vbm_popen_raw(
std::string& command, std::string& output, unsigned int timeout
);
void vbm_replay(
std::string& command
);
void vbm_trace(
std::string& command, std::string& ouput, int retval
);
};
#endif