2014-05-15 16 views
5

मैं लिनक्स पर निम्नलिखित जिटर समस्या को हल करने की कोशिश कर रहा हूं। मैं sendto() को उसी तरह से उसी डेटा के साथ 2 मिलियन बार कॉल करता हूं। मेरा न्यूनतम/अधिकतम/औसत हैं: न्यूनतम, अधिकतम, औसत, 1175,14211,1322.858685। वे नैनोसेकंड हैं। न्यूनतम 1175 है, औसत 1323 है लेकिन अधिकतम 14211 है जो औसत से +10 गुना है। मैं कैश मिस मुद्दों को खत्म करने के लिए sendto() को पहली कॉल भी शामिल नहीं करता हूं। मैंने जिटर के संभावित स्रोतों के रूप में कार्य स्विच और सॉफ्टक्रैक और इंटरप्ट को समाप्त कर दिया है। जिटर का एकमात्र शेष स्रोत, मुझे लगता है, कैश मिस हैं जो असंभव रूप से दिए गए हैं कि यह एकमात्र प्रक्रिया है जो इस बॉक्स पर चल रही है, इसलिए एल 3 कैश को प्रदूषित करने वाले किसी अन्य कोर पर कुछ अन्य प्रक्रिया नहीं है। अन्य संभावित स्रोत लिनक्स कर्नेल में कुछ है, लेकिन ऐसा लगता है कि यह यूडीपी है, इसलिए राज्य को रखने की कोई जरूरत नहीं है। भले ही कुछ लॉकिंग हो और कुछ कैश याद आती हैं, ऐसा लगता है कि औसत समय 1322 एनएस होने पर 12000 एनएस तक बढ़ जाएगा। कर्नेल में कुछ प्रकार की स्मृति आवंटन हालांकि काफी समय ले सकता है। मैं इस मुद्दे को और कैसे ट्रैक कर सकता हूं?मैं लिनक्स पर इस जिटर के स्रोत को कैसे ट्रैक कर सकता हूं?

Edit1: मैं 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,max,average,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 अधिक कोर काट दिया। मैंने हाइपर थ्रेडिंग बंद कर दी लेकिन यह mattered नहीं है।

मैं के साथ निम्नलिखित कोड संकलन: जी ++ -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,0,(struct sockaddr *)&servaddr,sizeof(servaddr)); 
     if (n != 64) 
     printf("failed to send\n"); 
     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 %ld\n", tMax); } 
    if (t2 < tMin) tMin = t2; 
    if (t2 > 20000) { printf("that took too long,took,%ld\n", t2); } 
    tTotal += t2; 
    } 
    printf("min,max,average,%ld,%ld,%f\n", tMin, tMax, tTotal*1.0/nIterations); 
} 


int main() 
{ 
    udp_send(); 

    return 0; 
} 

मैं इस स्क्रिप्ट (जो मैं linux dynticks परियोजना से लिया) (sudo ./run), जो सभी चालें के साथ इसे चलाने कोर 0 में बाधा डालती है और ट्रेसिंग सेट अप करती है।

# 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 

पर्फ़ उत्पादन होता है:

 4223.769000 task-clock (msec)   # 1.000 CPUs utilized   
       0 context-switches   # 0.000 K/sec     
       0 cpu-migrations   # 0.000 K/sec     
      1,129 page-faults    # 0.267 K/sec     
    10,977,496,067 cycles     # 2.599 GHz      
    5,798,270,864 stalled-cycles-frontend # 52.82% frontend cycles idle 
    <not supported> stalled-cycles-backend 
    11,756,238,450 instructions    # 1.07 insns per cycle   
              # 0.49 stalled cycles per insn 
    2,093,679,462 branches     # 495.690 M/sec     
     14,232,955 branch-misses    # 0.68% of all branches   

     4.222272487 seconds time elapsed 

उत्तर

3

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,max,average,1175,14211,1322.858685 

यहाँ जिसके परिणामस्वरूप प्रणाली का पता लगाने फ़ाइल है:

#!/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 फ़ाइल है मैं गलत था। जिटर विभिन्न सॉफ्टरिक्स और अन्य चीजों से आ रहा है जो ओएस कर रहा है। मैं चलाकर यह देख करने में कामयाब रहे:

a.out-3346 [005] 33832.957658: softirq_raise:  vec=1 [action=TIMER] 
      a.out-3346 [005] 33832.957658: rcu_utilization:  Start scheduler-tick 
      a.out-3346 [005] 33832.957658: softirq_raise:  vec=9 [action=RCU] 
      a.out-3346 [005] 33832.957659: rcu_utilization:  End scheduler-tick 
      a.out-3346 [005] 33832.957660: sched_stat_runtime: comm=a.out pid=3346 runtime=2950209 [ns] vruntime=38264172961 [ns] 
      a.out-3346 [005] 33832.957662: hrtimer_expire_exit: hrtimer=0xffff88087fd4eca0 
      a.out-3346 [005] 33832.957663: hrtimer_start:  hrtimer=0xffff88087fd4eca0 function=tick_sched_timer expires=33819608000000 softexpires=33819608000000 
      a.out-3346 [005] 33832.957663: local_timer_exit:  vector=239 
      a.out-3346 [005] 33832.957664: softirq_entry:  vec=1 [action=TIMER] 
      a.out-3346 [005] 33832.957666: softirq_exit:   vec=1 [action=TIMER] 
      a.out-3346 [005] 33832.957666: softirq_entry:  vec=9 [action=RCU] 
      a.out-3346 [005] 33832.957666: rcu_utilization:  Start RCU core 
      a.out-3346 [005] 33832.957667: rcu_utilization:  End RCU core 
      a.out-3346 [005] 33832.957667: softirq_exit:   vec=9 [action=RCU] 
      a.out-3346 [005] 33832.957668: tick_stop:   success=yes msg= 

कौन सा मुझे लगता है घबराना का कारण है:

sudo trace-cmd record -s 1000 -b 10000 -e all -o trace_1.dat `taskset -c 5 ./a.out > dfa2.tmp` 
sudo trace-cmd report -i trace_1.dat > tmp_1.txt 

फ़ाइल tmp_1.txt स्पष्ट रूप से इस तरह बातें पता चला है। मैंने/sys/kernel/debug/tracing/trace_marker को खोलने और लिखने का प्रयास किया और यह ट्रेस फ़ाइल में दिखाई देता है लेकिन यह उतना सहायक नहीं है जितना मैंने आशा की थी। आप पहले और बाद में पढ़ सकते हैं/देख सकते हैं और देख सकते हैं कि जब भी जिटर होता है तो किसी समस्या को इंगित करता है।

मैंने पढ़ने/proc/softirqs को कोड जोड़ा और सुनिश्चित किया कि हर बार जिटर है टाइमर टिक गिनती एक द्वारा बढ़ी है। विपरीत हालांकि सच नहीं है, कभी कभी टाइमर गिनती/proc/softirqs में चला जाता है लेकिन वहाँ इतनी स्पष्ट रूप से घबराना नहीं है यह कर्नेल टाइमर बंद हो जाता है ऐसा करने का फैसला करता है क्या पर निर्भर करता है:

  HI:,  685 
     TIMER:,  33295 
     NET_TX:,   12 
     NET_RX:, 4030892 
     BLOCK:,   0 
BLOCK_IOPOLL:,   0 
    TASKLET:,  55873 
     SCHED:,   0 
    HRTIMER:,   5 
     RCU:,  7946 
slow,11148 
      HI:,  685 
     TIMER:,  33296 
     NET_TX:,   12 
     NET_RX:, 4030892 
     BLOCK:,   0 
BLOCK_IOPOLL:,   0 
    TASKLET:,  55873 
     SCHED:,   0 
    HRTIMER:,   5 
     RCU:,  7947 

कभी कभी आरसीयू गिनती एक से बढ़ जाती है लेकिन कभी-कभी नहीं। टाइमर गिनती हमेशा एक से ऊपर जाती है।

#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> 

/* 
    g++ -O2 jitter.cpp 
    sudo trace-cmd record -s 1000 -b 10000 -e all -o trace_1.dat `taskset -c 5 ./a.out > dfa2.tmp` 
    sudo trace-cmd report -i trace_1.dat > tmp_1.txt 
*/ 

#pragma pack(push) 
#pragma pack(1) 
#define MAX_CPUS 6 
#define TARGET_CPU 5 
typedef struct 
{ 
    char chName[13]; 
    char chCPU[11*MAX_CPUS]; 
    char chNewLine[8]; 
} procSoftIRQLine1; 

typedef struct 
{ 
    char chName[13]; 
    char chCPU[11*MAX_CPUS]; 
    char chNewLine; 
} procSoftIRQLine2; 

typedef struct 
{ 
    procSoftIRQLine1 h; 
    procSoftIRQLine2 b[30]; 
} procSoftIRQ; 

#pragma pack(pop) 
FILE *pFProcSoftirq = NULL; 
procSoftIRQ data; 

