Как сопоставить номера блоков с именами файлов из вывода dmesg, полученного из vm.block_dump = 1, если устройство является ext4?

Question

tl; dr: Я хочу увидеть / получить имена файлов, частью которых являются сообщенные номера блоков в dmesg, когда vm.block_dump=1 пример dmesg: bash(13515): READ block 5434824 on xvda3 (32 sectors)

Когда, например. sudo sysctl -w vm.block_dump=1 или напр. echo '1' | sudo tee /proc/sys/vm/block_dump затем "Linux сообщает обо всех выполняемых операциях чтения и записи на диск и о всех загрязнениях блоков, сделанных в файлы. [...] Вывод block_dump записывается в вывод ядра, и его можно получить с помощью" dmesg " . Когда вы используете block_dump и ваш уровень ведения журнала ядра также включает в себя сообщения отладки ядра, вы, вероятно, захотите отключить klogd, в противном случае выходные данные block_dump будут регистрироваться, вызывая активность диска, которая обычно там не присутствует. " (цитата из здесь )

"Загрязнения блоков" не являются проблемой, например.

[ 3140.559675] systemd-journal(291): dirtied inode 399135 (system.journal) on xvda3

Я вижу его имя файла так:

$ echo -e 'open /dev/xvda3\n ncheck 399135' | sudo debugfs -f -
debugfs 1.44.2 (14-May-2018)
debugfs: open /dev/xvda3
debugfs:  ncheck 399135
Inode   Pathname
399135  /var/log/journal/12c5e521101c444594b96b53751551a8/system.journal

Проблема в том, что «Linux сообщает обо всех операциях чтения и записи на диске, которые имеют место» (если цитировать из вышеприведенного), когда они сообщаются в блоках, например.

[ 3140.376827] kworker/u24:3(21616): WRITE block 11037768 on xvda3 (8 sectors)
[ 3140.724725] bash(13515): READ block 5434824 on xvda3 (32 sectors)
[ 3140.725483] date(13515): READ block 5434896 on xvda3 (160 sectors)
[ 3140.728946] sed(13519): READ block 5143680 on xvda3 (32 sectors)
[ 3140.736022] sleep(13522): READ block 5379184 on xvda3 (24 sectors)
[ 3140.804803] qubes-gui(522): READ block 5179952 on xvda3 (16 sectors)
[ 3140.806519] Xorg(599): READ block 7420192 on xvda3 (176 sectors)
[ 3140.810348] InputThread(613): READ block 7418560 on xvda3 (112 sectors)
[ 3140.815866] at-spi2-registr(812): READ block 5654512 on xvda3 (8 sectors)
[ 3140.816860] xdg-desktop-por(888): READ block 5795168 on xvda3 (8 sectors)
[ 3140.818716] gnome-terminal-(865): READ block 5804672 on xvda3 (16 sectors)
[ 3141.064524] sed(13531): READ block 3446048 on xvda3 (16 sectors)
[ 3141.130808] systemd(571): READ block 4744136 on xvda3 (184 sectors)

Код ядра, отвечающий за отображение таких сообщений, можно увидеть здесь: https://elixir.bootlin.com/linux/v4.18.5/source/block/blk-core.c#L2542

Ни один из этих блоков не дает никаких номеров инодов, используя это:

$ echo -e 'open /dev/xvda3\n icheck 11037768' |sudo debugfs -f -
debugfs 1.44.2 (14-May-2018)
debugfs: open /dev/xvda3
debugfs:  icheck 11037768
Block   Inode number
11037768    <block not found>

Вместо <block not found> выше я должен получить номер инода, который я могу затем использовать с предыдущим эхом, чтобы увидеть имя файла.

То, что я пробовал: на всякий случай, если номер блока кратен размеру сектора (512 байт), и я знаю, что размер блока ext4 равен 4096 байт (sudo blockdev --getbsz /dev/xvda), я также пытался (используя результат умножения для): 11037768 * 2, 11037768 * 4 и 11037768 * 8 с одинаковым результатом: <block not found>

