Bug 1431263

On the debug kernel (4.5.0-15.el7.aarch64.debug), I see the following on the console:

====
[ 1456.231082] NMI watchdog: BUG: soft lockup - CPU#3 stuck for 23s! [kworker/u16:1:15106]
[ 1456.239059] Modules linked in: stap_054c2f68f83da5b9627cb81f07300d2_15586(OE) vfat fat sg i2c_xgene_slimpro xgene_rng gpio_xgene_sb i2c_core gpio_generic nfsd ip_tables xfs libcrc32c xgene_enet sdhci_acpi at803x realtek sdhci mmc_core ahci_xgene mdio_xgene libahci_platform dm_mirror dm_region_hash dm_log dm_mod
[ 1456.266787] irq event stamp: 0
[ 1456.269826] hardirqs last  enabled at (0): [<          (null)>]           (null)
[ 1456.277200] hardirqs last disabled at (0): [<fffffe00000ce3dc>] copy_process.isra.32.part.33+0x454/0x16d8
[ 1456.286741] softirqs last  enabled at (0): [<fffffe00000ce3dc>] copy_process.isra.32.part.33+0x454/0x16d8
[ 1456.296280] softirqs last disabled at (0): [<          (null)>]           (null)
[ 1456.303658] 
[ 1456.305146] CPU: 3 PID: 15106 Comm: kworker/u16:1 Tainted: G        W  OE  ------------   4.5.0-15.el7.aarch64.debug #1
[ 1456.315884] Hardware name: AppliedMicro X-Gene Mustang Board/X-Gene Mustang Board, BIOS 3.06.25 Oct 17 2016
[ 1456.325589] Workqueue: writeback wb_workfn (flush-253:0)
[ 1456.330900] task: fffffe035fb59000 ti: fffffe00037f4000 task.ti: fffffe00037f4000
[ 1456.338356] PC is at domain_dirty_limits+0x44/0x30c
[ 1456.343215] LR is at wb_over_bg_thresh+0xcc/0x1c8
[ 1456.347899] pc : [<fffffe00002129ec>] lr : [<fffffe0000215f24>] pstate: 20000145
[ 1456.355266] sp : fffffe00037f7aa0
[ 1456.358567] x29: fffffe00037f7aa0 x28: fffffe00010d2000 
[ 1456.363878] x27: 0000000000000000 x26: fffffe00010d0000 
[ 1456.369189] x25: fffffe000120c000 x24: 0000000000000000 
[ 1456.374500] x23: fffffe0000ee0550 x22: fffffe0000ee05a0 
[ 1456.379809] x21: fffffe00037f7b40 x20: 0000000000000000 
[ 1456.385118] x19: fffffe0000ee0280 x18: 000003ffd504dcb0 
[ 1456.390428] x17: 000003ffa02b1bfc x16: fffffe00002a89f4 
[ 1456.395738] x15: 0000000000000004 x14: 000003ffd50502d0 
[ 1456.401049] x13: 0000000000000001 x12: 0000000000000000 
[ 1456.406358] x11: fffffe00008a5940 x10: 00000000000023e0 
[ 1456.411669] x9 : fffffe00037f4000 x8 : 0000000000000000 
[ 1456.416980] x7 : fffffe00002c9cd8 x6 : 0000000000000000 
[ 1456.422290] x5 : fffffe0002499438 x4 : 0000000000034b64 
[ 1456.427601] x3 : 0000000000000000 x2 : fffffe0001143848 
[ 1456.432910] x1 : 0000000000000000 x0 : 0000000000000000 
[ 1456.438220]
====

I've used the following script to see if 'perf' had any problems running the equivalent of the hw_watch_addr.stp example script:

====
#!/bin/sh
addr="0x`grep "vm_dirty_ratio" /proc/kallsyms | awk '{print $1}'`"
echo "probing $addr..."
perf record -e mem:${addr}:rw -ag sleep 5
perf report
====

The script runs with no problems. So, this looks like a systemtap issue, not a kernel issue.

Here's an update.

After lots more investigation, I've found a small problem with the systemtap generated code, but it isn't enough to cause the problem we're seeing here. I'm seeing a large stream of these events before the cpu gets stuck - several thousand.

I guessed that perhaps something in the hardware watch code also accessed the vm_dirty_ratio variable, causing an infinite stream of events. However, after creating my own kernel module (where I can control the access to the probed variable), I'm still seeing an infinite stream of events.

