[netperf-talk] negative CPU utilization
Andrew Gallatin
gallatin at cs.duke.edu
Tue May 26 15:45:36 PDT 2009
I'm running into odd CPU utilization issue more and more
on recent linux kernels. Even on "fixed" 2.6.29, I'm
seeing much lower utilization than I should.
Today I saw a *negative* utilization from a ppc64 box
running a 2.6.27 kernel. vmstat seems to report about
20% (of a 4-way box), which I'd believe, but netperf
reports -29%.
Below is netperf's debugging output from a top-of-trunk
netperf2. Any ideas what's wrong? Everything is bound
to CPU1, and I believe the 94% utilization calculated for it,
but the idle CPUs wind up with a negative utilization.
Thanks,
Drew
power% ./src/netperf -Hdell2950b-m -tUDP_STREAM -T1,0 -C -c -d -- -m
8972 -S 1M -s 1M
scan_sockets_args called with the following argument vector
./src/netperf -Hdell2950b-m -tUDP_STREAM -T1 -C -c -d -- -m 8972 -S 1M
-s 1M
Program name: ./src/netperf
Local send alignment: 8
Local recv alignment: 8
Remote send alignment: 8
Remote recv alignment: 8
Report local CPU 1
Report remote CPU 1
Verbosity: 1
Debug: 1
Port: 12865
Test name: UDP_STREAM
Test bytes: 0 Test time: 10 Test trans: 0
Host name: dell2950b-m
installing catcher for all signals
Could not install signal catcher for sig 32, errno 22
Could not install signal catcher for sig 33, errno 22
Could not install signal catcher for sig 65, errno 22
remotehost is dell2950b-m and port 12865
establish_control called with host 'dell2950b-m' port '12865' remfam
AF_UNSPEC
local '0.0.0.0' port '0' locfam AF_UNSPEC
getaddrinfo returned the following for host 'dell2950b-m' port '12865'
family AF_UNSPEC
cannonical name: 'dell2950b-m.sw.myri.com'
flags: 2 family: AF_INET: socktype: SOCK_STREAM protocol
IPPROTO_TCP addrlen 16
sa_family: AF_INET sadata: 50 65 10 0 130 51
getaddrinfo returned the following for host '0.0.0.0' port '0' family
AF_UNSPEC
cannonical name: '0.0.0.0'
flags: 3 family: AF_INET: socktype: SOCK_STREAM protocol
IPPROTO_TCP addrlen 16
sa_family: AF_INET sadata: 0 0 0 0 0 0
bound control socket to 0.0.0.0 and 0
successful connection to remote netserver at dell2950b-m and 12865
complete_addrinfo using hostname dell2950b-m port 0 family AF_UNSPEC
type SOCK_DGRAM prot IPPROTO_UDP flags 0x0
getaddrinfo returned the following for host 'dell2950b-m' port '0'
family AF_UNSPEC
cannonical name: 'dell2950b-m.sw.myri.com'
flags: 2 family: AF_INET: socktype: SOCK_DGRAM protocol
IPPROTO_UDP addrlen 16
sa_family: AF_INET sadata: 0 0 10 0 130 51
local_data_address not set, using local_host_name of '0.0.0.0'
complete_addrinfo using hostname 0.0.0.0 port 0 family AF_UNSPEC type
SOCK_DGRAM prot IPPROTO_UDP flags 0x1
getaddrinfo returned the following for host '0.0.0.0' port '0' family
AF_UNSPEC
cannonical name: '0.0.0.0'
flags: 3 family: AF_INET: socktype: SOCK_DGRAM protocol
IPPROTO_UDP addrlen 16
sa_family: AF_INET sadata: 0 0 0 0 0 0
UDP UNIDIRECTIONAL SEND TEST from 0.0.0.0 (0.0.0.0) port 0 AF_INET to
dell2950b-m.sw.myri.com (10.0.130.51) port 0 AF_INET : cpu bind
create_data_socket: socket 4 obtained...
netperf: get_sock_buffer: send socket size determined to be 2097152
netperf: get_sock_buffer: receive socket size determined to be 2097152
calibrate: lib_num_loc_cpus 4 lines 5 CPU_LINE_LENGTH 96
proc_stat_buflen 480
recv_response: received a 256 byte response
send_udp_stream: remote data connection done.
About to start a timer for 10 seconds.
cpu_util_init enter, proc_stat_fd 5 proc_stat_buf 0x10086d60
proc_stat_buf 'cpu 84045 2004 176040 5009195681 323410 556747 700409
14078 0
cpu0 49168 194 88326 837611091 7320 297869 380223 3957 0
cpu1 15392 502 48232 1554929265 313747 37664 40532 4923 0
cpu2 8279 748 17522 1131894980 1038 158107 214154 2619 0
cpu3 11204 558 21958 1484760343 1303 63105 65498 2578 0
intr 68364764 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 119 0 2165252 0 0 0 0 0 0
0 0 0 0 0 0 0 0 0 0 0 0 22433066 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
0 0 0 0 0 0 0 0 0 0 0 17338275 0 0 0 0 0 0 0'
res[0] is 837611091
res[1] is 1554929265
res[2] is 1131894980
res[3] is 1484760343
proc_stat_buf 'cpu 84067 2004 176867 5009200709 323411 556810 700446
14214 0
cpu0 49168 194 88326 837612612 7321 297932 380260 3957 0
cpu1 15414 502 49059 1554929316 313747 37665 40533 5058 0
cpu2 8279 748 17522 1131896511 1038 158107 214154 2619 0
cpu3 11204 558 21958 1484762269 1303 63105 65498 2578 0
intr 68497473 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 119 0 2165483 0 0 0 0 0 0
0 0 0 0 0 0 0 0 0 0 0 0 22565506 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
0 0 0 0 0 0 0 0 0 0 0 17338275 0 0 0 0 0 0 0'
res[0] is 837612612
res[1] is 1554929316
res[2] is 1131896511
res[3] is 1484762269
recv_response: received a 256 byte response
send_udp_stream: remote results obtained
calc_cpu_util: actual_rate on processor 0 is 152.096985 start 31ecee53
end 31ecf444 util -52.096985 cf 1.000000
calc_cpu_util: actual_rate on processor 1 is 5.099899 start 5cae5671 end
5cae56a4 util 94.900101 cf 1.000000
calc_cpu_util: actual_rate on processor 2 is 153.096970 start 437758c4
end 43775ebf util -53.096970 cf 1.000000
calc_cpu_util: actual_rate on processor 3 is 192.596176 start 587fa517
end 587fac9d util -92.596176 cf 1.000000
calc_service_demand called: units_sent = 12405970196.000000
elapsed_time = 0.000000
cpu_util = 0.000000
num cpu = 0
calc_service_demand using: units_sent = 12405970196.000000
elapsed_time = 10.000198
cpu_util = -25.722507
num cpu = 4
calc_service_demand got: thruput = 1211496.495193
servdem = -0.849280
calc_service_demand called: units_sent = 12405970196.000000
elapsed_time = 0.000000
cpu_util = 0.784763
num cpu = 4
calc_service_demand using: units_sent = 12405970196.000000
elapsed_time = 10.000198
cpu_util = 0.784763
num cpu = 4
calc_service_demand got: thruput = 1211496.495193
servdem = 0.025911
calculate_confidence: itr 1; time 10.000198; res 9924.579289
lcpu -25.722507; rcpu 0.784763
lsdm -0.849280; rsdm 0.025911
Socket Message Elapsed Messages CPU Service
Size Size Time Okay Errors Throughput Util Demand
bytes bytes secs # # 10^6bits/sec % SS us/KB
2097152 8972 10.00 1382743 0 9924.6 -25.72 -0.849
2097152 10.00 1382743 9924.6 0.78 0.026
shutdown_control: shutdown of control connection requested.
More information about the netperf-talk
mailing list