print expected/actual times more saliently in performance tests
[idea/community.git] / platform / testFramework / src / com / intellij / testFramework / PlatformTestUtil.java
1 /*
2  * Copyright 2000-2016 JetBrains s.r.o.
3  *
4  * Licensed under the Apache License, Version 2.0 (the "License");
5  * you may not use this file except in compliance with the License.
6  * You may obtain a copy of the License at
7  *
8  * http://www.apache.org/licenses/LICENSE-2.0
9  *
10  * Unless required by applicable law or agreed to in writing, software
11  * distributed under the License is distributed on an "AS IS" BASIS,
12  * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
13  * See the License for the specific language governing permissions and
14  * limitations under the License.
15  */
16 package com.intellij.testFramework;
17
18 import com.intellij.concurrency.JobSchedulerImpl;
19 import com.intellij.execution.ExecutionException;
20 import com.intellij.execution.configurations.GeneralCommandLine;
21 import com.intellij.execution.process.ProcessOutput;
22 import com.intellij.execution.util.ExecUtil;
23 import com.intellij.ide.DataManager;
24 import com.intellij.ide.IdeEventQueue;
25 import com.intellij.ide.util.treeView.AbstractTreeNode;
26 import com.intellij.ide.util.treeView.AbstractTreeStructure;
27 import com.intellij.idea.Bombed;
28 import com.intellij.openapi.Disposable;
29 import com.intellij.openapi.actionSystem.*;
30 import com.intellij.openapi.application.Application;
31 import com.intellij.openapi.application.ApplicationManager;
32 import com.intellij.openapi.application.ModalityState;
33 import com.intellij.openapi.application.PathManager;
34 import com.intellij.openapi.application.ex.ApplicationEx;
35 import com.intellij.openapi.application.ex.ApplicationManagerEx;
36 import com.intellij.openapi.editor.Document;
37 import com.intellij.openapi.extensions.ExtensionPoint;
38 import com.intellij.openapi.extensions.ExtensionPointName;
39 import com.intellij.openapi.extensions.Extensions;
40 import com.intellij.openapi.extensions.ExtensionsArea;
41 import com.intellij.openapi.fileEditor.FileDocumentManager;
42 import com.intellij.openapi.fileEditor.impl.LoadTextUtil;
43 import com.intellij.openapi.fileTypes.FileTypes;
44 import com.intellij.openapi.paths.WebReference;
45 import com.intellij.openapi.project.Project;
46 import com.intellij.openapi.ui.Queryable;
47 import com.intellij.openapi.util.*;
48 import com.intellij.openapi.util.io.FileUtil;
49 import com.intellij.openapi.util.text.StringUtil;
50 import com.intellij.openapi.vfs.LocalFileSystem;
51 import com.intellij.openapi.vfs.VfsUtilCore;
52 import com.intellij.openapi.vfs.VirtualFile;
53 import com.intellij.openapi.vfs.VirtualFileFilter;
54 import com.intellij.openapi.vfs.ex.temp.TempFileSystem;
55 import com.intellij.psi.PsiElement;
56 import com.intellij.psi.PsiRecursiveElementWalkingVisitor;
57 import com.intellij.psi.PsiReference;
58 import com.intellij.util.*;
59 import com.intellij.util.containers.HashMap;
60 import com.intellij.util.io.ZipUtil;
61 import com.intellij.util.ui.UIUtil;
62 import junit.framework.AssertionFailedError;
63 import org.jdom.Element;
64 import org.jdom.JDOMException;
65 import org.jetbrains.annotations.*;
66 import org.junit.Assert;
67
68 import javax.swing.*;
69 import javax.swing.tree.DefaultMutableTreeNode;
70 import javax.swing.tree.TreePath;
71 import java.awt.*;
72 import java.awt.event.InvocationEvent;
73 import java.io.*;
74 import java.nio.charset.Charset;
75 import java.text.DecimalFormat;
76 import java.text.DecimalFormatSymbols;
77 import java.util.*;
78 import java.util.List;
79 import java.util.concurrent.CopyOnWriteArrayList;
80 import java.util.concurrent.atomic.AtomicBoolean;
81 import java.util.jar.JarFile;
82
83 /**
84  * @author yole
85  */
86 @SuppressWarnings({"UseOfSystemOutOrSystemErr", "TestOnlyProblems"})
87 public class PlatformTestUtil {
88   public static final boolean COVERAGE_ENABLED_BUILD = "true".equals(System.getProperty("idea.coverage.enabled.build"));
89
90   public static final boolean SKIP_HEADLESS = GraphicsEnvironment.isHeadless();
91   public static final boolean SKIP_SLOW = Boolean.getBoolean("skip.slow.tests.locally");
92   
93   private static final List<Runnable> ourProjectCleanups = new CopyOnWriteArrayList<>();
94
95   @NotNull
96   public static String getTestName(@NotNull String name, boolean lowercaseFirstLetter) {
97     name = StringUtil.trimStart(name, "test");
98     return StringUtil.isEmpty(name) ? "" : lowercaseFirstLetter(name, lowercaseFirstLetter);
99   }
100
101   @NotNull
102   public static String lowercaseFirstLetter(@NotNull String name, boolean lowercaseFirstLetter) {
103     if (lowercaseFirstLetter && !isAllUppercaseName(name)) {
104       name = Character.toLowerCase(name.charAt(0)) + name.substring(1);
105     }
106     return name;
107   }
108
109   public static boolean isAllUppercaseName(@NotNull String name) {
110     int uppercaseChars = 0;
111     for (int i = 0; i < name.length(); i++) {
112       if (Character.isLowerCase(name.charAt(i))) {
113         return false;
114       }
115       if (Character.isUpperCase(name.charAt(i))) {
116         uppercaseChars++;
117       }
118     }
119     return uppercaseChars >= 3;
120   }
121
122   public static <T> void registerExtension(@NotNull ExtensionPointName<T> name, @NotNull T t, @NotNull Disposable parentDisposable) {
123     registerExtension(Extensions.getRootArea(), name, t, parentDisposable);
124   }
125
126   public static <T> void registerExtension(@NotNull ExtensionsArea area, @NotNull ExtensionPointName<T> name, @NotNull final T t, @NotNull Disposable parentDisposable) {
127     final ExtensionPoint<T> extensionPoint = area.getExtensionPoint(name.getName());
128     extensionPoint.registerExtension(t);
129     Disposer.register(parentDisposable, new Disposable() {
130       @Override
131       public void dispose() {
132         extensionPoint.unregisterExtension(t);
133       }
134     });
135   }
136
137   @Nullable
138   protected static String toString(@Nullable Object node, @Nullable Queryable.PrintInfo printInfo) {
139     if (node instanceof AbstractTreeNode) {
140       if (printInfo != null) {
141         return ((AbstractTreeNode)node).toTestString(printInfo);
142       }
143       else {
144         @SuppressWarnings({"deprecation", "UnnecessaryLocalVariable"})
145         final String presentation = ((AbstractTreeNode)node).getTestPresentation();
146         return presentation;
147       }
148     }
149     if (node == null) {
150       return "NULL";
151     }
152     return node.toString();
153   }
154
155   public static String print(JTree tree, boolean withSelection) {
156     return print(tree, tree.getModel().getRoot(), withSelection, null, null);
157   }
158
159   public static String print(JTree tree, Object root, @Nullable Queryable.PrintInfo printInfo, boolean withSelection) {
160     return print(tree, root,  withSelection, printInfo, null);
161   }
162
163   public static String print(JTree tree, boolean withSelection, @Nullable Condition<String> nodePrintCondition) {
164     return print(tree, tree.getModel().getRoot(), withSelection, null, nodePrintCondition);
165   }
166   
167   public static String print(JTree tree, Object root, 
168                              boolean withSelection,
169                              @Nullable Queryable.PrintInfo printInfo,
170                              @Nullable Condition<String> nodePrintCondition) {
171     StringBuilder buffer = new StringBuilder();
172     final Collection<String> strings = printAsList(tree, root, withSelection, printInfo, nodePrintCondition);
173     for (String string : strings) {
174       buffer.append(string).append("\n");
175     }
176     return buffer.toString();
177   }
178
179   public static Collection<String> printAsList(JTree tree, boolean withSelection, @Nullable Condition<String> nodePrintCondition) {
180     return printAsList(tree, tree.getModel().getRoot(), withSelection, null, nodePrintCondition);
181   }
182
183   private static Collection<String> printAsList(JTree tree, Object root, 
184                                                 boolean withSelection,
185                                                 @Nullable Queryable.PrintInfo printInfo,
186                                                 Condition<String> nodePrintCondition) {
187     Collection<String> strings = new ArrayList<String>();
188     printImpl(tree, root, strings, 0, withSelection, printInfo, nodePrintCondition);
189     return strings;
190   }
191
192   private static void printImpl(JTree tree,
193                                 Object root,
194                                 Collection<String> strings,
195                                 int level,
196                                 boolean withSelection,
197                                 @Nullable Queryable.PrintInfo printInfo,
198                                 @Nullable Condition<String> nodePrintCondition) {
199     DefaultMutableTreeNode defaultMutableTreeNode = (DefaultMutableTreeNode)root;
200
201     final Object userObject = defaultMutableTreeNode.getUserObject();
202     String nodeText;
203     if (userObject != null) {
204       nodeText = toString(userObject, printInfo);
205     }
206     else {
207       nodeText = "null";
208     }
209
210     if (nodePrintCondition != null && !nodePrintCondition.value(nodeText)) return;
211
212     final StringBuilder buff = new StringBuilder();
213     StringUtil.repeatSymbol(buff, ' ', level);
214
215     final boolean expanded = tree.isExpanded(new TreePath(defaultMutableTreeNode.getPath()));
216     if (!defaultMutableTreeNode.isLeaf()) {
217       buff.append(expanded ? "-" : "+");
218     }
219
220     final boolean selected = tree.getSelectionModel().isPathSelected(new TreePath(defaultMutableTreeNode.getPath()));
221     if (withSelection && selected) {
222       buff.append("[");
223     }
224
225     buff.append(nodeText);
226
227     if (withSelection && selected) {
228       buff.append("]");
229     }
230
231     strings.add(buff.toString());
232
233     int childCount = tree.getModel().getChildCount(root);
234     if (expanded) {
235       for (int i = 0; i < childCount; i++) {
236         printImpl(tree, tree.getModel().getChild(root, i), strings, level + 1, withSelection, printInfo, nodePrintCondition);
237       }
238     }
239   }
240
241   public static void assertTreeEqual(JTree tree, @NonNls String expected) {
242     assertTreeEqual(tree, expected, false);
243   }
244
245   public static void assertTreeEqualIgnoringNodesOrder(JTree tree, @NonNls String expected) {
246     assertTreeEqualIgnoringNodesOrder(tree, expected, false);
247   }
248
249   public static void assertTreeEqual(JTree tree, String expected, boolean checkSelected) {
250     String treeStringPresentation = print(tree, checkSelected);
251     Assert.assertEquals(expected, treeStringPresentation);
252   }
253
254   public static void assertTreeEqualIgnoringNodesOrder(JTree tree, String expected, boolean checkSelected) {
255     final Collection<String> actualNodesPresentation = printAsList(tree, checkSelected, null);
256     final List<String> expectedNodes = StringUtil.split(expected, "\n");
257     UsefulTestCase.assertSameElements(actualNodesPresentation, expectedNodes);
258   }
259
260   @TestOnly
261   public static void waitForAlarm(final int delay) throws InterruptedException {
262     Application app = ApplicationManager.getApplication();
263     assert !app.isWriteAccessAllowed(): "It's a bad idea to wait for an alarm under the write action. Somebody creates an alarm which requires read action and you are deadlocked.";
264     assert app.isDispatchThread();
265
266     final AtomicBoolean runnableInvoked = new AtomicBoolean();
267     final AtomicBoolean alarmInvoked1 = new AtomicBoolean();
268     final AtomicBoolean alarmInvoked2 = new AtomicBoolean();
269     final Alarm alarm = new Alarm(Alarm.ThreadToUse.SWING_THREAD);
270     ModalityState initialModality = ModalityState.current();
271
272     alarm.addRequest(() -> {
273       alarmInvoked1.set(true);
274       app.invokeLater(() -> {
275         runnableInvoked.set(true);
276         alarm.addRequest(() -> alarmInvoked2.set(true), delay);
277       });
278     }, delay);
279
280     UIUtil.dispatchAllInvocationEvents();
281
282     long start = System.currentTimeMillis();
283     boolean sleptAlready = false;
284     while (!alarmInvoked2.get()) {
285       UIUtil.dispatchAllInvocationEvents();
286       //noinspection BusyWait
287       Thread.sleep(sleptAlready ? 10 : delay);
288       sleptAlready = true;
289       if (System.currentTimeMillis() - start > 100 * 1000) {
290         throw new AssertionError("Couldn't await alarm" +
291                                  "; alarm1 passed=" + alarmInvoked1.get() +
292                                  "; modality1=" + initialModality +
293                                  "; modality2=" + ModalityState.current() +
294                                  "; invokeLater passed=" + runnableInvoked.get() +
295                                  "; app.disposed=" + app.isDisposed() +
296                                  "; alarm.disposed=" + alarm.isDisposed() +
297                                  "; alarm.requests=" + alarm.getActiveRequestCount()
298         );
299       }
300     }
301     UIUtil.dispatchAllInvocationEvents();
302   }
303
304   @TestOnly
305   public static void dispatchAllInvocationEventsInIdeEventQueue() throws InterruptedException {
306     assert SwingUtilities.isEventDispatchThread() : Thread.currentThread();
307     final IdeEventQueue eventQueue = (IdeEventQueue)Toolkit.getDefaultToolkit().getSystemEventQueue();
308     while (true) {
309       AWTEvent event = eventQueue.peekEvent();
310       if (event == null) break;
311       AWTEvent event1 = eventQueue.getNextEvent();
312       if (event1 instanceof InvocationEvent) {
313         eventQueue.dispatchEvent(event1);
314       }
315     }
316   }
317
318   @TestOnly
319   public static void dispatchAllEventsInIdeEventQueue() throws InterruptedException {
320     assert SwingUtilities.isEventDispatchThread() : Thread.currentThread();
321     final IdeEventQueue eventQueue = (IdeEventQueue)Toolkit.getDefaultToolkit().getSystemEventQueue();
322     while (dispatchNextEventIfAny(eventQueue) != null);
323   }
324
325   @TestOnly
326   public static AWTEvent dispatchNextEventIfAny(@NotNull IdeEventQueue eventQueue) throws InterruptedException {
327     AWTEvent event = eventQueue.peekEvent();
328     if (event == null) return null;
329     AWTEvent event1 = eventQueue.getNextEvent();
330     eventQueue.dispatchEvent(event1);
331     return event1;
332   }
333
334   private static Date raidDate(Bombed bombed) {
335     final Calendar instance = Calendar.getInstance();
336     instance.set(Calendar.YEAR, bombed.year());
337     instance.set(Calendar.MONTH, bombed.month());
338     instance.set(Calendar.DAY_OF_MONTH, bombed.day());
339     instance.set(Calendar.HOUR_OF_DAY, bombed.time());
340     instance.set(Calendar.MINUTE, 0);
341
342     return instance.getTime();
343   }
344
345   public static boolean bombExplodes(Bombed bombedAnnotation) {
346     Date now = new Date();
347     return now.after(raidDate(bombedAnnotation));
348   }
349
350   public static StringBuilder print(AbstractTreeStructure structure,
351                                     Object node,
352                                     int currentLevel,
353                                     @Nullable Comparator comparator,
354                                     int maxRowCount,
355                                     char paddingChar,
356                                     @Nullable Queryable.PrintInfo printInfo) {
357     StringBuilder buffer = new StringBuilder();
358     doPrint(buffer, currentLevel, node, structure, comparator, maxRowCount, 0, paddingChar, printInfo);
359     return buffer;
360   }
361
362   private static int doPrint(StringBuilder buffer,
363                              int currentLevel,
364                              Object node,
365                              AbstractTreeStructure structure,
366                              @Nullable Comparator comparator,
367                              int maxRowCount,
368                              int currentLine,
369                              char paddingChar,
370                              @Nullable Queryable.PrintInfo printInfo) {
371     if (currentLine >= maxRowCount && maxRowCount != -1) return currentLine;
372
373     StringUtil.repeatSymbol(buffer, paddingChar, currentLevel);
374     buffer.append(toString(node, printInfo)).append("\n");
375     currentLine++;
376     Object[] children = structure.getChildElements(node);
377
378     if (comparator != null) {
379       ArrayList<?> list = new ArrayList<Object>(Arrays.asList(children));
380       @SuppressWarnings({"UnnecessaryLocalVariable", "unchecked"}) Comparator<Object> c = comparator;
381       Collections.sort(list, c);
382       children = ArrayUtil.toObjectArray(list);
383     }
384     for (Object child : children) {
385       currentLine = doPrint(buffer, currentLevel + 1, child, structure, comparator, maxRowCount, currentLine, paddingChar, printInfo);
386     }
387
388     return currentLine;
389   }
390
391   public static String print(Object[] objects) {
392     return print(Arrays.asList(objects));
393   }
394
395   public static String print(Collection c) {
396     StringBuilder result = new StringBuilder();
397     for (Iterator iterator = c.iterator(); iterator.hasNext();) {
398       Object each = iterator.next();
399       result.append(toString(each, null));
400       if (iterator.hasNext()) {
401         result.append("\n");
402       }
403     }
404
405     return result.toString();
406   }
407
408   public static String print(ListModel model) {
409     StringBuilder result = new StringBuilder();
410     for (int i = 0; i < model.getSize(); i++) {
411       result.append(toString(model.getElementAt(i), null));
412       result.append("\n");
413     }
414     return result.toString();
415   }
416
417   public static String print(JTree tree) {
418     return print(tree, false);
419   }
420
421   public static void updateRecursively(@NotNull AbstractTreeNode<?> node) {
422     node.update();
423     for (AbstractTreeNode child : node.getChildren()) {
424       updateRecursively(child);
425     }
426   }
427
428   public static void assertTreeStructureEquals(@NotNull AbstractTreeStructure treeStructure, @NotNull String expected) {
429     Assert.assertEquals(expected.trim(), print(treeStructure, treeStructure.getRootElement(), 0, null, -1, ' ', null).toString().trim());
430   }
431
432   public static void invokeNamedAction(final String actionId) {
433     final AnAction action = ActionManager.getInstance().getAction(actionId);
434     Assert.assertNotNull(action);
435     final Presentation presentation = new Presentation();
436     @SuppressWarnings("deprecation") final DataContext context = DataManager.getInstance().getDataContext();
437     final AnActionEvent event = AnActionEvent.createFromAnAction(action, null, "", context);
438     action.update(event);
439     Assert.assertTrue(presentation.isEnabled());
440     action.actionPerformed(event);
441   }
442
443   public static void assertTiming(final String message, final long expectedMs, final long actual) {
444     if (COVERAGE_ENABLED_BUILD) return;
445
446     final long expectedOnMyMachine = Math.max(1, expectedMs * Timings.MACHINE_TIMING / Timings.ETALON_TIMING);
447
448     // Allow 10% more in case of test machine is busy.
449     String logMessage = message;
450     if (actual > expectedOnMyMachine) {
451       int percentage = (int)(100.0 * (actual - expectedOnMyMachine) / expectedOnMyMachine);
452       logMessage += ". Operation took " + percentage + "% longer than expected";
453     }
454     logMessage += ". Expected on my machine: " + expectedOnMyMachine + "." +
455                   " Actual: " + actual + "." +
456                   " Expected on Standard machine: " + expectedMs + ";" +
457                   " Actual on Standard: " + actual * Timings.ETALON_TIMING / Timings.MACHINE_TIMING + ";" +
458                   " Timings: CPU=" + Timings.CPU_TIMING +
459                   ", I/O=" + Timings.IO_TIMING + "." +
460                   " (" + (int)(Timings.MACHINE_TIMING*1.0/Timings.ETALON_TIMING*100) + "% of the Standard)" +
461                   ".";
462     final double acceptableChangeFactor = 1.1;
463     if (actual < expectedOnMyMachine) {
464       System.out.println(logMessage);
465       TeamCityLogger.info(logMessage);
466     }
467     else if (actual < expectedOnMyMachine * acceptableChangeFactor) {
468       TeamCityLogger.warning(logMessage, null);
469     }
470     else {
471       // throw AssertionFailedError to try one more time
472       throw new AssertionFailedError(logMessage);
473     }
474   }
475
476   /**
477    * example usage: startPerformanceTest("calculating pi",100, testRunnable).cpuBound().assertTiming();
478    */
479   @Contract(pure = true) // to warn about not calling .assertTiming() in the end
480   public static TestInfo startPerformanceTest(@NonNls @NotNull String message, int expectedMs, @NotNull ThrowableRunnable test) {
481     return new TestInfo(test, expectedMs,message);
482   }
483
484   public static boolean canRunTest(@NotNull Class testCaseClass) {
485     if (!SKIP_SLOW && !SKIP_HEADLESS) {
486       return true;
487     }
488
489     for (Class<?> clazz = testCaseClass; clazz != null; clazz = clazz.getSuperclass()) {
490       if (SKIP_HEADLESS && clazz.getAnnotation(SkipInHeadlessEnvironment.class) != null) {
491         System.out.println("Class '" + testCaseClass.getName() + "' is skipped because it requires working UI environment");
492         return false;
493       }
494       if (SKIP_SLOW && clazz.getAnnotation(SkipSlowTestLocally.class) != null) {
495         System.out.println("Class '" + testCaseClass.getName() + "' is skipped because it is dog slow");
496         return false;
497       }
498     }
499
500     return true;
501   }
502
503   public static void assertPathsEqual(@Nullable String expected, @Nullable String actual) {
504     if (expected != null) expected = FileUtil.toSystemIndependentName(expected);
505     if (actual != null) actual = FileUtil.toSystemIndependentName(actual);
506     Assert.assertEquals(expected, actual);
507   }
508
509   @NotNull
510   public static String getRtJarPath() {
511     String home = System.getProperty("java.home");
512     return SystemInfo.isAppleJvm ? FileUtil.toCanonicalPath(home + "/../Classes/classes.jar") : home + "/lib/rt.jar";
513   }
514
515   public static void saveProject(Project project) {
516     ApplicationEx application = ApplicationManagerEx.getApplicationEx();
517     boolean oldValue = application.isDoNotSave();
518     try {
519       application.doNotSave(false);
520       project.save();
521     }
522     finally {
523       application.doNotSave(oldValue);
524     }
525   }
526
527   public static class TestInfo {
528     private final ThrowableRunnable test; // runnable to measure
529     private final int expectedMs;           // millis the test is expected to run
530     private ThrowableRunnable setup;      // to run before each test
531     private boolean usesAllCPUCores;      // true if the test runs faster on multi-core
532     private int attempts = 4;             // number of retries if performance failed
533     private final String message;         // to print on fail
534     private boolean adjustForIO = true;   // true if test uses IO, timings need to be re-calibrated according to this agent disk performance
535     private boolean adjustForCPU = true;  // true if test uses CPU, timings need to be re-calibrated according to this agent CPU speed
536     private boolean useLegacyScaling;
537
538     private TestInfo(@NotNull ThrowableRunnable test, int expectedMs, String message) {
539       this.test = test;
540       this.expectedMs = expectedMs;
541       assert expectedMs > 0 : "Expected must be > 0. Was: "+ expectedMs;
542       this.message = message;
543     }
544
545     @Contract(pure = true) // to warn about not calling .assertTiming() in the end
546     public TestInfo setup(@NotNull ThrowableRunnable setup) { assert this.setup==null; this.setup = setup; return this; }
547     @Contract(pure = true) // to warn about not calling .assertTiming() in the end
548     public TestInfo usesAllCPUCores() { assert adjustForCPU : "This test configured to be io-bound, it cannot use all cores"; usesAllCPUCores = true; return this; }
549     @Contract(pure = true) // to warn about not calling .assertTiming() in the end
550     public TestInfo cpuBound() { adjustForIO = false; adjustForCPU = true; return this; }
551     @Contract(pure = true) // to warn about not calling .assertTiming() in the end
552     public TestInfo ioBound() { adjustForIO = true; adjustForCPU = false; return this; }
553     @Contract(pure = true) // to warn about not calling .assertTiming() in the end
554     public TestInfo attempts(int attempts) { this.attempts = attempts; return this; }
555     /**
556      * @deprecated Enables procedure for nonlinear scaling of results between different machines. This was historically enabled, but doesn't
557      * seem to be meaningful, and is known to make results worse in some cases. Consider migration off this setting, recalibrating
558      * expected execution time accordingly.
559      */
560     @Contract(pure = true) // to warn about not calling .assertTiming() in the end
561     public TestInfo useLegacyScaling() { useLegacyScaling = true; return this; }
562
563     public void assertTiming() {
564       assert expectedMs != 0 : "Must call .expect() before run test";
565       if (COVERAGE_ENABLED_BUILD) return;
566       Timings.getStatistics(); // warm-up, measure
567
568       while (true) {
569         attempts--;
570         long start;
571         try {
572           if (setup != null) setup.run();
573           start = System.currentTimeMillis();
574           test.run();
575         }
576         catch (Throwable throwable) {
577           throw new RuntimeException(throwable);
578         }
579         long finish = System.currentTimeMillis();
580         long duration = finish - start;
581
582         int expectedOnMyMachine = expectedMs;
583         if (adjustForCPU) {
584           expectedOnMyMachine = adjust(expectedOnMyMachine, Timings.CPU_TIMING, Timings.ETALON_CPU_TIMING, useLegacyScaling);
585
586           expectedOnMyMachine = usesAllCPUCores ? expectedOnMyMachine * 8 / JobSchedulerImpl.CORES_COUNT : expectedOnMyMachine;
587         }
588         if (adjustForIO) {
589           expectedOnMyMachine = adjust(expectedOnMyMachine, Timings.IO_TIMING, Timings.ETALON_IO_TIMING, useLegacyScaling);
590         }
591
592         // Allow 10% more in case of test machine is busy.
593         String logMessage = message;
594         if (duration > expectedOnMyMachine) {
595           int percentage = (int)(100.0 * (duration - expectedOnMyMachine) / expectedOnMyMachine);
596           logMessage += ": " + percentage + "% longer";
597         }
598         logMessage +=
599           "\n  Expected: " + formatTime(expectedOnMyMachine) + "\n  Actual: " + formatTime(duration) + "\n " + Timings.getStatistics();
600         final double acceptableChangeFactor = 1.1;
601         if (duration < expectedOnMyMachine) {
602           int percentage = (int)(100.0 * (expectedOnMyMachine - duration) / expectedOnMyMachine);
603           logMessage = percentage + "% faster. " + logMessage;
604
605           TeamCityLogger.info(logMessage);
606           System.out.println("SUCCESS: " + logMessage);
607         }
608         else if (duration < expectedOnMyMachine * acceptableChangeFactor) {
609           TeamCityLogger.warning(logMessage, null);
610           System.out.println("WARNING: " + logMessage);
611         }
612         else {
613           // try one more time
614           if (attempts == 0) {
615             //try {
616             //  Object result = Class.forName("com.intellij.util.ProfilingUtil").getMethod("captureCPUSnapshot").invoke(null);
617             //  System.err.println("CPU snapshot captured in '"+result+"'");
618             //}
619             //catch (Exception e) {
620             //}
621
622             throw new AssertionFailedError(logMessage);
623           }
624           System.gc();
625           System.gc();
626           System.gc();
627           String s = "Another epic fail (remaining attempts: " + attempts + "): " + logMessage;
628           TeamCityLogger.warning(s, null);
629           System.err.println(s);
630           //if (attempts == 1) {
631           //  try {
632           //    Class.forName("com.intellij.util.ProfilingUtil").getMethod("startCPUProfiling").invoke(null);
633           //  }
634           //  catch (Exception e) {
635           //  }
636           //}
637           continue;
638         }
639         break;
640       }
641     }
642
643     private static String formatTime(long millis) {
644       String hint = "";
645       DecimalFormat format = new DecimalFormat("#.0", DecimalFormatSymbols.getInstance(Locale.US));
646       if (millis >= 60 * 1000) hint = format.format(millis / 60 / 1000.f) + "m";
647       if (millis >= 1000) hint += (hint.isEmpty() ? "" : " ") + format.format(millis / 1000.f) + "s";
648       String result = millis + "ms";
649       if (!hint.isEmpty()) {
650         result = result + " (" + hint + ")";
651       }
652       return result;
653     }
654
655     private static int adjust(int expectedOnMyMachine, long thisTiming, long etalonTiming, boolean useLegacyScaling) {
656       if (useLegacyScaling) {
657         double speed = 1.0 * thisTiming / etalonTiming;
658         double delta = speed < 1
659                        ? 0.9 + Math.pow(speed - 0.7, 2)
660                        : 0.45 + Math.pow(speed - 0.25, 2);
661         expectedOnMyMachine *= delta;
662         return expectedOnMyMachine;
663       }
664       else {
665         return (int)(expectedOnMyMachine * thisTiming / etalonTiming);
666       }
667     }
668   }
669
670
671   public static void assertTiming(String message, long expected, @NotNull Runnable actionToMeasure) {
672     assertTiming(message, expected, 4, actionToMeasure);
673   }
674
675   public static long measure(@NotNull Runnable actionToMeasure) {
676     long start = System.currentTimeMillis();
677     actionToMeasure.run();
678     long finish = System.currentTimeMillis();
679     return finish - start;
680   }
681
682   public static void assertTiming(String message, long expected, int attempts, @NotNull Runnable actionToMeasure) {
683     while (true) {
684       attempts--;
685       long duration = measure(actionToMeasure);
686       try {
687         assertTiming(message, expected, duration);
688         break;
689       }
690       catch (AssertionFailedError e) {
691         if (attempts == 0) throw e;
692         System.gc();
693         System.gc();
694         System.gc();
695         String s = "Another epic fail (remaining attempts: " + attempts + "): " + e.getMessage();
696         TeamCityLogger.warning(s, null);
697         System.err.println(s);
698       }
699     }
700   }
701
702   private static HashMap<String, VirtualFile> buildNameToFileMap(VirtualFile[] files, @Nullable VirtualFileFilter filter) {
703     HashMap<String, VirtualFile> map = new HashMap<String, VirtualFile>();
704     for (VirtualFile file : files) {
705       if (filter != null && !filter.accept(file)) continue;
706       map.put(file.getName(), file);
707     }
708     return map;
709   }
710
711   public static void assertDirectoriesEqual(VirtualFile dirAfter, VirtualFile dirBefore) throws IOException {
712     assertDirectoriesEqual(dirAfter, dirBefore, null);
713   }
714
715   @SuppressWarnings("UnsafeVfsRecursion")
716   public static void assertDirectoriesEqual(VirtualFile dirAfter, VirtualFile dirBefore, @Nullable VirtualFileFilter fileFilter) throws IOException {
717     FileDocumentManager.getInstance().saveAllDocuments();
718
719     VirtualFile[] childrenAfter = dirAfter.getChildren();
720
721     if (dirAfter.isInLocalFileSystem() && dirAfter.getFileSystem() != TempFileSystem.getInstance()) {
722       File[] ioAfter = new File(dirAfter.getPath()).listFiles();
723       shallowCompare(childrenAfter, ioAfter);
724     }
725
726     VirtualFile[] childrenBefore = dirBefore.getChildren();
727     if (dirBefore.isInLocalFileSystem() && dirBefore.getFileSystem() != TempFileSystem.getInstance()) {
728       File[] ioBefore = new File(dirBefore.getPath()).listFiles();
729       shallowCompare(childrenBefore, ioBefore);
730     }
731
732     HashMap<String, VirtualFile> mapAfter = buildNameToFileMap(childrenAfter, fileFilter);
733     HashMap<String, VirtualFile> mapBefore = buildNameToFileMap(childrenBefore, fileFilter);
734
735     Set<String> keySetAfter = mapAfter.keySet();
736     Set<String> keySetBefore = mapBefore.keySet();
737     Assert.assertEquals(dirAfter.getPath(), keySetAfter, keySetBefore);
738
739     for (String name : keySetAfter) {
740       VirtualFile fileAfter = mapAfter.get(name);
741       VirtualFile fileBefore = mapBefore.get(name);
742       if (fileAfter.isDirectory()) {
743         assertDirectoriesEqual(fileAfter, fileBefore, fileFilter);
744       }
745       else {
746         assertFilesEqual(fileAfter, fileBefore);
747       }
748     }
749   }
750
751   private static void shallowCompare(VirtualFile[] vfs, @Nullable File[] io) {
752     List<String> vfsPaths = new ArrayList<String>();
753     for (VirtualFile file : vfs) {
754       vfsPaths.add(file.getPath());
755     }
756
757     List<String> ioPaths = new ArrayList<String>();
758     if (io != null) {
759       for (File file : io) {
760         ioPaths.add(file.getPath().replace(File.separatorChar, '/'));
761       }
762     }
763
764     Assert.assertEquals(sortAndJoin(vfsPaths), sortAndJoin(ioPaths));
765   }
766
767   private static String sortAndJoin(List<String> strings) {
768     Collections.sort(strings);
769     StringBuilder buf = new StringBuilder();
770     for (String string : strings) {
771       buf.append(string);
772       buf.append('\n');
773     }
774     return buf.toString();
775   }
776
777   public static void assertFilesEqual(VirtualFile fileAfter, VirtualFile fileBefore) throws IOException {
778     try {
779       assertJarFilesEqual(VfsUtilCore.virtualToIoFile(fileAfter), VfsUtilCore.virtualToIoFile(fileBefore));
780     }
781     catch (IOException e) {
782       FileDocumentManager manager = FileDocumentManager.getInstance();
783
784       Document docBefore = manager.getDocument(fileBefore);
785       boolean canLoadBeforeText = !fileBefore.getFileType().isBinary() || fileBefore.getFileType() == FileTypes.UNKNOWN;
786       String textB = docBefore != null
787                      ? docBefore.getText()
788                      : !canLoadBeforeText
789                        ? null
790                        : LoadTextUtil.getTextByBinaryPresentation(fileBefore.contentsToByteArray(false), fileBefore).toString();
791
792       Document docAfter = manager.getDocument(fileAfter);
793       boolean canLoadAfterText = !fileBefore.getFileType().isBinary() || fileBefore.getFileType() == FileTypes.UNKNOWN;
794       String textA = docAfter != null
795                      ? docAfter.getText()
796                      : !canLoadAfterText
797                        ? null
798                        : LoadTextUtil.getTextByBinaryPresentation(fileAfter.contentsToByteArray(false), fileAfter).toString();
799
800       if (textA != null && textB != null) {
801         Assert.assertEquals(fileAfter.getPath(), textA, textB);
802       }
803       else {
804         Assert.assertArrayEquals(fileAfter.getPath(), fileAfter.contentsToByteArray(), fileBefore.contentsToByteArray());
805       }
806     }
807   }
808
809   public static void assertJarFilesEqual(File file1, File file2) throws IOException {
810     final File tempDirectory1;
811     final File tempDirectory2;
812
813     final JarFile jarFile1 = new JarFile(file1);
814     try {
815       final JarFile jarFile2 = new JarFile(file2);
816       try {
817         tempDirectory1 = PlatformTestCase.createTempDir("tmp1");
818         tempDirectory2 = PlatformTestCase.createTempDir("tmp2");
819         ZipUtil.extract(jarFile1, tempDirectory1, null);
820         ZipUtil.extract(jarFile2, tempDirectory2, null);
821       }
822       finally {
823         jarFile2.close();
824       }
825     }
826     finally {
827       jarFile1.close();
828     }
829
830     final VirtualFile dirAfter = LocalFileSystem.getInstance().refreshAndFindFileByIoFile(tempDirectory1);
831     Assert.assertNotNull(tempDirectory1.toString(), dirAfter);
832     final VirtualFile dirBefore = LocalFileSystem.getInstance().refreshAndFindFileByIoFile(tempDirectory2);
833     Assert.assertNotNull(tempDirectory2.toString(), dirBefore);
834     ApplicationManager.getApplication().runWriteAction(() -> {
835       dirAfter.refresh(false, true);
836       dirBefore.refresh(false, true);
837     });
838     assertDirectoriesEqual(dirAfter, dirBefore);
839   }
840
841   public static void assertElementsEqual(final Element expected, final Element actual) throws IOException {
842     if (!JDOMUtil.areElementsEqual(expected, actual)) {
843       Assert.assertEquals(printElement(expected), printElement(actual));
844     }
845   }
846
847   public static void assertElementEquals(final String expected, final Element actual) {
848     try {
849       assertElementsEqual(JDOMUtil.loadDocument(expected).getRootElement(), actual);
850     }
851     catch (IOException | JDOMException e) {
852       throw new AssertionError(e);
853     }
854   }
855
856   public static String printElement(final Element element) throws IOException {
857     final StringWriter writer = new StringWriter();
858     JDOMUtil.writeElement(element, writer, "\n");
859     return writer.getBuffer().toString();
860   }
861
862   public static String getCommunityPath() {
863     final String homePath = PathManager.getHomePath();
864     if (new File(homePath, "community/.idea").isDirectory()) {
865       return homePath + File.separatorChar + "community";
866     }
867     return homePath;
868   }
869
870   public static String getPlatformTestDataPath() {
871     return getCommunityPath().replace(File.separatorChar, '/') + "/platform/platform-tests/testData/";
872   }
873
874
875   public static Comparator<AbstractTreeNode> createComparator(final Queryable.PrintInfo printInfo) {
876     return (o1, o2) -> {
877       String displayText1 = o1.toTestString(printInfo);
878       String displayText2 = o2.toTestString(printInfo);
879       return Comparing.compare(displayText1, displayText2);
880     };
881   }
882
883   @NotNull
884   public static <T> T notNull(@Nullable T t) {
885     Assert.assertNotNull(t);
886     return t;
887   }
888
889   @NotNull
890   public static String loadFileText(@NotNull String fileName) throws IOException {
891     return StringUtil.convertLineSeparators(FileUtil.loadFile(new File(fileName)));
892   }
893
894   public static void tryGcSoftlyReachableObjects() {
895     GCUtil.tryGcSoftlyReachableObjects();
896   }
897
898   public static void withEncoding(@NotNull String encoding, @NotNull ThrowableRunnable r) {
899     try {
900       Charset oldCharset = Charset.defaultCharset();
901       try {
902         patchSystemFileEncoding(encoding);
903         r.run();
904       }
905       finally {
906         patchSystemFileEncoding(oldCharset.name());
907       }
908     }
909     catch (Throwable t) {
910       throw new RuntimeException(t);
911     }
912   }
913
914   private static void patchSystemFileEncoding(String encoding) {
915     ReflectionUtil.resetField(Charset.class, Charset.class, "defaultCharset");
916     System.setProperty("file.encoding", encoding);
917   }
918
919   public static void withStdErrSuppressed(@NotNull Runnable r) {
920     PrintStream std = System.err;
921     System.setErr(new PrintStream(NULL));
922     try {
923       r.run();
924     }
925     finally {
926       System.setErr(std);
927     }
928   }
929
930   @SuppressWarnings("IOResourceOpenedButNotSafelyClosed")
931   private static final OutputStream NULL = new OutputStream() {
932     @Override
933     public void write(int b) throws IOException { }
934   };
935
936   public static void assertSuccessful(@NotNull GeneralCommandLine command) {
937     try {
938       ProcessOutput output = ExecUtil.execAndGetOutput(command.withRedirectErrorStream(true));
939       Assert.assertEquals(output.getStdout(), 0, output.getExitCode());
940     }
941     catch (ExecutionException e) {
942       throw new RuntimeException(e);
943     }
944   }
945
946   @NotNull
947   public static List<WebReference> collectWebReferences(@NotNull PsiElement element) {
948     List<WebReference> refs = new ArrayList<>();
949     element.accept(new PsiRecursiveElementWalkingVisitor() {
950       @Override
951       public void visitElement(PsiElement element) {
952         for (PsiReference ref : element.getReferences()) {
953           if (ref instanceof WebReference) {
954             refs.add((WebReference)ref);
955           }
956         }
957         super.visitElement(element);
958       }
959     });
960     return refs;
961   }
962   
963   public static void registerProjectCleanup(@NotNull Runnable cleanup) {
964     ourProjectCleanups.add(cleanup);
965   }
966   
967   public static void cleanupAllProjects() {
968     for (Runnable each : ourProjectCleanups) {
969       each.run();
970     }
971     ourProjectCleanups.clear();
972   }
973   
974 }