如何在Linux上查找此抖动的来源？
发布时间：2020-05-25 04:07:57 所属栏目：Linux 来源：互联网
导读：我正在尝试解决 linux上的以下抖动问题.我用完全相同的方式调用sendto()200万次完全相同的数据.我的最小值/最大值/平均值是：最小值,最大值,平均值,1175,14211,1322.858685.那是纳秒.最小值是1175,平均值是1323,但最大值是14211,是平均值的10倍.我甚至不包括
|
我正在尝试解决 linux上的以下抖动问题.我用完全相同的方式调用sendto()200万次完全相同的数据.我的最小值/最大值/平均值是：最小值,最大值,平均值,1175,14211,1322.858685.那是纳秒.最小值是1175,平均值是1323,但最大值是14211,是平均值的10倍.我甚至不包括第一次调用sendto()来消除缓存未命中问题.我已经消除了任务开关,softirqs和中断作为潜在的抖动源.我认为,唯一剩下的抖动源是缓存未命中,这似乎不太可能,因为这是唯一一个在此框上运行的进程,因此在另一个核心上没有其他进程污染L3缓存.另一个潜在的来源是 Linux内核本身的东西,但这似乎也不太可能,因为这是UDP所以不需要保持状态.即使有一些锁定和一些缓存未命中,当平均时间需要1322 ns时,似乎不太可能加起来为12000 ns.虽然内核中的某种内存分配可能会花费那么多时间.如何进一步跟踪此问题？ 编辑1：我删除了memcpy,结果稍有改动,但抖动主要依然存在： new max,time is 3029 new max,time is 3746 new max,time is 5287 new max,time is 6043 new max,time is 9882 min,max,average,1837,9882,2087.033864 编辑2：我删除了sendto()调用,循环执行memcpy 600次,结果如下： new max,time is 1894 new max,time is 1922 new max,time is 1923 new max,time is 1925 new max,time is 1928 new max,time is 2002 new max,time is 4530 new max,time is 9269 new max,time is 9466 min,1880,9466,1881.731031 由于这些结果非常接近,它与sendto()调用本身无关,而是与其他一些系统性问题无关. 这是设置： uname -a Linux ubuntu 3.13.0-24-generic #47-Ubuntu SMP Fri May 2 23:30:00 UTC 2014 x86_64 x86_64 x86_64 GNU/Linux cat /proc/cmdline BOOT_IMAGE=/boot/vmlinuz-3.13.0-24-generic root=UUID=9cd0a310-313a-4445-8594-39a7fc037b1e ro isolcpus=1-11 nohz_full=1-11 rcu_nocbs=1-11 intel_idle.max_cstate=0 intel_pstate=disable cat /proc/cpuinfo | more processor : 0 vendor_id : GenuineIntel cpu family : 6 model : 62 model name : Intel(R) Xeon(R) CPU E5-2630 v2 @ 2.60GHz stepping : 4 microcode : 0x415 cpu MHz : 2599.941 cache size : 15360 KB physical id : 0 siblings : 6 core id : 0 cpu cores : 6 apicid : 0 initial apicid : 0 fpu : yes fpu_exception : yes cpuid level : 13 wp : yes flags : fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush dts acpi mmx fxsr sse sse2 ss ht tm pbe syscall nx pdpe1gb rdtscp lm constant_tsc arch_perfmon pebs bt s rep_good nopl xtopology nonstop_tsc aperfmperf eagerfpu pni pclmulqdq dtes64 monitor ds_cpl vmx smx est tm2 ssse3 cx16 xtpr pdcm pcid dca sse4_1 sse4_2 x2apic popcnt tsc_deadline_timer aes xsave avx f16c rdrand lahf_lm arat epb xsaveopt pln pts dtherm tpr_shadow vnmi flexpriority ept vpid fsgsbase smep erms bogomips : 5199.88 clflush size : 64 cache_alignment : 64 address sizes : 46 bits physical,48 bits virtual power management: ……切断了5个核心.我关闭了超线程,但这并不重要. 我用以下代码编译以下代码：g -O2 jitter.cpp #include <stdio.h>
#include <sys/time.h>
#include <inttypes.h>
#include <stdint.h>
#include <stdlib.h>
#include <string.h>
#include <sys/socket.h>
#include <netinet/in.h>
#include <strings.h>
#include <arpa/inet.h>
#include <time.h>
#include <unistd.h>
#include <sys/syscall.h>
void udp_send()
{
struct timespec tpe1,tpe2;
int sockfd,n;
struct sockaddr_in servaddr,cliaddr;
char sendline[1000];
sockfd=socket(AF_INET,SOCK_DGRAM,0);
bzero(&servaddr,sizeof(servaddr));
servaddr.sin_family = AF_INET;
// servaddr.sin_addr.s_addr=inet_addr("127.0.0.1");
servaddr.sin_addr.s_addr=inet_addr("192.168.5.51");
servaddr.sin_port=htons(3000);
int nIterations = 2000000;
int64_t *tTime = new int64_t[nIterations];
int k = 0;
for( k = 0; k < nIterations; k++)
{
clock_gettime(CLOCK_REALTIME,&tpe1);
memcpy( sendline,sendline+200,64 );
int n = sendto(sockfd,sendline,64,(struct sockaddr *)&servaddr,sizeof(servaddr));
if ( n != 64 )
printf("failed to sendn");
clock_gettime(CLOCK_REALTIME,&tpe2);
int64_t t2 = ( tpe2.tv_sec - tpe1.tv_sec ) *1000000000 + tpe2.tv_nsec - tpe1.tv_nsec;
if ( k > 0 )
tTime[k] = t2;
}
int64_t tMax = 0;
int64_t tMin = 99999999999;
int64_t tTotal = 0;
for ( k = 1; k < nIterations; k++ )
{
int64_t t2 = tTime[k];
if ( t2 > tMax ) { tMax = t2; printf("new max,time is %ldn",tMax ); }
if ( t2 < tMin ) tMin = t2;
if ( t2 > 20000 ) { printf("that took too long,took,%ldn",t2 ); }
tTotal += t2;
}
printf("min,%ld,%fn",tMin,tMax,tTotal*1.0 / nIterations );
}
int main()
{
udp_send();
return 0;
}
我使用这个脚本(我从linux dynticks项目中获取)(sudo ./run)运行它,它将所有中断移动到核心0并设置跟踪. #!/bin/bash
# Full dyntick CPU on which we'll run the user loop,# it must be part of nohz_full kernel parameter
TARGET=5
NR_CPUS=$(getconf _NPROCESSORS_ONLN)
# Migrate nocb tasks to CPU 0
# Beware,this assume that there is no online CPU > NR_CPUS
for CPU in $(seq $(($NR_CPUS-1)))
do
PIDS=$(ps -o pid= -C rcuob/$CPU,rcuos/$CPU,rcuop/$CPU)
for PID in $PIDS
do
taskset -cp 0 $PID
done
done
# Migrate irqs to CPU 0
for D in $(ls /proc/irq)
do
if [[ -x "/proc/irq/$D" && $D != "0" ]]
then
echo $D
echo 1 > /proc/irq/$D/smp_affinity
fi
done
# Delay the annoying vmstat timer far away
sysctl vm.stat_interval=300
# Shutdown nmi watchdog as it uses perf events
sysctl -w kernel.watchdog=0
# Pin the writeback workqueue to CPU0
echo 1 > /sys/bus/workqueue/devices/writeback/cpumask
DIR=/sys/kernel/debug/tracing
echo > $DIR/trace
echo 0 > $DIR/tracing_on
# Uncomment the below for more details on what disturbs the CPU
echo 0 > $DIR/events/irq/enable
echo 1 > $DIR/events/sched/sched_switch/enable
echo 1 > $DIR/events/workqueue/workqueue_queue_work/enable
echo 1 > $DIR/events/workqueue/workqueue_execute_start/enable
echo 1 > $DIR/events/timer/hrtimer_expire_entry/enable
echo 1 > $DIR/events/timer/tick_stop/enable
echo 1 > $DIR/events/timer/enable
echo 0 > $DIR/events/net/enable
echo 0 > $DIR/events/sock/enable
echo 0 > $DIR/events/udp/enable
echo 0 > $DIR/events/skb/enable
echo nop > $DIR/current_tracer
echo 1 > $DIR/tracing_on
# Run a 10 secs user loop on target
taskset -c $TARGET /usr/lib/linux-tools/3.13.0-24-generic/perf stat ./a.out > dfa.tmp &
# chrt -f 99 taskset -c 1 ./a.out
sleep 30
killall a.out
# Checkout the trace in trace.* file
cat /sys/kernel/debug/tracing/per_cpu/cpu$TARGET/trace > trace.$TARGET
这是生成的dfa.tmp文件： new max,time is 2196 new max,time is 2729 new max,time is 5900 new max,time is 11621 new max,time is 14211 min,1322.858685 以下是生成的系统跟踪文件： # tracer: nop
#
# entries-in-buffer/entries-written: 34361/34361 #P:6
#
# _-----=> irqs-off
# / _----=> need-resched
# | / _---=> hardirq/softirq
# || / _--=> preempt-depth
# ||| / delay
# TASK-PID CPU# |||| TIMESTAMP FUNCTION
# | | | |||| | |
<idle>-0 [005] dN.. 733.720555: hrtimer_cancel: hrtimer=ffff88087fd4eca0
<idle>-0 [005] dN.. 733.720555: hrtimer_start: hrtimer=ffff88087fd4eca0 function=tick_sched_timer expires=733280000000 softexpires=733280000000
<idle>-0 [005] d... 733.720556: sched_switch: prev_comm=swapper/5 prev_pid=0 prev_prio=120 prev_state=R ==> next_comm=taskset next_pid=1312 next_prio=120
perf-1312 [005] .... 733.721806: hrtimer_init: hrtimer=ffff880850b53378 clockid=CLOCK_MONOTONIC mode=HRTIMER_MODE_REL
perf-1312 [005] d... 733.721857: tick_stop: success=no msg=more than 1 task in runqueue
perf-1312 [005] d... 733.721883: sched_switch: prev_comm=perf prev_pid=1312 prev_prio=120 prev_state=S ==> next_comm=perf next_pid=1314 next_prio=120
a.out-1314 [005] dN.. 733.721934: tick_stop: success=no msg=more than 1 task in runqueue
a.out-1314 [005] d... 733.721936: sched_switch: prev_comm=perf prev_pid=1314 prev_prio=120 prev_state=R ==> next_comm=perf next_pid=1312 next_prio=120
perf-1312 [005] d... 733.722111: sched_switch: prev_comm=perf prev_pid=1312 prev_prio=120 prev_state=S ==> next_comm=perf next_pid=1314 next_prio=120
a.out-1314 [005] d.h. 733.722727: hrtimer_cancel: hrtimer=ffff88087fd4eca0
a.out-1314 [005] d.h. 733.722728: hrtimer_expire_entry: hrtimer=ffff88087fd4eca0 function=tick_sched_timer now=733280000768
a.out-1314 [005] d.h. 733.722731: hrtimer_expire_exit: hrtimer=ffff88087fd4eca0
a.out-1314 [005] d.h. 733.722731: hrtimer_start: hrtimer=ffff88087fd4eca0 function=tick_sched_timer expires=733284000000 softexpires=733284000000
a.out-1314 [005] d... 733.722736: tick_stop: success=yes msg=
a.out-1314 [005] d... 733.722737: hrtimer_cancel: hrtimer=ffff88087fd4eca0
a.out-1314 [005] d... 733.722737: hrtimer_start: hrtimer=ffff88087fd4eca0 function=tick_sched_timer expires=734280000000 softexpires=734280000000
a.out-1314 [005] .... 733.722960: timer_init: timer=ffff88084f8ec1d8
a.out-1314 [005] d.s. 733.723023: timer_start: timer=ffff8808518d0650 function=neigh_timer_handler expires=4295075867 [timeout=250]
a.out-1314 [005] d... 733.986838: hrtimer_cancel: hrtimer=ffff88087fd4eca0
a.out-1314 [005] d... 733.986839: hrtimer_start: hrtimer=ffff88087fd4eca0 function=tick_sched_timer expires=734044000000 softexpires=734044000000
a.out-1314 [005] d.h. 734.487025: hrtimer_cancel: hrtimer=ffff88087fd4eca0
a.out-1314 [005] d.h. 734.487025: hrtimer_expire_entry: hrtimer=ffff88087fd4eca0 function=tick_sched_timer now=734044000419
a.out-1314 [005] d.h. 734.487028: hrtimer_expire_exit: hrtimer=ffff88087fd4eca0
a.out-1314 [005] d.h. 734.487028: hrtimer_start: hrtimer=ffff88087fd4eca0 function=tick_sched_timer expires=734048000000 softexpires=734048000000
a.out-1314 [005] d.s. 734.487029: timer_cancel: timer=ffffffff81efd6a0
a.out-1314 [005] ..s. 734.487030: timer_expire_entry: timer=ffffffff81efd6a0 function=clocksource_watchdog now=4295075808
a.out-1314 [005] d.s. 734.487031: timer_start: timer=ffffffff81efd6a0 function=clocksource_watchdog expires=4295075933 [timeout=125]
a.out-1314 [005] ..s. 734.487032: timer_expire_exit: timer=ffffffff81efd6a0
a.out-1314 [005] d... 734.487033: hrtimer_cancel: hrtimer=ffff88087fd4eca0
a.out-1314 [005] d... 734.487033: hrtimer_start: hrtimer=ffff88087fd4eca0 function=tick_sched_timer expires=734280000000 softexpires=734280000000
a.out-1314 [005] d... 734.487033: hrtimer_cancel: hrtimer=ffff88087fd4eca0
a.out-1314 [005] d... 734.487033: hrtimer_start: hrtimer=ffff88087fd4eca0 function=tick_sched_timer expires=734280000000 softexpires=734280000000
a.out-1314 [005] d.h. 734.723117: hrtimer_cancel: hrtimer=ffff88087fd4eca0
a.out-1314 [005] d.h. 734.723117: hrtimer_expire_entry: hrtimer=ffff88087fd4eca0 function=tick_sched_timer now=734280000410
a.out-1314 [005] d.h. 734.723119: hrtimer_expire_exit: hrtimer=ffff88087fd4eca0
a.out-1314 [005] d.h. 734.723119: hrtimer_start: hrtimer=ffff88087fd4eca0 function=tick_sched_timer expires=734284000000 softexpires=734284000000
a.out-1314 [005] d.s. 734.723120: timer_cancel: timer=ffff8808518d0650
a.out-1314 [005] ..s. 734.723120: timer_expire_entry: timer=ffff8808518d0650 function=neigh_timer_handler now=4295075867
a.out-1314 [005] d.s. 734.723122: timer_start: timer=ffff8808518d0650 function=neigh_timer_handler expires=4295076117 [timeout=250]
a.out-1314 [005] ..s. 734.723126: timer_expire_exit: timer=ffff8808518d0650
a.out-1314 [005] d... 734.723127: hrtimer_cancel: hrtimer=ffff88087fd4eca0
a.out-1314 [005] d... 734.723127: hrtimer_start: hrtimer=ffff88087fd4eca0 function=tick_sched_timer expires=735280000000 softexpires=735280000000
a.out-1314 [005] d.h. 735.723507: hrtimer_cancel: hrtimer=ffff88087fd4eca0
a.out-1314 [005] d.h. 735.723508: hrtimer_expire_entry: hrtimer=ffff88087fd4eca0 function=tick_sched_timer now=735280000448
a.out-1314 [005] d.h. 735.723509: hrtimer_expire_exit: hrtimer=ffff88087fd4eca0
a.out-1314 [005] d.h. 735.723509: hrtimer_start: hrtimer=ffff88087fd4eca0 function=tick_sched_timer expires=735284000000 softexpires=735284000000
a.out-1314 [005] d.s. 735.723511: timer_cancel: timer=ffff8808518d0650
a.out-1314 [005] ..s. 735.723511: timer_expire_entry: timer=ffff8808518d0650 function=neigh_timer_handler now=4295076117
a.out-1314 [005] d.s. 735.723512: timer_start: timer=ffff8808518d0650 function=neigh_timer_handler expires=4295076367 [timeout=250]
a.out-1314 [005] ..s. 735.723515: timer_expire_exit: timer=ffff8808518d0650
a.out-1314 [005] d... 735.723516: hrtimer_cancel: hrtimer=ffff88087fd4eca0
a.out-1314 [005] d... 735.723516: hrtimer_start: hrtimer=ffff88087fd4eca0 function=tick_sched_timer expires=736280000000 softexpires=736280000000
a.out-1314 [005] d... 736.452298: timer_start: timer=ffff8800368823e0 function=commit_timeout expires=4295077736 [timeout=1437]
a.out-1314 [005] d.h. 736.452533: tick_stop: success=no msg=more than 1 task in runqueue
a.out-1314 [005] d.h. 736.452534: hrtimer_cancel: hrtimer=ffff88087fd4eca0
a.out-1314 [005] d.h. 736.452535: hrtimer_start: hrtimer=ffff88087fd4eca0 function=tick_sched_timer expires=736012000000 softexpires=736012000000
a.out-1314 [005] d... 736.452536: tick_stop: success=no msg=more than 1 task in runqueue
a.out-1314 [005] d... 736.452537: sched_switch: prev_comm=a.out prev_pid=1314 prev_prio=120 prev_state=x ==> next_comm=perf next_pid=1312 next_prio=120
perf-1312 [005] d... 736.452647: timer_start: timer=ffffffff81d14ae0 function=delayed_work_timer_fn expires=4295076549 [timeout=250]
perf-1312 [005] d.h. 736.455802: hrtimer_cancel: hrtimer=ffff88087fd4eca0
（编辑：安卓应用网） 【声明】本站内容均来自网络，其相关言论仅代表作者个人观点，不代表本站立场。若无意侵犯到您的权利，请及时与联系站长删除相关内容! |
相关内容
- linux – ssh multi-hop上的“bash：nc：command not found
- linux – 如何从命令行合并ubuntu上的两个ext3分区？
- Supervisord不会启动被杀死的进程
- 检查一个目录. readdir返回的条目是目录,链接或文件
- linux – 如何使用非默认运行参数在AWS Elastic Beanstalk中
- linux – Cron with notify-send
- 我如何知道要为我的Linux AMI安装哪个Linux软件包
- 通过linux上的usb发送原始数据
- Linux – 帮助,我用完了inode！
- LINUX实操：Ubuntu 16.04安装Adobe AIR