There is another case in test_monitor.go [1] that also reports monitor failures. At the moment we support two monitor types. One is global and runs throughout the test without requiring a monitor.Go wrapped function.

So on that note. Could we add an error wrapper a little lower down pkg/roachprod/errors/errors.go? Or is there something preventing this from working / being able to trace it back to a monitor process death?

[1] https://github.com/cockroachdb/cockroach/blob/master/pkg/cmd/roachtest/test_monitor.go#L35

So after seeing the monitor work in debug mode a bit, I thought it might make more sense to wrap the errors returned by Wait, WaitE, and WaitforNodeDeath, as those are the methods that the test author will call and by keeping the error wrapper in the defer of monitorImpl.Go, I'm relying on a panic / fatal happening in the goroutine itself which isn't guaranteed to happen, the test author would have to explicitly make another call to Fatal or panic the goroutine.

So Wait & WaitE will both eventually call wait so I wrapped the error returned by wait.

For the testMonitorImpl, I wrapped the error returned by WaitforNodeDeath. I could also move this to testMonitorImpl.start, my reasoning is just trying to wrap the error at the lowest level possible (same reasoning why i choose wait and not Wait.

Is this what you mean by

Could we add an error wrapper a little lower down

Also interestingly wait does make a call to WaitforNodeDeath so I thought I could get away with just one wrapped error for both the testMonitor and Monitor cases, but

func (m *monitorImpl) wait() error {
	m.startNodeMonitor()
	userErr := m.userGroup.Wait()
	m.cancel() // stop monitoring goroutine
	// By canceling the monitor context above, the goroutines created by
	// `roachprod.Monitor` should terminate the session and close the
	// event channel that the monitoring goroutine is reading from. We
	// wait for that goroutine to return to ensure that we don't leak
	// goroutines after wait() returns.
	monitorErr := m.WaitForNodeDeath()

	return registry.FatalMonitor(errors.Join(userErr, monitorErr))
}

in the case where the Monitor is being used in the roachtest itself (not the one in the test runner that uses testMonitor), the call to m.WaitForNodeDeath doesn't return an error. My understanding is that the error is coming from the userGroup.Wait(), and by calling m.WaitForNodeDeath, that's acting as a "wait for goroutines to cancel after sending the cancel signal", but I don't understand why or how that works. Probably a mechanism of the language / cancel signals / goroutines I don't understand yet, but that is my understanding on why I need to wrap the error in 2 places.

As per conversation here, no longer wrapping the error and will just inspect node artifacts for fatal logs on all failures

I took a look at the sample GItHub issue; and I wonder if it will be possible to add a new section instead of appending it to the existing message?

ex.

failed with ...

....

Fatal entries found in Cockroach logs:

F25...

I also like a new section for better readability. Btw, the sample issue has file path prefix, but I see the latest code strips them, which is the desired output, for brevity.

new format #152540

Failed with:

(monitor.go:267).Wait: monitor failure: dial tcp 127.0.0.1:29000: connect: connection refused
test artifacts and logs in: artifacts/roachtest/manual/monitor/test-failure/node-fatal-explicit-monitor/cpu_arch=arm64/run_1

Fatal entries found in Cockroach logs:

F250826 19:49:07.194443 3106 sql/sem/builtins/builtins.go:6063 ⋮ [T1,Vsystem,n1,client=127.0.0.1:54552,hostssl,user=‹roachprod›] 250  force_log_fatal(): ‹oops›
F250826 19:49:07.194443 3106 sql/sem/builtins/builtins.go:6063 ⋮ [T1,Vsystem,n1,client=127.0.0.1:54552,hostssl,user=‹roachprod›] 250 !goroutine 3106 [running]:
F250826 19:49:07.194443 3106 sql/sem/builtins/builtins.go:6063 ⋮ [T1,Vsystem,n1,client=127.0.0.1:54552,hostssl,user=‹roachprod›] 250 !github.com/cockroachdb/cockroach/pkg/util/allstacks.GetWithBuf({0x0?, 0x1021c7af8?, 0x38?})
F250826 19:49:07.194443 3106 sql/sem/builtins/builtins.go:6063 ⋮ [T1,Vsystem,n1,client=127.0.0.1:54552,hostssl,user=‹roachprod›] 250 !	pkg/util/allstacks/allstacks.go:31 +0x70
F250826 19:49:07.194443 3106 sql/sem/builtins/builtins.go:6063 ⋮ [T1,Vsystem,n1,client=127.0.0.1:54552,hostssl,user=‹roachprod›] 250 !github.com/cockroachdb/cockroach/pkg/util/allstacks.Get(...)
F250826 19:49:07.194443 3106 sql/sem/builtins/builtins.go:6063 ⋮ [T1,Vsystem,n1,client=127.0.0.1:54552,hostssl,user=‹roachprod›] 250 !	pkg/util/allstacks/allstacks.go:18
F250826 19:49:07.194443 3106 sql/sem/builtins/builtins.go:6063 ⋮ [T1,Vsystem,n1,client=127.0.0.1:54552,hostssl,user=‹roachprod›] 250 !github.com/cockroachdb/cockroach/pkg/util/log.(*loggerT).outputLogEntry(_, {{{0x1400201e8d0, 0x24}, {0x1076db81f, 0x1}, {0x1076db81f, 0x1}, {0x1075f672c, 0x6}, {0x1076db81f, ...}}, ...})
F250826 19:49:07.194443 3106 sql/sem/builtins/builtins.go:6063 ⋮ [T1,Vsystem,n1,client=127.0.0.1:54552,hostssl,user=‹roachprod›] 250 !	pkg/util/log/clog.go:294 +0xb0
F250826 19:49:07.194443 3106 sql/sem/builtins/builtins.go:6063 ⋮ [T1,Vsystem,n1,client=127.0.0.1:54552,hostssl,user=‹roachprod›] 250 !github.com/cockroachdb/cockroach/pkg/util/log.logfDepthInternal({0x109736b18, 0x1401134ed20}, 0x2, 0x4, 0x0, 0x0?, {0x10765823d, 0x15}, {0x1401148ada8, 0x1, ...})
F250826 19:49:07.194443 3106 sql/sem/builtins/builtins.go:6063 ⋮ [T1,Vsystem,n1,client=127.0.0.1:54552,hostssl,user=‹roachprod›] 250 !	pkg/util/log/channels.go:104 +0x44c

It might be helpful for readability to move all the logic in this else if branch to a new function. Preferably we try to avoid else if statements, if we can, in favour of early returns. So you could in the new function to handle the logic of extracting fatals from logs add a function parameter timedOut and do an early return with a comment saying we opt out if the test timed out.

Moved to a new inspectArtifacts function that is called after teardownTest. Also adjusted the logic to favor early returns.

Talked a bit about the logging on the call, but I still was unsure where to send the logs of inspectArtifacts. I think the fatal node logs if found should forsure go to test.log because that's the most visable log / where people look first (my assumption). But I have some additional logging that provides context / would be great if had some sort of "debug" level log i.e. the log where i write the command used is pretty bulky and I opted to put that one in the test-teardown.log (confusing but it's like multiple lines long).

