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

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


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/
>>>>>>>
>>>>>>
>>>>>
>>>>
>>
>




More information about the security-dev mailing list