nx stops recognizing project after project.json update when using (n)vim on linux

jeremyhofer commented 12 months ago

Current Behavior

Testing in a Nx workspace for a personal project, and recreating in a stripped down Nx workspace, whenever the project.json file is updated for the target project the project fails to be recognized going forward. This causes any of the following to happen: the project graph to be incorrect, the daemon to crash, the project to note display when running npx nx graph, or other related issues from the project supposedly not existing.

Running npx nx reset does fix this.

Expected Behavior

Updating a project.json file should not cause a project to no longer be recognized. Being forced to run npx nx reset after project.json changes should not be necessary.

GitHub Repo

https://github.com/jeremyhofer/nx-project-json-bug-reproduce

Steps to Reproduce

Install dependencies
Run npx nx graph or other nx command that depends on the project graph
Update project.json and make any change. For example, update sourceMap to false under the development build configuration
Run npx nx graph or other nx command that depends on the project graph

Nx Report

Node   : 18.13.0
   OS     : linux-x64
   npm    : 8.19.3

   nx                 : 17.1.3
   @nx/js             : 17.1.3
   @nx/jest           : 17.1.3
   @nx/linter         : 17.1.3
   @nx/eslint         : 17.1.3
   @nx/workspace      : 17.1.3
   @nx/angular        : 17.1.3
   @nx/cypress        : 17.1.3
   @nx/devkit         : 17.1.3
   @nx/eslint-plugin  : 17.1.3
   @nx/playwright     : 17.1.3
   @nrwl/tao          : 17.1.3
   @nx/web            : 17.1.3
   @nx/webpack        : 17.1.3
   typescript         : 5.2.2

Failure Logs

From daemon.log:
[NX Daemon Server] - 2023-12-07T02:12:05.437Z - Started listening on: /tmp/6642e934d6170962b3f0/d.sock
[NX Daemon Server] - 2023-12-07T02:12:05.438Z - [WATCHER]: Subscribed to changes within: /home/jhofer/Devel/personal/test-nx (native)
[NX Daemon Server] - 2023-12-07T02:12:05.445Z - Established a connection. Number of open connections: 1
[NX Daemon Server] - 2023-12-07T02:12:05.446Z - Established a connection. Number of open connections: 2
[NX Daemon Server] - 2023-12-07T02:12:05.447Z - [REQUEST]: Client Request for Project Graph Received
[NX Daemon Server] - 2023-12-07T02:12:05.482Z - [REQUEST]: Updated file-hasher based on watched changes, recomputing project graph...
[NX Daemon Server] - 2023-12-07T02:12:05.482Z - [REQUEST]: 
[NX Daemon Server] - 2023-12-07T02:12:05.482Z - [REQUEST]: 
[NX Daemon Server] - 2023-12-07T02:12:05.556Z - [REQUEST]: Responding to the client. project-graph
[NX Daemon Server] - 2023-12-07T02:12:05.557Z - Time taken for 'total for creating and serializing project graph' 108.33702501654625ms
[NX Daemon Server] - 2023-12-07T02:12:05.557Z - Closed a connection. Number of open connections: 1
[NX Daemon Server] - 2023-12-07T02:12:05.559Z - Done responding to the client project-graph
[NX Daemon Server] - 2023-12-07T02:12:05.559Z - Handled REQUEST_PROJECT_GRAPH. Handling time: 109. Response time: 3.
[NX Daemon Server] - 2023-12-07T02:12:05.568Z - [REQUEST]: Client Request for Project Graph Received
[NX Daemon Server] - 2023-12-07T02:12:05.568Z - [REQUEST]: Responding to the client. project-graph
[NX Daemon Server] - 2023-12-07T02:12:05.570Z - Time taken for 'total for creating and serializing project graph' 0.2815290093421936ms
[NX Daemon Server] - 2023-12-07T02:12:05.570Z - Done responding to the client project-graph
[NX Daemon Server] - 2023-12-07T02:12:05.570Z - Handled REQUEST_PROJECT_GRAPH. Handling time: 0. Response time: 2.
[NX Daemon Server] - 2023-12-07T02:12:11.038Z - Closed a connection. Number of open connections: 0
[NX Daemon Server] - 2023-12-07T02:12:15.257Z - [WATCHER]: 0 file(s) created or restored, 0 file(s) modified, 2 file(s) deleted
[NX Daemon Server] - 2023-12-07T02:12:15.257Z - [WATCHER]: Processing file changes in outputs
[NX Daemon Server] - 2023-12-07T02:12:15.364Z - [REQUEST]: Updated file-hasher based on watched changes, recomputing project graph...
[NX Daemon Server] - 2023-12-07T02:12:15.364Z - [REQUEST]: 
[NX Daemon Server] - 2023-12-07T02:12:15.364Z - [REQUEST]: 4913,project.json
[NX Daemon Server] - 2023-12-07T02:12:15.376Z - Error detected when creating a project graph: Configuration Error
The following implicitDependencies point to non-existent project(s):
  e2e
    test-nx