tl;dr i'm still logging to 2 places in the new inspectArtifacts function, I don't love it, but personally I tend to opt for verbosity so I like having the logs vs not having them at all even if their location(s) is a bit confusing

Also added a TODO here https://github.com/cockroachdb/cockroach/pull/151850/files#diff-1e3ec1fc5bade2df4b8681c44959be2a390f703839f30a979da98f963769c9fcR1498
to capture some of the log ambiguity

I noticed the output of the sample issue contains the full path for each entry, I wonder if we could trim it to only have the node number / log file path?

Trimmed the entire path, I couldn't think of an easy way of preserving the node number without adding a fair bit of string parsing logic and even then, the log would look something like which I think would be a bit confusing because if a user went to go search for that entire string (to see the entire output), they wouldn't be able to find it because that Node 1: was artificially added. I feel like the convenience of seeing the node number isn't worth that, but I don't feel strongly either way. Either way, it is more readable trimmed.

Node 1: F250822 06:43:24.899885 3119 sql/sem/builtins/builtins.go:6063 ⋮ [T1,Vsystem,n1,client=127.0.0.1:57720,hostssl,user=‹roachprod›] 248  force_log_fatal(): ‹oops›

Before

monitor/cpu_arch=arm64/run_1/logs/unredacted/cockroach.Mac.wchoe.2025-08-22T06_09_20Z.048229.log:F250822 06:09:22.816982 3127 sql/sem/builtins/builtins.go:6063 ⋮ [T1,Vsystem,n1,client=127.0.0.1:56933,hostssl,user=‹roachprod›] 248 force_log_fatal(): ‹oops› 
artifacts/roachtest/manual/monitor/test-failure/node-fatal-explicit-monitor/cpu_arch=arm64/run_1/logs/unredacted/cockroach.Mac.wchoe.2025-08-22T06_09_20Z.048229.log:F250822 06:09:22.816982 3127 sql/sem/builtins/builtins.go:6063 ⋮ [T1,Vsystem,n1,client=127.0.0.1:56933,hostssl,user=‹roachprod›] 248 !goroutine 3127 [running]: 
artifacts/roachtest/manual/monitor/test-failure/node-fatal-explicit-monitor/cpu_arch=arm64/run_1/logs/unredacted/cockroach.Mac.wchoe.2025-08-22T06_09_20Z.048229.log:F250822 06:09:22.816982 3127 sql/sem/builtins/builtins.go:6063 ⋮ [T1,Vsystem,n1,client=127.0.0.1:56933,hostssl,user=‹roachprod›] 248 !github.com/cockroachdb/cockroach/pkg/util/allstacks.GetWithBuf({0x0?, 0x10214baf8?, 0x38?})

