Added time measurements for key steps.

This commit is contained in:
Anthony Whitford
2015-09-05 00:31:50 -07:00
parent 49736a87aa
commit 92e1fd3f28
3 changed files with 10 additions and 4 deletions

View File

@@ -352,6 +352,7 @@ public class Engine implements FileFilter {
LOGGER.debug("\n----------------------------------------------------\nBEGIN ANALYSIS\n----------------------------------------------------"); LOGGER.debug("\n----------------------------------------------------\nBEGIN ANALYSIS\n----------------------------------------------------");
LOGGER.info("Analysis Starting"); LOGGER.info("Analysis Starting");
final long analysisStart = System.currentTimeMillis();
// analysis phases // analysis phases
for (AnalysisPhase phase : AnalysisPhase.values()) { for (AnalysisPhase phase : AnalysisPhase.values()) {
@@ -398,7 +399,7 @@ public class Engine implements FileFilter {
} }
LOGGER.debug("\n----------------------------------------------------\nEND ANALYSIS\n----------------------------------------------------"); LOGGER.debug("\n----------------------------------------------------\nEND ANALYSIS\n----------------------------------------------------");
LOGGER.info("Analysis Complete"); LOGGER.info("Analysis Complete ({} ms)", System.currentTimeMillis() - analysisStart);
} }
/** /**
@@ -442,6 +443,7 @@ public class Engine implements FileFilter {
*/ */
public void doUpdates() { public void doUpdates() {
LOGGER.info("Checking for updates"); LOGGER.info("Checking for updates");
final long updateStart = System.currentTimeMillis();
final UpdateService service = new UpdateService(serviceClassLoader); final UpdateService service = new UpdateService(serviceClassLoader);
final Iterator<CachedWebDataSource> iterator = service.getDataSources(); final Iterator<CachedWebDataSource> iterator = service.getDataSources();
while (iterator.hasNext()) { while (iterator.hasNext()) {
@@ -454,7 +456,7 @@ public class Engine implements FileFilter {
LOGGER.debug("Unable to update details for {}", source.getClass().getName(), ex); LOGGER.debug("Unable to update details for {}", source.getClass().getName(), ex);
} }
} }
LOGGER.info("Check for updates complete"); LOGGER.info("Check for updates complete ({} ms)", System.currentTimeMillis() - updateStart);
} }
/** /**

View File

@@ -185,6 +185,7 @@ public class DownloadTask implements Callable<Future<ProcessTask>> {
final URL url1 = new URL(nvdCveInfo.getUrl()); final URL url1 = new URL(nvdCveInfo.getUrl());
final URL url2 = new URL(nvdCveInfo.getOldSchemaVersionUrl()); final URL url2 = new URL(nvdCveInfo.getOldSchemaVersionUrl());
LOGGER.info("Download Started for NVD CVE - {}", nvdCveInfo.getId()); LOGGER.info("Download Started for NVD CVE - {}", nvdCveInfo.getId());
final long startDownload = System.currentTimeMillis();
try { try {
Downloader.fetchFile(url1, first); Downloader.fetchFile(url1, first);
Downloader.fetchFile(url2, second); Downloader.fetchFile(url2, second);
@@ -204,7 +205,8 @@ public class DownloadTask implements Callable<Future<ProcessTask>> {
extractGzip(second); extractGzip(second);
} }
LOGGER.info("Download Complete for NVD CVE - {}", nvdCveInfo.getId()); LOGGER.info("Download Complete for NVD CVE - {} ({} ms)", nvdCveInfo.getId(),
System.currentTimeMillis() - startDownload);
if (this.processorService == null) { if (this.processorService == null) {
return null; return null;
} }

View File

@@ -157,6 +157,7 @@ public class ProcessTask implements Callable<ProcessTask> {
*/ */
private void processFiles() throws UpdateException { private void processFiles() throws UpdateException {
LOGGER.info("Processing Started for NVD CVE - {}", filePair.getNvdCveInfo().getId()); LOGGER.info("Processing Started for NVD CVE - {}", filePair.getNvdCveInfo().getId());
final long startProcessing = System.currentTimeMillis();
try { try {
importXML(filePair.getFirst(), filePair.getSecond()); importXML(filePair.getFirst(), filePair.getSecond());
cveDB.commit(); cveDB.commit();
@@ -178,6 +179,7 @@ public class ProcessTask implements Callable<ProcessTask> {
} finally { } finally {
filePair.cleanup(); filePair.cleanup();
} }
LOGGER.info("Processing Complete for NVD CVE - {}", filePair.getNvdCveInfo().getId()); LOGGER.info("Processing Complete for NVD CVE - {} ({} ms)", filePair.getNvdCveInfo().getId(),
System.currentTimeMillis() - startProcessing);
} }
} }