{"thread":{"id":"52184","subject":"[PATCH 0/1] fsmonitor: fix watchman integration","startedAt":"2019-11-04T17:50:47Z","lastAt":"2019-11-12T11:32:29Z","messageCount":6,"participants":["Kevin Willford via GitGitGadget","Junio C Hamano","Kevin Willford","Derrick Stolee","SZEDER Gábor"],"isPatch":true,"patchVersion":1,"patchTotal":1},"messages":[{"id":"385406","messageId":"pull.444.git.1572889841.gitgitgadget@gmail.com","threadId":"52184","inReplyTo":null,"subject":"[PATCH 0/1] fsmonitor: fix watchman integration","fromName":"Kevin Willford via GitGitGadget","fromEmail":"gitgitgadget@gmail.com","sentAt":"2019-11-04T17:50:40Z","receivedAt":"2019-11-04T17:50:47Z","isPatch":true,"sender":{"key":"kewillf@microsoft.com","avatar":null},"body":"When running Git commands quickly -- such as in a shell script or the test\nsuite -- the Git commands frequently complete and start again during the\nsame second. The example fsmonitor hooks to integrate with Watchman truncate\nthe nanosecond times to seconds. In principle, this is fine, as Watchman\nclaims to use inclusive comparisons [1]. The result should only be an\nover-representation of the changed paths since the last Git command.\n\nHowever, Watchman's own documentation claims \"Using a timestamp is prone to\nrace conditions in understanding the complete state of the file tree\" [2].\nAll of their documented examples use a \"clockspec\" that looks like\n'c:123:234'. Git should eventually learn how to store this type of string to\nprovide a stronger integration, but that will be a more invasive change.\n\nWhen using GIT_TEST_FSMONITOR=\"$(pwd)/t7519/fsmonitor-watchman\", scripts\nsuch as t7519-wtstatus.sh fail due to these race conditions. In fact,\nrunning any test script with GIT_TEST_FSMONITOR pointing at\nt/t7519/fsmonitor-wathcman will cause failures in the test_commit function.\nThe 'git add \"$indir$file\"' command fails due to not enough time between the\ncreation of '$file' and the 'git add' command.\n\nFor now, subtract one second from the timestamp we pass to Watchman. This\nwill make our window large enough to avoid these race conditions. Increasing\nthe window causes tests like t7519-wtstatus.sh to pass.\n\nWhen the integration was introduced in def437671 (fsmonitor: add a sample\nintegration script for Watchman, 2018-09-22), the query included an\nexpression that would ignore files created and deleted in that window. The\nperformance reason for this change was to ignore temporary files created by\na build between Git commands. However, this causes failures in script\nscenarios where Git is creating or deleting files quickly.\n\nWhen using GIT_TEST_FSMONITOR as before, t2203-add-intent.sh fails due to\nthis add-and-delete race condition.\n\nBy removing the \"expression\" from the Watchman query, we remove this race\ncondition. It will lead to some performance degradation in the case of users\ncreating and deleting temporary files inside their working directory between\nGit commands. However, that is a cost we need to pay to be correct.\n\n[1] https://github.com/facebook/watchman/blob/master/query/since.cpp#L35-L39\n[2] https://facebook.github.io/watchman/docs/clockspec.html\n\nKevin Willford (1):\n fsmonitor: fix watchman integration\n\n t/t7519/fsmonitor-watchman | 13 ++++---------\n templates/hooks--fsmonitor-watchman.sample | 13 ++++---------\n 2 files changed, 8 insertions(+), 18 deletions(-)\n\n\nbase-commit: da72936f544fec5a335e66432610e4cef4430991\nPublished-As: https://github.com/gitgitgadget/git/releases/tag/pr-444%2Fkewillford%2Ffsmonitor-watchman-fix-v1\nFetch-It-Via: git fetch https://github.com/gitgitgadget/git pr-444/kewillford/fsmonitor-watchman-fix-v1\nPull-Request: https://github.com/gitgitgadget/git/pull/444\n-- \ngitgitgadget\n"},{"id":"385407","messageId":"52eaf20f405b53743e27935dfe89f62e6f824a33.1572889841.git.gitgitgadget@gmail.com","threadId":"52184","inReplyTo":"pull.444.git.1572889841.gitgitgadget@gmail.com","subject":"[PATCH 1/1] fsmonitor: fix watchman integration","fromName":"Kevin Willford via GitGitGadget","fromEmail":"gitgitgadget@gmail.com","sentAt":"2019-11-04T17:50:41Z","receivedAt":"2019-11-04T17:50:48Z","isPatch":true,"sender":{"key":"kewillf@microsoft.com","avatar":null},"body":"From: Kevin Willford \n\nWhen running Git commands quickly -- such as in a shell script or the\ntest suite -- the Git commands frequently complete and start again\nduring the same second. The example fsmonitor hooks to integrate with\nWatchman truncate the nanosecond times to seconds. In principle, this is\nfine, as Watchman claims to use inclusive comparisons [1]. The result\nshould only be an over-representation of the changed paths since the\nlast Git command.\n\nHowever, Watchman's own documentation claims \"Using a timestamp is prone\nto race conditions in understanding the complete state of the file tree\"\n[2]. All of their documented examples use a \"clockspec\" that looks like\n'c:123:234'. Git should eventually learn how to store this type of\nstring to provide a stronger integration, but that will be a more\ninvasive change.\n\nWhen using GIT_TEST_FSMONITOR=\"$(pwd)/t7519/fsmonitor-watchman\", scripts\nsuch as t7519-wtstatus.sh fail due to these race conditions. In fact,\nrunning any test script with GIT_TEST_FSMONITOR pointing at\nt/t7519/fsmonitor-wathcman will cause failures in the test_commit\nfunction. The 'git add \"$indir$file\"' command fails due to not enough\ntime between the creation of '$file' and the 'git add' command.\n\nFor now, subtract one second from the timestamp we pass to Watchman.\nThis will make our window large enough to avoid these race conditions.\nIncreasing the window causes tests like t7519-wtstatus.sh to pass.\n\nWhen the integration was introduced in def437671 (fsmonitor: add a\nsample integration script for Watchman, 2018-09-22), the query included\nan expression that would ignore files created and deleted in that\nwindow. The performance reason for this change was to ignore temporary\nfiles created by a build between Git commands. However, this causes\nfailures in script scenarios where Git is creating or deleting files\nquickly.\n\nWhen using GIT_TEST_FSMONITOR as before, t2203-add-intent.sh fails\ndue to this add-and-delete race condition.\n\nBy removing the \"expression\" from the Watchman query, we remove this\nrace condition. It will lead to some performance degradation in the case\nof users creating and deleting temporary files inside their working\ndirectory between Git commands. However, that is a cost we need to pay\nto be correct.\n\n[1] https://github.com/facebook/watchman/blob/master/query/since.cpp#L35-L39\n[2] https://facebook.github.io/watchman/docs/clockspec.html\n\nHelped-by: Derrick Stolee \nSigned-off-by: Kevin Willford \n---\n t/t7519/fsmonitor-watchman | 13 ++++---------\n templates/hooks--fsmonitor-watchman.sample | 13 ++++---------\n 2 files changed, 8 insertions(+), 18 deletions(-)\n\ndiff --git a/t/t7519/fsmonitor-watchman b/t/t7519/fsmonitor-watchman\nindex 5514edcf68..d8e7a1e5ba 100755\n--- a/t/t7519/fsmonitor-watchman\n+++ b/t/t7519/fsmonitor-watchman\n@@ -23,7 +23,8 @@ my ($version, $time) = @ARGV;\n \n if ($version == 1) {\n \t# convert nanoseconds to seconds\n-\t$time = int $time / 1000000000;\n+\t# subtract one second to make sure watchman will return all changes\n+\t$time = int ($time / 1000000000) - 1;\n } else {\n \tdie \"Unsupported query-fsmonitor hook version '$version'.\\n\" .\n \t \"Falling back to scanning...\\n\";\n@@ -54,18 +55,12 @@ sub launch_watchman {\n \t#\n \t# To accomplish this, we're using the \"since\" generator to use the\n \t# recency index to select candidate nodes and \"fields\" to limit the\n-\t# output to file names only. Then we're using the \"expression\" term to\n-\t# further constrain the results.\n-\t#\n-\t# The category of transient files that we want to ignore will have a\n-\t# creation clock (cclock) newer than $time_t value and will also not\n-\t# currently exist.\n+\t# output to file names only.\n \n \tmy $query = <<\"\tEND\";\n \t\t[\"query\", \"$git_work_tree\", {\n \t\t\t\"since\": $time,\n-\t\t\t\"fields\": [\"name\"],\n-\t\t\t\"expression\": [\"not\", [\"allof\", [\"since\", $time, \"cclock\"], [\"not\", \"exists\"]]]\n+\t\t\t\"fields\": [\"name\"]\n \t\t}]\n \tEND\n \t\ndiff --git a/templates/hooks--fsmonitor-watchman.sample b/templates/hooks--fsmonitor-watchman.sample\nindex e673bb3980..ef94fa2938 100755\n--- a/templates/hooks--fsmonitor-watchman.sample\n+++ b/templates/hooks--fsmonitor-watchman.sample\n@@ -22,7 +22,8 @@ my ($version, $time) = @ARGV;\n \n if ($version == 1) {\n \t# convert nanoseconds to seconds\n-\t$time = int $time / 1000000000;\n+\t# subtract one second to make sure watchman will return all changes\n+\t$time = int ($time / 1000000000) - 1;\n } else {\n \tdie \"Unsupported query-fsmonitor hook version '$version'.\\n\" .\n \t \"Falling back to scanning...\\n\";\n@@ -53,18 +54,12 @@ sub launch_watchman {\n \t#\n \t# To accomplish this, we're using the \"since\" generator to use the\n \t# recency index to select candidate nodes and \"fields\" to limit the\n-\t# output to file names only. Then we're using the \"expression\" term to\n-\t# further constrain the results.\n-\t#\n-\t# The category of transient files that we want to ignore will have a\n-\t# creation clock (cclock) newer than $time_t value and will also not\n-\t# currently exist.\n+\t# output to file names only.\n \n \tmy $query = <<\"\tEND\";\n \t\t[\"query\", \"$git_work_tree\", {\n \t\t\t\"since\": $time,\n-\t\t\t\"fields\": [\"name\"],\n-\t\t\t\"expression\": [\"not\", [\"allof\", [\"since\", $time, \"cclock\"], [\"not\", \"exists\"]]]\n+\t\t\t\"fields\": [\"name\"]\n \t\t}]\n \tEND\n \n-- \ngitgitgadget\n"},{"id":"385521","messageId":"xmqqlfstvg09.fsf@gitster-ct.c.googlers.com","threadId":"52184","inReplyTo":"pull.444.git.1572889841.gitgitgadget@gmail.com","subject":"Re: [PATCH 0/1] fsmonitor: fix watchman integration","fromName":"Junio C Hamano","fromEmail":"gitster@pobox.com","sentAt":"2019-11-06T03:29:58Z","receivedAt":"2019-11-06T03:30:02Z","isPatch":true,"sender":{"key":"gitster@pobox.com","avatar":"https://avatars.githubusercontent.com/u/54884?v=4"},"body":"\"Kevin Willford via GitGitGadget\" writes:\n\n> When running Git commands quickly -- such as in a shell script or the test\n> suite -- the Git commands frequently complete and start again during the\n> same second. The example fsmonitor hooks to integrate with Watchman truncate\n> the nanosecond times to seconds. In principle, this is fine, as Watchman\n> claims to use inclusive comparisons [1]. The result should only be an\n> over-representation of the changed paths since the last Git command.\n> ...\n\nSo, it doesn't seem to use \"inclusive\" and we need a workaround?\n\n> Kevin Willford (1):\n> fsmonitor: fix watchman integration\n>\n> t/t7519/fsmonitor-watchman | 13 ++++---------\n> templates/hooks--fsmonitor-watchman.sample | 13 ++++---------\n> 2 files changed, 8 insertions(+), 18 deletions(-)\n\nThanks, will queue.\n"},{"id":"385594","messageId":"BN6PR21MB0786856156CFB55E8812D51E91790@BN6PR21MB0786.namprd21.prod.outlook.com","threadId":"52184","inReplyTo":"xmqqlfstvg09.fsf@gitster-ct.c.googlers.com","subject":"RE: [PATCH 0/1] fsmonitor: fix watchman integration","fromName":"Kevin Willford","fromEmail":"kevin.willford@microsoft.com","sentAt":"2019-11-06T15:32:22Z","receivedAt":"2019-11-06T15:32:26Z","isPatch":true,"sender":{"key":"kevin.willford@microsoft.com","avatar":"https://avatars.githubusercontent.com/u/40003493?v=4"},"body":"> From: Junio C Hamano \n> Sent: Tuesday, November 5, 2019 8:30 PM\n> \n> \"Kevin Willford via GitGitGadget\" writes:\n> \n> > When running Git commands quickly -- such as in a shell script or the\n> > test suite -- the Git commands frequently complete and start again\n> > during the same second. The example fsmonitor hooks to integrate with\n> > Watchman truncate the nanosecond times to seconds. In principle, this\n> > is fine, as Watchman claims to use inclusive comparisons [1]. The\n> > result should only be an over-representation of the changed paths since\n> the last Git command.\n> > ...\n> \n> So, it doesn't seem to use \"inclusive\" and we need a workaround?\n\nThat is what is seems like. I would like to dig into the watchman code\nto understand what is really going on. They also document that \"Using\na timestamp is prone to race conditions in understanding the complete\nstate of the file tree.\" Which could be the cause since the tests are\nrunning things in quick succession, i.e. change a file, run a git command.\n\nLong term we should switch to using watchman's clock id which the\ndocumentation says does not have the race conditions. But the clock\nid is a string and would take more invasive changes to integrate that\ninto the index where we are now simply using a uint64_t.\n\n"},{"id":"385596","messageId":"cca49c40-8abc-96c2-f79c-399f29ceae0d@gmail.com","threadId":"52184","inReplyTo":"BN6PR21MB0786856156CFB55E8812D51E91790@BN6PR21MB0786.namprd21.prod.outlook.com","subject":"Re: [PATCH 0/1] fsmonitor: fix watchman integration","fromName":"Derrick Stolee","fromEmail":"stolee@gmail.com","sentAt":"2019-11-06T15:46:34Z","receivedAt":"2019-11-06T15:46:38Z","isPatch":true,"sender":{"key":"stolee@gmail.com","avatar":"https://avatars.githubusercontent.com/u/570044?v=4"},"body":"On 11/6/2019 10:32 AM, Kevin Willford wrote:\n>> From: Junio C Hamano \n>> Sent: Tuesday, November 5, 2019 8:30 PM\n>>\n>> \"Kevin Willford via GitGitGadget\" writes:\n>>\n>>> When running Git commands quickly -- such as in a shell script or the\n>>> test suite -- the Git commands frequently complete and start again\n>>> during the same second. The example fsmonitor hooks to integrate with\n>>> Watchman truncate the nanosecond times to seconds. In principle, this\n>>> is fine, as Watchman claims to use inclusive comparisons [1]. The\n>>> result should only be an over-representation of the changed paths since\n>> the last Git command.\n>>> ...\n>>\n>> So, it doesn't seem to use \"inclusive\" and we need a workaround?\n> \n> That is what is seems like. I would like to dig into the watchman code\n> to understand what is really going on. They also document that \"Using\n> a timestamp is prone to race conditions in understanding the complete\n> state of the file tree.\" Which could be the cause since the tests are\n> running things in quick succession, i.e. change a file, run a git command.\n> \n> Long term we should switch to using watchman's clock id which the\n> documentation says does not have the race conditions. But the clock\n> id is a string and would take more invasive changes to integrate that\n> into the index where we are now simply using a uint64_t.\n\nI should mention that I'm working on a patch series that will allow us\nto use GIT_TEST_FSMONITOR pointing at Watchman in our CI builds. There\nare several places where our fsmonitor integration does not work well\n(such as when we delete submodules), but most of the remaining fixes\nare small.\n\nThis timing issue fixes MOST of the problems we see when running the\ntest suite.\n\nThanks,\n-Stolee\n\n"},{"id":"386006","messageId":"20191112113223.GO4348@szeder.dev","threadId":"52184","inReplyTo":"52eaf20f405b53743e27935dfe89f62e6f824a33.1572889841.git.gitgitgadget@gmail.com","subject":"Re: [PATCH 1/1] fsmonitor: fix watchman integration","fromName":"SZEDER Gábor","fromEmail":"szeder.dev@gmail.com","sentAt":"2019-11-12T11:32:23Z","receivedAt":"2019-11-12T11:32:29Z","isPatch":true,"sender":{"key":"szeder.dev@gmail.com","avatar":"https://avatars.githubusercontent.com/u/116324?v=4"},"body":"On Mon, Nov 04, 2019 at 05:50:41PM +0000, Kevin Willford via GitGitGadget wrote:\n> When running Git commands quickly -- such as in a shell script or the\n> test suite -- the Git commands frequently complete and start again\n> during the same second. The example fsmonitor hooks to integrate with\n> Watchman truncate the nanosecond times to seconds. In principle, this is\n> fine, as Watchman claims to use inclusive comparisons [1]. The result\n> should only be an over-representation of the changed paths since the\n> last Git command.\n\n> [1] https://github.com/facebook/watchman/blob/master/query/since.cpp#L35-L39\n\nNit: please refer to the specific blob in this link. The file's\ncontent in 'master' might change in time, and then the highlight will\npoint to different lines. Worse, the file might be renamed, and then\nwe'll get a broken link.\n\n"}]}