Solaris 动态跟踪指南

第 13 章 推理跟踪

本章介绍用于推理跟踪的 DTrace 工具,它可用于试探性地跟踪数据,并在以后决定是将这些数据提交到跟踪缓冲区还是放弃这些数据。在 DTrace 中,过滤出非关注事件的主要机制是谓词机制(已在第 4 章中介绍)。如果在触发探测器时,要知道该探测事件是否是所关注的事件,此时谓词很有用。例如,如果您只关注与某个进程或某个文件描述符关联的活动,则在触发探测器时,您将知道该活动是否与所关注的进程或文件描述符关联。但是,在其他情况下,可能需要在触发探测器之后的某个时间,才可知道指定的探测事件是否是所关注的事件。

例如,如果系统调用偶尔失败,并生成常见的错误代码(例如,EIOEINVAL),则可能需要检查导致该错误的代码路径。要捕获代码路径,可以启用所有探测器-但只有以此方式隔离失败的调用,才可以构造有意义的谓词。如果故障具有偶发性或不确定性,则必须跟踪可能需要关注的所有事件,然后对数据进行后期处理以过滤出与失败的代码路径无关的数据。在此情况下,即使需要关注的事件数量可能相当少,但必须跟踪的事件数量还是会非常大,这将使得后期处理很困难。

在这些情况下,您可以使用推理跟踪工具在一个或多个探测位置试探性地跟踪数据,然后在另一个探测位置决定是否将这些数据提交到主体缓冲区。因此,跟踪数据将只包含所关注的输出,无需进行后期处理,从而 DTrace 开销也降至最低。

推理接口

下表说明了 DTrace 推理函数:

表 13–1 DTrace 推理函数

函数名 

参数 

说明 

speculation

无 

返回新推理缓冲区的标识符 

speculate

ID 

表示子句的其余部分应跟踪到由 ID 指定的推理缓冲区 

commit

ID 

提交与 ID 关联的推理缓冲区 

discard

ID 

放弃与 ID 关联的推理缓冲区 

创建推理

speculation() 函数分配推理缓冲区并返回推理标识符。在对 speculate() 函数的后续调用中应使用推理标识符。推理缓冲区是一种有限的资源:如果在调用 speculation() 时无推理缓冲区可用,则返回的 ID 为零,并将递增相应的 DTrace 错误计数器。值为零的 ID 始终无效,但可以传递到 speculate()commit()discard()。如果调用 speculation() 失败,则将生成与以下示例类似的 dtrace 消息:


dtrace: 2 failed speculations (no speculative buffer space available)

推理缓冲区的数量缺省值为 1,但是也可以调高。有关更多信息,请参见推理选项和调整

使用推理

要使用推理,必须在执行任何数据记录操作之前,将从 speculation() 返回的标识符传递到子句中的 speculate() 函数。包含 speculate() 的子句中所有后续数据记录操作将被推理跟踪。如果在 D 探测子句中对 speculate() 的调用紧跟在数据记录操作之后,D 编译器将会生成编译时错误。因此,子句可以包含推理跟踪请求或非推理跟踪请求,但不能同时包含二者。

不能对聚集操作、破坏性操作和 exit 操作进行推理跟踪。在包含 speculate() 的子句中采用这其中某个操作的任何尝试,都将导致编译时错误。一个 speculate() 不能跟在另一个 speculate() 之后:每条子句中只允许使用一个推理。包含一个 speculate() 的子句将推理性地跟踪缺省操作,该缺省操作被定义为仅跟踪已经启用的探测器 ID。有关缺省操作的说明,请参见第 10 章

通常,将 speculation() 的结果赋给线程局部变量,然后使用该变量作为其他探测器的后续谓词以及 speculate() 的参数。例如:

syscall::open:entry
{
	self->spec = speculation();
}

syscall:::
/self->spec/
{
	speculate(self->spec);
	printf("this is speculative");
}

提交推理

可使用 commit() 函数提交推理。提交推理缓冲区时,其中的数据将被复制到主体缓冲区。如果指定的推理缓冲区中包含的数据多于主体缓冲区中的可用空间,则不会复制该数据,并将递增缓冲区的删除计数。如果已推理跟踪多个 CPU 中的缓冲区,则会立即复制要提交的 CPU 中的推理数据,而其他 CPU 中的推理数据将在 commit() 之后的某个时间复制。因此,从 commit() 开始在一个 CPU 中运行到数据从推理缓冲区复制到所有 CPU 中的主体缓冲区之间可能会经历一段时间。此时间肯定不长于清除速率指定的时间。有关更多详细信息,请参见推理选项和调整

