четверг, 23 октября 2014 г.

Анализ crashdump в OS Solaris. Ищем виновника причины. #1

Причина поиска

Итак, у нас внезапно перезагрузился сервер. После подъёма, вы посмотрели в /var/crash/ и увидели там свежий vmdump.0.
Поздравляю! Вы стали свидетелем краха ядра ОС Solaris и теперь пытаетесь выяснить причину, хотя бы косвенную, этого падения.
Для начала нам надо распаковать crashdump в /var/crash/vmdump.0 в стандартную пару для анализа unix.0 и vmcore.0, позволю себе напомнить, что unix.0 — это дамп ядра системы, а vmcore.0 — это дамп памяти и в анализе причины падения эти файлы участвуют совместно.
/usr/bin/savecore -vf /var/crash/vmdump.0
Загружаем пару дампов, системы и памяти, в отладчик и пытаемся посмотреть причину падения:
/usr/bin/mdb -k /var/crash/{unix,vmcore}.0
Теперь просто даем команду в отладчике:
::status
и в большинстве случаев – этого достаточно, ровно как и
file /var/crash/{unix,vmcore}.0
чтобы понять причину падения. Однако, в этот раз вам не повезло и вы видите, что падение вызвано непонятной записью:
panic message: BAD TRAP: type=31 rp=2a102fb0db0 addr=6fffedd6b4b mmu_fsr=0
dump content: kernel pages only

Анализируем и находим процесс, вызвавший падение

В данной статье не будем подробно рассматривать многообразие команд The Modular Debugger (MDB), остановимся только на тех, которые помогут нам найти процесс-виновник.
Для начала воспользуемся стандартной для этого случая командой mdb:
::panicinfo
При обычном анализе, нам вполне было бы достаточно значения поля message:
             cpu               23
          thread      30005f767a0         message BAD TRAP: type=31 rp=2a102fb0db0 addr=6fffedd6b4b mmu_fsr=0
          tstate       1980001604
              g1                8
              g2      7003d1d6a80
              g3      7003d0a6b00
              g4           12ff80
              g5             25ff
              g6                0
              g7      30005f767a0
              o0                8
              o1        3f07fda00
              o2                1
              o3        3f0038008
              o4                1
              o5                0
              o6      2a102fb0651
              o7          1098ce4
              pc          1098de8
             npc          1098dec
               y              39b
            sfsr                0
            sfar      6fffedd6b4b
              tt               31
но в данном случае мы займемся анализом адреса в поле thread.
Давайте рассмотрим его детально:
30005f767a0::thread -p
И смотрим вывод:
       ADDR             PROC              LWP             CRED
0000030005f767a0      6005d7e6080      3002e71b3d8      6005cb8a0f0
У нас есть адрес процесса, прямо или косвенно повинного в падении, запросим его детализацию в mdb:
6005d7e6080::ps -t
Получаем вывод:
S    PID   PPID   PGID    SID    UID      FLAGS             ADDR NAME
R  20077      1  20077  20077      0 0x52010400 000006005d7e6080 sendmail        T     0x30005f767a0 
видим, что на момент crash у нас прямо или косвенно повлиял sendmail, исполняющий свой код на 23 процессоре системы.
Так же можно просмотреть открытые файлы и сокеты связанные с проблемным процессом:
6005d7e6080::pfiles
FD   TYPE            VNODE INFO
   0  CHR 000006006cbd19c0 /opt/z/zifx12/root/dev/null
   1  CHR 000006006cbd19c0 /opt/z/zifx12/root/dev/null
   2  CHR 000006006cbd19c0 /opt/z/zifx12/root/dev/null
   3 DOOR 0000030040808340 /opt/z/zifx12/root/var/run/name_service_door [door to 'nscd' (proc=6005e2e92d8)]
   4  CHR 000006005e33a080 /opt/z/zifx12/root/dev/conslog
   5 SOCK 000006005d97c100 socket: AF_INET 127.0.0.1 25
   6 SOCK 000006006c987480 socket: AF_INET 127.0.0.1 587
   7  REG 000006006c987c80 /opt/z/zifx12/root/var/run/sendmail.pid

Что можно еще посмотреть?

Увы, у меня на этом этапе отняли сервер не дав доанализировать crashdump. Поэтому, тут несколько теоретические выкладки.
Альтернативно, проблемный тред можно было найти и такой командой mdb:
*panic_thread::findstack

stack pointer for thread 30005f767a0: 2a102fb0221  000002a102fb02d1 die+0x9c()
  000002a102fb03b1 trap+0xa20()
  000002a102fb0501 ktl0+0x64()
  000002a102fb0651 page_geti_contig_pages+0x558()
  000002a102fb07c1 page_get_contig_pages+0x160()
  000002a102fb0881 page_get_flist+0x11c()
  000002a102fb0971 page_alloc_pages+0x130()
  000002a102fb0a51 anon_map_getpages+0x348()
  000002a102fb0c21 segvn_fault_anonpages+0x32c()
  000002a102fb0df1 segvn_fault+0x530()
  000002a102fb0fc1 as_fault+0x4c8()
  000002a102fb10d1 pagefault+0x68()
  000002a102fb1191 trap+0xd8c()
  000002a102fb12e1 utl0+0x4c()
Адрес thread у нас сразу идет за этим словом, т.е. 30005f767a0. Дальше, все как описано выше, находим процесс.
Можно найти проблемный процесс, вызвавший крах системы и путем просмотра вывод специфической команды:
$C

000002a102fb0651 page_geti_contig_pages+0x65c(0, 1, 1b090b0, 0, f, 0)
000002a102fb07c1 page_get_contig_pages+0x160(0, 0, d, 20000, 19146f0, 30010)
000002a102fb0881 page_get_flist+0x11c(0, d, 0, 1098fb0, 0, 18fdff8)
000002a102fb0971 page_alloc_pages+0x130(60050bf7e40, 6005e174e50, 1a0000, 0, 600589b5588, 18fdff8)
000002a102fb0a51 anon_map_getpages+0x348(0, 0, 8, 10be568, 2a102fb13e0, 1)
000002a102fb0c21 segvn_fault_anonpages+0x32c(0, 1a0000, 0, 1, 6005e2f3c58, 1)
000002a102fb0df1 segvn_fault+0x530(300298ae3c0, 6005e174e50, 1, 1, 1b0000, ffffffffffe50000)
000002a102fb0fc1 as_fault+0x4c8(6005e174e50, 3002e71b3d8, 1ae000, 6005e338cf0, 1a1cf58, 0)
000002a102fb10d1 pagefault+0x68(1ae000, 0, 1, 0, 6005d7e6080, 6005e338c78)000002a102fb1191 trap+0xd8c(2a102fb1b90, 10000, 0, 1, ff109534, 0)
000002a102fb12e1 utl0+0x4c(1b00c0, 0, 0, 1c00, 0, 0)
Здесь, ищем служебное слово pagefault смотрим на пятое значение в круглых скобках, которое будет являться адресом проблемного процесса (1ae000, 0, 1, 0,6005d7e6080, 6005e338c78) и дальше по аналогии, как было описано выше.

Комментариев нет: