Thanks for the replies.

I dont think so that perl counts anything in the test, just run the code with truss -D, you will see the timing that the open() syscall takes just more time with multilabel enabled.

Even a single touch shows that:

# truss -D touch 1
0.000056431 mmap(0x0,32768,PROT_READ|PROT_WRITE,MAP_PRIVATE|MAP_ANON,-1,0x0) = 34366259200 (0x800638000) 0.000020672 issetugid(0x800639015,0x80062e4be,0x80084a0b0,0x80084a080,0xab57,0x0) = 0 (0x0) 0.000060342 open("/etc/libmap.conf",O_RDONLY,0666) ERR#2 'No such file or directory'
0.000032964 open("/var/run/ld-elf.so.hints",O_RDONLY,057) = 3 (0x3)
0.000029891 read(3,"Ehnt\^A\0\0\0\M^@\0\0\0-\0\0\0\0"...,128) = 128 (0x80)
0.000063135 lseek(3,0x80,SEEK_SET)               = 128 (0x80)
0.000040228 read(3,"/lib:/usr/lib:/usr/lib/compat:/u"...,45) = 45 (0x2d)
0.000034361 close(3)                             = 0 (0x0)
0.000031288 access("/lib/libc.so.7",0)                 = 0 (0x0)
0.000038551 open("/lib/libc.so.7",O_RDONLY,040754040) = 3 (0x3)
0.000045256 fstat(3,{ mode=-r--r--r-- ,inode=4107,size=1306952,blksize=32768 }) = 0 (0x0) 0.000031847 pread(0x3,0x80083c800,0x1000,0x0,0x101010101010101,0x8080808080808080) = 4096 (0x1000) 0.000024025 mmap(0x0,3420160,PROT_NONE,MAP_PRIVATE|MAP_ANON|MAP_NOCORE,-1,0x0) = 34368434176 (0x80084b000) 0.000055872 mmap(0x80084b000,1171456,PROT_READ|PROT_EXEC,MAP_PRIVATE|MAP_FIXED|MAP_NOCORE,3,0x0) = 34368434176 (0x80084b000) 0.000046095 mmap(0x800b68000,45056,PROT_READ|PROT_WRITE,MAP_PRIVATE|MAP_FIXED,3,0x11d000) = 34371698688 (0x800b68000) 0.000022628 mmap(0x800b73000,110592,PROT_READ|PROT_WRITE,MAP_PRIVATE|MAP_FIXED|MAP_ANON,-1,0x0) = 34371743744 (0x800b73000)
0.000022069 close(3)                             = 0 (0x0)
0.000024584 munmap(0x80063f000,4096)             = 0 (0x0)
0.000030450 mmap(0x0,102400,PROT_READ|PROT_WRITE,MAP_PRIVATE|MAP_ANON,-1,0x0) = 34366287872 (0x80063f000) 0.000036875 sysarch(0x81,0x7fffffffd450,0x80063c0c8,0x0,0xffffffffffad2228,0x8080808080808080) = 0 (0x0) 0.000041345 sigprocmask(SIG_BLOCK,SIGHUP|SIGINT|SIGQUIT|SIGKILL|SIGPIPE|SIGALRM|SIGTERM|SIGURG|SIGSTOP|SIGTSTP|SIGCONT|SIGCHLD|SIGTTIN|SIGTTOU|SIGIO|SIGXCPU|SIGXFSZ|SIGVTALRM|SIGPROF|SIGWINCH|SIGINFO|SIGUSR1|SIGUSR2,0x0) = 0 (0x0)
0.000065370 sigprocmask(SIG_SETMASK,0x0,0x0)     = 0 (0x0)
0.000041066 sigprocmask(SIG_BLOCK,SIGHUP|SIGINT|SIGQUIT|SIGKILL|SIGPIPE|SIGALRM|SIGTERM|SIGURG|SIGSTOP|SIGTSTP|SIGCONT|SIGCHLD|SIGTTIN|SIGTTOU|SIGIO|SIGXCPU|SIGXFSZ|SIGVTALRM|SIGPROF|SIGWINCH|SIGINFO|SIGUSR1|SIGUSR2,0x0) = 0 (0x0)
0.000032685 sigprocmask(SIG_SETMASK,0x0,0x0)     = 0 (0x0)
0.000051681 readlink("/etc/malloc.conf",0x7fffffffd5e0,1024) ERR#2 'No such file or directory' 0.000020393 issetugid(0x800945101,0x7fffffffd5e0,0xffffffffffffffff,0x0,0x2,0x7fffffffef79) = 0 (0x0)
0.000025143 break(0x800000)                      = 0 (0x0)
0.000024863 mmap(0x0,4194304,PROT_READ|PROT_WRITE,MAP_PRIVATE|MAP_ANON,-1,0x0) = 34371854336 (0x800b8e000) 0.000038273 mmap(0x800f8e000,466944,PROT_READ|PROT_WRITE,MAP_PRIVATE|MAP_ANON,-1,0x0) = 34376048640 (0x800f8e000)
0.000025142 munmap(0x800b8e000,466944)           = 0 (0x0)
0.000025143 gettimeofday({1334522860.892157 },0x0) = 0 (0x0)
0.000042463 stat("1",0x7fffffffdb10) ERR#2 'No such file or directory'
0.116764212 open("1",O_WRONLY|O_CREAT,0666)    = 3 (0x3)
0.000025701 fstat(3,{ mode=-rw-r--r-- ,inode=5,size=0,blksize=32768 }) = 0 (0x0)
0.000026819 close(3)                             = 0 (0x0)
0.000021231 sigprocmask(SIG_BLOCK,SIGHUP|SIGINT|SIGQUIT|SIGKILL|SIGPIPE|SIGALRM|SIGTERM|SIGURG|SIGSTOP|SIGTSTP|SIGCONT|SIGCHLD|SIGTTIN|SIGTTOU|SIGIO|SIGXCPU|SIGXFSZ|SIGVTALRM|SIGPROF|SIGWINCH|SIGINFO|SIGUSR1|SIGUSR2,0x0) = 0 (0x0)
0.000026818 sigprocmask(SIG_SETMASK,0x0,0x0)     = 0 (0x0)
0.000020952 sigprocmask(SIG_BLOCK,SIGHUP|SIGINT|SIGQUIT|SIGKILL|SIGPIPE|SIGALRM|SIGTERM|SIGURG|SIGSTOP|SIGTSTP|SIGCONT|SIGCHLD|SIGTTIN|SIGTTOU|SIGIO|SIGXCPU|SIGXFSZ|SIGVTALRM|SIGPROF|SIGWINCH|SIGINFO|SIGUSR1|SIGUSR2,0x0) = 0 (0x0)
0.000032127 sigprocmask(SIG_SETMASK,0x0,0x0)     = 0 (0x0)
-1.999864511 process exit, rval = 0

