☰

Journalctl의 mmap() 호출로 인해 속도가 매우 느려집니다.

tag-icon • tag-icon performance mmap
Journalctl의 mmap() 호출로 인해 속도가 매우 느려집니다.

달릴 때마다 journalctl속도가 엄청나게 느려집니다. 결과가 반환되는 데 몇 분 또는 몇 시간이 걸리는 경우가 많습니다. 영향을 받는 컴퓨터에서 I/O 집약적 응용 프로그램과 관련된 것으로 보이는 몇 가지 다른 성능 문제가 발생했습니다. 최근 SATA 케이블을 교체했는데 성능이 향상되었지만 문제가 완전히 해결되지는 않았습니다. 모든 드라이브에 대해 SMART 테스트를 실행했는데 결과는 모두 양호했습니다.이 목록디스크 오류를 예측하기 위한 "주요" 속성입니다.

안타깝게도 몇 달 동안 영향을 받은 컴퓨터에 물리적으로 접근할 수 없습니다.

저는 루트로 실행 중입니다 journalctl -xn. strace -T출력 예는 다음과 같습니다.

fstatfs(23, {f_type=0x9123683e, f_bsize=4096, f_blocks=272871862, f_bfree=10246662, f_bavail=9257376, f_files=0, f_ffree=0, f_fsid={-1736151745, 782050752}, f_namelen=255, f_frsize=4096}) = 0 <0.000044>
open("/var/log/journal/40b4c4d188900ed4b228417f53bce3a8/[email protected]~", O_RDONLY|O_CLOEXEC) = 24 <0.000045>
fstat(24, {st_mode=S_IFREG|0640, st_size=67108864, ...}) = 0 <0.000044>
mmap(NULL, 4096, PROT_READ, MAP_SHARED, 24, 0) = 0x7fce771b7000 <0.000052>
mmap(NULL, 8388608, PROT_READ, MAP_SHARED, 24, 0) = 0x7fce6be4c000 <0.000101>
fstatfs(24, {f_type=0x9123683e, f_bsize=4096, f_blocks=272871862, f_bfree=10246681, f_bavail=9257367, f_files=0, f_ffree=0, f_fsid={-1736151745, 782050752}, f_namelen=255, f_frsize=4096}) = 0 <0.000044>
open("/var/log/journal/40b4c4d188900ed4b228417f53bce3a8/[email protected]~", O_RDONLY|O_CLOEXEC) = 25 <0.000040>
fstat(25, {st_mode=S_IFREG|0640, st_size=83886080, ...}) = 0 <0.000040>
mmap(NULL, 4096, PROT_READ, MAP_SHARED, 25, 0) = 0x7fce771b6000 <0.000177>
mmap(NULL, 8388608, PROT_READ, MAP_SHARED, 25, 0) = 0x7fce6b64c000 <0.000126>
fstatfs(25, {f_type=0x9123683e, f_bsize=4096, f_blocks=272871862, f_bfree=10246807, f_bavail=9257509, f_files=0, f_ffree=0, f_fsid={-1736151745, 782050752}, f_namelen=255, f_frsize=4096}) = 0 <0.000071>
open("/var/log/journal/40b4c4d188900ed4b228417f53bce3a8/[email protected]~", O_RDONLY|O_CLOEXEC) = 26 <0.000073>
fstat(26, {st_mode=S_IFREG|0640, st_size=67108864, ...}) = 0 <0.000046>
mmap(NULL, 4096, PROT_READ, MAP_SHARED, 26, 0) = 0x7fce771b5000 <0.554027>
mmap(NULL, 8388608, PROT_READ, MAP_SHARED, 26, 0) = 0x7fce6ae4c000 <0.000155>
fstatfs(26, {f_type=0x9123683e, f_bsize=4096, f_blocks=272871862, f_bfree=10248655, f_bavail=9257373, f_files=0, f_ffree=0, f_fsid={-1736151745, 782050752}, f_namelen=255, f_frsize=4096}) = 0 <0.000091>
open("/var/log/journal/40b4c4d188900ed4b228417f53bce3a8/[email protected]~", O_RDONLY|O_CLOEXEC) = 27 <0.000082>
fstat(27, {st_mode=S_IFREG|0640, st_size=8388608, ...}) = 0 <0.000064>
mmap(NULL, 4096, PROT_READ, MAP_SHARED, 27, 0) = 0x7fce771b4000 <0.129685>
mmap(NULL, 8388608, PROT_READ, MAP_SHARED, 27, 0) = 0x7fce6a64c000 <0.000119>
fstatfs(27, {f_type=0x9123683e, f_bsize=4096, f_blocks=272871862, f_bfree=10245778, f_bavail=9256592, f_files=0, f_ffree=0, f_fsid={-1736151745, 782050752}, f_namelen=255, f_frsize=4096}) = 0 <0.000043>
open("/var/log/journal/40b4c4d188900ed4b228417f53bce3a8/[email protected]~", O_RDONLY|O_CLOEXEC) = 28 <0.000043>
fstat(28, {st_mode=S_IFREG|0640, st_size=109051904, ...}) = 0 <0.000047>
mmap(NULL, 4096, PROT_READ, MAP_SHARED, 28, 0) = 0x7fce771b3000 <2.106414>
mmap(NULL, 8388608, PROT_READ, MAP_SHARED, 28, 0) = 0x7fce69e4c000 <0.000099>
fstatfs(28, {f_type=0x9123683e, f_bsize=4096, f_blocks=272871862, f_bfree=10247093, f_bavail=9257207, f_files=0, f_ffree=0, f_fsid={-1736151745, 782050752}, f_namelen=255, f_frsize=4096}) = 0 <0.000037>
open("/var/log/journal/40b4c4d188900ed4b228417f53bce3a8/[email protected]~", O_RDONLY|O_CLOEXEC) = 29 <0.000039>
fstat(29, {st_mode=S_IFREG|0640, st_size=50331648, ...}) = 0 <0.000034>
mmap(NULL, 4096, PROT_READ, MAP_SHARED, 29, 0) = 0x7fce771b2000 <0.000043>
mmap(NULL, 8388608, PROT_READ, MAP_SHARED, 29, 0) = 0x7fce6964c000 <0.000026>
open("/dev/urandom", O_RDONLY|O_NOCTTY|O_CLOEXEC) = 30 <0.000019>
read(30, "_\f\327\367\310\220\344\23U\307\23N@\310\323\226", 16) = 16 <0.000010>
close(30)                               = 0 <0.000010>
open("/dev/urandom", O_RDONLY|O_NOCTTY|O_CLOEXEC) = 30 <0.000014>
read(30, "u\207\326\2360t\0T*\34\222\226\4\22\361w", 16) = 16 <0.000011>
close(30)                               = 0 <0.000010>
fstatfs(29, {f_type=0x9123683e, f_bsize=4096, f_blocks=272871862, f_bfree=10246938, f_bavail=9257024, f_files=0, f_ffree=0, f_fsid={-1736151745, 782050752}, f_namelen=255, f_frsize=4096}) = 0 <0.000015>
open("/var/log/journal/40b4c4d188900ed4b228417f53bce3a8/[email protected]~", O_RDONLY|O_CLOEXEC) = 30 <0.000014>
fstat(30, {st_mode=S_IFREG|0640, st_size=58720256, ...}) = 0 <0.000010>
mmap(NULL, 4096, PROT_READ, MAP_SHARED, 30, 0) = 0x7fce771b1000 <3.332606>

