Я пытаюсь настроить простой бродячий бокс для тестирования с FreeIPA. Я использую образ CentOS 7, устанавливаю в коробку минимум дополнительных вещей и использую очень простое определение FreeIPA для начала. Я пробовал делать это с помощью простых команд оболочки, а также пробовал использовать ансибль-фриипа. В обоих случаях я вижу одну и ту же ошибку, хотя частота ее появления, кажется, различается. В простых командах оболочки он терпит неудачу только в 50% случаев, но с Ansible это кажется 100%.
Ошибка вызывает следующую ошибку.
fatal: [ipaserver.test.hadoop.com]: FAILED! => {"changed": false, "module_stderr": "Shared connection to ipaserver.test.hadoop.com closed.\r\n", "module_stdout": "\u001b[?1034hTraceback (most recent call last):\r\n File "/root/.ansible/tmp/ansible-tmp-1583188576.27-186488091977372/AnsiballZ_ipaserver_setup_ca.py", line 102, in \r\n _ansiballz_main()\r\n File "/root/.ansible/tmp/ansible-tmp-1583188576.27-186488091977372/AnsiballZ_ipaserver_setup_ca.py", line 94, in _ansiballz_main\r\n invoke_module(zipped_mod, temp_path, ANSIBALLZ_PARAMS)\r\n File "/root/.ansible/tmp/ansible-tmp-1583188576.27-186488091977372/AnsiballZ_ipaserver_setup_ca.py", line 40, in invoke_module\r\n runpy.run_module(mod_name='ansible.modules.ipaserver_setup_ca', init_globals=None, run_name='main', alter_sys=True)\r\n File "/usr/lib64/python2.7/runpy.py", line 176, in run_module\r\n fname, loader, pkg_name)\r\n File "/usr/lib64/python2.7/runpy.py", line 82, in _run_module_code\r\n mod_name, mod_fname, mod_loader, pkg_name)\r\n File "/usr/lib64/python2.7/runpy.py", line 72, in _run_code\r\n exec code in run_globals\r\n File "/tmp/ansible_ipaserver_setup_ca_payload_Pc9wnM/ansible_ipaserver_setup_ca_payload.zip/ansible/modules/ipaserver_setup_ca.py", line 354, in \r\n File "/tmp/ansible_ipaserver_setup_ca_payload_Pc9wnM/ansible_ipaserver_setup_ca_payload.zip/ansible/modules/ipaserver_setup_ca.py", line 345, in main\r\n File "/usr/lib/python2.7/site-packages/ipaserver/install/ca.py", line 391, in install_step_1\r\n ca.start('pki-tomcat')\r\n File "/usr/lib/python2.7/site-packages/ipaserver/install/service.py", line 464, in start\r\n self.service.start(instance_name, capture_output=capture_output, wait=wait)\r\n File "/usr/lib/python2.7/site-packages/ipaplatform/redhat/services.py", line 192, in start\r\n self.wait_until_running()\r\n File "/usr/lib/python2.7/site-packages/ipaplatform/redhat/services.py", line 186, in wait_until_running\r\n raise RuntimeError('CA did not start in %ss' % timeout)\r\nRuntimeError: CA did not start in 300.0s\r\n", "msg": "MODULE FAILURE\nSee stdout/stderr for the exact error", "rc": 1}
Заглянув в / var / log / messages, я вижу, что ошибка произошла где-то между 23:25 и 23:27 по системному времени. В зависимости от ошибок это происходит при перезапуске центра сертификации. Кажется, что он запускается правильно с первого раза.
Mar 2 23:25:42 localhost systemd: Stopped PKI Tomcat Server pki-tomcat.
Mar 2 23:25:43 localhost systemd: Starting PKI Tomcat Server pki-tomcat...
Mar 2 23:26:13 localhost pkidaemon: -----------------------
Mar 2 23:26:13 localhost pkidaemon: Banner is not installed
Mar 2 23:26:13 localhost pkidaemon: -----------------------
Mar 2 23:27:07 localhost pkidaemon: ----------------------
Mar 2 23:27:08 localhost pkidaemon: Enabled all subsystems
Mar 2 23:27:08 localhost pkidaemon: ----------------------
Mar 2 23:27:18 localhost systemd: pki-tomcatd@pki-tomcat.service start-pre operation timed out. Terminating.
Mar 2 23:27:18 localhost systemd: Failed to start PKI Tomcat Server pki-tomcat.
Mar 2 23:27:18 localhost systemd: Unit pki-tomcatd@pki-tomcat.service entered failed state.
Mar 2 23:27:18 localhost systemd: pki-tomcatd@pki-tomcat.service failed.
Однако, когда я смотрю в журналы PKI, там ничего нет в течение этого периода времени. Это последние несколько строк в /var/log/pki/pki-ca-spawn.20200302231442.log:
2020-03-02 23:18:32 pkispawn : INFO END spawning subsystem 'CA' of instance 'pki-tomcat'
2020-03-02 23:18:32 pkispawn : INFO ... archiving configuration into '/var/log/pki/pki-tomcat/ca/archive/spawn_deployment.cfg.20200302231442'
2020-03-02 23:18:32 pkispawn : INFO ....... cp -p /etc/sysconfig/pki/tomcat/pki-tomcat/ca/deployment.cfg /var/log/pki/pki-tomcat/ca/archive/spawn_deployment.cfg.20200302231442
2020-03-02 23:18:32 pkispawn : DEBUG ........... chmod 660 /var/log/pki/pki-tomcat/ca/archive/spawn_deployment.cfg.20200302231442
2020-03-02 23:18:32 pkispawn : DEBUG ........... chown 17:17 /var/log/pki/pki-tomcat/ca/archive/spawn_deployment.cfg.20200302231442
2020-03-02 23:18:32 pkispawn : INFO ... archiving manifest into '/var/log/pki/pki-tomcat/ca/archive/spawn_manifest.20200302231442'
2020-03-02 23:18:32 pkispawn : INFO ....... cp -p /etc/sysconfig/pki/tomcat/pki-tomcat/ca/manifest /var/log/pki/pki-tomcat/ca/archive/spawn_manifest.20200302231442
2020-03-02 23:18:32 pkispawn : DEBUG ........... chmod 660 /var/log/pki/pki-tomcat/ca/archive/spawn_manifest.20200302231442
2020-03-02 23:18:32 pkispawn : DEBUG ........... chown 17:17 /var/log/pki/pki-tomcat/ca/archive/spawn_manifest.20200302231442
То же самое для / var / log / pki / pki-tomcat / ca / debug:
[02/Mar/2020:23:25:00][http-bio-8080-exec-14]: getConn: mNumConns now 4
[02/Mar/2020:23:25:00][http-bio-8080-exec-14]: returnConn: mNumConns now 5
[02/Mar/2020:23:25:00][http-bio-8080-exec-14]: In LdapBoundConnFactory::getConn()
[02/Mar/2020:23:25:00][http-bio-8080-exec-14]: masterConn is connected: true
[02/Mar/2020:23:25:00][http-bio-8080-exec-14]: getConn: conn is connected true
[02/Mar/2020:23:25:00][http-bio-8080-exec-14]: getConn: mNumConns now 4
[02/Mar/2020:23:25:00][http-bio-8080-exec-14]: returnConn: mNumConns now 5
[02/Mar/2020:23:25:00][http-bio-8080-exec-14]: CMSServlet.java: renderTemplate
[02/Mar/2020:23:25:00][http-bio-8080-exec-14]: CMSServlet.java: xml parameter detected, returning xml
[02/Mar/2020:23:25:00][http-bio-8080-exec-14]: CMSServlet: curDate=Mon Mar 02 23:25:00 UTC 2020 id=caDisplayCertFromRequest time=144
В / var / log / pki / pki-tomcat / ca / system есть несколько ошибок, но ни одной после 23:25:
0.localhost-startStop-1 - [02/Mar/2020:23:15:08 UTC] [13] [3] authz instance DirAclAuthz initialization failed and skipped, error=Property internaldb.ldapconn.port missing value
0.http-bio-8443-exec-3 - [02/Mar/2020:23:17:53 UTC] [3] [3] CASigningUnit: Object certificate not found. Error Certificate object not found
0.http-bio-8443-exec-3 - [02/Mar/2020:23:17:54 UTC] [11] [3] UGSubsystem: Get User Error netscape.ldap.LDAPException: error result (32); matchedDN = ou=People,o=ipaca
0.Thread-16 - [02/Mar/2020:23:25:00 UTC] [8] [3] Publishing: Could not publish certificate serial number 0x7. Error Failed to publish using rule: No rules enabled
Я не понимаю, что могло бы вызвать это. Любые идеи? Бродячий файл и файл hosts находятся в репозитории GitHub ниже: https://github.com/davidov541/HadoopOnVagrant/tree/AnsibleRetrofit/FreeIPA
Возможная ошибка в конце:
'CA did not start in %ss' % timeout)\r\nRuntimeError: CA did not start in 300.0s\r\n"
Это заставляет меня думать о том, что оно появилось в списке рассылки и было исправлено путем установки более высокого значения переменной start_timeout в сценарии.
Решение описано здесь:
https://www.freeipa.org/page/HowTo/FreeIPA_on_banana_pi
Может быть, что-то попробовать, я не могу гарантировать, что это исправит для вас, но ...
В итоге я увеличил размер своего бродячего ящика до 2 ГБ, чтобы исправить еще одну проблему, которую я видел, и после повторного создания ящика 10-20 раз со вчерашнего дня я не видел проблемы с тех пор. Исходя из этого, я считаю, что проблема была связана с тем, что tomcat не имел достаточно памяти для запуска, как это было необходимо, что привело к поведению, которое мы видели.