1

perf ツールを使用して、プログラムの興味深い動作を説明したいと思います。

いくつかの背景情報

私のマシンには 4 つの NUMA ノードがあり、メイン アプリケーションはマシン上で実行されています。cpusets を使用してマシンを分割し、アプリケーションに 3 つのノード、システムに 1 つのノードを割り当てています。同じマシンで単体テスト (ログの改善のため) を実行しているときに、perf ツールを使用して調査しようとしている予期しない動作が発生します。

予期しない動作は、アプリケーションが実行されている NUMA ノード (ノード 2 としましょう) で、単体テストでより良い時間を取得することです。ノード 3)。node2のCPU(スピンロックを行わないCPU)で実行しているように見えますが、別のnumaで実行するよりも良い結果が得られます。

ログシステムを改善しようとしているので、テストはアプリケーションによっても行われる作業を行っており、後でディスクにダンプするためにいくつかのログメッセージをキューに書き込みます (別のスレッド)。キューへの競合は、スピンロック (CAS) によって制御されます。unitest は、2 つのループを持つ 1 つのライター スレッドです。100 回、1000 個のログがキューに書き込まれ、RDTSC (私の選択) を使用して各内部ループが測定され、統計が出力されます。キューは十分に大きく、標準偏差を取得し、メモリ操作は最小限に抑えられます (memcpy なし)。リーダーは別のスレッドでディスクにダンプしています。

アプリケーションを停止して、もう一度テストを実行してみました。この場合、テストを実行するために選択した NUMA ノードに関係なく、node3(slow) で実行した場合と同様の結果が得られます。つまり、同じ numa でテストを実行すると、実行中のアプリケーションがテストを高速化しています。アプリケーションが実行されるノード。私にとって非常に直感的ではありません。

次の perf ツール コマンドを使用してデータを取得する

rm /tmp/a; rm /tmp/ats; for f in $(perf list | tr -s ' ' | cut -d' ' -f 2 ); do perf stat -o /tmp/ats --append -e $f taskset -c $(cat /sys/devices/system/node/node2/cpulist) ./bin/testCore >> /tmp/a 2>&1;perf stat -o /tmp/ats --append -e $f taskset -c $(cat /sys/devices/system/node/node3/cpulist) ./bin/testCore >> /tmp/a 2>&1;done

コマンドを使用して分析する

cat /tmp/ats | grep -v "#" | grep -v "^ *$" | grep -v "seconds time elapsed\|Performance\|supported" | grep -v " 0 " | tr -s ' ' | tr -d ',' | awk '{if(knownEvent[$2]){if(((knownEvent[$2]/$1)<0.95) || ((knownEvent[$2]/$1)>1.05)){printf "diff:%s %.2f(%d/%d)\n",$2,(knownEvent[$2]/$1),knownEvent[$2],$1}}else{knownEvent[$2]=$1}}'| more
diff:branch-misses 1.08(470184/435284)
diff:bus-cycles 0.70(25570333/36774093)
diff:cpu-clock 0.69(191/276)
diff:L1-dcache-prefetch-misses 1.05(624172/593780)
diff:LLC-loads 0.92(665199/720197)
diff:LLC-load-misses 1.16(217684/187823)
diff:LLC-prefetches 0.87(193398/222148)
diff:LLC-prefetch-misses 0.85(98653/115483)
diff:dTLB-load-misses 1.09(195668/180291)
diff:dTLB-store-misses 1.11(39755/35910)
diff:scsi:scsi_dispatch_cmd_start 1.38(11/8)
diff:block:block_rq_insert 0.58(36/62)
diff:block:block_rq_issue 1.50(12/8)
diff:block:block_bio_backmerge 1.05(683/650)
diff:block:block_getrq 0.57(36/63)
diff:block:block_plug 0.52(26/50)
diff:kmem:mm_pagevec_free 1.06(16853/15838)
diff:kmem:mm_kernel_pagefault 0.88(7/8)
diff:timer:timer_start 0.36(21/59)
diff:timer:timer_expire_entry 3.00(3/1)
diff:timer:timer_expire_exit 2.00(2/1)
diff:timer:timer_cancel 1.60(8/5)
diff:timer:hrtimer_start 0.93(1275/1368)
diff:timer:hrtimer_expire_entry 0.72(186/259)
diff:timer:hrtimer_expire_exit 0.69(182/264)
diff:timer:hrtimer_cancel 0.74(192/259)
diff:irq:softirq_entry 0.64(374/585)
diff:irq:softirq_exit 0.74(394/536)
diff:irq:softirq_raise 0.73(390/531)
diff:sched:sched_wakeup 0.75(3/4)
diff:sched:sched_stat_wait 0.50(1/2)
diff:sched:sched_stat_sleep 2.00(2/1)
diff:sched:sched_stat_runtime 0.93(1284/1379)

私はいくつかの違いを含むものを抽出しました。 sched-、LLC-、branch-、TLB を疑うべきかどうかはわかりません。相対的な違いが私が見ている動作を説明するかどうかの手がかりがないからです。

これを調査するためのより良い方法の提案はありますか?

4

0 に答える 0