mmap()이전 통화와 비슷하게 보이는 통화의 경우 프로세스가 항상 잠시 중단되는 것처럼 보입니다. dd if=/dev/zero of=testfile.tmp디스크 I/O를 벤치마킹 한 적이 있습니다 . 이 작업을 수행하는 동안 디스크 쓰기 속도가 때때로 300M/s 이하로 떨어지기는 했지만(대부분 +/- ~150M/s) 약 1000M/s(대부분 +/- ~150M/s)를 맴돌고 있음을 관찰했습니다. 70M/s)/초). 내가 죽였을 때 dd신고했어요 15689293824 bytes (16 GB) copied, 174.361 s, 90.0 MB/s. 동일한 테스트를 역방향으로 실행할 때( dd if=testfile.tmp of=/dev/null) 보고된 디스크 읽기 성능은 iotop결코 250M/s를 초과하지 않으며 거의 ​​항상 100M/s 미만, 종종 50M/s 미만이라는 점에 주목할 가치가 있습니다. 두 번째 dd살해 과정이 진행됩니다 10573660160 bytes (11 GB) copied, 148.573 s, 71.2 MB/s.

추가 디버깅 정보는 다음과 같습니다. (이러한 내용은 실행 중입니다.뒤쪽에나는 journalctl -xn프로세스를 종료했습니다):

% find /var/log/journal | wc -l
115
% uname -a
Linux steevie 4.9.0-0.bpo.5-amd64 #1 SMP Debian 4.9.65-3+deb9u2~bpo8+1 (2017-01-05) x86_64 GNU/Linux
% vmstat
procs -----------memory---------- ---swap-- -----io---- -system-- ------cpu-----
 r  b   swpd   free   buff  cache   si   so    bi    bo   in   cs us sy id wa st
 0  0 1495592 160420     80 4586516  199  179 15827  1391   15    8  7  5 37 51  0

파일 시스템은 btrfs RAID1 배열에 있고 장치 중 하나는 LUKS 컨테이너 내부에 있습니다(기록상의 이유로).

% sudo btrfs filesystem show /
Label: '[root]'  uuid: 06c6565d-af6c-4123-9e42-3b6281f164e6
        Total devices 4 FS bytes used 990.93GiB
        devid    2 size 931.47GiB used 931.47GiB path /dev/mapper/sda2_crypt
        devid    4 size 109.45GiB used 109.45GiB path /dev/sda6
        devid    5 size 109.45GiB used 109.45GiB path /dev/sdb6
        devid    6 size 931.47GiB used 931.47GiB path /dev/sdc2

% sudo btrfs device usage /
/dev/mapper/sda2_crypt, ID: 2
   Device size:           931.47GiB
   Device slack:              0.00B
   Data,RAID1:            917.50GiB
   Metadata,RAID1:         13.94GiB
   System,RAID1:           32.00MiB
   Unallocated:             1.02MiB

/dev/sda6, ID: 4
   Device size:           109.45GiB
   Device slack:              0.00B
   Data,RAID1:            102.51GiB
   Metadata,RAID1:          6.94GiB
   Unallocated:             1.00MiB

/dev/sdb6, ID: 5
   Device size:           109.45GiB
   Device slack:              0.00B
   Data,RAID1:            104.42GiB
   Metadata,RAID1:          5.00GiB
   System,RAID1:           32.00MiB
   Unallocated:             3.00MiB

/dev/sdc2, ID: 6
   Device size:           931.47GiB
   Device slack:              0.00B
   Data,RAID1:            927.47GiB
   Metadata,RAID1:          4.00GiB
   Unallocated:             1.02MiB

sda2_crypt/dev/sdd2여기에는 오해의 소지가 있습니다 . 실제로는 SSD /dev/sda이고 HDD입니다 ./dev/sdb/dev/sdc/dev/sdd

저는 데비안 8을 사용하고 있습니다. 필요한 경우 로그를 게시할 수 있어서 기쁘지만 smartctl, 약간 길기 때문에 지금은 생략하겠습니다.

관련 정보