Skip to content

Commit 03acf56

Browse files
FrottyFrotty
authored
Runmap & performance improvements (#1148)
* better runmap file in use handling * better model robustness * less log spam * one cached map for each input map
1 parent e3eaa6c commit 03acf56

36 files changed

Lines changed: 1000 additions & 335 deletions

‎de.peeeq.wurstscript/build.gradle‎

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -106,7 +106,7 @@ dependencies {
106106
implementation 'commons-lang:commons-lang:2.6'
107107
implementation 'com.github.albfernandez:juniversalchardet:2.4.0'
108108
implementation 'com.github.inwc3:jmpq3:29b55f2c32'
109-
implementation 'com.github.inwc3:wc3libs:bab65b961b'
109+
implementation 'com.github.inwc3:wc3libs:cc49c8e63c'
110110
implementation('com.github.wurstscript:wurstsetup:393cf5ea39') {
111111
exclude group: 'org.eclipse.jgit', module: 'org.eclipse.jgit'
112112
exclude group: 'org.eclipse.jgit', module: 'org.eclipse.jgit.ssh.apache'

‎de.peeeq.wurstscript/src/main/java/de/peeeq/wurstio/CompiletimeFunctionRunner.java‎

Lines changed: 59 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -51,6 +51,8 @@ public class CompiletimeFunctionRunner {
5151
private final ImTranslator translator;
5252
private boolean injectObjects;
5353
private final Deque<Runnable> delayedActions = new ArrayDeque<>();
54+
private final Map<String, Long> compiletimeFunctionNanos = new LinkedHashMap<>();
55+
private long compiletimeExprNanos = 0L;
5456

5557
public ILInterpreter getInterpreter() {
5658
return interpreter;
@@ -97,21 +99,29 @@ public CompiletimeFunctionRunner(
9799

98100
public void run() {
99101
try {
102+
long t0 = System.nanoTime();
100103
List<Either<ImCompiletimeExpr, ImFunction>> toExecute = new ArrayList<>();
101104
collectCompiletimeExpressions(toExecute);
102105
collectCompiletimeFunctions(toExecute);
106+
long tCollected = System.nanoTime();
103107

104108
toExecute.sort(Comparator.comparing(this::getOrderIndex));
109+
long tSorted = System.nanoTime();
105110

106111
execute(toExecute);
112+
long tExecuted = System.nanoTime();
107113

108114

109115
if (functionFlag == FunctionFlagToRun.CompiletimeFunctions) {
110116
interpreter.writebackGlobalState(isInjectObjects());
111117
}
118+
long tWriteback = System.nanoTime();
112119
runDelayedActions();
120+
long tDelayed = System.nanoTime();
113121

114122
partitionCompiletimeStateInitFunction();
123+
long tPartitioned = System.nanoTime();
124+
logCompiletimeTiming(toExecute, t0, tCollected, tSorted, tExecuted, tWriteback, tDelayed, tPartitioned);
115125

116126
} catch (InterpreterException e) {
117127
Element origin = e.getTrace();
@@ -136,6 +146,48 @@ public void run() {
136146

137147
}
138148

149+
private void logCompiletimeTiming(List<Either<ImCompiletimeExpr, ImFunction>> toExecute,
150+
long t0, long tCollected, long tSorted, long tExecuted,
151+
long tWriteback, long tDelayed, long tPartitioned) {
152+
int exprCount = 0;
153+
int funcCount = 0;
154+
for (Either<ImCompiletimeExpr, ImFunction> e : toExecute) {
155+
if (e.isLeft()) {
156+
exprCount++;
157+
} else {
158+
funcCount++;
159+
}
160+
}
161+
WLogger.info(String.format(
162+
"Compiletime breakdown: total=%dms collect=%dms sort=%dms execute=%dms writeback=%dms delayed=%dms partition=%dms funcs=%d exprs=%d exprEval=%dms",
163+
ms(tPartitioned - t0),
164+
ms(tCollected - t0),
165+
ms(tSorted - tCollected),
166+
ms(tExecuted - tSorted),
167+
ms(tWriteback - tExecuted),
168+
ms(tDelayed - tWriteback),
169+
ms(tPartitioned - tDelayed),
170+
funcCount,
171+
exprCount,
172+
ms(compiletimeExprNanos)
173+
));
174+
if (!compiletimeFunctionNanos.isEmpty()) {
175+
List<Map.Entry<String, Long>> top = compiletimeFunctionNanos.entrySet().stream()
176+
.sorted((a, b) -> Long.compare(b.getValue(), a.getValue()))
177+
.limit(10)
178+
.collect(Collectors.toList());
179+
StringBuilder sb = new StringBuilder("Top compiletime functions:");
180+
for (Map.Entry<String, Long> e : top) {
181+
sb.append("\n ").append(e.getKey()).append(": ").append(ms(e.getValue())).append("ms");
182+
}
183+
WLogger.info(sb.toString());
184+
}
185+
}
186+
187+
private static long ms(long nanos) {
188+
return nanos / 1_000_000L;
189+
}
190+
139191
private void partitionCompiletimeStateInitFunction() {
140192
if (compiletimeStateInitFunction == null) {
141193
return;
@@ -220,6 +272,7 @@ public void visit(ImCompiletimeExpr e) {
220272

221273

222274
private void executeCompiletimeExpr(ImCompiletimeExpr cte) {
275+
long t0 = System.nanoTime();
223276
try {
224277
ProgramState globalState = interpreter.getGlobalState();
225278
globalState.setLastStatement(cte);
@@ -261,6 +314,8 @@ private void executeCompiletimeExpr(ImCompiletimeExpr cte) {
261314
e.setStacktrace(msg);
262315
e.setTrace(cte.attrTrace());
263316
throw e;
317+
} finally {
318+
compiletimeExprNanos += System.nanoTime() - t0;
264319
}
265320
}
266321

@@ -491,11 +546,12 @@ private ImFunction findNative(String funcName, WPos trace) {
491546

492547
private void executeCompiletimeFunction(ImFunction f) {
493548
if (functionFlag.matches(f)) {
549+
long t0 = System.nanoTime();
494550
try {
495551
if (!f.getBody().isEmpty()) {
496552
interpreter.getGlobalState().setLastStatement(f.getBody().get(0));
497553
}
498-
WLogger.debug("running " + functionFlag + " function " + f.getName());
554+
WLogger.trace(() -> "running " + functionFlag + " function " + f.getName());
499555
interpreter.runVoidFunc(f, null);
500556
successTests.add(f);
501557
} catch (TestSuccessException e) {
@@ -505,6 +561,8 @@ private void executeCompiletimeFunction(ImFunction f) {
505561
} catch (Throwable e) {
506562
failTests.put(f, Pair.create(interpreter.getLastStatement(), e.toString()));
507563
throw e;
564+
} finally {
565+
compiletimeFunctionNanos.merge(f.getName(), System.nanoTime() - t0, Long::sum);
508566
}
509567
}
510568
}

‎de.peeeq.wurstscript/src/main/java/de/peeeq/wurstio/WurstCompilerJassImpl.java‎

Lines changed: 11 additions & 7 deletions
Original file line numberDiff line numberDiff line change
@@ -535,12 +535,14 @@ public JassProg transformProgToJass() {
535535
}
536536

537537
beginPhase(13, "flatten");
538-
optimizer.removeGarbage();
538+
boolean garbageChanged = optimizer.removeGarbage();
539539
imProg.flatten(imTranslator);
540540

541541
// Re-run to avoid #883
542-
optimizer.removeGarbage();
543-
imProg.flatten(imTranslator);
542+
if (garbageChanged) {
543+
optimizer.removeGarbage();
544+
imProg.flatten(imTranslator);
545+
}
544546

545547
printDebugImProg("./test-output/im " + stage++ + "_afterremoveGarbage1.im");
546548
timeTaker.endPhase();
@@ -561,7 +563,7 @@ public JassProg transformProgToJass() {
561563
// translate flattened intermediate lang to jass:
562564

563565
beginPhase(14, "translate to jass");
564-
getImTranslator().calculateCallRelationsAndUsedVariables();
566+
getImTranslator().calculateCallRelationsAndReadVariables();
565567
ImToJassTranslator translator =
566568
new ImToJassTranslator(getImProg(), getImTranslator().getCalledFunctions(), getImTranslator().getMainFunc(), getImTranslator().getConfFunc());
567569
prog = translator.translate();
@@ -952,12 +954,14 @@ public LuaCompilationUnit transformProgToLua() {
952954

953955
printDebugImProg("./test-output/lua/im " + stage++ + "_afterlocalopts.im");
954956

955-
optimizer.removeGarbage();
957+
boolean garbageChanged = optimizer.removeGarbage();
956958
imProg.flatten(imTranslator);
957959

958960
// Re-run to avoid #883
959-
optimizer.removeGarbage();
960-
imProg.flatten(imTranslator);
961+
if (garbageChanged) {
962+
optimizer.removeGarbage();
963+
imProg.flatten(imTranslator);
964+
}
961965

962966
printDebugImProg("./test-output/lua/im " + stage++ + "_afterremoveGarbage1.im");
963967

‎de.peeeq.wurstscript/src/main/java/de/peeeq/wurstio/jassinterpreter/JassInterpreter.java‎

Lines changed: 3 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -60,7 +60,7 @@ public static ILconst getDefaultValue(String type) {
6060

6161
public ILconst executeFunction(String name, ILconst... arguments) {
6262
if (trace) {
63-
WLogger.trace(name + "( " + Utils.join(arguments, ", ") + ")");
63+
WLogger.trace(() -> name + "( " + Utils.join(arguments, ", ") + ")");
6464
}
6565

6666
ExecutableJassFunction func = searchFunction(name);
@@ -99,13 +99,13 @@ ILconst executeJassFunction(JassFunction func, ILconst... arguments) {
9999
this.executeStatements(localVarMap, body);
100100
} catch (ReturnException e) {
101101
if (trace) {
102-
WLogger.trace("end function " + func.getName() + " returns " + e.getVal());
102+
WLogger.trace(() -> "end function " + func.getName() + " returns " + e.getVal());
103103
}
104104
return e.getVal();
105105
}
106106

107107
if (trace) {
108-
WLogger.trace("end function " + func.getName());
108+
WLogger.trace(() -> "end function " + func.getName());
109109
}
110110
return null;
111111
}

‎de.peeeq.wurstscript/src/main/java/de/peeeq/wurstio/jassinterpreter/providers/ForceProvider.java‎

Lines changed: 0 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -44,7 +44,6 @@ public void DestroyForce(IlConstHandle force) {
4444
public void ForForce(IlConstHandle force, ILconstFuncRef funcRef) {
4545
// TODO take force param into account
4646
// For now this simply executes the supplied function.
47-
WLogger.trace("for force call");
4847
interpreter.runFuncRef(funcRef, null);
4948
}
5049
}

‎de.peeeq.wurstscript/src/main/java/de/peeeq/wurstio/jassinterpreter/providers/GroupProvider.java‎

Lines changed: 0 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -52,11 +52,9 @@ public ILconst FirstOfGroup(IlConstHandle group) {
5252
}
5353

5454
public void ForGroup(IlConstHandle group, ILconstFuncRef funcRef) {
55-
WLogger.trace("for group call");
5655
LinkedHashSet<IlConstHandle> groupList = (LinkedHashSet<IlConstHandle>) group.getObj();
5756
groupList.forEach((IlConstHandle u) -> {
5857
enumUnitStack.push(u);
59-
WLogger.trace("for group call itr: " + funcRef.getFuncName());
6058
interpreter.runFuncRef(funcRef, null);
6159
enumUnitStack.pop();
6260
});

‎de.peeeq.wurstscript/src/main/java/de/peeeq/wurstio/languageserver/ConfigProvider.java‎

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -143,7 +143,7 @@ private void refreshCacheAsync() {
143143
}
144144
})
145145
.exceptionally(e -> {
146-
WLogger.trace("Background config refresh failed (this is normal if client is busy): " + e.getMessage());
146+
WLogger.trace(() -> "Background config refresh failed (this is normal if client is busy): " + e.getMessage());
147147
return null;
148148
});
149149
}

‎de.peeeq.wurstscript/src/main/java/de/peeeq/wurstio/languageserver/ModelManagerImpl.java‎

Lines changed: 34 additions & 19 deletions
Original file line numberDiff line numberDiff line change
@@ -87,25 +87,30 @@ private List<CompilationUnit> getJassdocCUs(Path jassdoc, WurstGui gui) {
8787

8888
@Override
8989
public Changes removeCompilationUnit(WFile resource) {
90-
parseErrors.remove(resource);
9190
WurstModel model2 = model;
92-
if (model2 == null) {
93-
return Changes.empty();
94-
}
95-
96-
syncCompilationUnitContent(resource, "");
9791
List<CompilationUnit> toRemove = new ArrayList<>();
98-
for (CompilationUnit compilationUnit : model2) {
99-
if (wFile(compilationUnit).equals(resource)) {
100-
toRemove.add(compilationUnit);
92+
if (model2 != null) {
93+
for (CompilationUnit compilationUnit : model2) {
94+
if (wFile(compilationUnit).equals(resource)) {
95+
toRemove.add(compilationUnit);
96+
}
10197
}
98+
model2.removeAll(toRemove);
10299
}
103-
model2.removeAll(toRemove);
104-
return new Changes(toRemove.stream()
105-
.map(this::wFile),
100+
101+
// Always clear state and diagnostics for removed files.
102+
clearFileState(resource);
103+
reportErrors("remove cu ", resource, Collections.emptyList());
104+
105+
toRemove.forEach(compilationunitFile::remove);
106+
107+
return new Changes(
108+
java.util.Collections.singletonList(resource),
106109
toRemove.stream()
107110
.flatMap(cu -> cu.getPackages().stream())
108-
.map(WPackage::getName));
111+
.map(WPackage::getName)
112+
.collect(Collectors.toList())
113+
);
109114
}
110115

111116
@Override
@@ -165,7 +170,7 @@ private File[] getFiles(File dir) {
165170
}
166171

167172
private void processWurstFile(WFile f) {
168-
WLogger.info("processing file " + f);
173+
WLogger.debug("processing file " + f);
169174
replaceCompilationUnit(f);
170175
}
171176

@@ -366,7 +371,6 @@ private WurstCompilerJassImpl getCompiler(WurstGui gui) {
366371
}
367372

368373
private void updateModel(CompilationUnit cu, WurstGui gui) {
369-
WLogger.trace("update model with " + cu.getCuInfo().getFile());
370374
parseErrors.put(wFile(cu), new ArrayList<>(gui.getErrorsAndWarnings()));
371375

372376
WurstModel model2 = model;
@@ -526,15 +530,20 @@ private CompilationUnit replaceCompilationUnit(WFile filename, String contents,
526530
if (fileHashcodes.containsKey(filename)) {
527531
int oldHash = fileHashcodes.get(filename);
528532
if (oldHash == contents.hashCode()) {
529-
// no change
530-
WLogger.trace("CU " + filename + " was unchanged.");
531-
return getCompilationUnit(filename);
533+
CompilationUnit existing = getCompilationUnit(filename);
534+
if (existing != null) {
535+
// no change
536+
WLogger.trace(() -> "CU " + filename + " was unchanged.");
537+
return existing;
538+
}
539+
// Stale hash cache after remove/move; CU is gone, so reparse.
540+
WLogger.info("CU hash unchanged but model entry missing for " + filename + ", reparsing.");
532541
} else {
533542
WLogger.info("CU changed. oldHash = " + oldHash + " == " + contents.hashCode());
534543
}
535544
}
536545

537-
WLogger.trace("replace CU " + filename);
546+
WLogger.trace(() -> "replace CU " + filename);
538547
WurstGui gui = new WurstGuiLogger();
539548
WurstCompilerJassImpl c = getCompiler(gui);
540549
CompilationUnit cu = c.parse(filename.toString(), new StringReader(contents));
@@ -557,6 +566,12 @@ private CompilationUnit replaceCompilationUnit(WFile filename, String contents,
557566
return cu;
558567
}
559568

569+
private void clearFileState(WFile file) {
570+
parseErrors.remove(file);
571+
otherErrors.remove(file);
572+
fileHashcodes.remove(file);
573+
}
574+
560575
@Override
561576
public CompilationUnit getCompilationUnit(WFile filename) {
562577
List<CompilationUnit> matches = getCompilationUnits(Collections.singletonList(filename));

‎de.peeeq.wurstscript/src/main/java/de/peeeq/wurstio/languageserver/requests/BuildMap.java‎

Lines changed: 19 additions & 8 deletions
Original file line numberDiff line numberDiff line change
@@ -61,17 +61,28 @@ public Object execute(ModelManager modelManager) throws IOException {
6161
// first we copy in same location to ensure validity
6262
File buildDir = getBuildDir();
6363
String fileName = projectConfig.getBuildMapData().getFileName();
64-
Optional<File> targetMap = Optional.of(
65-
new File(buildDir, fileName.isEmpty() ? projectConfig.getProjectName() + ".w3x" : fileName + ".w3x"));
66-
CompilationResult result = compileScript(modelManager, gui, targetMap, projectConfig, buildDir, true);
67-
68-
injectMapData(gui, targetMap, result);
69-
70-
Files.copy(getCachedMapFile().toPath(), targetMap.get().toPath(), java.nio.file.StandardCopyOption.REPLACE_EXISTING);
64+
File targetMapFile = new File(buildDir, fileName.isEmpty() ? projectConfig.getProjectName() + ".w3x" : fileName + ".w3x");
65+
targetMapFile = ensureWritableTargetFile(
66+
targetMapFile,
67+
"Build Map",
68+
"The output map file is in use and cannot be replaced.\nClose Warcraft III and click Retry, choose Rename to use a temporary file name, or Cancel.",
69+
"Build canceled because output map target is in use."
70+
);
71+
CompilationResult result = compileScript(modelManager, gui, Optional.of(targetMapFile), projectConfig, buildDir, true);
72+
73+
injectMapData(gui, Optional.of(targetMapFile), result);
74+
75+
targetMapFile = ensureWritableTargetFile(
76+
targetMapFile,
77+
"Build Map",
78+
"The output map file is still in use and cannot be replaced.\nClick Retry, choose Rename to use a temporary file name, or Cancel.",
79+
"Build canceled because output map target is in use."
80+
);
81+
Files.copy(getCachedMapFile().toPath(), targetMapFile.toPath(), java.nio.file.StandardCopyOption.REPLACE_EXISTING);
7182

7283
gui.sendProgress("Finalizing map");
7384

74-
try (MpqEditor mpq = MpqEditorFactory.getEditor(targetMap)) {
85+
try (MpqEditor mpq = MpqEditorFactory.getEditor(Optional.of(targetMapFile))) {
7586
if (mpq != null) {
7687
mpq.closeWithCompression();
7788
}

0 commit comments

Comments
 (0)