Test failure in 'nc_test4_tst_filter' on Linux with netcdf v4.8.1

[abhibaruah]

netcdf version: 4.8.1
OS: Debian 10
Compiler: gcc version 8.3.0
hdf5 version: 1.8.12

While trying to build netcdf, I see the following failure in the C tests shipped with netcdf.

 76/209 Testing: nc_test4_tst_filter
 76/209 Test: nc_test4_tst_filter
 Command: "/usr/local/bin/bash" "-c" "export srcdir=/mathworks/devel/sandbox/abaruah/3p-tmw/3p/derived/glnxa64/netcdf/nc_test4;export TOPSRCDIR=/mathworks/devel/sandbox/abaruah/3p-tmw/3p/derived/glnxa64/netcdf;/mathworks/devel/sandbox/abaruah/3p-tmw/3p/derived/glnxa64/netcdf/nc_test4/tst_filter.sh "
 Directory: /mathworks/devel/sandbox/abaruah/3p-tmw/3p/derived/glnxa64/netcdf/nc_test4
 "nc_test4_tst_filter" start time: Sep 07 09:39 EDT
 Output:
 ----------------------------------------------------------
 findplugin.sh loaded
 final HDF5_PLUGIN_PATH=/mathworks/devel/sandbox/abaruah/3p-tmw/3p/derived/glnxa64/netcdf/plugins
 *** Testing dynamic filters using API
 fail (225): NetCDF: Filter error: unimplemented filter encountered

 *** Testing API: bzip2 compression.
 show parameters for bzip2: level=9
 show chunks: chunks=4,4,4,4
 <end of output>
 Test time = 0.06 sec
 ----------------------------------------------------------
 Test Failed.
 "nc_test4_tst_filter" end time: Sep 07 09:39 EDT
 "nc_test4_tst_filter" time elapsed: 00:00:00

My guess is that one of the following changes made in netcdf v4.8.1 might be responsible for the failure that we are seeing:
#2000
#1969

Noteworthy to mention here that we are still using hdf5 version 1.8.12 with netcdf.

It would be really helpful if the developers at Unidata can help us resolve this issue?

[DennisHeimbigner]

See if you can find the file called ' libh5bzip2.so'
If so, then run this command

nm libh5bzip2.so

and post the output here as text attachment.
This will tell me if the entry points are defined properly in the bzip2 compressor.

[abhibaruah]

nm_output.txt

Please find the output of the command
nm libh5bzip2.so
attached

[abhibaruah]

I tried to dig a little into the source of the error, and it seems like the error is originating from line 225 of netcdf/nc_test4/test_filter.c

/* write array */
    CHECK(nc_put_var(ncid,varid,expected));

[abhibaruah]

I tried to printf the error code on line 225

int returnid = nc_put_var(ncid,varid,expected);
printf("Returnid = %d", returnid);

Returnid = -136

[DennisHeimbigner]

What is the full file path for libh5bzip2.so

[abhibaruah]

\netcdf\plugins\libh5bzip2.so

[DennisHeimbigner]

So the full path is

/mathworks/devel/sandbox/abaruah/3p-tmw/3p/derived/glnxa64/netcdf/plugins/libh5bzip2.so

[abhibaruah]

Correct

[DennisHeimbigner]

I guess I need to see the full output of the tst_filter.sh script.
Can you add 'set -x' to it and rerun and send me the output?

[abhibaruah]

Hello Dennis,
I added 'set -x' to tst_filter.sh and here is the additional output that was logged to LastTest.log

