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