1 of 27

Cache Pathology Report of Linux System Calls

LINUX.CONF.AU

21-25 January 2019 Christchurch, NZ

The Linux of Things

|

#LCA2019

|

@linuxconfau

Xi Yang

Confluent and Australian National University yangxi.github.io

1

2 of 27

2

3 of 27

Tail latency

400 millisecond delay decreased searches/user by 0.59%. [Jack Brutlag, Google]

3

4 of 27

Each tail request has an unique tale

4

5 of 27

Powerful abstractions hide root causes of tail latency

Client

Server

5

6 of 27

Helpful signals are isolated and lost

6

7 of 27

SHIM: a high-frequency continuous profiler (LCA 2016)

SHIM 10 MHz

100 KHz

Sampling CPU perf counters at 1 KHz

IPC

7

8 of 27

SHIM

One write system call

8

9 of 27

Tracing by continuous sampling

Channel

E1

E2

E3

E1

E2

E3

E4

while(1)

for each channel

if changed

push_to_stream()

Correlated profiling stream

9

10 of 27

10

11 of 27

11

12 of 27

Example signals and their connections

12

13 of 27

Kernel activities of a normal Kafka produce request

The two write system calls (14856 cycles + 9736 cycles) take about 17% processing cycles of the request

13

14 of 27

One normal Lucene request

14

15 of 27

Xmit delay, JVM GC delay

JVM GC

Nagle’s algorithm

15

16 of 27

Long page faults after deep sleep

Page fault

16

17 of 27

Diagnosing slow page faults with ftrace and trace-cmd

RESOURCE_STALLS:SB:k / NHALTED_CORE_CYCLES:k = 73%

trace-cmd record -p function_graph -g '__do_page_fault’

--max-graph-depth 5

17

18 of 27

Correlate SHIM streams with ftrace records

18

19 of 27

Questions?

19

20 of 27

20

21 of 27

21

22 of 27

Google Protocol Buffer

22

The 25 μs life of the address_book.SerializeToOstream(&output).

Sampling at 5 MHz, every 608 cycles

22

23 of 27

Edit Master text styles

Second level

Third level

Fourth level

Fifth level

23

24 of 27

24

25 of 27

Edit Master text styles

Second level

Third level

Fourth level

Fifth level

25

26 of 27

26

27 of 27

Thank You!

27