devpts mounts too slowly

devpts mounts too slowly

[Alexey Vlasov]

Hi.

In comparison with bind/proc mounting it takes a lot more time mounting
devpts. Is it possible to somehow accelerate the process? Now there are
about 5k devpts mounting, it already took 20 minutes, further will take
even more time.

# time mount -n -i -t devpts none /home/staff/.server-1/dev/pts
real    0m0.295s
user    0m0.000s
sys     0m0.288s

# time mount -i -n --bind /var/bin /home/staff/.server-1/bin
real    0m0.004s
user    0m0.000s
sys     0m0.004s

-- 
BRGDS. Alexey Vlasov.

Re: devpts mounts too slowly

[H. Peter Anvin]

Alexey Vlasov wrote:
> Hi.
> 
> In comparison with bind/proc mounting it takes a lot more time mounting
> devpts. Is it possible to somehow accelerate the process? Now there are
> about 5k devpts mounting, it already took 20 minutes, further will take
> even more time.
> 
> # time mount -n -i -t devpts none /home/staff/.server-1/dev/pts
> real    0m0.295s
> user    0m0.000s
> sys     0m0.288s
> 

A profile would be handy here.  There is no sensible reason for this to
that 0.3 seconds.  This might be RCU-epoch related?

	-hpa

Re: devpts mounts too slowly

[Andrew Morton]

On Wed, 03 Jun 2009 14:28:56 -0700
"H. Peter Anvin" <hpa@zytor.com> wrote:

> Alexey Vlasov wrote:
> > Hi.
> > 
> > In comparison with bind/proc mounting it takes a lot more time mounting
> > devpts. Is it possible to somehow accelerate the process? Now there are
> > about 5k devpts mounting, it already took 20 minutes, further will take
> > even more time.
> > 
> > # time mount -n -i -t devpts none /home/staff/.server-1/dev/pts
> > real    0m0.295s
> > user    0m0.000s
> > sys     0m0.288s
> > 
> 
> A profile would be handy here.  There is no sensible reason for this to
> that 0.3 seconds.  This might be RCU-epoch related?
> 

It seems OK here.

akpm2:/home/akpm/xx# time mount -n -i -t devpts none /tmp/pts
mount -n -i -t devpts none /tmp/pts  0.00s user 0.00s system 0% cpu 0.002 total

Re: devpts mounts too slowly

[Ray Lee]

On Tue, Jun 9, 2009 at 4:19 PM, Andrew Morton<akpm@linux-foundation.org> wrote:
> On Wed, 03 Jun 2009 14:28:56 -0700
> "H. Peter Anvin" <hpa@zytor.com> wrote:
>
>> Alexey Vlasov wrote:
>> > Hi.
>> >
>> > In comparison with bind/proc mounting it takes a lot more time mounting
>> > devpts. Is it possible to somehow accelerate the process? Now there are
>> > about 5k devpts mounting, it already took 20 minutes, further will take
>> > even more time.
>> >
>> > # time mount -n -i -t devpts none /home/staff/.server-1/dev/pts
>> > real    0m0.295s
>> > user    0m0.000s
>> > sys     0m0.288s
>> >
>>
>> A profile would be handy here.  There is no sensible reason for this to
>> that 0.3 seconds.  This might be RCU-epoch related?
>>
>
> It seems OK here.
>
> akpm2:/home/akpm/xx# time mount -n -i -t devpts none /tmp/pts
> mount -n -i -t devpts none /tmp/pts  0.00s user 0.00s system 0% cpu 0.002 total

I read the Original Post as that test being performed with 5k /dev/pts
already mounted.

Re: devpts mounts too slowly

[Andrew Morton]

On Tue, 9 Jun 2009 16:30:31 -0700
Ray Lee <ray-lk@madrabbit.org> wrote:

