Skip to content

Commit 85118ae

Browse files
magicprincmagicprinc
committed
[#5] Unit tests for new code
1 parent 281f528 commit 85118ae

File tree

8 files changed

+4250
-0
lines changed

8 files changed

+4250
-0
lines changed

‎jOOL-java-8/src/test/java/org/jooq/lambda/ExtraMagicTest.java

Lines changed: 352 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,352 @@
1+
package org.jooq.lambda;
2+
3+
import org.jooq.lambda.function.Consumer3;
4+
import org.junit.Test;
5+
6+
import java.io.IOError;
7+
import java.io.IOException;
8+
import java.lang.invoke.CallSite;
9+
import java.lang.invoke.LambdaMetafactory;
10+
import java.lang.invoke.MethodHandle;
11+
import java.lang.invoke.MethodHandles;
12+
import java.lang.invoke.MethodType;
13+
import java.lang.reflect.InvocationTargetException;
14+
import java.lang.reflect.Method;
15+
import java.util.Objects;
16+
import java.util.concurrent.CountDownLatch;
17+
import java.util.concurrent.atomic.AtomicLong;
18+
import java.util.function.Consumer;
19+
import java.util.function.LongSupplier;
20+
21+
import static org.jooq.lambda.LambdaLogFacade.printToStdErr;
22+
import static org.jooq.lambda.Loops.loop;
23+
import static org.junit.Assert.*;
24+
25+
/*
26+
https://www.jmix.io/cuba-blog/think-twice-before-using-reflection/
27+
28+
https://github.com/cuba-rnd/entity-lambda-accessors-benchmark/blob/master/src/jmh/java/utils/MethodHandleCache.java
29+
30+
https://www.mail-archive.com/mlvm-dev@openjdk.java.net/msg06747.html
31+
32+
https://www.optaplanner.org/blog/2018/01/09/JavaReflectionButMuchFaster.html
33+
34+
https://wttech.blog/blog/2020/method-handles-and-lambda-metafactory/
35+
36+
https://forum.image.sc/t/performance-profiling-ways-of-invoking-a-method-dynamically/27471
37+
38+
!!!
39+
private static final System.Logger log = System.getLogger("c.f.b.DefaultLogger");
40+
+
41+
clsLoader = Thread.currentThread().getContextClassLoader();
42+
clsLoader = Wrap.class.getClassLoader();
43+
clsLoader = ClassLoader.getPlatformClassLoader();
44+
clsLoader = ClassLoader.getSystemClassLoader();
45+
*/
46+
public class ExtraMagicTest {
47+
static volatile Throwable FAILED;
48+
static final Method winner;
49+
static {
50+
Thread.setDefaultUncaughtExceptionHandler((Thread t, Throwable e) ->
51+
{
52+
FAILED = e;
53+
loop(9, ()-> System.err.println("{{{{{ DefaultUncaughtExceptionHandler @ "+t));
54+
e.printStackTrace();
55+
loop(9, ()-> System.err.println("}}}}} DefaultUncaughtExceptionHandler @ "+t));
56+
});
57+
58+
//1. on/off → lambdaLogFacadeLoggerTest
59+
System.setProperty("org.jooq.logger", "org.jooq.lambda.ExtraMagicTest$LoggerOverride");
60+
final Method winner0 = LambdaLogFacade.findLoggerFactoryGetLogger("org.jooq.lambda.ExtraMagicTest$LoggerOverride");
61+
62+
//2. slf4j
63+
// final Method winner0 = LambdaLogFacade.findLoggerFactoryGetLogger("org.slf4j.LoggerFactory");
64+
65+
//3. log4j
66+
// System.setProperty("org.jooq.logger.0", "-");
67+
// final Method winner0 = LambdaLogFacade.findLoggerFactoryGetLogger("org.apache.logging.log4j.LogManager");
68+
// //4. ×JUL: no slf4j/log4j
69+
// System.setProperty("org.jooq.logger.0", "-");
70+
// System.setProperty("org.jooq.logger.1", "-");
71+
// final Method winner0 = null;
72+
73+
if (Objects.equals(winner0, LambdaLogFacade.staticLoggerFactoryGetLoggerMethod)) {
74+
// good! We are the first UnitTest, we have initialized LambdaLogFacade with our wishes
75+
winner = winner0;
76+
} else if (LambdaLogFacade.staticLoggerFactoryGetLoggerMethod == null) {
77+
printToStdErr(ExtraMagicTest.class,
78+
"Other UnitTest was faster and have already initialized LambdaLogFacade with null (slf4j and log4j were not found)", null);
79+
winner = null;
80+
} else {
81+
printToStdErr(ExtraMagicTest.class,
82+
"Other UnitTest was faster and have already initialized LambdaLogFacade with "+LambdaLogFacade.staticLoggerFactoryGetLoggerMethod, null);
83+
winner = LambdaLogFacade.staticLoggerFactoryGetLoggerMethod;
84+
}
85+
}
86+
87+
@Test(expected = IOError.class)
88+
public void andThen () {
89+
Error e1 = new Error("test1: → ERROR is OK here!!!");
90+
Unchecked.PRINT_STACK_TRACE.accept(e1);
91+
92+
IOError e2 = new IOError(e1);
93+
Consumer<Throwable> c = Unchecked.SILENT_IGNORE
94+
.andThen((t) -> fail("unreachable. But: " + t));
95+
c.accept(e2);
96+
97+
fail("unreachable");
98+
}
99+
100+
101+
@Test public void modulesHackJUL () {
102+
Object jul = getActualLogger("java.util.logging.Logger", ExtraMagicTest.class);
103+
assertEquals("class java.util.logging.Logger", jul.getClass().toString());
104+
assertTrue(jul.toString().startsWith("java.util.logging.Logger@"));
105+
}
106+
107+
@Test public void modulesHackSlf4j () {
108+
Object slf4j = getActualLogger("org.slf4j.LoggerFactory", ExtraMagicTest.class);
109+
assertEquals("class org.slf4j.simple.SimpleLogger", slf4j.getClass().toString());// class org.slf4j.helpers.NOPLogger
110+
assertTrue(slf4j.toString().startsWith("org.slf4j.simple.SimpleLogger@"));// org.slf4j.helpers.NOPLogger(NOP)
111+
}
112+
113+
@Test public void modulesHackLog4j () {
114+
Object log4j = getActualLogger("org.apache.logging.log4j.LogManager", ExtraMagicTest.class);
115+
assertEquals("class org.apache.logging.log4j.core.Logger", log4j.getClass().toString());
116+
assertTrue(log4j.toString().startsWith("org.jooq.lambda.ExtraMagicTest:ERROR in "));
117+
}
118+
119+
public static class FakeLogger extends LambdaLogFacade implements LongSupplier, Runnable {
120+
public FakeLogger () {
121+
super(null);
122+
}
123+
124+
final AtomicLong cnt = new AtomicLong();
125+
126+
public static FakeLogger getLogger (String notUsed) {
127+
return new FakeLogger();
128+
}
129+
@Override public void warn (String msg, Throwable t) {
130+
assertNotNull(t);
131+
cnt.incrementAndGet();
132+
if (cnt.get() == MAX_LOOP) {
133+
new Exception("[INFO] Almost there! "+msg+"\t\t"+this).printStackTrace();
134+
}
135+
}
136+
@Override public long getAsLong () {
137+
return cnt.get();
138+
}
139+
@Override public void run () {}
140+
}
141+
142+
static /*NOT final!*/ Throwable LOG_EXCEPTION = new Exception("fake");//MethodHandle.invokeExact check type of variable (not ref object)
143+
static final long MAX_LOOP = 10_000_000;
144+
static final long MAX_LOOP_WARM = 10_050_000;
145+
146+
@Test public void speedDirect () {
147+
FakeLogger fl = new FakeLogger() {
148+
@Override public void run () {
149+
warn("message-to-log: Direct", LOG_EXCEPTION);
150+
}
151+
};
152+
String st = Loops.loopMeasuredWarm(MAX_LOOP, fl).toString();
153+
System.out.println("*** speedDirect →\t\t"+st);
154+
assertEquals(MAX_LOOP_WARM, fl.getAsLong());
155+
}
156+
157+
@Test public void speedLambda () {
158+
FakeLogger fl = new FakeLogger();
159+
160+
String st = Loops.loopMeasuredWarm(MAX_LOOP, Wrap.runnable(() ->
161+
fl.warn("message-to-log: Lambda", LOG_EXCEPTION))).toString();
162+
System.out.println("*** speedLambda →\t\t"+st);
163+
assertEquals(MAX_LOOP_WARM, fl.getAsLong());
164+
}
165+
@Test public void speedLambdaMethodRef () {
166+
FakeLogger fl = new FakeLogger(){
167+
@Override public void run () {
168+
warn("message-to-log: LambdaMethodRef", LOG_EXCEPTION);
169+
}
170+
};
171+
172+
String st = Loops.loopMeasuredWarm(MAX_LOOP, Wrap.runnable(fl::run)).toString();
173+
System.out.println("*** speedLambdaMethodRef →\t\t"+st);
174+
assertEquals(MAX_LOOP_WARM, fl.getAsLong());
175+
}
176+
177+
private static final MethodHandle staticMethodHandle;
178+
static {// Static MethodHandle setup ^
179+
try {
180+
Object fl = getActualLogger("org.jooq.lambda.ExtraMagicTest$FakeLogger", ExtraMagicTest.class);
181+
182+
MethodHandles.Lookup lookup = MethodHandles.lookup();
183+
//1. method → MethodHandle
184+
//m = LambdaLogFacade.getWarnMethod(fl);
185+
//staticMethodHandle = lookup.unreflect(m);
186+
//2. .asType for invokeExact (vs invoke)
187+
staticMethodHandle = lookup.findVirtual(fl.getClass(), "warn",
188+
MethodType.methodType(Void.TYPE, String.class, Throwable.class))
189+
.asType(MethodType.methodType(Void.TYPE, LongSupplier.class/*this*/,
190+
/*args:*/ String.class, Throwable.class));
191+
} catch (IllegalAccessException | NoSuchMethodException e) {
192+
throw new IllegalStateException(e);
193+
}
194+
}
195+
196+
@Test public void speedStaticMethodHandle () throws ClassNotFoundException, NoSuchMethodException, InvocationTargetException, InstantiationException, IllegalAccessException {
197+
Class<?> cls = Class.forName("org.jooq.lambda.ExtraMagicTest$FakeLogger");
198+
final LongSupplier fl = (LongSupplier) cls.getConstructor().newInstance();
199+
200+
String st = Loops.loopMeasuredWarm(MAX_LOOP, Unchecked.runnable(() -> {
201+
staticMethodHandle.invokeExact(fl, "message-to-log: MH", LOG_EXCEPTION);//vs invoke (ivoke is slower, but w/o .asType↑)
202+
//invokeExact→java.lang.invoke.WrongMethodTypeException: expected (FakeLogger,String,Throwable)void but found (LongSupplier,String,Exception)void
203+
})).toString();
204+
System.out.println("*** speedStaticMethodHandle →\t\t"+st);
205+
assertEquals(MAX_LOOP_WARM, fl.getAsLong());
206+
}
207+
208+
209+
private static final Method staticMethod;
210+
static {
211+
Object fl = getActualLogger("org.jooq.lambda.ExtraMagicTest$FakeLogger", ExtraMagicTest.class);
212+
staticMethod = LambdaLogFacade.getWarnMethod(fl);
213+
}
214+
@Test public void speedStaticReflection () throws ClassNotFoundException, NoSuchMethodException, InvocationTargetException, InstantiationException, IllegalAccessException {
215+
Class<?> cls = Class.forName("org.jooq.lambda.ExtraMagicTest$FakeLogger");
216+
final LongSupplier fl = (LongSupplier) cls.getConstructor().newInstance();
217+
218+
String st = Loops.loopMeasuredWarm(MAX_LOOP, Unchecked.runnable(() ->
219+
staticMethod.invoke(fl, "message-to-log: Reflection", LOG_EXCEPTION))).toString();
220+
System.out.println("*** speedStaticReflection →\t\t"+st);
221+
assertEquals(MAX_LOOP_WARM, fl.getAsLong());
222+
}
223+
224+
225+
private static final Consumer3<Object,String,Throwable> staticLambda;
226+
static {// Static Lambda setup ^
227+
try {
228+
Object fl = getActualLogger("org.jooq.lambda.ExtraMagicTest$FakeLogger", ExtraMagicTest.class);
229+
230+
MethodHandles.Lookup lookup = MethodHandles.lookup();
231+
//1. method → MethodHandle
232+
Method m = LambdaLogFacade.getWarnMethod(fl);
233+
MethodHandle mhLogWarn = lookup.unreflect(m);
234+
235+
MethodType genericMethodType = MethodType.methodType(Void.TYPE, fl.getClass()/*logger*/, String.class, Throwable.class);
236+
237+
CallSite callSite = LambdaMetafactory.metafactory(
238+
lookup,// method handle lookup
239+
"accept",//Interface Method Name: name of the method defined in the target functional interface: Consumer::accept
240+
241+
// type to be implemented and captured objects
242+
// e.g. String instance to be trimmed is captured: MethodType.methodType(Supplier.class, String.class)
243+
MethodType.methodType(Consumer3.class),
244+
245+
// type erasure, Consumer3 will accept 3 Object NOT Void.TYPE, Object.class/*logger*/, String.class, Throwable.class
246+
MethodType.methodType(Void.TYPE, Object.class/*logger*/, Object.class, Object.class),
247+
248+
mhLogWarn,// method handle to transform
249+
250+
// Consumer3 method real signature (reified)
251+
// e.g. Supplier=trim accepts no parameters and returns String: MethodType.methodType(String.class)
252+
genericMethodType);
253+
254+
//noinspection unchecked
255+
staticLambda = (Consumer3<Object,String,Throwable>) callSite.getTarget()
256+
/*.bindTo(contextObject e.g. "str")*/
257+
.invokeExact();// or invoke
258+
259+
} catch (Throwable invokeExactEx) {
260+
invokeExactEx.printStackTrace();
261+
throw new IllegalStateException(invokeExactEx);
262+
}
263+
}
264+
@Test public void speedStaticLambda () {
265+
Object fl = getActualLogger("org.jooq.lambda.ExtraMagicTest$FakeLogger", ExtraMagicTest.class);
266+
267+
String st = Loops.loopMeasuredWarm(MAX_LOOP, Unchecked.runnable(() ->
268+
staticLambda.accept(fl, "message-to-log: StaticLambda", LOG_EXCEPTION))).toString();
269+
System.out.println("*** speedStaticLambda →\t\t"+st);
270+
assertEquals(MAX_LOOP_WARM, ((LongSupplier) fl).getAsLong());
271+
}
272+
273+
/** Get slf4j.Logger, JUL Logger, or log4j Logger */
274+
static Object getActualLogger (String loggerFactoryClassName, Class<?> clazzWhereLogger) {
275+
Method loggerFactoryGetLogger = LambdaLogFacade.findLoggerFactoryGetLogger(loggerFactoryClassName);
276+
if (loggerFactoryGetLogger == null) { return null;}// LoggerFactory not found in classpath
277+
return LambdaLogFacade.invokeGetLogger(loggerFactoryGetLogger, clazzWhereLogger);
278+
}
279+
280+
281+
@Test public void lambdaLogFacadeLoggerTest () throws InterruptedException {
282+
LambdaLogFacade log = LambdaLogFacade.getLogger(ExtraMagicTest.class);
283+
assertSame(ExtraMagicTest.class, log.loggerAppClassName);// ^^^
284+
285+
printToStdErr(null, "#1 staticLoggerFactoryGetLoggerMethod= "+LambdaLogFacade.staticLoggerFactoryGetLoggerMethod, null);
286+
printToStdErr(null, "#2 staticWarnMethodHandle= "+LambdaLogFacade.staticWarnMethodHandle, null);
287+
assertEquals(winner, LambdaLogFacade.staticLoggerFactoryGetLoggerMethod);
288+
289+
log.warn("lambdaLogFacade #1", null);
290+
log.warn("lambdaLogFacade #2", new Throwable("#2 Test Throwable"));
291+
log.warn("lambdaLogFacade #3", new Error("#3 Test Error"));
292+
String msg = "lambdaLogFacade #4";
293+
Exception t = new Exception("#4 Test Error");
294+
log.warn(msg, t);
295+
if (winner != null && winner.toString().contains("LoggerOverride")) {
296+
assertEquals(4, LoggerOverride.CNT.get());
297+
assertSame(msg, LoggerOverride.lastMessage);
298+
assertSame(t, LoggerOverride.lastThrowable);
299+
} else {
300+
System.err.println("WINNER is not LoggerOverride, so no checks");
301+
}
302+
303+
final int THREADS = 100;
304+
final CountDownLatch startSignal = new CountDownLatch(1);
305+
final CountDownLatch doneSignal = new CountDownLatch(THREADS);
306+
loop(THREADS, (num) -> new Thread(()->{
307+
Wrap.run(startSignal::await);
308+
log.warn("Hello from thread "+num, new Exception("Thread "+num));
309+
loop(999, () -> log.warn("Hello from thread "+num, null));
310+
311+
Wrap.run(doneSignal::countDown);
312+
}, "lambdaLogFacade-"+num).start());
313+
startSignal.countDown();// let's go!
314+
doneSignal.await();
315+
assertNull(FAILED);
316+
317+
if (winner != null && winner.toString().contains("LoggerOverride")) {
318+
assertEquals(THREADS * 1000 + 4, LoggerOverride.CNT.get());
319+
}
320+
}
321+
322+
public static class LoggerOverride extends LambdaLogFacade {
323+
public LoggerOverride () {
324+
super(null);
325+
}//new
326+
327+
static final AtomicLong CNT = new AtomicLong();
328+
static String lastMessage;
329+
static Throwable lastThrowable;
330+
331+
public static LoggerOverride getLogger (String notUsed) {
332+
return new LoggerOverride();
333+
}
334+
@Override public void warn (String msg, Throwable t) {
335+
CNT.incrementAndGet();
336+
lastMessage = msg;
337+
lastThrowable = t;
338+
if (t != null || msg.startsWith("lambda")) {
339+
System.out.println("LoggerOverride.warn >>> "+msg+"\t>>> "+t+" # "+Thread.currentThread());
340+
}
341+
}
342+
}//LoggerOverride
343+
344+
@Test public void lambdaLogFacadeToStdErr () {
345+
LambdaLogFacade.LambdaLogFacadeStdErr log = new LambdaLogFacade.LambdaLogFacadeStdErr(ExtraMagicTest.class);
346+
assertSame(ExtraMagicTest.class, log.loggerAppClassName);// ^^^
347+
log.warn("Test message to System.err #1", null);
348+
log.warn("Test message to System.err #2 'with Throwable/Exception'",
349+
new IOException("#2 Test Throwable/Exception to System.err"));
350+
}
351+
352+
}

0 commit comments

Comments
 (0)