writeFile corrupts data with high frequency requests on same file

[anywhichway]

• Version: v12.13.0
• Platform: 64-bit (Windows 10)
• Subsystem: fs

const fs = require('fs'),
  assert = require('assert')
  file = './foo.json';

const numbers = [];
async function verify() {
	const number = Math.random();
	numbers.push(number);
	await fs.promises.writeFile(file, JSON.stringify({number}), "utf-8");
	const data = JSON.parse(fs.readFileSync(file,"utf-8"));
	// since we await the write and then read synchronously immediately
	// we expect the data to be what was just written
	assert.equal(data.number,number);
	// what is actually experienced is a corrupt file
	// SyntaxError: Unexpected token } in JSON at position 29
	// Modifying the read to be asynchronous will also throw an error
	// but this is expected since another write may have been done before the read.
	// Expected behavior: The file should never be in a partially written state
	// once the writeFile await is resolved. We presume that internally, Node is
	// not truncating the file to the new length prior to resolving the Promise.
}

try {
	fs.unlinkSync(file);
} catch(e) {
	if(e.code!=="ENOENT") {
		throw(e)
	}
}
(async () => {
	for (var i = 0; i < 10; i++) {
		await verify();
	}
	console.log("await loop ok")
})().then(() => {
	const promises = [];
	for (var i = 0; i < 10; i++) {
		promises.push(verify());
	}
	Promise.all(promises)
		.then(() => console.log("no await loop ok"))
		.catch((e) => {
			console.log(numbers);
			console.error(e);
		})
})

Although we have not been able to reproduce it with a small code sample, under high load we have experienced the same corruption when both the write and the read use the fs.promises module and the writes and reads are always awaited with moderate file content sizes, e.g. 1K or less. For now, if we make everything synchronous, we have no issues. This is a big step up from earlier versions of node; however, it obviously has a negative impact on our app overall.

A similar issue is documented here: nodejs/node-v0.x-archive#4965

[jasnell]

If I'm reading this correctly, data corruption should be expected given that multiple concurrent writes are happening against the same file within the context of the Promise.all().

[jasnell]

Closed as this is not a bug in Node.js.

[anywhichway]

@jasnell Actually, I said this in the comments:

"Expected behavior: The file should never be in a partially written state once the writeFile await is resolved."

If await resolves, as in does in the 'verify' function, then the file should be closed and of the correct length for the data written. The promises in the Promise.all are the promises automatically generated because verify is an async function. The Node documentation only says there is risk if the callback is not invoked, i.e. the Promise is not resolved (assuming internally it is using a callback.) "It is unsafe to use fs.writeFile() multiple times on the same file without waiting for the callback."

Additionally, when comparing the use of file descriptors to file names, the following is stated:

"For example, if fs.writeFile() is called twice in a row, first to write the string 'Hello', then to write the string ', World', the file would contain 'Hello, World', and might contain some of the file's original data (depending on the size of the original file, and the position of the file descriptor). If a file name had been used instead of a descriptor, the file would be guaranteed to contain only ', World'."

By implication, I would expect the file to be guaranteed to only contain the last string written.

Finally, the code clearly indicates the file should be truncated. The error being manifested, and extra "{", is an indication the file is not being truncated.

Below is an updated example that includes the use of callbacks:

const fs = require('fs'),
  assert = require('assert')
  file = './foo.json';

const numbers = [];
async function verify() {
	const number = Math.random(),
		flag = fs.O_CREAT|fs.O_SYNC|fs.O_WRONLY|fs.O_TRUNC|fs.O_NONBLOCK;
	numbers.push(number);
	await fs.promises.writeFile(file, JSON.stringify({number}),{flag});
	const data = JSON.parse(fs.readFileSync(file,"utf-8"));
	// since we await the write and then read synchronously immediately
	// we expect the data to be what was just written
	assert.equal(data.number,number);
	// what is actually experienced is a corrupt file
	// SyntaxError: Unexpected token } in JSON at position 29
	// Modifying the read to be asynchronous will also throw an error
	// but this is expected since another write may have been done before the read.
	// Expected behavior: The file should never be in a partially written state
	// once the writeFile await is resolved. We presume that internally, Node is
	// not truncating the file to the new length prior to resolving the Promise.
}

