From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: from mail-qk1-x72a.google.com (mail-qk1-x72a.google.com [IPv6:2607:f8b0:4864:20::72a]) by sourceware.org (Postfix) with ESMTPS id A38DF3858415 for ; Sun, 19 Sep 2021 12:40:39 +0000 (GMT) DMARC-Filter: OpenDMARC Filter v1.4.1 sourceware.org A38DF3858415 Received: by mail-qk1-x72a.google.com with SMTP id 194so8223679qkj.11 for ; Sun, 19 Sep 2021 05:40:39 -0700 (PDT) X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20210112; h=x-gm-message-state:mime-version:references:in-reply-to:from:date :message-id:subject:to:cc:content-transfer-encoding; bh=IMyguH83k57ae5nb4A/bksZWtPvMS0EZLzGfRLTB1wQ=; b=UpfEr/GOQlaRCRwZVQEwkTGHPeTxk6aL93Z0zJ6p/eYS8+HGN5u8wgQJEOtAFGSW9Q +OBOQQ0Q+dOL7WarKOSPwQEFE7tWcSe0jjM79emwBmMPV4kJgQEscjJUe1lPI0gHF3ds 0WOs2kkG1TjKvMfqsb9q8913Z58ZQTamCeBBVEI+0RtTdw8Pkvt1h2kocDrbV+k+IMc9 ZITcs6DNFXe7YqmSS84PkJnMBmVKByK8X4F0TG+kMJQirV47wlii4Dbd814btB0HoILK KOoYZY3uWfo6RxTRLtt5cpK9zqhzKN2rvRywcEWS2ZUdlCFCma08zgUrOyhl5j1gvXGB PCWA== X-Gm-Message-State: AOAM5312ViXiqNdNqADcsM25S63/NbhwjsVVN0R75jkBZXCZAODw31Lb h2A3/OSRAGFIxx/GXobuFVwvtUlPflwpg7f4+79e33WPD4deXg== X-Google-Smtp-Source: ABdhPJw+bCAdy6WuTPh31CsjWz9UKN9GfFkh7UG81cPJ+me34Jw9+nUIow47HHR7wGvT83TdllESAjhPMbRHflV6Y+s= X-Received: by 2002:a25:3109:: with SMTP id x9mr24595146ybx.184.1632055239077; Sun, 19 Sep 2021 05:40:39 -0700 (PDT) MIME-Version: 1.0 References: <2b184d53-9044-0e6c-b4db-b87606478026@web.de> In-Reply-To: <2b184d53-9044-0e6c-b4db-b87606478026@web.de> From: Adhemerval Zanella Date: Sun, 19 Sep 2021 09:40:28 -0300 Message-ID: Subject: Re: Checking special execution durations for the determination of mountable file systems To: Markus Elfring Cc: Adhemerval Zanella via Libc-help Content-Type: text/plain; charset="UTF-8" Content-Transfer-Encoding: quoted-printable X-Spam-Status: No, score=-5.0 required=5.0 tests=BAYES_00, DKIM_SIGNED, DKIM_VALID, DKIM_VALID_AU, DKIM_VALID_EF, KAM_SHORT, RCVD_IN_DNSWL_NONE, SPF_HELO_NONE, SPF_PASS, TXREP autolearn=ham autolearn_force=no version=3.4.4 X-Spam-Checker-Version: SpamAssassin 3.4.4 (2020-01-24) on server2.sourceware.org X-BeenThere: libc-help@sourceware.org X-Mailman-Version: 2.1.29 Precedence: list List-Id: Libc-help mailing list List-Unsubscribe: , List-Archive: List-Help: List-Subscribe: , X-List-Received-Date: Sun, 19 Sep 2021 12:40:41 -0000 On Sun, Sep 19, 2021 at 3:41 AM Markus Elfring via Libc-help wrote: > > Hello, > > I came along the need to check unexpected software execution durations > at another place. > > * Qt > https://doc.qt.io/qt-5/qstorageinfo.html#mountedVolumes > > * KPMcore > https://github.com/KDE/kpmcore/blob/ce39e149040bce9782b91e532d041ca0c7= 548a77/src/fs/filesystem.cpp#L145 > > Example: > [Markus_Elfring@fedora mountedVolumes]$ time ./mountedVolumes > Number of eventually mounted filesystems: 43 > > real 3m3,561s > user 0m0,016s > sys 0m0,026s > > > I increased software analysis efforts accordingly. > https://github.com/namhyung/uftrace/ > > [Markus_Elfring@fedora mountedVolumes]$ time sudo uftrace record --data= =3D/home/Markus_Elfring/Test/mountedVolumes/Probe-uftrace/ --nest-libcall -= -kernel --num-thread=3D4 ./mountedVolumes > Number of eventually mounted filesystems: 42 > > real 3m4,835s > user 0m0,346s > sys 0m3,549s > > > [Markus_Elfring@fedora ~]$ uftrace --data=3DTest/mountedVolumes/Probe-uft= race report --filter=3DQStorageInfo::mountedVolumes > Total time Self time Calls Function > =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D =3D=3D= =3D=3D=3D=3D=3D=3D=3D=3D =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D= =3D=3D=3D=3D > 3.000 m 478.403 us 1 QStorageInfo::mountedVolumes > 3.000 m 38.261 us 90 QStorageInfo::QStorageInfo > 3.000 m 10.244 ms 48 QStorageInfo::setPath > 3.000 m 3.000 m 23 linux:schedule > 3.000 m 1.030 m 48 statvfs64 > 1.030 m 1.315 ms 47 __x64_sys_statfs > 45.887 ms 5.746 ms 944 QDirIterator::next > 28.768 ms 3.691 ms 944 QFileInfo::symLinkTarget > 19.421 ms 1.246 ms 3185 fgets > 18.845 ms 659.323 us 1900 QFileInfo::isFile > 18.035 ms 1.207 ms 950 statx > =E2=80=A6 > > > Another bit of background information: > The function =E2=80=9Cstatvfs64=E2=80=9D gets called by the function =E2= =80=9CQStorageInfoPrivate::retrieveVolumeInfo=E2=80=9D (which is called by = the function =E2=80=9CQStorageInfoPrivate::doStat=E2=80=9D and so on). > https://github.com/bminor/glibc/blob/595c22ecd8e87a27fd19270ed30fdbae9ad2= 5426/sysdeps/unix/sysv/linux/statvfs64.c#L27 > https://code.woboq.org/qt5/qtbase/src/corelib/io/qstorageinfo_unix.cpp.ht= ml#_ZN19QStorageInfoPrivate18retrieveVolumeInfoEv > https://code.woboq.org/qt5/qtbase/src/corelib/io/qstorageinfo_unix.cpp.ht= ml#_ZN19QStorageInfoPrivate14mountedVolumesEv > > > Would you like to help with the clarification for the shown measurements? The statvfs() calls statfs() which in turn is a syscall. There is some memory copy involved on __internal_statvfs64(), but it's runtime should be negligible. I would check with Linux perf with kernel probing enabled to see exactly what is happening.