Can you see the open()'s spent time?

Without multilabel:

# truss -D touch 1
0.000078779 mmap(0x0,32768,PROT_READ|PROT_WRITE,MAP_PRIVATE|MAP_ANON,-1,0x0) = 34366259200 (0x800638000) 0.000053078 issetugid(0x800639015,0x80062e4be,0x80084a0b0,0x80084a080,0xab57,0x0) = 0 (0x0) 0.000078500 open("/etc/libmap.conf",O_RDONLY,0666) ERR#2 'No such file or directory'
0.000039390 open("/var/run/ld-elf.so.hints",O_RDONLY,057) = 3 (0x3)
0.000034920 read(3,"Ehnt\^A\0\0\0\M^@\0\0\0-\0\0\0\0"...,128) = 128 (0x80)
0.000031847 lseek(3,0x80,SEEK_SET)               = 128 (0x80)
0.000029612 read(3,"/lib:/usr/lib:/usr/lib/compat:/u"...,45) = 45 (0x2d)
0.000053357 close(3)                             = 0 (0x0)
0.000040508 access("/lib/libc.so.7",0)                 = 0 (0x0)
0.000035758 open("/lib/libc.so.7",O_RDONLY,040754040) = 3 (0x3)
0.000057828 fstat(3,{ mode=-r--r--r-- ,inode=4107,size=1306952,blksize=32768 }) = 0 (0x0) 0.000037713 pread(0x3,0x80083c800,0x1000,0x0,0x101010101010101,0x8080808080808080) = 4096 (0x1000) 0.000075986 mmap(0x0,3420160,PROT_NONE,MAP_PRIVATE|MAP_ANON|MAP_NOCORE,-1,0x0) = 34368434176 (0x80084b000) 0.000031568 mmap(0x80084b000,1171456,PROT_READ|PROT_EXEC,MAP_PRIVATE|MAP_FIXED|MAP_NOCORE,3,0x0) = 34368434176 (0x80084b000) 0.000048888 mmap(0x800b68000,45056,PROT_READ|PROT_WRITE,MAP_PRIVATE|MAP_FIXED,3,0x11d000) = 34371698688 (0x800b68000) 0.000027656 mmap(0x800b73000,110592,PROT_READ|PROT_WRITE,MAP_PRIVATE|MAP_FIXED|MAP_ANON,-1,0x0) = 34371743744 (0x800b73000)
0.000032405 close(3)                             = 0 (0x0)
0.000033244 munmap(0x80063f000,4096)             = 0 (0x0)
0.000032406 mmap(0x0,102400,PROT_READ|PROT_WRITE,MAP_PRIVATE|MAP_ANON,-1,0x0) = 34366287872 (0x80063f000) 0.000043301 sysarch(0x81,0x7fffffffd450,0x80063c0c8,0x0,0xffffffffffad2228,0x8080808080808080) = 0 (0x0) 0.000032405 sigprocmask(SIG_BLOCK,SIGHUP|SIGINT|SIGQUIT|SIGKILL|SIGPIPE|SIGALRM|SIGTERM|SIGURG|SIGSTOP|SIGTSTP|SIGCONT|SIGCHLD|SIGTTIN|SIGTTOU|SIGIO|SIGXCPU|SIGXFSZ|SIGVTALRM|SIGPROF|SIGWINCH|SIGINFO|SIGUSR1|SIGUSR2,0x0) = 0 (0x0)
0.000028495 sigprocmask(SIG_SETMASK,0x0,0x0)     = 0 (0x0)
0.000068443 sigprocmask(SIG_BLOCK,SIGHUP|SIGINT|SIGQUIT|SIGKILL|SIGPIPE|SIGALRM|SIGTERM|SIGURG|SIGSTOP|SIGTSTP|SIGCONT|SIGCHLD|SIGTTIN|SIGTTOU|SIGIO|SIGXCPU|SIGXFSZ|SIGVTALRM|SIGPROF|SIGWINCH|SIGINFO|SIGUSR1|SIGUSR2,0x0) = 0 (0x0)
0.000030450 sigprocmask(SIG_SETMASK,0x0,0x0)     = 0 (0x0)
0.000084925 readlink("/etc/malloc.conf",0x7fffffffd5e0,1024) ERR#2 'No such file or directory' 0.000024304 issetugid(0x800945101,0x7fffffffd5e0,0xffffffffffffffff,0x0,0x2,0x7fffffffef79) = 0 (0x0)
0.000029891 break(0x800000)                      = 0 (0x0)
0.000029054 mmap(0x0,4194304,PROT_READ|PROT_WRITE,MAP_PRIVATE|MAP_ANON,-1,0x0) = 34371854336 (0x800b8e000) 0.000025701 mmap(0x800f8e000,466944,PROT_READ|PROT_WRITE,MAP_PRIVATE|MAP_ANON,-1,0x0) = 34376048640 (0x800f8e000)
0.000063135 munmap(0x800b8e000,466944)           = 0 (0x0)
0.000030171 gettimeofday({1334522939.716792 },0x0) = 0 (0x0)
0.000464296 stat("1",0x7fffffffdb10) ERR#2 'No such file or directory'
0.000612356 open("1",O_WRONLY|O_CREAT,0666)    = 3 (0x3)
0.000034082 fstat(3,{ mode=-rw-r--r-- ,inode=4,size=0,blksize=32768 }) = 0 (0x0)
0.000058945 close(3)                             = 0 (0x0)
0.000027377 sigprocmask(SIG_BLOCK,SIGHUP|SIGINT|SIGQUIT|SIGKILL|SIGPIPE|SIGALRM|SIGTERM|SIGURG|SIGSTOP|SIGTSTP|SIGCONT|SIGCHLD|SIGTTIN|SIGTTOU|SIGIO|SIGXCPU|SIGXFSZ|SIGVTALRM|SIGPROF|SIGWINCH|SIGINFO|SIGUSR1|SIGUSR2,0x0) = 0 (0x0)
0.000032685 sigprocmask(SIG_SETMASK,0x0,0x0)     = 0 (0x0)
0.000026818 sigprocmask(SIG_BLOCK,SIGHUP|SIGINT|SIGQUIT|SIGKILL|SIGPIPE|SIGALRM|SIGTERM|SIGURG|SIGSTOP|SIGTSTP|SIGCONT|SIGCHLD|SIGTTIN|SIGTTOU|SIGIO|SIGXCPU|SIGXFSZ|SIGVTALRM|SIGPROF|SIGWINCH|SIGINFO|SIGUSR1|SIGUSR2,0x0) = 0 (0x0)
0.000023746 sigprocmask(SIG_SETMASK,0x0,0x0)     = 0 (0x0)
-1.999924294 process exit, rval = 0

