Speed of pysnmp

[Roy Smith]

There's been some talk recently about the relative speeds of the various
python SNMP libraries. I just did a little benchmarking, and got some
surprising results.

I downloaded pysnmp-3.4.2 and build a little mib walk application around
it. I used it to walk ifDescr on an Extreme Summit 48i (48 port
ethernet switch). I did the same thing using snmpwalk from net-snmp
5.0.8.

The switch is back in my office; I'm sitting at home running this on my
Mac OSX box, through a VLAN connection over DSL. Ping times are around
40ms:

--- 192.168.1.1 ping statistics ---
13 packets transmitted, 13 packets received, 0% packet loss
round-trip min/avg/max = 37.597/39.801/41.902 ms

The results are rather surprising (I ran these several times; the
numbers below are fairly typical):

$ time ./get.py > get.out
real 0m9.045s
user 0m1.010s
sys 0m0.510s

$ time snmpwalk -v1 -c public 192.168.1.1 ifDescr > snmpwalk.out
real 0m3.896s
user 0m0.120s
sys 0m0.130s

The two output files had identical information (except for trivial
output formatting differences). There were a total of 73 rows.

It's entirely expected that the pysnmp version had much higher CPU times
(from about 0.25 to 1.5 total user+sys). What I don't understand is why
the real time went up so much, from about 4 seconds to about 9 seconds.
Most of the time doing a mib walk is waiting for UDP packets on the wire.

If the ping RTT is 40ms, and there's 73 rows, that's 2.9 seconds, which
accounts for about 3/4 of the real time. Add in a 1/4 second of CPU at
this end, figure the same at the other end, a few ms for process
switching for each packet, and it's easy to see where all the time goes.

But, where does the additional 5 seconds of real time come from for the
pysnmp version? I burned another 1-1/4 seconds of CPU at my end, but
everything else really should be the same. The network doesn't know
what kind of code built the packets. Neither does the box at the other
end. Something's inserting another 50ms or so delay per packet which is
not accounted for my the CPU time. Anybody have any ideas where that
might be coming from?

 

[Anthony Baxter]

There's been some talk recently about the relative speeds of the various
python SNMP libraries. I just did a little benchmarking, and got some
surprising results.

I downloaded pysnmp-3.4.2 and build a little mib walk application around
it. I used it to walk ifDescr on an Extreme Summit 48i (48 port
ethernet switch). I did the same thing using snmpwalk from net-snmp
5.0.8.

[snip]

But, where does the additional 5 seconds of real time come from for the
pysnmp version? I burned another 1-1/4 seconds of CPU at my end, but
everything else really should be the same. The network doesn't know
what kind of code built the packets. Neither does the box at the other
end. Something's inserting another 50ms or so delay per packet which is
not accounted for my the CPU time. Anybody have any ideas where that
might be coming from?

Try profiling the pysnmp code, see where the time is being taken.

From past, bitter experience, I can say that you can make a massive

massive difference in any SNMP application by carefully constructing
your getnext packets - don't just get things one at a time. Do some
rough calculations on how many entries you can fit in a packet, and
getnext multiple things at once. If you're walking a table of more than
one column, start at the top of each column and getnext in parallel.
If it's just one column, hopefully you can find out how many entries
are in the table. Start off at 0, 25%, 50% and 75% of the table, and
walk it in parallel. The SnmpTable code in the (very old, and now
abandoned) snmpy package had all sorts of evil smarts for dealing
with this stuff. I believe it got ported across to pysnmp, but I've been
blissfully able to avoid SNMP for about 5 years now, so I haven't
touched it at all.

 

[Ilya Etingof]

[ skipped ]

It's entirely expected that the pysnmp version had much higher CPU times
(from about 0.25 to 1.5 total user+sys). What I don't understand is why
the real time went up so much, from about 4 seconds to about 9 seconds.
Most of the time doing a mib walk is waiting for UDP packets on the wire.

My guess is that Python code takes up so much CPU time on a single SNMP message
processing, that OS's likely to schedule out (involuntarily context switch) python
process for greater number of times than it is with C version.

In other words, if you burn 0.01 CPU sec, you're likely to get it done within a
process's time slice. Although, when you burn 10 CPU secs in bulk, you're likely
to 1) run out of process's time slice (context switch) 2) compete for CPU time
with other processes on the system. In the end, both factors might contribute
to real time increase...

-ilya

 

[Ilya Etingof]

[ skipped ]

massive difference in any SNMP application by carefully constructing
your getnext packets - don't just get things one at a time. Do some
rough calculations on how many entries you can fit in a packet, and
getnext multiple things at once. If you're walking a table of more than
one column, start at the top of each column and getnext in parallel.

[ skipped ]

A variation of this method would be to use GETBULK PDU of SNMP v2c
wnenever available at your management target to save on 1) round-trip time
2) SNMP message build/parse expenses. Here's what I got doing IF-MIB table
traversal:

# pysnmp
[ilya@cray ~]$ /usr/bin/time pysnmpbulkwalk wrt -c public .1.3.6.1.2.1.2.2.1.1 > /dev/null
1.13user 0.02system 0:01.35elapsed 84%CPU (0avgtext+0avgdata 0maxresident)k
0inputs+0outputs (667major+409minor)pagefaults 0swaps

[ilya@cray ~]$ /usr/bin/time pysnmpwalk wrt -c public .1.3.6.1.2.1.2.2.1.1 > /dev/null
2.39user 0.04system 0:05.93elapsed 40%CPU (0avgtext+0avgdata 0maxresident)k
0inputs+0outputs (667major+368minor)pagefaults 0swaps

# net-snmp
[ilya@cray ~]$ /usr/bin/time snmpbulkwalk -On -v2c -c public wrt .1.3.6.1.2.1.2.2.1.1 > /dev/null
0.07user 0.02system 0:00.50elapsed 17%CPU (0avgtext+0avgdata 0maxresident)k
0inputs+0outputs (404major+125minor)pagefaults 0swaps

[ilya@cray ~]$ /usr/bin/time snmpwalk -On -v1 -c public wrt .1.3.6.1.2.1.2.2.1.1 > /dev/null
0.06user 0.01system 0:02.68elapsed 2%CPU (0avgtext+0avgdata 0maxresident)k
0inputs+0outputs (404major+122minor)pagefaults 0swaps

-ilya

 

[Roy Smith]

[ skipped ]

It's entirely expected that the pysnmp version had much higher CPU times
(from about 0.25 to 1.5 total user+sys). What I don't understand is why
the real time went up so much, from about 4 seconds to about 9 seconds.
Most of the time doing a mib walk is waiting for UDP packets on the wire.

My guess is that Python code takes up so much CPU time on a single SNMP
message
processing, that OS's likely to schedule out (involuntarily context switch)
python
process for greater number of times than it is with C version.

In other words, if you burn 0.01 CPU sec, you're likely to get it done within
a
process's time slice. Although, when you burn 10 CPU secs in bulk, you're
likely
to 1) run out of process's time slice (context switch) 2) compete for CPU
time
with other processes on the system. In the end, both factors might contribute
to real time increase...

-ilya

It turned out to be less complicated than that. In fact, it turned out
to be so simple that I canceled my articled about 2 minutes after I
posted it, but I guess it escaped before I got to it!

The problem turned out that in my python code, I was doing a getNext to
get the next oid, then a get for the value of that oid, so I was
generating twice as many packets as I needed to!

Why was I doing such a dumb thing? Because I was using a style I had
gotten used to in another system I'd worked with which caches the values
of getNext's. My code didn't have the cache, so I went out to the
network to satisfy the second request. Dumb, dumb, dumb.