dom0+vm/dispvm: add some timing logs

This commit is contained in:
Marek Marczykowski 2013-02-25 06:48:29 +01:00
parent 305143371d
commit 92f6c6df20
3 changed files with 21 additions and 1 deletions

View File

@ -68,6 +68,7 @@ class QfileDaemonDvm:
if len(sys.argv) > 4 and len(sys.argv[4]) > 0: if len(sys.argv) > 4 and len(sys.argv[4]) > 0:
assert sys.argv[4] in QubesDispVmLabels.keys(), "Invalid label" assert sys.argv[4] in QubesDispVmLabels.keys(), "Invalid label"
label = QubesDispVmLabels[sys.argv[4]] label = QubesDispVmLabels[sys.argv[4]]
print >>sys.stderr, "time=%s, starting qubes_restore" % (str(time.time()))
retcode = subprocess.call(['/usr/lib/qubes/qubes_restore', retcode = subprocess.call(['/usr/lib/qubes/qubes_restore',
current_savefile, current_savefile,
current_dvm_conf, current_dvm_conf,
@ -88,6 +89,7 @@ class QfileDaemonDvm:
disp_name = f.readline().rstrip('\n') disp_name = f.readline().rstrip('\n')
disptempl = f.readline().rstrip('\n') disptempl = f.readline().rstrip('\n')
f.close() f.close()
print >>sys.stderr, "time=%s, adding to qubes.xml" % (str(time.time()))
vm_disptempl = qvm_collection.get_vm_by_name(disptempl); vm_disptempl = qvm_collection.get_vm_by_name(disptempl);
if vm_disptempl is None: if vm_disptempl is None:
sys.stderr.write( 'Domain ' + disptempl + ' does not exist ?') sys.stderr.write( 'Domain ' + disptempl + ' does not exist ?')
@ -106,6 +108,7 @@ class QfileDaemonDvm:
qvm_collection.save() qvm_collection.save()
qvm_collection.unlock_db() qvm_collection.unlock_db()
# Reload firewall rules # Reload firewall rules
print >>sys.stderr, "time=%s, reloading firewall" % (str(time.time()))
for vm in qvm_collection.values(): for vm in qvm_collection.values():
if vm.is_proxyvm() and vm.is_running(): if vm.is_proxyvm() and vm.is_running():
vm.write_iptables_xenstore_entry() vm.write_iptables_xenstore_entry()
@ -158,7 +161,9 @@ def main():
# sys.argv[4] - override label # sys.argv[4] - override label
# sys.argv[5] - override firewall # sys.argv[5] - override firewall
print >>sys.stderr, "time=%s, qfile-daemon-dvm init" % (str(time.time()))
notify_object = dbus.SessionBus().get_object("org.freedesktop.Notifications", "/org/freedesktop/Notifications") notify_object = dbus.SessionBus().get_object("org.freedesktop.Notifications", "/org/freedesktop/Notifications")
print >>sys.stderr, "time=%s, creating DispVM" % (str(time.time()))
qfile = QfileDaemonDvm(src_vmname) qfile = QfileDaemonDvm(src_vmname)
lockf = open("/var/run/qubes/qfile-daemon-dvm.lock", 'a') lockf = open("/var/run/qubes/qfile-daemon-dvm.lock", 'a')
fcntl.fcntl(lockf, fcntl.F_SETFD, fcntl.FD_CLOEXEC) fcntl.fcntl(lockf, fcntl.F_SETFD, fcntl.FD_CLOEXEC)
@ -166,6 +171,7 @@ def main():
dispname = qfile.get_dvm() dispname = qfile.get_dvm()
lockf.close() lockf.close()
if dispname is not None: if dispname is not None:
print >>sys.stderr, "time=%s, starting VM process" % (str(time.time()))
subprocess.call(['/usr/lib/qubes/qrexec_client', '-d', dispname, subprocess.call(['/usr/lib/qubes/qrexec_client', '-d', dispname,
user+':exec /usr/lib/qubes/qubes_rpc_multiplexer ' + exec_index + " " + src_vmname]) user+':exec /usr/lib/qubes/qubes_rpc_multiplexer ' + exec_index + " " + src_vmname])
subprocess.call(['/usr/sbin/xl', 'destroy', dispname]) subprocess.call(['/usr/sbin/xl', 'destroy', dispname])

View File

@ -476,9 +476,11 @@ int main(int argc, char **argv)
"time=%s, created domid=%d, creating xenstore entries\n", "time=%s, created domid=%d, creating xenstore entries\n",
gettime(), domid); gettime(), domid);
setup_xenstore(netvm_id, domid, dispid, name); setup_xenstore(netvm_id, domid, dispid, name);
fprintf(stderr, "time=%s, starting qubes_guid\n", gettime());
rm_fast_flag(); rm_fast_flag();
fprintf(stderr, "time=%s, starting qrexec\n", gettime());
start_rexec(domid, default_user); start_rexec(domid, default_user);
fprintf(stderr, "time=%s, starting qubes_guid\n", gettime());
start_guid(domid, argc-guid_args_start, argv+guid_args_start); start_guid(domid, argc-guid_args_start, argv+guid_args_start);
fprintf(stderr, "time=%s, started qubes_guid\n", gettime());
return 0; return 0;
} }

View File

@ -8,6 +8,16 @@
#include <ioall.h> #include <ioall.h>
#include "dvm2.h" #include "dvm2.h"
char *gettime()
{
static char retbuf[60];
struct timeval tv;
gettimeofday(&tv, NULL);
snprintf(retbuf, sizeof(retbuf), "%lld.%lld",
(long long) tv.tv_sec, (long long) tv.tv_usec);
return retbuf;
}
char *get_filename() char *get_filename()
{ {
char buf[DVM_FILENAME_SIZE]; char buf[DVM_FILENAME_SIZE];
@ -67,6 +77,7 @@ main()
perror("stat pre"); perror("stat pre");
exit(1); exit(1);
} }
fprintf(stderr, "time=%s, waiting for qubes-session\n", gettime());
// wait for X server to starts (especially in DispVM) // wait for X server to starts (especially in DispVM)
if (stat("/tmp/qubes-session-env", &session_stat)) { if (stat("/tmp/qubes-session-env", &session_stat)) {
switch (child = fork()) { switch (child = fork()) {
@ -95,6 +106,7 @@ main()
} }
} }
} }
fprintf(stderr, "time=%s, starting editor\n", gettime());
switch (child = fork()) { switch (child = fork()) {
case -1: case -1:
perror("fork"); perror("fork");