Source code

001package ca.uhn.fhir.rest.server.interceptor;
002
003import static org.apache.commons.lang3.StringUtils.isNotBlank;
004
005import java.io.IOException;
006
007/*
008 * #%L
009 * HAPI FHIR - Core Library
010 * %%
011 * Copyright (C) 2014 - 2017 University Health Network
012 * %%
013 * Licensed under the Apache License, Version 2.0 (the "License");
014 * you may not use this file except in compliance with the License.
015 * You may obtain a copy of the License at
016 * 
017 *      http://www.apache.org/licenses/LICENSE-2.0
018 * 
019 * Unless required by applicable law or agreed to in writing, software
020 * distributed under the License is distributed on an "AS IS" BASIS,
021 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
022 * See the License for the specific language governing permissions and
023 * limitations under the License.
024 * #L%
025 */
026
027import java.io.UnsupportedEncodingException;
028import java.net.URLEncoder;
029import java.util.Date;
030import java.util.Map.Entry;
031
032import javax.servlet.ServletException;
033import javax.servlet.http.HttpServletRequest;
034import javax.servlet.http.HttpServletResponse;
035
036import org.apache.commons.lang3.StringUtils;
037import org.apache.commons.lang3.Validate;
038import org.apache.commons.lang3.text.StrLookup;
039import org.apache.commons.lang3.text.StrSubstitutor;
040import org.slf4j.Logger;
041import org.slf4j.LoggerFactory;
042
043import ca.uhn.fhir.rest.method.RequestDetails;
044import ca.uhn.fhir.rest.server.Constants;
045import ca.uhn.fhir.rest.server.EncodingEnum;
046import ca.uhn.fhir.rest.server.RestfulServer;
047import ca.uhn.fhir.rest.server.RestfulServerUtils;
048import ca.uhn.fhir.rest.server.RestfulServerUtils.ResponseEncoding;
049import ca.uhn.fhir.rest.server.exceptions.BaseServerResponseException;
050import ca.uhn.fhir.rest.server.servlet.ServletRequestDetails;
051
052/**
053 * Server interceptor which logs each request using a defined format
054 * <p>
055 * The following substitution variables are supported:
056 * </p>
057 * <table summary="Substitution variables supported by this class">
058 * <tr>
059 * <td>${id}</td>
060 * <td>The resource ID associated with this request (or "" if none)</td>
061 * </tr>
062 * <tr>
063 * <td>${idOrResourceName}</td>
064 * <td>The resource ID associated with this request, or the resource name if the request applies to a type but not an
065 * instance, or "" otherwise</td>
066 * </tr>
067 * <tr>
068 * <td>${operationName}</td>
069 * <td>If the request is an extended operation (e.g. "$validate") this value will be the operation name, or ""
070 * otherwise</td>
071 * </tr>
072 * <tr>
073 * <td>${operationType}</td>
074 * <td>A code indicating the operation type for this request, e.g. "read", "history-instance",
075 * "extended-operation-instance", etc.)</td>
076 * </tr>
077 * <tr>
078 * <td>${remoteAddr}</td>
079 * <td>The originating IP of the request</td>
080 * </tr>
081 * <tr>
082 * <td>${requestHeader.XXXX}</td>
083 * <td>The value of the HTTP request header named XXXX. For example, a substitution variable named
084 * "${requestHeader.x-forwarded-for} will yield the value of the first header named "x-forwarded-for
085 * ", or "" if none.</td>
086 * </tr>
087 * <tr>
088 * <td>${requestParameters}</td>
089 * <td>The HTTP request parameters (or "")</td>
090 * </tr>
091 * <tr>
092 * <td>${responseEncodingNoDefault}</td>
093 * <td>The encoding format requested by the client via the _format parameter or the Accept header. Value will be "json"
094 * or "xml", or "" if the client did not explicitly request a format</td>
095 * </tr>
096 * <tr>
097 * <td>${servletPath}</td>
098 * <td>The part of thre requesting URL that corresponds to the particular Servlet being called (see
099 * {@link HttpServletRequest#getServletPath()})</td>
100 * </tr>
101 * <tr>
102 * <td>${requestBodyFhir}</td>
103 * <td>The complete body of the request if the request has a FHIR content-type (this can be quite large!). Will emit an
104 * empty string if the content type is not a FHIR content type</td>
105 * </tr>
106 * <tr>
107 * <td>${requestUrl}</td>
108 * <td>The complete URL of the request</td>
109 * </tr>
110 * <tr>
111 * <td>${requestVerb}</td>
112 * <td>The HTTP verb of the request</td>
113 * </tr>
114 * <tr>
115 * <td>${exceptionMessage}</td>
116 * <td>Applies only to an error message: The message from {@link Exception#getMessage()}</td>
117 * </tr>
118 * </table>
119 */
120
121/*
122 * TODO: implement this, but it needs the logging to happen at the end
123 * <tr>
124 * <td>${processingTimeMillis}</td>
125 * <td>The number of milliseconds spent processing this request</td>
126 * </tr>
127
128 */
129public class LoggingInterceptor extends InterceptorAdapter {
130
131        private static final org.slf4j.Logger ourLog = org.slf4j.LoggerFactory.getLogger(LoggingInterceptor.class);
132
133        private String myErrorMessageFormat = "ERROR - ${operationType} - ${idOrResourceName}";
134        private boolean myLogExceptions = true;
135        private Logger myLogger = ourLog;
136        private String myMessageFormat = "${operationType} - ${idOrResourceName}";
137
138        /**
139         * Constructor for server logging interceptor
140         */
141        public LoggingInterceptor() {
142                super();
143        }
144        
145        /**
146         * Get the log message format to be used when logging exceptions
147         */
148        public String getErrorMessageFormat() {
149                return myErrorMessageFormat;
150        }
151
152        @Override
153        public boolean handleException(RequestDetails theRequestDetails, BaseServerResponseException theException, HttpServletRequest theServletRequest, HttpServletResponse theServletResponse) throws ServletException, IOException {
154                if (myLogExceptions) {
155                        // Perform any string substitutions from the message format
156                        StrLookup<?> lookup = new MyLookup(theServletRequest, theException, theRequestDetails);
157                        StrSubstitutor subs = new StrSubstitutor(lookup, "${", "}", '\\');
158
159                        // Actuall log the line
160                        String line = subs.replace(myErrorMessageFormat);
161                        myLogger.info(line);
162
163                }
164                return true;
165        }
166
167
168        @Override
169        public void processingCompletedNormally(ServletRequestDetails theRequestDetails) {
170                // Perform any string substitutions from the message format
171                StrLookup<?> lookup = new MyLookup(theRequestDetails.getServletRequest(), theRequestDetails);
172                StrSubstitutor subs = new StrSubstitutor(lookup, "${", "}", '\\');
173
174                // Actuall log the line
175                String line = subs.replace(myMessageFormat);
176                myLogger.info(line);
177        }
178
179        /**
180         * Should exceptions be logged by this logger
181         */
182        public boolean isLogExceptions() {
183                return myLogExceptions;
184        }
185
186        /**
187         * Set the log message format to be used when logging exceptions
188         */
189        public void setErrorMessageFormat(String theErrorMessageFormat) {
190                Validate.notBlank(theErrorMessageFormat, "Message format can not be null/empty");
191                myErrorMessageFormat = theErrorMessageFormat;
192        }
193
194        /**
195         * Should exceptions be logged by this logger
196         */
197        public void setLogExceptions(boolean theLogExceptions) {
198                myLogExceptions = theLogExceptions;
199        }
200
201        public void setLogger(Logger theLogger) {
202                Validate.notNull(theLogger, "Logger can not be null");
203                myLogger = theLogger;
204        }
205
206        public void setLoggerName(String theLoggerName) {
207                Validate.notBlank(theLoggerName, "Logger name can not be null/empty");
208                myLogger = LoggerFactory.getLogger(theLoggerName);
209
210        }
211
212        /**
213         * Sets the message format itself. See the {@link LoggingInterceptor class documentation} for information on the
214         * format
215         */
216        public void setMessageFormat(String theMessageFormat) {
217                Validate.notBlank(theMessageFormat, "Message format can not be null/empty");
218                myMessageFormat = theMessageFormat;
219        }
220
221        private static final class MyLookup extends StrLookup<String> {
222                private final Throwable myException;
223                private final HttpServletRequest myRequest;
224                private final RequestDetails myRequestDetails;
225
226                private MyLookup(HttpServletRequest theRequest, RequestDetails theRequestDetails) {
227                        myRequest = theRequest;
228                        myRequestDetails = theRequestDetails;
229                        myException = null;
230                }
231
232                public MyLookup(HttpServletRequest theServletRequest, BaseServerResponseException theException, RequestDetails theRequestDetails) {
233                        myException = theException;
234                        myRequestDetails = theRequestDetails;
235                        myRequest = theServletRequest;
236                }
237
238                @Override
239                public String lookup(String theKey) {
240
241                        /*
242                         * TODO: this method could be made more efficient through some sort of lookup map
243                         */
244
245                        if ("operationType".equals(theKey)) {
246                                if (myRequestDetails.getRestOperationType() != null) {
247                                        return myRequestDetails.getRestOperationType().getCode();
248                                }
249                                return "";
250                        } else if ("operationName".equals(theKey)) {
251                                if (myRequestDetails.getRestOperationType() != null) {
252                                        switch (myRequestDetails.getRestOperationType()) {
253                                        case EXTENDED_OPERATION_INSTANCE:
254                                        case EXTENDED_OPERATION_SERVER:
255                                        case EXTENDED_OPERATION_TYPE:
256                                                return myRequestDetails.getOperation();
257                                        default:
258                                                return "";
259                                        }
260                                }
261                                        return "";
262                        } else if ("id".equals(theKey)) {
263                                if (myRequestDetails.getId() != null) {
264                                        return myRequestDetails.getId().getValue();
265                                }
266                                return "";
267                        } else if ("servletPath".equals(theKey)) {
268                                return StringUtils.defaultString(myRequest.getServletPath());
269                        } else if ("idOrResourceName".equals(theKey)) {
270                                if (myRequestDetails.getId() != null) {
271                                        return myRequestDetails.getId().getValue();
272                                }
273                                if (myRequestDetails.getResourceName() != null) {
274                                        return myRequestDetails.getResourceName();
275                                }
276                                return "";
277                        } else if (theKey.equals("requestParameters")) {
278                                StringBuilder b = new StringBuilder();
279                                for (Entry<String, String[]> next : myRequestDetails.getParameters().entrySet()) {
280                                        for (String nextValue : next.getValue()) {
281                                                if (b.length() == 0) {
282                                                        b.append('?');
283                                                } else {
284                                                        b.append('&');
285                                                }
286                                                try {
287                                                        b.append(URLEncoder.encode(next.getKey(), "UTF-8"));
288                                                        b.append('=');
289                                                        b.append(URLEncoder.encode(nextValue, "UTF-8"));
290                                                } catch (UnsupportedEncodingException e) {
291                                                        throw new ca.uhn.fhir.context.ConfigurationException("UTF-8 not supported", e);
292                                                }
293                                        }
294                                }
295                                return b.toString();
296                        } else if (theKey.startsWith("requestHeader.")) {
297                                String val = myRequest.getHeader(theKey.substring("requestHeader.".length()));
298                                return StringUtils.defaultString(val);
299                        } else if (theKey.startsWith("remoteAddr")) {
300                                return StringUtils.defaultString(myRequest.getRemoteAddr());
301                        } else if (theKey.equals("responseEncodingNoDefault")) {
302                                ResponseEncoding encoding = RestfulServerUtils.determineResponseEncodingNoDefault(myRequestDetails, myRequestDetails.getServer().getDefaultResponseEncoding());
303                                if (encoding != null) {
304                                        return encoding.getEncoding().name();
305                                }
306                                return "";
307                        } else if (theKey.equals("exceptionMessage")) {
308                                return myException != null ? myException.getMessage() : null;
309                        } else if (theKey.equals("requestUrl")) {
310                                return myRequest.getRequestURL().toString();
311                        } else if (theKey.equals("requestVerb")) {
312                                return myRequest.getMethod();
313                        } else if (theKey.equals("requestBodyFhir")) {
314                                String contentType = myRequest.getContentType();
315                                if (isNotBlank(contentType)) {
316                                        int colonIndex = contentType.indexOf(';');
317                                        if (colonIndex != -1) {
318                                                contentType = contentType.substring(0, colonIndex);
319                                        }
320                                        contentType = contentType.trim();
321
322                                        EncodingEnum encoding = EncodingEnum.forContentType(contentType);
323                                        if (encoding != null) {
324                                                byte[] requestContents = myRequestDetails.loadRequestContents();
325                                                return new String(requestContents, Constants.CHARSET_UTF8);
326                                        }
327                                }
328                                return "";
329                        } else if ("processingTimeMillis".equals(theKey)) {
330                                Date startTime = (Date) myRequest.getAttribute(RestfulServer.REQUEST_START_TIME);
331                                if (startTime != null) {
332                                        long time = System.currentTimeMillis() - startTime.getTime();
333                                        return Long.toString(time);
334                                }
335                        }
336
337                        return "!VAL!";
338                }
339        }
340
341}