Что мне здесь не хватает? Эти блоки указывают на записи каталога или что-то, что не является именем файла? Тем не менее, не должен ли debugfs по-прежнему выдавать номер инода?
Есть ли лучший способ получить имя файла?

РЕДАКТИРОВАТЬ: Номер блока, который icheck (внутри debugfs) ожидает, это числа, подобные тем, что stat сообщает debugfs в EXTENTS, например, любое число в диапазон 2172716-2172721 виден ниже как

$ sudo debugfs -R "stat /usr/lib/python2.7/site-packages/salt/modules/zonecfg.py" /dev/xvda3
debugfs 1.44.2 (14-May-2018)
Inode: 550529   Type: regular    Mode:  0644   Flags: 0x80000
Generation: 1781055959    Version: 0x00000000:00000001
User:     0   Group:     0   Project:     0   Size: 22179
File ACL: 0
Links: 1   Blockcount: 48
Fragment:  Address: 0    Number: 0    Size: 0
 ctime: 0x5b6ec29d:1b2e0200 -- Sat Aug 11 13:03:57 2018
 atime: 0x5b33b5a9:00000000 -- Wed Jun 27 18:04:57 2018
 mtime: 0x5b33b5a9:00000000 -- Wed Jun 27 18:04:57 2018
crtime: 0x5b6ec29d:1af0f900 -- Sat Aug 11 13:03:57 2018
Size of extra inode fields: 32
EXTENTS:
(0-5):2172716-2172721

Другой способ:

$ filefrag -s -v /usr/lib/python2.7/site-packages/salt/modules/zonecfg.py
Filesystem type is: ef53
File size of /usr/lib/python2.7/site-packages/salt/modules/zonecfg.py is 22179 (6 blocks of 4096 bytes)
 ext:     logical_offset:        physical_offset: length:   expected: flags:
   0:        0..       5:    2172716..   2172721:      6:             last,eof
/usr/lib/python2.7/site-packages/salt/modules/zonecfg.py: 1 extent found

Теперь остается вопрос: как соотносятся эти номера блоков устройств (номера блоков, указанные для xvda3 в dmesg), с этими физическими смещениями?

EDIT2: Я только что подтвердил, что эти номера физических смещений совпадают с номерами блочных устройств (очевидно, они не совпадают с теми, о которых сообщалось в dmesg); ниже показан последний блок указанного выше файла, и я могу подтвердить, что он такой же, как и при просмотре файла с помощью vim:

$ sudo dd bs=4096 skip=2172721 count=1 if=/dev/xvda3 | hexdump -C

Я проверил это под ядром 4.18.5 внутри приложения Qubes OS R4.0 Fedora 28. (При необходимости я могу перекомпилировать собственное ядро ​​с пользовательскими .config / patches - предложения приветствуются)

Answer 1

Номера блоков, сообщаемые в dmesg, когда vm.block_dump=1 являются номерами секторов - 512 байт на блок - но номера блоков, которые команда debugfs ожидает для своей команды icheck, обычно составляют 4096 байт на блок для ext4, поэтому все, что требуется, это деление на 8.

Хотя размер блока обычно составляет 4096 байт, вы должны быть уверены, поэтому получите размер блока следующим образом:

$ sudo blockdev --getbsz /dev/xvda3
4096

Хотя обычно это значение равно 4096, в некоторых случаях оно может быть другим, например, например. mkfs.ext4 с помощью -b может создать файловую систему ext4 с другим размером блока; vfat имеет размер блока 512 байт.

Чтобы получить делитель для деления по размеру блока, все за один раз (в bash):

$ echo $(( `sudo blockdev --getbsz /dev/xvda3` / 512 ))
8

Давайте использовать эту строку в качестве ввода:
[ 3140.736022] sleep(13522): READ block 5379184 on xvda3 (24 sectors)

Получите номер блока для icheck, разделив вышеуказанное на 8:

