<div dir="ltr"><br><div class="gmail_extra"><br><div class="gmail_quote">On 29 August 2017 at 21:55, Paul Wouters <span dir="ltr"><<a href="mailto:paul@nohats.ca" target="_blank">paul@nohats.ca</a>></span> wrote:<br><blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex"><br>
I was looking at a busy libreswan server to see where it is spending<br>
it's CPU in, to find out if there is something obvious to speed up.<br>
<br>
Below are the entries consisting of more then 1% but since most time<br>
looks spend in nss and sqlite and freebl, we might need to get more<br>
detailed info out of oprofile.... The most expensive "native" calls<br>
seem to be state_with_serialno() and vfprintf(). I'm a little<br>
puzzled by with resolve_myid(). And maybe sanitize_string() could<br>
be more sparringly used as well.<br>
<br></blockquote>The thing I hate about simplistic profiling is its lack of context, and how this leads to micro-optimizing; context would let us see why the calls are occurring and likely eliminate them.<br><div><br></div><div>vfprintf() and friends:<br><br></div><div>- presumably the vfprintf() calls are coming from libreswan_vloglog() and friends. These call fprintf() and/or a syslog(3) (both likely call vfprintf(); don't get confused by syslog(2)). While I've no direct evidence of this, sanitize_string() also showing up tends to support this theory.<br><div><div><br></div>While some fprintf() could be replaced with fwrite(), I'm not sure of the benefit.<br><br></div>As an aside, does it include:<br>
e77fd263fb7e13b8897441e8bd66af054ced8378 logging: change
libreswan_log()/libreswan_loglog() into calls to new
libreswan_vloglog()<br>which would have helped reduce sprintf() calls. Prior to that, everything was doing sprintf() calls all the way down.<br></div><br><div>- sanitize_string():<br><br></div><div>I still can't get my head around if/when it is needed, and I suspect I'm not alone - is there a diagram explaining what is going on? It feels like we've solved the wrong problem.<br><br></div><div>- other print calls<br><br></div><div>Since we're doing lots of logging they would naturally bubble up.<br><br></div><div>NSS:<br></div><div><br></div><div>- what is making such seemingly heavy use of SQLITE? Is it NSS?<br><br></div><div>- do we know our NSS workload? For instance, the number of DH and/or other "heavy" operations we're doing. If we know that we can work out the expected throughput; not being close would suggest we're instead making NSS jump through hoops.<br><br></div><div>Andrew<br></div><div><br><br></div><blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex">
CPU: Intel Ivy Bridge microarchitecture, speed 3292.52 MHz (estimated)<br>
Counted CPU_CLK_UNHALTED events (Clock cycles when not halted) with a unit mask of 0x00 (No unit mask) count 100000<br>
samples % image name app name symbol name<br>
------------------------------<wbr>------------------------------<wbr>-------------------<br>
34791 18.9389 libsoftokn3.so pluto /usr/lib/x86_64-linux-gnu/nss/<wbr>libsoftokn3.so<br>
34791 100.000 libsoftokn3.so pluto /usr/lib/x86_64-linux-gnu/nss/<wbr>libsoftokn3.so [self]<br>
------------------------------<wbr>------------------------------<wbr>-------------------<br>
22648 12.3287 libsqlite3.so.0.8.6 pluto /usr/lib/x86_64-linux-gnu/libs<wbr>qlite3.so.0.8.6<br>
22648 100.000 libsqlite3.so.0.8.6 pluto /usr/lib/x86_64-linux-gnu/libs<wbr>qlite3.so.0.8.6 [self]<br>
------------------------------<wbr>------------------------------<wbr>-------------------<br>
15405 8.3859 <a href="http://libpthread-2.23.so" rel="noreferrer" target="_blank">libpthread-2.23.so</a> pluto pthread_mutex_lock<br>
<a href="tel:15405%20%20%20%20100.000" value="+15405100000" target="_blank">15405 100.000</a> <a href="http://libpthread-2.23.so" rel="noreferrer" target="_blank">libpthread-2.23.so</a> pluto pthread_mutex_lock [self]<br>
------------------------------<wbr>------------------------------<wbr>-------------------<br>
10967 5.9700 libfreeblpriv3.so pluto /usr/lib/x86_64-linux-gnu/nss/<wbr>libfreeblpriv3.so<br>
10967 100.000 libfreeblpriv3.so pluto /usr/lib/x86_64-linux-gnu/nss/<wbr>libfreeblpriv3.so [self]<br>
------------------------------<wbr>------------------------------<wbr>-------------------<br>
6861 3.7349 pluto pluto state_with_serialno<br>
6861 100.000 pluto pluto state_with_serialno [self]<br>
------------------------------<wbr>------------------------------<wbr>-------------------<br>
5977 3.2537 <a href="http://libc-2.23.so" rel="noreferrer" target="_blank">libc-2.23.so</a> pluto vfprintf<br>
5977 100.000 <a href="http://libc-2.23.so" rel="noreferrer" target="_blank">libc-2.23.so</a> pluto vfprintf [self]<br>
------------------------------<wbr>------------------------------<wbr>-------------------<br>
4343 2.3642 <a href="http://libc-2.23.so" rel="noreferrer" target="_blank">libc-2.23.so</a> pluto _int_malloc<br>
4343 100.000 <a href="http://libc-2.23.so" rel="noreferrer" target="_blank">libc-2.23.so</a> pluto _int_malloc [self]<br>
------------------------------<wbr>------------------------------<wbr>-------------------<br>
4279 2.3293 pluto pluto resolve_myid<br>
4279 100.000 pluto pluto resolve_myid [self]<br>
------------------------------<wbr>------------------------------<wbr>-------------------<br>
4106 2.2352 <a href="http://libc-2.23.so" rel="noreferrer" target="_blank">libc-2.23.so</a> pluto __memcmp_sse4_1<br>
4106 100.000 <a href="http://libc-2.23.so" rel="noreferrer" target="_blank">libc-2.23.so</a> pluto __memcmp_sse4_1 [self]<br>
------------------------------<wbr>------------------------------<wbr>-------------------<br>
4056 2.2079 <a href="http://libpthread-2.23.so" rel="noreferrer" target="_blank">libpthread-2.23.so</a> pluto pthread_mutex_unlock<br>
4056 100.000 <a href="http://libpthread-2.23.so" rel="noreferrer" target="_blank">libpthread-2.23.so</a> pluto pthread_mutex_unlock [self]<br>
------------------------------<wbr>------------------------------<wbr>-------------------<br>
3161 1.7207 pluto pluto sanitize_string<br>
3161 100.000 pluto pluto sanitize_string [self]<br>
------------------------------<wbr>------------------------------<wbr>-------------------<br>
2890 1.5732 ip_tables pluto /ip_tables<br>
2890 100.000 ip_tables pluto /ip_tables [self]<br>
------------------------------<wbr>------------------------------<wbr>-------------------<br>
2643 1.4388 <a href="http://libc-2.23.so" rel="noreferrer" target="_blank">libc-2.23.so</a> pluto _int_free<br>
2643 100.000 <a href="http://libc-2.23.so" rel="noreferrer" target="_blank">libc-2.23.so</a> pluto _int_free [self]<br>
------------------------------<wbr>------------------------------<wbr>-------------------<br>
2582 1.4055 pluto pluto delete_public_keys<br>
2582 100.000 pluto pluto delete_public_keys [self]<br>
------------------------------<wbr>------------------------------<wbr>-------------------<br>
2423 1.3190 pluto pluto get_next_rdn<br>
2423 100.000 pluto pluto get_next_rdn [self]<br>
------------------------------<wbr>------------------------------<wbr>-------------------<br>
2342 1.2749 libnss3.so pluto /usr/lib/x86_64-linux-gnu/libn<wbr>ss3.so<br>
2342 100.000 libnss3.so pluto /usr/lib/x86_64-linux-gnu/libn<wbr>ss3.so [self]<br>
------------------------------<wbr>------------------------------<wbr>-------------------<br>
1968 1.0713 <a href="http://libc-2.23.so" rel="noreferrer" target="_blank">libc-2.23.so</a> pluto malloc<br>
1968 100.000 <a href="http://libc-2.23.so" rel="noreferrer" target="_blank">libc-2.23.so</a> pluto malloc [self]<br>
------------------------------<wbr>------------------------------<wbr>-------------------<br>
1959 1.0664 libnspr4.so pluto /usr/lib/x86_64-linux-gnu/libn<wbr>spr4.so<br>
1959 100.000 libnspr4.so pluto /usr/lib/x86_64-linux-gnu/libn<wbr>spr4.so [self]<br>
------------------------------<wbr>------------------------------<wbr>-------------------<br>
______________________________<wbr>_________________<br>
Swan-dev mailing list<br>
<a href="mailto:Swan-dev@lists.libreswan.org" target="_blank">Swan-dev@lists.libreswan.org</a><br>
<a href="https://lists.libreswan.org/mailman/listinfo/swan-dev" rel="noreferrer" target="_blank">https://lists.libreswan.org/ma<wbr>ilman/listinfo/swan-dev</a><br>
</blockquote></div><br></div></div>