On 29 August 2017 at 21:55, Paul Wouters <[email protected]> wrote: > > I was looking at a busy libreswan server to see where it is spending > it's CPU in, to find out if there is something obvious to speed up. > > Below are the entries consisting of more then 1% but since most time > looks spend in nss and sqlite and freebl, we might need to get more > detailed info out of oprofile.... The most expensive "native" calls > seem to be state_with_serialno() and vfprintf(). I'm a little > puzzled by with resolve_myid(). And maybe sanitize_string() could > be more sparringly used as well. > > 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.
vfprintf() and friends: - 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. While some fprintf() could be replaced with fwrite(), I'm not sure of the benefit. As an aside, does it include: e77fd263fb7e13b8897441e8bd66af054ced8378 logging: change libreswan_log()/libreswan_loglog() into calls to new libreswan_vloglog() which would have helped reduce sprintf() calls. Prior to that, everything was doing sprintf() calls all the way down. - sanitize_string(): 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. - other print calls Since we're doing lots of logging they would naturally bubble up. NSS: - what is making such seemingly heavy use of SQLITE? Is it NSS? - 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. Andrew CPU: Intel Ivy Bridge microarchitecture, speed 3292.52 MHz (estimated) > Counted CPU_CLK_UNHALTED events (Clock cycles when not halted) with a unit > mask of 0x00 (No unit mask) count 100000 > samples % image name app name symbol > name > ------------------------------------------------------------ > ------------------- > 34791 18.9389 libsoftokn3.so pluto > /usr/lib/x86_64-linux-gnu/nss/libsoftokn3.so > 34791 100.000 libsoftokn3.so pluto > /usr/lib/x86_64-linux-gnu/nss/libsoftokn3.so [self] > ------------------------------------------------------------ > ------------------- > 22648 12.3287 libsqlite3.so.0.8.6 pluto > /usr/lib/x86_64-linux-gnu/libsqlite3.so.0.8.6 > 22648 100.000 libsqlite3.so.0.8.6 pluto > /usr/lib/x86_64-linux-gnu/libsqlite3.so.0.8.6 [self] > ------------------------------------------------------------ > ------------------- > 15405 8.3859 libpthread-2.23.so pluto > pthread_mutex_lock > 15405 100.000 libpthread-2.23.so pluto > pthread_mutex_lock [self] > ------------------------------------------------------------ > ------------------- > 10967 5.9700 libfreeblpriv3.so pluto > /usr/lib/x86_64-linux-gnu/nss/libfreeblpriv3.so > 10967 100.000 libfreeblpriv3.so pluto > /usr/lib/x86_64-linux-gnu/nss/libfreeblpriv3.so [self] > ------------------------------------------------------------ > ------------------- > 6861 3.7349 pluto pluto > state_with_serialno > 6861 100.000 pluto pluto > state_with_serialno [self] > ------------------------------------------------------------ > ------------------- > 5977 3.2537 libc-2.23.so pluto > vfprintf > 5977 100.000 libc-2.23.so pluto > vfprintf [self] > ------------------------------------------------------------ > ------------------- > 4343 2.3642 libc-2.23.so pluto > _int_malloc > 4343 100.000 libc-2.23.so pluto > _int_malloc [self] > ------------------------------------------------------------ > ------------------- > 4279 2.3293 pluto pluto > resolve_myid > 4279 100.000 pluto pluto > resolve_myid [self] > ------------------------------------------------------------ > ------------------- > 4106 2.2352 libc-2.23.so pluto > __memcmp_sse4_1 > 4106 100.000 libc-2.23.so pluto > __memcmp_sse4_1 [self] > ------------------------------------------------------------ > ------------------- > 4056 2.2079 libpthread-2.23.so pluto > pthread_mutex_unlock > 4056 100.000 libpthread-2.23.so pluto > pthread_mutex_unlock [self] > ------------------------------------------------------------ > ------------------- > 3161 1.7207 pluto pluto > sanitize_string > 3161 100.000 pluto pluto > sanitize_string [self] > ------------------------------------------------------------ > ------------------- > 2890 1.5732 ip_tables pluto > /ip_tables > 2890 100.000 ip_tables pluto > /ip_tables [self] > ------------------------------------------------------------ > ------------------- > 2643 1.4388 libc-2.23.so pluto > _int_free > 2643 100.000 libc-2.23.so pluto > _int_free [self] > ------------------------------------------------------------ > ------------------- > 2582 1.4055 pluto pluto > delete_public_keys > 2582 100.000 pluto pluto > delete_public_keys [self] > ------------------------------------------------------------ > ------------------- > 2423 1.3190 pluto pluto > get_next_rdn > 2423 100.000 pluto pluto > get_next_rdn [self] > ------------------------------------------------------------ > ------------------- > 2342 1.2749 libnss3.so pluto > /usr/lib/x86_64-linux-gnu/libnss3.so > 2342 100.000 libnss3.so pluto > /usr/lib/x86_64-linux-gnu/libnss3.so [self] > ------------------------------------------------------------ > ------------------- > 1968 1.0713 libc-2.23.so pluto malloc > 1968 100.000 libc-2.23.so pluto > malloc [self] > ------------------------------------------------------------ > ------------------- > 1959 1.0664 libnspr4.so pluto > /usr/lib/x86_64-linux-gnu/libnspr4.so > 1959 100.000 libnspr4.so pluto > /usr/lib/x86_64-linux-gnu/libnspr4.so [self] > ------------------------------------------------------------ > ------------------- > _______________________________________________ > Swan-dev mailing list > [email protected] > https://lists.libreswan.org/mailman/listinfo/swan-dev >
_______________________________________________ Swan-dev mailing list [email protected] https://lists.libreswan.org/mailman/listinfo/swan-dev
