Thanks Sean.
Some feedback on the code in the security libraries.
- We should use camel case naming convention for variables (not underscore).
- Looking at sun/security/ssl/Finished.java,
I wonder if it wouldn't be less code and more easy to read, if we would
commit the event in a local private function and then use the
EventHelper class for common functionality. Instead of:
private static void recordEvent(SSLSessionImpl session) {
TLSHandshakeEvent hs_event = new TLSHandshakeEvent();
if (hs_event.isEnabled() || EventHelper.loggingSecurity()) {
String certIDs = "";
try {
certIDs = Stream.of(session.getPeerCertificates())
.filter(c -> c instanceof X509Certificate)
.map(c -> (X509Certificate) c)
.map(c -> c.getSerialNumber().toString(16))
.collect(Collectors.joining(", "));
} catch (SSLPeerUnverifiedException e) {
certIDs = e.getMessage(); // not verified msg
}
EventHelper.commitTLSHandshakeEvent(hs_event, null,
session.getPeerHost(), session.getPeerPort(),
session.getCipherSuite(), session.getProtocol(),
certIDs);
}
}
...
public static void commitTLSHandshakeEvent(TLSHandshakeEvent event,
Instant start,
String remoteHost,
int remotePort,
String cipherSuite,
String protocolVersion,
String certChain) {
if (event != null && event.shouldCommit()) {
event.remoteHost = remoteHost;
event.remotePort = remotePort;
event.cipherSuite = cipherSuite;
event.protocolVersion = protocolVersion;
event.certificateChain = certChain;
event.commit();
}
if (loggingSecurity()) {
String prepend = getDurationString(start);
SECURITY_LOGGER.log(LOG_LEVEL, prepend +
" TLSHandshake: {0}:{1,number,#}, {2}, {3}, {4}",
remoteHost, remotePort, protocolVersion, cipherSuite,
certChain);
}
}
We would do:
private static void logHandshake(SSLSessionImpl s) {
TLSHandshakeEvent event = new TLSHandshakeEvent();
if (event.shouldCommit()) {
event.remoteHost = s.getPeerHost();
event.remotePort = s.getPeerPort();
event.cipherSuite = s.getCipherSuite();
event.protocolVersion = s.getProtocol();
event.certificateChain =
EventHelper.certificateChain(s.getPeerCerticates());
event.commit();
}
if (EventHelper.isLoggingSecurity()) {
EventHelper.SECURITY_LOGGER.log(LOG_LEVEL, " TLSHandshake:
{0}:{1,number,#}, {2}, {3}, {4}",
s.getPeerHost(), s.getPeerPort(), s.getProtocol(),
s.getCipherSuite(),
EventHelper.certificateChain(s.getPeerCerticates()));
}
}
...
public static String certificateChain(Certificate[] certificates) {
try {
return Stream.of(certificates)
.filter(c -> c instanceof X509Certificate)
.map(c -> (X509Certificate) c)
.map(c -> c.getSerialNumber().toString(16))
.collect(Collectors.joining(", "));
} catch (SSLPeerUnverifiedException e) {
return e.getMessage(); // not verified msg
}
}
It will also meanless overhead, since only one check is needed for the
log and the JIT will be able to remove the allocation.
Maybe a similar pattern could be used for the other events as well?
Thanks
Erik
As per request from Erik, I separated the tests out into individual
ones to test the JFR and Logger functionality. I introduced a new
separate test for the CertificateChainEvent event also. Originally
this was wrapped into the TLSHandshakeEvent test.
Thanks to Erik for extra refactoring and modifications carried out to
clean up the code up further.
http://cr.openjdk.java.net/~coffeys/webrev.8148188.v5/webrev/
This enhancement has a dependency on JDK-8203629
Regards,
Sean.
On 02/07/18 09:49, Erik Gahlin wrote:
On 29 Jun 2018, at 17:34, Seán Coffey <sean.cof...@oracle.com> wrote:
I've introduced a new test helper class in the jdk/test/lib/jfr
directory to help with the dual test nature of the new tests. It's
helped alot with test code duplication.
My thinking was to put things like the certificates in a separate
file, i.e TestCertificates, and then have a logging test and a JFR
test reuse it.
One rationale for adding logging was to use it if JFR is not present.
By putting the tests together, it becomes impossible to compile and
test logging without having JFR.
Looked at use of @DataAmount(DataAmount.BITS) also. Not sure if it's
fits. The output is displayed in units like "KiB" - not the normal
when examining key lengths used in X509Certificates. i.e a 2048 bit
key gets displayed as "2 KiB" - I'd prefer to keep the 2048 display
version.
We should not let the JMC GUI decide how units are specified. There
will be other GUIs and this is the first event that uses bits, so I
don’t think it is formatted that way because it was considered superior.
Erik
new webrev at:
http://cr.openjdk.java.net/~coffeys/webrev.8148188.v4/webrev/
Regards,
Sean.
On 28/06/18 17:59, Seán Coffey wrote:
Comments inline.
On 28/06/2018 17:20, Erik Gahlin wrote:
It's sufficient if an event object escapes to another method
(regardless if JFR is enabled or not).
Some more feedback:
Rename event jdk.CertChain to jdk.CertificateChain
Rename event jdk.X509Cert to jdk.X509Certificate
Rename field certChain to certificateChain.
Rename field serialNum to serialNumber
all above done.
Rename field algId to AlgorithmicId or AlgorithmicID
maybe "algorithm" works here also ?
Rename @Label("Ciphersuite") to @Label("Cipher Suite")
Rename @Label("Cert Chain") to @Label("Certificate Chain")
Rename @Label("Property Name") to "Name" or "Key" if that makes
sense in the context?
Rename @Label("Property Value") to "Value".
Put events in a subcategory, i.e @Category({"Java Development
Kit", "Security"})
done.
Make classes final.
done. I had thought that the JFR mechanism required non-final classes.
What is the unit of the key in X509Certificate event? Bits? If
that is the case, use @DataAmount(DataAmount.BITS)
Yes - it's essentially the bit length of the keys used. Let me look
into that annotation usage.
@Label("Serial numbers forming chain of trust") should not be a
sentence. How about "Serial Numbers"?
I think the tests are hard to read when two things are tested at
the same time. It is also likely that if a test fail due to
logging issues, it will be assigned to JFR because of the test
name, even thought the issues is not JFR related.
I think we're always going to have some ownership issues when tests
serve a dual purpose. I still think it makes sense to keep the test
logic in one place. Any failures in these tests will most likely be
owned by security team. (moving the tests to security directory is
also an option)
If you want to reuse code between tests, I would put it in
testlibrary.
Let me check if there's any common patterns that could be added to
the testlibary.
Thanks,
Sean.
Erik
Thanks for the update Erik. By default I'm proposing that the new
JFR Events and Logger be disabled. As a result the event class
shouldn't escape. If performance metrics highlight an issue, we
should revisit.
regards,
Sean.
On 27/06/2018 20:57, Erik Gahlin wrote:
On 2018-06-27 21:14, Seán Coffey wrote:
On 27/06/2018 19:57, Xuelei Fan wrote:
Hi Sean,
I may reply in several replies.
PKIXMasterCertPathValidator.java
--------------------------------
+ CertChainEvent cce = new CertChainEvent();
+ if(cce.isEnabled() || EventHelper.loggingSecurity()) {
+ String c = reversedCertList.stream()
+ .map(x -> x.getSerialNumber().toString(16))
+ .collect(Collectors.joining(", "));
+ EventHelper.commitCertChainEvent(cce, c);
+ }
No matter the event or the JFR mechanism is enabled or not,
the above code will create a new instance. Is the return
value of cce.isEnabled() dynamically changed or static?
This is a requirement from the JFR framework. All their
event.isEnabled calls are instance methods and follow a similar
pattern. The JFR team assure me that the JIT can optimize away
such calls.
The JIT will most likely not be able to optimize if the event
class escapes.
From a JFR perspective, this would be the preferred layout:
EventA eventA= new EventA();
eventA.value = this.value;
eventA.commit();
and then do logging separately:
System.Logger.log(DEBUG, this.value)
With this layout, the JIT will remove the allocation and dead
store.
If it is expensive to gather the data for the event, like the
CertChainEvent above, the following pattern should be used.
EventB eventB= new EventB ();
if (eventB.shouldCommit()) {
eventB.value = calculateValue();
eventB .commit();
}
If JFR is not enabled, shouldCommit returns false and the JIT
should be able to remove the allocation. This will be best from
a performance point of view, and also in my opinion from a
maintenance and readability perspective. Others may disagree.
Erik
Is there a need to support both logging and JFR? I'm new to
record events. I did not get the point to use both.
I was initially hoping to concentrate on just JFR events but I
got strong feedback to also consider use of Logger (esp. in
cases where the jdk.jfr module is not available)
regards,
Sean.
Thanks,
Xuelei
On 6/26/2018 3:18 PM, Seán Coffey wrote:
Erik,
I rebased the patch with TLS v1.3 integration today. I hadn't
realized how much the handshaker code had changed. Hopefully,
I'll get a review from security dev team on that front.
Regards the JFR semantics, I believe the edits should match
majority of requests . I still have a preference for the test
infra design for these new logger/JFR tests used in version 1
of webrev. I think it makes sense to keep the test
functionality together - no sense in separating them out into
different components IMO. Also, some of the edits to the JFR
testing were made to test for the new dual log/record
functionality. I might catch up with you tomorrow to see what
the best arrangement would be.
http://cr.openjdk.java.net/~coffeys/webrev.8148188.v2/webrev/
regards,
Sean.
On 25/06/2018 21:22, Seán Coffey wrote:
Many thanks for the review comments Erik. Replies inline.
On 24/06/2018 14:21, Erik Gahlin wrote:
Hi Sean,
Some of the changes in the webrev belongs to JDK-8203629
and should be removed for clarity.
Some initial comments:
default.jfc, profile.jfr:
The events should not have control="enable-exceptions". The
purpose of the control attribute is so to provide
parameterized configuration of events for JMC. As it is
now, the security events will be enabled when a user turns
on the exception events.
Makes sense. I'll remove that parameter.
X509CertEvent:
You should use milliseconds since epoch to represent a date
instead of a string value, i.e.
@Label("Valid From")
@Timestamp(Timestamp.MILLISECONDS_SINCE_EPOCH)
public long validFrom;
@Label("Valid Until")
@Timestamp(Timestamp.MILLISECONDS_SINCE_EPOCH)
public long validUntil;
The CertificateValidity class operates on Date Object
values. I'll work with the Date.getTime() method then (and
update the Logger formatting)
This following annotation adds little value
@Description("Details of Security Property")
I would either remove the annotation, or provide
information that helps a user understand the event. For
instance, what is X509, and what kind of certificates are
we talking about?
Yes - that looks like the wrong Description. I'll review all
of these fields.
@Category("Java Application")
I'm a bit worried that we will pollute the "Java
Application" namespace if we add lots of JDK events in that
category. We may want to add a new top level category "Java
Development Kit", analogous to the "Java Virtual Machine"
category, and put all security related events in
subcategory, perhaps called "Security".
Yes - Open to suggestions. "Security" sounds like a good
suggestion.
@Label("X509Cert")
The label should be human readable name, with spaces, title
cased etc. I would recommend "X.509 Certificate". In
general, avoid abbreviations like "certs" and instead use
labels such as "Certificate Chain". The label should be
short and not a full sentence.
For details see,
https://docs.oracle.com/javase/10/docs/api/jdk/jfr/Label.html
I think it would be good to separate testing of JFR and
logging into different files / tests. I would prefer that
the test name is the same as the event prefixed with
"Test", i.e TestX509CertificateEvent, as this is the
pattern used by other JFR tests.
I'll take a look at that pattern again. I've separated out
the current tests into an (a) outer test to analyze the
logger output and (b) the inner test which checks for JFR
correctness. I did include extra logic to make sure that the
EventHelper configuration was working correctly.
"Events.assertField" looks very helpful. Thanks for the
pointer.
Let me take on board the suggestions below and get a new
webrev out on Tuesday.
regards,
Sean.
I reworked one of the tests to how I like to see it:
/*
* @test
* @key jfr
* @library /test/lib
* @run main/othervm
jdk.jfr.event.security.TestX509CertificateEvent
*/
public class TestX509CertificateEvent {
private static final String CERTIFICATE_1 = "...";
private static final String CERTIFICATE_2 = "...";
public static void main(String... args) throws
CertificateException {
Recording r = new Recording();
r.enable(EventNames.X509Certificate).withoutStackTrace();
r.start();
CertificateFactory cf =
CertificateFactory.getInstance("X.509");
cf.generateCertificate(new
ByteArrayInputStream(CERTIFICATE_1.getBytes()));
cf.generateCertificate(new
ByteArrayInputStream(CERTIFICATE_2.getBytes()));
// Make sure only one event per certificate
cf.generateCertificate(new
ByteArrayInputStream(CERTIFICATE_1.getBytes()));
cf.generateCertificate(new
ByteArrayInputStream(CERTIFICATE_2.getBytes()));
r.stop();
List<RecordedEvent> events = Events.fromRecording(r);
Asserts.assertEquals(events.size(), 2, "Expected
two X.509 Certificate events");
assertEvent(events, "1000", "SHA256withRSA",
"CN=SSLCertificate, O=SomeCompany",
"CN=Intermediate CA Cert, O=SomeCompany",
"RSA", 2048);
assertEvent(events, "1000", "SHA256withRSA",
"CN=SSLCertificate, O=SomeCompany",
"CN=Intermediate CA Cert, O=SomeCompany",
"RSA", 2048);
}
private static void assertEvent(List<RecordedEvent>
events, String certID, String algId, String subject,
String issuer, String keyType, int length)
throws Exception {
for (RecordedEvent e : events) {
if (e.getString("serialNumber").equals(certID)) {
Events.assertField(e, "algId").equal(algId);
...
return;
}
}
System.out.println(events);
throw new Exception("Could not find event with Cert
ID: " + certID);
}
}
The reworked example uses the Events.assertField method,
which will give context if the assertion fails. Keeping the
test simple, means it can be analyzed quickly if it fails
in testing. There is no new test framework to learn, or
methods to search for, and it is usually not hard to
determine if the failure is product, test or infrastructure
related, and what component (team) should be assigned the
issue. The use of EventNames.X509Certificate means all
occurrences of the event can be tracked done in an IDE
using find by reference.
Thanks
Erik
Following on from the recent JDK-8203629 code review, I'd
like to propose enhancements on how we can record events
in security libs. The introduction of the JFR libraries
can give us much better ways of examining JDK actions. For
the initial phase, I'm looking to enhance some key
security library events in JDK 11 so that they can be
either recorded to JFR, logged to a traditional logger, or
both.
Examples of how useful JFR recordings could be can be seen
here :
http://cr.openjdk.java.net/~coffeys/event_snaps/X509Event_1.png
http://cr.openjdk.java.net/~coffeys/event_snaps/securityProp_1.png
http://cr.openjdk.java.net/~coffeys/event_snaps/securityProp_2.png
http://cr.openjdk.java.net/~coffeys/event_snaps/TLSEvent_1.png
securityProp_2.png gives an example of how the JFR
recording can be queried to quickly locate events of
interest (in this case, code setting the jdk.tls.*
Security properties). I still need to clean up the
TLSEvents testcase to improve test coverage and hope to do
that in coming days.
JBS record :
* https://bugs.openjdk.java.net/browse/JDK-8148188
webrev :
http://cr.openjdk.java.net/~coffeys/webrev.8148188.v1/webrev/