Re: fsmonitor: perpetual trivial response

From: Johannes Schindelin <johannes.schindelin@gmx.de>
Date: Jul 28, 2022, 13:48 UTC
Message-ID: <840r6312-3r19-n087-68s1-rpo1n9869osn@tzk.qr>
In-Reply-To: <CAMxJVdH6=dP7vwruSnKFVTT4ZgygLK_2fu5TKoRia+WyMzATXA@mail.gmail.com>

Hi Eric,

On Wed, 27 Jul 2022, Eric D wrote:

Show 54 quoted lines

> fsmonitor daemon was started in the background (i.e. git
> fsmonitor--daemon start) so I could enable trace2 logging.
>
> 15:36:37.860862 ...n/fsmonitor--daemon.c:969 | d1 | th01:ipc-server
>       | region_enter | r1  | 124.965540 |           | fsmonitor    |
> label:handle_client
> 15:36:37.860862 ...n/fsmonitor--daemon.c:970 | d1 | th01:ipc-server
>       | data         | r1  | 124.965809 |  0.000269 | fsmonitor    |
> ..request:1658950597810367000
> 15:36:37.860862 ...n/fsmonitor--daemon.c:786 | d1 | th01:ipc-server
>       | data         | r1  | 124.965892 |  0.000352 | fsmonitor    |
> ..response/token:builtin:0.12336.20220727T193432.938608Z:0
> 15:36:37.860862 ...n/fsmonitor--daemon.c:822 | d1 | th01:ipc-server
>       | data         | r1  | 124.965969 |  0.000429 | fsmonitor    |
> ..response/trivial:1
> 15:36:37.860862 ...n/fsmonitor--daemon.c:974 | d1 | th01:ipc-server
>       | region_leave | r1  | 124.966000 |  0.000460 | fsmonitor    |
> label:handle_client
> 15:38:40.079662 ...n/fsmonitor--daemon.c:969 | d1 | th02:ipc-server
>       | region_enter | r1  | 247.186960 |           | fsmonitor    |
> label:handle_client
> 15:38:40.079662 ...n/fsmonitor--daemon.c:970 | d1 | th02:ipc-server
>       | data         | r1  | 247.187067 |  0.000107 | fsmonitor    |
> ..request:1658950720017776200
> 15:38:40.079662 ...n/fsmonitor--daemon.c:786 | d1 | th02:ipc-server
>       | data         | r1  | 247.187328 |  0.000368 | fsmonitor    |
> ..response/token:builtin:0.12336.20220727T193432.938608Z:0
> 15:38:40.079662 ...n/fsmonitor--daemon.c:822 | d1 | th02:ipc-server
>       | data         | r1  | 247.187448 |  0.000488 | fsmonitor    |
> ..response/trivial:1
> 15:38:40.079662 ...n/fsmonitor--daemon.c:974 | d1 | th02:ipc-server
>       | region_leave | r1  | 247.187491 |  0.000531 | fsmonitor    |
> label:handle_client
> 15:42:14.719673 ...n/fsmonitor--daemon.c:969 | d1 | th03:ipc-server
>       | region_enter | r1  | 461.821373 |           | fsmonitor    |
> label:handle_client
> 15:42:14.719673 ...n/fsmonitor--daemon.c:970 | d1 | th03:ipc-server
>       | data         | r1  | 461.821429 |  0.000056 | fsmonitor    |
> ..request:1658950934652816400
> 15:42:14.719673 ...n/fsmonitor--daemon.c:786 | d1 | th03:ipc-server
>       | data         | r1  | 461.821467 |  0.000094 | fsmonitor    |
> ..response/token:builtin:0.12336.20220727T193432.938608Z:0
> 15:42:14.719673 ...n/fsmonitor--daemon.c:822 | d1 | th03:ipc-server
>       | data         | r1  | 461.821486 |  0.000113 | fsmonitor    |
> ..response/trivial:1
> 15:42:14.719673 ...n/fsmonitor--daemon.c:974 | d1 | th03:ipc-server
>       | region_leave | r1  | 461.821497 |  0.000124 | fsmonitor    |
> label:handle_client
>
> Note that this is a slightly hacked build of mine where I disabled the
> check for network filesystems. I also added some additional logging
> that tells me that the query is successful, it's just that the
> response is trivial. The sandbox I am using is on the network and
> being accessed from my Windows VM.

Since you already "hacked" it, why not instrument it a bit more, e.g. offering some trace2 message for all the places where `do_trivial` is set to 1 in builtin/fsmonitor--daemon.c?

Or maybe you need to use `GIT_TRACE2_EVENT` instead of `GIT_TRACE2_PERF` (I vaguely remember that `error()` messages are only logged in one of these two modes).

Ciao, Johannes