sympa_msg.pl crashed with an include_users_ldap_2level

[ydelattre]

Hi,

We encounter some problem with some lists when the second query from an include_users_ldap_2level try to query an object that doesn't exist in our LDAP.

First : task_manager.pl died when he was trying to sync those lists.
Second : if we send a mail to those lists, sympa_msg.pl dies too.
Third : this makes "review subscriber" page unavailable to the user.

From the sympa log :

DIED: Can't call method "shift_entry" on an undefined value at /var/lib/sympa/bin/Sympa/List.pm line 5625, <DATA> line 558.
	Sympa::List::_include_users_ldap_2level(HASH(0xa475a9c), '0ad4baf2', HASH(0xad0af90), Sympa::DatabaseDriver::LDAP <bind_dn=uid=sympa,o=mondomaine,c=fr;ca_verify=required;host=ldap://ldap.mondomaine.fr;ssl_ciphers=ALL;ssl_version=sslv2;use_tls=none>, HASH(0xa9484ac)) called at /var/lib/sympa/bin/Sympa/List.pm line 6128
	Sympa::List::_load_list_members_from_include(Sympa::List <[email protected]>, HASH(0xa49f4d8)) called at /var/lib/sympa/bin/Sympa/List.pm line 6900
	Sympa::List::sync_include(Sympa::List <[email protected]>) called at /var/lib/sympa/bin/Sympa/List.pm line 7252
	Sympa::List::on_the_fly_sync_include(Sympa::List <[email protected]>, 'use_ttl', 1) called at /var/lib/sympa/bin/Sympa/Spindle/ToList.pm line 182
	Sympa::Spindle::ToList::_send_msg(Sympa::Message <[email protected]_e4616dc19e1bdf865ccd9d3bfa9e6cf3.distribute>, undef) called at /var/lib/sympa/bin/Sympa/Spindle/ToList.pm line 55
	Sympa::Spindle::ToList::_twist(Sympa::Spindle::ProcessModeration=HASH(0xab31794), Sympa::Message <[email protected]_e461adc12e1cdf465ccd9d3bfa9e6cf3.distribute>) called at /var/lib/sympa/bin/Sympa/Spindle.pm line 92
	Sympa::Spindle::spin(Sympa::Spindle::ProcessModeration=HASH(0xab31794)) called at /var/lib/sympa/bin/Sympa/Request/Handler/distribute.pm line 60
	Sympa::Request::Handler::distribute::_twist(Sympa::Spindle::ProcessMessage=HASH(0xab350b4), Sympa::Request <action=distribute;[email protected]>) called at /var/lib/sympa/bin/Sympa/Spindle.pm line 92
	Sympa::Spindle::spin(Sympa::Spindle::ProcessMessage=HASH(0xab350b4)) called at /var/lib/sympa/bin/Sympa/Spindle/DoCommand.pm line 117
	Sympa::Spindle::DoCommand::_twist(Sympa::Spindle::ProcessIncoming=HASH(0xa903124), Sympa::Message <[email protected],6337>) called at /var/lib/sympa/bin/Sympa/Spindle.pm line 92
	Sympa::Spindle::spin(Sympa::Spindle::ProcessIncoming=HASH(0xa903124)) called at /var/lib/sympa/bin/sympa_msg.pl line 240

I know that our LDAP should be clean and contain no reference to a missing object, but is it possible, for this case, to catch an error and not raise an exception ?

Thanks a lot,
Yoann

[ikedas]

Yoann, could you please show error log entries just before dying?

[sivertkh]

@ikedas It looks like the same bug I reported in #11012.
https://sourcesup.renater.fr/tracker/?group_id=23&atid=167&func=detail&aid=11012

[ydelattre]

Hi,

thanks for your answer :)
@ikedas Below the mail send by SYMPA juste before the task_manager crash.

