[Samba] Possible problem w/ 'idmap restore' under 3.0.25rc3 (the sequel)

[Don Meyer]

At 04:40 PM 5/9/2007, simo wrote:
>On Fri, 2007-05-04 at 19:14 -0500, Don Meyer wrote:
> > At 06:00 PM 5/4/2007, simo wrote:
> > >Sorry for the problem, this slipped through during recent patches to fix
> > >the sid checking layer violation and the idmap offline code.
> >
> > No problem.
> >
> > I may have another for you, however.   This patch enables me to
> > successfully restore when using a tdb backend.  However, when using
> > idmap_ldap, it seems that winbind is opening a connection to the ldap
> > server and not closing it for many updates/queries.
> >
> > When I try 'net idmap restore' when using idmap_ldap, the command
> > will plug away until the ldap server starts complaining "accept(8)
> > failed errno=24 (Too many open files)".   netstat -aln shows around
> > 1000 open connections from winbind on another system. (The one 
> with 3.0.25rc3+)
>
>Found the problem, see patch for revision 22771.
>Another one-liner :/
>
>Thanks again for testing rc3 out.


Simo, you are going to think I'm picking on you, but I think we may 
have yet another problem...

The 22771 patch does fix winbindd's abuse of the ldap server -- when 
I start winbind, it opens two sessions to the ldap server.  When I 
subsequently try the 'net idmap restore' command to restore several 
thousand SID-UID/GID mappings,  all the transactions flow one of 
those TCP sessions.  However, the command throws a huge list of 
errors (thousands) that we've seen before IIRC, and we thought you 
had fixed with patch 22677:

-------------------
Could not set mapping of UID 10392 to sid 
S-1-5-21-893289765-2623729106-2343379446-1290
Could not set mapping of UID 10107 to sid 
S-1-5-21-893289765-2623729106-2343379446-1120
Could not set mapping of UID 15937 to sid 
S-1-5-21-893289765-2623729106-2343379446-3005
Could not set mapping of UID 10745 to sid 
S-1-5-21-893289765-2623729106-2343379446-2134
Could not set mapping of UID 10476 to sid 
S-1-5-21-893289765-2623729106-2343379446-1311
Could not set mapping of UID 17143 to sid 
S-1-5-21-893289765-2623729106-2343379446-1899
Could not set mapping of UID 15891 to sid 
S-1-5-21-893289765-2623729106-2343379446-1880
Could not set mapping of UID 10109 to sid 
S-1-5-21-893289765-2623729106-2343379446-1131
Could not set mapping of UID 15912 to sid 
S-1-5-21-893289765-2623729106-2343379446-1853
Could not set mapping of UID 10900 to sid 
S-1-5-21-893289765-2623729106-2343379446-1417
Could not set mapping of UID 10708 to sid 
S-1-5-21-893289765-2623729106-2343379446-1369
Could not set mapping of UID 10557 to sid 
S-1-5-21-893289765-2623729106-2343379446-1587
...
--------------------------

The ldap.log shows an equally long list of suspect entries:

---------------------------
May 10 01:07:21 lns-0 slapd2.3[7972]: conn=8624 op=7233 ADD 
dn="sambaSID=S-1-5-21-25438887-418410483-241655303-3099,ou=idmap,dc=aces-web"
May 10 01:07:21 lns-0 slapd2.3[7972]: conn=8624 op=7233 RESULT 
tag=105 err=0 text=
May 10 01:07:21 lns-0 slapd2.3[7972]: conn=8624 op=7234 ADD 
dn="sambaSID=S-1-5-21-25438887-418410483-241655303-2867,ou=idmap,dc=aces-web"
May 10 01:07:21 lns-0 slapd2.3[7972]: conn=8624 op=7234 RESULT 
tag=105 err=0 text=
May 10 01:07:21 lns-0 slapd2.3[7972]: conn=8624 op=7235 ADD 
dn="sambaSID=S-1-5-21-25438887-418410483-241655303-1279,ou=idmap,dc=aces-web"
May 10 01:07:21 lns-0 slapd2.3[7972]: conn=8624 op=7235 RESULT 
tag=105 err=0 text=
May 10 01:07:21 lns-0 slapd2.3[7972]: conn=8624 op=7236 ADD 
dn="sambaSID=S-1-5-21-25438887-418410483-241655303-2435,ou=idmap,dc=aces-web"
May 10 01:07:21 lns-0 slapd2.3[7972]: conn=8624 op=7236 RESULT 
tag=105 err=0 text=
May 10 01:07:21 lns-0 slapd2.3[7972]: conn=8624 op=7237 ADD 
dn="sambaSID=S-1-5-21-25438887-418410483-241655303-2893,ou=idmap,dc=aces-web"
May 10 01:07:21 lns-0 slapd2.3[7972]: conn=8624 op=7237 RESULT 
tag=105 err=0 text=
May 10 01:07:21 lns-0 slapd2.3[7972]: conn=8624 op=7238 ADD 
dn="sambaSID=S-1-5-21-893289765-2623729106-2343379446-2458,ou=idmap,dc=aces-web" 

May 10 01:07:21 lns-0 slapd2.3[7972]: conn=8624 op=7238 RESULT 
tag=105 err=0 text=
May 10 01:07:21 lns-0 slapd2.3[7972]: conn=8624 op=7239 ADD 
dn="sambaSID=S-1-5-21-893289765-2623729106-2343379446-1417,ou=idmap,dc=aces-web" 

May 10 01:07:21 lns-0 slapd2.3[7972]: conn=8624 op=7239 RESULT 
tag=105 err=68 text=
May 10 01:07:21 lns-0 slapd2.3[7972]: conn=8624 op=7240 ADD 
dn="sambaSID=S-1-5-21-893289765-2623729106-2343379446-2676,ou=idmap,dc=aces-web" 

May 10 01:07:21 lns-0 slapd2.3[7972]: conn=8624 op=7240 RESULT 
tag=105 err=0 text=
May 10 01:07:21 lns-0 slapd2.3[7972]: conn=8624 op=7241 ADD 
dn="sambaSID=S-1-5-21-893289765-2623729106-2343379446-2401,ou=idmap,dc=aces-web" 

May 10 01:07:21 lns-0 slapd2.3[7972]: conn=8624 op=7241 RESULT 
tag=105 err=0 text=
....
---------------------------

Afterward, testing the UID mappings that should have been established 
(by 'getent passwd {username}' results in allocation of a new number.

My first thought was that perhaps I missed the original patch for 
this problem, so I reset the smb.conf back from ldap to tdb mode, 
cleaned out /var/lib/samba/ and restarted the smb & winbind service, 
then issued the same 'net idmap restore' command -- which finished 
without a single error, and successfully initialized all the 
users/groups to their correct UID/GID.

So, the previous patch fixes TDB mode, but that particular problem 
appears to still exist under LDAP mode.

If there is any additional info you need (or tests to run) to help 
diagnose this problem, I'd be glad to try to get it for you.

Cheers,
-D



Don Meyer                                           <dlmeyer at uiuc.edu>
Network Manager, ACES Academic Computing Facility
Technical System Manager, ACES TeleNet System
UIUC College of ACES, Information Technology and Communication Services

   "They that can give up essential liberty to obtain a little 
temporary safety,
         deserve neither liberty or safety."     -- Benjamin Franklin, 1759