[why] when consume with "No job now", scheduler output 14 lines log. when submit 1 job and consume it, scheduler output 78 lines log. it is a bit of heavy for log collect and some logs are redundancy. [how] 1.merge 4 lines to 1 line (form to json) for debug_message. 2.remove output "Done", it's same with kemal-frame meesage "200 GET/PUT..." 3.only 0 | 1 extra message for 1 API: if there has an active message, do not call debug_message as default, there has 1 kemal-frame message for each API 2020-10-20 09:40:28 UTC 200 GET /boot.ipxe/mac/0a-4c-34-18-0a-17 7.18ms <time in> <response status> <----request API----> <response time span> [now] this patch cut 92 lines log to 26 line, interactive with 15 API. examples: --- <4 to 1> and <remove single "Done">

...

172.168.131.113:29720 << Done 2020-10... 200 PUT /set_host_mac?hostname=vm... 289.2µs --> 2020-10... 200 PUT /set_host_mac?hostname=vm... 977.56µs

--- <0 | 1 extra message>

...

172.18.222.81:44210 << Done {"job_state":"running","job_id":"crystal.105070"} 2020-10... 200 GET /~lkp/cgi-bin/lkp-jobfile-append-var?... 2.36ms --> {"job_state":"running","job_id":"crystal.105071"} 2020-10... UTC 200 GET /~lkp/cgi-bin/lkp-jobfile-append-var?... 2.8ms

Signed-off-by: Tong Qunfeng <taxcom@tom.com> --- src/lib/sched.cr | 9 +++------ src/scheduler/scheduler.cr | 30 ++++++++++-------------------- 2 files changed, 13 insertions(+), 26 deletions(-) diff --git a/src/lib/sched.cr b/src/lib/sched.cr index e6f353a..7215df5 100644 --- a/src/lib/sched.cr +++ b/src/lib/sched.cr @@ -317,7 +317,6 @@ class Sched JobHelper.service_path("#{SRV_INITRD}/lkp/#{job.lkp_initrd_user}/lkp-#{job.arch}.cgz") response["job"] = "http://#{SCHED_HOST}:#{SCHED_PORT}/job_initrd_tmpfs/#{job.id}/job.cgz" - puts %({"job_id": "#{job.id}", "job_state": "boot"}) return response.to_json end @@ -339,7 +338,6 @@ class Sched response += "boot\n" - puts %({"job_id": "#{job.id}", "job_state": "boot"}) return response end @@ -481,7 +479,6 @@ class Sched response += job.kernel_params response += "\nboot\n" - puts %({"job_id": "#{job.id}", "job_state": "boot"}) return response end @@ -512,7 +509,7 @@ class Sched # json log log = job_content.dup log["job_id"] = log.delete("id").not_nil! - puts log.to_json + return log.to_json end def update_tbox_wtmp(env : HTTP::Server::Context) @@ -541,7 +538,7 @@ class Sched # json log hash["testbox"] = testbox - puts hash.to_json + return hash.to_json end def report_ssh_port(testbox : String, ssh_port : String) @@ -572,6 +569,6 @@ class Sched @redis.remove_finished_job(job_id) - puts %({"job_id": "#{job_id}", "job_state": "complete"}) + return %({"job_id": "#{job_id}", "job_state": "complete"}) end end diff --git a/src/scheduler/scheduler.cr b/src/scheduler/scheduler.cr index e38d15c..5befcf9 100644 --- a/src/scheduler/scheduler.cr +++ b/src/scheduler/scheduler.cr @@ -34,9 +34,7 @@ module Scheduler # for debug (maybe kemal debug|logger does better) def self.debug_message(env, response) - puts "\n\n" - puts ">> #{env.request.remote_address}" - puts "<< #{response}" + puts %({"from": "#{env.request.remote_address}", "response": #{response.to_json}}) end # echo alive @@ -53,7 +51,8 @@ module Scheduler get "/boot.:boot_type/:parameter/:value" do |env| response = sched.find_job_boot(env) - debug_message(env, response) + job_id = response[/tmpfs\/(.*)\/job\.cgz/, 1]? + puts %({"job_id": "#{job_id}", "job_state": "boot"}) if job_id response end @@ -62,7 +61,8 @@ module Scheduler get "/~lkp/cgi-bin/gpxelinux.cgi" do |env| response = sched.find_next_job_boot(env) - debug_message(env, response) + job_id = response[/tmpfs\/(.*)\/job\.cgz/, 1]? + puts %({"job_id": "#{job_id}", "job_state": "boot"}) if job_id response end @@ -87,7 +87,6 @@ module Scheduler file_path = ::File.join [Kemal.config.public_folder, job_id, job_package] puts %({"job_id": "#{job_id}", "job_state": "download"}) - debug_message(env, file_path) send_file env, file_path end @@ -102,8 +101,6 @@ module Scheduler if (client_hostname = env.params.query["hostname"]?) && (client_mac = env.params.query["mac"]?) sched.set_host_mac(client_mac, client_hostname) - debug_message(env, "Done") - "Done" else "No yet!" @@ -115,8 +112,6 @@ module Scheduler if client_mac = env.params.query["mac"]? sched.del_host_mac(client_mac) - debug_message(env, "Done") - "Done" else "No yet!" @@ -129,10 +124,8 @@ module Scheduler # ?job_file=/lkp/scheduled/job.yaml&job_state=post_run&job_id=10 # ?job_file=/lkp/scheduled/job.yaml&loadavg=0.28 0.82 0.49 1/105 3389&start_time=1587725398&end_time=1587725698&job_id=10 get "/~lkp/cgi-bin/lkp-jobfile-append-var" do |env| - # get job_id from request - debug_message(env, "Done") + puts sched.update_job_parameter(env) - sched.update_job_parameter(env) "Done" end @@ -168,17 +161,15 @@ module Scheduler # get job_id from request job_id = env.params.query["job_id"]? if job_id - debug_message(env, "Done") - - sched.close_job(job_id) + puts sched.close_job(job_id) end + "Done" end get "/~lkp/cgi-bin/lkp-wtmp" do |env| - debug_message(env, "Done") + puts sched.update_tbox_wtmp(env) - sched.update_tbox_wtmp(env) "Done" end @@ -188,12 +179,11 @@ module Scheduler job_id = env.params.query["job_id"].to_s if testbox && ssh_port - debug_message(env, "Done") - sched.report_ssh_port(testbox, ssh_port) end puts %({"job_id": "#{job_id}", "state": "set ssh port", "ssh_port": "#{ssh_port}", "tbox_name": "#{testbox}"}) + "Done" end end -- 2.23.0