[Freeipa-users] migrate-ds aborts

Tue Jan 20 15:49:35 UTC 2015

We are making progress.

> -----Original Message-----
> From: Martin Kosek [mailto:mkosek at redhat.com]
> Sent: Monday, January 19, 2015 2:52 AM
> To: Quayle, Bill; Ludwig Krispenz
> Cc: 'freeipa-users at redhat.com'
> Subject: Re: [Freeipa-users] migrate-ds aborts
>
> On 01/16/2015 08:21 PM, Quayle, Bill wrote:
> >
> >
> >> -----Original Message-----
> >> From: Martin Kosek [mailto:mkosek at redhat.com]
> >> Sent: Friday, January 16, 2015 12:51 PM
> >> To: Quayle, Bill; Ludwig Krispenz
> >> Cc: 'freeipa-users at redhat.com'
> >> Subject: Re: [Freeipa-users] migrate-ds aborts
> >>
> >> On 01/16/2015 04:48 PM, Quayle, Bill wrote:
> >>> Thanks for looking into this!
> >>>
> >>> I was finally able to import all 11811 user records into IPA, but
> >>> even now,
> >> when I re-run the migrate, I get the same failure.
> >>
> >> How did you do it in the end? Simply by running migrate-ds command
> >> multiple times or did you succeeded with the limits?
> >>
> > I re-ran migrate-ds about 30 times to complete the migration of users.
>
> Hm, this is definitely not how the migrate-ds is supposed work :-/ I wish we
> can find the problem to avoid such difficulties for other users.
>
As this is an evaluation setup, I can tear-down and rebuild to try to capture more data, if you want.
> ...
> >>> One thing that is also confusing me, is that I am getting this error:
> >>> [Fri Jan 16 09:28:29.007575 2015] [:error] [pid 14924] ipa: WARNING:
> >>> GID
> >> number 11 of migrated user anyone does not point to a known group.
> >>
> >> migrate-ds command runs a search against the migrated OpenLDAP
> >> database and tries to find a group with gidNumber 11. When it fails
> >> to locate it, it reports this error. Do you have all the groups in DN
> >> "ou=people,ou=agroup,dc=example,dc=com"?
> >>
> > Groups are in "ou=groups,ou=agroup,dc=example,dc=com"
> > I use --base-dn="ou=agroup,dc=example,dc=com" as an option to
> > migrate-ds
>
> Right, sorry - I see I mistyped the DN. Does the container then contain a
> group with gidNumber 11? It would explain the error you were asking about.
>
I also mistyped the dn.  We use "group" instead of "groups", which explains a lot.
> >>
> >>> And it never migrates my groups.  The ou=Groups is used in my source
> >> openLDAP tree, so I'm not sure why it wouldn't migrate.
>
> Maybe your groups use some scheme that migrate-ds does not recognize as
> group.
> Can you show an example/LDIF of a group stored in ou=Groups?
>
> migrate-ds will search for groups with this default filter BTW:
>
> (&(|(objectClass=groupofuniquenames)(objectClass=groupofnames))(cn=*)
> )
>
We also do not use this objectClass.  I've set:
   --group-contain="ou=group" --group-objectclass=posixGroup --user-objectclass=foo
And re-run the migrate-ds.

It populated my groups!  :-)

