On Thu, Jul 28, 2022 at 9:48 AM Johannes Schindelin
[off-list ref] wrote:

Hi Eric,

On Wed, 27 Jul 2022, Eric D wrote:

quoted

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

My sandbox is sparse, but it is not "cone compliant"; temporarily
disabling sparse checkout seems to have (temporarily) resolved this
issue - at least for my purposes of testing fsmonitor out on network
filesystems.

-Eric