Skip to content

Commit 66bf5fe

Browse files
tzezulatzezula
committed
[GR-10553] Use Truffle logging for Context pre-initialization.
PullRequest: graal/1730
2 parents 807f516 + 7b4d355 commit 66bf5fe

File tree

4 files changed

+98
-10
lines changed

4 files changed

+98
-10
lines changed

‎truffle/src/com.oracle.truffle.api.test/src/com/oracle/truffle/api/test/polyglot/ContextPreInitializationTest.java

Lines changed: 73 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -34,6 +34,7 @@
3434
import java.io.ByteArrayOutputStream;
3535
import java.io.IOException;
3636
import java.io.OutputStream;
37+
import java.io.PrintStream;
3738
import java.lang.reflect.Method;
3839
import java.nio.file.Paths;
3940
import java.util.ArrayList;
@@ -46,6 +47,8 @@
4647
import java.util.Map;
4748
import java.util.Set;
4849
import java.util.concurrent.atomic.AtomicInteger;
50+
import java.util.logging.Handler;
51+
import java.util.logging.LogRecord;
4952
import org.graalvm.options.OptionCategory;
5053
import org.graalvm.options.OptionDescriptors;
5154
import org.graalvm.options.OptionKey;
@@ -852,6 +855,59 @@ public void testTemporaryEngine() throws Exception {
852855
assertEquals(1, firstLangCtx.disposeThreadCount);
853856
}
854857

