Skip to content
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.

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

Fix of custom GDAL error handler management by deregistrating it at exit (done in __init__()). Plus a few modifications on GDAL utilities' tests and #245

Merged

Conversation

mathieu17g
Copy link
Collaborator

@mathieu17g mathieu17g commented Sep 28, 2021

Fixes #241 and some other issues in GDAL utilities tests

  • include("test_gdalutilities.jl"): that's where the GDAL error is written to stderr "CPLDestroyMutex: Error = 16 (Resource busy)"
  • include("test_rasterattrtable.jl"): produces a warning "There is no linear binning information." -> maybe it should be handled
  • include("test_ospy_examples.jl"): produces a timing output. Is it necessary to keep the @time that must linger within ?
  • include("test_images.jl"): Maybe add GDAL import at the beginning instead of relying on other test files

Copy link
Collaborator Author

@mathieu17g mathieu17g left a comment

Choose a reason for hiding this comment

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

@visr, I have narrowed the issue to one test on AG.gdalinfo throwing an error
As evoked in GDAL GDALInfo()'s docstring, isn't it the result of GDAL GDALInfo() that has to be freed ?

EDIT: Well, I misread the docstring, in case of error GDALInfo() returns NULL, so there should not be any result to free.
The mystery thickens :-)

Copy link
Collaborator Author

@mathieu17g mathieu17g left a comment

Choose a reason for hiding this comment

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

Putting GDAL.gdalinfo within AG.gdalinfo, in a try... finally block to free options, does not solve the issue either

EDIT1: no use in the current case since the error occurs in GDAL GDALInfoOptionsNew() before calling GDAL GDALInfo(). But it can't hurt.

Copy link
Collaborator Author

@mathieu17g mathieu17g left a comment

Choose a reason for hiding this comment

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

Maybe it has something to do with AG.gdalinfo's options local variable interfered by options arg -> No :-(

@visr would it be interesting to activate some debug on GDAL (if feasible)?

EDIT : I have tried with AG.setconfigoption("CPL_DEBUG", "ON"), but nothing interesting comes out

julia> using ArchGDAL; const AG = ArchGDAL
ArchGDAL

julia> AG.setconfigoption("CPL_DEBUG", "ON")

julia> AG.getconfigoption("CPL_DEBUG")
"ON"

julia> AG.read("data/utmsmall.tif") do ds_small
           AG.gdalinfo(ds_small, ["-novalidoption"])
       end
ERROR: GDALError (CE_Failure, code 6):
	Unknown option name '-novalidoption'

Stacktrace:
 [1] gdaljl_errorhandler(class::GDAL.CPLErr, errno::Int32, errmsg::Cstring)
   @ GDAL ~/.julia/packages/GDAL/ycHfN/src/error.jl:36
 [2] gdalinfooptionsnew(papszArgv::Vector{String}, psOptionsForBinary::Ptr{Nothing})
   @ GDAL ~/.julia/packages/GDAL/ycHfN/src/GDAL.jl:18417
 [3] gdalinfo(dataset::ArchGDAL.Dataset, options::Vector{String})
   @ ArchGDAL ~/.julia/packages/ArchGDAL/zkx2f/src/utilities.jl:15
 [4] #1
   @ ./REPL[4]:2 [inlined]
 [5] read(f::var"#1#2", args::String; kwargs::Base.Iterators.Pairs{Union{}, Union{}, Tuple{}, NamedTuple{(), Tuple{}}})
   @ ArchGDAL ~/.julia/packages/ArchGDAL/zkx2f/src/context.jl:267
 [6] read(f::Function, args::String)
   @ ArchGDAL ~/.julia/packages/ArchGDAL/zkx2f/src/context.jl:265
 [7] top-level scope
   @ REPL[4]:1

julia> exit()
CPLDestroyMutex: Error = 16 (Resource busy)


[Opération terminée]

Copy link
Collaborator Author

@mathieu17g mathieu17g left a comment

Choose a reason for hiding this comment

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

Tried to test errored AG.gdalinfo with @test instead of @test_throws: issue not solved

@mathieu17g
Copy link
Collaborator Author

mathieu17g commented Sep 29, 2021

