oprofile: Can't see kernel system calls in Ubuntu guest

Discussions about using Linux guests in VirtualBox.
Post Reply
feathers
Posts: 1
Joined: 16. May 2014, 16:39

oprofile: Can't see kernel system calls in Ubuntu guest

Post by feathers »

I'm running a 64-bit Ubuntu "Trusty" guest w/2GB RAM on a 64-bit Windows-7 host w/8GB RAM. H/W=HP EliteBook 840 w/Intel i5

I attempted to profile the following program:

Code: Select all

$ cat optest.cc
#include <sys/time.h>

long long gettimeofday_ms()
{
    struct timeval tv;
    long long ms = 0;
    if (gettimeofday(&tv, 0) == 0)
    {
        ms = tv.tv_sec * 1000 + tv.tv_usec / 1000;
    }

    return ms;
}

int main(int argc, char* argv[])
{

    for (int i=0; i<1000000000; ++i)
    {
     long long ms = gettimeofday_ms();
    }

    return 0;
}
I then obtained the uncompressed Ubuntu vmlinux image by following these directions: << google: getting-started-with-oprofile-on-ubuntu >> site=smackerelofopinion dot blogspot dot com
(Sorry - first post - I'm not permitted to provide you with the YOU ARE ELL. (And apparently I'm not even permitted to spell it.))

For convenience [i.e. less typing], I sym-linked the vmlinux image to the /boot directory: sudo ln –s /usr/lib/debug/boot/vmlinux-3.13.0-24-generic /boot/vmlinux-3.13.0-24-generic

I then set up my environment to run oprofile:

Code: Select all

$ sudo modprobe oprofile timer=1
$ sudo opcontrol --init
$ sudo opcontrol --vmlinux=/boot/vmlinux-3.13.0-24-generic 
$ sudo opcontrol --reset
And then I ran a profiling session:

Code: Select all

$ sudo opcontrol --start
Using 2.6+ OProfile kernel interface.
Reading module info.
Using log file /var/lib/oprofile/samples/oprofiled.log
Daemon started.
Profiler running.
$ ./optest                      # the executable(s) that I wish to profile
$ sudo opcontrol --stop
Stopping profiling.
$ sudo opcontrol --dump
And finally I took a look at the profiling results:

Code: Select all

