View Javadoc

1   /*
2    * UCCWrapper.java
3    *
4    */
5   package cz.cuni.amis.pogamut.udk.utils;
6   
7   import com.jezhumble.javasysmon.OsProcess;
8   import java.io.BufferedReader;
9   import java.io.File;
10  import java.io.IOException;
11  import java.io.InputStream;
12  import java.io.InputStreamReader;
13  import java.io.Serializable;
14  import java.util.Timer;
15  import java.util.TimerTask;
16  import java.util.concurrent.CountDownLatch;
17  import java.util.logging.Level;
18  import java.util.logging.Logger;
19  import java.util.regex.Matcher;
20  import java.util.regex.Pattern;
21  
22  import cz.cuni.amis.pogamut.base.agent.impl.AgentId;
23  import cz.cuni.amis.pogamut.base.agent.state.WaitForAgentStateChange;
24  import cz.cuni.amis.pogamut.base.agent.state.level1.IAgentStateDown;
25  import cz.cuni.amis.pogamut.base.agent.state.level1.IAgentStateUp;
26  import cz.cuni.amis.pogamut.base.communication.connection.impl.socket.SocketConnectionAddress;
27  import cz.cuni.amis.pogamut.base.utils.Pogamut;
28  import cz.cuni.amis.pogamut.base.utils.logging.LogCategory;
29  import cz.cuni.amis.pogamut.base.utils.logging.LogPublisher;
30  import cz.cuni.amis.pogamut.udk.communication.messages.gbcommands.Console;
31  import cz.cuni.amis.pogamut.udk.factory.direct.remoteagent.UDKServerFactory;
32  import cz.cuni.amis.pogamut.udk.server.IUDKServer;
33  import cz.cuni.amis.pogamut.udk.server.exception.UCCStartException;
34  import cz.cuni.amis.utils.exception.PogamutException;
35  import java.util.HashSet;
36  import java.util.Set;
37  import java.util.concurrent.TimeUnit;
38  import com.jezhumble.javasysmon.ProcessVisitor;
39  import com.jezhumble.javasysmon.JavaSysMon;
40  import cz.cuni.amis.pogamut.base.communication.worldview.event.IWorldEventListener;
41  import cz.cuni.amis.pogamut.base.component.exception.ComponentCantStopException;
42  import cz.cuni.amis.pogamut.udk.communication.messages.gbcommands.ChangeMap;
43  import cz.cuni.amis.pogamut.udk.communication.messages.gbinfomessages.MapChange;
44  import cz.cuni.amis.utils.ExceptionToString;
45  import cz.cuni.amis.utils.exception.PogamutInterruptedException;
46  import java.util.ArrayList;
47  import java.util.List;
48  
49  /**
50   * Wrapper of running instance of UDK server. Implements pooling of instances.
51   * The location of UDK executabe will be determined by an environment variable
52   * pogamut.udk.home (e.g. c:\Games\UDK). The property cam be set via <i>java ...
53   * -Dpogamut.udk.home=c:\Games\UDK</i>. Another posibility is to set it
54   * by code <code>System.setProperty("pogamut.udk.home", "c:\\udks\\UDK-2011-05");</code>.
55   *
56   * <p>
57   * As of now, UCCWrapper uses console command exit to kill the server when calling {@link #stop() } or
58   * upon JVM shutdown. However, this fails if there are non-Pogamut players connected (e.g. when spectating) and the server stays alive.
59   * If the exit command is not effective, UCCWrapper tries to kill the server in a platform dependent way using UDK process PID. However, some
60   * tricks are needed to obtain the pid. The biggest problem is that UDK.com which needs to be run in order to get console output from the server
61   * spawns another process called UDK.exe and killing the original process does not kill UDK.exe. Moreover,
62   * if used on UNIX (see below) the UDK.exe is not a child process of UDK.com for some reason... So there are some not exactly neat tricks. 
63   * However, on Windows, the UCCWrapper might be considered reliable (even thread-safe) providing no other code in current JVM spawns 
64   * (directly or undirectly)
65   * processes called UDK.exe. On UNIX, there are some additional issues (see below).
66   * </p>
67   * 
68   * <h3>UNIX usage</h3>
69   * <p>
70   *  It is possible to use UCCWrapper under UNIX systems. First you need to setup UDK
71   * as described at our WIKI: <a href="http://pogamut.cuni.cz/pogamut-devel/doku.php?id=guidelines:udk_on_linux">
72   * pogamut.cuni.cz/pogamut-devel/doku.php?id=guidelines:udk_on_linux</a>. Then UCCWrapper must have access to Wine 
73   * in order to this, UCCWrapper uses property called WINE (might be an environment variable or it might be a Java property - see above).
74   * Property value defaults to "wine" which should be just fine if you have wine regularly installed. Make sure that WINEPREFIX environment
75   * variable is set in the shell that runs your program, otherwise Wine will not have access to correct wineprefix.
76   * </p>
77   * <p>
78   * As noted above, there are some not very neat tricks in getting the process PID of UDK. On UNIX, UCCWrapper relies on the fact
79   * that no other program than the current JVM spawns new processes called UDK.exe. If this is not true, UCCWrapper will usually
80   * detect this situation and not read PID at all. But on very rare occasions (another process starts UDK.exe at the same time and starting of UDK.exe
81   * in this JVM fails or is delayed) UCCWrapper may take pid of a different UDK.exe process. 
82   * Since pid is only used to kill the server if the EXIT command fails, it is even more unlikely that this problem will actually
83   * exhibit in killing wrong process. 
84   * </p>
85   * 
86   * @author Ik
87   */
88  public class UCCWrapper {
89  
90      public static final long DEFAULT_START_TIMEOUT = 2 * 60 * 1000;
91  
92      /**
93       * Mutex that forces only one child UCC to be spawned at a time. This allows
94       * 
95       */
96      private static final Object spawnProcessMutex = new Object();
97      
98      /**
99       * How many times will the wrapper try to send ChangeMap command to server,
100      * until it gives up waiting for notification.
101      */
102     public static final int CHANGE_MAP_COMMAND_MAX_REPEATS = 5;
103     
104     public static final long DEFAULT_UDK_EXE_SPAWN_TIMEOUT_WINDOWS = 10000;
105     
106     /**
107      * The ammount of time taken to to start UDK.exe on UNIX is quite large, since wine needs to boot in that time
108      */
109     public static final long DEFAULT_UDK_EXE_SPAWN_TIMEOUT_UNIX = 30000;
110         
111     /**
112      * How long (msec) will wrapper wait for confirmation of ChangeMap message
113      */
114     public static final int CHANGE_MAP_CONFIRMATION_TIMEOUT = 500;
115 
116     /**
117      * Start the server, if not already started. This method blocks, until the server
118      * is ready to accept bot connections
119      * @throws UCCStartException 
120      */
121     public synchronized void start() throws UCCStartException {
122         if(uccProcess != null){
123             throw new IllegalStateException("Wrapper already started");
124         }
125         initUCCWrapper();
126         uccLog.info("Adding shutdown hook");
127         Runtime.getRuntime().addShutdownHook(shutDownHook);
128     }
129 
130     protected String getMapNameWithOptions() {
131         // start new ucc instance
132         String id = System.currentTimeMillis() + "a" + fileCounter++;
133         String fileWithPorts = "GBports" + id;
134         String portsSetting;
135         if(configuration.botServerPort != null || configuration.controlServerPort != null){
136             portsSetting = "";
137             if(configuration.controlServerPort != null){
138                 portsSetting += "?ControlServerPort=" + configuration.controlServerPort;
139             }                
140             if(configuration.botServerPort != null){
141                 portsSetting += "?BotServerPort=" + configuration.botServerPort;
142             }                
143         }
144         else if(configuration.startOnUnusedPort){
145             portsSetting = "?PortsLog=" + fileWithPorts + "?bRandomPorts=true";
146         } else {
147             portsSetting = "";
148         }
149         String gameOptions = configuration.mapName
150                              + "?game=" + configuration.gameBotsPack + "." + configuration.gameType
151                              + portsSetting + configuration.options;
152         return gameOptions;
153     }
154 
155     private Set<Integer> getNewUDKProcesses(JavaSysMon monitor, Set<Integer> oldUDKProcesses){
156             UDKChildProcessVisitor visitor = new UDKChildProcessVisitor();
157             if(isWindows()){
158                 //On Windows, the UDK.exe process is child of current process
159                 monitor.visitProcessTree(monitor.currentPid(), visitor);
160             } else {
161                 //On UNIX, the UDK.exe is not a child of current process - we need
162                 //to search the whole process tree, which reduces reliability as noted
163                 //class javadoc
164                 for(OsProcess child :(List<OsProcess>)monitor.processTree().children()){
165                     monitor.visitProcessTree(child.processInfo().getPid(), visitor);
166                 }                
167             }
168             Set<Integer> newProcesses = visitor.getUdkPids();
169 
170             newProcesses.removeAll(oldUDKProcesses);
171             return newProcesses;
172         
173     }
174     
175     /**
176      * Spawns a new UDK process and sets {@link #uccPid} to it's PID. To work correctly,
177      * the code relies on the fact that no other method in this JVM runs UDK processes and
178      * that no method kills a process unless it acquires lock on spawnProcessMutex.
179      * @param procBuilder
180      * @return 
181      */
182     private Process spawnUDK(ProcessBuilder procBuilder) throws IOException {
183         synchronized (spawnProcessMutex) {
184             JavaSysMon monitor = new JavaSysMon();
185             UDKChildProcessVisitor beforeVisitor = new UDKChildProcessVisitor();
186             
187             long udkExeSpawnTimeout;
188             if(isWindows()){
189                 //On Windows, the UDK.exe process is child of current process
190                 monitor.visitProcessTree(monitor.currentPid(), beforeVisitor);
191                 udkExeSpawnTimeout = udkExeSpawnTimeoutWindows;
192             } else {
193                 //On UNIX, the UDK.exe is not a child of current process - we need
194                 //to search the whole process tree, which reduces reliability as noted
195                 //class javadoc
196                 for(OsProcess child :(List<OsProcess>)monitor.processTree().children()){
197                     monitor.visitProcessTree(child.processInfo().getPid(), beforeVisitor);
198                 }
199                 udkExeSpawnTimeout = udkExeSpawnTimeoutUnix;
200             }
201             Set<Integer> alreadySpawnedProcesses = beforeVisitor.getUdkPids();
202 
203             Process proc = procBuilder.start();
204 
205             long startTime = System.currentTimeMillis();
206             
207             Set<Integer> newProcesses;
208             
209             //actively wait before the UDK.exe process is spawned
210             do {
211                 newProcesses = getNewUDKProcesses(monitor, alreadySpawnedProcesses);
212             } while (newProcesses.isEmpty() && System.currentTimeMillis() - startTime < udkExeSpawnTimeout); 
213             
214 
215 
216             if (newProcesses.isEmpty()) {
217                 uccLog.severe("There is no new UDK PID.");
218             } else if (newProcesses.size() > 1) {
219                 uccLog.severe("Multiple new candidate UDK PIDs");
220             } else {
221                 uccPid = newProcesses.iterator().next();
222             }
223             return proc;
224         }
225     }
226 
227     private void killUDKByPID() {
228         if (uccPid < 0) {
229             uccLog.severe("Cannot kill UCC by PID. PID not set.");
230             return;
231         }
232         synchronized (spawnProcessMutex) {
233             JavaSysMon monitor = new JavaSysMon();
234             monitor.killProcessTree(uccPid, false);
235             uccPid = -1;
236         }
237     }
238 
239     private static class UDKChildProcessVisitor implements ProcessVisitor {
240 
241         Set<Integer> udkPids = new HashSet<Integer>();
242 
243         @Override
244         public boolean visit(OsProcess op, int i) {
245             if (op.processInfo().getCommand().contains("UDK.exe") || (op.processInfo().getName().equals("UDK.exe"))) {
246                 udkPids.add(op.processInfo().getPid());
247             }
248             return false;
249         }
250 
251         public Set<Integer> getUdkPids() {
252             return udkPids;
253         }
254     }
255 
256     /**
257      * Kills all UDK instances with platform specific-system call.
258      * Useful to enforce a full cleanup.
259      */
260     public static void killAllUCCs(LogCategory uccLog) {
261         if (!isWindows()) {
262             //kill process in linux with comand 'killall -9 <process_name>'
263 
264             //System.out.println(plannerRunFile.getName());
265             String[] command1 = new String[2];
266             command1[0] = "killall";
267             command1[1] = "UDK.com";
268 
269             String[] command2 = new String[2];
270             command2[0] = "killall";
271             command2[1] = "UDK.exe";
272 
273             try {
274                 Runtime.getRuntime().exec(command1);
275                 Runtime.getRuntime().exec(command2);
276             } catch (IOException ex) {
277                 uccLog.log(Level.SEVERE, "Could not kill the UDK process: " + ex, ex);
278             }
279         } else {
280             //kill process with wnodes task kill
281             String[] command = new String[4];
282             command[0] = "taskkill";
283             command[1] = "/F";
284             command[2] = "/IM";
285             command[3] = "UDK.*";
286 
287 
288             try {
289                 Runtime.getRuntime().exec(command);
290             } catch (IOException ex) {
291                 uccLog.log(Level.SEVERE, "Could not kill the UDK with taskkill: " + ex, ex);
292             }
293 
294         }
295 
296     }
297     /** Loger containing all output from running instance of UCC. */
298     protected LogCategory uccLog;
299 
300     protected static int fileCounter = 0;
301 
302     Process uccProcess = null;
303 
304     /** Port for bots. */
305     protected int gbPort = -1;
306 
307     /** Port for server connection. */
308     protected int controlPort = -1;
309 
310     /** Port for observer connection. */
311     protected int observerPort = -1;
312 
313     protected IUDKServer utServer = null;
314 
315     /** First port assigned to a ucc instance. */
316     protected static final int basePort = 39782;
317 
318     protected static Integer nextUccWrapperUID = 0;
319 
320     /** ID of the wrapper object. Useful for debuging. */
321     protected int uccWrapperUID = 0;
322 
323     protected String unrealHome = null;
324 
325     protected UCCWrapperConf configuration = null;
326 
327     protected long startingTimeout = DEFAULT_START_TIMEOUT;
328     //protected String mapToLoad
329 
330     protected int uccPid = -1;
331 
332     protected UDKServerFactory serverFactory;
333 
334     /**
335      * Agressive killing means that the server is always killed by PID, if PID is available 
336      * Otherwise it is killed by EXIT command first and if the connection dies, it is considered killed. In some
337      * cases however, the connection dies after exit command, but the server is not down.
338      * Setting this to false is conservative as it lessens the chance of killing a wrong process, setting
339      * this to true on the other hand raise chances that the server is actually stopped.
340      * Set to false by default, since the reading of PID depends on some non-obvious requirements
341      * the programmer should check (see class docs)
342      */
343     protected boolean aggressiveKilling = false;
344     
345     /**
346      * How long to wait for UDK.exe process to be spawned after the UDK.com process
347      * has been started. On Windows. 
348      */
349     private long udkExeSpawnTimeoutWindows = DEFAULT_UDK_EXE_SPAWN_TIMEOUT_WINDOWS;
350 
351     /**
352      * How long to wait for UDK.exe process to be spawned after the UDK.com process
353      * has been started for UNIX systems. The bigger the value, the bigger chance of trouble on UNIX systems (see class comments), however
354      * low values might mean that we will not get UDK process pid.
355      */
356     private long udkExeSpawnTimeoutUnix = DEFAULT_UDK_EXE_SPAWN_TIMEOUT_UNIX;
357     
358     
359     ScannerSink scanner;
360     /**
361      * @return Log with output of UCC. If you want to listen also for messages 
362      * from the startup sequence then use UCCWrapper.create(Logger parent). Set
363      * Parent logger of this log and register listeners before creating this
364      * instance of UCCWrapper.  
365      */
366     public Logger getLogger() {
367         return uccLog;
368     }
369 
370     /**
371      * @return Server connected to this UCC instance.
372      */
373     public synchronized IUDKServer getUTServer() {
374         stopCheck();
375         if (utServer == null) {
376             UDKServerRunner serverRunner = new UDKServerRunner(serverFactory, "NBUTServer", getHost(), controlPort);
377             utServer = serverRunner.startAgent();
378         }
379         return utServer;
380     }
381     
382     public synchronized void restartServer(){
383         stopCheck();
384         utServer = null;
385     }
386 
387     protected String getUnrealHome() {
388         if (unrealHome == null) {
389             return Pogamut.getPlatform().getProperty(PogamutUDKProperty.POGAMUT_UNREAL_HOME.getKey());
390         } else {
391             return unrealHome;
392         }
393     }
394 
395     public UCCWrapper(UCCWrapperConf configuration) {
396         this(configuration, new UDKServerFactory());
397     }
398 
399     public UCCWrapper(UCCWrapperConf configuration, UDKServerFactory factory) {
400         this(configuration, factory, true);
401     }
402 
403     public UCCWrapper(UCCWrapperConf configuration, boolean startImmediately) {
404         this(configuration, new UDKServerFactory(), startImmediately);
405     }
406 
407     /**
408      * 
409      * @param configuration
410      * @param startingTimeout
411      * @param serverFactory allows to specify external server factory. As of 3.3.0, this is needed to prevent memory leaks on subsequent creation of multiple UCCWrappers
412      * @throws UCCStartException 
413      */
414     public UCCWrapper(UCCWrapperConf configuration, UDKServerFactory serverFactory, boolean startImmediately) throws UCCStartException {
415         this.serverFactory = serverFactory;
416         uccLog = new LogCategory("Wrapper");
417         uccLog.addHandler(new LogPublisher.ConsolePublisher(new AgentId("UCC")));
418         
419         configuration.applyDefaults(UCCWrapperConf.DEFAULTS);        
420         
421         if (configuration.log != null) {
422             uccLog.setParent(configuration.log);
423         }
424         this.configuration = configuration;
425         uccWrapperUID = nextUccWrapperUID++;
426         if(startImmediately){
427             start();
428         }
429     }
430 
431     public UCCWrapperConf getConfiguration() {
432         return configuration;
433     }
434 
435     /**
436      * Only makes sense if created with startImmediately = false
437      * @param configuration 
438      */
439     public void setConfiguration(UCCWrapperConf configuration) {
440         this.configuration = configuration;
441     }
442 
443     public UDKServerFactory getServerFactory() {
444         return serverFactory;
445     }
446 
447     /**
448      *  Only makes sense if created with startImmediately = false
449      * @param serverFactory 
450      */
451     public void setServerFactory(UDKServerFactory serverFactory) {
452         this.serverFactory = serverFactory;
453     }
454 
455     public long getStartingTimeout() {
456         return startingTimeout;
457     }
458 
459     /**
460      * Only makes sense if created with startImmediately = false and the serve was not started yet
461      * @param udkExeSpawnTimeout 
462      */
463     public void setStartingTimeout(long startingTimeout) {
464         this.startingTimeout = startingTimeout;
465     }
466 
467     public long getUdkExeSpawnTimeoutUnix() {
468         return udkExeSpawnTimeoutUnix;
469     }
470 
471     /**
472      * Only makes sense if created with startImmediately = false and the serve was not started yet
473      * @param udkExeSpawnTimeout 
474      */
475     public void setUdkExeSpawnTimeoutUnix(long udkExeSpawnTimeoutUnix) {
476         this.udkExeSpawnTimeoutUnix = udkExeSpawnTimeoutUnix;
477     }
478 
479     public long getUdkExeSpawnTimeoutWindows() {
480         return udkExeSpawnTimeoutWindows;
481     }
482 
483     /**
484      * Only makes sense if created with startImmediately = false and the serve was not started yet
485      * @param udkExeSpawnTimeout 
486      */
487     public void setUdkExeSpawnTimeoutWindows(long udkExeSpawnTimeoutWindows) {
488         this.udkExeSpawnTimeoutWindows = udkExeSpawnTimeoutWindows;
489     }
490 
491     public boolean isAggressiveKilling() {
492         return aggressiveKilling;
493     }
494 
495     public void setAggressiveKilling(boolean aggressiveKilling) {
496         this.aggressiveKilling = aggressiveKilling;
497     }
498     
499     
500 
501     
502     
503     /**
504      * Task that will kill the UCC process when user forgets to do so.
505      */
506     Thread shutDownHook = new Thread("UCC wrapper finalizer") {
507 
508         @Override
509         public void run() {
510             UCCWrapper.this.stopNoWaiting();
511         }
512     };
513 
514     private static boolean isWindows() {
515         return System.getProperty("os.name").contains("Windows");
516     }
517     public static long stamp = System.currentTimeMillis();
518 
519     private void cleanupAfterException() {
520         if (uccProcess != null) {
521             uccProcess.destroy();
522         }
523         if (uccPid >= 0) {
524             killUDKByPID();
525         }
526     }
527 
528     protected void initUCCWrapper() throws UCCStartException {
529         try {
530             String udkHomePath = getUnrealHome();
531             String binariesPath = udkHomePath + File.separator + "Binaries";
532 
533             // default ucc executable for Windows
534             //udk.exe creates a separate console for output and the output is thus unavaliable to this process, udk.com does not
535             String uccFile = "Win32" + File.separator + "UDK.com";
536             String uccFileAbsolute = binariesPath + File.separator + uccFile;
537 
538             
539             // determine OS type, if it isn't win suppose it is Linux and try to run UDK through Wine
540             List<String> command = new ArrayList<String>();
541             
542             if(isWindows()){
543                 command.add(uccFileAbsolute);
544             }
545             else {
546                 if(configuration.wineprefix != null && !configuration.wineprefix.isEmpty()){
547                     command.add("WINEPREFIX=" + configuration.wineprefix);
548                 }
549                 command.add(Pogamut.getPlatform().getProperty("WINE", "wine"));
550                 command.add(uccFileAbsolute);
551             }
552             
553             command.add("server");
554             command.add(getMapNameWithOptions());
555             if(configuration.otherCommandLineParameters != null){
556                 command.add(configuration.otherCommandLineParameters);
557             }
558             
559             if(!isWindows()){
560                 command.add("-nohomedir");
561             }
562             
563 
564             ProcessBuilder procBuilder = new ProcessBuilder(command);
565             procBuilder.directory(new File(binariesPath));
566 
567             uccProcess = spawnUDK(procBuilder);
568 
569             uccLog.info("Spawned UDK process. Pid: " + uccPid);
570 
571             scanner = new ScannerSink(uccProcess.getInputStream());
572             scanner.start();
573             new StreamSink(uccProcess.getErrorStream()).start();
574 
575             scanner.serverStartedLatch.await();
576 
577             if (scanner.exception != null) {
578                 // ucc failed to start 
579                 cleanupAfterException();
580                 throw new UCCStartException("Scanner exception", scanner.exception);
581             }
582 
583             controlPort = scanner.controlPort;
584             gbPort = scanner.botsPort;
585             Thread.sleep(5000);
586         } catch (InterruptedException ex) {
587             cleanupAfterException();
588             throw new UCCStartException("Interrupted.", ex);
589         } catch (IOException ex) {
590             cleanupAfterException();
591             throw new UCCStartException("IO Exception.", ex);
592         }
593     }
594     
595     /**
596      * Tries to change map on the server and blocks until either the map
597      * has changed or timeout happens. 
598      * @throws PogamutException if the map change was not succesful
599      */
600     public void changeMap(String mapName, boolean notifyGame, long timeout){
601         uccLog.info("Changing map to: " + mapName);
602         configuration.setMapName(mapName);
603         if(getUTServer().getState().getFlag().isNotState(IAgentStateUp.class)){
604             restartServer();
605             new WaitForAgentStateChange(getUTServer().getState(), IAgentStateUp.class).await(2, TimeUnit.SECONDS);
606         }
607         
608         //It is important to start to await new game start BEFORE the actual command is sent.
609         //Otherwise I might miss the response, if it is fast enough, especially,
610         //if I spend some time waiting for map change confirmation
611         CountDownLatch gameStartLatch = awaitGameStart();
612         
613         
614         /**
615          * Sending the ChangeMap command.
616          * In some cases, the ChangeMap command gets lost along the way. So it is
617          * a good idea to wait for confirmation and resend it if neccessary
618          */
619         final CountDownLatch notifiedMapChangeLatch = new CountDownLatch(1);
620         final String mapNameWithOptions = getMapNameWithOptions();
621         IWorldEventListener<MapChange> mapChangeListener = new IWorldEventListener<MapChange>() {
622 
623             @Override
624             public void notify(MapChange event) {
625                 if(event.getMapName().equals(mapNameWithOptions)){
626                     notifiedMapChangeLatch.countDown();
627                 } else {
628                     uccLog.severe("Notified of unexpected map change. Contiuning waiting. Notified for map:" + event.getMapName());
629                 }
630             }
631         };
632         
633         
634         getUTServer().getWorldView().addEventListener(MapChange.class, mapChangeListener);
635         
636         boolean mapChangeConfirmed = false;
637         
638         for(int i = 0; i < CHANGE_MAP_COMMAND_MAX_REPEATS; i++){        
639             if(gameStartLatch.getCount() <= 0){
640                 mapChangeConfirmed = true;
641                 uccLog.info("New match started while waiting for ChangeMap confirmation. Let's trust it is the correct game.");
642                 break;
643             }
644             if(getUTServer().getState().getFlag().isNotState(IAgentStateUp.class)){
645                 break;
646             }
647             getUTServer().getAct().act(new ChangeMap(mapNameWithOptions, notifyGame));
648             try {
649                 if(notifiedMapChangeLatch.await(CHANGE_MAP_CONFIRMATION_TIMEOUT, TimeUnit.MILLISECONDS)){
650                     uccLog.info("ChangeMap confirmed from GB server");
651                     try {
652                         getUTServer().stop();
653                     } catch (ComponentCantStopException ex){
654                         uccLog.severe("Server could not stop: " + ex.getMessage());                        
655                     }
656                     mapChangeConfirmed = true;
657                     break;
658                 }
659             } catch (InterruptedException ex) {                
660             }
661         }
662         
663         if(!mapChangeConfirmed){
664             uccLog.severe("ChangeMap command was not confirmed. Trying to wait for map change anyway.");
665         }
666         
667         
668         try {
669             try {
670                 if (gameStartLatch.await(timeout, TimeUnit.MILLISECONDS)) {
671                     if (scanner.exception != null) {
672                         throw scanner.exception;
673                     }
674                     uccLog.info("Map changed.");
675                     restartServer();
676                 } else {
677                     uccLog.severe("Map change timed out.");
678                     throw new PogamutException("Map change timed out.", this);
679                 }
680             } catch (InterruptedException ex) {
681                 uccLog.severe("Waiting for map change interrupted.");
682                 throw new PogamutInterruptedException("Waiting for map change interrupted.", ex, this);
683             }
684         } finally {
685             gameStartLatch.countDown();
686         }
687     }
688     
689     
690     /**
691      * Returns a countdown latch, that is raised after map change message was encountered
692      * @return 
693      */
694     public CountDownLatch awaitGameStart(){
695         return scanner.awaitGameStart();
696     }
697 
698     /**
699      * Process of the
700      * @return
701      */
702     public Process getProcess() {
703         return uccProcess;
704     }
705     /** Was this instance already released? */
706     protected boolean stopped = false;
707 
708     private synchronized void stopNoWaiting() {
709         if(stopped){
710             getLogger().info("UCCWrapper already stopped, ignoring call to stopNoWaiting()");
711             return;
712         }
713         try {
714             //Because of some kind of error, it is possible, that the
715             //original server was killed. In this case I need to restart the server component - setting it to null, forces restart upon new 
716             //getter call
717             if (getUTServer().getState().getFlag().isNotState(IAgentStateUp.class)) {
718                 getLogger().info("Server component down, creating new to send EXIT command");
719                 utServer = null;
720             }
721 
722             getLogger().info("Sending EXIT command");
723             getUTServer().getAct().act(new Console("EXIT"));
724 
725             //Killing the server connection is useless - it might prevent EXIT from being propagated to the ucc
726             //while killing the ucc will surely kill server connection
727 
728             //Wait for the server connection to die to ensure that ucc was killed
729             WaitForAgentStateChange waitForServerDeath = new WaitForAgentStateChange(getUTServer().getState(), IAgentStateDown.class);
730             try {
731                 waitForServerDeath.await(3, TimeUnit.SECONDS);
732             } catch (PogamutInterruptedException ex) {
733                 uccLog.log(Level.SEVERE, "Waiting for server death interrupted.", ex);
734             }
735 
736             if (!getUTServer().getState().getFlag().isState(IAgentStateDown.class)) {
737                 getUTServer().kill();
738                 uccLog.severe("Server did not die in response to EXIT command. Trying to kill by pid.");
739                 killUDKByPID();
740             } else if (isAggressiveKilling()) {
741                 uccLog.info("Aggressive killing set to true. Trying to kill by pid.");
742                 killUDKByPID();
743             }
744 
745             utServer = null;
746 
747 
748             if (uccProcess != null) {
749                 uccProcess.destroy();
750             }
751         } catch (Exception ex) {
752             uccLog.severe("Exception killing UCCWrapper :" + ex.getMessage());
753             uccLog.severe(ExceptionToString.process(ex));
754             if(isAggressiveKilling()){
755                 uccLog.info("Aggressive killing set to true. Trying to kill by pid.");
756                 killUDKByPID();
757             }
758         } finally {
759             uccProcess = null;
760             stopped = true;
761         }
762     }
763 
764     /**
765      * Stops the UCC server.
766      */
767     public synchronized void stop() {
768         if (uccProcess != null) {
769             stopNoWaiting();
770             getLogger().info("Removing shutdown hook");
771             Runtime.getRuntime().removeShutdownHook(shutDownHook);
772             
773             try {
774                 Thread.sleep(1000);
775                 // give the process some time to terminate
776             } catch (InterruptedException e) {
777             }
778         }
779     }
780 
781     /**
782      * @return Port for GameBots connection.
783      */
784     public int getBotPort() {
785         stopCheck();
786         return gbPort;
787     }
788 
789     /**
790      * @return Port of the Observer of GameBots2004.
791      * @deprecated observer port is not used in UDK
792      */
793     @Deprecated
794     public int getObserverPort() {
795         stopCheck();
796         return observerPort;
797     }
798 
799     /**
800      * @return Port for control connection.
801      */
802     public int getControlPort() {
803         stopCheck();
804         return controlPort;
805     }
806 
807     protected void stopCheck() {
808         if (stopped) {
809             throw new PogamutException("UCC already stopped.", this);
810         }
811     }
812 
813     public String getHost() {
814         return "localhost";
815     }
816 
817     public SocketConnectionAddress getBotAddress() {
818         return new SocketConnectionAddress(getHost(), getBotPort());
819     }
820 
821     public SocketConnectionAddress getServerAddress() {
822         return new SocketConnectionAddress(getHost(), getControlPort());
823     }
824 
825     /**
826      * 
827      * @return
828      * @deprecated there is no observer connection in UDK
829      */
830     @Deprecated
831     public SocketConnectionAddress getObserverAddress() {
832         return new SocketConnectionAddress(getHost(), getObserverPort());
833     }
834 
835     /**
836      * Configuration object of the UCC wrapper instance.
837      */
838     public static class UCCWrapperConf implements Serializable {
839 
840         String mapName = null;
841 
842         String gameBotsPack = null;
843 
844         String gameType = null;
845 
846         String options = null;
847 
848         Boolean startOnUnusedPort = null;
849 
850         String otherCommandLineParameters = null;
851 
852         Integer botServerPort = null;
853 
854         Integer controlServerPort = null;
855 
856         /**
857          * UNIX only option to specify wineprefix for wine installation to use
858          */
859         String wineprefix = null;                
860         
861         transient Logger log = null;
862 
863         public static final UCCWrapperConf DEFAULTS;
864 
865         static {
866             DEFAULTS = new UCCWrapperConf();
867             DEFAULTS.setMapName("DM-Deck").setGameBotsPack("GameBotsUDK").setGameType("BotDeathMatch").setStartOnUnusedPort(true);
868 
869         }
870 
871         public UCCWrapperConf() {
872         }
873 
874         public void applyDefaults(UCCWrapperConf defaults) {
875             if (mapName == null) {
876                 setMapName(defaults.mapName);
877             }
878             if (gameBotsPack == null) {
879                 setGameBotsPack(defaults.gameBotsPack);
880             }
881             if (gameType == null) {
882                 setGameType(defaults.gameType);
883             }
884             if (options == null) {
885                 setOptions(defaults.options);
886             }
887             if (startOnUnusedPort == null) {
888                 setStartOnUnusedPort(defaults.startOnUnusedPort);
889             }
890             if (otherCommandLineParameters == null) {
891                 setOtherCommandLineParameters(defaults.otherCommandLineParameters);
892             }
893             if (log == null) {
894                 setLogger(defaults.log);
895             }
896             if (botServerPort == null) {
897                 setBotServerPort(defaults.botServerPort);
898             }
899             if (controlServerPort == null) {
900                 setControlServerPort(defaults.controlServerPort);
901             }
902             if(wineprefix == null){
903                 setWineprefix(wineprefix);
904             }
905         }
906 
907         /**
908          * Forces UCC to find free port and start on it, otherwise it will start on ports 3000 + 3001.
909          * @param startOnUnusedPort
910          */
911         public UCCWrapperConf setStartOnUnusedPort(boolean startOnUnusedPort) {
912             this.startOnUnusedPort = startOnUnusedPort;
913             return this;
914         }
915 
916         /**
917          * Eg. GameBots2004, GBSceanrio etc.
918          * @param gameBotsPack
919          */
920         public UCCWrapperConf setGameBotsPack(String gameBotsPack) {
921             this.gameBotsPack = gameBotsPack;
922             return this;
923         }
924 
925         public UCCWrapperConf setMapName(String mapName) {
926             this.mapName = mapName;
927             return this;
928         }
929 
930         /**
931          * Eg. BotDeathMatch, BotCTFGame etc. Consult GameBots documentation for
932          * complete list available game types.
933          */
934         public UCCWrapperConf setGameType(String gameType) {
935             this.gameType = gameType;
936             return this;
937         }
938 
939         /**
940          * Can be used for setting mutators etc.
941          * @param options
942          */
943         public UCCWrapperConf setOptions(String options) {
944             this.options = options;
945             return this;
946         }
947 
948         /**
949          * Logger used by the UCC.
950          * @param log
951          */
952         public UCCWrapperConf setLogger(Logger log) {
953             this.log = log;
954             return this;
955         }
956 
957         public UCCWrapperConf setOtherCommandLineParameters(String otherCommandLineParameters) {
958             this.otherCommandLineParameters = otherCommandLineParameters;
959             return this;
960         }
961 
962         public UCCWrapperConf setBotServerPort(Integer botServerPort) {
963             this.botServerPort = botServerPort;
964             return this;
965         }
966 
967         public UCCWrapperConf setControlServerPort(Integer controlServerPort) {
968             this.controlServerPort = controlServerPort;
969             return this;
970         }
971         
972         /**
973          * UNIX-only option
974          * @param wineprefix
975          * @return 
976          */
977         public UCCWrapperConf setWineprefix(String wineprefix){
978             this.wineprefix = wineprefix;
979             return this;
980         }
981     }
982 
983     /**
984      * Reads content of the stream and discards it.
985      */
986     protected class StreamSink extends Thread {
987 
988         protected InputStream os = null;
989 
990         public StreamSink(InputStream os) {
991             setName("UCC Stream handler");
992             this.os = os;
993         }
994 
995         protected void handleInput(String str) {
996             if (uccLog.isLoggable(Level.INFO)) {
997                 uccLog.info("ID" + uccWrapperUID + " " + str);
998             }
999         }
1000 
1001         @Override
1002         public void run() {
1003             BufferedReader stdInput = new BufferedReader(new InputStreamReader(os));
1004 
1005             String s = null;
1006             try {
1007                 while ((s = stdInput.readLine()) != null) {
1008                     handleInput(s);
1009                 }
1010                 os.close();
1011             } catch (IOException ex) {
1012                 // the process has been closed so reading the line has failed, 
1013                 // don't worry about it
1014                 //ex.printStackTrace();
1015             }
1016         }
1017     }
1018 
1019     /**
1020      * Scanns the output of UCC for some specific srings (Ports bounded. START MATCH). 
1021      */
1022     public class ScannerSink extends StreamSink {
1023 
1024         /** Exception that ended the startig. Should be checked after the latch is raised. */
1025         public UCCStartException exception = null;
1026 
1027         public ScannerSink(InputStream is) {
1028             super(is);
1029             timer.schedule(task = new TimerTask() {
1030 
1031                 @Override
1032                 public void run() {
1033                     exception = new UCCStartException("Starting timed out. Ports weren't bound in the required time (" + startingTimeout + " ms).", this);
1034                     timer.cancel();
1035                     serverStartedLatch.countDown();
1036                 }
1037             }, startingTimeout);
1038         }
1039         public CountDownLatch serverStartedLatch = new CountDownLatch(1);
1040         public CountDownLatch mapChangedLatch = null;
1041 
1042         public int controlPort = -1;
1043 
1044         public int botsPort = -1;
1045 
1046         /**
1047          * Thread that kills ucc process after specified time if the ports aren't 
1048          * read from the console. This prevents freezing the ScannerSink when ucc
1049          * fails to start.
1050          */
1051         Timer timer = new Timer("UDK start timeout");
1052 
1053         TimerTask task = null;
1054 //        private final String defaultPatternStart = "\\[[0-9]*\\.[0-9]*\\] [^:]*: ";
1055 
1056         private final String defaultPatternStart = "";
1057 
1058         private final Pattern portPattern = Pattern.compile(defaultPatternStart + "BotServerPort:(\\d*) ControlServerPort:(\\d*)");
1059 
1060         private final Pattern commandletNotFoundPattern = Pattern.compile(defaultPatternStart + "Commandlet server not found");
1061 
1062         private final Pattern mapNotFoundPattern = Pattern.compile(defaultPatternStart + "No maplist entries found matching the current command line.*");
1063 
1064         private final Pattern matchStartedPattern = Pattern.compile(defaultPatternStart + "START MATCH");
1065 
1066         public CountDownLatch awaitGameStart(){
1067             if(serverStartedLatch != null && serverStartedLatch.getCount() > 0){
1068                 throw new IllegalStateException("Only one game start await might be in progress");
1069             }
1070             serverStartedLatch = new CountDownLatch(1);
1071             return serverStartedLatch;
1072         }
1073         
1074         
1075         @Override
1076         protected void handleInput(String str) {
1077             super.handleInput(str);
1078             if (serverStartedLatch.getCount() != 0) {
1079                 // server has not yet started
1080 
1081                 Matcher matcher = portPattern.matcher(str);
1082                 if (matcher.find()) {
1083                     botsPort = Integer.parseInt(matcher.group(1));
1084                     controlPort = Integer.parseInt(matcher.group(2));
1085                     //raiseLatch();
1086                 }
1087 
1088                 matcher = commandletNotFoundPattern.matcher(str);
1089                 if (matcher.find()) {
1090                     exception = new UCCStartException("UDK failed to start due to: Commandlet server not found.", this);
1091                     raiseServerStartedLatch();
1092                 }
1093 
1094                 matcher = mapNotFoundPattern.matcher(str);
1095                 if (matcher.find()) {
1096                     exception = new UCCStartException("UDK failed to start due to: Map not found.", this);
1097                     raiseServerStartedLatch();
1098                 }
1099 
1100                 matcher = matchStartedPattern.matcher(str);
1101                 if (matcher.find()) {
1102                     // The match has started, raise the latch
1103                     raiseServerStartedLatch();
1104                 }
1105             }
1106 
1107         }
1108 
1109         protected void raiseServerStartedLatch() {
1110             timer.cancel();
1111             task.cancel();
1112             serverStartedLatch.countDown();
1113         }
1114     }
1115 }