void read_proc_softirqs() 
{ 
    rewind(pFProcSoftirq); 
    size_t tR = fread((char *)&data, 1, sizeof(data), pFProcSoftirq); 
    size_t nP = sizeof(data.h); 
    for (int i = 0; i < sizeof(data.b)/sizeof(data.b[0]) && nP < tR; i++) 
    { 
    printf("%.13s,%.11s\n", data.b[i].chName, data.b[i].chCPU+11*(TARGET_CPU)); 
    nP += sizeof(procSoftIRQLine2) + 1; 
    } 
} 


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); 
    FILE *pF = NULL; 

    pFProcSoftirq = fopen("/proc/softirqs", "r"); 
    // pF = fopen("/sys/kernel/debug/tracing/trace_marker", "w"); 

    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 = 1000000; 
    // int64_t *tTime = new int64_t[nIterations]; 

    int k = 0; 
    for(k = 0; k < nIterations; k++) 
    { 
     // fputs("#dfa,starting\n", pF); 
     read_proc_softirqs(); 
     clock_gettime(CLOCK_REALTIME, &tpe1); 
     for (int j = 0; j < 600; j++) 
     memcpy(sendline, sendline+200, 64); 
     /* 
     int n = sendto(sockfd,sendline,64,0,(struct sockaddr *)&servaddr,sizeof(servaddr)); 
     if (n != 64) 
     printf("failed to send\n"); 
     */ 
     clock_gettime(CLOCK_REALTIME, &tpe2); 
     int64_t t2 = (tpe2.tv_sec - tpe1.tv_sec) *1000000000 + tpe2.tv_nsec - tpe1.tv_nsec; 
     if (k > 0) 
     { 
     if (t2 > 10000) 
     { 
      printf("slow,%ld\n", t2); 
      read_proc_softirqs(); 
     // if (t2 > 10000) 
     // fputs("#dfa,slow\n", pF); 
     // else 
     // fputs("#dfa,fast\n", pF); 
     // tTime[k] = t2; 
     } 
     } 
    } 
} 


int main() 
{ 
    udp_send(); 

    return 0; 
} 

आप TARGET_CPU का मूल्य हार्डकोड करने सीपीयू है कि आप पर कार्यक्रम चलाने के लिए जा रहे हैं होना जरूरी:

यहाँ नवीनतम कोड है। TARGET_CPU वह कार्य होना चाहिए जिसका आप टास्कसेट -c TARGET_CPU ./a.out> out.txt में उपयोग करने जा रहे हैं।

मैं भी गूंज function_graph> $ DIR/current_tracer साथ ftrace किया था और मुझे पता चला है कि बहुत समय चाप में समारोह smp_apic_timer_interrupt में खर्च किया गया था/86/कर्नेल/apic/apic.c तो मैं समय पर कोड जोड़ दिया उस समारोह में कितना समय व्यतीत किया गया था और एक सिस्टम कॉल जोड़ा गया था, इसलिए मुझे उस स्थान में उपयोगकर्ता स्थान से व्यतीत समय की मात्रा मिल सकती थी। निश्चित रूप से, अधिकांश लापता समय उस समारोह से आ रहा था लेकिन सभी नहीं। कई अन्य कार्य भी हैं जो कुछ समय लेते हैं।

+0

प्रमुख दोषों को खत्म करने के प्रयास में 'mlockall (MCL_CURRENT | MCL_FUTURE)' के साथ इसे चलाने का नतीजा क्या है? –

+0

मैंने कोशिश नहीं की लेकिन जब मैं छुट्टी से वापस आ गया (सितंबर में, दोह ?!) मैं करूँगा। मैं कहूंगा कि जब मैं ftrace भाग गया तो पेज गलती के कुछ उदाहरण शायद 10-20 उपयोग के बाधा के स्रोत के रूप में दिखाई दे रहे थे, लेकिन वे केवल शुरुआती ही हुए। सबसे बड़ा बाधा यह थी कि apic.c में smp_apic_timer_interrupt को कॉल करें जिसका मैंने उल्लेख किया था और यह 60-70 उपयोग सीमा में था इसलिए मैंने सोचा कि मैं पहले उस पर ध्यान केंद्रित करूंगा। कर्नेल को हैक और सिस्टम कॉल मैंने बनाया है, मैं पुष्टि कर सकता हूं कि वास्तव में smp_apic_timer_interrupt 90 +% समय के लिए ज़िम्मेदार था। – user3642186

+0

यहां क्या है इसके लिए कुछ कर्नेल डेवलपर्स इस समस्या के बारे में बात कर रहे हैं: https://lkml.org/lkml/2012/3/28/92 – user3642186

संबंधित मुद्दे