diff --git a/java/server/pom.xml b/java/server/pom.xml --- a/java/server/pom.xml +++ b/java/server/pom.xml @@ -18,6 +18,11 @@ + ch.qos.logback + logback-classic + 1.2.3 + + junit junit 4.11 diff --git a/java/server/src/main/java/org/softwareheritage/graph/Endpoint.java b/java/server/src/main/java/org/softwareheritage/graph/Endpoint.java --- a/java/server/src/main/java/org/softwareheritage/graph/Endpoint.java +++ b/java/server/src/main/java/org/softwareheritage/graph/Endpoint.java @@ -2,6 +2,9 @@ import java.util.ArrayList; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; + import org.softwareheritage.graph.Graph; import org.softwareheritage.graph.SwhId; import org.softwareheritage.graph.SwhPath; @@ -21,6 +24,13 @@ /** Internal traversal API */ Traversal traversal; + /** Timings logger */ + private static final Logger logger = LoggerFactory.getLogger(Endpoint.class); + /** Starting time used for logging purposes */ + private long startTime; + /** Total duration time measured for logging purposes */ + private double duration; + /** * Constructor. * @@ -34,16 +44,34 @@ } /** + * Starts timing measurement for logging purposes. + */ + private void startTiming() { + this.startTime = System.nanoTime(); + } + + /** + * Ends timing measurement and computes total duration in seconds for logging purposes. + */ + private void stopTiming() { + long endTime = System.nanoTime(); + this.duration = (double) (endTime - startTime) / 1_000_000_000; + } + + /** * Converts a list of (internal) long node ids to a list of corresponding (external) SWH PIDs. * * @param nodeIds the list of long node ids * @return a list of corresponding SWH PIDs */ private ArrayList convertNodesToSwhIds(ArrayList nodeIds) { + this.startTiming(); ArrayList swhIds = new ArrayList<>(); for (long nodeId : nodeIds) { swhIds.add(graph.getSwhId(nodeId)); } + this.stopTiming(); + logger.debug("convertNodesToSwhIds() took {} s.", this.duration); return swhIds; } @@ -55,10 +83,13 @@ * @see org.softwareheritage.graph.SwhPath */ private SwhPath convertNodesToSwhPath(ArrayList nodeIds) { + this.startTiming(); SwhPath path = new SwhPath(); for (long nodeId : nodeIds) { path.add(graph.getSwhId(nodeId)); } + this.stopTiming(); + logger.debug("convertNodesToSwhPath() took {} s.", this.duration); return path; } @@ -70,10 +101,13 @@ * @see org.softwareheritage.graph.SwhPath */ private ArrayList convertPathsToSwhIds(ArrayList> pathsNodeId) { + this.startTiming(); ArrayList paths = new ArrayList<>(); for (ArrayList path : pathsNodeId) { paths.add(convertNodesToSwhPath(path)); } + this.stopTiming(); + logger.debug("convertPathsToSwhIds() took {} s.", this.duration); return paths; } @@ -87,7 +121,12 @@ */ public ArrayList leaves(SwhId src) { long srcNodeId = graph.getNodeId(src); + + this.startTiming(); ArrayList nodeIds = traversal.leaves(srcNodeId); + this.stopTiming(); + logger.debug("leaves({}) took {} s.", src, this.duration); + return convertNodesToSwhIds(nodeIds); } @@ -101,7 +140,12 @@ */ public ArrayList neighbors(SwhId src) { long srcNodeId = graph.getNodeId(src); + + this.startTiming(); ArrayList nodeIds = traversal.neighbors(srcNodeId); + this.stopTiming(); + logger.debug("neighbors({}) took {} s.", src, this.duration); + return convertNodesToSwhIds(nodeIds); } @@ -124,11 +168,19 @@ try { SwhId dstSwhId = new SwhId(dstFmt); long dstNodeId = graph.getNodeId(dstSwhId); + + this.startTiming(); nodeIds = traversal.walk(srcNodeId, dstNodeId, algorithm); + this.stopTiming(); + logger.debug("walk({}) took {} s.", src, this.duration); } catch (IllegalArgumentException ignored1) { try { Node.Type dstType = Node.Type.fromStr(dstFmt); + + this.startTiming(); nodeIds = traversal.walk(srcNodeId, dstType, algorithm); + this.stopTiming(); + logger.debug("walk({}) took {} s.", src, this.duration); } catch (IllegalArgumentException ignored2) { } } @@ -145,7 +197,12 @@ */ public ArrayList visitNodes(SwhId src) { long srcNodeId = graph.getNodeId(src); + + this.startTiming(); ArrayList nodeIds = traversal.visitNodes(srcNodeId); + this.stopTiming(); + logger.debug("visitNodes({}) took {} s.", src, this.duration); + return convertNodesToSwhIds(nodeIds); } @@ -160,7 +217,12 @@ */ public ArrayList visitPaths(SwhId src) { long srcNodeId = graph.getNodeId(src); + + this.startTiming(); ArrayList> paths = traversal.visitPaths(srcNodeId); + this.stopTiming(); + logger.debug("visitPaths({}) took {} s.", src, this.duration); + return convertPathsToSwhIds(paths); } }