2020-08-07 21:33:04

by Jonathan Adams

[permalink] [raw]
Subject: [RFC PATCH 0/7] metricfs metric file system and examples

[resending to widen the CC lists per [email protected]'s suggestion
original posting to lkml here: https://lkml.org/lkml/2020/8/5/1009]

To try to restart the discussion of kernel statistics started by the
statsfs patchsets (https://lkml.org/lkml/2020/5/26/332), I wanted
to share the following set of patches which are Google's 'metricfs'
implementation and some example uses. Google has been using metricfs
internally since 2012 as a way to export various statistics to our
telemetry systems (similar to OpenTelemetry), and we have over 200
statistics exported on a typical machine.

These patches have been cleaned up and modernized v.s. the versions
in production; I've included notes under the fold in the patches.
They're based on v5.8-rc6.

The statistics live under debugfs, in a tree rooted at:

/sys/kernel/debug/metricfs

Each metric is a directory, with four files in it. For example, the '
core/metricfs: Create metricfs, standardized files under debugfs.' patch
includes a simple 'metricfs_presence' metric, whose files look like:
/sys/kernel/debug/metricfs:
metricfs_presence/annotations
DESCRIPTION A\ basic\ presence\ metric.
metricfs_presence/fields
value
int
metricfs_presence/values
1
metricfs_presence/version
1

(The "version" field always says '1', and is kind of vestigial)

An example of a more complicated stat is the networking stats.
For example, the tx_bytes stat looks like:

net/dev/stats/tx_bytes/annotations
DESCRIPTION net\ device\ transmited\ bytes\ count
CUMULATIVE
net/dev/stats/tx_bytes/fields
interface value
str int
net/dev/stats/tx_bytes/values
lo 4394430608
eth0 33353183843
eth1 16228847091
net/dev/stats/tx_bytes/version
1

The per-cpu statistics show up in the schedulat stat info and x86
IRQ counts. For example:

stat/user/annotations
DESCRIPTION time\ in\ user\ mode\ (nsec)
CUMULATIVE
stat/user/fields
cpu value
int int
stat/user/values
0 1183486517734
1 1038284237228
...
stat/user/version
1

The full set of example metrics I've included are:

core/metricfs: Create metricfs, standardized files under debugfs.
metricfs_presence
core/metricfs: metric for kernel warnings
warnings/values
core/metricfs: expose scheduler stat information through metricfs
stat/*
net-metricfs: Export /proc/net/dev via metricfs.
net/dev/stats/[tr]x_*
core/metricfs: expose x86-specific irq information through metricfs
irq_x86/*

The general approach is called out in kernel/metricfs.c:

The kernel provides:
- A description of the metric
- The subsystem for the metric (NULL is ok)
- Type information about the metric, and
- A callback function which supplies metric values.

Limitations:
- "values" files are at MOST 64K. We truncate the file at that point.
- The list of fields and types is at most 1K.
- Metrics may have at most 2 fields.

Best Practices:
- Emit the most important data first! Once the 64K per-metric buffer
is full, the emit* functions won't do anything.
- In userspace, open(), read(), and close() the file quickly! The kernel
allocation for the metric is alive as long as the file is open. This
permits users to seek around the contents of the file, while
permitting an atomic view of the data.

Note that since the callbacks are called and the data is generated at
file open() time, the relative consistency is only between members of
a given metric; the rx_bytes stat for every network interface will
be read at almost the same time, but if you want to get rx_bytes
and rx_packets, there could be a bunch of slew between the two file
opens. (So this doesn't entirely address Andrew Lunn's comments in
https://lkml.org/lkml/2020/5/26/490)

This also doesn't address one of the basic parts of the statsfs work:
moving the statistics out of debugfs to avoid lockdown interactions.

Google has found a lot of value in having a generic interface for adding
these kinds of statistics with reasonably low overhead (reading them
is O(number of statistics), not number of objects in each statistic).
There are definitely warts in the interface, but does the basic approach
make sense to folks?

Thanks,
- Jonathan

Jonathan Adams (5):
core/metricfs: add support for percpu metricfs files
core/metricfs: metric for kernel warnings
core/metricfs: expose softirq information through metricfs
core/metricfs: expose scheduler stat information through metricfs
core/metricfs: expose x86-specific irq information through metricfs

Justin TerAvest (1):
core/metricfs: Create metricfs, standardized files under debugfs.

Laurent Chavey (1):
net-metricfs: Export /proc/net/dev via metricfs.

arch/x86/kernel/irq.c | 80 ++++
fs/proc/stat.c | 57 +++
include/linux/metricfs.h | 131 +++++++
kernel/Makefile | 2 +
kernel/metricfs.c | 775 +++++++++++++++++++++++++++++++++++++
kernel/metricfs_examples.c | 151 ++++++++
kernel/panic.c | 131 +++++++
kernel/softirq.c | 45 +++
lib/Kconfig.debug | 18 +
net/core/Makefile | 1 +
net/core/net_metricfs.c | 194 ++++++++++
11 files changed, 1585 insertions(+)
create mode 100644 include/linux/metricfs.h
create mode 100644 kernel/metricfs.c
create mode 100644 kernel/metricfs_examples.c
create mode 100644 net/core/net_metricfs.c

--
2.28.0.236.gb10cc79966-goog


2020-08-07 21:34:13

by Jonathan Adams

[permalink] [raw]
Subject: [RFC PATCH 6/7] core/metricfs: expose x86-specific irq information through metricfs

Add metricfs support for displaying percpu irq counters for x86.
The top directory is /sys/kernel/debug/metricfs/irq_x86.
Then there is a subdirectory for each x86-specific irq counter.
For example:

cat /sys/kernel/debug/metricfs/irq_x86/TLB/values

Signed-off-by: Jonathan Adams <[email protected]>

---

[email protected]: rebased to 5.8-pre6
This is work originally done by another engineer at
google, who would rather not have their name associated with
this patchset. They're okay with me sending it under my name.
---
arch/x86/kernel/irq.c | 80 +++++++++++++++++++++++++++++++++++++++++++
1 file changed, 80 insertions(+)

diff --git a/arch/x86/kernel/irq.c b/arch/x86/kernel/irq.c
index 181060247e3c..ffacbbc4066c 100644
--- a/arch/x86/kernel/irq.c
+++ b/arch/x86/kernel/irq.c
@@ -12,6 +12,7 @@
#include <linux/delay.h>
#include <linux/export.h>
#include <linux/irq.h>
+#include <linux/metricfs.h>

#include <asm/irq_stack.h>
#include <asm/apic.h>
@@ -374,3 +375,82 @@ void fixup_irqs(void)
}
}
#endif
+
+#ifdef CONFIG_METRICFS
+#define METRICFS_ITEM(name, field, desc) \
+static void \
+metricfs_##name(struct metric_emitter *e, int cpu) \
+{ \
+ int64_t v = irq_stats(cpu)->field; \
+ METRIC_EMIT_PERCPU_INT(e, cpu, v); \
+} \
+METRIC_EXPORT_PERCPU_COUNTER(name, desc, metricfs_##name)
+
+METRICFS_ITEM(NMI, __nmi_count, "Non-maskable interrupts");
+#ifdef CONFIG_X86_LOCAL_APIC
+METRICFS_ITEM(LOC, apic_timer_irqs, "Local timer interrupts");
+METRICFS_ITEM(SPU, irq_spurious_count, "Spurious interrupts");
+METRICFS_ITEM(PMI, apic_perf_irqs, "Performance monitoring interrupts");
+METRICFS_ITEM(IWI, apic_irq_work_irqs, "IRQ work interrupts");
+METRICFS_ITEM(RTR, icr_read_retry_count, "APIC ICR read retries");
+#endif
+METRICFS_ITEM(PLT, x86_platform_ipis, "Platform interrupts");
+#ifdef CONFIG_SMP
+METRICFS_ITEM(RES, irq_resched_count, "Rescheduling interrupts");
+METRICFS_ITEM(CAL, irq_call_count, "Function call interrupts");
+METRICFS_ITEM(TLB, irq_tlb_count, "TLB shootdowns");
+#endif
+#ifdef CONFIG_X86_THERMAL_VECTOR
+METRICFS_ITEM(TRM, irq_thermal_count, "Thermal event interrupts");
+#endif
+#ifdef CONFIG_X86_MCE_THRESHOLD
+METRICFS_ITEM(THR, irq_threshold_count, "Threshold APIC interrupts");
+#endif
+#ifdef CONFIG_X86_MCE_AMD
+METRICFS_ITEM(DFR, irq_deferred_error_count, "Deferred Error APIC interrupts");
+#endif
+#ifdef CONFIG_HAVE_KVM
+METRICFS_ITEM(PIN, kvm_posted_intr_ipis, "Posted-interrupt notification event");
+METRICFS_ITEM(PIW, kvm_posted_intr_wakeup_ipis,
+ "Posted-interrupt wakeup event");
+#endif
+
+static int __init init_irq_metricfs(void)
+{
+ struct metricfs_subsys *subsys;
+
+ subsys = metricfs_create_subsys("irq_x86", NULL);
+
+ metric_init_NMI(subsys);
+#ifdef CONFIG_X86_LOCAL_APIC
+ metric_init_LOC(subsys);
+ metric_init_SPU(subsys);
+ metric_init_PMI(subsys);
+ metric_init_IWI(subsys);
+ metric_init_RTR(subsys);
+#endif
+ metric_init_PLT(subsys);
+#ifdef CONFIG_SMP
+ metric_init_RES(subsys);
+ metric_init_CAL(subsys);
+ metric_init_TLB(subsys);
+#endif
+#ifdef CONFIG_X86_THERMAL_VECTOR
+ metric_init_TRM(subsys);
+#endif
+#ifdef CONFIG_X86_MCE_THRESHOLD
+ metric_init_THR(subsys);
+#endif
+#ifdef CONFIG_X86_MCE_AMD
+ metric_init_DFR(subsys);
+#endif
+#ifdef CONFIG_HAVE_KVM
+ metric_init_PIN(subsys);
+ metric_init_PIW(subsys);
+#endif
+
+ return 0;
+}
+module_init(init_irq_metricfs);
+
+#endif
--
2.28.0.236.gb10cc79966-goog

2020-08-07 21:34:48

by Jonathan Adams

[permalink] [raw]
Subject: [RFC PATCH 2/7] core/metricfs: add support for percpu metricfs files

Add a simple mechanism for exporting percpu data through metricfs.
The API follows the existing metricfs pattern. A percpu file is
defined with:

METRIC_EXPORT_PERCPU_INT(name, desc, fn)
METRIC_EXPORT_PERCPU_COUNTER(name, desc, fn)

The first defines a file for exposing a percpu int. The second is
similar, but is for a counter that accumulates since boot. The
'name' is used as the metricfs file. The 'desc' is a description
of the metric. The 'fn' is a callback function to emit a single
percpu value:

void (*fn)(struct metric_emitter *e, int cpu);

The callback must call METRIC_EMIT_PERCPU_INT with the value for
the specified CPU.

Signed-off-by: Jonathan Adams <[email protected]>

---

[email protected]: rebased to 5.6-pre6, renamed funcs to start with
metric_. This is work originally done by another engineer at
google, who would rather not have their name associated with this
patchset. They're okay with me sending it under my name.
---
include/linux/metricfs.h | 28 +++++++++++++++++++
kernel/metricfs.c | 58 ++++++++++++++++++++++++++++++++++++----
2 files changed, 81 insertions(+), 5 deletions(-)

diff --git a/include/linux/metricfs.h b/include/linux/metricfs.h
index 65a1baa8e8c1..f103dc8c44ec 100644
--- a/include/linux/metricfs.h
+++ b/include/linux/metricfs.h
@@ -22,6 +22,19 @@ void metric_exit_##name(void) \
metric_unregister(metric_##name); \
}

+#define METRIC_EXPORT_PERCPU(name, desc, fn, cumulative) \
+static struct metric *metric_##name; \
+void metric_init_##name(struct metricfs_subsys *parent) \
+{ \
+ metric_##name = metric_register_percpu(__stringify(name), (parent), \
+ (desc), (fn), \
+ (cumulative), THIS_MODULE); \
+} \
+void metric_exit_##name(void) \
+{ \
+ metric_unregister(metric_##name); \
+}
+
/*
* Metricfs only deals with two types: int64_t and const char*.
*
@@ -47,6 +60,11 @@ void metric_exit_##name(void) \
METRIC_EXPORT_GENERIC(name, (desc), (fname0), (fname1), (fn), \
true, false)

+#define METRIC_EXPORT_PERCPU_INT(name, desc, fn) \
+ METRIC_EXPORT_PERCPU(name, (desc), (fn), false)
+#define METRIC_EXPORT_PERCPU_COUNTER(name, desc, fn) \
+ METRIC_EXPORT_PERCPU(name, (desc), (fn), true)
+
/* Subsystem support. */
/* Pass NULL as 'parent' to create a new top-level subsystem. */
struct metricfs_subsys *metricfs_create_subsys(const char *name,
@@ -69,6 +87,8 @@ struct metric_emitter;
metric_emit_int_value((e), (v), (f0), (f1))
#define METRIC_EMIT_STR(e, v, f0, f1) \
metric_emit_str_value((e), (v), (f0), (f1))
+#define METRIC_EMIT_PERCPU_INT(e, cpu, v) \
+ metric_emit_percpu_int_value((e), (cpu), (v))

/* Users don't have to call any functions below;
* use the macro definitions above instead.
@@ -77,6 +97,7 @@ void metric_emit_int_value(struct metric_emitter *e,
int64_t v, const char *f0, const char *f1);
void metric_emit_str_value(struct metric_emitter *e,
const char *v, const char *f0, const char *f1);
+void metric_emit_percpu_int_value(struct metric_emitter *e, int cpu, int64_t v);

struct metric *metric_register(const char *name,
struct metricfs_subsys *parent,
@@ -98,6 +119,13 @@ struct metric *metric_register_parm(const char *name,
bool is_cumulative,
struct module *owner);

+struct metric *metric_register_percpu(const char *name,
+ struct metricfs_subsys *parent,
+ const char *description,
+ void (*fn)(struct metric_emitter *e, int cpu),
+ bool is_cumulative,
+ struct module *owner);
+
void metric_unregister(struct metric *m);

#endif /* _METRICFS_H_ */
diff --git a/kernel/metricfs.c b/kernel/metricfs.c
index 676b7b04aa2b..992fdd9a4d0a 100644
--- a/kernel/metricfs.c
+++ b/kernel/metricfs.c
@@ -76,6 +76,8 @@ struct metric {
bool is_string;
bool is_cumulative;
bool has_parm;
+ bool is_percpu;
+ void (*percpu_fn)(struct metric_emitter *e, int cpu);

/* dentry for the directory that contains the metric */
struct dentry *dentry;
@@ -285,6 +287,19 @@ void metric_emit_str_value(struct metric_emitter *e, const char *v,
}
EXPORT_SYMBOL(metric_emit_str_value);

+void metric_emit_percpu_int_value(struct metric_emitter *e, int cpu, int64_t v)
+{
+ char *ckpt = e->buf;
+ bool ok = true;
+
+ ok &= emit_int(e, cpu);
+ ok &= emit_string(e, " ");
+ ok &= emit_int(e, v);
+ ok &= emit_string(e, "\n");
+ if (!ok)
+ e->buf = ckpt;
+}
+
/* Contains file data generated at open() */
struct metricfs_file_private {
size_t bytes_written;
@@ -400,11 +415,15 @@ static int metricfs_fields_open(struct inode *inode, struct file *filp)
}
ok &= emit_string(&e, "value\n");

- if (m->fname0)
- ok &= emit_string(&e, "str ");
- if (m->fname1)
- ok &= emit_string(&e, "str ");
- ok &= emit_string(&e, (m->is_string) ? "str\n" : "int\n");
+ if (m->is_percpu) {
+ ok &= emit_string(&e, "int int\n");
+ } else {
+ if (m->fname0)
+ ok &= emit_string(&e, "str ");
+ if (m->fname1)
+ ok &= emit_string(&e, "str ");
+ ok &= emit_string(&e, (m->is_string) ? "str\n" : "int\n");
+ }

/* Emit all or nothing. */
if (ok) {
@@ -640,6 +659,35 @@ struct metric *metric_register(const char *name,
}
EXPORT_SYMBOL(metric_register);

+static void metric_emit_percpu(struct metric_emitter *e)
+{
+ int cpu;
+
+ for_each_possible_cpu(cpu)
+ e->metric->percpu_fn(e, cpu);
+}
+
+struct metric *metric_register_percpu(const char *name,
+ struct metricfs_subsys *parent,
+ const char *description,
+ void (*fn)(struct metric_emitter *e, int cpu),
+ bool is_cumulative,
+ struct module *owner)
+{
+ struct metric *metric =
+ metric_register(name, parent, description,
+ "cpu", NULL,
+ metric_emit_percpu,
+ false,
+ is_cumulative, owner);
+ if (metric) {
+ metric->is_percpu = true;
+ metric->percpu_fn = fn;
+ }
+ return metric;
+}
+EXPORT_SYMBOL(metric_register_percpu);
+
struct metric *metric_register_parm(const char *name,
struct metricfs_subsys *parent,
const char *description,
--
2.28.0.236.gb10cc79966-goog

2020-08-07 21:34:52

by Jonathan Adams

[permalink] [raw]
Subject: [RFC PATCH 3/7] core/metricfs: metric for kernel warnings

Count kernel warnings by function name of the caller.

Each time WARN() is called, which includes WARN_ON(), increment a counter
in a 256-entry hash table. The table key is the entry point of the calling
function, which is found using kallsyms.

We store the name of the function in the table (because it may be a
module address); reporting the metric just walks the table and prints
the values.

The "warnings" metric is cumulative.

Signed-off-by: Jonathan Adams <[email protected]>

---

[email protected]: rebased to 5.8-rc6, removed google-isms,
added lockdep_assert_held(), NMI handling, ..._unknown*_counts
and locking in warn_tbl_fn(); renamed warn_metric... to
warn_tbl...

The original work was done in 2012 by an engineer no longer
at Google.
---
kernel/panic.c | 131 +++++++++++++++++++++++++++++++++++++++++++++++++
1 file changed, 131 insertions(+)

diff --git a/kernel/panic.c b/kernel/panic.c
index e2157ca387c8..c019b41ab387 100644
--- a/kernel/panic.c
+++ b/kernel/panic.c
@@ -31,6 +31,9 @@
#include <linux/bug.h>
#include <linux/ratelimit.h>
#include <linux/debugfs.h>
+#include <linux/utsname.h>
+#include <linux/hash.h>
+#include <linux/metricfs.h>
#include <asm/sections.h>

#define PANIC_TIMER_STEP 100
@@ -568,6 +571,133 @@ void oops_exit(void)
kmsg_dump(KMSG_DUMP_OOPS);
}

+#ifdef CONFIG_METRICFS
+
+/*
+ * Hash table from function address to count of WARNs called within that
+ * function.
+ * So far this is an add-only hash table (ie, entries never removed), so some
+ * simplifying assumptions are made.
+ */
+#define WARN_TBL_BITS (8)
+#define WARN_TBL_SIZE (1<<WARN_TBL_BITS)
+static struct {
+ void *function;
+ int count;
+ char function_name[KSYM_NAME_LEN];
+} warn_tbl[WARN_TBL_SIZE];
+
+static DEFINE_SPINLOCK(warn_tbl_lock);
+static atomic_t warn_tbl_unknown_lookup_count = ATOMIC_INIT(0);
+static atomic_t warn_tbl_unknown_nmi_count = ATOMIC_INIT(0);
+static int warn_tbl_unknown_count;
+
+/*
+ * Find the entry corresponding to the given function address.
+ * Insert a new entry if one doesn't exist yet.
+ * Returns -1 if the hash table is full.
+ */
+static int tbl_find(void *caller_function)
+{
+ int entry, start_entry;
+
+ lockdep_assert_held(&warn_tbl_lock);
+
+ start_entry = hash_ptr(caller_function, WARN_TBL_BITS);
+ entry = start_entry;
+ do {
+ if (warn_tbl[entry].function == caller_function)
+ return entry;
+ if (warn_tbl[entry].function == NULL) {
+ if (!kallsyms_lookup((unsigned long)caller_function,
+ NULL, NULL, NULL,
+ warn_tbl[entry].function_name))
+ return -1;
+ warn_tbl[entry].function = caller_function;
+ return entry;
+ }
+ entry = (entry + 1) % (WARN_TBL_SIZE);
+ } while (entry != start_entry);
+
+ return -1;
+}
+
+static void tbl_increment(void *caller)
+{
+ void *caller_function;
+ unsigned long caller_offset;
+ unsigned long flags;
+ int entry;
+
+ if (!kallsyms_lookup_size_offset(
+ (unsigned long)caller, NULL, &caller_offset)) {
+ atomic_inc(&warn_tbl_unknown_lookup_count);
+ return;
+ }
+ /* use function entrypoint */
+ caller_function = caller - caller_offset;
+
+ if (in_nmi()) {
+ if (!spin_trylock_irqsave(&warn_tbl_lock, flags)) {
+ atomic_inc(&warn_tbl_unknown_nmi_count);
+ return;
+ }
+ } else {
+ spin_lock_irqsave(&warn_tbl_lock, flags);
+ }
+ entry = tbl_find(caller_function);
+ if (entry >= 0)
+ warn_tbl[entry].count++;
+ else
+ warn_tbl_unknown_count++;
+
+ spin_unlock_irqrestore(&warn_tbl_lock, flags);
+}
+
+/*
+ * Export the hash table to metricfs.
+ */
+static void warn_tbl_fn(struct metric_emitter *e)
+{
+ int i;
+ unsigned long flags;
+ int unknown_count = READ_ONCE(warn_tbl_unknown_count) +
+ atomic_read(&warn_tbl_unknown_nmi_count) +
+ atomic_read(&warn_tbl_unknown_lookup_count);
+
+ if (unknown_count != 0)
+ METRIC_EMIT_INT(e, unknown_count, "(unknown)", NULL);
+
+ spin_lock_irqsave(&warn_tbl_lock, flags);
+ for (i = 0; i < WARN_TBL_SIZE; i++) {
+ unsigned long fn = (unsigned long)warn_tbl[i].function;
+ const char *function_name = warn_tbl[i].function_name;
+ int count = warn_tbl[i].count;
+
+ if (!fn)
+ continue;
+
+ // function_name[] is constant once function is non-NULL
+ spin_unlock_irqrestore(&warn_tbl_lock, flags);
+ METRIC_EMIT_INT(e, count, function_name, NULL);
+ spin_lock_irqsave(&warn_tbl_lock, flags);
+ }
+ spin_unlock_irqrestore(&warn_tbl_lock, flags);
+}
+METRIC_EXPORT_COUNTER(warnings, "Count of calls to WARN().",
+ "function", NULL, warn_tbl_fn);
+
+static int __init metricfs_panic_init(void)
+{
+ metric_init_warnings(NULL);
+ return 0;
+}
+late_initcall(metricfs_panic_init);
+
+#else /* CONFIG_METRICFS */
+inline void tbl_increment(void *caller) {}
+#endif
+
struct warn_args {
const char *fmt;
va_list args;
@@ -576,6 +706,7 @@ struct warn_args {
void __warn(const char *file, int line, void *caller, unsigned taint,
struct pt_regs *regs, struct warn_args *args)
{
+ tbl_increment(caller);
disable_trace_on_warning();

if (file)
--
2.28.0.236.gb10cc79966-goog

2020-08-08 02:07:23

by Andrew Lunn

[permalink] [raw]
Subject: Re: [RFC PATCH 0/7] metricfs metric file system and examples

> net/dev/stats/tx_bytes/annotations
> DESCRIPTION net\ device\ transmited\ bytes\ count
> CUMULATIVE
> net/dev/stats/tx_bytes/fields
> interface value
> str int
> net/dev/stats/tx_bytes/values
> lo 4394430608
> eth0 33353183843
> eth1 16228847091

This is a rather small system. Have you tested it at scale? An
Ethernet switch with 64 physical interfaces, and say 32 VLAN
interfaces stack on top. So this one file will contain 2048 entries?

And generally, you are not interested in one statistic, but many
statistics. So you will need to cat each file, not just one file. And
the way this is implemented:

+static void dev_stats_emit(struct metric_emitter *e,
+ struct net_device *dev,
+ struct metric_def *metricd)
+{
+ struct rtnl_link_stats64 temp;
+ const struct rtnl_link_stats64 *stats = dev_get_stats(dev, &temp);
+
+ if (stats) {
+ __u8 *ptr = (((__u8 *)stats) + metricd->off);
+
+ METRIC_EMIT_INT(e, *(__u64 *)ptr, dev->name, NULL);
+ }
+}

means you are going to be calling dev_get_stats() for each file, and
there are 23 files if i counted correctly. So dev_get_stats() will be
called 47104 times, in this made up example. And this is not always
cheap, these counts can be atomic.

So i personally don't think netdev statistics is a good idea, i doubt
it scales.

I also think you are looking at the wrong set of netdev counters. I
would be more interested in ethtool -S counters. But it appears you
make the assumption that each object you are collecting metrics for
has the same set of counters. This is untrue for network interfaces,
where each driver can export whatever counters it wants, and they can
be dynamic.

Andrew

2020-08-08 05:44:40

by Greg Kroah-Hartman

[permalink] [raw]
Subject: Re: [RFC PATCH 2/7] core/metricfs: add support for percpu metricfs files

On Fri, Aug 07, 2020 at 02:29:11PM -0700, Jonathan Adams wrote:
> Add a simple mechanism for exporting percpu data through metricfs.
> The API follows the existing metricfs pattern. A percpu file is
> defined with:
>
> METRIC_EXPORT_PERCPU_INT(name, desc, fn)
> METRIC_EXPORT_PERCPU_COUNTER(name, desc, fn)
>
> The first defines a file for exposing a percpu int. The second is
> similar, but is for a counter that accumulates since boot. The
> 'name' is used as the metricfs file. The 'desc' is a description
> of the metric. The 'fn' is a callback function to emit a single
> percpu value:
>
> void (*fn)(struct metric_emitter *e, int cpu);
>
> The callback must call METRIC_EMIT_PERCPU_INT with the value for
> the specified CPU.
>
> Signed-off-by: Jonathan Adams <[email protected]>
>
> ---
>
> [email protected]: rebased to 5.6-pre6, renamed funcs to start with
> metric_. This is work originally done by another engineer at
> google, who would rather not have their name associated with this
> patchset. They're okay with me sending it under my name.
> ---
> include/linux/metricfs.h | 28 +++++++++++++++++++
> kernel/metricfs.c | 58 ++++++++++++++++++++++++++++++++++++----

fs/metricfs/ ? This isn't a kernel "core" feature.

Or just put it in fs/debugfs/ and tack it along with one of the debugfs
helper functions to make it easier for everyone to use these (if they
actually are valuable. It's hard to see how this differs from any other
debugfs interface today.

thanks,

greg k-h

2020-08-08 05:46:00

by Greg Kroah-Hartman

[permalink] [raw]
Subject: Re: [RFC PATCH 3/7] core/metricfs: metric for kernel warnings

On Fri, Aug 07, 2020 at 02:29:12PM -0700, Jonathan Adams wrote:
> Count kernel warnings by function name of the caller.
>
> Each time WARN() is called, which includes WARN_ON(), increment a counter
> in a 256-entry hash table. The table key is the entry point of the calling
> function, which is found using kallsyms.

Why is this needed?

As systems seem to like to reboot when WARN() is called, will this only
ever show 1? :)

>
> We store the name of the function in the table (because it may be a
> module address); reporting the metric just walks the table and prints
> the values.
>
> The "warnings" metric is cumulative.

If you are creating specific files in a specific location that people
can rely on, shouldn't they show up in Documentation/ABI/ as well?

But again, is this feature something that anyone really needs/wants?
What can the number of warnings show you?

thanks,

greg k-h

2020-08-08 16:03:17

by David Ahern

[permalink] [raw]
Subject: Re: [RFC PATCH 0/7] metricfs metric file system and examples

On 8/7/20 8:06 PM, Andrew Lunn wrote:
> So i personally don't think netdev statistics is a good idea, i doubt
> it scales.

+1

2020-08-10 09:24:55

by Pavel Machek

[permalink] [raw]
Subject: Re: [RFC PATCH 0/7] metricfs metric file system and examples

On Fri 2020-08-07 14:29:09, Jonathan Adams wrote:
> [resending to widen the CC lists per [email protected]'s suggestion
> original posting to lkml here: https://lkml.org/lkml/2020/8/5/1009]
>
> To try to restart the discussion of kernel statistics started by the
> statsfs patchsets (https://lkml.org/lkml/2020/5/26/332), I wanted
> to share the following set of patches which are Google's 'metricfs'
> implementation and some example uses. Google has been using metricfs
> internally since 2012 as a way to export various statistics to our
> telemetry systems (similar to OpenTelemetry), and we have over 200
> statistics exported on a typical machine.
>
> These patches have been cleaned up and modernized v.s. the versions
> in production; I've included notes under the fold in the patches.
> They're based on v5.8-rc6.
>
> The statistics live under debugfs, in a tree rooted at:
>
> /sys/kernel/debug/metricfs

Is debugfs right place for this? It looks like something where people
would expect compatibility guarantees...

Pavel

--

2020-08-10 18:21:20

by Jakub Kicinski

[permalink] [raw]
Subject: Re: [RFC PATCH 0/7] metricfs metric file system and examples

On Sat, 8 Aug 2020 09:59:34 -0600 David Ahern wrote:
> On 8/7/20 8:06 PM, Andrew Lunn wrote:
> > So i personally don't think netdev statistics is a good idea, i doubt
> > it scales.
>
> +1

+1

Please stop using networking as the example for this.

We don't want file interfaces for stats, and we already made that very
clear last time.

2020-08-13 10:12:33

by Thomas Gleixner

[permalink] [raw]
Subject: Re: [RFC PATCH 6/7] core/metricfs: expose x86-specific irq information through metricfs

Jonathan Adams <[email protected]> writes:

How is that related to core? The x86 subsys prefix is 'x86' and for this
particular thing it's 'x86/irq:'. That applies to the rest of the series
as well.

> Add metricfs support for displaying percpu irq counters for x86.
> The top directory is /sys/kernel/debug/metricfs/irq_x86.
> Then there is a subdirectory for each x86-specific irq counter.
> For example:
>
> cat /sys/kernel/debug/metricfs/irq_x86/TLB/values

What is 'TLB'? I'm not aware of any vector which is named TLB.

The changelog is pretty useless in providing any form of rationale for
this. It tells the WHAT, but not the WHY.

Also what is does this file contain? Aggregates, one line per CPU or the
value of the random CPU of the day? I'm not going to dive into the macro
zoo to figure that out.

> [email protected]: rebased to 5.8-pre6
> This is work originally done by another engineer at
> google, who would rather not have their name associated with
> this patchset. They're okay with me sending it under my name.

I can understand why they wont have their name associated with this.

> +#ifdef CONFIG_METRICFS
> +METRICFS_ITEM(NMI, __nmi_count, "Non-maskable interrupts");
> +#ifdef CONFIG_X86_LOCAL_APIC
> +METRICFS_ITEM(LOC, apic_timer_irqs, "Local timer interrupts");
> +METRICFS_ITEM(SPU, irq_spurious_count, "Spurious interrupts");
> +METRICFS_ITEM(PMI, apic_perf_irqs, "Performance monitoring interrupts");
> +METRICFS_ITEM(IWI, apic_irq_work_irqs, "IRQ work interrupts");
> +METRICFS_ITEM(RTR, icr_read_retry_count, "APIC ICR read retries");
> +#endif
....

So you are adding NR_CPUS * NR_DIRECT_VECTORS debugfs files which show
exactly the same information as /proc/interrupts, right?

Aside of that _all_ of this information is available via tracepoints as
well.

That's NR_CPUS * 15 and incomplete because x86 has 23 of those directly
handled vectors which do not go through the irq core. So with just 15
and 256 CPUs that's 3840 files.

Impressive number especially without any information why this is useful
and provides value over the existing mechanisms to retrieve exactly the
same information.

The cover letter talks a lot about who Google finds this useful, but
that's not really a convincing argument for this metric failsystem
addon.

Thanks,

tglx



2020-08-13 12:03:41

by Paolo Bonzini

[permalink] [raw]
Subject: Re: [RFC PATCH 6/7] core/metricfs: expose x86-specific irq information through metricfs

On 13/08/20 12:11, Thomas Gleixner wrote:
>> Add metricfs support for displaying percpu irq counters for x86.
>> The top directory is /sys/kernel/debug/metricfs/irq_x86.
>> Then there is a subdirectory for each x86-specific irq counter.
>> For example:
>>
>> cat /sys/kernel/debug/metricfs/irq_x86/TLB/values
> What is 'TLB'? I'm not aware of any vector which is named TLB.

There's a "TLB" entry in /proc/interrupts.

Paolo

2020-08-13 12:15:05

by Thomas Gleixner

[permalink] [raw]
Subject: Re: [RFC PATCH 6/7] core/metricfs: expose x86-specific irq information through metricfs

Paolo Bonzini <[email protected]> writes:

> On 13/08/20 12:11, Thomas Gleixner wrote:
>>> Add metricfs support for displaying percpu irq counters for x86.
>>> The top directory is /sys/kernel/debug/metricfs/irq_x86.
>>> Then there is a subdirectory for each x86-specific irq counter.
>>> For example:
>>>
>>> cat /sys/kernel/debug/metricfs/irq_x86/TLB/values
>> What is 'TLB'? I'm not aware of any vector which is named TLB.
>
> There's a "TLB" entry in /proc/interrupts.

It's TLB shootdowns and not TLB.

Thanks,

tglx

2020-08-13 14:11:55

by Paolo Bonzini

[permalink] [raw]
Subject: Re: [RFC PATCH 6/7] core/metricfs: expose x86-specific irq information through metricfs

On 13/08/20 14:13, Thomas Gleixner wrote:
>>>> Add metricfs support for displaying percpu irq counters for x86.
>>>> The top directory is /sys/kernel/debug/metricfs/irq_x86.
>>>> Then there is a subdirectory for each x86-specific irq counter.
>>>> For example:
>>>>
>>>> cat /sys/kernel/debug/metricfs/irq_x86/TLB/values
>>> What is 'TLB'? I'm not aware of any vector which is named TLB.
>> There's a "TLB" entry in /proc/interrupts.
> It's TLB shootdowns and not TLB.

Yes but it's using the shortcut name on the left of the table.

> +METRICFS_ITEM(LOC, apic_timer_irqs, "Local timer interrupts");
> +METRICFS_ITEM(SPU, irq_spurious_count, "Spurious interrupts");
> +METRICFS_ITEM(PMI, apic_perf_irqs, "Performance monitoring interrupts");
> +METRICFS_ITEM(IWI, apic_irq_work_irqs, "IRQ work interrupts");
> +METRICFS_ITEM(RTR, icr_read_retry_count, "APIC ICR read retries");
> +#endif
> +METRICFS_ITEM(PLT, x86_platform_ipis, "Platform interrupts");
> +#ifdef CONFIG_SMP
> +METRICFS_ITEM(RES, irq_resched_count, "Rescheduling interrupts");
> +METRICFS_ITEM(CAL, irq_call_count, "Function call interrupts");
> +METRICFS_ITEM(TLB, irq_tlb_count, "TLB shootdowns");

Paolo

2020-08-13 14:22:42

by Thomas Gleixner

[permalink] [raw]
Subject: Re: [RFC PATCH 6/7] core/metricfs: expose x86-specific irq information through metricfs

Paolo Bonzini <[email protected]> writes:
> On 13/08/20 14:13, Thomas Gleixner wrote:
>>>>> cat /sys/kernel/debug/metricfs/irq_x86/TLB/values
>>>> What is 'TLB'? I'm not aware of any vector which is named TLB.
>>> There's a "TLB" entry in /proc/interrupts.
>> It's TLB shootdowns and not TLB.
>
> Yes but it's using the shortcut name on the left of the table.

Fair enough, that's the first column in /proc/interrupts. I totally
missed the explanation in the elaborate changelog.

Thanks,

tglx