[Freeipa-users] Upgrade to 3.1.2: web UI no longer works

Thomas Sailer sailer at sailer.dynip.lugs.ch
Tue Feb 5 18:40:48 UTC 2013


On 02/05/2013 06:32 PM, John Dennis wrote:
> % ipactl status
# ipactl status
Directory Service: RUNNING
krb5kdc Service: RUNNING
kadmin Service: RUNNING
named Service: RUNNING
httpd Service: RUNNING
pki-cad Service: RUNNING
ipa: INFO: The ipactl command was successful

Apparently, it isn't...

I've started it using:
# systemctl restart ipa_memcached.service
# systemctl enable ipa_memcached.service

But still, it's not listed with ipactl status (systemctl says it started 
successfully)

Now I'm getting "IPA Error 903".

Thanks,
Tom

-------------- next part --------------
[Tue Feb 05 19:38:27.394919 2013] [:error] [pid 7520] ipa: INFO: *** PROCESS START ***
[Tue Feb 05 19:38:27.410930 2013] [:error] [pid 7519] ipa: INFO: *** PROCESS START ***
[Tue Feb 05 19:38:55.828540 2013] [:error] [pid 7520] ipa: DEBUG: WSGI wsgi_dispatch.__call__:
[Tue Feb 05 19:38:55.829826 2013] [:error] [pid 7520] ipa: DEBUG: WSGI jsonserver_session.__call__:
[Tue Feb 05 19:38:55.831338 2013] [:error] [pid 7520] ipa: DEBUG: found session cookie_id = bcc81ee57dd1b0dc068a6b049618dfa8
[Tue Feb 05 19:38:55.832468 2013] [:error] [pid 7520] ipa: DEBUG: found session data in cache with id=bcc81ee57dd1b0dc068a6b049618dfa8
[Tue Feb 05 19:38:55.852098 2013] [:error] [pid 7520] ipa: DEBUG: jsonserver_session.__call__: session_id=bcc81ee57dd1b0dc068a6b049618dfa8 start_timestamp=2013-02-05T19:34:48 access_timestamp=2013-02-05T19:38:55 expiration_timestamp=2013-02-05T19:57:31
[Tue Feb 05 19:38:55.853918 2013] [:error] [pid 7520] ipa: DEBUG: storing ccache data into file "/var/run/ipa_memcached/krbcc_7520"
[Tue Feb 05 19:38:55.857797 2013] [:error] [pid 7520] ipa: DEBUG: get_credential_times: principal=krbtgt/XXXX.COM at XXXX.COM, authtime=02/05/13 14:28:55, starttime=02/05/13 19:34:48, endtime=02/06/13 14:25:28, renew_till=01/01/70 01:00:00
[Tue Feb 05 19:38:55.858643 2013] [:error] [pid 7520] ipa: DEBUG: get_credential_times: principal=krbtgt/XXXX.COM at XXXX.COM, authtime=02/05/13 14:28:55, starttime=02/05/13 19:34:48, endtime=02/06/13 14:25:28, renew_till=01/01/70 01:00:00
[Tue Feb 05 19:38:55.863192 2013] [:error] [pid 7520] ipa: DEBUG: KRB5_CCache FILE:/var/run/ipa_memcached/krbcc_7520 endtime=1360157128 (02/06/13 14:25:28)
[Tue Feb 05 19:38:55.864570 2013] [:error] [pid 7520] ipa: DEBUG: set_session_expiration_time: duration_type=inactivity_timeout duration=1200 max_age=1360156828 expiration=1360090735.86 (2013-02-05T19:58:55)
[Tue Feb 05 19:38:56.000067 2013] [:error] [pid 7520] ipa: DEBUG: Created connection context.ldap2
[Tue Feb 05 19:38:56.000523 2013] [:error] [pid 7520] ipa: DEBUG: WSGI jsonserver.__call__:
[Tue Feb 05 19:38:56.000831 2013] [:error] [pid 7520] ipa: DEBUG: WSGI WSGIExecutioner.__call__:
[Tue Feb 05 19:38:56.001809 2013] [:error] [pid 7520] ipa: DEBUG: raw: batch(({u'params': [[], {}], u'method': u'i18n_messages'}, {u'params': [[], {}], u'method': u'config_show'}, {u'params': [[], {u'all': True, u'whoami': True}], u'method': u'user_find'}, {u'params': [[], {}], u'method': u'env'}, {u'params': [[], {}], u'method': u'dns_is_enabled'}))
[Tue Feb 05 19:38:56.002558 2013] [:error] [pid 7520] ipa: DEBUG: batch(({u'params': [[], {}], u'method': u'i18n_messages'}, {u'params': [[], {}], u'method': u'config_show'}, {u'params': [[], {u'all': True, u'whoami': True}], u'method': u'user_find'}, {u'params': [[], {}], u'method': u'env'}, {u'params': [[], {}], u'method': u'dns_is_enabled'}))
[Tue Feb 05 19:38:56.003219 2013] [:error] [pid 7520] ipa: DEBUG: raw: i18n_messages()
[Tue Feb 05 19:38:56.003633 2013] [:error] [pid 7520] ipa: DEBUG: i18n_messages()
[Tue Feb 05 19:38:56.011433 2013] [:error] [pid 7520] ipa: INFO: user at XXXX.COM: batch: i18n_messages(): SUCCESS
[Tue Feb 05 19:38:56.011971 2013] [:error] [pid 7520] ipa: DEBUG: raw: config_show()
[Tue Feb 05 19:38:56.012526 2013] [:error] [pid 7520] ipa: DEBUG: config_show(rights=False, all=False, raw=False)
[Tue Feb 05 19:38:56.016416 2013] [:error] [pid 7520] ipa: DEBUG: retrieving schema for SchemaCache url=ldapi://%2fvar%2frun%2fslapd-XXXX-COM.socket conn=<ldap.ldapobject.SimpleLDAPObject instance at 0x7f1d487dad40>
[Tue Feb 05 19:38:56.322078 2013] [:error] [pid 7520] ipa: INFO: user at XXXX.COM: batch: config_show(): SUCCESS
[Tue Feb 05 19:38:56.322640 2013] [:error] [pid 7520] ipa: DEBUG: raw: user_find(None, whoami=True, all=True)
[Tue Feb 05 19:38:56.323390 2013] [:error] [pid 7520] ipa: DEBUG: user_find(None, whoami=True, all=True, raw=False, pkey_only=False)
[Tue Feb 05 19:38:56.335920 2013] [:error] [pid 7520] ipa: DEBUG: get_memberof: entry_dn=uid=user,cn=users,cn=accounts,dc=xxxx,dc=com memberof=[ipapython.dn.DN('cn=admins,cn=groups,cn=accounts,dc=xxxx,dc=com'), ipapython.dn.DN('cn=Replication Administrators,cn=privileges,cn=pbac,dc=xxxx,dc=com'), ipapython.dn.DN('cn=Add Replication Agreements,cn=permissions,cn=pbac,dc=xxxx,dc=com'), ipapython.dn.DN('cn=Modify Replication Agreements,cn=permissions,cn=pbac,dc=xxxx,dc=com'), ipapython.dn.DN('cn=Remove Replication Agreements,cn=permissions,cn=pbac,dc=xxxx,dc=com'), ipapython.dn.DN('cn=Host Enrollment,cn=privileges,cn=pbac,dc=xxxx,dc=com'), ipapython.dn.DN('cn=Manage host keytab,cn=permissions,cn=pbac,dc=xxxx,dc=com'), ipapython.dn.DN('cn=Enroll a host,cn=permissions,cn=pbac,dc=xxxx,dc=com'), ipapython.dn.DN('cn=Add krbPrincipalName to a host,cn=permissions,cn=pbac,dc=xxxx,dc=com'), ipapython.dn.DN('cn=Unlock user accounts,cn=permissions,cn=pbac,dc=xxxx,dc=com'), ipapython.dn.DN('cn=Manage service keytab,cn=permissions,cn=pbac,dc=xxxx,dc=com'), ipapython.dn.DN('cn=ipausers,cn=groups,cn=accounts,dc=xxxx,dc=com'), ipapython.dn.DN('cn=domain admins,cn=groups,cn=accounts,dc=xxxx,dc=com'), ipapython.dn.DN('cn=domain users,cn=groups,cn=accounts,dc=xxxx,dc=com'), ipapython.dn.DN('cn=administrators,cn=groups,cn=accounts,dc=xxxx,dc=com')]
[Tue Feb 05 19:38:56.357334 2013] [:error] [pid 7520] ipa: DEBUG: get_memberof: result direct=[ipapython.dn.DN('cn=admins,cn=groups,cn=accounts,dc=xxxx,dc=com'), ipapython.dn.DN('cn=ipausers,cn=groups,cn=accounts,dc=xxxx,dc=com'), ipapython.dn.DN('cn=domain admins,cn=groups,cn=accounts,dc=xxxx,dc=com'), ipapython.dn.DN('cn=domain users,cn=groups,cn=accounts,dc=xxxx,dc=com'), ipapython.dn.DN('cn=administrators,cn=groups,cn=accounts,dc=xxxx,dc=com')] indirect=[ipapython.dn.DN('cn=Replication Administrators,cn=privileges,cn=pbac,dc=xxxx,dc=com'), ipapython.dn.DN('cn=Add Replication Agreements,cn=permissions,cn=pbac,dc=xxxx,dc=com'), ipapython.dn.DN('cn=Modify Replication Agreements,cn=permissions,cn=pbac,dc=xxxx,dc=com'), ipapython.dn.DN('cn=Remove Replication Agreements,cn=permissions,cn=pbac,dc=xxxx,dc=com'), ipapython.dn.DN('cn=Host Enrollment,cn=privileges,cn=pbac,dc=xxxx,dc=com'), ipapython.dn.DN('cn=Manage host keytab,cn=permissions,cn=pbac,dc=xxxx,dc=com'), ipapython.dn.DN('cn=Enroll a host,cn=permissions,cn=pbac,dc=xxxx,dc=com'), ipapython.dn.DN('cn=Add krbPrincipalName to a host,cn=permissions,cn=pbac,dc=xxxx,dc=com'), ipapython.dn.DN('cn=Unlock user accounts,cn=permissions,cn=pbac,dc=xxxx,dc=com'), ipapython.dn.DN('cn=Manage service keytab,cn=permissions,cn=pbac,dc=xxxx,dc=com')]
[Tue Feb 05 19:38:56.369686 2013] [:error] [pid 7520] ipa: INFO: user at XXXX.COM: batch: user_find(None, whoami=True, all=True): SUCCESS
[Tue Feb 05 19:38:56.370010 2013] [:error] [pid 7520] ipa: DEBUG: raw: env(None)
[Tue Feb 05 19:38:56.370285 2013] [:error] [pid 7520] ipa: DEBUG: env(None, server=False, all=True)
[Tue Feb 05 19:38:56.370822 2013] [:error] [pid 7520] ipa: INFO: user at XXXX.COM: batch: env(None): SUCCESS
[Tue Feb 05 19:38:56.371065 2013] [:error] [pid 7520] ipa: DEBUG: raw: dns_is_enabled()
[Tue Feb 05 19:38:56.371253 2013] [:error] [pid 7520] ipa: DEBUG: dns_is_enabled()
[Tue Feb 05 19:38:56.374367 2013] [:error] [pid 7520] ipa: INFO: user at XXXX.COM: batch: dns_is_enabled(): SUCCESS
[Tue Feb 05 19:38:56.374978 2013] [:error] [pid 7520] ipa: INFO: user at XXXX.COM: batch(({u'params': [[], {}], u'method': u'i18n_messages'}, {u'params': [[], {}], u'method': u'config_show'}, {u'params': [[], {u'all': True, u'whoami': True}], u'method': u'user_find'}, {u'params': [[], {}], u'method': u'env'}, {u'params': [[], {}], u'method': u'dns_is_enabled'})): SUCCESS
[Tue Feb 05 19:38:56.386777 2013] [:error] [pid 7520] ipa: DEBUG: reading ccache data from file "/var/run/ipa_memcached/krbcc_7520"
[Tue Feb 05 19:38:56.387450 2013] [:error] [pid 7520] ipa: DEBUG: store session: session_id=bcc81ee57dd1b0dc068a6b049618dfa8 start_timestamp=2013-02-05T19:34:48 access_timestamp=2013-02-05T19:38:56 expiration_timestamp=2013-02-05T19:58:55
[Tue Feb 05 19:38:56.388829 2013] [:error] [pid 7520] ipa: DEBUG: Destroyed connection context.ldap2
[Tue Feb 05 19:38:56.435801 2013] [:error] [pid 7519] ipa: DEBUG: WSGI wsgi_dispatch.__call__:
[Tue Feb 05 19:38:56.436182 2013] [:error] [pid 7519] ipa: DEBUG: WSGI jsonserver_session.__call__:
[Tue Feb 05 19:38:56.436897 2013] [:error] [pid 7519] ipa: DEBUG: found session cookie_id = bcc81ee57dd1b0dc068a6b049618dfa8
[Tue Feb 05 19:38:56.437951 2013] [:error] [pid 7519] ipa: DEBUG: found session data in cache with id=bcc81ee57dd1b0dc068a6b049618dfa8
[Tue Feb 05 19:38:56.438451 2013] [:error] [pid 7519] ipa: DEBUG: jsonserver_session.__call__: session_id=bcc81ee57dd1b0dc068a6b049618dfa8 start_timestamp=2013-02-05T19:34:48 access_timestamp=2013-02-05T19:38:56 expiration_timestamp=2013-02-05T19:58:55
[Tue Feb 05 19:38:56.438673 2013] [:error] [pid 7519] ipa: DEBUG: storing ccache data into file "/var/run/ipa_memcached/krbcc_7519"
[Tue Feb 05 19:38:56.440594 2013] [:error] [pid 7519] ipa: DEBUG: get_credential_times: principal=krbtgt/XXXX.COM at XXXX.COM, authtime=02/05/13 14:28:55, starttime=02/05/13 19:34:48, endtime=02/06/13 14:25:28, renew_till=01/01/70 01:00:00
[Tue Feb 05 19:38:56.441541 2013] [:error] [pid 7519] ipa: DEBUG: get_credential_times: principal=krbtgt/XXXX.COM at XXXX.COM, authtime=02/05/13 14:28:55, starttime=02/05/13 19:34:48, endtime=02/06/13 14:25:28, renew_till=01/01/70 01:00:00
[Tue Feb 05 19:38:56.441955 2013] [:error] [pid 7519] ipa: DEBUG: KRB5_CCache FILE:/var/run/ipa_memcached/krbcc_7519 endtime=1360157128 (02/06/13 14:25:28)
[Tue Feb 05 19:38:56.442392 2013] [:error] [pid 7519] ipa: DEBUG: set_session_expiration_time: duration_type=inactivity_timeout duration=1200 max_age=1360156828 expiration=1360090736.44 (2013-02-05T19:58:56)
[Tue Feb 05 19:38:56.466157 2013] [:error] [pid 7520] ipa: DEBUG: WSGI wsgi_dispatch.__call__:
[Tue Feb 05 19:38:56.466577 2013] [:error] [pid 7520] ipa: DEBUG: WSGI jsonserver_session.__call__:
[Tue Feb 05 19:38:56.467221 2013] [:error] [pid 7520] ipa: DEBUG: found session cookie_id = bcc81ee57dd1b0dc068a6b049618dfa8
[Tue Feb 05 19:38:56.467841 2013] [:error] [pid 7520] ipa: DEBUG: found session data in cache with id=bcc81ee57dd1b0dc068a6b049618dfa8
[Tue Feb 05 19:38:56.468299 2013] [:error] [pid 7520] ipa: DEBUG: jsonserver_session.__call__: session_id=bcc81ee57dd1b0dc068a6b049618dfa8 start_timestamp=2013-02-05T19:34:48 access_timestamp=2013-02-05T19:38:56 expiration_timestamp=2013-02-05T19:58:55
[Tue Feb 05 19:38:56.468595 2013] [:error] [pid 7520] ipa: DEBUG: storing ccache data into file "/var/run/ipa_memcached/krbcc_7520"
[Tue Feb 05 19:38:56.469656 2013] [:error] [pid 7520] ipa: DEBUG: get_credential_times: principal=krbtgt/XXXX.COM at XXXX.COM, authtime=02/05/13 14:28:55, starttime=02/05/13 19:34:48, endtime=02/06/13 14:25:28, renew_till=01/01/70 01:00:00
[Tue Feb 05 19:38:56.470506 2013] [:error] [pid 7520] ipa: DEBUG: get_credential_times: principal=krbtgt/XXXX.COM at XXXX.COM, authtime=02/05/13 14:28:55, starttime=02/05/13 19:34:48, endtime=02/06/13 14:25:28, renew_till=01/01/70 01:00:00
[Tue Feb 05 19:38:56.470926 2013] [:error] [pid 7520] ipa: DEBUG: KRB5_CCache FILE:/var/run/ipa_memcached/krbcc_7520 endtime=1360157128 (02/06/13 14:25:28)
[Tue Feb 05 19:38:56.471342 2013] [:error] [pid 7520] ipa: DEBUG: set_session_expiration_time: duration_type=inactivity_timeout duration=1200 max_age=1360156828 expiration=1360090736.47 (2013-02-05T19:58:56)
[Tue Feb 05 19:38:56.591917 2013] [:error] [pid 7519] ipa: DEBUG: Created connection context.ldap2
[Tue Feb 05 19:38:56.592432 2013] [:error] [pid 7520] ipa: DEBUG: Created connection context.ldap2
[Tue Feb 05 19:38:56.592946 2013] [:error] [pid 7519] ipa: DEBUG: WSGI jsonserver.__call__:
[Tue Feb 05 19:38:56.592995 2013] [:error] [pid 7520] ipa: DEBUG: WSGI jsonserver.__call__:
[Tue Feb 05 19:38:56.593399 2013] [:error] [pid 7519] ipa: DEBUG: WSGI WSGIExecutioner.__call__:
[Tue Feb 05 19:38:56.594329 2013] [:error] [pid 7520] ipa: DEBUG: WSGI WSGIExecutioner.__call__:
[Tue Feb 05 19:38:56.595505 2013] [:error] [pid 7520] ipa: DEBUG: raw: json_metadata(None, None, command=u'all')
[Tue Feb 05 19:38:56.595568 2013] [:error] [pid 7519] ipa: DEBUG: raw: json_metadata(None, None, object=u'all')
[Tue Feb 05 19:38:56.596156 2013] [:error] [pid 7520] ipa: DEBUG: json_metadata(None, None, command=u'all')
[Tue Feb 05 19:38:56.597081 2013] [:error] [pid 7519] ipa: DEBUG: json_metadata(None, None, object=u'all')
[Tue Feb 05 19:38:56.602179 2013] [:error] [pid 7519] ipa: DEBUG: retrieving schema for SchemaCache url=ldapi://%2fvar%2frun%2fslapd-XXXX-COM.socket conn=<ldap.ldapobject.SimpleLDAPObject instance at 0x7f1d487dad40>
[Tue Feb 05 19:38:57.108457 2013] [:error] [pid 7519] ipa: ERROR: non-public: KeyError: 'ipaExternalGroup'
[Tue Feb 05 19:38:57.108702 2013] [:error] [pid 7519] Traceback (most recent call last):
[Tue Feb 05 19:38:57.108791 2013] [:error] [pid 7519]   File "/usr/lib/python2.7/site-packages/ipaserver/rpcserver.py", line 334, in wsgi_execute
[Tue Feb 05 19:38:57.108881 2013] [:error] [pid 7519]     result = self.Command[name](*args, **options)
[Tue Feb 05 19:38:57.108973 2013] [:error] [pid 7519]   File "/usr/lib/python2.7/site-packages/ipalib/frontend.py", line 435, in __call__
[Tue Feb 05 19:38:57.109191 2013] [:error] [pid 7519]     ret = self.run(*args, **options)
[Tue Feb 05 19:38:57.109454 2013] [:error] [pid 7519]   File "/usr/lib/python2.7/site-packages/ipalib/frontend.py", line 747, in run
[Tue Feb 05 19:38:57.109605 2013] [:error] [pid 7519]     return self.execute(*args, **options)
[Tue Feb 05 19:38:57.109696 2013] [:error] [pid 7519]   File "/usr/lib/python2.7/site-packages/ipalib/plugins/internal.py", line 119, in execute
[Tue Feb 05 19:38:57.109825 2013] [:error] [pid 7519]     (o.name, json_serialize(o)) for o in self.api.Object()
[Tue Feb 05 19:38:57.109914 2013] [:error] [pid 7519]   File "/usr/lib/python2.7/site-packages/ipalib/plugins/internal.py", line 119, in <genexpr>
[Tue Feb 05 19:38:57.110043 2013] [:error] [pid 7519]     (o.name, json_serialize(o)) for o in self.api.Object()
[Tue Feb 05 19:38:57.110178 2013] [:error] [pid 7519]   File "/usr/lib/python2.7/site-packages/ipalib/util.py", line 56, in json_serialize
[Tue Feb 05 19:38:57.110281 2013] [:error] [pid 7519]     return json_serialize(obj.__json__())
[Tue Feb 05 19:38:57.110382 2013] [:error] [pid 7519]   File "/usr/lib/python2.7/site-packages/ipalib/plugins/baseldap.py", line 600, in __json__
[Tue Feb 05 19:38:57.110504 2013] [:error] [pid 7519]     attrs = self.api.Backend.ldap2.schema.attribute_types(objectclasses)
[Tue Feb 05 19:38:57.110604 2013] [:error] [pid 7519]   File "/usr/lib64/python2.7/site-packages/ldap/schema/subentry.py", line 377, in attribute_types
[Tue Feb 05 19:38:57.110713 2013] [:error] [pid 7519]     object_class = self.sed[ObjectClass][object_class_oid]
[Tue Feb 05 19:38:57.110801 2013] [:error] [pid 7519] KeyError: 'ipaExternalGroup'
[Tue Feb 05 19:38:57.111401 2013] [:error] [pid 7519] ipa: INFO: user at XXXX.COM: json_metadata(None, None, object=u'all'): KeyError
[Tue Feb 05 19:38:57.112574 2013] [:error] [pid 7519] ipa: DEBUG: reading ccache data from file "/var/run/ipa_memcached/krbcc_7519"
[Tue Feb 05 19:38:57.113382 2013] [:error] [pid 7519] ipa: DEBUG: store session: session_id=bcc81ee57dd1b0dc068a6b049618dfa8 start_timestamp=2013-02-05T19:34:48 access_timestamp=2013-02-05T19:38:57 expiration_timestamp=2013-02-05T19:58:56
[Tue Feb 05 19:38:57.115977 2013] [:error] [pid 7519] ipa: DEBUG: Destroyed connection context.ldap2
[Tue Feb 05 19:38:57.504186 2013] [:error] [pid 7520] ipa: INFO: user at XXXX.COM: json_metadata(None, None, command=u'all'): SUCCESS
[Tue Feb 05 19:38:57.700424 2013] [:error] [pid 7520] ipa: DEBUG: reading ccache data from file "/var/run/ipa_memcached/krbcc_7520"
[Tue Feb 05 19:38:57.701086 2013] [:error] [pid 7520] ipa: DEBUG: store session: session_id=bcc81ee57dd1b0dc068a6b049618dfa8 start_timestamp=2013-02-05T19:34:48 access_timestamp=2013-02-05T19:38:57 expiration_timestamp=2013-02-05T19:58:56
[Tue Feb 05 19:38:57.702346 2013] [:error] [pid 7520] ipa: DEBUG: Destroyed connection context.ldap2


More information about the Freeipa-users mailing list