From 9e5d1bced16aa9975692115a964c661cd7897a7c Mon Sep 17 00:00:00 2001 From: hansonr Date: Mon, 28 Jan 2019 20:01:45 -0600 Subject: [PATCH 1/1] more iterators out; some time checks --- src/jalview/ext/ensembl/EnsemblRestClient.java | 10 ++-- src/jalview/ext/ensembl/EnsemblSeqProxy.java | 71 +++++++++++++++++++++--- src/jalview/gui/Desktop.java | 2 + src/jalview/util/Platform.java | 32 ++++++++--- 4 files changed, 93 insertions(+), 22 deletions(-) diff --git a/src/jalview/ext/ensembl/EnsemblRestClient.java b/src/jalview/ext/ensembl/EnsemblRestClient.java index da9d2e5..bef1db0 100644 --- a/src/jalview/ext/ensembl/EnsemblRestClient.java +++ b/src/jalview/ext/ensembl/EnsemblRestClient.java @@ -501,17 +501,17 @@ boolean checkEnsembl() if (url == null) url = getUrl(ids); -// Platform.timeCheck("EnsembleRestClient.getJSON0 " + url, Platform.TIME_MARK); - Reader br = null; try { + + Platform.timeCheck(null, Platform.TIME_MARK); + br = (url == null ? null : getHttpResponse(url, ids, msDelay)); -// Platform.timeCheck("EnsembleRestClient.getJSON1 parsing... ", Platform.TIME_MARK); - Object ret = (br == null ? null : JSONUtils.parse(br)); -// Platform.timeCheck("EnsembleRestClient.getJSON2 ...done ", Platform.TIME_MARK); + Platform.timeCheck("EnsembleRestClient.getJSON " + url, Platform.TIME_MARK); + if (ret != null && mapKey != null) ret = ((Map) ret).get(mapKey); diff --git a/src/jalview/ext/ensembl/EnsemblSeqProxy.java b/src/jalview/ext/ensembl/EnsemblSeqProxy.java index a558ad2..fb01708 100644 --- a/src/jalview/ext/ensembl/EnsemblSeqProxy.java +++ b/src/jalview/ext/ensembl/EnsemblSeqProxy.java @@ -171,14 +171,15 @@ public abstract class EnsemblSeqProxy extends EnsemblRestClient * fetch and transfer genomic sequence features, * fetch protein product and add as cross-reference */ - for (String accId : allIds) + for (int i = 0, n = allIds.size(); i < n; i++) { - addFeaturesAndProduct(accId, alignment); + addFeaturesAndProduct(allIds.get(i), alignment); } - for (SequenceI seq : alignment.getSequences()) + List seqs = alignment.getSequences(); + for (int i = 0, n = seqs.size(); i < n; i++) { - getCrossReferences(seq); + getCrossReferences(seqs.get(i)); } return alignment; @@ -209,12 +210,19 @@ public abstract class EnsemblSeqProxy extends EnsemblRestClient SequenceI genomicSequence = null; EnsemblFeatures gffFetcher = new EnsemblFeatures(getDomain()); EnsemblFeatureType[] features = getFeaturesToFetch(); + + Platform.timeCheck("ESP.getsequencerec1", Platform.TIME_MARK); + + AlignmentI geneFeatures = gffFetcher.getSequenceRecords(accId, features); if (geneFeatures != null && geneFeatures.getHeight() > 0) { genomicSequence = geneFeatures.getSequenceAt(0); } + + Platform.timeCheck("ESP.getsequencerec2", Platform.TIME_MARK); + if (genomicSequence != null) { /* @@ -228,6 +236,7 @@ public abstract class EnsemblSeqProxy extends EnsemblRestClient * fetch and map protein product, and add it as a cross-reference * of the retrieved sequence */ + Platform.timeCheck("ESP.transferFeatures", Platform.TIME_MARK); addProteinProduct(querySeq); } } @@ -236,6 +245,7 @@ public abstract class EnsemblSeqProxy extends EnsemblRestClient System.err.println( "Error transferring Ensembl features: " + e.getMessage()); } + Platform.timeCheck("ESP.addfeat done", Platform.TIME_MARK); } /** @@ -348,28 +358,47 @@ public abstract class EnsemblSeqProxy extends EnsemblRestClient */ protected void getCrossReferences(SequenceI seq) { + + Platform.timeCheck("ESP. getdataseq ", Platform.TIME_MARK); + + while (seq.getDatasetSequence() != null) { seq = seq.getDatasetSequence(); } + + Platform.timeCheck("ESP. getxref ", Platform.TIME_MARK); + EnsemblXref xrefFetcher = new EnsemblXref(getDomain(), getDbSource(), getEnsemblDataVersion()); List xrefs = xrefFetcher.getCrossReferences(seq.getName()); for (int i = 0, n = xrefs.size(); i < n; i++) { +// Platform.timeCheck("ESP. getxref + " + (i) + "/" + n, Platform.TIME_MARK); // BH 2019.01.25 this next method was taking 174 ms PER addition for a 266-reference example. // DBRefUtils.ensurePrimaries(seq) // was at the end of seq.addDBRef, so executed after ever addition! // This method was moved to seq.getPrimaryDBRefs() seq.addDBRef(xrefs.get(i)); } + +// System.out.println("primaries are " + seq.getPrimaryDBRefs().toString()); /* * and add a reference to itself */ + +// Platform.timeCheck("ESP. getxref self ", Platform.TIME_MARK); + DBRefEntry self = new DBRefEntry(getDbSource(), getEnsemblDataVersion(), seq.getName()); + +// Platform.timeCheck("ESP. getxref self add ", Platform.TIME_MARK); + seq.addDBRef(self); + + Platform.timeCheck("ESP. seqprox done ", Platform.TIME_MARK); + } /** @@ -390,6 +419,8 @@ public abstract class EnsemblSeqProxy extends EnsemblRestClient inProgress = false; throw new JalviewException("ENSEMBL Rest API not available."); } + Platform.timeCheck("EnsemblSeqProx.fetchSeq ", Platform.TIME_MARK); + List seqs = parseSequenceJson(ids); if (seqs == null) return alignment; @@ -455,6 +486,8 @@ public abstract class EnsemblSeqProxy extends EnsemblRestClient * for now, assumes only one sequence returned; refactor if needed * in future to handle a JSONArray with more than one */ + + Platform.timeCheck("ENS seqproxy", Platform.TIME_MARK); Map val = (Map) getJSON(null, ids, -1, MODE_MAP, null); if (val == null) return null; @@ -480,6 +513,7 @@ public abstract class EnsemblSeqProxy extends EnsemblRestClient System.err.println("Error processing JSON response: " + e.toString()); // ignore } + Platform.timeCheck("ENS seqproxy2", Platform.TIME_MARK); return result; } @@ -659,7 +693,9 @@ public abstract class EnsemblSeqProxy extends EnsemblRestClient */ protected abstract List getIdentifyingFeatures( SequenceI seq, String accId); - + + int bhtest = 0; + /** * Transfers the sequence feature to the target sequence, locating its start * and end range based on the mapping. Features which do not overlap the @@ -681,6 +717,7 @@ public abstract class EnsemblSeqProxy extends EnsemblRestClient if (mappedRange != null) { +// Platform.timeCheck(null, Platform.TIME_SET); String group = sf.getFeatureGroup(); if (".".equals(group)) { @@ -688,8 +725,11 @@ public abstract class EnsemblSeqProxy extends EnsemblRestClient } int newBegin = Math.min(mappedRange[0], mappedRange[1]); int newEnd = Math.max(mappedRange[0], mappedRange[1]); - SequenceFeature copy = new SequenceFeature(sf, newBegin, newEnd, - group, sf.getScore()); +// Platform.timeCheck(null, Platform.TIME_MARK); + bhtest++; + // 280 ms/1000 here: + SequenceFeature copy = new SequenceFeature(sf, newBegin, newEnd, group, sf.getScore()); + // 0.175 ms here: targetSequence.addSequenceFeature(copy); /* @@ -794,10 +834,14 @@ public abstract class EnsemblSeqProxy extends EnsemblRestClient MapList mapping = getGenomicRangesFromFeatures(sourceSequence, accessionId, targetSequence.getStart()); if (mapping == null) - { + { return false; } + + Platform.timeCheck("ESP. xfer " + sfs.size(), Platform.TIME_MARK); + + boolean result = transferFeatures(sfs, targetSequence, mapping, accessionId); // System.out.println("transferFeatures (" + (sfs.size()) + " --> " @@ -831,14 +875,23 @@ public abstract class EnsemblSeqProxy extends EnsemblRestClient SequenceFeatures.sortFeatures(sfs, forwardStrand); boolean transferred = false; - for (SequenceFeature sf : sfs) + + for (int i = 0, n = sfs.size(); i < n; i++) { + + if ((i%1000) == 0) { +// Platform.timeCheck("Feature " + bhtest, Platform.TIME_GET); + Platform.timeCheck("ESP. xferFeature + " + (i) + "/" + n, Platform.TIME_MARK); + } + + SequenceFeature sf = sfs.get(i); if (retainFeature(sf, parentId)) { transferFeature(sf, targetSequence, mapping, forwardStrand); transferred = true; } } + return transferred; } diff --git a/src/jalview/gui/Desktop.java b/src/jalview/gui/Desktop.java index a50a2e6..30c37de 100644 --- a/src/jalview/gui/Desktop.java +++ b/src/jalview/gui/Desktop.java @@ -2801,6 +2801,8 @@ public class Desktop extends jalview.jbgui.GDesktop @Override public void setProgressBar(String message, long id) { + Platform.timeCheck("Desktop " + message, Platform.TIME_MARK); + if (progressBars == null) { progressBars = new Hashtable<>(); diff --git a/src/jalview/util/Platform.java b/src/jalview/util/Platform.java index 286ded1..0b9185c 100644 --- a/src/jalview/util/Platform.java +++ b/src/jalview/util/Platform.java @@ -201,21 +201,37 @@ public class Platform public final static int TIME_RESET = 0; public final static int TIME_MARK = 1; + public static final int TIME_SET = 2; + public static final int TIME_GET = 3; - public static long time, mark; + public static long time, mark, set, duration; public static void timeCheck(String msg, int mode) { + long t = System.currentTimeMillis(); switch (mode) { case TIME_RESET: - time = mark = System.currentTimeMillis(); - System.err.println("Platform: timer reset\t\t\t" + msg); + time = mark = t; + if (msg != null) + System.err.println("Platform: timer reset\t\t\t" + msg); break; case TIME_MARK: - long t = System.currentTimeMillis(); - if (time == 0) - time = mark = t; - System.err.println("Platform: timer mark\t" + ((t - time)/1000f) + "\t" + ((t - mark)/1000f) + "\t" + msg); - mark = t; + if (set > 0) { + duration += (t - set); + } else { + if (time == 0) + time = mark = t; + if (msg != null) + System.err.println("Platform: timer mark\t" + ((t - time)/1000f) + "\t" + ((t - mark)/1000f) + "\t" + msg); + mark = t; + } + break; + case TIME_SET: + set = t; + break; + case TIME_GET: + if (msg != null) + System.err.println("Platform: timer dur\t" + ((t - time)/1000f) + "\t" + ((duration)/1000f) + "\t" + msg); + set = 0; break; } } -- 1.7.10.2