1.3.6 dirsrv crash: ERR - valueset_value_syntax_cmp - slapi_attr_values2keys_sv failed for type lastUpdated

OS: CentOS Linux release 7.4.1708 (Core) 
dirsrv: 1.3.6.1 B2017.249.1616

I've had two of these running in multi-master replication for a week now with no
issues, but last night they both crashed at the same time and there were a lot of these
just before they died:

[06/Oct/2017:22:30:41.990009449 -0700] - ERR - valueset_value_syntax_cmp -
slapi_attr_values2keys_sv failed for type lastUpdated
[06/Oct/2017:22:30:41.991965822 -0700] - ERR - valueset_value_syntax_cmp -
slapi_attr_values2keys_sv failed for type lastUpdated
[06/Oct/2017:22:30:41.993908534 -0700] - ERR - valueset_value_syntax_cmp -
slapi_attr_values2keys_sv failed for type lastUpdated

When I try to start either server now, I get the usual recovery messages and then a bunch
of these errors and a crash. I've checked as many things as I can think of, including
dse.ldif, which is fine.

Unrelated probably, but annoying, my error logs are also filling up with lots of these:
[06/Oct/2017:21:51:16.987020789 -0700] - ERR - attrlist_replace - attr_replace
(nsslapd-referral, ldap://ldap2.arizona.edu:389/dc%3Deds%2Cdc%3Darizona%2Cdc%3Dedu)
failed.

I fixed the problem but the solution makes me concerned that this version of 389 server is
not going to work for me. In short, I found that deleting a particular entry on both
servers brought them back to life. This actually makes sense because they both died at
exactly the same time, so I'm guessing this entry was updated on one, got replicated
to the other and then they both crashed. At the time of this crash, what is typically
happening to this entry is a lot of individual attribute value adds and deletes coming
from multiple machines and processes.

I've never seen anything bad happen on version 1.2 servers and, in fact, I had two 1.2
servers replicating with these 1.3.6 servers and both of them stayed up.

So, what do I do now? CentOS won't let me go backwards. Should I go forward and use
1.3.7 instead?

[Mark Reynolds]

On 10/09/2017 05:20 PM, tdarby(a)email.arizona.edu wrote:
>  I fixed the problem but the solution makes me concerned that this
> version of 389 server is not going to work for me. In short, I found that deleting a
> particular entry on both servers brought them back to life. This actually makes sense
> because they both died at exactly the same time, so I'm guessing this entry was
> updated on one, got replicated to the other and then they both crashed. At the time of
> this crash, what is typically happening to this entry is a lot of individual attribute
> value adds and deletes coming from multiple machines and processes.
>
>  I've never seen anything bad happen on version 1.2 servers and, in fact, I had two
> 1.2 servers replicating with these 1.3.6 servers and both of them stayed up. 
This
might be fixed in a newer version of 1.3.6, what version are you
using now?   rpm -qa | grep 389-ds-base
>  So, what do I do now? CentOS won't let me go backwards. Should I go forward and use
> 1.3.7 instead?
>  _______________________________________________
>  389-users mailing list -- 389-users(a)lists.fedoraproject.org
>  To unsubscribe send an email to 389-users-leave(a)lists.fedoraproject.org

>  On 10/09/2017 05:20 PM, tdarby(a)email.arizona.edu wrote:
>  This
>  might be fixed in a newer version of 1.3.6, what version are you
>  using now?   rpm -qa | grep 389-ds-base 
389-ds-base-1.3.6.1-19.el7_4.x86_64
389-ds-base-libs-1.3.6.1-19.el7_4.x86_64

[Mark Reynolds]

On 10/09/2017 05:33 PM, tdarby(a)email.arizona.edu wrote:
> > On 10/09/2017 05:20 PM, tdarby(a)email.arizona.edu wrote:
> > This
> > might be fixed in a newer version of 1.3.6, what version are you
> > using now?   rpm -qa | grep 389-ds-base 
Okay the version you have has a few
known crashes.  They have been fixed
in 1.3.6.1-20 and up.  This fix will also be part of RHEL's 7.4 batch
update 2.
>  389-ds-base-1.3.6.1-19.el7_4.x86_64
>  389-ds-base-libs-1.3.6.1-19.el7_4.x86_64
>  _______________________________________________
>  389-users mailing list -- 389-users(a)lists.fedoraproject.org
>  To unsubscribe send an email to 389-users-leave(a)lists.fedoraproject.org

[William Brown]

On Sat, 2017-10-07 at 15:11 +0000, tdarby(a)email.arizona.edu wrote:
>  OS: CentOS Linux release 7.4.1708 (Core) 
>  dirsrv: 1.3.6.1 B2017.249.1616
>  
>  I've had two of these running in multi-master replication for a week now with no
> issues, but last night they both crashed at the same time and there were a lot of these
> just before they died:
>  
>  [06/Oct/2017:22:30:41.990009449 -0700] - ERR - valueset_value_syntax_cmp -
> slapi_attr_values2keys_sv failed for type lastUpdated
>  [06/Oct/2017:22:30:41.991965822 -0700] - ERR - valueset_value_syntax_cmp -
> slapi_attr_values2keys_sv failed for type lastUpdated
>  [06/Oct/2017:22:30:41.993908534 -0700] - ERR - valueset_value_syntax_cmp -
> slapi_attr_values2keys_sv failed for type lastUpdated
>  
>  When I try to start either server now, I get the usual recovery messages and then a bunch
> of these errors and a crash. I've checked as many things as I can think of, including
> dse.ldif, which is fine.
>   
When the server crashes do you get a core dump or similar? That would
really help. 

I think the issue with the lastUpdated type is that this is a custom
element of your schema - I can't find any references to it at all in our
code base. Can you send me your schema definiton for this attribute? 

>  Unrelated probably, but annoying, my error logs are also filling up
> with lots of these:
>  [06/Oct/2017:21:51:16.987020789 -0700] - ERR - attrlist_replace - attr_replace
> (nsslapd-referral, ldap://ldap2.arizona.edu:389/dc%3Deds%2Cdc%3Darizona%2Cdc%3Dedu)
> failed. 

I think the error is fixed in 1.3.7 ... 

>  _______________________________________________
>  389-users mailing list -- 389-users(a)lists.fedoraproject.org
>  To unsubscribe send an email to 389-users-leave(a)lists.fedoraproject.org 
-- 
Sincerely,

William Brown
Software Engineer
Red Hat, Australia/Brisbane

>  On 10/09/2017 05:33 PM, tdarby(a)email.arizona.edu wrote:
>  Okay the version you have has a few
>  known crashes.  They have been fixed
>  in 1.3.6.1-20 and up.  This fix will also be part of RHEL's 7.4 batch
>  update 2. 
Thanks, I don't see a way to get a higher packaged version with CentOS 7.4. I'm
not committed to CentOS. What about switching to Fedora 26 in order to get the 1.3.6.8
package?

Is there anything I can do about the attrlist_replace - attr_replace nsslapd-referral
messages filling up the errors log?

[Mark Reynolds]

On 10/10/2017 09:56 AM, tdarby(a)email.arizona.edu wrote:
> > On 10/09/2017 05:33 PM, tdarby(a)email.arizona.edu wrote:
> > Okay the version you have has a few
> > known crashes.  They have been fixed
> > in 1.3.6.1-20 and up.  This fix will also be part of RHEL's 7.4 batch
> > update 2.
>  Thanks, I don't see a way to get a higher packaged version with CentOS 7.4. I'm
> not committed to CentOS. What about switching to Fedora 26 in order to get the 1.3.6.8
> package? 
That's up to you :-)    What is nice about fedora in this regard is
that
you can always get the latest (upstream) version.  If you could at least
test this on Fedora with the latest version of 389 so we can rule out if
its a known issue or a new one.
>  Is there anything I can do about the attrlist_replace - attr_replace nsslapd-referral
> messages filling up the errors log? 
This is now fixed upstream on Fedora (26 and
up)

Downstream, RHEL 7.4 does not have the fix yet, but it will in Batch
Update 3 (a few months away)
>  _______________________________________________
>  389-users mailing list -- 389-users(a)lists.fedoraproject.org
>  To unsubscribe send an email to 389-users-leave(a)lists.fedoraproject.org

>  When the server crashes do you get a core dump or similar? That
> would
>  really help.  
Where do I find a core dump?

>  I think the issue with the lastUpdated type is that this is a custom
>  element of your schema - I can't find any references to it at all in our
>  code base. Can you send me your schema definiton for this attribute?  
This is the entry that after I deleted it enabled the server to start up again:
dn: cn=grouperstatus, ou=People,dc=eds,dc=arizona,dc=edu
objectClass: edsstatus
objectClass: top
cn: grouperstatus

It contains the multi-valued attributes lastUpdated and lastStarted, both strings.

[Mark Reynolds]

On 10/10/2017 10:27 AM, tdarby(a)email.arizona.edu wrote:
> > When the server crashes do you get a core dump or similar? That
> would
> > really help. 
>  Where do I find a core dump? 
First you need to make sure cores are allowed to be
generated:

http://www.port389.org/docs/389ds/FAQ/faq.html#sts=Debugging%C2%A0Crashes

Where the core file gets written can vary on OS/OS config.  It is
sometimes found here:

/var/spool/abrt/*/coredump

or /var/lib/systemd/coredump/ You could also just search the filesystem
for "core". Once you find it, attach gdb and get a stack trace. See the
doc above for more info on that as well.Regards, Mark

> > I think the issue with the lastUpdated type is that this is a custom
> > element of your schema - I can't find any references to it at all in our
> > code base. Can you send me your schema definiton for this attribute? 
>  This is the entry that after I deleted it enabled the server to start up again:
>  dn: cn=grouperstatus, ou=People,dc=eds,dc=arizona,dc=edu
>  objectClass: edsstatus
>  objectClass: top
>  cn: grouperstatus
>
>  It contains the multi-valued attributes lastUpdated and lastStarted, both strings.
>  _______________________________________________
>  389-users mailing list -- 389-users(a)lists.fedoraproject.org
>  To unsubscribe send an email to 389-users-leave(a)lists.fedoraproject.org

>  you can always get the latest (upstream) version.  If you could at
> least
>  test this on Fedora with the latest version of 389 so we can rule out if
>  its a known issue or a new one.
>  This is now fixed upstream on Fedora (26 and
>  up) 
I'm testing this in a docker container and the latest container image is Fedora 26 and
the only package it offers me is 1.3.6.8. I was testing a new install of this last night
on two instances and the failure happened again with the same errors and now 389 server
won't stay up. It will run for a few minutes, then generate hundreds of
slapi_attr_values2keys_sv failed for type lastUpdated errors and then die. Again, this
didn't seem to bother the two 1.2 servers that were replicating with them.

I tried setting up the system for core dumps but I can't find a core dump when it
dies. Is there anything you want me to look at while it's in this state?

[Mark Reynolds]

On 10/11/2017 10:45 AM, tdarby(a)email.arizona.edu wrote:
> > you can always get the latest (upstream) version.  If you could
> at least
> > test this on Fedora with the latest version of 389 so we can rule out if
> > its a known issue or a new one.
> > This is now fixed upstream on Fedora (26 and
> > up)
>  I'm testing this in a docker container and the latest container image is Fedora 26
> and the only package it offers me is 1.3.6.8.  
Its not pushed to stable yet, but you can get it here though:

https://koji.fedoraproject.org/koji/buildinfo?buildID=982203


>  I was testing a new install of this last night on two instances and
> the failure happened again with the same errors and now 389 server won't stay up. It
> will run for a few minutes, then generate hundreds of slapi_attr_values2keys_sv failed for
> type lastUpdated errors and then die. Again, this didn't seem to bother the two 1.2
> servers that were replicating with them.
>
>  I tried setting up the system for core dumps but I can't find a core dump when it
> dies. Is there anything you want me to look at while it's in this state? 
Can you
run the server under gdb to catch the crash?

Can you provide me a simple test case to reproduce the crash?
>  _______________________________________________
>  389-users mailing list -- 389-users(a)lists.fedoraproject.org
>  To unsubscribe send an email to 389-users-leave(a)lists.fedoraproject.org

>  Can you provide me a simple test case to reproduce the crash? 
I spent a lot of time yesterday trying different ideas for reproducing the crash and
haven't found the right sequence of events yet. I did discover that I was able to
bring back a failed server instance by deleting a different entry, cn=grouperfeeds, which
like cn=grouperstatus contains the lastUpdated and lastStarted attributes.

I'm testing now with 1.3.7.6, built from source, on Fedora 26.

>  I spent a lot of time yesterday trying different ideas for
> reproducing the crash and
>  haven't found the right sequence of events yet. I did discover that I was able to
>  bring back a failed server instance by deleting a different entry, cn=grouperfeeds,
> which
>  like cn=grouperstatus contains the lastUpdated and lastStarted attributes.
>  
>  I'm testing now with 1.3.7.6, built from source, on Fedora 26. 
It was looking good until both test servers crashed again this morning:

389-ds-base-libs-1.3.7.6-1.fc26.x86_64
389-ds-base-1.3.7.6-1.fc26.x86_64

I see hundreds of these errors:
[20/Oct/2017:01:55:11.852720430 -0700] - ERR - valueset_value_syntax_cmp -
slapi_attr_values2keys_sv failed for type lastStarted

So, it's happening on both the lastStarted and lastUpdated attributes of
cn=grouperstatus.

What I know for sure is that this never happened on 389 1.2.11.15 and has happened on
1.3.6.1, 1.3.6.8, and 1.3.7.6.

[Mark Reynolds]

On 10/20/2017 12:32 PM, tdarby(a)email.arizona.edu wrote:
> > I spent a lot of time yesterday trying different ideas for
> reproducing the crash and
> > haven't found the right sequence of events yet. I did discover that I was able
> to
> > bring back a failed server instance by deleting a different entry, cn=grouperfeeds,
> which
> > like cn=grouperstatus contains the lastUpdated and lastStarted attributes.
> >
> > I'm testing now with 1.3.7.6, built from source, on Fedora 26.
>  It was looking good until both test servers crashed again this morning:
>
>  389-ds-base-libs-1.3.7.6-1.fc26.x86_64
>  389-ds-base-1.3.7.6-1.fc26.x86_64
>
>  I see hundreds of these errors:
>  [20/Oct/2017:01:55:11.852720430 -0700] - ERR - valueset_value_syntax_cmp -
> slapi_attr_values2keys_sv failed for type lastStarted
>
>  So, it's happening on both the lastStarted and lastUpdated attributes of
> cn=grouperstatus. 
Is there a core file you get a stack trace from? 

What are the schema definitions for lastUpdated & lastStarted?

Can you reproduce this in a non-production environment where you could
run it under valgrind?
Or can you run it under gdb so we can catch the crash live?

Are there any other errors messages at the time you see: 
"valueset_value_syntax_cmp - slapi_attr_values2keys_sv failed for type
lastStarted"?

Mark

>  What I know for sure is that this never happened on 389 1.2.11.15 and has happened on
> 1.3.6.1, 1.3.6.8, and 1.3.7.6
>  _______________________________________________
>  389-users mailing list -- 389-users(a)lists.fedoraproject.org
>  To unsubscribe send an email to 389-users-leave(a)lists.fedoraproject.org

>  On 10/20/2017 12:32 PM, tdarby(a)email.arizona.edu wrote:
>  Is there a core file you get a stack trace from?  
Not sure how to set up to get a core dump in a docker container.

>  What are the schema definitions for lastUpdated & lastStarted?
As I said earlier, these are standard directory string attributes, multi-valued, nothing
special. They are used in 3 different entries.

>  Can you reproduce this in a non-production environment where you
> could
>  run it under valgrind?
>  Or can you run it under gdb so we can catch the crash live? 
If I can figure out how to do this I will, but again, this is a difficult thing to
reproduce. The 1.3.7 servers ran for a week before it happened.

>  Are there any other errors messages at the time you see: 
>  "valueset_value_syntax_cmp - slapi_attr_values2keys_sv failed for type
>  lastStarted"? 
These were the only errors.

[Mark Reynolds]

On 10/20/2017 07:58 PM, tdarby(a)email.arizona.edu wrote:
> > On 10/20/2017 12:32 PM, tdarby(a)email.arizona.edu wrote:
> > Is there a core file you get a stack trace from? 
>  Not sure how to set up to get a core dump in a docker container. 
Me neither, but
once the server is up and running can you follow the
steps outlined here:

http://www.port389.org/docs/389ds/FAQ/faq.html#sts=Debugging%C2%A0Crashes

Make sure debug symbols are installed (the degbuinfo pacakge).  Unless
you build it yourself with debugging enabled (enable-debug) a configure
option, and "-g" for C flags.

CFLAGS='-g -pipe -Wall -fexceptions -fstack-protector
--param=ssp-buffer-size=4 -m64 -mtune=generic' CXXFLAGS='-g -pipe -Wall
-O0-fexceptions -fstack-protector --param=ssp-buffer-size=4 -m64
-mtune=generic' ../389-ds-base/configure --enable-autobind
--with-selinux --with-openldap
--with-tmpfiles-d=/etc/tmpfiles.d--with-systemdsystemunitdir=/usr/lib/systemd/system
--with-systemdsystemconfdir=/etc/systemd/system --enable-debug
--with-systemdgroupname=dirsrv.target --with-fhs --libdir=/usr/lib64
--enable-tcmalloc|||--||with-systemd|

> > What are the schema definitions for lastUpdated & lastStarted?
>  As I said earlier, these are standard directory string attributes, multi-valued, nothing
> special. They are used in 3 different entries. 
The error indicates that there is no
syntax plugin for these attributes
- even in the code says its not sure how that could even happen, that's
why I'm asking what syntax they used.  But is keeps happening with just
these two attributes.

So you are saying its syntax is:  1.3.6.1.4.1.1466.115.121.1.15

> > Can you reproduce this in a non-production environment where you could
> > run it under valgrind?
> > Or can you run it under gdb so we can catch the crash live?
>  If I can figure out how to do this I will, but again, this is a difficult thing to
> reproduce. The 1.3.7 servers ran for a week before it happened. 
I know its hard, but
unfortunately it might be the only way we are going
to fix the crash.  Unless we get a good core file where we can dive in a
see whats going on.  We might also need to run the server under valgrind
if its some type of memory corruption - this can be disruptive to a
production environment that's why if we can reproduce it in house that
would be better for everyone.
> > Are there any other errors messages at the time you see: 
> > "valueset_value_syntax_cmp - slapi_attr_values2keys_sv failed for type
> > lastStarted"?
>  These were the only errors.
>  _______________________________________________
>  389-users mailing list -- 389-users(a)lists.fedoraproject.org
>  To unsubscribe send an email to 389-users-leave(a)lists.fedoraproject.org

[David Partridge]

I would check values for empty string or null values here.  Could cause issues for
database and indexes.


David M. Partridge

On 10/20/17, 19:59, &quot;tdarby(a)email.arizona.edu&quot; <tdarby(a)email.arizona.edu&gt;
wrote:

>  On 10/20/2017 12:32 PM, tdarby(a)email.arizona.edu wrote:
>  Is there a core file you get a stack trace from?
>  
    Not sure how to set up to get a core dump in a docker container.

>  What are the schema definitions for lastUpdated & lastStarted?
>  
    As I said earlier, these are standard directory string attributes, multi-valued,
nothing special. They are used in 3 different entries.

>  Can you reproduce this in a non-production environment where you
> could
>  run it under valgrind?
>  Or can you run it under gdb so we can catch the crash live?
>  
    If I can figure out how to do this I will, but again, this is a difficult thing to
reproduce. The 1.3.7 servers ran for a week before it happened.

>  Are there any other errors messages at the time you see:
>  "valueset_value_syntax_cmp - slapi_attr_values2keys_sv failed for type
>  lastStarted"?
>  
    These were the only errors.
    _______________________________________________
    389-users mailing list -- 389-users(a)lists.fedoraproject.org
    To unsubscribe send an email to 389-users-leave(a)lists.fedoraproject.org


CONFIDENTIALITY NOTICE: This e-mail message, including any attachments, is for the sole
use of the intended recipient(s) and may contain confidential and privileged information
or otherwise be protected by law. Any unauthorized review, use, disclosure or distribution
is prohibited. If you are not the intended recipient, please contact the sender by reply
e-mail and destroy all copies of the original message.

>  So you are saying its syntax is:  1.3.6.1.4.1.1466.115.121.1.15
>   
Yes, and I checked to make sure that is the case.