X

Blogs about Deep Learning, Machine Learning, AI, NLP, Security, Oracle Traffic Director,Oracle iPlanet WebServer

  • October 24, 2008

DTrace script to collect information about cipher suites used

DTrace script to collect information about cipher suites used

Given below is a dtrace script I have to trace SSL calls. Running this script on a Web Server instance (32 bit ) pid lets say in our case is 9149. Sending some SSL requests on to this server :

There are two ways to run this log=normal and log=verbose. Pressing control C returns the statistical data.

$./ssltop.d 9149 log=normal
t@26: 2008 Oct 30 16:50:56: 129.158.224.109 Connection created
t@26: 2008 Oct 30 16:50:56: ListenSocket::accept called
t@30: 2008 Oct 30 16:50:56: 129.158.224.109 Negotiated cipher RC4
t@33: 2008 Oct 30 16:51:06: 129.158.224.109 Negotiated cipher AES-256
t@32: 2008 Oct 30 16:51:06: 129.158.224.109 Negotiated cipher AES-256
t@26: 2008 Oct 30 16:51:06: 129.158.224.109 Connection created
t@26: 2008 Oct 30 16:51:06: ListenSocket::accept called
t@33: 2008 Oct 30 16:51:06: 129.158.224.109 Negotiated cipher AES-256
t@32: 2008 Oct 30 16:51:06: 129.158.224.109 Negotiated cipher AES-256
t@33: 2008 Oct 30 16:51:06: 129.158.224.109 Negotiated cipher AES-256
t@32: 2008 Oct 30 16:51:06: 129.158.224.109 Negotiated cipher AES-256
t@33: 2008 Oct 30 16:51:06: 129.158.224.109 Negotiated cipher AES-256
t@32: 2008 Oct 30 16:51:06: 129.158.224.109 Negotiated cipher AES-256
t@33: 2008 Oct 30 16:51:06: 129.158.224.109 Negotiated cipher AES-256
t@32: 2008 Oct 30 16:51:06: 129.158.224.109 Negotiated cipher AES-256
t@33: 2008 Oct 30 16:51:06: 129.158.224.109 Negotiated cipher AES-256
t@32: 2008 Oct 30 16:51:06: 129.158.224.109 Negotiated cipher AES-256
t@30: 2008 Oct 30 16:51:06: 129.158.224.109 Negotiated cipher AES-256
\^C
SSL Functions Called
--------------------
count      Function
SSL Ciphers used
--------------------
count      cipher suite
1          RC4
13         AES-256

 Running in verbose mode gives more information :

