DBへの実行ログ挿入時のプライマリキー重複について

671 views
Skip to first unread message

Ryu

unread,
Jun 22, 2016, 12:36:44 AM6/22/16
to 日本JobSchedulerユーザーグループ(JJUG)
度々失礼いたします。


現在JobSchedulerを以下の環境で動かしています。

・JobScheduler 1.9.11(Active Cluster)
・MySQL 5.7.13(マルチマスターレプリケーション)
・lsyncd 2.1.5 (/config/live配下を同期)

また、テスト用に簡単なジョブ(ジョブチェイン)を作成し、オーダーとして15分置きに実行している状況です。(20ジョブ程度)

しかし時々、ジョブの実行ログをDBに書き込むタイミングでプライマリキーの重複が起きており、
放置すると延々INSERTとROLLBACKを繰り返してJobSchedulerの動作がストップします。
また、scheduler.logにも逐次そのエラーを書き込むため、ディスクがパンクしてDBも落ちる状況です。

対策として、my.cnfにslave_skip_errors=1062の設定を追記してみましたがMySQLのログに出なくなっただけで効果がなく・・・
またJobSchedulerでログの出力を制御できないか探してもみたのですが見当たりません・・・・
現在は一時的に重複したログをDELETEしてしのいでおりますが、数時間置きに出ているため根本的な解決になっておりません・・・。

何かよい方法はありませんでしょうか。
また、Active Cluster構成でDBの冗長性を確保する場合に他にどのような構成で構築しておられるでしょうか。
何か良い案がありましたらよろしくお願いいたします。


scheduler.log
------------------------------------------------------------------------------------------------------------------------------------------------
.21 18:41:53.913     1 10866.D4C7E700 .DatabaseProductName=MySQL, DriverName=mariadb-jdbc
.21 18:41:53.914     1 10866.D4C7E700 {scheduler} sos::scheduler::database::Transaction::execute  INSERT into SCHEDULER_HISTORY ("CAUSE","CLUSTER_MEMBER_ID","ID","JOB_NAME","SPOOLER_ID","START_TIME") values ('period_single','scheduler/scheduler01:4444',19442,'job1','scheduler',{ts'2016-06-21 04:05:00'})  (sos::scheduler::database::Task_history::write)
.21 18:41:53.914     0 10866.D4C7E700 [xc.insert 1, "java.sql.SQLIntegrityConstraintViolationException: Duplicate entry '19442' for key 'PRIMARY' - caused by - org.mariadb.jdbc.internal.common.QueryException: Duplicate entry '19442' for key 'PRIMARY'"]
.21 18:41:53.914     0 10866.D4C7E700 [xc.insert 2, "executeUpdate"]
.21 18:41:53.914     0 10866.D4C7E700 [xc.append "sos::scheduler::database::Task_history::write"]
.21 18:41:53.914     0 10866.D4C7E700 {scheduler} sos::scheduler::database::Transaction::execute  ROLLBACK  (sos::scheduler::database::Transaction::~Transaction)
.21 18:41:53.915     1 10866.D4C7E700 ~Sos_database_session()   id=spooler db=jdbc:mysql://localhost:3306/scheduler user=scheduler cmd=ROLLBACK open_mode=3 ref=0
.21 18:41:53.915     0 10866.D4C7E700 .[xc.insert "Datei file:/home/scheduler/jobscheduler/scheduler/config/sos.ini"]
.21 18:41:53.915     0 10866.D4C7E700 .[xc.insert "Datei file:/home/scheduler/jobscheduler/scheduler/config/sos.ini"]
.21 18:41:53.915     0 10866.D4C7E700 .[xc.insert "Datei file:/home/scheduler/jobscheduler/scheduler/config/sos.ini"]
.21 18:41:53.915     0 10866.D4C7E700 .(Letzte Zeile wiederholt sich 2 mal)

Satoru Funai

unread,
Jun 28, 2016, 5:50:47 AM6/28/16
to Ryu, 日本JobSchedulerユーザーグループ(JJUG)
Ryuさん
DBアクセスが遅い場合、このような現象が発生することがあります。
MySQLのSlow queryログには、何も出ていないでしょうか?
私の経験では、DB冗長構成は普通にcorosync/pacemaker/drdbでアクティブスタンバイ構成します。
船井

----- 元のメッセージ -----
> 差出人: "Ryu" <ryu.ka...@g.softbank.co.jp>
> 宛先: "日本JobSchedulerユーザーグループ(JJUG)" <jobsche...@googlegroups.com>
> 送信済み: 2016年6月22日, 水曜日 午後 1:36:43
> 件名: DBへの実行ログ挿入時のプライマリキー重複について

> --
> このメールは Google
> グループのグループ「日本JobSchedulerユーザーグループ(JJUG)」に登録しているユーザーに送られています。
> このグループから退会し、グループからのメールの配信を停止するには
> jobscheduler-...@googlegroups.com にメールを送信してください。
> このグループに投稿するには jobsche...@googlegroups.com にメールを送信してください。
> https://groups.google.com/group/jobscheduler-ja からこのグループにアクセスしてください。
> その他のオプションについては https://groups.google.com/d/optout にアクセスしてください。
>

Ryu

unread,
Jun 29, 2016, 12:51:45 AM6/29/16
to 日本JobSchedulerユーザーグループ(JJUG), ryu.ka...@g.softbank.co.jp
船井さん

my.cnfに設定を追記してslow queryログを見てみましたが、クラスタメンバの参照と思われるログしか出ていないようです・・・・


DBがアクティブスタンバイ構成で、EngineがActive Cluster構成だとDBがボトルネックになるような気がしているのですが、
船井さんの以前の資料にあったように1500ジョブ程度なら特に問題ないと考えてよろしいのでしょうか。
(もちろんジョブの内容等にもよると思いますが・・・・)



<my.cnf>
# slow query log
slow_query_log = 1
long_query_time =1 
log_queries_not_using_indexes = 1
slow_query_log_file = /var/lib/mysql/slow_query.log

<slow_query.log>
SET timestamp=1467169793:
select "MEMBER_ID", "LAST_HEART_BEAT", "NEXT_HEART_BEAT", "EXCLUSIVE", "ACTIVE", "DEAD", "DEACTIVATING_MEMBER_ID",
"HTTP_URL" from SCHEDULER_CLUSTERS where "SCHEDULER_ID"='scheduler';
# Time:2016-06-29T03:09:53.817385Z
# User@Host: scheduler[scheduler] @ localhost [127.0.0.1] id:    35
# Query_time: 0.000127  Lock_time:0.000053 Rows_sent: 2  Rows_examined 2
.......
......
.....
....


2016年6月28日火曜日 18時50分47秒 UTC+9 satoruf:
Reply all
Reply to author
Forward
0 new messages