Project

General

Profile

操作問い合わせ #2535

ジョブが実行されない

Added by Anonymous about 2 years ago. Updated over 1 year ago.

Status:
終了
Priority:
高め
Assignee:
-
Start date:
04/19/2017
Due date:
% Done:

0%

Estimated time:

Description

ご担当者様

本件、確認させて頂きたい事項がございます。
インストールマニュアルに沿い、ジョブサーバ、ジョブエージェント、ジョブマネージャの設定を実施致しました。
しかしながら、肝心のジョブアイコンのところで止まってしまい、テスト実行、即時実行、保留実行も動作しない状態です。

・ジョブサーバ V3.0.0(以下設定値のみ抜粋)
Include=/etc/zabbix/zabbix_server.conf
TmpDir=/var/lib/jobarranger/tmp
DBHost=localhost #DBはlocalhostで構成されている事は確認済み。後述します。
DBName=利用DB名
DBUser=DBユーザ名
DBpassword=利用DBパスワード
DBPort=3306
SourceIP=ZabbixのIPと同一(同一サーバの為)
DebugLevel=3
LogFileSize=512
JaLogFile=/var/log/jobarranger/jobarg_server.log
JaPidFile=/var/run/jobarranger/jobarg_server.pid
JaExtjobPath=/etc/jobarranger/extendedjob
JaErrorCmdPath=/etc/jobarranger/alert
JaLogMessageFile=/etc/jobarranger/locale/logmessage_64BIT.txt
JaZabbixVersion=3 #Zabbix Ver3.0.2
JaZabbixMessageFile=/etc/jobarranger/locale

・ジョブエージェント Ver3.0.0
Include=/etc/zabbix/zabbix_agentd.conf
TmpDir=/var/lib/jobarranger/tmp
Server=ZabbixサーバIP(ジョブサーバと同一)を指定
Hostname=エージェント側のZabbixに登録している同一名を登録
AllowRoot=1 #rebootをタスクとして発生させることを想定している為
Timeout=40
DebugLevel=3
LogFileSize=512
JaLogFile=/var/log/jobarranger/jobarg_agentd.log
JaPidFile=/var/run/jobarranger/jobarg_agentd.pid
JaServerPort=10061
JaListenPort=10055
JaSendRetry=30
JaDatabaseFile=/var/lib/jobarranger/jobarg_agentd.db
JaJobHistory=30
JaBackupTime=24
JaExtjobPath=/etc/jobarranger/extendedjob

・ジョブマネージャ
ODBCの設定をし、ログイン可能。
ジョブを作成する際にZabbixに登録されているホスト名を正常に引っ張れている事から
DBを正確に参照している事は確認済み。

上記内容の設定でジョブを
START<--->REBOOT<--->ENDで実施したところREBOOTで止まってしまいます。
タイムアウトも発生しない状態です。

尚Server側のlogとしてはテスト実行やechoさせるコマンドなどを作成致しましたが反映されず、強制的に終了した際のlogのみ残っております。
jobarg_server [30833]: Is this process already running? Could not lock PID file [/var/run/jobarranger/jobarg_server.pid]: [11] Resource temporarily unavailable
1740:20170418:152119.085 [WARN] slow query: 433.814877 sec, "delete from ja_send_message_table where send_status = 1 and send_date <= 20170417151459"
1725:20170418:182716.970 [INFO] [JAJOBNET000001] In jajobnet_kill() jobnet was forced to stop. inner_jobnet_id: 1500000000000000006, jobnet_id: JOBNET_2, user_name: Admin

尚、Agent側では開始された、というlogのみ出力されております。
4554:20170418:193225.042 [WARN] Got signal [signal:15(SIGTERM),sender_pid:8128,sender_uid:0,reason:0]. Exiting ...
4553:20170418:193225.043 [WARN] Got signal [signal:15(SIGTERM),sender_pid:8128,sender_uid:0,reason:0]. Exiting ...
4551:20170418:193225.046 [CRIT] One child process died (PID:4554,exitcode/signal:19). Exiting ...
4551:20170418:193227.046 [INFO] Job Arranger Agent stopped. Job Arranger 3.0.0 (revision 7065).
2951:20170419:094925.842 [INFO] Starting Job Arranger Agent. Job Arranger 3.0.0 (revision 7065).
2951:20170419:094925.865 [INFO] open the database. filename: /var/lib/jobarranger/jobarg_agentd.db
2951:20170419:094925.924 [INFO] In ja_jobdb_init() : not alter table jobs add column
2960:20170419:094925.925 [INFO] jobarg_agentd #1 started [listener]
2959:20170419:094925.925 [INFO] jobarg_agentd #0 started [executive]

上記内容をご確認頂き、なにか設定に誤りなどがございますでしょうか。

jobarranger_0424.txt (1.22 MB) jobarranger_0424.txt 全体logです。 Anonymous, 04/24/2017 04:37 PM
log_0501.txt (52.8 KB) log_0501.txt Anonymous, 05/01/2017 12:46 PM

History

#1 Updated by 保守サポート 担当 about 2 years ago

  • Status changed from 新規登録 to 回答中

ジョブアレンジャーのご利用ありがとうございます。

しかしながら、肝心のジョブアイコンのところで止まってしまい、テスト実行、即時実行、保留実行も動作しない状態です。

ja_host_lock_table に当該ホストのデータが残っていませんでしょうか。
ありましたら削除してください。

START<--->REBOOT<--->ENDで実施したところREBOOTで止まってしまいます。

jobarg-agentdの再起動設定はされていますでしょうか?ご確認ください。

速やかな返信のためにサポート契約をご検討頂ければ幸甚です。
宜しくお願い致します。

#2 Updated by Anonymous about 2 years ago

たまにくるひとです。

jobarg_server [30833]: Is this process already running? Could not lock PID file [/var/run/jobarranger/jobarg_server.pid]: [11] Resource temporarily unavailable

この内容はOSをrebootするときにDBよりJob Arranagerが先に実行されていることでは?
もっとログが欲しいですね。。

Server logをDebugにするとよい情報が取れますよ。

#3 Updated by Anonymous about 2 years ago

保守サポート様
#1については確認し、lock_tableには該当データが残ってはいない様に見受けられました。

再起動設定というのはどの設定でしょうか。為念確認させて頂ければと存じます。
ちなみにrebootのジョブアイコンの中は監視している端末であることを確認しております。
設定もジョブネットの画面より設定を実施しております。

#2 様
debugレベルでlogを採取しました。
少し長くなってしまったのでtail 500で採取しております。

