[dtrace] [java] нужна помощь

какие именно сисколлы, как и когда, выполняет JVM для конкретного потока

Я может не понял какой-то тонкости, но вот именно это может показать обычный strace, нет?

а чего сразу dtrace, любой профилировщик для явы тебе много чего в состоянии рассказать

Любой, и в том числе стандартный с HotSpot. А так, да, strace

солярка, наверное?

по сабжу: а что iostat, для начала?

как конкретно? это Соляра с Azul JVM (есть возможность также ранить под ИБМ-овской JVM). насколько я понимаю, дтрейсить можно только сановскую джвм? truss и обычный dtrace по сисколлам не показывают того, чего хочеться - они показывают все сисколлы от ДЖВМ, а не только для конкретного потока. ну тоесть на самом деле есть возможность смотреть только конкретный lightweight process, но как поставить в соответствие tread-id из jvm к lpw я не знаю, не знаю даже или такое соответствие действительно есть.
насчет других трейсилок для джавы вообще не вкурсе. напомню, что меня интересуют именно сисколлы, стектрейсы и все прочее на джвм уровне я и так вижу, черех PMI(JMX), и еще лучше - через RTPM (такая приблуда в Azul JVM)
а стрейс из линукса мне такое покажет? как?

это не начало, это вторая неделя дебаггинга продакшн-проблемы. что ты хочешь увидеть в иостате? да, есть активность, вполне обычная для этого приложения. никакого криминала, увы...

BUMP. кто-нибуть может помочь?

последнее время они регулярно и непредсказуемо вырастают до 300

это можно как-либо объяснить выросшей нагрузкой?

небольшое архитектурное описание не помешало бы тоже. есть подозрения, что вам нужно не совсем то, о чем вы спрашиваете =)

внезапно из ниоткуда ведь ничто не появляется/происходит

что меня интересуют именно сисколлы,

а стрейс из линукса мне такое покажет? как?

Ну стрейс именно сисколлы и показывает, с пидами и временем.

Как-то так

strace -ttt -f -p $PID

Вот кусок файрфокса например (первое, что попалось многопоточное):

17475 1284551975.048574 gettimeofday({1284551975, 48614}, NULL) = 0
17475 1284551975.048719 clock_gettime(CLOCK_REALTIME, {1284551975, 48760223}) = 0
17475 1284551975.048872 futex(0xb76ea5c8, FUTEX_WAIT_PRIVATE, 3531669, {0, 76853777} <unfinished ...>
17470 1284551975.048974 <... restart_syscall resumed> ) = 1
17470 1284551975.049101 read(20, "\372", 1) = 1
17470 1284551975.049313 gettimeofday({1284551975, 49362}, NULL) = 0
17470 1284551975.049507 gettimeofday({1284551975, 49556}, NULL) = 0
17470 1284551975.049694 gettimeofday({1284551975, 49743}, NULL) = 0
17470 1284551975.049874 gettimeofday({1284551975, 49923}, NULL) = 0
17470 1284551975.050076 futex(0xb76ea5c8, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0xb76ea5c4, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1
17475 1284551975.050273 <... futex resumed> ) = 0
17470 1284551975.050341 gettimeofday( <unfinished ...>
17475 1284551975.050414 gettimeofday( <unfinished ...>
17470 1284551975.050475 <... gettimeofday resumed> {1284551975, 50381}, NULL) = 0
17470 1284551975.050582 read(3,  <unfinished ...>
17475 1284551975.050657 <... gettimeofday resumed> {1284551975, 50606}, NULL) = 0
17470 1284551975.050731 <... read resumed> 0xb7669058, 4096) = -1 EAGAIN (Resource temporarily unavailable)
17475 1284551975.050830 gettimeofday( <unfinished ...>
17470 1284551975.050894 poll([{fd=4, events=POLLIN}, {fd=3, events=POLLIN}, {fd=8, events=POLLIN|POLLPRI}, {fd=28, events=POLLIN}, {fd=30, events=POLLIN|POLLPRI}, {fd=31, events=POLLIN|POLLPRI}, {fd=32, events=POLLIN|POLLPRI}, {fd=19, events=POLLIN}, {fd=10, events=POLLIN|POLLPRI}, {fd=46, events=POLLIN}, {fd=20, events=POLLIN}], 11, 0 <unfinished ...>
17475 1284551975.051151 <... gettimeofday resumed> {1284551975, 50878}, NULL) = 0
17470 1284551975.051248 <... poll resumed> ) = 0 (Timeout)
17475 1284551975.051342 futex(0xb767dd60, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
17470 1284551975.051407 gettimeofday( <unfinished ...>

Здесь первая колонка - пид(треды тоже), вторая - время, а затем сисколл со всеми аргументами. Если тред прерван переключением - пишет unfinished, затем resumed, как-то так.

=) вы трасс видели? я вкурсе, что такое стрейс и как он работает. афаик, он не умеет того, что я хочу, и вы очевидно не поняли, что мне надо..

А что говорит поддержка Sun/Oracle?

что это IBM WebSphere, Azul JVM и Vignette VAP. к ним и посылают. а они по кругу посылают, ну как всегда. только Азул помогает, но пока ничего дельного, что решило бы ситуацию, не нашли

> это можно как-либо объяснить выросшей нагрузкой?

нет, мы видели куда большую нагрузку.

небольшое архитектурное описание не помешало бы тоже. есть подозрения, что вам нужно не совсем то, о чем вы спрашиваете =)