> >>
> >> If i crashes during user migration, it won't even continue with
> >> groups. I know this is not a proper fix, but you could make sure the
> >> user migration part does not find anything (e.g. with
> >> --user-objectclass=foo) and using --continue option. Then it will jump
> directly to group migration.
> >>
> > I had actually already tried doing that.  I just re-tried using the debug=True,
> and here's the contents of error_log:
>
> Ah. Yes, this revealed one error, although this one just means that neither
> user or group search did not return any errors. I created a ticket for it:
>
> https://fedorahosted.org/freeipa/ticket/4846
>
> The fix for this will be easy, but it will not fix the actual root cause of the
> migration problems you are hitting
>
> > [Fri Jan 16 13:07:42.819342 2015] [:error] [pid 15335] ipa: DEBUG: WSGI
> wsgi_dispatch.__call__:
> > [Fri Jan 16 13:07:42.819462 2015] [:error] [pid 15335] ipa: DEBUG: WSGI
> xmlserver_session.__call__:
> > [Fri Jan 16 13:07:42.819649 2015] [:error] [pid 15335] ipa: DEBUG:
> > found session cookie_id = 7efb4fc24d37b7fe064fa2a4f0af447b [Fri Jan 16
> > 13:07:42.819926 2015] [:error] [pid 15335] ipa: DEBUG: found session
> > data in cache with id=7efb4fc24d37b7fe064fa2a4f0af447b
> > [Fri Jan 16 13:07:42.820031 2015] [:error] [pid 15335] ipa: DEBUG:
> > xmlserver_session.__call__:
> > session_id=7efb4fc24d37b7fe064fa2a4f0af447b
> > start_timestamp=2015-01-16T13:06:02
> > access_timestamp=2015-01-16T13:07:42
> > expiration_timestamp=2015-01-16T13:26:02
> > [Fri Jan 16 13:07:42.820113 2015] [:error] [pid 15335] ipa: DEBUG: storing
> ccache data into file "/var/run/ipa_memcached/krbcc_15335"
> > [Fri Jan 16 13:07:42.820724 2015] [:error] [pid 15335] ipa: DEBUG:
> > get_credential_times:
> > principal=HTTP/testserver.example.com at IDMTEST.EXAMPLE.COM,
> > authtime=01/15/15 16:44:10, starttime=01/15/15 16:44:17,
> > endtime=01/16/15 16:44:04, renew_till=12/31/69 18:00:00 [Fri Jan 16
> 13:07:42.821070 2015] [:error] [pid 15335] ipa: DEBUG: get_credential_times:
> principal=HTTP/testserver.example.com at IDMTEST.EXAMPLE.COM,
> authtime=01/15/15 16:44:10, starttime=01/15/15 16:44:17, endtime=01/16/15
> 16:44:04, renew_till=12/31/69 18:00:00 [Fri Jan 16 13:07:42.821370 2015]
> [:error] [pid 15335] ipa: DEBUG: KRB5_CCache
> FILE:/var/run/ipa_memcached/krbcc_15335 endtime=1421448244 (01/16/15
> 16:44:04) [Fri Jan 16 13:07:42.821480 2015] [:error] [pid 15335] ipa: DEBUG:
> set_session_expiration_time: duration_type=inactivity_timeout
> duration=1200 max_age=1421447944 expiration=1421436462.82 (2015-01-
> 16T13:27:42) [Fri Jan 16 13:07:42.821539 2015] [:error] [pid 15335] ipa: DEBUG:
> WSGI xmlserver.__call__:
> > [Fri Jan 16 13:07:42.850018 2015] [:error] [pid 15335] ipa: DEBUG:
> > Created connection context.ldap2 [Fri Jan 16 13:07:42.850117 2015] [:error]
> [pid 15335] ipa: DEBUG: WSGI WSGIExecutioner.__call__:
> > [Fri Jan 16 13:07:42.851403 2015] [:error] [pid 15335] ipa: DEBUG:
> > raw: migrate_ds(u'ldap://10.x.x.x:389', u'********',
> > binddn=u'uid=me,ou=people,ou=agroup,dc=example,dc=com',
> > usercontainer=u'ou=people', groupcontainer=u'ou=groups',
> > userobjectclass=(u'foo',), groupobjectclass=(u'groupOfUniqueNames',
> u'groupOfNames'), userignoreobjectclass=None, userignoreattribute=None,
> groupignoreobjectclass=None, groupignoreattribute=None,
> groupoverwritegid=False, schema=u'RFC2307bis', continue=True,
> basedn=u'ou=agroup,dc=example,dc=com', compat=False, version=u'2.65',
> exclude_groups=None, exclude_users=None) [Fri Jan 16 13:07:42.852159
> 2015] [:error] [pid 15335] ipa: DEBUG: migrate_ds(u'ldap://10.x.x.x:389',
> u'********',
> binddn=ipapython.dn.DN('uid=me,ou=people,ou=agroup,dc=example,dc=c
> om'), usercontainer=ipapython.dn.DN('ou=people'),
> groupcontainer=ipapython.dn.DN('ou=groups'), userobjectclass=(u'foo',),
> groupobjectclass=(u'groupOfUniqueNames', u'groupOfNames'),
> userignoreobjectclass=None, userignoreattribute=None,
> groupignoreobjectclass=None, groupignoreattribute=None,
> groupoverwritegid=False, schema=u'RFC2307bis', continue=True,
> basedn=ipapython.dn.DN('ou=agroup,dc=example,dc=com'), compat=False,
> version=u'2.65', exclude_groups=None, exclude_users=None) [Fri Jan 16
> 13:07:42.933433 2015] [:error] [pid 15335] ipa: DEBUG: Created connection
> context.ldap2_140625322494032 [Fri Jan 16 13:07:42.944655 2015] [:error] [pid
> 15335] ipa: ERROR: non-public: UnboundLocalError: local variable 'pkey'
> referenced before assignment [Fri Jan 16 13:07:42.944666 2015] [:error] [pid
> 15335] Traceback (most recent call last):
> > [Fri Jan 16 13:07:42.944668 2015] [:error] [pid 15335]   File
> "/usr/lib/python2.7/site-packages/ipaserver/rpcserver.py", line 333, in
> wsgi_execute
> > [Fri Jan 16 13:07:42.944670 2015] [:error] [pid 15335]     result =
> self.Command[name](*args, **options)
> > [Fri Jan 16 13:07:42.944671 2015] [:error] [pid 15335]   File
> "/usr/lib/python2.7/site-packages/ipalib/frontend.py", line 436, in __call__
> > [Fri Jan 16 13:07:42.944673 2015] [:error] [pid 15335]     ret = self.run(*args,
> **options)
> > [Fri Jan 16 13:07:42.944683 2015] [:error] [pid 15335]   File
> "/usr/lib/python2.7/site-packages/ipalib/frontend.py", line 755, in run
> > [Fri Jan 16 13:07:42.944686 2015] [:error] [pid 15335]     result =
> self.execute(*args, **options)
> > [Fri Jan 16 13:07:42.944687 2015] [:error] [pid 15335]   File
> "/usr/lib/python2.7/site-packages/ipalib/plugins/migration.py", line 894, in
> execute
> > [Fri Jan 16 13:07:42.944689 2015] [:error] [pid 15335]     ldap, config, ds_ldap,
> ds_base_dn, options
> > [Fri Jan 16 13:07:42.944691 2015] [:error] [pid 15335]   File
> "/usr/lib/python2.7/site-packages/ipalib/plugins/migration.py", line 843, in
> migrate
> > [Fri Jan 16 13:07:42.944692 2015] [:error] [pid 15335]
> _update_default_group(ldap, pkey, config, context, True)
> > [Fri Jan 16 13:07:42.944694 2015] [:error] [pid 15335]
> > UnboundLocalError: local variable 'pkey' referenced before assignment
> > [Fri Jan 16 13:07:42.944888 2015] [:error] [pid 15335] ipa: INFO:
> > admin at IDMTEST.EXAMPLE.COM: migrate_ds(u'ldap://10.x.x.x:389',
> > u'********',
> binddn=u'uid=me,ou=people,ou=agroup,dc=example,dc=com',
> > usercontainer=u'ou=people', groupcontainer=u'ou=groups',
> userobjectclass=(u'foo',), groupobjectclass=(u'groupOfUniqueNames',
> u'groupOfNames'), userignoreobjectclass=None, userignoreattribute=None,
> groupignoreobjectclass=None, groupignoreattribute=None,
> groupoverwritegid=False, schema=u'RFC2307bis', continue=True,
> basedn=u'ou=agroup,dc=example,dc=com', compat=False, version=u'2.65',
> exclude_groups=None, exclude_users=None): UnboundLocalError [Fri Jan
> 16 13:07:42.944952 2015] [:error] [pid 15335] ipa: DEBUG: response:
> InternalError: an internal error has occurred [Fri Jan 16 13:07:42.945645 2015]
> [:error] [pid 15335] ipa: DEBUG: Destroyed connection context.ldap2 [Fri Jan
> 16 13:07:42.945757 2015] [:error] [pid 15335] ipa: DEBUG: Destroyed
> connection context.ldap2_140625322494032 [Fri Jan 16 13:07:42.945846 2015]
> [:error] [pid 15335] ipa: DEBUG: reading ccache data from file
> "/var/run/ipa_memcached/krbcc_15335"
> > [Fri Jan 16 13:07:42.946019 2015] [:error] [pid 15335] ipa: DEBUG:
> > store session: session_id=7efb4fc24d37b7fe064fa2a4f0af447b
> > start_timestamp=2015-01-16T13:06:02
> > access_timestamp=2015-01-16T13:07:42
> > expiration_timestamp=2015-01-16T13:27:42
> >
> >> I am still thinking it would make sense to also check the migrated
> >> OpenLDAP logs and see if there is anything interesting when the
> migration breaks.
> >
> > I've been watching the logs on the OpenLDAP servers, and they just see
> the connection close.
>
> access log excerpt may help, if it contains any error logs we could use. I was
> also thinking it would be also useful to know which LDAP search exactly failed
> as it is not clear from the error. If you modify the FreeIPA server this way:
>
> # cp /usr/lib/python2.7/site-packages/ipaserver/rpcserver.py
> /usr/lib/python2.7/site-packages/ipaserver/rpcserver.py.bkp
> # sed -i "s/error = e$/error = e\n            import traceback\n
> traceback.print_exc()/" /usr/lib/python2.7/site-
> packages/ipaserver/rpcserver.py
> # service httpd restart
>
> The traceback of where the NetworkError is raised should be added to
> /var/log/httpd/error_log.
>
So we have successfully migrated the users and groups.  I can't seem to find any pointers on migrating netgroups and automount maps.   Is this done via an LDIF dump and import?

Thanks!
-Bill

________________________________

CONFIDENTIALITY AND SECURITY NOTICE

The contents of this message and any attachments may be confidential and proprietary. If you are not an intended recipient, please inform the sender of the transmission error and delete this message immediately without reading, distributing or copying the contents.