1 /*
2 * $Id$
3 *
4 * Copyright (c) 2001, 2010, Oracle and/or its affiliates. All rights reserved.
5 * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER.
6 *
7 * This code is free software; you can redistribute it and/or modify it
8 * under the terms of the GNU General Public License version 2 only, as
9 * published by the Free Software Foundation. Oracle designates this
10 * particular file as subject to the "Classpath" exception as provided
11 * by Oracle in the LICENSE file that accompanied this code.
12 *
13 * This code is distributed in the hope that it will be useful, but WITHOUT
14 * ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or
15 * FITNESS FOR A PARTICULAR PURPOSE. See the GNU General Public License
16 * version 2 for more details (a copy is included in the LICENSE file that
17 * accompanied this code).
18 *
19 * You should have received a copy of the GNU General Public License version
20 * 2 along with this work; if not, write to the Free Software Foundation,
21 * Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA.
22 *
23 * Please contact Oracle, 500 Oracle Parkway, Redwood Shores, CA 94065 USA
24 * or visit www.oracle.com if you need additional information or have any
25 * questions.
26 */
27 package com.sun.javatest;
28
29 import java.io.File;
30 import java.io.IOException;
31 import java.io.RandomAccessFile;
32 import java.lang.ref.WeakReference;
33 import java.util.Iterator;
34 import java.util.Map;
35 import java.util.TreeMap;
36
37 import com.sun.javatest.logging.WorkDirLogHandler;
38 import com.sun.javatest.util.Debug;
39 import com.sun.javatest.util.Fifo;
40 import com.sun.javatest.util.I18NResourceBundle;
41
42 import java.util.logging.Handler;
43 import java.util.logging.Logger;
44
45 /**
46 * Class which maintains a cache of the results currently existing inside a
47 * work directory. It is designed to allow the harness to get general
48 * information (name, status) about tests without having to open all the
49 * result files.
50 */
51 public class TestResultCache {
52
53 /**
54 * Interface which allows an external class to monitor the cache's
55 * activities.
56 */
57 public static interface Observer {
58 /**
59 * Called when tests have been read from the cache file.
60 * @param tests the tests that have been read
61 */
62 void update(Map<String, TestResult> tests);
63
64 /**
65 * Called periodically while waiting to access the cache.
66 * @param timeSoFar the time so far that a client has been waiting to
67 * access the cache
68 */
69 void waitingForLock(long timeSoFar);
70
71 /**
72 * Called when the timed out waiting for access to the cache.
73 */
74 void timeoutWaitingForLock();
75
76 /**
77 * Called when the cache has been locked.
78 */
79 void acquiredLock();
80
81 /**
82 * Called when the lock on the cache has been released.
83 */
84 void releasedLock();
85
86 /**
87 * Called when starting to (re)build the cache.
88 * @param reset currently, always true
89 */
90 void buildingCache(boolean reset);
91
92 /**
93 * Called when a test has been found to put in the cache.
94 * @param tr the test that is being put in the cache
95 */
96 void buildingCache(TestResult tr);
97
98 /**
99 * Called when the cache has been (re)built.
100 */
101 void builtCache();
102
103 /**
104 * Called when a serious error has occurred and the cache is unable to continue.
105 * @param t an object identifying the error that occurred
106 */
107 void error(Throwable t);
108 };
109
110 /**
111 * Primary constructor for a cache.
112 * @param workDir the work directory to attach to
113 * @param observer the observer to notify of cache events
114 * @throws IOException if an error occurs reading the cache file
115 */
116 public TestResultCache(WorkDirectory workDir, Observer observer)
117 throws IOException {
118 this.workDir = workDir;
119 this.observer = observer;
120
121 weakWorkDir = new WeakReference<>(workDir);
122 weakObserver = new WeakReference<>(observer);
123
124 cacheFile = workDir.getSystemFile(V2_FILENAME);
125 lockFile = workDir.getSystemFile(V2_LOCKNAME);
126
127 File old = workDir.getSystemFile(V1_FILENAME);
128 if (old.exists()) {
129 workDir.log(i18n, "trc.rmCachev1", old.getAbsolutePath());
130 old.delete();
131 }
132
133 old = workDir.getSystemFile(V1_LOCKNAME);
134 if (old.exists()) {
135 workDir.log(i18n, "trc.rmLockv1", old.getAbsolutePath());
136 old.delete();
137 }
138
139 raf = new RandomAccessFile(cacheFile, "rw");
140
141 worker = new Thread() {
142 public void run() {
143 doWorkUntilDone();
144 }
145 };
146 worker.setName("TestResultCache.worker" + (workerNumber++) + "[" + workDir.getRoot() + "]");
147 worker.setDaemon(true); // allows thread to run during shutdown
148
149 // ensure priority is lower than that of the calling thread, but don't
150 // want priority too low because we want cache updated in a timely fashion
151 int prio = Math.max(0, Math.min(Thread.currentThread().getPriority() - 1, 3));
152 worker.setPriority(prio);
153
154 worker.start();
155
156 shutdownHandler = new Thread() {
157 public void run() {
158 shutdown();
159 }
160 };
161 Runtime.getRuntime().addShutdownHook(shutdownHandler);
162 }
163
164 /**
165 * Insert a test result into the cache.
166 * The cache file will be updated asynchronously.
167 * @param tr the test to be inserted.
168 **/
169 synchronized void insert(TestResult tr) {
170 if (DEBUG_TESTS)
171 Debug.println("TRC.insert " + tr.getWorkRelativePath() + " " + tr.getStatus());
172
173 reviveWeakReferences();
174 testsToWrite.insert(tr);
175 notifyAll();
176 }
177
178 /**
179 * Request an update via the observer of all the tests in the cache.
180 */
181 synchronized void requestFullUpdate() {
182 if (!shutdownRequested) {
183 reviveWeakReferences();
184 fullUpdateRequested = true;
185 notifyAll();
186 }
187 }
188
189 /**
190 * Check if a call to compress the cache is advised.
191 */
192 synchronized boolean needsCompress() {
193 return compressNeeded;
194 }
195
196 /**
197 * Compress the cache file, eliminating any obsolete entries.
198 * The cache file will be updated asynchronously.
199 */
200 synchronized void compress() {
201 if (!shutdownRequested) {
202 reviveWeakReferences();
203 compressRequested = true;
204 notifyAll();
205 }
206 }
207
208 /**
209 * Expedite any outstanding updates to the cache file.
210 * The cache file will be updated asynchronously.
211 */
212 synchronized void flush() {
213 reviveWeakReferences();
214 flushRequested = true;
215 notifyAll();
216 }
217
218 boolean workerAlive() {
219 return worker != null;
220 }
221
222 //-------------------------------------------------------------------------------------
223 //
224 // the main worker code
225
226 private static final int DEFAULT_COMPRESS_PERCENT_LEVEL = 40;
227
228 private void doWorkUntilDone() {
229 int compressPercentLevel =
230 Integer.getInteger("javatest.trc.cacheThreshold",
231 DEFAULT_COMPRESS_PERCENT_LEVEL).intValue();
232 compressPercentLevel = Math.max(1, Math.min(compressPercentLevel, 100));
233
234 boolean haveWork = true; // first time in, we need to read/build the cache
235 fullUpdateRequested = true; // first time in, update client when initialized
236
237 try {
238 while (haveWork) {
239 doWork();
240
241 synchronized (this) {
242 if (flushRequested && testsToWrite.size() == 0)
243 flushRequested = false;
244
245 long timeLastWork = System.currentTimeMillis();
246 haveWork = isWorkAvailable(timeLastWork);
247 while (!haveWork && !shutdownRequested) {
248 workDir = null;
249 observer = null;
250
251 if (DEBUG_SYNC)
252 Debug.println("TRC.worker waiting");
253
254 wait(MIN_TEST_READ_INTERVAL);
255 haveWork = isWorkAvailable(timeLastWork);
256
257 if (DEBUG_SYNC)
258 Debug.println("TRC.worker awake haveWork=" + haveWork);
259 }
260
261 // wake up the workDir and observer (if still available)
262 reviveWeakReferences();
263
264 // if workDir and/or observer are null, then the WD and TRT
265 // that opened this cache have been GC-ed. This means that this
266 // thread has woken up for an external reason, such as noticing
267 // that the cache file size has changed. Since the client has
268 // gone away, there is nothing left to do but return.
269 if (workDir == null || observer == null)
270 return;
271
272 // re-evaluate compressNeeded now, while still synchronized
273 // so that totalEntryCount and uniqueInitialEntry do not have
274 // to be synchronized inside doWork()
275 if (totalEntryCount == 0)
276 compressNeeded = false;
277 else {
278 // when we read/wrote the beginning of the cache file, there was a set of
279 // unique entries. Everything after that is essentially unknown.
280 // If that latter part gets disproportionately big, set compressNeeded.
281 int uncompressedEntryCount = totalEntryCount - uniqueInitialEntryCount;
282 compressNeeded = (uncompressedEntryCount * 100 / totalEntryCount > compressPercentLevel);
283 }
284 }
285 }
286 }
287 catch (IOException e) {
288 // A serious error has occurred that cannot be recovered from;
289 // report it, and give up
290 observer.error(e);
291 }
292 catch (InterruptedException e) {
293 // should never happen, but if it does, we were idle anyway
294 // so just return, and exit the worker thread
295 }
296 finally {
297 try {
298 raf.close();
299 }
300 catch (IOException e) {
301 // ignore
302 }
303
304 synchronized (this) {
305 worker = null;
306 notifyAll();
307 }
308 }
309 }
310
311 private void doWork() throws IOException {
312 Map<String, TestResult> tests = null;
313 boolean rebuildCache = false;
314
315 getLock();
316
317 try {
318 // if cache file exists and has content, read it all or read updates
319 // as appropriate; if any errors occur, zap the file, so it will be rebuilt
320 try {
321 if (raf.length() > 0) {
322 tests = readCache();
323 } else {
324 rebuildCache = true;
325 }
326 }
327 catch (Throwable e) {
328 // cache appears to be corrupt; empty it and rebuild it
329 if (DEBUG_BASIC)
330 Debug.println("TRC.corrupt " + e);
331 workDir.log(i18n, "trc.reloadFault", e);
332 rebuildCache = true;
333 raf.setLength(0);
334 }
335
336 // if we're rebuilding the cache and the VM has started to shut down,
337 // quit rebuilding the cache and give up, as quickly as possible,
338 // leaving the next client to rebuild the cache instead
339 if (rebuildCache && shutdownRequested) {
340 testsToWrite.flush();
341 raf.setLength(0);
342 return;
343 }
344
345 // if cache is empty, rebuild it from .jtr files;
346 // note that a valid cache with no tests has length 4
347 if (rebuildCache) {
348 observer.buildingCache(rebuildCache);
349 tests = readJTRFiles();
350 observer.builtCache();
351 }
352
353 if (rebuildCache || compressRequested || raf.length() == 0) {
354 writeCache(tests);
355 // it is safe to clear the compressRequested flag because the client
356 // can only set it to true (not false, nor read it)
357 compressRequested = false;
358 }
359
360 // write any outstanding tests
361 updateCache(tests);
362 }
363 finally {
364 // if we're exiting abnormally, leave the next user to clean up
365 // if the file is corrupt; for now, it is better to unlock the
366 // file to say we're not using it any more
367 releaseLock();
368 }
369
370 if (updateNeeded) {
371 if (!shutdownRequested) {
372 observer.update(tests);
373 }
374 // it is safe to clear the fullUpdateRequested flag because the client
375 // can only set it to true (not false, nor read it)
376 fullUpdateRequested = false;
377 }
378 }
379
380 private static final int MIN_TEST_READ_INTERVAL = 10000; // 10 seconds
381 private static final int MIN_TEST_WRITE_INTERVAL = 10000; // 10 seconds
382
383 private boolean isWorkAvailable(long timeLastWork) {
384 if (compressRequested || flushRequested || fullUpdateRequested) {
385 if (DEBUG_CHECK_WORK)
386 Debug.println("TRC.haveWork (request"
387 + (compressRequested ? ":compress" : "")
388 + (flushRequested ? ":flush" : "")
389 + (fullUpdateRequested ? ":update" : "") + ")");
390 return true;
391 }
392
393 long now = System.currentTimeMillis();
394
395 if (now - timeLastWork >= MIN_TEST_WRITE_INTERVAL && testsToWrite.size() > 0) {
396 if (DEBUG_CHECK_WORK)
397 Debug.println("TRC.haveWork (" + testsToWrite.size() + " tests)");
398 return true;
399 }
400
401 try {
402 if (now - timeLastWork >= MIN_TEST_READ_INTERVAL && raf.length() != lastFileSize) {
403 if (DEBUG_CHECK_WORK)
404 Debug.println("TRC.haveWork (file size changed: " + raf.length() + ")");
405 return true;
406 }
407 }
408 catch (IOException e) {
409 // if an error occurred, we ought to let the worker thread go investigate
410 if (DEBUG_CHECK_WORK)
411 Debug.println("TRC.haveWork (" + e.getMessage() + ")");
412 return true;
413 }
414
415 return false;
416 }
417
418 //-------------------------------------------------------------------------------------
419 //
420 // shutdown handler code
421
422 private static final int MAX_SHUTDOWN_TIME = 30000; // 30 seconds
423
424 synchronized void shutdown() {
425 if (DEBUG_BASIC)
426 Debug.println("TRC.worker shutdown, " + testsToWrite.size() + " tests to flush");
427
428 // shutdownRequested is initially false, and gets set true here;
429 // once set true, it stays true and never goes false again, which
430 // reduces the need for synchronized access
431 shutdownRequested = true;
432 if (testsToWrite.size() > 0)
433 flushRequested = true;
434 notifyAll();
435
436 long now = System.currentTimeMillis();
437 long end = now + MAX_SHUTDOWN_TIME;
438 try {
439 while (worker != null & now < end) {
440 if (DEBUG_SYNC)
441 Debug.println("TRC.shutdown waiting for worker to exit");
442
443 wait(end - now);
444 now = System.currentTimeMillis();
445 }
446
447 if (DEBUG_SYNC)
448 Debug.println("TRC.shutdown done");
449 }
450 catch (InterruptedException e) {
451 // ignore
452 }
453
454 try {
455 if (workDir != null && workDir.getTestSuite() != null) {
456 Logger log = workDir.getTestSuite().getLog(workDir, i18n.getString("core.log.name"));
457 if (log != null && log.getHandlers() != null) {
458 for (Handler handler : log.getHandlers()) {
459 if (handler instanceof WorkDirLogHandler) {
460 ((WorkDirLogHandler) handler).close();
461 }
462 }
463 }
464 }
465 }
466 catch (TestSuite.NoSuchLogFault noSuchLogFault) {
467 //nothing to do
468 }
469
470 // important to avoid memory leak !!!
471 try {
472 if (shutdownHandler != null) {
473 Runtime.getRuntime().removeShutdownHook(shutdownHandler);
474 }
475 }
476 catch(IllegalStateException ex) {
477 // it's ok if shutdown is in process now
478 }
479 }
480
481 //-------------------------------------------------------------------------------------
482 //
483 // Read a set of tests from the *.jtr files in the work directory
484
485 private Map<String, TestResult> readJTRFiles() {
486 final long start = System.currentTimeMillis();
487 Map<String, TestResult> tests = new TreeMap<>();
488 readJTRFiles(workDir.getRoot(), tests);
489
490 // these lines are all for logging benchmark info
491 final long time = System.currentTimeMillis() - start;
492 Logger log = null;
493 try {
494 log = workDir.getTestSuite().createLog(workDir, null,
495 i18n.getString("core.log.name"));
496 }
497 catch (TestSuite.DuplicateLogNameFault f) {
498 try {
499 log = workDir.getTestSuite().getLog(workDir, i18n.getString("core.log.name"));
500 }
501 catch (TestSuite.NoSuchLogFault f2) { }
502 }
503
504 if (log != null) {
505 Integer loadTime = new Integer((int) (time / 1000));
506 Object[] params = new Object[]{loadTime};
507 String output = i18n.getString("trc.log.rtime", params);
508 log.info(output);
509 if (DEBUG_BASIC) Debug.println(output);
510 }
511
512 return tests;
513 }
514
515 private void readJTRFiles(File dir, Map<String, TestResult> tests) {
516 File[] entries = dir.listFiles();
517 if (entries != null) {
518 // monitor shutdownRequested and give up if set true;
519 // no specific notification is passed back in this case;
520 // it is assumed the caller will also check shutdownRequested
521 // and act appropriately
522 for (int i = 0; i < entries.length && !shutdownRequested; i++) {
523 File f = entries[i];
524 if (f.isDirectory())
525 readJTRFiles(f, tests);
526 else if (TestResult.isResultFile(f)) {
527 try {
528 TestResult tr = new TestResult(f);
529 tests.put(tr.getWorkRelativePath(), tr);
530 }
531 catch (TestResult.ResultFileNotFoundFault e) {
532 // hmm, should not happen, since we just read the directory
533 workDir.log(i18n, "trc.lostjtr", f);
534 }
535 catch (TestResult.ReloadFault e) {
536 // delete this jtr and continue
537 // should we inform TRT? perhaps via observer
538 workDir.log(i18n, "trc.badjtr", new Object[] {f, e.getLocalizedMessage()});
539 f.delete();
540 }
541 }
542 entries[i] = null; // just to help GC
543 }
544 }
545 }
546
547 private TestResult reload(Map<String, TestResult> tests, TestResult tr) {
548 File jtr = workDir.getFile(tr.getWorkRelativePath());
549 try {
550 return new TestResult(jtr);
551 }
552 catch (TestResult.ResultFileNotFoundFault e) {
553 // test is presumably not run or has been purged
554 // this notRun status will persist in cache until cache rebuilt
555 String name = tr.getTestName();
556 tr = new TestResult(name, workDir, Status.notRun(""));
557 tests.put(name, tr); // in case fullUpdateRequested
558 return tr;
559 }
560 catch (TestResult.ReloadFault e) {
561 // bad .jtr, delete it
562 workDir.log(i18n, "trc.badjtr", new Object[] {jtr, e.getLocalizedMessage()});
563 jtr.delete();
564 // this notRun status will persist in cache until cache rebuilt
565 String name = tr.getTestName();
566 tr = new TestResult(name, workDir, Status.notRun("previous results corrupted"));
567 tests.put(name, tr); // in case fullUpdateRequested
568 return tr;
569 }
570 }
571
572 //-------------------------------------------------------------------------------------
573 //
574 // Read the cache
575
576 private Map<String, TestResult> readCache()
577 throws IOException, IllegalArgumentException
578 {
579 final long start = System.currentTimeMillis();
580
581 if (DEBUG_WORK)
582 Debug.println("TRC.readCache");
583
584 raf.seek(0);
585 int fileSerial = raf.readInt();
586
587 if (DEBUG_WORK)
588 Debug.println("TRC.readCache serial=" + fileSerial);
589
590 if (lastFileSize == -1 || fileSerial != lastSerial
591 || fullUpdateRequested || compressRequested) {
592 updateNeeded = (fullUpdateRequested
593 || fileSerial != lastSerial
594 || raf.length() > lastFileSize);
595 // read full cache
596 lastSerial = fileSerial;
597 totalEntryCount = 0;
598 Map<String, TestResult> tests = readCacheEntries();
599 uniqueInitialEntryCount = tests.size();
600
601 if (DEBUG_WORK)
602 Debug.println("TRC.readCache read all (" + tests.size() + " tests, " + uniqueInitialEntryCount + " unique)");
603
604 final long time = System.currentTimeMillis() - start;
605 Logger log = null;
606 try {
607 log = workDir.getTestSuite().createLog(workDir, null,
608 i18n.getString("core.log.name"));
609 }
610 catch (TestSuite.DuplicateLogNameFault f) {
611 try {
612 log = workDir.getTestSuite().getLog(workDir, i18n.getString("core.log.name"));
613 }
614 catch (TestSuite.NoSuchLogFault f2) { }
615 }
616
617 if (log != null) {
618 Integer loadTime = new Integer((int) (time / 1000));
619 Object[] params = new Object[]{loadTime};
620 String output = i18n.getString("trc.log.ptime", params);
621 log.info(output);
622 if (DEBUG_BASIC) Debug.println(output);
623 }
624
625 return tests;
626 }
627 else if (raf.length() > lastFileSize) {
628 // just read updates from file
629 raf.seek(lastFileSize);
630 Map<String, TestResult> tests = readCacheEntries();
631
632 if (DEBUG_WORK)
633 Debug.println("TRC.readCache read update (" + tests.size() + " tests)");
634
635 updateNeeded = true;
636 return tests;
637 }
638 else {
639 // no updates available
640 updateNeeded = false;
641 return null;
642 }
643 }
644
645 private Map<String, TestResult> readCacheEntries()
646 throws IOException, IllegalArgumentException
647 {
648 Map<String, TestResult> tests = new TreeMap<>();
649 while (raf.getFilePointer() < raf.length()) {
650 String name = raf.readUTF();
651 int status = raf.readInt();
652 String reason = raf.readUTF();
653 long endTime = raf.readLong();
654 TestResult tr = new TestResult(name, workDir, new Status(status, reason), endTime);
655 File f = tr.getFile();
656 if (!f.exists()) {
657 tr.resetFile();
658 }
659 tests.put(tr.getWorkRelativePath(), tr);
660 totalEntryCount++; // count all entries, including duplicates
661 }
662 lastFileSize = raf.length();
663 return tests;
664 }
665
666 //-------------------------------------------------------------------------------------
667 //
668 // Write the cache
669
670 private void writeCache(Map<String, TestResult> tests) throws IOException {
671 if (tests == null)
672 throw new IllegalStateException();
673
674 // merge any tests in testsToWrite
675 // testsToWrite is a thread-safe fifo, so it is safe to keep reading
676 // it till its empty, even though some tests may even have been added
677 // after the worker woke up
678 TestResult tr;
679 while ((tr = (TestResult) (testsToWrite.remove())) != null) {
680 // check if test is in the set we've just read
681 String name = tr.getTestName();
682 TestResult tr2 = tests.get(name);
683 // if the cache file contains a conflicting entry,
684 // reload the test from the .jtr file; otherwise, add it to the cache
685 if (tr2 != null && !tr2.getStatus().equals(tr.getStatus()))
686 reload(tests, tr);
687 else
688 tests.put(tr.getWorkRelativePath(), tr);
689 }
690
691 // write cache
692 raf.seek(0);
693 long now = System.currentTimeMillis();
694 lastSerial = (int) ((now >> 16) + (now & 0xffff));
695 raf.writeInt(lastSerial);
696
697 for (Iterator iter = tests.values().iterator(); iter.hasNext(); ) {
698 tr = (TestResult) (iter.next());
699 writeCacheEntry(tr);
700 }
701
702 if (DEBUG_WORK)
703 Debug.println("TRC.writeCache write all (" + tests.size() + " tests)");
704
705 raf.setLength(raf.getFilePointer());
706 lastFileSize = raf.length();
707 uniqueInitialEntryCount = totalEntryCount = tests.size();
708 }
709
710 private void updateCache(Map<String, TestResult> tests) throws IOException {
711 // testsToWrite is a thread-safe fifo, so it is safe to keep reading
712 // it till its empty, even though some tests may even have been added
713 // after the worker woke up
714 int debugCount = 0;
715 raf.seek(lastFileSize);
716 TestResult tr;
717 while ((tr = (TestResult) (testsToWrite.remove())) != null) {
718 if (tests != null) {
719 // check if test is in the set we've just read
720 String name = tr.getTestName();
721 TestResult tr2 = tests.get(name);
722 if (tr2 != null) {
723 // cache also contains an entry for this test:
724 // reload from .jtr file in case of conflict
725 if (!tr2.getStatus().equals(tr.getStatus()))
726 tr = reload(tests, tr);
727 }
728 }
729 writeCacheEntry(tr);
730 debugCount++;
731 }
732 if (DEBUG_WORK && debugCount > 0)
733 Debug.println("TRC.writeCache write update (" + debugCount + " tests)");
734
735 raf.setLength(raf.getFilePointer());
736 lastFileSize = raf.length();
737 }
738
739 private void writeCacheEntry(TestResult tr) throws IOException {
740 String name = tr.getTestName();
741 Status status = tr.getStatus();
742 raf.writeUTF(name);
743 raf.writeInt(status.getType());
744
745 String reason = status.getReason();
746
747 if (reason == null) {
748 reason = "";
749 }
750
751 // writeUTF() can only accept a limited string length, additionally,
752 // in this field and in the cache, the full data is not needed
753 if (reason.length() > MAX_REASON_LENGTH) {
754 reason = reason.substring(0,15) +
755 "[...]" +
756 reason.substring(reason.length()-MAX_REASON_LENGTH+20);
757 }
758 raf.writeUTF(reason);
759
760
761 raf.writeLong(tr.getEndTime());
762 totalEntryCount++;
763 }
764
765 //-------------------------------------------------------------------------------------
766 //
767 // lock acquisition and release
768
769 // lock acquisition and notification parameters
770 private static final long INITIAL_LOCK_NOTIFY_TIME = 20000; // 20 seconds
771 private static final long LOCK_NOTIFY_INTERVAL = 60000; // 60 second
772 private static final long MAX_LOCK_WAIT_TIME =
773 Integer.getInteger("javatest.trc.timeout", 5).intValue() * 60000;
774 // default 5 minutes
775
776 // retry parameters
777 private static final int INITIAL_RETRY_DELAY_TIME = 500; // 0.5 second
778 private static final int MAX_RETRY_DELAY_TIME = 10000; // 10 seconds
779
780 private void getLock() throws IOException {
781 long start = System.currentTimeMillis();
782 int retryDelay = INITIAL_RETRY_DELAY_TIME;
783 long lastNotified = 0;
784
785 // for JDK 1.4, should consider using raf.getChannel().tryLock()
786 while (!lockFile.createNewFile()) {
787 long now = System.currentTimeMillis();
788 long timeSinceStart = now - start;
789 if (timeSinceStart < INITIAL_LOCK_NOTIFY_TIME) {
790 // no need to worry, yet
791 continue;
792 }
793 else if (timeSinceStart < MAX_LOCK_WAIT_TIME) {
794 // slowly getting nervous: periodically notify observer
795 long timeSinceLastNotified = now - lastNotified;
796 if (lastNotified == 0
797 || timeSinceLastNotified > LOCK_NOTIFY_INTERVAL) {
798 observer.waitingForLock(timeSinceStart);
799 lastNotified = System.currentTimeMillis();
800 }
801
802 // slowly increase delay while we are waiting
803 if (retryDelay < MAX_RETRY_DELAY_TIME)
804 retryDelay = Math.min(2 * retryDelay, MAX_RETRY_DELAY_TIME);
805 }
806 else {
807 // full fledge panic: trash the lock and rebuild the cache
808 observer.timeoutWaitingForLock();
809 workDir.log(i18n, "trc.lockTimeout");
810
811 try {
812 if (raf != null)
813 raf.close();
814 }
815 catch (IOException e) {
816 // ignore
817 }
818
819 cacheFile.delete();
820 lockFile.delete();
821
822 raf = new RandomAccessFile(cacheFile, "rw");
823
824 // leave caller to repopulate cache
825 }
826
827 // sleep for a bit before retrying to avoid busy waiting
828 try {
829 Thread.currentThread().sleep(retryDelay);
830 }
831 catch (InterruptedException e) {
832 // ignore
833 }
834
835 }
836
837 observer.acquiredLock();
838 }
839
840 private void releaseLock() {
841 // for JDK 1.4, should consider releasing the FileLock obtained from
842 // raf.getChannel().tryLock()
843 lockFile.delete();
844 observer.releasedLock();
845 }
846
847 //-------------------------------------------------------------------------------------
848
849 // When the work thread sleeps, it zaps the main references to observer and workDir
850 // to the possibility that the WD and TRT might be GCed, and just retains weak references.
851 // These weak references get revived when the worker thread has work to do.
852 private void reviveWeakReferences() {
853 if (workDir == null)
854 workDir = weakWorkDir.get();
855
856 if (observer == null)
857 observer = weakObserver.get();
858 }
859
860 //-------------------------------------------------------------------------------------
861
862 // general instance data
863 private Observer observer;
864 private WeakReference<Observer> weakObserver;
865 private WorkDirectory workDir;
866 private WeakReference<WorkDirectory> weakWorkDir;
867 private File cacheFile;
868 private File lockFile;
869 private Thread worker;
870 private Thread shutdownHandler;
871
872 // worker thread data
873 private RandomAccessFile raf;
874 private int uniqueInitialEntryCount;
875 private int totalEntryCount;
876 private int lastSerial;
877 private long lastFileSize;
878 private boolean updateNeeded;
879
880 // synchronized data
881 private boolean fullUpdateRequested;
882 private boolean compressNeeded;
883 private boolean compressRequested;
884 private boolean flushRequested;
885 private boolean shutdownRequested;
886 private Fifo testsToWrite = new Fifo();
887
888 private static final String V1_FILENAME = "ResultCache.jtw";
889 private static final String V1_LOCKNAME = V1_FILENAME + ".lck";
890 private static final String V2_FILENAME = "ResultCache2.jtw";
891 private static final String V2_LOCKNAME = V2_FILENAME + ".lck";
892
893 // other
894 private static I18NResourceBundle i18n = I18NResourceBundle.getBundleForClass(TestResultCache.class);
895 private static int workerNumber; // for naming threads
896
897 // maximum length of reason string written into cache
898 // writeUTF can only write a limited length string, see writeCacheEntry()
899 private static final int MAX_REASON_LENGTH = 256;
900
901 private static int debug = Debug.getInt(TestResultCache.class);
902 private static final boolean DEBUG_BASIC = (debug >= 1); // basic messages and stack trace
903 private static final boolean DEBUG_TESTS = (debug >= 2); // details about tests
904 private static final boolean DEBUG_WORK = (debug >= 3); // details about work done
905 private static final boolean DEBUG_CHECK_WORK = (debug >= 4); // details when checking for work
906 private static final boolean DEBUG_SYNC = (debug >= 5); // details about thread syncs
907 }