History

workqueue: Make show_pwq() use run-length encoding

The show_pwq() function dumps out a pool_workqueue structure's activity, including the pending work-queue handlers: Showing busy workqueues and worker pools: workqueue events: flags=0x0 pwq 0: cpus=0 node=0 flags=0x1 nice=0 active=10/256 refcnt=11 in-flight: 7:test_work_func, 64:test_work_func, 249:test_work_func pending: test_work_func, test_work_func, test_work_func1, test_work_func1, test_work_func1, test_work_func1, test_work_func1 When large systems are facing certain types of hang conditions, it is not unusual for this "pending" list to contain runs of hundreds of identical function names. This "wall of text" is difficult to read, and worse yet, it can be interleaved with other output such as stack traces. Therefore, make show_pwq() use run-length encoding so that the above printout instead looks like this: Showing busy workqueues and worker pools: workqueue events: flags=0x0 pwq 0: cpus=0 node=0 flags=0x1 nice=0 active=10/256 refcnt=11 in-flight: 7:test_work_func, 64:test_work_func, 249:test_work_func pending: 2*test_work_func, 5*test_work_func1 When no comma would be printed, including the WORK_STRUCT_LINKED case, a new run is started unconditionally. This output is more readable, places less stress on the hardware, firmware, and software on the console-log path, and reduces interference with other output.

Paul E. McKenney committed 3 years ago

Commit c76feb01 parent 33e3f0a1 file · +39 −5Browse files

Showing the changes to kernel/workqueue.c (1 of 1 file). Show all

Unified · Split

kernel/workqueue.c+39−5
@@ -4718,22 +4718,53 @@ static void pr_cont_pool_info(struct worker_pool *pool) · 4717 unmodified lines
47184718 pr_cont(" flags=0x%x nice=%d", pool->flags, pool->attrs->nice);
47194719 }
47204720
4721−static void pr_cont_work(bool comma, struct work_struct *work)
4721+struct pr_cont_work_struct {
4722+ bool comma;
4723+ work_func_t func;
4724+ long ctr;
4725+};
4726+
4727+static void pr_cont_work_flush(bool comma, work_func_t func, struct pr_cont_work_struct *pcwsp)
4728+{
4729+ if (!pcwsp->ctr)
4730+ goto out_record;
4731+ if (func == pcwsp->func) {
4732+ pcwsp->ctr++;
4733+ return;
4734+ }
4735+ if (pcwsp->ctr == 1)
4736+ pr_cont("%s %ps", pcwsp->comma ? "," : "", pcwsp->func);
4737+ else
4738+ pr_cont("%s %ld*%ps", pcwsp->comma ? "," : "", pcwsp->ctr, pcwsp->func);
4739+ pcwsp->ctr = 0;
4740+out_record:
4741+ if ((long)func == -1L)
4742+ return;
4743+ pcwsp->comma = comma;
4744+ pcwsp->func = func;
4745+ pcwsp->ctr = 1;
4746+}
4747+
4748+static void pr_cont_work(bool comma, struct work_struct *work, struct pr_cont_work_struct *pcwsp)
47224749 {
47234750 if (work->func == wq_barrier_func) {
47244751 struct wq_barrier *barr;
47254752
47264753 barr = container_of(work, struct wq_barrier, work);
47274754
4755+ pr_cont_work_flush(comma, (work_func_t)-1, pcwsp);
47284756 pr_cont("%s BAR(%d)", comma ? "," : "",
47294757 task_pid_nr(barr->task));
47304758 } else {
4731− pr_cont("%s %ps", comma ? "," : "", work->func);
4759+ if (!comma)
4760+ pr_cont_work_flush(comma, (work_func_t)-1, pcwsp);
4761+ pr_cont_work_flush(comma, work->func, pcwsp);
47324762 }
47334763 }
47344764
47354765 static void show_pwq(struct pool_workqueue *pwq)
47364766 {
4767+ struct pr_cont_work_struct pcws = { .ctr = 0, };
47374768 struct worker_pool *pool = pwq->pool;
47384769 struct work_struct *work;
47394770 struct worker *worker;
@@ -4766,7 +4797,8 @@ static void show_pwq(struct pool_workqueue *pwq) · 26 unmodified lines
47664797 worker->rescue_wq ? "(RESCUER)" : "",
47674798 worker->current_func);
47684799 list_for_each_entry(work, &worker->scheduled, entry)
4769− pr_cont_work(false, work);
4800+ pr_cont_work(false, work, &pcws);
4801+ pr_cont_work_flush(comma, (work_func_t)-1L, &pcws);
47704802 comma = true;
47714803 }
47724804 pr_cont("\n");
@@ -4786,9 +4818,10 @@ static void show_pwq(struct pool_workqueue *pwq) · 13 unmodified lines
47864818 if (get_work_pwq(work) != pwq)
47874819 continue;
47884820
4789− pr_cont_work(comma, work);
4821+ pr_cont_work(comma, work, &pcws);
47904822 comma = !(*work_data_bits(work) & WORK_STRUCT_LINKED);
47914823 }
4824+ pr_cont_work_flush(comma, (work_func_t)-1L, &pcws);
47924825 pr_cont("\n");
47934826 }
47944827
@@ -4797,9 +4830,10 @@ static void show_pwq(struct pool_workqueue *pwq) · 2 unmodified lines
47974830
47984831 pr_info(" inactive:");
47994832 list_for_each_entry(work, &pwq->inactive_works, entry) {
4800− pr_cont_work(comma, work);
4833+ pr_cont_work(comma, work, &pcws);
48014834 comma = !(*work_data_bits(work) & WORK_STRUCT_LINKED);
48024835 }
4836+ pr_cont_work_flush(comma, (work_func_t)-1L, &pcws);
48034837 pr_cont("\n");
48044838 }
48054839 }