在将每个 CPU 的推理缓冲区完全复制到相应的每个 CPU 的主体缓冲区之前,后续 speculation() 调用将不能使用要提交的推理缓冲区。类似地,提交缓冲区对 speculate() 的后续调用将默认被放弃,对 commit()discard() 的后续调用将默认失败。最后,包含 commit() 的子句不能包含数据记录操作,但是子句可能包含多个 commit() 调用来提交不相交的缓冲区。

放弃推理

可使用 discard() 函数放弃推理。放弃推理缓冲区时,其中的内容将被丢弃。如果推理仅在调用 discard() 的 CPU 中处于活动状态,则后续对 speculation() 的调用将可以立即使用该缓冲区。如果推理在多个 CPU 中处于活动状态,则在调用 discard() 之后的某个时间,后续 speculation() 将可以使用放弃的缓冲区。在一个 CPU 中执行 discard() 之后到后续推理操作可以使用缓冲区之间的时间肯定不长于清除速率指定的时间。如果在调用 speculation() 时,因为所有推理缓冲区当前都正在被放弃或提交,而没有可用的缓冲区,将会生成与以下示例类似的 dtrace 消息:


dtrace: 905 failed speculations (available buffer(s) still busy)

可以通过调整推理缓冲区的数量或清除速率,来降低所有缓冲区都不可用的可能性。有关详细信息,请参见推理选项和调整

推理示例

推理的一个可能用法是突出显示特定的代码路径。只有当 open() 失败时,以下示例才在 open(2) 系统调用下显示整个代码路径:


示例 13–1 specopen.d:失败的 open(2) 代码流

#!/usr/sbin/dtrace -Fs

syscall::open:entry,
syscall::open64:entry
{
	/*
	 * The call to speculation() creates a new speculation.  If this fails,
	 * dtrace(1M) will generate an error message indicating the reason for
	 * the failed speculation(), but subsequent speculative tracing will be
	 * silently discarded.
	 */
	self->spec = speculation();
	speculate(self->spec);

	/*
	 * Because this printf() follows the speculate(), it is being 
	 * speculatively traced; it will only appear in the data buffer if the
	 * speculation is subsequently commited.
	 */
	printf("%s", stringof(copyinstr(arg0)));
}

fbt:::
/self->spec/
{
	/*
	 * A speculate() with no other actions speculates the default action:
	 * tracing the EPID.
	 */
	speculate(self->spec);
}

syscall::open:return,
syscall::open64:return
/self->spec/
{
	/*
	 * To balance the output with the -F option, we want to be sure that
	 * every entry has a matching return.  Because we speculated the
	 * open entry above, we want to also speculate the open return.
	 * This is also a convenient time to trace the errno value.
	 */
	speculate(self->spec);
	trace(errno);
}

syscall::open:return,
syscall::open64:return
/self->spec && errno != 0/
{
	/*
	 * If errno is non-zero, we want to commit the speculation.
	 */
	commit(self->spec);
	self->spec = 0;
}

syscall::open:return,
syscall::open64:return
/self->spec && errno == 0/
{
	/*
	 * If errno is not set, we discard the speculation.
	 */
	discard(self->spec);
	self->spec = 0;
}

运行上面的脚本将会生成与以下示例类似的输出:


