diff --git a/common/src/main/java/net/pcal/fastback/logging/SystemLogger.java b/common/src/main/java/net/pcal/fastback/logging/SystemLogger.java index 61541090..8fcc60c8 100644 --- a/common/src/main/java/net/pcal/fastback/logging/SystemLogger.java +++ b/common/src/main/java/net/pcal/fastback/logging/SystemLogger.java @@ -18,6 +18,8 @@ package net.pcal.fastback.logging; +import java.util.function.Supplier; + /** * Singleton logger instance that writes to the serverside console. * @@ -46,6 +48,10 @@ default void error(Throwable e) { void debug(String message); + default void trace(Supplier message) { + debug(message.get()); //FIXME + } + void debug(String message, Throwable t); default void debug(Throwable t) { diff --git a/common/src/main/java/net/pcal/fastback/repo/CommitUtils.java b/common/src/main/java/net/pcal/fastback/repo/CommitUtils.java index eb8ef31e..30df9adc 100644 --- a/common/src/main/java/net/pcal/fastback/repo/CommitUtils.java +++ b/common/src/main/java/net/pcal/fastback/repo/CommitUtils.java @@ -21,6 +21,7 @@ import net.pcal.fastback.config.GitConfig; import net.pcal.fastback.logging.UserLogger; import net.pcal.fastback.utils.EnvironmentUtils; +import net.pcal.fastback.utils.ProcessUtils.ExecException; import org.apache.commons.io.FileUtils; import org.eclipse.jgit.api.AddCommand; import org.eclipse.jgit.api.Git; @@ -61,7 +62,7 @@ */ abstract class CommitUtils { - public static SnapshotId doCommitSnapshot(final RepoImpl repo, final UserLogger ulog) throws IOException { + static SnapshotId doCommitSnapshot(final RepoImpl repo, final UserLogger ulog) throws IOException, ExecException { PreflightUtils.doPreflight(repo); final WorldId uuid = repo.getWorldId(); final GitConfig conf = repo.getConfig(); @@ -115,25 +116,31 @@ private static void doSettingsBackup(RepoImpl repo, UserLogger ulog) { } } - private static void native_commit(final String newBranchName, final Repo repo, final UserLogger log) throws IOException, InterruptedException { + private static void native_commit(final String newBranchName, final Repo repo, final UserLogger ulog) throws IOException, InterruptedException { syslog().debug("Start native_commit"); - log.update(styledLocalized("fastback.hud.local-saving", NATIVE_GIT)); + ulog.update(styledLocalized("fastback.hud.local-saving", NATIVE_GIT)); final File worktree = repo.getWorkTree(); final Map env = Map.of("GIT_LFS_FORCE_PROGRESS", "1"); - final Consumer outputConsumer = line -> log.update(styledRaw(line, NATIVE_GIT)); + final Consumer outputConsumer = line -> ulog.update(styledRaw(line, NATIVE_GIT)); String[] checkout = {"git", "-C", worktree.getAbsolutePath(), "checkout", "--orphan", newBranchName}; - doExec(checkout, env, outputConsumer, outputConsumer); - mod().setWorldSaveEnabled(false); try { - String[] add = {"git", "-C", worktree.getAbsolutePath(), "add", "-v", "."}; - doExec(add, env, outputConsumer, outputConsumer); - } finally { - mod().setWorldSaveEnabled(true); - syslog().debug("World save re-enabled."); - } - { - String[] commit = {"git", "-C", worktree.getAbsolutePath(), "commit", "-m", newBranchName}; - doExec(commit, env, outputConsumer, outputConsumer); + doExec(checkout, env, outputConsumer, outputConsumer); + mod().setWorldSaveEnabled(false); + try { + String[] add = {"git", "-C", worktree.getAbsolutePath(), "add", "-v", "."}; + doExec(add, env, outputConsumer, outputConsumer); + } finally { + mod().setWorldSaveEnabled(true); + syslog().debug("World save re-enabled."); + } + { + String[] commit = {"git", "-C", worktree.getAbsolutePath(), "commit", "-m", newBranchName}; + doExec(commit, env, outputConsumer, outputConsumer); + } + } catch (ExecException e) { + syslog().error(e); + e.report(ulog); + return; } syslog().debug("End native_commit"); } diff --git a/common/src/main/java/net/pcal/fastback/repo/PreflightUtils.java b/common/src/main/java/net/pcal/fastback/repo/PreflightUtils.java index f182eac4..657091a4 100644 --- a/common/src/main/java/net/pcal/fastback/repo/PreflightUtils.java +++ b/common/src/main/java/net/pcal/fastback/repo/PreflightUtils.java @@ -21,6 +21,7 @@ import net.pcal.fastback.config.GitConfig; import net.pcal.fastback.logging.SystemLogger; import net.pcal.fastback.utils.EnvironmentUtils; +import net.pcal.fastback.utils.ProcessUtils.ExecException; import org.eclipse.jgit.api.Git; import java.io.IOException; @@ -49,7 +50,7 @@ abstract class PreflightUtils { * Should be called prior to any heavy-lifting with git (e.g. commiting and pushing). Ensures that * key files are all set correctly. */ - static void doPreflight(RepoImpl repo) throws IOException { + static void doPreflight(RepoImpl repo) throws IOException, ExecException { final SystemLogger syslog = syslog(); syslog.debug("Doing world maintenance"); final Git jgit = repo.getJGit(); @@ -68,11 +69,7 @@ static void doPreflight(RepoImpl repo) throws IOException { writeResourceToFile("world/gitattributes-jgit", targetPath); } } - try { - updateNativeLfsInstallation(repo); - } catch (InterruptedException e) { - throw new IOException(e); - } + updateNativeLfsInstallation(repo); } // ====================================================================== @@ -81,14 +78,12 @@ static void doPreflight(RepoImpl repo) throws IOException { /** * Ensures that git-lfs is installed or uninstalled in the worktree as appropriate. */ - private static void updateNativeLfsInstallation(final Repo repo) throws IOException, InterruptedException { + private static void updateNativeLfsInstallation(final Repo repo) throws ExecException { if (EnvironmentUtils.isNativeGitInstalled()) { final boolean isNativeEnabled = repo.getConfig().getBoolean(IS_NATIVE_GIT_ENABLED); final String action = isNativeEnabled ? "install" : "uninstall"; final String[] cmd = {"git", "-C", repo.getWorkTree().getAbsolutePath(), "lfs", action, "--local"}; - doExec(cmd, Collections.emptyMap(), s -> { - }, s -> { - }); + doExec(cmd, Collections.emptyMap(), s -> {}, s -> {}); } } } diff --git a/common/src/main/java/net/pcal/fastback/repo/PushUtils.java b/common/src/main/java/net/pcal/fastback/repo/PushUtils.java index af566bbe..52ce42f3 100644 --- a/common/src/main/java/net/pcal/fastback/repo/PushUtils.java +++ b/common/src/main/java/net/pcal/fastback/repo/PushUtils.java @@ -21,6 +21,7 @@ import com.google.common.collect.ListMultimap; import net.pcal.fastback.config.GitConfig; import net.pcal.fastback.logging.UserLogger; +import net.pcal.fastback.utils.ProcessUtils.ExecException; import org.eclipse.jgit.api.Git; import org.eclipse.jgit.api.errors.GitAPIException; import org.eclipse.jgit.lib.ObjectId; @@ -71,7 +72,8 @@ static boolean isTempBranch(String branchName) { return branchName.startsWith("temp/"); } - static void doPush(SnapshotId sid, RepoImpl repo, UserLogger ulog) throws IOException { + // TODO stop throwing IOE + static void doPush(SnapshotId sid, RepoImpl repo, UserLogger ulog) throws IOException, ExecException { try { final GitConfig conf = repo.getConfig(); final String pushUrl = conf.getString(REMOTE_PUSH_URL); @@ -102,7 +104,6 @@ static void doPush(SnapshotId sid, RepoImpl repo, UserLogger ulog) throws IOExce syslog().debug("Pushing to " + pushUrl); PreflightUtils.doPreflight(repo); - if (conf.getBoolean(IS_NATIVE_GIT_ENABLED)) { native_doPush(repo, sid.getBranchName(), ulog); } else if (conf.getBoolean(IS_SMART_PUSH_ENABLED)) { @@ -112,12 +113,12 @@ static void doPush(SnapshotId sid, RepoImpl repo, UserLogger ulog) throws IOExce jgit_doPush(jgit, sid.getBranchName(), conf, ulog); } syslog().info("Remote backup complete."); - } catch (GitAPIException | InterruptedException e) { + } catch (GitAPIException e) { throw new IOException(e); } } - private static void native_doPush(final Repo repo, final String branchNameToPush, final UserLogger log) throws IOException, InterruptedException { + private static void native_doPush(final Repo repo, final String branchNameToPush, final UserLogger log) throws ExecException { syslog().debug("Start native_push"); log.update(styledLocalized("fastback.chat.push-started", NATIVE_GIT)); final File worktree = repo.getWorkTree(); @@ -131,16 +132,12 @@ private static void native_doPush(final Repo repo, final String branchNameToPush } - private static void jgit_doPush(final Git jgit, final String branchNameToPush, final GitConfig conf, final UserLogger ulog) throws IOException { + private static void jgit_doPush(final Git jgit, final String branchNameToPush, final GitConfig conf, final UserLogger ulog) throws GitAPIException { final ProgressMonitor pm = new JGitIncrementalProgressMonitor(new JGitPushProgressMonitor(ulog), 100); final String remoteName = conf.getString(REMOTE_NAME); syslog().info("Doing simple push of " + branchNameToPush); - try { - jgit.push().setProgressMonitor(pm).setRemote(remoteName). - setRefSpecs(new RefSpec(branchNameToPush + ":" + branchNameToPush)).call(); - } catch (GitAPIException e) { - throw new IOException(e); - } + jgit.push().setProgressMonitor(pm).setRemote(remoteName). + setRefSpecs(new RefSpec(branchNameToPush + ":" + branchNameToPush)).call(); } /** diff --git a/common/src/main/java/net/pcal/fastback/repo/ReclamationUtils.java b/common/src/main/java/net/pcal/fastback/repo/ReclamationUtils.java index fe465d9f..09d3e115 100644 --- a/common/src/main/java/net/pcal/fastback/repo/ReclamationUtils.java +++ b/common/src/main/java/net/pcal/fastback/repo/ReclamationUtils.java @@ -21,6 +21,7 @@ import net.pcal.fastback.config.GitConfig; import net.pcal.fastback.logging.UserLogger; import net.pcal.fastback.utils.FileUtils; +import net.pcal.fastback.utils.ProcessUtils.ExecException; import org.eclipse.jgit.api.errors.GitAPIException; import org.eclipse.jgit.internal.storage.file.FileRepository; import org.eclipse.jgit.internal.storage.file.GC; @@ -61,23 +62,19 @@ */ abstract class ReclamationUtils { - static void doReclamation(RepoImpl repo, UserLogger ulog) throws IOException { + static void doReclamation(RepoImpl repo, UserLogger ulog) throws GitAPIException, ExecException { if (repo.getConfig().getBoolean(IS_NATIVE_GIT_ENABLED)) { - try { - native_doLfsPrune(repo, ulog); - } catch (InterruptedException e) { - throw new IOException(e); - } + native_doLfsPrune(repo, ulog); } else { try { jgit_doGc(repo, ulog); - } catch (GitAPIException | ParseException e) { - throw new IOException(e); + } catch (ParseException | IOException e) { + throw new RuntimeException(e); } } } - private static void native_doLfsPrune(RepoImpl repo, UserLogger ulog) throws IOException, InterruptedException { + private static void native_doLfsPrune(RepoImpl repo, UserLogger ulog) throws ExecException { final File worktree = repo.getWorkTree(); final String[] push = {"git", "-C", worktree.getAbsolutePath(), "-c", "lfs.pruneoffsetdays=999999", "lfs", "prune", "--verbose", "--no-verify-remote",}; final Consumer outputConsumer = line->ulog.update(styledRaw(line, NATIVE_GIT)); @@ -89,7 +86,7 @@ private static void native_doLfsPrune(RepoImpl repo, UserLogger ulog) throws IOE * Runs git garbage collection. Aggressively deletes reflogs, tracking branches and stray temporary branches * in an attempt to free up objects and reclaim disk space. */ - private static void jgit_doGc(RepoImpl repo, UserLogger ulog) throws IOException, GitAPIException, ParseException { + private static void jgit_doGc(RepoImpl repo, UserLogger ulog) throws GitAPIException, ParseException, IOException { final File gitDir = repo.getJGit().getRepository().getDirectory(); final GitConfig config = repo.getConfig(); ulog.update(styledLocalized("fastback.hud.gc-percent", JGIT, 0)); diff --git a/common/src/main/java/net/pcal/fastback/repo/Repo.java b/common/src/main/java/net/pcal/fastback/repo/Repo.java index e349777a..99cb81cd 100644 --- a/common/src/main/java/net/pcal/fastback/repo/Repo.java +++ b/common/src/main/java/net/pcal/fastback/repo/Repo.java @@ -20,6 +20,7 @@ import net.pcal.fastback.config.GitConfig; import net.pcal.fastback.logging.UserLogger; +import net.pcal.fastback.utils.ProcessUtils.ExecException; import org.eclipse.jgit.api.errors.GitAPIException; import org.eclipse.jgit.errors.NoWorkTreeException; @@ -63,9 +64,9 @@ public interface Repo extends AutoCloseable { Collection doRemotePrune(UserLogger ulog) throws IOException; - void doGc(UserLogger ulog) throws IOException; + void doGc(UserLogger ulog); - void doPushSnapshot(SnapshotId sid, UserLogger ulog) throws IOException, ParseException; + void doPushSnapshot(SnapshotId sid, UserLogger ulog); Path doRestoreSnapshot(String uri, Path restoresDir, String worldName, SnapshotId sid, UserLogger ulog) throws IOException; diff --git a/common/src/main/java/net/pcal/fastback/repo/RepoImpl.java b/common/src/main/java/net/pcal/fastback/repo/RepoImpl.java index 71c64498..cb384221 100644 --- a/common/src/main/java/net/pcal/fastback/repo/RepoImpl.java +++ b/common/src/main/java/net/pcal/fastback/repo/RepoImpl.java @@ -24,6 +24,7 @@ import net.pcal.fastback.repo.SnapshotIdUtils.SnapshotIdCodec; import net.pcal.fastback.repo.WorldIdUtils.WorldIdInfo; import net.pcal.fastback.utils.EnvironmentUtils; +import net.pcal.fastback.utils.ProcessUtils.ExecException; import org.eclipse.jgit.api.Git; import org.eclipse.jgit.api.errors.GitAPIException; import org.eclipse.jgit.errors.NoWorkTreeException; @@ -97,6 +98,12 @@ public void doCommitAndPush(final UserLogger ulog) { try { newSid = CommitUtils.doCommitSnapshot(this, ulog); } catch(IOException ioe) { + syslog().error(ioe); + ulog.message(styledLocalized("fastback.chat.commit-failed", ERROR)); + return; + } catch (ExecException e) { + syslog().error(e); + e.report(ulog); ulog.message(styledLocalized("fastback.chat.commit-failed", ERROR)); return; } @@ -106,6 +113,11 @@ public void doCommitAndPush(final UserLogger ulog) { ulog.message(styledLocalized("fastback.chat.push-failed", ERROR)); syslog().error(ioe); return; + } catch(ExecException e) { + syslog().error(e); + e.report(ulog); + ulog.message(styledLocalized("fastback.chat.push-failed", ERROR)); + return; } ulog.message(localized("fastback.chat.backup-complete-elapsed", getDuration(start))); } @@ -123,12 +135,17 @@ public void doCommitSnapshot(final UserLogger ulog) { ulog.message(styledLocalized("fastback.chat.commit-failed", ERROR)); syslog().error(ioe); return; + } catch (ExecException e) { + e.report(ulog); + ulog.message(styledLocalized("fastback.chat.commit-failed", ERROR)); + syslog().error(e); + return; } ulog.message(localized("fastback.chat.backup-complete-elapsed", getDuration(start))); } @Override - public void doPushSnapshot(SnapshotId sid, final UserLogger ulog) throws IOException, ParseException { + public void doPushSnapshot(SnapshotId sid, final UserLogger ulog) { if (!this.getConfig().isSet(REMOTE_PUSH_URL)) { ulog.message(styledLocalized("No remote is configured. Run set-remote ", ERROR)); //FIXME i18n return; @@ -141,6 +158,11 @@ public void doPushSnapshot(SnapshotId sid, final UserLogger ulog) throws IOExcep ulog.message(styledLocalized("fastback.chat.commit-failed", ERROR)); syslog().error(ioe); return; + } catch(ExecException e) { + syslog().error(e); + e.report(ulog); + ulog.message(styledLocalized("fastback.chat.push-failed", ERROR)); + return; } ulog.message(UserMessage.localized("Successfully pushed " + sid.getShortName() + ". Time elapsed: "+getDuration(start))); // FIXME i18n } @@ -157,9 +179,18 @@ public Collection doRemotePrune(final UserLogger ulog) throws IOExce } @Override - public void doGc(final UserLogger ulog) throws IOException { + public void doGc(final UserLogger ulog) { if (!doNativeCheck(ulog)) return; - ReclamationUtils.doReclamation(this, ulog); + try { + ReclamationUtils.doReclamation(this, ulog); + } catch (GitAPIException e) { + ulog.message(styledLocalized("Command failed. Check log for details.", ERROR)); // FIXME i18n + syslog().error(e); + } catch (ExecException e) { + syslog().error(e); + e.report(ulog); + ulog.message(styledLocalized("Command failed. Check log for details.", ERROR)); // FIXME i18n + } } @Override diff --git a/common/src/main/java/net/pcal/fastback/utils/EnvironmentUtils.java b/common/src/main/java/net/pcal/fastback/utils/EnvironmentUtils.java index 8d5b2ce8..306f6c98 100644 --- a/common/src/main/java/net/pcal/fastback/utils/EnvironmentUtils.java +++ b/common/src/main/java/net/pcal/fastback/utils/EnvironmentUtils.java @@ -18,7 +18,8 @@ package net.pcal.fastback.utils; -import java.io.IOException; +import net.pcal.fastback.utils.ProcessUtils.ExecException; + import java.util.ArrayList; import java.util.Collections; import java.util.List; @@ -46,7 +47,7 @@ private static String execForVersion(String[] cmd) { try { exit = doExec(cmd, Collections.emptyMap(), stdout::add, line -> { }); - } catch (IOException | InterruptedException e) { + } catch (ExecException e) { syslog().debug("Could not run " + String.join(" ", cmd), e); return null; } diff --git a/common/src/main/java/net/pcal/fastback/utils/ProcessUtils.java b/common/src/main/java/net/pcal/fastback/utils/ProcessUtils.java index bc4f1008..7aeed975 100644 --- a/common/src/main/java/net/pcal/fastback/utils/ProcessUtils.java +++ b/common/src/main/java/net/pcal/fastback/utils/ProcessUtils.java @@ -18,6 +18,9 @@ package net.pcal.fastback.utils; +import net.pcal.fastback.logging.UserLogger; +import net.pcal.fastback.logging.UserMessage; + import java.io.IOException; import java.io.InputStreamReader; import java.io.Reader; @@ -38,17 +41,84 @@ */ public class ProcessUtils { - public static int doExec(String[] args, final Map envOriginal, Consumer stdoutSink, Consumer stderrSink) throws IOException, InterruptedException { + public static int doExec(String[] args, final Map envOriginal, Consumer stdoutSink, Consumer stderrSink) throws ExecException { + return doExec(args, envOriginal, stdoutSink, stderrSink, true); + } + + public static int doExec(final String[] args, final Map envOriginal, final Consumer stdoutSink, final Consumer stderrSink, boolean throwOnNonZero) throws ExecException { syslog().debug("Executing " + String.join(" ", args)); final Map env = new HashMap<>(envOriginal); env.putAll(System.getenv()); + // output a few values that are important for debugging; don't indiscriminately dump everything or someone's going + // to end up uploading a bunch of passwords into pastebin. + syslog().debug("PATH: " + env.get("PATH")); + syslog().debug("USER: " + env.get("USER")); + syslog().debug("HOME: " + env.get("HOME")); + final List stderrBuffer = new ArrayList<>(); + final Consumer stdout = line->{ + syslog().debug("[STDOUT] " + line); + stdoutSink.accept(line); + }; + final Consumer stderr = line->{ + syslog().debug("[STDERR] " + line); + stderrSink.accept(line); + stderrBuffer.add(line); + }; final List envlist = new ArrayList<>(); for (Map.Entry entry : env.entrySet()) { envlist.add(entry.getKey() + "=" + entry.getValue()); } final String[] enva = envlist.toArray(new String[0]); - final Process p = Runtime.getRuntime().exec(args, enva); - return drainAndWait(p, new LineWriter(stdoutSink), new LineWriter(stderrSink)); + final int exit; + try { + final Process p = Runtime.getRuntime().exec(args, enva); + exit = drainAndWait(p, new LineWriter(stdout), new LineWriter(stderr)); + } catch (IOException | InterruptedException e) { + throw new ExecException(args, 0, stderrBuffer, e); + } + if (exit != 0) { + throw new ExecException(args, exit, stderrBuffer); + } + return exit; + } + + public static class ExecException extends Exception { + private final String[] args; + private final List stderrLines; + private final int exitCode; + + ExecException(String[] args, final int exitCode, final List stdoutLines, Throwable nested) { + super("Failed to execute "+String.join(" ", args), nested); + this.args = requireNonNull(args); + this.exitCode = exitCode; + this.stderrLines = requireNonNull(stdoutLines); + } + + ExecException(String[] args, final int exitCode, final List stdoutLines) { + super("Failed to execute "+String.join(" ", args)); + this.args = requireNonNull(args); + this.exitCode = exitCode; + this.stderrLines = requireNonNull(stdoutLines); + } + + public List getStderrLines() { + return this.stderrLines; + } + + public int getExitCode() { + return this.exitCode; + } + + public String getCommand() { + return String.join(" ", this.args); + } + + public void report(UserLogger ulog) { + ulog.message(UserMessage.raw("Failed to execute a command. See log for details.")); + for(String line : this.stderrLines) { + ulog.message(UserMessage.raw(line)); + } + } } private static class LineWriter extends Writer {