Skip to content

Commit 8e649dd

Browse files
maeisabelle08maeisabelle08
committed
Added performance trace for Datahub core libraries
1 parent fe3b773 commit 8e649dd

File tree

6 files changed

+122
-41
lines changed

6 files changed

+122
-41
lines changed

‎marklogic-data-hub/src/main/java/com/marklogic/hub/DataHub.java‎

Lines changed: 34 additions & 9 deletions
Original file line numberDiff line numberDiff line change
@@ -32,6 +32,7 @@
3232
import org.slf4j.Logger;
3333
import org.slf4j.LoggerFactory;
3434
import org.springframework.core.io.ClassPathResource;
35+
import org.springframework.util.StopWatch;
3536
import org.springframework.web.client.ResourceAccessException;
3637

3738
import com.fasterxml.jackson.databind.JsonNode;
@@ -57,6 +58,7 @@
5758
import com.marklogic.hub.commands.UpdateRestApiServersCommand;
5859
import com.marklogic.hub.util.HubFileFilter;
5960
import com.marklogic.hub.util.HubModulesLoader;
61+
import com.marklogic.hub.util.PerformanceLogger;
6062
import com.marklogic.mgmt.ManageClient;
6163
import com.marklogic.mgmt.ManageConfig;
6264
import com.marklogic.mgmt.admin.AdminConfig;
@@ -103,6 +105,9 @@ public void setAssetInstallTimeFile(File assetInstallTimeFile) {
103105
* @return true if installed, false otherwise
104106
*/
105107
public boolean isInstalled() {
108+
109+
StopWatch stopWatch = PerformanceLogger.monitorTimeInsideMethod();
110+
106111
ServerManager sm = new ServerManager(client);
107112
DatabaseManager dm = new DatabaseManager(client);
108113

@@ -149,6 +154,9 @@ public boolean isInstalled() {
149154
finalDbExists && finalIndexesOn &&
150155
tracingDbExists && tracingIndexesOn);
151156
boolean forestsOk = (stagingForestsExist && finalForestsExist && tracingForestsExist);
157+
158+
PerformanceLogger.logTimeInsideMethod(stopWatch, this.getClass().getName(),
159+
"isInstalled", (Object[])null);
152160

153161
return (appserversOk && dbsOk && forestsOk);
154162
}
@@ -158,6 +166,7 @@ public boolean isInstalled() {
158166
* @throws ServerValidationException if the server is not compatible
159167
*/
160168
public void validateServer() throws ServerValidationException {
169+
StopWatch stopWatch = PerformanceLogger.monitorTimeInsideMethod();
161170
try {
162171
AdminManager am = getAdminManager();
163172
String versionString = am.getServerVersion();
@@ -170,6 +179,8 @@ public void validateServer() throws ServerValidationException {
170179
catch(ResourceAccessException e) {
171180
throw new ServerValidationException(e.toString());
172181
}
182+
PerformanceLogger.logTimeInsideMethod(stopWatch, this.getClass().getName(),
183+
"validateServer", (Object[])null);
173184
}
174185

175186
private AppConfig getAppConfig() throws IOException {
@@ -202,7 +213,8 @@ private AppConfig getAppConfig() throws IOException {
202213
* @throws IOException
203214
*/
204215
public void install() throws IOException {
205-
long startTime = System.nanoTime();
216+
StopWatch stopWatch = PerformanceLogger.monitorTimeInsideMethod();
217+
206218
LOGGER.debug("Installing the Data Hub into MarkLogic");
207219

208220
// clean up any lingering cache for deployed modules
@@ -214,9 +226,9 @@ public void install() throws IOException {
214226
deployer.setCommands(getCommands(config));
215227

216228
deployer.deploy(config);
217-
long endTime = System.nanoTime();
218-
long duration = (endTime - startTime);
219-
LOGGER.info("Install took: " + (duration / 1000000000) + " seconds");
229+
230+
PerformanceLogger.logTimeInsideMethod(stopWatch, this.getClass().getName(),
231+
"install", (Object[])null);
220232
}
221233

222234
private DatabaseClient getDatabaseClient(int port) {
@@ -240,6 +252,7 @@ private DatabaseClient getDatabaseClient(int port) {
240252
* @throws IOException
241253
*/
242254
public Set<File> installUserModules(String pathToUserModules) throws IOException {
255+
StopWatch stopWatch = PerformanceLogger.monitorTimeInsideMethod();
243256
LOGGER.debug("Installing user modules into MarkLogic");
244257

245258
AppConfig config = getAppConfig();
@@ -283,14 +296,25 @@ else if (isHarmonizeDir) {
283296
}
284297
}
285298
});
299+
300+
PerformanceLogger.logTimeInsideMethod(stopWatch, this.getClass().getName(),
301+
"installUserModules", (Object[])null);
302+
286303
return loadedFiles;
287304
}
288305

289306
public JsonNode validateUserModules() {
307+
StopWatch stopWatch = PerformanceLogger.monitorTimeInsideMethod();
290308
LOGGER.debug("validating user modules");
309+
291310
DatabaseClient client = getDatabaseClient(hubConfig.stagingPort);
292311
EntitiesValidator ev = new EntitiesValidator(client);
293-
return ev.validate();
312+
JsonNode jsonNode = ev.validate();
313+
314+
PerformanceLogger.logTimeInsideMethod(stopWatch, this.getClass().getName(),
315+
"validateUserModules", (Object[])null);
316+
317+
return jsonNode;
294318
}
295319

296320
private List<Command> getCommands(AppConfig config) {
@@ -342,8 +366,9 @@ private AdminManager getAdminManager() {
342366
* @throws IOException
343367
*/
344368
public void uninstall() throws IOException {
345-
long startTime = System.nanoTime();
369+
StopWatch stopWatch = PerformanceLogger.monitorTimeInsideMethod();
346370
LOGGER.debug("Uninstalling the Data Hub from MarkLogic");
371+
347372
AppConfig config = getAppConfig();
348373
AdminManager adminManager = getAdminManager();
349374
adminManager.setWaitForRestartCheckInterval(250);
@@ -354,9 +379,9 @@ public void uninstall() throws IOException {
354379
// clean up any lingering cache for deployed modules
355380
PropertiesModuleManager moduleManager = new PropertiesModuleManager(this.assetInstallTimeFile);
356381
moduleManager.deletePropertiesFile();
357-
long endTime = System.nanoTime();
358-
long duration = (endTime - startTime);
359-
LOGGER.info("Uninstall took: " + (duration / 1000000000) + " seconds");
382+
383+
PerformanceLogger.logTimeInsideMethod(stopWatch, this.getClass().getName(),
384+
"uninstall", (Object[])null);
360385
}
361386

362387
class EntitiesValidator extends ResourceManager {

‎marklogic-data-hub/src/main/java/com/marklogic/hub/EntityManager.java‎

Lines changed: 8 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -18,6 +18,7 @@
1818
import java.util.ArrayList;
1919
import java.util.List;
2020

21+
import org.springframework.util.StopWatch;
2122
import org.w3c.dom.Document;
2223
import org.w3c.dom.Element;
2324
import org.w3c.dom.Node;
@@ -31,6 +32,7 @@
3132
import com.marklogic.client.util.RequestParameters;
3233
import com.marklogic.hub.entity.Entity;
3334
import com.marklogic.hub.entity.EntityImpl;
35+
import com.marklogic.hub.util.PerformanceLogger;
3436

3537
public class EntityManager extends ResourceManager {
3638
static final public String NAME = "entity";
@@ -48,6 +50,8 @@ public EntityManager(DatabaseClient client) {
4850
* @return a list of entities
4951
*/
5052
public List<Entity> getEntities() {
53+
StopWatch stopWatch = PerformanceLogger.monitorTimeInsideMethod();
54+
5155
RequestParameters params = new RequestParameters();
5256
ServiceResultIterator resultItr = this.getServices().get(params);
5357
if (resultItr == null || ! resultItr.hasNext()) {
@@ -70,6 +74,10 @@ public List<Entity> getEntities() {
7074
entities.add(entityFromXml((Element) children.item(i)));
7175
}
7276
}
77+
78+
PerformanceLogger.logTimeInsideMethod(stopWatch, this.getClass().getName(),
79+
"getEntities", (Object[])null);
80+
7381
return entities;
7482
}
7583

‎marklogic-data-hub/src/main/java/com/marklogic/hub/FlowManager.java‎

Lines changed: 13 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -36,6 +36,7 @@
3636
import org.springframework.batch.item.ItemWriter;
3737
import org.springframework.batch.support.transaction.ResourcelessTransactionManager;
3838
import org.springframework.scheduling.concurrent.ThreadPoolTaskExecutor;
39+
import org.springframework.util.StopWatch;
3940
import org.w3c.dom.Document;
4041
import org.w3c.dom.Element;
4142
import org.w3c.dom.Node;
@@ -55,6 +56,7 @@
5556
import com.marklogic.hub.flow.Flow;
5657
import com.marklogic.hub.flow.FlowType;
5758
import com.marklogic.hub.flow.SimpleFlow;
59+
import com.marklogic.hub.util.PerformanceLogger;
5860
import com.marklogic.spring.batch.hub.CollectorReader;
5961
import com.marklogic.spring.batch.hub.FlowWriter;
6062

@@ -153,7 +155,11 @@ public List<Flow> getFlows(String entityName) {
153155
* @return the flow
154156
*/
155157
public Flow getFlow(String entityName, String flowName) {
156-
return getFlow(entityName, flowName, null);
158+
StopWatch stopWatch = PerformanceLogger.monitorTimeInsideMethod();
159+
Flow flow = getFlow(entityName, flowName, null);
160+
PerformanceLogger.logTimeInsideMethod(stopWatch, this.getClass().getName(),
161+
"getFlow", new Object[]{entityName, flowName});
162+
return flow;
157163
}
158164

159165
public Flow getFlow(String entityName, String flowName, FlowType flowType) {
@@ -196,6 +202,8 @@ public JobExecution runFlow(Flow flow, int batchSize) {
196202
* @return
197203
*/
198204
public JobExecution runFlow(Flow flow, int batchSize, JobExecutionListener listener) {
205+
StopWatch stopWatch = PerformanceLogger.monitorTimeInsideMethod();
206+
199207
Collector c = flow.getCollector();
200208
if (c instanceof ServerCollector) {
201209
((ServerCollector)c).setClient(client);
@@ -217,9 +225,11 @@ public JobExecution runFlow(Flow flow, int batchSize, JobExecutionListener liste
217225

218226
try {
219227
return jobLauncher.run(job, new JobParameters());
220-
}
221-
catch (Exception e) {
228+
} catch (Exception e) {
222229
throw new RuntimeException(e);
230+
} finally {
231+
PerformanceLogger.logTimeInsideMethod(stopWatch, this.getClass().getName(),
232+
"runFlow", new Object[]{flow,batchSize,listener});
223233
}
224234
}
225235

‎marklogic-data-hub/src/main/java/com/marklogic/hub/Scaffolding.java‎

Lines changed: 20 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -29,38 +29,50 @@
2929

3030
import org.slf4j.Logger;
3131
import org.slf4j.LoggerFactory;
32+
import org.springframework.util.StopWatch;
3233

3334
import com.marklogic.client.io.Format;
3435
import com.marklogic.hub.flow.FlowType;
3536
import com.marklogic.hub.flow.SimpleFlow;
37+
import com.marklogic.hub.util.PerformanceLogger;
3638

3739
public class Scaffolding {
3840

3941
static final private Logger LOGGER = LoggerFactory.getLogger(Scaffolding.class);
4042

4143
public static File getEntityDir(File userlandDir, String entityName) {
44+
StopWatch stopWatch = PerformanceLogger.monitorTimeInsideMethod();
4245
File entitiesDir = new File(userlandDir, "entities");
4346
File entityDir = new File(entitiesDir, entityName);
47+
PerformanceLogger.logTimeInsideMethod(stopWatch, Scaffolding.class.getName(),
48+
"getEntityDir", new Object[]{userlandDir, entityName});
4449
return entityDir;
4550
}
4651

4752
public static File getFlowDir(File userlandDir, String entityName,
4853
String flowName, FlowType flowType) {
54+
StopWatch stopWatch = PerformanceLogger.monitorTimeInsideMethod();
4955
File entityDir = getEntityDir(userlandDir, entityName);
5056
File typeDir = new File(entityDir, flowType.toString());
5157
File flowDir = new File(typeDir, flowName);
58+
PerformanceLogger.logTimeInsideMethod(stopWatch, Scaffolding.class.getName(),
59+
"getEntityDir", new Object[]{userlandDir, entityName});
5260
return flowDir;
5361
}
5462

5563
public static void createEntity(String entityName, File userlandPath) {
64+
StopWatch stopWatch = PerformanceLogger.monitorTimeInsideMethod();
5665
File entityDir = getEntityDir(userlandPath, entityName);
5766
entityDir.mkdirs();
67+
PerformanceLogger.logTimeInsideMethod(stopWatch, Scaffolding.class.getName(),
68+
"createEntity", new Object[]{entityName, userlandPath});
5869
}
5970

6071
public static void createFlow(String entityName, String flowName,
6172
FlowType flowType, PluginFormat pluginFormat, Format dataFormat,
6273
File userlandDir)
6374
throws IOException {
75+
StopWatch stopWatch = PerformanceLogger.monitorTimeInsideMethod();
6476
File flowDir = getFlowDir(userlandDir, entityName, flowName, flowType);
6577

6678
if (flowType.equals(FlowType.HARMONIZE)) {
@@ -97,6 +109,8 @@ public static void createFlow(String entityName, String flowName,
97109
out.println(flow.serialize(false));
98110
out.close();
99111
}
112+
PerformanceLogger.logTimeInsideMethod(stopWatch, Scaffolding.class.getName(),
113+
"createFlow", new Object[]{entityName, flowName, flowType, pluginFormat, dataFormat, userlandDir});
100114
}
101115

102116
private static void writeFile(String srcFile, Path dstFile)
@@ -109,7 +123,7 @@ private static void writeFile(String srcFile, Path dstFile)
109123

110124
public static void createRestExtension(String entityName, String extensionName,
111125
FlowType flowType, PluginFormat pluginFormat, File userlandDir) throws IOException, ScaffoldingValidationException {
112-
LOGGER.info(extensionName);
126+
StopWatch stopWatch = PerformanceLogger.monitorTimeInsideMethod();
113127
if(!ScaffoldingValidator.isUniqueRestServiceExtension(userlandDir, extensionName)) {
114128
throw new ScaffoldingValidationException("A rest service extension with the same name as " + extensionName + " already exists.");
115129
}
@@ -118,11 +132,13 @@ public static void createRestExtension(String entityName, String extensionName,
118132
File dstFile = createEmptyRestExtensionFile(entityName, extensionName, flowType, pluginFormat, userlandDir);
119133
writeToFile(fileContent, dstFile);
120134
writeMetadataForFile(dstFile, scaffoldRestServicesPath + "metadata/template.xml", extensionName);
135+
PerformanceLogger.logTimeInsideMethod(stopWatch, Scaffolding.class.getName(),
136+
"createRestExtension", new Object[]{entityName, extensionName, flowType, pluginFormat, userlandDir});
121137
}
122138

123139
public static void createRestTransform(String entityName, String transformName,
124140
FlowType flowType, PluginFormat pluginFormat, File userlandDir) throws IOException, ScaffoldingValidationException {
125-
LOGGER.info(transformName);
141+
StopWatch stopWatch = PerformanceLogger.monitorTimeInsideMethod();
126142
if(!ScaffoldingValidator.isUniqueRestTransform(userlandDir, transformName)) {
127143
throw new ScaffoldingValidationException("A rest transform with the same name as " + transformName + " already exists.");
128144
}
@@ -131,6 +147,8 @@ public static void createRestTransform(String entityName, String transformName,
131147
File dstFile = createEmptyRestTransformFile(entityName, transformName, flowType, pluginFormat, userlandDir);
132148
writeToFile(fileContent, dstFile);
133149
writeMetadataForFile(dstFile, scaffoldRestTransformsPath + "metadata/template.xml", transformName);
150+
PerformanceLogger.logTimeInsideMethod(stopWatch, Scaffolding.class.getName(),
151+
"createRestTransform", new Object[]{entityName, transformName, flowType, pluginFormat, userlandDir});
134152
}
135153

136154
private static void writeToFile(String fileContent, File dstFile)

‎marklogic-data-hub/src/main/java/com/marklogic/hub/util/PerformanceLogger.java‎

Lines changed: 39 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,39 @@
1+
package com.marklogic.hub.util;
2+
3+
import org.slf4j.Logger;
4+
import org.slf4j.LoggerFactory;
5+
import org.springframework.util.StopWatch;
6+
7+
public class PerformanceLogger {
8+
9+
private final static Logger LOGGER = LoggerFactory.getLogger(PerformanceLogger.class);
10+
11+
public static StopWatch monitorTimeInsideMethod() {
12+
StopWatch stopWatch = new StopWatch();
13+
stopWatch.start();
14+
return stopWatch;
15+
}
16+
17+
public static void logTimeInsideMethod(StopWatch stopWatch, String className, String methodName, Object... args) {
18+
stopWatch.stop();
19+
StringBuilder logMessage = new StringBuilder();
20+
logMessage.append(className);
21+
logMessage.append(".");
22+
logMessage.append(methodName);
23+
logMessage.append("(");
24+
// append args
25+
if(args!=null) {
26+
for (int i = 0; i < args.length; i++) {
27+
logMessage.append(args[i]).append(",");
28+
}
29+
if (args.length > 0) {
30+
logMessage.deleteCharAt(logMessage.length() - 1);
31+
}
32+
}
33+
logMessage.append(")");
34+
logMessage.append(" took ");
35+
logMessage.append(stopWatch.getTotalTimeMillis());
36+
logMessage.append(" ms");
37+
LOGGER.info(logMessage.toString());
38+
}
39+
}

0 commit comments

Comments
 (0)