Test works in REPL but not as part of @testset

Hi!

I started deploying the JMtk15 project on GitHub, but this question is about my local implementation (using Julia 1.8.5 and git 2.39.2 on a recent MacBook Pro): The test function jMtkReadData_tst_0100.jl works as expected when called from the REPL but yields an error message when part of a @testset in runtests.jl: what could cause this difference in outcome?

Within the JMtk15 project (under development at GitHub - mmverstraete/JMtk15: Julia wrapper functions to the C functions of the MISR Toolkit (Mtk) Version 1.5.), test/src/jMtkReadData_tst_0100.jl calls the Julia function src/jMtkReadData.jl which itself is a wrapper to the C function MtkReadData.c of NASA’s shared library Mtk available at GitHub - nasa/MISR-Toolkit: an API facilitating the access of MISR standard product files. It is activated within the test/runtests.jl function that manages the project tests, starting on line 1296.

When executed alone in the REPL, it generates expected results:

julia> using JMtk15

julia> using Test

julia> include(JMtk15_test * "src/jMtkReadData_tst_0100.jl")
jMtkReadData_tst_0100

julia> databuf, mapinfo = jMtkReadData_tst_0100();

julia> @test Int.(transpose(databuf[461:466, 67:71])) == Int.([
                       1  1  1  1  1  1
                       1  1  1  2  2  2
                       1  1  2  2  3  2
                       2  2  3  3  2  3
                       3  3  3  3  2  2])
Test Passed

but when the exact same lines are executed as part of the @testset in test/runtests.jl, they generate the following error message:

julia> using JMtk15

(JMtk15) pkg> activate .
  Activating project at `~/Projects/MISR/MISR_Toolkit.1.5/JMtk15`

(JMtk15) pkg> add Test
    Updating registry at `~/.julia/registries/General.toml`
   Resolving package versions...
  No Changes to `~/Projects/MISR/MISR_Toolkit.1.5/JMtk15/Project.toml`
  No Changes to `~/Projects/MISR/MISR_Toolkit.1.5/JMtk15/Manifest.toml`

(JMtk15) pkg> test JMtk15
     Testing JMtk15
      Status `/private/var/folders/st/q_mz5gzn2g3blprp2kvqnhr00000gn/T/jl_46x47h/Project.toml`
  [6c71635d] JMtk15 v0.1.0 `~/Projects/MISR/MISR_Toolkit.1.5/JMtk15`
  [8dfed614] Test `@stdlib/Test`
      Status `/private/var/folders/st/q_mz5gzn2g3blprp2kvqnhr00000gn/T/jl_46x47h/Manifest.toml`
  [fa961155] CEnum v0.4.2
  [bd334432] InlineTest v0.2.0
  [6c71635d] JMtk15 v0.1.0 `~/Projects/MISR/MISR_Toolkit.1.5/JMtk15`
  [e0db7c4e] ReTest v0.3.2
⌃ [90137ffa] StaticArrays v1.5.19
  [1e83bf80] StaticArraysCore v1.4.0
  [354b36f9] StringViews v1.3.0
  [56f22d72] Artifacts `@stdlib/Artifacts`
  [2a0f44e3] Base64 `@stdlib/Base64`
  [8ba89e20] Distributed `@stdlib/Distributed`
  [b77e0a4c] InteractiveUtils `@stdlib/InteractiveUtils`
  [8f399da3] Libdl `@stdlib/Libdl`
  [37e2e46d] LinearAlgebra `@stdlib/LinearAlgebra`
  [56ddb016] Logging `@stdlib/Logging`
  [d6f4376e] Markdown `@stdlib/Markdown`
  [de0858da] Printf `@stdlib/Printf`
  [9a3f8284] Random `@stdlib/Random`
  [ea8e919c] SHA v0.7.0 `@stdlib/SHA`
  [9e88b42a] Serialization `@stdlib/Serialization`
  [6462fe0b] Sockets `@stdlib/Sockets`
  [2f01184e] SparseArrays `@stdlib/SparseArrays`
  [10745b16] Statistics `@stdlib/Statistics`
  [8dfed614] Test `@stdlib/Test`
  [4ec0a83e] Unicode `@stdlib/Unicode`
  [e66e0078] CompilerSupportLibraries_jll v1.0.1+0 `@stdlib/CompilerSupportLibraries_jll`
  [4536629a] OpenBLAS_jll v0.3.20+0 `@stdlib/OpenBLAS_jll`
  [8e850b90] libblastrampoline_jll v5.1.1+0 `@stdlib/libblastrampoline_jll`
        Info Packages marked with ⌃ have new versions available and may be upgradable.
     Testing Running tests...
