-
Enhancement
-
Resolution: Unresolved
-
P4
-
None
-
16
ADDITIONAL SYSTEM INFORMATION :
JDK 16.0.1
running on win64 and linux 64 using RMI in a huge distributed environment
A DESCRIPTION OF THE PROBLEM :
We have a distributed process environment which relies on RMI for internal communication. In order to track issues, each log line has a globally unique identifier that we refer to as "trace id". Log4J inserts it by means of its MDC / ThreadContext functionality. It is automatically transmitted in every RMI call and thus valid in both client and server (and thus in all affected log files).
To this end, we override (un)marshalCustomCallData.
This, in turn, requires the customization of internal sun apis and is thus subject to https://openjdk.java.net/jeps/396 .
We request a public service provider interface which allows to to marshal custom call data, i.e. a public replacement for sun.rmi.server.UnicastRef.marshalCustomCallData(ObjectOutput) and sun.rmi.server.UnicastServerRef.unmarshalCustomCallData(ObjectInput) .
Minimal working example which demonstrates the intended usage:
USAGE (source pasted below):
0. The example has a dependency to log4j2 in order to demonstrate the approach (download from https://www.apache.org/dyn/closer.lua/logging/log4j/2.14.1/apache-log4j-2.14.1-bin.zip )
1. compile with
$ build.bat
2. run server in one command shell with
run.bat server
example output:
Initializing in mode 'server' [server.-1kipod5]
Server is up and running [server.-1kipod5]
Server is running (hopefully with log4j)
Hello world [client.-13orc6l]
Hello world [client.-ca9o4n]
3. run client in another command shell with
run.bat client
Example output:
Initializing in mode 'client' [client.-ca9o4n]
Remote call done! [client.-ca9o4n]
----------------------------
MWE.java:
----------------------------
import java.io.IOException;
import java.io.ObjectInput;
import java.io.ObjectOutput;
import java.rmi.AlreadyBoundException;
import java.rmi.NotBoundException;
import java.rmi.Remote;
import java.rmi.RemoteException;
import java.rmi.registry.LocateRegistry;
import java.rmi.registry.Registry;
import java.rmi.server.RemoteCall;
import java.rmi.server.RemoteRef;
import java.util.HashMap;
import java.util.Map;
import java.util.Random;
import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.Logger;
import org.apache.logging.log4j.ThreadContext;
import sun.rmi.server.UnicastRef;
import sun.rmi.server.UnicastServerRef;
import sun.rmi.transport.LiveRef;
/**
* Minimal working example demonstrating the use of "trace identifiers" which are valid on both RMI server and
* RMI client
*
* the code uses (un)marshalCustomCallData in order to transmit (or even generate) such an identifier
*
* DEPENDENCIES: log4j2
*/
public class MWE
{
public static final String TRACEID = "TRACEID";
private static String generateTraceId()
{
return Integer.toString(new Random().nextInt(), 30);
}
public static class MdcCapableUnicastServerRef
extends
UnicastServerRef
{
/**
* For externalization.
*/
public MdcCapableUnicastServerRef()
{
super();
}
/**
* Initializes the reference.
* @param aPort
*/
public MdcCapableUnicastServerRef(final int aPort)
{
super(aPort);
}
@Override
protected RemoteRef getClientRef()
{
return new MdcCapableUnicastRef(ref);
}
@Override
public String getRefClass(final ObjectOutput aOut)
{
// this disables sun's optimization for standard classes.
return null;
}
static void unmarshalAndStoreThreadLocalMdcCallData(final ObjectInput aIn)
throws IOException, ClassNotFoundException
{
@SuppressWarnings("unchecked")
final Map<String, String> contextMap = (Map<String, String>) aIn.readObject();
ThreadContext.putAll(contextMap);
}
static void clearMdcThreadLocalData()
{
ThreadContext.clearAll();
}
@Override
protected void unmarshalCustomCallData(final ObjectInput aIn) throws IOException, ClassNotFoundException
{
unmarshalAndStoreThreadLocalMdcCallData(aIn);
}
@Override
public void dispatch(final Remote aObj, final RemoteCall aCall) throws IOException
{
try
{
super.dispatch(aObj, aCall);
}
finally
{
clearMdcThreadLocalData();
}
}
}
public static class MdcCapableUnicastRef
extends
UnicastRef
{
private static final long serialVersionUID = 3041893609356301876L;
public MdcCapableUnicastRef()
{
super();
}
public MdcCapableUnicastRef(final LiveRef aLiveRef)
{
super(aLiveRef);
}
@Override
public String getRefClass(final ObjectOutput aOut)
{
// this disables sun's optimization for standard classes.
return null;
}
@Override
protected void marshalCustomCallData(final ObjectOutput aOut) throws IOException
{
ensureAndMarshalMapDiagnosticContext(aOut);
}
/**
* Assembles the information which is sent from the client to the server.
*/
static void ensureAndMarshalMapDiagnosticContext(final ObjectOutput aOut) throws IOException
{
final Map<String, String> contextMap = getContextMapForRemoteCall();
aOut.writeObject(contextMap);
}
/**
* @return
*/
private static Map<String, String> getContextMapForRemoteCall()
{
Map<String, String> contextMap;
if (ThreadContext.isEmpty())
{
// we want to generate the information *on the client* -- keep in mind that the context contains a unique client context identifier.
contextMap = new HashMap<>();
contextMap.put(TRACEID, generateTraceId());
}
else
{
contextMap = new HashMap<>(ThreadContext.getContext());
}
return contextMap;
}
}
public static interface Server
extends
Remote
{
public void helloWorld() throws RemoteException;
}
public static class DefaultServer
implements
Server
{
private static final Logger serverLogger = LogManager.getLogger("HelloWorld");
public DefaultServer() throws RemoteException
{
new MdcCapableUnicastServerRef(1000).exportObject(this, null, false);
}
@Override
public void helloWorld() throws RemoteException
{
serverLogger.info("Hello world");
}
}
public static void main(String[] args) throws RemoteException, AlreadyBoundException, NotBoundException
{
final Logger mainLogger = LogManager.getLogger("Main");
if (args.length != 1)
{
System.err.println("Invocation: MWE server|client");
System.exit(1);
}
ThreadContext.put(TRACEID, args[0] + "." + generateTraceId());
mainLogger.info("Initializing in mode '" + args[0] + "'");
switch (args[0])
{
case "server":
{
DefaultServer server = new DefaultServer();
Registry r = LocateRegistry.createRegistry(1000);
r.bind("server", server);
mainLogger.info("Server is up and running");
System.out.println("Server is running (hopefully with log4j)");
break;
}
case "client":
{
Registry r = LocateRegistry.getRegistry(1000);
Server stub = (MWE.Server) r.lookup("server");
stub.helloWorld();
mainLogger.info("Remote call done!");
break;
}
}
}
}
---------------------------------------------
log4j2.properties:
---------------------------------------------
appender.console.type = Console
appender.console.name = STDOUT
appender.console.layout.type = PatternLayout
appender.console.layout.pattern = %m [%X{TRACEID}]%n
rootLogger.level = info
rootLogger.appenderRef.stdout.ref = STDOUT
-----------------------------------------------
invocations:
build.bat:
c:\Tools\java\jdk-16.0.1\bin\javac --add-exports java.rmi/sun.rmi.server=ALL-UNNAMED --add-exports java.rmi/sun.rmi.transport=ALL-UNNAMED -cp ".;.\lib\log4j-api-2.14.1.jar;.\lib\log4j-core-2.14.1.jar" MWE.java
run.bat
c:\Tools\java\jdk-16.0.1\bin\java --add-exports java.rmi/sun.rmi.server=ALL-UNNAMED --add-exports java.rmi/sun.rmi.transport=ALL-UNNAMED -cp ".;.\lib\log4j-api-2.14.1.jar;.\lib\log4j-core-2.14.1.jar" MWE %*
JDK 16.0.1
running on win64 and linux 64 using RMI in a huge distributed environment
A DESCRIPTION OF THE PROBLEM :
We have a distributed process environment which relies on RMI for internal communication. In order to track issues, each log line has a globally unique identifier that we refer to as "trace id". Log4J inserts it by means of its MDC / ThreadContext functionality. It is automatically transmitted in every RMI call and thus valid in both client and server (and thus in all affected log files).
To this end, we override (un)marshalCustomCallData.
This, in turn, requires the customization of internal sun apis and is thus subject to https://openjdk.java.net/jeps/396 .
We request a public service provider interface which allows to to marshal custom call data, i.e. a public replacement for sun.rmi.server.UnicastRef.marshalCustomCallData(ObjectOutput) and sun.rmi.server.UnicastServerRef.unmarshalCustomCallData(ObjectInput) .
Minimal working example which demonstrates the intended usage:
USAGE (source pasted below):
0. The example has a dependency to log4j2 in order to demonstrate the approach (download from https://www.apache.org/dyn/closer.lua/logging/log4j/2.14.1/apache-log4j-2.14.1-bin.zip )
1. compile with
$ build.bat
2. run server in one command shell with
run.bat server
example output:
Initializing in mode 'server' [server.-1kipod5]
Server is up and running [server.-1kipod5]
Server is running (hopefully with log4j)
Hello world [client.-13orc6l]
Hello world [client.-ca9o4n]
3. run client in another command shell with
run.bat client
Example output:
Initializing in mode 'client' [client.-ca9o4n]
Remote call done! [client.-ca9o4n]
----------------------------
MWE.java:
----------------------------
import java.io.IOException;
import java.io.ObjectInput;
import java.io.ObjectOutput;
import java.rmi.AlreadyBoundException;
import java.rmi.NotBoundException;
import java.rmi.Remote;
import java.rmi.RemoteException;
import java.rmi.registry.LocateRegistry;
import java.rmi.registry.Registry;
import java.rmi.server.RemoteCall;
import java.rmi.server.RemoteRef;
import java.util.HashMap;
import java.util.Map;
import java.util.Random;
import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.Logger;
import org.apache.logging.log4j.ThreadContext;
import sun.rmi.server.UnicastRef;
import sun.rmi.server.UnicastServerRef;
import sun.rmi.transport.LiveRef;
/**
* Minimal working example demonstrating the use of "trace identifiers" which are valid on both RMI server and
* RMI client
*
* the code uses (un)marshalCustomCallData in order to transmit (or even generate) such an identifier
*
* DEPENDENCIES: log4j2
*/
public class MWE
{
public static final String TRACEID = "TRACEID";
private static String generateTraceId()
{
return Integer.toString(new Random().nextInt(), 30);
}
public static class MdcCapableUnicastServerRef
extends
UnicastServerRef
{
/**
* For externalization.
*/
public MdcCapableUnicastServerRef()
{
super();
}
/**
* Initializes the reference.
* @param aPort
*/
public MdcCapableUnicastServerRef(final int aPort)
{
super(aPort);
}
@Override
protected RemoteRef getClientRef()
{
return new MdcCapableUnicastRef(ref);
}
@Override
public String getRefClass(final ObjectOutput aOut)
{
// this disables sun's optimization for standard classes.
return null;
}
static void unmarshalAndStoreThreadLocalMdcCallData(final ObjectInput aIn)
throws IOException, ClassNotFoundException
{
@SuppressWarnings("unchecked")
final Map<String, String> contextMap = (Map<String, String>) aIn.readObject();
ThreadContext.putAll(contextMap);
}
static void clearMdcThreadLocalData()
{
ThreadContext.clearAll();
}
@Override
protected void unmarshalCustomCallData(final ObjectInput aIn) throws IOException, ClassNotFoundException
{
unmarshalAndStoreThreadLocalMdcCallData(aIn);
}
@Override
public void dispatch(final Remote aObj, final RemoteCall aCall) throws IOException
{
try
{
super.dispatch(aObj, aCall);
}
finally
{
clearMdcThreadLocalData();
}
}
}
public static class MdcCapableUnicastRef
extends
UnicastRef
{
private static final long serialVersionUID = 3041893609356301876L;
public MdcCapableUnicastRef()
{
super();
}
public MdcCapableUnicastRef(final LiveRef aLiveRef)
{
super(aLiveRef);
}
@Override
public String getRefClass(final ObjectOutput aOut)
{
// this disables sun's optimization for standard classes.
return null;
}
@Override
protected void marshalCustomCallData(final ObjectOutput aOut) throws IOException
{
ensureAndMarshalMapDiagnosticContext(aOut);
}
/**
* Assembles the information which is sent from the client to the server.
*/
static void ensureAndMarshalMapDiagnosticContext(final ObjectOutput aOut) throws IOException
{
final Map<String, String> contextMap = getContextMapForRemoteCall();
aOut.writeObject(contextMap);
}
/**
* @return
*/
private static Map<String, String> getContextMapForRemoteCall()
{
Map<String, String> contextMap;
if (ThreadContext.isEmpty())
{
// we want to generate the information *on the client* -- keep in mind that the context contains a unique client context identifier.
contextMap = new HashMap<>();
contextMap.put(TRACEID, generateTraceId());
}
else
{
contextMap = new HashMap<>(ThreadContext.getContext());
}
return contextMap;
}
}
public static interface Server
extends
Remote
{
public void helloWorld() throws RemoteException;
}
public static class DefaultServer
implements
Server
{
private static final Logger serverLogger = LogManager.getLogger("HelloWorld");
public DefaultServer() throws RemoteException
{
new MdcCapableUnicastServerRef(1000).exportObject(this, null, false);
}
@Override
public void helloWorld() throws RemoteException
{
serverLogger.info("Hello world");
}
}
public static void main(String[] args) throws RemoteException, AlreadyBoundException, NotBoundException
{
final Logger mainLogger = LogManager.getLogger("Main");
if (args.length != 1)
{
System.err.println("Invocation: MWE server|client");
System.exit(1);
}
ThreadContext.put(TRACEID, args[0] + "." + generateTraceId());
mainLogger.info("Initializing in mode '" + args[0] + "'");
switch (args[0])
{
case "server":
{
DefaultServer server = new DefaultServer();
Registry r = LocateRegistry.createRegistry(1000);
r.bind("server", server);
mainLogger.info("Server is up and running");
System.out.println("Server is running (hopefully with log4j)");
break;
}
case "client":
{
Registry r = LocateRegistry.getRegistry(1000);
Server stub = (MWE.Server) r.lookup("server");
stub.helloWorld();
mainLogger.info("Remote call done!");
break;
}
}
}
}
---------------------------------------------
log4j2.properties:
---------------------------------------------
appender.console.type = Console
appender.console.name = STDOUT
appender.console.layout.type = PatternLayout
appender.console.layout.pattern = %m [%X{TRACEID}]%n
rootLogger.level = info
rootLogger.appenderRef.stdout.ref = STDOUT
-----------------------------------------------
invocations:
build.bat:
c:\Tools\java\jdk-16.0.1\bin\javac --add-exports java.rmi/sun.rmi.server=ALL-UNNAMED --add-exports java.rmi/sun.rmi.transport=ALL-UNNAMED -cp ".;.\lib\log4j-api-2.14.1.jar;.\lib\log4j-core-2.14.1.jar" MWE.java
run.bat
c:\Tools\java\jdk-16.0.1\bin\java --add-exports java.rmi/sun.rmi.server=ALL-UNNAMED --add-exports java.rmi/sun.rmi.transport=ALL-UNNAMED -cp ".;.\lib\log4j-api-2.14.1.jar;.\lib\log4j-core-2.14.1.jar" MWE %*