> On Tue, Jun 9, 2009 at 4:19 PM, Andrew Morton<akpm@linux-foundation.org> wrote:
> > On Wed, 03 Jun 2009 14:28:56 -0700
> > "H. Peter Anvin" <hpa@zytor.com> wrote:
> >
> >> Alexey Vlasov wrote:
> >> > Hi.
> >> >
> >> > In comparison with bind/proc mounting it takes a lot more time mounting
> >> > devpts. Is it possible to somehow accelerate the process? Now there are
> >> > about 5k devpts mounting, it already took 20 minutes, further will take
> >> > even more time.
> >> >
> >> > # time mount -n -i -t devpts none /home/staff/.server-1/dev/pts
> >> > real __ __0m0.295s
> >> > user __ __0m0.000s
> >> > sys __ __ 0m0.288s
> >> >
> >>
> >> A profile would be handy here. __There is no sensible reason for this to
> >> that 0.3 seconds. __This might be RCU-epoch related?
> >>
> >
> > It seems OK here.
> >
> > akpm2:/home/akpm/xx# time mount -n -i -t devpts none /tmp/pts
> > mount -n -i -t devpts none /tmp/pts __0.00s user 0.00s system 0% cpu 0.002 total
> 
> I read the Original Post as that test being performed with 5k /dev/pts
> already mounted.

hm, OK.

I've now mounted 15000 devpts's and still no slowdown is evident.

Re: devpts mounts too slowly

[H. Peter Anvin]

