diff --git a/base/loading.jl b/base/loading.jl index 592cbfe19a4c5..86ffaef060f1d 100644 --- a/base/loading.jl +++ b/base/loading.jl @@ -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 @@ -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("JL_DEBUG_LOADING: Failed to load $path_to_try because $(restored.msg)") continue end warn("Deserialization checks failed while attempting to load cache from $path_to_try.") @@ -229,13 +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 +# this value is set by `require` based on whether JULIA_DEBUG_LOADING +# is presently defined as an environment variable +# and makes the logic in this file noisier about what it is doing and why +const DEBUG_LOADING = Ref(false) + # to synchronize multiple tasks trying to import/using something const package_locks = Dict{Symbol,Condition}() @@ -275,9 +275,9 @@ immutable PrecompilableError <: Exception end function show(io::IO, ex::PrecompilableError) if ex.isprecompilable - print(io, "__precompile__(true) is only allowed in module files being imported") + print(io, "Declaring __precompile__(true) is only allowed in module files being imported.") else - print(io, "__precompile__(false) is not allowed in files that are being precompiled") + print(io, "Declaring __precompile__(false) is not allowed in files that are being precompiled.") end end precompilableerror(ex::PrecompilableError, c) = ex.isprecompilable == c @@ -375,6 +375,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) @@ -392,7 +393,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 @@ -410,6 +411,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 @@ -419,8 +424,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("The call to compilecache failed to create a usable precompiled cache file for module $name. Got:") warn(m, prefix="WARNING: ") + # fall-through, TODO: disable __precompile__(true) error so that the normal include will succeed else return # success end @@ -448,7 +454,8 @@ 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.") + # TODO: disable __precompile__(true) error and do normal include instead of error + error("Module $mod declares __precompile__(true) but require failed to create a usable precompiled cache file.") end end finally @@ -645,7 +652,7 @@ 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 @@ -653,7 +660,7 @@ function compilecache(name::String) 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 @@ -678,9 +685,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" @@ -690,7 +695,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) @@ -713,7 +718,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) @@ -724,28 +729,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) has changed.") return true end end diff --git a/base/util.jl b/base/util.jl index ff43543ec6f7e..ad0d06e4d77b5 100644 --- a/base/util.jl +++ b/base/util.jl @@ -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) diff --git a/test/compile.jl b/test/compile.jl index f49de8f02d590..6098ced8e8337 100644 --- a/test/compile.jl +++ b/test/compile.jl @@ -16,6 +16,10 @@ function redirected_stderr(expected) return t end +# this environment variable would affect some error messages being tested below +# so we disable it for the tests below +withenv( "JULIA_DEBUG_LOADING" => nothing ) do + olderr = STDERR dir = mktempdir() dir2 = mktempdir() @@ -158,7 +162,7 @@ try end """) - t = redirected_stderr("ERROR: LoadError: __precompile__(false) is not allowed in files that are being precompiled\n in __precompile__") + t = redirected_stderr("ERROR: LoadError: Declaring __precompile__(false) is not allowed in files that are being precompiled.\n in __precompile__") try Base.compilecache("Baz") # from __precompile__(false) error("__precompile__ disabled test failed") @@ -225,11 +229,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 @@ -331,3 +331,5 @@ let module_name = string("a",randstring()) deleteat!(LOAD_PATH,1) rm(file_name) end + +end # !withenv