Maybe the factor is not this much in real installations, not as in my domU, but still it is slow.

Regards,
Kojedzinszky Richard
Euronet Magyarorszag Informatikai Zrt.

On Sun, 15 Apr 2012, Garrett Cooper wrote:

Date: Sun, 15 Apr 2012 13:35:59 -0700
From: Garrett Cooper <yaneg...@gmail.com>
To: O. Hartmann <ohart...@zedat.fu-berlin.de>
Cc: freebsd-secur...@freebsd.org, Richard Kojedzinszky <kri...@tvnetwork.hu>,
    Current FreeBSD <freebsd-curr...@freebsd.org>,
    freebsd-performance@freebsd.org
Subject: Re: ufs multilabel performance (fwd)

On Apr 15, 2012, at 1:17 PM, O. Hartmann wrote:

Am 04/15/12 22:00, schrieb Garrett Cooper:
On Apr 15, 2012, at 12:30 PM, O. Hartmann wrote:

Am 04/15/12 15:59, schrieb Richard Kojedzinszky:
Thank you for the reply.

Unfortunately, dont know why, but on my xen virtualised environment,
fbsd amd64 domU performs much slower, not only 30 times. Without
multilabel, file creation speed is around 2500/s, but with multilabels
enabled, it is only 15/s (!). so it is more than 100 times slower.

