ompi/v3.x.x bug since August 21: opal_datatype_pack.c:203 and opal_datatype_unpack.c:135

[ericch1]

Hi,

EDIT: I modified the mentioned SHAs in this first message since it contains wrong info about the wrong sha
up to commit d3587f5, everything was fine, but
as of commit 390e0bc, we have some tests that are failing with errors like this:

[dockercentos7:18478] opal_datatype_pack.c:203
	Pointer 0xdf6c970 size 9 is outside [0xdf6c880,0xdf6c969] for
	base ptr 0xdf6c880 count 10 and data 
[dockercentos7:18478] Datatype 0xa10f7a0[] size 17 align 8 id 0 length 4 used 3
true_lb 0 true_ub 17 (true_extent 17) lb 0 ub 24 (extent 24)
nbElems 3 loops 0 flags 114 (committed contiguous )-cC----GD--[---][---]
   contain OPAL_INT1:* OPAL_INT8:* OPAL_FLOAT8:* 
--C---P-D--[---][---]    OPAL_FLOAT8 count 1 disp 0x0 (0) blen 1 extent 8 (size 8)
--C---P-D--[---][---]      OPAL_INT8 count 1 disp 0x8 (8) blen 1 extent 8 (size 8)
--C---P-D--[---][---]      OPAL_INT1 count 1 disp 0x10 (16) blen 1 extent 1 (size 1)
-------G---[---][---]    OPAL_LOOP_E prev 3 elements first elem displacement 0 size of data 17
Optimized description 
-cC---P-DB-[---][---]     OPAL_UINT1 count 1 disp 0x0 (0) blen 8 extent 8 (size 8)
-cC---P-DB-[---][---]     OPAL_UINT1 count 1 disp 0x8 (8) blen 9 extent 9 (size 9)
-------G---[---][---]    OPAL_LOOP_E prev 2 elements first elem displacement 0 size of data 17

[dockercentos7:18478] opal_datatype_unpack.c:135
	Pointer 0xeb57a98 size 9 is outside [0xeb579a8,0xeb57a91] for
	base ptr 0xeb579a8 count 10 and data 
[dockercentos7:18478] Datatype 0xa10f7a0[] size 17 align 8 id 0 length 4 used 3
true_lb 0 true_ub 17 (true_extent 17) lb 0 ub 24 (extent 24)
nbElems 3 loops 0 flags 114 (committed contiguous )-cC----GD--[---][---]
   contain OPAL_INT1:* OPAL_INT8:* OPAL_FLOAT8:* 
--C---P-D--[---][---]    OPAL_FLOAT8 count 1 disp 0x0 (0) blen 1 extent 8 (size 8)
--C---P-D--[---][---]      OPAL_INT8 count 1 disp 0x8 (8) blen 1 extent 8 (size 8)
--C---P-D--[---][---]      OPAL_INT1 count 1 disp 0x10 (16) blen 1 extent 1 (size 1)
-------G---[---][---]    OPAL_LOOP_E prev 3 elements first elem displacement 0 size of data 17
Optimized description 
-cC---P-DB-[---][---]     OPAL_UINT1 count 1 disp 0x0 (0) blen 8 extent 8 (size 8)
-cC---P-DB-[---][---]     OPAL_UINT1 count 1 disp 0x8 (8) blen 9 extent 9 (size 9)
-------G---[---][---]    OPAL_LOOP_E prev 2 elements first elem displacement 0 size of data 17

Other example:

[dockercentos7:09967] opal_datatype_pack.c:203
	Pointer 0x8be7d78 size 9 is outside [0x8be4c40,0x8be7d71] for
	base ptr 0x8be4c40 count 525 and data 
[dockercentos7:09967] Datatype 0x8ab8650[] size 17 align 8 id 0 length 4 used 3
true_lb 0 true_ub 17 (true_extent 17) lb 0 ub 24 (extent 24)
nbElems 3 loops 0 flags 114 (committed contiguous )-cC----GD--[---][---]
   contain OPAL_INT8:* OPAL_BOOL:* 
--C---P-D--[---][---]      OPAL_INT8 count 1 disp 0x0 (0) blen 1 extent 8 (size 8)
--C---P-D--[---][---]      OPAL_INT8 count 1 disp 0x8 (8) blen 1 extent 8 (size 8)
--C---P-D--[---][---]      OPAL_BOOL count 1 disp 0x10 (16) blen 1 extent 1 (size 1)
-------G---[---][---]    OPAL_LOOP_E prev 3 elements first elem displacement 0 size of data 17
Optimized description 
-cC---P-DB-[---][---]      OPAL_INT8 count 1 disp 0x0 (0) blen 1 extent 8 (size 8)
-cC---P-DB-[---][---]     OPAL_UINT1 count 1 disp 0x8 (8) blen 9 extent 9 (size 9)
-------G---[---][---]    OPAL_LOOP_E prev 2 elements first elem displacement 0 size of data 17