ReadData: Test Failed at /Users/michel/Projects/MISR/MISR_Toolkit.1.5/JMtk15/test/runtests.jl:1298
  Expression: Int.(transpose(databuf[461:466, 67:71])) == Int.([1 1 1 1 1 1; 1 1 1 2 2 2; 1 1 2 2 3 2; 2 2 3 3 2 3; 3 3 3 3 2 2])
   Evaluated: [255 255 … 0 240; 255 255 … 128 47; … ; 255 255 … 32 141; 255 255 … 0 240] == [1 1 … 1 1; 1 1 … 2 2; … ; 2 2 … 2 3; 3 3 … 2 2]
Stacktrace:
 [1] macro expansion
   @ ~/.julia/juliaup/julia-1.8.5+0.x64.apple.darwin14/share/julia/stdlib/v1.8/Test/src/Test.jl:464 [inlined]
 [2] macro expansion
   @ ~/Projects/MISR/MISR_Toolkit.1.5/JMtk15/test/runtests.jl:1298 [inlined]
 [3] macro expansion
   @ ~/.julia/juliaup/julia-1.8.5+0.x64.apple.darwin14/share/julia/stdlib/v1.8/Test/src/Test.jl:1363 [inlined]
 [4] macro expansion
   @ ~/Projects/MISR/MISR_Toolkit.1.5/JMtk15/test/runtests.jl:1296 [inlined]
 [5] macro expansion
   @ ~/.julia/juliaup/julia-1.8.5+0.x64.apple.darwin14/share/julia/stdlib/v1.8/Test/src/Test.jl:1363 [inlined]
 [6] top-level scope
   @ ~/Projects/MISR/MISR_Toolkit.1.5/JMtk15/test/runtests.jl:6
Test Summary: | Pass  Fail  Total  Time
JMtk15.jl     |  440     1    441  4.6s
  Util        |   10           10  0.1s
  FileQuery   |  293          293  1.6s
  UnitConv    |   12           12  0.1s
  CoordQuery  |   21           21  1.4s
  MapQuery    |   28           28  0.6s
  OrbitPath   |   13           13  0.3s
  SetRegion   |   45           45  0.1s
  ReadData    |   18     1     19  0.4s
ERROR: LoadError: Some tests did not pass: 440 passed, 1 failed, 0 errored, 0 broken.
in expression starting at /Users/michel/Projects/MISR/MISR_Toolkit.1.5/JMtk15/test/runtests.jl:5
ERROR: Package JMtk15 errored during testing

For reference, the native values read from the data file are of type UInt8. I don’t understand why the very same commands yield different outcomes in the REPL and in the test environment. Comments and suggestions will be much appreciated.

So something is changed in databuf. I would add some debug output in jMtkReadData_tst_0100() to try and see where the two situations diverge. One difference with the test environment is that it forces bounds checking to be on which can in some cases change some optimizations (for example @simd) but I am not sure it is applicable to this case.

Hi Kristoffer,

Thanks for your quick response. I have introduced a couple of println statements in the wrapper function src/jMtkReadData.jl to document the type of databuf as it is originally created, and modified the test/runtests.jl function to replace

@test Int.(transpose(databuf[461:466, 67:71])) == Int.([
                1  1  1  1  1  1
                1  1  1  2  2  2
                1  1  2  2  3  2
                2  2  3  3  2  3
                3  3  3  3  2  2])

by

@test UInt8.(transpose(databuf[461:466, 67:71])) == UInt8.([
                1  1  1  1  1  1
                1  1  1  2  2  2
                1  1  2  2  3  2
                2  2  3  3  2  3
                3  3  3  3  2  2])

When I run the unmodified test function test/src/src/jMtkReadData_tst_0100.jl in REPL, the outcome is

julia> using JMtk15

julia> include(JMtk15_test * "src/jMtkReadData_tst_0100.jl")
jMtkReadData_tst_0100

julia> databuf, mapinfo = jMtkReadData_tst_0100();
In jMtkReadData, typeof(databuf) = Base.RefValue{MTKt_DataBuffer}, ct = UInt8
    and typeof(julia_databuf) = Matrix{UInt8}

julia> typeof(databuf)
Matrix{UInt8} (alias for Array{UInt8, 2})

julia> @test UInt8.(transpose(databuf[461:466, 67:71])) == UInt8.([
        1  1  1  1  1  1
        1  1  1  2  2  2
        1  1  2  2  3  2
        2  2  3  3  2  3
        3  3  3  3  2  2])
Test Passed

as before, and when I run the whole set of tests, with the modifications (IntUInt8) described above, I get

