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