[#1030] Keep the setup log out of the way of start-ds, and say when it is gone - #1032
Conversation
maximthomas
left a comment
There was a problem hiding this comment.
praise: The fix sits where the bug is, and each failure road of the report has its own arm.
start-ds:83/start-ds.bat:67sweep onlybc-fips-jni_*, the directories #576 introduced the sweep for; the comment says why nothing else intmp/is the script's to remove.SetupLauncher.instanceLogsDirectory():90-97puts the setup log next toserver.out, where a failed start's two halves can be read together.Installer.notifyListenersOfExistingLogFile():617-644reports a missing log (INFO_GENERAL_LOG_IN_ERROR_MISSING) and an unreadable one (INFO_GENERAL_LOG_IN_ERROR_UNREADABLE) through the listeners;printStackTrace()is gone.
issue (blocking): Every setup exit that attempts no install leaves an opendj-setup-*.log in <instance>/logs for good.
opendj-server-legacy/src/main/java/org/opends/quicksetup/installer/SetupLauncher.java:71, :123-160; opendj-server-legacy/src/main/java/org/opends/server/tools/InstallDS.java:308-342; opendj-server-legacy/src/main/java/org/opends/quicksetup/installer/Installer.java:308
SetupLauncher(String[]):71 creates the log through super(args, LOG_FILE_PREFIX, instanceLogsDirectory()) — TempLogFile.newTempLogFile(prefix, dir):79-80 creates <instance>/logs and the file, and the constructor writes the "QuickSetup application launched" line — before initializeParser():76 and before launch():119 parses anything. launch() then leaves through System.exit at :125 (--version), :131 (--help, usage displayed), :155 (ArgumentException) and :160 (IncompatibleVersionException), and InstallDS.mainCLI returns before installer.run():367 at :308, :313, :323, :328 and :342 (argument error, usage, already installed, licence refused, cancel / user-data error). None of them touches tempLogFile; the only caller of deleteLogFileAfterSuccess() in main code is Installer.java:308, the FINISHED_SUCCESSFULLY road. At the base the same file landed under java.io.tmpdir = <instance>/tmp and the next start-ds swept it; this PR moves it into the operator-facing logs/ directory and removes the sweep, so ./setup --help on an installed package now leaves logs/opendj-setup-<n>.log, one line long, one per invocation, forever. On a split-instance layout (instance.loc naming a directory not yet created) it also materialises the instance root and logs/ as the invoking user. "Plain successful setup … no opendj-setup-*.log left in logs/" holds for the success road only.
Is keeping the log after a CANCELED install (Installer.run():313-316) intended, as the log of a real attempt? That road is arguable; the --help / --version / argument-error roads attempt nothing.
// SetupLauncher.java — System.exit runs no finally, so each exit discards the log itself
private void exit(final int returnCode)
{
tempLogFile.deleteLogFileAfterSuccess();
System.exit(returnCode);
}
// :125 exit(ReturnCode.PRINT_VERSION.getReturnCode());
// :131 exit(ReturnCode.SUCCESSFUL.getReturnCode());
// :155 exit(ReturnCode.USER_DATA_ERROR.getReturnCode());
// :160 exit(ReturnCode.JAVA_VERSION_INCOMPATIBLE.getReturnCode());
// InstallDS.mainCLI: tempLogFile.deleteLogFileAfterSuccess() before each return at :308, :313, :323, :328, :342Or: create the log lazily, on the first road that can fail an install — that closes every exit at once and also stops setup --help from creating <instance>/logs on a split-instance layout.
issue (non-blocking): The three arms of Installer.notifyListenersOfExistingLogFile are pinned by no test.
opendj-server-legacy/src/main/java/org/opends/quicksetup/installer/Installer.java:619-643
The only caller is handleInstallationError():383, reached only when setup fails; no test names the method or either new message, and the one automated setup run (TestUtilities.setupServer) throws on a non-zero exit, so in a green suite the failure road runs zero times. The "say when it is gone" half of the title is verified by the manual macOS run only. Mutant, traced: !tempLogFile.isReadable() → !tempLogFile.isEnabled() (dead after the :619 guard) puts a removed log back on the readContents() road — the MISSING arm is dead, the #1030 symptom is back as an UNREADABLE report — and every cell stays green; deleting the MISSING arm outright survives the same way.
// Installer.java — the decision without the listeners, package-private for the test
static LocalizableMessage describeLogFile(final TempLogFile log)
{
if (!log.isReadable())
{
return INFO_GENERAL_LOG_IN_ERROR_MISSING.get(log.getPath());
}
try
{
return LocalizableMessage.raw(log.readContents());
}
catch (final IOException e)
{
return INFO_GENERAL_LOG_IN_ERROR_UNREADABLE.get(log.getPath(), e);
}
}Pin: three cases in TempLogFileTest — a fresh log (its contents come back), a deleted log (INFO_GENERAL_LOG_IN_ERROR_MISSING), a directory at the log path or a log whose readContents() throws (INFO_GENERAL_LOG_IN_ERROR_UNREADABLE); the isEnabled() mutant above goes red on the deleted-log case.
issue (non-blocking): testIsReadableFollowsTheFileNotTheLogger deletes the log while the TempLogFile's FileOutputStream still holds it; red on Windows.
opendj-server-legacy/src/test/java/org/opends/quicksetup/TempLogFileTest.java:113; opendj-server-legacy/src/main/java/org/opends/quicksetup/TempLogFile.java:118
The writer opened at :118 (new TextWriter.STREAM(new FileOutputStream(file)) — OPENDJ_LOG_TO_STDOUT is set nowhere in the poms, src/test or .github) is shut only by deleteLogFileAfterSuccess() in @AfterClass. java.io opens without FILE_SHARE_DELETE on Windows, so File.delete() returns false there and assertTrue fails; CI does not see it (failsafe runs on the Linux cells only), a Windows developer box does. Not run: no Windows box here.
logFile.deleteLogFileAfterSuccess(); // shuts the writer, then deletes
assertFalse(logFile.getLogFile().exists());
assertTrue(logFile.isEnabled());
assertFalse(logFile.isReadable());tearDown's second deleteLogFileAfterSuccess() is idempotent (PrintWriter.close, FileOutputStream.close, a false delete() ignored).
issue (non-blocking): testReadContentsReturnsWhatIsInTheFile appends the marker through a second channel while the log's non-append stream is still open.
opendj-server-legacy/src/test/java/org/opends/quicksetup/TempLogFileTest.java:101; opendj-server-legacy/src/main/java/org/opends/quicksetup/TempLogFile.java:118
The stream at :118 is opened without append and sits at the end of its own bytes; Files.write(..., APPEND) moves the file's end, not the stream's offset. Any NOTICE+ record reaching ErrorLogger between :101 and :103 is println'd over the marker and endsWith fails (reproduced with a three-line program: true before the extra record, false after). DirectoryServerTestCase stops the in-core server only at @AfterSuite, so a server thread from an earlier class can log in that window; <parallel>none</parallel> rules out a second test thread, not that one. Rate not measured.
logFile.writer.shutdown(); // package-private field, same package
Files.write(logFile.getLogFile().toPath(), (marker + "\n").getBytes(UTF_8), APPEND);Or: new FileOutputStream(file, true) at TempLogFile.java:118 — append mode makes the fixture sound and changes nothing for setup.
issue (non-blocking): setup --help on a split-instance layout materialises the instance root and logs/ as the invoking user.
opendj-server-legacy/src/main/java/org/opends/quicksetup/TempLogFile.java:79; opendj-server-legacy/src/main/java/org/opends/quicksetup/installer/SetupLauncher.java:97
instanceLogsDirectory() takes the instance.loc path whether or not it exists and Files.createDirectories() creates it — and logs/ — in the constructor, before any argument is parsed. At the base a missing instance root made the script's tmp/ and createTempFile fail and nothing was left on disk. Run as root before the real setup runs as the service user, a root-owned instance root stays behind (the chain past copyTemplateInstance was not traced). Docker's run.sh creates the instance root first, so this is the package / instance.loc layout only. The lazy-creation shape of the blocking fix closes this too; a delete-before-exit fix does not.
suggestion (non-blocking): Each TempLogFile the test builds leaves a startup ErrorLogPublisher on the ErrorLogger singleton for the rest of the JVM.
opendj-server-legacy/src/main/java/org/opends/quicksetup/TempLogFile.java:120-121, :138-147; opendj-server-legacy/src/test/java/org/opends/quicksetup/TempLogFileTest.java:62-65
The constructor registers TextErrorLogPublisher over the writer; deleteLogFileAfterSuccess() shuts the writer and deletes the file but never removes the publisher, and tearDown calls only that. The next removeAllLogPublishers() is DirectoryServer.shutDown():4347. Every NOTICE+ record of every later class in the failsafe JVM is println'd to five closed PrintWriters; swallowed, so nothing goes red — fixture hygiene, not a flake.
private final ErrorLogPublisher startupErrorLogPublisher; // kept from the constructor
public void deleteLogFileAfterSuccess()
{
if (isEnabled())
{
ErrorLogger.getInstance().removeLogPublisher(startupErrorLogPublisher);
writer.shutdown();
logFile.delete();
}
}suggestion (non-blocking): The fallback warning at TempLogFile.java:84 reaches no publisher.
opendj-server-legacy/src/main/java/org/opends/quicksetup/TempLogFile.java:84-85
localizedLogger.warn(...) runs before the constructor at :120-121 installs the first publisher; ErrorLogger.isEnabledFor iterates an empty list and the adapter has no console fallback. An unwritable <instance>/logs moves the setup log to tmp/ silently; the operator learns the location from the failure-road path line, never why it is there.
catch (final IOException e)
{
fallbackReason = e; // warn after the fallback log exists, see below
}
...
final TempLogFile log = new TempLogFile(Files.createTempFile(prefix, ".log").toFile());
if (fallbackReason != null)
{
localizedLogger.warn(LocalizableMessage.raw("Unable to create temp log file in " + directory
+ " because: " + fallbackReason.getMessage() + ", falling back to the temporary directory"), fallbackReason);
}
return log;Or: one System.err.println for the operator.
suggestion (non-blocking): readContents() decodes UTF-8 while TextWriter.STREAM writes in the platform default charset.
opendj-server-legacy/src/main/java/org/opends/quicksetup/TempLogFile.java:185; opendj-server-legacy/src/main/java/org/opends/server/loggers/TextWriter.java:125
Pre-existing — the base Installer decoded the same file with "UTF-8"; the PR moved the decode. Windows with Java 11 or 17 (both in the matrix) and a Cp1252/Cp1251 default: the DateFormat.LONG line, a non-ASCII path or base DN come back as U+FFFD in the dumped report; the file itself is intact. JEP 400 covers 18+ only; no -Dfile.encoding in the poms or the launcher scripts. Writer and reader run in the same JVM, so match them either way.
// TempLogFile.java:185 — the charset TextWriter.STREAM:125 wrote with; javadoc "decoded as UTF-8" changes to match
return new String(Files.readAllBytes(logFile.toPath()), Charset.defaultCharset());Or: a TextWriter.STREAM constructor taking a charset, UTF-8 on both sides.
suggestion (non-blocking): rmdir "%%i" at start-ds.bat:67 depends on cmd handing %%i back without the set element's quotes.
opendj-server-legacy/resource/bin/start-ds.bat:67
for /D %%i in ("%OPENDJ_TMP_DIR%\bc-fips-jni_*") do rmdir "%%i" /s/q>NUL 2>&1. Under the documented cmd rule a set element with a wildcard is replaced by its bare matches (quotes are kept only for a wildcard-free element), so the line reads as right; if the quotes came back, rmdir ""C:\a b\..."" /s/q would split at the space and the redirect would hide it — the sweep would remove nothing on a space-containing install path. Not run: no cmd.exe on this box, and the CI Windows path has no space and no step lists tmp\.
for /D %%i in ("%OPENDJ_TMP_DIR%\bc-fips-jni_*") do rmdir "%%~i" /s/q>NUL 2>&1suggestion (non-blocking): isReadable()'s Files.isRegularFile conjunct is unpinned; either predicate alone keeps TempLogFileTest green.
opendj-server-legacy/src/main/java/org/opends/quicksetup/TempLogFile.java:169; opendj-server-legacy/src/test/java/org/opends/quicksetup/TempLogFileTest.java:90, :111, :116, :147
The four isReadable() calls see both predicates agree — a fresh regular file, or a just-deleted path — so dropping Files.isReadable(...) or dropping Files.isRegularFile(...) survives, and a regression to logFile.exists() passes; only dropping both is killed at :116. Traced, not run.
// after the delete (with the writer shut, see above)
assertTrue(logFile.getLogFile().mkdir()); // readable, not a regular file
assertFalse(logFile.isReadable());Pin: the isRegularFile mutant goes red; the isReadable arm has no pin under root and is left alone.
suggestion (non-blocking): The narrowed tmp/ sweep has no CI observable.
opendj-server-legacy/resource/bin/start-ds:83; opendj-server-legacy/resource/bin/start-ds.bat:67; .github/workflows/build.yml:239-260
"Test on Unix FIPS" runs bin/start-ds twice and never lists tmp/; the non-FIPS, docker and deb/rpm steps probe LDAP only; nothing under src/test names start-ds, bc-fips-jni or the instance tmp dir. Restoring rm -rf ${OPENDJ_TMP_DIR}/* or misspelling the pattern passes every cell; the "bc-fips-jni_123 removed, opendj-replication-*.log kept" check exists only in the manual run.
# before the first bin/start-ds of the FIPS step
- run: mkdir -p opendj/tmp/bc-fips-jni_123 && touch opendj/tmp/keep.me
# after it
- run: test ! -e opendj/tmp/bc-fips-jni_123 && test -e opendj/tmp/keep.mePin: the same two lines in the "Test on Windows" step pin start-ds.bat:67 and settle the quoting question above for the CI path.
|
Round 2. All eleven points taken; three of them reach a little further than the report says, and the question about issue (blocking) — every setup exit that attempts no install leaves a logTaken, and closed the lazy way you suggest, since a delete before each exit would leave the directory behind and one more
Two things the report did not name, both closed by the same change:
On Pinned by issue (non-blocking) — the three arms of
|
maximthomas
left a comment
There was a problem hiding this comment.
praise: Round 1's Major is closed on the CLI road, and the closure is pinned where it was measured.
Launcher.getTempLogFile():97-101is lazy andInstallDS.mainCLI(String[], OutputStream, OutputStream, Supplier<TempLogFile>)resolves it atInstallDS.java:383, after the eight pre-install returns;LauncherTest.testBuildingALauncherLeavesNothingOnDiskkills the constructor mutant.InstallerTestdrives the three arms ofInstaller.notifyListenersOfExistingLogFiledirectly (:74,:88,:104,:122) — the shape round 1 asked for — and theisReadable()→isEnabled()mutant is measured red.- The
build.ymlprobes (:244-254,:406-413:bc-fips-jni_123gone,keep.mekept, on both shells) give the narrowed sweep the CI observable it lacked; withrmdir "%%~i"atstart-ds.bat:69the cmd quoting question is moot, and the green windows cells at this head close it.
issue (blocking): The GUI road creates the setup log at the splash, and every GUI exit that installs nothing leaves <instance>/logs/opendj-setup-*.log behind for good.
opendj-server-legacy/src/main/java/org/opends/quicksetup/Launcher.java:249, opendj-server-legacy/src/main/java/org/opends/quicksetup/installer/Installer.java:829-849, opendj-server-legacy/src/main/java/org/opends/quicksetup/ui/QuickSetup.java:456-460
./setup without --cli (resource/setup adds no flag; Launcher.isCli():192 looks for it only) reaches launchGui(), whose thread body is SplashScreen.main(getTempLogFile(), args). The argument is evaluated before main is entered, so getTempLogFile() creates logs/ and the log before the wizard exists; SplashScreen.main:68-72 only stores it and QuickSetup.initialize:108 hands it to the Installer. Every exit that installs nothing — quitClicked(): installStatus.isInstalled() ("Server Already Configured"), javaVersionCheckFailed, a confirmed Quit at any wizard step — ends in QuickSetup.quit(): flushLogs(); System.exit(0). The only deletes at this head are Installer.run():308 (success) and :320 (CANCELED, raised by ProgressPanel after the install started). On a headless box the same road creates the file, new SplashScreen() throws, guiLaunchFailed() names it, and mainCLI's early returns (already installed, licence refused, cancel at the prompt) keep it. At BASE the same leftover sat in tmp/ and the next start-ds swept it; this PR removes that sweep. Description item 3 ("already installed", "a cancel at the prompt" leave neither the file nor the directory) holds for --cli only. Not run: needs a display; the road is unconditional.
The fix is the shape the CLI road already has — hand the supplier through, resolve it where the install begins:
// Launcher.launchGui()
SplashScreen.main(this::getTempLogFile, args);
// SplashScreen
public static void main(final Supplier<TempLogFile> tempLogFile, String[] args)
// :199 — getMethod("initialize", Supplier.class, String[].class)
// QuickSetup
public void initialize(final Supplier<TempLogFile> tempLogFile, String[] args)
// :108 — application.setTempLogFile(tempLogFile);
// Application
protected Supplier<TempLogFile> tempLogFileSupplier;
public void setTempLogFile(final Supplier<TempLogFile> tempLogFile) { this.tempLogFileSupplier = tempLogFile; }
// Installer.run(), first statement — the first point where an install can fail
tempLogFile = tempLogFileSupplier.get();Or: tempLogFile.deleteLogFileAfterSuccess() before each qs.quit() in quitClicked() except at FINISHED — closes the wizard exits, not the headless fallback, whose file is created at the splash and kept by mainCLI's early returns.
Pin: a LauncherTest case whose launchGui() override records whether getTempLogFile() ran before SplashScreen.main — or, with the supplier shape, a counting supplier asserted never called when the override quits at once.
issue (non-blocking): The InstallDS half of the lazy log — tempLogFile.get() at the installer build, after the eight pre-install returns — is pinned by no test.
opendj-server-legacy/src/main/java/org/opends/server/tools/InstallDS.java:383, :305-376
No test drives InstallDS.mainCLI(String[], OutputStream, OutputStream, Supplier<TempLogFile>) (git grep 'InstallDS\b\|mainCLI' over src/test at this head hits ReplicationCliMain/StatusCli only). A mutant that hoists tempLogFile.get() into the constructor (:227) or to the head of execute() (:305) brings the leftover back on the already-installed, refused-licence and cancel roads — the roads item 3 names — and every test in the PR stays green. testBuildingALauncherLeavesNothingOnDisk pins the Launcher half only. Deferred; take it or leave it.
@Test
public void testARunThatInstallsNothingAsksForNoLog() throws Exception
{
AtomicInteger asked = new AtomicInteger();
int rc = InstallDS.mainCLI(new String[] { "--help" }, null, null, () -> { asked.incrementAndGet(); return null; });
assertEquals(rc, InstallReturnCode.SUCCESSFUL_NOP.getReturnCode());
assertEquals(asked.get(), 0);
}Pin: the same with "--no-such-option" expects ERROR_USER_DATA and asked == 0; either kills both hoist mutants. Not run here whether mainCLI with --help needs anything of the failsafe JVM beyond the argument parser — the road returns at :342 before checkInstallStatus().
suggestion (non-blocking): The CANCELED-road delete at Installer.run():320 is pinned by no test.
opendj-server-legacy/src/main/java/org/opends/quicksetup/installer/Installer.java:313-320
CANCELED is raised by checkAbort():2416 on the canceled flag, set by cancel():825, whose only non-test caller is ui/ProgressPanel.java:229; the only Installer built in src/test is InstallerTest.reportOf():140, which never calls run(). Deleting :320, or moving it above uninstall(), changes no test outcome. The delete is placed right; the pin is not a one-liner, so this is for your discretion.
// shape: an Installer over a UserData whose server location is a temp dir
installer.setTempLogFile(logFile);
installer.cancel();
installer.run(); // checkAbort() at :252 throws CANCELED before anything is written
assertFalse(logFile.getLogFile().exists());suggestion (non-blocking): The deferred fallback warning at TempLogFile.newTempLogFile:93-98 is pinned by no test.
opendj-server-legacy/src/test/java/org/opends/quicksetup/TempLogFileTest.java:157-169
testUnusableDirectoryFallsBackToTheTemporaryDirectory asserts isEnabled(), isReadable() and the parent directory only. Deleting the if (fallbackReason != null) block, or moving the warn back into the catch (the round-1 shape, where it reached no publisher), leaves 6/6 green. The warn lands in the fallback file itself: the startup publisher (TextErrorLogPublisher:88-93, ERROR/WARNING/NOTICE) is on ErrorLogger by :95.
// end of testUnusableDirectoryFallsBackToTheTemporaryDirectory — the shutdown-then-read shape of :98-105
logFile.writer.shutdown();
assertTrue(logFile.readContents().contains("falling back to the temporary directory"));suggestion (non-blocking): The publisher removal in deleteLogFileAfterSuccess() is pinned by no test.
opendj-server-legacy/src/main/java/org/opends/quicksetup/TempLogFile.java:162-167, opendj-server-legacy/src/test/java/org/opends/quicksetup/TempLogFileTest.java:112-125
Dropping both removeLogPublisher calls is exactly BASE, and 12/12 stay green: a leaked publisher writes to a shut PrintWriter, which sets its error flag and never throws. testIsReadableFollowsTheFileNotTheLogger asserts the file half only.
int before = ErrorLogger.getInstance().getLogPublishers().size();
TempLogFile logFile = newLogFile();
logFile.deleteLogFileAfterSuccess();
assertEquals(ErrorLogger.getInstance().getLogPublishers().size(), before);suggestion (non-blocking): InstallerTest's plain-text formatter cannot tell the warning arm from the progress arm.
opendj-server-legacy/src/test/java/org/opends/quicksetup/installer/InstallerTest.java:141, :161, :166
PlainTextProgressMessageFormatter.getFormattedWarning(text, false) (:60-66) and getFormattedProgress (:127-130) both return text unchanged, and the four asserts are report.contains(expected.toString()). Swapping getFormattedWarning for getFormattedProgress at Installer.java:633/:646 keeps 4/4 green; only the GUI's HTML formatter distinguishes them. Presentation only — a formatter stub that wraps warnings as "[W]" + text and progress as "[P]" + text pins the arm per line, or leave it.
suggestion (non-blocking): testAReadableLogIsHandedOver turns red in a shell that exports OPENDJ_LOG_TO_STDOUT=true.
opendj-server-legacy/src/test/java/org/opends/quicksetup/installer/InstallerTest.java:82, opendj-server-legacy/src/main/java/org/opends/quicksetup/TempLogFile.java:129-133
With the variable set, TempLogFile(File) takes TextWriter.STDOUT; the file from createTempFile exists and stays empty, readContents() returns "", and :82 fails on "QuickSetup application launched". CI does not set it (green at this head), so it bites a developer box or a container-derived shell only; TextWriter.STDOUT.shutdown() is empty, so tearDown does not close System.out. Write the marker through logFile.writer and assert on that (as testReadContentsReturnsWhatIsInTheFile does), or throw new SkipException(...) when the variable is set.
question (non-blocking): Is the unbounded accumulation of failed-run logs of the other tools in <instance>/tmp the intended cost of the narrowed sweep?
opendj-server-legacy/resource/bin/start-ds:76-83
_script-util.sh:140-145 points java.io.tmpdir of every tool at <instance>/tmp; ReplicationCliMain.mainCLI:368-380 and StatusCli:176-180 create opendj-replication-*.log / opendj-status-*.log there and delete only on return code 0. BASE's rm -rf tmp/* swept them at the next start; the narrowed line does not, and nothing else in resource/bin does — a monitoring cron running status against a server that is down leaves one file per failed run. The comment at :76-80 states the narrowing as intended and the blanket wipe was the bug, so this is recorded, not required. If wanted: find "$OPENDJ_TMP_DIR" -name 'opendj-*.log' -mtime +7 -delete next to the sweep, or a sentence in the comment handing these logs to the operator.
…t-ds, and say when it is gone Since OpenIdentityPlatform#576 the launcher scripts put java.io.tmpdir at <instance>/tmp and start-ds sweeps that directory clean before starting the server. Setup starts the server through start-ds, so its own log went with the sweep on every run; a start that failed afterwards named a file that was no longer there and printed a NoSuchFileException stack instead of the log. - start-ds / start-ds.bat: remove only the bc-fips-jni_* directories the BC FIPS native loader extracts on every start, which is what the sweep was introduced for; other files in tmp belong to tools that may still be running. - TempLogFile can be placed in a directory of the caller's choosing; SetupLauncher puts the setup log under <instance>/logs, next to server.out, falling back to the temporary directory when the launcher does not run from an installation or the directory cannot be used. - Installer checks that the log is readable before promising it, and reports a missing or unreadable log to the listeners instead of printStackTrace(). - build.yml: on a failed test step, print logs/server.out and logs/errors of the instances left behind - the server-side reason of a failed start is nowhere else. Fixes OpenIdentityPlatform#1030
…l is at stake Round 2 of the review. The log was built in the launcher constructor, before any argument was parsed, and only a successful install removed it, so --help, --version, a usage error, "already installed", a refused licence and a cancel each left an opendj-setup-*.log - and, on a package not yet set up, the logs/ directory itself - behind for good. Launcher now creates it on the first road that can fail an operation: SetupLauncher hands InstallDS a Supplier<TempLogFile> called where the installer is built, hasTempLogFile() answers whether there is a log to name without making one, and a cancelled install deletes the log that road never names. Also from the review: the error and debug publishers installed with the log are taken off the logger singletons when it is deleted; the fallback warning is logged once there is a log to carry it; readContents() decodes with the charset TextWriter.STREAM wrote with; start-ds.bat uses %%~i; InstallerTest pins the arms of the failure report and LauncherTest pins when the log is created; TempLogFileTest removes the log through deleteLogFileAfterSuccess() (Windows will not delete an open file) and shuts the writer before appending its marker; the FIPS and Windows CI steps check that the tmp/ sweep takes the bc-fips-jni_* directories and nothing else.
…gins, not where the wizard opens Round 3 of the review. The lazy log of round 2 closed the CLI road only. On the GUI road getTempLogFile() was evaluated as the argument of SplashScreen.main, so the log - and the instance logs/ directory - was created before the wizard existed, and every exit that installs nothing (a quit at any step, "Server Already Configured", the failed java version check, the headless fallback) kept it for good. Launcher now hands the splash screen a Supplier<TempLogFile>, which SplashScreen, QuickSetup.initialize and Application pass on untouched, and Installer.run() resolves it as its first statement - the first point where an install can fail. InstallDS hands the installer the same supplier instead of the file. The reason a GUI launch failed is kept in the launcher and written to the log as soon as something asks for one, so nothing is created to hold it, and Launcher.launch()'s fallback from the GUI to the command line asks for the log itself, since the operation runs there. Also from the review: InstallDSTest pins that a run which installs nothing never asks for a log; InstallerTest pins the cancel road, marks the arm each line of the report goes out on and pins the contents of the log through a mock, so OPENDJ_LOG_TO_STDOUT cannot empty it; TempLogFileTest pins the deferred fallback warning and that the log's publisher comes off the error logger; the tmp/ sweep comment hands the logs of the other tools to the operator.
81cdd36 to
03a03d3
Compare
|
Round 3. All seven points taken; two of them reach further than the report says, and one is issue (blocking) — the GUI road creates the log at the splash screenTaken, in the shape you propose: the supplier is handed through and resolved where the install
Two things the report did not name, both of which the lazy log opened and which are closed here:
On the GUI uninstall: Pin: issue (non-blocking) — the InstallDS half is pinned by no testTaken. Your hoist mutant ( suggestion (non-blocking) — the CANCELED-road delete is pinned by no testTaken. Dropping the delete at suggestion (non-blocking) — the deferred fallback warning is pinned by no testTaken: The case skips itself when suggestion (non-blocking) — the publisher removal is pinned by no testTaken: The debug publisher has no pin: suggestion (non-blocking) — the plain-text formatter cannot tell the arms apartTaken: suggestion (non-blocking) —
|
maximthomas
left a comment
There was a problem hiding this comment.
praise: The setup log is now created where the install begins, and every round-2 item is taken.
Launcher.launchGuihands the splashLauncher.this::getTempLogFile(Launcher.java:276), andInstaller.run()resolves it in its first statement (Installer.java:248). A wizard quit at any step, "Server Already Configured" and the headless fallback no longer leaveopendj-setup-*.logor<instance>/logsbehind.- A GUI launch failure is kept in
guiLaunchFailureand written bylogGuiLaunchFailure()once a log exists (Launcher.java:103), so the failure alone creates nothing. InstallDSTest,InstallerTest.testACancelledInstallTakesItsLogWithIt,TempLogFileTest:162/:189and the arm-marking formatter close the round-2 test gaps.
issue (blocking): The uninstall wizard no longer creates any log: only Installer.run() resolves the supplier that QuickSetup now hands to every Application.
opendj-server-legacy/src/main/java/org/opends/quicksetup/ui/QuickSetup.java:111, opendj-server-legacy/src/main/java/org/opends/quicksetup/Application.java:719-739, opendj-server-legacy/src/main/java/org/opends/guitools/uninstaller/Uninstaller.java:698
QuickSetup.initialize calls setTempLogFile(Supplier), which leaves tempLogFile null. The only resolver, openTempLogFile(), has one caller: Installer.java:248. On a GUI uninstall, org.opends.quicksetup.Application.class names Uninstaller. Uninstaller.run() never resolves the supplier, and nothing else on that road calls getTempLogFile(). As a result, no ErrorLogger publisher is ever installed, and logger.error("Error: " + ex, ex) at :740/:746 is discarded. At BASE the log was created in the Launcher constructor, and at 81cdd36 at the splash argument. Both left /tmp/opendj-uninstall-*.log holding the stack trace. Now a failed GUI uninstall leaves no record anywhere. The resolver must be null-safe: the CLI road's new Uninstaller() (UninstallLauncher.java:151) is never given a supplier, so a bare tempLogFileSupplier.get() would throw an NPE there. The CLI road keeps its log from Launcher.launch(), :428.
// Application
protected TempLogFile openTempLogFile()
{
if (tempLogFile == null && tempLogFileSupplier != null)
{
tempLogFile = tempLogFileSupplier.get();
}
return tempLogFile;
}
// Uninstaller
@Override
public void run() {
// The uninstall begins here, as the install begins in Installer.run() (issue #1030).
openTempLogFile();
status = STARTED;
logger.info(LocalizableMessage.raw("run of the Uninstaller started"));issue (non-blocking): The *_GUI_LAUNCHED_FAILED_DETAILS arm is dead in both launchers, because guiLaunchFailed() always runs before any log exists.
opendj-server-legacy/src/main/java/org/opends/quicksetup/Launcher.java:437-440, opendj-server-legacy/src/main/java/org/opends/quicksetup/installer/SetupLauncher.java:151, :177, opendj-server-legacy/src/main/java/org/opends/guitools/uninstaller/UninstallLauncher.java:133
When the GUI does not come up, launchGui only stores the throwable (Launcher.java:285). Launcher.launch() then calls guiLaunchFailed() at :437, three lines before getTempLogFile() at :440. SetupLauncher calls it at :151, before it hands InstallDS the supplier. So hasTempLogFile() is false in both overrides every time, and a headless setup or uninstall prints "GUI launch failed" without naming the log that holds the stack trace. At BASE and at 81cdd36 the message named it. On setup, a CLI fallback that returns before Installer.run() (usage error, already installed, cancel) writes the reason nowhere. That is the trade-off stated at Launcher.java:280-284, and it leaves the DETAILS message there as dead code. On uninstall the two calls are simply in the wrong order.
if (exitCode != 0) {
// The GUI did not come up and the operation runs on the command line after all: from
// here on there is something worth logging, the reason the GUI failed included.
getTempLogFile();
guiLaunchFailed();Or, for setup: drop the DETAILS arm and its message, since Installer.run() names the log on failure anyway.
suggestion (non-blocking): No test gives an Application a Supplier, so neither openTempLogFile() at Installer.run():248 nor the lazy setTempLogFile(Supplier) is pinned.
opendj-server-legacy/src/main/java/org/opends/quicksetup/installer/Installer.java:248, opendj-server-legacy/src/test/java/org/opends/quicksetup/installer/InstallerTest.java:189
Both InstallerTest roads that build an Installer (:189, and :223 in reportOf) use the eager setTempLogFile(TempLogFile), which sets the field directly. That makes openTempLogFile() a no-op in every case. InstallDSTest returns before InstallDS.java:385, and LauncherTest never builds an Application. Deleting :248 passes under failsafe, yet every real install then hits an NPE at :313/:325/:629. Making the Supplier setter call get() immediately also passes, and it brings back the wizard-quit leak.
final int[] asked = { 0 };
installer.setTempLogFile(() -> { asked[0]++; return logFile; });
installer.setUserData(new UserData());
installer.cancel();
assertEquals(asked[0], 0, "nothing is logged before the install begins");
installer.run();
assertEquals(asked[0], 1);
assertFalse(logFile.getLogFile().exists(), logFile.getPath());Pin: the same fixture as testACancelledInstallTakesItsLogWithIt, with the Supplier overload in place of the file. It fails against either mutant.
suggestion (non-blocking): LauncherTest pins only the Launcher layer of the GUI fix. An eager .get() in QuickSetup/SplashScreen survives, and so does dropping the deferred GUI-failure record.
opendj-server-legacy/src/test/java/org/opends/quicksetup/LauncherTest.java:136, opendj-server-legacy/src/main/java/org/opends/quicksetup/Launcher.java:103
TestLauncher.startSplashScreen stores the supplier and never throws. No test reaches QuickSetup.initialize or SplashScreen.main, and none enters the catch at Launcher.java:285. application.setTempLogFile(tempLogFile.get()) at QuickSetup.java:111 still compiles against the retained TempLogFile overload, and it would bring the leak back with every test green. Deleting logGuiLaunchFailure() at :103 would also stay green.
// TestLauncher: private RuntimeException splashFailure;
// startSplashScreen(...) { splashLogFile = tempLogFile; if (splashFailure != null) throw splashFailure; }
launcher.splashFailure = new IllegalStateException("no display");
launcher.launchGui(new String[0]);
assertFalse(launcher.hasTempLogFile(), "a GUI which does not come up costs no log");
final TempLogFile logFile = launcher.getTempLogFile();
created.add(logFile);
assertTrue(logFile.readContents().contains("no display"), logFile.getPath());Pin: the case above catches the deletion at :103. The QuickSetup layer is pinned once the GUI road can no longer reach the eager overload, or with one case that runs QuickSetup.initialize on a stub Application.
suggestion (non-blocking): InstallDSTest pins only the parse-time returns. The roads named in the comment at InstallDS.java:381-384 (already installed, refused licence, cancel at the prompt) are unpinned.
opendj-server-legacy/src/test/java/org/opends/server/tools/InstallDSTest.java:74
assertAsksForNoLog runs --help (return at InstallDS.java:342) and --no-such-option (:337). If a tempLogFile.get() is moved up to :344, ahead of checkInstallStatus() at :347, a log is created on "already installed" (:352), on a refused licence (:357) and on a cancel (:371), and both cases stay green.
Pin: one more assertAsksForNoLog case on a road where checkInstallStatus() reports the server as configured (:352, before any prompt), asserting that the counting supplier was never asked.
… the log only where there is one The uninstall wizard was left with no log at all: only Installer.run() resolved the supplier, and the uninstaller's errors reach the file only through the publisher the log puts on the error logger. Uninstaller.run() now resolves it too, and Application.openTempLogFile() tolerates the command line uninstaller, which is handed no supplier. Application no longer takes the file itself, only the supplier, so no caller on the way can resolve it early again. guiLaunchFailed() could never name a log: none existed yet when it ran. The uninstall road now asks for the log first; the setup road cannot without bringing the headless leftover back, so its DETAILS arm and INFO_SETUP_LAUNCHER_GUI_LAUNCHED_FAILED_DETAILS are removed. Tests pin the supplier road of the installer, the null guard, the GUI failure written once a log exists, and the "already installed" road of the CLI setup.
|
Round 4, at 4845f2f. All five points taken. The blocking one corrects something I stated in round 3 that was wrong. issue (blocking): the uninstall wizard no longer creates any logTaken, in the shape you propose. In round 3 I wrote that
Pin: The line in issue (non-blocking): the
|
maximthomas
left a comment
There was a problem hiding this comment.
praise: The uninstall wizard writes its log again, and the fix covers the command-line uninstaller too.
Uninstaller.run()resolves the log in its first statement (Uninstaller.java:703), andApplication.openTempLogFile()is null-safe (Application.java:730). The command-linenew Uninstaller(), which is never handed a supplier, therefore keeps the log its launcher created instead of throwing an NPE.Launcher.launch()now asks for the log beforeguiLaunchFailed()(Launcher.java:440-441), so a headless uninstall names the file that holds the reason. The setup road drops the*_DETAILSmessage rather than creating a log just to name it.InstallerTest.testACancelledInstallTakesItsLogWithItpasses a countingSupplierand asserts 0 asks beforerun()and 1 after.InstallerTest,LauncherTest,InstallDSTestandTempLogFileTestrun 21/21 green under failsafe at 4845f2f.
Fixes #1030
What was wrong
Since #576 the launcher scripts put
java.io.tmpdirat<instance>/tmp, andstart-dsdidrm -rf tmp/*before starting the server. Setup starts the server throughstart-ds, so its ownopendj-setup-*.logwas unlinked mid-run on every setup; a start that failed afterwards named a file that was no longer there and printed aNoSuchFileExceptionstack instead of the log. In the non-verbose mode theserver: …lines that say why the server did not come up go only into that log, so the one place the diagnosis lived was the deleted file. Analysis and reproduction in #1030.What changes
start-ds/start-ds.bat— the sweep is narrowed to thebc-fips-jni_*directories the BC FIPS native loader extracts on every start (the name is"%s_%d"with module namebc-fips-jni, fromLoaderUtilsin bc-fips 2.1.3), which is what [#575] Set OpenDJ tmp dir to an installation directory #576 introduced it for. Other files intmp/belong to tools that may still be running; the comment hands the logs a faileddsreplicationorstatusrun leaves there to the operator. The.batblock becomes a singlefor /D … rmdirline, so the parse-time parenthesis problem the old block had to guard against does not arise.TempLogFile.newTempLogFile(prefix, directory)— the log can be placed in a directory of the caller's choosing (created if needed, fallback tojava.io.tmpdirwhennullor unusable).SetupLauncherputs the setup log under<instance>/logs, next toserver.out. Uninstall and the embedded server keep using the temporary directory.Launcher.getTempLogFile()creates it on the first ask; what is handed around until then is aSupplier<TempLogFile>:SetupLauncher→InstallDS.mainCLIon the command line, andLauncher.launchGui→SplashScreen→QuickSetup.initialize→Applicationin the wizard.Installer.run()resolves it as its first statement, and so doesUninstaller.run(): the uninstall's errors reach the file only through the publisher the log puts on the error logger, so a failed GUI uninstall keeps its stack trace there as before.Applicationtakes the supplier only; there is no setter for the file itself, so nothing on the way can resolve it early. An application given no supplier has no log of its own, which is how the command line uninstaller is built (its launcher creates the log before running it). So--help,--version, a usage error, "already installed", a refused licence, a cancel at the prompt, a quit at any wizard step and a failed java version check create nothing; the reason a GUI launch failed is kept in the launcher and written to the log only if something later asks for one. When the GUI fails, the uninstall road asks for the log beforeguiLaunchFailed(), so the message names the file; the setup road does not (that would bring the headless leftover back), andINFO_SETUP_LAUNCHER_GUI_LAUNCHED_FAILED_DETAILSis removed.hasTempLogFile()answers "is there a log to name?" without creating one. The publicmainCLI(String[], OutputStream, OutputStream, TempLogFile)is unchanged.Installer.notifyListenersOfExistingLogFile— checksTempLogFile.isReadable()before promising the file; a missing log is reported withINFO_GENERAL_LOG_IN_ERROR_MISSING, a read failure withINFO_GENERAL_LOG_IN_ERROR_UNREADABLE, both to the listeners;printStackTrace()is gone. A cancelled install deletes its log: that road never names it anduninstall()has just taken the installation back.TempLogFilehousekeeping — the error and debug publishers installed with the log are removed again when it is deleted, the fallback warning is logged once there is a log to carry it, andreadContents()decodes with the charsetTextWriter.STREAMwrote with.build.yml— afailure()-only step printsopendj*/logs/server.outandlogs/errorsof the instances a failed test step leaves behind; the server-side reason of a failed start is nowhere else. The Unix FIPS and Windows steps plant abc-fips-jni_*directory and an unrelated file intmp/before astart-dsand check after it that the first is gone and the second is not.Verification
TempLogFileTest(7),InstallerTest(7),LauncherTest(4),InstallDSTest(3),UtilsTest(3) andConfigurationTest(9): green.InstallationTest,FileManagerTestandServerControllerTestshare a quicksetup test server that cannot bind the fixed admin ports on the development box at the moment (taken by other JVMs there); they are untouched by this PR, were green on the round 3 tree, and CI runs them.SplashScreen.mainfailstestLaunchingTheGuiCreatesNoLog;tempLogFile.get()hoisted to theInstallDSbuild fails both parse-timeInstallDSTestcases, and hoisted only as far ascheckInstallStatus()failstestAServerWhichIsConfiguredAlreadyAsksForNoLog;openTempLogFile()dropped fromInstaller.run(), or the supplier resolved in the setter, failstestACancelledInstallTakesItsLogWithIt; the null guard inopenTempLogFile()dropped failstestAnApplicationGivenNoLogHasNone; the GUI failure no longer written once a log exists failstestAGuiWhichDoesNotComeUpIsLoggedOnceThereIsALog;isReadable()→isEnabled()in the report (the Setup: a failed installation asks for a log file it has not checked is there, and prints a stack trace instead of saying so #1030 symptom comes back as anUNREADABLEline) failstestAMissingLogIsReportedAsMissing; the same report line sent out as progress rather than as a warning fails it too; the CANCELED-road delete dropped failstestACancelledInstallTakesItsLogWithIt;readContents()not written to the report failstestTheContentsOfTheLogReachTheReport; the publisher left on the error logger failstestDeletingTheLogTakesItsPublisherOffTheLogger; the fallback warning moved back into the catch failstestUnusableDirectoryFallsBackToTheTemporaryDirectory; dropping theisRegularFileconjunct failstestADirectoryAtTheLogPathIsNotReadable; creating the log in theLauncherconstructor again failstestBuildingALauncherLeavesNothingOnDisk../setup --help,./setup --version, an unknown argument and a secondsetupon an installed package ("Server Already Configured"): nologs/directory is created at all on a fresh package, andtmp/stays empty.<instance>/logswhile it runs (watched), and after a successful setuplogs/holds noopendj-setup-*.logandtmp/is empty.dbpath made a regular file): exit 6, "See…/logs/opendj-setup-*.logfor a detailed log", the log printed inline from its first line, no stack trace, and the file left in place.Error code: 1,See …/logs/opendj-setup-*.log, the dumped log carriesserver: … unable to bind to 0.0.0.0:31389: IOException(Address already in use), no stack trace, exit code 7 as before;tmp/: abc-fips-jni_123directory removed, an unrelatedopendj-replication-*.logkept.openTempLogFile()inUninstaller.run()(new Uninstaller()resets the registries of the test JVM's server throughDirectoryServer.bootstrapClient()) and the order ofgetTempLogFile()/guiLaunchFailed()inLauncher.launch()(that road ends inSystem.exit).start-ds.batis exercised by the "Test on Windows" step and the MSI jobs.