[python] plugin-storage/global-state.json: Unexpected end of JSON input

[akosyakov]

Python extension is trying to read storage files and fails:

root ERROR Failed to parse data from " /home/gitpod/.theia/plugin-storage/global-state.json ". Reason: SyntaxError: /home/gitpod/.theia/plugin-storage/global-state.json: Unexpected end of JSON input
    at JSON.parse (<anonymous>)
    at /workspace/theia/node_modules/jsonfile/index.js:33:18
    at /workspace/theia/node_modules/graceful-fs/graceful-fs.js:115:16
    at FSReqCallback.readFileAfterClose [as oncomplete] (internal/fs/read_file_context.js:61:3)

[daimor]

Exactly the same issue, with the workspaceState.

root ERROR Failed to parse data from " /home/theia/.theia/workspace-storage/9c491c7c323deca0a9a4af50687fc724/workspace-state.json ". Reason: SyntaxError: /home/theia/.theia/workspace-storage/9c491c7c323deca0a9a4af50687fc724/workspace-state.json: Unexpected end of JSON input
     at JSON.parse (<anonymous>)
     at /home/theia/node_modules/jsonfile/index.js:33:18
     at /home/theia/node_modules/graceful-fs/graceful-fs.js:123:16
     at FSReqWrap.readFileAfterClose [as oncomplete] (internal/fs/read_file_context.js:53:3)

[daimor]

I found a case where such errors happen.

Clear any previous value, how it supposed to work in VSCode.

globalState.update('someKey', undefined); 

After that, any get should return defaultValue, as there are no values supposed to be stored anymore.

globalState.get('someKey', 'defaultValue');

But, it logs an error and returns undefined instead.

Test code

			// Just clear start, completely nothing in globalState, yet
			val = globalState.get('test', "default") || "WTF";

			globalState.update('test1', undefined);
			val1 = globalState.get('test1', "default") || "WTF";

			globalState.update('test2', "somevalue");
			val2 = globalState.get('test2', "default") || "WTF";	

Expected values,

val="default"
val1="default"
val2="somevalue"

but it gets

val1="WTF"

[daimor]

But error with parsing JSON happens due to its emptiness.

[daimor]

After some investigation and a few attempts to solve this issue, I would like to add some notes about it.
The error happens, due to the way how writeFile works in nodejs, when it returns, it does not mean that file is really saved, and data on the disk, it only means that data on the way. But here we also have subsequent readFile, which will fail due to this behavior. In VSCode they extended native fs with their own pfs when they cover some of the issues, as well as confidence that data on the disk. And I'm sure that in Theia would be good to go this way as well.

[tekumara]

Also experiencing this.
Seems to occur whilst the python vscode extension is loading, without succeeding (its stuck in Python extension loading...)
rm ~/.theia/plugin-storage/global-state.json does not resolve the issue.

[marcdumais-work]

I found a case where this problem reproduces relatively frequently: running the browser test suite. When running that suite [1], a new global storage folder is created each time, under the system's temporary folder. This permits always starting fresh and not polluting the local user's global settings.

I think it may be that, with a new global storage, more write operations happen in global-state.json, increasing the risks of hitting the race condition described by @daimor above (thanks BTW for taking time to troubleshoot the issue and sharing your analysis!). In any case, close to the startup of the suite, I see exceptions such as the following relatively frequently:

2023-02-20T15:00:57.449Z root ERROR Failed to parse data from " /tmp/theia-test-config-dir2023120-103955-1mfri5h.wnzp/plugin-storage/global-state.json ". Reason: SyntaxError: /tmp/theia-test-config-dir2023120-103955-1mfri5h.wnzp/plugin-storage/global-state.json: Unexpected token t in JSON at position 687
    at JSON.parse (<anonymous>)
    at /home/lmcmcds/theia/node_modules/fs-extra/node_modules/jsonfile/index.js:33:18
    at /home/lmcmcds/theia/node_modules/graceful-fs/graceful-fs.js:123:16
    at FSReqCallback.readFileAfterClose [as oncomplete] (node:internal/fs/read_file_context:68:3)

I captured the content of global-state.json for a few occurrences, and it looks like it's indeed corrupted:

Note: We do not have the Python extension installed by default, but other extensions seem to be also able to trigger this - perhaps ESLint according to the captured content.

[1] yarn browser test

[paul-marechal]

@marcdumais-work I think the issue you reported mostly comes from https://github.com/eclipse-theia/theia/blob/7971705d4d5fbd381042c0be50892b49b39fd807/packages/plugin-ext/src/main/node/plugins-key-value-storage.ts:

Neither PluginsKeyValueStorage.readFromFile nor PluginsKeyValueStorage.writeToFile are written in a way to avoid concurrent read/write. These methods are mostly called through PluginsKeyValueStorage.get and PluginsKeyValueStorage.set but I don't see what would prevent those methods from being called concurrently?