On Sun Apr 15 12, Alexander Best wrote:
> On Sun Apr 15 12, Alexander Best wrote:
> > On Sun Apr 15 12, Alexander Leidinger wrote:
> > > On Sun, 15 Apr 2012 13:03:06 +0000 Alexander Best <arun...@freebsd.org>
> > > wrote:
> > >
> > > > On Sun Apr 15 12, Alexander Leidinger wrote:
> > > > > On Sun, 15 Apr 2012 11:51:12 +0000 Alexander Best
> > > > > <arun...@freebsd.org> wrote:
> > > > >
> > > > > > ahh ok. i've managed to get some stats via stats_timing.d. this
> > > > > > is a snapshot during which a newly loaded tab in chromium was
> > > > > > unresponsive for about 5 seconds. without the linux flash plugin
> > > > > > running i never experienced such lock ups.
> > > > > >
> > > > > > i've attached the d-script stats.
> > > > >
> > > > > What about the trace_futexes script and the two check_* scripts? The
> > > > > stats show that there is a lot of work spend in the futexes.
> > > >
> > > > i'm having problems with those scripts. they have a negative impact
> > > > on the linux processes. when i have the player at www.mixcloud.com
> > > > running and run those scripts the music stops and the flash graphics
> > > > get all distorted. here's some output from the trace_futexes.d script:
> > > >
> > > > otaku% sudo ./trace_futexes.d
> > > > dtrace: 808 dynamic variable drops with non-empty dirty list
> > > > dtrace: 833 failed speculations (available buffer(s) still busy)
> > >
> > > You should increase the buffers in the scripts, they are overflowing.
> > >
> > > [...]
> > > > ERROR: missing_access_check in linuxulator32:futex:futex_atomic_op
> > >
> > > This is missing code in the kernel... or a superfluous comment.
> > >
> > > > kernel`ia32_syscall+0x299
> > > > kernel`0xffffffff805b05e5
> > > >
> > > > dtrace: ERROR: open failed: No such file or directory
> > > > `0x287b6533
> > > > Fatal error 'mutex is on list' at line 424 in
> > > > file /usr/github-freebsd-head/lib/libthr/thread/thr_mutex.c (errno =
> > > > 0)
> > >
> > > No idea.
> > >
> > > > this is from the check_error.d script:
> > > >
> > > > otaku% sudo ./check_error.d
> > > > ERROR: sleep_error in linuxulator32:futex:futex_sleep
> > >
> > > Well... the sx_sleep returned with a non-null value. I assume this
> > > means a timeout fired. No idea if it is good or bad.
> > >
> > > > kernel`ia32_syscall+0x299
> > > > kernel`0xffffffff805b05e5
> > > >
> > > > 0x287b6278
> > > > 0x2a12800029d5fa5c
> > > > ERROR: sleep_error in linuxulator32:futex:futex_wait
> > >
> > > As above.
> > >
> > > > kernel`ia32_syscall+0x299
> > > > kernel`0xffffffff805b05e5
> > > >
> > > > 0x287b6278
> > > > 0x2a12800029d5fa5c
> > >
> > > > the check_internal_locks.d scripts seems to work fine. i think we
> > > > talked about the failed-speculation-warnings beforehand and that they
> > > > aren't critical:
> > >
> > > Yes and no... you do not have enough buffers to store all the info the
> > > script want to store. As such it does not work as intended.
> >
> > i've set
> >
> > #pragma D option dynvarsize=512m
> > #pragma D option specsize=512m
> >
> > in check_internal_locks.d
> >
> > however i get a warning that the size got downgraded and still the buffers
> > don't seem to be large enough:
> >
> > dtrace: dynamic variable size lowered to 256m
> > dtrace: 220 failed speculations (available buffer(s) still busy)
> > dtrace: 206 failed speculations (available buffer(s) still busy)
> > dtrace: 205 failed speculations (available buffer(s) still busy)
> > dtrace: 206 failed speculations (available buffer(s) still busy)
> > dtrace: 182 failed speculations (available buffer(s) still busy)
> > dtrace: 219 failed speculations (available buffer(s) still busy)
> > dtrace: 194 failed speculations (available buffer(s) still busy)
> > dtrace: 210 failed speculations (available buffer(s) still busy)
> > dtrace: 218 failed speculations (available buffer(s) still busy)
> > dtrace: 206 failed speculations (available buffer(s) still busy)
> > dtrace: 222 failed speculations (available buffer(s) still busy)
> > dtrace: 214 failed speculations (available buffer(s) still busy)
> > dtrace: 213 failed speculations (available buffer(s) still busy)
> > dtrace: 205 failed speculations (available buffer(s) still busy)
> > dtrace: 216 failed speculations (available buffer(s) still busy)
> > dtrace: 220 failed speculations (available buffer(s) still busy)
> > dtrace: 210 failed speculations (available buffer(s) still busy)
> >
> > maybe the problem with the above errors was that my kernel got built with
> > dtrace support, but my world didn't. i'm now rebuilding and installing
> > world.
> > maybe that fixes some of the issues.
> >
> > >
> > >
> > > > Number of locks per type:
> > > > emul_shared_rlock 3
> > > > emul_shared_wlock 37
> > > > emul_lock 55
> > > > futex_mtx 31179
>
> here are the results for a single flash instance:
>
> otaku% sudo time ./check_internal_locks.d
> dtrace: 217 failed speculations (available buffer(s) still busy)
> dtrace: 223 failed speculations (available buffer(s) still busy)
> dtrace: 218 failed speculations (available buffer(s) still busy)
> dtrace: 216 failed speculations (available buffer(s) still busy)
> dtrace: 206 failed speculations (available buffer(s) still busy)
> dtrace: 200 failed speculations (available buffer(s) still busy)
> dtrace: 218 failed speculations (available buffer(s) still busy)
> dtrace: 246 failed speculations (available buffer(s) still busy)
> dtrace: 218 failed speculations (available buffer(s) still busy)
> dtrace: 258 failed speculations (available buffer(s) still busy)
> dtrace: 223 failed speculations (available buffer(s) still busy)
> dtrace: 246 failed speculations (available buffer(s) still busy)
> dtrace: 240 failed speculations (available buffer(s) still busy)
> dtrace: 258 failed speculations (available buffer(s) still busy)
> dtrace: 252 failed speculations (available buffer(s) still busy)
> dtrace: 230 failed speculations (available buffer(s) still busy)
> dtrace: 257 failed speculations (available buffer(s) still busy)
> ^C
> dtrace: 227 failed speculations (available buffer(s) still busy)
> Number of locks per type:
> futex_mtx 4585
>
> 18,48 real 0,10 user 0,36 sys
>
> and here for two flash tabs:
>
> otaku% sudo time ./check_internal_locks.d
> dtrace: 1148 failed speculations (available buffer(s) still busy)
> dtrace: 1524 failed speculations (available buffer(s) still busy)
> dtrace: 1604 failed speculations (available buffer(s) still busy)
> dtrace: 1029 failed speculations (available buffer(s) still busy)
> dtrace: 1471 failed speculations (available buffer(s) still busy)
> dtrace: 1466 failed speculations (available buffer(s) still busy)
> dtrace: 1720 failed speculations (available buffer(s) still busy)
> dtrace: 1049 failed speculations (available buffer(s) still busy)
> dtrace: 1549 failed speculations (available buffer(s) still busy)
> dtrace: 1421 failed speculations (available buffer(s) still busy)
> dtrace: 1595 failed speculations (available buffer(s) still busy)
> dtrace: 1097 failed speculations (available buffer(s) still busy)
> dtrace: 1853 failed speculations (available buffer(s) still busy)
> dtrace: 1900 failed speculations (available buffer(s) still busy)
> dtrace: 1729 failed speculations (available buffer(s) still busy)
> dtrace: 1389 failed speculations (available buffer(s) still busy)
> dtrace: 1314 failed speculations (available buffer(s) still busy)
> dtrace: 1712 failed speculations (available buffer(s) still busy)
> ^C
> dtrace: 1615 failed speculations (available buffer(s) still busy)
> Number of locks per type:
> futex_mtx 29364
>
> 19,41 real 0,09 user 0,32 sys
>
> ...and for three flash tabs:
>
> otaku% sudo time ./check_internal_locks.d
> dtrace: 535 failed speculations (available buffer(s) still busy)
> dtrace: 213 failed speculations (available buffer(s) still busy)
> dtrace: 282 failed speculations (available buffer(s) still busy)
> dtrace: 571 failed speculations (available buffer(s) still busy)
> dtrace: 666 failed speculations (available buffer(s) still busy)
> dtrace: 857 failed speculations (available buffer(s) still busy)
> dtrace: 1310 failed speculations (available buffer(s) still busy)
> dtrace: 1277 failed speculations (available buffer(s) still busy)
> dtrace: 118 failed speculations (available buffer(s) still busy)
> dtrace: 1503 failed speculations (available buffer(s) still busy)
> dtrace: 2069 failed speculations (available buffer(s) still busy)
> dtrace: 3562 failed speculations (available buffer(s) still busy)
> dtrace: 6561 failed speculations (available buffer(s) still busy)
> dtrace: 3750 failed speculations (available buffer(s) still busy)
> dtrace: 2569 failed speculations (available buffer(s) still busy)
> dtrace: 1362 failed speculations (available buffer(s) still busy)
> dtrace: 2722 failed speculations (available buffer(s) still busy)
> dtrace: 3461 failed speculations (available buffer(s) still busy)
> dtrace: 2579 failed speculations (available buffer(s) still busy)
> dtrace: 3451 failed speculations (available buffer(s) still busy)
> dtrace: 2325 failed speculations (available buffer(s) still busy)
> ^C
> dtrace: 2632 failed speculations (available buffer(s) still busy)
> Number of locks per type:
> emul_shared_wlock 14
> emul_lock 20
> futex_mtx 45571
>
> 22,46 real 0,11 user 0,35 sys
running stats_timing.d revealed something strange...according to this section:
Number of calls per provider/application/kernel function:
linuxulator32 npviewer.bin
linux_schedtail
2
linuxulator32 npviewer.bin
linux_set_robust_list
2
linuxulator32 npviewer.bin
proc_exit
2
linuxulator32 npviewer.bin
proc_init
2
linuxulator32 npviewer.bin
release_futexes
2
linuxulator32 npviewer.bin
fetch_robust_entry
4
linuxulator32 npviewer.bin
linux_get_osname
8
linuxulator32 npviewer.bin
linux_get_osrelease
8
linuxulator32 npviewer.bin
em_find
12
linuxulator32 npviewer.bin
linux_get_prison
16
linuxulator32 npviewer.bin
futex_atomic_op
734
linuxulator32 npviewer.bin
futex_wake
1082
linuxulator32 npviewer.bin
futex_sleep
1133
linuxulator32 npviewer.bin
futex_wait
1133
linuxulator32 npviewer.bin
linux_emul_convpath
2949
linuxulator32 npviewer.bin
futex_put
2970
linuxulator32 npviewer.bin
linux_sys_futex
3211
linuxulator32 npviewer.bin
futex_get
3945
linuxulator32 npviewer.bin
futex_get0
3945
linuxulator32 npviewer.bin
linux_clock_gettime
75342
linuxulator32 npviewer.bin
linux_to_native_clockid
75342
linuxulator32 npviewer.bin
native_to_linux_timespec
75342
proc_exit only got callded twice. however according to this section:
Longest running (CPU-time!) functions per provider (in ns):
linuxulator32 proc_exit
-16995
linuxulator32 linux_emul_convpath
-11330
linuxulator32 futex_wait
-3950
linuxulator32 futex_sleep
-3535
linuxulator32 proc_init
-3310
linuxulator32 release_futexes
-2075
linuxulator32 linux_schedtail
-1350
linuxulator32 linux_get_osname
-1280
linuxulator32 linux_sys_futex
-1090
linuxulator32 linux_set_robust_list
-860
linuxulator32 futex_get
-770
linuxulator32 linux_get_osrelease
-760
linuxulator32 linux_clock_gettime
-570
linuxulator32 futex_put
-560
linuxulator32 futex_get0
-555
linuxulator32 futex_atomic_op
-325
linuxulator32 em_find
-190
linuxulator32 fetch_robust_entry
-180
linuxulator32 linux_get_prison
-155
linuxulator32 futex_wake
-120
linuxulator32 linux_to_native_clockid
-90
linuxulator32 native_to_linux_timespec
-90
the CPU spent a lot of time for those two calls.
cheers.
alex
>
>
> i've tuned the script to have the maximum buffer size of 256 megabyte via
>
> #pragma D option dynvarsize=256m
> #pragma D option specsize=256m
>
> ...still the buffers seem to be too small.
>
> also...even after installing a fresh kernel and world with dtrace enabled,
> the "check_error.d" and "trace_futexes.d" fail and sometimes even render
> the flash instance unusable.
>
> cheers.
> alex
>
> > >
> > > Depending on how long you traced: that's a lot of futex operations.
> >
> > i traced for ~ 5 seconds. i'll make sure to prepend the time command to any
> > dtrace script next time to give you more exact numbers.
> >
> > cheers.
> > alex
> >
> > >
> > > Bye,
> > > Alexander.
> > >
> > > --
> > > http://www.Leidinger.net Alexander @ Leidinger.net: PGP ID = B0063FE7
> > > http://www.FreeBSD.org netchild @ FreeBSD.org : PGP ID = 72077137
_______________________________________________
freebsd-emulation@freebsd.org mailing list
http://lists.freebsd.org/mailman/listinfo/freebsd-emulation
To unsubscribe, send any mail to "freebsd-emulation-unsubscr...@freebsd.org"