function verifyWithCallback() {
	const number = Math.random(),
		flag = fs.O_CREAT|fs.O_SYNC|fs.O_WRONLY|fs.O_TRUNC|fs.O_NONBLOCK;
	numbers.push(number);
	return new Promise((resolve,reject) => {
		fs.writeFile(file, JSON.stringify({number}),{flag},() => resolve());
	}).then(() => {
		const data = JSON.parse(fs.readFileSync(file,"utf-8"));
		// since the callback to writeFile has been invoked
		// we expect the data to be what was just written
		assert.equal(data.number,number);
		// what is actually experienced is a corrupt file
		// SyntaxError: Unexpected token } in JSON at position 29
	})
}

try {
	fs.unlinkSync(file);
} catch(e) {
	if(e.code!=="ENOENT") {
		throw(e)
	}
}
(async () => {
	for (var i = 0; i < 10; i++) {
		await verify();
	}
	console.log("await loop ok")
})().then(() => {
	const promises = [];
	for (var i = 0; i < 10; i++) {
		promises.push(verify());
	}
	Promise.all(promises)
		.then(() => console.log("no outer await loop ok"))
		.catch((e) => {
			console.log("no outer await loop failed");
			console.log(numbers);
			console.error(e);
		})
}).then(() => {
	const promises = [];
	for (var i = 0; i < 10; i++) {
		promises.push(verifyWithCallback());
	}
	Promise.all(promises)
	.then(() => console.log("callback loop ok"))
	.catch((e) => {
		console.log("callback loop failed")
		console.log(numbers);
		console.error(e);
	})
})

[addaleax]

@anywhichway You’re still starting 10 fs.writeFile() calls concurrently, and that is exactly what the documentation you quoted warns against:

"It is unsafe to use fs.writeFile() multiple times on the same file without waiting for the callback."

If you waited for each verify() or verifyWithCallback() call to finish before starting the next one, this issue should not appear.

Also, side note, but code on Github is usually more readable with syntax highlighting, e.g. ```js instead of ``` for JavaScript :)

[anywhichway]

@addaleax please see the code below (cut from the example), it does wait for the callback, that is what resolves the promise. I do understand that if I await in the outer loop things are fine (my very first example does that). What I am trying to get my head wrapped around is how to get high speed writes invoked by arbitrary clients to not collide with each other without going synchronous.

return new Promise((resolve,reject) => {
		fs.writeFile(file, JSON.stringify({number}),{flag},() => resolve());
	}).then(() => {
		const data = JSON.parse(fs.readFileSync(file,"utf-8"));
		// since the callback to writeFile has been invoked
		// we expect the data to be what was just written
		assert.equal(data.number,number);
		// what is actually experienced is a corrupt file
		// SyntaxError: Unexpected token } in JSON at position 29
	})

The below code using streams is subject to the same issue:

function verifyWithStream() {
	const number = Math.random(),
		wstream = fs.createWriteStream(file);
	numbers.push(number);
	wstream.on("finish", () => {
		const data = JSON.parse(fs.readFileSync(file,"utf-8"));
		//assert.equal(data.number,number);
	})
	wstream.write(JSON.stringify({number,stream:true}))
	wstream.end();
}

There are only two hypotheses I can arrive at given the extra "}". Either Node is opening the file for the next write while the sync read is occurring and manages to get characters in after the reads gets the first few and a new "}" is picked-up at the end before read returns. Or, the write operations are surrendering without truncating the file to the new length and flushing to disk.

If a developer has to understand all of the nesting down to file operations (in code the developer potentially did not write) it will make debugging really hard.

[anywhichway]

@addaleax I realized that there is one other possibility, the way Promises get queued:

Let P1,P2,P3 be promises and T1,T2,T3 be their respective thens.

Option 1:

P1 resolves and the processing of the next promise P2 starts then T1 is invoked

Option 2:

P1 resolves and the processing of T1 is started prior to starting P2.

I realize now that Option 1 is what is occurring because Promises don't actually wait to start. A theoretical complaint a few people have made about Promises.

I will just have to create a queue.

[addaleax]

I realize now that Option 1 is what is occurring because Promises don't actually wait to start.

Yes, that’s probably it – Promises aren’t asynchronous tasks, they represent the results of asynchronous tasks.