Manuel de suivi dynamique Solaris

enqueue et dequeue

Lorsqu'une CPU passe au repos, le dispatcheur recherche des tâches mises en file d'attente sur d'autres CPU (pas au repos). L'exemple suivant utilise la sonde dequeue pour connaître la fréquence de transfert des applications et par quelle CPU :

#pragma D option quiet

sched:::dequeue
/args[2]->cpu_id != --1 && cpu != args[2]->cpu_id &&
    (curlwpsinfo->pr_flag & PR_IDLE)/
{
	@[stringof(args[1]->pr_fname), args[2]->cpu_id] =
	    lquantize(cpu, 0, 100);
}

END
{
	printa("%s stolen from CPU %d by:\n%@d\n", @);
}

La fin de la sortie de l'exécution du script ci-dessus sur un système à 4 CPU donne une sortie similaire à l'exemple suivant :


# dtrace -s ./whosteal.d
^C
...
 nscd stolen from CPU 1 by:

           value  -------------- Distribution ------------ count    
               1 |                                         0        
               2 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 28       
               3 |                                         0        

snmpd stolen from CPU 1 by:

           value  -------------- Distribution ------------ count    
             < 0 |                                         0        
               0 |@                                        1        
               1 |                                         0        
               2 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@     31       
               3 |@@                                       2        
               4 |                                         0        

sched stolen from CPU 1 by:

           value  -------------- Distribution ------------ count    
             < 0 |                                         0        
               0 |@@                                       3        
               1 |                                         0        
               2 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@         36       
               3 |@@@@                                     5        
               4 |                                         0

Plutôt que de connaître les CPU actives, vous pouvez souhaiter connaître les CPU sur lesquelles des processus et des threads sont en attente d'exécution. Vous pouvez utiliser les sondes enqueue et dequeue ensemble pour répondre à cette question :

sched:::enqueue
{
	self->ts = timestamp;
}

sched:::dequeue
/self->ts/
{
	@[args[2]->cpu_id] = quantize(timestamp - self->ts);
	self->ts = 0;
}

L'exécution du script ci-dessus pendant plusieurs secondes donne une sortie similaire à l'exemple suivant :


# dtrace -s ./qtime.d
dtrace: script './qtime.d' matched 5 probes
^C
       -1
           value  -------------- Distribution ------------ count    
            4096 |                                         0        
            8192 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 2        
           16384 |                                         0        

        0
           value  -------------- Distribution ------------ count    
            1024 |                                         0        
            2048 |@@@@@@@@@@@@@@@                          262      
            4096 |@@@@@@@@@@@@@                            227      
            8192 |@@@@@                                    87       
           16384 |@@@                                      54       
           32768 |                                         7        
           65536 |                                         9        
          131072 |                                         1        
          262144 |                                         5        
          524288 |                                         4        
         1048576 |                                         2        
         2097152 |                                         0        
         4194304 |                                         0        
         8388608 |                                         0        
        16777216 |                                         1        
        33554432 |                                         2        
        67108864 |                                         2        
       134217728 |                                         0        
       268435456 |                                         0        
       536870912 |                                         0        
      1073741824 |                                         1        
      2147483648 |                                         1        
      4294967296 |                                         0        

        1
           value  -------------- Distribution ------------ count    
            1024 |                                         0        
            2048 |@@@@                                     49       
            4096 |@@@@@@@@@@@@@@@@@@@@                     241      
            8192 |@@@@@@@                                  91       
           16384 |@@@@                                     55       
           32768 |                                         7        
           65536 |                                         3        
          131072 |                                         2        
          262144 |                                         1        
          524288 |                                         0        
         1048576 |                                         0        
         2097152 |                                         0        
         4194304 |                                         0        
         8388608 |                                         0        
        16777216 |                                         0        
        33554432 |                                         3        
        67108864 |                                         1        
       134217728 |                                         4        
       268435456 |                                         2        
       536870912 |                                         0        
      1073741824 |                                         3        
      2147483648 |                                         2        
      4294967296 |                                         0

Notez les valeurs différentes de zéro au bas de la sortie. Ces points de données représentent plusieurs instances sur les CPU où un thread a été placé en file d'attente d'exécution pendant plusieurs secondes.

Plutôt que de rechercher les délais d'attente, vous pouvez souhaiter observer la longueur de la file d'attente dans le temps. Grâce aux sondes enqueue et dequeue, vous pouvez définir un ensemble associatif pour suivre la longueur de la file d'attente :

sched:::enqueue
{
	this->len = qlen[args[2]->cpu_id]++;
	@[args[2]->cpu_id] = lquantize(this->len, 0, 100);
}

sched:::dequeue
/qlen[args[2]->cpu_id]/
{
	qlen[args[2]->cpu_id]—;
}

L'exécution du script ci-dessus pendant 30 secondes environ sur un système portable à un processeur au repos donne une sortie similaire à l'exemple suivant :


# dtrace -s ./qlen.d
dtrace: script './qlen.d' matched 5 probes
^C
        0
           value  -------------- Distribution ------------ count    
             < 0 |                                         0        
               0 |@@@@@@@@@@@@@@@@@@@@@@@@@                110626   
               1 |@@@@@@@@@                                41142    
               2 |@@                                       12655    
               3 |@                                        5074     
               4 |                                         1722     
               5 |                                         701      
               6 |                                         302      
               7 |                                         63       
               8 |                                         23       
               9 |                                         12       
              10 |                                         24       
              11 |                                         58       
              12 |                                         14       
              13 |                                         3        
              14 |                                         0

