It seems that many developers and dtrace users found themselves in a position where they wanted to add some SDT probes to a module to get more insight into what's going on but the had to pause and were thinking "okay, more probes. But where to put them ? Do I really need the additional probes when I already have the fbt ones ?". To do this, systematic approach is needed in order not to over-do or under-do. I will use KSSL (Solaris kernel SSL proxy [1]) for illustration.

With CR 6556447, tens of SDT probes were introduced into KSSL module and other modules which interface with it. Also, in addition to the new SDT probes, in KSSL we got rid of the KSSL_DEBUG macros compiled only in DEBUG kernels and substituted them with SDT probes. As a result, much better observability and error detection was achieved with both debug and non-debug kernels. The other option would be to create KSSL dtrace provider but that would be too big gun for what is needed to achieve.

Generically, the following interesting data points for data gathering/observation can be identified in code:

• data paths
  When there is a more than one path how data could flow into a subsystem. E.g. for TCP we have couple of cases how SSL data could reach KSSL input queue. To identify where from exactly was tcp_kssl_input() called we use SDT probes:

  	if (tcp->tcp_listener || tcp->tcp_hard_binding) {
  ...
  		if (tcp->tcp_kssl_pending) {
  			DTRACE_PROBE1(kssl_mblk__ksslinput_pending,
  			    mblk_t *, mp);
  			tcp_kssl_input(tcp, mp);
  		} else {
  			tcp_rcv_enqueue(tcp, mp, seg_len);
  		}
  	} else {
  ...
  		/* Does this need SSL processing first? */
  			if ((tcp->tcp_kssl_ctx != NULL) &&
  			    (DB_TYPE(mp) == M_DATA)) {
  				DTRACE_PROBE1(kssl_mblk__ksslinput_data1,
  				    mblk_t *, mp);
  				tcp_kssl_input(tcp, mp);
  			} else {
  				putnext(tcp->tcp_rq, mp);
  				if (!canputnext(tcp->tcp_rq))
  					tcp->tcp_rwnd -= seg_len;
  			}
  ...
  

• data processed in while/for cycles
  To observe what happens in each iteration of the cycle. Can be used in code like this:

  while (mp != NULL) {
  
    DTRACE_PROBE1(kssl_mblk__handle_record_cycle, mblk_t *, mp);
  
    /* process the data */
    ...
  
    mp = mp->b_cont;
  }
  

• switch statements
  If significant/non-trivial processing happens inside switch it may be useful to add SDT probes there too. E.g.:

    content_type = (SSL3ContentType)mp->b_rptr[0];
    switch(content_type) {
      /* select processing according to type */
      case content_alert:
         DTRACE_PROBE1(kssl_mblk__content_alert, mblk_t *, mp);
         ...
         break;
      case content_change_cipher_spec:
         DTRACE_PROBE1(kssl_mblk__change_cipher_spec, mblk_t *, mp);
         ...
         break;
      default:
         DTRACE_PROBE1(kssl_mblk__unexpected_msg, mblk_t *, mp);
         break;
    }
  

• labels which cannot be (easily) identified in other way
  Useful if code which follows the label is generic (assignments, no function calls), e.g.:

                                  /*
                                   * Give this session a chance to fall back to
                                   * userland SSL
                                   */
                                  if (ctxmp == NULL)
                                          goto no_can_do;
  ...
  no_can_do:
                                  DTRACE_PROBE1(kssl_no_can_do, tcp_t *, tcp);
                                  listener = tcp->tcp_listener;
                                  ind_mp = tcp->tcp_conn.tcp_eager_conn_ind;
                                  ASSERT(ind_mp != NULL);
  

You've surely noticed that same of the probe definitions above have common prefix (kssl_mblk-). This is one of the things which make SDT probes so attractive. With prefixes it is possible to do the e.g. following:

sdt:::kssl_err-*
{
  trace(timestamp);
  printf("hit error in %s\n", probefunc);
  stack(); ustack();
}

The important part is that we do not specify module of function name. The implicit wildcard (funcname/probename left out) combined with explicit wildcard (prefix + asterisk) will lead to all KSSL error probes to be activated regardless of in which module or function there are defined. This is obviously very useful for technologies which span multiple Solaris subsystems or modules (such as KSSL).

The nice thing about the error probes is that they could be leveraged in test suites. For each test case we can first run dtrace script with the above probeset covering all KSSL errors in the background and after the test completes just check if it produced some data. If it did, then the test case can be considered as failed. No need to check kstat(1M) (and other counters), log files, etc.

Also, thanks to the way how dtrace probes are activated we can have both generic probeset (using this for lack of better term) as above with addition of probe specific action, e.g.:

/* probeset of all KSSL error probes */
sdt:::kssl_err-*
{
  trace(timestamp);
  printf("hit error in %s\n", probefunc);
}

/* 
  the probe definition is:
     DTRACE_PROBE2(kssl_err__bad_record_size,
         uint16_t, rec_sz, int, spec->cipher_bsize);
 */
sdt:kssl:kssl_handle_record:kssl_err-bad_record_size
{
  trace(timestamp);
  tracemem(arg0, 32);
  printf("rec_sz = %d , cipher_bsize = %d\n", arg1, arg2);
}

If probe kssl_err-bad_record_size gets activated the generic probe will be activated (and fires) too because the probeset contains the probe.

Similarly to the error prefix, we can have data specific prefix. For KSSL it is kssl_mblk- prefix which could be used for tracing all mblks (msgb(9S)) as they flow through TCP/IP, STREAMS and KSSL modules. With such probes it is possible to do e.g. the following:

/* how many bytes from a mblk to dump */
#define DUMP_SIZE       48

/* use macros from  */
#define MBLKL(mp)       ((mp)->b_wptr - (mp)->b_rptr)
#define DB_FLAGS(mp)    ((mp)->b_datap->db_flags)

#define PRINT_MBLK_INFO(mp)                                             \
        printf("mblk = 0x%p\n", mp);                                    \
        printf("mblk size = %d\n", MBLKL((mblk_t *)mp));                \
        PRINT_MBLK_PTRS(mp);

#define PRINT_MBLK(mp)                                                  \
                trace(timestamp);                                       \
                printf("\n");                                           \
                PRINT_MBLK_INFO(mp);                                    \
                printf("DB_FLAGS = 0x%x", DB_FLAGS((mblk_t *)mp));      \
                tracemem(((mblk_t *)mp)->b_rptr, DUMP_SIZE);            \
                tracemem(((mblk_t *)mp)->b_wptr - DUMP_SIZE,            \
                        DUMP_SIZE);

sdt:::kssl_mblk-*
{
  trace(timestamp);
  printf("\n");
  PRINT_MBLK(arg0)
}

This is actually an excerpt from my (currently internal) KSSL debugging suite.
An example of output from such probe can be seen in my Coloring dtrace output post.

For more complex projects it would be waste to stop here. Prefixes could be further structured. However, this has some drawbacks. In particular, I was thinking about having kssl_mblk- and kssl_err- prefixes. Now what to do for places where an error condition occurred _and_ we would like to see the associated mblk ? Using something like kssl_mblk_err-* comes to ones mind. However, there is a problem with that - what about the singleton cases (only mblk, only err). Sure, using multiple wildcards in dtrace is possible (e.g. syscall::*read*:) but this will make it ugly and complicated given the number of mblk+err cases (it's probably safe to assume that the number of such cases will be low). Simply, it's not worth the hassle. Rather, I went with 2 probes.
To conclude, using structured prefixes is highly beneficial only for set of probes where categories/sub-prefixes create non-intersecting sets (e.g. data type and debug level).

Of course, all of the above is not valid only for kernel but also for custom userland probes !

[1] High-level description of KSSL can be found in blueprint 819-5782.