[PATCH] TDB traverse lock changes for massive AD DC perf improvement
Ralph Böhme
slow at samba.org
Fri Apr 7 11:11:24 UTC 2017
On Fri, Apr 07, 2017 at 09:48:03AM +0200, Ralph Böhme wrote:
> On Fri, Apr 07, 2017 at 08:33:44AM +0200, Volker Lendecke wrote:
> > On Fri, Apr 07, 2017 at 08:23:59AM +0200, Ralph Böhme wrote:
> > > On Fri, Apr 07, 2017 at 08:18:14AM +0200, Volker Lendecke via samba-technical wrote:
> > > > On Fri, Apr 07, 2017 at 05:28:02PM +1200, Douglas Bagnall via samba-technical wrote:
> > > > > I had a go at it. Attached.
> > > > >
> > > > > cheers,
> > > > >
> > > > > Douglas
> > > >
> > > > Thanks, looks interesting! Attached find a version with a bit of
> > > > logging beyond strace. Unsurprisingly works fine on debian jessie. Now
> > > > lets find someone with a Solaris box :-)
> > >
> > > Is this the expected output?
> > >
> > > ---8<---
> > > slow at login [login]:~ > ssh unstable10x
> > > Last login: Fri Apr 7 08:22:49 2017 from login.bo.opencs
> > > Sun Microsystems Inc. SunOS 5.10 Generic January 2005
> > > slow at unstable10x [global]:~ > gcc -o fcntl_deadlock fcntl_deadlock.c
> > > slow at unstable10x [global]:~ > ./fcntl_deadlock
> > > usage: ./fcntl_deadlock <filename>
> > > slow at unstable10x [global]:~ > ./fcntl_deadlock fcntl_deadlock
> > > process 1 lock ofs=0 len=2: Resource temporarily unavailable
> >
> > I guess you need a separate file, not the executable itself :-)
>
> d'oh, sorry!
>
> So:
>
> ---8<---
> slow at unstable10x [global]:~ > touch foo
> slow at unstable10x [global]:~ > ./fcntl_deadlock foo
> process 1 took read lock on range 0,2
> process 2 took read lock on range 0,1
> process 1 starts upgrade on range 0,2
> process 2 got read lock on 1,1
> process 2 released read lock on 0,2
> process 1 got read upgrade done
> process 2 has got to the end
> process 1 has got to the end
> ---8<---
as requested by metze, here's the truss output.
Cheerio!
-slow
-------------- next part --------------
Base time stamp: 1491563342.3542 [ Fri Apr 7 13:09:02 CEST 2017 ]
22590: 0.0000 execve("fcntl_deadlock", 0x08047B68, 0x08047B74) argc = 2
22590: 0.0156 sysinfo(SI_MACHINE, "i86pc", 257) = 6
22590: 0.0158 mmap(0x00000000, 32, PROT_READ|PROT_WRITE|PROT_EXEC, MAP_PRIVATE|MAP_ANON, -1, 0) = 0xFEFF0000
22590: 0.0159 mmap(0x00000000, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANON, -1, 0) = 0xFEFB0000
22590: 0.0159 mmap(0x00000000, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANON, -1, 0) = 0xFEFA0000
22590: 0.0160 memcntl(0xFEFBE000, 13236, MC_ADVISE, MADV_WILLNEED, 0, 0) = 0
22590: 0.0161 memcntl(0x08050000, 2816, MC_ADVISE, MADV_WILLNEED, 0, 0) = 0
22590: 0.0162 resolvepath("/usr/lib/ld.so.1", "/lib/ld.so.1", 1023) = 12
22590: 0.0164 getcwd("/home/slow", 1008) = 0
22590: 0.0165 resolvepath("/home/slow/fcntl_deadlock", "/home/slow/fcntl_deadlock", 1023) = 25
22590: 0.0167 stat64("/home/slow/fcntl_deadlock", 0x08047750) = 0
22590: d=0x04E041C2 i=1056154 m=0100755 l=1 u=17162 g=10000 sz=10324
22590: at = Apr 7 08:21:57 CEST 2017 [ 1491546117.739051999 ]
22590: mt = Apr 7 08:21:57 CEST 2017 [ 1491546117.752120005 ]
22590: ct = Apr 7 08:21:57 CEST 2017 [ 1491546117.752120005 ]
22590: bsz=8192 blks=14 fs=nfs
22590: 0.0169 open("/var/ld/ld.config", O_RDONLY) Err#2 ENOENT
22590: 0.0171 stat64("/opt/csw/lib/libc.so.1", 0x08047000) Err#2 ENOENT
22590: 0.0172 stat64("/lib/libc.so.1", 0x08047000) = 0
22590: d=0x02D50002 i=1163040 m=0100755 l=1 u=0 g=2 sz=1425024
22590: at = Apr 7 13:09:02 CEST 2017 [ 1491563342.371477328 ]
22590: mt = May 29 10:31:34 CEST 2012 [ 1338280294.000000000 ]
22590: ct = Aug 24 01:05:45 CEST 2012 [ 1345763145.730573136 ]
22590: bsz=131072 blks=2823 fs=lofs
22590: 0.0175 resolvepath("/lib/libc.so.1", "/lib/libc.so.1", 1023) = 14
22590: 0.0176 sysconfig(_CONFIG_PAGESIZE) = 4096
22590: 0.0177 open("/lib/libc.so.1", O_RDONLY) = 3
22590: 0.0177 mmap(0x00010000, 32768, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_ALIGN, 3, 0) = 0xFEF90000
22590: 0.0178 mmap(0x00010000, 1216512, PROT_NONE, MAP_PRIVATE|MAP_NORESERVE|MAP_ANON|MAP_ALIGN, -1, 0) = 0xFEE60000
22590: 0.0178 mmap(0xFEE60000, 1109165, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_TEXT, 3, 0) = 0xFEE60000
22590: 0.0179 mmap(0xFEF7F000, 30375, PROT_READ|PROT_WRITE|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_INITDATA, 3, 1110016) = 0xFEF7F000
22590: 0.0179 mmap(0xFEF87000, 4320, PROT_READ|PROT_WRITE|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_ANON, -1, 0) = 0xFEF87000
22590: 0.0180 munmap(0xFEF6F000, 65536) = 0
22590: 0.0180 munmap(0xFEF90000, 32768) = 0
22590: 0.0181 close(3) = 0
22590: 0.0182 mmap(0x00000000, 4096, PROT_READ|PROT_WRITE|PROT_EXEC, MAP_PRIVATE|MAP_ANON, -1, 0) = 0xFEF90000
22590: 0.0182 memcntl(0xFEE60000, 124652, MC_ADVISE, MADV_WILLNEED, 0, 0) = 0
22590: 0.0185 mmap(0x00010000, 24576, PROT_READ|PROT_WRITE|PROT_EXEC, MAP_PRIVATE|MAP_ANON|MAP_ALIGN, -1, 0) = 0xFEF70000
22590: 0.0188 getcontext(0x080475C0)
22590: 0.0188 getrlimit(RLIMIT_STACK, 0x080475B8) = 0
22590: cur = 10485760 max = RLIM_INFINITY
22590: 0.0189 getpid() = 22590 [22570]
22590: 0.0189 lwp_private(0, 1, 0xFEF72A00) = 0x000001C3
22590: 0.0190 setustack(0xFEF72A60)
22590: 0.0191 sysi86(SI86FPSTART, 0xFEF87790, 0x0000133F, 0x00001F80) = 0x00000001
22590: 0.0191 pipe() = 3 [4]
22590: 0.0192 pipe() = 5 [6]
22590: 0.0227 open("foo", O_RDWR|O_CREAT, 037671530350) = 7
22590: 0.0231 schedctl() = 0xFEFF8000
22590: 0.0233 fork1() = 22602
22590: 0.0272 lwp_sigmask(SIG_SETMASK, 0x00000000, 0x00000000) = 0xFFBFFEFF [0x0000FFFF]
22602: 0.0233 fork1() (returning as child ...) = 22590
22602: 0.0276 getpid() = 22602 [22590]
22602: 0.0280 lwp_self() = 1
22602: 0.0282 lwp_sigmask(SIG_SETMASK, 0x00000000, 0x00000000) = 0xFFBFFEFF [0x0000FFFF]
22590: 0.0287 fcntl(7, F_SETLKW, 0x08047AA8) = 0
22590: typ=F_RDLCK whence=SEEK_SET start=0 len=2 sys=4276695007 pid=0
22590: 0.0290 ioctl(1, TCGETA, 0x080479D4) = 0
22590: iflag=0026402 oflag=0014005 cflag=0000275 lflag=0105033 line=0
22590: cc: 003 034 177 025 004 377 377 377
22590: 0.0291 fstat64(1, 0x08047940) = 0
22590: d=0x04A80000 i=12582918 m=0020620 l=1 u=17162 g=7 rdev=0x00600001
22590: at = Apr 7 13:09:02 CEST 2017 [ 1491563342.000000000 ]
22590: mt = Apr 7 13:09:02 CEST 2017 [ 1491563342.000000000 ]
22590: ct = Apr 7 13:06:39 CEST 2017 [ 1491563199.000000000 ]
22590: bsz=8192 blks=1 fs=devfs
22590: 0.0294 write(1, " p r o c e s s 1 t o".., 38) = 38
22602: 0.0295 read(3, " a", 1) = 1
22590: 0.0295 write(4, " a", 1) = 1
22602: 0.0302 fcntl(7, F_SETLKW, 0x08047AA8) = 0
22602: typ=F_RDLCK whence=SEEK_SET start=0 len=1 sys=4278167824 pid=0
22602: 0.0304 ioctl(1, TCGETA, 0x080479D4) = 0
22602: iflag=0026402 oflag=0014005 cflag=0000275 lflag=0105033 line=0
22602: cc: 003 034 177 025 004 377 377 377
22602: 0.0305 fstat64(1, 0x08047940) = 0
22602: d=0x04A80000 i=12582918 m=0020620 l=1 u=17162 g=7 rdev=0x00600001
22602: at = Apr 7 13:09:02 CEST 2017 [ 1491563342.000000000 ]
22602: mt = Apr 7 13:09:02 CEST 2017 [ 1491563342.000000000 ]
22602: ct = Apr 7 13:06:39 CEST 2017 [ 1491563199.000000000 ]
22602: bsz=8192 blks=1 fs=devfs
22602: 0.0310 write(1, " p r o c e s s 2 t o".., 38) = 38
22602: 0.0311 write(6, " b", 1) = 1
22590: 0.0312 read(5, " b", 1) = 1
22590: 0.0314 write(4, " c", 1) = 1
22602: 0.0315 read(3, " c", 1) = 1
22590: 0.0316 write(1, " p r o c e s s 1 s t".., 38) = 38
22602: nanosleep(0x08047AD8, 0x08047AE0) (sleeping...)
22602: tmout: 1.000000000 sec
22590: fcntl(7, F_SETLKW, 0x08047AA8) (sleeping...)
22590: typ=F_WRLCK whence=SEEK_SET start=0 len=2 sys=1 pid=0
22602: 1.0317 nanosleep(0x08047AD8, 0x08047AE0) = 0
22602: tmout: 1.000000000 sec
22602: resid: 0.000000000 sec
22602: 1.0329 fcntl(7, F_SETLKW, 0x08047AA8) = 0
22602: typ=F_RDLCK whence=SEEK_SET start=1 len=1 sys=0 pid=0
22602: 1.0331 write(1, " p r o c e s s 2 g o".., 31) = 31
22602: 1.0339 fcntl(7, F_SETLKW, 0x08047ABC) = 0
22602: typ=F_UNLCK whence=SEEK_SET start=0 len=2 sys=134617040 pid=0
22602: 1.0342 write(1, " p r o c e s s 2 r e".., 36) = 36
22590: 1.1036 fcntl(7, F_SETLKW, 0x08047AA8) = 0
22590: typ=F_WRLCK whence=SEEK_SET start=0 len=2 sys=1 pid=0
22590: 1.1040 write(1, " p r o c e s s 1 g o".., 32) = 32
22602: nanosleep(0x08047AD8, 0x08047AE0) (sleeping...)
22602: tmout: 1.000000000 sec
22602: 2.0343 nanosleep(0x08047AD8, 0x08047AE0) = 0
22602: tmout: 1.000000000 sec
22602: resid: 0.000000000 sec
22590: 2.0346 read(5, " d", 1) = 1
22602: 2.0346 write(6, " d", 1) = 1
22590: 2.0350 write(1, " p r o c e s s 1 h a".., 29) = 29
22602: 2.0350 write(1, " p r o c e s s 2 h a".., 29) = 29
22590: 2.0352 _exit(0)
22602: 2.0353 _exit(0)
More information about the samba-technical
mailing list