After

F250822 06:43:24.899885 3119 sql/sem/builtins/builtins.go:6063 ⋮ [T1,Vsystem,n1,client=127.0.0.1:57720,hostssl,user=‹roachprod›] 248  force_log_fatal(): ‹oops›
F250822 06:43:24.899885 3119 sql/sem/builtins/builtins.go:6063 ⋮ [T1,Vsystem,n1,client=127.0.0.1:57720,hostssl,user=‹roachprod›] 248 !goroutine 3119 [running]:
F250822 06:43:24.899885 3119 sql/sem/builtins/builtins.go:6063 ⋮ [T1,Vsystem,n1,client=127.0.0.1:57720,hostssl,user=‹roachprod›] 248 !github.com/cockroachdb/cockroach/pkg/util/allstacks.GetWithBuf({0x0?, 0x104be7af8?, 0x38?})

I wonder if we should move the fatal log level extraction to rather be a post step after r.teardownTest. It doesn't entirely logically fit that methods intention, but we needed to wait for artifact collection. Which should also be done after a return from this method.

addressed in above comment

Nit: since Go is a statically-typed language, the suffix is redundant; i.e., we know the type of n1 is *gosql.DB.

Nit: could be folded into a single function, parameterized by the bool monitored flag; the boilerplate is virtually the same modulo m.Go ... m.Wait.

Since this is a new message type, methinks we could augment our existing data-driven tests (see TestCreatePostRequest) with a new test. This way we can preview the markdown (before rendering) as well as catch any undesired, future format changes.

will take a look

added

Nit: timedOut is superfluous as an argument to inspectArtifacts.

misread that if statement, thought we weren't downloading artifacts if we timed out, removing from inspectArtifacts

It's not immediately clear why we abort here. In future, you could envision inspectArtifacts being extended to collect other types of errors, not only fatals. Thus, the comment could be made more precise to indicate what it's currently doing.

got it, makes sense, i can do the opposite boolean check and wrap the following logic in an if i.e.

if failuresMatchingError(t.failures(), &errMonitor) {...}

On second thought, what if an unmonitored node panics? I'm not sure we can guarantee that every test invocation uses a Monitor. Out of extra caution, perhaps we should make inspectArtifacts agnostic to the type of failure; i.e., if a test failed, always run inspectArtifacts?

Had a similar thought as well.
Then it's just a trade off between doing this grep for every test failure instead of a smaller selection of tests. So a failed test's execution time would go up a bit. I think previously I was more concerned about this when I thought i'd have to do a download or some other network call before realizing we already fetch and zip the logs for all test failures.