$ bc -l
bc 1.06.95
Copyright 1991-1994, 1997, 1998, 2000, 2004, 2006 Free Software Foundation, Inc.
This is free software with ABSOLUTELY NO WARRANTY.
For details type `warranty'. 
5379184/8
672398.00000000000000000000

Я использовал bc -l, чтобы убедиться, что я не опечатал число (если оно заканчивается .00000000000000000000, скорее всего, нет)

Получить имя пути с помощью debugfs:

$ sudo debugfs
debugfs 1.44.2 (14-May-2018)
debugfs:  open /dev/xvda3
debugfs:  icheck 672398
Block   Inode number
672398  134571
debugfs:  ncheck 134571
Inode   Pathname
134571  /usr/bin/sleep
debugfs:  close
debugfs:  quit

Я не уверен, могут ли номера блоков, указанные в dmesg, когда-либо быть кратными значениям, отличным от 512 байтов на сектор. Например, они по-прежнему составляют 512 байт на блок, если базовый диск имеет физически 4096 байт на сектор ? Если бы я догадался, я бы сказал, что можно с уверенностью предположить, что они всегда 512 байт на блок.

Вот сценарий версия выше:

#!/bin/bash

#./showblock rev.02 rewritten for question/answer from: https://stackoverflow.com/q/52058914/10239615

#----
bytes_per_sector=512 #assumed that dmesg block numbers are 512 bytes each (ie. 512 bytes per sector; aka block size is 512)!
#----

#use `sudo` only when not already root
if test "`id -u`" != "0"; then
    sudo='sudo'
else
    sudo=''
fi

if ! test "$#" -ge "2"; then
  echo "Usage: $0 <device> <dmesgblocknumber> [dmesgblocknumber ...]"
  echo "Examples:"
  echo "$0 /dev/xvda3 5379184"
  echo "$0 /dev/xvda3 5379184 5129952 7420192"
  exit 1
fi

within_exit() {
  echo -e "\nSkipped current instruction within on_exit()"
}
on_exit() {
  #trap - EXIT SIGINT SIGQUIT SIGHUP  #will exit by skipping the rest of all instrunction from on_exit() eg. if C-c
  trap within_exit EXIT SIGINT SIGQUIT SIGHUP #skip only current instruction from on_exit() eg. when C-c is pressed
  #echo "first sleep"
  #sleep 10
  #echo "second sleep"
  #sleep 10
  if test "${#remaining_args[@]}" -gt 0; then
    echo -n "WARNING: There are '${#remaining_args[@]}' remaining args not processed, they are: " >&2
    for i in `seq 0 1 "$(( "${#remaining_args[@]}" - 1 ))"`; do  #seq is part of coreutils package
      echo -n "'${remaining_args[${i}]}' " >&2
    done
    echo >&2
  fi
}

trap on_exit EXIT SIGINT SIGQUIT SIGHUP

dev="$1"
shift 1

if test -z "$dev" -o ! -b "$dev"; then
  echo "Bad device name or not a device: '$dev'" >&2
  exit 1
fi

blocksize="`$sudo blockdev --getbsz "$dev"`"
if test "${blocksize:-0}" -le "0"; then #handles empty arg too
  echo "Failed getting block size for '$dev', got '$blocksize'" >&2
  exit 1
fi
#TODO: check and fail if not a multiplier
divider="$(( $blocksize / $bytes_per_sector ))"
if ! test "${divider:-0}" -gt "0"; then
  echo "Failed computing divider from: '$blocksize' / '$bytes_per_sector', got '$divider'" >&2
  exit 1
fi

# for each passed-in dmesg block number do
while test "$#" -gt "0"; do
dmesgblock="$1"
shift
remaining_args=("$@") #for on_exit() above
echo '--------'
echo "Passed-in dmesg block($bytes_per_sector bytes per block) number: '$dmesgblock'"
#have to handle the case when $dmesgblock is empty and when it's negative eg. "-1" so using a default value(of 0) when unset in the below 'if' block will help not break the 'test' expecting an integer while also allowing negative numbers ("0$dmesgblock" would otherwise yield "0-1" a non-integer):
if test "${dmesgblock:-0}" -le "0"; then
  echo "Bad passed-in dmesg block number: '$dmesgblock'" >&2
  exit 1
fi

#TODO: check and fail(or warn? nah, it should be fail!) if not a multiplier (eg. use modullo? is it "%" ?)
block=$(( $dmesgblock / 8 ))
if ! test "${block:--1}" -ge "0"; then
  echo "Badly computed device block number: '$block'" >&2
  exit 1