[dockercentos7:09967] *** Process received signal ***
[dockercentos7:09967] Signal: Aborted (6)
[dockercentos7:09967] Signal code:  (-6)
[dockercentos7:09967] [ 0] /lib64/libpthread.so.0(+0xf5d0)[0x7f355e57d5d0]
[dockercentos7:09967] [ 1] /lib64/libc.so.6(gsignal+0x37)[0x7f355d5a2207]
[dockercentos7:09967] [ 2] /lib64/libc.so.6(abort+0x148)[0x7f355d5a38f8]
[dockercentos7:09967] [ 3] /home/cmpbib/compilation_BIB_docker/COMPILE_AUTO/BIB/bin/Test.BIBProblemeGD.opt(_Z15attacheDebuggerv+0x2c5e)[0x41a3ee]
[dockercentos7:09967] [ 4] /home/cmpbib/compilation_BIB_docker/COMPILE_AUTO/GIREF/lib/libgiref_opt_Util.so(traitementSignal+0x2bd0)[0x7f356bcfd7e0]
[dockercentos7:09967] [ 5] /lib64/libc.so.6(+0x36280)[0x7f355d5a2280]
[dockercentos7:09967] [ 6] /lib64/libc.so.6(__sched_yield+0x7)[0x7f355d64ed47]
[dockercentos7:09967] [ 7] /opt/openmpi-4.x_debug/lib/libopen-pal.so.40(opal_progress+0xc0)[0x7f355c1988f0]
[dockercentos7:09967] [ 8] /opt/openmpi-4.x_debug/lib/libopen-pal.so.40(ompi_sync_wait_mt+0x187)[0x7f355c1a10a5]
[dockercentos7:09967] [ 9] /opt/openmpi-4.x_debug/lib/libmpi.so.40(+0x5ef27)[0x7f355f164f27]
[dockercentos7:09967] [10] /opt/openmpi-4.x_debug/lib/libmpi.so.40(ompi_request_default_wait+0x27)[0x7f355f164fe9]
[dockercentos7:09967] [11] /opt/openmpi-4.x_debug/lib/libmpi.so.40(ompi_coll_base_sendrecv_actual+0xeb)[0x7f355f209957]
[dockercentos7:09967] [12] /opt/openmpi-4.x_debug/lib/libmpi.so.40(ompi_coll_base_allreduce_intra_recursivedoubling+0x35e)[0x7f355f20b976]
[dockercentos7:09967] [13] /opt/openmpi-4.x_debug/lib/openmpi/mca_coll_tuned.so(ompi_coll_tuned_allreduce_intra_dec_fixed+0xa8)[0x7f354b37e42e]
[dockercentos7:09967] [14] /opt/openmpi-4.x_debug/lib/libmpi.so.40(PMPI_Allreduce+0x3c5)[0x7f355f181612]

http://www.giref.ulaval.ca/~cmpgiref/ompi_4.x/2019.08.19.20h08m05s_config.log
http://www.giref.ulaval.ca/~cmpgiref/ompi_4.x/2019.08.19.20h08m05s_confdefs.h
http://www.giref.ulaval.ca/~cmpgiref/ompi_4.x/2019.08.19.20h08m05s_ompi_info_all.txt

All failing tests have more than 1 process.
They are all showing opal_datatype_pack.c:203 and opal_datatype_unpack.c:135 as above.

Note that we are compiling/testing with --enable-debug ...

I do not have a MWE now, but I wanted to report asap so you can be aware of this.

Thanks,

Eric

[hppritcha]

@ericch1 could you provide us with a test case?

[ericch1]

Ok, I will try do this this week. It is not easy to extract an example from the code, but since it looks like it's happening at the beginning I should be able to do it...

[ericch1]

It is not as easy as I tough... I will try to see if valgrind will give us some clues...
In the meantime, I will test commit fd13b27

[ericch1]

Ok, the commit fd13b27 is good.
Now I am launching the tests against commit 7b09c15, I will have the results in a few hours.

[ericch1]

Ok, 7b09c15 is not yet finished, but all tests that were failing are all good! So the real wrong merge is really only the modifications in f96994b...

I was looking for the validation tests of the OpenMPI. Are you still using jenkins to tests merge requests? I found this:
http://bgate.mellanox.com/jenkins/view/all/

but when I try to look into the details of a build/tests, I only see very few tests that lasts 13 seconds:

