Add documentation for logginginterceptor processing time variable (which

already worked, but wasn't documented)
This commit is contained in:
James Agnew 2017-08-31 10:12:15 -04:00
parent 78fd13c2f4
commit 022b556648
3 changed files with 34 additions and 7 deletions

View File

@ -113,17 +113,13 @@ import ca.uhn.fhir.rest.server.servlet.ServletRequestDetails;
* <td>${exceptionMessage}</td>
* <td>Applies only to an error message: The message from {@link Exception#getMessage()}</td>
* </tr>
* </table>
*/
/*
* TODO: implement this, but it needs the logging to happen at the end
* <tr>
* <td>${processingTimeMillis}</td>
* <td>The number of milliseconds spent processing this request</td>
* </tr>
* </table>
*/
public class LoggingInterceptor extends InterceptorAdapter {
private static final org.slf4j.Logger ourLog = org.slf4j.LoggerFactory.getLogger(LoggingInterceptor.class);
@ -169,7 +165,7 @@ public class LoggingInterceptor extends InterceptorAdapter {
StrLookup<?> lookup = new MyLookup(theRequestDetails.getServletRequest(), theRequestDetails);
StrSubstitutor subs = new StrSubstitutor(lookup, "${", "}", '\\');
// Actuall log the line
// Actually log the line
String line = subs.replace(myMessageFormat);
myLogger.info(line);
}

View File

@ -1,6 +1,8 @@
package ca.uhn.fhir.rest.server.interceptor;
import static org.hamcrest.Matchers.greaterThan;
import static org.hamcrest.Matchers.matchesPattern;
import static org.hamcrest.Matchers.startsWith;
import static org.junit.Assert.assertEquals;
import static org.junit.Assert.assertThat;
import static org.junit.Assert.assertTrue;
@ -149,6 +151,28 @@ public class LoggingInterceptorDstu2Test {
assertEquals("read - - Patient/1 - ", captor.getValue());
}
@Test
public void testRequestProcessingTime() throws Exception {
LoggingInterceptor interceptor = new LoggingInterceptor();
interceptor.setMessageFormat("${operationType} - ${processingTimeMillis}");
servlet.setInterceptors(Collections.singletonList((IServerInterceptor) interceptor));
Logger logger = mock(Logger.class);
interceptor.setLogger(logger);
HttpGet httpGet = new HttpGet("http://localhost:" + ourPort + "/Patient/1");
HttpResponse status = ourClient.execute(httpGet);
IOUtils.closeQuietly(status.getEntity().getContent());
ArgumentCaptor<String> captor = ArgumentCaptor.forClass(String.class);
verify(logger, timeout(1000).times(1)).info(captor.capture());
assertThat(captor.getValue(), startsWith("read - "));
int millis = Integer.parseInt(captor.getValue().substring("read - ".length()));
assertThat(millis, greaterThan(1));
}
@Test
public void testProcessingTime() throws Exception {
ourDelayMs = 110;

View File

@ -342,6 +342,13 @@
This property causes references to unknown resources in created/updated resources to have a placeholder
target resource automatically created.
</action>
<action type="add">
The server LoggingInterceptor has had a variable called
<![CDATA[<code>processingTimeMillis</code>]]> which logs the number
of milliseconds the server took to process a given request since
HAPI FHIR 2.5, but this was not documented. This variable has now been
documented as a part of the available features.
</action>
</release>
<release version="2.5" date="2017-06-08">
<action type="fix">