The man page for perf_event_open(2) says that recent kernels treat a 0 value for wakeup_events the same as 1, which I believe means it will notify after a single sample. However, strace on perf(1) shows that it uses wakeup_events=0, and it's definitely not waking up on every sample (it seems to be waking up every few seconds.) tools/perf/design.txt says "Normally a notification is generated for every page filled". Is the documentation wrong, or am I misunderstanding something? ~Theodore _______________________________________________ Kernelnewbies mailing list Kernelnewbies@kernelnewbies.org https://lists.kernelnewbies.org/mailman/listinfo/kernelnewbies
[-- Attachment #1.1: Type: text/plain, Size: 1827 bytes --] On Fri, 06 Sep 2019 16:28:24 -0700, Theodore Dubois said: > The man page for perf_event_open(2) says that recent kernels treat a 0 > value for wakeup_events the same as 1, which I believe means it will > notify after a single sample. However, strace on perf(1) shows that it > uses wakeup_events=0, and it's definitely not waking up on every > sample (it seems to be waking up every few seconds.) > tools/perf/design.txt says "Normally a notification is generated for > every page filled". Is the documentation wrong, or am I > misunderstanding something? wakeup_events, wakeup_watermark This union sets how many samples (wakeup_events) or bytes (wakeup_watermark) happen before an overflow notification happens. Which one is used is selected by the watermark bit flag. wakeup_events counts only PERF_RECORD_SAMPLE record types. To receive overflow notification for all PERF_RECORD types choose watermark and set wakeup_watermark to 1. Prior to Linux 3.0, setting wakeup_events to 0 resulted in no overflow notifications; more recent ker? nels treat 0 the same as 1. My reading of that is that in pre-3.0 kernels, you could choose to not get overflow notifications, and now you'll get them whether or not you wanted them. Under "overflow handling", we see: Overflows are generated only by sampling events (sample_period must have a nonzero value). So the reason strace says perf is only waking up every few seconds is probably because you either launched perf with options that only create trace events, or it takes several seconds for an overflow to happen on a sampling event. A lot of those fields are u64 counters, and won't overflow anytime soon. Even the u32 counters can take a few seconds to overflow.... [-- Attachment #1.2: Type: application/pgp-signature, Size: 832 bytes --] [-- Attachment #2: Type: text/plain, Size: 170 bytes --] _______________________________________________ Kernelnewbies mailing list Kernelnewbies@kernelnewbies.org https://lists.kernelnewbies.org/mailman/listinfo/kernelnewbies
>> The man page for perf_event_open(2) says that recent kernels treat a 0 >> value for wakeup_events the same as 1, which I believe means it will >> notify after a single sample. However, strace on perf(1) shows that it >> uses wakeup_events=0, and it's definitely not waking up on every >> sample (it seems to be waking up every few seconds.) >> tools/perf/design.txt says "Normally a notification is generated for >> every page filled". Is the documentation wrong, or am I >> misunderstanding something? > > wakeup_events, wakeup_watermark > This union sets how many samples (wakeup_events) or bytes (wakeup_watermark) happen before an overflow > notification happens. Which one is used is selected by the watermark bit flag. > > wakeup_events counts only PERF_RECORD_SAMPLE record types. To receive overflow notification for all > PERF_RECORD types choose watermark and set wakeup_watermark to 1. > > Prior to Linux 3.0, setting wakeup_events to 0 resulted in no overflow notifications; more recent ker? > nels treat 0 the same as 1. > > My reading of that is that in pre-3.0 kernels, you could choose to not get overflow > notifications, and now you'll get them whether or not you wanted them. > > Under "overflow handling", we see: > > Overflows are generated only by sampling events (sample_period must have a nonzero value). > > So the reason strace says perf is only waking up every few seconds is probably > because you either launched perf with options that only create trace events, or > it takes several seconds for an overflow to happen on a sampling event. A lot > of those fields are u64 counters, and won't overflow anytime soon. Even the > u32 counters can take a few seconds to overflow.... I launched perf record with the default options. Here’s one of the perf_event_open calls from strace: 08:57:37.083733 perf_event_open({type=PERF_TYPE_HARDWARE, size=PERF_ATTR_SIZE_VER5, config=PERF_COUNT_HW_CPU_CYCLES, sample_freq=4000, sample_type=PERF_SAMPLE_IP|PERF_SAMPLE_TID|PERF_SAMPLE_TIME|PERF_SAMPLE_PERIOD, read_format=PERF_FORMAT_ID, disabled=1, inherit=1, pinned=0, exclusive=0, exclusive_user=0, exclude_kernel=1, exclude_hv=0, exclude_idle=0, mmap=1, comm=1, freq=1, inherit_stat=0, enable_on_exec=1, task=1, watermark=0, precise_ip=3 /* must have 0 skid */, mmap_data=0, sample_id_all=1, exclude_host=0, exclude_guest=1, exclude_callchain_kernel=0, exclude_callchain_user=0, mmap2=1, comm_exec=1, use_clockid=0, context_switch=0, write_backward=0, namespaces=0, wakeup_events=0, config1=0, config2=0, sample_regs_user=0, sample_regs_intr=0, aux_watermark=0, sample_max_stack=0}, 134206, 18, -1, PERF_FLAG_FD_CLOEXEC) = 23 <0.000023> sample_freq is 4000 (and freq is 1). Here’s the man page on this field: sample_period, sample_freq A "sampling" event is one that generates an overflow notifica‐ tion every N events, where N is given by sample_period. A sam‐ pling event has sample_period > 0. When an overflow occurs, requested data is recorded in the mmap buffer. The sample_type field controls what data is recorded on each overflow. sample_freq can be used if you wish to use frequency rather than period. In this case, you set the freq flag. The kernel will adjust the sampling period to try and achieve the desired rate. The rate of adjustment is a timer tick. If I’m reading this right, this is a sampling event which overflows 4000 times a second. But perf then does a poll call which wakes up on this FD with POLLIN after 1.637 seconds, instead of 0.00025 seconds. The man page snippet you pasted seems to be a different definition of an overflow event, but that doesn’t make sense either: the event generates a sample 4000 times a second, and 0 (supposedly the same as 1) would mean to wake up the FD after 1 sample, which would be 0.00025 seconds. ~Theodore _______________________________________________ Kernelnewbies mailing list Kernelnewbies@kernelnewbies.org https://lists.kernelnewbies.org/mailman/listinfo/kernelnewbies
[-- Warning: decoded text below may be mangled, UTF-8 assumed --] [-- Attachment #1.1: Type: text/plain; charset=us-ascii, Size: 546 bytes --] On Sat, 07 Sep 2019 09:14:49 -0700, Theodore Dubois said: > If I’m reading this right, this is a sampling event which overflows 4000 > times a second. But perf then does a poll call which wakes up on this FD with > POLLIN after 1.637 seconds, instead of 0.00025 seconds. No, it *takes a sample* 4,000 times a second. For instance, number of cache line misses since the last sample. You get an overflow when the counter wraps because there have been more than 2^32 events since you read the counter. At least that's my understanding of it. [-- Attachment #1.2: Type: application/pgp-signature, Size: 832 bytes --] [-- Attachment #2: Type: text/plain, Size: 170 bytes --] _______________________________________________ Kernelnewbies mailing list Kernelnewbies@kernelnewbies.org https://lists.kernelnewbies.org/mailman/listinfo/kernelnewbies
[-- Warning: decoded text below may be mangled, UTF-8 assumed --] [-- Attachment #1.1: Type: text/plain; charset=us-ascii, Size: 2292 bytes --] On Sat, 07 Sep 2019 09:14:49 -0700, Theodore Dubois said: Reading what it actually says rather than what I thought it said.. :) Events come in two flavors: counting and sampled. A counting event is one that is used for counting the aggregate number of events that occur. In general, counting event results are gathered with a read(2) call. A sampling event periodically writes measurements to a buffer that can then be accessed via mmap(2). For some reason, I was thinking counting events. -ENOCAFFEINE. :) > sample_freq is 4000 (and freq is 1). Here’s the man page on this field: > > sample_period, sample_freq > A "sampling" event is one that generates an overflow notifica‐ > tion every N events, where N is given by sample_period. A sam‐ > pling event has sample_period > 0. There's this part: > pling event has sample_period > 0. When an overflow occurs, > requested data is recorded in the mmap buffer. The sample_type > field controls what data is recorded on each overflow. So an entry is made in the buffer. It's not clear that this immediately triggers a signal... MMAP layout When using perf_event_open() in sampled mode, asynchronous events (like counter overflow or PROT_EXEC mmap tracking) are logged into a ring- buffer. This ring-buffer is created and accessed through mmap(2). The mmap size should be 1+2^n pages, where the first page is a metadata page (struct perf_event_mmap_page) that contains various bits of infor? mation such as where the ring-buffer head is. So you need to look at what size mmap buffer is being allocated. It's *probably* on the order of megabytes, so that you can buffer a fairly large number of entries and not take several user/kernel transitions on every single entry... > If I’m reading this right, this is a sampling event which overflows 4000 times a second. And 4,000 entries are made in the buffer per second.. > But perf then does a poll call which wakes up on this FD with POLLIN after > 1.637 seconds, instead of 0.00025 seconds At which point perf goes and looks at several thousand entries in the ring buffer... [-- Attachment #1.2: Type: application/pgp-signature, Size: 832 bytes --] [-- Attachment #2: Type: text/plain, Size: 170 bytes --] _______________________________________________ Kernelnewbies mailing list Kernelnewbies@kernelnewbies.org https://lists.kernelnewbies.org/mailman/listinfo/kernelnewbies
On Sep 7, 2019, at 3:45 PM, Valdis Klētnieks <valdis.kletnieks@vt.edu> wrote: > So an entry is made in the buffer. It's not clear that this immediately triggers > a signal… I think the documentation says it does when wakeup_events is 1. The code for perf backs this up: https://github.com/torvalds/linux/blob/a9815a4fa2fd297cab9fa7a12161b16657290293/tools/perf/util/evsel.c#L1051-L1054 The puzzle is what happens when wakeup_events is 0. The documentation saying "more recent kernels treat 0 the same as 1" suggests it should behave the same, but then why would perf set it to 1 after zero-initializing it? > So you need to look at what size mmap buffer is being allocated. It's *probably* > on the order of megabytes, so that you can buffer a fairly large number of entries > and not take several user/kernel transitions on every single entry… It’s 512 KiB. Each sample is 40 bytes (the sample_type is IP | TID | TIME | PERIOD, and each one of those 8 bytes). 40 bytes per sample * 4000 samples per second * 1.637 seconds is 261920 which is almost exactly half the buffer. So does wakeup_events = 0 means it causes a wakeup when the buffer is half full? I don't see anything in the man page about this.... If you'd like to try yourself, this is the strace command I've been using: strace -ttTv -eperf_event_open,mmap,poll -operf.strace perf record stress --cpu 1 --timeout 1 ~Theodore > > On Sat, 07 Sep 2019 09:14:49 -0700, Theodore Dubois said: > > Reading what it actually says rather than what I thought it said.. :) > > Events come in two flavors: counting and sampled. A counting event is > one that is used for counting the aggregate number of events that > occur. In general, counting event results are gathered with a read(2) > call. A sampling event periodically writes measurements to a buffer > that can then be accessed via mmap(2). > > For some reason, I was thinking counting events. -ENOCAFFEINE. :) > >> sample_freq is 4000 (and freq is 1). Here’s the man page on this field: >> >> sample_period, sample_freq >> A "sampling" event is one that generates an overflow notifica‐ >> tion every N events, where N is given by sample_period. A sam‐ >> pling event has sample_period > 0. > > There's this part: >> pling event has sample_period > 0. When an overflow occurs, >> requested data is recorded in the mmap buffer. The sample_type >> field controls what data is recorded on each overflow. > > So an entry is made in the buffer. It's not clear that this immediately triggers > a signal... > > MMAP layout > When using perf_event_open() in sampled mode, asynchronous events (like > counter overflow or PROT_EXEC mmap tracking) are logged into a ring- > buffer. This ring-buffer is created and accessed through mmap(2). > > The mmap size should be 1+2^n pages, where the first page is a metadata > page (struct perf_event_mmap_page) that contains various bits of infor? > mation such as where the ring-buffer head is. > > So you need to look at what size mmap buffer is being allocated. It's *probably* > on the order of megabytes, so that you can buffer a fairly large number of entries > and not take several user/kernel transitions on every single entry... > >> If I’m reading this right, this is a sampling event which overflows 4000 times a second. > > And 4,000 entries are made in the buffer per second.. > >> But perf then does a poll call which wakes up on this FD with POLLIN after >> 1.637 seconds, instead of 0.00025 seconds > > At which point perf goes and looks at several thousand entries in the ring buffer... _______________________________________________ Kernelnewbies mailing list Kernelnewbies@kernelnewbies.org https://lists.kernelnewbies.org/mailman/listinfo/kernelnewbies