(JMtk15) pkg> test JMtk15
     Testing JMtk15
      Status `/private/var/folders/st/q_mz5gzn2g3blprp2kvqnhr00000gn/T/jl_gQIpLI/Project.toml`
  [6c71635d] JMtk15 v0.1.0 `~/Projects/MISR/MISR_Toolkit.1.5/JMtk15`
  [8dfed614] Test `@stdlib/Test`
      Status `/private/var/folders/st/q_mz5gzn2g3blprp2kvqnhr00000gn/T/jl_gQIpLI/Manifest.toml`
  [fa961155] CEnum v0.4.2
  [bd334432] InlineTest v0.2.0
  [6c71635d] JMtk15 v0.1.0 `~/Projects/MISR/MISR_Toolkit.1.5/JMtk15`
  [e0db7c4e] ReTest v0.3.2
⌃ [90137ffa] StaticArrays v1.5.19
  [1e83bf80] StaticArraysCore v1.4.0
  [354b36f9] StringViews v1.3.0
  [56f22d72] Artifacts `@stdlib/Artifacts`
  [2a0f44e3] Base64 `@stdlib/Base64`
  [8ba89e20] Distributed `@stdlib/Distributed`
  [b77e0a4c] InteractiveUtils `@stdlib/InteractiveUtils`
  [8f399da3] Libdl `@stdlib/Libdl`
  [37e2e46d] LinearAlgebra `@stdlib/LinearAlgebra`
  [56ddb016] Logging `@stdlib/Logging`
  [d6f4376e] Markdown `@stdlib/Markdown`
  [de0858da] Printf `@stdlib/Printf`
  [9a3f8284] Random `@stdlib/Random`
  [ea8e919c] SHA v0.7.0 `@stdlib/SHA`
  [9e88b42a] Serialization `@stdlib/Serialization`
  [6462fe0b] Sockets `@stdlib/Sockets`
  [2f01184e] SparseArrays `@stdlib/SparseArrays`
  [10745b16] Statistics `@stdlib/Statistics`
  [8dfed614] Test `@stdlib/Test`
  [4ec0a83e] Unicode `@stdlib/Unicode`
  [e66e0078] CompilerSupportLibraries_jll v1.0.1+0 `@stdlib/CompilerSupportLibraries_jll`
  [4536629a] OpenBLAS_jll v0.3.20+0 `@stdlib/OpenBLAS_jll`
  [8e850b90] libblastrampoline_jll v5.1.1+0 `@stdlib/libblastrampoline_jll`
        Info Packages marked with ⌃ have new versions available and may be upgradable.
Precompiling project...
  1 dependency successfully precompiled in 7 seconds. 9 already precompiled.
  1 dependency precompiled but a different version is currently loaded. Restart julia to access the new version
     Testing Running tests...
In jMtkReadData, typeof(databuf) = Base.RefValue{MTKt_DataBuffer}, ct = Float32
    and typeof(julia_databuf) = Matrix{Float32}
In jMtkReadData, typeof(databuf) = Base.RefValue{MTKt_DataBuffer}, ct = Float64
    and typeof(julia_databuf) = Matrix{Float64}
In jMtkReadData, typeof(databuf) = Base.RefValue{MTKt_DataBuffer}, ct = Float32
    and typeof(julia_databuf) = Matrix{Float32}
In jMtkReadData, typeof(databuf) = Base.RefValue{MTKt_DataBuffer}, ct = UInt16
    and typeof(julia_databuf) = Matrix{UInt16}
In jMtkReadData, typeof(databuf) = Base.RefValue{MTKt_DataBuffer}, ct = UInt8
    and typeof(julia_databuf) = Matrix{UInt8}
In jMtkReadData, typeof(databuf) = Base.RefValue{MTKt_DataBuffer}, ct = Float32
    and typeof(julia_databuf) = Matrix{Float32}
In jMtkReadData, typeof(databuf) = Base.RefValue{MTKt_DataBuffer}, ct = Float32
    and typeof(julia_databuf) = Matrix{Float32}
In jMtkReadData, typeof(databuf) = Base.RefValue{MTKt_DataBuffer}, ct = Int16
    and typeof(julia_databuf) = Matrix{Int16}
In jMtkReadData, typeof(databuf) = Base.RefValue{MTKt_DataBuffer}, ct = Float64
    and typeof(julia_databuf) = Matrix{Float64}
In jMtkReadData, typeof(databuf) = Base.RefValue{MTKt_DataBuffer}, ct = UInt16
    and typeof(julia_databuf) = Matrix{UInt16}
In jMtkReadData, typeof(databuf) = Base.RefValue{MTKt_DataBuffer}, ct = UInt16
    and typeof(julia_databuf) = Matrix{UInt16}
