On 03/12/2012 4:24 PM, Simo Sorce wrote:
On Mon, 2012-12-03 at 15:42 -0500, Qing Chang wrote:
> On 03/12/2012 10:12 AM, Dmitri Pal wrote:
>> On 12/02/2012 11:37 AM, Jakub Hrozek wrote:
>>> On Sat, Dec 01, 2012 at 10:01:55PM -0500, Qing Chang wrote:
>>>> On 30/11/2012 7:30 PM, Dmitri Pal wrote:
>>>>> On 11/30/2012 05:21 PM, Qing Chang wrote:
>>>>>> my dovecot IMAP server would randomly lose memory of users, as
an
>>>>>> example:
>>>>>>
>>>>>> Samba/NFS server knows this user:
>>>>>> [root@smb2 shassan]# getent passwd bqiang
>>>>>> bqiang:*:47105:471:Beiping Qiang:/home2/bqiang:/bin/tcsh
>>>>>>
>>>>>> But dovecot server does not:
>>>>>> [root@dovecot2 ~]# getent passwd bqiang
>>>>>>
>>>>>> Only when I apply this:
>>>>>> [root@dovecot2 ~]# \rm /var/lib/sss/db/cache_sri.utoronto.ca.ldb
>>>>>> [root@dovecot2 ~]# service sssd restart
>>>>>>
>>>>>> It gets it:
>>>>>> [root@dovecot2 ~]# getent passwd bqiang
>>>>>> bqiang:*:47105:471:Beiping Qiang:/home2/bqiang:/bin/tcsh
>>>>>>
>>>>>> So far I have to deal with this for three users. It's quite
possible
>>>>>> that there are more than 3 that are affected, they were just
patient
>>>>>> enough to wait until dovecot "recovers its memory".
>>>>>>
>>>>>> =====
>>>>>> sssd.x86_64 1.8.0-32.el6
>>>>>> @rhel-x86_64-server-6
>>>>>> sssd-client.x86_64 1.8.0-32.el6
>>>>>> @rhel-x86_64-server-6
>>>>>> =====
>>>>>>
>>>>>> Your help is much appreciated.
>>>>>>
>>>>>> Thanks,
>>>>>> Qing
>>>>>>
>>>>> Can it be because hierarchy changes in some way?
>>>> I assume this is not a question for me? Please explain if it is, I do not
have a clue what this is.
>>> I think that Dmitri was asking if the group membreships may have changed
>>> on the server between the two lookups. In other words, was the user
>>> added to or removed from some groups on the server?
>> Correct but not only this.
>> Have the nesting of the groups the user is in changed in any way?
>> For example a group was moved from one parent group to another.
> I am no using nested groups.
>
> It happened to one of the three users today, I was putting in change for increasing
> log level, by doing "service sssd restart", like Simo suspected, that along
brought
> back the memory:-( But I have to wait for another occurrence to catch the bug in
> action...
>
> Will report back.
Hi this is already valuable feedback, thanks a lot, focuses the problem
in the nss responder.
Simo.
It happened this morning, following I have the logs spanning a few hours to
show how the state has changed (there may be a lot noises, it's level 8):
===== when it's working =====
(Tue Dec 4 09:19:02 2012) [sssd[nss]] [sss_cmd_get_version] (0x0200): Received client
version [1].
(Tue Dec 4 09:19:02 2012) [sssd[nss]] [sss_cmd_get_version] (0x0200): Offered version
[1].
(Tue Dec 4 09:19:02 2012) [sssd[nss]] [nss_cmd_getpwnam] (0x0100): Requesting info for
[shassan]
from [<ALL>]
(Tue Dec 4 09:19:02 2012) [sssd[nss]] [sss_ncache_check_str] (0x2000): Checking negative
cache for
[NCE/USER/sri.utoronto.ca/shassan]
(Tue Dec 4 09:19:02 2012) [sssd[nss]] [nss_cmd_getpwnam_search] (0x0100): Requesting info
for
[shassan(a)sri.utoronto.ca]
(Tue Dec 4 09:19:02 2012) [sssd[nss]] [sss_dp_issue_request] (0x0400): Issuing request
for
[0x4267b0:1:shassan@sri.utoronto.ca]
(Tue Dec 4 09:19:02 2012) [sssd[nss]] [sss_dp_get_account_msg] (0x0400): Creating request
for
[sri.utoronto.ca][4097][1][name=shassan]
(Tue Dec 4 09:19:02 2012) [sssd[nss]] [sbus_add_timeout] (0x2000): 0x17f2b40
(Tue Dec 4 09:19:02 2012) [sssd[nss]] [sss_dp_internal_get_send] (0x0400): Entering
request
[0x4267b0:1:shassan@sri.utoronto.ca]
(Tue Dec 4 09:19:02 2012) [sssd[nss]] [sbus_remove_timeout] (0x2000): 0x17f2b40
(Tue Dec 4 09:19:02 2012) [sssd[nss]] [sss_dp_get_reply] (0x1000): Got reply from Data
Provider -
DP error code: 0 errno: 0 error message: Success
(Tue Dec 4 09:19:02 2012) [sssd[nss]] [sss_ncache_check_str] (0x2000): Checking negative
cache for
[NCE/USER/sri.utoronto.ca/shassan]
(Tue Dec 4 09:19:02 2012) [sssd[nss]] [nss_cmd_getpwnam_search] (0x0100): Requesting info
for
[shassan(a)sri.utoronto.ca]
(Tue Dec 4 09:19:02 2012) [sssd[nss]] [nss_cmd_getpwnam_search] (0x0400): Returning info
for user
[shassan(a)sri.utoronto.ca]
(Tue Dec 4 09:19:02 2012) [sssd[nss]] [sss_dp_req_destructor] (0x0400): Deleting request:
[0x4267b0:1:shassan@sri.utoronto.ca]
(Tue Dec 4 09:19:02 2012) [sssd[nss]] [nss_cmd_initgroups] (0x0100): Requesting info for
[shassan]
from [<ALL>]
(Tue Dec 4 09:19:02 2012) [sssd[nss]] [sss_ncache_check_str] (0x2000): Checking negative
cache for
[NCE/USER/sri.utoronto.ca/shassan]
(Tue Dec 4 09:19:02 2012) [sssd[nss]] [nss_cmd_initgroups_search] (0x0100): Requesting
info for
[shassan(a)sri.utoronto.ca]
(Tue Dec 4 09:19:02 2012) [sssd[nss]] [sss_dp_issue_request] (0x0400): Issuing request
for
[0x4267b0:3:shassan@sri.utoronto.ca]
(Tue Dec 4 09:19:02 2012) [sssd[nss]] [sss_dp_get_account_msg] (0x0400): Creating request
for
[sri.utoronto.ca][4099][1][name=shassan]
(Tue Dec 4 09:19:02 2012) [sssd[nss]] [sbus_add_timeout] (0x2000): 0x107cf60
(Tue Dec 4 09:19:02 2012) [sssd[nss]] [sss_dp_internal_get_send] (0x0400): Entering
request
[0x4267b0:3:shassan@sri.utoronto.ca]
(Tue Dec 4 09:19:02 2012) [sssd[nss]] [sbus_remove_timeout] (0x2000): 0x107cf60
(Tue Dec 4 09:19:02 2012) [sssd[nss]] [sss_dp_get_reply] (0x1000): Got reply from Data
Provider -
DP error code: 0 errno: 0 error message: Success
(Tue Dec 4 09:19:02 2012) [sssd[nss]] [sss_ncache_check_str] (0x2000): Checking negative
cache for
[NCE/USER/sri.utoronto.ca/shassan]
(Tue Dec 4 09:19:02 2012) [sssd[nss]] [nss_cmd_initgroups_search] (0x0100): Requesting
info for
[shassan(a)sri.utoronto.ca]
(Tue Dec 4 09:19:02 2012) [sssd[nss]] [nss_cmd_initgroups_search] (0x0400): Initgroups
for
[shassan(a)sri.utoronto.ca] completed
(Tue Dec 4 09:19:02 2012) [sssd[nss]] [sss_dp_req_destructor] (0x0400): Deleting request:
[0x4267b0:3:shassan@sri.utoronto.ca]
(Tue Dec 4 09:19:02 2012) [sssd[nss]] [nss_cmd_initgroups] (0x0100): Requesting info for
[shassan]
from [<ALL>]
(Tue Dec 4 09:19:02 2012) [sssd[nss]] [sss_ncache_check_str] (0x2000): Checking negative
cache for
[NCE/USER/sri.utoronto.ca/shassan]
(Tue Dec 4 09:19:02 2012) [sssd[nss]] [nss_cmd_initgroups_search] (0x0100): Requesting
info for
[shassan(a)sri.utoronto.ca]
(Tue Dec 4 09:19:02 2012) [sssd[nss]] [check_cache] (0x0400): Cached entry is valid,
returning..
(Tue Dec 4 09:19:02 2012) [sssd[nss]] [nss_cmd_initgroups_search] (0x0400): Initgroups
for
[shassan(a)sri.utoronto.ca] completed
(Tue Dec 4 09:19:02 2012) [sssd[nss]] [nss_cmd_getpwnam] (0x0100): Requesting info for
[shassan]
from [<ALL>]
(Tue Dec 4 09:19:02 2012) [sssd[nss]] [sss_ncache_check_str] (0x2000): Checking negative
cache for
[NCE/USER/sri.utoronto.ca/shassan]
(Tue Dec 4 09:19:02 2012) [sssd[nss]] [nss_cmd_getpwnam_search] (0x0100): Requesting info
for
[shassan(a)sri.utoronto.ca]
(Tue Dec 4 09:19:02 2012) [sssd[nss]] [check_cache] (0x0400): Cached entry is valid,
returning..
(Tue Dec 4 09:19:02 2012) [sssd[nss]] [nss_cmd_getpwnam_search] (0x0400): Returning info
for user
[shassan(a)sri.utoronto.ca]
(Tue Dec 4 09:19:02 2012) [sssd[nss]] [accept_fd_handler] (0x0100): Client connected!
(Tue Dec 4 09:19:02 2012) [sssd[nss]] [sss_cmd_get_version] (0x0200): Received client
version [1].
(Tue Dec 4 09:19:02 2012) [sssd[nss]] [sss_cmd_get_version] (0x0200): Offered version
[1].
(Tue Dec 4 09:19:02 2012) [sssd[nss]] [nss_cmd_getpwnam] (0x0100): Requesting info for
[shassan]
from [<ALL>]
(Tue Dec 4 09:19:02 2012) [sssd[nss]] [sss_ncache_check_str] (0x2000): Checking negative
cache for
[NCE/USER/sri.utoronto.ca/shassan]
(Tue Dec 4 09:19:02 2012) [sssd[nss]] [nss_cmd_getpwnam_search] (0x0100): Requesting info
for
[shassan(a)sri.utoronto.ca]
(Tue Dec 4 09:19:02 2012) [sssd[nss]] [check_cache] (0x0400): Cached entry is valid,
returning..
(Tue Dec 4 09:19:02 2012) [sssd[nss]] [nss_cmd_getpwnam_search] (0x0400): Returning info
for user
[shassan(a)sri.utoronto.ca]
(Tue Dec 4 09:19:02 2012) [sssd[nss]] [nss_cmd_initgroups] (0x0100): Requesting info for
[shassan]
from [<ALL>]
(Tue Dec 4 09:19:02 2012) [sssd[nss]] [sss_ncache_check_str] (0x2000): Checking negative
cache for
[NCE/USER/sri.utoronto.ca/shassan]
(Tue Dec 4 09:19:02 2012) [sssd[nss]] [nss_cmd_initgroups_search] (0x0100): Requesting
info for
[shassan(a)sri.utoronto.ca]
(Tue Dec 4 09:19:02 2012) [sssd[nss]] [check_cache] (0x0400): Cached entry is valid,
returning..
(Tue Dec 4 09:19:02 2012) [sssd[nss]] [nss_cmd_initgroups_search] (0x0400): Initgroups
for
[shassan(a)sri.utoronto.ca] completed
(Tue Dec 4 09:19:08 2012) [sssd[nss]] [accept_fd_handler] (0x0100): Client connected!
===== still working =====
(Tue Dec 4 09:34:50 2012) [sssd[nss]] [nss_cmd_getpwnam] (0x0100): Requesting info for
[shassan]
from [sri.utoronto.ca]
(Tue Dec 4 09:34:50 2012) [sssd[nss]] [sss_ncache_check_str] (0x2000): Checking negative
cache for
[NCE/USER/sri.utoronto.ca/shassan]
(Tue Dec 4 09:34:50 2012) [sssd[nss]] [nss_cmd_getpwnam_search] (0x0100): Requesting info
for
[shassan(a)sri.utoronto.ca]
(Tue Dec 4 09:34:50 2012) [sssd[nss]] [check_cache] (0x0400): Cached entry is valid,
returning..
(Tue Dec 4 09:34:50 2012) [sssd[nss]] [nss_cmd_getpwnam_search] (0x0400): Returning info
for user
[shassan(a)sri.utoronto.ca]
(Tue Dec 4 09:34:50 2012) [sssd[nss]] [nss_cmd_getpwnam] (0x0100): Requesting info for
[shassan]
from [sri.utoronto.ca]
(Tue Dec 4 09:34:50 2012) [sssd[nss]] [sss_ncache_check_str] (0x2000): Checking negative
cache for
[NCE/USER/sri.utoronto.ca/shassan]
(Tue Dec 4 09:34:50 2012) [sssd[nss]] [nss_cmd_getpwnam_search] (0x0100): Requesting info
for
[shassan(a)sri.utoronto.ca]
(Tue Dec 4 09:34:50 2012) [sssd[nss]] [check_cache] (0x0400): Cached entry is valid,
returning..
(Tue Dec 4 09:34:50 2012) [sssd[nss]] [nss_cmd_getpwnam_search] (0x0400): Returning info
for user
[shassan(a)sri.utoronto.ca]
(Tue Dec 4 09:34:50 2012) [sssd[nss]] [nss_cmd_getpwnam] (0x0100): Requesting info for
[shassan]
from [sri.utoronto.ca]
(Tue Dec 4 09:34:50 2012) [sssd[nss]] [sss_ncache_check_str] (0x2000): Checking negative
cache for
[NCE/USER/sri.utoronto.ca/shassan]
(Tue Dec 4 09:34:50 2012) [sssd[nss]] [nss_cmd_getpwnam_search] (0x0100): Requesting info
for
[shassan(a)sri.utoronto.ca]
(Tue Dec 4 09:34:50 2012) [sssd[nss]] [check_cache] (0x0400): Cached entry is valid,
returning..
(Tue Dec 4 09:34:50 2012) [sssd[nss]] [nss_cmd_getpwnam_search] (0x0400): Returning info
for user
[shassan(a)sri.utoronto.ca]
(Tue Dec 4 09:34:50 2012) [sssd[nss]] [nss_cmd_getpwnam] (0x0100): Requesting info for
[shassan]
from [sri.utoronto.ca]
(Tue Dec 4 09:34:50 2012) [sssd[nss]] [sss_ncache_check_str] (0x2000): Checking negative
cache for
[NCE/USER/sri.utoronto.ca/shassan]
(Tue Dec 4 09:34:50 2012) [sssd[nss]] [nss_cmd_getpwnam_search] (0x0100): Requesting info
for
[shassan(a)sri.utoronto.ca]
(Tue Dec 4 09:34:50 2012) [sssd[nss]] [check_cache] (0x0400): Cached entry is valid,
returning..
(Tue Dec 4 09:34:50 2012) [sssd[nss]] [nss_cmd_getpwnam_search] (0x0400): Returning info
for user
[shassan(a)sri.utoronto.ca]
(Tue Dec 4 09:34:50 2012) [sssd[nss]] [nss_cmd_getpwnam] (0x0100): Requesting info for
[shassan]
from [sri.utoronto.ca]
(Tue Dec 4 09:34:50 2012) [sssd[nss]] [sss_ncache_check_str] (0x2000): Checking negative
cache for
[NCE/USER/sri.utoronto.ca/shassan]
(Tue Dec 4 09:34:50 2012) [sssd[nss]] [nss_cmd_getpwnam_search] (0x0100): Requesting info
for
[shassan(a)sri.utoronto.ca]
(Tue Dec 4 09:34:50 2012) [sssd[nss]] [check_cache] (0x0400): Cached entry is valid,
returning..
(Tue Dec 4 09:34:50 2012) [sssd[nss]] [nss_cmd_getpwnam_search] (0x0400): Returning info
for user
[shassan(a)sri.utoronto.ca]
(Tue Dec 4 09:34:50 2012) [sssd[nss]] [client_recv] (0x0200): Client disconnected!
(Tue Dec 4 09:34:50 2012) [sssd[nss]] [client_recv] (0x0200): Client disconnected!
(Tue Dec 4 09:34:50 2012) [sssd[nss]] [nss_cmd_getpwnam] (0x0100): Requesting info for
[shassan]
from [sri.utoronto.ca]
(Tue Dec 4 09:34:50 2012) [sssd[nss]] [sss_ncache_check_str] (0x2000): Checking negative
cache for
[NCE/USER/sri.utoronto.ca/shassan]
(Tue Dec 4 09:34:50 2012) [sssd[nss]] [nss_cmd_getpwnam_search] (0x0100): Requesting info
for
[shassan(a)sri.utoronto.ca]
(Tue Dec 4 09:34:50 2012) [sssd[nss]] [check_cache] (0x0400): Cached entry is valid,
returning..
(Tue Dec 4 09:34:50 2012) [sssd[nss]] [nss_cmd_getpwnam_search] (0x0400): Returning info
for user
[shassan(a)sri.utoronto.ca]
(Tue Dec 4 09:34:50 2012) [sssd[nss]] [nss_cmd_getpwnam] (0x0100): Requesting info for
[shassan]
from [sri.utoronto.ca]
(Tue Dec 4 09:34:50 2012) [sssd[nss]] [sss_ncache_check_str] (0x2000): Checking negative
cache for
[NCE/USER/sri.utoronto.ca/shassan]
(Tue Dec 4 09:34:50 2012) [sssd[nss]] [nss_cmd_getpwnam_search] (0x0100): Requesting info
for
[shassan(a)sri.utoronto.ca]
(Tue Dec 4 09:34:50 2012) [sssd[nss]] [check_cache] (0x0400): Cached entry is valid,
returning..
(Tue Dec 4 09:34:50 2012) [sssd[nss]] [nss_cmd_getpwnam_search] (0x0400): Returning info
for user
[shassan(a)sri.utoronto.ca]
(Tue Dec 4 09:34:50 2012) [sssd[nss]] [nss_cmd_getpwnam] (0x0100): Requesting info for
[shassan]
from [sri.utoronto.ca]
(Tue Dec 4 09:34:50 2012) [sssd[nss]] [sss_ncache_check_str] (0x2000): Checking negative
cache for
[NCE/USER/sri.utoronto.ca/shassan]
(Tue Dec 4 09:34:50 2012) [sssd[nss]] [nss_cmd_getpwnam_search] (0x0100): Requesting info
for
[shassan(a)sri.utoronto.ca]
(Tue Dec 4 09:34:50 2012) [sssd[nss]] [check_cache] (0x0400): Cached entry is valid,
returning..
(Tue Dec 4 09:34:50 2012) [sssd[nss]] [nss_cmd_getpwnam_search] (0x0400): Returning info
for user
[shassan(a)sri.utoronto.ca]
(Tue Dec 4 09:34:50 2012) [sssd[nss]] [nss_cmd_getpwnam] (0x0100): Requesting info for
[shassan]
from [sri.utoronto.ca]
(Tue Dec 4 09:34:50 2012) [sssd[nss]] [sss_ncache_check_str] (0x2000): Checking negative
cache for
[NCE/USER/sri.utoronto.ca/shassan]
(Tue Dec 4 09:34:50 2012) [sssd[nss]] [nss_cmd_getpwnam_search] (0x0100): Requesting info
for
[shassan(a)sri.utoronto.ca]
(Tue Dec 4 09:34:50 2012) [sssd[nss]] [check_cache] (0x0400): Cached entry is valid,
returning..
(Tue Dec 4 09:34:50 2012) [sssd[nss]] [nss_cmd_getpwnam_search] (0x0400): Returning info
for user
[shassan(a)sri.utoronto.ca]
(Tue Dec 4 09:34:50 2012) [sssd[nss]] [accept_fd_handler] (0x0100): Client connected!
(Tue Dec 4 09:34:50 2012) [sssd[nss]] [sss_cmd_get_version] (0x0200): Received client
version [1].
(Tue Dec 4 09:34:50 2012) [sssd[nss]] [sss_cmd_get_version] (0x0200): Offered version
[1].
(Tue Dec 4 09:34:50 2012) [sssd[nss]] [nss_cmd_initgroups] (0x0100): Requesting info for
[shassan]
from [<ALL>]
(Tue Dec 4 09:34:50 2012) [sssd[nss]] [sss_ncache_check_str] (0x2000): Checking negative
cache for
[NCE/USER/sri.utoronto.ca/shassan]
(Tue Dec 4 09:34:50 2012) [sssd[nss]] [nss_cmd_initgroups_search] (0x0100): Requesting
info for
[shassan(a)sri.utoronto.ca]
(Tue Dec 4 09:34:50 2012) [sssd[nss]] [check_cache] (0x0400): Cached entry is valid,
returning..
(Tue Dec 4 09:34:50 2012) [sssd[nss]] [nss_cmd_initgroups_search] (0x0400): Initgroups
for
[shassan(a)sri.utoronto.ca] completed
(Tue Dec 4 09:34:51 2012) [sssd[nss]] [client_recv] (0x0200): Client disconnected!
===== gone bad =====
(Tue Dec 4 10:50:49 2012) [sssd[nss]] [nss_cmd_getpwnam] (0x0100): Requesting info for
[shassan]
from [<ALL>]
(Tue Dec 4 10:50:49 2012) [sssd[nss]] [sss_ncache_check_str] (0x2000): Checking negative
cache for
[NCE/USER/sri.utoronto.ca/shassan]
(Tue Dec 4 10:50:49 2012) [sssd[nss]] [nss_cmd_getpwnam_search] (0x0100): Requesting info
for
[shassan(a)sri.utoronto.ca]
(Tue Dec 4 10:50:49 2012) [sssd[nss]] [sss_dp_issue_request] (0x0400): Issuing request
for
[0x4267b0:1:shassan@sri.utoronto.ca]
(Tue Dec 4 10:50:49 2012) [sssd[nss]] [sss_dp_get_account_msg] (0x0400): Creating request
for
[sri.utoronto.ca][4097][1][name=shassan]
(Tue Dec 4 10:50:49 2012) [sssd[nss]] [sbus_add_timeout] (0x2000): 0x15215f0
(Tue Dec 4 10:50:49 2012) [sssd[nss]] [sss_dp_internal_get_send] (0x0400): Entering
request
[0x4267b0:1:shassan@sri.utoronto.ca]
(Tue Dec 4 10:50:49 2012) [sssd[nss]] [sbus_remove_timeout] (0x2000): 0x15215f0
(Tue Dec 4 10:50:49 2012) [sssd[nss]] [sss_dp_get_reply] (0x1000): Got reply from Data
Provider -
DP error code: 1 errno: 11 error message: Fast reply - offline
(Tue Dec 4 10:50:49 2012) [sssd[nss]] [nss_cmd_getpwnam_dp_callback] (0x0040): Unable to
get
information from Data Provider
Error: 1, 11, Fast reply - offline
Will try to return what we have in cache
(Tue Dec 4 10:50:49 2012) [sssd[nss]] [sss_dp_req_destructor] (0x0400): Deleting request:
[0x4267b0:1:shassan@sri.utoronto.ca]
===== second wave =====
(Tue Dec 4 11:34:31 2012) [sssd[nss]] [sss_cmd_get_version] (0x0200): Received client
version [1].
(Tue Dec 4 11:34:31 2012) [sssd[nss]] [sss_cmd_get_version] (0x0200): Offered version
[1].
(Tue Dec 4 11:34:31 2012) [sssd[nss]] [nss_cmd_getpwnam] (0x0100): Requesting info for
[shassan]
from [<ALL>]
(Tue Dec 4 11:34:31 2012) [sssd[nss]] [sss_ncache_check_str] (0x2000): Checking negative
cache for
[NCE/USER/sri.utoronto.ca/shassan]
(Tue Dec 4 11:34:31 2012) [sssd[nss]] [nss_cmd_getpwnam_search] (0x0100): Requesting info
for
[shassan(a)sri.utoronto.ca]
(Tue Dec 4 11:34:31 2012) [sssd[nss]] [sss_dp_issue_request] (0x0400): Issuing request
for
[0x4267b0:1:shassan@sri.utoronto.ca]
(Tue Dec 4 11:34:31 2012) [sssd[nss]] [sss_dp_get_account_msg] (0x0400): Creating request
for
[sri.utoronto.ca][4097][1][name=shassan]
(Tue Dec 4 11:34:31 2012) [sssd[nss]] [sbus_add_timeout] (0x2000): 0x11bd340
(Tue Dec 4 11:34:31 2012) [sssd[nss]] [sss_dp_internal_get_send] (0x0400): Entering
request
[0x4267b0:1:shassan@sri.utoronto.ca]
(Tue Dec 4 11:34:31 2012) [sssd[nss]] [sbus_remove_timeout] (0x2000): 0x11bd340
(Tue Dec 4 11:34:31 2012) [sssd[nss]] [sss_dp_get_reply] (0x1000): Got reply from Data
Provider -
DP error code: 1 errno: 11 error message: Fast reply - offline
(Tue Dec 4 11:34:31 2012) [sssd[nss]] [nss_cmd_getpwnam_dp_callback] (0x0040): Unable to
get
information from Data Provider
Error: 1, 11, Fast reply - offline
Will try to return what we have in cache
(Tue Dec 4 11:34:31 2012) [sssd[nss]] [sss_dp_req_destructor] (0x0400): Deleting request:
[0x4267b0:1:shassan@sri.utoronto.ca]
(Tue Dec 4 11:34:31 2012) [sssd[nss]] [client_recv] (0x0200): Client disconnected!
(Tue Dec 4 11:34:32 2012) [sssd[nss]] [client_recv] (0x0200): Client disconnected!
(Tue Dec 4 11:34:32 2012) [sssd[nss]] [client_recv] (0x0200): Client disconnected!
===== user is asked to close and open thunderbird =====
(Tue Dec 4 11:38:06 2012) [sssd[nss]] [nss_cmd_getpwnam] (0x0100): Requesting info for
[shassan]
from [sri.utoronto.ca]
(Tue Dec 4 11:38:06 2012) [sssd[nss]] [sss_ncache_check_str] (0x2000): Checking negative
cache for
[NCE/USER/sri.utoronto.ca/shassan]
(Tue Dec 4 11:38:06 2012) [sssd[nss]] [nss_cmd_getpwnam_search] (0x0100): Requesting info
for
[shassan(a)sri.utoronto.ca]
(Tue Dec 4 11:38:06 2012) [sssd[nss]] [sss_dp_issue_request] (0x0400): Issuing request
for
[0x4267b0:1:shassan@sri.utoronto.ca]
(Tue Dec 4 11:38:06 2012) [sssd[nss]] [sss_dp_get_account_msg] (0x0400): Creating request
for
[sri.utoronto.ca][4097][1][name=shassan]
(Tue Dec 4 11:38:06 2012) [sssd[nss]] [sbus_add_timeout] (0x2000): 0xf66f90
(Tue Dec 4 11:38:06 2012) [sssd[nss]] [sss_dp_internal_get_send] (0x0400): Entering
request
[0x4267b0:1:shassan@sri.utoronto.ca]
(Tue Dec 4 11:38:06 2012) [sssd[nss]] [sbus_remove_timeout] (0x2000): 0xf66f90
(Tue Dec 4 11:38:06 2012) [sssd[nss]] [sss_dp_get_reply] (0x1000): Got reply from Data
Provider -
DP error code: 1 errno: 11 error message: Fast reply - offline
(Tue Dec 4 11:38:06 2012) [sssd[nss]] [nss_cmd_getpwnam_dp_callback] (0x0040): Unable to
get
information from Data Provider
Error: 1, 11, Fast reply - offline
Will try to return what we have in cache
(Tue Dec 4 11:38:06 2012) [sssd[nss]] [sss_dp_req_destructor] (0x0400): Deleting request:
[0x4267b0:1:shassan@sri.utoronto.ca]
(Tue Dec 4 11:38:06 2012) [sssd[nss]] [nss_cmd_getpwnam] (0x0100): Requesting info for
[shassan]
from [sri.utoronto.ca]
(Tue Dec 4 11:38:06 2012) [sssd[nss]] [sss_ncache_check_str] (0x2000): Checking negative
cache for
[NCE/USER/sri.utoronto.ca/shassan]
(Tue Dec 4 11:38:06 2012) [sssd[nss]] [nss_cmd_getpwnam_search] (0x0100): Requesting info
for
[shassan(a)sri.utoronto.ca]
(Tue Dec 4 11:38:06 2012) [sssd[nss]] [sss_dp_issue_request] (0x0400): Issuing request
for
[0x4267b0:1:shassan@sri.utoronto.ca]
(Tue Dec 4 11:38:06 2012) [sssd[nss]] [sss_dp_get_account_msg] (0x0400): Creating request
for
[sri.utoronto.ca][4097][1][name=shassan]
(Tue Dec 4 11:38:06 2012) [sssd[nss]] [sbus_add_timeout] (0x2000): 0xe65ed0
(Tue Dec 4 11:38:06 2012) [sssd[nss]] [sss_dp_internal_get_send] (0x0400): Entering
request
[0x4267b0:1:shassan@sri.utoronto.ca]
(Tue Dec 4 11:38:06 2012) [sssd[nss]] [sbus_remove_timeout] (0x2000): 0xe65ed0
(Tue Dec 4 11:38:06 2012) [sssd[nss]] [sss_dp_get_reply] (0x1000): Got reply from Data
Provider -
DP error code: 1 errno: 11 error message: Fast reply - offline
(Tue Dec 4 11:38:06 2012) [sssd[nss]] [nss_cmd_getpwnam_dp_callback] (0x0040): Unable to
get
information from Data Provider
Error: 1, 11, Fast reply - offline
Will try to return what we have in cache
(Tue Dec 4 11:38:06 2012) [sssd[nss]] [sss_dp_req_destructor] (0x0400): Deleting request:
[0x4267b0:1:shassan@sri.utoronto.ca]
(Tue Dec 4 11:38:06 2012) [sssd[nss]] [nss_cmd_getpwnam] (0x0100): Requesting info for
[shassan]
from [sri.utoronto.ca]
(Tue Dec 4 11:38:06 2012) [sssd[nss]] [sss_ncache_check_str] (0x2000): Checking negative
cache for
[NCE/USER/sri.utoronto.ca/shassan]
(Tue Dec 4 11:38:06 2012) [sssd[nss]] [nss_cmd_getpwnam_search] (0x0100): Requesting info
for
[shassan(a)sri.utoronto.ca]
(Tue Dec 4 11:38:06 2012) [sssd[nss]] [sss_dp_issue_request] (0x0400): Issuing request
for
[0x4267b0:1:shassan@sri.utoronto.ca]
(Tue Dec 4 11:38:06 2012) [sssd[nss]] [sss_dp_get_account_msg] (0x0400): Creating request
for
[sri.utoronto.ca][4097][1][name=shassan]
(Tue Dec 4 11:38:06 2012) [sssd[nss]] [sbus_add_timeout] (0x2000): 0x167ac00
(Tue Dec 4 11:38:06 2012) [sssd[nss]] [sss_dp_internal_get_send] (0x0400): Entering
request
[0x4267b0:1:shassan@sri.utoronto.ca]
(Tue Dec 4 11:38:06 2012) [sssd[nss]] [sbus_remove_timeout] (0x2000): 0x167ac00
(Tue Dec 4 11:38:06 2012) [sssd[nss]] [sss_dp_get_reply] (0x1000): Got reply from Data
Provider -
DP error code: 1 errno: 11 error message: Fast reply - offline
(Tue Dec 4 11:38:06 2012) [sssd[nss]] [nss_cmd_getpwnam_dp_callback] (0x0040): Unable to
get
information from Data Provider
Error: 1, 11, Fast reply - offline
Will try to return what we have in cache
(Tue Dec 4 11:38:06 2012) [sssd[nss]] [sss_dp_req_destructor] (0x0400): Deleting request:
[0x4267b0:1:shassan@sri.utoronto.ca]
(Tue Dec 4 11:38:06 2012) [sssd[nss]] [accept_fd_handler] (0x0100): Client connected!
(Tue Dec 4 11:38:06 2012) [sssd[nss]] [sss_cmd_get_version] (0x0200): Received client
version [1].
(Tue Dec 4 11:38:06 2012) [sssd[nss]] [sss_cmd_get_version] (0x0200): Offered version
[1].
(Tue Dec 4 11:38:06 2012) [sssd[nss]] [nss_cmd_getpwnam] (0x0100): Requesting info for
[shassan]
from [<ALL>]
(Tue Dec 4 11:38:06 2012) [sssd[nss]] [sss_ncache_check_str] (0x2000): Checking negative
cache for
[NCE/USER/sri.utoronto.ca/shassan]
(Tue Dec 4 11:38:06 2012) [sssd[nss]] [nss_cmd_getpwnam_search] (0x0100): Requesting info
for
[shassan(a)sri.utoronto.ca]
(Tue Dec 4 11:38:06 2012) [sssd[nss]] [sss_dp_issue_request] (0x0400): Issuing request
for
[0x4267b0:1:shassan@sri.utoronto.ca]
(Tue Dec 4 11:38:06 2012) [sssd[nss]] [sss_dp_get_account_msg] (0x0400): Creating request
for
[sri.utoronto.ca][4097][1][name=shassan]
(Tue Dec 4 11:38:06 2012) [sssd[nss]] [sbus_add_timeout] (0x2000): 0x1b34d70
(Tue Dec 4 11:38:06 2012) [sssd[nss]] [sss_dp_internal_get_send] (0x0400): Entering
request
[0x4267b0:1:shassan@sri.utoronto.ca]
(Tue Dec 4 11:38:06 2012) [sssd[nss]] [sbus_remove_timeout] (0x2000): 0x1b34d70
(Tue Dec 4 11:38:06 2012) [sssd[nss]] [sss_dp_get_reply] (0x1000): Got reply from Data
Provider -
DP error code: 1 errno: 11 error message: Fast reply - offline
(Tue Dec 4 11:38:06 2012) [sssd[nss]] [nss_cmd_getpwnam_dp_callback] (0x0040): Unable to
get
information from Data Provider
Error: 1, 11, Fast reply - offline
Will try to return what we have in cache
(Tue Dec 4 11:38:06 2012) [sssd[nss]] [sss_dp_req_destructor] (0x0400): Deleting request:
[0x4267b0:1:shassan@sri.utoronto.ca]
===== end =====
A "service sssd restart" "fix" the problem...
I am thinking of running a cron job of above every 10 minutes to work around
the problem while it is being troubleshoot. Is it a bad idea?
Thanks,
Qing