Skip to content

Commit

Permalink
fix an inverted return conditional from stale_cachefile
Browse files Browse the repository at this point in the history 
also add plenty of helpful debugging information enabled by the environment variable:
JULIA_DEBUG_LOADING

this bug would cause compilation to become confused
and likely tardy at recompiling files when it should
that would up with longer dependency chains where one
of the files had been updated

this is a fix for #18150
  • Loading branch information
@vtjnash
vtjnash committed Sep 5, 2016
1 parent 79a7172 commit a4e7884
Show file tree
Hide file tree
Showing 3 changed files with 41 additions and 31 deletions.
59 changes: 33 additions & 26 deletions base/loading.jl
View file
Original file line number Diff line number Diff line change
Expand Up @@ -210,7 +210,6 @@ function _require_search_from_serialized(node::Int, mod::Symbol, sourcepath::Str
paths = @fetchfrom node find_all_in_cache_path(mod)
end

local restored = nothing, failedpath = ""
for path_to_try in paths::Vector{String}
if stale_cachefile(sourcepath, path_to_try)
continue
Expand All @@ -220,7 +219,7 @@ function _require_search_from_serialized(node::Int, mod::Symbol, sourcepath::Str
if isa(restored, ErrorException) && endswith(restored.msg, " uuid did not match cache file.")
# can't use this cache due to a module uuid mismatch,
# defer reporting error until after trying all of the possible matches
failedpath = path_to_try
DEBUG_LOADING[] && info(restored, prefix="INFO: JL_DEBUG_LOADING: Failed to load $path_to_try because ")
continue
end
warn("Deserialization checks failed while attempting to load cache from $path_to_try.")
Expand All @@ -229,17 +228,14 @@ function _require_search_from_serialized(node::Int, mod::Symbol, sourcepath::Str
return restored
end
end
if isa(restored, Exception)
warn("Deserialization checks failed while attempting to load cache from $failedpath.")
warn(restored, prefix="WARNING: ")
end
return !isempty(paths)
end

# to synchronize multiple tasks trying to import/using something
const package_locks = Dict{Symbol,Condition}()

# used to optionally track dependencies when requiring a module:
const DEBUG_LOADING = Ref(false)
const _concrete_dependencies = Any[] # these dependency versions are "set in stone", and the process should try to avoid invalidating them
const _require_dependencies = Any[] # a list of (path, mtime) tuples that are the file dependencies of the module currently being precompiled
const _track_dependencies = Ref(false) # set this to true to track the list of file dependencies
Expand Down Expand Up @@ -341,7 +337,7 @@ during package development as code is modified.
function reload(name::AbstractString)
if isfile(name) || contains(name,Filesystem.path_separator)
# for reload("path/file.jl") just ask for include instead
error("use `include` instead of `reload` to load source files")
error("Use `include` instead of `reload` to load source files.")
else
# reload("Package") is ok
require(Symbol(require_modname(name)))
Expand Down Expand Up @@ -375,6 +371,7 @@ function require(mod::Symbol)
# and is not applied recursively to imported modules:
old_track_dependencies = _track_dependencies[]
_track_dependencies[] = false
DEBUG_LOADING[] = haskey(ENV, "JULIA_DEBUG_LOADING")

global toplevel_load
loading = get(package_locks, mod, false)
Expand All @@ -392,7 +389,7 @@ function require(mod::Symbol)
name = string(mod)
path = find_in_node_path(name, nothing, 1)
if path === nothing
throw(ArgumentError("module $name not found in current path.\nRun `Pkg.add(\"$name\")` to install the $name package."))
throw(ArgumentError("Module $name not found in current path.\nRun `Pkg.add(\"$name\")` to install the $name package."))
end

# attempt to load the module file via the precompile cache locations
Expand All @@ -410,6 +407,10 @@ function require(mod::Symbol)
if mod === concrete_mod
warn("""Module $mod with uuid $concrete_uuid is missing from the cache.
This may mean module $mod does not support precompilation but is imported by a module that does.""")
if JLOptions().incremental != 0
# during incremental precompilation, this should be fail-fast
throw(PrecompilableError(false))
end
end
end

Expand All @@ -419,8 +420,9 @@ function require(mod::Symbol)
cachefile = compilecache(mod)
m = _require_from_serialized(1, mod, cachefile, last)
if isa(m, Exception)
warn("Compilecache failed to create a usable precompiled cache file for module $name. Got:")
warn("`compilecache` failed to create a usable precompiled cache file for module $name. Got:")
warn(m, prefix="WARNING: ")
# fall-through
else
return # success
end
Expand Down Expand Up @@ -448,7 +450,7 @@ function require(mod::Symbol)
m = _require_from_serialized(1, mod, cachefile, last)
if isa(m, Exception)
warn(m, prefix="WARNING: ")
error("module $mod declares __precompile__(true) but require failed to create a usable precompiled cache file.")
error("Module $mod declares __precompile__(true) but require failed to create a usable precompiled cache file.")
end
end
finally
Expand Down Expand Up @@ -629,15 +631,15 @@ function compilecache(name::String)
end
end
# run the expression and cache the result
if isinteractive()
if isinteractive() || DEBUG_LOADING[]
if isfile(cachefile)
info("Recompiling stale cache file $cachefile for module $name.")
else
info("Precompiling module $name.")
end
end
if !success(create_expr_cache(path, cachefile, concrete_deps))
error("Failed to precompile $name to $cachefile")
error("Failed to precompile $name to $cachefile.")
end
return cachefile
end
Expand All @@ -662,9 +664,7 @@ function parse_cache_header(f::IO)
n = ntoh(read(f, Int32))
n == 0 && break
totbytes -= 4 + n + 8
if n < 0 # probably means this wasn't a valid file to be read by Base.parse_cache_header
error("EOF while reading cache header")
end
@assert n >= 0 "EOF while reading cache header" # probably means this wasn't a valid file to be read by Base.parse_cache_header
push!(files, (String(read(f, n)), ntoh(read(f, Float64))))
end
@assert totbytes == 4 "header of cache file appears to be corrupt"
Expand All @@ -674,7 +674,7 @@ end
function parse_cache_header(cachefile::String)
io = open(cachefile, "r")
try
!isvalid_cache_header(io) && throw(ArgumentError("invalid cache file $cachefile"))
!isvalid_cache_header(io) && throw(ArgumentError("Invalid header in cache file $cachefile."))
return parse_cache_header(io)
finally
close(io)
Expand All @@ -697,7 +697,7 @@ end
function cache_dependencies(cachefile::String)
io = open(cachefile, "r")
try
!isvalid_cache_header(io) && throw(ArgumentError("invalid cache file $cachefile"))
!isvalid_cache_header(io) && throw(ArgumentError("Invalid header in cache file $cachefile."))
return cache_dependencies(io)
finally
close(io)
Expand All @@ -708,28 +708,35 @@ function stale_cachefile(modpath::String, cachefile::String)
io = open(cachefile, "r")
try
if !isvalid_cache_header(io)
DEBUG_LOADING[] && info("JL_DEBUG_LOADING: Rejecting cache file $cachefile due to it containing an invalid cache header.")
return true # invalid cache file
end
modules, files = parse_cache_header(io)

# check if this file is going to provide one of our concrete dependencies
provides_concrete = false
for (mod, uuid) in _concrete_dependencies
if get(modules, mod, UInt64(0)) === uuid
provides_concrete = true
else
return false # cachefile doesn't provide the required version of the dependency
# or if it provides a version that conflicts with our concrete dependencies
# or neither
for (mod, uuid_req) in _concrete_dependencies
uuid = get(modules, mod, UInt64(0))
if uuid !== UInt64(0)
if uuid === uuid_req
return false # this is the file we want
end
DEBUG_LOADING[] && info("JL_DEBUG_LOADING: Rejecting cache file $cachefile because it provides the wrong uuid (got $uuid) for $mod (want $uuid_req).")
return true # cachefile doesn't provide the required version of the dependency
end
end
provides_concrete && return false # this is the file we want

# now check if this file is fresh relative to its source files
if files[1][1] != modpath
DEBUG_LOADING[] && info("JL_DEBUG_LOADING: Rejecting cache file $cachefile because it is for file $(files[1][1])) not file $modpath.")
return true # cache file was compiled from a different path
end
for (f, ftime) in files
for (f, ftime_req) in files
# Issue #13606: compensate for Docker images rounding mtimes
if mtime(f) ∉ (ftime, floor(ftime))
ftime = mtime(f)
if ftime != ftime_req && ftime != floor(ftime_req)
DEBUG_LOADING[] && info("JL_DEBUG_LOADING: Rejecting stale cache file $cachefile (mtime $ftime_req) because file $f (mtime $ftime) is updated.")
return true
end
end
Expand Down
6 changes: 6 additions & 0 deletions base/util.jl
View file
Original file line number Diff line number Diff line change
Expand Up @@ -383,6 +383,12 @@ warn(io::IO, err::Exception; prefix="ERROR: ", kw...) =
warn(err::Exception; prefix="ERROR: ", kw...) =
warn(STDERR, err, prefix=prefix; kw...)

info(io::IO, err::Exception; prefix="ERROR: ", kw...) =
info(io, sprint(buf->showerror(buf, err)), prefix=prefix; kw...)

info(err::Exception; prefix="ERROR: ", kw...) =
info(STDERR, err, prefix=prefix; kw...)

function julia_cmd(julia=joinpath(JULIA_HOME, julia_exename()))
opts = JLOptions()
cpu_target = unsafe_string(opts.cpu_target)
Expand Down
7 changes: 2 additions & 5 deletions test/compile.jl
View file
Original file line number Diff line number Diff line change
Expand Up @@ -16,6 +16,7 @@ function redirected_stderr(expected)
return t
end

delete!(ENV, "JULIA_DEBUG_LOADING") # this would affect some error messages being tested below
olderr = STDERR
dir = mktempdir()
dir2 = mktempdir()
Expand Down Expand Up @@ -225,11 +226,7 @@ try
@test !Base.stale_cachefile(FooBar1_file, joinpath(dir2, "FooBar1.ji"))
@test !Base.stale_cachefile(FooBar_file, joinpath(dir2, "FooBar.ji"))

t = redirected_stderr("""
WARNING: Deserialization checks failed while attempting to load cache from $(joinpath(dir2, "FooBar1.ji")).
WARNING: Module FooBar uuid did not match cache file.
WARNING: replacing module FooBar1.
""")
t = redirected_stderr("WARNING: replacing module FooBar1.")
try
reload("FooBar1")
finally
Expand Down

0 comments on commit a4e7884

Please sign in to comment.