[NX Daemon Server] - 2023-12-07T02:12:15.376Z - Time taken for 'hash changed files from watcher' 0.06640401482582092ms
[NX Daemon Server] - 2023-12-07T02:12:18.948Z - Established a connection. Number of open connections: 1
[NX Daemon Server] - 2023-12-07T02:12:18.948Z - Closed a connection. Number of open connections: 0
[NX Daemon Server] - 2023-12-07T02:12:18.949Z - Established a connection. Number of open connections: 1
[NX Daemon Server] - 2023-12-07T02:12:18.949Z - [REQUEST]: Client Request for Project Graph Received
[NX Daemon Server] - 2023-12-07T02:12:18.949Z - [REQUEST]: Responding to the client with an error. Error when preparing serialized project graph. Configuration Error
The following implicitDependencies point to non-existent project(s):
  e2e
    test-nx
Error: Configuration Error
The following implicitDependencies point to non-existent project(s):
  e2e
    test-nx
    at assertWorkspaceValidity (/home/jhofer/Devel/personal/test-nx/node_modules/nx/src/utils/assert-workspace-validity.js:70:11)
    at buildProjectGraphUsingProjectFileMap (/home/jhofer/Devel/personal/test-nx/node_modules/nx/src/project-graph/build-project-graph.js:42:61)
    at createAndSerializeProjectGraph (/home/jhofer/Devel/personal/test-nx/node_modules/nx/src/daemon/server/project-graph-incremental-recomputation.js:171:124)
    at async Timeout._onTimeout (/home/jhofer/Devel/personal/test-nx/node_modules/nx/src/daemon/server/project-graph-incremental-recomputation.js:79:13)
[NX Daemon Server] - 2023-12-07T02:12:18.950Z - Done responding to the client null

Package Manager Version

No response

Operating System

[ ] macOS
[X] Linux
[ ] Windows
[ ] Other (Please specify)

Additional Information

I tested this with multiple different versions of node. 18.13.0, 20.10.0, 20.9.0, and 21.4.0. Similar issue in all versions I tried.

This was also existing in Nx 17.1.1 as well (did not test any other previous Nx versions).

Here is further information on my system:

 OS: Arch Linux
 Kernel: x86_64 Linux 6.6.3-arch1-1
 Shell: zsh 5.9
 CPU: AMD Ryzen 7 7840U w/ Radeon 780M Graphics @ 16x 5.289GHz

airtonix commented 10 months ago

I cloned your repo and ran through the reproduction and I don't see anything weird.

what I did:

default to my global nodejs install provided by asdf
cloned your repo
npm i
npx nx graph
observed that both test-e2e- and nx-test are seen by the graph.
stopped the graph ui cmd
modified project.json#targets.build.configuration.development.sourceMap = true
saved the file
ran npx nx graph again
observed that both test-e2e- and nx-test are seen by the graph.

🤷🏻

MaxKless commented 6 months ago

Hey @jeremyhofer :) Thank you for taking the time to report this. I cloned your repo and went through the steps and can confirm that no errors show & the graph app renders both projects as usual. This error

The following implicitDependencies point to non-existent project(s):
  e2e
    test-nx

usuall means the following: There is a syntax error in your project.json, which means the name field can't be read, which means the test-nx project doesn't exist... which causes that error.

Maybe this is something specific to your environment? Since I can't repro, there are no real steps I can take forward to fixing this issue. Can you try one of the following things:

Try and reproduce this on another machine. If you can, record a video of it happening so I can maybe spot anything that's happening
Try reproducing this on a newer version of Nx. Probably the issue is solved by now :)

Thank you!

github-actions[bot] commented 6 months ago

This issue has been automatically marked as stale because no reproduction was provided within 7 days. Please help us help you. Providing a repository exhibiting the issue helps us diagnose and fix the issue. Any time that we spend reproducing this issue is time taken away from addressing this issue and other issues. This issue will be closed in 21 days if a reproduction is not provided. If a reproduction has been provided, please reply to keep it active. Thanks for being a part of the Nx community! 🙏

volago commented 5 months ago

It happens for me too, NX 18.3.4. It is production repo, so I cannot provide it as reproduction

MaxKless commented 5 months ago

Are you seeing the exact same error with implicitDependencies? If so, can you try whether the issue still persists on a newer version of Nx? As I mentioned above, I cannot reproduce this and need more information here. It's very possible the issue is already fixed on latest.

jeremyhofer commented 5 months ago

Hi @MaxKless, apologies for not responding back on this issue sooner.

I am still experiencing this issue, even on latest Nx 19.3.0.

Fresh nx report from my personal project:

Node   : 20.14.0
OS     : linux-x64
npm    : 10.7.0

