JobScheduler プロセス障害
617 views
Skip to first unread message
koba...@gmail.com
Jul 17, 2020, 6:14:36 AM7/17/20
to 日本JobSchedulerユーザーグループ（JJUG）
小林と申します。
JobScheduler のプロセス障害が頻繁に発生しており何かヒントが得られないかと思い投稿します。
JobScheduler のプロセス障害が頻繁に発生しており何かヒントが得られないかと思い投稿します。
Jobscheduler 1.13.2（OpenJDK11.0.6+10-LTS)/CentOS7 を利用しています。
1.11 から継続して利用しております。
JobSchedulerが浸透し、Cronからの置き換えが順調に進んでおりました。
jobの同時実行数は10程度ですが、1日あたりの3000order 7000job を実行しています。
JobおよびJobChainはすべてSSH実行です。
障害時の事象は下記のとおりです。
１）joc からの動作が不安定になる
２）/etc/init.d/jobscheduler status jobs 等が利用できなくなる。
--> 40444 へのconnection が refuse される
３）jobが実行されなくなる
定期的に jobscheduler を再起動させると発生しにくいため毎週月曜日、木曜日にプロセス再起動をしています。
ところが、１日立たずして１）２）の障害が発生しました。
この障害が発生すると、
・JVMのHeap利用量が大きくなる
・CPU利用率が高くなる
といった事象が観測されます。
15時00分01秒 all 11.12 0.00 1.67 0.17 0.00 87.03
15時10分02秒 all 12.61 0.00 1.74 0.23 0.00 85.41
15時20分01秒 all 13.23 0.00 1.85 0.25 0.00 84.67
15時30分01秒 all 9.78 0.00 1.52 0.17 0.00 88.53
15時40分01秒 all 13.12 0.00 1.82 0.21 0.00 84.85
15時50分02秒 all 9.61 0.00 1.50 0.14 0.00 88.75
16時00分01秒 all 11.11 0.00 1.67 0.20 0.00 87.02
★1
16時10分02秒 all 16.16 0.00 1.92 0.21 0.00 81.71
16時20分01秒 all 17.70 0.00 2.38 3.45 0.00 76.47
16時30分01秒 all 14.69 0.00 1.94 0.29 0.00 83.08
★2
16時40分02秒 all 19.11 0.00 2.12 0.27 0.00 78.50
16時50分01秒 all 21.39 0.00 2.06 0.18 0.00 76.37
★3
17時00分01秒 all 58.06 0.00 1.82 0.14 0.00 39.99
17時10分01秒 all 85.44 0.00 2.07 0.03 0.00 12.46
17時20分01秒 all 85.25 0.00 2.35 0.04 0.00 12.36
17時30分02秒 all 84.38 0.00 1.82 0.02 0.00 13.78
17時40分01秒 all 86.11 0.00 2.07 0.04 0.00 11.77
17時50分01秒 all 80.57 0.00 1.74 0.01 0.00 17.67
18時00分01秒 all 79.48 0.00 1.78 0.03 0.00 18.71
18時10分01秒 all 84.16 0.00 2.07 0.03 0.00 13.74
18時20分01秒 all 85.73 0.00 2.31 0.02 0.00 11.94
18時30分01秒 all 81.83 0.00 2.06 0.05 0.00 16.06
18時30分01秒 CPU %user %nice %system %iowait %steal %idle
☆再起動
18時40分01秒 all 14.05 0.00 1.76 0.85 0.00 83.34
オーダーA,B,Cは定時実行になっており、直近の７日以上は問題なく実行されていることを確認済みです。
解決に向けての方針が全くつかめておらずJobSchedulerを分散するか別の Job管理システムへの移行を計画が必要かもしれません。
確認すべき観点等ありましたら助言いただけると幸いです。
JobSchedulerが浸透し、Cronからの置き換えが順調に進んでおりました。
jobの同時実行数は10程度ですが、1日あたりの3000order 7000job を実行しています。
JobおよびJobChainはすべてSSH実行です。
障害時の事象は下記のとおりです。
１）joc からの動作が不安定になる
２）/etc/init.d/jobscheduler status jobs 等が利用できなくなる。
--> 40444 へのconnection が refuse される
３）jobが実行されなくなる
定期的に jobscheduler を再起動させると発生しにくいため毎週月曜日、木曜日にプロセス再起動をしています。
ところが、１日立たずして１）２）の障害が発生しました。
この障害が発生すると、
・JVMのHeap利用量が大きくなる
・CPU利用率が高くなる
といった事象が観測されます。
15時00分01秒 all 11.12 0.00 1.67 0.17 0.00 87.03
15時10分02秒 all 12.61 0.00 1.74 0.23 0.00 85.41
15時20分01秒 all 13.23 0.00 1.85 0.25 0.00 84.67
15時30分01秒 all 9.78 0.00 1.52 0.17 0.00 88.53
15時40分01秒 all 13.12 0.00 1.82 0.21 0.00 84.85
15時50分02秒 all 9.61 0.00 1.50 0.14 0.00 88.75
16時00分01秒 all 11.11 0.00 1.67 0.20 0.00 87.02
★1
16時10分02秒 all 16.16 0.00 1.92 0.21 0.00 81.71
16時20分01秒 all 17.70 0.00 2.38 3.45 0.00 76.47
16時30分01秒 all 14.69 0.00 1.94 0.29 0.00 83.08
★2
16時40分02秒 all 19.11 0.00 2.12 0.27 0.00 78.50
16時50分01秒 all 21.39 0.00 2.06 0.18 0.00 76.37
★3
17時00分01秒 all 58.06 0.00 1.82 0.14 0.00 39.99
17時10分01秒 all 85.44 0.00 2.07 0.03 0.00 12.46
17時20分01秒 all 85.25 0.00 2.35 0.04 0.00 12.36
17時30分02秒 all 84.38 0.00 1.82 0.02 0.00 13.78
17時40分01秒 all 86.11 0.00 2.07 0.04 0.00 11.77
17時50分01秒 all 80.57 0.00 1.74 0.01 0.00 17.67
18時00分01秒 all 79.48 0.00 1.78 0.03 0.00 18.71
18時10分01秒 all 84.16 0.00 2.07 0.03 0.00 13.74
18時20分01秒 all 85.73 0.00 2.31 0.02 0.00 11.94
18時30分01秒 all 81.83 0.00 2.06 0.05 0.00 16.06
18時30分01秒 CPU %user %nice %system %iowait %steal %idle
☆再起動
18時40分01秒 all 14.05 0.00 1.76 0.85 0.00 83.34
★1 16:04:14.284 com.sos.scheduler.engine.kernel.scheduler.SchedulerException: Order is not in a job chain: Order ('Order: オーダーA')
★2 16:34:20.723 com.sos.scheduler.engine.kernel.scheduler.SchedulerException: Order is not in a job chain: Order ('Order:オーダーB')
★3 16:52:04.095 com.sos.scheduler.engine.kernel.scheduler.SchedulerException: Order is not in a job chain: Order ('Order:オーダーC')
オーダーA,B,Cは定時実行になっており、直近の７日以上は問題なく実行されていることを確認済みです。
解決に向けての方針が全くつかめておらずJobSchedulerを分散するか別の Job管理システムへの移行を計画が必要かもしれません。
確認すべき観点等ありましたら助言いただけると幸いです。
takas...@nifty.com
Jul 19, 2020, 5:26:10 PM7/19/20
to jobsche...@googlegroups.com
ログを見てみないとなんとも言えないと思います。
koba...@gmail.com <koba...@gmail.com>さん：
小林と申します。
JobScheduler のプロセス障害が頻繁に発生しており何かヒントが得られないかと
思い投稿します。
Jobscheduler 1.13.2（OpenJDK11.0.6+10-LTS)/CentOS7 を利用しています。
1.11 から継続して利用しております。
JobSchedulerが浸透し、Cronからの置き換えが順調に進んでおりました。
jobの同時実行数は10程度ですが、1日あたりの3000order 7000job を実行してい
ます。
JobおよびJobChainはすべてSSH実行です。
障害時の事象は下記のとおりです。
１）joc からの動作が不安定になる
２）/etc/init.d/jobscheduler status jobs 等が利用できなくなる。
--> 40444 へのconnection が refuse される
３）jobが実行されなくなる
定期的に jobscheduler を再起動させると発生しにくいため毎週月曜日、木曜日
にプロセス再起動をしています。
ところが、１日立たずして１）２）の障害が発生しました。
この障害が発生すると、
・JVMのHeap利用量が大きくなる
・CPU利用率が高くなる
といった事象が観測されます。
15時00分01秒 all 11.12 0.00 1.67 0.17 0.
00 87.03
18時30分01秒 CPU %user %nice %system %iowait %
steal %idle
★1 16:04:14.284 com.sos.scheduler.engine.kernel.scheduler.
SchedulerException: Order is not in a job chain: Order ('Order: オーダー
A')
★2 16:34:20.723 com.sos.scheduler.engine.kernel.scheduler.
SchedulerException: Order is not in a job chain: Order ('Order:オーダー
オーダーA,B,Cは定時実行になっており、直近の７日以上は問題なく実行されてい
ることを確認済みです。
解決に向けての方針が全くつかめておらずJobSchedulerを分散するか別の Job管
理システムへの移行を計画が必要かもしれません。
確認すべき観点等ありましたら助言いただけると幸いです。
--
このメールは Google グループのグループ「日本JobSchedulerユーザーグループ
（JJUG）」に登録しているユーザーに送られています。
このグループから退会し、グループからのメールの配信を停止するには
jobscheduler-...@googlegroups.com にメールを送信してください。
このディスカッションをウェブ上で閲覧するには https://groups.google.com/d/msgid/jobscheduler-ja/fe903301-4e2c-4afa-966e-5e397768ab48n%40googlegroups.com
にアクセスしてください。
koba...@gmail.com <koba...@gmail.com>さん：
小林と申します。
JobScheduler のプロセス障害が頻繁に発生しており何かヒントが得られないかと
思い投稿します。
Jobscheduler 1.13.2（OpenJDK11.0.6+10-LTS)/CentOS7 を利用しています。
1.11 から継続して利用しております。
JobSchedulerが浸透し、Cronからの置き換えが順調に進んでおりました。
jobの同時実行数は10程度ですが、1日あたりの3000order 7000job を実行してい
ます。
JobおよびJobChainはすべてSSH実行です。
障害時の事象は下記のとおりです。
１）joc からの動作が不安定になる
２）/etc/init.d/jobscheduler status jobs 等が利用できなくなる。
--> 40444 へのconnection が refuse される
３）jobが実行されなくなる
定期的に jobscheduler を再起動させると発生しにくいため毎週月曜日、木曜日
にプロセス再起動をしています。
ところが、１日立たずして１）２）の障害が発生しました。
この障害が発生すると、
・JVMのHeap利用量が大きくなる
・CPU利用率が高くなる
といった事象が観測されます。
15時00分01秒 all 11.12 0.00 1.67 0.17 0.
15時10分02秒 all 12.61 0.00 1.74 0.23 0.
00 85.41
15時20分01秒 all 13.23 0.00 1.85 0.25 0.
00 84.67
15時30分01秒 all 9.78 0.00 1.52 0.17 0.
00 88.53
15時40分01秒 all 13.12 0.00 1.82 0.21 0.
00 84.85
15時50分02秒 all 9.61 0.00 1.50 0.14 0.
00 88.75
16時00分01秒 all 11.11 0.00 1.67 0.20 0.
00 87.02
★1
16時10分02秒 all 16.16 0.00 1.92 0.21 0.
00 81.71
16時10分02秒 all 16.16 0.00 1.92 0.21 0.
16時20分01秒 all 17.70 0.00 2.38 3.45 0.
00 76.47
16時30分01秒 all 14.69 0.00 1.94 0.29 0.
00 83.08
★2
16時40分02秒 all 19.11 0.00 2.12 0.27 0.
00 78.50
16時40分02秒 all 19.11 0.00 2.12 0.27 0.
16時50分01秒 all 21.39 0.00 2.06 0.18 0.
00 76.37
★3
17時00分01秒 all 58.06 0.00 1.82 0.14 0.
00 39.99
17時00分01秒 all 58.06 0.00 1.82 0.14 0.
17時10分01秒 all 85.44 0.00 2.07 0.03 0.
00 12.46
17時20分01秒 all 85.25 0.00 2.35 0.04 0.
00 12.36
17時30分02秒 all 84.38 0.00 1.82 0.02 0.
00 13.78
17時40分01秒 all 86.11 0.00 2.07 0.04 0.
00 11.77
17時50分01秒 all 80.57 0.00 1.74 0.01 0.
00 17.67
18時00分01秒 all 79.48 0.00 1.78 0.03 0.
00 18.71
18時10分01秒 all 84.16 0.00 2.07 0.03 0.
00 13.74
18時20分01秒 all 85.73 0.00 2.31 0.02 0.
00 11.94
18時30分01秒 all 81.83 0.00 2.06 0.05 0.
00 16.06
18時30分01秒 CPU %user %nice %system %iowait %
☆再起動
18時40分01秒 all 14.05 0.00 1.76 0.85 0.
00 83.34
18時40分01秒 all 14.05 0.00 1.76 0.85 0.
★1 16:04:14.284 com.sos.scheduler.engine.kernel.scheduler.
SchedulerException: Order is not in a job chain: Order ('Order: オーダー
A')
★2 16:34:20.723 com.sos.scheduler.engine.kernel.scheduler.
SchedulerException: Order is not in a job chain: Order ('Order:オーダー
B')
★3 16:52:04.095 com.sos.scheduler.engine.kernel.scheduler.
★3 16:52:04.095 com.sos.scheduler.engine.kernel.scheduler.
SchedulerException: Order is not in a job chain: Order ('Order:オーダー
C')
オーダーA,B,Cは定時実行になっており、直近の７日以上は問題なく実行されてい
ることを確認済みです。
解決に向けての方針が全くつかめておらずJobSchedulerを分散するか別の Job管
理システムへの移行を計画が必要かもしれません。
確認すべき観点等ありましたら助言いただけると幸いです。
--
このメールは Google グループのグループ「日本JobSchedulerユーザーグループ
（JJUG）」に登録しているユーザーに送られています。
このグループから退会し、グループからのメールの配信を停止するには
jobscheduler-...@googlegroups.com にメールを送信してください。
このディスカッションをウェブ上で閲覧するには https://groups.google.com/d/msgid/jobscheduler-ja/fe903301-4e2c-4afa-966e-5e397768ab48n%40googlegroups.com
にアクセスしてください。
Satoru Funai
Jul 20, 2020, 6:49:46 AM7/20/20
to koba...@gmail.com, jobsche...@googlegroups.com
小林さん
矢野さんのご指摘どおりログ及びジョブ内容を見ないと判断できませんが、もしJava OOMが発生しているようでしたら JVMの調整が必要かもしれません。
ご参考
https://kb.sos-berlin.com/display/PKB/Z-JAVA-105+Java+exception+java+lang+OutOfMemoryError
船井
矢野さんのご指摘どおりログ及びジョブ内容を見ないと判断できませんが、もしJava OOMが発生しているようでしたら JVMの調整が必要かもしれません。
ご参考
https://kb.sos-berlin.com/display/PKB/Z-JAVA-105+Java+exception+java+lang+OutOfMemoryError
船井
----- 元のメッセージ -----
> 差出人: "takasi yano" <takas...@nifty.com>
> 宛先: jobsche...@googlegroups.com
> 送信済み: 2020年7月20日, 月曜日 午前 6:26:03
> 件名: Re: JobScheduler プロセス障害
> このメールは Google グループのグループ「日本JobSchedulerユーザーグループ（JJUG）」の登録者に送られています。
> このグループから退会し、グループからのメールの配信を停止するには
> jobscheduler-...@googlegroups.com にメールを送信してください。
> このディスカッションをウェブ上で閲覧するには、https://groups.google.com/d/msgid/jobscheduler-ja/JxS5WO1BtLJcSlgA._30rrmQ0%40nifty.com
> にアクセスしてください。
>
koba...@gmail.com
Jul 24, 2020, 10:45:30 PM7/24/20
to 日本JobSchedulerユーザーグループ（JJUG）
矢野さん、船井さん ご返信ありがとうございます。
exceptionをキーワードを元にログを検索しているのですが、原因となりそうなログがなく行き詰まっている状態です。
ご提示いただきました Java OOMでもなさそうです。
下記グラフは前日の17:30頃再起動したあとの jobscheduer プロセスのheapの状態を確認したものです。
２４時間前のグラフは下記のとおりです。
17:35頃プロセス再起動（計画作業）を実施しております。
job計画は曜日による差異はありませんし、発生する場合としない場合がある状況です。
sos.ini の[options]には
options = -Xmx2048m -Dcom.sun.management.jmxremote
が記述してあります。
子プロセス用には
https://change.sos-berlin.com/browse/JS-1748 を参考に
jobscheduler_environment_variables.sh に手を入れ
SCHEDULER_START_PARAMS="$SCHEDULER_PARAMS \"-pid-file=$SCHEDULER_PID\" \"-job-java-options=-Xms64m -Xmx128m\" -env=LD_LIBRARY_PATH=\"$ORIG_LD_LIBRARY_PATH\""
が記述してあります。
# grep -i java.lang 発生日前後のログファイル
該当なし
# grep -i '\[ERROR\]' scheduler-2020-07-1*
scheduler-2020-07-13-084006.scheduler.log:2020-07-13 17:40:06.887+0900 [ERROR] (Job_chain /test/job_chain1) SCHEDULER-428 Error when reading base file '/home/scheduler/sos-berlin.com/jobscheduler/scheduler/config/live/test/job_chain1.job_chain.xml' (2018-03-02 15:14:18.000+0900):
scheduler-2020-07-13-084006.scheduler.log:2020-07-13 17:40:06.887+0900 [ERROR] (Job_chain /test/job_chain1) SCHEDULER-149 There is no job in job chain "/test/job_chain1" for the state "success"
scheduler-2020-07-13-084006.scheduler.log:2020-07-13 17:40:09.750+0900 [ERROR] (Job_chain /test/job_chain1) SCHEDULER-149 There is no job in job chain "/test/job_chain1" for the state "success"
scheduler-2020-07-13-084006.scheduler.log:2020-07-13 17:40:10.504+0900 [ERROR] (Job_chain /test/job_chain1) SCHEDULER-149 There is no job in job chain "/test/job_chain1" for the state "success"
scheduler-2020-07-16-084019.scheduler.log:2020-07-16 17:40:20.207+0900 [ERROR] (Job_chain /test/job_chain1) SCHEDULER-428 Error when reading base file '/home/scheduler/sos-berlin.com/jobscheduler/scheduler/config/live/test/job_chain1.job_chain.xml' (2018-03-02 15:14:18.000+0900):
scheduler-2020-07-16-084019.scheduler.log:2020-07-16 17:40:20.207+0900 [ERROR] (Job_chain /test/job_chain1) SCHEDULER-149 There is no job in job chain "/test/job_chain1" for the state "success"
scheduler-2020-07-16-084019.scheduler.log:2020-07-16 17:40:22.922+0900 [ERROR] (Job_chain /test/job_chain1) SCHEDULER-149 There is no job in job chain "/test/job_chain1" for the state "success"
scheduler-2020-07-16-084019.scheduler.log:2020-07-16 17:40:23.771+0900 [ERROR] (Job_chain /test/job_chain1) SCHEDULER-149 There is no job in job chain "/test/job_chain1" for the state "success"
scheduler-2020-07-17-093000.scheduler.log:2020-07-17 18:30:01.582+0900 [ERROR] (Job_chain /test/job_chain1) SCHEDULER-428 Error when reading base file '/home/scheduler/sos-berlin.com/jobscheduler/scheduler/config/live/test/job_chain1.job_chain.xml' (2018-03-02 15:14:18.000+0900):
scheduler-2020-07-17-093000.scheduler.log:2020-07-17 18:30:01.582+0900 [ERROR] (Job_chain /test/job_chain1) SCHEDULER-149 There is no job in job chain "/test/job_chain1" for the state "success"
scheduler-2020-07-17-093000.scheduler.log:2020-07-17 18:30:05.461+0900 [ERROR] (Job_chain /test/job_chain1) SCHEDULER-149 There is no job in job chain "/test/job_chain1" for the state "success"
scheduler-2020-07-17-093000.scheduler.log:2020-07-17 18:30:06.680+0900 [ERROR] (Job_chain /test/job_chain1) SCHEDULER-149 There is no job in job chain "/test/job_chain1" for the state "success"
# ls -la /home/scheduler/sos-berlin.com/jobscheduler/scheduler/config/live/test/job_chain1.job_chain.xml
-rw-rw-r-- 1 scheduler scheduler 255 3月 2 2018 /home/scheduler/sos-berlin.com/jobscheduler/scheduler/config/live/test/job_chain1.job_chain.xml
# cat /home/scheduler/sos-berlin.com/jobscheduler/scheduler/config/live/test/job_chain1.job_chain.xml
<?xml version="1.0" encoding="ISO-8859-1"?>
<job_chain title="job_chain test">
<job_chain_node state="step-1" job="job1" next_state="step-2"/>
<job_chain_node state="step-2" job="job2" next_state="success" error_state="error"/>
何か手がかりとなるキーワードがあるとよいのですが。。。
exceptionをキーワードを元にログを検索しているのですが、原因となりそうなログがなく行き詰まっている状態です。
ご提示いただきました Java OOMでもなさそうです。
下記グラフは前日の17:30頃再起動したあとの jobscheduer プロセスのheapの状態を確認したものです。
２４時間前のグラフは下記のとおりです。
17:35頃プロセス再起動（計画作業）を実施しております。
job計画は曜日による差異はありませんし、発生する場合としない場合がある状況です。
sos.ini の[options]には
options = -Xmx2048m -Dcom.sun.management.jmxremote
が記述してあります。
子プロセス用には
https://change.sos-berlin.com/browse/JS-1748 を参考に
jobscheduler_environment_variables.sh に手を入れ
SCHEDULER_START_PARAMS="$SCHEDULER_PARAMS \"-pid-file=$SCHEDULER_PID\" \"-job-java-options=-Xms64m -Xmx128m\" -env=LD_LIBRARY_PATH=\"$ORIG_LD_LIBRARY_PATH\""
が記述してあります。
# grep -i java.lang 発生日前後のログファイル
該当なし
# grep -i Z-JAVA 発生日前後のログファイル
該当なし# grep -i '\[ERROR\]' scheduler-2020-07-1*
scheduler-2020-07-13-084006.scheduler.log:2020-07-13 17:40:06.887+0900 [ERROR] (Job_chain /test/job_chain1) SCHEDULER-428 Error when reading base file '/home/scheduler/sos-berlin.com/jobscheduler/scheduler/config/live/test/job_chain1.job_chain.xml' (2018-03-02 15:14:18.000+0900):
scheduler-2020-07-13-084006.scheduler.log:2020-07-13 17:40:06.887+0900 [ERROR] (Job_chain /test/job_chain1) SCHEDULER-149 There is no job in job chain "/test/job_chain1" for the state "success"
scheduler-2020-07-13-084006.scheduler.log:2020-07-13 17:40:09.750+0900 [ERROR] (Job_chain /test/job_chain1) SCHEDULER-149 There is no job in job chain "/test/job_chain1" for the state "success"
scheduler-2020-07-13-084006.scheduler.log:2020-07-13 17:40:10.504+0900 [ERROR] (Job_chain /test/job_chain1) SCHEDULER-149 There is no job in job chain "/test/job_chain1" for the state "success"
scheduler-2020-07-16-084019.scheduler.log:2020-07-16 17:40:20.207+0900 [ERROR] (Job_chain /test/job_chain1) SCHEDULER-428 Error when reading base file '/home/scheduler/sos-berlin.com/jobscheduler/scheduler/config/live/test/job_chain1.job_chain.xml' (2018-03-02 15:14:18.000+0900):
scheduler-2020-07-16-084019.scheduler.log:2020-07-16 17:40:20.207+0900 [ERROR] (Job_chain /test/job_chain1) SCHEDULER-149 There is no job in job chain "/test/job_chain1" for the state "success"
scheduler-2020-07-16-084019.scheduler.log:2020-07-16 17:40:22.922+0900 [ERROR] (Job_chain /test/job_chain1) SCHEDULER-149 There is no job in job chain "/test/job_chain1" for the state "success"
scheduler-2020-07-16-084019.scheduler.log:2020-07-16 17:40:23.771+0900 [ERROR] (Job_chain /test/job_chain1) SCHEDULER-149 There is no job in job chain "/test/job_chain1" for the state "success"
scheduler-2020-07-17-093000.scheduler.log:2020-07-17 18:30:01.582+0900 [ERROR] (Job_chain /test/job_chain1) SCHEDULER-428 Error when reading base file '/home/scheduler/sos-berlin.com/jobscheduler/scheduler/config/live/test/job_chain1.job_chain.xml' (2018-03-02 15:14:18.000+0900):
scheduler-2020-07-17-093000.scheduler.log:2020-07-17 18:30:01.582+0900 [ERROR] (Job_chain /test/job_chain1) SCHEDULER-149 There is no job in job chain "/test/job_chain1" for the state "success"
scheduler-2020-07-17-093000.scheduler.log:2020-07-17 18:30:05.461+0900 [ERROR] (Job_chain /test/job_chain1) SCHEDULER-149 There is no job in job chain "/test/job_chain1" for the state "success"
scheduler-2020-07-17-093000.scheduler.log:2020-07-17 18:30:06.680+0900 [ERROR] (Job_chain /test/job_chain1) SCHEDULER-149 There is no job in job chain "/test/job_chain1" for the state "success"
# grep -v '\[ERROR\]' scheduler-2020-07-1* | grep -v '\[info\]'
scheduler-2020-07-10-150015.scheduler.log:
scheduler-2020-07-10-150015.scheduler.log:Das Protokoll wird fortgefuehrt in /home/scheduler/sos-berlin.com/jobscheduler/scheduler/logs/scheduler-2020-07-11-150014.scheduler.log
scheduler-2020-07-11-150014.scheduler.log:
scheduler-2020-07-11-150014.scheduler.log:Das Protokoll wird fortgefuehrt in /home/scheduler/sos-berlin.com/jobscheduler/scheduler/logs/scheduler-2020-07-12-150015.scheduler.log
scheduler-2020-07-13-084006.scheduler.log:2020-07-13 17:40:07.595+0900 [WARN] SCHEDULER-292 Missing from, to, subject or body. Suppressing email
scheduler-2020-07-13-084006.scheduler.log:2020-07-13 17:40:09.873+0900 [WARN] SCHEDULER-292 Missing from, to, subject or body. Suppressing email
scheduler-2020-07-13-084006.scheduler.log:2020-07-13 17:40:09.873+0900 [WARN] SCHEDULER-320 Could not send mail
scheduler-2020-07-13-084006.scheduler.log:
scheduler-2020-07-13-084006.scheduler.log:Das Protokoll wird fortgefuehrt in /home/scheduler/sos-berlin.com/jobscheduler/scheduler/logs/scheduler-2020-07-13-150009.scheduler.log
scheduler-2020-07-13-150009.scheduler.log:
scheduler-2020-07-13-150009.scheduler.log:Das Protokoll wird fortgefuehrt in /home/scheduler/sos-berlin.com/jobscheduler/scheduler/logs/scheduler-2020-07-14-150014.scheduler.log
scheduler-2020-07-14-150014.scheduler.log:
scheduler-2020-07-14-150014.scheduler.log:Das Protokoll wird fortgefuehrt in /home/scheduler/sos-berlin.com/jobscheduler/scheduler/logs/scheduler-2020-07-15-150014.scheduler.log
scheduler-2020-07-16-084019.scheduler.log:2020-07-16 17:40:20.860+0900 [WARN] SCHEDULER-292 Missing from, to, subject or body. Suppressing email
scheduler-2020-07-16-084019.scheduler.log:2020-07-16 17:40:23.046+0900 [WARN] SCHEDULER-292 Missing from, to, subject or body. Suppressing email
scheduler-2020-07-16-084019.scheduler.log:2020-07-16 17:40:23.046+0900 [WARN] SCHEDULER-320 Could not send mail
scheduler-2020-07-16-084019.scheduler.log:
scheduler-2020-07-16-084019.scheduler.log:Das Protokoll wird fortgefuehrt in /home/scheduler/sos-berlin.com/jobscheduler/scheduler/logs/scheduler-2020-07-16-150010.scheduler.log
scheduler-2020-07-16-150010.scheduler.log:2020-07-17 16:03:52.236+0900 [WARN] (Order オーダA) SCHEDULER-893 Standing_order is 'incomplete' now [missing Job_chain JOB-CHAIN名-002]
scheduler-2020-07-16-150010.scheduler.log:2020-07-17 16:34:20.722+0900 [WARN] (Order オーダB) SCHEDULER-893 Standing_order is 'incomplete' now [missing Job_chain JOB-CHAIN名-004]
scheduler-2020-07-16-150010.scheduler.log:2020-07-17 16:52:04.095+0900 [WARN] (Order オーダC) SCHEDULER-893 Standing_order is 'incomplete' now [missing Job_chain JOB-CHAIN名-002]
scheduler-2020-07-16-150010.scheduler.log:2020-07-17 16:56:51.987+0900 [WARN] SCHEDULER-721 Scheduler is not responding quickly, a microstep took 00:00:13.596s
scheduler-2020-07-16-150010.scheduler.log:2020-07-17 16:59:02.519+0900 [WARN] SCHEDULER-721 Scheduler is not responding quickly, a microstep took 00:02:10.532s
scheduler-2020-07-16-150010.scheduler.log:2020-07-17 16:59:16.268+0900 [WARN] SCHEDULER-721 Scheduler is not responding quickly, a microstep took 00:00:13.749s
scheduler-2020-07-16-150010.scheduler.log:2020-07-17 16:59:27.323+0900 [WARN] SCHEDULER-721 Scheduler is not responding quickly, a microstep took 00:00:11.055s
scheduler-2020-07-16-150010.scheduler.log:2020-07-17 17:00:12.279+0900 [WARN] SCHEDULER-721 Scheduler is not responding quickly, a microstep took 00:00:13.305s
scheduler-2020-07-16-150010.scheduler.log:2020-07-17 17:30:16.119+0900 [WARN] SCHEDULER-721 Scheduler is not responding quickly, a microstep took 00:00:16.112s
scheduler-2020-07-16-150010.scheduler.log:2020-07-17 18:00:21.542+0900 [WARN] SCHEDULER-721 Scheduler is not responding quickly, a microstep took 00:00:21.531s
★jobscheduler の強制停止( kill -9 PID)
scheduler-2020-07-17-093000.scheduler.log:2020-07-17 18:30:02.341+0900 [WARN] SCHEDULER-292 Missing from, to, subject or body. Suppressing email
scheduler-2020-07-17-093000.scheduler.log:2020-07-17 18:30:05.576+0900 [WARN] SCHEDULER-292 Missing from, to, subject or body. Suppressing email
scheduler-2020-07-17-093000.scheduler.log:2020-07-17 18:30:05.576+0900 [WARN] SCHEDULER-320 Could not send mail
scheduler-2020-07-17-093000.scheduler.log:
scheduler-2020-07-17-093000.scheduler.log:Das Protokoll wird fortgefuehrt in /home/scheduler/sos-berlin.com/jobscheduler/scheduler/logs/scheduler-2020-07-17-150009.scheduler.log
scheduler-2020-07-17-150009.scheduler.log:
scheduler-2020-07-17-150009.scheduler.log:Das Protokoll wird fortgefuehrt in /home/scheduler/sos-berlin.com/jobscheduler/scheduler/logs/scheduler-2020-07-18-150014.scheduler.log
scheduler-2020-07-18-150014.scheduler.log:
scheduler-2020-07-18-150014.scheduler.log:Das Protokoll wird fortgefuehrt in /home/scheduler/sos-berlin.com/jobscheduler/scheduler/logs/scheduler-2020-07-19-150015.scheduler.log
scheduler-2020-07-10-150015.scheduler.log:
scheduler-2020-07-10-150015.scheduler.log:Das Protokoll wird fortgefuehrt in /home/scheduler/sos-berlin.com/jobscheduler/scheduler/logs/scheduler-2020-07-11-150014.scheduler.log
scheduler-2020-07-11-150014.scheduler.log:
scheduler-2020-07-11-150014.scheduler.log:Das Protokoll wird fortgefuehrt in /home/scheduler/sos-berlin.com/jobscheduler/scheduler/logs/scheduler-2020-07-12-150015.scheduler.log
scheduler-2020-07-13-084006.scheduler.log:2020-07-13 17:40:07.595+0900 [WARN] SCHEDULER-292 Missing from, to, subject or body. Suppressing email
scheduler-2020-07-13-084006.scheduler.log:2020-07-13 17:40:09.873+0900 [WARN] SCHEDULER-292 Missing from, to, subject or body. Suppressing email
scheduler-2020-07-13-084006.scheduler.log:2020-07-13 17:40:09.873+0900 [WARN] SCHEDULER-320 Could not send mail
scheduler-2020-07-13-084006.scheduler.log:
scheduler-2020-07-13-084006.scheduler.log:Das Protokoll wird fortgefuehrt in /home/scheduler/sos-berlin.com/jobscheduler/scheduler/logs/scheduler-2020-07-13-150009.scheduler.log
scheduler-2020-07-13-150009.scheduler.log:
scheduler-2020-07-13-150009.scheduler.log:Das Protokoll wird fortgefuehrt in /home/scheduler/sos-berlin.com/jobscheduler/scheduler/logs/scheduler-2020-07-14-150014.scheduler.log
scheduler-2020-07-14-150014.scheduler.log:
scheduler-2020-07-14-150014.scheduler.log:Das Protokoll wird fortgefuehrt in /home/scheduler/sos-berlin.com/jobscheduler/scheduler/logs/scheduler-2020-07-15-150014.scheduler.log
scheduler-2020-07-16-084019.scheduler.log:2020-07-16 17:40:20.860+0900 [WARN] SCHEDULER-292 Missing from, to, subject or body. Suppressing email
scheduler-2020-07-16-084019.scheduler.log:2020-07-16 17:40:23.046+0900 [WARN] SCHEDULER-292 Missing from, to, subject or body. Suppressing email
scheduler-2020-07-16-084019.scheduler.log:2020-07-16 17:40:23.046+0900 [WARN] SCHEDULER-320 Could not send mail
scheduler-2020-07-16-084019.scheduler.log:
scheduler-2020-07-16-084019.scheduler.log:Das Protokoll wird fortgefuehrt in /home/scheduler/sos-berlin.com/jobscheduler/scheduler/logs/scheduler-2020-07-16-150010.scheduler.log
scheduler-2020-07-16-150010.scheduler.log:2020-07-17 16:03:52.236+0900 [WARN] (Order オーダA) SCHEDULER-893 Standing_order is 'incomplete' now [missing Job_chain JOB-CHAIN名-002]
scheduler-2020-07-16-150010.scheduler.log:2020-07-17 16:34:20.722+0900 [WARN] (Order オーダB) SCHEDULER-893 Standing_order is 'incomplete' now [missing Job_chain JOB-CHAIN名-004]
scheduler-2020-07-16-150010.scheduler.log:2020-07-17 16:52:04.095+0900 [WARN] (Order オーダC) SCHEDULER-893 Standing_order is 'incomplete' now [missing Job_chain JOB-CHAIN名-002]
scheduler-2020-07-16-150010.scheduler.log:2020-07-17 16:56:51.987+0900 [WARN] SCHEDULER-721 Scheduler is not responding quickly, a microstep took 00:00:13.596s
scheduler-2020-07-16-150010.scheduler.log:2020-07-17 16:59:02.519+0900 [WARN] SCHEDULER-721 Scheduler is not responding quickly, a microstep took 00:02:10.532s
scheduler-2020-07-16-150010.scheduler.log:2020-07-17 16:59:16.268+0900 [WARN] SCHEDULER-721 Scheduler is not responding quickly, a microstep took 00:00:13.749s
scheduler-2020-07-16-150010.scheduler.log:2020-07-17 16:59:27.323+0900 [WARN] SCHEDULER-721 Scheduler is not responding quickly, a microstep took 00:00:11.055s
scheduler-2020-07-16-150010.scheduler.log:2020-07-17 17:00:12.279+0900 [WARN] SCHEDULER-721 Scheduler is not responding quickly, a microstep took 00:00:13.305s
scheduler-2020-07-16-150010.scheduler.log:2020-07-17 17:30:16.119+0900 [WARN] SCHEDULER-721 Scheduler is not responding quickly, a microstep took 00:00:16.112s
scheduler-2020-07-16-150010.scheduler.log:2020-07-17 18:00:21.542+0900 [WARN] SCHEDULER-721 Scheduler is not responding quickly, a microstep took 00:00:21.531s
★jobscheduler の強制停止( kill -9 PID)
scheduler-2020-07-17-093000.scheduler.log:2020-07-17 18:30:02.341+0900 [WARN] SCHEDULER-292 Missing from, to, subject or body. Suppressing email
scheduler-2020-07-17-093000.scheduler.log:2020-07-17 18:30:05.576+0900 [WARN] SCHEDULER-292 Missing from, to, subject or body. Suppressing email
scheduler-2020-07-17-093000.scheduler.log:2020-07-17 18:30:05.576+0900 [WARN] SCHEDULER-320 Could not send mail
scheduler-2020-07-17-093000.scheduler.log:
scheduler-2020-07-17-093000.scheduler.log:Das Protokoll wird fortgefuehrt in /home/scheduler/sos-berlin.com/jobscheduler/scheduler/logs/scheduler-2020-07-17-150009.scheduler.log
scheduler-2020-07-17-150009.scheduler.log:
scheduler-2020-07-17-150009.scheduler.log:Das Protokoll wird fortgefuehrt in /home/scheduler/sos-berlin.com/jobscheduler/scheduler/logs/scheduler-2020-07-18-150014.scheduler.log
scheduler-2020-07-18-150014.scheduler.log:
scheduler-2020-07-18-150014.scheduler.log:Das Protokoll wird fortgefuehrt in /home/scheduler/sos-berlin.com/jobscheduler/scheduler/logs/scheduler-2020-07-19-150015.scheduler.log
# ls -la /home/scheduler/sos-berlin.com/jobscheduler/scheduler/config/live/test/job_chain1.job_chain.xml
-rw-rw-r-- 1 scheduler scheduler 255 3月 2 2018 /home/scheduler/sos-berlin.com/jobscheduler/scheduler/config/live/test/job_chain1.job_chain.xml
# cat /home/scheduler/sos-berlin.com/jobscheduler/scheduler/config/live/test/job_chain1.job_chain.xml
<?xml version="1.0" encoding="ISO-8859-1"?>
<job_chain title="job_chain test">
<job_chain_node state="step-1" job="job1" next_state="step-2"/>
<job_chain_node state="step-2" job="job2" next_state="success" error_state="error"/>
何か手がかりとなるキーワードがあるとよいのですが。。。
2020年7月20日月曜日 19:49:46 UTC+9 satoruf:
Satoru Funai
Jul 27, 2020, 7:30:49 AM7/27/20
to koba...@gmail.com, 日本JobSchedulerユーザーグループ（JJUG）
小林さん
ログを見る限りJVMまわりのエラーはなさそうです
気になるのは
> JobおよびJobChainはすべてSSH実行です。
ということはsshに起因するセッションまたはファイルディスクリプタの関係は考えられませんか？
ふない
ログを見る限りJVMまわりのエラーはなさそうです
気になるのは
> JobおよびJobChainはすべてSSH実行です。
ということはsshに起因するセッションまたはファイルディスクリプタの関係は考えられませんか？
ふない
----- 元のメッセージ -----
> 差出人: "koba...@gmail.com" <koba...@gmail.com>
> 宛先: "日本JobSchedulerユーザーグループ（JJUG）" <jobsche...@googlegroups.com>
> 送信済み: 2020年7月25日, 土曜日 午前 11:45:30
> 件名: Re: JobScheduler プロセス障害
>
>
> 矢野さん、船井さん ご返信ありがとうございます。
>
> exceptionをキーワードを元にログを検索しているのですが、原因となりそうなログがなく行き詰まっている状態です。
> ご提示いただきました Java OOMでもなさそうです。
>
> 下記グラフは前日の17:30頃再起動したあとの jobscheduer プロセスのheapの状態を確認したものです。
>
> スクリーンショット 2020-07-25 11.26.29.png
>
> ２４時間前のグラフは下記のとおりです。
> 17:35頃プロセス再起動（計画作業）を実施しております。
>
> https://groups.google.com/d/msgid/jobscheduler-ja/6b3ddf6b-ee25-42d7-b237-79ab7f7b94f1n%40googlegroups.com
> にアクセスしてください。
>
>
> [image/png:スクリーンショット 2020-07-25 11.38.08.png]
>
>
> [image/png:スクリーンショット 2020-07-25 11.26.29.png]
>
koba...@gmail.com
Aug 12, 2020, 12:16:59 PM8/12/20
to 日本JobSchedulerユーザーグループ（JJUG）
船井さん
[scheduler@ホスト名 ~]$ ulimit -a
core file size (blocks, -c) 0
data seg size (kbytes, -d) unlimited
scheduling priority (-e) 0
file size (blocks, -f) unlimited
pending signals (-i) 31119
max locked memory (kbytes, -l) 64
max memory size (kbytes, -m) unlimited
open files (-n) 1024
pipe size (512 bytes, -p) 8
POSIX message queues (bytes, -q) 819200
real-time priority (-r) 0
stack size (kbytes, -s) 8192
cpu time (seconds, -t) unlimited
max user processes (-u) 4096
virtual memory (kbytes, -v) unlimited
file locks (-x) unlimited
たしかに open files は標準の1024のままのようです。資料 fd を確認しつつ調整してみます。
障害が発生したためログを確認しました。
.13 00:35:59.562 40112 8774.33538740 .[xc.insert "Datei file:/home/scheduler/sos-berlin.com/jobscheduler/scheduler/config/sos.ini"]
.13 00:35:59.562 0 8774.33538740 .[xc.insert "Datei file:/home/scheduler/sos-berlin.com/jobscheduler/scheduler/config/sos.ini"]
.13 00:35:59.562 0 8774.33538740 .[xc.insert "Datei file:/home/scheduler/sos-berlin.com/jobscheduler/scheduler/config/sos.ini"]
.13 00:35:59.562 0 8774.33538740 .(Letzte Zeile wiederholt sich 2 mal)
.13 00:35:59.562 0 8774.33538740 .[xc.insert 1, "java.lang.NullPointerException"]
.13 00:35:59.562 0 8774.33538740 .[xc.insert 2, "newInstance"]
.13 00:35:59.562 0 8774.33538740 .[xc.insert 3, "org.mariadb.jdbc.Driver"]
.13 00:35:59.563 1 8774.33538740 ~Sos_database_session() id=spooler db=jdbc:mysql://127.0.0.1:3306/scheduler user=scheduler cmd= open_mode=3 ref=0
.13 00:35:59.563 0 8774.33538740 Exception SCHEDULER-309 Error when opening database: Z-JAVA-105 Java exception java.lang.NullPointerException, method=newInstance [org.mariadb.jdbc.Driver]
このとき、同サーバ内に稼働しているMariaDBは正常起動中
MariaDB [(none)]> show processlist;
+--------+-------------+--------------------+-----------+---------+------+--------------------------+------------------+----------+
| Id | User | Host | db | Command | Time | State | Info | Progress |
+--------+-------------+--------------------+-----------+---------+------+--------------------------+------------------+----------+
| 1 | system user | | NULL | Daemon | NULL | InnoDB purge coordinator | NULL | 0.000 |
| 2 | system user | | NULL | Daemon | NULL | InnoDB purge worker | NULL | 0.000 |
| 3 | system user | | NULL | Daemon | NULL | InnoDB purge worker | NULL | 0.000 |
| 4 | system user | | NULL | Daemon | NULL | InnoDB purge worker | NULL | 0.000 |
| 5 | system user | | NULL | Daemon | NULL | InnoDB shutdown handler | NULL | 0.000 |
| 133816 | dbmonitor | 監視サーバIP:51590 | NULL | Sleep | 0 | | NULL | 0.000 |
| 233514 | scheduler | localhost:48664 | scheduler | Sleep | 1030 | | NULL | 0.000 |
| 233523 | scheduler | localhost:48948 | scheduler | Sleep | 715 | | NULL | 0.000 |
| 233528 | scheduler | localhost:49038 | scheduler | Sleep | 1309 | | NULL | 0.000 |
| 233595 | scheduler | localhost:50506 | scheduler | Sleep | 527 | | NULL | 0.000 |
| 233596 | scheduler | localhost:50508 | scheduler | Sleep | 527 | | NULL | 0.000 |
| 233597 | scheduler | localhost:50510 | scheduler | Sleep | 530 | | NULL | 0.000 |
| 233639 | scheduler | localhost:51524 | scheduler | Sleep | 702 | | NULL | 0.000 |
| 233642 | scheduler | localhost:51560 | scheduler | Sleep | 616 | | NULL | 0.000 |
| 233664 | scheduler | localhost:51836 | scheduler | Sleep | 202 | | NULL | 0.000 |
| 233668 | scheduler | localhost:52090 | scheduler | Sleep | 24 | | NULL | 0.000 |
| 233828 | scheduler | localhost:56446 | scheduler | Sleep | 715 | | NULL | 0.000 |
| 234064 | scheduler | localhost:34032 | scheduler | Sleep | 715 | | NULL | 0.000 |
| 234075 | scheduler | localhost:34468 | scheduler | Sleep | 703 | | NULL | 0.000 |
| 234089 | scheduler | localhost:34928 | scheduler | Sleep | 504 | | NULL | 0.000 |
| 234090 | scheduler | localhost:34962 | scheduler | Sleep | 664 | | NULL | 0.000 |
| 234108 | scheduler | localhost:35900 | scheduler | Sleep | 715 | | NULL | 0.000 |
| 234130 | scheduler | localhost:36726 | scheduler | Sleep | 382 | | NULL | 0.000 |
| 234131 | scheduler | localhost:36740 | scheduler | Sleep | 356 | | NULL | 0.000 |
| 234133 | scheduler | localhost:36754 | scheduler | Sleep | 338 | | NULL | 0.000 |
| 234135 | scheduler | localhost:36798 | scheduler | Sleep | 267 | | NULL | 0.000 |
| 234136 | scheduler | localhost:36810 | scheduler | Sleep | 257 | | NULL | 0.000 |
| 234137 | scheduler | localhost:36820 | scheduler | Sleep | 239 | | NULL | 0.000 |
| 234139 | scheduler | localhost:36830 | scheduler | Sleep | 225 | | NULL | 0.000 |
| 234140 | scheduler | localhost:36832 | scheduler | Sleep | 220 | | NULL | 0.000 |
| 234141 | scheduler | localhost:36840 | scheduler | Sleep | 208 | | NULL | 0.000 |
| 234142 | scheduler | localhost:36842 | scheduler | Sleep | 205 | | NULL | 0.000 |
| 234146 | root | localhost | NULL | Query | 0 | init | show processlist | 0.000 |
+--------+-------------+--------------------+-----------+---------+------+--------------------------+------------------+----------+
33 rows in set (0.00 sec)
似た事例では
https://change.sos-berlin.com/browse/JS-1842
を見つけることができましたが環境が異なるようです。
# /etc/init.d/jobscheduler status jobs
________________________________________________________________________
Job Scheduler instance: scheduler
.............. version: 1.13.2
......... operated for:ホスト名:4444
........ running since: 2020-08-12T15:36:46Z
................ state: running
............. cpu used:
........... job chains: 64
................. jobs: 292
....... enqueued tasks: 0
............... orders: 61
..... remote instances: 0, connected instances:
________________________________________________________________________
# java -version
openjdk version "11.0.6" 2020-01-14 LTS
OpenJDK Runtime Environment 18.9 (build 11.0.6+10-LTS)
OpenJDK 64-Bit Server VM 18.9 (build 11.0.6+10-LTS, mixed mode, sharing)
# rpm -qa | grep -i maria
MariaDB-backup-10.2.30-1.el7.centos.x86_64
MariaDB-common-10.2.30-1.el7.centos.x86_64
MariaDB-client-10.2.30-1.el7.centos.x86_64
MariaDB-server-10.2.30-1.el7.centos.x86_64
MariaDB-compat-10.2.30-1.el7.centos.x86_64
# locate jdbc | grep jar
/home/scheduler/sos-berlin.com/joc/temp/jetty-0.0.0.0-4446-joc.war-_joc-any-5509425224378395499.dir/webapp/WEB-INF/lib/ojdbc6-11.1.0.7.0-Production.jar
/opt/sos-berlin.com/jobscheduler/scheduler/lib/jdbc/h2-1.3.170.jar
/opt/sos-berlin.com/jobscheduler/scheduler/lib/jdbc/jtds-1.3.1.jar
/opt/sos-berlin.com/jobscheduler/scheduler/lib/jdbc/mariadb-java-client-2.2.6.jar
/opt/sos-berlin.com/jobscheduler/scheduler/lib/jdbc/ojdbc6-11.1.0.7.0-Production.jar
/opt/sos-berlin.com/jobscheduler/scheduler/lib/jdbc/postgresql-9.4.1209.jar
[scheduler@ホスト名 ~]$ ulimit -a
core file size (blocks, -c) 0
data seg size (kbytes, -d) unlimited
scheduling priority (-e) 0
file size (blocks, -f) unlimited
pending signals (-i) 31119
max locked memory (kbytes, -l) 64
max memory size (kbytes, -m) unlimited
open files (-n) 1024
pipe size (512 bytes, -p) 8
POSIX message queues (bytes, -q) 819200
real-time priority (-r) 0
stack size (kbytes, -s) 8192
cpu time (seconds, -t) unlimited
max user processes (-u) 4096
virtual memory (kbytes, -v) unlimited
file locks (-x) unlimited
たしかに open files は標準の1024のままのようです。資料 fd を確認しつつ調整してみます。
障害が発生したためログを確認しました。
.13 00:35:59.562 40112 8774.33538740 .[xc.insert "Datei file:/home/scheduler/sos-berlin.com/jobscheduler/scheduler/config/sos.ini"]
.13 00:35:59.562 0 8774.33538740 .[xc.insert "Datei file:/home/scheduler/sos-berlin.com/jobscheduler/scheduler/config/sos.ini"]
.13 00:35:59.562 0 8774.33538740 .[xc.insert "Datei file:/home/scheduler/sos-berlin.com/jobscheduler/scheduler/config/sos.ini"]
.13 00:35:59.562 0 8774.33538740 .(Letzte Zeile wiederholt sich 2 mal)
.13 00:35:59.562 0 8774.33538740 .[xc.insert 1, "java.lang.NullPointerException"]
.13 00:35:59.562 0 8774.33538740 .[xc.insert 2, "newInstance"]
.13 00:35:59.562 0 8774.33538740 .[xc.insert 3, "org.mariadb.jdbc.Driver"]
.13 00:35:59.563 1 8774.33538740 ~Sos_database_session() id=spooler db=jdbc:mysql://127.0.0.1:3306/scheduler user=scheduler cmd= open_mode=3 ref=0
.13 00:35:59.563 0 8774.33538740 Exception SCHEDULER-309 Error when opening database: Z-JAVA-105 Java exception java.lang.NullPointerException, method=newInstance [org.mariadb.jdbc.Driver]
このとき、同サーバ内に稼働しているMariaDBは正常起動中
MariaDB [(none)]> show processlist;
+--------+-------------+--------------------+-----------+---------+------+--------------------------+------------------+----------+
| Id | User | Host | db | Command | Time | State | Info | Progress |
+--------+-------------+--------------------+-----------+---------+------+--------------------------+------------------+----------+
| 1 | system user | | NULL | Daemon | NULL | InnoDB purge coordinator | NULL | 0.000 |
| 2 | system user | | NULL | Daemon | NULL | InnoDB purge worker | NULL | 0.000 |
| 3 | system user | | NULL | Daemon | NULL | InnoDB purge worker | NULL | 0.000 |
| 4 | system user | | NULL | Daemon | NULL | InnoDB purge worker | NULL | 0.000 |
| 5 | system user | | NULL | Daemon | NULL | InnoDB shutdown handler | NULL | 0.000 |
| 133816 | dbmonitor | 監視サーバIP:51590 | NULL | Sleep | 0 | | NULL | 0.000 |
| 233514 | scheduler | localhost:48664 | scheduler | Sleep | 1030 | | NULL | 0.000 |
| 233523 | scheduler | localhost:48948 | scheduler | Sleep | 715 | | NULL | 0.000 |
| 233528 | scheduler | localhost:49038 | scheduler | Sleep | 1309 | | NULL | 0.000 |
| 233595 | scheduler | localhost:50506 | scheduler | Sleep | 527 | | NULL | 0.000 |
| 233596 | scheduler | localhost:50508 | scheduler | Sleep | 527 | | NULL | 0.000 |
| 233597 | scheduler | localhost:50510 | scheduler | Sleep | 530 | | NULL | 0.000 |
| 233639 | scheduler | localhost:51524 | scheduler | Sleep | 702 | | NULL | 0.000 |
| 233642 | scheduler | localhost:51560 | scheduler | Sleep | 616 | | NULL | 0.000 |
| 233664 | scheduler | localhost:51836 | scheduler | Sleep | 202 | | NULL | 0.000 |
| 233668 | scheduler | localhost:52090 | scheduler | Sleep | 24 | | NULL | 0.000 |
| 233828 | scheduler | localhost:56446 | scheduler | Sleep | 715 | | NULL | 0.000 |
| 234064 | scheduler | localhost:34032 | scheduler | Sleep | 715 | | NULL | 0.000 |
| 234075 | scheduler | localhost:34468 | scheduler | Sleep | 703 | | NULL | 0.000 |
| 234089 | scheduler | localhost:34928 | scheduler | Sleep | 504 | | NULL | 0.000 |
| 234090 | scheduler | localhost:34962 | scheduler | Sleep | 664 | | NULL | 0.000 |
| 234108 | scheduler | localhost:35900 | scheduler | Sleep | 715 | | NULL | 0.000 |
| 234130 | scheduler | localhost:36726 | scheduler | Sleep | 382 | | NULL | 0.000 |
| 234131 | scheduler | localhost:36740 | scheduler | Sleep | 356 | | NULL | 0.000 |
| 234133 | scheduler | localhost:36754 | scheduler | Sleep | 338 | | NULL | 0.000 |
| 234135 | scheduler | localhost:36798 | scheduler | Sleep | 267 | | NULL | 0.000 |
| 234136 | scheduler | localhost:36810 | scheduler | Sleep | 257 | | NULL | 0.000 |
| 234137 | scheduler | localhost:36820 | scheduler | Sleep | 239 | | NULL | 0.000 |
| 234139 | scheduler | localhost:36830 | scheduler | Sleep | 225 | | NULL | 0.000 |
| 234140 | scheduler | localhost:36832 | scheduler | Sleep | 220 | | NULL | 0.000 |
| 234141 | scheduler | localhost:36840 | scheduler | Sleep | 208 | | NULL | 0.000 |
| 234142 | scheduler | localhost:36842 | scheduler | Sleep | 205 | | NULL | 0.000 |
| 234146 | root | localhost | NULL | Query | 0 | init | show processlist | 0.000 |
+--------+-------------+--------------------+-----------+---------+------+--------------------------+------------------+----------+
33 rows in set (0.00 sec)
似た事例では
https://change.sos-berlin.com/browse/JS-1842
を見つけることができましたが環境が異なるようです。
# /etc/init.d/jobscheduler status jobs
________________________________________________________________________
Job Scheduler instance: scheduler
.............. version: 1.13.2
......... operated for:ホスト名:4444
........ running since: 2020-08-12T15:36:46Z
................ state: running
............. cpu used:
........... job chains: 64
................. jobs: 292
....... enqueued tasks: 0
............... orders: 61
..... remote instances: 0, connected instances:
________________________________________________________________________
# java -version
openjdk version "11.0.6" 2020-01-14 LTS
OpenJDK Runtime Environment 18.9 (build 11.0.6+10-LTS)
OpenJDK 64-Bit Server VM 18.9 (build 11.0.6+10-LTS, mixed mode, sharing)
# rpm -qa | grep -i maria
MariaDB-backup-10.2.30-1.el7.centos.x86_64
MariaDB-common-10.2.30-1.el7.centos.x86_64
MariaDB-client-10.2.30-1.el7.centos.x86_64
MariaDB-server-10.2.30-1.el7.centos.x86_64
MariaDB-compat-10.2.30-1.el7.centos.x86_64
# locate jdbc | grep jar
/home/scheduler/sos-berlin.com/joc/temp/jetty-0.0.0.0-4446-joc.war-_joc-any-5509425224378395499.dir/webapp/WEB-INF/lib/ojdbc6-11.1.0.7.0-Production.jar
/opt/sos-berlin.com/jobscheduler/scheduler/lib/jdbc/h2-1.3.170.jar
/opt/sos-berlin.com/jobscheduler/scheduler/lib/jdbc/jtds-1.3.1.jar
/opt/sos-berlin.com/jobscheduler/scheduler/lib/jdbc/mariadb-java-client-2.2.6.jar
/opt/sos-berlin.com/jobscheduler/scheduler/lib/jdbc/ojdbc6-11.1.0.7.0-Production.jar
/opt/sos-berlin.com/jobscheduler/scheduler/lib/jdbc/postgresql-9.4.1209.jar
2020年7月27日月曜日 20:30:49 UTC+9 satoruf:
koba...@gmail.com
Aug 12, 2020, 11:41:04 PM8/12/20
to 日本JobSchedulerユーザーグループ（JJUG）
小林です。
JOC からJob定義を更新した際に、Heapが上昇する傾向があるようです。
JOCの不具合修正がいくつかあった気がしますので1.13.2 --> 1.13.5 へのバージョンアップ実施を検証してみます。
JOC からJob定義を更新した際に、Heapが上昇する傾向があるようです。
JOCの不具合修正がいくつかあった気がしますので1.13.2 --> 1.13.5 へのバージョンアップ実施を検証してみます。
2020年8月13日木曜日 1:16:59 UTC+9 koba...@gmail.com:
koba...@gmail.com
Aug 18, 2020, 1:12:22 AM8/18/20
to 日本JobSchedulerユーザーグループ（JJUG）
小林です。検証環境を 1.13.6 へバージョンアップしてみました。
.18 04:53:24.093 0 127889.1FC34740 {scheduler} sos::scheduler::database::Transaction::execute UPDATE SCHEDULER_ORDER_STEP_HISTORY set "END_TIME"={ts'2020-08-17 19:53:24'},"ERROR"=0 where "HISTORY_ID"=578001 and "STEP"=1 (sos::scheduler::order::Order::db_update_order_step_history_record)
.18 04:53:24.093 17302 130211.D25B4740 .{scheduler.call} Java_module_instance.spooler_exit() begin
.18 04:53:24.094 1 127889.1FC34740 {scheduler} sos::scheduler::database::Transaction::execute UPDATE SCHEDULER_ORDER_HISTORY set "END_TIME"={ts'2020-08-17 19:53:24'},"STATE"='success',"STATE_TEXT"='',"TITLE"='' where "HISTORY_ID"=578001 (sos::scheduler::order::Order::db_update_order_history_record)
.18 04:53:24.094 0 127889.1FC34740 open("/home/scheduler/sos-berlin.com/jobscheduler/scheduler/logs/order.オーダーログ名.log") .18 04:53:24.094 1 130211.D25B4740 .{scheduler.call} Java_module_instance.spooler_exit() end
=> 268
.18 04:53:24.094 0 127889.1FC34740 close(268) /home/scheduler/sos-berlin.com/jobscheduler/scheduler/logs/order.オーダーログ名.log
.18 04:53:24.094 0 127889.1FC34740 ..mkstemp("/tmp/scheduler/sos.XXXXXX") => 268 /tmp/scheduler/sos.zM1xTd
.18 04:53:24.095 1 127889.1FC34740 close(268) /tmp/scheduler/sos.zM1xTd
.18 04:53:24.095 0 127889.1FC34740 unlink("/tmp/scheduler/sos.zM1xTd")
.18 04:53:24.095 0 127889.1FC34740 {scheduler} sos::scheduler::database::Transaction::execute COMMIT (sos::scheduler::order::Order::close_log_and_write_history)
.18 04:53:25.110 344946 2046.D500D740 .{scheduler.call} Java_module_instance.spooler_process() end
.18 04:53:25.115 344958 2752.38D56740 .{scheduler.call} Java_module_instance.spooler_process() end
.18 04:54:27.458 c.z.h.p.HikariPool [WARN ] - HikariPool-1 - Thread starvation or clock leap detected (housekeeper delta=1m338ms731µs266ns).
.18 04:54:50.352 86257 127889.1FC34740 {scheduler} logfile /home/scheduler/sos-berlin.com/jobscheduler/scheduler/logs/order.オーダーログ名.log opened (append=0, append_for_cache=0)
.18 04:54:50.352 0 127889.1FC34740 {scheduler} sos::scheduler::database::Transaction::execute UPDATE SCHEDULER_ORDERS set "DISTRIBUTED_NEXT_TIME"=NULL,"INITIAL_STATE"='contract_start',"MOD_TIME"={ts'2020-08-17 19:54:50'},"STATE"='contract_start' where "OCCUPYING_CLUSTER_MEMBER_ID" IS NULL and "JOB_CHAIN"='ジョブチェイン名' and "ID"='contract_start' and "SPOOLER_ID"='scheduler' (sos::scheduler::order::Order::db_update2)
.18 04:54:58.926 8574 127889.1FC34740 .mkstemp("/tmp/scheduler/sos.XXXXXX") => 273 /tmp/scheduler/sos.oxSnch
.18 04:54:58.926 c.z.h.p.HikariPool [WARN ] - HikariPool-1 - Thread starvation or clock leap detected (housekeeper delta=1m3s231ms129µs731ns).
.18 04:54:58.926 0 127889.1FC34740 close(273) /tmp/scheduler/sos.oxSnch
.18 04:55:13.482 14556 127889.1FC34740 unlink("/tmp/scheduler/sos.oxSnch")
.18 04:57:12.190 118708 127889.1FC34740 [xc.insert 1, "java.lang.NullPointerException"]
.18 04:57:12.190 0 127889.1FC34740 [xc.insert 2, "CallObjectMethodA"]
.18 04:57:18.025 5835 127889.1FC34740 Exception SCHEDULER-306 Error when updating table SCHEDULER_ORDERS: Z-JAVA-105 Java exception java.lang.NullPointerException, method=CallObjectMethodA []
.18 04:57:18.029 4 127889.1FC34740 {scheduler} sos::scheduler::database::Transaction::execute ROLLBACK (sos::scheduler::database::Retry_nested_transaction::reopen_database_after_error, sos::scheduler::order::Order::db_update2)
.18 04:57:58.512 40483 127889.1FC34740 ~Sos_database_session() id=spooler db=jdbc:mysql://127.0.0.1:3306/scheduler user=scheduler cmd=ROLLBACK open_mode=3 ref=0
.18 04:57:58.513 1 127889.1FC34740 .[xc.insert "Datei file:/home/scheduler/sos-berlin.com/jobscheduler/scheduler/config/sos.ini"]
.18 04:57:58.513 0 127889.1FC34740 .[xc.insert "Datei file:/home/scheduler/sos-berlin.com/jobscheduler/scheduler/config/sos.ini"]
.18 04:57:58.513 0 127889.1FC34740 .[xc.insert "Datei file:/home/scheduler/sos-berlin.com/jobscheduler/scheduler/config/sos.ini"]
.18 04:57:58.513 0 127889.1FC34740 .(Letzte Zeile wiederholt sich 2 mal)
.18 04:57:58.513 0 127889.1FC34740 .[xc.insert 1, "java.lang.NullPointerException"]
.18 04:57:58.513 0 127889.1FC34740 .[xc.insert 2, "newInstance"]
.18 04:57:58.513 0 127889.1FC34740 .[xc.insert 3, "org.mariadb.jdbc.Driver"]
.18 04:57:58.513 0 127889.1FC34740 ~Sos_database_session() id=spooler db=jdbc:mysql://127.0.0.1:3306/scheduler user=scheduler cmd= open_mode=3 ref=0
JOCの実行計画がおかしい不具合が改善されたのは良かったのですが、不安定なのは相変わらずです。
（なんとなくDBの問題であるきもしますが特定に至っていません）
＜確認された不具合＞
2020-08-18 00:01:00.080+0900 [info]
2020-08-18 00:01:00.080+0900 [info] Order createDailyPlan - Protocol starts in /home/scheduler/sos-berlin.com/jobscheduler/scheduler/logs/order.sos,dailyplan,CreateDailyPlan.createDailyPlan.log
2020-08-17 15:16:54.324+0900 [info] SCHEDULER-891 Configuration file '/home/scheduler/sos-berlin.com/jobscheduler/scheduler/config/live/sos/dailyplan/CreateDailyPlan,createDailyPlan.order.xml' (2020-08-14 02:37:36.000+0900) is going to be be loaded into this new Standing_order
2020-08-17 15:16:57.556+0900 [info] SCHEDULER-938 Order will be processed at 2020-08-17 15:01:00.000Z
2020-08-17 15:16:57.556+0900 [info] SCHEDULER-893 Standing_order is 'active' now
2020-08-18 00:01:00.144+0900 [info] SCHEDULER-842 Task is going to process Order sos/dailyplan/CreateDailyPlan:createDailyPlan, state=Create, on JobScheduler 'http://mtsjm01:40444', Order's Process_class
2020-08-18 00:01:00.164+0900 [info]
2020-08-18 00:01:00.164+0900 [info] Task sos/dailyplan/CreateDailyPlan:1369087 - Protocol starts in /home/scheduler/sos-berlin.com/jobscheduler/scheduler/logs/task.sos,dailyplan,CreateDailyPlan.log
2020-08-18 00:01:00.206+0900 [info] SCHEDULER-726 Task runs on this JobScheduler 'http://mtsjm01:40444'
2020-08-18 00:01:00.206+0900 [info] SCHEDULER-918 state=starting (at=never)
2020-08-18 00:01:05.458+0900 [info] [stdout] 18 00:01:04.438 [INFO ] (JobSchedulerJobAdapter.java:59) - 1.13.6 (2020-08-13 15:55, revision 2e7405406f2e6531440a0880d16d11f5167089c9) Copyright 2003-2020 SOS GmbH Berlin
2020-08-18 00:01:05.458+0900 [info] [stdout] 18 00:01:05.262 [INFO ] (Version.java:44) - HHH000412: Hibernate ORM core version 5.4.19.Final
2020-08-18 00:01:17.184+0900 [info] [stdout] 18 00:01:06.571 [INFO ] (JavaReflectionManager.java:66) - HCANN000001: Hibernate Commons Annotations {5.0.1.Final}
2020-08-18 00:01:17.184+0900 [info] [stdout] 18 00:01:06.683 [INFO ] (Dialect.java:170) - HHH000400: Using dialect: org.hibernate.dialect.MySQLInnoDBDialect
2020-08-18 00:01:17.184+0900 [info] [stdout] 18 00:01:09.577 [INFO ] (C3P0ConnectionProvider.java:116) - HHH010002: C3P0 using driver: org.mariadb.jdbc.Driver at URL: jdbc:mysql://127.0.0.1:3306/scheduler
2020-08-18 00:01:17.184+0900 [info] [stdout] 18 00:01:09.578 [INFO ] (C3P0ConnectionProvider.java:117) - HHH10001001: Connection properties: autocommit=false, user=scheduler}
2020-08-18 00:01:17.184+0900 [info] [stdout] 18 00:01:09.578 [INFO ] (C3P0ConnectionProvider.java:120) - HHH10001003: Autocommit mode: false
2020-08-18 00:01:17.184+0900 [info] [stdout] 18 00:01:10.093 [INFO ] (Slf4jMLog.java:212) - MLog clients using slf4j logging.
2020-08-18 00:01:17.184+0900 [info] [stdout] 18 00:01:10.361 [INFO ] (Slf4jMLog.java:212) - Initializing c3p0-0.9.5.4 [built 23-March-2019 23:00:48 -0700; debug? true; trace: 10]
2020-08-18 00:01:17.184+0900 [info] [stdout] 18 00:01:10.485 [INFO ] (C3P0ConnectionProvider.java:200) - HHH10001007: JDBC isolation level: READ_COMMITTED
2020-08-18 00:03:18.685+0900 [info] [stdout] 18 00:03:10.174 [ERROR] (Calendar2DB.java:151) - SchedulerObjectFactory::run: COM-80020009 DISP_E_EXCEPTION [] [Z-JAVA-105 Java exception java.lang.OutOfMemoryError: Java heap space, method=CallObjectMethodA [] (Calling sos::scheduler::com_objects::Com_spooler::Execute_xml)] (COM-80020009 DISP_E_EXCEPTION [] [Z-JAVA-105 Java exception java.lang.OutOfMemoryError: Java heap space, method=CallObjectMethodA [] (Calling sos::scheduler::com_objects::Com_spooler::Execute_xml)])
2020-08-18 00:03:18.685+0900 [info] [stdout] com.sos.JSHelper.Exceptions.JobSchedulerException: SchedulerObjectFactory::run: COM-80020009 DISP_E_EXCEPTION [] [Z-JAVA-105 Java exception java.lang.OutOfMemoryError: Java heap space, method=CallObjectMethodA [] (Calling sos::scheduler::com_objects::Com_spooler::Execute_xml)] (COM-80020009 DISP_E_EXCEPTION [] [Z-JAVA-105 Java exception java.lang.OutOfMemoryError: Java heap space, method=CallObjectMethodA [] (Calling sos::scheduler::com_objects::Com_spooler::Execute_xml)])
2020-08-18 00:03:18.685+0900 [info] [stdout] at com.sos.scheduler.model.SchedulerObjectFactory.run(SchedulerObjectFactory.java:281) ~[com.sos-berlin.jobscheduler.jobscheduler-object-model-1.13.6.jar:1.13.6]
2020-08-18 00:03:18.685+0900 [info] [stdout] at com.sos.scheduler.model.answers.JSCmdBase.run(JSCmdBase.java:22) ~[com.sos-berlin.jobscheduler.jobscheduler-object-model-1.13.6.jar:1.13.6]
2020-08-18 00:03:18.685+0900 [info] [stdout] at com.sos.jitl.dailyplan.db.Calendar2DB.getCalendar(Calendar2DB.java:505) ~[com.sos-berlin.jitl.jitl-jobs-1.13.6.jar:1.13.6]
2020-08-18 00:03:18.685+0900 [info] [stdout] at com.sos.jitl.dailyplan.db.Calendar2DB.fillListOfCalendars(Calendar2DB.java:431) ~[com.sos-berlin.jitl.jitl-jobs-1.13.6.jar:1.13.6]
2020-08-18 00:03:18.685+0900 [info] [stdout] at com.sos.jitl.dailyplan.db.Calendar2DB.store(Calendar2DB.java:139) [com.sos-berlin.jitl.jitl-jobs-1.13.6.jar:1.13.6]
2020-08-18 00:03:18.685+0900 [info] [stdout] at com.sos.jitl.dailyplan.job.CreateDailyPlan.Execute(CreateDailyPlan.java:52) [com.sos-berlin.jitl.jitl-jobs-1.13.6.jar:1.13.6]
2020-08-18 00:03:18.685+0900 [info] [stdout] at com.sos.jitl.dailyplan.job.CreateDailyPlanJSAdapterClass.doProcessing(CreateDailyPlanJSAdapterClass.java:65) [com.sos-berlin.jitl.jitl-jobs-1.13.6.jar:1.13.6]
2020-08-18 00:03:18.685+0900 [info] [stdout] at com.sos.jitl.dailyplan.job.CreateDailyPlanJSAdapterClass.spooler_process(CreateDailyPlanJSAdapterClass.java:28) [com.sos-berlin.jitl.jitl-jobs-1.13.6.jar:1.13.6]
2020-08-18 00:03:18.685+0900 [info] [stdout] Caused by: java.lang.RuntimeException: COM-80020009 DISP_E_EXCEPTION [] [Z-JAVA-105 Java exception java.lang.OutOfMemoryError: Java heap space, method=CallObjectMethodA [] (Calling sos::scheduler::com_objects::Com_spooler::Execute_xml)]
2020-08-18 00:03:18.685+0900 [info] [stdout] at sos.spooler.Idispatch.com_call(Native Method) ~[com.sos-berlin.jobscheduler.engine-1.13.6.jar:?]
2020-08-18 00:03:18.685+0900 [info] [stdout] at sos.spooler.Idispatch.com_call(Idispatch.java:49) ~[com.sos-berlin.jobscheduler.engine-1.13.6.jar:?]
2020-08-18 00:03:18.685+0900 [info] [stdout] at sos.spooler.Spooler.execute_xml(Spooler.java:149) ~[com.sos-berlin.jobscheduler.engine-1.13.6.jar:?]
2020-08-18 00:03:18.685+0900 [info] [stdout] at com.sos.scheduler.model.SchedulerObjectFactory.getAnswerFromSpooler(SchedulerObjectFactory.java:291) ~[com.sos-berlin.jobscheduler.jobscheduler-object-model-1.13.6.jar:1.13.6]
2020-08-18 00:03:18.685+0900 [info] [stdout] at com.sos.scheduler.model.SchedulerObjectFactory.run(SchedulerObjectFactory.java:229) ~[com.sos-berlin.jobscheduler.jobscheduler-object-model-1.13.6.jar:1.13.6]
2020-08-18 00:03:18.685+0900 [info] [stdout] ... 7 more
2020-08-18 00:03:18.685+0900 [info] [stdout] 18 00:03:10.191 [ERROR] (CreateDailyPlanJSAdapterClass.java:31) - SchedulerObjectFactory::run: COM-80020009 DISP_E_EXCEPTION [] [Z-JAVA-105 Java exception java.lang.OutOfMemoryError: Java heap space, method=CallObjectMethodA [] (Calling sos::scheduler::com_objects::Com_spooler::Execute_xml)] (COM-80020009 DISP_E_EXCEPTION [] [Z-JAVA-105 Java exception java.lang.OutOfMemoryError: Java heap space, method=CallObjectMethodA [] (Calling sos::scheduler::com_objects::Com_spooler::Execute_xml)])
2020-08-18 00:03:18.685+0900 [info] [stdout] com.sos.JSHelper.Exceptions.JobSchedulerException: SchedulerObjectFactory::run: COM-80020009 DISP_E_EXCEPTION [] [Z-JAVA-105 Java exception java.lang.OutOfMemoryError: Java heap space, method=CallObjectMethodA [] (Calling sos::scheduler::com_objects::Com_spooler::Execute_xml)] (COM-80020009 DISP_E_EXCEPTION [] [Z-JAVA-105 Java exception java.lang.OutOfMemoryError: Java heap space, method=CallObjectMethodA [] (Calling sos::scheduler::com_objects::Com_spooler::Execute_xml)])
2020-08-18 00:03:18.685+0900 [info] [stdout] at com.sos.scheduler.model.SchedulerObjectFactory.run(SchedulerObjectFactory.java:281) ~[com.sos-berlin.jobscheduler.jobscheduler-object-model-1.13.6.jar:1.13.6]
2020-08-18 00:03:18.685+0900 [info] [stdout] at com.sos.scheduler.model.answers.JSCmdBase.run(JSCmdBase.java:22) ~[com.sos-berlin.jobscheduler.jobscheduler-object-model-1.13.6.jar:1.13.6]
2020-08-18 00:03:18.685+0900 [info] [stdout] at com.sos.jitl.dailyplan.db.Calendar2DB.getCalendar(Calendar2DB.java:505) ~[com.sos-berlin.jitl.jitl-jobs-1.13.6.jar:1.13.6]
2020-08-18 00:03:18.685+0900 [info] [stdout] at com.sos.jitl.dailyplan.db.Calendar2DB.fillListOfCalendars(Calendar2DB.java:431) ~[com.sos-berlin.jitl.jitl-jobs-1.13.6.jar:1.13.6]
2020-08-18 00:03:18.685+0900 [info] [stdout] at com.sos.jitl.dailyplan.db.Calendar2DB.store(Calendar2DB.java:139) ~[com.sos-berlin.jitl.jitl-jobs-1.13.6.jar:1.13.6]
2020-08-18 00:03:18.685+0900 [info] [stdout] at com.sos.jitl.dailyplan.job.CreateDailyPlan.Execute(CreateDailyPlan.java:52) ~[com.sos-berlin.jitl.jitl-jobs-1.13.6.jar:1.13.6]
2020-08-18 00:03:18.685+0900 [info] [stdout] at com.sos.jitl.dailyplan.job.CreateDailyPlanJSAdapterClass.doProcessing(CreateDailyPlanJSAdapterClass.java:65) ~[com.sos-berlin.jitl.jitl-jobs-1.13.6.jar:1.13.6]
2020-08-18 00:03:18.685+0900 [info] [stdout] at com.sos.jitl.dailyplan.job.CreateDailyPlanJSAdapterClass.spooler_process(CreateDailyPlanJSAdapterClass.java:28) [com.sos-berlin.jitl.jitl-jobs-1.13.6.jar:1.13.6]
2020-08-18 00:03:18.685+0900 [info] [stdout] Caused by: java.lang.RuntimeException: COM-80020009 DISP_E_EXCEPTION [] [Z-JAVA-105 Java exception java.lang.OutOfMemoryError: Java heap space, method=CallObjectMethodA [] (Calling sos::scheduler::com_objects::Com_spooler::Execute_xml)]
2020-08-18 00:03:18.685+0900 [info] [stdout] at sos.spooler.Idispatch.com_call(Native Method) ~[com.sos-berlin.jobscheduler.engine-1.13.6.jar:?]
2020-08-18 00:03:18.685+0900 [info] [stdout] at sos.spooler.Idispatch.com_call(Idispatch.java:49) ~[com.sos-berlin.jobscheduler.engine-1.13.6.jar:?]
2020-08-18 00:03:18.685+0900 [info] [stdout] at sos.spooler.Spooler.execute_xml(Spooler.java:149) ~[com.sos-berlin.jobscheduler.engine-1.13.6.jar:?]
2020-08-18 00:03:18.685+0900 [info] [stdout] at com.sos.scheduler.model.SchedulerObjectFactory.getAnswerFromSpooler(SchedulerObjectFactory.java:291) ~[com.sos-berlin.jobscheduler.jobscheduler-object-model-1.13.6.jar:1.13.6]
2020-08-18 00:03:18.685+0900 [info] [stdout] at com.sos.scheduler.model.SchedulerObjectFactory.run(SchedulerObjectFactory.java:229) ~[com.sos-berlin.jobscheduler.jobscheduler-object-model-1.13.6.jar:1.13.6]
2020-08-18 00:03:18.685+0900 [info] [stdout] ... 7 more
2020-08-18 00:03:24.362+0900 [info] [stderr] com.sos.JSHelper.Exceptions.JobSchedulerException: SchedulerObjectFactory::run: COM-80020009 DISP_E_EXCEPTION [] [Z-JAVA-105 Java exception java.lang.OutOfMemoryError: Java heap space, method=CallObjectMethodA [] (Calling sos::scheduler::com_objects::Com_spooler::Execute_xml)] (COM-80020009 DISP_E_EXCEPTION [] [Z-JAVA-105 Java exception java.lang.OutOfMemoryError: Java heap space, method=CallObjectMethodA [] (Calling sos::scheduler::com_objects::Com_spooler::Execute_xml)])
2020-08-18 00:03:24.362+0900 [info] [stderr] at com.sos.scheduler.model.SchedulerObjectFactory.run(SchedulerObjectFactory.java:281)
2020-08-18 00:03:24.362+0900 [info] [stderr] at com.sos.scheduler.model.answers.JSCmdBase.run(JSCmdBase.java:22)
2020-08-18 00:03:24.362+0900 [info] [stderr] at com.sos.jitl.dailyplan.db.Calendar2DB.getCalendar(Calendar2DB.java:505)
2020-08-18 00:03:24.362+0900 [info] [stderr] at com.sos.jitl.dailyplan.db.Calendar2DB.fillListOfCalendars(Calendar2DB.java:431)
2020-08-18 00:03:24.362+0900 [info] [stderr] at com.sos.jitl.dailyplan.db.Calendar2DB.store(Calendar2DB.java:139)
2020-08-18 00:03:24.362+0900 [info] [stderr] at com.sos.jitl.dailyplan.job.CreateDailyPlan.Execute(CreateDailyPlan.java:52)
2020-08-18 00:03:24.362+0900 [info] [stderr] at com.sos.jitl.dailyplan.job.CreateDailyPlanJSAdapterClass.doProcessing(CreateDailyPlanJSAdapterClass.java:65)
2020-08-18 00:03:24.362+0900 [info] [stderr] at com.sos.jitl.dailyplan.job.CreateDailyPlanJSAdapterClass.spooler_process(CreateDailyPlanJSAdapterClass.java:28)
2020-08-18 00:03:24.362+0900 [info] [stderr] Caused by: java.lang.RuntimeException: COM-80020009 DISP_E_EXCEPTION [] [Z-JAVA-105 Java exception java.lang.OutOfMemoryError: Java heap space, method=CallObjectMethodA [] (Calling sos::scheduler::com_objects::Com_spooler::Execute_xml)]
2020-08-18 00:03:24.362+0900 [info] [stderr] at sos.spooler.Idispatch.com_call(Native Method)
2020-08-18 00:03:24.362+0900 [info] [stderr] at sos.spooler.Idispatch.com_call(Idispatch.java:49)
2020-08-18 00:03:24.362+0900 [info] [stderr] at sos.spooler.Spooler.execute_xml(Spooler.java:149)
2020-08-18 00:03:24.362+0900 [info] [stderr] at com.sos.scheduler.model.SchedulerObjectFactory.getAnswerFromSpooler(SchedulerObjectFactory.java:291)
2020-08-18 00:03:24.362+0900 [info] [stderr] at com.sos.scheduler.model.SchedulerObjectFactory.run(SchedulerObjectFactory.java:229)
2020-08-18 00:03:24.362+0900 [info] [stderr] ... 7 more
2020-08-18 00:04:42.423+0900 [info] SCHEDULER-843 Task has ended processing of Order sos/dailyplan/CreateDailyPlan:createDailyPlan, state=Create, on JobScheduler 'http://mtsjm01:40444'
2020-08-18 00:04:42.424+0900 [info] set_state error
2020-08-18 00:04:42.424+0900 [info] SCHEDULER-944 End state reached - order will be repeated at 2020-08-18 15:01:00.000Z with state=Create
2020-08-18 00:04:42.424+0900 [info] SCHEDULER-962 Protocol ends in /home/scheduler/sos-berlin.com/jobscheduler/scheduler/logs/order.sos,dailyplan,CreateDailyPlan.createDailyPlan.log
Java Optionは下記を指定
-Xmx2048m -Dcom.sun.management.jmxremote
ただし、8/17 は正常に動作していました。
2020-08-16 00:01:33.276+0900 [info]
2020-08-16 00:01:33.276+0900 [info] Order createDailyPlan - Protocol starts in /home/scheduler/sos-berlin.com/jobscheduler/scheduler/logs/order.sos,dailyplan,CreateDailyPlan.createDailyPlan.log
2020-08-16 00:01:33.275+0900 [info] set_state Create, Job /sos/dailyplan/CreateDailyPlan
2020-08-17 00:01:00.017+0900 [info] SCHEDULER-842 Task is going to process Order sos/dailyplan/CreateDailyPlan:createDailyPlan, state=Create, on JobScheduler 'http://mtsjm01:40444', Order's Process_class
2020-08-17 00:01:00.024+0900 [info]
2020-08-17 00:01:00.024+0900 [info] Task sos/dailyplan/CreateDailyPlan:1363038 - Protocol starts in /home/scheduler/sos-berlin.com/jobscheduler/scheduler/logs/task.sos,dailyplan,CreateDailyPlan.log
2020-08-17 00:01:00.041+0900 [info] SCHEDULER-726 Task runs on this JobScheduler 'http://mtsjm01:40444'
2020-08-17 00:01:00.041+0900 [info] SCHEDULER-918 state=starting (at=never)
2020-08-17 00:01:03.330+0900 [info] [stdout] 17 00:01:02.334 [INFO ] (JobSchedulerJobAdapter.java:59) - 1.13.5 (2020-08-05 20:35, revision bccfefc06cd8b9c011f3eed18600f54e1b094ffc) Copyright 2003-2020 SOS GmbH Berlin
2020-08-17 00:01:03.330+0900 [info] [stdout] 17 00:01:02.604 [INFO ] (Version.java:44) - HHH000412: Hibernate ORM core version 5.4.19.Final
2020-08-17 00:01:13.332+0900 [info] [stdout] 17 00:01:03.462 [INFO ] (JavaReflectionManager.java:66) - HCANN000001: Hibernate Commons Annotations {5.0.1.Final}
2020-08-17 00:01:13.332+0900 [info] [stdout] 17 00:01:03.677 [INFO ] (Dialect.java:170) - HHH000400: Using dialect: org.hibernate.dialect.MySQLInnoDBDialect
2020-08-17 00:01:13.332+0900 [info] [stdout] 17 00:01:05.299 [INFO ] (C3P0ConnectionProvider.java:116) - HHH010002: C3P0 using driver: org.mariadb.jdbc.Driver at URL: jdbc:mysql://127.0.0.1:3306/scheduler
2020-08-17 00:01:13.332+0900 [info] [stdout] 17 00:01:05.300 [INFO ] (C3P0ConnectionProvider.java:117) - HHH10001001: Connection properties: autocommit=false, user=scheduler}
2020-08-17 00:01:13.332+0900 [info] [stdout] 17 00:01:05.300 [INFO ] (C3P0ConnectionProvider.java:120) - HHH10001003: Autocommit mode: false
2020-08-17 00:01:13.332+0900 [info] [stdout] 17 00:01:05.487 [INFO ] (Slf4jMLog.java:212) - MLog clients using slf4j logging.
2020-08-17 00:01:13.332+0900 [info] [stdout] 17 00:01:05.596 [INFO ] (Slf4jMLog.java:212) - Initializing c3p0-0.9.5.4 [built 23-March-2019 23:00:48 -0700; debug? true; trace: 10]
2020-08-17 00:01:13.332+0900 [info] [stdout] 17 00:01:05.647 [INFO ] (C3P0ConnectionProvider.java:200) - HHH10001007: JDBC isolation level: READ_COMMITTED
2020-08-17 00:01:13.332+0900 [info] [stdout] 17 00:01:08.288 [INFO ] (Slf4jMLog.java:212) - Initializing c3p0 pool... com.mchange.v2.c3p0.PoolBackedDataSource@9312be20 [ connectionPoolDataSource -> com.mchange.v2.c3p0.WrapperConnectionPoolDataSource@6e7601ca [ acquireIncrement -> 1, acquireRetryAttempts -> 1, acquireRetryDelay -> 1000, autoCommitOnClose -> false, automaticTestTable -> null, breakAfterAcquireFailure -> false, checkoutTimeout -> 0, connectionCustomizerClassName -> null, connectionTesterClassName -> com.mchange.v2.c3p0.impl.DefaultConnectionTester, contextClassLoaderSource -> caller, debugUnreturnedConnectionStackTraces -> false, factoryClassLocation -> null, forceIgnoreUnresolvedTransactions -> false, forceSynchronousCheckins -> false, identityToken -> 31u4yyab1wr3733hjmdyf|6b0ba697, idleConnectionTestPeriod -> 16200, initialPoolSize -> 1, maxAdministrativeTaskTime -> 0, maxConnectionAge -> 14400, maxIdleTime -> 14400, maxIdleTimeExcessConnections -> 0, maxPoolSize -> 3, maxStatements -> 0, maxStatementsPerConnection -> 0, minPoolSize -> 1, nestedDataSource -> com.mchange.v2.c3p0.DriverManagerDataSource@d20107f1 [ description -> null, driverClass -> null, factoryClassLocation -> null, forceUseNamedDriverClass -> false, identityToken -> 31u4yyab1wr3733hjmdyf|34bf66af, jdbcUrl -> jdbc:mysql://127.0.0.1:3306/scheduler, properties -> autocommit=false, user=******} ], preferredTestQuery -> null, privilegeSpawnedThreads -> false, propertyCycle -> 0, statementCacheNumDeferredCloseThreads -> 0, testConnectionOnCheckin -> false, testConnectionOnCheckout -> false, unreturnedConnectionTimeout -> 0, usesTraditionalReflectiveProxies -> false; userOverrides: {} ], dataSourceName -> null, extensions -> {}, factoryClassLocation -> null, identityToken -> 31u4yyab1wr3733hjmdyf|77d54a41, numHelperThreads -> 3 ]
2020-08-17 00:01:30.732+0900 [info] [stdout] 17 00:01:29.894 [INFO ] (JtaPlatformInitiator.java:52) - HHH000490: Using JtaPlatform implementation: [org.hibernate.engine.transaction.jta.platform.internal.NoJtaPlatform]
2020-08-17 00:01:30.733+0900 [info] SCHEDULER-843 Task has ended processing of Order sos/dailyplan/CreateDailyPlan:createDailyPlan, state=Create, on JobScheduler 'http://mtsjm01:40444'
2020-08-17 00:01:30.733+0900 [info] set_state success
2020-08-17 00:01:30.733+0900 [info] SCHEDULER-944 End state reached - order will be repeated at 2020-08-17 15:01:00.000Z with state=Create
2020-08-17 00:01:30.733+0900 [info] SCHEDULER-962 Protocol ends in /home/scheduler/sos-berlin.com/jobscheduler/scheduler/logs/order.sos,dailyplan,CreateDailyPlan.createDailyPlan.log
また、JobScheduerプロセスがDBに接続できなくなる事象が発生しているようです。
このエラー発生後は、プロセス再起動まですべてのJobが実行できなかったようです。
.18 04:53:24.093 0 127889.1FC34740 {scheduler} sos::scheduler::database::Transaction::execute UPDATE SCHEDULER_ORDER_STEP_HISTORY set "END_TIME"={ts'2020-08-17 19:53:24'},"ERROR"=0 where "HISTORY_ID"=578001 and "STEP"=1 (sos::scheduler::order::Order::db_update_order_step_history_record)
.18 04:53:24.093 17302 130211.D25B4740 .{scheduler.call} Java_module_instance.spooler_exit() begin
.18 04:53:24.094 1 127889.1FC34740 {scheduler} sos::scheduler::database::Transaction::execute UPDATE SCHEDULER_ORDER_HISTORY set "END_TIME"={ts'2020-08-17 19:53:24'},"STATE"='success',"STATE_TEXT"='',"TITLE"='' where "HISTORY_ID"=578001 (sos::scheduler::order::Order::db_update_order_history_record)
.18 04:53:24.094 0 127889.1FC34740 open("/home/scheduler/sos-berlin.com/jobscheduler/scheduler/logs/order.オーダーログ名.log") .18 04:53:24.094 1 130211.D25B4740 .{scheduler.call} Java_module_instance.spooler_exit() end
=> 268
.18 04:53:24.094 0 127889.1FC34740 close(268) /home/scheduler/sos-berlin.com/jobscheduler/scheduler/logs/order.オーダーログ名.log
.18 04:53:24.094 0 127889.1FC34740 ..mkstemp("/tmp/scheduler/sos.XXXXXX") => 268 /tmp/scheduler/sos.zM1xTd
.18 04:53:24.095 1 127889.1FC34740 close(268) /tmp/scheduler/sos.zM1xTd
.18 04:53:24.095 0 127889.1FC34740 unlink("/tmp/scheduler/sos.zM1xTd")
.18 04:53:24.095 0 127889.1FC34740 {scheduler} sos::scheduler::database::Transaction::execute COMMIT (sos::scheduler::order::Order::close_log_and_write_history)
.18 04:53:25.110 344946 2046.D500D740 .{scheduler.call} Java_module_instance.spooler_process() end
.18 04:53:25.115 344958 2752.38D56740 .{scheduler.call} Java_module_instance.spooler_process() end
.18 04:54:27.458 c.z.h.p.HikariPool [WARN ] - HikariPool-1 - Thread starvation or clock leap detected (housekeeper delta=1m338ms731µs266ns).
.18 04:54:50.352 86257 127889.1FC34740 {scheduler} logfile /home/scheduler/sos-berlin.com/jobscheduler/scheduler/logs/order.オーダーログ名.log opened (append=0, append_for_cache=0)
.18 04:54:50.352 0 127889.1FC34740 {scheduler} sos::scheduler::database::Transaction::execute UPDATE SCHEDULER_ORDERS set "DISTRIBUTED_NEXT_TIME"=NULL,"INITIAL_STATE"='contract_start',"MOD_TIME"={ts'2020-08-17 19:54:50'},"STATE"='contract_start' where "OCCUPYING_CLUSTER_MEMBER_ID" IS NULL and "JOB_CHAIN"='ジョブチェイン名' and "ID"='contract_start' and "SPOOLER_ID"='scheduler' (sos::scheduler::order::Order::db_update2)
.18 04:54:58.926 8574 127889.1FC34740 .mkstemp("/tmp/scheduler/sos.XXXXXX") => 273 /tmp/scheduler/sos.oxSnch
.18 04:54:58.926 c.z.h.p.HikariPool [WARN ] - HikariPool-1 - Thread starvation or clock leap detected (housekeeper delta=1m3s231ms129µs731ns).
.18 04:54:58.926 0 127889.1FC34740 close(273) /tmp/scheduler/sos.oxSnch
.18 04:55:13.482 14556 127889.1FC34740 unlink("/tmp/scheduler/sos.oxSnch")
.18 04:57:12.190 118708 127889.1FC34740 [xc.insert 1, "java.lang.NullPointerException"]
.18 04:57:12.190 0 127889.1FC34740 [xc.insert 2, "CallObjectMethodA"]
.18 04:57:18.025 5835 127889.1FC34740 Exception SCHEDULER-306 Error when updating table SCHEDULER_ORDERS: Z-JAVA-105 Java exception java.lang.NullPointerException, method=CallObjectMethodA []
.18 04:57:18.029 4 127889.1FC34740 {scheduler} sos::scheduler::database::Transaction::execute ROLLBACK (sos::scheduler::database::Retry_nested_transaction::reopen_database_after_error, sos::scheduler::order::Order::db_update2)
.18 04:57:58.512 40483 127889.1FC34740 ~Sos_database_session() id=spooler db=jdbc:mysql://127.0.0.1:3306/scheduler user=scheduler cmd=ROLLBACK open_mode=3 ref=0
.18 04:57:58.513 1 127889.1FC34740 .[xc.insert "Datei file:/home/scheduler/sos-berlin.com/jobscheduler/scheduler/config/sos.ini"]
.18 04:57:58.513 0 127889.1FC34740 .[xc.insert "Datei file:/home/scheduler/sos-berlin.com/jobscheduler/scheduler/config/sos.ini"]
.18 04:57:58.513 0 127889.1FC34740 .[xc.insert "Datei file:/home/scheduler/sos-berlin.com/jobscheduler/scheduler/config/sos.ini"]
.18 04:57:58.513 0 127889.1FC34740 .(Letzte Zeile wiederholt sich 2 mal)
.18 04:57:58.513 0 127889.1FC34740 .[xc.insert 1, "java.lang.NullPointerException"]
.18 04:57:58.513 0 127889.1FC34740 .[xc.insert 2, "newInstance"]
.18 04:57:58.513 0 127889.1FC34740 .[xc.insert 3, "org.mariadb.jdbc.Driver"]
.18 04:57:58.513 0 127889.1FC34740 ~Sos_database_session() id=spooler db=jdbc:mysql://127.0.0.1:3306/scheduler user=scheduler cmd= open_mode=3 ref=0
Chronyd は slew モードで起動しているため、時間が遡行することは考えにくい状態ですが、vmware上で実行していることもあり（Hostとの時刻同期はOffです）追加で調査を行います。
お気づきの点がありましたら ご指摘いただけますと幸いです。
---
小林
お気づきの点がありましたら ご指摘いただけますと幸いです。
---
小林
2020年8月13日木曜日 12:41:04 UTC+9 koba...@gmail.com:
Satoru Funai
Aug 19, 2020, 5:14:24 AM8/19/20
to koba...@gmail.com, 日本JobSchedulerユーザーグループ（JJUG）
小林さん
原因かどうかわかりませんが、一般的にMySQL JDBCドライバの対話型セッションのタイムアウトは、デフォルトで８時間となっており、その間にDBクエリがなかった場合接続できなくなります。
タイムアウト値は、下記SQLで確認できます。
mysql> show global variables like 'wait_timeout';
+---------------+-------+
| Variable_name | Value |
+---------------+-------+
| wait_timeout | 28800 |
+---------------+-------+
（単位は秒）
これを防止するには、タイムアウト値を十分大きな値（例：２４時間）にするか、８時間より短い間隔で定期的にDBにクエリをかけるジョブを作成する方法があります。
MySQLのタイムアウト値を稼働中に変更するには下記の方法となります。
mysql> set global wait_timeout=秒数;
my.cnf に書く場合、
[mysqld]
wait_timeout = 秒数
上記の問題があるため、弊社ではPostgresを推奨しています。
船井
----- 元のメッセージ -----
> 件名: Re: JobScheduler プロセス障害
> (COM-80020009 DISP_E_EXCEPTION [] [Z -JAVA-105 Java exception
> https://groups.google.com/d/msgid/jobscheduler-ja/576b97bd-9930-440d-868b-5d3f114f36b7n%40googlegroups.com
> にアクセスしてください。
>
原因かどうかわかりませんが、一般的にMySQL JDBCドライバの対話型セッションのタイムアウトは、デフォルトで８時間となっており、その間にDBクエリがなかった場合接続できなくなります。
タイムアウト値は、下記SQLで確認できます。
mysql> show global variables like 'wait_timeout';
+---------------+-------+
| Variable_name | Value |
+---------------+-------+
| wait_timeout | 28800 |
+---------------+-------+
（単位は秒）
これを防止するには、タイムアウト値を十分大きな値（例：２４時間）にするか、８時間より短い間隔で定期的にDBにクエリをかけるジョブを作成する方法があります。
MySQLのタイムアウト値を稼働中に変更するには下記の方法となります。
mysql> set global wait_timeout=秒数;
my.cnf に書く場合、
[mysqld]
wait_timeout = 秒数
上記の問題があるため、弊社ではPostgresを推奨しています。
船井
----- 元のメッセージ -----
> 差出人: "koba...@gmail.com" <koba...@gmail.com>
> 宛先: "日本JobSchedulerユーザーグループ（JJUG）" <jobsche...@googlegroups.com>
> 送信済み: 2020年8月18日, 火曜日 午後 2:12:22
> 宛先: "日本JobSchedulerユーザーグループ（JJUG）" <jobsche...@googlegroups.com>
> 件名: Re: JobScheduler プロセス障害
> java.lang.OutOfMemoryError: Java heap space,
> method=CallObjectMethodA [] (Calling
> sos::scheduler::com_objects::Com_spooler::Execute_xml )])
> method=CallObjectMethodA [] (Calling
> .13 00:35:59.562 0 8774.33538740 .(Letzte Zeile wiederholt sich 2
> mal)
> .13 00:35:59.562 0 8774.33538740 .[xc.insert 1,
> "java.lang.NullPointerException"]
> .13 00:35:59.562 0 8774.33538740 .[xc.insert 2, "newInstance"]
> .13 00:35:59.562 0 8774.33538740 .[xc.insert 3,
> "org.mariadb.jdbc.Driver"]
> .13 00:35:59.563 1 8774.33538740 ~Sos_database_session() id=spooler
> db=jdbc:mysql:// 127.0.0.1:3306/scheduler user=scheduler cmd=
> mal)
> .13 00:35:59.562 0 8774.33538740 .[xc.insert 1,
> "java.lang.NullPointerException"]
> .13 00:35:59.562 0 8774.33538740 .[xc.insert 2, "newInstance"]
> .13 00:35:59.562 0 8774.33538740 .[xc.insert 3,
> "org.mariadb.jdbc.Driver"]
> .13 00:35:59.563 1 8774.33538740 ~Sos_database_session() id=spooler
> にアクセスしてください。
>
koba...@gmail.com
Aug 19, 2020, 8:47:51 PM8/19/20
to 日本JobSchedulerユーザーグループ（JJUG）
船井さん
５分毎に実行されるJOBもあり、DBへの通信が発生しなくなる期間はほぼ発生しない状況です。
また、wait_time についてはすでに対策済みでした。
Welcome to the MariaDB monitor. Commands end with ; or \g.
Your MariaDB connection id is 11693
Server version: 10.2.33-MariaDB-log MariaDB Server
Copyright (c) 2000, 2018, Oracle, MariaDB Corporation Ab and others.
Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.
MariaDB [(none)]> show global variables like 'wait_timeout';
+---------------+-------+
| Variable_name | Value |
+---------------+-------+
| wait_timeout | 86400 |
+---------------+-------+
1 row in set (0.00 sec)
JDBCドライバをあえてMySQLのものにしてみるのが良いのかもしれませんね。
Web版のJOEを利用しない場合明らかにJavaHeapの上昇が少なく安定傾向にあるようです。
クライアント版のJOEの利用という選択肢もあるのですが、
Welcome to the MariaDB monitor. Commands end with ; or \g.
Your MariaDB connection id is 11693
Server version: 10.2.33-MariaDB-log MariaDB Server
Copyright (c) 2000, 2018, Oracle, MariaDB Corporation Ab and others.
Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.
MariaDB [(none)]> show global variables like 'wait_timeout';
+---------------+-------+
| Variable_name | Value |
+---------------+-------+
| wait_timeout | 86400 |
+---------------+-------+
1 row in set (0.00 sec)
JDBCドライバをあえてMySQLのものにしてみるのが良いのかもしれませんね。
Web版のJOEを利用しない場合明らかにJavaHeapの上昇が少なく安定傾向にあるようです。
クライアント版のJOEの利用という選択肢もあるのですが、
SFTP経由ですとせっかくの監査情報が取得できなくなるため踏ん切りがつかない状況です。
---
小林
---
小林
2020年8月19日水曜日 18:14:24 UTC+9 satoruf:
Reply all
Reply to author
Forward
0 new messages