From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: X-Spam-Checker-Version: SpamAssassin 3.4.0 (2014-02-07) on aws-us-west-2-korg-lkml-1.web.codeaurora.org Received: from lists.lttng.org (lists.lttng.org [167.114.26.123]) (using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)) (No client certificate requested) by smtp.lore.kernel.org (Postfix) with ESMTPS id 248F6EB64DB for ; Tue, 20 Jun 2023 10:27:24 +0000 (UTC) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/simple; d=lists.lttng.org; s=default; t=1687256843; bh=05b3joueBY2thvZgshYp3qzHJ5jSvNObySgRjkVC05g=; h=To:Date:Subject:List-Id:List-Unsubscribe:List-Archive:List-Post: List-Help:List-Subscribe:From:Reply-To:From; b=mZ+0kqGIkanAPLI+m5pggCNrFnPQiendplj1FBInPhaA2TvhgMy787qSGLxUrC5jO g1CMy11uPme3vku+PHsoJRbzZEMyZMWhwGmS9eC5KtPw/ld/riRAAETaU4oDtcS2bV zJ6c0G+uBKAWFF7YxDRsZiJt43I1T+FkCOVovwZL/U0moBusKvPg/0Vh/iStL+81gO B65ZUx1ST7+qIEhE5A1EA3lSh3ZnqQGCq84wJdSdFzflnQe9UfDA+gm6b4PTMijCi9 QvT6a8Pj6qtrMyAm+4HDd7aezoloN2y9v3CfSnax94qFsr91V2bp9Zbg/PYURWL+UV jvdfmYMQI/Gxw== Received: from lists-lttng01.efficios.com (localhost [IPv6:::1]) by lists.lttng.org (Postfix) with ESMTP id 4QljVy3tbhz1y1V; Tue, 20 Jun 2023 06:27:22 -0400 (EDT) Received: from smtp-fw-9103.amazon.com (smtp-fw-9103.amazon.com [207.171.188.200]) by lists.lttng.org (Postfix) with ESMTPS id 4QljVw59zjz1yKP for ; Tue, 20 Jun 2023 06:27:20 -0400 (EDT) X-IronPort-AV: E=Sophos;i="6.00,256,1681171200"; d="scan'208,217";a="1138494247" Received: from pdx4-co-svc-p1-lb2-vlan3.amazon.com (HELO email-inbound-relay-pdx-2a-m6i4x-8a14c045.us-west-2.amazon.com) ([10.25.36.214]) by smtp-border-fw-9103.sea19.amazon.com with ESMTP/TLS/ECDHE-RSA-AES256-GCM-SHA384; 20 Jun 2023 10:27:11 +0000 Received: from EX19D008EUC001.ant.amazon.com (pdx1-ws-svc-p6-lb9-vlan2.pdx.amazon.com [10.236.137.194]) by email-inbound-relay-pdx-2a-m6i4x-8a14c045.us-west-2.amazon.com (Postfix) with ESMTPS id B089D80456 for ; Tue, 20 Jun 2023 10:27:10 +0000 (UTC) Received: from EX19D008EUC001.ant.amazon.com (10.252.51.165) by EX19D008EUC001.ant.amazon.com (10.252.51.165) with Microsoft SMTP Server (version=TLS1_2, cipher=TLS_ECDHE_RSA_WITH_AES_128_CBC_SHA) id 15.2.1118.26; Tue, 20 Jun 2023 10:27:09 +0000 Received: from EX19D008EUC001.ant.amazon.com ([fe80::9611:c62b:a7ba:aee1]) by EX19D008EUC001.ant.amazon.com ([fe80::9611:c62b:a7ba:aee1%3]) with mapi id 15.02.1118.026; Tue, 20 Jun 2023 10:27:09 +0000 To: "lttng-dev@lists.lttng.org" Thread-Topic: Profiling LTTng tracepoint latency on different arm platforms Thread-Index: AQHZo2HEplRT2zY9N0ijivZSO5DOOA== Date: Tue, 20 Jun 2023 10:27:09 +0000 Message-ID: <6e06b605ec9f446da5dc8948c8621518@amazon.com> Accept-Language: en-US Content-Language: en-US X-MS-Has-Attach: X-MS-TNEF-Correlator: x-originating-ip: [10.85.143.172] MIME-Version: 1.0 Subject: [lttng-dev] Profiling LTTng tracepoint latency on different arm platforms X-BeenThere: lttng-dev@lists.lttng.org X-Mailman-Version: 2.1.39 Precedence: list List-Id: LTTng development list List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , From: "Mousa, Anas via lttng-dev" Reply-To: "Mousa, Anas" Content-Type: multipart/mixed; boundary="===============6493914625085299052==" Errors-To: lttng-dev-bounces@lists.lttng.org Sender: "lttng-dev" --===============6493914625085299052== Content-Language: en-US Content-Type: multipart/alternative; boundary="_000_6e06b605ec9f446da5dc8948c8621518amazoncom_" --_000_6e06b605ec9f446da5dc8948c8621518amazoncom_ Content-Type: text/plain; charset="iso-8859-1" Content-Transfer-Encoding: quoted-printable Hello, I've recently profiled the latency of LTTng tracepoints on arm platforms, using the follow sample program: ---------------------------------------------------------------------------= ---------------------------------------------------------------------------= ---------------------------- static inline uint64_t get_time_nsec(void) { struct timespec ts; if (caa_unlikely(clock_gettime(CLOCK_MONOTONIC, &ts))) { ts.tv_sec =3D 0; ts.tv_nsec =3D 0; } return ((uint64_t) ts.tv_sec * 1000000000ULL) + ts.tv_nsec; } int main(int argc, char *argv[]) { unsigned int i; int tp_num =3D 0; uint64_t total_time =3D 0; uint64_t now, nowz; if (argc > 1) { sscanf (argv[1],"%d",&tp_num); } for (i =3D 0; i < tp_num; i++) { now =3D get_time_nsec(); lttng_ust_tracepoint(hello_world, my_first_tracepoint, i, "some_str"); nowz =3D get_time_nsec(); total_time +=3D (nowz - now); } if (tp_num) { printf("---------------------------Average TP time is %"PRIu64"----= -----------------------\n", total_time / tp_num); } } ---------------------------------------------------------------------------= ---------------------------------------------------------------------------= ---------------------------- I observed a big average latency variance on different platforms when traci= ng a high number (many thousands to millions) of tracepoints: * [platform 1] with CPU info running a linux kernel based on Buildroot = (4.19.273 aarch64 GNU/Linux): BogoMIPS : 187.50 Features : fp asimd evtstrm aes pmull sha1 sha2 crc32 cpuid CPU implementer : 0x41 CPU architecture: 8 CPU variant : 0x0 CPU part : 0xd08 CPU revision : 3 * Saw an average latency of 2-3usec * [platform 2] with CPU info running a linux kernel based on Amazon Lin= ux (4.14.294-220.533.amzn2.aarch64 aarch64 GNU/Linux): BogoMIPS : 243.75 Features : fp asimd evtstrm aes pmull sha1 sha2 crc32 atomics fphp a= simdhp cpuid asimdrdm lrcpc dcpop asimddp ssbs CPU implementer : 0x41 CPU architecture: 8 CPU variant : 0x3 CPU part : 0xd0c CPU revision : 1 * Saw an average latency of ~0.5usec Are there any suggestions to root cause the high latency and potentially im= prove it on platform 1? Thanks and best regards, Anas. --_000_6e06b605ec9f446da5dc8948c8621518amazoncom_ Content-Type: text/html; charset="iso-8859-1" Content-Transfer-Encoding: quoted-printable 