небольшого не выйдет, нормальное описание - это у нас целый талмуд.

ребята, я благодарен за все ваши предложения и вопросы, но мне нужно именно то, что мне нужно. дебажить нашу проблему я вас не хочу напрягать, слишком много нюансов, и нас тут уже человек 30 этим занимается, вместе с девами. просто хотел выяснить, как это протрейсить.

посмотри, может пригодится http://kenai.com/projects/btrace/pages/UserGuide

вы трасс видели?

нет

и вы очевидно не поняли, что мне надо..

Я об этом написал в первом посте. Но ответ был - мне нужны именно сисколлы по тредам, поэтому я показал именно сисколы по тредам. Ну и не понял не только я, судя по треду, так что может попытайтесь переформулировать, что именно надо.

> но мне нужно именно то, что мне нужно

сомневаюсь :-) что это тебе даст?

просто хотел выяснить, как это протрейсить.

ну а собственно в чем проблема? вставляешь датчик в syscall провайдер, в качестве действия - агрегация по идентфикатору потока в качестве ключа того, что тебе интересно. Начать стоит просто со подсчета количества системных вызовов, потом когда поймешь, какие именно тебе интересны, для них можно уже будет использовать стэки в качестве значений в агрегации.. как-то так.. правда я все равно не въезжаю пока, что ты пытаешься найти.

Что за ФС-то? fsstat'ом статистику смотрели?

> Что за ФС-то? fsstat'ом статистику смотрели?

nfs, ufs, tmpfs. без разницы. смотрели.

ладно, пробую еще раз. выглядит так, что с точки зрения JVM ей приходится очень долго ждать ответов на любое дисковое ИО. с точки зрения ОС, все абсолютно нормально и в пределах нормы (и не изменилось по сравнению с данными за предидущий месяц).

спасибо за советы, все понятно. единственное, чего не достает, так это как поставить в соответствие треды ОС (pthreads, lpw) и треды JVM?

> сомневаюсь :-) что это тебе даст?

мне необходимо понять, на каком именно этапе запросы «застревают». еще в джвм, в обработчиках сисколлов, в вфс, в буферах ввода-вывода. это не фс-специфический аспект, и очевидно не устройство-специфический. проявляется на множестве нод в кластере. трудно поверить, что связано с джвм, так как проявляется на двух разных джвм.

>>приходится очень долго ждать ответов на любое дисковое ИО

это не фс-специфический аспект, и очевидно не устройство-специфический

зря вы так, когда идет разговор про io, fs и дисковая подсистема далеко не последние места где копать )

последнее время у вас не наблюдалось програмных или аппаратных изменений (той же дисковой подсистемы)?
еще раз повторю - оно ведь просто так не бывает ))

вы очень не внимательно читаете, очевидно.
небыло никаких изминений ни аппаратной, ни програмной части. ни сети. ничего.
изначально запись велась на нфсный нас, потом поменяли на локальную фс на зеркале, потом на тмпфс. какие имеено компоненты дисковой подсистемы используются во всех трех вариантах, а?

