[Home]

Summary:ASTERISK-12241: Wrong log level for one liner (ast_log LOG_WARNING) generates too much logging
Reporter:Nito Martinez (nito)Labels:
Date Opened:2008-06-21 01:53:52Date Closed:2008-06-21 07:47:47
Priority:TrivialRegression?No
Status:Closed/CompleteComponents:Resources/res_config_ldap
Versions:Frequency of
Occurrence
Related
Issues:
Environment:Attachments:
Description:

The offending line is

ast_log(LOG_WARNING, "Could not find any entry matching %s in base dn %s.\n",
filter->str, clean_basedn);


This line will print into the log for all the non found entries in LDAP.

Example, if you have in you use ldap in your dialplan, then any entry that is not matched or not partially matched will be logged.

Example:

[Jun 21 08:50:39] WARNING[5243] res_config_ldap.c: Could not find any entry matching (&(objectClass=AsteriskExtension)(AstExtension=5021)(AstContext=sipclients)(AstPriority=1)) in base dn dc=Company,dc=COM,o=Internet.
[Jun 21 08:50:39] WARNING[5243] res_config_ldap.c: Could not find any entry matching (&(objectClass=AsteriskExtension)(AstExtension=_*)(AstContext=sipclients)(AstPriority=1)) in base dn dc=Company,dc=COM,o=Internet.
[Jun 21 08:50:39] WARNING[5243] res_config_ldap.c: Could not find any entry matching (&(objectClass=AsteriskExtension)(AstExtension=5021)(AstContext=sipclients)(AstPriority=1)) in base dn dc=Company,dc=COM,o=Internet.
[Jun 21 08:50:39] WARNING[5243] res_config_ldap.c: Could not find any entry matching (&(objectClass=AsteriskExtension)(AstExtension=_*)(AstContext=sipclients)(AstPriority=1)) in base dn dc=Company,dc=COM,o=Internet.
[Jun 21 08:50:39] WARNING[5243] res_config_ldap.c: Could not find any entry matching (&(objectClass=AsteriskExtension)(AstExtension=5021)(AstContext=sipclients)(AstPriority=1)) in base dn dc=Company,dc=COM,o=Internet.
[Jun 21 08:50:39] WARNING[5243] res_config_ldap.c: Could not find any entry matching (&(objectClass=AsteriskExtension)(AstExtension=_*)(AstContext=sipclients)(AstPriority=1)) in base dn dc=Company,dc=COM,o=Internet.


And if you dial with an analog phone you would get something like

[Jun 21 08:52:23] WARNING[5243] res_config_ldap.c: Could not find any entry matching (&(objectClass=AsteriskExtension)(AstExtension=5)(AstContext=sipclients)(AstPriority=1)) in base dn dc=Company,dc=COM,o=Internet.
[Jun 21 08:52:23] WARNING[5243] res_config_ldap.c: Could not find any entry matching (&(objectClass=AsteriskExtension)(AstExtension=_*)(AstContext=sipclients)(AstPriority=1)) in base dn dc=Company,dc=COM,o=Internet.
[Jun 21 08:52:25] WARNING[5243] res_config_ldap.c: Could not find any entry matching (&(objectClass=AsteriskExtension)(AstExtension=50)(AstContext=sipclients)(AstPriority=1)) in base dn dc=Company,dc=COM,o=Internet.
[Jun 21 08:52:25] WARNING[5243] res_config_ldap.c: Could not find any entry matching (&(objectClass=AsteriskExtension)(AstExtension=_*)(AstContext=sipclients)(AstPriority=1)) in base dn dc=Company,dc=COM,o=Internet.
[Jun 21 08:52:25] WARNING[5243] res_config_ldap.c: Could not find any entry matching (&(objectClass=AsteriskExtension)(AstExtension=502)(AstContext=sipclients)(AstPriority=1)) in base dn dc=Qindel,dc=COM,o=Internet.
[Jun 21 08:52:25] WARNING[5243] res_config_ldap.c: Could not find any entry matching (&(objectClass=AsteriskExtension)(AstExtension=_*)(AstContext=sipclients)(AstPriority=1)) in base dn dc=Company,dc=COM,o=Internet.
[Jun 21 08:52:26] WARNING[5243] res_config_ldap.c: Could not find any entry matching (&(objectClass=AsteriskExtension)(AstExtension=5023)(AstContext=sipclients)(AstPriority=1)) in base dn dc=Company,dc=COM,o=Internet.
[Jun 21 08:52:26] WARNING[5243] res_config_ldap.c: Could not find any entry matching (&(objectClass=AsteriskExtension)(AstExtension=_*)(AstContext=sipclients)(AstPriority=1)) in base dn dc=Company,dc=COM,o=Internet.
[Jun 21 08:52:34] WARNING[5243] res_config_ldap.c: Could not find any entry matching (&(objectClass=AsteriskSIPUser)(uid=)) in base dn dc=Company,dc=COM,o=Internet.
[Jun 21 08:52:34] WARNING[5243] res_config_ldap.c: Could not find any entry matching (&(objectClass=AsteriskSIPUser)(uid=)(AstAccountHost=dynamic)) in base dn dc=Company,dc=COM,o=Internet.
[Jun 21 08:52:34] WARNING[5243] res_config_ldap.c: Could not find any entry matching (&(objectClass=AsteriskSIPUser)(uid=)) in base dn dc=Company,dc=COM,o=Internet.

which I think does not describe a WARNING severity. For me a WARNING severity is something that should attract the attention of the administrator because it might lead to a problem (could lead to an error condition). I don't think this is the case...

