Skip to content

Commit 47510e5

Browse files
committed
%time magic #104
1 parent 9704a79 commit 47510e5

15 files changed

Lines changed: 346 additions & 77 deletions

File tree

jjava-distro/src/main/java/org/dflib/jjava/distro/JJava.java

Lines changed: 5 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -6,6 +6,7 @@
66
import org.dflib.jjava.kernel.magics.ClasspathMagic;
77
import org.dflib.jjava.kernel.magics.JarsMagic;
88
import org.dflib.jjava.kernel.magics.LoadCodeMagic;
9+
import org.dflib.jjava.kernel.magics.TimeMagic;
910
import org.dflib.jjava.maven.MavenDependencyResolver;
1011
import org.dflib.jjava.maven.magics.AddMavenDependencyMagic;
1112
import org.dflib.jjava.maven.magics.LoadFromPomCellMagic;
@@ -49,6 +50,7 @@ public static void main(String[] args) throws Exception {
4950
MavenDependencyResolver mavenResolver = new MavenDependencyResolver();
5051

5152
Properties pomProps = loadPomProps();
53+
TimeMagic timeMagic = new TimeMagic();
5254

5355
JavaKernel kernel = JavaKernel.builder()
5456
.name("JJava")
@@ -60,6 +62,8 @@ public static void main(String[] args) throws Exception {
6062

6163
.lineMagic("load", new LoadCodeMagic("", ".jsh", ".jshell", ".java", ".jjava"))
6264
.lineMagic("classpath", new ClasspathMagic())
65+
.lineMagic("time", timeMagic)
66+
6367
.lineMagic("maven", new MavenMagic(mavenResolver))
6468
.lineMagic("mavenRepo", new MavenRepoMagic(mavenResolver))
6569
.lineMagic("loadFromPOM", new LoadFromPomLineMagic(mavenResolver))
@@ -69,6 +73,7 @@ public static void main(String[] args) throws Exception {
6973
.lineMagic("addMavenDependency", new AddMavenDependencyMagic(mavenResolver))
7074

7175
.cellMagic("loadFromPOM", new LoadFromPomCellMagic(mavenResolver))
76+
.cellMagic("time", timeMagic)
7277

7378
.build();
7479

Lines changed: 34 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,34 @@
1+
package org.dflib.jjava.jupyter.instrumentation;
2+
3+
import java.util.function.Supplier;
4+
5+
/**
6+
* Captures code evaluation performance metrics.
7+
*/
8+
public interface EvalTimer {
9+
10+
void start();
11+
12+
/**
13+
* Called by the kernel for each step in an evaluation of a piece of code. The timer would normally capture the
14+
* time metrics for a single step and add them to the totals being captured since {@link #start()} was called.
15+
*/
16+
<T> T runAndMeasureStep(Supplier<T> timedAction);
17+
18+
void stop();
19+
20+
EvalTimer DO_NOTHING = new EvalTimer() {
21+
@Override
22+
public void start() {
23+
}
24+
25+
@Override
26+
public <T> T runAndMeasureStep(Supplier<T> timedAction) {
27+
return timedAction.get();
28+
}
29+
30+
@Override
31+
public void stop() {
32+
}
33+
};
34+
}
Lines changed: 78 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,78 @@
1+
package org.dflib.jjava.jupyter.instrumentation;
2+
3+
import java.lang.management.ThreadMXBean;
4+
import java.util.concurrent.atomic.AtomicLong;
5+
import java.util.function.Supplier;
6+
7+
/**
8+
* A timer that makes an attempt to capture CPU and user time in addition to the overall elapsed time.
9+
*/
10+
public abstract class WallAndCpuTimer implements EvalTimer {
11+
12+
private final ThreadMXBean threadMXBean;
13+
private final AtomicLong totalWallTime;
14+
private final AtomicLong totalUserTime;
15+
private final AtomicLong totalCpuTime;
16+
17+
public static boolean canMeasureCpuTimes(ThreadMXBean threadMXBean) {
18+
// according to JavaDocs, isThreadCpuTimeEnabled() can throw in some cases
19+
try {
20+
return threadMXBean.isCurrentThreadCpuTimeSupported() && threadMXBean.isThreadCpuTimeEnabled();
21+
} catch (Exception e) {
22+
return false;
23+
}
24+
}
25+
26+
public WallAndCpuTimer(ThreadMXBean threadMXBean) {
27+
this.threadMXBean = threadMXBean;
28+
this.totalWallTime = new AtomicLong();
29+
this.totalUserTime = new AtomicLong();
30+
this.totalCpuTime = new AtomicLong();
31+
}
32+
33+
@Override
34+
public void start() {
35+
totalWallTime.set(0);
36+
totalUserTime.set(0);
37+
totalCpuTime.set(0);
38+
}
39+
40+
@Override
41+
public <T> T runAndMeasureStep(Supplier<T> timedAction) {
42+
43+
long t0 = System.nanoTime();
44+
long ut0 = threadMXBean.getCurrentThreadUserTime();
45+
long ct0 = threadMXBean.getCurrentThreadCpuTime();
46+
47+
try {
48+
return timedAction.get();
49+
} finally {
50+
51+
long ct1 = threadMXBean.getCurrentThreadCpuTime() - ct0;
52+
long ut1 = threadMXBean.getCurrentThreadUserTime() - ut0;
53+
long t1 = System.nanoTime() - t0;
54+
55+
totalWallTime.addAndGet(t1);
56+
57+
// sanity check
58+
if (ut0 != -1 && ut1 != -1 && ct0 != -1 && ct1 != -1) {
59+
totalUserTime.addAndGet(ut1);
60+
totalCpuTime.addAndGet(ct1);
61+
} else {
62+
totalUserTime.set(-1);
63+
totalCpuTime.set(-1);
64+
}
65+
}
66+
}
67+
68+
@Override
69+
public void stop() {
70+
onStop(totalWallTime.get(), totalUserTime.get(), totalCpuTime.get());
71+
}
72+
73+
protected abstract void onStop(
74+
long wallTimeNanos,
75+
long userTimeNanos,
76+
long totalTimeNanos);
77+
78+
}
Lines changed: 38 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,38 @@
1+
package org.dflib.jjava.jupyter.instrumentation;
2+
3+
import java.util.concurrent.atomic.AtomicLong;
4+
import java.util.function.Supplier;
5+
6+
/**
7+
* A simple timers that captures wall clock elapsed time.
8+
*/
9+
public abstract class WallTimer implements EvalTimer {
10+
11+
private final AtomicLong totalWallTime;
12+
13+
public WallTimer() {
14+
this.totalWallTime = new AtomicLong();
15+
}
16+
17+
@Override
18+
public void start() {
19+
totalWallTime.set(0);
20+
}
21+
22+
@Override
23+
public <T> T runAndMeasureStep(Supplier<T> timedAction) {
24+
long t0 = System.nanoTime();
25+
try {
26+
return timedAction.get();
27+
} finally {
28+
totalWallTime.addAndGet(System.nanoTime() - t0);
29+
}
30+
}
31+
32+
@Override
33+
public void stop() {
34+
onStop(totalWallTime.get());
35+
}
36+
37+
protected abstract void onStop(long wallTimeNanos);
38+
}

jjava-jupyter/src/main/java/org/dflib/jjava/jupyter/kernel/BaseKernel.java

Lines changed: 5 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -3,6 +3,7 @@
33
import org.dflib.jjava.jupyter.Extension;
44
import org.dflib.jjava.jupyter.channels.JupyterConnection;
55
import org.dflib.jjava.jupyter.channels.ShellReplyEnvironment;
6+
import org.dflib.jjava.jupyter.instrumentation.EvalTimer;
67
import org.dflib.jjava.jupyter.kernel.comm.CommManager;
78
import org.dflib.jjava.jupyter.kernel.display.DisplayData;
89
import org.dflib.jjava.jupyter.kernel.display.Renderer;
@@ -217,13 +218,14 @@ public Object evalRaw(String source) {
217218
* Creates and returns a builder for an evaluation pipeline.
218219
*/
219220
public <T> SimpleEvalBuilder<T> evalBuilder(String source) {
220-
return new SimpleEvalBuilder<>(this, source);
221+
return new SimpleEvalBuilder<>(this, source, EvalTimer.DO_NOTHING);
221222
}
222223

223224
/**
224-
* Evaluates the source code in a way appropriate for a given kernel subclass.
225+
* Evaluates the source code in a way appropriate for a given kernel subclass, and using the provided timer to
226+
* measure evaluation time.
225227
*/
226-
protected abstract Object doEval(String source);
228+
protected abstract Object doEval(String source, EvalTimer timer);
227229

228230
/**
229231
* Inspect the code to get things such as documentation for a function. This is

jjava-jupyter/src/main/java/org/dflib/jjava/jupyter/kernel/BaseNotebookStatics.java

Lines changed: 4 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -7,8 +7,8 @@
77
import java.util.UUID;
88

99
/**
10-
* An automatically-loaded extension that exposes a collection of static methods for notebook code to interact with the
11-
* kernel.
10+
* A collection of static methods for notebook code to interact with the kernel. The methods are automatically exposed
11+
* in notebooks via a static import on bootstrap.
1212
*/
1313
public class BaseNotebookStatics {
1414

@@ -28,7 +28,7 @@ public static <T> T lineMagic(String name, List<String> args) {
2828
} catch (UndefinedMagicException e) {
2929
throw e;
3030
} catch (Exception e) {
31-
throw new RuntimeException(String.format("Exception occurred while running line magic '%s': %s", name, e.getMessage()), e);
31+
throw new RuntimeException(String.format("Exception running line magic '%s': %s", name, e.getMessage()), e);
3232
}
3333
}
3434

@@ -40,7 +40,7 @@ public static <T> T cellMagic(String name, List<String> args, String body) {
4040
} catch (UndefinedMagicException e) {
4141
throw e;
4242
} catch (Exception e) {
43-
throw new RuntimeException(String.format("Exception occurred while running cell magic '%s': %s", name, e.getMessage()), e);
43+
throw new RuntimeException(String.format("Exception running cell magic '%s': %s", name, e.getMessage()), e);
4444
}
4545
}
4646

jjava-jupyter/src/main/java/org/dflib/jjava/jupyter/kernel/EvalBuilder.java

Lines changed: 6 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -1,5 +1,6 @@
11
package org.dflib.jjava.jupyter.kernel;
22

3+
import org.dflib.jjava.jupyter.instrumentation.EvalTimer;
34
import org.dflib.jjava.jupyter.kernel.display.DisplayData;
45

56
public interface EvalBuilder<T> {
@@ -8,5 +9,10 @@ public interface EvalBuilder<T> {
89

910
EvalBuilder<DisplayData> renderResults();
1011

12+
/**
13+
* Installs an evaluation timer for this builder eval call.
14+
*/
15+
EvalBuilder<T> timed(EvalTimer timer);
16+
1117
T eval();
1218
}

jjava-jupyter/src/main/java/org/dflib/jjava/jupyter/kernel/RenderedEvalBuilder.java

Lines changed: 6 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -1,5 +1,6 @@
11
package org.dflib.jjava.jupyter.kernel;
22

3+
import org.dflib.jjava.jupyter.instrumentation.EvalTimer;
34
import org.dflib.jjava.jupyter.kernel.display.DisplayData;
45

56
public class RenderedEvalBuilder implements EvalBuilder<DisplayData> {
@@ -22,6 +23,11 @@ public RenderedEvalBuilder resolveMagics() {
2223
return new RenderedEvalBuilder(kernel, delegate.resolveMagics());
2324
}
2425

26+
@Override
27+
public EvalBuilder<DisplayData> timed(EvalTimer timer) {
28+
return new RenderedEvalBuilder(kernel, delegate.timed(timer));
29+
}
30+
2531
@Override
2632
public DisplayData eval() {
2733
Object o = delegate.eval();
Lines changed: 16 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -1,20 +1,28 @@
11
package org.dflib.jjava.jupyter.kernel;
22

3+
import org.dflib.jjava.jupyter.instrumentation.EvalTimer;
34
import org.dflib.jjava.jupyter.kernel.display.DisplayData;
45

56
public class SimpleEvalBuilder<T> implements EvalBuilder<T> {
67

78
private final BaseKernel kernel;
89
private final String source;
10+
private final EvalTimer timer;
911

10-
protected SimpleEvalBuilder(BaseKernel kernel, String source) {
12+
protected SimpleEvalBuilder(BaseKernel kernel, String source, EvalTimer timer) {
1113
this.kernel = kernel;
1214
this.source = source;
15+
this.timer = timer;
16+
}
17+
18+
@Override
19+
public EvalBuilder<T> timed(EvalTimer timer) {
20+
return new SimpleEvalBuilder<>(kernel, source, timer);
1321
}
1422

1523
@Override
1624
public EvalBuilder<T> resolveMagics() {
17-
return new SimpleEvalBuilder<>(kernel, kernel.getMagicsResolver().resolve(source));
25+
return new SimpleEvalBuilder<>(kernel, kernel.getMagicsResolver().resolve(source), timer);
1826
}
1927

2028
@Override
@@ -24,6 +32,11 @@ public EvalBuilder<DisplayData> renderResults() {
2432

2533
@Override
2634
public T eval() {
27-
return (T) kernel.doEval(source);
35+
timer.start();
36+
try {
37+
return (T) kernel.doEval(source, timer);
38+
} finally {
39+
timer.stop();
40+
}
2841
}
2942
}

jjava-jupyter/src/main/java/org/dflib/jjava/jupyter/kernel/display/DisplayData.java

Lines changed: 4 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -8,7 +8,8 @@
88
import java.util.Map;
99

1010
public class DisplayData {
11-
public static final String DISPLAY_ID_KEY = "display_id";
11+
12+
private static final String DISPLAY_ID_KEY = "display_id";
1213

1314
public static final DisplayData EMPTY = new DisplayData(Collections.emptyMap());
1415

@@ -109,8 +110,9 @@ else if (data.transientData != null)
109110
this.transientData.putAll(data.transientData);
110111
}
111112

112-
public void setDisplayId(String id) {
113+
public DisplayData setDisplayId(String id) {
113114
this.putTransientData(DISPLAY_ID_KEY, id);
115+
return this;
114116
}
115117

116118
public boolean hasDisplayId() {

0 commit comments

Comments
 (0)