Skip to content

Commit

Permalink
Use stopwatch for ingestjob to make timing a bit cleaner (#2517)
Browse files Browse the repository at this point in the history
* Use stopwatch for ingestjob to make timing a bit cleaner

* Update timer name and print pretty summary
  • Loading branch information
alerman authored Oct 7, 2024
1 parent fdf627f commit c61d494
Showing 1 changed file with 21 additions and 5 deletions.
Original file line number Diff line number Diff line change
Expand Up @@ -79,6 +79,7 @@
import org.apache.log4j.Level;
import org.apache.log4j.Logger;
import org.apache.log4j.PatternLayout;
import org.springframework.util.StopWatch;

import datawave.ingest.config.TableConfigCache;
import datawave.ingest.data.Type;
Expand Down Expand Up @@ -249,7 +250,11 @@ protected void printUsage() {

@Override
public int run(String[] args) throws Exception {
long setupStart = System.currentTimeMillis();

long start = System.currentTimeMillis();

StopWatch sw = new StopWatch("Ingest Job");
sw.start("local init");

Logger.getLogger(TypeRegistry.class).setLevel(Level.ALL);

Expand Down Expand Up @@ -365,8 +370,9 @@ public int run(String[] args) throws Exception {
URL.setURLStreamHandlerFactory(new FsUrlStreamHandlerFactory(conf));

startDaemonProcesses(conf);
long start = System.currentTimeMillis();
log.info("JOB SETUP TIME: " + (start - setupStart));
sw.stop();
log.info(formatTaskInfo(sw.getLastTaskInfo()));
sw.start("AM Init");

job.submit();
JobID jobID = job.getJobID();
Expand Down Expand Up @@ -420,12 +426,18 @@ public int run(String[] args) throws Exception {
}
}
}
long setupStop = System.currentTimeMillis();
log.info("JOB SETUP TIME: " + (setupStop - setupStart) + "ms");
sw.stop();
log.info(formatTaskInfo(sw.getLastTaskInfo()));

sw.start("MR Job");
job.waitForCompletion(true);
sw.stop();

long stop = System.currentTimeMillis();

log.info(formatTaskInfo(sw.getLastTaskInfo()));
log.info(sw.prettyPrint());

// output the counters to the log
Counters counters = job.getCounters();
try (JobClient jobClient = new JobClient((org.apache.hadoop.mapred.JobConf) job.getConfiguration())) {
Expand Down Expand Up @@ -533,6 +545,10 @@ public int run(String[] args) throws Exception {
return 0;
}

private String formatTaskInfo(StopWatch.TaskInfo taskInfo) {
return "Timing - " + taskInfo.getTaskName() + ": " + taskInfo.getTimeSeconds() + " s";
}

private void setupHandlers(Configuration conf) {
// default to all types
Collection<Type> types = TypeRegistry.getTypes();
Expand Down

0 comments on commit c61d494

Please sign in to comment.