Синхронизация TDI для HCL Connections 6.5 завершается неудачно из-за неправильной грамматики SQL []; ошибка

Я использую Tivoli Directory Integrator (TDI) для синхронизации пользователей из Domino LDAP с локальной базой данных людей DB2 HCL Connections. При тестовой установке я получил следующую ошибку при попытке первоначальной синхронизации пользователей:

[root@cnx65 tdisol]# LANG=en_US.utf8 ./sync_all_dns.sh 
create synchronization lock
log4j:WARN No appenders could be found for logger (server).
log4j:WARN Please initialize the log4j system properly.
log4j:WARN See http://logging.apache.org/log4j/1.2/faq.html#noconfig for more info.
**********
CLFRN1275I: Begin to hash records in database.
CLFRN1269I: Finish hash records in database.
**********
"message": "CLFRN1254E: An error occurred while performing findEntry: {0}."
"exception": "com.ibm.lconn.profiles.api.tdi.service.TDIException: CLFRN1254E: An error occurred while performing findEntry: {0}."
Synchronize of Database Repository failed

Документация по HCL рекомендует проверять журналы в случае CLFRN1254E. Файл logs/SyncUpdates.log содержит следующее исключение:

2020-01-21 07:50:03,803 INFO  [org.apache.log4j.DailyRollingFileAppender.7431103d-4d0a-4d63-bdb7-61e274f23ed4] - CTGDIS092I Use entry provided at runtime as work entry (first pass only).
2020-01-21 07:50:11,723 ERROR [org.apache.log4j.DailyRollingFileAppender.7431103d-4d0a-4d63-bdb7-61e274f23ed4] - [hash_db_entries] CTGDIS181E Error while evaluating the hook 'Function error' in the component 'hash_db_entries (hash_db_entries.functioncall_fail).
com.ibm.lconn.profiles.api.tdi.service.TDIException: CLFRN1254E: An error occurred while executing findEntry: {0}.
        at com.ibm.lconn.profiles.api.tdi.connectors.ProfileConnector$ProfileCodeBlock.handleRecoverable(ProfileConnector.java:1063)
        at com.ibm.lconn.profiles.api.tdi.connectors.Util.TDICodeRunner.run(TDICodeRunner.java:41)
        at com.ibm.lconn.profiles.api.tdi.connectors.ProfileConnector.getNextEntry(ProfileConnector.java:155)
        at com.ibm.di.server.AssemblyLineComponent.executeOperation(AssemblyLineComponent.java:3370)
        at com.ibm.di.server.AssemblyLineComponent.getnext(AssemblyLineComponent.java:932)
        at com.ibm.di.server.AssemblyLine.msGetNextIteratorEntry(AssemblyLine.java:3689)
        at com.ibm.di.server.AssemblyLine.executeMainStep(AssemblyLine.java:3388)
        at com.ibm.di.server.AssemblyLine.executeMainLoop(AssemblyLine.java:3000)
        at com.ibm.di.server.AssemblyLine.executeMainLoop(AssemblyLine.java:2983)
        at com.ibm.di.server.AssemblyLine.executeAL(AssemblyLine.java:2952)
        at com.ibm.di.server.AssemblyLine.run(AssemblyLine.java:1319)
Caused by: org.springframework.jdbc.BadSqlGrammarException: SqlMapClient operation; bad SQL grammar []; nested exception is com.ibatis.common.jdbc.exception.NestedSQLException:
--- The error occurred while applying a parameter map.
--- Check the TDIProfile.get-InlineParameterMap.
--- Check the statement (query failed).
--- Cause: com.ibm.db2.jcc.c.SqlException: DB2 SQL error: SQLCODE: -551, SQLSTATE: 42501, SQLERRMC: LCUSER;SELECT;EMPINST.EMPLOYEE
        at org.springframework.jdbc.support.SQLStateSQLExceptionTranslator.doTranslate(SQLStateSQLExceptionTranslator.java:97)
        at org.springframework.jdbc.support.AbstractFallbackSQLExceptionTranslator.translate(AbstractFallbackSQLExceptionTranslator.java:72)
        at org.springframework.jdbc.support.AbstractFallbackSQLExceptionTranslator.translate(AbstractFallbackSQLExceptionTranslator.java:80)
        at org.springframework.jdbc.support.AbstractFallbackSQLExceptionTranslator.translate(AbstractFallbackSQLExceptionTranslator.java:80)
        at org.springframework.orm.ibatis.SqlMapClientTemplate.execute(SqlMapClientTemplate.java:212)
        at org.springframework.orm.ibatis.SqlMapClientTemplate.executeWithListResult(SqlMapClientTemplate.java:249)
        at org.springframework.orm.ibatis.SqlMapClientTemplate.queryForList(SqlMapClientTemplate.java:296)
        at com.ibm.lconn.profiles.internal.service.store.sqlmapdao.TDIProfileSqlMapDao.get(TDIProfileSqlMapDao.java:50)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:88)