I'll continue to debug this issue.

According to <http://stackoverflow.com/questions/28280813/register-wide-hw-breakpoint-continually-triggers-handler-callback>:	

====
This is by design. When an ARM hardware watchpoint is hit, it generates a Data Abort exception. On ARM, Data Abort exceptions trigger before the instruction that triggers them finishes1. This means that, in the exception handler, registers and memory locations affected by the instruction still hold their old values (or, in some cases, undefined values). As such, when the handler finishes, it must retry the aborted instruction so that the interrupted program runs as intended. If the watchpoint is still set when the handler returns, the instruction will trigger it again. This causes the loop...
====

Now the above is actually talking about ARMv7, and we're dealing with ARMv8 here. But, I'll bet a similar thing is happening.

Next I plan to look at what 'perf' is doing and how it handles this problem.

(In reply to David Smith from comment #4)
> Here's an update.
> 
> After lots more investigation, I've found a small problem with the systemtap
> generated code, but it isn't enough to cause the problem we're seeing here.

The "small problem" I mentioned here I fixed in upstream commit d0b322e.

<https://sourceware.org/git/gitweb.cgi?p=systemtap.git;a=commit;h=d0b322eddb2f0f248ced58df8e8448c6e557c81e>

Here's the interesting section from the arm64 hardware breakpoint code (arch/arm64/hw_breakpoint.c):

====
/*
 * Debug exception handlers.
 */
static int breakpoint_handler(unsigned long unused, unsigned int esr,
			      struct pt_regs *regs)
{
	int i, step = 0, *kernel_step;
	u32 ctrl_reg;
	u64 addr, val;
	struct perf_event *bp, **slots;
	struct debug_info *debug_info;
	struct arch_hw_breakpoint_ctrl ctrl;

	slots = this_cpu_ptr(bp_on_reg);
	addr = instruction_pointer(regs);
	debug_info = &current->thread.debug;

	for (i = 0; i < core_num_brps; ++i) {
		rcu_read_lock();

		bp = slots[i];

		if (bp == NULL)
			goto unlock;

		/* Check if the breakpoint value matches. */
		val = read_wb_reg(AARCH64_DBG_REG_BVR, i);
		if (val != (addr & ~0x3))
			goto unlock;

		/* Possible match, check the byte address select to confirm. */
		ctrl_reg = read_wb_reg(AARCH64_DBG_REG_BCR, i);
		decode_ctrl_reg(ctrl_reg, &ctrl);
		if (!((1 << (addr & 0x3)) & ctrl.len))
			goto unlock;

		counter_arch_bp(bp)->trigger = addr;
		perf_bp_event(bp, regs);

		/* Do we need to handle the stepping? */
		if (is_default_overflow_handler(bp))
			step = 1;
unlock:
		rcu_read_unlock();
	}

	if (!step)
		return 0;

	if (user_mode(regs)) {
		debug_info->bps_disabled = 1;
		toggle_bp_registers(AARCH64_DBG_REG_BCR, DBG_ACTIVE_EL0, 0);

		/* If we're already stepping a watchpoint, just return. */
		if (debug_info->wps_disabled)
			return 0;

		if (test_thread_flag(TIF_SINGLESTEP))
			debug_info->suspended_step = 1;
		else
			user_enable_single_step(current);
	} else {
		toggle_bp_registers(AARCH64_DBG_REG_BCR, DBG_ACTIVE_EL1, 0);
		kernel_step = this_cpu_ptr(&stepping_kernel_bp);

		if (*kernel_step != ARM_KERNEL_STEP_NONE)
			return 0;

		if (kernel_active_single_step()) {
			*kernel_step = ARM_KERNEL_STEP_SUSPEND;
		} else {
			*kernel_step = ARM_KERNEL_STEP_ACTIVE;
			kernel_enable_single_step(regs);
		}
	}

	return 0;
}
====

If I'm reading that correctly, the kernel will handle single-stepping over the breakpoint, but only if the breakpoint uses the default handler (see the is_default_overflow_handler() section of code). Since we've got a custom handler, we're expected to handle this ourselves.

I filed a kernel bug against this issue (bug #1435450). For now, we'll have to disable 'kernel.data' probes in systemtap for arm64.

Upstream commit 26f262a disables kernel.data probes on arm64.

Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory, and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://access.redhat.com/errata/RHBA-2017:2301