Bheve: Slow linux syscalls on AMD

[Willem Jan Withagen]

On 30-5-2014 23:27, Nils Beyer wrote:
> Hi Willem,
> 
> Willem Jan Withagen wrote:
>> 1) I'm looking for a better basic syscall in Linux that is not cache,
>> faked or otherwise tweaked to nog give what I want.
>> Would really be nice if there was a NOP_syscall, just go in and out of
>> kernel space.....
> 
> Hmm, I've tried your test with "getuid". Seems not to be cached. Here's the
> diff:
> 
> ===============================================================================
> # diff 0.orig.c 0.c
> 24c24
> <      j=getpid();
> ---
>>      (void)getuid();
> 38c38
> <    printf("Average time for System call getpid : %f\n",avgTimeSysCall);
> ---
>>    printf("Average time for System call getuid : %f\n",avgTimeSysCall);
> ===============================================================================
> 
> 
> And here is the result:
> 
> ===============================================================================
> # strace -c ./0
> Average time for System call getuid : 10564.581055
> Average time for Function call : 2.285000
> % time     seconds  usecs/call     calls    errors syscall
> ------ ----------- ----------- --------- --------- ----------------
> 100.00    0.004590           0   1000000           getuid
>   0.00    0.000000           0         1           read
>   0.00    0.000000           0         2           write
>   0.00    0.000000           0         2           open
>   0.00    0.000000           0         2           close
>   0.00    0.000000           0         3           fstat
>   0.00    0.000000           0         9           mmap
>   0.00    0.000000           0         3           mprotect
>   0.00    0.000000           0         1           munmap
>   0.00    0.000000           0         1           brk
>   0.00    0.000000           0         1         1 access
>   0.00    0.000000           0         1           execve
>   0.00    0.000000           0         1           arch_prctl
> ------ ----------- ----------- --------- --------- ----------------
> 100.00    0.004590               1000027         1 total
> ===============================================================================

Looks a bit like mine on i386 real hardware:
root at ubuntu-i386-14:~/src/tests# strace -c ./syscall-getuid
Average time for System call getuid :  272.023010
Average time for Function call : 7.169000
% time     seconds  usecs/call     calls    errors syscall
------ ----------- ----------- --------- --------- ----------------
100.00    0.018939           0   1000000           getuid32
  0.00    0.000000           0         1           read
  0.00    0.000000           0         2           write
  0.00    0.000000           0         2           open
  0.00    0.000000           0         2           close
  0.00    0.000000           0         1           execve
  0.00    0.000000           0         3         3 access
  0.00    0.000000           0         1           brk
  0.00    0.000000           0         4           gettimeofday
  0.00    0.000000           0         1           munmap
  0.00    0.000000           0         3           mprotect
  0.00    0.000000           0         7           mmap2
  0.00    0.000000           0         3           fstat64
  0.00    0.000000           0         1           set_thread_area
------ ----------- ----------- --------- --------- ----------------
100.00    0.018939               1000031         3 total


>> 3) Can somebody do the same test on an intel plaform and see what the
>> results are.
> 
> Here is the result from a bhyved CentOS on an Intel i3:
> 
> ===============================================================================
> # strace -c ./0.orig
> Average time for System call getpid : 3.776000
> Average time for Function call : 2.326000
> % time     seconds  usecs/call     calls    errors syscall
> ------ ----------- ----------- --------- --------- ----------------
>   -nan    0.000000           0         1           read
>   -nan    0.000000           0         2           write
>   -nan    0.000000           0         2           open
>   -nan    0.000000           0         2           close
>   -nan    0.000000           0         3           fstat
>   -nan    0.000000           0         9           mmap
>   -nan    0.000000           0         3           mprotect
>   -nan    0.000000           0         1           munmap
>   -nan    0.000000           0         1           brk
>   -nan    0.000000           0         1         1 access
>   -nan    0.000000           0         1           getpid
>   -nan    0.000000           0         1           execve
>   -nan    0.000000           0         1           arch_prctl
> ------ ----------- ----------- --------- --------- ----------------
> 100.00    0.000000                    28         1 total
> ===============================================================================

Right no long calls at all....

So the question remains:
	Why is it taking so long on the AMD platform.

--WjW