perf(ngcc): allow immediately reporting a stale lock file (#37250)

Currently, if an ngcc process is killed in a manner that it doesn't clean
up its lock file (or is killed too quickly) the compiler reports that it
is waiting on the PID of a process that doesn't exist, and that it will
wait up to a maximum of N seconds. This PR updates the locking code to
additionally check if the process exists, and if it does not it will
immediately bail out, and print the location of the lock file so a user
may clean it up.

PR Close #37250
This commit is contained in:
Terence D. Honles 2020-05-21 21:25:00 -07:00 committed by Matias Niemelä
parent 4414be77c4
commit 561c0f81a0
2 changed files with 104 additions and 10 deletions

View File

@ -56,22 +56,68 @@ export class AsyncLocker {
pid = newPid; pid = newPid;
} }
if (attempts === 0) { if (attempts === 0) {
this.logger.info( // Check to see if the process identified by the PID is still running. Because the
// process *should* clean up after itself, we only check for a stale lock file when the
// PID changes and only once. This may mean you have to wait if the process is killed
// after the first check and isn't given the chance to clean up after itself.
if (!this.isProcessRunning(pid)) {
// try to re-lock one last time in case there was a race condition checking the process.
try {
return this.lockFile.write();
} catch (e2) {
if (e2.code !== 'EEXIST') {
throw e2;
}
}
// finally check that the lock was held by the same process this whole time.
const finalPid = this.lockFile.read();
if (finalPid === pid) {
throw new TimeoutError(this.lockFileMessage(
`Lock found, but no process with PID ${pid} seems to be running.`));
} else {
// attempts is still 0, but adjust the PID so the message below is correct.
pid = finalPid;
}
}
this.logger.info(this.lockFileMessage(
`Another process, with id ${pid}, is currently running ngcc.\n` + `Another process, with id ${pid}, is currently running ngcc.\n` +
`Waiting up to ${this.retryDelay * this.retryAttempts / 1000}s for it to finish.\n` + `Waiting up to ${this.retryDelay * this.retryAttempts / 1000}s for it to finish.`));
`(If you are sure no ngcc process is running then you should delete the lock-file at ${
this.lockFile.path}.)`);
} }
// The file is still locked by another process so wait for a bit and retry // The file is still locked by another process so wait for a bit and retry
await new Promise(resolve => setTimeout(resolve, this.retryDelay)); await new Promise(resolve => setTimeout(resolve, this.retryDelay));
} }
} }
// If we fall out of the loop then we ran out of rety attempts // If we fall out of the loop then we ran out of rety attempts
throw new TimeoutError( throw new TimeoutError(this.lockFileMessage(`Timed out waiting ${
`Timed out waiting ${ this.retryAttempts * this.retryDelay /
this.retryAttempts * this.retryDelay / 1000}s for another ngcc process, with id ${pid}, to complete.`));
1000}s for another ngcc process, with id ${pid}, to complete.\n` + }
`(If you are sure no ngcc process is running then you should delete the lock-file at ${
this.lockFile.path}.)`); protected isProcessRunning(pid: string): boolean {
// let the normal logic run if this is not called with a valid PID
if (isNaN(+pid)) {
this.logger.debug(`Cannot check if invalid PID "${pid}" is running, a number is expected.`);
return true;
}
try {
process.kill(+pid, 0);
return true;
} catch (e) {
// If the process doesn't exist ESRCH will be thrown, if the error is not that, throw it.
if (e.code !== 'ESRCH') {
throw e;
}
return false;
}
}
private lockFileMessage(message: string): string {
return message +
`\n(If you are sure no ngcc process is running then you should delete the lock-file at ${
this.lockFile.path}.)`;
} }
} }

View File

