ATLAS-1030: performance trace instrumentation for REST APIs

common/src/main/java/org/apache/atlas/utils/AtlasPerfTracer.java

+/**
+ * Licensed to the Apache Software Foundation (ASF) under one
+ * or more contributor license agreements.  See the NOTICE file
+ * distributed with this work for additional information
+ * regarding copyright ownership.  The ASF licenses this file
+ * to you under the Apache License, Version 2.0 (the
+ * "License"); you may not use this file except in compliance
+ * with the License.  You may obtain a copy of the License at
+ *
+ *     http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License.
+ */
+package org.apache.atlas.utils;
+
+import org.slf4j.Logger;
+import org.slf4j.LoggerFactory;
+
+
+/**
+ * Handles logging of performance measurements.
+ */
+public final class AtlasPerfTracer {
+    protected final Logger logger;
+    protected final String tag;
+    private   final long   startTimeMs;
+
+    private static long reportingThresholdMs = 0L;
+
+    public static Logger getPerfLogger(String name) {
+        return LoggerFactory.getLogger("org.apache.atlas.perf." + name);
+    }
+
+    public static Logger getPerfLogger(Class<?> cls) {
+        return AtlasPerfTracer.getPerfLogger(cls.getName());
+    }
+
+    public static boolean isPerfTraceEnabled(Logger logger) {
+        return logger.isDebugEnabled();
+    }
+
+    public static AtlasPerfTracer getPerfTracer(Logger logger, String tag) {
+        return new AtlasPerfTracer(logger, tag);
+    }
+
+    public static void log(AtlasPerfTracer tracer) {
+        if (tracer != null) {
+            tracer.log();
+        }
+    }
+
+    private AtlasPerfTracer(Logger logger, String tag) {
+        this.logger = logger;
+        this.tag    = tag;
+        startTimeMs = System.currentTimeMillis();
+    }
+
+    public String getTag() {
+        return tag;
+    }
+
+    public long getStartTime() {
+        return startTimeMs;
+    }
+
+    public long getElapsedTime() {
+        return System.currentTimeMillis() - startTimeMs;
+    }
+
+    public void log() {
+        long elapsedTime = getElapsedTime();
+        if (elapsedTime > reportingThresholdMs) {
+            logger.debug("PERF|" + tag + "|" + elapsedTime);
+        }
+    }
+}

distro/src/conf/atlas-log4j.xml

@@ -48,6 +48,22 @@
         <appender-ref ref="FILE"/>
     </logger>
 
+    <!-- uncomment this block to generate performance traces
+    <appender name="perf_appender" class="org.apache.log4j.DailyRollingFileAppender">
+        <param name="file" value="${atlas.log.dir}/atlas_perf.log" />
+        <param name="datePattern" value="'.'yyyy-MM-dd" />
+        <param name="append" value="true" />
+        <layout class="org.apache.log4j.PatternLayout">
+            <param name="ConversionPattern" value="%d|%t|%m%n" />
+        </layout>
+    </appender>
+
+    <logger name="org.apache.atlas.perf" additivity="false">
+        <level value="debug" />
+        <appender-ref ref="perf_appender" />
+    </logger>
+    -->
+
     <logger name="com.thinkaurelius.titan" additivity="false">
         <level value="warn"/>
         <appender-ref ref="FILE"/>

typesystem/src/main/resources/atlas-log4j.xml

@@ -41,6 +41,22 @@
         <appender-ref ref="console"/>
     </logger>
 
+    <!-- uncomment this block to generate performance traces
+    <appender name="perf_appender" class="org.apache.log4j.DailyRollingFileAppender">
+        <param name="file" value="${atlas.log.dir}/atlas_perf.log" />
+        <param name="datePattern" value="'.'yyyy-MM-dd" />
+        <param name="append" value="true" />
+        <layout class="org.apache.log4j.PatternLayout">
+            <param name="ConversionPattern" value="%d|%t|%m%n" />
+        </layout>
+    </appender>
+
+    <logger name="org.apache.atlas.perf" additivity="false">
+        <level value="debug" />
+        <appender-ref ref="perf_appender" />
+    </logger>
+    -->
+
     <logger name="com.thinkaurelius.titan" additivity="false">
         <level value="info"/>
         <appender-ref ref="console"/>

webapp/src/main/java/org/apache/atlas/web/resources/AdminResource.java

@@ -31,6 +31,7 @@ import javax.ws.rs.core.MediaType;
 import javax.ws.rs.core.Response;
 
 import org.apache.atlas.AtlasClient;