And anyway freebsd is known to be fast as well, as functional. The power
to serve. :)

But in my environment, 15/s file creation is very-very slow. The
hardware is a q6700 cpu with 4G ram, 2x1T sata disks in raid1, the host
runs linux. I think with this hw the mentioned speed is really slow.

Regards,


Kojedzinszky Richard
Euronet Magyarorszag Informatikai Zrt.

On Sun, 15 Apr 2012, O. Hartmann wrote:

Date: Sun, 15 Apr 2012 13:20:23 +0200
From: O. Hartmann <ohart...@zedat.fu-berlin.de>
To: Richard Kojedzinszky <kri...@tvnetwork.hu>
Cc: freebsd-secur...@freebsd.org
Subject: Re: ufs multilabel performance (fwd)

Am 04/14/12 21:37, schrieb Richard Kojedzinszky:
Dear list,

Although it is not only security-related question, I did not get any
answer from freebsd-performance. The original question is below.

Can someone give some advice?

Thanks in advance,


Kojedzinszky Richard
Euronet Magyarorszag Informatikai Zrt.

---------- Forwarded message ----------
Date: Thu, 10 Nov 2011 06:16:57 +0100 (CET)
From: Richard Kojedzinszky <kri...@tvnetwork.hu>
To: freebsd-performance@freebsd.org
Subject: ufs multilabel performance