何か問題点等、知見がございましたらご教授頂きたく存じます。
[root@ZABBIX jobarranger]# tail -500 jobarg_server.log
12084:20170424:162422.650 [DEBUG] In get_purge_date(60)
12084:20170424:162422.650 [DEBUG] In get_purge_date(43200)
12084:20170424:162422.650 [DEBUG] In jobnet_purge(201704241524)
12084:20170424:162422.650 [DEBUG] query [txnlev:0] [select inner_jobnet_id, jobnet_id, update_date, status from ja_run_jobnet_summary_table where end_time <= 20170424152459 and status in(3, 5)]
12084:20170424:162422.650 [DEBUG] jobnet boot #1 (jobnet purge) spent 0.000280 seconds while processing rules
12084:20170424:162422.650 [DEBUG] In joblog_purge(201703251624)
12084:20170424:162422.651 [DEBUG] query [txnlev:0] [select inner_jobnet_main_id from ja_run_log_table where log_date <= 20170325162459999 group by inner_jobnet_main_id]
12084:20170424:162422.651 [DEBUG] jobnet boot #1 (joblog purge) spent 0.000273 seconds while processing rules
12084:20170424:162422.651 [DEBUG] In jobnet_boot(201704241624)
12084:20170424:162422.651 [DEBUG] query [txnlev:0] [select inner_jobnet_id, run_type, scheduled_time, jobnet_id, update_date, multiple_start_up, load_status, start_pending_flag from ja_run_jobnet_summary_table where status = 0 and start_pending_flag != 1 and (scheduled_time <= 201704241624 or scheduled_time = 0) order by scheduled_time, inner_jobnet_id]
12084:20170424:162422.651 [DEBUG] jobnet boot #1 (jobnet start) spent 0.000262 seconds while processing rules
12084:20170424:162422.651 [DEBUG] sleeping for 1 seconds
12086:20170424:162422.877 [DEBUG] In ja_collect_selfmon_stats()
12086:20170424:162422.877 [DEBUG] End of ja_collect_selfmon_stats()
12086:20170424:162422.877 [DEBUG] sleeping for 1 seconds
12075:20170424:162423.404 [DEBUG] query [txnlev:0] [select inner_jobnet_id, status, jobnet_abort_flag from ja_run_jobnet_summary_table where status in (1, 2)]
12075:20170424:162423.404 [DEBUG] In process_jajobnet_summary() ja_run_jobnet_summary_table(status): 0.000466 sec.
12075:20170424:162423.404 [DEBUG] End of process_jajobnet_summary()
12075:20170424:162423.404 [DEBUG] query [txnlev:0] [select inner_jobnet_id, inner_job_id, timeout_flag, status from ja_run_jobnet_table where status in (1, 2 ,4)]
12075:20170424:162423.405 [DEBUG] In process_jajobnet() ja_run_jobnet_table(status): 0.000205 sec.
12075:20170424:162423.405 [DEBUG] End of process_jajobnet()
12075:20170424:162423.405 [DEBUG] sleeping for 1 seconds
12076:20170424:162423.515 [DEBUG] query [txnlev:0] [select inner_job_id, inner_jobnet_id, method_flag, job_type, test_flag from ja_run_job_table where status = 1 ]
12076:20170424:162423.515 [DEBUG] In process_jarun() ja_run_job_table(status = READY): 0.000366 sec.
12076:20170424:162423.515 [DEBUG] End of process_jarun()
12076:20170424:162423.515 [DEBUG] sleeping for 1 seconds
12077:20170424:162423.594 [DEBUG] query [txnlev:0] [select inner_job_id, inner_jobnet_id, job_type, method_flag, timeout_flag, start_time from ja_run_job_table where status = 2]
12077:20170424:162423.595 [DEBUG] In process_jajob() ja_run_job_table(status: RUN): 0.000340 sec.
12077:20170424:162423.595 [DEBUG] End of process_jajob()
12077:20170424:162423.595 [DEBUG] sleeping for 1 seconds
12083:20170424:162423.626 [DEBUG] In jobnet_load_immediate()
12083:20170424:162423.626 [DEBUG] query [txnlev:0] [select inner_jobnet_id, inner_job_id, update_date, run_type, scheduled_time, public_flag, jobnet_id, user_name, jobnet_name, memo, execution_user_name, multiple_start_up, initial_scheduled_time from ja_run_jobnet_table where run_type <> 0 and main_flag = 0 and status = 0]
12083:20170424:162423.626 [DEBUG] job loader #1 (immediate start) spent 0.000330 seconds while processing rules
12083:20170424:162423.626 [DEBUG] sleeping for 1 seconds
12085:20170424:162423.648 [DEBUG] In message_purge()
12085:20170424:162423.648 [DEBUG] In get_purge_date(1440)
12085:20170424:162423.648 [DEBUG] query [txnlev:1] [begin;]
12085:20170424:162423.648 [DEBUG] query [txnlev:1] [delete from ja_send_message_table where send_status = 1 and send_date <= 20170423162459]
12085:20170424:162423.648 [DEBUG] query [txnlev:1] [commit;]
12085:20170424:162423.648 [DEBUG] query [txnlev:1] [begin;]
12085:20170424:162423.649 [DEBUG] query [txnlev:1] [delete from ja_send_message_table where send_status = 3 and send_error_date <= 20170423162459]
12085:20170424:162423.649 [DEBUG] query [txnlev:1] [commit;]
12085:20170424:162423.649 [DEBUG] message send #1 (message purge) spent 0.000933 seconds while processing rules
12085:20170424:162423.649 [DEBUG] In message_send()
12085:20170424:162423.649 [DEBUG] query [txnlev:0] [select send_no, message_date, send_status, retry_count, retry_date, message_type, user_name, host_name, jobnet_id, jobnet_name, job_id, job_id_full, job_name, log_message_id, log_message from ja_send_message_table where (send_status = 0 or send_status = 2) and retry_date <= 20170424162423 order by retry_date, message_date]
12085:20170424:162423.649 [DEBUG] message send #1 (message send) spent 0.000307 seconds while processing rules
12085:20170424:162423.649 [DEBUG] sleeping for 1 seconds
12084:20170424:162423.651 [DEBUG] In get_purge_date(60)
12084:20170424:162423.651 [DEBUG] In get_purge_date(43200)
12084:20170424:162423.651 [DEBUG] In jobnet_purge(201704241524)
12084:20170424:162423.651 [DEBUG] query [txnlev:0] [select inner_jobnet_id, jobnet_id, update_date, status from ja_run_jobnet_summary_table where end_time <= 20170424152459 and status in(3, 5)]
12084:20170424:162423.652 [DEBUG] jobnet boot #1 (jobnet purge) spent 0.000313 seconds while processing rules
12084:20170424:162423.652 [DEBUG] In joblog_purge(201703251624)
12084:20170424:162423.652 [DEBUG] query [txnlev:0] [select inner_jobnet_main_id from ja_run_log_table where log_date <= 20170325162459999 group by inner_jobnet_main_id]
12084:20170424:162423.652 [DEBUG] jobnet boot #1 (joblog purge) spent 0.000264 seconds while processing rules
12084:20170424:162423.652 [DEBUG] In jobnet_boot(201704241624)
12084:20170424:162423.652 [DEBUG] query [txnlev:0] [select inner_jobnet_id, run_type, scheduled_time, jobnet_id, update_date, multiple_start_up, load_status, start_pending_flag from ja_run_jobnet_summary_table where status = 0 and start_pending_flag != 1 and (scheduled_time <= 201704241624 or scheduled_time = 0) order by scheduled_time, inner_jobnet_id]
12084:20170424:162423.652 [DEBUG] jobnet boot #1 (jobnet start) spent 0.000264 seconds while processing rules
12084:20170424:162423.652 [DEBUG] sleeping for 1 seconds
12086:20170424:162423.877 [DEBUG] In ja_collect_selfmon_stats()
12086:20170424:162423.877 [DEBUG] End of ja_collect_selfmon_stats()
12086:20170424:162423.877 [DEBUG] sleeping for 1 seconds
12075:20170424:162424.405 [DEBUG] query [txnlev:0] [select inner_jobnet_id, status, jobnet_abort_flag from ja_run_jobnet_summary_table where status in (1, 2)]
12075:20170424:162424.405 [DEBUG] In process_jajobnet_summary() ja_run_jobnet_summary_table(status): 0.000561 sec.
12075:20170424:162424.405 [DEBUG] End of process_jajobnet_summary()
12075:20170424:162424.405 [DEBUG] query [txnlev:0] [select inner_jobnet_id, inner_job_id, timeout_flag, status from ja_run_jobnet_table where status in (1, 2 ,4)]
12075:20170424:162424.406 [DEBUG] In process_jajobnet() ja_run_jobnet_table(status): 0.000252 sec.
12075:20170424:162424.406 [DEBUG] End of process_jajobnet()
12075:20170424:162424.406 [DEBUG] sleeping for 1 seconds
12076:20170424:162424.515 [DEBUG] query [txnlev:0] [select inner_job_id, inner_jobnet_id, method_flag, job_type, test_flag from ja_run_job_table where status = 1 ]
12076:20170424:162424.516 [DEBUG] In process_jarun() ja_run_job_table(status = READY): 0.000551 sec.
12076:20170424:162424.516 [DEBUG] End of process_jarun()
12076:20170424:162424.516 [DEBUG] sleeping for 1 seconds
12077:20170424:162424.595 [DEBUG] query [txnlev:0] [select inner_job_id, inner_jobnet_id, job_type, method_flag, timeout_flag, start_time from ja_run_job_table where status = 2]
12077:20170424:162424.596 [DEBUG] In process_jajob() ja_run_job_table(status: RUN): 0.000485 sec.
12077:20170424:162424.596 [DEBUG] End of process_jajob()
12077:20170424:162424.596 [DEBUG] sleeping for 1 seconds
12083:20170424:162424.626 [DEBUG] In jobnet_load_immediate()
12083:20170424:162424.626 [DEBUG] query [txnlev:0] [select inner_jobnet_id, inner_job_id, update_date, run_type, scheduled_time, public_flag, jobnet_id, user_name, jobnet_name, memo, execution_user_name, multiple_start_up, initial_scheduled_time from ja_run_jobnet_table where run_type <> 0 and main_flag = 0 and status = 0]
12083:20170424:162424.627 [DEBUG] job loader #1 (immediate start) spent 0.000414 seconds while processing rules
12083:20170424:162424.627 [DEBUG] sleeping for 1 seconds
12085:20170424:162424.649 [DEBUG] In message_purge()
12085:20170424:162424.649 [DEBUG] In get_purge_date(1440)
12085:20170424:162424.650 [DEBUG] query [txnlev:1] [begin;]
12085:20170424:162424.650 [DEBUG] query [txnlev:1] [delete from ja_send_message_table where send_status = 1 and send_date <= 20170423162459]
12085:20170424:162424.650 [DEBUG] query [txnlev:1] [commit;]
12085:20170424:162424.650 [DEBUG] query [txnlev:1] [begin;]
12085:20170424:162424.650 [DEBUG] query [txnlev:1] [delete from ja_send_message_table where send_status = 3 and send_error_date <= 20170423162459]
12085:20170424:162424.650 [DEBUG] query [txnlev:1] [commit;]
12085:20170424:162424.650 [DEBUG] message send #1 (message purge) spent 0.000943 seconds while processing rules
12085:20170424:162424.650 [DEBUG] In message_send()
12085:20170424:162424.650 [DEBUG] query [txnlev:0] [select send_no, message_date, send_status, retry_count, retry_date, message_type, user_name, host_name, jobnet_id, jobnet_name, job_id, job_id_full, job_name, log_message_id, log_message from ja_send_message_table where (send_status = 0 or send_status = 2) and retry_date <= 20170424162424 order by retry_date, message_date]
12085:20170424:162424.651 [DEBUG] message send #1 (message send) spent 0.000334 seconds while processing rules
12085:20170424:162424.651 [DEBUG] sleeping for 1 seconds
12084:20170424:162424.653 [DEBUG] In get_purge_date(60)
12084:20170424:162424.653 [DEBUG] In get_purge_date(43200)
12084:20170424:162424.653 [DEBUG] In jobnet_purge(201704241524)
12084:20170424:162424.653 [DEBUG] query [txnlev:0] [select inner_jobnet_id, jobnet_id, update_date, status from ja_run_jobnet_summary_table where end_time <= 20170424152459 and status in(3, 5)]
12084:20170424:162424.653 [DEBUG] jobnet boot #1 (jobnet purge) spent 0.000320 seconds while processing rules
12084:20170424:162424.653 [DEBUG] In joblog_purge(201703251624)
12084:20170424:162424.653 [DEBUG] query [txnlev:0] [select inner_jobnet_main_id from ja_run_log_table where log_date <= 20170325162459999 group by inner_jobnet_main_id]
12084:20170424:162424.653 [DEBUG] jobnet boot #1 (joblog purge) spent 0.000263 seconds while processing rules
12084:20170424:162424.653 [DEBUG] In jobnet_boot(201704241624)
12084:20170424:162424.653 [DEBUG] query [txnlev:0] [select inner_jobnet_id, run_type, scheduled_time, jobnet_id, update_date, multiple_start_up, load_status, start_pending_flag from ja_run_jobnet_summary_table where status = 0 and start_pending_flag != 1 and (scheduled_time <= 201704241624 or scheduled_time = 0) order by scheduled_time, inner_jobnet_id]
12084:20170424:162424.654 [DEBUG] jobnet boot #1 (jobnet start) spent 0.000265 seconds while processing rules
12084:20170424:162424.654 [DEBUG] sleeping for 1 seconds
12086:20170424:162424.877 [DEBUG] In ja_collect_selfmon_stats()
12086:20170424:162424.877 [DEBUG] End of ja_collect_selfmon_stats()
12086:20170424:162424.877 [DEBUG] sleeping for 1 seconds
12075:20170424:162425.406 [DEBUG] query [txnlev:0] [select inner_jobnet_id, status, jobnet_abort_flag from ja_run_jobnet_summary_table where status in (1, 2)]
12075:20170424:162425.407 [DEBUG] In process_jajobnet_summary() ja_run_jobnet_summary_table(status): 0.000529 sec.
12075:20170424:162425.407 [DEBUG] End of process_jajobnet_summary()
12075:20170424:162425.407 [DEBUG] query [txnlev:0] [select inner_jobnet_id, inner_job_id, timeout_flag, status from ja_run_jobnet_table where status in (1, 2 ,4)]
12075:20170424:162425.407 [DEBUG] In process_jajobnet() ja_run_jobnet_table(status): 0.000208 sec.
12075:20170424:162425.407 [DEBUG] End of process_jajobnet()
12075:20170424:162425.407 [DEBUG] sleeping for 1 seconds
12076:20170424:162425.516 [DEBUG] query [txnlev:0] [select inner_job_id, inner_jobnet_id, method_flag, job_type, test_flag from ja_run_job_table where status = 1 ]
12076:20170424:162425.517 [DEBUG] In process_jarun() ja_run_job_table(status = READY): 0.000376 sec.
12076:20170424:162425.517 [DEBUG] End of process_jarun()
12076:20170424:162425.517 [DEBUG] sleeping for 1 seconds
12077:20170424:162425.596 [DEBUG] query [txnlev:0] [select inner_job_id, inner_jobnet_id, job_type, method_flag, timeout_flag, start_time from ja_run_job_table where status = 2]
12077:20170424:162425.596 [DEBUG] In process_jajob() ja_run_job_table(status: RUN): 0.000284 sec.
12077:20170424:162425.596 [DEBUG] End of process_jajob()
12077:20170424:162425.596 [DEBUG] sleeping for 1 seconds
12083:20170424:162425.627 [DEBUG] In jobnet_load_immediate()
12083:20170424:162425.627 [DEBUG] query [txnlev:0] [select inner_jobnet_id, inner_job_id, update_date, run_type, scheduled_time, public_flag, jobnet_id, user_name, jobnet_name, memo, execution_user_name, multiple_start_up, initial_scheduled_time from ja_run_jobnet_table where run_type <> 0 and main_flag = 0 and status = 0]
12083:20170424:162425.627 [DEBUG] job loader #1 (immediate start) spent 0.000328 seconds while processing rules
12083:20170424:162425.627 [DEBUG] sleeping for 1 seconds
12085:20170424:162425.651 [DEBUG] In message_purge()
12085:20170424:162425.651 [DEBUG] In get_purge_date(1440)
12085:20170424:162425.651 [DEBUG] query [txnlev:1] [begin;]
12085:20170424:162425.651 [DEBUG] query [txnlev:1] [delete from ja_send_message_table where send_status = 1 and send_date <= 20170423162459]
12085:20170424:162425.651 [DEBUG] query [txnlev:1] [commit;]
12085:20170424:162425.651 [DEBUG] query [txnlev:1] [begin;]
12085:20170424:162425.652 [DEBUG] query [txnlev:1] [delete from ja_send_message_table where send_status = 3 and send_error_date <= 20170423162459]
12085:20170424:162425.652 [DEBUG] query [txnlev:1] [commit;]
12085:20170424:162425.652 [DEBUG] message send #1 (message purge) spent 0.000926 seconds while processing rules
12085:20170424:162425.652 [DEBUG] In message_send()
12085:20170424:162425.652 [DEBUG] query [txnlev:0] [select send_no, message_date, send_status, retry_count, retry_date, message_type, user_name, host_name, jobnet_id, jobnet_name, job_id, job_id_full, job_name, log_message_id, log_message from ja_send_message_table where (send_status = 0 or send_status = 2) and retry_date <= 20170424162425 order by retry_date, message_date]
12085:20170424:162425.652 [DEBUG] message send #1 (message send) spent 0.000294 seconds while processing rules
12085:20170424:162425.652 [DEBUG] sleeping for 1 seconds
12084:20170424:162425.654 [DEBUG] In get_purge_date(60)
12084:20170424:162425.654 [DEBUG] In get_purge_date(43200)
12084:20170424:162425.654 [DEBUG] In jobnet_purge(201704241524)
12084:20170424:162425.654 [DEBUG] query [txnlev:0] [select inner_jobnet_id, jobnet_id, update_date, status from ja_run_jobnet_summary_table where end_time <= 20170424152459 and status in(3, 5)]
12084:20170424:162425.654 [DEBUG] jobnet boot #1 (jobnet purge) spent 0.000285 seconds while processing rules
12084:20170424:162425.654 [DEBUG] In joblog_purge(201703251624)
12084:20170424:162425.654 [DEBUG] query [txnlev:0] [select inner_jobnet_main_id from ja_run_log_table where log_date <= 20170325162459999 group by inner_jobnet_main_id]
12084:20170424:162425.654 [DEBUG] jobnet boot #1 (joblog purge) spent 0.000262 seconds while processing rules
12084:20170424:162425.654 [DEBUG] In jobnet_boot(201704241624)
12084:20170424:162425.654 [DEBUG] query [txnlev:0] [select inner_jobnet_id, run_type, scheduled_time, jobnet_id, update_date, multiple_start_up, load_status, start_pending_flag from ja_run_jobnet_summary_table where status = 0 and start_pending_flag != 1 and (scheduled_time <= 201704241624 or scheduled_time = 0) order by scheduled_time, inner_jobnet_id]
12084:20170424:162425.655 [DEBUG] jobnet boot #1 (jobnet start) spent 0.000290 seconds while processing rules
12084:20170424:162425.655 [DEBUG] sleeping for 1 seconds
12086:20170424:162425.878 [DEBUG] In ja_collect_selfmon_stats()
12086:20170424:162425.878 [DEBUG] End of ja_collect_selfmon_stats()
12086:20170424:162425.878 [DEBUG] sleeping for 1 seconds
12075:20170424:162426.407 [DEBUG] query [txnlev:0] [select inner_jobnet_id, status, jobnet_abort_flag from ja_run_jobnet_summary_table where status in (1, 2)]
12075:20170424:162426.408 [DEBUG] In process_jajobnet_summary() ja_run_jobnet_summary_table(status): 0.001074 sec.
12075:20170424:162426.408 [DEBUG] End of process_jajobnet_summary()
12075:20170424:162426.408 [DEBUG] query [txnlev:0] [select inner_jobnet_id, inner_job_id, timeout_flag, status from ja_run_jobnet_table where status in (1, 2 ,4)]
12075:20170424:162426.408 [DEBUG] In process_jajobnet() ja_run_jobnet_table(status): 0.000232 sec.
12075:20170424:162426.408 [DEBUG] End of process_jajobnet()
12075:20170424:162426.409 [DEBUG] sleeping for 1 seconds
12076:20170424:162426.517 [DEBUG] query [txnlev:0] [select inner_job_id, inner_jobnet_id, method_flag, job_type, test_flag from ja_run_job_table where status = 1 ]
12076:20170424:162426.517 [DEBUG] In process_jarun() ja_run_job_table(status = READY): 0.000288 sec.
12076:20170424:162426.517 [DEBUG] End of process_jarun()
12076:20170424:162426.517 [DEBUG] sleeping for 1 seconds
12077:20170424:162426.596 [DEBUG] query [txnlev:0] [select inner_job_id, inner_jobnet_id, job_type, method_flag, timeout_flag, start_time from ja_run_job_table where status = 2]
12077:20170424:162426.597 [DEBUG] In process_jajob() ja_run_job_table(status: RUN): 0.000332 sec.
12077:20170424:162426.597 [DEBUG] End of process_jajob()
12077:20170424:162426.597 [DEBUG] sleeping for 1 seconds
12083:20170424:162426.628 [DEBUG] In jobnet_load_immediate()
12083:20170424:162426.628 [DEBUG] query [txnlev:0] [select inner_jobnet_id, inner_job_id, update_date, run_type, scheduled_time, public_flag, jobnet_id, user_name, jobnet_name, memo, execution_user_name, multiple_start_up, initial_scheduled_time from ja_run_jobnet_table where run_type <> 0 and main_flag = 0 and status = 0]
12083:20170424:162426.628 [DEBUG] job loader #1 (immediate start) spent 0.000356 seconds while processing rules
12083:20170424:162426.628 [DEBUG] sleeping for 1 seconds
12085:20170424:162426.652 [DEBUG] In message_purge()
12085:20170424:162426.652 [DEBUG] In get_purge_date(1440)
12085:20170424:162426.652 [DEBUG] query [txnlev:1] [begin;]
12085:20170424:162426.653 [DEBUG] query [txnlev:1] [delete from ja_send_message_table where send_status = 1 and send_date <= 20170423162459]
12085:20170424:162426.653 [DEBUG] query [txnlev:1] [commit;]
12085:20170424:162426.653 [DEBUG] query [txnlev:1] [begin;]
12085:20170424:162426.653 [DEBUG] query [txnlev:1] [delete from ja_send_message_table where send_status = 3 and send_error_date <= 20170423162459]
12085:20170424:162426.653 [DEBUG] query [txnlev:1] [commit;]
12085:20170424:162426.653 [DEBUG] message send #1 (message purge) spent 0.000924 seconds while processing rules
12085:20170424:162426.653 [DEBUG] In message_send()
12085:20170424:162426.653 [DEBUG] query [txnlev:0] [select send_no, message_date, send_status, retry_count, retry_date, message_type, user_name, host_name, jobnet_id, jobnet_name, job_id, job_id_full, job_name, log_message_id, log_message from ja_send_message_table where (send_status = 0 or send_status = 2) and retry_date <= 20170424162426 order by retry_date, message_date]
12085:20170424:162426.654 [DEBUG] message send #1 (message send) spent 0.000279 seconds while processing rules
12085:20170424:162426.654 [DEBUG] sleeping for 1 seconds
12084:20170424:162426.655 [DEBUG] In get_purge_date(60)
12084:20170424:162426.655 [DEBUG] In get_purge_date(43200)
12084:20170424:162426.655 [DEBUG] In jobnet_purge(201704241524)
12084:20170424:162426.655 [DEBUG] query [txnlev:0] [select inner_jobnet_id, jobnet_id, update_date, status from ja_run_jobnet_summary_table where end_time <= 20170424152459 and status in(3, 5)]
12084:20170424:162426.655 [DEBUG] jobnet boot #1 (jobnet purge) spent 0.000280 seconds while processing rules
12084:20170424:162426.655 [DEBUG] In joblog_purge(201703251624)
12084:20170424:162426.655 [DEBUG] query [txnlev:0] [select inner_jobnet_main_id from ja_run_log_table where log_date <= 20170325162459999 group by inner_jobnet_main_id]
12084:20170424:162426.656 [DEBUG] jobnet boot #1 (joblog purge) spent 0.000318 seconds while processing rules
12084:20170424:162426.656 [DEBUG] In jobnet_boot(201704241624)
12084:20170424:162426.656 [DEBUG] query [txnlev:0] [select inner_jobnet_id, run_type, scheduled_time, jobnet_id, update_date, multiple_start_up, load_status, start_pending_flag from ja_run_jobnet_summary_table where status = 0 and start_pending_flag != 1 and (scheduled_time <= 201704241624 or scheduled_time = 0) order by scheduled_time, inner_jobnet_id]
12084:20170424:162426.656 [DEBUG] jobnet boot #1 (jobnet start) spent 0.000263 seconds while processing rules
12084:20170424:162426.656 [DEBUG] sleeping for 1 seconds
12086:20170424:162426.878 [DEBUG] In ja_collect_selfmon_stats()
12086:20170424:162426.878 [DEBUG] End of ja_collect_selfmon_stats()
12086:20170424:162426.878 [DEBUG] sleeping for 1 seconds
12075:20170424:162427.409 [DEBUG] query [txnlev:0] [select inner_jobnet_id, status, jobnet_abort_flag from ja_run_jobnet_summary_table where status in (1, 2)]
12075:20170424:162427.409 [DEBUG] In process_jajobnet_summary() ja_run_jobnet_summary_table(status): 0.000298 sec.
12075:20170424:162427.409 [DEBUG] End of process_jajobnet_summary()
12075:20170424:162427.409 [DEBUG] query [txnlev:0] [select inner_jobnet_id, inner_job_id, timeout_flag, status from ja_run_jobnet_table where status in (1, 2 ,4)]
12075:20170424:162427.409 [DEBUG] In process_jajobnet() ja_run_jobnet_table(status): 0.000205 sec.
12075:20170424:162427.409 [DEBUG] End of process_jajobnet()
12075:20170424:162427.409 [DEBUG] sleeping for 1 seconds
12076:20170424:162427.517 [DEBUG] query [txnlev:0] [select inner_job_id, inner_jobnet_id, method_flag, job_type, test_flag from ja_run_job_table where status = 1 ]
12076:20170424:162427.518 [DEBUG] In process_jarun() ja_run_job_table(status = READY): 0.000291 sec.
12076:20170424:162427.518 [DEBUG] End of process_jarun()
12076:20170424:162427.518 [DEBUG] sleeping for 1 seconds
12077:20170424:162427.597 [DEBUG] query [txnlev:0] [select inner_job_id, inner_jobnet_id, job_type, method_flag, timeout_flag, start_time from ja_run_job_table where status = 2]
12077:20170424:162427.597 [DEBUG] In process_jajob() ja_run_job_table(status: RUN): 0.000326 sec.
12077:20170424:162427.597 [DEBUG] End of process_jajob()
12077:20170424:162427.597 [DEBUG] sleeping for 1 seconds
12083:20170424:162427.628 [DEBUG] In jobnet_load_immediate()
12083:20170424:162427.628 [DEBUG] query [txnlev:0] [select inner_jobnet_id, inner_job_id, update_date, run_type, scheduled_time, public_flag, jobnet_id, user_name, jobnet_name, memo, execution_user_name, multiple_start_up, initial_scheduled_time from ja_run_jobnet_table where run_type <> 0 and main_flag = 0 and status = 0]
12083:20170424:162427.628 [DEBUG] job loader #1 (immediate start) spent 0.000336 seconds while processing rules
12083:20170424:162427.628 [DEBUG] sleeping for 1 seconds
12085:20170424:162427.654 [DEBUG] In message_purge()
12085:20170424:162427.654 [DEBUG] In get_purge_date(1440)
12085:20170424:162427.654 [DEBUG] query [txnlev:1] [begin;]
12085:20170424:162427.654 [DEBUG] query [txnlev:1] [delete from ja_send_message_table where send_status = 1 and send_date <= 20170423162459]
12085:20170424:162427.654 [DEBUG] query [txnlev:1] [commit;]
12085:20170424:162427.654 [DEBUG] query [txnlev:1] [begin;]
12085:20170424:162427.654 [DEBUG] query [txnlev:1] [delete from ja_send_message_table where send_status = 3 and send_error_date <= 20170423162459]
12085:20170424:162427.655 [DEBUG] query [txnlev:1] [commit;]
12085:20170424:162427.655 [DEBUG] message send #1 (message purge) spent 0.000937 seconds while processing rules
12085:20170424:162427.655 [DEBUG] In message_send()
12085:20170424:162427.655 [DEBUG] query [txnlev:0] [select send_no, message_date, send_status, retry_count, retry_date, message_type, user_name, host_name, jobnet_id, jobnet_name, job_id, job_id_full, job_name, log_message_id, log_message from ja_send_message_table where (send_status = 0 or send_status = 2) and retry_date <= 20170424162427 order by retry_date, message_date]
12085:20170424:162427.655 [DEBUG] message send #1 (message send) spent 0.000296 seconds while processing rules
12085:20170424:162427.655 [DEBUG] sleeping for 1 seconds
12084:20170424:162427.656 [DEBUG] In get_purge_date(60)
12084:20170424:162427.656 [DEBUG] In get_purge_date(43200)
12084:20170424:162427.656 [DEBUG] In jobnet_purge(201704241524)
12084:20170424:162427.656 [DEBUG] query [txnlev:0] [select inner_jobnet_id, jobnet_id, update_date, status from ja_run_jobnet_summary_table where end_time <= 20170424152459 and status in(3, 5)]
12084:20170424:162427.657 [DEBUG] jobnet boot #1 (jobnet purge) spent 0.000276 seconds while processing rules
12084:20170424:162427.657 [DEBUG] In joblog_purge(201703251624)
12084:20170424:162427.657 [DEBUG] query [txnlev:0] [select inner_jobnet_main_id from ja_run_log_table where log_date <= 20170325162459999 group by inner_jobnet_main_id]
12084:20170424:162427.657 [DEBUG] jobnet boot #1 (joblog purge) spent 0.000265 seconds while processing rules
12084:20170424:162427.657 [DEBUG] In jobnet_boot(201704241624)
12084:20170424:162427.657 [DEBUG] query [txnlev:0] [select inner_jobnet_id, run_type, scheduled_time, jobnet_id, update_date, multiple_start_up, load_status, start_pending_flag from ja_run_jobnet_summary_table where status = 0 and start_pending_flag != 1 and (scheduled_time <= 201704241624 or scheduled_time = 0) order by scheduled_time, inner_jobnet_id]
12084:20170424:162427.657 [DEBUG] jobnet boot #1 (jobnet start) spent 0.000263 seconds while processing rules
12084:20170424:162427.657 [DEBUG] sleeping for 1 seconds
12086:20170424:162427.878 [DEBUG] In ja_collect_selfmon_stats()
12086:20170424:162427.878 [DEBUG] End of ja_collect_selfmon_stats()
12086:20170424:162427.878 [DEBUG] sleeping for 1 seconds
12075:20170424:162428.410 [DEBUG] query [txnlev:0] [select inner_jobnet_id, status, jobnet_abort_flag from ja_run_jobnet_summary_table where status in (1, 2)]
12075:20170424:162428.410 [DEBUG] In process_jajobnet_summary() ja_run_jobnet_summary_table(status): 0.000559 sec.
12075:20170424:162428.410 [DEBUG] End of process_jajobnet_summary()
12075:20170424:162428.410 [DEBUG] query [txnlev:0] [select inner_jobnet_id, inner_job_id, timeout_flag, status from ja_run_jobnet_table where status in (1, 2 ,4)]
12075:20170424:162428.410 [DEBUG] In process_jajobnet() ja_run_jobnet_table(status): 0.000210 sec.
12075:20170424:162428.410 [DEBUG] End of process_jajobnet()
12075:20170424:162428.410 [DEBUG] sleeping for 1 seconds
12076:20170424:162428.518 [DEBUG] query [txnlev:0] [select inner_job_id, inner_jobnet_id, method_flag, job_type, test_flag from ja_run_job_table where status = 1 ]
12076:20170424:162428.518 [DEBUG] In process_jarun() ja_run_job_table(status = READY): 0.000475 sec.
12076:20170424:162428.518 [DEBUG] End of process_jarun()
12076:20170424:162428.518 [DEBUG] sleeping for 1 seconds
12077:20170424:162428.597 [DEBUG] query [txnlev:0] [select inner_job_id, inner_jobnet_id, job_type, method_flag, timeout_flag, start_time from ja_run_job_table where status = 2]
12077:20170424:162428.598 [DEBUG] In process_jajob() ja_run_job_table(status: RUN): 0.000463 sec.
12077:20170424:162428.598 [DEBUG] End of process_jajob()
12077:20170424:162428.598 [DEBUG] sleeping for 1 seconds
12083:20170424:162428.629 [DEBUG] In jobnet_load_immediate()
12083:20170424:162428.629 [DEBUG] query [txnlev:0] [select inner_jobnet_id, inner_job_id, update_date, run_type, scheduled_time, public_flag, jobnet_id, user_name, jobnet_name, memo, execution_user_name, multiple_start_up, initial_scheduled_time from ja_run_jobnet_table where run_type <> 0 and main_flag = 0 and status = 0]
12083:20170424:162428.629 [DEBUG] job loader #1 (immediate start) spent 0.000323 seconds while processing rules
12083:20170424:162428.629 [DEBUG] sleeping for 1 seconds
12085:20170424:162428.655 [DEBUG] In message_purge()
12085:20170424:162428.655 [DEBUG] In get_purge_date(1440)
12085:20170424:162428.655 [DEBUG] query [txnlev:1] [begin;]
12085:20170424:162428.656 [DEBUG] query [txnlev:1] [delete from ja_send_message_table where send_status = 1 and send_date <= 20170423162459]
12085:20170424:162428.656 [DEBUG] query [txnlev:1] [commit;]
12085:20170424:162428.656 [DEBUG] query [txnlev:1] [begin;]
12085:20170424:162428.656 [DEBUG] query [txnlev:1] [delete from ja_send_message_table where send_status = 3 and send_error_date <= 20170423162459]
12085:20170424:162428.656 [DEBUG] query [txnlev:1] [commit;]
12085:20170424:162428.656 [DEBUG] message send #1 (message purge) spent 0.000940 seconds while processing rules
12085:20170424:162428.656 [DEBUG] In message_send()
12085:20170424:162428.656 [DEBUG] query [txnlev:0] [select send_no, message_date, send_status, retry_count, retry_date, message_type, user_name, host_name, jobnet_id, jobnet_name, job_id, job_id_full, job_name, log_message_id, log_message from ja_send_message_table where (send_status = 0 or send_status = 2) and retry_date <= 20170424162428 order by retry_date, message_date]
12085:20170424:162428.657 [DEBUG] message send #1 (message send) spent 0.000278 seconds while processing rules
12085:20170424:162428.657 [DEBUG] sleeping for 1 seconds
12084:20170424:162428.657 [DEBUG] In get_purge_date(60)
12084:20170424:162428.657 [DEBUG] In get_purge_date(43200)
12084:20170424:162428.657 [DEBUG] In jobnet_purge(201704241524)
12084:20170424:162428.657 [DEBUG] query [txnlev:0] [select inner_jobnet_id, jobnet_id, update_date, status from ja_run_jobnet_summary_table where end_time <= 20170424152459 and status in(3, 5)]
12084:20170424:162428.658 [DEBUG] jobnet boot #1 (jobnet purge) spent 0.000292 seconds while processing rules
12084:20170424:162428.658 [DEBUG] In joblog_purge(201703251624)
12084:20170424:162428.658 [DEBUG] query [txnlev:0] [select inner_jobnet_main_id from ja_run_log_table where log_date <= 20170325162459999 group by inner_jobnet_main_id]
12084:20170424:162428.658 [DEBUG] jobnet boot #1 (joblog purge) spent 0.000260 seconds while processing rules
12084:20170424:162428.658 [DEBUG] In jobnet_boot(201704241624)
12084:20170424:162428.658 [DEBUG] query [txnlev:0] [select inner_jobnet_id, run_type, scheduled_time, jobnet_id, update_date, multiple_start_up, load_status, start_pending_flag from ja_run_jobnet_summary_table where status = 0 and start_pending_flag != 1 and (scheduled_time <= 201704241624 or scheduled_time = 0) order by scheduled_time, inner_jobnet_id]
12084:20170424:162428.658 [DEBUG] jobnet boot #1 (jobnet start) spent 0.000262 seconds while processing rules
12084:20170424:162428.658 [DEBUG] sleeping for 1 seconds
12086:20170424:162428.878 [DEBUG] In ja_collect_selfmon_stats()
12086:20170424:162428.879 [DEBUG] End of ja_collect_selfmon_stats()
12086:20170424:162428.879 [DEBUG] sleeping for 1 seconds
12075:20170424:162429.411 [DEBUG] query [txnlev:0] [select inner_jobnet_id, status, jobnet_abort_flag from ja_run_jobnet_summary_table where status in (1, 2)]
12075:20170424:162429.411 [DEBUG] In process_jajobnet_summary() ja_run_jobnet_summary_table(status): 0.000567 sec.
12075:20170424:162429.411 [DEBUG] End of process_jajobnet_summary()
12075:20170424:162429.411 [DEBUG] query [txnlev:0] [select inner_jobnet_id, inner_job_id, timeout_flag, status from ja_run_jobnet_table where status in (1, 2 ,4)]
12075:20170424:162429.411 [DEBUG] In process_jajobnet() ja_run_jobnet_table(status): 0.000208 sec.
12075:20170424:162429.411 [DEBUG] End of process_jajobnet()
12075:20170424:162429.411 [DEBUG] sleeping for 1 seconds
12076:20170424:162429.519 [DEBUG] query [txnlev:0] [select inner_job_id, inner_jobnet_id, method_flag, job_type, test_flag from ja_run_job_table where status = 1 ]
12076:20170424:162429.519 [DEBUG] In process_jarun() ja_run_job_table(status = READY): 0.000556 sec.
12076:20170424:162429.519 [DEBUG] End of process_jarun()
12076:20170424:162429.519 [DEBUG] sleeping for 1 seconds
12077:20170424:162429.598 [DEBUG] query [txnlev:0] [select inner_job_id, inner_jobnet_id, job_type, method_flag, timeout_flag, start_time from ja_run_job_table where status = 2]
12077:20170424:162429.599 [DEBUG] In process_jajob() ja_run_job_table(status: RUN): 0.000536 sec.
12077:20170424:162429.599 [DEBUG] End of process_jajob()
12077:20170424:162429.599 [DEBUG] sleeping for 1 seconds
12083:20170424:162429.629 [DEBUG] In jobnet_load_immediate()
12083:20170424:162429.629 [DEBUG] query [txnlev:0] [select inner_jobnet_id, inner_job_id, update_date, run_type, scheduled_time, public_flag, jobnet_id, user_name, jobnet_name, memo, execution_user_name, multiple_start_up, initial_scheduled_time from ja_run_jobnet_table where run_type <> 0 and main_flag = 0 and status = 0]
12083:20170424:162429.630 [DEBUG] job loader #1 (immediate start) spent 0.000516 seconds while processing rules
12083:20170424:162429.630 [DEBUG] sleeping for 1 seconds
12085:20170424:162429.657 [DEBUG] In message_purge()
12085:20170424:162429.657 [DEBUG] In get_purge_date(1440)
12085:20170424:162429.657 [DEBUG] query [txnlev:1] [begin;]
12085:20170424:162429.657 [DEBUG] query [txnlev:1] [delete from ja_send_message_table where send_status = 1 and send_date <= 20170423162459]
12085:20170424:162429.657 [DEBUG] query [txnlev:1] [commit;]
12085:20170424:162429.657 [DEBUG] query [txnlev:1] [begin;]
12085:20170424:162429.657 [DEBUG] query [txnlev:1] [delete from ja_send_message_table where send_status = 3 and send_error_date <= 20170423162459]
12085:20170424:162429.658 [DEBUG] query [txnlev:1] [commit;]
12085:20170424:162429.658 [DEBUG] message send #1 (message purge) spent 0.000949 seconds while processing rules
12085:20170424:162429.658 [DEBUG] In message_send()
12085:20170424:162429.658 [DEBUG] query [txnlev:0] [select send_no, message_date, send_status, retry_count, retry_date, message_type, user_name, host_name, jobnet_id, jobnet_name, job_id, job_id_full, job_name, log_message_id, log_message from ja_send_message_table where (send_status = 0 or send_status = 2) and retry_date <= 20170424162429 order by retry_date, message_date]
12085:20170424:162429.658 [DEBUG] message send #1 (message send) spent 0.000299 seconds while processing rules
12085:20170424:162429.658 [DEBUG] sleeping for 1 seconds
12084:20170424:162429.659 [DEBUG] In get_purge_date(60)
12084:20170424:162429.659 [DEBUG] In get_purge_date(43200)
12084:20170424:162429.659 [DEBUG] In jobnet_purge(201704241524)
12084:20170424:162429.659 [DEBUG] query [txnlev:0] [select inner_jobnet_id, jobnet_id, update_date, status from ja_run_jobnet_summary_table where end_time <= 20170424152459 and status in(3, 5)]
12084:20170424:162429.659 [DEBUG] jobnet boot #1 (jobnet purge) spent 0.000306 seconds while processing rules
12084:20170424:162429.659 [DEBUG] In joblog_purge(201703251624)
12084:20170424:162429.659 [DEBUG] query [txnlev:0] [select inner_jobnet_main_id from ja_run_log_table where log_date <= 20170325162459999 group by inner_jobnet_main_id]
12084:20170424:162429.659 [DEBUG] jobnet boot #1 (joblog purge) spent 0.000257 seconds while processing rules
12084:20170424:162429.659 [DEBUG] In jobnet_boot(201704241624)
12084:20170424:162429.659 [DEBUG] query [txnlev:0] [select inner_jobnet_id, run_type, scheduled_time, jobnet_id, update_date, multiple_start_up, load_status, start_pending_flag from ja_run_jobnet_summary_table where status = 0 and start_pending_flag != 1 and (scheduled_time <= 201704241624 or scheduled_time = 0) order by scheduled_time, inner_jobnet_id]
12084:20170424:162429.660 [DEBUG] jobnet boot #1 (jobnet start) spent 0.000276 seconds while processing rules
12084:20170424:162429.660 [DEBUG] sleeping for 1 seconds
12086:20170424:162429.879 [DEBUG] In ja_collect_selfmon_stats()
12086:20170424:162429.879 [DEBUG] End of ja_collect_selfmon_stats()
12086:20170424:162429.879 [DEBUG] sleeping for 1 seconds
12075:20170424:162430.412 [DEBUG] query [txnlev:0] [select inner_jobnet_id, status, jobnet_abort_flag from ja_run_jobnet_summary_table where status in (1, 2)]
12075:20170424:162430.412 [DEBUG] In process_jajobnet_summary() ja_run_jobnet_summary_table(status): 0.000547 sec.
12075:20170424:162430.412 [DEBUG] End of process_jajobnet_summary()
12075:20170424:162430.412 [DEBUG] query [txnlev:0] [select inner_jobnet_id, inner_job_id, timeout_flag, status from ja_run_jobnet_table where status in (1, 2 ,4)]
12075:20170424:162430.412 [DEBUG] In process_jajobnet() ja_run_jobnet_table(status): 0.000216 sec.
12075:20170424:162430.413 [DEBUG] End of process_jajobnet()
12075:20170424:162430.413 [DEBUG] sleeping for 1 seconds
12076:20170424:162430.519 [DEBUG] query [txnlev:0] [select inner_job_id, inner_jobnet_id, method_flag, job_type, test_flag from ja_run_job_table where status = 1 ]
12076:20170424:162430.520 [DEBUG] In process_jarun() ja_run_job_table(status = READY): 0.000556 sec.
12076:20170424:162430.520 [DEBUG] End of process_jarun()
12076:20170424:162430.520 [DEBUG] sleeping for 1 seconds
12077:20170424:162430.599 [DEBUG] query [txnlev:0] [select inner_job_id, inner_jobnet_id, job_type, method_flag, timeout_flag, start_time from ja_run_job_table where status = 2]
12077:20170424:162430.600 [DEBUG] In process_jajob() ja_run_job_table(status: RUN): 0.000540 sec.
12077:20170424:162430.600 [DEBUG] End of process_jajob()
12077:20170424:162430.600 [DEBUG] sleeping for 1 seconds
12083:20170424:162430.630 [DEBUG] In jobnet_load_immediate()
12083:20170424:162430.630 [DEBUG] query [txnlev:0] [select inner_jobnet_id, inner_job_id, update_date, run_type, scheduled_time, public_flag, jobnet_id, user_name, jobnet_name, memo, execution_user_name, multiple_start_up, initial_scheduled_time from ja_run_jobnet_table where run_type <> 0 and main_flag = 0 and status = 0]
12083:20170424:162430.630 [DEBUG] job loader #1 (immediate start) spent 0.000342 seconds while processing rules
12083:20170424:162430.630 [DEBUG] sleeping for 1 seconds
12085:20170424:162430.658 [DEBUG] In message_purge()
12085:20170424:162430.658 [DEBUG] In get_purge_date(1440)
12085:20170424:162430.658 [DEBUG] query [txnlev:1] [begin;]
12085:20170424:162430.658 [DEBUG] query [txnlev:1] [delete from ja_send_message_table where send_status = 1 and send_date <= 20170423162459]
12085:20170424:162430.659 [DEBUG] query [txnlev:1] [commit;]
12085:20170424:162430.659 [DEBUG] query [txnlev:1] [begin;]
12085:20170424:162430.659 [DEBUG] query [txnlev:1] [delete from ja_send_message_table where send_status = 3 and send_error_date <= 20170423162459]
12085:20170424:162430.659 [DEBUG] query [txnlev:1] [commit;]
12085:20170424:162430.659 [DEBUG] message send #1 (message purge) spent 0.000957 seconds while processing rules
12085:20170424:162430.659 [DEBUG] In message_send()
12085:20170424:162430.659 [DEBUG] query [txnlev:0] [select send_no, message_date, send_status, retry_count, retry_date, message_type, user_name, host_name, jobnet_id, jobnet_name, job_id, job_id_full, job_name, log_message_id, log_message from ja_send_message_table where (send_status = 0 or send_status = 2) and retry_date <= 20170424162430 order by retry_date, message_date]
12085:20170424:162430.660 [DEBUG] message send #1 (message send) spent 0.000296 seconds while processing rules
12085:20170424:162430.660 [DEBUG] sleeping for 1 seconds
12084:20170424:162430.660 [DEBUG] In get_purge_date(60)
12084:20170424:162430.660 [DEBUG] In get_purge_date(43200)
12084:20170424:162430.660 [DEBUG] In jobnet_purge(201704241524)
12084:20170424:162430.660 [DEBUG] query [txnlev:0] [select inner_jobnet_id, jobnet_id, update_date, status from ja_run_jobnet_summary_table where end_time <= 20170424152459 and status in(3, 5)]
12084:20170424:162430.660 [DEBUG] jobnet boot #1 (jobnet purge) spent 0.000289 seconds while processing rules
12084:20170424:162430.660 [DEBUG] In joblog_purge(201703251624)
12084:20170424:162430.660 [DEBUG] query [txnlev:0] [select inner_jobnet_main_id from ja_run_log_table where log_date <= 20170325162459999 group by inner_jobnet_main_id]
12084:20170424:162430.660 [DEBUG] jobnet boot #1 (joblog purge) spent 0.000268 seconds while processing rules
12084:20170424:162430.660 [DEBUG] In jobnet_boot(201704241624)
12084:20170424:162430.661 [DEBUG] query [txnlev:0] [select inner_jobnet_id, run_type, scheduled_time, jobnet_id, update_date, multiple_start_up, load_status, start_pending_flag from ja_run_jobnet_summary_table where status = 0 and start_pending_flag != 1 and (scheduled_time <= 201704241624 or scheduled_time = 0) order by scheduled_time, inner_jobnet_id]
12084:20170424:162430.661 [DEBUG] jobnet boot #1 (jobnet start) spent 0.000313 seconds while processing rules
12084:20170424:162430.661 [DEBUG] sleeping for 1 seconds
12086:20170424:162430.879 [DEBUG] In ja_collect_selfmon_stats()
12086:20170424:162430.879 [DEBUG] End of ja_collect_selfmon_stats()
12086:20170424:162430.879 [DEBUG] sleeping for 1 seconds
12075:20170424:162431.413 [DEBUG] query [txnlev:0] [select inner_jobnet_id, status, jobnet_abort_flag from ja_run_jobnet_summary_table where status in (1, 2)]
12075:20170424:162431.413 [DEBUG] In process_jajobnet_summary() ja_run_jobnet_summary_table(status): 0.000548 sec.
12075:20170424:162431.413 [DEBUG] End of process_jajobnet_summary()
12075:20170424:162431.413 [DEBUG] query [txnlev:0] [select inner_jobnet_id, inner_job_id, timeout_flag, status from ja_run_jobnet_table where status in (1, 2 ,4)]
12075:20170424:162431.414 [DEBUG] In process_jajobnet() ja_run_jobnet_table(status): 0.000198 sec.
12075:20170424:162431.414 [DEBUG] End of process_jajobnet()
12075:20170424:162431.414 [DEBUG] sleeping for 1 seconds
12076:20170424:162431.520 [DEBUG] query [txnlev:0] [select inner_job_id, inner_jobnet_id, method_flag, job_type, test_flag from ja_run_job_table where status = 1 ]
12076:20170424:162431.520 [DEBUG] In process_jarun() ja_run_job_table(status = READY): 0.000292 sec.
12076:20170424:162431.520 [DEBUG] End of process_jarun()
12076:20170424:162431.520 [DEBUG] sleeping for 1 seconds
12077:20170424:162431.600 [DEBUG] query [txnlev:0] [select inner_job_id, inner_jobnet_id, job_type, method_flag, timeout_flag, start_time from ja_run_job_table where status = 2]
12077:20170424:162431.600 [DEBUG] In process_jajob() ja_run_job_table(status: RUN): 0.000367 sec.
12077:20170424:162431.600 [DEBUG] End of process_jajob()
12077:20170424:162431.600 [DEBUG] sleeping for 1 seconds
12083:20170424:162431.630 [DEBUG] In jobnet_load_immediate()
12083:20170424:162431.630 [DEBUG] query [txnlev:0] [select inner_jobnet_id, inner_job_id, update_date, run_type, scheduled_time, public_flag, jobnet_id, user_name, jobnet_name, memo, execution_user_name, multiple_start_up, initial_scheduled_time from ja_run_jobnet_table where run_type <> 0 and main_flag = 0 and status = 0]
12083:20170424:162431.631 [DEBUG] job loader #1 (immediate start) spent 0.000367 seconds while processing rules
12083:20170424:162431.631 [DEBUG] sleeping for 1 seconds
12085:20170424:162431.660 [DEBUG] In message_purge()
12085:20170424:162431.660 [DEBUG] In get_purge_date(1440)
12085:20170424:162431.660 [DEBUG] query [txnlev:1] [begin;]
12085:20170424:162431.660 [DEBUG] query [txnlev:1] [delete from ja_send_message_table where send_status = 1 and send_date <= 20170423162459]
12085:20170424:162431.660 [DEBUG] query [txnlev:1] [commit;]
12085:20170424:162431.660 [DEBUG] query [txnlev:1] [begin;]
12085:20170424:162431.660 [DEBUG] query [txnlev:1] [delete from ja_send_message_table where send_status = 3 and send_error_date <= 20170423162459]
12085:20170424:162431.661 [DEBUG] query [txnlev:1] [commit;]
12085:20170424:162431.661 [DEBUG] message send #1 (message purge) spent 0.000921 seconds while processing rules
12085:20170424:162431.661 [DEBUG] In message_send()
12085:20170424:162431.661 [DEBUG] query [txnlev:0] [select send_no, message_date, send_status, retry_count, retry_date, message_type, user_name, host_name, jobnet_id, jobnet_name, job_id, job_id_full, job_name, log_message_id, log_message from ja_send_message_table where (send_status = 0 or send_status = 2) and retry_date <= 20170424162431 order by retry_date, message_date]
12084:20170424:162431.661 [DEBUG] In get_purge_date(60)
12085:20170424:162431.661 [DEBUG] message send #1 (message send) spent 0.000295 seconds while processing rules
12085:20170424:162431.661 [DEBUG] sleeping for 1 seconds
12084:20170424:162431.661 [DEBUG] In get_purge_date(43200)
12084:20170424:162431.661 [DEBUG] In jobnet_purge(201704241524)
12084:20170424:162431.661 [DEBUG] query [txnlev:0] [select inner_jobnet_id, jobnet_id, update_date, status from ja_run_jobnet_summary_table where end_time <= 20170424152459 and status in(3, 5)]
12084:20170424:162431.661 [DEBUG] jobnet boot #1 (jobnet purge) spent 0.000284 seconds while processing rules
12084:20170424:162431.661 [DEBUG] In joblog_purge(201703251624)
12084:20170424:162431.661 [DEBUG] query [txnlev:0] [select inner_jobnet_main_id from ja_run_log_table where log_date <= 20170325162459999 group by inner_jobnet_main_id]
12084:20170424:162431.662 [DEBUG] jobnet boot #1 (joblog purge) spent 0.000291 seconds while processing rules
12084:20170424:162431.662 [DEBUG] In jobnet_boot(201704241624)
12084:20170424:162431.662 [DEBUG] query [txnlev:0] [select inner_jobnet_id, run_type, scheduled_time, jobnet_id, update_date, multiple_start_up, load_status, start_pending_flag from ja_run_jobnet_summary_table where status = 0 and start_pending_flag != 1 and (scheduled_time <= 201704241624 or scheduled_time = 0) order by scheduled_time, inner_jobnet_id]
12084:20170424:162431.662 [DEBUG] jobnet boot #1 (jobnet start) spent 0.000268 seconds while processing rules
12084:20170424:162431.662 [DEBUG] sleeping for 1 seconds
12086:20170424:162431.879 [DEBUG] In ja_collect_selfmon_stats()
12086:20170424:162431.879 [DEBUG] End of ja_collect_selfmon_stats()
12086:20170424:162431.879 [DEBUG] sleeping for 1 seconds
12075:20170424:162432.414 [DEBUG] query [txnlev:0] [select inner_jobnet_id, status, jobnet_abort_flag from ja_run_jobnet_summary_table where status in (1, 2)]
12075:20170424:162432.414 [DEBUG] In process_jajobnet_summary() ja_run_jobnet_summary_table(status): 0.000535 sec.
12075:20170424:162432.414 [DEBUG] End of process_jajobnet_summary()
12075:20170424:162432.414 [DEBUG] query [txnlev:0] [select inner_jobnet_id, inner_job_id, timeout_flag, status from ja_run_jobnet_table where status in (1, 2 ,4)]
12075:20170424:162432.415 [DEBUG] In process_jajobnet() ja_run_jobnet_table(status): 0.000207 sec.
12075:20170424:162432.415 [DEBUG] End of process_jajobnet()
12075:20170424:162432.415 [DEBUG] sleeping for 1 seconds
12076:20170424:162432.521 [DEBUG] query [txnlev:0] [select inner_job_id, inner_jobnet_id, method_flag, job_type, test_flag from ja_run_job_table where status = 1 ]
12076:20170424:162432.521 [DEBUG] In process_jarun() ja_run_job_table(status = READY): 0.000458 sec.
12076:20170424:162432.521 [DEBUG] End of process_jarun()
12076:20170424:162432.521 [DEBUG] sleeping for 1 seconds
12077:20170424:162432.600 [DEBUG] query [txnlev:0] [select inner_job_id, inner_jobnet_id, job_type, method_flag, timeout_flag, start_time from ja_run_job_table where status = 2]
12077:20170424:162432.601 [DEBUG] In process_jajob() ja_run_job_table(status: RUN): 0.000330 sec.
12077:20170424:162432.601 [DEBUG] End of process_jajob()
12077:20170424:162432.601 [DEBUG] sleeping for 1 seconds
12083:20170424:162432.631 [DEBUG] In jobnet_load_schedule(60)
12083:20170424:162432.631 [DEBUG] In get_search_date(60)
12083:20170424:162432.631 [DEBUG] query [txnlev:0] [select schedule_id, update_date from ja_schedule_control_table where valid_flag = 1]
12083:20170424:162432.631 [DEBUG] job loader #1 (scheduled start) spent 0.000312 seconds while processing rules
12083:20170424:162432.631 [DEBUG] In jobnet_load_immediate()
12083:20170424:162432.631 [DEBUG] query [txnlev:0] [select inner_jobnet_id, inner_job_id, update_date, run_type, scheduled_time, public_flag, jobnet_id, user_name, jobnet_name, memo, execution_user_name, multiple_start_up, initial_scheduled_time from ja_run_jobnet_table where run_type <> 0 and main_flag = 0 and status = 0]
12083:20170424:162432.632 [DEBUG] job loader #1 (immediate start) spent 0.000307 seconds while processing rules
12083:20170424:162432.632 [DEBUG] sleeping for 1 seconds
12085:20170424:162432.661 [DEBUG] In message_purge()
12085:20170424:162432.661 [DEBUG] In get_purge_date(1440)
12085:20170424:162432.661 [DEBUG] query [txnlev:1] [begin;]
12085:20170424:162432.661 [DEBUG] query [txnlev:1] [delete from ja_send_message_table where send_status = 1 and send_date <= 20170423162459]
12085:20170424:162432.662 [DEBUG] query [txnlev:1] [commit;]
12085:20170424:162432.662 [DEBUG] query [txnlev:1] [begin;]
12085:20170424:162432.662 [DEBUG] query [txnlev:1] [delete from ja_send_message_table where send_status = 3 and send_error_date <= 20170423162459]
12085:20170424:162432.662 [DEBUG] query [txnlev:1] [commit;]
12085:20170424:162432.662 [DEBUG] message send #1 (message purge) spent 0.000971 seconds while processing rules
12085:20170424:162432.662 [DEBUG] In message_send()
12084:20170424:162432.662 [DEBUG] In get_purge_date(60)
12085:20170424:162432.662 [DEBUG] query [txnlev:0] [select send_no, message_date, send_status, retry_count, retry_date, message_type, user_name, host_name, jobnet_id, jobnet_name, job_id, job_id_full, job_name, log_message_id, log_message from ja_send_message_table where (send_status = 0 or send_status = 2) and retry_date <= 20170424162432 order by retry_date, message_date]
12084:20170424:162432.662 [DEBUG] In get_purge_date(43200)
12084:20170424:162432.662 [DEBUG] In jobnet_purge(201704241524)
12084:20170424:162432.662 [DEBUG] query [txnlev:0] [select inner_jobnet_id, jobnet_id, update_date, status from ja_run_jobnet_summary_table where end_time <= 20170424152459 and status in(3, 5)]
12085:20170424:162432.663 [DEBUG] message send #1 (message send) spent 0.000300 seconds while processing rules
12085:20170424:162432.663 [DEBUG] sleeping for 1 seconds
12084:20170424:162432.663 [DEBUG] jobnet boot #1 (jobnet purge) spent 0.000296 seconds while processing rules
12084:20170424:162432.663 [DEBUG] In joblog_purge(201703251624)
12084:20170424:162432.663 [DEBUG] query [txnlev:0] [select inner_jobnet_main_id from ja_run_log_table where log_date <= 20170325162459999 group by inner_jobnet_main_id]
12084:20170424:162432.663 [DEBUG] jobnet boot #1 (joblog purge) spent 0.000271 seconds while processing rules
12084:20170424:162432.663 [DEBUG] In jobnet_boot(201704241624)
12084:20170424:162432.663 [DEBUG] query [txnlev:0] [select inner_jobnet_id, run_type, scheduled_time, jobnet_id, update_date, multiple_start_up, load_status, start_pending_flag from ja_run_jobnet_summary_table where status = 0 and start_pending_flag != 1 and (scheduled_time <= 201704241624 or scheduled_time = 0) order by scheduled_time, inner_jobnet_id]
12084:20170424:162432.663 [DEBUG] jobnet boot #1 (jobnet start) spent 0.000270 seconds while processing rules
12084:20170424:162432.663 [DEBUG] sleeping for 1 seconds
12086:20170424:162432.880 [DEBUG] In ja_collect_selfmon_stats()
12086:20170424:162432.880 [DEBUG] End of ja_collect_selfmon_stats()
12086:20170424:162432.880 [DEBUG] sleeping for 1 seconds
12075:20170424:162433.415 [DEBUG] query [txnlev:0] [select inner_jobnet_id, status, jobnet_abort_flag from ja_run_jobnet_summary_table where status in (1, 2)]
12075:20170424:162433.415 [DEBUG] In process_jajobnet_summary() ja_run_jobnet_summary_table(status): 0.000515 sec.
12075:20170424:162433.415 [DEBUG] End of process_jajobnet_summary()
12075:20170424:162433.415 [DEBUG] query [txnlev:0] [select inner_jobnet_id, inner_job_id, timeout_flag, status from ja_run_jobnet_table where status in (1, 2 ,4)]
12075:20170424:162433.416 [DEBUG] In process_jajobnet() ja_run_jobnet_table(status): 0.000247 sec.
12075:20170424:162433.416 [DEBUG] End of process_jajobnet()
12075:20170424:162433.416 [DEBUG] sleeping for 1 seconds
12076:20170424:162433.521 [DEBUG] query [txnlev:0] [select inner_job_id, inner_jobnet_id, method_flag, job_type, test_flag from ja_run_job_table where status = 1 ]
12076:20170424:162433.522 [DEBUG] In process_jarun() ja_run_job_table(status = READY): 0.000318 sec.
12076:20170424:162433.522 [DEBUG] End of process_jarun()
12076:20170424:162433.522 [DEBUG] sleeping for 1 seconds
[root@ZABBIX jobarranger]#

