Skip to content

Improve logging accuracy #299

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
dlang-bot merged 1 commit into from
Feb 8, 2018
Merged

Improve logging accuracy #299

Changes from all commits
Commits
Show all changes
1 commit
Select commit
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
179 changes: 111 additions & 68 deletions rdmd.d
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -15,10 +15,13 @@
// Written in the D programming language.

import std.algorithm, std.array, core.stdc.stdlib, std.datetime,
std.digest.md, std.exception, std.file, std.getopt,
std.digest.md, std.exception, std.getopt,
std.parallelism, std.path, std.process, std.range, std.regex,
std.stdio, std.string, std.typecons, std.typetuple;

// Globally import types and functions that don't need to be logged
import std.file : FileException, DirEntry, SpanMode, thisExePath, tempDir;

version (Posix)
{
enum objExt = ".o";
Expand Down Expand Up @@ -62,7 +65,7 @@ int main(string[] args)
// Look for the D compiler rdmd invokes automatically in the same directory as rdmd
// and fall back to using the one in your path otherwise.
string compilerPath = buildPath(dirName(thisExePath()), defaultCompiler);
if (compilerPath.exists && compilerPath.isFile)
if (Filesystem.existsAsFile(compilerPath))
compiler = compilerPath;

if (args.length > 1 && args[1].startsWith("--shebang ", "--shebang="))
Expand Down Expand Up @@ -229,9 +232,7 @@ int main(string[] args)
immutable workDir = getWorkPath(root, compilerFlags);
lockWorkPath(workDir); // will be released by the OS on process exit
string objDir = buildPath(workDir, "objs");
yap("mkdirRecurse ", objDir);
if (!dryRun)
mkdirRecurse(objDir);
Filesystem.mkdirRecurseIfLive(objDir);

if (lib)
{
Expand Down Expand Up @@ -288,16 +289,14 @@ int main(string[] args)
// Both exe and buildWitness exist, and exe is older than
// buildWitness. This is the only situation in which we
// may NOT need to recompile.
yap("stat ", buildWitness);
lastBuildTime = buildWitness.timeLastModified(SysTime.min);
lastBuildTime = Filesystem.timeLastModified(buildWitness, SysTime.min);
}
}
else
{
exe = buildPath(workDir, exeBasename) ~ outExt;
buildWitness = exe;
yap("stat ", buildWitness);
lastBuildTime = buildWitness.timeLastModified(SysTime.min);
lastBuildTime = Filesystem.timeLastModified(buildWitness, SysTime.min);
}

// Have at it
Expand All @@ -310,11 +309,7 @@ int main(string[] args)

// Touch the build witness to track the build time
if (buildWitness != exe)
{
yap("touch ", buildWitness);
if (!dryRun)
std.file.write(buildWitness, "");
}
Filesystem.touchEmptyFileIfLive(buildWitness);
}

if (buildOnly)
Expand Down Expand Up @@ -391,9 +386,7 @@ private @property string myOwnTmpDir()
else
tmpRoot = tmpRoot.replace("/", dirSeparator).buildPath(".rdmd");

yap("mkdirRecurse ", tmpRoot);
if (!dryRun)
mkdirRecurse(tmpRoot);
Filesystem.mkdirRecurseIfLive(tmpRoot);
return tmpRoot;
}

Expand Down Expand Up @@ -423,9 +416,7 @@ private string getWorkPath(in string root, in string[] compilerFlags)
workPath = buildPath(tmpRoot,
"rdmd-" ~ baseName(root) ~ '-' ~ hash);

yap("mkdirRecurse ", workPath);
if (!dryRun)
mkdirRecurse(workPath);
Filesystem.mkdirRecurseIfLive(workPath);

