Skip to content

Commit a26fd9b

Browse files
sblivensbliven
committed
Fix multithreading bug in EcodInstallation
Add additional tests and logging messages for debugging
1 parent c5f169d commit a26fd9b

3 files changed

Lines changed: 104 additions & 10 deletions

File tree

‎biojava-core/src/main/java/org/biojava/nbio/core/util/ConcurrencyTools.java‎

Lines changed: 2 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -39,11 +39,7 @@ public class ConcurrencyTools {
3939
private final static Logger logger = LoggerFactory.getLogger(ConcurrencyTools.class);
4040

4141
private static ThreadPoolExecutor pool;
42-
// private static int tasks;
43-
44-
// TODO additional logging and listening services
45-
46-
// prevents instantiation
42+
private static int tasks = 0;
4743
private ConcurrencyTools() { }
4844

4945
/**
@@ -155,7 +151,7 @@ public static void shutdownAndAwaitTermination() {
155151
* @return future on which the desired value is retrieved by calling get()
156152
*/
157153
public static<T> Future<T> submit(Callable<T> task, String message) {
158-
// TODO log("Task " + (++tasks) + " submitted to shared thread pool. " + message);
154+
logger.debug("Task " + (++tasks) + " submitted to shared thread pool. " + message);
159155
return getThreadPool().submit(task);
160156
}
161157

‎biojava-structure/src/main/java/org/biojava/nbio/structure/domain/EcodInstallation.java‎

Lines changed: 35 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -73,11 +73,14 @@ public EcodInstallation() {
7373
public List<EcodDomain> getDomainsForPDB(String pdbId) throws IOException {
7474
domainsFileLock.readLock().lock();
7575
try {
76+
logger.trace("LOCK readlock");
7677
while( domainMap == null ) {
7778
// unlock to allow ensureDomainsFileInstalled to get the write lock
79+
logger.trace("UNLOCK readlock");
7880
domainsFileLock.readLock().unlock();
7981
indexDomains();
8082
domainsFileLock.readLock().lock();
83+
logger.trace("LOCK readlock");
8184
}
8285

8386
if(pdbId != null)
@@ -93,6 +96,7 @@ public List<EcodDomain> getDomainsForPDB(String pdbId) throws IOException {
9396
}
9497
return clonedDoms;
9598
} finally {
99+
logger.trace("UNLOCK readlock");
96100
domainsFileLock.readLock().unlock();
97101
}
98102
}
@@ -107,6 +111,11 @@ public EcodDomain getDomainsById(String ecodId) throws IOException {
107111
if( match.matches() )
108112
pdbId = match.group(1);
109113
List<EcodDomain> doms = getDomainsForPDB(pdbId);
114+
if(doms == null) {
115+
logger.debug("Null domains for {} from {}",pdbId,ecodId);
116+
return null;
117+
}
118+
logger.debug("Got {} domains from {}",doms.size(),pdbId);
110119
for(EcodDomain d: doms) {
111120
if(ecodId.equals(d.getDomainId())) {
112121
return d;
@@ -117,16 +126,20 @@ public EcodDomain getDomainsById(String ecodId) throws IOException {
117126

118127
public List<EcodDomain> getAllDomains() throws IOException {
119128
domainsFileLock.readLock().lock();
129+
logger.trace("LOCK readlock");
120130
try {
121131
while( allDomains == null) {
122132
// unlock to allow ensureDomainsFileInstalled to get the write lock
133+
logger.trace("UNLOCK readlock");
123134
domainsFileLock.readLock().unlock();
124135
ensureDomainsFileInstalled();
125136
domainsFileLock.readLock().lock();
137+
logger.trace("LOCK readlock");
126138
}
127139
return allDomains;
128140
} finally {
129-
domainsFileLock.readLock().lock();
141+
logger.trace("UNLOCK readlock");
142+
domainsFileLock.readLock().unlock();
130143
}
131144

132145
}
@@ -135,30 +148,36 @@ public List<EcodDomain> getAllDomains() throws IOException {
135148
* Clears all domains, requiring the file to be reparsed for subsequent accesses
136149
*/
137150
public void clear() {
138-
domainsFileLock.writeLock().lock();;
151+
domainsFileLock.writeLock().lock();
152+
logger.trace("LOCK writelock");
139153
allDomains = null;
140154
domainMap = null;
155+
logger.trace("UNLOCK writelock");
141156
domainsFileLock.writeLock().unlock();
142157
}
143158
public String getVersion() {
144159
return version;
145160
}
146161
public void setVersion(String version) {
147162
domainsFileLock.readLock().lock();
163+
logger.trace("LOCK readlock");
148164
try {
149165
if(version.equals(this.version)) {
150166
return; //no change
151167
}
152168
} finally {
169+
logger.trace("UNLOCK readlock");
153170
domainsFileLock.readLock().unlock();
154171
}
155172

156173
// update version and force reparsing
157174
domainsFileLock.writeLock().lock();
175+
logger.trace("LOCK writelock");
158176
try {
159177
this.version = version;
160178
this.clear();
161179
} finally {
180+
logger.trace("UNLOCK writelock");
162181
domainsFileLock.writeLock().unlock();
163182
}
164183
}
@@ -197,7 +216,9 @@ public void setCacheLocation(String cacheLocation) {
197216
}
198217
// update location
199218
domainsFileLock.writeLock().lock();
219+
logger.trace("LOCK writelock");
200220
this.cacheLocation = cacheLocation;
221+
logger.trace("UNLOCK writelock");
201222
domainsFileLock.writeLock().unlock();
202223
}
203224

@@ -210,22 +231,26 @@ public void setCacheLocation(String cacheLocation) {
210231
public void ensureDomainsFileInstalled() throws IOException{
211232
// Quick check for availability
212233
domainsFileLock.readLock().lock();
234+
logger.trace("LOCK readlock");
213235
try {
214236
if( allDomains != null ) {
215237
return;
216238
}
217239
} finally {
240+
logger.trace("UNLOCK readlock");
218241
domainsFileLock.readLock().unlock();
219242
}
220243

221244
// Download domains
222245
domainsFileLock.writeLock().lock();
246+
logger.trace("LOCK writelock");
223247
try {
224248
if( !domainsAvailable() ) {
225249
downloadDomains();
226250
}
227251
parseDomains();
228252
} finally {
253+
logger.trace("UNLOCK writelock");
229254
domainsFileLock.writeLock().unlock();
230255
}
231256
}
@@ -236,11 +261,13 @@ public void ensureDomainsFileInstalled() throws IOException{
236261
*/
237262
private boolean domainsAvailable() {
238263
domainsFileLock.readLock().lock();
264+
logger.trace("LOCK readlock");
239265
try {
240266
File f = getDomainFile();
241267

242268
return f.exists() && f.length()>0;
243269
} finally {
270+
logger.trace("UNLOCK readlock");
244271
domainsFileLock.readLock().unlock();
245272
}
246273
}
@@ -251,6 +278,7 @@ private boolean domainsAvailable() {
251278
*/
252279
private void downloadDomains() throws IOException {
253280
domainsFileLock.writeLock().lock();
281+
logger.trace("LOCK writelock");
254282
try {
255283
URL domainsURL = new URL( url + DOMAINS_PATH + getDomainFilename());
256284
File localFile = getDomainFile();
@@ -260,6 +288,7 @@ private void downloadDomains() throws IOException {
260288
} catch (MalformedURLException e) {
261289
logger.error("Malformed url: "+ url + DOMAINS_PATH + getDomainFilename(),e);
262290
} finally {
291+
logger.trace("UNLOCK writelock");
263292
domainsFileLock.writeLock().unlock();
264293
}
265294
}
@@ -286,10 +315,12 @@ private File getDomainFile() {
286315
*/
287316
private void parseDomains() throws IOException {
288317
domainsFileLock.writeLock().lock();
318+
logger.trace("LOCK writelock");
289319
try {
290320
EcodParser parser = new EcodParser(getDomainFile());
291321
allDomains = parser.getDomains();
292322
} finally {
323+
logger.trace("UNLOCK writelock");
293324
domainsFileLock.writeLock().unlock();
294325
}
295326
}
@@ -300,6 +331,7 @@ private void parseDomains() throws IOException {
300331
*/
301332
private void indexDomains() throws IOException {
302333
domainsFileLock.writeLock().lock();
334+
logger.trace("LOCK writelock");
303335
try {
304336
if( allDomains == null) {
305337
ensureDomainsFileInstalled();
@@ -331,6 +363,7 @@ private void indexDomains() throws IOException {
331363
currDomains.add(d);
332364
}
333365
} finally {
366+
logger.trace("UNLOCK writelock");
334367
domainsFileLock.writeLock().unlock();
335368
}
336369

‎biojava-structure/src/test/java/org/biojava/nbio/structure/domain/EcodDomainTest.java‎

Lines changed: 67 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -7,19 +7,33 @@
77

88
import java.io.File;
99
import java.io.IOException;
10+
import java.util.ArrayList;
1011
import java.util.Arrays;
1112
import java.util.Collections;
1213
import java.util.HashSet;
1314
import java.util.List;
1415
import java.util.Set;
16+
import java.util.concurrent.Callable;
17+
import java.util.concurrent.ExecutionException;
18+
import java.util.concurrent.Future;
19+
import java.util.concurrent.TimeUnit;
20+
import java.util.concurrent.TimeoutException;
1521

22+
import org.biojava.nbio.core.util.ConcurrencyTools;
23+
import org.biojava.nbio.structure.io.util.FileDownloadUtils;
24+
import org.junit.Rule;
1625
import org.junit.Test;
26+
import org.junit.rules.TemporaryFolder;
27+
import org.slf4j.Logger;
28+
import org.slf4j.LoggerFactory;
1729

1830
/**
1931
* @author Spencer Bliven
2032
*
2133
*/
2234
public class EcodDomainTest {
35+
36+
private static final Logger logger = LoggerFactory.getLogger(EcodDomainTest.class);
2337
private static EcodInstallation ecod;
2438
private static final String VERSION = "develop77";
2539

@@ -29,15 +43,23 @@ public class EcodDomainTest {
2943
ecod.setVersion(VERSION);
3044
}
3145

46+
static {
47+
//System.setProperty("Log4jContextSelector", "org.apache.logging.log4j.core.async.AsyncLoggerContextSelector");
48+
}
49+
@Rule
50+
public TemporaryFolder tmpFolder = new TemporaryFolder();
3251
@Test
3352
public void testDownloads() throws IOException {
53+
// Use second installation with tmp location to avoid overwriting main cache
54+
EcodInstallation ecod2 = new EcodInstallation(tmpFolder.getRoot().getAbsolutePath());
55+
ecod2.setVersion(VERSION);
3456
// Delete old VERSION
35-
File domainsFile = new File(ecod.getCacheLocation(),"ecod."+VERSION+".domains.txt");
57+
File domainsFile = new File(ecod2.getCacheLocation(),"ecod."+VERSION+".domains.txt");
3658
if( domainsFile.exists() ) {
3759
domainsFile.delete();
3860
}
3961
// Force download
40-
ecod.ensureDomainsFileInstalled();
62+
ecod2.ensureDomainsFileInstalled();
4163
// Check for download
4264
assertTrue("No downloaded file at "+domainsFile.toString(),domainsFile.exists());
4365
}
@@ -92,4 +114,47 @@ public void testParsing() throws IOException {
92114
assertEquals(ecodId,expected,domain);
93115

94116
}
117+
118+
@Test
119+
public void testMultithreaded() throws IOException {
120+
ecod.clear();
121+
String[] ecodIds = new String[] {
122+
"e4s1gA1", "e4umoB1", "e4v0cA1", "e4v1af1", "e3j7yj1", "e4wfcA1","e4b0jP1",
123+
};
124+
List<Future<EcodDomain>> futureDomains = new ArrayList<Future<EcodDomain>>();
125+
for(final String ecodId : ecodIds) {
126+
Callable<EcodDomain> job = new Callable<EcodDomain>() {
127+
@Override
128+
public EcodDomain call() throws Exception {
129+
logger.info("Running "+ecodId);
130+
EcodDomain d = ecod.getDomainsById(ecodId);
131+
logger.info("Finished "+ecodId);
132+
return d;
133+
}
134+
@Override
135+
public String toString() {
136+
return "Job fetching ECOD "+ecodId;
137+
}
138+
};
139+
Future<EcodDomain> future = ConcurrencyTools.submit(job,ecodId);
140+
futureDomains.add(future);
141+
}
142+
int successful = 0;
143+
for(Future<EcodDomain> future : futureDomains) {
144+
try {
145+
EcodDomain domain = future.get(60, TimeUnit.SECONDS);
146+
if(domain != null) {
147+
successful++;
148+
}
149+
} catch (InterruptedException e) {
150+
logger.error("Job "+future+" interrupted",e);
151+
} catch (ExecutionException e) {
152+
logger.error("Job "+future+" error",e);
153+
} catch (TimeoutException e) {
154+
logger.error("Job "+future+" timed out",e);
155+
}
156+
157+
}
158+
assertEquals(ecodIds.length, successful);
159+
}
95160
}

0 commit comments

Comments
 (0)