Skip to content

Commit 1178547

Browse files
ctruedenclaude
andcommitted
Send build and script output to SciJava task logs
Build tool output goes to the build task's logger, and a script's stdout, stderr, task.update messages and failure traceback go to its run task's logger, so that the task monitor can show them. Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
1 parent 6ce1696 commit 1178547

6 files changed

Lines changed: 195 additions & 11 deletions

File tree

‎GAPS.md‎

Lines changed: 11 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -115,6 +115,17 @@ Because stderr is read separately from stdout, the wrapper writes a unique
115115
end-marker line to stderr, and the engine waits up to 2 s for it before
116116
returning, so that late stderr lines are not lost or misattributed.
117117

118+
The same lines, plus `task.update` messages and the traceback of a failed
119+
run, also go to the run's SciJava task logger (`Task#log()`), and a
120+
build's tool output goes to the build task's logger. The task monitor's log
121+
window shows them.
122+
123+
**Tradeoff:** Task loggers retain nothing, so the log window shows only what
124+
is logged after it is opened. And since the task monitor drops tasks as soon
125+
as they finish, a build that fails quickly cannot have its log opened at
126+
all; its error message is the
127+
only record. If this proves annoying, `DefaultTask` could keep a history.
128+
118129
**Fragile because:** The whole mechanism depends on debug message formats,
119130
which are not API. Appose core should offer structured stdout/stderr
120131
callbacks on `Service`, ideally tagged by task (see

‎pom.xml‎

Lines changed: 3 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -91,6 +91,9 @@
9191

9292
<appose.version>0.12.0</appose.version>
9393
<imglib2-appose.version>0.9.0</imglib2-appose.version>
94+
95+
<!-- TEMP: for Task#log(); drop once propagated to pom-scijava. -->
96+
<scijava-common.version>2.101.0</scijava-common.version>
9497
</properties>
9598

9699
<dependencies>

‎src/main/java/org/scijava/plugins/scripting/appose/python/ApposePythonScriptEngine.java‎

Lines changed: 18 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -67,6 +67,7 @@
6767
import org.scijava.app.StatusService;
6868
import org.scijava.convert.ConvertService;
6969
import org.scijava.log.LogService;
70+
import org.scijava.log.Logger;
7071
import org.scijava.module.ModuleItem;
7172
import org.scijava.plugin.Parameter;
7273
import org.scijava.plugins.scripting.appose.python._internal.ResidentWorker;
@@ -254,6 +255,7 @@ private Object runTask(final ResidentWorker worker,
254255
});
255256
progress = SciJavaTasks.track(taskService, statusService, "Running " +
256257
scriptName(info), task, worker::kill);
258+
if (progress != null) forwarder.taskLog = progress.log();
257259
try {
258260
task.waitFor();
259261
}
@@ -281,6 +283,7 @@ private Object runTask(final ResidentWorker worker,
281283
// which would say the worker crashed if it had to be stopped.
282284
throw new ScriptException("Python script canceled");
283285
}
286+
if (progress != null) progress.log().error(e.getMessage());
284287
throw scriptException("Python script failed: " + e.getMessage(), e);
285288
}
286289
catch (final InterruptedException e) {
@@ -309,7 +312,8 @@ private static String scriptName(final ScriptInfo info) {
309312

310313
/**
311314
* Forwards the worker process's stdout (other than Appose protocol
312-
* messages) and stderr to the script context's writers.
315+
* messages) and stderr to the script context's writers, and to the run's
316+
* task logger, if any.
313317
* <p>
314318
* Note: This relies on the format of Appose's debug messages: stderr lines
315319
* arrive as {@code [WORKER-n] line} and non-protocol stdout lines as
@@ -326,6 +330,9 @@ private class OutputForwarder implements Consumer<String> {
326330
"]";
327331
private final CountDownLatch ended = new CountDownLatch(1);
328332

333+
/** Logger of the run's SciJava task, if any. */
334+
private volatile Logger taskLog;
335+
329336
@Override
330337
public void accept(final String message) {
331338
final int end = message.indexOf("] ");
@@ -334,13 +341,21 @@ public void accept(final String message) {
334341
final String line = message.substring(end + 2);
335342
if (prefix.startsWith("[WORKER-")) {
336343
if (line.equals(endMarker)) ended.countDown();
337-
else writeLine(getContext().getErrorWriter(), line);
344+
else output(getContext().getErrorWriter(), line);
338345
}
339346
else if (prefix.startsWith("[SERVICE-") && line.startsWith("<INVALID> ")) {
340-
writeLine(getContext().getWriter(), line.substring(10));
347+
output(getContext().getWriter(), line.substring(10));
341348
}
342349
}
343350

351+
private void output(final Writer writer, final String line) {
352+
writeLine(writer, line);
353+
// Note: Info level for stderr too, since Python writes ordinary
354+
// output there as well, e.g. via the logging module.
355+
final Logger logger = taskLog;
356+
if (logger != null) logger.info(line);
357+
}
358+
344359
/** Waits until the wrapper script's stderr output has all arrived. */
345360
private void awaitEnd() throws InterruptedException {
346361
ended.await(OUTPUT_DRAIN_MILLIS, TimeUnit.MILLISECONDS);

‎src/main/java/org/scijava/plugins/scripting/appose/python/_internal/SciJavaTasks.java‎

Lines changed: 25 additions & 7 deletions
Original file line numberDiff line numberDiff line change
@@ -60,7 +60,8 @@ private SciJavaTasks() {
6060

6161
/**
6262
* Creates a {@link BuildListener} that shows each environment build as a
63-
* SciJava task of its own, and logs the build tool's output at debug level.
63+
* SciJava task of its own. The build tool's output goes to the task's
64+
* logger, and to the application log at debug level.
6465
* <p>
6566
* A build gets its own task, rather than borrowing that of the run which
6667
* needs it, because a build can take minutes: a run stuck at 0% for that
@@ -107,21 +108,30 @@ public void buildProgress(final String envName, final String title,
107108

108109
@Override
109110
public void buildOutput(final String envName, final String text) {
110-
if (log != null) log.debug(text.trim());
111+
output(envName, text);
111112
}
112113

113114
@Override
114115
public void buildError(final String envName, final String text) {
115-
// Note: Not log.error! Build tools write ordinary status to stderr.
116-
if (log != null) log.debug(text.trim());
116+
// Note: Not error level! Build tools write ordinary status to stderr.
117+
output(envName, text);
118+
}
119+
120+
private void output(final String envName, final String text) {
121+
final String line = chomp(text);
122+
if (log != null) log.debug(line);
123+
final Task task = building.get(envName);
124+
if (task != null) task.log().info(line);
117125
}
118126

119127
@Override
120128
public void buildFinished(final String envName, final Throwable error) {
121129
final Task task = building.remove(envName);
122130
if (task != null) {
123-
if (error != null) task.setStatusMessage("Failed: " + error
124-
.getMessage());
131+
if (error != null) {
132+
task.setStatusMessage("Failed: " + error.getMessage());
133+
task.log().error("Build failed", error);
134+
}
125135
task.finish();
126136
}
127137
if (status != null) status.clearStatus();
@@ -163,7 +173,10 @@ public static Task track(final TaskService tasks, final StatusService status,
163173
if (event.responseType.isTerminal()) finished.set(true);
164174
if (event.responseType != ResponseType.UPDATE) return;
165175
if (task != null) {
166-
if (event.message != null) task.setStatusMessage(event.message);
176+
if (event.message != null) {
177+
task.setStatusMessage(event.message);
178+
task.log().info(event.message);
179+
}
167180
task.setProgressValue(event.current);
168181
task.setProgressMaximum(event.maximum);
169182
}
@@ -194,4 +207,9 @@ public static Task track(final TaskService tasks, final StatusService status,
194207
task.start();
195208
return task;
196209
}
210+
211+
/** Strips trailing line breaks, keeping any indentation. */
212+
private static String chomp(final String text) {
213+
return text.replaceAll("[\\r\\n]+$", "");
214+
}
197215
}

‎src/test/java/org/scijava/plugins/scripting/appose/python/ApposePythonIntegrationTest.java‎

Lines changed: 34 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -43,10 +43,13 @@
4343
import java.net.URISyntaxException;
4444
import java.nio.charset.StandardCharsets;
4545
import java.nio.file.Files;
46+
import java.util.ArrayList;
47+
import java.util.Collections;
4648
import java.util.HashMap;
4749
import java.util.List;
4850
import java.util.Map;
4951
import java.util.concurrent.ConcurrentHashMap;
52+
import java.util.concurrent.CopyOnWriteArrayList;
5053
import java.util.concurrent.Future;
5154
import java.util.concurrent.TimeUnit;
5255

@@ -63,6 +66,8 @@
6366
import org.scijava.Context;
6467
import org.scijava.event.EventHandler;
6568
import org.scijava.event.EventService;
69+
import org.scijava.log.LogLevel;
70+
import org.scijava.log.LogMessage;
6671
import org.scijava.module.ModuleService;
6772
import org.scijava.plugins.scripting.appose.python._internal.SciJavaTasks;
6873
import org.scijava.script.ScriptInfo;
@@ -176,6 +181,11 @@ public void testPrintAndStderr() throws Exception {
176181
"print('to stderr', file=sys.stderr)\n", new HashMap<>());
177182
assertTrue(out.toString(), out.toString().contains("to stdout"));
178183
assertTrue(err.toString(), err.toString().contains("to stderr"));
184+
185+
// The output also goes to the run's task log.
186+
final List<String> lines = tasks.log("Running print.py", LogLevel.INFO);
187+
assertTrue(lines.toString(), lines.contains("to stdout"));
188+
assertTrue(lines.toString(), lines.contains("to stderr"));
179189
}
180190

181191
@Test
@@ -189,6 +199,10 @@ public void testErrorReportsScriptLine() throws Exception {
189199
assertTrue(error, error.contains(new File(scriptDir, "failing.py").getPath()));
190200
assertTrue(error, error.contains("line 5"));
191201
assertNull(module.getOutput("x"));
202+
203+
final List<String> errors = tasks.log("Running failing.py", LogLevel.ERROR);
204+
assertEquals(1, errors.size());
205+
assertTrue(errors.get(0), errors.get(0).contains("ValueError: boom"));
192206
}
193207

194208
@Test
@@ -260,6 +274,8 @@ public void testRunIsSciJavaTask() throws Exception {
260274
assertNotNull(task);
261275
assertTrue(task.isDone());
262276
assertEquals(2, task.getProgressMaximum());
277+
assertEquals(Collections.singletonList("halfway"), tasks.log(
278+
"Running tracked.py", LogLevel.INFO));
263279
}
264280

265281
@Test
@@ -331,16 +347,33 @@ private ScriptModule module(final String name, final String script)
331347
public static class TaskRecorder {
332348

333349
private final Map<String, Task> tasks = new ConcurrentHashMap<>();
350+
private final Map<Task, List<LogMessage>> logs = new ConcurrentHashMap<>();
334351

335352
@EventHandler
336353
public void onEvent(final TaskEvent event) {
337-
tasks.put(event.getTask().getName(), event.getTask());
354+
final Task task = event.getTask();
355+
tasks.put(task.getName(), task);
356+
// Note: A task's first event arrives before it produces any output.
357+
logs.computeIfAbsent(task, t -> {
358+
final List<LogMessage> messages = new CopyOnWriteArrayList<>();
359+
t.log().addLogListener(messages::add);
360+
return messages;
361+
});
338362
}
339363

340364
public Task find(final String name) {
341365
return tasks.get(name);
342366
}
343367

368+
/** Gets the lines logged to the named task at the given level. */
369+
public List<String> log(final String name, final int level) {
370+
final List<String> lines = new ArrayList<>();
371+
for (final LogMessage message : logs.get(find(name))) {
372+
if (message.level() == level) lines.add(message.text());
373+
}
374+
return lines;
375+
}
376+
344377
public Task await(final String name) throws InterruptedException {
345378
final long deadline = System.currentTimeMillis() + 10000;
346379
while (System.currentTimeMillis() < deadline) {
Lines changed: 104 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,104 @@
1+
/*
2+
* #%L
3+
* Python scripting language plugin backed by Appose.
4+
* %%
5+
* Copyright (C) 2026 SciJava developers.
6+
* %%
7+
* Redistribution and use in source and binary forms, with or without
8+
* modification, are permitted provided that the following conditions are met:
9+
*
10+
* 1. Redistributions of source code must retain the above copyright notice,
11+
* this list of conditions and the following disclaimer.
12+
* 2. Redistributions in binary form must reproduce the above copyright notice,
13+
* this list of conditions and the following disclaimer in the documentation
14+
* and/or other materials provided with the distribution.
15+
*
16+
* THIS SOFTWARE IS PROVIDED BY THE COPYRIGHT HOLDERS AND CONTRIBUTORS "AS IS"
17+
* AND ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO, THE
18+
* IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR PURPOSE
19+
* ARE DISCLAIMED. IN NO EVENT SHALL THE COPYRIGHT HOLDERS OR CONTRIBUTORS BE
20+
* LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL, SPECIAL, EXEMPLARY, OR
21+
* CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT LIMITED TO, PROCUREMENT OF
22+
* SUBSTITUTE GOODS OR SERVICES; LOSS OF USE, DATA, OR PROFITS; OR BUSINESS
23+
* INTERRUPTION) HOWEVER CAUSED AND ON ANY THEORY OF LIABILITY, WHETHER IN
24+
* CONTRACT, STRICT LIABILITY, OR TORT (INCLUDING NEGLIGENCE OR OTHERWISE)
25+
* ARISING IN ANY WAY OUT OF THE USE OF THIS SOFTWARE, EVEN IF ADVISED OF THE
26+
* POSSIBILITY OF SUCH DAMAGE.
27+
* #L%
28+
*/
29+
30+
31+
package org.scijava.plugins.scripting.appose.python._internal;
32+
33+
import static org.junit.Assert.assertEquals;
34+
import static org.junit.Assert.assertNotNull;
35+
import static org.junit.Assert.assertSame;
36+
import static org.junit.Assert.assertTrue;
37+
38+
import java.util.List;
39+
import java.util.concurrent.CopyOnWriteArrayList;
40+
41+
import org.junit.After;
42+
import org.junit.Before;
43+
import org.junit.Test;
44+
import org.scijava.Context;
45+
import org.scijava.event.EventHandler;
46+
import org.scijava.event.EventService;
47+
import org.scijava.log.LogLevel;
48+
import org.scijava.log.LogMessage;
49+
import org.scijava.task.Task;
50+
import org.scijava.task.TaskService;
51+
import org.scijava.task.event.TaskEvent;
52+
53+
/**
54+
* Tests {@link SciJavaTasks}.
55+
*
56+
* @author Curtis Rueden
57+
*/
58+
public class SciJavaTasksTest {
59+
60+
private Context context;
61+
private final List<LogMessage> messages = new CopyOnWriteArrayList<>();
62+
private Task buildTask;
63+
64+
@Before
65+
public void setUp() {
66+
context = new Context();
67+
context.service(EventService.class).subscribe(this);
68+
}
69+
70+
@After
71+
public void tearDown() {
72+
context.dispose();
73+
}
74+
75+
@EventHandler
76+
public void onEvent(final TaskEvent event) {
77+
if (buildTask != null) return;
78+
buildTask = event.getTask();
79+
buildTask.log().addLogListener(messages::add);
80+
}
81+
82+
@Test
83+
public void testBuildOutputGoesToTaskLog() {
84+
final BuildListener listener = SciJavaTasks.buildListener(context.service(
85+
TaskService.class), null, null);
86+
listener.buildStarted("myenv");
87+
assertNotNull(buildTask);
88+
listener.buildOutput("myenv", " resolving\n");
89+
listener.buildError("myenv", "installed\r\n");
90+
listener.buildProgress("myenv", "Downloading", 1, 2);
91+
final RuntimeException failure = new RuntimeException("no space left");
92+
listener.buildFinished("myenv", failure);
93+
94+
assertTrue(buildTask.isDone());
95+
assertEquals(3, messages.size());
96+
// Note: Build tools write ordinary status to stderr, so it is not an error.
97+
assertEquals(LogLevel.INFO, messages.get(0).level());
98+
assertEquals(" resolving", messages.get(0).text());
99+
assertEquals(LogLevel.INFO, messages.get(1).level());
100+
assertEquals("installed", messages.get(1).text());
101+
assertEquals(LogLevel.ERROR, messages.get(2).level());
102+
assertSame(failure, messages.get(2).throwable());
103+
}
104+
}

0 commit comments

Comments
 (0)