@ -71,6 +71,7 @@ runInEachFileSystem(() => {
} }
return lockFileContents; return lockFileContents;
}); });
spyOn(process, 'kill').and.returnValue();
const promise = locker.lock(async () => log.push('fn()')); const promise = locker.lock(async () => log.push('fn()'));
// The lock is now waiting on the lock-file becoming free, so no `fn()` in the log. // The lock is now waiting on the lock-file becoming free, so no `fn()` in the log.
@ -80,6 +81,7 @@ runInEachFileSystem(() => {
`(If you are sure no ngcc process is running then you should delete the lock-file at ${ `(If you are sure no ngcc process is running then you should delete the lock-file at ${
lockFile.path}.)` lockFile.path}.)`
]]); ]]);
expect(process.kill).toHaveBeenCalledWith(188, 0);
lockFileContents = null; lockFileContents = null;
// The lock-file has been removed, so we can create our own lock-file, call `fn()` and then // The lock-file has been removed, so we can create our own lock-file, call `fn()` and then
@ -88,6 +90,47 @@ runInEachFileSystem(() => {
expect(log).toEqual(['write()', 'read() => 188', 'write()', 'fn()', 'remove()']); expect(log).toEqual(['write()', 'read() => 188', 'write()', 'fn()', 'remove()']);
}); });
it('should fail fast when waiting on a dead process', async () => {
const fs = getFileSystem();
const log: string[] = [];
const lockFile = new MockLockFile(fs, log);
const logger = new MockLogger();
const locker = new AsyncLocker(lockFile, logger, 100, 10);
let lockFileContents: string|null = '188';
spyOn(lockFile, 'write').and.callFake(() => {
log.push('write()');
if (lockFileContents) {
throw {code: 'EEXIST'};
}
});
spyOn(lockFile, 'read').and.callFake(() => {
log.push('read() => ' + lockFileContents);
if (lockFileContents === null) {
throw {code: 'ENOENT'};
}
return lockFileContents;
});
spyOn(process, 'kill').and.callFake(() => {
throw {code: 'ESRCH'};
});
const promise = locker.lock(async () => log.push('fn()'));
// The lock has already failed so no `fn()` in the log.
expect(log).toEqual(['write()', 'read() => 188', 'write()', 'read() => 188']);
expect(logger.logs.info).toEqual([]);
expect(process.kill).toHaveBeenCalledWith(188, 0);
// Check that a missing process errors out.
let error: Error;
await promise.catch(e => error = e);
expect(log).toEqual(['write()', 'read() => 188', 'write()', 'read() => 188']);
expect(error!.message)
.toEqual(
`Lock found, but no process with PID 188 seems to be running.\n` +
`(If you are sure no ngcc process is running then you should delete the lock-file at ${
lockFile.path}.)`);
});
it('should extend the retry timeout if the other process locking the file changes', async () => { it('should extend the retry timeout if the other process locking the file changes', async () => {
const fs = getFileSystem(); const fs = getFileSystem();
const log: string[] = []; const log: string[] = [];
@ -109,6 +152,7 @@ runInEachFileSystem(() => {
} }
return lockFileContents; return lockFileContents;
}); });
spyOn(process, 'kill').and.returnValue();
const promise = locker.lock(async () => log.push('fn()')); const promise = locker.lock(async () => log.push('fn()'));
// The lock is now waiting on the lock-file becoming free, so no `fn()` in the log. // The lock is now waiting on the lock-file becoming free, so no `fn()` in the log.
@ -118,6 +162,7 @@ runInEachFileSystem(() => {
`(If you are sure no ngcc process is running then you should delete the lock-file at ${ `(If you are sure no ngcc process is running then you should delete the lock-file at ${
lockFile.path}.)` lockFile.path}.)`
]]); ]]);
expect(process.kill).toHaveBeenCalledWith(188, 0);
lockFileContents = '444'; lockFileContents = '444';
// The lock-file has been taken over by another process - wait for the next attempt // The lock-file has been taken over by another process - wait for the next attempt
@ -131,6 +176,7 @@ runInEachFileSystem(() => {
`(If you are sure no ngcc process is running then you should delete the lock-file at ${ `(If you are sure no ngcc process is running then you should delete the lock-file at ${
lockFile.path}.)`] lockFile.path}.)`]
]); ]);
expect(process.kill).toHaveBeenCalledWith(444, 0);
lockFileContents = null; lockFileContents = null;
// The lock-file has been removed, so we can create our own lock-file, call `fn()` and // The lock-file has been removed, so we can create our own lock-file, call `fn()` and
@ -163,11 +209,13 @@ runInEachFileSystem(() => {
} }
return lockFileContents; return lockFileContents;
}); });
spyOn(process, 'kill').and.returnValue();
const promise = locker.lock(async () => log.push('fn()')); const promise = locker.lock(async () => log.push('fn()'));
// The lock is now waiting on the lock-file becoming free, so no `fn()` in the log. // The lock is now waiting on the lock-file becoming free, so no `fn()` in the log.
expect(log).toEqual(['write()', 'read() => 188']); expect(log).toEqual(['write()', 'read() => 188']);
expect(process.kill).toHaveBeenCalledWith(188, 0);
// Do not remove the lock-file and let the call to `lock()` timeout. // Do not remove the lock-file and let the call to `lock()` timeout.
let error: Error; let error: Error;
await promise.catch(e => error = e); await promise.catch(e => error = e);