Hi, I am a newbie in dtrace. There is a multi-thread application running in my box. But looking prstat ?Lmp <java> i saw that almost all time is LCK and SLP. A ran plockstat and saw the most locks were malloc, so I changed my application to use mtmalloc, but didn?t resolv the problem. After changed malloc to mtmalloc, i ran again plockstat and i?m still getting many locks. How can I use better dtrace to find out the problem ? PID USERNAME USR SYS TRP TFL DFL LCK SLP LAT VCX ICX SCL SIG PROCESS/LWPID 5637 root 94 0,0 0,0 0,0 0,0 4,2 0,0 1,4 19 96 61 0 java/7 5637 root 1,3 0,2 0,0 0,0 0,0 98 0,0 0,2 2K 7 2K 0 java/5 5637 root 1,1 0,2 0,0 0,0 0,0 98 0,0 0,3 3K 16 3K 0 java/3 5637 root 1,1 0,1 0,0 0,0 0,0 98 0,1 0,4 1K 6 1K 0 java/4 5637 root 1,1 0,1 0,0 0,0 0,0 98 0,0 0,4 1K 10 1K 0 java/6 5637 root 0,7 0,1 0,0 0,0 0,0 33 65 0,8 11 17 129 0 java/347 5637 root 0,7 0,1 0,0 0,0 0,0 65 34 0,0 20 0 129 0 java/134 5637 root 0,6 0,1 0,0 0,0 0,0 93 5,7 0,2 21 1 133 0 java/84 5637 root 0,4 0,1 0,0 0,0 0,0 49 51 0,1 20 1 135 0 java/435 5637 root 0,5 0,1 0,0 0,0 0,0 14 85 0,1 16 0 87 0 java/162 5637 root 0,5 0,0 0,0 0,0 0,0 23 76 0,8 3 2 44 0 java/291 5637 root 0,4 0,1 0,0 0,0 0,0 36 63 0,6 9 5 81 0 java/412 5637 root 0,4 0,1 0,0 0,0 0,0 52 46 1,0 9 0 70 0 java/370 5637 root 0,3 0,1 0,0 0,0 0,0 81 17 1,2 9 4 75 0 java/376 5637 root 0,3 0,1 0,0 0,0 0,0 37 63 0,0 8 0 77 0 java/174 5637 root 0,3 0,1 0,0 0,0 0,0 42 57 0,1 7 1 61 0 java/145 5637 root 0,3 0,1 0,0 0,0 0,0 43 56 0,9 12 11 53 0 java/114 5637 root 0,2 0,1 0,0 0,0 0,0 2,6 96 0,8 8 0 38 0 java/269 5637 root 0,3 0,0 0,0 0,0 0,0 98 0,1 1,1 10 0 38 0 java/361 5637 root 0,2 0,1 0,0 0,0 0,0 2,4 97 0,0 6 2 37 0 java/81 5637 root 0,2 0,1 0,0 0,0 0,0 84 14 1,2 6 7 57 0 java/292 5637 root 0,2 0,1 0,0 0,0 0,0 2,5 97 0,3 5 1 33 0 java/192 5637 root 0,2 0,1 0,0 0,0 0,0 85 14 0,8 7 8 54 0 java/212 5637 root 0,2 0,1 0,0 0,0 0,0 3,2 96 0,2 6 6 36 0 java/149 5637 root 0,2 0,0 0,0 0,0 0,0 42 58 0,1 7 1 50 1 java/411 5637 root 0,2 0,1 0,0 0,0 0,0 2,3 97 0,3 8 3 38 0 java/236 5637 root 0,2 0,1 0,0 0,0 0,0 43 56 0,9 10 4 44 0 java/438 5637 root 0,2 0,0 0,0 0,0 0,0 2,5 97 0,1 5 1 34 0 java/137 5637 root 0,2 0,0 0,0 0,0 0,0 2,2 98 0,0 7 1 34 0 java/179 5637 root 0,1 0,1 0,0 0,0 0,0 2,5 97 0,6 1 4 111 0 java/20 5637 root 0,2 0,0 0,0 0,0 0,0 91 8,2 0,2 4 8 48 0 java/72 5637 root 0,2 0,0 0,0 0,0 0,0 3,1 97 0,2 6 2 35 0 java/75 5637 root 0,2 0,0 0,0 0,0 0,0 21 78 0,2 3 2 38 0 java/109 5637 root 0,2 0,0 0,0 0,0 0,0 89 9,9 0,9 3 6 36 0 java/256 5637 root 0,2 0,0 0,0 0,0 0,0 99 0,0 1,0 4 8 39 1 java/458 Total: 1 processes, 489 lwps, load averages: 1,92, 1,74, 1,65 Atenciosamente, ------------------------------------------------------------------ Kleyson Rios. Ger?ncia de Suporte T?cnico Analista de Suporte / L?der de Equipe Governo do Estado de Goi?s Ag?ncia de Administra??o Diretoria de Inform?tica +55 62 3201-6582 "Voc? sabe a diferen?a entre pessoas bem sucedidas e pessoas mal sucedidas ? Pessoas bem sucedidas est?o dispostas a fazer as coisas que as pessoas mal sucedidas n?o est?o." -------------- next part -------------- An HTML attachment was scrubbed... URL: <http://mail.opensolaris.org/pipermail/dtrace-discuss/attachments/20080415/0a5aec98/attachment.html>
Try linking the JVM to libumem.so.1 (export LD_PRELOAD=/usr/lib/libumem.so.1) I have, in the past, been able to reduce lock contention in malloc using libumem malloc. If that does not help, you need to see where the mallocs are coming from in the code, and see if there''s opportunity to change the app such that the JVM makes fewer malloc calls. dtrace -n ''pid$target:libc:malloc:entry { @s[jstack()] = count() }'' 500 threads - does your need that many threads? Are the locks mostly associated with condition variables? Typically, the only way to solve lock contention problems is by changing the code... HTH, /jim Kleyson Rios wrote:> > Hi, > > I am a newbie in dtrace. > > There is a multi-thread application running in my box. But looking > prstat ?Lmp <java> i saw that almost all time is LCK and SLP. > > A ran plockstat and saw the most locks were malloc, so I changed my > application to use mtmalloc, but didn?t resolv the problem. > > After changed malloc to mtmalloc, i ran again plockstat and i?m still > getting many locks. > > How can I use better dtrace to find out the problem ? > > PID USERNAME USR SYS TRP TFL DFL LCK SLP LAT VCX ICX SCL SIG > PROCESS/LWPID > > 5637 root 94 0,0 0,0 0,0 0,0 4,2 0,0 1,4 19 96 61 0 java/7 > > 5637 root 1,3 0,2 0,0 0,0 0,0 98 0,0 0,2 2K 7 2K 0 java/5 > > 5637 root 1,1 0,2 0,0 0,0 0,0 98 0,0 0,3 3K 16 3K 0 java/3 > > 5637 root 1,1 0,1 0,0 0,0 0,0 98 0,1 0,4 1K 6 1K 0 java/4 > > 5637 root 1,1 0,1 0,0 0,0 0,0 98 0,0 0,4 1K 10 1K 0 java/6 > > 5637 root 0,7 0,1 0,0 0,0 0,0 33 65 0,8 11 17 129 0 java/347 > > 5637 root 0,7 0,1 0,0 0,0 0,0 65 34 0,0 20 0 129 0 java/134 > > 5637 root 0,6 0,1 0,0 0,0 0,0 93 5,7 0,2 21 1 133 0 java/84 > > 5637 root 0,4 0,1 0,0 0,0 0,0 49 51 0,1 20 1 135 0 java/435 > > 5637 root 0,5 0,1 0,0 0,0 0,0 14 85 0,1 16 0 87 0 java/162 > > 5637 root 0,5 0,0 0,0 0,0 0,0 23 76 0,8 3 2 44 0 java/291 > > 5637 root 0,4 0,1 0,0 0,0 0,0 36 63 0,6 9 5 81 0 java/412 > > 5637 root 0,4 0,1 0,0 0,0 0,0 52 46 1,0 9 0 70 0 java/370 > > 5637 root 0,3 0,1 0,0 0,0 0,0 81 17 1,2 9 4 75 0 java/376 > > 5637 root 0,3 0,1 0,0 0,0 0,0 37 63 0,0 8 0 77 0 java/174 > > 5637 root 0,3 0,1 0,0 0,0 0,0 42 57 0,1 7 1 61 0 java/145 > > 5637 root 0,3 0,1 0,0 0,0 0,0 43 56 0,9 12 11 53 0 java/114 > > 5637 root 0,2 0,1 0,0 0,0 0,0 2,6 96 0,8 8 0 38 0 java/269 > > 5637 root 0,3 0,0 0,0 0,0 0,0 98 0,1 1,1 10 0 38 0 java/361 > > 5637 root 0,2 0,1 0,0 0,0 0,0 2,4 97 0,0 6 2 37 0 java/81 > > 5637 root 0,2 0,1 0,0 0,0 0,0 84 14 1,2 6 7 57 0 java/292 > > 5637 root 0,2 0,1 0,0 0,0 0,0 2,5 97 0,3 5 1 33 0 java/192 > > 5637 root 0,2 0,1 0,0 0,0 0,0 85 14 0,8 7 8 54 0 java/212 > > 5637 root 0,2 0,1 0,0 0,0 0,0 3,2 96 0,2 6 6 36 0 java/149 > > 5637 root 0,2 0,0 0,0 0,0 0,0 42 58 0,1 7 1 50 1 java/411 > > 5637 root 0,2 0,1 0,0 0,0 0,0 2,3 97 0,3 8 3 38 0 java/236 > > 5637 root 0,2 0,1 0,0 0,0 0,0 43 56 0,9 10 4 44 0 java/438 > > 5637 root 0,2 0,0 0,0 0,0 0,0 2,5 97 0,1 5 1 34 0 java/137 > > 5637 root 0,2 0,0 0,0 0,0 0,0 2,2 98 0,0 7 1 34 0 java/179 > > 5637 root 0,1 0,1 0,0 0,0 0,0 2,5 97 0,6 1 4 111 0 java/20 > > 5637 root 0,2 0,0 0,0 0,0 0,0 91 8,2 0,2 4 8 48 0 java/72 > > 5637 root 0,2 0,0 0,0 0,0 0,0 3,1 97 0,2 6 2 35 0 java/75 > > 5637 root 0,2 0,0 0,0 0,0 0,0 21 78 0,2 3 2 38 0 java/109 > > 5637 root 0,2 0,0 0,0 0,0 0,0 89 9,9 0,9 3 6 36 0 java/256 > > 5637 root 0,2 0,0 0,0 0,0 0,0 99 0,0 1,0 4 8 39 1 java/458 > > Total: 1 processes, 489 lwps, load averages: 1,92, 1,74, 1,65 > > Atenciosamente, > > ------------------------------------------------------------------ > > Kleyson Rios. > > Ger?ncia de Suporte T?cnico > > Analista de Suporte / L?der de Equipe > > Governo do Estado de Goi?s > > Ag?ncia de Administra??o > > Diretoria de Inform?tica > > +55 62 3201-6582 > > "Voc? sabe a diferen?a entre pessoas bem sucedidas e pessoas mal > sucedidas ? > > Pessoas bem sucedidas est?o dispostas a fazer as coisas que as pessoas > mal sucedidas n?o est?o." > > ------------------------------------------------------------------------ > > _______________________________________________ > dtrace-discuss mailing list > dtrace-discuss at opensolaris.org >
We had such case in the past. I don''t think it is the same reason but might give you some ideas. We had a lot of locks. By using plockstat it turned out that those locks comes from malloc. Using mtmalloc or libumem reduced a number of locks but it was still a huge number (and eating our CPU). By using dtrace it turned out that those locks comes from threads which were ... supposed to be killed. Our programmers found a bug in the application (already unnecessary threads were still alive and all of the them going in the endless loop), changed the code and ... all locks went away. As Jim said: start with watching who is using mallocs (which thread(s)). Regards przemol -- http://przemol.blogspot.com/ On Wed, Apr 16, 2008 at 07:44:21PM -0400, Jim Mauro wrote:> Try linking the JVM to libumem.so.1 > (export LD_PRELOAD=/usr/lib/libumem.so.1) > > I have, in the past, been able to reduce lock contention in malloc > using libumem malloc. > > If that does not help, you need to see where the mallocs are coming > from in the code, and see if there''s opportunity to change the app > such that the JVM makes fewer malloc calls. > > dtrace -n ''pid$target:libc:malloc:entry { @s[jstack()] = count() }'' > > 500 threads - does your need that many threads? > > Are the locks mostly associated with condition variables? > > Typically, the only way to solve lock contention problems is by > changing the code... > > HTH, > /jim > > > Kleyson Rios wrote: > > > > Hi, > > > > I am a newbie in dtrace. > > > > There is a multi-thread application running in my box. But looking > > prstat ?Lmp <java> i saw that almost all time is LCK and SLP. > > > > A ran plockstat and saw the most locks were malloc, so I changed my > > application to use mtmalloc, but didn?t resolv the problem. > > > > After changed malloc to mtmalloc, i ran again plockstat and i?m still > > getting many locks. > > > > How can I use better dtrace to find out the problem ? > > > > PID USERNAME USR SYS TRP TFL DFL LCK SLP LAT VCX ICX SCL SIG > > PROCESS/LWPID > > > > 5637 root 94 0,0 0,0 0,0 0,0 4,2 0,0 1,4 19 96 61 0 java/7 > > > > 5637 root 1,3 0,2 0,0 0,0 0,0 98 0,0 0,2 2K 7 2K 0 java/5 > > > > 5637 root 1,1 0,2 0,0 0,0 0,0 98 0,0 0,3 3K 16 3K 0 java/3 > > > > 5637 root 1,1 0,1 0,0 0,0 0,0 98 0,1 0,4 1K 6 1K 0 java/4 > > > > 5637 root 1,1 0,1 0,0 0,0 0,0 98 0,0 0,4 1K 10 1K 0 java/6 > > > > 5637 root 0,7 0,1 0,0 0,0 0,0 33 65 0,8 11 17 129 0 java/347 > > > > 5637 root 0,7 0,1 0,0 0,0 0,0 65 34 0,0 20 0 129 0 java/134 > > > > 5637 root 0,6 0,1 0,0 0,0 0,0 93 5,7 0,2 21 1 133 0 java/84 > > > > 5637 root 0,4 0,1 0,0 0,0 0,0 49 51 0,1 20 1 135 0 java/435 > > > > 5637 root 0,5 0,1 0,0 0,0 0,0 14 85 0,1 16 0 87 0 java/162 > > > > 5637 root 0,5 0,0 0,0 0,0 0,0 23 76 0,8 3 2 44 0 java/291 > > > > 5637 root 0,4 0,1 0,0 0,0 0,0 36 63 0,6 9 5 81 0 java/412 > > > > 5637 root 0,4 0,1 0,0 0,0 0,0 52 46 1,0 9 0 70 0 java/370 > > > > 5637 root 0,3 0,1 0,0 0,0 0,0 81 17 1,2 9 4 75 0 java/376 > > > > 5637 root 0,3 0,1 0,0 0,0 0,0 37 63 0,0 8 0 77 0 java/174 > > > > 5637 root 0,3 0,1 0,0 0,0 0,0 42 57 0,1 7 1 61 0 java/145 > > > > 5637 root 0,3 0,1 0,0 0,0 0,0 43 56 0,9 12 11 53 0 java/114 > > > > 5637 root 0,2 0,1 0,0 0,0 0,0 2,6 96 0,8 8 0 38 0 java/269 > > > > 5637 root 0,3 0,0 0,0 0,0 0,0 98 0,1 1,1 10 0 38 0 java/361 > > > > 5637 root 0,2 0,1 0,0 0,0 0,0 2,4 97 0,0 6 2 37 0 java/81 > > > > 5637 root 0,2 0,1 0,0 0,0 0,0 84 14 1,2 6 7 57 0 java/292 > > > > 5637 root 0,2 0,1 0,0 0,0 0,0 2,5 97 0,3 5 1 33 0 java/192 > > > > 5637 root 0,2 0,1 0,0 0,0 0,0 85 14 0,8 7 8 54 0 java/212 > > > > 5637 root 0,2 0,1 0,0 0,0 0,0 3,2 96 0,2 6 6 36 0 java/149 > > > > 5637 root 0,2 0,0 0,0 0,0 0,0 42 58 0,1 7 1 50 1 java/411 > > > > 5637 root 0,2 0,1 0,0 0,0 0,0 2,3 97 0,3 8 3 38 0 java/236 > > > > 5637 root 0,2 0,1 0,0 0,0 0,0 43 56 0,9 10 4 44 0 java/438 > > > > 5637 root 0,2 0,0 0,0 0,0 0,0 2,5 97 0,1 5 1 34 0 java/137 > > > > 5637 root 0,2 0,0 0,0 0,0 0,0 2,2 98 0,0 7 1 34 0 java/179 > > > > 5637 root 0,1 0,1 0,0 0,0 0,0 2,5 97 0,6 1 4 111 0 java/20 > > > > 5637 root 0,2 0,0 0,0 0,0 0,0 91 8,2 0,2 4 8 48 0 java/72 > > > > 5637 root 0,2 0,0 0,0 0,0 0,0 3,1 97 0,2 6 2 35 0 java/75 > > > > 5637 root 0,2 0,0 0,0 0,0 0,0 21 78 0,2 3 2 38 0 java/109 > > > > 5637 root 0,2 0,0 0,0 0,0 0,0 89 9,9 0,9 3 6 36 0 java/256 > > > > 5637 root 0,2 0,0 0,0 0,0 0,0 99 0,0 1,0 4 8 39 1 java/458 > > > > Total: 1 processes, 489 lwps, load averages: 1,92, 1,74, 1,65 > > > > Atenciosamente, > > > > ------------------------------------------------------------------ > > > > Kleyson Rios. > > > > Ger?ncia de Suporte T?cnico > > > > Analista de Suporte / L?der de Equipe > > > > Governo do Estado de Goi?s > > > > Ag?ncia de Administra??o > > > > Diretoria de Inform?tica > > > > +55 62 3201-6582 > > > > "Voc? sabe a diferen?a entre pessoas bem sucedidas e pessoas mal > > sucedidas ? > > > > Pessoas bem sucedidas est?o dispostas a fazer as coisas que as pessoas > > mal sucedidas n?o est?o." > > > > ------------------------------------------------------------------------ > > > > _______________________________________________ > > dtrace-discuss mailing list > > dtrace-discuss at opensolaris.org > > > _______________________________________________ > dtrace-discuss mailing list > dtrace-discuss at opensolaris.org-- http://przemol.blogspot.com/ ---------------------------------------------------------------------- Szalony rowerzysta ucieka policji! http://link.interia.pl/f1d9d