Hello,
 
I've recently profiled the latency of LTTng tracepoints on arm pla=
tforms,
using the follow sample program:
 
--------=
---------------------------------------------------------------------------=
---------------------------------------------------------------------------=
--------------------
static =
inline uint64_t=
 get_time_nsec(void)
{
        struct timespec=
 ts;
 
        if (caa_unlikely=
(clock_gettime(CLOCK_MONOTONIC, &ts))) {
                <=
span style=3D"font-size: 12pt;">ts.tv_sec=
 =
=3D =
0;

                <=
span style=3D"font-size: 12pt;">ts.tv_nsec=
 =3D =
0;

        }
        return ((uint64_t) ts.=
tv_sec *=
 =
1000000000ULL) + ts.tv_nsec=
;
}
=0A=

 
int main(int argc, char *argv[])
{
    unsigned int =
i;
    int tp_num =3D 0=
;
    uint64_t total_time<=
b> =3D 0;<=
/pre>

    uint64_t now, nowz;
 
    if (argc =
&=
gt; 1=
) {
        sscanf (argv[1],"%d",&<=
/span>);
    }
    for (i =3D=
 0; i < tp_num; i++<=
b>) {
        now =3D<=
font size=3D"3" color=3D"black" style=3D"font-family: Calibri, Helvetica, s=
ans-serif, serif, EmojiFont;"> <=
b>get_time_nsec();
        lttng_ust_tracepoint(hello=
_world, my_first_tracepoint,
                             i, &quo=
t;some_str");
        nowz =3D =
get_time_nsec();
        total_time +=3D=
 (nowz - now=
);
    }
 
    if (tp_num) {
        printf("------------=
---------------Average TP time is %"PRIu64=
"--=
-------------------------\n", total_time<=
b> / =
tp_num);      
    }
}
--------=
---------------------------------------------------------------------------=
---------------------------------------------------------------------------=
--------------------
 
=0A=

I observed a big average latency variance on different platforms when tracin=
g a high number (many thousands <=
/font>to=
 millions) of tracepoints:
 
  • [platform 1] <=
span style=3D"font-size: 14pt;">with CPU info running=
 a linux kernel based on Buildroot (<=
/span> aarch64 GNU/Linux):
 
BogoMIPS        : 187.50
Features        : fp asimd evtstrm aes=
 =
pmull sha1 sha2 crc32 cpuid

CPU implementer   : 0x41
CPU architecture: 8
CPU variant       : 0x0
CPU part  : 0xd08
CPU revision      : 3
 
       Saw<=
/span>an average latency of 2-<=
/span>[platform 2] <=
/font>with<=
/span>CPU info running a linux kernel=
 =
based on Amazon Linux (4.14.294-<=
font size=3D"4" color=3D"black" style=3D"font-family: Calibri, Helvetica, s=
ans-serif, serif, EmojiFont;">220.533.amzn=
2.aarch64 aarch64 GNU/Linux):
 
BogoMIPS        : 243.75
Features        : fp asimd evtstrm aes=
 =
pmull sha1 sha2 crc32 atomics fphp =
asim=
dhp cpuid asimdrdm=
 lrcpc dcpop asimddp=
 =
ssbs
CPU implementer   : 0x41
CPU architecture: 8
CPU variant       : 0x3
CPU part  : 0xd0c
CPU revision      : 1
 
      Saw=
 =
an average latency=
 of ~0.5u=
s=
ec=0A=

=0A=

 
Are there any suggestions to root cause the high latency and =
potentially=
 improve it on platform =
1=
?
 
Thanks and best regards,
Anas.

--_000_6e06b605ec9f446da5dc8948c8621518amazoncom_-- --===============6493914625085299052== Content-Type: text/plain; charset="us-ascii" MIME-Version: 1.0 Content-Transfer-Encoding: 7bit Content-Disposition: inline _______________________________________________ lttng-dev mailing list lttng-dev@lists.lttng.org https://lists.lttng.org/cgi-bin/mailman/listinfo/lttng-dev --===============6493914625085299052==--