return workPath;
}
Expand Down Expand Up @@ -462,24 +453,18 @@ private int rebuild(string root, string fullExe,
fullExe = fullExe.defaultExtension(".exe");

// Delete the old executable before we start building.
yap("stat ", fullExe);
if (exists(fullExe))
if (Filesystem.exists(fullExe))
Copy link

@joseph-wakeling-sociomantic joseph-wakeling-sociomantic Feb 6, 2018

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Won't there be two stat outputs from yap as a consequence of the separate

if (exists)
{
    enforce(isFile)
    ...
}

... setup? Why do we want this to behave differently from all other exists && isFile situations?

(The implicit argument here is: why bother with the existsAsFile, rather than just allowing separate checks and having chatty output report this accordingly.)

Copy link
Contributor Author

@marler8997 marler8997 Feb 6, 2018

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I'll change the second one to a DirectFilesystem call so it doesn't log.

Copy link
Member

@CyberShadow CyberShadow Feb 6, 2018

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

We really shouldn't use DirectFilesystem in the main rdmd logic.

I think this is fine as it is.

Copy link
Contributor Author

@marler8997 marler8997 Feb 6, 2018

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

ok, changing back, this one isn't a big issue for me, it only happens once so I'm ok with either solution

Copy link
Contributor Author

@marler8997 marler8997 Feb 6, 2018

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Note that this will get fixed if we implement the rest of #295...which I plan on making a PR for later.

Copy link
Contributor Author

@marler8997 marler8997 Feb 6, 2018

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This all becomes much simpler and more consistent if we just forgo existsAsFile. Why not just drop it?

Ah, I misread you're comment. You were saying drop existsAsFile altogether. Can you explain you're rationale?

Copy link

@joseph-wakeling-sociomantic joseph-wakeling-sociomantic Feb 6, 2018

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

If we drop existsAsFile altogether then (i) there is no discrepancy in stat reports by rdmd and stat records in e.g. an strace, and (ii) we have one less custom use-case to handle.

Put that together, it leads to simpler and more consistent code that is more precise in its --chatty output.

Copy link
Contributor Author

@marler8997 marler8997 Feb 6, 2018 •
edited
Loading

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

If we drop existsAsFile altogether then (i) there is no discrepancy in stat reports by rdmd and stat records in e.g. an strace, and (ii) we have one less custom use-case to handle.

We've already discussed this and established this is not a problem. If this is your only justification then I think the answer is clear. Repeating the same arguments does not make them more true or valid in other cases.

Copy link

@joseph-wakeling-sociomantic joseph-wakeling-sociomantic Feb 6, 2018

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This is not a problem. If this is your only justification then I think the answer is clear.

Every line of code that does not need to exist is a maintenance burden. This method does not need to exist, so why bother implementing it?

Copy link
Contributor Author

@marler8997 marler8997 Feb 6, 2018

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Every line of code that does not need to exist is a maintenance burden.

This is most certainly not true. More lines of code can be easier to maintain than less.

This method does not need to exist, so why bother implementing it?

Please stop asking me to re-explain this. You're talking in circles making the same arguments and asking me to repeat mine.

{
enforce(isFile(fullExe), fullExe ~ " is not a regular file");
yap("rm ", fullExe);
if (!dryRun)
enforce(Filesystem.isFile(fullExe), fullExe ~ " is not a regular file");
try
Filesystem.removeIfLive(fullExe);
catch (FileException)
{
try
remove(fullExe);
catch (FileException e)
{
// This can occur on Windows if the executable is locked.
// Although we can't delete the file, we can still rename it.
auto oldExe = "%s.%s-%s.old".format(fullExe,
Clock.currTime.stdTime, thisProcessID);
yap("mv ", fullExe, " ", oldExe);
rename(fullExe, oldExe);
}
// This can occur on Windows if the executable is locked.
// Although we can't delete the file, we can still rename it.
auto oldExe = "%s.%s-%s.old".format(fullExe,
Clock.currTime.stdTime, thisProcessID);
Filesystem.rename(fullExe, oldExe);
}
}

Expand All @@ -500,7 +485,7 @@ private int rebuild(string root, string fullExe,
if (addStubMain)
{
auto stubMain = buildPath(myOwnTmpDir, "stubmain.d");
std.file.write(stubMain, "void main(){}");
Filesystem.write(stubMain, "void main(){}");
todo ~= [ stubMain ];
}
return todo;
Expand All @@ -517,7 +502,7 @@ private int rebuild(string root, string fullExe,

// DMD uses Windows-style command-line parsing in response files
// regardless of the operating system it's running on.
std.file.write(rspName, array(map!escapeWindowsArgument(todo)).join(" "));
Filesystem.write(rspName, array(map!escapeWindowsArgument(todo)).join(" "));

todo = [ "@" ~ rspName ];
}
Expand All @@ -526,25 +511,23 @@ private int rebuild(string root, string fullExe,
if (result)
{
// build failed
if (exists(fullExeTemp))
remove(fullExeTemp);
if (Filesystem.exists(fullExeTemp))
Filesystem.remove(fullExeTemp);

return result;
}
// clean up the dir containing the object file, just not in dry
// run mode because we haven't created any!
if (!dryRun)
{
yap("stat ", objDir);
if (objDir.exists && objDir.startsWith(workDir))
if (Filesystem.exists(objDir) && objDir.startsWith(workDir))
{
yap("rmdirRecurse ", objDir);
// We swallow the exception because of a potential race: two
// concurrently-running scripts may attempt to remove this
// directory. One will fail.
collectException(rmdirRecurse(objDir));
collectException(Filesystem.rmdirRecurse(objDir));
}
yap("mv ", fullExeTemp, " ", fullExe);
rename(fullExeTemp, fullExe);
Filesystem.rename(fullExeTemp, fullExe);
}
return 0;
}
Expand Down Expand Up @@ -620,7 +603,7 @@ private string[string] getDependencies(string rootModule, string workDir,
foreach (name; names)
{
auto path = buildPath(dir, name);
if (path.exists)
if (Filesystem.exists(path))
return absolutePath(path);
}
return null;
Expand Down Expand Up @@ -658,8 +641,7 @@ private string[string] getDependencies(string rootModule, string workDir,
auto confFile = captures[2].strip;
// The config file is special: if missing, that's fine too. So
// add it as a dependency only if it actually exists.
yap("stat ", confFile);
if (confFile.exists)
if (Filesystem.exists(confFile))
{
result[confFile] = null;
}
Expand Down Expand Up @@ -687,8 +669,7 @@ private string[string] getDependencies(string rootModule, string workDir,
// Check if the old dependency file is fine
if (!force)
{
yap("stat ", depsFilename);
auto depsT = depsFilename.timeLastModified(SysTime.min);
auto depsT = Filesystem.timeLastModified(depsFilename, SysTime.min);
if (depsT > SysTime.min)
{
// See if the deps file is still in good shape
Expand Down Expand Up @@ -719,14 +700,14 @@ private string[string] getDependencies(string rootModule, string workDir,
{
// Delete the deps file on failure, we don't want to be fooled
// by it next time we try
collectException(std.file.remove(depsFilename));
collectException(Filesystem.remove(depsFilename));
}

immutable depsExitCode = run(depsGetter, depsFilename);
if (depsExitCode)
{
stderr.writefln("Failed: %s", depsGetter);
collectException(std.file.remove(depsFilename));
collectException(Filesystem.remove(depsFilename));
exit(depsExitCode);
}

Expand All @@ -736,8 +717,7 @@ private string[string] getDependencies(string rootModule, string workDir,
// Is any file newer than the given file?
bool anyNewerThan(T)(T files, in string file)
{
yap("stat ", file);
return files.anyNewerThan(file.timeLastModified);
return files.anyNewerThan(Filesystem.timeLastModified(file));
}

// Is any file newer than the given file?
Expand All @@ -763,17 +743,15 @@ than target's. Otherwise, returns true.
private bool newerThan(string source, string target)
{
if (force) return true;
yap("stat ", target);
return source.newerThan(target.timeLastModified(SysTime.min));
return source.newerThan(Filesystem.timeLastModified(target, SysTime.min));
}

private bool newerThan(string source, SysTime target)
{
if (force) return true;
try
{
yap("stat ", source);
return DirEntry(source).timeLastModified > target;
return Filesystem.timeLastModified(DirEntry(source)) > target;
}
catch (Exception)
{
Expand Down Expand Up @@ -936,21 +914,19 @@ string makeEvalFile(string todo)
auto srcfile = buildPath(pathname,
"eval." ~ todo.md5Of.toHexString ~ ".d");

if (force || !exists(srcfile))
if (force || !Filesystem.exists(srcfile))
{
std.file.write(srcfile, todo);
Filesystem.write(srcfile, todo);
}

// Clean pathname
enum lifetimeInHours = 24;
auto cutoff = Clock.currTime() - dur!"hours"(lifetimeInHours);
yap("dirEntries ", pathname);
foreach (DirEntry d; dirEntries(pathname, SpanMode.shallow))
foreach (DirEntry d; Filesystem.dirEntries(pathname, SpanMode.shallow))
{
yap("stat ", d.name);
if (d.timeLastModified < cutoff)
if (Filesystem.timeLastModified(d) < cutoff)
{
collectException(std.file.remove(d.name));
collectException(Filesystem.remove(d.name));
//break; // only one per call so we don't waste time
}
}
Expand Down Expand Up @@ -993,8 +969,7 @@ string which(string path)
foreach (extension; extensions)
{
string absPath = buildPath(envPath, path ~ extension);
yap("stat ", absPath);
if (exists(absPath) && isFile(absPath))
if (Filesystem.existsAsFile(absPath))
return absPath;
}
}
Expand All @@ -1007,3 +982,71 @@ void yap(size_t line = __LINE__, T...)(auto ref T stuff)
debug stderr.writeln(line, ": ", stuff);
else stderr.writeln(stuff);
}

/**
Used to wrap filesystem operations that should also be logged with the
yap function or affected by dryRun. Append the string "IfLive" to the end
of the function for it to be skipped during a dry run.

These functions allow the filename to be given once so the log statement
always matches the operation. Using it also guarantees you won't forget to
include a `yap` alongside any file operation you want to be logged.
*/
struct Filesystem
{
static:
static auto opDispatch(string func, T...)(T args)
Copy link
Member

@CyberShadow CyberShadow Feb 6, 2018

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

static on function is redundant

Copy link
Contributor Author

@marler8997 marler8997 Feb 6, 2018

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I think the redundancy is ok....if this struct had really big functions, and you couldn't see the static: modifier, having static in the function definition is helpful. But if you really don't like the redundancy, I'll remove it.

Copy link
Member

@CyberShadow CyberShadow Feb 6, 2018

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Ah OK, I didn't realize it was intentional.

{
static if (func.endsWith("IfLive"))
{
enum fileFunc = func[0 .. $ - "IfLive".length];
enum skipOnDryRun = true;
Copy link

@joseph-wakeling-sociomantic joseph-wakeling-sociomantic Feb 6, 2018

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This means that the dry-run check will be performed on the basis of the virtuous developer remembering to use the IfLive suffix, rather than on the basis of what the actual action is.

In other words, if I call Filesystem.mkdirRecurse (without adding the IfLive prefix), the filesystem will be modified even in dry run mode. That's surely not wanted, is it?

The IfLive suffix should therefore be dropped in favour of making a decision on the basis of the action concerned.

Copy link
Contributor Author

@marler8997 marler8997 Feb 6, 2018 •
edited
Loading

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

In other words, if I call Filesystem.mkdirRecurse (without adding the IfLive prefix), the filesystem will be modified even in dry run mode. That's surely not wanted, is it?

Yes, actually this is what is wanted. Whether or not something should be done on a dry run isn't based on the action itself, it's based on what behavior the caller wants in it's particular scenario.

Copy link

@joseph-wakeling-sociomantic joseph-wakeling-sociomantic Feb 6, 2018

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Whether or not something should be one on a dry run isn't based on the action itself, it's based on what behavior the caller wants in it's particular scenario.

But if this PR is anything to go by, there is no existing use-case for not respecting the dry-run behaviour. So why implement the possibility?

Note also that respecting the dry-run behaviour by default is the safe option because then you are guaranteeing that the filesystem will not be modified. Forcing a modification should be the non-default, only-on-request option.

With this in mind it's better to make the dry-run behaviour dependent on the filesystem operation (ensuring that ones that modify it are guaranteed to respect the dry-run behaviour) and implement an ability to override that in future only if a use-case ever.

If there's really a strong wish to have non-dry-run behaviour available to the developer, it should be the non-default option that only occurs on clear developer request, rather than the default option.

Copy link
Contributor Author

@marler8997 marler8997 Feb 6, 2018

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

But if this PR is anything to go by, there is no existing use-case for not respecting the dry-run behaviour. So why implement the possibility?

This is a behavior you don't want to abstract from the caller. If there's a possibility that the action won't be executed, the caller should definitely be aware of this instead of abstracting it away.

Copy link
Contributor Author

@marler8997 marler8997 Feb 6, 2018 •
edited
Loading

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Note also that respecting the dry-run behaviour by default is the safe option because then you are guaranteeing that the filesystem will not be modified.

This actually isn't true, rdmd will still make file system modifications on a dry run. It just won't generate the final executable.

Copy link

@joseph-wakeling-sociomantic joseph-wakeling-sociomantic Feb 6, 2018

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Some functions would be affected by dryRun and some wouldn't, the only way you would know is if you went and looked at the implementation of Filesystem and followed the logic.

That's already the case, is it not?

Copy link
Contributor Author

@marler8997 marler8997 Feb 6, 2018

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

No, the current PR always executes the function, unless you specify IfLive.

Copy link
Member

@CyberShadow CyberShadow Feb 6, 2018

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Ugh, this sounds like a nightmare. Some functions would be affected by dryRun and some wouldn't,

Well, if we consistently implement this according to the obvious rule ("does it change something on the filesystem? then it should be affected by --dry-run"), then that shouldn't be an issue... the proposal is enticing but I agree the current design is simpler.

Maybe we should just merge this and call it a day. I think we're out of low-hanging fruit, and it seems like we're losing the forest for the trees with all this debate over trivia. We should try to improve the status quo (in a way that preferably doesn't compromise future improvements), and move on to the next problem.

Copy link

@joseph-wakeling-sociomantic joseph-wakeling-sociomantic Feb 6, 2018

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

No, the current PR always executes the function, unless you specify IfLive.

It's usually pretty obvious from the function name which of them change things (touch, rename, remove, write, mkdir, ...) and which of them do not (exists, isFile, isDir, ...).

Copy link
Contributor Author

@marler8997 marler8997 Feb 6, 2018

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Adding extra rules makes the code harder to maintain. A developer has to learn that functions that don't modify the file system will always be executed, and functions that do will only be executed if dryRun is false. Sometimes having a dumb interface that's more intuitive is better than trying to make a clever interface that tries to abstract details away from the developer.

}
else
{
enum fileFunc = func;
enum skipOnDryRun = false;
}

static if (fileFunc.among("exists", "timeLastModified", "isFile", "isDir", "existsAsFile"))
yap("stat ", args[0]);
else static if (fileFunc == "rename")
yap("mv ", args[0], " ", args[1]);
else static if (fileFunc.among("remove", "mkdirRecurse", "rmdirRecurse", "dirEntries", "write", "touchEmptyFile"))
yap(fileFunc, " ", args[0]);
else static assert(0, "Filesystem.opDispatch has not implemented " ~ fileFunc);

static if (skipOnDryRun)
{
if (dryRun)
return;
}
Copy link

@joseph-wakeling-sociomantic joseph-wakeling-sociomantic Feb 6, 2018

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This is a leaky abstraction: it assumes that the functions which need the dry-run option have void return-type. This may be true of the particular functions currently used, but is not guaranteed to be generally true.

Copy link
Contributor Author

@marler8997 marler8997 Feb 6, 2018 •
edited
Loading

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Yes I thought about this. I originally was going to return the .init value of the return type, but then I realized that was assuming the the .init value would have been representative of a return value when NOT EXECUTING the function. After realizing this, it became clear that any function affected by dry run would most certainly have a void return value since a function that can optionally do nothing would return nothing.

Copy link
Member

@CyberShadow CyberShadow Feb 6, 2018

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

We'll get a compilation error in that case, so I think we're good here.

Copy link

@joseph-wakeling-sociomantic joseph-wakeling-sociomantic Feb 6, 2018

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

We'll get a compilation error in that case

Well, of course. But it'd be nice to avoid the maintenance burden of some future developer wanting to add an extra function here, and finding that it breaks the assumptions made by Filesystem.opDispatch.

Copy link
Contributor

@wilzbach wilzbach Feb 6, 2018

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I think we are good here too. It's a single file, has produced < 5 bugs in two years and is not a huge codebase anyways. Also doing a __traits(allMembers over std.file would lead to worse pretty-printed loggin (I thought about proposing it too).

Copy link
Contributor Author

@marler8997 marler8997 Feb 6, 2018

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

You've not addressed my reasoning for assuming the function must return void.

mixin("return DirectFilesystem." ~ fileFunc ~ "(args);");
}

/**
Operates on the file system without logging its operations or being
affected by dryRun.
*/
static struct DirectFilesystem
{
static:
import file = std.file;
alias file this;

/**
Update an empty file's timestamp.
*/
static void touchEmptyFile(string name)
{
file.write(name, "");
}
/**
Returns true if name exists and is a file.
*/
static bool existsAsFile(string name)
{
return file.exists(name) && file.isFile(name);
}
}
}