+import org.apache.atlas.utils.AtlasPerfTracer;
 import org.apache.atlas.web.filters.AtlasCSRFPreventionFilter;
 import org.apache.atlas.web.service.ServiceState;
 import org.apache.atlas.web.util.Servlets;
@@ -39,6 +40,7 @@ import org.apache.commons.configuration.PropertiesConfiguration;
 import org.apache.commons.lang.StringUtils;
 import org.codehaus.jettison.json.JSONException;
 import org.codehaus.jettison.json.JSONObject;
+import org.slf4j.Logger;
 import org.springframework.security.core.Authentication;
 import org.springframework.security.core.GrantedAuthority;
 import org.springframework.security.core.context.SecurityContextHolder;
@@ -51,6 +53,7 @@ import com.google.inject.Inject;
 @Path("admin")
 @Singleton
 public class AdminResource {
+    private static final Logger PERF_LOG = AtlasPerfTracer.getPerfLogger("rest.AdminResource");
 
     private static final String isCSRF_ENABLED = "atlas.rest-csrf.enabled";
     private static final String BROWSER_USER_AGENT_PARAM = "atlas.rest-csrf.browser-useragents-regex";
@@ -75,6 +78,13 @@ public class AdminResource {
     @Path("stack")
     @Produces(MediaType.TEXT_PLAIN)
     public String getThreadDump() {
+        AtlasPerfTracer perf = null;
+
+        try {
+            if (AtlasPerfTracer.isPerfTraceEnabled(PERF_LOG)) {
+                perf = AtlasPerfTracer.getPerfTracer(PERF_LOG, "AdminResource.getThreadDump()");
+            }
+
             ThreadGroup topThreadGroup = Thread.currentThread().getThreadGroup();
 
             while (topThreadGroup.getParent() != null) {
@@ -91,6 +101,9 @@ public class AdminResource {
                 builder.append(stackTrace);
             }
             return builder.toString();
+        } finally {
+            AtlasPerfTracer.log(perf);
+        }
     }
 
     /**
@@ -102,6 +115,13 @@ public class AdminResource {
     @Path("version")
     @Produces(Servlets.JSON_MEDIA_TYPE)
     public Response getVersion() {
+        AtlasPerfTracer perf = null;
+
+        try {
+            if (AtlasPerfTracer.isPerfTraceEnabled(PERF_LOG)) {
+                perf = AtlasPerfTracer.getPerfTracer(PERF_LOG, "AdminResource.getVersion()");
+            }
+
             if (version == null) {
                 try {
                     PropertiesConfiguration configProperties = new PropertiesConfiguration("atlas-buildinfo.properties");
@@ -121,12 +141,22 @@ public class AdminResource {
             }
 
             return version;
+        } finally {
+            AtlasPerfTracer.log(perf);
+        }
     }
 
     @GET
     @Path("status")
     @Produces(Servlets.JSON_MEDIA_TYPE)
     public Response getStatus() {
+        AtlasPerfTracer perf = null;
+
+        try {
+            if (AtlasPerfTracer.isPerfTraceEnabled(PERF_LOG)) {
+                perf = AtlasPerfTracer.getPerfTracer(PERF_LOG, "AdminResource.getStatus()");
+            }
+
             JSONObject responseData = new JSONObject();
             try {
                 responseData.put(AtlasClient.STATUS, serviceState.getState().toString());
@@ -135,6 +165,9 @@ public class AdminResource {
             } catch (JSONException e) {
                 throw new WebApplicationException(Servlets.getErrorResponse(e, Response.Status.INTERNAL_SERVER_ERROR));
             }
+        } finally {
+            AtlasPerfTracer.log(perf);
+        }
     }
     
     @GET
@@ -143,7 +176,12 @@ public class AdminResource {
     public Response getUserProfile() {
         JSONObject responseData = new JSONObject();
         Boolean enableTaxonomy = null;
+        AtlasPerfTracer perf = null;
         try {
+            if (AtlasPerfTracer.isPerfTraceEnabled(PERF_LOG)) {
+                perf = AtlasPerfTracer.getPerfTracer(PERF_LOG, "AdminResource.getUserProfile()");
+            }
+
             PropertiesConfiguration configProperties = new PropertiesConfiguration("atlas-application.properties");
             enableTaxonomy = new Boolean(configProperties.getString(isTaxonomyEnabled, "false"));
             Authentication auth = SecurityContextHolder.getContext().getAuthentication();
@@ -170,6 +208,8 @@ public class AdminResource {
             return response;
         } catch (JSONException | ConfigurationException e) {
             throw new WebApplicationException(Servlets.getErrorResponse(e, Response.Status.INTERNAL_SERVER_ERROR));
+        } finally {
+            AtlasPerfTracer.log(perf);
         }
     }
 }

webapp/src/main/java/org/apache/atlas/web/resources/DataSetLineageResource.java

@@ -22,6 +22,7 @@ import org.apache.atlas.AtlasClient;
 import org.apache.atlas.discovery.DiscoveryException;
 import org.apache.atlas.discovery.LineageService;
 import org.apache.atlas.typesystem.exception.EntityNotFoundException;
+import org.apache.atlas.utils.AtlasPerfTracer;
 import org.apache.atlas.web.util.Servlets;
 import org.codehaus.jettison.json.JSONObject;
 import org.slf4j.Logger;
@@ -47,6 +48,7 @@ import javax.ws.rs.core.Response;
 public class DataSetLineageResource {
 
     private static final Logger LOG = LoggerFactory.getLogger(DataSetLineageResource.class);
+    private static final Logger PERF_LOG = AtlasPerfTracer.getPerfLogger("rest.DataSetLineageResource");
 
     private final LineageService lineageService;
 
@@ -73,7 +75,12 @@ public class DataSetLineageResource {
     public Response inputsGraph(@Context HttpServletRequest request, @PathParam("tableName") String tableName) {
         LOG.info("Fetching lineage inputs graph for tableName={}", tableName);
 
+        AtlasPerfTracer perf = null;
         try {
+            if (AtlasPerfTracer.isPerfTraceEnabled(PERF_LOG)) {
+                perf = AtlasPerfTracer.getPerfTracer(PERF_LOG, "DataSetLineageResource.inputsGraph(" + tableName + ")");
+            }
+
             final String jsonResult = lineageService.getInputsGraph(tableName);
 
             JSONObject response = new JSONObject();
@@ -91,6 +98,8 @@ public class DataSetLineageResource {
         } catch (Throwable e) {
             LOG.error("Unable to get lineage inputs graph for table {}", tableName, e);
             throw new WebApplicationException(Servlets.getErrorResponse(e, Response.Status.INTERNAL_SERVER_ERROR));
+        } finally {
+            AtlasPerfTracer.log(perf);
         }
     }
 
@@ -106,7 +115,12 @@ public class DataSetLineageResource {
     public Response outputsGraph(@Context HttpServletRequest request, @PathParam("tableName") String tableName) {
         LOG.info("Fetching lineage outputs graph for tableName={}", tableName);
 
+        AtlasPerfTracer perf = null;
         try {
+            if (AtlasPerfTracer.isPerfTraceEnabled(PERF_LOG)) {
+                perf = AtlasPerfTracer.getPerfTracer(PERF_LOG, "DataSetLineageResource.outputsGraph(" + tableName + ")");
+            }
+
             final String jsonResult = lineageService.getOutputsGraph(tableName);
 
             JSONObject response = new JSONObject();
@@ -124,6 +138,8 @@ public class DataSetLineageResource {
         } catch (Throwable e) {
             LOG.error("Unable to get lineage outputs graph for table {}", tableName, e);
             throw new WebApplicationException(Servlets.getErrorResponse(e, Response.Status.INTERNAL_SERVER_ERROR));
+        } finally {
+            AtlasPerfTracer.log(perf);
         }
     }
 
@@ -139,7 +155,12 @@ public class DataSetLineageResource {
     public Response schema(@Context HttpServletRequest request, @PathParam("tableName") String tableName) {
         LOG.info("Fetching schema for tableName={}", tableName);
 
+        AtlasPerfTracer perf = null;
         try {
+            if (AtlasPerfTracer.isPerfTraceEnabled(PERF_LOG)) {
+                perf = AtlasPerfTracer.getPerfTracer(PERF_LOG, "DataSetLineageResource.schema(" + tableName + ")");
+            }
+
             final String jsonResult = lineageService.getSchema(tableName);
 
             JSONObject response = new JSONObject();
@@ -157,6 +178,8 @@ public class DataSetLineageResource {
         } catch (Throwable e) {
             LOG.error("Unable to get schema for table {}", tableName, e);
             throw new WebApplicationException(Servlets.getErrorResponse(e, Response.Status.INTERNAL_SERVER_ERROR));
+        } finally {
+            AtlasPerfTracer.log(perf);
         }
     }
 }

webapp/src/main/java/org/apache/atlas/web/resources/EntityService.java

@@ -22,7 +22,9 @@ import org.apache.atlas.AtlasException;
 import org.apache.atlas.catalog.*;
 import org.apache.atlas.catalog.exception.CatalogException;
 import org.apache.atlas.services.MetadataService;
+import org.apache.atlas.utils.AtlasPerfTracer;
 import org.apache.atlas.web.util.Servlets;
+import org.slf4j.Logger;
 
 import javax.inject.Inject;
 import javax.inject.Singleton;
@@ -36,6 +38,7 @@ import java.util.*;
 @Path("v1/entities")
 @Singleton
 public class EntityService extends BaseService {
+    private static final Logger PERF_LOG = AtlasPerfTracer.getPerfLogger("rest.EntityService");
 
     private final EntityResourceProvider entityResourceProvider;
     private final EntityTagResourceProvider entityTagResourceProvider;
@@ -50,12 +53,21 @@ public class EntityService extends BaseService {
     @GET
     @Produces(Servlets.JSON_MEDIA_TYPE)
     public Response getEntities(@Context HttpHeaders headers, @Context UriInfo ui) throws CatalogException {
+        AtlasPerfTracer perf = null;
+        try {
+            if (AtlasPerfTracer.isPerfTraceEnabled(PERF_LOG)) {
+                perf = AtlasPerfTracer.getPerfTracer(PERF_LOG, "EntityService.getEntities()");
+            }
+
             String queryString = decode(getQueryString(ui));
 
             BaseRequest request = new CollectionRequest(Collections.<String, Object>emptyMap(), queryString);
             Result result = getResources(entityResourceProvider, request);
 
             return Response.status(Response.Status.OK).entity(getSerializer().serialize(result, ui)).build();
+        } finally {
+            AtlasPerfTracer.log(perf);
+        }
     }
 
     @GET
@@ -64,11 +76,19 @@ public class EntityService extends BaseService {
     public Response getEntity(@Context HttpHeaders headers,
                               @Context UriInfo ui,
                               @PathParam("entityId") String entityId) throws CatalogException {
+        AtlasPerfTracer perf = null;
+        try {
+            if (AtlasPerfTracer.isPerfTraceEnabled(PERF_LOG)) {
+                perf = AtlasPerfTracer.getPerfTracer(PERF_LOG, "EntityService.getEntity(" + entityId + ")");
+            }
 
             BaseRequest request = new InstanceRequest(Collections.<String, Object>singletonMap("id", entityId));
             Result result = getResource(entityResourceProvider, request);
 
             return Response.status(Response.Status.OK).entity(getSerializer().serialize(result, ui)).build();
+        } finally {
+            AtlasPerfTracer.log(perf);
+        }
     }
 
     @GET
@@ -78,6 +98,11 @@ public class EntityService extends BaseService {
                                  @Context UriInfo ui,
                                  @PathParam("entityId") String entityId,
                                  @PathParam("tag") String tagName) throws CatalogException {
+        AtlasPerfTracer perf = null;
+        try {
+            if (AtlasPerfTracer.isPerfTraceEnabled(PERF_LOG)) {
+                perf = AtlasPerfTracer.getPerfTracer(PERF_LOG, "EntityService.getEntityTag(" + entityId + ", " + tagName + ")");
+            }
 
             Map<String, Object> properties = new HashMap<>();
             properties.put("id", entityId);
@@ -85,6 +110,9 @@ public class EntityService extends BaseService {
             Result result = getResource(entityTagResourceProvider, new InstanceRequest(properties));
 
             return Response.status(Response.Status.OK).entity(getSerializer().serialize(result, ui)).build();
+        } finally {
+            AtlasPerfTracer.log(perf);
+        }
     }
 
     @GET
@@ -93,12 +121,20 @@ public class EntityService extends BaseService {
     public Response getEntityTags(@Context HttpHeaders headers,
                                   @Context UriInfo ui,
                                   @PathParam("entityId") String entityGuid) throws CatalogException {
+        AtlasPerfTracer perf = null;
+        try {
+            if (AtlasPerfTracer.isPerfTraceEnabled(PERF_LOG)) {
+                perf = AtlasPerfTracer.getPerfTracer(PERF_LOG, "EntityService.getEntityTags(" + entityGuid + ")");
+            }
 
             BaseRequest request = new CollectionRequest(Collections.<String, Object>singletonMap("id", entityGuid),
                     decode(getQueryString(ui)));
             Result result = getResources(entityTagResourceProvider, request);
 
             return Response.status(Response.Status.OK).entity(getSerializer().serialize(result, ui)).build();
+        } finally {
+            AtlasPerfTracer.log(perf);
+        }
     }
 
     @POST
@@ -109,6 +145,11 @@ public class EntityService extends BaseService {
                               @Context UriInfo ui,
                               @PathParam("entityId") String entityId,
                               @PathParam("tag") String tagName) throws CatalogException {
+        AtlasPerfTracer perf = null;
+        try {
+            if (AtlasPerfTracer.isPerfTraceEnabled(PERF_LOG)) {
+                perf = AtlasPerfTracer.getPerfTracer(PERF_LOG, "EntityService.tagEntity(" + entityId + ", " + tagName + ")");
+            }
 
             Map<String, Object> properties = new HashMap<>();
             properties.put("id", entityId);
@@ -117,6 +158,9 @@ public class EntityService extends BaseService {
 
             return Response.status(Response.Status.CREATED).entity(
                     new Results(ui.getRequestUri().toString(), 201)).build();
+        } finally {
+            AtlasPerfTracer.log(perf);
+        }
     }
 
     @POST
@@ -124,6 +168,11 @@ public class EntityService extends BaseService {
     public Response tagEntities(String body,
                                 @Context HttpHeaders headers,
                                 @Context UriInfo ui) throws CatalogException {
+        AtlasPerfTracer perf = null;
+        try {
+            if (AtlasPerfTracer.isPerfTraceEnabled(PERF_LOG)) {
+                perf = AtlasPerfTracer.getPerfTracer(PERF_LOG, "EntityService.tagEntities()");
+            }
 
             Map<String, Object> properties = parsePayload(body);
 
@@ -142,7 +191,11 @@ public class EntityService extends BaseService {
             }
 
             return Response.status(Response.Status.CREATED).entity(
-                new GenericEntity<Collection<Results>>(result) {}).build();
+                    new GenericEntity<Collection<Results>>(result) {
+                    }).build();
+        } finally {
+            AtlasPerfTracer.log(perf);
+        }
     }
 
     @DELETE
@@ -152,6 +205,11 @@ public class EntityService extends BaseService {
                                     @Context UriInfo ui,
                                     @PathParam("entityId") String entityId,
                                     @PathParam("tag") String tagName) throws CatalogException {
+        AtlasPerfTracer perf = null;
+        try {
+            if (AtlasPerfTracer.isPerfTraceEnabled(PERF_LOG)) {
+                perf = AtlasPerfTracer.getPerfTracer(PERF_LOG, "EntityService.deleteEntityTag()");
+            }
 
             Map<String, Object> properties = new HashMap<>();
             properties.put("id", entityId);
@@ -160,5 +218,8 @@ public class EntityService extends BaseService {
 
             return Response.status(Response.Status.OK).entity(
                     new Results(ui.getRequestUri().toString(), 200)).build();
+        } finally {
+            AtlasPerfTracer.log(perf);
+        }
     }
 }

webapp/src/main/java/org/apache/atlas/web/resources/LineageResource.java

@@ -22,6 +22,7 @@ import org.apache.atlas.AtlasClient;
 import org.apache.atlas.discovery.DiscoveryException;
 import org.apache.atlas.discovery.LineageService;
 import org.apache.atlas.typesystem.exception.EntityNotFoundException;
+import org.apache.atlas.utils.AtlasPerfTracer;
 import org.apache.atlas.web.util.Servlets;
 import org.codehaus.jettison.json.JSONObject;
 import org.slf4j.Logger;
@@ -41,6 +42,7 @@ import javax.ws.rs.core.Response;
 @Singleton
 public class LineageResource {
     private static final Logger LOG = LoggerFactory.getLogger(DataSetLineageResource.class);
+    private static final Logger PERF_LOG = AtlasPerfTracer.getPerfLogger("rest.LineageResource");
 
     private final LineageService lineageService;
 
@@ -67,7 +69,12 @@ public class LineageResource {
     public Response inputsGraph(@PathParam("guid") String guid) {
         LOG.info("Fetching lineage inputs graph for guid={}", guid);
 
+        AtlasPerfTracer perf = null;
         try {
+            if (AtlasPerfTracer.isPerfTraceEnabled(PERF_LOG)) {
+                perf = AtlasPerfTracer.getPerfTracer(PERF_LOG, "LineageResource.inputsGraph(" + guid + ")");
+            }
+
             final String jsonResult = lineageService.getInputsGraphForEntity(guid);
 
             JSONObject response = new JSONObject();
@@ -84,6 +91,8 @@ public class LineageResource {
         } catch (Throwable e) {
             LOG.error("Unable to get lineage inputs graph for entity guid={}", guid, e);
             throw new WebApplicationException(Servlets.getErrorResponse(e, Response.Status.INTERNAL_SERVER_ERROR));
+        } finally {
+            AtlasPerfTracer.log(perf);
         }
     }
 
@@ -99,7 +108,12 @@ public class LineageResource {
     public Response outputsGraph(@PathParam("guid") String guid) {
         LOG.info("Fetching lineage outputs graph for entity guid={}", guid);
 
+        AtlasPerfTracer perf = null;
         try {
+            if (AtlasPerfTracer.isPerfTraceEnabled(PERF_LOG)) {
+                perf = AtlasPerfTracer.getPerfTracer(PERF_LOG, "LineageResource.outputsGraph(" + guid + ")");
+            }
+
             final String jsonResult = lineageService.getOutputsGraphForEntity(guid);
 
             JSONObject response = new JSONObject();
@@ -116,6 +130,8 @@ public class LineageResource {
         } catch (Throwable e) {
             LOG.error("Unable to get lineage outputs graph for entity guid={}", guid, e);
             throw new WebApplicationException(Servlets.getErrorResponse(e, Response.Status.INTERNAL_SERVER_ERROR));
+        } finally {
+            AtlasPerfTracer.log(perf);
         }
     }
 
@@ -131,7 +147,12 @@ public class LineageResource {
     public Response schema(@PathParam("guid") String guid) {
         LOG.info("Fetching schema for entity guid={}", guid);
 
+        AtlasPerfTracer perf = null;
         try {
+            if (AtlasPerfTracer.isPerfTraceEnabled(PERF_LOG)) {
+                perf = AtlasPerfTracer.getPerfTracer(PERF_LOG, "LineageResource.schema(" + guid + ")");
+            }
+
             final String jsonResult = lineageService.getSchemaForEntity(guid);
 
             JSONObject response = new JSONObject();
@@ -148,6 +169,8 @@ public class LineageResource {
         } catch (Throwable e) {
             LOG.error("Unable to get schema for entity={}", guid, e);
             throw new WebApplicationException(Servlets.getErrorResponse(e, Response.Status.INTERNAL_SERVER_ERROR));
+        } finally {
+            AtlasPerfTracer.log(perf);
         }
     }
 }

webapp/src/main/java/org/apache/atlas/web/resources/MetadataDiscoveryResource.java

@@ -20,6 +20,7 @@ package org.apache.atlas.web.resources;
 
 import com.google.common.base.Preconditions;
 import org.apache.atlas.AtlasClient;
+import org.apache.atlas.utils.AtlasPerfTracer;
 import org.apache.atlas.utils.ParamChecker;
 import org.apache.atlas.discovery.DiscoveryException;
 import org.apache.atlas.discovery.DiscoveryService;
@@ -51,6 +52,7 @@ import org.apache.hadoop.classification.InterfaceAudience;
 public class MetadataDiscoveryResource {
 
     private static final Logger LOG = LoggerFactory.getLogger(MetadataDiscoveryResource.class);
+    private static final Logger PERF_LOG = AtlasPerfTracer.getPerfLogger("rest.MetadataDiscoveryResource");
     private static final String QUERY_TYPE_DSL = "dsl";
     private static final String QUERY_TYPE_GREMLIN = "gremlin";
     private static final String QUERY_TYPE_FULLTEXT = "full-text";
@@ -80,7 +82,12 @@ public class MetadataDiscoveryResource {
     @Produces(Servlets.JSON_MEDIA_TYPE)
     public Response search(@QueryParam("query") String query) {
         JSONObject response;
+        AtlasPerfTracer perf = null;
         try {   // fall back to dsl
+            if (AtlasPerfTracer.isPerfTraceEnabled(PERF_LOG)) {
+                perf = AtlasPerfTracer.getPerfTracer(PERF_LOG, "MetadataDiscoveryResource.search(" + query + ")");
+            }
+
             ParamChecker.notEmpty(query, "query cannot be null");
 
             final String jsonResultStr = discoveryService.searchByDSL(query);
@@ -94,6 +101,8 @@ public class MetadataDiscoveryResource {
         } catch (Throwable throwable) {
             LOG.error("Unable to get entity list for query {} using dsl", query, throwable);
             return searchUsingFullText(query);
+        } finally {
+            AtlasPerfTracer.log(perf);
         }
     }
 
@@ -108,7 +117,12 @@ public class MetadataDiscoveryResource {
     @Consumes(Servlets.JSON_MEDIA_TYPE)
     @Produces(Servlets.JSON_MEDIA_TYPE)
     public Response searchUsingQueryDSL(@QueryParam("query") String dslQuery) {
+        AtlasPerfTracer perf = null;
         try {
+            if (AtlasPerfTracer.isPerfTraceEnabled(PERF_LOG)) {
+                perf = AtlasPerfTracer.getPerfTracer(PERF_LOG, "MetadataDiscoveryResource.searchUsingQueryDSL(" + dslQuery + ")");
+            }
+
             ParamChecker.notEmpty(dslQuery, "dslQuery cannot be null");
             final String jsonResultStr = discoveryService.searchByDSL(dslQuery);
 
@@ -121,6 +135,8 @@ public class MetadataDiscoveryResource {
         } catch (Throwable e) {
             LOG.error("Unable to get entity list for dslQuery {}", dslQuery, e);
             throw new WebApplicationException(Servlets.getErrorResponse(e, Response.Status.INTERNAL_SERVER_ERROR));
+        } finally {
+            AtlasPerfTracer.log(perf);
         }
     }
 
@@ -136,7 +152,12 @@ public class MetadataDiscoveryResource {
     @Produces(Servlets.JSON_MEDIA_TYPE)
     @InterfaceAudience.Private
     public Response searchUsingGremlinQuery(@QueryParam("query") String gremlinQuery) {
+        AtlasPerfTracer perf = null;
         try {
+            if (AtlasPerfTracer.isPerfTraceEnabled(PERF_LOG)) {
+                perf = AtlasPerfTracer.getPerfTracer(PERF_LOG, "MetadataDiscoveryResource.searchUsingGremlinQuery(" + gremlinQuery + ")");
+            }
+
             ParamChecker.notEmpty(gremlinQuery, "gremlinQuery cannot be null or empty");
             final List<Map<String, String>> results = discoveryService.searchByGremlin(gremlinQuery);
 
@@ -159,6 +180,8 @@ public class MetadataDiscoveryResource {
         } catch (Throwable e) {
             LOG.error("Unable to get entity list for gremlinQuery {}", gremlinQuery, e);
             throw new WebApplicationException(Servlets.getErrorResponse(e, Response.Status.INTERNAL_SERVER_ERROR));
+        } finally {
+            AtlasPerfTracer.log(perf);
         }
     }
 
@@ -173,7 +196,12 @@ public class MetadataDiscoveryResource {
     @Consumes(Servlets.JSON_MEDIA_TYPE)
     @Produces(Servlets.JSON_MEDIA_TYPE)
     public Response searchUsingFullText(@QueryParam("query") String query) {
+        AtlasPerfTracer perf = null;
         try {
+            if (AtlasPerfTracer.isPerfTraceEnabled(PERF_LOG)) {
+                perf = AtlasPerfTracer.getPerfTracer(PERF_LOG, "MetadataDiscoveryResource.searchUsingFullText(" + query + ")");
+            }
+
             ParamChecker.notEmpty(query, "query cannot be null or empty");
             final String jsonResultStr = discoveryService.searchByFullText(query);
             JSONArray rowsJsonArr = new JSONArray(jsonResultStr);
@@ -186,6 +214,8 @@ public class MetadataDiscoveryResource {
         } catch (Throwable e) {
             LOG.error("Unable to get entity list for query {}", query, e);
             throw new WebApplicationException(Servlets.getErrorResponse(e, Response.Status.INTERNAL_SERVER_ERROR));
+        } finally {
+            AtlasPerfTracer.log(perf);
         }
     }
 

webapp/src/main/java/org/apache/atlas/web/resources/TypesResource.java

@@ -24,6 +24,7 @@ import org.apache.atlas.AtlasException;
 import org.apache.atlas.services.MetadataService;
 import org.apache.atlas.typesystem.exception.TypeExistsException;
 import org.apache.atlas.typesystem.types.DataTypes;
+import org.apache.atlas.utils.AtlasPerfTracer;
 import org.apache.atlas.web.util.Servlets;
 import org.codehaus.jettison.json.JSONArray;
 import org.codehaus.jettison.json.JSONException;
@@ -62,6 +63,7 @@ import java.util.List;
 public class TypesResource {
 
     private static final Logger LOG = LoggerFactory.getLogger(TypesResource.class);
+    private static final Logger PERF_LOG = AtlasPerfTracer.getPerfLogger("rest.TypesResource");
 
     private final MetadataService metadataService;
 
@@ -80,7 +82,12 @@ public class TypesResource {
     @Consumes({Servlets.JSON_MEDIA_TYPE, MediaType.APPLICATION_JSON})
     @Produces(Servlets.JSON_MEDIA_TYPE)
     public Response submit(@Context HttpServletRequest request) {
+        AtlasPerfTracer perf = null;
         try {
+            if (AtlasPerfTracer.isPerfTraceEnabled(PERF_LOG)) {
+                perf = AtlasPerfTracer.getPerfTracer(PERF_LOG, "TypesResource.submit()");
+            }
+
             final String typeDefinition = Servlets.getRequestPayload(request);
             LOG.info("Creating type with definition {} ", typeDefinition);
 
@@ -108,6 +115,8 @@ public class TypesResource {
         } catch (Throwable e) {
             LOG.error("Unable to persist types", e);
             throw new WebApplicationException(Servlets.getErrorResponse(e, Response.Status.INTERNAL_SERVER_ERROR));
+        } finally {
+            AtlasPerfTracer.log(perf);
         }
     }
 
@@ -124,7 +133,12 @@ public class TypesResource {
     @Consumes({Servlets.JSON_MEDIA_TYPE, MediaType.APPLICATION_JSON})
     @Produces(Servlets.JSON_MEDIA_TYPE)
     public Response update(@Context HttpServletRequest request) {
+        AtlasPerfTracer perf = null;
         try {
+            if (AtlasPerfTracer.isPerfTraceEnabled(PERF_LOG)) {
+                perf = AtlasPerfTracer.getPerfTracer(PERF_LOG, "TypesResource.update()");
+            }
+
             final String typeDefinition = Servlets.getRequestPayload(request);
             LOG.info("Updating type with definition {} ", typeDefinition);
 
@@ -152,6 +166,8 @@ public class TypesResource {
         } catch (Throwable e) {
             LOG.error("Unable to persist types", e);
             throw new WebApplicationException(Servlets.getErrorResponse(e, Response.Status.INTERNAL_SERVER_ERROR));
+        } finally {
+            AtlasPerfTracer.log(perf);
         }
     }
 
@@ -164,7 +180,12 @@ public class TypesResource {
     @Path("{typeName}")
     @Produces(Servlets.JSON_MEDIA_TYPE)
     public Response getDefinition(@Context HttpServletRequest request, @PathParam("typeName") String typeName) {
+        AtlasPerfTracer perf = null;
         try {
+            if (AtlasPerfTracer.isPerfTraceEnabled(PERF_LOG)) {
+                perf = AtlasPerfTracer.getPerfTracer(PERF_LOG, "TypesResource.getDefinition(" + typeName + ")");
+            }
+
             final String typeDefinition = metadataService.getTypeDefinition(typeName);
 
             JSONObject response = new JSONObject();
@@ -182,6 +203,8 @@ public class TypesResource {
         } catch (Throwable e) {
             LOG.error("Unable to get type definition for type {}", typeName, e);
             throw new WebApplicationException(Servlets.getErrorResponse(e, Response.Status.INTERNAL_SERVER_ERROR));
+        } finally {
+            AtlasPerfTracer.log(perf);
         }
     }
 
@@ -197,7 +220,12 @@ public class TypesResource {
     @Produces(Servlets.JSON_MEDIA_TYPE)
     public Response getTypesByFilter(@Context HttpServletRequest request,
             @DefaultValue(TYPE_ALL) @QueryParam("type") String type) {
+        AtlasPerfTracer perf = null;
         try {
+            if (AtlasPerfTracer.isPerfTraceEnabled(PERF_LOG)) {
+                perf = AtlasPerfTracer.getPerfTracer(PERF_LOG, "TypesResource.getTypesByFilter(" + type + ")");
+            }
+
             List<String> result;
             if (TYPE_ALL.equals(type)) {
                 result = metadataService.getTypeNamesList();
@@ -219,6 +247,8 @@ public class TypesResource {
         } catch (Throwable e) {
             LOG.error("Unable to get types list", e);
             throw new WebApplicationException(Servlets.getErrorResponse(e, Response.Status.INTERNAL_SERVER_ERROR));
+        } finally {
+            AtlasPerfTracer.log(perf);
         }
     }
 }