RFR: 8148188: Enhance the security libraries to record events of interest

Seán Coffey sean.coffey at oracle.com
Thu Jun 28 12:28:07 UTC 2018


Thanks for reviewing Xuelei,

I do acknowledge that the new TLS v1.3 code has greatly improved the 
logging output for related operations. I think the main drive with this 
enhancement is to use the new JFR API to capture interesting events. We 
can revisit the Logger requirements if there's a strong opinion from 
users. By default, both the new Logger and JFR output will be switched 
off. I've just made an edit to the JFR jfc files to disable these events.

"I may suggest remove this method and use Key.getAlgorithm() directly." 
- Yes, great idea. Done.

Thanks for feedback on Finished.java edits. I did question to myself 
whether fewer edits were sufficient given the client/server nature of 
the handshake.

I've refreshed the webrev :

http://cr.openjdk.java.net/~coffeys/webrev.8148188.v3/webrev/

some jfr side edits also :

* Change label from "X.509 Certificate" to "X509 Certificate" - JFR test 
fails with "." usage
* Move the instance field variable name in CertChainEvent to "certChain" 
- JFR tests discourage use of  "ID" in "certIDs"

regards,
Sean.


On 27/06/2018 21:11, Xuelei Fan wrote:
> Finished.java
> -------------
> In each handshake, Finished messages are delivered twice.  One from 
> client, and the other one from the server side.  Catch Finished 
> message and use the final one of them should be sufficient.
>
> In the Finished.java implementation, the signal of the final Finished 
> message is the handshakeFinished field is set to true.
>
> Please move line 582:
>  582             recordEvent(chc.conContext.conSession);
> to line 558:
>  556                 // handshake context cleanup.
>  557                 chc.handshakeFinished = true;
>  558
>
> Please move line 632:
>  632             recordEvent(shc.conContext.conSession);
> to line 608:
>  606                 // handshake context cleanup.
>  607                 shc.handshakeFinished = true;
>  608
>
> Please remove line 838:
>  838             recordEvent(shc.conContext.conSession);
>
> Please remove line 984:
>  984             recordEvent(chc.conContext.conSession);
>
> No more comment.
>
> Thanks,
> Xuelei
>
> On 6/27/2018 11:57 AM, 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?
>>
>> 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.
>>
>> 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/
>>>>>>
>>>>>
>>>>
>>>




More information about the security-dev mailing list