nx                 : 19.3.0
@nx/js             : 19.3.0
@nx/jest           : 19.3.0
@nx/linter         : 19.3.0
@nx/eslint         : 19.3.0
@nx/workspace      : 19.3.0
@nx/angular        : 19.3.0
@nx/devkit         : 19.3.0
@nx/esbuild        : 19.3.0
@nx/eslint-plugin  : 19.3.0
@nx/node           : 19.3.0
@nx/playwright     : 19.3.0
@nrwl/tao          : 19.3.0
@nx/vite           : 19.3.0
@nx/web            : 19.3.0
@nx/webpack        : 19.3.0
typescript         : 5.4.5
---------------------------------------
Community plugins:
@analogjs/content             : 1.5.0
@analogjs/platform            : 1.5.0
@analogjs/router              : 1.5.0
@analogjs/trpc                : 0.2.45
@analogjs/vite-plugin-angular : 1.5.0
@spartan-ng/cli               : 0.0.1-alpha.357
@testing-library/angular      : 16.0.0

To clarify, a valid change is being made. The change can be as simple as updating any number (e.g. a port from 4200 to 4201), changing a boolean value (e.g. from true to false) or any other simple change. The structure of the file is still accurate.

I just did more debugging / experimentation on my side. I've better isolated that this seems to specifically be an issue when updating files using (neo)vim on linux (happens for both neovim and vim). Testing on a Macbook where I similarly use neovim I have no issues.

When a file is updated with neovim or vim on linux the file is being reported as being deleted, not updated. In the case of project.json files these are being reported as deleted, and I, assuming, believe this will cause the project / data related to that project.json to be removed from the workspace context.

Testing, all files are detected as deleted when written via (neo)vim on linux.

Comparing to using (neo)vim on a Macbook the project.json is listed as updated instead of deleted. Additionally, comparing to other edit methods - sed, vi, and nano - all these report the project.json is updated, not deleted.

I believe the root issue is due to a combination of two things:

(neo)vim using an atomic-like write process, where the original file is removed and replaced instead of updated directly
The native watcher.rs prioritizes delete operations over any other operations, regardless of order of events and final filesystem state, resulting in only a delete event being reported: https://github.com/nrwl/nx/blob/master/packages/nx/src/native/watch/watcher.rs#L134

Installing watchexec and running watchexec --print-events echo, which I believe should print the same/similar set of events the native watcher is processing, we can see the remove/rename operations being performed:

[EVENT 0] Event source=Filesystem kind=Create(File) path=/home/jhofer/Devel/personal/organized-chaos/libs/utils/4913
[EVENT 1] Event source=Filesystem kind=Remove(File) path=/home/jhofer/Devel/personal/organized-chaos/libs/utils/4913
[EVENT 2] Event source=Filesystem kind=Create(File) path=/home/jhofer/Devel/personal/organized-chaos/libs/utils/project.json filetype=file
[EVENT 3] Event source=Filesystem kind=Modify(Name(Both)) path=/home/jhofer/Devel/personal/organized-chaos/libs/utils/project.json filetype=file path=/home/jhofer/Devel/pers
onal/organized-chaos/libs/utils/project.json~ filetype=file
[EVENT 4] Event source=Filesystem kind=Modify(Data(Any)) path=/home/jhofer/Devel/personal/organized-chaos/libs/utils/project.json filetype=file
[EVENT 5] Event source=Filesystem kind=Modify(Name(To)) path=/home/jhofer/Devel/personal/organized-chaos/libs/utils/project.json~ filetype=file
[EVENT 6] Event source=Filesystem kind=Modify(Metadata(Any)) path=/home/jhofer/Devel/personal/organized-chaos/libs/utils/4913
[EVENT 7] Event source=Filesystem kind=Modify(Name(From)) path=/home/jhofer/Devel/personal/organized-chaos/libs/utils/project.json filetype=file
[EVENT 8] Event source=Filesystem kind=Modify(Metadata(Any)) path=/home/jhofer/Devel/personal/organized-chaos/libs/utils/project.json filetype=file
[EVENT 9] Event source=Filesystem kind=Remove(File) path=/home/jhofer/Devel/personal/organized-chaos/libs/utils/project.json~

Let me know if this helps with recreation at all, and if I can help provide any additional information.

MaxKless commented 5 months ago

Thanks for the detailed investigation @jeremyhofer! Super useful. I remember someone talking about a similar issue recently, I'll check in with the rest of the team and get the latest information on what the status here is. I'll let you know once I know more!

github-actions[bot] commented 5 months ago

This issue has been automatically marked as stale because no reproduction was provided within 7 days. Please help us help you. Providing a repository exhibiting the issue helps us diagnose and fix the issue. Any time that we spend reproducing this issue is time taken away from addressing this issue and other issues. This issue will be closed in 21 days if a reproduction is not provided. If a reproduction has been provided, please reply to keep it active. Thanks for being a part of the Nx community! 🙏

nrwl / nx