La sortie est grossièrement ce que vous auriez pu attendre d'un système au repos : le thread exécutable est placé en file d'attente quasiment tout le temps et la file d'attente d'exécution est très courte (trois threads maximum). Cependant, étant donné que le système était au repos, les points de données exceptionnels au bas du tableau peuvent être inattendus. Par exemple, pourquoi la file d'attente comportait-elle 13 threads exécutables ? Pour répondre à cette question, vous pourriez rédiger un script D affichant le contenu de la file d'attente lorsque celle-ci est longue. Ce problème est complexe car les activations D ne peuvent pas être itérées sur des structures de données, et donc pas sur l'ensemble de la file d'attente. Même si des activations D le pouvaient, vous devez éviter toute dépendance aux structures de données internes du noyau.

Pour ce type de script, vous devriez activer les sondes enqueue et dequeue et utiliser des spéculations et des ensembles associatifs. Lorsqu'un thread est placé en file d'attente, le script incrémente la longueur de la file d'attente et enregistre l'horodatage dans un ensemble associatif affecté au thread. Vous ne pouvez pas utiliser une variable locale de thread dans ce cas car un thread peut être placé en file d'attente par un autre thread. Le script vérifie alors si la longueur de la file d'attente est supérieure à la valeur maximale. Si c'est le cas, le script entame une nouvelle spéculation, et enregistre l'horodatage et la nouvelle valeur maximale. Ensuite, lorsqu'un thread est retiré de la file d'attente, le script compare l'horotadage de mise en file d'attente avec celui de la longueur la plus importante : si le thread a été placé en file d'attente avant l'horodatage de la longueur la plus importante, le thread se trouvait en file d'attente au moment de l'enregistrement de la longueur la plus importante. Dans ce cas, le script suit de manière spéculative les informations du thread. Lorsque le noyau retire de la file d'attente le dernier thread placé au niveau de l'horodatage de la longueur la plus importante, le script fournit les données de spéculation. Ce script est illustré ci-dessous :

#pragma D option quiet
#pragma D option nspec=4
#pragma D option specsize=100k

int maxlen;
int spec[int];

sched:::enqueue
{
	this->len = ++qlen[this->cpu = args[2]->cpu_id];
	in[args[0]->pr_addr] = timestamp;
}

sched:::enqueue
/this->len > maxlen && spec[this->cpu]/
{
	/*
	 * There is already a speculation for this CPU.  We just set a new
	 * record, so we'll discard the old one.
	 */
	discard(spec[this->cpu]);
}

sched:::enqueue
/this->len > maxlen/
{
	/*
	 * We have a winner.  Set the new maximum length and set the timestamp
	 * of the longest length.
	 */
	maxlen = this->len;
	longtime[this->cpu] = timestamp;	

	/*
	 * Now start a new speculation, and speculatively trace the length.
	 */
	this->spec = spec[this->cpu] = speculation();
	speculate(this->spec);
	printf("Run queue of length %d:\n", this->len);
}

sched:::dequeue
/(this->in = in[args[0]->pr_addr]) &&
    this->in <= longtime[this->cpu = args[2]->cpu_id]/
{
	speculate(spec[this->cpu]);
	printf("  %d/%d (%s)\n", 
	    args[1]->pr_pid, args[0]->pr_lwpid,
	    stringof(args[1]->pr_fname));
}

sched:::dequeue
/qlen[args[2]->cpu_id]/
{
	in[args[0]->pr_addr] = 0;
	this->len = --qlen[args[2]->cpu_id];
}

sched:::dequeue
/this->len == 0 && spec[this->cpu]/
{
	/*
	 * We just processed the last thread that was enqueued at the time
	 * of longest length; commit the speculation, which by now contains
	 * each thread that was enqueued when the queue was longest.
	 */
	commit(spec[this->cpu]);
	spec[this->cpu] = 0;
}

L'exécution du script ci-dessus sur le même système portable à un processeur donne une sortie similaire à l'exemple suivant :


# dtrace -s ./whoqueue.d
Run queue of length 3:
 0/0 (sched)
  0/0 (sched)
  101170/1 (dtrace)
Run queue of length 4:
  0/0 (sched)
  100356/1 (Xsun)
  100420/1 (xterm)
  101170/1 (dtrace)
Run queue of length 5:
  0/0 (sched)
  0/0 (sched)
  100356/1 (Xsun)
  100420/1 (xterm)
  101170/1 (dtrace)
Run queue of length 7:
  0/0 (sched)
  100221/18 (nscd)
  100221/17 (nscd)
  100221/16 (nscd)
  100221/13 (nscd)
  100221/14 (nscd)
  100221/15 (nscd)
Run queue of length 16:
  100821/1 (xterm)
  100768/1 (xterm)
  100365/1 (fvwm2)
  101118/1 (xterm)
  100577/1 (xterm)
  101170/1 (dtrace)
  101020/1 (xterm)
  101089/1 (xterm)
  100795/1 (xterm)
  100741/1 (xterm)
  100710/1 (xterm)
  101048/1 (xterm)
  100697/1 (MozillaFirebird-)
  100420/1 (xterm)
  100394/1 (xterm)
  100368/1 (xterm)
^C

La sortie indique que les longues files d'attente d'exécution sont dues à de nombreux processus xterm exécutables. Cette expérimentation coïncide avec un changement de bureau virtuel et les résultats sont donc probablement dus à une sorte de traitement d'événement X.