In numbers, be aware that this is for my personal configuration, this will not match other people numbers, but could be indicative:

$ grep -c res_config_ldap /var/log/asterisk/messages
100523
grep res_config_ldap /var/log/asterisk/messages | grep -c "Could not find any entry matching"
99186
$



****** STEPS TO REPRODUCE ******

Just use LDAP either for a SIP user or for dialplan.


res_ldap.conf
[_general]
host=myhost
basedn=dc=Company,dc=COM,o=Internet
protocol=3
user=cn=asterisk,ou=Admin,dc=Company,dc=COM,o=Internet
pass=mypassword


; Sip Users Table
[sip]
name=uid
amaflags=AstAccountAMAFlags
callgroup=AstAccountCallGroup
callerid=AstAccountCallerID
canreinvite=AstAccountCanReinvite
context=AstAccountContext
dtmfmode=AstAccountDTMFMode
fromuser=AstAccountFromUser
fromdomain=AstAccountFromDomain
fullcontact=AstAccountFullContact
;fullcontact=commonName
host=AstAccountHost
insecure=AstAccountInsecure
mailbox=AstAccountMailbox
md5secret=AstAccountRealmedPassword
nat=AstAccountNAT
deny=AstAccountDeny
permit=AstAccountPermit
pickupgroup=AstAccountPickupGroup
port=AstAccountPort
qualify=AstAccountQualify
restrictcid=AstAccountRestrictCID
rtptimeout=AstAccountRTPTimeout
rtpholdtimeout=AstAccountRTPHoldTimeout
type=AstAccountType
disallow=AstAccountDisallowedCodec
allow=AstAccountAllowedCodec
MusicOnHold=AstAccountMusicOnHold
regseconds=AstAccountExpirationTimestamp
regcontext=AstAccountRegistrationContext
regexten=AstAccountRegistrationExten
canCallForward=AstAccountCanCallForward
;secret=AstAccountSecret
additionalFilter=(objectClass=AsteriskSIPUser)

; Sip Users Table
[iax]
name=uid
amaflags=AstAccountAMAFlags
callerid=AstAccountCallerID
context=AstAccountContext
fullcontact=AstAccountFullContact
host=AstAccountHost
mailbox=AstAccountMailbox
md5secret=AstAccountRealmedPassword
deny=AstAccountDeny
permit=AstAccountPermit
port=AstAccountPort
qualify=AstAccountQualify
type=AstAccountType
disallow=AstAccountDisallowedCodec
regseconds=AstAccountExpirationTimestamp
regcontext=AstAccountRegistrationContext
regexten=AstAccountRegistrationExten
additionalFilter=(objectClass=AsteriskSIPUser)

[extensions]
context=AstContext
exten=AstExtension
;extension=AstExtension
priority=AstPriority
app=AstApplication
appdata=AstApplicationData
additionalFilter=(objectClass=AsteriskExtension)



/etc/asterisk/extconfig.conf

extensions => ldap,"dc=Company,dc=COM,o=Internet",extensions
sipusers => ldap,"dc=Company,dc=COM,o=Internet",sip
sippeers => ldap,"dc=Company,dc=COM,o=Internet",sip
iaxusers => ldap,"dc=Company,dc=COM,o=Internet",iax
iaxpeers => ldap,"dc=Company,dc=COM,o=Internet",iax

And the relevant LDAP entries...







****** ADDITIONAL INFORMATION ******

This is the proposed patch (asterisk-1.6.0-beta9).

--- asterisk-1.6.0-beta9/res/res_config_ldap.c.orig     2008-06-21 08:42:06.000000000 +0200
+++ asterisk-1.6.0-beta9/res/res_config_ldap.c  2008-06-21 08:42:27.000000000 +0200
@@ -814,7 +814,7 @@
                       /* is this a static var or some other? they are handled different for delimited values */
                       vars = realtime_ldap_result_to_vars(table_config, ldap_result, entries_count_ptr);
               } else {
-                       ast_log(LOG_WARNING, "Could not find any entry matching %s in base dn %s.\n",
+                       ast_log(LOG_DEBUG, "Could not find any entry matching %s in base dn %s.\n",
                               filter->str, clean_basedn);
               }
Comments:By: Digium Subversion (svnbot) 2008-06-21 07:46:48

Repository: asterisk
Revision: 124505

U   trunk/res/res_config_ldap.c

------------------------------------------------------------------------
r124505 | tilghman | 2008-06-21 07:46:43 -0500 (Sat, 21 Jun 2008) | 4 lines

Reduce warning to debug, otherwise we flood the log when we (legitimately)
can't find a record.
(Closes issue ASTERISK-12241)

------------------------------------------------------------------------

http://svn.digium.com/view/asterisk?view=rev&revision=124505
By: Digium Subversion (svnbot) 2008-06-21 07:47:47

Repository: asterisk
Revision: 124506

_U  branches/1.6.0/
U   branches/1.6.0/res/res_config_ldap.c

------------------------------------------------------------------------
r124506 | tilghman | 2008-06-21 07:47:46 -0500 (Sat, 21 Jun 2008) | 12 lines

Merged revisions 124505 via svnmerge from
https://origsvn.digium.com/svn/asterisk/trunk

........
r124505 | tilghman | 2008-06-21 07:53:48 -0500 (Sat, 21 Jun 2008) | 4 lines

Reduce warning to debug, otherwise we flood the log when we (legitimately)
can't find a record.
(Closes issue ASTERISK-12241)

........

------------------------------------------------------------------------

http://svn.digium.com/view/asterisk?view=rev&revision=124506