Maybe the issue turns around catching GDAL.GDALError ? Here is below a test with and without catching the error and and test with a valid option. All three followed by an exit()` -> No link with catching the error

  • Catching the error
julia> using ArchGDAL; const AG = ArchGDAL
ArchGDAL

julia> cd("/Users/Mathieu/.julia/dev/ArchGDAL/test/")

julia> AG.read("data/utmsmall.tif") do ds_small
           try
               AG.gdalinfo(
                   ds_small,
                   ["-novalidoption"],
               )
           catch e
               string(e)
           end
       end
"GDAL.GDALError(GDAL.CE_Failure, 6, \"Unknown option name '-novalidoption'\")"

julia> exit()
CPLDestroyMutex: Error = 16 (Resource busy)

[Opération terminée]
  • Without catching the error:
julia> using ArchGDAL; const AG = ArchGDAL
ArchGDAL

julia> cd("/Users/Mathieu/.julia/dev/ArchGDAL/test/")

julia> AG.read("data/utmsmall.tif") do ds_small
           AG.gdalinfo(ds_small, ["-novalidoption"])
       end
ERROR: GDALError (CE_Failure, code 6):
	Unknown option name '-novalidoption'

Stacktrace:
 [1] gdaljl_errorhandler(class::GDAL.CPLErr, errno::Int32, errmsg::Cstring)
   @ GDAL ~/.julia/packages/GDAL/ycHfN/src/error.jl:36
 [2] gdalinfooptionsnew(papszArgv::Vector{String}, psOptionsForBinary::Ptr{Nothing})
   @ GDAL ~/.julia/packages/GDAL/ycHfN/src/GDAL.jl:18417
 [3] gdalinfo(dataset::ArchGDAL.Dataset, options::Vector{String})
   @ ArchGDAL ~/.julia/packages/ArchGDAL/zkx2f/src/utilities.jl:15
 [4] #1
   @ ./REPL[3]:2 [inlined]
 [5] read(f::var"#1#2", args::String; kwargs::Base.Iterators.Pairs{Union{}, Union{}, Tuple{}, NamedTuple{(), Tuple{}}})
   @ ArchGDAL ~/.julia/packages/ArchGDAL/zkx2f/src/context.jl:267
 [6] read(f::Function, args::String)
   @ ArchGDAL ~/.julia/packages/ArchGDAL/zkx2f/src/context.jl:265
 [7] top-level scope
   @ REPL[3]:1

julia> exit()
CPLDestroyMutex: Error = 16 (Resource busy)

[Opération terminée]

-> No link with catching the error

  • Call with a valid option, does raise the issue:
julia> using ArchGDAL; const AG = ArchGDAL
ArchGDAL

julia> cd("/Users/Mathieu/.julia/dev/ArchGDAL/test/")

julia> AG.read("data/utmsmall.tif") do ds_small
           AG.gdalinfo(ds_small, ["-stats"])
       end
"Driver: GTiff/GeoTIFF\nFiles: data/utmsmall.tif\nSize is 100, 100\nCoordinate System is:\nPROJCRS[\"NAD27 / UTM zone 11N\",\n    BASEGEOGCRS[\"NAD27\",\n        DATUM[\"North American Datum 1927\",\n            ELLIPSOID[\"Clarke 1866\",6378206.4,294.978698213898,\n                LENGTHUNIT[\"metre\",1]]],\n        PRIMEM[\"Greenwich\",0,\n            ANGLEUNIT[\"degree\",0.0174532925199433]],\n        ID[\"EPSG\",4267]],\n    CONVERSION[\"Transverse Mercator\",\n        METHOD[\"Transverse Mercator\",\n            ID[\"EPSG\",9807]],\n        PARAMETER[\"Latitude of natural origin\",0,\n            ANGLEUNIT[\"degree\",0.0174532925199433],\n            ID[\"EPSG\",8801]],\n        PARAMETER[\"Longitude of natural origin\",-117,\n            ANGLEUNIT[\"degree\",0.0174532925199433],\n            ID[\"EPSG\",8802]],\n        PARAMETER[\"Scale factor at natural origin\",0.9996,\n            SCALEUNIT[\"unity\",1],\n            ID[\"EPSG\",8805]],\n        PARAMETER[\"False easting\",500000,\n            LENGTHUNIT[\"metre\",1],\n            ID[\"EPSG\",8806]],\n        PARAMETER[\"False northing\",0,\n            LENGTHUNIT[\"metre\",1],\n            ID[\"EPSG\",8807]]],\n    CS[Cartesian,2],\n        AXIS[\"easting\",east,\n            ORDER[1],\n            LENGTHUNIT[\"metre\",1]],\n        AXIS[\"northing\",north,\n            ORDER[2],\n            LENGTHUNIT[\"metre\",1]],\n    ID[\"EPSG\",26711]]\nData axis to CRS axis mapping: 1,2\nOrigin = (440720.000000000000000,3751320.000000000000000)\nPixel Size = (60.000000000000000,-60.000000000000000)\nMetadata:\n  AREA_OR_POINT=Area\nImage Structure Metadata:\n  INTERLEAVE=BAND\nCorner Coordinates:\nUpper Left  (  440720.000, 3751320.000) (117d38'28.21\"W, 33d54' 8.47\"N)\nLower Left  (  440720.000, 3745320.000) (117d38'26.75\"W, 33d50'53.66\"N)\nUpper Right (  446720.000, 3751320.000) (117d34'34.59\"W, 33d54' 9.62\"N)\nLower Right (  446720.000, 3745320.000) (117d34'33.28\"W, 33d50'54.82\"N)\nCenter      (  443720.000, 3748320.000) (117d36'30.71\"W, 33d52'31.66\"N)\nBand 1 Block=100x81 Type=Byte, ColorInterp=Gray\n  Minimum=0.000, Maximum=255.000, Mean=154.621, StdDev=54.251\n  Metadata:\n    STATISTICS_MAXIMUM=255\n    STATISTICS_MEAN=154.6212\n    STATISTICS_MINIMUM=0\n    STATISTICS_STDDEV=54.250980733624\n    STATISTICS_VALID_PERCENT=100\n"

julia> exit()

[Opération terminée]

@mathieu17g
Copy link
Collaborator Author

No more ideas.
I clean up and mark the PR as final with the three corrections.
I will put the last tests in the issue for later investigations.

@mathieu17g mathieu17g marked this pull request as ready for review September 29, 2021 15:45
Copy link
Owner

@yeesian yeesian left a comment

Choose a reason for hiding this comment

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

Yeah I don't think it's necessary to keep the time macro, and your other observations are all on point, thank you!

test/test_gdalutilities.jl Outdated Show resolved Hide resolved
@yeesian yeesian requested a review from visr September 30, 2021 06:08
Copy link
Collaborator

@visr visr left a comment

Choose a reason for hiding this comment

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

Looks like a good improvement, thanks!

would it be interesting to activate some debug on GDAL (if feasible)?

Woud be! Unfortunately I don't really have other ideas for how to achieve this. You could try in https://github.com/JuliaGeo/GDAL.jl/blob/master/src/error.jl to be stricter, and raise warnings or errors on CE_Warning, now it is set to CE_Failure.

@mathieu17g
Copy link
Collaborator Author

You could try in https://github.com/JuliaGeo/GDAL.jl/blob/master/src/error.jl to be stricter, and raise warnings or errors on CE_Warning, now it is set to CE_Failure.

Nothing comes out

Maybe in the DriverManager finalization. I'll have a look...

Copy link
Collaborator Author

@mathieu17g mathieu17g left a comment

Choose a reason for hiding this comment

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

@visr and @yeesian, in the current code there is no real link between ArchGDAL.DRIVER_MANAGER and GDAL DriverManager

If you have the same reading I suggest to either:

  1. try the modifications of this commit. They have, in prerequisite, the creation in GDAL.jl of (I don't know if it can be done) :
  • type GDAL.GDALDriverManager
  • function GDAL.getgdaldrivermanager() calling GDAL GetGDALDriverManager()

Plus maybe in the destroy(::DriverManager):
a. deregister the custom error handler function by restoring the default with GDAL.seterrorhandler(C_NULL)
b. ...?

  1. just drop the mapping of the drivermanager
    EDIT: tested -> no positive consequence on the issue

Copy link
Collaborator Author

@mathieu17g mathieu17g left a comment

Choose a reason for hiding this comment

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

Deregistering gdaljl_errorhandler C function at exit works :-)
@visr, Maybe it could be done in GDAL.jl __init__() function

@visr, @yeesian, what about the proposition around the mapping of GDAL DriverManager in ArchGDAL:

  • suppression?
  • modification?
  • leave it as it is?

Copy link
Owner

@yeesian yeesian left a comment

Choose a reason for hiding this comment

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

Regarding your question: my vote is to drop the driver manager mapping: this PR looks good to me once we've deleted all the redundant comments. I double-checked with the original commit in b140d51 and think this is a much cleaner way of managing the drivers -- thank you for investigating!

src/ArchGDAL.jl Outdated Show resolved Hide resolved
src/ArchGDAL.jl Outdated Show resolved Hide resolved
src/ArchGDAL.jl Outdated Show resolved Hide resolved
@yeesian
Copy link
Owner

yeesian commented Oct 1, 2021

Might be worth also updating the PR title to reflect proper finalization of driver management (by deregistering the error handler).

@yeesian yeesian linked an issue Oct 1, 2021 that may be closed by this pull request
@mathieu17g mathieu17g changed the title Modification of tests on GDAL utilities Fix of on custom GDAL error handler management by deregistrating it at exit (done in __init__()). Plus a few modifications on GDAL utilities' tests and Oct 1, 2021
@mathieu17g mathieu17g changed the title Fix of on custom GDAL error handler management by deregistrating it at exit (done in __init__()). Plus a few modifications on GDAL utilities' tests and Fix of custom GDAL error handler management by deregistrating it at exit (done in __init__()). Plus a few modifications on GDAL utilities' tests and Oct 1, 2021
@visr
Copy link
Collaborator

visr commented Oct 2, 2021

I don't fully understand. Now GDAL.jl deregisters the custom error handler on exit, which looks like a good thing.

But why does this PR remove the call to GDAL.gdaldestroydrivermanager()? Isn't that the counterpart to GDAL.gdalallregister() that is called when ArchGDAL loads? Should gdaldestroydrivermanager be called onexit here?

src/ArchGDAL.jl Outdated Show resolved Hide resolved
@mathieu17g
Copy link
Collaborator Author

Now we should be good to go :-)

src/ArchGDAL.jl Outdated Show resolved Hide resolved
Copy link
Collaborator Author

@mathieu17g mathieu17g left a comment

Choose a reason for hiding this comment

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

Comments could have been:

    # As gdaldestroy() is registered first in Julia exit hooks 
    # (and then called last) in GDAL.jl/gen/epilogue.jl __init__() function, 
    # we don't have to:
    # - deregister of gdaljl_errorhandler (used to raise an error in Julia 
    #   when a GDAL error with level CEFailure is raised)
    # - destroy of the GDALDriverManager 

But the discussion in this PR should be enough for later reference to explain what cleanup should have been done if not handled in GDAL.jl

@mathieu17g
Copy link
Collaborator Author

Oops, I rebased to master and got all those new commit reappearing in this pull request.
@yeesian I hope I rebased the right way...

@yeesian
Copy link
Owner

yeesian commented Oct 9, 2021

Hmm, might it be easier to bail on this PR and start a new one? Sorry for the churn

@mathieu17g
Copy link
Collaborator Author

Is there a way, on GitHub, to rebase a pull request ?
Otherwise how do you delete a PR ? I have not found the button :-)

@yeesian
Copy link
Owner

yeesian commented Oct 9, 2021

Oh we'll be closing the PR rather than deleting it -- but happy to keep the PR open as long as we still find it helpful as a reference

@yeesian
Copy link
Owner

yeesian commented Oct 9, 2021

Is there a way, on GitHub, to rebase a pull request ?

Unfortunately, I don't think it's straightforward if it isn't a "fastforward merge" (from what I've read in https://docs.github.com/en/repositories/configuring-branches-and-merges-in-your-repository/configuring-pull-request-merges/about-merge-methods-on-github#rebasing-and-merging-your-commits)

@mathieu17g mathieu17g mentioned this pull request Oct 9, 2021
10 tasks
@mathieu17g mathieu17g force-pushed the debug_CPLDestroyMutex_Error_with_Pkg_test branch from dd16c0e to a3c36a8 Compare October 9, 2021 08:52
@mathieu17g mathieu17g force-pushed the debug_CPLDestroyMutex_Error_with_Pkg_test branch from a3c36a8 to a797de6 Compare October 9, 2021 09:25
Copy link
Owner

@yeesian yeesian left a comment

Choose a reason for hiding this comment

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

There isn't a good way to mark a PR as being blocked by another, so I'll use this comment for now to indicate the dependency on JuliaGeo/GDAL.jl#124. It can be resolved once that PR has been merged and a new release of GDAL.jl is made.

src/ArchGDAL.jl Show resolved Hide resolved
@yeesian yeesian merged commit 43e1408 into yeesian:master Oct 11, 2021
@yeesian
Copy link
Owner

yeesian commented Oct 11, 2021

Thank you!

@mathieu17g mathieu17g deleted the debug_CPLDestroyMutex_Error_with_Pkg_test branch October 11, 2021 04:16
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

CPLDestroyMutex: Error = 16 (Device or resource busy)
3 participants