Dear List,

I've noticed that when I enable multilabel on an fs, a file creation
gets around 20-30 times slower than without multilabel set.

This one-liner can be used to test the differences:
$ truss -D perl -e 'open(F, ">$_.file") for 1 .. 1000'

Same here, creating files seems to be 10 - 30 times slower with
multilabels as it is without.

But as several posts and discussions reflects, FreeBSD isn't supposed to
be fast although it is claimed that writing is the major than reading;
FBSD should serve functionality.

And one can see that the open call takes much more when multilabel is
set on an fs. It seems that only file creation needs that many time,
when a file exists it is opened much faster.

Could someone acknowledge this, and have some suggestions how to make it
faster?

Regards,


Kojedzinszky Richard
TvNetWork Nyrt.
E-mail: krichy (at) tvnetwork [dot] hu
PGP: 0x54B2BF0C8F59B1B7
Fingerprint = F6D4 3FFE AF03 CACF 0DCB  46A1 54B2 BF0C 8F59 B1B7

At the moment, I'm troubled with a nasty kernel bug on all FreeBSD 10
boxes I have spare to test.

I just tried to reproduce your observation and as far as I can go with
my experience, I can confirm that by using your perl script.

I'd like to test this again with a small C program.

I can only test the issue (test is too far optimistic, it's simply a
reproduction of your observation) on FreeBSD 10, the only remaining
FreeBSD server at our department is running FBSD 9-STABLE/amd64 and "in
production", so changing multilabel support is a bit harsh at the moment.


Sorry about crossposting, but I think this belongs more to CURRENT and
PERFORMANCE than SECURITY.

My suggestion is completely take perl out of the equation because the way 
you're invoking it above uses stdio and a few other things that add unnecessary 
overhead.

Try the attached C program/bourne shell snippet instead.

Cheers,
-Garrett

#!/bin/sh

set -e

tmp=$(mktemp -d tmp.XXXXXX)
trap "cd /; rm -Rf $tmp" EXIT
cd $tmp

cat > test_open.c <<EOF

#include <fcntl.h>
#include <stdio.h>
#include <unistd.h>

int
main(void)
{
       char buf[20];
       int i;

       for (i = 0; i < 1000; i++) {
               sprintf(buf, "%d", i);
               close(open(buf, O_WRONLY|O_CREAT, 0600));
       }
       return (0);
}
EOF

gcc -o test_open test_open.c
time ./test_open_______________________________________________

This was pretty fast ;-)

        If it turns out that it wasn't that particular item that's causing a 
slowdown, I can easily modify my above snippet to use stdio, etc. But unless 
the version of perl and a few other items are the same, I wouldn't necessarily 
blame the guest OS. Please also make sure that Xen, etc is completely 
up-to-date because there were some performance degradation issues that were 
fixed post-6.0.
-Garrett
_______________________________________________
freebsd-performance@freebsd.org mailing list
http://lists.freebsd.org/mailman/listinfo/freebsd-performance
To unsubscribe, send any mail to "freebsd-performance-unsubscr...@freebsd.org"

Reply via email to