http://bgate.mellanox.com/jenkins/job/gh-ompi-master-pr/10301/console

Do I look at the good place?

Is it possible or necessary to have a build with "--enable-debug" mode to catch my issue?
If it costs only 13s, it would worth the trouble!!! :)
For us, all the tests (3341) consumes about 1-2 hours...

[ericch1]

Hi,
I was testing the commits when I saw I mispointed the problem: It occured on August 21 with commit 390e0bc. The preceding merge, d3587f5, is good.

Sorry for this misguiding error!!! :/

[bosilca]

To confirm that is a problem with the merge or with the datatype engine itself, can you run your test with the master ?

[ericch1]

Ok, I will test master this morning. Also, I have to look how to launch your tests database with my configuration (particularly --enable-debug)

[ericch1]

Ok, which master/SHAs should I test? Maybe in this order:

• 8f32a59
• 94f26f5

[ericch1]

Ok, I just tested 390e0bc without "--enable-debug" and the problem is still there, but I have less information on stderr:

[dockercentos7:17688] *** Process received signal ***
[dockercentos7:17688] Signal: Aborted (6)
[dockercentos7:17688] Signal code:  (-6)
[dockercentos7:17688] [ 0] /lib64/libpthread.so.0(+0xf5d0)[0x7f14f92a35d0]
[dockercentos7:17688] [ 1] /lib64/libc.so.6(gsignal+0x37)[0x7f14f82c8207]
[dockercentos7:17688] [ 2] /lib64/libc.so.6(abort+0x148)[0x7f14f82c98f8]
[dockercentos7:17688] [ 3] /home/cmpbib/compilation_BIB_docker/COMPILE_AUTO/BIB/bin/Test.BIBProblemeGD.opt(_Z15attacheDebuggerv+0x2c5e)[0x41a3ee]
[dockercentos7:17688] [ 4] /home/cmpbib/compilation_BIB_docker/COMPILE_AUTO/GIREF/lib/libgiref_opt_Util.so(traitementSignal+0x2bd0)[0x7f150695a7e0]
[dockercentos7:17688] [ 5] /lib64/libc.so.6(+0x36280)[0x7f14f82c8280]
[dockercentos7:17688] [ 6] /lib64/libc.so.6(__sched_yield+0x7)[0x7f14f8374d47]
[dockercentos7:17688] [ 7] /opt/openmpi-4.x_debug/lib/libopen-pal.so.40(ompi_sync_wait_mt+0xb5)[0x7f14f6f72dc5]
[dockercentos7:17688] [ 8] /opt/openmpi-4.x_debug/lib/libmpi.so.40(ompi_request_default_wait+0x1f0)[0x7f14f9e7cb40]
[dockercentos7:17688] [ 9] /opt/openmpi-4.x_debug/lib/libmpi.so.40(ompi_coll_base_sendrecv_actual+0xc9)[0x7f14f9ecc789]
[dockercentos7:17688] [10] /opt/openmpi-4.x_debug/lib/libmpi.so.40(ompi_coll_base_allreduce_intra_recursivedoubling+0x296)[0x7f14f9ecd016]
[dockercentos7:17688] [11] /opt/openmpi-4.x_debug/lib/libmpi.so.40(PMPI_Allreduce+0x183)[0x7f14f9e8f8a3]

I will now launch the tests with branch master 8f32a59 to verify it is ok, then I will launch tests against master 94f26f5.

Also, is https://github.com/open-mpi/mtt the suite which I could launch to test more deeply my local OpenMPI installation? (I never used it before).

Thanks,
Eric

[ericch1]

Looks like 8f32a59 is ok. All failing tests passed (the remaining tests are running).
I am about to launch tests with 94f26f5.

[bosilca]

Looking at your output it seems to me that the datatype representation could have been further optimized in order for the optimized description to look like

Optimized description 
-cC---P-DB-[---][---]      OPAL_INT1 count 1 disp 0x0 (0) blen 17 extent 17 (size 17)
-------G---[---][---]    OPAL_LOOP_E prev 1 elements first elem displacement 0 size of data 17

instead of

Optimized description 
-cC---P-DB-[---][---]      OPAL_INT8 count 1 disp 0x0 (0) blen 1 extent 8 (size 8)
-cC---P-DB-[---][---]     OPAL_UINT1 count 1 disp 0x8 (8) blen 9 extent 9 (size 9)
-------G---[---][---]    OPAL_LOOP_E prev 2 elements first elem displacement 0 size of data 17

I created #6945 to address this optimization issue, but I don't think it fixes anything else. If you can give it a try let me know the outcome.

Also, do you have a reproducer for your test case ?