В чем может быть проблема? Как я могу узнать подробнее, почему возникает эта ошибка?

Что я уже пробовал

Увеличить уровень журнала

В profiles_tdi.properties я включил журналы отладки для каждого компонента:

debug_collect=true
debug_draft=true
debug_fill_codes=true
debug_managers=true
debug_photos=true
debug_pronounce=true
debug_special=true
debug_update_profile=true
trace_profile_tdi_javascript=on

Поскольку это не повлияло, я установил уровень log4j для отладки всего приложения в etc/log4j.properties:

log3j.rootCategory=DEBUG, Default

Также пробовал ALL вместо DEBUG. Однако на выходе нет никаких изменений. Я ожидал увидеть SQL-запрос, вызвавший исключение.

Установить mode в свойствах

Согласно этому сообщению, Атрибут mode будет использоваться для определения того, является ли пользователь внутренним или внешним. Поскольку пример конфигурации говорит

Actually, any string other than "external" is interpreted as employee.

он установлен на mode=memberType. Также пробовал mode=uid и mode=mail. Оба поля содержат строку, отличную от «external», поэтому в результате все члены будут импортированы как внутренние пользователи.

Синхронизировать отдельных пользователей

Поскольку мой фильтр LDAP применяется примерно к 60 пользователям, я успешно выполнил ./collect_dns.sh и удалил всех пользователей из collect.dns файла, кроме своего собственного. Затем синхронизируйте пользователя из файла dn с ./populate_from_dn_file.sh. Это было сделано для двух других пользователей, что всегда приводило к одной и той же ошибке:

CLFRN0027I: After operation, success records is 0, duplicate records 0, failure records is 1, and last successful entry is null.
CLFRN1280I: 20200121105123 Iterations total number: 1.

Единственное отличие состоит в том, что logs/PopulateDBFromDNFile.log содержит более подробную информацию о выбранных атрибутах, сопоставлениях и так далее. К сожалению, это не очень помогает мне с точки зрения ошибки, так как выдает похожее сообщение:

2020-01-21 10:55:27,530 INFO  [com.ibm.di.log.FileRollerAppender.268b5e1d-d0fc-4a7c-9e12-4d742c44faa5] - [callSyncDB_mod] [add_manager_data] [setup_if_lookup] CTGDIS126I Return false.
2020-01-21 10:55:27,530 INFO  [com.ibm.di.log.FileRollerAppender.268b5e1d-d0fc-4a7c-9e12-4d742c44faa5] - [callSyncDB_mod] [add_manager_data] [setup_if_lookup] CTGDIS123I Returned object class java.lang.Boolean.
2020-01-21 10:55:27,530 INFO  [com.ibm.di.log.FileRollerAppender.268b5e1d-d0fc-4a7c-9e12-4d742c44faa5] - [callSyncDB_mod] [add_manager_data] CTGDIS075I Trying to exit TaskCallBlock.
2020-01-21 10:55:27,531 INFO  [com.ibm.di.log.FileRollerAppender.268b5e1d-d0fc-4a7c-9e12-4d742c44faa5] - [callSyncDB_mod] [add_manager_data] CTGDIS076I Succeeded exiting TaskCallBlock.
2020-01-21 10:55:27,531 INFO  [com.ibm.di.log.FileRollerAppender.268b5e1d-d0fc-4a7c-9e12-4d742c44faa5] - [callSyncDB_mod] [add_manager_data] CTGDIS057I Hook after_functioncall not enabled.
2020-01-21 10:55:27,531 INFO  [com.ibm.di.log.FileRollerAppender.268b5e1d-d0fc-4a7c-9e12-4d742c44faa5] - [callSyncDB_mod] CTGDIS352I Use null Behavior for $_already_lookup_manager.
2020-01-21 10:55:27,531 INFO  [com.ibm.di.log.FileRollerAppender.268b5e1d-d0fc-4a7c-9e12-4d742c44faa5] - [callSyncDB_mod] CTGDIS351I Map Attribute $manager_uid [1].
2020-01-21 10:55:27,531 INFO  [com.ibm.di.log.FileRollerAppender.268b5e1d-d0fc-4a7c-9e12-4d742c44faa5] - [callSyncDB_mod] CTGDIS353I Script is: conn["$manager_uid"]
2020-01-21 10:55:27,531 INFO  [com.ibm.di.log.FileRollerAppender.268b5e1d-d0fc-4a7c-9e12-4d742c44faa5] - [callSyncDB_mod] CTGDIS352I Use null Behavior for $manager_uid.
2020-01-21 10:55:27,531 INFO  [com.ibm.di.log.FileRollerAppender.268b5e1d-d0fc-4a7c-9e12-4d742c44faa5] - [callSyncDB_mod] [add_manager_data] CTGDIS057I Hook functioncall_ok not enabled.
2020-01-21 10:55:27,531 INFO  [com.ibm.di.log.FileRollerAppender.268b5e1d-d0fc-4a7c-9e12-4d742c44faa5] - [callSyncDB_mod] [add_manager_data] CTGDIS057I Hook default_ok not enabled.
2020-01-21 10:55:27,538 INFO  [com.ibm.di.log.FileRollerAppender.268b5e1d-d0fc-4a7c-9e12-4d742c44faa5] - [callSyncDB_mod] Result: <My Name of the User in dn file>
2020-01-21 10:55:27,591 ERROR [com.ibm.di.log.FileRollerAppender.268b5e1d-d0fc-4a7c-9e12-4d742c44faa5] - [callSyncDB_mod] [ProfileConnector] SqlMapClient operation; bad SQL grammar []; nested exception is com.ibatis.common.jdbc.exception.NestedSQLException:
--- The error occurred while applying a parameter map.
--- Check the TDIProfile.get-InlineParameterMap.
--- Check the statement (query failed).
--- Cause: com.ibm.db2.jcc.c.SqlException: DB2 SQL error: SQLCODE: -551, SQLSTATE: 42501, SQLERRMC: LCUSER;SELECT;EMPINST.EMPLOYEE

person Lion    schedule 21.01.2020    source источник


Ответы (1)


Выяснилось, что это неудачная логическая ошибка с моей стороны. База данных создается с использованием файлов sql, поставляемых с мастером установки Connections. Я автоматически импортирую их в цикле. Поскольку это было очень медленно (около 30 минут для всех сценариев), я попытался распараллелить их, добавив & в конце команды и, наконец, wait в конце, чтобы убедиться, что все сценарии выполняются.

- name: Check and create non existing DBs for CNX
  become: yes
  become_user: "{{ db2.instance.name }}"
  shell: |
    db={{ item.name }}
    scripts=({{ item.files | join(' ') }})
    existing_dbs=$(echo -e '{{ existing_dbs.stdout }}')
    echo "Check db ${db}"

    if ! echo ${existing_dbs} | grep -q ${db}; then
      echo "DB ${db} doesn't exist, execute scripts"
      for script in "${scripts[@]}"
      do
        echo "${db}: Execute script ${script}"
        {{ db2.target }}/bin/db2 -td@ -f {{ cnx_sql_dir }}/${script} &
      done
      wait
    fi
  register: db_check
  changed_when: "'execute scripts' in db_check.stdout"
  loop: "{{ cnx.db_scripts }}"

cnx.db_scripts - это отображение имен баз данных в файлы SQL:

  db_scripts:
    - name: PEOPLEDB
      files:
        - profiles/db2/createDb.sql
        - profiles/db2/appGrants.sql
    - name: FORUM
      files: 
         # - ...

Оглядываясь назад, можно сказать, что это была ужасная логическая ошибка, потому что я упустил тот факт, что эти сценарии полагаются друг на друга: когда profiles/db2/appGrants.sql выполняется до завершения profiles/db2/createDb.sql, это не сработает, потому что база данных не существует.

В результате запросы TDI не выполнялись, потому что база данных и таблицы были созданы только частично. Я не заметил этого сразу, так как машина была несколько раз развернута во время разработки Ansible playbook. Как ни странно, TDI потерпел неудачу только в 2 из 10 развертываний. Похоже, что DB2 создает какую-то очередь, и в зависимости от времени база данных людей, необходимая для TDI, создается успешно при некоторых запусках.

person Lion    schedule 21.01.2020