* fsmonitor: perpetual trivial response
@ 2022-07-27 20:03 Eric D
2022-07-28 13:48 ` Johannes Schindelin
0 siblings, 1 reply; 4+ messages in thread
From: Eric D @ 2022-07-27 20:03 UTC (permalink / raw)
To: git
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.
-Eric
^ permalink raw reply [flat|nested] 4+ messages in thread
* Re: fsmonitor: perpetual trivial response
2022-07-27 20:03 fsmonitor: perpetual trivial response Eric D
@ 2022-07-28 13:48 ` Johannes Schindelin
2022-08-01 18:19 ` Eric D
0 siblings, 1 reply; 4+ messages in thread
From: Johannes Schindelin @ 2022-07-28 13:48 UTC (permalink / raw)
To: Eric D; +Cc: git
Hi Eric,
On Wed, 27 Jul 2022, Eric D wrote:
> 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
^ permalink raw reply [flat|nested] 4+ messages in thread
* Re: fsmonitor: perpetual trivial response
2022-07-28 13:48 ` Johannes Schindelin
@ 2022-08-01 18:19 ` Eric D
2022-08-02 13:51 ` Jeff Hostetler
0 siblings, 1 reply; 4+ messages in thread
From: Eric D @ 2022-08-01 18:19 UTC (permalink / raw)
To: Johannes Schindelin; +Cc: git
On Thu, Jul 28, 2022 at 9:48 AM Johannes Schindelin
<Johannes.Schindelin@gmx.de> wrote:
>
> Hi Eric,
>
> On Wed, 27 Jul 2022, Eric D wrote:
>
> > 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
^ permalink raw reply [flat|nested] 4+ messages in thread
* Re: fsmonitor: perpetual trivial response
2022-08-01 18:19 ` Eric D
@ 2022-08-02 13:51 ` Jeff Hostetler
0 siblings, 0 replies; 4+ messages in thread
From: Jeff Hostetler @ 2022-08-02 13:51 UTC (permalink / raw)
To: Eric D, Johannes Schindelin; +Cc: git
On 8/1/22 2:19 PM, Eric D wrote:
> On Thu, Jul 28, 2022 at 9:48 AM Johannes Schindelin
> <Johannes.Schindelin@gmx.de> wrote:
>>
>> Hi Eric,
>>
>> On Wed, 27 Jul 2022, Eric D wrote:
>>
>>> 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
>
The first time status runs and it starts the daemon, you'll get
a trivial response (because the daemon doesn't have a sync point
established with client commands yet).
Subsequent client commands (like status) will continue to receive
a trivial response *UNTIL* one of them updates the index and records
the sync point (token) into the index. That is, until the index
is updated with a valid token, they will continue to send not-sync'd
timestamp in the request header and get a trivial response.
> ..request:1658950934652816400
>
> ..response/token:builtin:0.12336.20220727T193432.938608Z:0
> ..response/trivial:1
When/if any of these client commands update the the index, they will
write the response token to the FSM index extension, and subsequent
requests will send it to the daemon. The daemon will then start sending
non-trivial responses (possibly with an updated token).
> ..request:builtin:0.12336.20220727T193432.938608Z:0
>
> ..response/token:builtin:0.12336.20220727T193432.938608Z:1
Commands like `git status` may be read-only or may update the `lstat`
times in cache-entries and rewrite the index. It is not always clear
when a status command will and will not rewrite the index -- it just
depends on what kind of changes it sees and how many. My point is
that it will not update the token unless it updates the index, so you
need to watch for that on the client side rather than looking at the
daemon log.
Hope this helps,
Jeff
^ permalink raw reply [flat|nested] 4+ messages in thread
end of thread, other threads:[~2022-08-02 13:54 UTC | newest]
Thread overview: 4+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2022-07-27 20:03 fsmonitor: perpetual trivial response Eric D
2022-07-28 13:48 ` Johannes Schindelin
2022-08-01 18:19 ` Eric D
2022-08-02 13:51 ` Jeff Hostetler
This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.