[-- Attachment #1: Type: text/plain, Size: 185 bytes --]

Andrew Morton wrote:
> hm, OK.
> 
> I've now mounted 15000 devpts's and still no slowdown is evident.

This is the test script I used; graphing the results is quite interesting.

	-hpa

[-- Attachment #2: test.sh --]
[-- Type: application/x-shellscript, Size: 284 bytes --]

Re: devpts mounts too slowly

[H. Peter Anvin]

Andrew Morton wrote:
> 
> hm, OK.
> 
> I've now mounted 15000 devpts's and still no slowdown is evident.

I ran my test script, mounting ramfs, with n=100000, and well, gave up
since it hadn't gotten any further than 57000 or so overnight.  At that
time each individual mount was taking several seconds.

Graphing the delays seem to indicate O(n^2) behavior.

umounts do not appear affected; each umount still take negible time.

	-hpa

Re: devpts mounts too slowly

[Al Viro]

On Wed, Jun 10, 2009 at 01:51:25PM -0700, H. Peter Anvin wrote:
> Andrew Morton wrote:
> > 
> > hm, OK.
> > 
> > I've now mounted 15000 devpts's and still no slowdown is evident.
> 
> I ran my test script, mounting ramfs, with n=100000, and well, gave up
> since it hadn't gotten any further than 57000 or so overnight.  At that
> time each individual mount was taking several seconds.
> 
> Graphing the delays seem to indicate O(n^2) behavior.
> 
> umounts do not appear affected; each umount still take negible time.

I think I know what's going on.  /sbin/mount is linked against libselinux
/sbin/umount is not.  And FPOS in question blows if you
	* do not have selinuxfs mounted (e.g. because selinux is not enabled)
	* have a lot of mounts.

What happens is that this piece of crap checks for presence of selinuxfs
on /selinux; then, if the thing isn't there, we go and scan the entire
/proc/mounts in search of selinuxfs mounts.

If akpm has selinux enabled on his testbox and you don't have it on yours,
we have all observations explained.  I'd expect similar slowdown from
ls on an empty directory, BTW - /bin/ls is linked against the same thing,
so it gets hit as well.  Before it even gets to main().

Re: devpts mounts too slowly

[Andrew Morton]

On Wed, 24 Jun 2009 21:01:08 +0100
Al Viro <viro@ZenIV.linux.org.uk> wrote:

> On Wed, Jun 10, 2009 at 01:51:25PM -0700, H. Peter Anvin wrote:
> > Andrew Morton wrote:
> > > 
> > > hm, OK.
> > > 
> > > I've now mounted 15000 devpts's and still no slowdown is evident.
> > 
> > I ran my test script, mounting ramfs, with n=100000, and well, gave up
> > since it hadn't gotten any further than 57000 or so overnight.  At that
> > time each individual mount was taking several seconds.
> > 
> > Graphing the delays seem to indicate O(n^2) behavior.
> > 
> > umounts do not appear affected; each umount still take negible time.
> 
> I think I know what's going on.  /sbin/mount is linked against libselinux
> /sbin/umount is not.  And FPOS in question blows if you
> 	* do not have selinuxfs mounted (e.g. because selinux is not enabled)
> 	* have a lot of mounts.
> 
> What happens is that this piece of crap checks for presence of selinuxfs
> on /selinux; then, if the thing isn't there, we go and scan the entire
> /proc/mounts in search of selinuxfs mounts.
> 
> If akpm has selinux enabled on his testbox and you don't have it on yours,
> we have all observations explained.

CONFIG_SECURITY_SELINUX=y
CONFIG_SECURITY_SELINUX_BOOTPARAM=y
CONFIG_SECURITY_SELINUX_BOOTPARAM_VALUE=1
CONFIG_SECURITY_SELINUX_DISABLE=y
CONFIG_SECURITY_SELINUX_DEVELOP=y
CONFIG_SECURITY_SELINUX_AVC_STATS=y
CONFIG_SECURITY_SELINUX_CHECKREQPROT_VALUE=1
# CONFIG_SECURITY_SELINUX_ENABLE_SECMARK_DEFAULT is not set
# CONFIG_SECURITY_SELINUX_POLICYDB_VERSION_MAX is not set

>  I'd expect similar slowdown from
> ls on an empty directory, BTW - /bin/ls is linked against the same thing,
> so it gets hit as well.  Before it even gets to main().

Re: devpts mounts too slowly

[H. Peter Anvin]

Andrew Morton wrote:
>>>
>>> umounts do not appear affected; each umount still take negible time.
>> I think I know what's going on.  /sbin/mount is linked against libselinux
>> /sbin/umount is not.  And FPOS in question blows if you
>> 	* do not have selinuxfs mounted (e.g. because selinux is not enabled)
>> 	* have a lot of mounts.
>>
>> What happens is that this piece of crap checks for presence of selinuxfs
>> on /selinux; then, if the thing isn't there, we go and scan the entire
>> /proc/mounts in search of selinuxfs mounts.
>>
>> If akpm has selinux enabled on his testbox and you don't have it on yours,
>> we have all observations explained.
> 
> CONFIG_SECURITY_SELINUX=y
> CONFIG_SECURITY_SELINUX_BOOTPARAM=y
> CONFIG_SECURITY_SELINUX_BOOTPARAM_VALUE=1
> CONFIG_SECURITY_SELINUX_DISABLE=y
> CONFIG_SECURITY_SELINUX_DEVELOP=y
> CONFIG_SECURITY_SELINUX_AVC_STATS=y
> CONFIG_SECURITY_SELINUX_CHECKREQPROT_VALUE=1
> # CONFIG_SECURITY_SELINUX_ENABLE_SECMARK_DEFAULT is not set
> # CONFIG_SECURITY_SELINUX_POLICYDB_VERSION_MAX is not set
> 

Wow.  It doesn't even check for selinux actually being enabled before
embarking on this stupidity.

FAIL.

	-hpa

Re: devpts mounts too slowly

[H. Peter Anvin]

Ray Lee wrote:
>>
>> akpm2:/home/akpm/xx# time mount -n -i -t devpts none /tmp/pts
>> mount -n -i -t devpts none /tmp/pts  0.00s user 0.00s system 0% cpu 0.002 total
> 
> I read the Original Post as that test being performed with 5k /dev/pts
> already mounted.

A quick script seems to confirm that the time starts creeping up as the
number of mount points increase; on my Core i7 system the 10000th mount
takes around 50 ms whereas the early instances are submillisecond, and
the increase *seems* to be O(n log n) or thereabouts -- slightly
superlinear but not a good fit for a power law.

The same thing happens with ramfs, so the problem is either in libfs or
in the VFS; I suspect the latter as I don't really think we have had a
huge reason to optimize a very large number of mounts in the past.

	-hpa

Re: devpts mounts too slowly

[Alexey Vlasov]

On Tue, Jun 09, 2009 at 05:02:59PM -0700, H. Peter Anvin wrote:

> A quick script seems to confirm that the time starts creeping up as the
> number of mount points increase; on my Core i7 system the 10000th mount
> takes around 50 ms whereas the early instances are submillisecond, and
> the increase *seems* to be O(n log n) or thereabouts -- slightly
> superlinear but not a good fit for a power law.

I have prepared a new machine for testing, and I don't see any slowdown
by mounting devpts.
Total mounts on it:
# wc -l /proc/mounts
153481 /proc/mounts
# fgrep -c devpts /proc/mounts
10231

On my other servers there're slowdown already by this number of:
# wc -l /proc/mounts
49889 /proc/mounts
# fgrep -c devpts /proc/mounts
3323

But the first box is totally empty, others are in use, may be this
matters?

-- 
BRGDS. Alexey Vlasov.

Re: devpts mounts too slowly

[Alexey Vlasov]

On Mon, Jul 06, 2009 at 11:52:52PM +0400, Alexey Vlasov wrote:
> On Tue, Jun 09, 2009 at 05:02:59PM -0700, H. Peter Anvin wrote:
> 
> > A quick script seems to confirm that the time starts creeping up as the
> > number of mount points increase; on my Core i7 system the 10000th mount
> > takes around 50 ms whereas the early instances are submillisecond, and
> > the increase *seems* to be O(n log n) or thereabouts -- slightly
> > superlinear but not a good fit for a power law.
> 
> I have prepared a new machine for testing, and I don't see any slowdown
> by mounting devpts.
> Total mounts on it:
> # wc -l /proc/mounts
> 153481 /proc/mounts
> # fgrep -c devpts /proc/mounts
> 10231
> 
> On my other servers there're slowdown already by this number of:
> # wc -l /proc/mounts
> 49889 /proc/mounts
> # fgrep -c devpts /proc/mounts
> 3323

One more notice, box with slowdowns:
...
geteuid()                               = 0
getcwd("/home/staff/r_renton"..., 4095) = 21
readlink("/home/staff/r_renton/none", 0x7ffffa32aa00, 4096) = -1 ENOENT
(No such file or directory)
rt_sigprocmask(SIG_BLOCK, ~[TRAP SEGV RTMIN RT_1], NULL, 8) = 0
mount("none", "/home/www/server_7e014b11/dev/pts",
"devpts", MS_MGC_VAL, NULL) = 0
getcwd("/home/staff/r_renton"..., 4095) = 21
...

And this on the new one, about 100k mounting points and no
slowdowns at all.
...
getuid()                                = 0
geteuid()                               = 0
rt_sigprocmask(SIG_BLOCK, ~[TRAP SEGV RTMIN RT_1], NULL, 8) = 0
mount("none", "/home/www/server_56d48c7d/dev/pts", "devpts",
MS_MGC_VAL, NULL) = 0
readlink("/home", 0x7fff79a82e10, 4096) = -1 EINVAL (Invalid argument)
...

-- 
BRGDS. Alexey Vlasov.

Re: devpts mounts too slowly

[H. Peter Anvin]

Alexey Vlasov wrote:
> On Tue, Jun 09, 2009 at 05:02:59PM -0700, H. Peter Anvin wrote:
> 
>> A quick script seems to confirm that the time starts creeping up as the
>> number of mount points increase; on my Core i7 system the 10000th mount
>> takes around 50 ms whereas the early instances are submillisecond, and
>> the increase *seems* to be O(n log n) or thereabouts -- slightly
>> superlinear but not a good fit for a power law.
> 
> I have prepared a new machine for testing, and I don't see any slowdown
> by mounting devpts.
> Total mounts on it:
> # wc -l /proc/mounts
> 153481 /proc/mounts
> # fgrep -c devpts /proc/mounts
> 10231
> 
> On my other servers there're slowdown already by this number of:
> # wc -l /proc/mounts
> 49889 /proc/mounts
> # fgrep -c devpts /proc/mounts
> 3323
> 
> But the first box is totally empty, others are in use, may be this
> matters?
> 

Do you have /selinux mounted on one of them?

	-hpa

Re: devpts mounts too slowly

[Alexey Vlasov]

On Mon, Jul 06, 2009 at 02:21:51PM -0700, H. Peter Anvin wrote:
>
> Do you have /selinux mounted on one of them?

I don't use SELinux anywhere.

-- 
BRGDS. Alexey Vlasov.

Re: devpts mounts too slowly

[H. Peter Anvin]

Alexey Vlasov wrote:
> On Mon, Jul 06, 2009 at 02:21:51PM -0700, H. Peter Anvin wrote:
>> Do you have /selinux mounted on one of them?
> 
> I don't use SELinux anywhere.
> 

That's, apparently, the problem: some version of the mount binary will
search all of /proc/mounts for selinux if it isn't mounted on /selinux.
 This is a serious performance bug, obviously.

	-hpa

-- 
H. Peter Anvin, Intel Open Source Technology Center
I work for Intel.  I don't speak on their behalf.