If we do that, then should we keep the monitor error type? Nice to have, I think having more well defined error types would be nice besides the Errorwith/withoutOwner and i think there's Transient as well, but there's no direct need.

Maybe taking it out for now, and putting it in some design docs for test framework error types would be best?

So a failed test's execution time would go up a bit

Not by more than a few seconds, right? To be safe, you could generously bound the execution by say 5 minutes; see FetchDebugZip for an example.

If we do that, then should we keep the monitor error type?

Don't see why. If a need arises, we can alway resurrect it later.

This will match other unrelated things like cockroach.stdout.log and cockroach-health.log. It seems okay to expand the search radius, but probably worth adding a comment to clarify the glob expression.

We should also add -a. I believe I've seen cases where cockroach.log had non-ascii chars.

What if we used %q instead? Do we still need the above comment?

i'll try %q and no it's not needed, i just personally got tripped up on that detail so just added the comment but i can take it out

The command should be executed (remotely) on all cluster nodes, not locally; the latter works only in local-mode.
It would also help (readability) to group the fatal message by node id.

Design
Initially wanted to run grep on each node via Cluster.RunE() and then return those results back to the test runner, but because by the time we are in the monitor defer block, the cancel context signal has already been sent so Cluster.RunE() is unable to run.

From above, basically couldn't get it to work using Cluster.RunE(), not 100% sure the exact reason my best guess is the context cancel signal being sent

Manually verified local single node cluster, local multi node cluster, remote single node cluster, remote multi node cluster.

Works with remote because we will always download the artifacts if there's a test failure (except for timeout).

Works with remote because we will always download the artifacts if there's a test failure (except for timeout).

Ah, I totally forgot. In fairness, that's a hidden assumption, so we should explicitly comment why this works.

What is testLogger as opposed to t.L()?

At that point, t.L() returns test-teardown.log. I wanted to write the log message that we found a Fatal to test.log though. In general the switch to test.log to test-teardown.log is confusing because yes I can see separating teardown ops / msgs into it's own log, but after teardownTest, in the defer of run_test, we're still writing out to test.log even though we're in the "post test" stage at this point. I wrote a TODO to capture that. Personally I feel like ripping out test-teardown.log would be simpler to me given this back and forth that already exists.

Line 1498

	// From now on, all logging goes to test-teardown.log to give a clear separation between
	// operations originating from the test vs the harness. The only error that can originate here
	// is from artifact collection, which is best effort and for which we do not fail the test.
	// TODO(wchoe): improve log destination consistency, above comment doesn't take deferred calls into account
	// testRunner.runTest's deferred calls write to the original test.log, not test-teardown.log
	// and the deferred calls aren't necessarily related to test teardown so the
	// correct log to write to is ambiguous
	replaceLogger("test-teardown")
	if err := r.teardownTest(ctx, t, c, timedOut); err != nil {
		l.PrintfCtx(ctx, "error during test teardown: %v; see test-teardown.log for details", err)
	}
	if err := r.inspectArtifacts(ctx, t, l); err != nil {
		// inspect artifacts and potentially add helpful triage information for failed tests
		l.PrintfCtx(ctx, "error during artifact inspection: %v", err)
	}

Looks like i'm writing to both test.log and test-teardown.log to respect the attempt at separating messages the current approach takes, and yes i agree it's confusing. But i do feel like the fatal log message should be logged in test.log instead of test-teardown.log

At that point, t.L() returns test-teardown.log

Right, I saw that. But inside inspectArtifacts, it becomes a "hidden" assumption; we need a comment to remind the reader why t.L() is different; otherwise, it's confusing.

I think we need some unit tests and examples of what this matches and doesn't match; it's not very human-readable.

added a datadriven test here https://github.com/cockroachdb/cockroach/pull/151850/files/8703f3c6cc49b150c096b6519b9496637d0161bb#diff-b2032c52729cef2b35246db8d577020d59a1d464edc7898c5dff3bf00f1acf44R1

just did 1 example, should i add something else?

I think that should suffice. Removing the optional \r would simplify it; none of the preceding regexes handle, and it's reasonably safe to assume these logs aren't coming from windows.