(SNMP over) UDP performance
Peter Valdemar Mørch
measurement. To get the performance numbers, I'm issuing:
$ snmpwalk -v2c -cpublic ipAddress ifIndex
That request returns 164 rows, which means there are 165 UDP request/
response pairs going out one after the other.
Raw - directly from the server in the other end - without sshuttle:
real 0m0.401s
user 0m0.028s
sys 0m0.012s
Using a socat pair (described at http://www.morch.com/2011/07/05/forwarding-snmp-ports-over-ssh-using-socat/)
real 0m4.475s
user 0m0.024s
sys 0m0.036s
Using sshuttle:
real 0m57.153s
user 0m0.040s
sys 0m0.024s
So sshuttle takes > 10 times longer. Is there something I can do to
improve that? It is useful as it is, but I'd prefer it to be a little
closer to a socat pair performance-wise, as I'm guessing the UDP-over-
TCP characteristics should be the same, shouldn't they?
BTW, I'm aware that in my post in the thread "UDP Support?", I wrote:
"I'm prepared to accept even very poor performance". :-)
Peter
Roger
Roger
--
You may say I am a dreamer, but I am not the only one.
Peter Valdemar Mørch
> You might want to try the '--no-latency-control' option.
* With --no-latency-control (46.4s average)
* Without --no-latency-control (49.7s average)
What I see is that timings vary a lot, regardless of whether --no-
latency-control is present. Sometimes it is close to the 5 secs that
socat takes. Due to the variation, I don't trust my sample of only 10
runs to conclude whether --no-latency-control really helps, but it
looks like it might. As you can see by the '164' in the output, the
very low timings do not indicate error conditions.
I also tried 10 runs each both directly on the remote server and using
socat, but there I found the timings to be consistently low.
################################
* With --no-latency-control
################################
46.4s average (the last timing information is a total!)
> time for ((i=0;$i<10;i++)) do time snmpwalk -v2c -cpublic ipAddress ifIndex | wc -l ; done
164
real 0m42.908s
user 0m0.040s
sys 0m0.040s
164
real 0m47.497s
user 0m0.032s
sys 0m0.048s
164
real 1m19.089s
user 0m0.024s
sys 0m0.060s
164
real 0m4.836s
user 0m0.052s
sys 0m0.024s
164
real 0m37.105s
user 0m0.040s
sys 0m0.032s
164
real 0m47.754s
user 0m0.044s
sys 0m0.032s
164
real 0m28.335s
user 0m0.040s
sys 0m0.040s
164
real 1m0.955s
user 0m0.032s
sys 0m0.048s
164
real 0m49.006s
user 0m0.032s
sys 0m0.048s
164
real 1m6.983s
user 0m0.052s
sys 0m0.028s
real 7m44.471s
user 0m0.388s
sys 0m0.404s
################################
* Without --no-latency-control
################################
49.7s average (the last timing information is a total!)
> time for ((i=0;$i<10;i++)) do time snmpwalk -v2c -cpublic ipAddress ifIndex | wc -l ; done
164
real 0m15.013s
user 0m0.048s
sys 0m0.036s
164
real 1m7.126s
user 0m0.056s
sys 0m0.040s
164
real 1m20.085s
user 0m0.028s
sys 0m0.052s
164
real 0m43.267s
user 0m0.044s
sys 0m0.032s
164
real 0m29.197s
user 0m0.040s
sys 0m0.040s
164
real 0m41.606s
user 0m0.040s
sys 0m0.036s
164
real 0m59.451s
user 0m0.032s
sys 0m0.052s
164
real 0m43.025s
user 0m0.036s
sys 0m0.044s
164
real 1m18.273s
user 0m0.044s
sys 0m0.036s
164
real 0m40.397s
user 0m0.040s
sys 0m0.036s
real 8m17.441s
user 0m0.408s
sys 0m0.408s
Avery Pennarun
> You might want to try the '--no-latency-control' option.
I'd be very surprised if the latency control had any significant
negative effect (which apparently it didn't :)). After all, the whole
*point* of it is to keep latency low, and if it takes 57 seconds to do
165 turnarounds, that's very high latency.
The "problem" with SNMP is that it has a very large number of
synchronous requests, which is about the worst possible case for any
network protocol. Fundamentally, it's just badly designed and never
should have been done that way, but oh well.
In any case, 57/165 = 345ms per turnaround. That's not *crazily*
high, but if you're normally getting much much faster times, that
means your ping times must be much lower than 345ms.
So... what are your ping times from your sshuttle client machine to
the ssh server? What are the ping times from the ssh server to the
snmp server? Is the combination anywhere near 345ms?
It's certainly possible that sshuttle is delaying things somehow due
to some sort of accident, particularly if you have other sessions
(file transfers?) going through the tunnel at once. Is that a
possibility?
Finally, we might be suffering from the nagle algorithm in TCP, which
we have little control over since the TCP session is managed by ssh.
Stupid idea: can you try adding, say, 500 or 1500 bytes to every UDP
packet we send through the tunnel and stripping it off at the receive
side? It sounds stupid, but this should tell us if there are any
nagle-related issues.
...I guess I should really review those UDP patches :)
Sorry I've been so busy lately, I'll have to do another burst of
catching up sometime soon. Maybe even this weekend.
Have fun,
Avery
Brian May
> It's certainly possible that sshuttle is delaying things somehow due
> to some sort of accident, particularly if you have other sessions
> (file transfers?) going through the tunnel at once. Is that a
> possibility?
It is always possible there is a performance bug in my code too. I can
think of some minor things that can be optimized (e.g. two round trips
required on initial connection), nothing that would affect this
significantly however (as same connection is used for every packet).
It is also possible that some part of my code, while technically
correct, as written, doesn't perform as well as I hoped under python.
> ...I guess I should really review those UDP patches :)
So far I haven't submitted the UDP patches (although the code is
written), only the IPv6 patches. UDP would be the next patch after the
ones I have already submitted.
--
Brian May <br...@microcomaustralia.com.au>
Avery Pennarun
<br...@microcomaustralia.com.au> wrote:
> On 28 July 2011 03:21, Avery Pennarun <apen...@gmail.com> wrote:
>> It's certainly possible that sshuttle is delaying things somehow due
>> to some sort of accident, particularly if you have other sessions
>> (file transfers?) going through the tunnel at once. Is that a
>> possibility?
>
> It is always possible there is a performance bug in my code too. I can
> think of some minor things that can be optimized (e.g. two round trips
> required on initial connection), nothing that would affect this
> significantly however (as same connection is used for every packet).
Yup. A strace or tcpdump might help to track this down. At least
snmpwalk is a pretty easy use case (I think you can just apt-get
install an snmp server to test with on Debian).
> It is also possible that some part of my code, while technically
> correct, as written, doesn't perform as well as I hoped under python.
This is conceivable, but pretty unlikely - 345ms per packet would be
completely shocking unless we're grinding through each byte one by one
or something awful like that.
>> ...I guess I should really review those UDP patches :)
>
> So far I haven't submitted the UDP patches (although the code is
> written), only the IPv6 patches. UDP would be the next patch after the
> ones I have already submitted.
Ah. Well, in that case, I should at least just review my overflowing inbox :)
Have fun,
Avery
Brian May
> Yup. A strace or tcpdump might help to track this down. At least
> snmpwalk is a pretty easy use case (I think you can just apt-get
> install an snmp server to test with on Debian).
This seems to affect Peter a lot more then me I think. I get slow
times, but I expect that as this isn't a fast connection and as
discussed snmp isn't very efficient. Then again, maybe a fast
connection is a contributing factor?
A tshark shows 2574 snmp packets on the sshuttle client end and 2542
snmp packets at the server end for a single walk operation. Or 32
packets lost.
The first one lost seems to be a request to the server:
327 5.417118 128.250.103.238 -> 192.168.3.3 SNMP get-next-request
1.3.6.1.2.1.4.24.4.1.3.192.168.3.0.0.255.255.255.0.0.0.0.0
This is retransmitted and works on the 2nd attempt:
328 6.418173 128.250.103.238 -> 192.168.3.3 SNMP get-next-request
1.3.6.1.2.1.4.24.4.1.3.192.168.3.0.0.255.255.255.0.0.0.0.0
In fact all the missing packets seem to be outgoing packets, similar
to above. Always works for me on the 2nd attempt.
So the question is, where is this data being lost?
The last thing in the sshuttle logs before it paused indicates a
success 2 way transfer, e.g.:
c : Waiting: 7 r=[3, 5, 7, 8, 11, 12, 15] w=[] x=[] (fullness=8934/0)
c : Ready: 7 r=[8] w=[] x=[]
c : Accept UDP using socket_ext recvmsg.
c : Accept UDP: ('128.250.103.238', 58452) -> ('192.168.3.3', 161).
c : > channel=2 cmd=UDP_DATA len=64 (fullness=8934)
c : Remaining DNS requests: 0
c : Remaining UDP channels: 1
c : mux wrote: 72/72
c : Waiting: 7 r=[3, 5, 7, 8, 11, 12, 15] w=[] x=[] (fullness=8998/0)
s: mux wrote: 76/76
s: Waiting: 2 r=[4, 6] w=[] x=[] (fullness=9969/0)
s: Ready: 2 r=[4] w=[] x=[]
s: < channel=2 cmd=UDP_DATA len=64
s: Incoming UDP request channel=2, cmd=16909
s: is incoming UDP data. '192.168.3.3' 161.
s: UDP: sending to '192.168.3.3' port 161
s: Waiting: 2 r=[4, 6] w=[] x=[] (fullness=9969/0)
s: Ready: 2 r=[6] w=[] x=[]
s: UDP response: 54 bytes
s: > channel=2 cmd=UDP_DATA len=70 (fullness=9969)
c : Ready: 7 r=[15] w=[] x=[]
c : < channel=2 cmd=UDP_DATA len=70
c : doing send from ('192.168.3.3', 161) to ('128.250.103.238', 58452)
c : Waiting: 7 r=[3, 5, 7, 8, 11, 12, 15] w=[] x=[] (fullness=8998/0)
s: mux wrote: 78/78
s: Waiting: 2 r=[4, 6] w=[] x=[] (fullness=10039/0)
[ pause ]
So this can't be the botched transfer, because the botched transfer
never got any response, not even at the server end.
Which in turn means our select(...) call never detected the packet, or
the client would have printed a "Ready" after the "Waiting".
The very next log entries also represent another successful two way transfer.
Is it possible we have encountered an obscure kernel bug here?
--
Brian May <br...@microcomaustralia.com.au>