вторник, 3 декабря 2013 г.

Solaris kernel panic. Выясняем причины. Пример 2

Обратился клиент с просьбой понять причину перезагрузки сервера T4-4 по панике ядра.
Смотрим настройки дампов:
#dumpadm
Dump content: kernel pages
       Dump device: /dev/dsk/c0d1s1 (swap)
Savecore directory: /var/crash
  Savecore enabled: yes
   Save compressed: on

#cd /var/crash
#ls -al
drwx------   2 root     root         512 Dec  1 09:31 .
drwxr-xr-x   5 root     root         512 Dec 12  2012 ..
-rw-r--r--   1 root     root     2727215104 Dec  1 09:31 vmdump.0

приготовим дамп для работы с отладчиком:
#savecore -vf vmdump.0
Если нет места для создания структуры, сделайте либо линком каталог /var/crash либо dumpadm -s НОВОЕ_МЕСТО

Первичный осмотр:
#echo "::status" | mdb -k unix.0 vmcore.0
debugging crash dump vmcore.0 (64-bit) from server_name
operating system: 5.10 Generic_147440-23 (sun4v)
panic message: BAD TRAP: type=31 rp=2a101085410 addr=5f9ce380008 mmu_fsr=0
dump content: kernel pages only

Хмм. Ничего особенного не показало. Тип 31 - как ошибка 600 в оракле, мало что конкретного понять можно.
Посмотрим что было:
#mdb 0
>::memstat
Page Summary                Pages                MB  %Tot
------------     ----------------  ----------------  ----
Kernel                     544015              4250    4%
Anon                      6548402             51159   53%
Exec and libs               38006               296    0%
Page cache                1398218             10923   11%
Free (cachelist)          3800403             29690   31%
Free (freelist)             30245               236    0%

Total                    12359289             96556
Physical                 12339051             96398

>::cpuinfo
 ID ADDR        FLG NRUN BSPL PRI RNRN KRNRN SWITCH THREAD      PROC
  0 0000180c000  1d    0    0  -1   no    no t-0    2a10001fc80 (idle)
  8 3000b9d0000  1d    0    0   0   no    no t-1    3005f540000 tr
 16 3000b9d4000  1d    0    0  10   no    no t-1    3001e14e820 oracle
 24 3000b9da000  1d    1    0  -1   no    no t-0    2a100b79c80 (idle)
 32 3000b9e4000  1d    0    0  31   no    no t-1    3000c77a100 perl
 40 000018aa150  1b    0    0  31   no    no t-0    3000c7331c0 perl
 48 3000b9ee000  1d    0    0  -1   no    no t-1    2a100cd1c80 (idle)
 56 3000b9f2000  1d    0    0   9   no    no t-1    30025265800 oracle
 64 3000b9f8000  1d    0    0   0   no    no t-0    3005fd9dba0 cat

Уже что-то есть...

> panic_thread/J
panic_thread:
panic_thread:   3000c7331c0

>3000c7331c0::findstack
stack pointer for thread 3000c7331c0: 2a101084881
  000002a101084931 die+0x9c()
  000002a101084a11 trap+0x9e4()
  000002a101084b61 ktl0+0x64()
  000002a101084cb1 5()
  000002a101084db1 fbrelse+0x4c()
  000002a101084e61 ufs_rename+0x728()
  000002a101084fe1 fop_rename+0x1c()
  000002a101085091 vn_renameat+0x238()
  000002a101085231 rename+0xc()
  000002a1010852e1 syscall_trap+0xac()

Да. Некий процесс под управление Perl, вызваный из Java, которая была вызвана из Perl :) пытался выполнить операцию переименования на фаловой системе ufs и что-то пошло не так, что привело к kernel_panic.

>$r
 $r
%g0 = 0x0000000000000000                 %l0 = 0x000005f9ce380000
%g1 = 0x0000000000000002                 %l1 = 0x0000000000000000
%g2 = 0x0000000000000001                 %l2 = 0xfffffd58b0000000
%g3 = 0x0000060070800000                 %l3 = 0x0000030006ea63f8
%g4 = 0xfffffff95db80000                 %l4 = 0x0000000001958800 plocks+0x370
%g5 = 0xffffffffeac58000                 %l5 = 0x000000000000ffcf
%g6 = 0x0000000000007d0c                 %l6 = 0x000003000b9e8000
%g7 = 0x000003000c7331c0                 %l7 = 0x000002a750000000

%o0 = 0xffffffffab160000                 %i0 = 0xffffffff95db8000
%o1 = 0x0000030002fb2140                 %i1 = 0x00000000018a9528 kmapseg
%o2 = 0x0000000000000000                 %i2 = 0x0000000000000003
%o3 = 0x0000000000aab42d                 %i3 = 0x0000000000000000
%o4 = 0x0000030002fb2000                 %i4 = 0x0000030006ea63f8
%o5 = 0x0000000000000140                 %i5 = 0x0000000000000000
%o6 = 0x000002a101084cb1                 %i6 = 0x000002a101084db1
%o7 = 0x0000000000000005                 %i7 = 0x0000000001127134 fbrelse+0x4c

 %ccr = 0x14 xcc=nzvC icc=nZvc
%fprs = 0x00 fef=0 du=0 dl=0
 %asi = 0x00
   %y = 0x0000000000000000
  %pc = 0x000000000119ae88 segmap_fault+0x17c
 %npc = 0x000000000119ae8c segmap_fault+0x180
  %sp = 0x000002a101084cb1 unbiased=0x000002a1010854b0
  %fp = 0x000002a101084db1

  %tick = 0x006a367678aea74c
   %tba = 0x0000000000000000
    %tt = 0x31
    %tl = 0x0
   %pil = 0x0
%pstate = 0x016 cle=0 tle=0 mm=TSO red=0 pef=1 am=0 priv=1 ie=1 ag=0

       %cwp = 0x05  %cansave = 0x00
%canrestore = 0x00 %otherwin = 0x00
    %wstate = 0x00 %cleanwin = 0x00

>3000c7331c0::thread -p
            ADDR             PROC              LWP             CRED
000003000c7331c0      3004a57e620      3001628ac20      6007441ea88

> 3004a57e620::ptree
00000000018a6940  sched
     00000600747fa5d0  init
          0000030006e42cf0  perl
               0000030072cea678  java
                    000003004a57e620  perl


>$c
segmap_fault+0x17c(ffffffff95db8000, 18a9528, 3, 0, 30006ea63f8, 0)
fbrelse+0x4c(6007ca972a0, 0, 0, 0, 1fff, 0)
ufs_rename+0x728(6007df6bc48, 0, 80, 92e2a0, 6007441ea88, 0)
fop_rename+0x1c(300163dde80, 6007cbe64f5, 300163dde80, 3003cf0fb75, 6007441ea88, 12f63dc)
vn_renameat+0x238(0, 1006dd258, 0, 1006dd438, 0, 300163dde80)
rename+0xc(1006dd258, 1006dd438, 1006c1a60, 602, 0, 0)
syscall_trap+0xac(1006dd258, 1006dd438, 1006c1a60, 602, 0, 0)


> 300163dde80::vnode2path
??/app/oracle/product/agent12c/agent_inst/sysman/log





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