извините за резкость, просто злой сегодня.

>>извините за резкость, просто злой сегодня.

я уже не обращаю внимания, это же лор ;

о том что не было никаких изменений в инфраструктуре и нагрузках, до начала проблем, не было ни слова. потому и спросил.
но вы действительно верите в то что оно могло вот так вот из ниоткуда нате получите? вы самоипереписывающийся и саморазмножающийся код пишете или как? или восстали машины из серверных?

изначально запись велась

изначально вы сказали только про кэш. или у вас только с кэшем работа и происходит?

на нфсный нас, потом поменяли на локальную фс на зеркале, потом на тмпфс

а это по вашему не манипуляции с файловыми системами и способами доступа к ним?

ну и кэш по эзернету с наса... а потом удивляетесь почему

приходится очень долго ждать ответов на любое дисковое ИО

ну да ладно, не буду докучать вас глупыми расспросами, пойду лучше в вов погоняю, пятница же.
и да пребудет с вами сила, она пригодна будет вам в борьбе вашей ;

> но вы действительно верите в то что оно могло вот так вот из ниоткуда нате получите? вы самоипереписывающийся и саморазмножающийся код пишете или как? или восстали машины из серверных?

я это регулярно наблюдаю, так что мне остается только не верить собственным глазам.
на самом деле, обычно потом выясняется, что программа в процессе работы где-то что-то сама в себе запорола.

о том что не было никаких изменений в инфраструктуре и нагрузках, до начала проблем, не было ни слова. потому и спросил.

ну, я какбы не совсем дурак. очевидные вещи очевидны.

изначально вы сказали только про кэш. или у вас только с кэшем работа и происходит?

запись на фс - только кэш и лог.

а это по вашему не манипуляции с файловыми системами и способами доступа к ним?

я не понял вашу мысль. если вы про «изминения», то это все уже делалось потом, чтобы найти возможный источник проблемы. если вы про то, что в принципе это все ио, ну так да, я это и написал. только вот общих моментов у них свех только ВФС, буферы и обработка сисколлов, разный код и устройства задействуются во всех случаях.

ну и кэш по эзернету с наса... а потом удивляетесь почему

ну, положим, не езернет. но тем не менее, это не ко мне, я девам об этом говорил с десяток раз. особенно если учесть как офигительно он эффективен - уровень записи/чтения получается 15/1. нафиг такой кеш. ну так нет, они же еще и паблишинг через него делают. гады.

ну да ладно, не буду докучать вас глупыми расспросами, пойду лучше в вов погоняю, пятница же.

и да пребудет с вами сила, она пригодна будет вам в борьбе вашей ;

спасибо. я кстати на Борейской Тундре =)

>>ну, я какбы не совсем дурак. очевидные вещи очевидны.

в том то и дело, у меня, скажем так, немалый опыт в решении задач производительности, и очевидные вещи не всегда очевидны =)

но не смею настаивать, гадая на кофейной гуще можно и в лужу сесть ))

ну, положим, не езернет.

iscsi?
вообще нас такая специфичная штука, что оно пригодно только для файло-помоек в гетерогенных сетях, по-большому счету. имхо.

спасибо. я кстати на Борейской Тундре =)

российский сервер?
я в al'akir обитаю. так что привет от европейского тролля-затейника =)

Я бы посмотрел, что делает приклад в тот момент, когда его снимают с процессора.. Если его снимают с процессора, когда он держит какой-нибудь прикладой лок, то это не айс.. Для этого провайдеров pid, sched и действия ustack() хватит за глаза. Сам справишься или набросать скриптик?

> iscsi?

пробовали сан через инфинибенд.

российский сервер?

да, руофф.

вообщем-то, мы за выходные выяснили вот что: треды лочат один HashSet, а потом пытаются в него либо записать данные из файлухи, либо сбросить его содержимое на файлуху. и тут фокус в чем - Azul JVM делает вид, что блокировку получил, но на самом деле не пытается ее взять до того момента, как произойдет реальное обращение к данным, поэтому выглядит так, что тред пытается работать с фс, а на самом деле он ждет блокировки. почему это не вызывало проблем в прошлом - открытый вопрос, но нам удалось внедрить воркэраунд, так что всем спасибо!