ご担当者様
お世話になっております。
便利なソフトウェアを公開していただき感謝しております。
これまでServerとAgentは同一ネットワークに存在する状況で、Server1台に対しAgentが8台の環境でJob Arrangerを使用させていただいております。
1年半以上安定して稼働してきました。
この度、離れたネットワークに存在し、かつマシンの性能が芳しくないサーバ(Agent)を追加しなければならなくなってしまいました。
本来はそれらを解決するのが正しいと思いますが、すぐに実施できない状況です。
システム環境は以下の通りです。
※同居させているZabbixが他システムと共通であり、これ以上バージョンを上げられない状況です。
■Server
OS: Red Hat Enterprise Linux 6系(詳細バージョン不明)
Zabbix: 2.2.9
DB: MySQL 5.1.73
Job Arranger Server: 3.4
■Agent
OS: Windows Server 2019 Standard x64
Job Arranger Agent: 6.0.8 (※参考情報参照)
この組み合わせで問題なく動作するようになりました(※参考情報参照)が、jobarg_agent.log に、
「[ERROR] In ja_tcp_recv_to() message: received data is null」が出力されます。
ログ抜粋ログ抜粋
10820:20241205:173521.469 [INFO] Starting Job Arranger Agent. Job Arranger 6.0.8 (revision 3480).
10820:20241205:173521.480 [INFO] jobarg_agentd(): Current System ANSI code page :932
5620:20241205:173521.490 [INFO] Use folder [C:\JobArranger\agent\temp\temp]
5620:20241205:173521.501 [INFO] Use folder [C:\JobArranger\agent\temp\begin]
5620:20241205:173521.510 [INFO] Use folder [C:\JobArranger\agent\temp\close]
5620:20241205:173521.519 [INFO] Use folder [C:\JobArranger\agent\temp\data]
5620:20241205:173521.529 [INFO] Use folder [C:\JobArranger\agent\temp\end]
5620:20241205:173521.538 [INFO] Use folder [C:\JobArranger\agent\temp\error]
5620:20241205:173521.547 [INFO] Use folder [C:\JobArranger\agent\temp\exec]
5620:20241205:173521.558 [INFO] Use folder [C:\JobArranger\agent\temp\jobs]
5620:20241205:173521.568 [INFO] Use folder [C:\JobArranger\agent\temp\serverIPs]
5620:20241205:173521.578 [INFO] Use folder [C:\JobArranger\agent\temp\abort]
5516:20241205:173521.590 [INFO] jobarg_agentd #0 started [executive]
10164:20241205:173521.601 [INFO] jobarg_agentd #1 started [listener]
9008:20241205:173521.611 [INFO] jobarg_agentd #2 started [jabackup]
10244:20241205:173523.669 [ERROR] In ja_tcp_recv_to() message: received data is null
2908:20241205:173553.142 [ERROR] In ja_tcp_recv_to() message: received data is null
(略)
1144:20241205:190323.596 [ERROR] In ja_tcp_recv_to() message: received data is null
6932:20241205:190353.662 [ERROR] In ja_tcp_recv_to() message: received data is null
ジョブの実行状況にかかわらず30秒おきに出力されるところを見ると、何らかのAgentの内部的な動作により出力されているのではないかと考えます。
ここで質問です。
(1) このような30秒置きの「[ERROR] In ja_tcp_recv_to() message: received data is null」はどういう原因で出力されているものでしょうか。
(実害はなく無視してよいものでしょうか)
(2) このエラーログ出力を抑止する方法はありますでしょうか。
お忙しいところ恐れ入りますが、ご回答の程宜しくお願い致します。
※参考情報
本環境で Agent 3.4.2 または 5.1.0 を使用してジョブネット起動を行いますと、一部のジョブ(不特定)の実行結果がまれに赤色表示になる事象が発生しました。
その時、以下のようなログが出力されます。
ShowHide
Agent 3.4.2の場合
特定できませんでしたが、赤色表示発生と近い時間で以下のようなログが見受けられました。
3836:20241204:134909.019 [ERROR] query failed: [BEGIN IMMEDIATE;] error [cannot start a transaction within a transaction]
3836:20241204:134916.285 [ERROR] job response message: the job is not running. inner_job_id: 16458947
Agent 5.1.0の場合
9424:20241205:073852.112 [INFO] In ja_agent_begin(),jobid: 16494807, method: 0 is begin
7116:20241205:073853.925 [INFO] In ja_job_check_beginfile(),job id :16494807[16494807-20241205073852.job] is found, and will be starting.
7116:20241205:073853.948 [INFO] In ja_agent_run(),jobid: 16494807 process started.Status: 0
7116:20241205:073854.224 [INFO] In ja_job_check_beginfile(),job id :16494807[16494807-20241205073852.job] started and deleted begin file.
7116:20241205:073857.666 [INFO] In ja_job_exec_end(), job id : 16494807,total files read :5, process id : 8736 finished.
7116:20241205:073857.753 [WARN] job response message: the job is not running. inner_job_id: 16494807, Server IP 10.8.8.38
7116:20241205:073857.773 [WARN] In ja_job_exec_close() agent close failed. retry count :[0].
7116:20241205:073858.873 [WARN] job response message: the job is not running. inner_job_id: 16494807, Server IP 10.8.8.38
7116:20241205:073858.888 [WARN] In ja_job_exec_close() agent close failed. retry count :[1].
(繰り返しのため中略)
7116:20241205:073930.492 [WARN] job response message: the job is not running. inner_job_id: 16494807, Server IP 10.8.8.38
7116:20241205:073930.513 [WARN] In ja_job_exec_close() agent close failed. retry count :[29].
7116:20241205:073931.611 [WARN] job response message: the job is not running. inner_job_id: 16494807, Server IP 10.8.8.38
7116:20241205:073931.632 [INFO] In job_to_error() [16494807-20241205073852-8736] file and it's data files will be moved to error folder.
7116:20241205:073931.654 [INFO] In job_to_error() [16494807-20241205073852-8736*] files will be moved from [data] and [close] folders to C:\JobArranger\agent\temp\error\16494807-20241205073852-8736 folder.
7116:20241205:073931.680 [WARN] In job_to_error() [C:\JobArranger\agent\temp\close\16494807-20241205073852-8736] folder does not exist. (No such file or directory)
7116:20241205:073931.704 [INFO] In job_to_error() move[16494807-20241205073852-8736.job] file from C:\JobArranger\agent\temp\end to C:\JobArranger\agent\temp\error folder.
7116:20241205:073931.725 [ERROR] In ja_job_exec_close() agent close failed.Can not send the result to server. jobid: 16494807
本サイトで類似事例を検索しましたが、同一の事象は見つけられませんでした。
ただしAgentのサーバが重かったり、ネットワークに問題がある場合に似たような問題が起こることが分かってきました。
稼働環境 を参照し、Agentの通信プロトコルVersionが揃っていれば、Serverのバージョンが古いままAgentを更新することは可能なのだろうと判断しました。
そこで、6.0.8 のリリースノート
Job Arranger エージェントでの期限切れジョブフォルダおよびファイルの削除処理の問題を修正しました。
Jobnet,Iconの停止処理でデッドロックを引き起こしていたいくつかのクエリを修正しました。
内部タイムアウト監視処理で jobarg_joblogput が中断される問題を修正しました。
終了したサブジョブネットのデータが削除されない問題を修正しました。
の改善点に期待し、最新のAgentを適用したところ、この問題に遭遇した次第です。
さらに余談ですが、Agent 6.1.5.1 ではジョブ起動そのものができませんでした。