76/198 Testing: nc_test4_tst_filter
76/198 Test: nc_test4_tst_filter
Command: "/usr/local/bin/bash" "-c" "export srcdir=/mathworks/devel/sandbox/abaruah/3p-tmw/3p/derived/glnxa64/netcdf/nc_test4;export TOPSRCDIR=/mathworks/devel/sandbox/abaruah/3p-tmw/3p/derived/glnxa64/netcdf;/mathworks/devel/sandbox/abaruah/3p-tmw/3p/derived/glnxa64/netcdf/nc_test4/tst_filter.sh "
Directory: /mathworks/devel/sandbox/abaruah/3p-tmw/3p/derived/glnxa64/netcdf/nc_test4
"nc_test4_tst_filter" start time: Sep 11 10:19 EDT
Output:
----------------------------------------------------------
+ API=1
+ NG=1
+ NCP=1
+ UNK=1
+ NGC=1
+ MISC=1
+ MULTI=1
+ REP=1
+ ORDER=1
+ . /mathworks/devel/sandbox/abaruah/3p-tmw/3p/derived/glnxa64/netcdf/nc_test4/findplugin.sh
+ echo 'findplugin.sh loaded'
findplugin.sh loaded
+ findplugin h5bzip2
+ FP_NAME=h5bzip2
+ FP_ISCMAKE=1
+ FP_ISMSVC=
+ FP_ISCYGWIN=
+ FP_ISOSX=
+ FP_PLUGINS=/mathworks/devel/sandbox/abaruah/3p-tmw/3p/derived/glnxa64/netcdf/plugins
+ FP_PLUGIN_LIB=
+ FP_PLUGIN_PATH=
+ test x '!=' x
+ test x '!=' x
+ test x '!=' x
+ FP_PLUGIN_LIB=libh5bzip2.so
+ test x1 '!=' x -a x '!=' x
+ test -f /mathworks/devel/sandbox/abaruah/3p-tmw/3p/derived/glnxa64/netcdf/plugins/.libs/libh5bzip2.so
+ test -f /mathworks/devel/sandbox/abaruah/3p-tmw/3p/derived/glnxa64/netcdf/plugins/libh5bzip2.so
+ FP_PLUGIN_PATH=/mathworks/devel/sandbox/abaruah/3p-tmw/3p/derived/glnxa64/netcdf/plugins
+ test x/mathworks/devel/sandbox/abaruah/3p-tmw/3p/derived/glnxa64/netcdf/plugins = x
+ test -f /mathworks/devel/sandbox/abaruah/3p-tmw/3p/derived/glnxa64/netcdf/plugins/libh5bzip2.so
+ test x '!=' x -a x '!=' x
+ HDF5_PLUGIN_LIB=libh5bzip2.so
+ HDF5_PLUGIN_PATH=/mathworks/devel/sandbox/abaruah/3p-tmw/3p/derived/glnxa64/netcdf/plugins
+ return 0
+ BZIP2LIB=libh5bzip2.so
+ BZIP2PATH=/mathworks/devel/sandbox/abaruah/3p-tmw/3p/derived/glnxa64/netcdf/plugins/libh5bzip2.so
+ findplugin misc
+ FP_NAME=misc
+ FP_ISCMAKE=1
+ FP_ISMSVC=
+ FP_ISCYGWIN=
+ FP_ISOSX=
+ FP_PLUGINS=/mathworks/devel/sandbox/abaruah/3p-tmw/3p/derived/glnxa64/netcdf/plugins
+ FP_PLUGIN_LIB=
+ FP_PLUGIN_PATH=
+ test x '!=' x
+ test x '!=' x
+ test x '!=' x
+ FP_PLUGIN_LIB=libmisc.so
+ test x1 '!=' x -a x '!=' x
+ test -f /mathworks/devel/sandbox/abaruah/3p-tmw/3p/derived/glnxa64/netcdf/plugins/.libs/libmisc.so
+ test -f /mathworks/devel/sandbox/abaruah/3p-tmw/3p/derived/glnxa64/netcdf/plugins/libmisc.so
+ FP_PLUGIN_PATH=/mathworks/devel/sandbox/abaruah/3p-tmw/3p/derived/glnxa64/netcdf/plugins
+ test x/mathworks/devel/sandbox/abaruah/3p-tmw/3p/derived/glnxa64/netcdf/plugins = x
+ test -f /mathworks/devel/sandbox/abaruah/3p-tmw/3p/derived/glnxa64/netcdf/plugins/libmisc.so
+ test x '!=' x -a x '!=' x
+ HDF5_PLUGIN_LIB=libmisc.so
+ HDF5_PLUGIN_PATH=/mathworks/devel/sandbox/abaruah/3p-tmw/3p/derived/glnxa64/netcdf/plugins
+ return 0
+ MISCPATH=/mathworks/devel/sandbox/abaruah/3p-tmw/3p/derived/glnxa64/netcdf/plugins/libmisc.so
+ echo 'final HDF5_PLUGIN_PATH=/mathworks/devel/sandbox/abaruah/3p-tmw/3p/derived/glnxa64/netcdf/plugins'
final HDF5_PLUGIN_PATH=/mathworks/devel/sandbox/abaruah/3p-tmw/3p/derived/glnxa64/netcdf/plugins
+ export HDF5_PLUGIN_PATH
+ test -f /mathworks/devel/sandbox/abaruah/3p-tmw/3p/derived/glnxa64/netcdf/plugins/libh5bzip2.so
+ test -f /mathworks/devel/sandbox/abaruah/3p-tmw/3p/derived/glnxa64/netcdf/plugins/libmisc.so
+ HAVE_SZIP=0
+ test -f /mathworks/devel/sandbox/abaruah/3p-tmw/3p/derived/glnxa64/netcdf/libnetcdf.settings
+ grep 'SZIP Support:[ 	]*yes'
+ test x1 = x1
+ echo '*** Testing dynamic filters using API'
*** Testing dynamic filters using API
+ rm -f ./bzip2.nc ./bzip2.dump ./tst_filter.txt
+ /mathworks/devel/sandbox/abaruah/3p-tmw/3p/derived/glnxa64/netcdf/nc_test4/test_filter
fail (225): NetCDF: Filter error: unimplemented filter encountered

