292166 - Cache misses from SSL_GetStatistics are misleading

Status: NEW

(NSS :: Libraries, enhancement, P3)

Description

[Julien Pierre]

The client-side statistics in the SSL3Statistics structure include the following
fields :

    /* statistics from ssl3_HandleServerHello (hsh) */
    long hsh_sid_cache_hits;
    long hsh_sid_cache_misses;
    long hsh_sid_cache_not_ok;

As explained to me by Nelson, hsh_sid_cache_not_ok tracks cases in which the
session sent in the server hello matched the client helo, but the client was
unable to resume for some reason (eg. the smartcard containing the key was
pulled out).

hsh_sid_cache_hits tracks cases of successful session restarts.

My issue is with hsh_sid_cache_misses . Currently, this counter includes not
only legitimate cache misses - in which the client sent a session ID to the
server, which the server couldn't resume - but also cases in which the client
didn't have a session in its local cache to restart, such as as when starting
the application with an empty cache, or if the client set the SSL_NO_CACHE
socket option . I believe the later two cases should not be counted as part of
"cache misses" - since there is no involvment with the client's local cache that
resulted in a miss. Only handshakes in which the client sent a non-zero session
ID should be legitimately counted as cache misses. The full handshakes that
didn't result from cache misses should be counted in a new field of the
statistics structure - perhaps called hsh_new_sessions, which we are free to
extend at will, since it is a static variable in ssl3con.c .

The lack of differentation of these handshakes cost me a lot time in debugging
yesterday. The problem was that a few few true cache misses were happening,
because the server's SID cache was too small, but these cache misses were
counted by strsclnt together with requests made by the client with the
SSL_NO_CACHE option.

The same differentiation issue would need to be resolved for the server-side
handle client hello (hch_xxx), and for the client-side send client hello step
(sch_xxx). Again the fix would be an extra counter for each case.

Comment 1

[Nelson Bolyard (seldom reads bugmail)]

To preserve backwards binary compatibility, and continue to pass our 
backwards binary compatibility tests (which run new libs with old programs),
the existing counters must continue to count what they presently count.

SO, instead of changing the definition of hsh_sid_cache_misses, you should
add two new counters, one that counts real misses, and one that counts 
handshakes that did not attempt to use the cache.  

Of course the new counters need to be added to the end of the struct.

Comment 2

[Julien Pierre]

Attachment: dtrace script to show true detailed handshake statistics on the server-side

Just for information, I attached this dtrace script, which collects stats at
the server-side. It needs to be run under solaris 10 as root with the pid of
the selfserv server (or any other NSS SSL server process). It should always
work with debug NSS bits. With optimized bits, the name of the symbols in the
dtrace script may need to be adjusted, since optimizers remove some symbols,
but this differs with various compilers.

These were the stats reported on the client side by strsclnt (./strsclnt -o -T
-p 2000 -t 100 -c 2200 -D -P 50 monstre) :

strsclnt: 0 cache hits; 1 cache misses, 0 cache not reusable
strsclnt: 1098 cache hits; 1102 cache misses, 0 cache not reusable

These were the stats reported by my dtrace script :

dtrace: script './hs2.d' matched 9 probes
^C
CPU	ID		      FUNCTION:NAME
  0	 2			       :END 
Total stats

  SSL session cache misses					    2
  Time elapsed (s)						    3
  Restart SSL handshakes					 1098
  SSL session cache lookups					 1100
  Full SSL handshakes						 1102
  Total SSL handshakes						 2200

I would like to get the same kind of detailed stats from strsclnt, notably the
information about the 2 actual cache misses . Right now, the information from
strsclnt is basically only full vs restart handshakes, not cache misses.