1 package cz.cuni.amis.pogamut.ut2004.tournament.match;
2
3 import java.io.File;
4 import java.io.IOException;
5 import java.text.SimpleDateFormat;
6 import java.util.Collection;
7 import java.util.Date;
8 import java.util.HashMap;
9 import java.util.Map;
10 import java.util.Map.Entry;
11 import java.util.concurrent.Callable;
12 import java.util.concurrent.CountDownLatch;
13 import java.util.concurrent.TimeUnit;
14 import java.util.logging.Level;
15 import java.util.logging.Logger;
16
17 import org.apache.commons.io.FileUtils;
18
19 import cz.cuni.amis.pogamut.base.agent.impl.AgentId;
20 import cz.cuni.amis.pogamut.base.agent.state.level1.IAgentStateUp;
21 import cz.cuni.amis.pogamut.base.communication.worldview.event.IWorldEventListener;
22 import cz.cuni.amis.pogamut.base.communication.worldview.object.IWorldObjectEvent;
23 import cz.cuni.amis.pogamut.base.communication.worldview.object.IWorldObjectListener;
24 import cz.cuni.amis.pogamut.base.component.bus.event.BusAwareCountDownLatch;
25 import cz.cuni.amis.pogamut.base.utils.guice.AdaptableProvider;
26 import cz.cuni.amis.pogamut.base.utils.logging.LogCategory;
27 import cz.cuni.amis.pogamut.base.utils.logging.LogFormatter;
28 import cz.cuni.amis.pogamut.base.utils.logging.LogHandler;
29 import cz.cuni.amis.pogamut.base.utils.logging.LogPublisher;
30 import cz.cuni.amis.pogamut.base3d.worldview.object.Location;
31 import cz.cuni.amis.pogamut.unreal.communication.messages.UnrealId;
32 import cz.cuni.amis.pogamut.ut2004.agent.params.UT2004AgentParameters;
33 import cz.cuni.amis.pogamut.ut2004.analyzer.IAnalyzerObserverListener;
34 import cz.cuni.amis.pogamut.ut2004.analyzer.IUT2004AnalyzerObserver;
35 import cz.cuni.amis.pogamut.ut2004.analyzer.UT2004Analyzer;
36 import cz.cuni.amis.pogamut.ut2004.analyzer.UT2004AnalyzerModule;
37 import cz.cuni.amis.pogamut.ut2004.analyzer.UT2004AnalyzerParameters;
38 import cz.cuni.amis.pogamut.ut2004.analyzer.stats.UT2004AnalyzerObsStatsModule;
39 import cz.cuni.amis.pogamut.ut2004.communication.messages.gbcommands.AddBot;
40 import cz.cuni.amis.pogamut.ut2004.communication.messages.gbcommands.ChangeTeam;
41 import cz.cuni.amis.pogamut.ut2004.communication.messages.gbcommands.GameConfiguration;
42 import cz.cuni.amis.pogamut.ut2004.communication.messages.gbcommands.Kick;
43 import cz.cuni.amis.pogamut.ut2004.communication.messages.gbcommands.Record;
44 import cz.cuni.amis.pogamut.ut2004.communication.messages.gbcommands.Respawn;
45 import cz.cuni.amis.pogamut.ut2004.communication.messages.gbcommands.StartPlayers;
46 import cz.cuni.amis.pogamut.ut2004.communication.messages.gbinfomessages.GameRestarted;
47 import cz.cuni.amis.pogamut.ut2004.communication.messages.gbinfomessages.Player;
48 import cz.cuni.amis.pogamut.ut2004.factory.guice.remoteagent.UT2004AnalyzerFactory;
49 import cz.cuni.amis.pogamut.ut2004.factory.guice.remoteagent.UT2004ServerFactory;
50 import cz.cuni.amis.pogamut.ut2004.factory.guice.remoteagent.UT2004ServerModule;
51 import cz.cuni.amis.pogamut.ut2004.server.impl.UT2004Server;
52 import cz.cuni.amis.pogamut.ut2004.tournament.botexecution.UT2004BotExecution;
53 import cz.cuni.amis.pogamut.ut2004.tournament.deathmatch.UT2004DeathMatch;
54 import cz.cuni.amis.pogamut.ut2004.utils.UCCWrapper;
55 import cz.cuni.amis.utils.ExceptionToString;
56 import cz.cuni.amis.utils.FilePath;
57 import cz.cuni.amis.utils.NullCheck;
58 import cz.cuni.amis.utils.collections.CollectionEventListener;
59 import cz.cuni.amis.utils.exception.PogamutException;
60 import cz.cuni.amis.utils.exception.PogamutInterruptedException;
61 import cz.cuni.amis.utils.flag.FlagListener;
62 import cz.cuni.amis.utils.token.IToken;
63
64
65
66
67
68
69
70
71
72
73
74 public abstract class UT2004Match<CONFIG extends UT2004MatchConfig, RESULT extends UT2004MatchResult> implements Callable<RESULT>, Runnable {
75
76 private static final int MAX_TEAMS = 8;
77
78
79
80 protected CONFIG config;
81 protected LogCategory log;
82 protected RESULT result;
83 protected Throwable exception;
84 protected boolean teamMatch;
85
86 protected LogHandler fileHandler;
87
88
89
90
91 protected File gb2004FileBackup;
92
93
94
95
96
97 public UT2004Match(boolean teamMatch, CONFIG config, LogCategory log) {
98 NullCheck.check(config, "config");
99 this.config = config;
100 NullCheck.check(config.getMatchId(), "config.getMatchId()");
101 this.log = log;
102 teamMatch = false;
103 }
104
105
106
107
108
109
110
111 public boolean isTeamMatch() {
112 return teamMatch;
113 }
114
115
116
117
118
119
120
121
122
123
124 public RESULT getResult() {
125 return result;
126 }
127
128
129
130
131
132 public Throwable getException() {
133 return exception;
134 }
135
136
137
138
139 public void run() {
140 try {
141 if (log != null && log.isLoggable(Level.WARNING)) log.warning("Executing match: " + getMatchId().getToken());
142
143 result = null;
144 exception = null;
145
146 this.result = execute();
147
148 if (log != null && log.isLoggable(Level.WARNING)) log.warning("---/// MATCH OK ///---");
149 } catch (Exception e) {
150 if (log != null && log.isLoggable(Level.SEVERE)) log.severe(ExceptionToString.process("Failed to execute the match: " + getMatchId().getToken() + ".", e));
151 this.exception = e;
152 if (e instanceof RuntimeException) throw (RuntimeException)e;
153 throw new PogamutException("Failed to execute the match: " + getMatchId().getToken(), e, this);
154 }
155 }
156
157 public RESULT call() {
158 run();
159 return getResult();
160 }
161
162
163
164
165
166
167
168 protected abstract RESULT execute();
169
170
171
172
173
174
175
176
177
178
179
180 public static String getCurrentDate() {
181 Date date = new Date(System.currentTimeMillis());
182 SimpleDateFormat dateFormat = new SimpleDateFormat("yyyy-MM-dd_HH-mm-ss");
183 return dateFormat.format(date);
184 }
185
186
187
188
189
190 public CONFIG getConfig() {
191 return config;
192 }
193
194
195
196
197
198 public IToken getMatchId() {
199 return config.getMatchId();
200 }
201
202
203
204
205
206 public LogCategory getLog() {
207 return log;
208 }
209
210 @Override
211 public String toString() {
212 if (this == null) return "UT2004Match";
213 return getClass().getSimpleName() + "[id=" + config.getMatchId().getToken() + ", custom bots=" + config.getBots().size() + ", native bots =" + config.getNativeBots().size() + "]";
214 }
215
216
217
218
219
220 public File getOutputPath() {
221 return getOutputPath("");
222 }
223
224
225
226
227
228
229 public File getOutputPath(String relativePath) {
230 if (relativePath == null || relativePath.length() == 0) {
231 return new File(config.getOutputDirectory().getAbsoluteFile() + File.separator + config.getMatchId().getToken());
232 } else {
233 return new File(config.getOutputDirectory().getAbsoluteFile() + File.separator + config.getMatchId().getToken() + File.separator + relativePath);
234 }
235 }
236
237
238
239
240
241 protected void setupLogger() {
242 if (log != null && log.isLoggable(Level.FINE)) {
243 log.fine(config.getMatchId().getToken() + ": Adding output of logs into " + getOutputPath("match-" + config.getMatchId().getToken() + ".log"));
244 }
245 if (log != null) {
246 log.addHandler(fileHandler = new LogHandler(new LogPublisher.FilePublisher(getOutputPath("match-" + config.getMatchId().getToken() + ".log"), new LogFormatter(new AgentId(config.getMatchId().getToken()), true))));
247 }
248 if (log != null && log.isLoggable(Level.INFO)) {
249 log.info(this + " file output setup");
250 }
251 }
252
253
254
255
256
257
258
259
260 public void validate() {
261 try {
262 if (log != null && log.isLoggable(Level.FINE)) {
263 log.fine(config.getMatchId().getToken() + ": Validating match configuration...");
264 }
265 config.validate();
266 if (log != null && log.isLoggable(Level.INFO)) {
267 log.info(config.getMatchId().getToken() + ": Match configuration validated - OK.");
268 }
269 } catch (PogamutException e) {
270 if (log != null) log.severe(e.getMessage());
271 throw e;
272 } catch (Exception e) {
273 if (log != null) log.severe(e.getMessage());
274 throw new PogamutException("Validation failed.", e, log, this);
275 }
276 }
277
278
279
280
281
282 public void cleanUp() {
283 if (log != null && log.isLoggable(Level.WARNING)) log.warning("Cleaning up! Deleting: " + getOutputPath().getAbsolutePath());
284 FileUtils.deleteQuietly(getOutputPath());
285 }
286
287
288
289
290
291 protected File getUccHome() {
292 return new File(config.getUccConf().getUnrealHome() + File.separator + "System");
293 }
294
295
296
297
298
299 protected File getGB2004IniFile() {
300 return new File(config.getUccConf().getUnrealHome() + File.separator + "System" + File.separator + "GameBots2004.ini");
301 }
302
303
304
305
306
307
308 protected void createGB2004Ini() {
309 if (log != null && log.isLoggable(Level.FINE)) {
310 log.fine(config.getMatchId().getToken() + ": Outputting GameBots2004.ini into " + getGB2004IniFile().getAbsolutePath() + " ...");
311 }
312 File gb2004File = getGB2004IniFile();
313 Date date = new Date(System.currentTimeMillis());
314 SimpleDateFormat sdf = new SimpleDateFormat("yyyy-MM-dd_HH-mm-ss");
315 gb2004FileBackup = new File(gb2004File.getParent() + File.separator + "GameBots2004.ini." + sdf.format(date) + ".backup");
316 if (gb2004File.isFile() && gb2004File.exists()) {
317 if (log != null && log.isLoggable(Level.FINE)) {
318 log.fine(config.getMatchId().getToken() + ": Backing up GameBots2004.ini from " + gb2004File.getAbsolutePath() + " into + " + gb2004FileBackup.getAbsolutePath() + " ...");
319 }
320 boolean backup = true;
321 try {
322 FileUtils.copyFile(gb2004File, gb2004FileBackup);
323 } catch (IOException e) {
324 backup = false;
325 }
326 if (backup && log != null && log.isLoggable(Level.FINE)) {
327 log.fine(config.getMatchId().getToken() + ": Backed up GameBots2004.ini from " + gb2004File.getAbsolutePath() + " into + " + gb2004FileBackup.getAbsolutePath() + " ...");
328 } else
329 if (!backup && log != null && log.isLoggable(Level.SEVERE)){
330 log.severe(config.getMatchId().getToken() + ": Failed to back up GameBots2004.ini from " + gb2004File.getAbsolutePath() + " into + " + gb2004FileBackup.getAbsolutePath() + " !!!");
331
332 }
333 }
334 config.getGb2004Ini().output(gb2004File);
335 if (log != null && log.isLoggable(Level.INFO)) {
336 log.info(config.getMatchId().getToken() + ": GameBots2004.ini output into " + getGB2004IniFile().getAbsolutePath() + ".");
337 }
338 }
339
340
341
342
343
344
345
346
347 protected UCCWrapper startUCC() {
348 if (log != null && log.isLoggable(Level.FINE)) {
349 log.fine(config.getMatchId().getToken() + ": Starting UCC with " + config.getUccConf() + " ...");
350 }
351 UCCWrapper result = new UCCWrapper(config.getUccConf());
352 if (log != null && log.isLoggable(Level.INFO)) {
353 log.info(config.getMatchId().getToken() + ": UCC started with " + config.getUccConf() + ".");
354 log.info(config.getMatchId().getToken() + ": GB2004 host = " + result.getHost());
355 log.info(config.getMatchId().getToken() + ": GB2004 bot port = " + result.getBotPort());
356 log.info(config.getMatchId().getToken() + ": GB2004 control server port = " + result.getControlPort());
357 log.info(config.getMatchId().getToken() + ": GB2004 observer port = " + result.getObserverPort());
358 }
359 return result;
360 }
361
362
363
364
365
366
367
368
369
370
371
372
373
374 protected UT2004Server startControlServer(UCCWrapper ucc) {
375 if (log != null && log.isLoggable(Level.FINE)) {
376 log.fine(config.getMatchId().getToken() + ": Starting UT2004Server...");
377 }
378 NullCheck.check(ucc, "ucc");
379 UT2004ServerModule module = new UT2004ServerModule<UT2004AgentParameters>();
380 UT2004ServerFactory<UT2004Server, UT2004AgentParameters> factory = new UT2004ServerFactory(module);
381 UT2004Server server = (UT2004Server) factory.newAgent(new UT2004AgentParameters().setAgentId(new AgentId(config.getMatchId().getToken()+"-UT2004Server")).setWorldAddress(ucc.getServerAddress()));
382 server.getLogger().setLevel(Level.WARNING);
383 server.getLogger().addDefaultConsoleHandler();
384 server.start();
385 if (log != null && log.isLoggable(Level.INFO)) {
386 log.info(config.getMatchId().getToken() + ": UT2004Server started.");
387 }
388 return server;
389 }
390
391 public static class Bots {
392
393
394
395
396
397
398
399 public Map<IToken, UnrealId> botId2UnrealId = new HashMap<IToken, UnrealId>();
400
401
402
403
404
405
406
407 public Map<UnrealId, IToken> unrealId2BotId = new HashMap<UnrealId, IToken>();
408
409
410
411
412
413
414
415 public Map<IToken, UnrealId> nativeBotId2UnrealId = new HashMap<IToken, UnrealId>();
416
417
418
419
420
421
422
423 public Map<UnrealId, IToken> nativeUnrealId2BotId = new HashMap<UnrealId, IToken>();
424
425
426
427
428 public Map<IToken, UT2004BotExecution> bots = new HashMap<IToken, UT2004BotExecution>();
429
430
431
432
433 public Map<IToken, IUT2004AnalyzerObserver> botObservers = new HashMap<IToken, IUT2004AnalyzerObserver>();
434
435
436
437
438 public long matchStart = 0;
439
440
441
442
443 public long matchEnd = 0;
444
445 public UnrealId getUnrealId(IToken botId) {
446 UnrealId result = botId2UnrealId.get(botId);
447 if (result != null) return result;
448 return nativeBotId2UnrealId.get(botId);
449 }
450
451 public IToken getBotId(UnrealId unrealId) {
452 IToken result = unrealId2BotId.get(unrealId);
453 if (result != null) return result;
454 return nativeUnrealId2BotId.get(unrealId);
455 }
456
457 public boolean isNativeBot(IToken botId) {
458 return nativeBotId2UnrealId.containsKey(botId);
459 }
460
461 public boolean isNativeBot(UnrealId unrealId) {
462 return nativeUnrealId2BotId.containsKey(unrealId);
463 }
464 }
465
466 protected void changeBotTeam(UT2004Server server, UnrealId botId, int desiredTeam) {
467 NullCheck.check(server, "server");
468 NullCheck.check(botId, "botId");
469 final int targetTeam = desiredTeam;
470 if (targetTeam < 0 || targetTeam >= MAX_TEAMS) return;
471
472 Player player = (Player)server.getWorldView().get(botId);
473 if (player == null) {
474 throw new PogamutException("Bot with unrealId '" + botId + "' does not exists in 'server' worldview! **PUZZLED**", log, this);
475 }
476 if (player.getTeam() == targetTeam) {
477
478 return;
479 }
480
481 if (log != null && log.isLoggable(Level.FINE)) {
482 log.fine(config.getMatchId().getToken() + ": Switching Bot[unrealId=" + botId.getStringId() + "] to team " + desiredTeam + "...");
483 }
484
485 final CountDownLatch teamChangedLatch = new CountDownLatch(1);
486
487 IWorldObjectListener<Player> playerListener = new IWorldObjectListener<Player>() {
488 Location previous;
489 @Override
490 public void notify(IWorldObjectEvent<Player> event) {
491 if (event.getObject().getTeam() == targetTeam) teamChangedLatch.countDown();
492 }
493 };
494 server.getWorldView().addObjectListener(botId, playerListener);
495
496 try {
497 server.getAct().act(new ChangeTeam(botId, targetTeam));
498 try {
499 Thread.sleep(500);
500 } catch (InterruptedException e) {
501 throw new PogamutInterruptedException("Interrupted while awaiting team-change.", log, e);
502 }
503 server.getAct().act(new Respawn().setId(botId));
504
505 long teamChangeTimeoutSecs = 60;
506
507 if (log != null && log.isLoggable(Level.FINE)) {
508 log.fine(config.getMatchId().getToken() + ": Waitng for Bot[unrealId=" + botId.getStringId() + "] to be switched to team " + desiredTeam + " for " + teamChangeTimeoutSecs + "secs...");
509 }
510 try {
511 teamChangedLatch.await(teamChangeTimeoutSecs, TimeUnit.SECONDS);
512 } catch (InterruptedException e) {
513 throw new PogamutInterruptedException("Interrupted while awaiting team-change.", log, e);
514 }
515
516 player = (Player)server.getWorldView().get(botId);
517 if (player == null) {
518 throw new PogamutException("Bot with unrealId '" + botId + "' does not exists in 'server' worldview! **PUZZLED**", log, this);
519 }
520 if (player.getTeam() != targetTeam) {
521 throw new PogamutException("Failed to change the bot with botId '" + botId +"' corresponding unrealId '" + botId + "' into correct team within " + teamChangeTimeoutSecs + "secs! Required team is " + targetTeam + ", current team is " + player.getTeam() + ".", log, this);
522 }
523 if (log != null && log.isLoggable(Level.INFO)) {
524 log.info(config.getMatchId().getToken() + ": Bot[unrealId=" + botId.getStringId() + "] switched to team " + desiredTeam + ".");
525 }
526 } finally {
527 server.getWorldView().removeObjectListener(botId, playerListener);
528 }
529
530 }
531
532
533
534
535
536
537
538
539
540
541
542
543
544
545 protected Bots startBots(UCCWrapper ucc, UT2004Server server) {
546 if (log != null && log.isLoggable(Level.FINE)) {
547 log.fine(config.getMatchId().getToken() + ": Starting custom & native bots...");
548 }
549
550 NullCheck.check(ucc, "ucc");
551 NullCheck.check(server, "server");
552
553 final Bots bots = new Bots();
554
555 server.getAct().act(new StartPlayers());
556
557 try {
558 Thread.sleep(500);
559 } catch (InterruptedException e) {
560 throw new PogamutInterruptedException("Interrupted while awaiting start of players' exporting on the server.", log, e);
561 }
562
563 if (server.getPlayers().size() > 0) {
564 throw new PogamutException("There are already some bots/players/native bots connected to the game, even though we have not started to connect any of them yet. INVALID STATE!", log, this);
565 }
566
567
568
569
570 {
571 final AdaptableProvider<IToken> connecting = new AdaptableProvider<IToken>(null);
572 final AdaptableProvider<CountDownLatch> latch = new AdaptableProvider<CountDownLatch>(null);
573
574 CollectionEventListener<Player> playerListener = new CollectionEventListener<Player>() {
575 @Override
576 public void postAddEvent(Collection<Player> alreadyAdded,Collection<Player> whereWereAdded) {
577 }
578 @Override
579 public void postRemoveEvent(Collection<Player> alreadyAdded,Collection<Player> whereWereRemoved) {
580 if (alreadyAdded.size() == 0) return;
581 }
582 @Override
583 public void preAddEvent(Collection<Player> toBeAdded, Collection<Player> whereToAdd) {
584 if (toBeAdded.size() == 0) return;
585 if (toBeAdded.size() > 1) {
586 throw new PogamutException("(CustomBot connecting) More than one player connected at a single time? We're not doing this, something has failed, or someone has hacked into the game.", log, this);
587 }
588 Player player = toBeAdded.iterator().next();
589 if (log != null && log.isLoggable(Level.FINE)) {
590 log.fine(config.getMatchId().getToken() + ": New bot connected to GB2004. Bot[unrealId=" + player.getId().getStringId() + ", name=" + player.getName() + "], binding its unrealId to botId " + connecting.get().getToken() + ".");
591 }
592
593 bots.botId2UnrealId.put(connecting.get(), player.getId());
594 bots.unrealId2BotId.put(player.getId(), connecting.get());
595
596 latch.get().countDown();
597 }
598 @Override
599 public void preRemoveEvent(Collection<Player> toBeRemoved, Collection<Player> whereToRemove) {
600 if (toBeRemoved.size() == 0) return;
601 if (log != null && log.isLoggable(Level.WARNING)) {
602 StringBuffer sb = new StringBuffer();
603 sb.append(config.getMatchId().getToken() + ": Bot(s) removed from GB2004!!!");
604 boolean first = true;
605 for (Player plr : toBeRemoved) {
606 if (first) first = false;
607 else sb.append(", ");
608 sb.append("Bot[unrealId=" + plr.getId().getStringId() + ", name=" + plr.getName() + "]");
609 }
610 log.warning(sb.toString());
611 }
612 throw new PogamutException("(CustomBot connecting) There can't be any 'removes' at this stage.", log, this);
613 }
614 };
615
616 server.getPlayers().addCollectionListener(playerListener);
617
618 boolean exception = false;
619 try {
620 for (UT2004BotConfig botConfig : config.getBots().values()) {
621 if (log != null && log.isLoggable(Level.FINE)) {
622 log.fine(config.getMatchId().getToken() + ": Starting custom Bot[botId=" + botConfig.getBotId().getToken() + "]...");
623 }
624
625
626 if (server.notInState(IAgentStateUp.class)) {
627 throw new PogamutException("(CustomBot connecting) Server is DEAD! Some previous exception will have the explanation...", log, this);
628 }
629
630
631
632 latch.set(new CountDownLatch(1));
633
634
635 connecting.set(botConfig.getBotId());
636
637
638 UT2004BotExecution execution = new UT2004BotExecution(botConfig, log);
639
640
641 FlagListener<Boolean> botObs = new FlagListener<Boolean>() {
642 @Override
643 public void flagChanged(Boolean changedValue) {
644 if (!changedValue) {
645 latch.get().countDown();
646 }
647 }
648 };
649
650
651 execution.getRunning().addListener(botObs);
652
653 try {
654
655 bots.bots.put(botConfig.getBotId(), execution);
656
657
658 execution.start(ucc.getHost(), ucc.getBotPort());
659
660
661 latch.get().await(2 * 60 * 1000, TimeUnit.MILLISECONDS);
662 } finally {
663
664 execution.getRunning().removeListener(botObs);
665 }
666
667 if (!execution.isRunning()) {
668 throw new PogamutException("(CustomBot connecting) Bot[botId=" + botConfig.getBotId().getToken() + "] startup failed!", log, this);
669 }
670 if (latch.get().getCount() > 0) {
671
672 throw new PogamutException("(CustomBot connecting) Bot[botId=" + botConfig.getBotId().getToken() + "], startup failed! It does not showed up on server for 2 minutes... either failed to start, or " + server + " failed to got its presence from GB2004.", log, this);
673 }
674
675
676 if (log != null && log.isLoggable(Level.INFO)) {
677 log.info(config.getMatchId().getToken() + ": Started custom Bot[botId=" + botConfig.getBotId().getToken() + ", unrealId=" + bots.getUnrealId(botConfig.getBotId()).getStringId() + "].");
678 }
679
680
681 if (botConfig.getTeamNumber() >= 0 && botConfig.getTeamNumber() < MAX_TEAMS) {
682 changeBotTeam(server, bots.getUnrealId(botConfig.getBotId()), botConfig.getTeamNumber());
683 }
684 }
685 if (bots.botId2UnrealId.size() != config.getBots().size()) {
686 throw new PogamutException("(CustomBot connecting) Not all mappings BotId<->UnrealId has been created. **PUZZLING**", log, this);
687 }
688 if (bots.unrealId2BotId.size() != config.getBots().size()) {
689 throw new PogamutException("(CustomBot connecting) Not all mappings UnrealId<->BotId has been created. **PUZZLING**", log, this);
690 }
691 } catch (Exception e) {
692 exception = true;
693 if (e instanceof PogamutException) throw (PogamutException)e;
694 throw new PogamutException("(CustomBot connecting) Can't start all custom bots! Exception happened while starting " + connecting.get().getToken() + ".", e, log, this);
695 } finally {
696 if (exception) {
697
698 for (UT2004BotExecution execution : bots.bots.values()) {
699 execution.stop();
700 }
701 bots.bots.clear();
702 }
703
704 server.getPlayers().removeCollectionListener(playerListener);
705 }
706
707 }
708
709
710
711
712 {
713 final AdaptableProvider<IToken> connecting = new AdaptableProvider<IToken>(null);
714 final AdaptableProvider<CountDownLatch> latch = new AdaptableProvider<CountDownLatch>(null);
715
716 CollectionEventListener<Player> playerListener = new CollectionEventListener<Player>() {
717 @Override
718 public void postAddEvent(Collection<Player> alreadyAdded,Collection<Player> whereWereAdded) {
719 }
720 @Override
721 public void postRemoveEvent(Collection<Player> alreadyAdded,Collection<Player> whereWereRemoved) {
722 if (alreadyAdded.size() == 0) return;
723 }
724 @Override
725 public void preAddEvent(Collection<Player> toBeAdded, Collection<Player> whereToAdd) {
726 if (toBeAdded.size() == 0) return;
727 if (toBeAdded.size() > 1) {
728 throw new PogamutException("(NativeBot connecting) More than one player connected at a single time? We're not doing this, something has failed, or someone has hacked into the game.", log, this);
729 }
730 Player player = toBeAdded.iterator().next();
731 if (log != null && log.isLoggable(Level.FINE)) {
732 log.fine(config.getMatchId().getToken() + ": New bot connected to GB2004. Bot[unrealId=" + player.getId().getStringId() + ", name=" + player.getName() + "], binding its unrealId to botId " + connecting.get().getToken() + "...");
733 }
734
735 bots.nativeBotId2UnrealId.put(connecting.get(), player.getId());
736 bots.nativeUnrealId2BotId.put(player.getId(), connecting.get());
737
738 latch.get().countDown();
739 }
740 @Override
741 public void preRemoveEvent(Collection<Player> toBeRemoved, Collection<Player> whereToRemove) {
742 if (toBeRemoved.size() == 0) return;
743 if (log != null && log.isLoggable(Level.WARNING)) {
744 StringBuffer sb = new StringBuffer();
745 sb.append(config.getMatchId().getToken() + ": Bot(s) removed from GB2004!!!");
746 boolean first = true;
747 for (Player plr : toBeRemoved) {
748 if (first) first = false;
749 else sb.append(", ");
750 sb.append("Bot[unrealId=" + plr.getId().getStringId() + ", name=" + plr.getName() + "]");
751 }
752 log.warning(sb.toString());
753 }
754 throw new PogamutException("(NativeBot connecting) There can't be any 'removes' at this stage.", log, this);
755 }
756 };
757 server.getPlayers().addCollectionListener(playerListener);
758
759 boolean exception = false;
760 try {
761 for (UT2004NativeBotConfig botConfig : config.getNativeBots().values()) {
762 if (log != null && log.isLoggable(Level.FINE)) {
763 log.fine(config.getMatchId().getToken() + ": Starting native Bot[botId=" + botConfig.getBotId().getToken() + "]...");
764 }
765
766
767 if (server.notInState(IAgentStateUp.class)) {
768 throw new PogamutException("(NativeBot connecting) Server is DEAD! Some previous exception will have the explanation...", log, this);
769 }
770
771
772
773 latch.set(new CountDownLatch(1));
774
775
776 connecting.set(botConfig.getBotId());
777
778
779 AddBot addBotCommand = new AddBot().setSkill(botConfig.getSkillLevel());
780 Integer teamNumber = botConfig.getTeamNumber();
781 addBotCommand.setTeam(teamNumber);
782 server.getAct().act(addBotCommand);
783
784
785 latch.get().await(2 * 60 * 1000, TimeUnit.MILLISECONDS);
786 if (latch.get().getCount() > 0) {
787
788 throw new PogamutException("(NativeBot connecting) We're tried to start up native bot " + botConfig.getBotId().getToken() + ", but it does not showed up on server for 2 minutes... either failed to start, or " + server + " failed to got it from GB2004.", log, this);
789 }
790
791
792 if (log != null && log.isLoggable(Level.INFO)) {
793 log.info(config.getMatchId().getToken() + ": Started native Bot[botId=" + botConfig.getBotId().getToken() + ", unrealId=" + bots.getUnrealId(botConfig.getBotId()).getStringId() + "].");
794 }
795
796
797 if (botConfig.getTeamNumber() >= 0 && botConfig.getTeamNumber() < MAX_TEAMS) {
798 changeBotTeam(server, bots.getUnrealId(botConfig.getBotId()), botConfig.getTeamNumber());
799 }
800 }
801 if (bots.nativeBotId2UnrealId.size() != config.getNativeBots().size()) {
802 throw new PogamutException("(NativeBot connecting) Not all mappings BotId<->UnrealId has been created. **PUZZLING**", log, this);
803 }
804 if (bots.nativeUnrealId2BotId.size() != config.getNativeBots().size()) {
805 throw new PogamutException("(NativeBot connecting) Not all mappings UnrealId<->BotId has been created. **PUZZLING**", log, this);
806 }
807 } catch (Exception e) {
808 exception = true;
809 if (e instanceof PogamutException) throw (PogamutException)e;
810 throw new PogamutException("(NativeBot connecting) Can't start all native bots! Exception happened while starting " + connecting.get().getToken() + ".", e, log, this);
811 } finally {
812 if (exception) {
813
814 for (UT2004BotExecution execution : bots.bots.values()) {
815 execution.stop();
816 }
817 for (UnrealId id : bots.nativeUnrealId2BotId.keySet()) {
818 try {
819 server.getAct().act(new Kick(id));
820 } catch (Exception e) {
821 }
822 }
823 }
824
825 server.getPlayers().removeCollectionListener(playerListener);
826 }
827
828 }
829
830
831 if (log != null && log.isLoggable(Level.INFO)) {
832 log.info(config.getMatchId().getToken() + ": All custom & native bots are up and running in correct teams..");
833 }
834
835 return bots;
836 }
837
838
839
840
841
842
843
844
845
846
847
848
849
850
851
852
853
854
855 protected UT2004Analyzer startAnalyzer(UCCWrapper ucc, Bots bots, File outputDirectory, boolean humanLikeObserving) {
856 if (log != null && log.isLoggable(Level.FINE)) {
857 log.fine(config.getMatchId().getToken() + ": Starting UT2004Analyzer" + (humanLikeObserving ? "[humanLikeObserving enabled]" : "") + "...");
858 }
859 NullCheck.check(ucc, "ucc");
860 NullCheck.check(bots, "bots");
861 NullCheck.check(outputDirectory, "outputDirectory");
862
863 UT2004AnalyzerModule module = new UT2004AnalyzerModule();
864 UT2004AnalyzerFactory factory = new UT2004AnalyzerFactory<UT2004Analyzer, UT2004AgentParameters>(module);
865
866 Map<UnrealId, String> fileNames = new HashMap<UnrealId, String>();
867 for (Entry<UnrealId, IToken> entry : bots.unrealId2BotId.entrySet()) {
868 fileNames.put(entry.getKey(), entry.getValue().getToken());
869 }
870
871 UT2004Analyzer analyzer = (UT2004Analyzer)factory.newAgent(
872 new UT2004AnalyzerParameters()
873 .setAgentId(new AgentId(config.getMatchId().getToken()+"-UT2004Analyzer"))
874 .setWorldAddress(ucc.getServerAddress())
875 .setObserverModule(new UT2004AnalyzerObsStatsModule())
876 .setObserverAddress(ucc.getObserverAddress())
877 .setWaitForMatchRestart(true)
878 .setOutputPath(getOutputPath("bots").getAbsolutePath())
879 .setFileNames(fileNames)
880 .setHumanLikeObserving(humanLikeObserving)
881 );
882 analyzer.getLogger().setLevel(Level.WARNING);
883 analyzer.getLogger().addDefaultConsoleHandler();
884
885 final CountDownLatch observersLatch = new CountDownLatch(bots.unrealId2BotId.size());
886 final Bots myBots = bots;
887
888 IAnalyzerObserverListener observerListener = new IAnalyzerObserverListener() {
889
890 @Override
891 public void observerAdded(UnrealId botId, IUT2004AnalyzerObserver observer) {
892 if (!myBots.unrealId2BotId.containsKey(botId)) {
893 throw new PogamutException("Observer has been created for the bot with unknown id " + botId.getStringId() + ", this bot should not be part of the tournament.", log, this);
894 }
895 myBots.botObservers.put(myBots.unrealId2BotId.get(botId), observer);
896 observersLatch.countDown();
897 }
898
899 @Override
900 public void observerRemoved(UnrealId botId, IUT2004AnalyzerObserver observer) {
901 throw new PogamutException("Observer can't be removed at this stage (analyzer initialization), this indicates ERROR in the match!", log, this);
902 }
903
904 };
905
906 analyzer.addListener(observerListener);
907 analyzer.start();
908
909 try {
910 observersLatch.await(5 * 60 * 1000, TimeUnit.MILLISECONDS);
911 } catch (InterruptedException e) {
912 analyzer.removeListener(observerListener);
913 analyzer.kill();
914 throw new PogamutInterruptedException("Interrupted while awaiting for observers to be setup for bots.", log, this);
915 }
916
917 analyzer.removeListener(observerListener);
918
919 if (observersLatch.getCount() > 0) {
920 analyzer.kill();
921 throw new PogamutException("Timeout (5min) - not all observers has been attached within 5 minutes.", log, this);
922 }
923
924 if (analyzer.notInState(IAgentStateUp.class)) {
925 analyzer.kill();
926 throw new PogamutException("After all observers have been started, analyzer was found DEAD... :-(", log, this);
927 }
928
929 if (bots.botObservers.size() != config.getBots().size()) {
930 analyzer.kill();
931 throw new PogamutException("Not all observers have been attached to running custom bots :-(", log, this);
932 }
933
934 if (log != null && log.isLoggable(Level.INFO)) {
935 log.info(config.getMatchId().getToken() + ": UT2004Analyzer started.");
936 }
937
938 return analyzer;
939 }
940
941
942
943
944
945
946
947
948
949
950
951 protected void matchIsAboutToBegin(UCCWrapper ucc, UT2004Server server, UT2004Analyzer analyzer, Bots bots) {
952 }
953
954
955
956
957
958
959
960
961
962
963 protected void restartMatch(UT2004Server server, Bots bots) {
964 if (log != null && log.isLoggable(Level.FINE)) {
965 log.fine(config.getMatchId().getToken() + ": Restarting match...");
966 }
967
968 NullCheck.check(server, "server");
969
970 final BusAwareCountDownLatch latch = new BusAwareCountDownLatch(1, server.getEventBus(), server.getWorldView());
971 IWorldEventListener<GameRestarted> listener = new IWorldEventListener<GameRestarted>() {
972 @Override
973 public void notify(GameRestarted event) {
974 if (event.isFinished()) {
975 latch.countDown();
976 }
977 }
978 };
979
980 if (bots.botObservers.size() > 0) {
981 if (log != null && log.isLoggable(Level.FINE)) {
982 log.fine(config.getMatchId().getToken() + ": Waiting for 5 seconds, to give GB2004 time to initialize observers...");
983 }
984 }
985 try {
986 Thread.sleep(5000);
987 } catch (InterruptedException e) {
988 throw new PogamutInterruptedException("Interrupted while giving GB2004 time to hook up listeners...", log, this);
989 }
990
991 server.getWorldView().addEventListener(GameRestarted.class, listener);
992 server.getAct().act(new GameConfiguration().setRestart(true));
993
994 latch.await(5 * 60 * 1000, TimeUnit.MILLISECONDS);
995
996 if (latch.getCount() > 0) {
997 throw new PogamutException("Restart was not successful, event GameRestarted[finished==true] was not received.", log, this);
998 }
999
1000 bots.matchStart = System.currentTimeMillis();
1001
1002 if (log != null && log.isLoggable(Level.INFO)) {
1003 log.info(config.getMatchId().getToken() + ": Match restarted.");
1004 }
1005 }
1006
1007
1008
1009
1010
1011
1012 protected void recordReplay(UT2004Server server, String fileName) {
1013 if (log != null && log.isLoggable(Level.INFO)) {
1014 log.info(config.getMatchId().getToken() + ": Recording replay " + fileName);
1015 }
1016 server.getAct().act(new Record(fileName));
1017 }
1018
1019
1020
1021
1022
1023
1024
1025
1026
1027
1028
1029
1030
1031
1032
1033
1034
1035
1036
1037
1038 protected abstract UT2004MatchResult waitMatchFinish(UCCWrapper ucc, UT2004Server server, UT2004Analyzer analyzer, Bots bots, long timeoutInMillis);
1039
1040
1041
1042
1043
1044
1045
1046
1047 public void restoreGB2004IniBackup() {
1048 File gb2004File = getGB2004IniFile();
1049 if (gb2004FileBackup == null) {
1050 if (log != null && log.isLoggable(Level.WARNING)) {
1051 log.warning(config.getMatchId().getToken() + ": Could not restore GameBots2004.ini file, missing backup file reference, gb2004FileBackup == null.");
1052 }
1053 return;
1054 }
1055 if (gb2004FileBackup.isFile() && gb2004FileBackup.exists()) {
1056 if (log != null && log.isLoggable(Level.FINE)) {
1057 log.fine(config.getMatchId().getToken() + ": Restoring " + gb2004File.getAbsolutePath() + " into + " + gb2004FileBackup.getAbsolutePath() + " ...");
1058 }
1059 boolean restore = true;
1060 try {
1061 FileUtils.copyFile(gb2004FileBackup, gb2004File);
1062 } catch (IOException e) {
1063 restore = false;
1064 }
1065 if (restore && log != null && log.isLoggable(Level.FINE)) {
1066 log.fine(config.getMatchId().getToken() + ": GameBots2004.ini restored from " + gb2004FileBackup.getAbsolutePath() + ".");
1067 } else
1068 if (!restore && log != null && log.isLoggable(Level.SEVERE)){
1069 log.severe(config.getMatchId().getToken() + ": Failed to restore up GameBots2004.ini from " + gb2004FileBackup.getAbsolutePath() + " into + " + gb2004File.getAbsolutePath() + " !!!");
1070
1071 }
1072 }
1073 }
1074
1075
1076
1077
1078
1079
1080 protected void copyReplay(UCCWrapper ucc, String fileName, File outputDirectory) {
1081 if (log != null && log.isLoggable(Level.FINE)) {
1082 log.fine(config.getMatchId().getToken() + ": Copying replay file into " + outputDirectory.getAbsolutePath());
1083 }
1084 File replayFile = new File(ucc.getConfiguration().getUnrealHome() + File.separator + "Demos" + File.separator + fileName + ".demo4");
1085 File destination = new File(outputDirectory.getAbsoluteFile() + File.separator + "match-" + config.getMatchId().getToken() + "-replay.demo4");
1086 FilePath.makeDirsToFile(destination);
1087 boolean ex = false;
1088 try {
1089 FileUtils.copyFile(replayFile, destination);
1090 } catch (IOException e) {
1091 ex = true;
1092 if (log != null) {
1093 log.warning(config.getMatchId().getToken() + ": Failed to copy replay file from: " + replayFile.getAbsolutePath() + " into " + destination.getAbsolutePath() + ": " + e.getMessage());
1094 }
1095 }
1096 if (!ex) {
1097 if (log != null && log.isLoggable(Level.INFO)) {
1098 log.info(config.getMatchId().getToken() + ": Replay copied into " + destination.getAbsolutePath());
1099 }
1100 }
1101 }
1102
1103
1104
1105
1106
1107
1108
1109
1110
1111
1112
1113
1114
1115
1116 protected abstract void outputResults(UCCWrapper ucc, UT2004Server server, UT2004Analyzer analyzer, Bots bots, UT2004MatchResult result, File outputDirectory);
1117
1118
1119
1120
1121
1122 protected void shutdownAll(UCCWrapper ucc, UT2004Server server, UT2004Analyzer analyzer, Bots bots) {
1123 if (log != null && log.isLoggable(Level.FINE)) {
1124 log.fine(config.getMatchId().getToken() + ": Shutting down everything...");
1125 }
1126
1127 if (ucc != null) {
1128 try {
1129 if (log != null && log.isLoggable(Level.INFO)) {
1130 log.info(config.getMatchId().getToken() + ": Killing UCC...");
1131 }
1132 } catch (Exception e) {
1133 }
1134 try {
1135 ucc.stop();
1136 } catch (Exception e) {
1137 }
1138 }
1139 if (server != null) {
1140 try {
1141 if (log != null && log.isLoggable(Level.INFO)) {
1142 log.info(config.getMatchId().getToken() + ": Killing UT2004Server...");
1143 }
1144 } catch (Exception e) {
1145 }
1146 try {
1147 server.kill();
1148 } catch (Exception e) {
1149 }
1150 }
1151 if (bots != null) {
1152 try {
1153 if (log != null && log.isLoggable(Level.INFO)) {
1154 log.info(config.getMatchId().getToken() + ": Killing Custom bots...");
1155 }
1156 } catch (Exception e) {
1157 }
1158 if (bots.bots != null) {
1159 for (UT2004BotExecution exec : bots.bots.values()) {
1160 try {
1161 exec.stop();
1162 } catch (Exception e) {
1163 }
1164 }
1165 }
1166 try {
1167 if (log != null && log.isLoggable(Level.INFO)) {
1168 log.info(config.getMatchId().getToken() + ": Killing Custom bot observers...");
1169 }
1170 } catch (Exception e) {
1171 }
1172 if (bots.botObservers != null) {
1173 for (IUT2004AnalyzerObserver obs : bots.botObservers.values()) {
1174 try {
1175 obs.kill();
1176 } catch (Exception e) {
1177 }
1178 }
1179 }
1180 }
1181 if (analyzer != null) {
1182 try {
1183 if (log != null && log.isLoggable(Level.INFO)) {
1184 log.info(config.getMatchId().getToken() + ": Killing UT2004Analyzer...");
1185 }
1186 } catch (Exception e) {
1187 }
1188 try {
1189 analyzer.kill();
1190 } catch (Exception e) {
1191 }
1192 }
1193
1194 if (log != null && log.isLoggable(Level.INFO)) {
1195 log.info(config.getMatchId().getToken() + ": UCC, Bots, UT2004Server, UT2004Analyzer + observers were shut down.");
1196 }
1197 }
1198
1199
1200
1201
1202 protected void closeLogger() {
1203 if (log != null && log.isLoggable(Level.WARNING)) {
1204 log.warning(config.getMatchId().getToken() + ": Closing file output...");
1205 }
1206 if (fileHandler != null) {
1207 if (log != null) {
1208 log.removeHandler(fileHandler);
1209 }
1210 fileHandler.close();
1211 fileHandler = null;
1212 }
1213 if (log != null && log.isLoggable(Level.WARNING)) {
1214 log.warning(config.getMatchId().getToken() + ": Logging to file stopped.");
1215 }
1216 }
1217 }