$./ssltop.d 9149 log=verbose
t@32: 2008 Oct 30 16:50:13: Entered ssl3_GatherAppDataRecord ...
t@32: 2008 Oct 30 16:50:13: Entered ssl3_GatherCompleteHandshake ...
t@32: 2008 Oct 30 16:50:13: Entered ssl3_GatherData ...
t@35: 2008 Oct 30 16:50:13: Entered ssl3_GatherAppDataRecord ...
t@35: 2008 Oct 30 16:50:13: Entered ssl3_GatherCompleteHandshake ...
t@35: 2008 Oct 30 16:50:13: Entered ssl3_GatherData ...
t@32: 2008 Oct 30 16:50:14: Entered ssl3_HandleRecord ...
t@32: 2008 Oct 30 16:50:14: Entered ssl3_ClientAuthTokenPresent ...
t@32: 2008 Oct 30 16:50:14: Entered ssl3_ComputeRecordMAC ...
t@32: 2008 Oct 30 16:50:14: Entered ssl3_BumpSequenceNumber ...
t@32: 2008 Oct 30 16:50:14: 129.158.224.109 Negotiated cipher AES-256
t@32: 2008 Oct 30 16:50:14: Entered ssl3_SendApplicationData ...
t@32: 2008 Oct 30 16:50:14: Entered ssl3_SendRecord ...
t@32: 2008 Oct 30 16:50:14: Entered ssl3_ClientAuthTokenPresent ...
t@32: 2008 Oct 30 16:50:14: Entered ssl3_CompressMACEncryptRecord ...
t@32: 2008 Oct 30 16:50:14: Entered ssl3_ComputeRecordMAC ...
t@32: 2008 Oct 30 16:50:14: Entered ssl3_BumpSequenceNumber ...
t@32: 2008 Oct 30 16:50:14: Entered ssl3_SendApplicationData ...
t@32: 2008 Oct 30 16:50:14: Entered ssl3_SendRecord ...
t@32: 2008 Oct 30 16:50:14: Entered ssl3_ClientAuthTokenPresent ...
t@32: 2008 Oct 30 16:50:14: Entered ssl3_CompressMACEncryptRecord ...
t@32: 2008 Oct 30 16:50:14: Entered ssl3_ComputeRecordMAC ...
t@32: 2008 Oct 30 16:50:14: Entered ssl3_BumpSequenceNumber ...
t@32: 2008 Oct 30 16:50:14: Entered ssl3_GatherAppDataRecord ...
t@32: 2008 Oct 30 16:50:14: Entered ssl3_GatherCompleteHandshake ...
t@32: 2008 Oct 30 16:50:14: Entered ssl3_GatherData ...
t@35: 2008 Oct 30 16:50:14: Entered ssl3_HandleRecord ...
t@35: 2008 Oct 30 16:50:14: Entered ssl3_ClientAuthTokenPresent ...
t@35: 2008 Oct 30 16:50:14: Entered ssl3_ComputeRecordMAC ...
t@35: 2008 Oct 30 16:50:14: Entered ssl3_BumpSequenceNumber ...
t@35: 2008 Oct 30 16:50:14: 129.158.224.109 Negotiated cipher AES-256
t@35: 2008 Oct 30 16:50:14: Entered ssl3_SendApplicationData ...
t@35: 2008 Oct 30 16:50:14: Entered ssl3_SendRecord ...
t@35: 2008 Oct 30 16:50:14: Entered ssl3_ClientAuthTokenPresent ...
t@35: 2008 Oct 30 16:50:14: Entered ssl3_CompressMACEncryptRecord ...
t@35: 2008 Oct 30 16:50:14: Entered ssl3_ComputeRecordMAC ...
t@35: 2008 Oct 30 16:50:14: Entered ssl3_BumpSequenceNumber ...
t@35: 2008 Oct 30 16:50:14: Entered ssl3_GatherAppDataRecord ...
t@35: 2008 Oct 30 16:50:14: Entered ssl3_GatherCompleteHandshake ...
t@35: 2008 Oct 30 16:50:14: Entered ssl3_GatherData ...
t@32: 2008 Oct 30 16:50:14: Entered ssl3_HandleRecord ...
t@32: 2008 Oct 30 16:50:14: Entered ssl3_ClientAuthTokenPresent ...
t@32: 2008 Oct 30 16:50:14: Entered ssl3_ComputeRecordMAC ...
t@32: 2008 Oct 30 16:50:14: Entered ssl3_BumpSequenceNumber ...
t@32: 2008 Oct 30 16:50:14: 129.158.224.109 Negotiated cipher AES-256
t@32: 2008 Oct 30 16:50:14: Entered ssl3_SendApplicationData ...
t@32: 2008 Oct 30 16:50:14: Entered ssl3_SendRecord ...
t@32: 2008 Oct 30 16:50:14: Entered ssl3_ClientAuthTokenPresent ...
t@32: 2008 Oct 30 16:50:14: Entered ssl3_CompressMACEncryptRecord ...
t@32: 2008 Oct 30 16:50:14: Entered ssl3_ComputeRecordMAC ...
t@32: 2008 Oct 30 16:50:14: Entered ssl3_BumpSequenceNumber ...
t@32: 2008 Oct 30 16:50:14: Entered ssl3_GatherAppDataRecord ...
t@32: 2008 Oct 30 16:50:14: Entered ssl3_GatherCompleteHandshake ...
t@32: 2008 Oct 30 16:50:14: Entered ssl3_GatherData ...
t@32: 2008 Oct 30 16:50:14: Entered ssl3_HandleRecord ...
t@32: 2008 Oct 30 16:50:14: Entered ssl3_ClientAuthTokenPresent ...
t@32: 2008 Oct 30 16:50:14: Entered ssl3_ComputeRecordMAC ...
t@32: 2008 Oct 30 16:50:14: Entered ssl3_BumpSequenceNumber ...
t@32: 2008 Oct 30 16:50:14: 129.158.224.109 Negotiated cipher AES-256
t@32: 2008 Oct 30 16:50:14: Entered ssl3_SendApplicationData ...
t@32: 2008 Oct 30 16:50:14: Entered ssl3_SendRecord ...
t@32: 2008 Oct 30 16:50:14: Entered ssl3_ClientAuthTokenPresent ...
t@32: 2008 Oct 30 16:50:14: Entered ssl3_CompressMACEncryptRecord ...
t@32: 2008 Oct 30 16:50:14: Entered ssl3_ComputeRecordMAC ...
t@32: 2008 Oct 30 16:50:14: Entered ssl3_BumpSequenceNumber ...
t@32: 2008 Oct 30 16:50:14: Entered ssl3_GatherAppDataRecord ...
t@32: 2008 Oct 30 16:50:14: Entered ssl3_GatherCompleteHandshake ...
t@32: 2008 Oct 30 16:50:14: Entered ssl3_GatherData ...
t@32: 2008 Oct 30 16:50:14: Entered ssl3_HandleRecord ...
t@32: 2008 Oct 30 16:50:14: Entered ssl3_ClientAuthTokenPresent ...
t@32: 2008 Oct 30 16:50:14: Entered ssl3_ComputeRecordMAC ...
t@32: 2008 Oct 30 16:50:14: Entered ssl3_BumpSequenceNumber ...
t@32: 2008 Oct 30 16:50:14: 129.158.224.109 Negotiated cipher AES-256
t@32: 2008 Oct 30 16:50:14: Entered ssl3_SendApplicationData ...
t@32: 2008 Oct 30 16:50:14: Entered ssl3_SendRecord ...
t@32: 2008 Oct 30 16:50:14: Entered ssl3_ClientAuthTokenPresent ...
t@32: 2008 Oct 30 16:50:14: Entered ssl3_CompressMACEncryptRecord ...
t@32: 2008 Oct 30 16:50:14: Entered ssl3_ComputeRecordMAC ...
t@32: 2008 Oct 30 16:50:14: Entered ssl3_BumpSequenceNumber ...
t@32: 2008 Oct 30 16:50:14: Entered ssl3_GatherAppDataRecord ...
t@32: 2008 Oct 30 16:50:14: Entered ssl3_GatherCompleteHandshake ...
t@32: 2008 Oct 30 16:50:14: Entered ssl3_GatherData ...
...
t@32: 2008 Oct 30 16:50:14: Entered ssl3_BumpSequenceNumber ...
t@32: 2008 Oct 30 16:50:14: 129.158.224.109 Negotiated cipher AES-256
t@32: 2008 Oct 30 16:50:14: Entered ssl3_SendApplicationData ...
t@32: 2008 Oct 30 16:50:14: Entered ssl3_SendRecord ...
t@32: 2008 Oct 30 16:50:14: Entered ssl3_ClientAuthTokenPresent ...
t@32: 2008 Oct 30 16:50:14: Entered ssl3_CompressMACEncryptRecord ...
t@32: 2008 Oct 30 16:50:14: Entered ssl3_ComputeRecordMAC ...
t@32: 2008 Oct 30 16:50:14: Entered ssl3_BumpSequenceNumber ...
t@32: 2008 Oct 30 16:50:14: Entered ssl3_GatherAppDataRecord ...
t@32: 2008 Oct 30 16:50:14: Entered ssl3_GatherCompleteHandshake ...
t@32: 2008 Oct 30 16:50:14: Entered ssl3_GatherData ...
t@35: 2008 Oct 30 16:50:14: Entered ssl3_HandleRecord ...
t@35: 2008 Oct 30 16:50:14: Entered ssl3_ClientAuthTokenPresent ...
t@35: 2008 Oct 30 16:50:14: Entered ssl3_ComputeRecordMAC ...
t@35: 2008 Oct 30 16:50:14: Entered ssl3_BumpSequenceNumber ...
t@35: 2008 Oct 30 16:50:14: 129.158.224.109 Negotiated cipher AES-256
t@35: 2008 Oct 30 16:50:14: Entered ssl3_SendApplicationData ...
t@35: 2008 Oct 30 16:50:14: Entered ssl3_SendRecord ...
t@35: 2008 Oct 30 16:50:14: Entered ssl3_ClientAuthTokenPresent ...
t@35: 2008 Oct 30 16:50:14: Entered ssl3_CompressMACEncryptRecord ...
t@35: 2008 Oct 30 16:50:14: Entered ssl3_ComputeRecordMAC ...
t@35: 2008 Oct 30 16:50:14: Entered ssl3_BumpSequenceNumber ...
t@35: 2008 Oct 30 16:50:14: Entered ssl3_GatherAppDataRecord ...
t@35: 2008 Oct 30 16:50:14: Entered ssl3_GatherCompleteHandshake ...
t@35: 2008 Oct 30 16:50:14: Entered ssl3_GatherData ...
\^C
SSL Functions Called
--------------------
count      Function
13         ssl3_HandleRecord
15         ssl3_CompressMACEncryptRecord
15         ssl3_GatherAppDataRecord
15         ssl3_GatherCompleteHandshake
15         ssl3_GatherData
15         ssl3_SendApplicationData
15         ssl3_SendRecord
28         ssl3_BumpSequenceNumber
28         ssl3_ClientAuthTokenPresent
28         ssl3_ComputeRecordMAC
SSL Ciphers used
--------------------
count      cipher suite
13         AES-256