*** Testing API: bzip2 compression.
show parameters for bzip2: level=9
show chunks: chunks=4,4,4,4
<end of output>
Test time =   0.11 sec
----------------------------------------------------------
Test Failed.
"nc_test4_tst_filter" end time: Sep 11 10:19 EDT
"nc_test4_tst_filter" time elapsed: 00:00:00
----------------------------------------------------------

I am also attaching LastTest.log, in case it is helpful.

Thanks,
Abhi
LastTest.log

[DennisHeimbigner]

ok, the next step is a bit painful.
You need to rebuild netcdf with the --enable-logging option.
Then you need to set

export NETCDF_LOG_LEVEL=10

and then manually run tst_filter.sh
The resulting output is large, but you need to capture it and attach
that output to this issue.

[abhibaruah]

Hello Dennis,
I built netcdf with the 'ENABLE_LOGGING' flag set to 'ON' in CMakeLists.txt.
Next, I added 'export NETCDF_LOG_LEVEL=10' to tst_filter.sh.

Instead of manually running tst_filter.sh, I just built netcdf (the Makefile is configured to run the tests). I do get some extra output in LastTest.log.
Is this sufficient or do I have to manually run tst_filter.sh?

See the resulting output from LastTest.log in
output.log

[DennisHeimbigner]

I finally found the problem.
The semantics of H5Zfilter_avail changed sometime after HDF5 version 1.8.12.
In 1.8.12 and before, if the filter was not in the list of already loaded filters,
then it returned not-found.
Sometime after 1.8.12, this changed so that if the filter was not already loaded,
then H5Zfilter_avail attempted to load it.
Not sure what to do about this since I think 1.8.12 is actually no longer supported.

[abhibaruah]

Okay. We have plans to change the netcdf dependency on hdf5 from v1.8.12 to v1.10.7, but not sure when. Do you think changing dependency to hdf5-1.10.7 will resolve this issue?
Until then, is there an interim patch/solution for netcdf that will make the test pass?

[DennisHeimbigner]

Yes, I use 1.10.7 as my HDF5 for testing.
You do have another partial option.

1. edit netcdf-c/libhdf5/hdf5filter.c
2. find the call to H5Zfilter_avail and change that line to always return true.

This will have two consequences:

1. If you actually use a filter you do not have, then you will get some kind of HDF5 error when you actually read the data.
2. It is possible that some other tests fill fail. I think that adding --disable-filter-tests will fix that.

[DennisHeimbigner]

BTW, 1.10.x purportedly have some performance issues.
Our github actions test successfully using 1.8.21, so you can
probably just upgrade to that version if you want to stay with 1.8.x

[abhibaruah]

Thank for your help. For now, I think we will disable the filter plugin tests, and in a couple months, we will change the netcdf dependency on hdf5 from v1.8.12 to v1.10.7 (We are aware that this would introduce some performance regressions, but we have decided to go ahead nevertheless.). Once that is done, we will evaluate this again and will get back to you if we run into any issues with this.

[DennisHeimbigner]

This issue can be closed