Օրական պահոցներ՝ 25 Հուլիսի, 2020

Ասք DTrace-ով ծրագրերի հոսքը հետեւլու մասին

Մի շաբաթ առաջ գրառեցի թէ ինչպէս DTrace-ով վօկին հետեւել, այսօր ուզում եմ խօսել թէ ինչպէս հետեւլ ծրագրերին առհասարակ։

Վերցնենք էս օրինակը Սի-ով՝

#include <unistd.h>
#include <stdlib.h>

void a();
void b();

void a() {
  sleep(1);
};

void b() {
  sleep(1);
};

int main() {
  while (1) {
    a();
    b();
  };
  exit(0);
}

Հիմա փորձենք հետեւլ DTrace-ով՝

root@illuria-dev:~/voc-dtrace # dtrace -F -n 'pid$target:prog0::entry,pid$target:prog0::return{} tick-5s{exit(0)}' -c ./prog0
dtrace: description 'pid$target:prog0::entry,pid$target:prog0::return' matched 17 probes
CPU FUNCTION
  0  -> _start
  0    -> handle_static_init
  0    <- handle_static_init
  0    -> main
  0      -> a
  0      <- a
  0      -> b
  0      <- b
  0      -> a
  1      <- a
  1      -> b
  1      <- b
  1      -> a
  0       | :tick-5s

Ահա փաստօրէն կարողանում ենք նաեւ տեսնել թէ ֆունկցիան երբ ա մտնում ու երբ ա դուրս գալիս։

Մի փոքր բացատրեմ, ունենք provider, module, function, probe, նշել եմ որ ուզում եմ օգտագործել pid provider-ը, որը հետեւում է userland-ում կատարուող գործերին, մոդուլը դրել եմ ծրագրի անունը՝ prog0, ֆունկցիան էական չի, իսկ probe-ը նշել եմ եւ entry (մուտք) եւ return (էլք)։ Նաեւ նշել եմ, որ 5 վայրկեան յետոյ դուրս գայ։

Օկ հրաշալի, հիմա փորձենք օբերոնով գրած ծրագիր՝

MODULE prog1;

IMPORT Platform;

PROCEDURE A();
BEGIN
  Platform.Delay(1000)
END A;

PROCEDURE B();
BEGIN
  Platform.Delay(1000)
END B;

BEGIN
  WHILE TRUE
  DO
    A();
    B();
  END
END prog1.

Հիմա փորձենք հետեւել DTrace-ով՝

root@illuria-dev:~/voc-dtrace # dtrace -F -n 'pid$target:prog1::entry,pid$target:prog1::return{} tick-5s{exit(0)}' -c ./prog1
dtrace: description 'pid$target:prog1::entry,pid$target:prog1::return' matched 17 probes
CPU FUNCTION
  1  -> _start
  1    -> handle_static_init
  1    <- handle_static_init
  1    -> main
  1      -> prog1_A
  1      <- prog1_A
  1      -> prog1_B
  1      <- prog1_B
  1      -> prog1_A
  1      <- prog1_A
  1      -> prog1_B
  1      <- prog1_B
  1      -> prog1_A
  0       | :tick-5s

Ահ, մի բան էն չի։ հմմ։ երեւի վօկի գեներացրած կոդից ա՝

/* voc 2.1.0 [2020/07/14] for clang LP64 on freebsd xtpam */

#define SHORTINT INT8
#define INTEGER  INT16
#define LONGINT  INT32
#define SET      UINT32

#include "SYSTEM.h"
#include "Platform.h"

static void prog1_A (void);
static void prog1_B (void);

static void prog1_A (void)
{
  Platform_Delay(1000);
}

static void prog1_B (void)
{
  Platform_Delay(1000);
}

export int main(int argc, char **argv)
{
  __INIT(argc, argv);
  __MODULE_IMPORT(Platform);
  __REGMAIN("prog1", 0);
/* BEGIN */
  while (1) {
    prog1_A();
    prog1_B();
  }
  __FINI;
}

Հա, փաստօրէն վօկի գեներացրած կոդից ա։

Լաւ, ենթադրենք սա իրական ծրագիր ա, ու ուզում ենք իմանալ ուր ա bottleneck-ը, պէտք է հասկանալ ամենաերկարը որտեղ ա ծրագրին երկար տեւում։

pid$target:prog1::entry
{
        self->ts = timestamp;
}

pid$target:prog1::return
/self->ts/
{
        @time[probefunc] = sum(timestamp - self->ts);
        self->ts = 0;
}

tick-5s
{
        exit(0)
}

Էս դէպքում ֆունկցիայի մէջ մտնելու ժամանակ ասում եմ որ ts փոփոխականի մէջ նշի timestamp-ը, ու ելքի ժամանակ ստուգել եթէ ts փոփոխականը յայտարարուած ա։

@time[probefunc] = sum(timestamp - self->ts); տողի վրայ ագրիգացիա է կատարւում գումարելով (sum) թէ ինչքան ժամանակ է տեւել մտնելուց մինչեւ դուրս գալը (timestamp - self->ts) ու պահում time փոփոխականի մէջ։

5 վայրկեան յետոյ դուրս է գալիս ։)

ահա՝

root@illuria-dev:~/voc-dtrace # dtrace -s prog1.d -c ./prog1
dtrace: script 'prog1.d' matched 17 probes
CPU     ID                    FUNCTION:NAME
  0  72544                         :tick-5s

  handle_static_init                                             5137
  prog1_A                                                  2057419770
  prog1_B                                                  2063438603

էսօրուայ համար էսքանը։

ասանկ բաներ։

Պատասխանել մեյլով