858+
@Test
859+
public void testLogging() throws Exception {
860+
setPatchable(FIRST);
861+
// In context pre-initialization there is no sdk Context to set log handler,
862+
// logging is done to System.out
863+
final PrintStream origOut = System.out;
864+
final ByteArrayOutputStream preInitOut = new ByteArrayOutputStream();
865+
try (PrintStream printStream = new PrintStream(preInitOut)) {
866+
System.setOut(printStream);
867+
System.setProperty("polyglot.log.engine.level", "FINE");
868+
doContextPreinitialize(FIRST);
869+
} finally {
870+
System.setOut(origOut);
871+
System.getProperties().remove("polyglot.log.engine.level");
872+
}
873+
final String preInitLog = preInitOut.toString("UTF-8");
874+
assertTrue(preInitLog.contains("Pre-initialized context for language: ContextPreInitializationFirst"));
875+
List<CountingContext> contexts = new ArrayList<>(emittedContexts);
876+
assertEquals(1, contexts.size());
877+
final CountingContext firstLangCtx = findContext(FIRST, contexts);
878+
assertNotNull(firstLangCtx);
879+
assertEquals(1, firstLangCtx.createContextCount);
880+
assertEquals(1, firstLangCtx.initializeContextCount);
881+
assertEquals(0, firstLangCtx.patchContextCount);
882+
assertEquals(0, firstLangCtx.disposeContextCount);
883+
assertEquals(0, firstLangCtx.initializeThreadCount);
884+
assertEquals(0, firstLangCtx.disposeThreadCount);
885+
final TestHandler testHandler = new TestHandler();
886+
final Context ctx = Context.newBuilder().option("log.engine.level", "FINE").logHandler(testHandler).build();
887+
Value res = ctx.eval(Source.create(FIRST, "test"));
888+
assertEquals("test", res.asString());
889+
assertEquals(1, testHandler.logs.size());
890+
assertEquals(FIRST, testHandler.logs.get(0).getParameters()[0]);
891+
assertEquals("Successfully patched context of language: {0}", testHandler.logs.get(0).getMessage());
892+
contexts = new ArrayList<>(emittedContexts);
893+
assertEquals(1, contexts.size());
894+
assertEquals(1, firstLangCtx.createContextCount);
895+
assertEquals(1, firstLangCtx.initializeContextCount);
896+
assertEquals(1, firstLangCtx.patchContextCount);
897+
assertEquals(0, firstLangCtx.disposeContextCount);
898+
assertEquals(1, firstLangCtx.initializeThreadCount);
899+
assertEquals(0, firstLangCtx.disposeThreadCount);
900+
ctx.close();
901+
contexts = new ArrayList<>(emittedContexts);
902+
assertEquals(1, contexts.size());
903+
assertEquals(1, firstLangCtx.createContextCount);
904+
assertEquals(1, firstLangCtx.initializeContextCount);
905+
assertEquals(1, firstLangCtx.patchContextCount);
906+
assertEquals(1, firstLangCtx.disposeContextCount);
907+
assertEquals(1, firstLangCtx.initializeThreadCount);
908+
assertEquals(1, firstLangCtx.disposeThreadCount);
909+
}
910+
855911
private static void resetSystemPropertiesOptions() {
856912
System.getProperties().remove("polyglot.engine.PreinitializeContexts");
857913
System.getProperties().remove(SYS_OPTION1_KEY);
@@ -1097,4 +1153,21 @@ protected void initializeContext(CountingContext context) throws Exception {
10971153
@TruffleLanguage.Registration(id = INTERNAL, name = INTERNAL, version = "1.0", mimeType = INTERNAL, internal = true)
10981154
public static final class ContextPreInitializationTestInternalLanguage extends BaseLanguage {
10991155
}
1156+
1157+
private static final class TestHandler extends Handler {
1158+
final List<LogRecord> logs = new ArrayList<>();
1159+
1160+
@Override
1161+
public void publish(LogRecord record) {
1162+
logs.add(record);
1163+
}
1164+
1165+
@Override
1166+
public void flush() {
1167+
}
1168+
1169+
@Override
1170+
public void close() throws SecurityException {
1171+
}
1172+
}
11001173
}

‎truffle/src/com.oracle.truffle.api.vm/src/com/oracle/truffle/api/vm/PolyglotEngineImpl.java

Lines changed: 4 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -309,8 +309,10 @@ private void parseOptions(Map<String, String> options, boolean useSystemProperti
309309
String key = (String) systemKey;
310310
if (key.startsWith(OptionValuesImpl.SYSTEM_PROPERTY_PREFIX)) {
311311
String engineKey = key.substring(OptionValuesImpl.SYSTEM_PROPERTY_PREFIX.length(), key.length());
312-
if (!options.containsKey(engineKey) && (!preInitialization || idToPublicLanguage.containsKey(parseOptionGroup(engineKey)) ||
313-
engineKey.equals(PolyglotImpl.OPTION_GROUP_ENGINE + '.' + PolyglotEngineOptions.PREINITIALIZE_CONTEXT_NAME))) {
312+
String optionGroup = parseOptionGroup(engineKey);
313+
if (!options.containsKey(engineKey) && (!preInitialization || idToPublicLanguage.containsKey(optionGroup) ||
314+
engineKey.equals(PolyglotImpl.OPTION_GROUP_ENGINE + '.' + PolyglotEngineOptions.PREINITIALIZE_CONTEXT_NAME) ||
315+
PolyglotEngineOptions.OPTION_GROUP_LOG.equals(optionGroup))) {
314316
options.put(engineKey, System.getProperty(key));
315317
}
316318
}

‎truffle/src/com.oracle.truffle.api.vm/src/com/oracle/truffle/api/vm/PolyglotImpl.java

Lines changed: 13 additions & 8 deletions
Original file line numberDiff line numberDiff line change
@@ -193,14 +193,19 @@ public Engine buildEngine(OutputStream out, OutputStream err, InputStream in, Ma
193193
@Override
194194
public void preInitializeEngine() {
195195
ensureInitialized();
196-
final PolyglotEngineImpl preInitializedEngine = PolyglotEngineImpl.preInitialize(
197-
this,
198-
INSTRUMENT.createDispatchOutput(System.out),
199-
INSTRUMENT.createDispatchOutput(System.err),
200-
System.in,
201-
TruffleOptions.AOT ? null : Thread.currentThread().getContextClassLoader(),
202-
PolyglotLogHandler.createStreamHandler(System.out, false, true));
203-
preInitializedEngineRef.set(preInitializedEngine);
196+
final Handler logHandler = PolyglotLogHandler.createStreamHandler(System.out, false, true);
197+
try {
198+
final PolyglotEngineImpl preInitializedEngine = PolyglotEngineImpl.preInitialize(
199+
this,
200+
INSTRUMENT.createDispatchOutput(System.out),
201+
INSTRUMENT.createDispatchOutput(System.err),
202+
System.in,
203+
TruffleOptions.AOT ? null : Thread.currentThread().getContextClassLoader(),
204+
logHandler);
205+
preInitializedEngineRef.set(preInitializedEngine);
206+
} finally {
207+
logHandler.flush();
208+
}
204209
}
205210

206211
/**

‎truffle/src/com.oracle.truffle.api.vm/src/com/oracle/truffle/api/vm/PolyglotLanguageContext.java

Lines changed: 8 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -46,13 +46,17 @@
4646
import com.oracle.truffle.api.CompilerDirectives.TruffleBoundary;
4747
import com.oracle.truffle.api.Scope;
4848
import com.oracle.truffle.api.TruffleLanguage.Env;
49+
import com.oracle.truffle.api.TruffleLogger;
4950
import com.oracle.truffle.api.interop.TruffleObject;
5051
import com.oracle.truffle.api.nodes.ExplodeLoop;
5152
import com.oracle.truffle.api.source.Source;
53+
import java.util.logging.Level;
5254

5355
@SuppressWarnings("deprecation")
5456
final class PolyglotLanguageContext implements PolyglotImpl.VMObject {
5557

58+
private static final TruffleLogger LOG = TruffleLogger.getLogger("engine", PolyglotLanguageContext.class);
59+
5660
/*
5761
* Lazily created when a language context is created.
5862
*/
@@ -388,6 +392,7 @@ static Object[] toGuestValues(Object languageContext, Object[] args) {
388392

389393
void preInitialize() {
390394
ensureInitialized(null);
395+
LOG.log(Level.FINE, "Pre-initialized context for language: {0}", language.getId());
391396
}
392397

393398
boolean patch(PolyglotContextConfig newConfig) {
@@ -398,13 +403,16 @@ boolean patch(PolyglotContextConfig newConfig) {
398403
newConfig.fileSystem);
399404
if (newEnv != null) {
400405
env = newEnv;
406+
LOG.log(Level.FINE, "Successfully patched context of language: {0}", this.language.getId());
401407
return true;
402408
}
409+
LOG.log(Level.FINE, "Failed to patch context of language: {0}", this.language.getId());
403410
return false;
404411
} catch (Throwable t) {
405412
if (t instanceof ThreadDeath) {
406413
throw t;
407414
}
415+
LOG.log(Level.FINE, "Exception during patching context of language: {0}", this.language.getId());
408416
throw PolyglotImpl.wrapGuestException(this, t);
409417
}
410418
} else {

0 commit comments

Comments
 (0)