fi

echo "Actual block number(of $blocksize bytes per block): $block"
inode="$(echo "open ${dev}"$'\n'"icheck ${block}"$'\n'"close" | $sudo debugfs -f - 2>/dev/null | tail -n2|head -1|cut -f2 -d$'\t')"
if test "<block not found>" == "$inode"; then
  echo "No inode was found for the provided dmesg block number '$dmesgblock' which mapped to dev block number '$block'" >&2
  exit 1
else
    #assuming number TODO: check for this!
    echo "Found inode: $inode"
    fpath="$(echo "open ${dev}"$'\n'"ncheck ${inode}"$'\n'"close" | $sudo debugfs -f - 2>/dev/null | tail -n2|head -1|cut -f2- -d$'\t')"
  #fpath always begins with '/' right?
    if test "$fpath" != "Pathname"; then
        echo "Found path : $fpath"
    else
        echo "not found"
    fi
fi
done

Пример использования:

[user@dev01-w-s-f-fdr28 ~]$ ./showblock  /dev/xvda3 5379184 5129952 "" -1 "" 1200 ; echo "exit code: $?"
--------
Passed-in dmesg block(512 bytes per block) number: '5379184'
Actual block number(of 4096 bytes per block): 672398
Found inode: 134571
Found path : /usr/bin/sleep
--------
Passed-in dmesg block(512 bytes per block) number: '5129952'
Actual block number(of 4096 bytes per block): 641244
Found inode: 141497
Found path : /usr/lib64/libIlmImf-2_2.so.22.0.0
--------
Passed-in dmesg block(512 bytes per block) number: ''
Bad passed-in dmesg block number: ''
WARNING: There are '3' remaining args not processed, they are: '-1' '' '1200' 
exit code: 1
[user@dev01-w-s-f-fdr28 ~]$ ./showblock  /dev/xvda3 5379184 5129952 -1 "" "" 1200 ; echo "exit code: $?"
--------
Passed-in dmesg block(512 bytes per block) number: '5379184'
Actual block number(of 4096 bytes per block): 672398
Found inode: 134571
Found path : /usr/bin/sleep
--------
Passed-in dmesg block(512 bytes per block) number: '5129952'
Actual block number(of 4096 bytes per block): 641244
Found inode: 141497
Found path : /usr/lib64/libIlmImf-2_2.so.22.0.0
--------
Passed-in dmesg block(512 bytes per block) number: '-1'
Bad passed-in dmesg block number: '-1'
WARNING: There are '3' remaining args not processed, they are: '' '' '1200' 
exit code: 1
[user@dev01-w-s-f-fdr28 ~]$ ./showblock  /dev/xvda3 5379184 5129952 0 ; echo "exit code: $?"
--------
Passed-in dmesg block(512 bytes per block) number: '5379184'
Actual block number(of 4096 bytes per block): 672398
Found inode: 134571
Found path : /usr/bin/sleep
--------
Passed-in dmesg block(512 bytes per block) number: '5129952'
Actual block number(of 4096 bytes per block): 641244
Found inode: 141497
Found path : /usr/lib64/libIlmImf-2_2.so.22.0.0
--------
Passed-in dmesg block(512 bytes per block) number: '0'
Bad passed-in dmesg block number: '0'
exit code: 1
[user@dev01-w-s-f-fdr28 ~]$ ./showblock  /dev/xvda3 5379184 5129952 3 ; echo "exit code: $?"
--------
Passed-in dmesg block(512 bytes per block) number: '5379184'
Actual block number(of 4096 bytes per block): 672398
Found inode: 134571
Found path : /usr/bin/sleep
--------
Passed-in dmesg block(512 bytes per block) number: '5129952'
Actual block number(of 4096 bytes per block): 641244
Found inode: 141497
Found path : /usr/lib64/libIlmImf-2_2.so.22.0.0
--------
Passed-in dmesg block(512 bytes per block) number: '3'
Actual block number(of 4096 bytes per block): 0
No inode was found for the provided dmesg block number '3' which mapped to dev block number '0'
exit code: 1
[user@dev01-w-s-f-fdr28 ~]$ ./showblock  /dev/xvda3 5379184 5129952 ; echo "exit code: $?"
--------
Passed-in dmesg block(512 bytes per block) number: '5379184'
Actual block number(of 4096 bytes per block): 672398
Found inode: 134571
Found path : /usr/bin/sleep
--------
Passed-in dmesg block(512 bytes per block) number: '5129952'
Actual block number(of 4096 bytes per block): 641244
Found inode: 141497
Found path : /usr/lib64/libIlmImf-2_2.so.22.0.0
exit code: 0

