* Some changes to game start logic (better handling for disconnected users). Changes to server logging.

Mage.Client/src/main/java/mage/client/game/GamePane.java

@@ -34,9 +34,9 @@
 
 package mage.client.game;
 
-import java.awt.KeyboardFocusManager;
 import java.util.UUID;
 import javax.swing.SwingUtilities;
+import static javax.swing.WindowConstants.DISPOSE_ON_CLOSE;
 import mage.client.MagePane;
 
 /**

Mage.Common/src/mage/remote/SessionImpl.java

@@ -360,18 +360,18 @@ public class SessionImpl implements Session {
         }
         client.showMessage("Unable to connect to server. " + message);
         if (logger.isTraceEnabled()) {
-            t.printStackTrace();
+            logger.trace("StackTrace", t);
         }
     }
 
     /**
      *
-     * @param errorCall - was connection lost because of error
+     * @param errorCall - was connection lost because of error - ask user if he want to try to reconnect
      */
     @Override
     public synchronized void disconnect(boolean errorCall) {
         if (isConnected()) {
-            logger.info("DISCONNECT still connected");
+            logger.info("DISCONNECT (still connected)");
             sessionState = SessionState.DISCONNECTING;
         }
         if (connection == null || sessionState == SessionState.DISCONNECTED) {
@@ -1396,6 +1396,7 @@ public class SessionImpl implements Session {
             return true;
         } catch (MageException ex) {
                 handleMageException(ex);
+                disconnect(true);
         } catch (Throwable t) {
             handleThrowable(t);
         }

Mage.Server/src/main/java/mage/server/ChatManager.java

@@ -85,7 +85,7 @@ public class ChatManager {
                 synchronized (chatSession) {
                     if (chatSessions.containsKey(chatId)) {
                         chatSessions.remove(chatId);
-                        logger.debug("Chat removed - chatId: " + chatId);
+                        logger.trace("Chat removed - chatId: " + chatId);
                     } else {
                         logger.trace("Chat to destroy does not exist - chatId: " + chatId);
                     } 

Mage.Server/src/main/java/mage/server/ChatSession.java

@@ -67,7 +67,7 @@ public class ChatSession {
             String userName = user.getName();
             clients.put(userId, userName);
             broadcast(null, userName + " has joined", MessageColor.BLUE, true, MessageType.STATUS);
-            logger.debug(userName + " joined chat " + chatId);
+            logger.trace(userName + " joined chat " + chatId);
         }
     }
 

Mage.Server/src/main/java/mage/server/Session.java

@@ -220,7 +220,7 @@ public class Session {
         try {
             if(lock.tryLock(500, TimeUnit.MILLISECONDS)) {
                 lockSet = true;
-                logger.debug("SESSION LOCK SET sessionId: " + sessionId);
+                logger.trace("SESSION LOCK SET sessionId: " + sessionId);
                 User user = UserManager.getInstance().getUser(userId);
                 if (user == null || !user.isConnected()) {
                     return; //user was already disconnected by other thread
@@ -230,10 +230,10 @@ public class Session {
                     logger.info("OLD SESSION IGNORED - " + user.getName());
                     return;
                 }
-                logger.info("LOST CONNECTION - " + user.getName() + " id: " + userId);
+                // logger.info("LOST CONNECTION - " + user.getName() + " id: " + userId);
                 UserManager.getInstance().disconnect(userId, DisconnectReason.LostConnection);
             } else {
-                logger.error("SESSION LOCK lost connection - userId: " + userId);
+                logger.error("CAN'T GET LOCK - userId: " + userId);
             }
         } catch (InterruptedException ex) {
             logger.error("SESSION LOCK lost connection - userId: " + userId, ex);
@@ -241,7 +241,7 @@ public class Session {
         finally {
             if (lockSet)    {
                 lock.unlock();
-                logger.debug("SESSION LOCK UNLOCK sessionId: " + sessionId);
+                logger.trace("SESSION LOCK UNLOCK sessionId: " + sessionId);
             }
         }
 

Mage.Server/src/main/java/mage/server/TableController.java

@@ -502,39 +502,6 @@ public class TableController {
         }
     }
 
-
-//    public synchronized void startChallenge(UUID userId, UUID challengeId) {
-//        if (userId.equals(this.userId)) {
-//            try {
-//                match.startMatch();
-//                match.startGame();
-//                table.initGame();
-//                GameOptions gameOptions = new GameOptions();
-//                gameOptions.testMode = true;
-////                match.getGame().setGameOptions(gameOptions);
-//                GameManager.getInstance().createGameSession(match.getGame(), userPlayerMap, table.getId(), null);
-//                ChallengeManager.getInstance().prepareChallenge(getPlayerId(), match);
-//                for (Entry<UUID, UUID> entry: userPlayerMap.entrySet()) {
-//                    UserManager.getInstance().getUser(entry.getKey()).gameStarted(match.getGame().getId(), entry.getValue());
-//                }
-//            } catch (GameException ex) {
-//                logger.fatal(null, ex);
-//            }
-//        }
-//    }
-
-//    private UUID getPlayerId() throws GameException {
-//        UUID playerId = null;
-//        for (Entry<UUID, UUID> entry : userPlayerMap.entrySet()) {
-//            playerId = entry.getValue();
-//            break;
-//        }
-//        if (playerId == null) {
-//            throw new GameException("Couldn't find a player in challenge mode.");
-//        }
-//        return playerId;
-//    }
-
     /**
      * Used from non tournament match to start
      * 
@@ -572,20 +539,12 @@ public class TableController {
             GameManager.getInstance().createGameSession(match.getGame(), userPlayerMap, table.getId(), choosingPlayerId);
             String creator = null;
             StringBuilder opponent = new StringBuilder();
-            int activePlayers = 0;
+//            int activePlayers = 0;
             for (Entry<UUID, UUID> entry: userPlayerMap.entrySet()) { // no AI players
                 if (!match.getPlayer(entry.getValue()).hasQuit()) {
                     User user = UserManager.getInstance().getUser(entry.getKey());
                     if (user != null) {
-                        activePlayers++;
+//                        activePlayers++;
-                        if (!user.isConnected()) {
-                            // if the user is not connected but exits, the user is currently disconnected. So it's neccessary
-                            // to join the user to the game here (instead the client does it) , so he can join the game, if he reconnects in time.
-                            // remove an existing constructing for the player if it exists
-                            user.removeConstructing(match.getPlayer(entry.getValue()).getPlayer().getId());
-                            GameManager.getInstance().joinGame(match.getGame().getId(), user.getId());
-                            logger.debug("Joined currently not connected user " + user.getName() + "  matchId: " + match.getId());                            
-                        }
                         Player player = match.getPlayer(entry.getValue()).getPlayer();
                         player.setRequestToShowHandCardsAllowed(user.getUserData().allowRequestShowHandCards());
                         user.gameStarted(match.getGame().getId(), entry.getValue());                        
@@ -610,16 +569,16 @@ public class TableController {
             // Append AI opponents to the log file
             for (MatchPlayer mPlayer :match.getPlayers()) {
                 if (!mPlayer.getPlayer().isHuman()) {
-                    activePlayers++;
+//                    activePlayers++;
                     if (opponent.length() > 0) {
                         opponent.append(" - ");
                     }
                     opponent.append(mPlayer.getName());
                 }
             }
-            if (activePlayers < 2) {
+//            if (activePlayers < 2) {
-                throw new MageException("Can't start game - Less than two players active - " +activePlayers);
+//                throw new MageException("Can't start game - Less than two players active - " +activePlayers);
-            }
+//            }
             ServerMessagesUtil.getInstance().incGamesStarted();
 
 
@@ -737,7 +696,7 @@ public class TableController {
         GameManager.getInstance().removeGame(game.getId());
         try {
             if (!match.hasEnded()) {
-                if (match.getGame().getGameType().isSideboardingAllowed()) {
+                if (match.getGame() != null && match.getGame().getGameType().isSideboardingAllowed()) {
                     sideboard();
                 }
                 if (!match.hasEnded()) {

Mage.Server/src/main/java/mage/server/TableManager.java

@@ -94,8 +94,7 @@ public class TableManager {
                 try {
                     checkTableHealthState();
                 } catch(Exception ex) {
-                    logger.fatal("Check table health state job error:");
+                    logger.fatal("Check table health state job error:", ex);
-                    ex.printStackTrace();
                 }
             }
         }, EXPIRE_CHECK_PERIOD, EXPIRE_CHECK_PERIOD, TimeUnit.MINUTES);

Mage.Server/src/main/java/mage/server/User.java

@@ -125,15 +125,15 @@ public class User {
         if (sessionId.isEmpty()) {
             userState = UserState.Disconnected;
             lostConnection();
-            logger.debug("USER - lost connection: " + userName + " id: " + userId);
+            logger.trace("USER - lost connection: " + userName + " id: " + userId);
 
         } else if (userState == UserState.Created) {
             userState = UserState.Connected;
-            logger.debug("USER - created: " + userName + " id: " + userId);
+            logger.trace("USER - created: " + userName + " id: " + userId);
         } else {
             userState = UserState.Reconnected;
             reconnect();
-            logger.info("USER - reconnected: " + userName + " id: " + userId);
+            logger.trace("USER - reconnected: " + userName + " id: " + userId);
         }
     }
 
@@ -151,7 +151,7 @@ public class User {
     }
 
     public String getDisconnectDuration() {
-        long secondsDisconnected = SystemUtil.getDateDiff(lastActivity, new Date(), TimeUnit.SECONDS);
+        long secondsDisconnected = getSecondsDisconnected();
         long secondsLeft;
         String sign = "";
         if (secondsDisconnected > (3 * 60)) {            
@@ -166,6 +166,10 @@ public class User {
         return new StringBuilder(sign).append(Integer.toString(minutes)).append(":").append(seconds > 9 ? seconds: "0" + Integer.toString(seconds)).toString();
     }
 
+    public long getSecondsDisconnected() {
+        return SystemUtil.getDateDiff(lastActivity, new Date(), TimeUnit.SECONDS);
+    }
+
     public Date getConnectionTime() {
         return connectionTime;
     }
@@ -265,7 +269,7 @@ public class User {
 
     public boolean isExpired(Date expired) {
         if (lastActivity.before(expired)) {
-            logger.debug(userName + " is expired!");
+            logger.trace(userName + " is expired!");
             userState = UserState.Expired;
             return true;
         }
@@ -349,18 +353,18 @@ public class User {
     }
 
     public void remove(DisconnectReason reason) {
-        logger.debug("REMOVE " + getName() + " Game sessions: " + gameSessions.size() );
+        logger.trace("REMOVE " + getName() + " Game sessions: " + gameSessions.size() );
         for (GameSessionPlayer gameSession: gameSessions.values()) {
             logger.debug("-- kill game session of gameId: " + gameSession.getGameId() );
             gameSession.quitGame();
         }
         gameSessions.clear();
-        logger.debug("REMOVE " + getName() + " Draft sessions " + draftSessions.size());
+        logger.trace("REMOVE " + getName() + " Draft sessions " + draftSessions.size());
         for (DraftSession draftSession: draftSessions.values()) {
             draftSession.setKilled();
         }
         draftSessions.clear();
-        logger.debug("REMOVE " + getName() + " Tournament sessions " + tournamentSessions.size());
+        logger.trace("REMOVE " + getName() + " Tournament sessions " + tournamentSessions.size());
         for (TournamentSession tournamentSession: tournamentSessions.values()) {
             TournamentController tournamentController = TournamentManager.getInstance().getTournamentController(tournamentSession.getTournamentId());
             if (tournamentController != null) {
@@ -369,18 +373,18 @@ public class User {
             tournamentSession.setKilled();
         }
         tournamentSessions.clear();
-        logger.debug("REMOVE " + getName() + " Tables " + tables.size());
+        logger.trace("REMOVE " + getName() + " Tables " + tables.size());
         for (Entry<UUID, Table> entry: tables.entrySet()) {
             logger.debug("-- leave tableId: " + entry.getValue().getId());
             TableManager.getInstance().leaveTable(userId, entry.getValue().getId());
         }
         tables.clear();
-        logger.debug("REMOVE " + getName() + " watched Games " + watchedGames.size());
+        logger.trace("REMOVE " + getName() + " watched Games " + watchedGames.size());
         for (UUID gameId: watchedGames) {
             GameManager.getInstance().stopWatching(gameId, userId);
         }
         watchedGames.clear();
-        logger.debug("REMOVE " + getName() + " Chats ");
+        logger.trace("REMOVE " + getName() + " Chats ");
         ChatManager.getInstance().removeUser(userId, reason);
     }
 

Mage.Server/src/main/java/mage/server/game/GameController.java

@@ -44,7 +44,10 @@ import java.util.Set;
 import java.util.UUID;
 import java.util.concurrent.ConcurrentHashMap;
 import java.util.concurrent.ExecutorService;
+import java.util.concurrent.Executors;
 import java.util.concurrent.Future;
+import java.util.concurrent.ScheduledExecutorService;
+import java.util.concurrent.TimeUnit;
 import java.util.zip.GZIPOutputStream;
 import mage.MageException;
 import mage.abilities.Ability;
@@ -95,6 +98,8 @@ public class GameController implements GameCallback {
     private static final ExecutorService gameExecutor = ThreadExecutor.getInstance().getGameExecutor();
     private static final Logger logger = Logger.getLogger(GameController.class);
 
+    protected ScheduledExecutorService joinWaitingExecutor = Executors.newSingleThreadScheduledExecutor();
+
     private ConcurrentHashMap<UUID, GameSessionPlayer> gameSessions = new ConcurrentHashMap<>();
     private ConcurrentHashMap<UUID, GameSessionWatcher> watchers = new ConcurrentHashMap<>();
     private ConcurrentHashMap<UUID, PriorityTimer> timers = new ConcurrentHashMap<>();
@@ -123,6 +128,7 @@ public class GameController implements GameCallback {
             }
         }
         init();
+
     }
 
     public void cleanUp() {
@@ -250,7 +256,16 @@ public class GameController implements GameCallback {
                 }
             }
         );
-
+        joinWaitingExecutor.scheduleAtFixedRate(new Runnable() {
+            @Override
+            public void run() {
+                try {
+                    sendInfoAboutPlayersNotJoinedYet();
+                } catch(Exception ex) {
+                    logger.fatal("Send info about player not joined yet:", ex);
+                }
+            }
+        }, 15, 15, TimeUnit.SECONDS);
         checkStart();
     }
 
@@ -311,7 +326,7 @@ public class GameController implements GameCallback {
             joinType = "rejoined";
         }
         user.addGame(playerId, gameSession);
-        logger.debug("Player " + playerId + " has " + joinType + " gameId: " + game.getId());
+        logger.debug("Player " + player.getName()+ " " + playerId + " has " + joinType + " gameId: " + game.getId());
         ChatManager.getInstance().broadcast(chatId, "", game.getPlayer(playerId).getName() + " has " + joinType + " the game", MessageColor.ORANGE, true, MessageType.GAME);
         checkStart();
     }
@@ -319,20 +334,56 @@ public class GameController implements GameCallback {
     private synchronized void startGame() {
         if (gameFuture == null) {
             for (final Entry<UUID, GameSessionPlayer> entry: gameSessions.entrySet()) {
-                if (!entry.getValue().init()) {
+                entry.getValue().init();
-                    logger.fatal("Unable to initialize client");
-                    //TODO: generate client error message
-                    GameManager.getInstance().removeGame(game.getId());
-                    return;
-                }
             }
             GameWorker worker = new GameWorker(game, choosingPlayerId, this);
             gameFuture = gameExecutor.submit(worker);
         }
     }
 
+    private void sendInfoAboutPlayersNotJoinedYet() {
+        for (Player player: game.getPlayers().values()) {
+            if (!player.hasLeft() && player.isHuman()) {                
+                User user = getUserByPlayerId(player.getId());                
+                if (user != null) {
+                    if (!user.isConnected()) {
+                        if (gameSessions.get(player.getId()) == null) {
+                                // join the game because player has not joined are was removed because of disconnect
+                                user.removeConstructing(player.getId());
+                                GameManager.getInstance().joinGame(game.getId(), user.getId());
+                                logger.debug("Player " + user.getName() + " (disconnected) has joined gameId: " +game.getId());
+                        }
+                        ChatManager.getInstance().broadcast(chatId, player.getName(), user.getPingInfo() + " is pending to join the game", MessageColor.BLUE, true, ChatMessage.MessageType.STATUS);
+                        if (user.getSecondsDisconnected() > 240) {
+                            // Cancel player join possibility lately after 4 minutes
+                            logger.debug("Player " + user.getName() + " - canceled game (after 240 seconds) gameId: " +game.getId());
+                            player.leave();
+                        }
+
+                    }
+                } else {
+                    if (!player.hasLeft()) {
+                        logger.debug("Player " + player.getName() + " canceled game (no user) gameId: " + game.getId());
+                        player.leave();
+                    }
+                }
+            }
+        }
+        checkStart();
+    }
+
+    private User getUserByPlayerId(UUID playerId) {
+        for(Map.Entry<UUID,UUID> entry: userPlayerMap.entrySet()) {
+            if (entry.getValue().equals(playerId)) {
+                return UserManager.getInstance().getUser(entry.getKey());
+            }
+        }
+        return null;
+    }
+
     private void checkStart() {
         if (allJoined()) {
+            joinWaitingExecutor.shutdownNow();
             ThreadExecutor.getInstance().getCallExecutor().execute(
                 new Runnable() {
                     @Override
@@ -345,8 +396,16 @@ public class GameController implements GameCallback {
 
     private boolean allJoined() {
         for (Player player: game.getPlayers().values()) {
-            if (player.isHuman() && gameSessions.get(player.getId()) == null) {
+            if (!player.hasLeft()) {
-                return false;
+                User user = getUserByPlayerId(player.getId());
+                if (user != null) {
+                    if (!user.isConnected()) {
+                        return false;
+                    }
+                }
+                if (player.isHuman() && gameSessions.get(player.getId()) == null) {
+                    return false;
+                }
             }
         }
         return true;
@@ -379,30 +438,23 @@ public class GameController implements GameCallback {
         }
     }
 
-//    public void removeUser(UUID userId) {
-//        UUID playerId = userPlayerMap.get(userId);
-//        if (playerId != null) {
-//            GameSession gameSession = gameSessions.get(playerId);
-//            if (gameSession != null) {
-//                gameSession.setKilled();
-//                gameSessions.remove(playerId);
-//                quitMatch(userId);
-//                userPlayerMap.remove(userId);
-//            }
-//        }
-//        GameWatcher gameWatcher = watchers.get(userId);
-//        if (gameWatcher != null) {
-//            gameWatcher.setKilled();
-//            watchers.remove(userId);
-//        }
-//    }
-
     public void quitMatch(UUID userId) {
         UUID playerId = getPlayerId(userId);
         if (playerId != null) {
-            GameSessionPlayer gameSession = gameSessions.get(playerId);
+            if (allJoined()) {
-            if (gameSession != null) {
+                GameSessionPlayer gameSession = gameSessions.get(playerId);
-                gameSession.quitGame();
+                if (gameSession != null) {
+                    gameSession.quitGame();
+                }
+            } else {
+                // The player did never join the game but the game controller was started because the player was still connected as the
+                // game was started. But the Client never called the join action. So now after the user is expired, the
+                // quit match is called and has to end the game, because the player never joined the game.
+                Player player = game.getPlayer(playerId);
+                if (player != null) {
+                    player.leave();
+                    checkStart(); // => So the game starts and gets an result or multiplayer game starts with active players
+                }
             }
         }
     }

Mage.Server/src/main/java/mage/server/game/GameSessionPlayer.java

@@ -320,7 +320,14 @@ public class GameSessionPlayer extends GameSessionWatcher {
                         @Override
                         public void run() {
                             try {
-                                player.quit(game);
+                                if (game.getStartTime() == null) {
+                                    // gameController is still waiting to start the game
+                                    player.leave();
+                                } else {
+                                    // game was already started
+                                    player.quit(game);
+                                }
+                                
                             } catch (Exception ex) {
                                 if (ex != null) {
                                     // It seems this can happen if two threads try to end the game at the exact same time (one wins and one ends here)

Mage.Server/src/main/java/mage/server/game/GameWorker.java

@@ -55,7 +55,7 @@ public class GameWorker implements Callable {
     @Override
     public Object call() {
         try {
-            logger.debug("GameWorker started gameId "+ game.getId());
+            logger.debug("GAME WORKER started gameId "+ game.getId());
             game.start(choosingPlayerId);
             game.fireUpdatePlayersEvent();
             gameController.gameResult(game.getWinner());

Mage/src/mage/game/GameImpl.java

@@ -668,7 +668,7 @@ public abstract class GameImpl implements Game, Serializable {
         }
         if (gameOver(null) && !isSimulation()) {
             winnerId = findWinnersAndLosers();
-            StringBuilder sb = new StringBuilder("GAME ended  gameId: ").append(this.getId()).append(" ");
+            StringBuilder sb = new StringBuilder("GAME END  gameId: ").append(this.getId()).append(" ");
             int count = 0;
             for (Player player: this.getState().getPlayers().values()) {
                 if (count > 0) {
@@ -789,6 +789,10 @@ public abstract class GameImpl implements Game, Serializable {
 
         saveState(false);
 
+        if (gameOver(null)) {
+            return;
+        }
+
         //20091005 - 103.1
         if (!gameOptions.skipInitShuffling) { //don't shuffle in test mode for card injection on top of player's libraries
             for (Player player: state.getPlayers().values()) {

Mage/src/mage/players/PlayerImpl.java

@@ -185,7 +185,6 @@ public abstract class PlayerImpl implements Player, Serializable {
     protected int priorityTimeLeft = Integer.MAX_VALUE;
 
 
-    //
     // conceded or connection lost game
     protected boolean left;
     // set if the player quits the complete match