diff --git a/services/git-bridge/src/main/java/uk/ac/ic/wlgitbridge/bridge/Bridge.java b/services/git-bridge/src/main/java/uk/ac/ic/wlgitbridge/bridge/Bridge.java index 64906a6b46..f07e622d80 100644 --- a/services/git-bridge/src/main/java/uk/ac/ic/wlgitbridge/bridge/Bridge.java +++ b/services/git-bridge/src/main/java/uk/ac/ic/wlgitbridge/bridge/Bridge.java @@ -451,6 +451,7 @@ public class Bridge { RawDirectory oldDirectoryContents, String hostname ) throws SnapshotPostException, IOException, MissingRepositoryException, ForbiddenException, GitUserException { + Log.debug("[{}] pushing to Overleaf", projectName); try (LockGuard __ = lock.lockGuard(projectName)) { pushCritical( oauth2, @@ -538,10 +539,11 @@ public class Bridge { if (maxFileNum.isPresent()) { long maxFileNum_ = maxFileNum.get(); if (directoryContents.getFileTable().size() > maxFileNum_) { + Log.debug("[{}] Too many files: {}/{}", projectName, directoryContents.getFileTable().size(), maxFileNum_); throw new FileLimitExceededException(directoryContents.getFileTable().size(), maxFileNum_); } } - Log.info("[{}] Pushing", projectName); + Log.info("[{}] Pushing files ({} new, {} old)", projectName, directoryContents.getFileTable().size(), oldDirectoryContents.getFileTable().size()); String postbackKey = postbackManager.makeKeyForProject(projectName); Log.info( "[{}] Created postback key: {}", diff --git a/services/git-bridge/src/main/java/uk/ac/ic/wlgitbridge/data/ProjectLockImpl.java b/services/git-bridge/src/main/java/uk/ac/ic/wlgitbridge/data/ProjectLockImpl.java index 34342ae1bf..ee6729e916 100644 --- a/services/git-bridge/src/main/java/uk/ac/ic/wlgitbridge/data/ProjectLockImpl.java +++ b/services/git-bridge/src/main/java/uk/ac/ic/wlgitbridge/data/ProjectLockImpl.java @@ -7,6 +7,7 @@ import java.util.Map; import java.util.concurrent.locks.Lock; import java.util.concurrent.locks.ReentrantLock; import java.util.concurrent.locks.ReentrantReadWriteLock; +import uk.ac.ic.wlgitbridge.util.Log; /** * Created by Winston on 20/11/14. @@ -35,29 +36,40 @@ public class ProjectLockImpl implements ProjectLock { @Override public void lockForProject(String projectName) { + Log.debug("[{}] taking project lock", projectName); getLockForProjectName(projectName).lock(); + Log.debug("[{}] taking reentrant lock", projectName); rlock.lock(); + Log.debug("[{}] taken locks", projectName); } @Override public void unlockForProject(String projectName) { + Log.debug("[{}] releasing project lock", projectName); getLockForProjectName(projectName).unlock(); + Log.debug("[{}] releasing reentrant lock", projectName); rlock.unlock(); + Log.debug("[{}] released locks", projectName); if (waiting) { + Log.debug("[{}] waiting for remaining threads", projectName); trySignal(); } } private void trySignal() { int threads = rwlock.getReadLockCount(); + Log.debug("-> waiting for {} threads", threads); if (waiter != null && threads > 0) { waiter.threadsRemaining(threads); } + Log.debug("-> finished waiting for threads"); } public void lockAll() { + Log.debug("-> locking all threads"); waiting = true; trySignal(); + Log.debug("-> locking reentrant write lock"); wlock.lock(); } diff --git a/services/git-bridge/src/main/java/uk/ac/ic/wlgitbridge/git/handler/hook/WriteLatexPutHook.java b/services/git-bridge/src/main/java/uk/ac/ic/wlgitbridge/git/handler/hook/WriteLatexPutHook.java index d5b8b8f1f4..a786e831b5 100644 --- a/services/git-bridge/src/main/java/uk/ac/ic/wlgitbridge/git/handler/hook/WriteLatexPutHook.java +++ b/services/git-bridge/src/main/java/uk/ac/ic/wlgitbridge/git/handler/hook/WriteLatexPutHook.java @@ -65,6 +65,7 @@ public class WriteLatexPutHook implements PreReceiveHook { ReceivePack receivePack, Collection receiveCommands ) { + Log.debug("-> Handling {} commands in {}", receiveCommands.size(), receivePack.getRepository().getDirectory().getAbsolutePath()); for (ReceiveCommand receiveCommand : receiveCommands) { try { handleReceiveCommand( @@ -73,17 +74,20 @@ public class WriteLatexPutHook implements PreReceiveHook { receiveCommand ); } catch (IOException e) { + Log.debug("IOException on pre receive: {}", e.getMessage()); receivePack.sendError(e.getMessage()); receiveCommand.setResult( Result.REJECTED_OTHER_REASON, e.getMessage() ); } catch (OutOfDateException e) { + Log.debug("OutOfDateException on pre receive: {}", e.getMessage()); receiveCommand.setResult(Result.REJECTED_NONFASTFORWARD); } catch (GitUserException e) { + Log.debug("GitUserException on pre receive: {}", e.getMessage()); handleSnapshotPostException(receivePack, receiveCommand, e); } catch (Throwable t) { - Log.warn("Throwable on pre receive: ", t); + Log.warn("Throwable on pre receive: {}", t.getMessage()); handleSnapshotPostException( receivePack, receiveCommand, @@ -91,6 +95,7 @@ public class WriteLatexPutHook implements PreReceiveHook { ); } } + Log.debug("-> Handled {} commands in {}", receiveCommands.size(), receivePack.getRepository().getDirectory().getAbsolutePath()); } private void handleSnapshotPostException( diff --git a/services/git-bridge/src/main/java/uk/ac/ic/wlgitbridge/util/Log.java b/services/git-bridge/src/main/java/uk/ac/ic/wlgitbridge/util/Log.java index f4306cf59f..31286ce90d 100644 --- a/services/git-bridge/src/main/java/uk/ac/ic/wlgitbridge/util/Log.java +++ b/services/git-bridge/src/main/java/uk/ac/ic/wlgitbridge/util/Log.java @@ -27,6 +27,10 @@ public class Log { logger.debug(msg, t); } + public static void debug(String format, Object... args) { + logger.info(format, args); + } + public static void info(String msg) { logger.info(msg); } diff --git a/services/git-bridge/src/main/resources/logback.xml b/services/git-bridge/src/main/resources/logback.xml index 6ac2904b63..1e39a822dc 100644 --- a/services/git-bridge/src/main/resources/logback.xml +++ b/services/git-bridge/src/main/resources/logback.xml @@ -22,10 +22,10 @@ - + - +