またlog全体についても添付にて貼り付けておきますので必要情報等あれば情報をお伺いしたく存じます。

以上、宜しくお願い致します。

#4 Updated by Anonymous about 2 years ago

たまに来る人です。

log内容中に
process already running? Could not lock PID file
がないです。

#1については確認し、lock_tableには該当データが残ってはいない様に見受けられました。

書いたいますがja_host_unlockが実行されてないようですので
ja_host_lock_tableにTKY-COS11データがあるはずです。
これを削除してください。

しかし、job arranger serverを再起動することではないですね?

それではまた来る日まで

#5 Updated by Anonymous about 2 years ago

#4 様

ご回答ありがとうございます。
ご指摘通り、ja_host_lock_tableに残存しており、lockされている事を確認致しました。

その後、lockファイルを削除し、再度同様のリブートを実施しようとしましたが
START<--->REBOOT<--->END

の設定を実行致しましたら、REBOOTのアイコンが黄色になり、動作が止まる状態です。
本件は何が原因で、どのようにしたら改善されますでしょうか。

ご教授頂ければ幸いです。
以上、宜しくお願い致します。

#6 Updated by Anonymous about 2 years ago

為念、logを添付致します。
五月雨となりましたが参考になれば幸甚です。

#7 Updated by Anonymous about 2 years ago

たまにくるひとです。

rebootのタケットサーバーは
job arranger serverでしょうか?

OSは何でしょうか?

#8 Updated by 保守サポート 担当 about 2 years ago

前記指摘の通りではないでしょうか?
当初の情報に以下がありますので、Job Arranger server の動いているサーバ(Agentも同居)をリブートしていると思われます。
Job Arranger serverのサーバはRebootアイコンの対象にはできません。

・ジョブエージェント Ver3.0.0
Include=/etc/zabbix/zabbix_agentd.conf
TmpDir=/var/lib/jobarranger/tmp
Server=ZabbixサーバIP(ジョブサーバと同一)を指定

#9 Updated by 保守サポート 担当 over 1 year ago

  • Status changed from 回答中 to 終了

Also available in: Atom PDF