Make some fixes to logging in PVF subsystem (#6180)

* Log exit status code for workers

* Make log for execute job conclusion match prepare job conclusion

Trace log for conclusion of prepare job:

```rs
gum::debug!(
	target: LOG_TARGET,
	validation_code_hash = ?artifact_id.code_hash,
	?worker,
	?rip,
	"prepare worker concluded",
);
```

Co-authored-by: parity-processbot <>
This commit is contained in:
Marcin S
2022-10-26 11:49:51 -04:00
committed by GitHub
parent d40b31791d
commit d4e3501ec2
3 changed files with 18 additions and 6 deletions
+2 -2
View File
@@ -247,9 +247,9 @@ fn handle_job_finish(
gum::debug!(
target: LOG_TARGET,
validation_code_hash = ?artifact_id.code_hash,
?worker,
worker_rip = idle_worker.is_none(),
?result,
"job finished.",
"execute worker concluded",
);
// First we send the result. It may fail due the other end of the channel being dropped, that's
+1 -1
View File
@@ -129,7 +129,7 @@ impl Executor {
// 2. It cannot and does not limit the stack space consumed by Rust code.
//
// Meaning that if the wasm code leaves no stack space for Rust code, then the Rust code
// and that will abort the process as well.
// will abort and that will abort the process as well.
//
// Typically on Linux the main thread gets the stack size specified by the `ulimit` and
// typically it's configured to 8 MiB. Rust's spawned threads are 2 MiB. OTOH, the
+15 -3
View File
@@ -200,7 +200,7 @@ pub enum SpawnErr {
/// This is a representation of a potentially running worker. Drop it and the process will be killed.
///
/// A worker's handle is also a future that resolves when it's detected that the worker's process
/// has been terminated. Since the worker is running in another process it is obviously not necessarily
/// has been terminated. Since the worker is running in another process it is obviously not necessary
/// to poll this future to make the worker run, it's only for termination detection.
///
/// This future relies on the fact that a child process's stdout `fd` is closed upon it's termination.
@@ -209,6 +209,7 @@ pub struct WorkerHandle {
child: async_process::Child,
#[pin]
stdout: async_process::ChildStdout,
program: PathBuf,
drop_box: Box<[u8]>,
}
@@ -233,6 +234,7 @@ impl WorkerHandle {
Ok(WorkerHandle {
child,
stdout,
program: program.as_ref().to_path_buf(),
// We don't expect the bytes to be ever read. But in case we do, we should not use a buffer
// of a small size, because otherwise if the child process does return any data we will end up
// issuing a syscall for each byte. We also prefer not to do allocate that on the stack, since
@@ -267,9 +269,19 @@ impl futures::Future for WorkerHandle {
cx.waker().wake_by_ref();
Poll::Pending
},
Err(_) => {
Err(err) => {
// The implementation is guaranteed to not to return `WouldBlock` and Interrupted. This
// leaves us with a legit errors which we suppose were due to termination.
// leaves us with legit errors which we suppose were due to termination.
// Log the status code.
gum::debug!(
target: LOG_TARGET,
worker_pid = %me.child.id(),
status_code = ?me.child.try_status(),
"pvf worker ({}): {:?}",
me.program.display(),
err,
);
Poll::Ready(())
},
}