Use of uninitialized value $orderedValues[1] in join or string at /var/lib/sympa/bin/Sympa/Datasource.pm line 81.
Use of uninitialized value $orderedValues[1] in join or string at /var/lib/sympa/bin/Sympa/Datasource.pm line 81.
Use of uninitialized value $orderedValues[1] in join or string at /var/lib/sympa/bin/Sympa/Datasource.pm line 81.
Use of uninitialized value $orderedValues[1] in join or string at /var/lib/sympa/bin/Sympa/Datasource.pm line 81.
Use of uninitialized value $orderedValues[1] in join or string at /var/lib/sympa/bin/Sympa/Datasource.pm line 81.
Use of uninitialized value $orderedValues[1] in join or string at /var/lib/sympa/bin/Sympa/Datasource.pm line 81.
Use of uninitialized value $orderedValues[1] in join or string at /var/lib/sympa/bin/Sympa/Datasource.pm line 81.
Use of uninitialized value $orderedValues[1] in join or string at /var/lib/sympa/bin/Sympa/Datasource.pm line 81.
Use of uninitialized value $orderedValues[1] in join or string at /var/lib/sympa/bin/Sympa/Datasource.pm line 81.
Use of uninitialized value $orderedValues[1] in join or string at /var/lib/sympa/bin/Sympa/Datasource.pm line 81.
Use of uninitialized value $orderedValues[1] in join or string at /var/lib/sympa/bin/Sympa/Datasource.pm line 81.
Use of uninitialized value $orderedValues[1] in join or string at /var/lib/sympa/bin/Sympa/Datasource.pm line 81.
Use of uninitialized value $orderedValues[1] in join or string at /var/lib/sympa/bin/Sympa/Datasource.pm line 81.
Use of uninitialized value $orderedValues[1] in join or string at /var/lib/sympa/bin/Sympa/Datasource.pm line 81.
Use of uninitialized value $orderedValues[1] in join or string at /var/lib/sympa/bin/Sympa/Datasource.pm line 81.
Use of uninitialized value $orderedValues[1] in join or string at /var/lib/sympa/bin/Sympa/Datasource.pm line 81.
Use of uninitialized value $orderedValues[1] in join or string at /var/lib/sympa/bin/Sympa/Datasource.pm line 81.
Use of uninitialized value $orderedValues[1] in join or string at /var/lib/sympa/bin/Sympa/Datasource.pm line 81.
Use of uninitialized value $orderedValues[1] in join or string at /var/lib/sympa/bin/Sympa/Datasource.pm line 81.
Use of uninitialized value $orderedValues[1] in join or string at /var/lib/sympa/bin/Sympa/Datasource.pm line 81.
Use of uninitialized value $orderedValues[1] in join or string at /var/lib/sympa/bin/Sympa/Datasource.pm line 81.
Use of uninitialized value $orderedValues[1] in join or string at /var/lib/sympa/bin/Sympa/Datasource.pm line 81.
Use of uninitialized value $orderedValues[1] in join or string at /var/lib/sympa/bin/Sympa/Datasource.pm line 81.
Use of uninitialized value $orderedValues[1] in join or string at /var/lib/sympa/bin/Sympa/Datasource.pm line 81.
Use of uninitialized value $orderedValues[1] in join or string at /var/lib/sympa/bin/Sympa/Datasource.pm line 81.
Use of uninitialized value $orderedValues[1] in join or string at /var/lib/sympa/bin/Sympa/Datasource.pm line 81.
Use of uninitialized value $orderedValues[1] in join or string at /var/lib/sympa/bin/Sympa/Datasource.pm line 81.
Use of uninitialized value $orderedValues[1] in join or string at /var/lib/sympa/bin/Sympa/Datasource.pm line 81.
Use of uninitialized value $orderedValues[1] in join or string at /var/lib/sympa/bin/Sympa/Datasource.pm line 81.
Use of uninitialized value $orderedValues[1] in join or string at /var/lib/sympa/bin/Sympa/Datasource.pm line 81.
Use of uninitialized value $orderedValues[1] in join or string at /var/lib/sympa/bin/Sympa/Datasource.pm line 81.
Use of uninitialized value $orderedValues[1] in join or string at /var/lib/sympa/bin/Sympa/Datasource.pm line 81.
Use of uninitialized value $orderedValues[1] in join or string at /var/lib/sympa/bin/Sympa/Datasource.pm line 81.
Use of uninitialized value $orderedValues[1] in join or string at /var/lib/sympa/bin/Sympa/Datasource.pm line 81.
Use of uninitialized value $orderedValues[1] in join or string at /var/lib/sympa/bin/Sympa/Datasource.pm line 81.
Use of uninitialized value $orderedValues[1] in join or string at /var/lib/sympa/bin/Sympa/Datasource.pm line 81.
Use of uninitialized value $orderedValues[1] in join or string at /var/lib/sympa/bin/Sympa/Datasource.pm line 81.
Use of uninitialized value $orderedValues[1] in join or string at /var/lib/sympa/bin/Sympa/Datasource.pm line 81.
Use of uninitialized value $orderedValues[1] in join or string at /var/lib/sympa/bin/Sympa/Datasource.pm line 81.
Use of uninitialized value $orderedValues[1] in join or string at /var/lib/sympa/bin/Sympa/Datasource.pm line 81.
Use of uninitialized value $orderedValues[1] in join or string at /var/lib/sympa/bin/Sympa/Datasource.pm line 81.
Use of uninitialized value $orderedValues[1] in join or string at /var/lib/sympa/bin/Sympa/Datasource.pm line 81.
Use of uninitialized value $orderedValues[1] in join or string at /var/lib/sympa/bin/Sympa/Datasource.pm line 81.
Use of uninitialized value $orderedValues[1] in join or string at /var/lib/sympa/bin/Sympa/Datasource.pm line 81.
Use of uninitialized value $orderedValues[1] in join or string at /var/lib/sympa/bin/Sympa/Datasource.pm line 81.
Use of uninitialized value $orderedValues[1] in join or string at /var/lib/sympa/bin/Sympa/Datasource.pm line 81.
Use of uninitialized value $orderedValues[1] in join or string at /var/lib/sympa/bin/Sympa/Datasource.pm line 81.
Use of uninitialized value $orderedValues[1] in join or string at /var/lib/sympa/bin/Sympa/Datasource.pm line 81.
Use of uninitialized value $orderedValues[1] in join or string at /var/lib/sympa/bin/Sympa/Datasource.pm line 81.
DIED: Can't call method "shift_entry" on an undefined value at /var/lib/sympa/bin/Sympa/List.pm line 5625, <TASK> line 9.
	Sympa::List::_include_users_ldap_2level(HASH(0xb5b9f10), '6fe5bd11', HASH(0xda90790), Sympa::DatabaseDriver::LDAP <bind_dn=uid=consultsympa,ou=applications,ou=ac-lille,ou=education,o=gouv,c=fr;ca_verify=required;host=ldap://ldap.ac-lille.fr;ssl_ciphers=ALL;ssl_version=sslv2;use_tls=none>, HASH(0xbb43858)) called at /var/lib/sympa/bin/Sympa/List.pm line 6128
	Sympa::List::_load_list_members_from_include(Sympa::List <[email protected]>, HASH(0xb5e3dc4)) called at /var/lib/sympa/bin/Sympa/List.pm line 6900
	Sympa::List::sync_include(Sympa::List <[email protected]>) called at /var/lib/sympa/bin/task_manager.pl line 2068
	main::sync_include(Sympa::Task=HASH(0xba1e840), HASH(0xb9ca624)) called at /var/lib/sympa/bin/task_manager.pl line 883
	main::cmd_process('sync_include', ARRAY(0xb9bfed8), Sympa::Task=HASH(0xba1e840), HASH(0xb9c9db4), 4) called at /var/lib/sympa/bin/task_manager.pl line 812
	main::execute(Sympa::Task=HASH(0xba1e840)) called at /var/lib/sympa/bin/task_manager.pl line 401

@sivertkh i think it's the same bug too !

[ikedas]

@ydelattre, could you show syslog messages? The logs you have shown seem stderr outputs under tmp/ spool.

[ydelattre]

Here it is :

Apr 25 14:14:37 newsympa task_manager[13698]: info Sympa::List::_include_users_ldap() 4028 included users from LDAP query
Apr 25 14:14:37 newsympa task_manager[13698]: notice Sympa::List::sync_include(Sympa::List <[email protected]>) 0 users updated
Apr 25 14:14:38 newsympa task_manager[13698]: notice main::next_cmd() line 5 of sync_include : next (1493126078, INIT)
Apr 25 14:14:38 newsympa task_manager[13698]: notice main::create() Creation of /var/lib/sympa/spool/task/[email protected]
Apr 25 14:14:38 newsympa task_manager[13698]: notice main::create() With model /var/lib/sympa/default/list_task_models/sync_include.ttl.task
Apr 25 14:14:38 newsympa task_manager[13698]: notice main::next_cmd() --> new task sync_include (2017-04-25 15:14:38)
Apr 25 14:14:38 newsympa task_manager[13698]: notice main::execute() Running task /var/lib/sympa/spool/task/[email protected], line 0 with vars )
Apr 25 14:14:39 newsympa task_manager[13698]: err main::#401 > main::execute#812 > main::cmd_process#883 > main::sync_include#2068 > Sympa::List::sync_include#6900 > Sympa::List::_load_list_members_from_include#6128 > Sympa::List::_include_users_ldap_2level#5594 > Sympa::DatabaseDriver::LDAP::do_operation#219 Unable to perform LDAP operation: No such object
Apr 25 14:14:39 newsympa task_manager[13698]: err main::#401 > main::execute#812 > main::cmd_process#883 > main::sync_include#2068 > Sympa::List::sync_include#6900 > Sympa::List::_load_list_members_from_include#6128 > Sympa::List::_include_users_ldap_2level#5602 LDAP search (2nd level) failed: (32) No such object. Node: uid=abonne1,ou=people,o=mondomaine,c=fr (searching on server ldap.mondomaine.fr; suffix uid=abonne1,ou=people,o=mondomaine,c=fr ; filter (&(mail=*)(!(typensi=TMP;stagiaire))); attrs: mail)
Apr 25 14:14:39 newsympa task_manager[13698]: err main::#401 > main::execute#812 > main::cmd_process#883 > main::sync_include#2068 > Sympa::List::sync_include#6900 > Sympa::List::_load_list_members_from_include#6128 > Sympa::List::_include_users_ldap_2level#5625 DIED: Can't call method "shift_entry" on an undefined value at /var/lib/sympa/bin/Sympa/List.pm line 5625, <TASK> line 4.

[ikedas]

@ydelattre, does this patch stop dying?

diff --git a/src/lib/Sympa/List.pm b/src/lib/Sympa/List.pm
index 9b363c7..36ab590 100644
--- a/src/lib/Sympa/List.pm
+++ b/src/lib/Sympa/List.pm
@@ -5617,6 +5617,7 @@ sub _include_users_ldap_2level {
                 'fliter2',     $filter2,
                 'ldap_attrs2', $ldap_attrs2
                 };
+            next;
         }

         ## returns a reference to a HASH where the keys are the DNs

[ydelattre]

Thanks for your reactivity !
I will test this today and come back with an answer ASAP.

[ydelattre]

@ikedas this patch solve the issue !

Thanks a lot :)

[ikedas]

Thanks for reporting bug. Closed.