Dtrace Script :

#!/usr/sbin/dtrace -s
#pragma D option quiet
BEGIN
{

     log = $2;

}
 pid$1::ssl2_*:entry,
 pid$1::ssl_GatherRecord1stHandshake:entry,
 pid$1::sendRSAClientKeyExchange:entry,
 pid$1::sendDHClientKeyExchange:entry,
 pid$1::ssl3_*:entry,
 pid$1::SSL3_*:entry
/ log == "log=verbose" /
{
   printf("t@%d: %-20Y: Entered %s ...\n", tid, walltimestamp, probefunc);
   @count_table[probefunc] = count() ;
}

pid$1::*Listen*accept*:entry
{
    printf("t@%d: %-20Y: ListenSocket::accept called\n ", tid, walltimestamp);
}

pid$1::*HttpRequest*UnacceleratedRespond*:entry
{
/*
  strcpy(rqSn.sn.inbuf->address, clientIP)
*/
    self->getClientIP = 1;
}

pid$1::strcpy:entry
/ self->getClientIP == 1 /
{
    self->ip =  copyinstr(arg0);
    self->getClientIP = 0;
}

pid$1::*Connection*create*:entry
{
   self->connection = arg0;
}

pid$1::*Connection*create*:return
{
   self->ip = copyinstr(self->connection+8+112+112);
   printf("t@%d: %-20Y: %s Connection created\n", tid, walltimestamp, self->ip);
}