Вот скрипт для обработки всего журнала dmesg:

#!/bin/bash

#./showallblocks rev.01 rewritten for question/answer from: https://stackoverflow.com/q/52058914/10239615

if test "`id -u`" != "0"; then
    sudo='sudo'
else
    sudo=''
fi

dmesglog="$1"
if test -z "$dmesglog"; then
  echo "Usage: '$0' <dmesglogfile>"
  echo "Examples:"
  echo "sudo dmesg > dmesg1.log && '$0' dmesg1.log"
  echo "'$0' <(sudo dmesg)"
  #Note: '$0' used for the case when $0 has spaces or other things in its path names, and user wants to copy paste, for whatever reason, the output of the above into the command line.
  exit 1
fi

#(optional) Stop logging if already in progress:
$sudo sysctl -w vm.block_dump=0

#Using the answer from here(thanks to glenn jackman): https://unix.stackexchange.com/a/467377/306023
#grep --color=never -E -- 'READ block [0-9]+ on xvda3' "$dmesglog" |
#cat "$dmesglog" |
$sudo perl -pe '
if (! /READ block [0-9]+ on [A-Za-z0-9]+ .*$/) {
  s{.*}{}s
}

s{(READ block) (\d+) (on) ([A-Za-z0-9]+) ([^\$]*)\n$}
{join " ",$1, $2, $3, $4, $5, qx(./showblock "/dev/$4" "$2" | grep -F -- "Found path :" | cut -f4- -d" ")}es
' -- "$dmesglog"
#Note: the output of qx(...) above is purposely allowed to have trailing newline! (I did wonder if purposely is correct here or it should be purposefully, https://www.merriam-webster.com/words-at-play/purposely-purposefully-usage )
#To find out what "}es"(above) is, see perlre modifiers: https://perldoc.perl.org/perlre.html#Modifiers
#FIXME: noobish try to exclude lines not matching the lines that need to be replaced, from output! used 'if' above

Пример вывода:

[user@dev01-w-s-f-fdr28 ~]$ ./showallblocks sample.dmesg.log 
vm.block_dump = 0
[ 6031.953619] sysctl(20774): READ block 5285528 on xvda3 (32 sectors) /usr/lib64/libgpg-error.so.0.24.2
[ 6031.954317] sysctl(20774): READ block 5285768 on xvda3 (8 sectors) /usr/lib64/libgpg-error.so.0.24.2
[ 6031.954598] sysctl(20774): READ block 5285648 on xvda3 (120 sectors) /usr/lib64/libgpg-error.so.0.24.2
[ 6031.954617] sysctl(20774): READ block 5285776 on xvda3 (24 sectors) /usr/lib64/libgpg-error.so.0.24.2
[ 6031.955482] sysctl(20774): READ block 5285560 on xvda3 (88 sectors) /usr/lib64/libgpg-error.so.0.24.2
[ 6031.955699] sysctl(20774): READ block 4473568 on xvda3 (8 sectors) /usr/lib64/libuuid.so.1.3.0
[ 6031.955730] sysctl(20774): READ block 4473584 on xvda3 (16 sectors) /usr/lib64/libuuid.so.1.3.0
[ 6031.955787] sysctl(20774): READ block 4749496 on xvda3 (224 sectors) /usr/lib64/libblkid.so.1.1.0
[ 6030.638492] bash(20757): READ block 4543096 on xvda3 (32 sectors) /usr/bin/gawk
[ 6030.639133] awk(20757): READ block 4544280 on xvda3 (176 sectors) /usr/bin/gawk