$ opreport -l
Using /var/lib/oprofile/samples/ for samples directory.
warning: /vboxguest could not be found.
warning: [vdso] (tgid:1444 range:0x7fff9928c000-0x7fff9928e000) could not be found.
warning: [vdso] (tgid:1445 range:0x7fff9928c000-0x7fff9928e000) could not be found.
CPU: CPU with timer interrupt, speed 2270.74 MHz (estimated)
Profiling through timer interrupt
samples  %        image name               app name                 symbol name
2643     51.6312  vmlinux-3.13.0-24-generic vmlinux-3.13.0-24-generic native_safe_halt
2005     39.1678  optest                   optest                   gettimeofday_ms()
372       7.2670  optest                   optest                   main
10        0.1954  vmlinux-3.13.0-24-generic apache2                  finish_task_switch
6         0.1172  libglib-2.0.so.0.4000.0  gnome-terminal           /lib/x86_64-linux-gnu/libglib-2.0.so.0.4000.0
5         0.0977  vmlinux-3.13.0-24-generic optest                   context_tracking_user_exit
5         0.0977  vmlinux-3.13.0-24-generic optest                   finish_task_switch
4         0.0781  vmlinux-3.13.0-24-generic optest                   retint_signal
3         0.0586  vmlinux-3.13.0-24-generic Xorg                     finish_task_switch
3         0.0586  vmlinux-3.13.0-24-generic apache2                  context_tracking_user_enter
2         0.0391  Xorg                     Xorg                     /usr/bin/Xorg
2         0.0391  [vdso] (tgid:1444 range:0x7fff9928c000-0x7fff9928e000) apache2                  [vdso] (tgid:1444 range:0x7fff9928c000-0x7fff9928e000)
2         0.0391  bash                     bash                     /bin/bash
2         0.0391  libglib-2.0.so.0.4000.0  indicator-applet-complete /lib/x86_64-linux-gnu/libglib-2.0.so.0.4000.0
2         0.0391  vmlinux-3.13.0-24-generic VBoxService              finish_task_switch
2         0.0391  vmlinux-3.13.0-24-generic apache2                  context_tracking_user_exit
2         0.0391  vmlinux-3.13.0-24-generic apache2                  native_read_tsc
2         0.0391  vmlinux-3.13.0-24-generic gawk                     __do_page_fault
2         0.0391  vmlinux-3.13.0-24-generic ibus-daemon              finish_task_switch
2         0.0391  vmlinux-3.13.0-24-generic optest                   __do_softirq
2         0.0391  vmlinux-3.13.0-24-generic vmlinux-3.13.0-24-generic __do_softirq
1         0.0195  [vdso] (tgid:1445 range:0x7fff9928c000-0x7fff9928e000) apache2                  [vdso] (tgid:1445 range:0x7fff9928c000-0x7fff9928e000)
1         0.0195  evdev_drv.so             Xorg                     /usr/lib/xorg/modules/input/evdev_drv.so
1         0.0195  ld-2.19.so               cat                      _dl_relocate_object
1         0.0195  libc-2.19.so             dbus-daemon              __strcmp_sse2_unaligned
1         0.0195  libc-2.19.so             ibus-daemon              _int_free
1         0.0195  libc-2.19.so             oprofiled                __open_nocancel
1         0.0195  libc-2.19.so             sudo                     _IO_file_underflow_maybe_mmap
1         0.0195  libglib-2.0.so.0.4000.0  ibus-daemon              /lib/x86_64-linux-gnu/libglib-2.0.so.0.4000.0
1         0.0195  libglib-2.0.so.0.4000.0  ibus-engine-simple       /lib/x86_64-linux-gnu/libglib-2.0.so.0.4000.0
1         0.0195  libglib-2.0.so.0.4000.0  ibus-ui-gtk3             /lib/x86_64-linux-gnu/libglib-2.0.so.0.4000.0
1         0.0195  libgobject-2.0.so.0.4000.0 ibus-daemon              /usr/lib/x86_64-linux-gnu/libgobject-2.0.so.0.4000.0
1         0.0195  libpthread-2.19.so       ibus-daemon              pthread_mutex_lock
1         0.0195  vboxguest                VBoxService              /vboxguest
1         0.0195  vmlinux-3.13.0-24-generic VBoxService              __hrtimer_start_range_ns
1         0.0195  vmlinux-3.13.0-24-generic VBoxService              context_tracking_user_enter
1         0.0195  vmlinux-3.13.0-24-generic VBoxService              context_tracking_user_exit
1         0.0195  vmlinux-3.13.0-24-generic Xorg                     fget_light
1         0.0195  vmlinux-3.13.0-24-generic Xorg                     free_pages_prepare
1         0.0195  vmlinux-3.13.0-24-generic bash                     context_tracking_user_enter
1         0.0195  vmlinux-3.13.0-24-generic dash                     flush_tlb_page
1         0.0195  vmlinux-3.13.0-24-generic dbus-daemon              __slab_alloc
1         0.0195  vmlinux-3.13.0-24-generic gnome-terminal           __wake_up_sync_key
1         0.0195  vmlinux-3.13.0-24-generic gnome-terminal           context_tracking_user_exit
1         0.0195  vmlinux-3.13.0-24-generic gnome-terminal           fget_light
1         0.0195  vmlinux-3.13.0-24-generic gnome-terminal           rw_copy_check_uvector
1         0.0195  vmlinux-3.13.0-24-generic grep                     __do_page_fault
1         0.0195  vmlinux-3.13.0-24-generic ibus-daemon              context_tracking_user_exit
1         0.0195  vmlinux-3.13.0-24-generic ibus-engine-simple       finish_task_switch
1         0.0195  vmlinux-3.13.0-24-generic ibus-engine-simple       rw_verify_area
1         0.0195  vmlinux-3.13.0-24-generic ibus-ui-gtk3             remove_wait_queue
1         0.0195  vmlinux-3.13.0-24-generic id                       context_tracking_user_exit
1         0.0195  vmlinux-3.13.0-24-generic ophelp                   __do_page_fault
1         0.0195  vmlinux-3.13.0-24-generic oprofiled                __d_alloc
1         0.0195  vmlinux-3.13.0-24-generic oprofiled                apparmor_file_alloc_security
1         0.0195  vmlinux-3.13.0-24-generic oprofiled                do_sys_open
1         0.0195  vmlinux-3.13.0-24-generic oprofiled                ext4_es_lru_add
1         0.0195  vmlinux-3.13.0-24-generic oprofiled                link_path_walk
1         0.0195  vmlinux-3.13.0-24-generic oprofiled                path_init
1         0.0195  vmlinux-3.13.0-24-generic rm                       is_dx_dir
1         0.0195  vmlinux-3.13.0-24-generic sudo                     sysret_check
1         0.0195  vmlinux-3.13.0-24-generic vmlinux-3.13.0-24-generic ata_scsi_queuecmd
As you can see, 39% of oprofile’s samples occurred in my own gettimeofday_ms() function, an additional 51% took place in the kernel’s native_safe_halt function, and another 7% took place in main() for a total of 97%. This result makes sense because the native_safe_halt symbol is merely hiding the gettimeofday() kernel call.

Note that I was unable to use HW counters with oprofile; HW counters seem not to be supported by VirtualBox. Instead, I'm running oprofile in "timer mode", but I'm not sure whether this is the root of the problem.

QUESTION: How can I cause opreport to reveal the actual system call to gettimeofday()?
.
Attachments
ubuntu-guest-log.zip
Guest log file
(13.23 KiB) Downloaded 6 times
ubuntu-showinfo.zip
Host "showvminfo" file
(1.79 KiB) Downloaded 7 times
noteirak
Site Moderator
Posts: 5231
Joined: 13. Jan 2012, 11:14
Primary OS: Debian other
VBox Version: OSE Debian
Guest OSses: Debian, Win 2k8, Win 7
Contact:

Re: oprofile: Can't see kernel system calls in Ubuntu guest

Post by noteirak »

I am not fully sure to understand your question, but this looks more to me like a question directly for the devs. In which case, you'll get a better and faster answer on the Dev Mailing List.
Hyperbox - Virtual Infrastructure Manager - https://apps.kamax.lu/hyperbox/
Manage your VirtualBox infrastructure the free way!
Post Reply