[Dtrace SMB-related snippets] All things SMB #tags: smb, dtrace, io

idmap-sid-lookup.d

#!/usr/sbin/dtrace -qCs
#include <sys/idmap.h>

BEGIN {
  m[IDMAP_SUCCESS] = "found, OK" ;
  m[IDMAP_ERR_NOTFOUND] = "not found" ;

}
::smb_idmap_getsid:entry { this->uid = args[0] ; }
::smb_idmap_getsid:return { 
  printf("uid: %d result: %s\n", 
          this->uid, m[args[1]]) ; 
}

smb-is-read_control-set.d

dtrace -qn '
  ::smb_access_generic_to_file:entry {
    this->entry = args[0];
  }
  ::smb_access_generic_to_file:return {
    @[this->entry, args[1], args[1] == (args[1]|0x00020000L) ? "Y" : "N"] = count();
  }
  tick-5sec {
    printa("StartV: 0x%x, EndV: 0x%x READ_CONTROL: %s Count: %@d\n", @);
    trunc(@);
  }'

smb-ofiles-count.d

dtrace -qn '
  BEGIN {
    ts = walltimestamp;
    printf("timestamp,address,mean,max\n");
  }
  ::smb_open_subr:entry /ts/ {
    @fopenmax[ts, args[0]->session->ip_addr_str] =
     max(args[0]->session->s_file_cnt);
    @fopenav[ts, args[0]->session->ip_addr_str]  =
     avg(args[0]->session->s_file_cnt);
  }
  tick-60sec {
    printa("%Y,%s,%@d,%@d\n", @fopenav, @fopenmax);
    trunc(@fopenav); trunc(@fopenmax);
    ts = walltimestamp;
  }'

smb-oplock-acquire-time.d

dtrace -qn '
  BEGIN {
  ts = walltimestamp;
  /* print header for CSV */
  printf("timestamp,filename,avg.duration.ns,total.duration.ns\n");
  }
  ::smb_oplock_acquire:entry {
    this->start = timestamp;
    this->fname = stringof(args[2]->f_node->od_name);
  }
  ::smb_oplock_acquire:return {
    @[ts, this->fname] = sum(timestamp - this->start);
    /* average amount of time per op-lock acquisition */
    @av_dur[ts, this->fname] = avg(timestamp - this->start);
  }
  tick-5sec {
    printa("%Y,%s,%@d,%@d\n", @, @av_dur); 
    trunc(@); trunc(@av_dur);
    ts = walltimestamp;
  }'

smb-read-write-lat-by-path.d

dtrace -qn '
  char m[string];
  BEGIN {
    m["smb_fsop_read"] = 0x52;
    m["smb_fsop_write"] = 0x57;
  }
  ::smb_fsop_read:entry,::smb_fsop_write:entry {
    self->arg0 = args[0];
    self->node = args[2];
    self->t = timestamp;
    
    /* printf("%s\n", inet_ntop(this->a_family, this->addr));
    printf("%s\n", inet_ntop(this->l_a_family, this->l_addr)); */
}

::smb_fsop_read:return,::smb_fsop_write:return /self->arg0/ {
  this->delta = timestamp - self->t;
  this->a_family = self->arg0->session->ipaddr.a_family;
  this->l_a_family = self->arg0->session->local_ipaddr.a_family;
  this->addr = &self->arg0->session->ipaddr.au_addr.au_ipv4;
  this->l_addr = &self->arg0->session->local_ipaddr.au_addr.au_ipv4;
    @[m[probefunc], stringof(self->node->vp->v_path),
    inet_ntop(this->a_family, this->addr),
    inet_ntop(this->l_a_family, this->l_addr)] = quantize(this->delta);
  self->arg0 = 0; self->t = 0; self->node = 0;
}

END {
  printa("\t   (%c) %s\n\t   src: %s dst: %s%@d\n", @);
}'

smb-vop_lookup-access.d

dtrace -qn '
  /* 
   * See /usr/src/uts/common/sys/errno.h for all error codes. 
   */
  ::smb_vop_lookup:entry /args[0]->v_path != NULL/ {
    self->path  = (stringof(*(struct vnode *)args[0]).v_path);
    self->user  = args[8]->cr_uid;
    self->group = args[8]->cr_uid;
}
  ::smb_vop_lookup:return /self->path != NULL/ {
  this->err = args[1]; /* non-zero here implies a problem */
  @[self->path, self->user, self->group, this->err] = count();
}
END {
  printa("Path: %s uid: %d gid: %d retcode: %d Count: %@d\n", @);
}'

smb-write-offsets.d

// Measure Offsets of IOs issued, by file. We can observe with this snippet
// how IOs are issued, in terms of whether offsets are pretty constant or
// there is a healthy mix of different sizes. In general, differently sized
// offsets is a pretty solid indicator that IO is mostly random.
// This is an example of what we might see. In this instance all offsets are
// 1MB in size.
//   /storage/p01/global/smb/00/CentOS-6.8-x86_64-LiveDVD.iso
//            value  ------------- Distribution ------------- count
//           524288 |                                         0
//          1048576 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 391
//          2097152 |
dtrace -qn '
self offset_t prev[smb_node_t *];
::smb_fsop_write:entry /!self->prev[args[2]]/ {
self->prev[args[2]] = args[3]->_uio_offset._f;
}
::smb_fsop_write:entry
/self->prev[args[2]] != args[3]->_uio_offset._f/ {
    this->o = args[3]->_uio_offset._f;
    this->diff = this->o > self->prev[args[2]] ?
                this->o - self->prev[args[2]] :
                self->prev[args[2]] - this->o;
    @[stringof(args[2]->vp->v_path)] = quantize(this->diff);
    self->prev[args[2]] = 0;
}'

smb.d

# Trace smb2 write events
dtrace -qn 'fbt:smbsrv:smb2_write:entry {
    @[stringof(args[0]->uid_user->u_name),
    (uint16_t)args[0]->uid_user->u_uid,
    args[0]->smb_error.status,
    (uint16_t)args[0]->smb_error.errcode,
    stringof(args[0]->tid_tree->t_sharename), 
    stringof(args[0]->tid_tree->t_volume), 
    stringof(args[0]->tid_tree->t_resource),
    stringof(args[0]->tid_tree->t_snode->vp->v_path)
    ]= count(); }'
    
# Trace mkdir and rename operations with vnode info and name of file or dir being changed
dtrace -qn 'fbt:smbsrv:smb_vop_mkdir:entry,
    fbt:smbsrv:smb_vop_rename:entry {
    @[probefunc, stringof(args[1]), stringof(args[0]->v_path)] = count(); }
    tick-1sec {printa(@); trunc(@);}'

smb_vop_lookup_access.d

dtrace -qn '
  ::smb_vop_lookup:entry {
    self->x = 1}
  ::zfs_zaccess:entry /self->x/ {
    self->y = 1;
    self->x = 0;
    self->flags = args[0]->z_pflags;
    self->mode = args[1];
  }
  ::vn_rele:entry /self->y/ {
    @r[stringof(args[0]->v_path), self->flags, self->mode] = count();
    self->rc = 0;
    self->y = 0;
    self->flags = 0;
    self->mode = 0;
  }
  END {printa("%s flags: 0x%x mode: 0x%x\n", @r);}'