pid$1::SSL_SecurityStatus:entry
{
   self->getPblock = 1;
   /* first pblock call in this function is setting cipher */
}

pid$1::*pblock_kvinsert:entry
/ self->getPblock == 1 /
{
    self->getPblock = 0;
    self->cipher = copyinstr(arg1);
    printf("t@%d: %-20Y: %s Negotiated cipher %s\n", tid, walltimestamp,
           (self->ip != 0? self->ip : ""),
           (self->cipher != 0? self->cipher : ""));
    @count_cipher_freq[(self->cipher != 0?self->cipher:" ")] = count();
}

END
{
        printf("SSL Functions Called\n");
        printf("--------------------\n");
        printf("%-10s %-25s\n", "count", "Function");
        printa("%@-10u %-25s\n", @count_table);
        printf("SSL Ciphers used\n");
        printf("--------------------\n");
        printf("%-10s %-25s\n", "count", "cipher suite");
        printa("%@-10u %-25s\n", @count_cipher_freq);
}

Join the discussion

Comments ( 2 )
  • Jyri Friday, October 24, 2008

    This'll be useful for some of the cipher suite usage questions, cool.


  • Brian King Friday, December 15, 2017
    The link to the dtrace script is no longer working. Where can we find the script now?
Please enter your name.Please provide a valid email address.Please enter a comment.CAPTCHA challenge response provided was incorrect. Please try again.