0001 .. SPDX-License-Identifier: GPL-2.0
0002
0003 ==========================
0004 RCU Torture Test Operation
0005 ==========================
0006
0007
0008 CONFIG_RCU_TORTURE_TEST
0009 =======================
0010
0011 The CONFIG_RCU_TORTURE_TEST config option is available for all RCU
0012 implementations. It creates an rcutorture kernel module that can
0013 be loaded to run a torture test. The test periodically outputs
0014 status messages via printk(), which can be examined via the dmesg
0015 command (perhaps grepping for "torture"). The test is started
0016 when the module is loaded, and stops when the module is unloaded.
0017
0018 Module parameters are prefixed by "rcutorture." in
0019 Documentation/admin-guide/kernel-parameters.txt.
0020
0021 Output
0022 ======
0023
0024 The statistics output is as follows::
0025
0026 rcu-torture:--- Start of test: nreaders=16 nfakewriters=4 stat_interval=30 verbose=0 test_no_idle_hz=1 shuffle_interval=3 stutter=5 irqreader=1 fqs_duration=0 fqs_holdoff=0 fqs_stutter=3 test_boost=1/0 test_boost_interval=7 test_boost_duration=4
0027 rcu-torture: rtc: (null) ver: 155441 tfle: 0 rta: 155441 rtaf: 8884 rtf: 155440 rtmbe: 0 rtbe: 0 rtbke: 0 rtbre: 0 rtbf: 0 rtb: 0 nt: 3055767
0028 rcu-torture: Reader Pipe: 727860534 34213 0 0 0 0 0 0 0 0 0
0029 rcu-torture: Reader Batch: 727877838 17003 0 0 0 0 0 0 0 0 0
0030 rcu-torture: Free-Block Circulation: 155440 155440 155440 155440 155440 155440 155440 155440 155440 155440 0
0031 rcu-torture:--- End of test: SUCCESS: nreaders=16 nfakewriters=4 stat_interval=30 verbose=0 test_no_idle_hz=1 shuffle_interval=3 stutter=5 irqreader=1 fqs_duration=0 fqs_holdoff=0 fqs_stutter=3 test_boost=1/0 test_boost_interval=7 test_boost_duration=4
0032
0033 The command "dmesg | grep torture:" will extract this information on
0034 most systems. On more esoteric configurations, it may be necessary to
0035 use other commands to access the output of the printk()s used by
0036 the RCU torture test. The printk()s use KERN_ALERT, so they should
0037 be evident. ;-)
0038
0039 The first and last lines show the rcutorture module parameters, and the
0040 last line shows either "SUCCESS" or "FAILURE", based on rcutorture's
0041 automatic determination as to whether RCU operated correctly.
0042
0043 The entries are as follows:
0044
0045 * "rtc": The hexadecimal address of the structure currently visible
0046 to readers.
0047
0048 * "ver": The number of times since boot that the RCU writer task
0049 has changed the structure visible to readers.
0050
0051 * "tfle": If non-zero, indicates that the "torture freelist"
0052 containing structures to be placed into the "rtc" area is empty.
0053 This condition is important, since it can fool you into thinking
0054 that RCU is working when it is not. :-/
0055
0056 * "rta": Number of structures allocated from the torture freelist.
0057
0058 * "rtaf": Number of allocations from the torture freelist that have
0059 failed due to the list being empty. It is not unusual for this
0060 to be non-zero, but it is bad for it to be a large fraction of
0061 the value indicated by "rta".
0062
0063 * "rtf": Number of frees into the torture freelist.
0064
0065 * "rtmbe": A non-zero value indicates that rcutorture believes that
0066 rcu_assign_pointer() and rcu_dereference() are not working
0067 correctly. This value should be zero.
0068
0069 * "rtbe": A non-zero value indicates that one of the rcu_barrier()
0070 family of functions is not working correctly.
0071
0072 * "rtbke": rcutorture was unable to create the real-time kthreads
0073 used to force RCU priority inversion. This value should be zero.
0074
0075 * "rtbre": Although rcutorture successfully created the kthreads
0076 used to force RCU priority inversion, it was unable to set them
0077 to the real-time priority level of 1. This value should be zero.
0078
0079 * "rtbf": The number of times that RCU priority boosting failed
0080 to resolve RCU priority inversion.
0081
0082 * "rtb": The number of times that rcutorture attempted to force
0083 an RCU priority inversion condition. If you are testing RCU
0084 priority boosting via the "test_boost" module parameter, this
0085 value should be non-zero.
0086
0087 * "nt": The number of times rcutorture ran RCU read-side code from
0088 within a timer handler. This value should be non-zero only
0089 if you specified the "irqreader" module parameter.
0090
0091 * "Reader Pipe": Histogram of "ages" of structures seen by readers.
0092 If any entries past the first two are non-zero, RCU is broken.
0093 And rcutorture prints the error flag string "!!!" to make sure
0094 you notice. The age of a newly allocated structure is zero,
0095 it becomes one when removed from reader visibility, and is
0096 incremented once per grace period subsequently -- and is freed
0097 after passing through (RCU_TORTURE_PIPE_LEN-2) grace periods.
0098
0099 The output displayed above was taken from a correctly working
0100 RCU. If you want to see what it looks like when broken, break
0101 it yourself. ;-)
0102
0103 * "Reader Batch": Another histogram of "ages" of structures seen
0104 by readers, but in terms of counter flips (or batches) rather
0105 than in terms of grace periods. The legal number of non-zero
0106 entries is again two. The reason for this separate view is that
0107 it is sometimes easier to get the third entry to show up in the
0108 "Reader Batch" list than in the "Reader Pipe" list.
0109
0110 * "Free-Block Circulation": Shows the number of torture structures
0111 that have reached a given point in the pipeline. The first element
0112 should closely correspond to the number of structures allocated,
0113 the second to the number that have been removed from reader view,
0114 and all but the last remaining to the corresponding number of
0115 passes through a grace period. The last entry should be zero,
0116 as it is only incremented if a torture structure's counter
0117 somehow gets incremented farther than it should.
0118
0119 Different implementations of RCU can provide implementation-specific
0120 additional information. For example, Tree SRCU provides the following
0121 additional line::
0122
0123 srcud-torture: Tree SRCU per-CPU(idx=0): 0(35,-21) 1(-4,24) 2(1,1) 3(-26,20) 4(28,-47) 5(-9,4) 6(-10,14) 7(-14,11) T(1,6)
0124
0125 This line shows the per-CPU counter state, in this case for Tree SRCU
0126 using a dynamically allocated srcu_struct (hence "srcud-" rather than
0127 "srcu-"). The numbers in parentheses are the values of the "old" and
0128 "current" counters for the corresponding CPU. The "idx" value maps the
0129 "old" and "current" values to the underlying array, and is useful for
0130 debugging. The final "T" entry contains the totals of the counters.
0131
0132 Usage on Specific Kernel Builds
0133 ===============================
0134
0135 It is sometimes desirable to torture RCU on a specific kernel build,
0136 for example, when preparing to put that kernel build into production.
0137 In that case, the kernel should be built with CONFIG_RCU_TORTURE_TEST=m
0138 so that the test can be started using modprobe and terminated using rmmod.
0139
0140 For example, the following script may be used to torture RCU::
0141
0142 #!/bin/sh
0143
0144 modprobe rcutorture
0145 sleep 3600
0146 rmmod rcutorture
0147 dmesg | grep torture:
0148
0149 The output can be manually inspected for the error flag of "!!!".
0150 One could of course create a more elaborate script that automatically
0151 checked for such errors. The "rmmod" command forces a "SUCCESS",
0152 "FAILURE", or "RCU_HOTPLUG" indication to be printk()ed. The first
0153 two are self-explanatory, while the last indicates that while there
0154 were no RCU failures, CPU-hotplug problems were detected.
0155
0156
0157 Usage on Mainline Kernels
0158 =========================
0159
0160 When using rcutorture to test changes to RCU itself, it is often
0161 necessary to build a number of kernels in order to test that change
0162 across a broad range of combinations of the relevant Kconfig options
0163 and of the relevant kernel boot parameters. In this situation, use
0164 of modprobe and rmmod can be quite time-consuming and error-prone.
0165
0166 Therefore, the tools/testing/selftests/rcutorture/bin/kvm.sh
0167 script is available for mainline testing for x86, arm64, and
0168 powerpc. By default, it will run the series of tests specified by
0169 tools/testing/selftests/rcutorture/configs/rcu/CFLIST, with each test
0170 running for 30 minutes within a guest OS using a minimal userspace
0171 supplied by an automatically generated initrd. After the tests are
0172 complete, the resulting build products and console output are analyzed
0173 for errors and the results of the runs are summarized.
0174
0175 On larger systems, rcutorture testing can be accelerated by passing the
0176 --cpus argument to kvm.sh. For example, on a 64-CPU system, "--cpus 43"
0177 would use up to 43 CPUs to run tests concurrently, which as of v5.4 would
0178 complete all the scenarios in two batches, reducing the time to complete
0179 from about eight hours to about one hour (not counting the time to build
0180 the sixteen kernels). The "--dryrun sched" argument will not run tests,
0181 but rather tell you how the tests would be scheduled into batches. This
0182 can be useful when working out how many CPUs to specify in the --cpus
0183 argument.
0184
0185 Not all changes require that all scenarios be run. For example, a change
0186 to Tree SRCU might run only the SRCU-N and SRCU-P scenarios using the
0187 --configs argument to kvm.sh as follows: "--configs 'SRCU-N SRCU-P'".
0188 Large systems can run multiple copies of of the full set of scenarios,
0189 for example, a system with 448 hardware threads can run five instances
0190 of the full set concurrently. To make this happen::
0191
0192 kvm.sh --cpus 448 --configs '5*CFLIST'
0193
0194 Alternatively, such a system can run 56 concurrent instances of a single
0195 eight-CPU scenario::
0196
0197 kvm.sh --cpus 448 --configs '56*TREE04'
0198
0199 Or 28 concurrent instances of each of two eight-CPU scenarios::
0200
0201 kvm.sh --cpus 448 --configs '28*TREE03 28*TREE04'
0202
0203 Of course, each concurrent instance will use memory, which can be
0204 limited using the --memory argument, which defaults to 512M. Small
0205 values for memory may require disabling the callback-flooding tests
0206 using the --bootargs parameter discussed below.
0207
0208 Sometimes additional debugging is useful, and in such cases the --kconfig
0209 parameter to kvm.sh may be used, for example, ``--kconfig 'CONFIG_KASAN=y'``.
0210
0211 Kernel boot arguments can also be supplied, for example, to control
0212 rcutorture's module parameters. For example, to test a change to RCU's
0213 CPU stall-warning code, use "--bootargs 'rcutorture.stall_cpu=30'".
0214 This will of course result in the scripting reporting a failure, namely
0215 the resuling RCU CPU stall warning. As noted above, reducing memory may
0216 require disabling rcutorture's callback-flooding tests::
0217
0218 kvm.sh --cpus 448 --configs '56*TREE04' --memory 128M \
0219 --bootargs 'rcutorture.fwd_progress=0'
0220
0221 Sometimes all that is needed is a full set of kernel builds. This is
0222 what the --buildonly argument does.
0223
0224 Finally, the --trust-make argument allows each kernel build to reuse what
0225 it can from the previous kernel build.
0226
0227 There are additional more arcane arguments that are documented in the
0228 source code of the kvm.sh script.
0229
0230 If a run contains failures, the number of buildtime and runtime failures
0231 is listed at the end of the kvm.sh output, which you really should redirect
0232 to a file. The build products and console output of each run is kept in
0233 tools/testing/selftests/rcutorture/res in timestamped directories. A
0234 given directory can be supplied to kvm-find-errors.sh in order to have
0235 it cycle you through summaries of errors and full error logs. For example::
0236
0237 tools/testing/selftests/rcutorture/bin/kvm-find-errors.sh \
0238 tools/testing/selftests/rcutorture/res/2020.01.20-15.54.23
0239
0240 However, it is often more convenient to access the files directly.
0241 Files pertaining to all scenarios in a run reside in the top-level
0242 directory (2020.01.20-15.54.23 in the example above), while per-scenario
0243 files reside in a subdirectory named after the scenario (for example,
0244 "TREE04"). If a given scenario ran more than once (as in "--configs
0245 '56*TREE04'" above), the directories corresponding to the second and
0246 subsequent runs of that scenario include a sequence number, for example,
0247 "TREE04.2", "TREE04.3", and so on.
0248
0249 The most frequently used file in the top-level directory is testid.txt.
0250 If the test ran in a git repository, then this file contains the commit
0251 that was tested and any uncommitted changes in diff format.
0252
0253 The most frequently used files in each per-scenario-run directory are:
0254
0255 .config:
0256 This file contains the Kconfig options.
0257
0258 Make.out:
0259 This contains build output for a specific scenario.
0260
0261 console.log:
0262 This contains the console output for a specific scenario.
0263 This file may be examined once the kernel has booted, but
0264 it might not exist if the build failed.
0265
0266 vmlinux:
0267 This contains the kernel, which can be useful with tools like
0268 objdump and gdb.
0269
0270 A number of additional files are available, but are less frequently used.
0271 Many are intended for debugging of rcutorture itself or of its scripting.
0272
0273 As of v5.4, a successful run with the default set of scenarios produces
0274 the following summary at the end of the run on a 12-CPU system::
0275
0276 SRCU-N ------- 804233 GPs (148.932/s) [srcu: g10008272 f0x0 ]
0277 SRCU-P ------- 202320 GPs (37.4667/s) [srcud: g1809476 f0x0 ]
0278 SRCU-t ------- 1122086 GPs (207.794/s) [srcu: g0 f0x0 ]
0279 SRCU-u ------- 1111285 GPs (205.794/s) [srcud: g1 f0x0 ]
0280 TASKS01 ------- 19666 GPs (3.64185/s) [tasks: g0 f0x0 ]
0281 TASKS02 ------- 20541 GPs (3.80389/s) [tasks: g0 f0x0 ]
0282 TASKS03 ------- 19416 GPs (3.59556/s) [tasks: g0 f0x0 ]
0283 TINY01 ------- 836134 GPs (154.84/s) [rcu: g0 f0x0 ] n_max_cbs: 34198
0284 TINY02 ------- 850371 GPs (157.476/s) [rcu: g0 f0x0 ] n_max_cbs: 2631
0285 TREE01 ------- 162625 GPs (30.1157/s) [rcu: g1124169 f0x0 ]
0286 TREE02 ------- 333003 GPs (61.6672/s) [rcu: g2647753 f0x0 ] n_max_cbs: 35844
0287 TREE03 ------- 306623 GPs (56.782/s) [rcu: g2975325 f0x0 ] n_max_cbs: 1496497
0288 CPU count limited from 16 to 12
0289 TREE04 ------- 246149 GPs (45.5831/s) [rcu: g1695737 f0x0 ] n_max_cbs: 434961
0290 TREE05 ------- 314603 GPs (58.2598/s) [rcu: g2257741 f0x2 ] n_max_cbs: 193997
0291 TREE07 ------- 167347 GPs (30.9902/s) [rcu: g1079021 f0x0 ] n_max_cbs: 478732
0292 CPU count limited from 16 to 12
0293 TREE09 ------- 752238 GPs (139.303/s) [rcu: g13075057 f0x0 ] n_max_cbs: 99011