In jMtkReadData, typeof(databuf) = Base.RefValue{MTKt_DataBuffer}, ct = UInt8
    and typeof(julia_databuf) = Matrix{UInt8}
In jMtkReadData, typeof(databuf) = Base.RefValue{MTKt_DataBuffer}, ct = Int8
    and typeof(julia_databuf) = Matrix{Int8}
In jMtkReadData, typeof(databuf) = Base.RefValue{MTKt_DataBuffer}, ct = Float32
    and typeof(julia_databuf) = Matrix{Float32}
In jMtkReadData, typeof(databuf) = Base.RefValue{MTKt_DataBuffer}, ct = Int16
    and typeof(julia_databuf) = Matrix{Int16}
In jMtkReadData, typeof(databuf) = Base.RefValue{MTKt_DataBuffer}, ct = Float64
    and typeof(julia_databuf) = Matrix{Float64}
In jMtkReadData, typeof(databuf) = Base.RefValue{MTKt_DataBuffer}, ct = UInt16
    and typeof(julia_databuf) = Matrix{UInt16}
In jMtkReadData, typeof(databuf) = Base.RefValue{MTKt_DataBuffer}, ct = UInt16
    and typeof(julia_databuf) = Matrix{UInt16}
In jMtkReadData, typeof(databuf) = Base.RefValue{MTKt_DataBuffer}, ct = UInt8
    and typeof(julia_databuf) = Matrix{UInt8}
In jMtkReadData, typeof(databuf) = Base.RefValue{MTKt_DataBuffer}, ct = Int8
    and typeof(julia_databuf) = Matrix{Int8}
In jMtkReadData, typeof(databuf) = Base.RefValue{MTKt_DataBuffer}, ct = Float32
    and typeof(julia_databuf) = Matrix{Float32}
In jMtkReadData, typeof(databuf) = Base.RefValue{MTKt_DataBuffer}, ct = Int16
    and typeof(julia_databuf) = Matrix{Int16}
In jMtkReadData, typeof(databuf) = Base.RefValue{MTKt_DataBuffer}, ct = Float64
    and typeof(julia_databuf) = Matrix{Float64}
In jMtkReadData, typeof(databuf) = Base.RefValue{MTKt_DataBuffer}, ct = UInt16
    and typeof(julia_databuf) = Matrix{UInt16}
In jMtkReadData, typeof(databuf) = Base.RefValue{MTKt_DataBuffer}, ct = UInt16
    and typeof(julia_databuf) = Matrix{UInt16}
In jMtkReadData, typeof(databuf) = Base.RefValue{MTKt_DataBuffer}, ct = UInt8
    and typeof(julia_databuf) = Matrix{UInt8}
In jMtkReadData, typeof(databuf) = Base.RefValue{MTKt_DataBuffer}, ct = Int8
    and typeof(julia_databuf) = Matrix{Int8}
In jMtkReadData, typeof(databuf) = Base.RefValue{MTKt_DataBuffer}, ct = Float32
    and typeof(julia_databuf) = Matrix{Float32}
In jMtkReadData, typeof(databuf) = Base.RefValue{MTKt_DataBuffer}, ct = UInt8
    and typeof(julia_databuf) = Matrix{UInt8}
Test Summary: | Pass  Total  Time
JMtk15.jl     |  441    441  4.6s
     Testing JMtk15 tests passed 

(JMtk15) pkg> 

So now the unchanged test function test/src/jMtkReadData_tst_0100.jl is running fine within the @testset, but the diagnostic println statements are generated 29 times, instead of just once: it’s as if that function was run multiple times. In any case, I haven’t really changed the logic and only imposed the test to occur on UInt8 values instead of Int values…

So I don’t understand why casting both sides of the test equation to the same Int would yield a result different than casting them to UInt8.

Thanks for elucidating this issue.

Update: I may have found the source of the problem:

The C function MtkReadData.c returns a data buffer structure which contains metadata as well as the desired data array; the type of the latter varies with the data file and field being read. The src/jMtkReadData.jl wrapper to that function creates a Ref pointer to that data buffer structure, and I used to GC.@preserve the data array element of that structure instead of GC.@preserve the whole buffer structure.

I also turned the keyword own = true in the subsequent unsafe_wrap, which (presumably) now relies on the Julia Garbage Collector to dispose of the memory used for the buffer when it is not needed anymore. This was previously done with the C function MtkDataBufferFree.c provided in the shared library.

I don’t know whether this approach is appropriate or recommended, and I can’t explain why it works, but it does… for the time being. I also still do not understand why a println statement in the wrapper function still gets printed some 29 times when the test function gets called.