# ./specopen.d
dtrace: script './specopen.d' matched 24282 probes
CPU FUNCTION                                 
  1  => open                                  /var/ld/ld.config
  1    -> open                                
  1      -> copen                             
  1        -> falloc                          
  1          -> ufalloc                       
  1            -> fd_find                     
  1              -> mutex_owned               
  1              <- mutex_owned               
  1            <- fd_find                     
  1            -> fd_reserve                  
  1              -> mutex_owned               
  1              <- mutex_owned               
  1              -> mutex_owned               
  1              <- mutex_owned               
  1            <- fd_reserve                  
  1          <- ufalloc                       
  1          -> kmem_cache_alloc              
  1            -> kmem_cache_alloc_debug      
  1              -> verify_and_copy_pattern   
  1              <- verify_and_copy_pattern   
  1              -> file_cache_constructor    
  1                -> mutex_init              
  1                <- mutex_init              
  1              <- file_cache_constructor    
  1              -> tsc_gethrtime             
  1              <- tsc_gethrtime             
  1              -> getpcstack                
  1              <- getpcstack                
  1              -> kmem_log_enter            
  1              <- kmem_log_enter            
  1            <- kmem_cache_alloc_debug      
  1          <- kmem_cache_alloc              
  1          -> crhold                        
  1          <- crhold                        
  1        <- falloc                          
  1        -> vn_openat                       
  1          -> lookupnameat                  
  1            -> copyinstr                   
  1            <- copyinstr                   
  1            -> lookuppnat                  
  1              -> lookuppnvp                
  1                -> pn_fixslash             
  1                <- pn_fixslash             
  1                -> pn_getcomponent         
  1                <- pn_getcomponent         
  1                -> ufs_lookup              
  1                  -> dnlc_lookup           
  1                    -> bcmp                
  1                    <- bcmp                
  1                  <- dnlc_lookup           
  1                  -> ufs_iaccess           
  1                    -> crgetuid            
  1                    <- crgetuid            
  1                    -> groupmember         
  1                      -> supgroupmember    
  1                      <- supgroupmember
  1                    <- groupmember         
  1                  <- ufs_iaccess           
  1                <- ufs_lookup              
  1                -> vn_rele                 
  1                <- vn_rele                 
  1                -> pn_getcomponent         
  1                <- pn_getcomponent         
  1                -> ufs_lookup              
  1                  -> dnlc_lookup           
  1                    -> bcmp                
  1                    <- bcmp                
  1                  <- dnlc_lookup           
  1                  -> ufs_iaccess           
  1                    -> crgetuid            
  1                    <- crgetuid            
  1                  <- ufs_iaccess           
  1                <- ufs_lookup              
  1                -> vn_rele                 
  1                <- vn_rele                 
  1                -> pn_getcomponent         
  1                <- pn_getcomponent         
  1                -> ufs_lookup              
  1                  -> dnlc_lookup           
  1                    -> bcmp                
  1                    <- bcmp                
  1                  <- dnlc_lookup           
  1                  -> ufs_iaccess           
  1                    -> crgetuid            
  1                    <- crgetuid            
  1                  <- ufs_iaccess           
  1                  -> vn_rele               
  1                  <- vn_rele               
  1                <- ufs_lookup              
  1                -> vn_rele                 
  1                <- vn_rele                 
  1              <- lookuppnvp                
  1            <- lookuppnat                  
  1          <- lookupnameat                  
  1        <- vn_openat                       
  1        -> setf                            
  1          -> fd_reserve                    
  1            -> mutex_owned                 
  1            <- mutex_owned                 
  1            -> mutex_owned                 
  1            <- mutex_owned                 
  1          <- fd_reserve                    
  1          -> cv_broadcast                  
  1          <- cv_broadcast                  
  1        <- setf                            
  1        -> unfalloc                        
  1          -> mutex_owned                   
  1          <- mutex_owned                   
  1          -> crfree                        
  1          <- crfree                        
  1          -> kmem_cache_free               
  1            -> kmem_cache_free_debug       
  1              -> kmem_log_enter            
  1              <- kmem_log_enter            
  1              -> tsc_gethrtime             
  1              <- tsc_gethrtime             
  1              -> getpcstack                
  1              <- getpcstack                
  1              -> kmem_log_enter            
  1              <- kmem_log_enter
  1              -> file_cache_destructor     
  1                -> mutex_destroy           
  1                <- mutex_destroy           
  1              <- file_cache_destructor     
  1              -> copy_pattern              
  1              <- copy_pattern              
  1            <- kmem_cache_free_debug       
  1          <- kmem_cache_free               
  1        <- unfalloc                        
  1        -> set_errno                       
  1        <- set_errno                       
  1      <- copen                             
  1    <- open                                
  1  <= open                                          2

推理选项和调整

如果在尝试推理跟踪操作时推理缓冲区已满,则不会在缓冲区中存储任何数据,并将递增删除计数。在此情况下,将会生成与以下示例类似的 dtrace 消息:


dtrace: 38 speculative drops

在提交缓冲区后,推理删除不会阻止将整个推理缓冲区复制到主体缓冲区。类似地,即使在最终放弃的推理缓冲区中执行过删除,也可能会发生推理删除。通过增加推理缓冲区大小(使用 specsize 选项调整),可减少推理删除。可以使用任何大小后缀指定 specsize 选项。此缓冲区的调整大小策略由 bufresize 选项指示。

调用 speculation() 时,推理缓冲区可能不可用。如果存在尚未提交或放弃的缓冲区,则会生成与以下示例类似的 dtrace 消息:


dtrace: 1 failed speculation (no speculative buffer available)

通过使用 nspec 选项增加推理缓冲区的数量,可以降低此特性的推理失败的可能性。nspec 的缺省值为 1。

此外,speculation() 可能会因为所有推理缓冲区正忙而失败。在此情况下,将会生成与以下示例类似的 dtrace 消息:


dtrace: 1 failed speculation (available buffer(s) still busy)

此消息说明,在对推理缓冲区调用 commit() 之后,但在所有 CPU 中实际提交该缓冲区之前,调用了 speculation()。通过使用 cleanrate 选项增加清除 CPU 的速率,可以降低此特性的推理操作失败的可能性。cleanrate 的缺省值为 101hz


注 –

必须以每秒次数为单位指定 cleanrate 选项的值。请使用 hz 后缀。