mm: mmap_sem lock assertion failure in __mlock_vma_pages_range

Hi all,

I've ended up deleting the log file by mistake, but this bug does seem to be important so I'd rather not wait before the same issue is triggered again.

The call chain is:

	mlock (mm/mlock.c:745)
		__mm_populate (mm/mlock.c:700)
			__mlock_vma_pages_range (mm/mlock.c:229)
				VM_BUG_ON(!rwsem_is_locked(&mm->mmap_sem));

It seems to be a rather simple trace triggered from userspace. The only recent patch in the area (that I've noticed) was "mm/mlock: prepare params outside critical region". I've reverted it and trying to testing without it.

Quoted 11 lines · Sasha Levin

Hi all,

I've ended up deleting the log file by mistake, but this bug does seem to be important so I'd rather not wait before the same issue is triggered again.

The call chain is:

	mlock (mm/mlock.c:745)
		__mm_populate (mm/mlock.c:700)
			__mlock_vma_pages_range (mm/mlock.c:229)
				VM_BUG_ON(!rwsem_is_locked(&mm->mmap_sem));

So __mm_populate() is only called by mlock(2) and this VM_BUG_ON seems wrong as we call it without the lock held:

	up_write(&current->mm->mmap_sem);
	if (!error)
		error = __mm_populate(start, len, 0);
	return error;
}

Quoted 4 lines

It seems to be a rather simple trace triggered from userspace. The only recent patch in the area (that I've noticed) was "mm/mlock: prepare params outside critical region". I've reverted it and trying to testing without it.

Odd, this patch should definitely *not* cause this. In any case every operation removed from the critical region is local to the function:

	lock_limit = rlimit(RLIMIT_MEMLOCK);
	lock_limit >>= PAGE_SHIFT;
	locked = len >> PAGE_SHIFT;

	down_write(&current->mm->mmap_sem);

Quoted 30 lines · Davidlohr Bueso

Quoted 11 lines · Sasha Levin

Hi all,

I've ended up deleting the log file by mistake, but this bug does seem to be important so I'd rather not wait before the same issue is triggered again.

The call chain is:

	mlock (mm/mlock.c:745)
		__mm_populate (mm/mlock.c:700)
			__mlock_vma_pages_range (mm/mlock.c:229)
				VM_BUG_ON(!rwsem_is_locked(&mm->mmap_sem));

So __mm_populate() is only called by mlock(2) and this VM_BUG_ON seems wrong as we call it without the lock held:

	up_write(&current->mm->mmap_sem);
	if (!error)
		error = __mm_populate(start, len, 0);
	return error;
}

Quoted 4 lines

It seems to be a rather simple trace triggered from userspace. The only recent patch in the area (that I've noticed) was "mm/mlock: prepare params outside critical region". I've reverted it and trying to testing without it.

Odd, this patch should definitely *not* cause this. In any case every operation removed from the critical region is local to the function:

Quoted 5 lines

	lock_limit = rlimit(RLIMIT_MEMLOCK);
	lock_limit >>= PAGE_SHIFT;
	locked = len >> PAGE_SHIFT;

	down_write(&current->mm->mmap_sem);

Yeah, this patch doesn't look like it's causing it, I guess it was more of a "you touched this code last - do you still remember what's going on here?" :).

It's semi-odd because it seems like an obvious issue to hit with trinity but it's the first time I've seen it and it's probably been there for a while (that BUG_ON is there from 2009).

Quoted 11 lines · Sasha Levin

Hi all,

I've ended up deleting the log file by mistake, but this bug does seem to be important so I'd rather not wait before the same issue is triggered again.

The call chain is:

	mlock (mm/mlock.c:745)
		__mm_populate (mm/mlock.c:700)
			__mlock_vma_pages_range (mm/mlock.c:229)
				VM_BUG_ON(!rwsem_is_locked(&mm->mmap_sem));

So __mm_populate() is only called by mlock(2) and this VM_BUG_ON seems wrong as we call it without the lock held:

	up_write(&current->mm->mmap_sem);
	if (!error)
		error = __mm_populate(start, len, 0);
	return error;
}

I worry about what happens if __get_user_pages decides to do

				if (ret & VM_FAULT_RETRY) {
					if (nonblocking)
						*nonblocking = 0;
					return i;
				}

uh-oh, that just cleared __mm_populate()'s `locked' variable and we'll forget to undo mmap_sem. That won't explain this result, but it's a potential problem.

Quoted 13 lines · On Tue, 11 Mar 2014 13:07:33 -0700 Davidlohr Bueso <[email protected]> wrote:

Quoted 11 lines · Sasha Levin

Hi all,

I've ended up deleting the log file by mistake, but this bug does seem to be important so I'd rather not wait before the same issue is triggered again.

The call chain is:

	mlock (mm/mlock.c:745)
		__mm_populate (mm/mlock.c:700)
			__mlock_vma_pages_range (mm/mlock.c:229)
				VM_BUG_ON(!rwsem_is_locked(&mm->mmap_sem));

Quoted 8 lines

So __mm_populate() is only called by mlock(2) and this VM_BUG_ON seems wrong as we call it without the lock held:

	up_write(&current->mm->mmap_sem);
	if (!error)
		error = __mm_populate(start, len, 0);
	return error;
}

__mm_populate() pretty clearly calls __mlock_vma_pages_range() under down_read(mm->mmap_sem).

I worry about what happens if __get_user_pages decides to do

				if (ret & VM_FAULT_RETRY) {
					if (nonblocking)
						*nonblocking = 0;
					return i;
				}

uh-oh, that just cleared __mm_populate()'s `locked' variable and we'll forget to undo mmap_sem. That won't explain this result, but it's a potential problem.

All I can think is that find_vma() went and returned a vma from a different mm, which would be odd. How about I toss this in there?

All I can think is that find_vma() went and returned a vma from a different mm, which would be odd. How about I toss this in there?

mm/vmacache.c renamed from mm/vmacache.c~a +0 -0

@@ -72,8 +72,10 @@ struct vm_area_struct *vmacache_find(str
  	for (i = 0; i < VMACACHE_SIZE; i++) {

Quoted 7 lines · Andrew Morton

All I can think is that find_vma() went and returned a vma from a different mm, which would be odd. How about I toss this in there?

mm/vmacache.c renamed from mm/vmacache.c~a +0 -0

@@ -72,8 +72,10 @@ struct vm_area_struct *vmacache_find(str
  	for (i = 0; i < VMACACHE_SIZE; i++) {

mm/vmacache.c struct vm_area_struct *vmacache_find(str · line 81

Quoted 10 lines

mm/vmacache.c renamed from mm/vmacache.c~a +3 -1

  		struct vm_area_struct *vma = current->vmacache[i];
 
-		if (vma && vma->vm_start <= addr && vma->vm_end > addr)
+		if (vma && vma->vm_start <= addr && vma->vm_end > addr) {
+			BUG_ON(vma->vm_mm != mm);
  			return vma;
+		}
  	}
 
  	return NULL;

Bingo! With the above patch:

[  243.565794] kernel BUG at mm/vmacache.c:76!
[  243.566720] invalid opcode: 0000 [#1] PREEMPT SMP DEBUG_PAGEALLOC
[  243.568048] Dumping ftrace buffer:
[  243.568740]    (ftrace buffer empty)
[  243.569481] Modules linked in:
[  243.570203] CPU: 10 PID: 10073 Comm: trinity-c332 Tainted: G        W    3.14.0-rc5-next-20140307-sasha-00010-g1f812cb-dirty #143

Quoted 8 lines

Bingo! With the above patch:

Quoted 7 lines

[  243.565794] kernel BUG at mm/vmacache.c:76!
[  243.566720] invalid opcode: 0000 [#1] PREEMPT SMP DEBUG_PAGEALLOC
[  243.568048] Dumping ftrace buffer:
[  243.568740]    (ftrace buffer empty)
[  243.569481] Modules linked in:
[  243.570203] CPU: 10 PID: 10073 Comm: trinity-c332 Tainted: G        W    3.14.0-rc5-next-20140307-sasha-00010-g1f812cb-dirty #143

and this is also part of the DEBUG_PAGEALLOC + trinity combo! I suspect the root cause it the same as Fengguang's report.

Quoted 8 lines · Davidlohr Bueso

Quoted 8 lines

Bingo! With the above patch:

Quoted 7 lines

[  243.565794] kernel BUG at mm/vmacache.c:76!
[  243.566720] invalid opcode: 0000 [#1] PREEMPT SMP DEBUG_PAGEALLOC
[  243.568048] Dumping ftrace buffer:
[  243.568740]    (ftrace buffer empty)
[  243.569481] Modules linked in:
[  243.570203] CPU: 10 PID: 10073 Comm: trinity-c332 Tainted: G        W    3.14.0-rc5-next-20140307-sasha-00010-g1f812cb-dirty #143

Quoted 2 lines

and this is also part of the DEBUG_PAGEALLOC + trinity combo! I suspect the root cause it the same as Fengguang's report.

The BUG still happens without DEBUG_PAGEALLOC.

Quoted 5 lines · Sasha Levin

I've ended up deleting the log file by mistake, but this bug does seem to be important so I'd rather not wait before the same issue is triggered again.

The call chain is:

Quoted 4 lines

      mlock (mm/mlock.c:745)
              __mm_populate (mm/mlock.c:700)
                      __mlock_vma_pages_range (mm/mlock.c:229)
                              VM_BUG_ON(!rwsem_is_locked(&mm->mmap_sem));

So __mm_populate() is only called by mlock(2) and this VM_BUG_ON seems wrong as we call it without the lock held:

Quoted 10 lines · Sasha Levin

Quoted 9 lines · Andrew Morton

All I can think is that find_vma() went and returned a vma from a different mm, which would be odd. How about I toss this in there?

mm/vmacache.c renamed from mm/vmacache.c~a +0 -0

@@ -72,8 +72,10 @@ struct vm_area_struct *vmacache_find(str
  	for (i = 0; i < VMACACHE_SIZE; i++) {
  		struct vm_area_struct *vma = current->vmacache[i];
 

Quoted 8 lines

mm/vmacache.c struct vm_area_struct *vmacache_find(str · line 79

Quoted 6 lines

mm/vmacache.c renamed from mm/vmacache.c~a +3 -1

-		if (vma && vma->vm_start <= addr && vma->vm_end > addr)
+		if (vma && vma->vm_start <= addr && vma->vm_end > addr) {
+			BUG_ON(vma->vm_mm != mm);
  			return vma;
+		}
  	}

[  243.565794] kernel BUG at mm/vmacache.c:76!

and this is also part of the DEBUG_PAGEALLOC + trinity combo! I suspect the root cause it the same as Fengguang's report.

Quoted 9 lines · Sasha Levin

Quoted 9 lines · Davidlohr Bueso

Quoted 8 lines

Quoted 8 lines

Quoted 8 lines

Quoted 8 lines

Bingo! With the above patch:

Quoted 7 lines

Quoted 7 lines

[  243.565794] kernel BUG at mm/vmacache.c:76!
[  243.566720] invalid opcode: 0000 [#1] PREEMPT SMP DEBUG_PAGEALLOC
[  243.568048] Dumping ftrace buffer:
[  243.568740]    (ftrace buffer empty)
[  243.569481] Modules linked in:
[  243.570203] CPU: 10 PID: 10073 Comm: trinity-c332 Tainted: G        W    3.14.0-rc5-next-20140307-sasha-00010-g1f812cb-dirty #143

Quoted 4 lines

Quoted 4 lines

Quoted 2 lines

Quoted 2 lines

and this is also part of the DEBUG_PAGEALLOC + trinity combo! I suspect the root cause it the same as Fengguang's report.

The BUG still happens without DEBUG_PAGEALLOC.

Any idea what trinity itself is doing?

Could you add the following, I just want to make sure the bug isn't being caused by an overflow:

Quoted 13 lines · Davidlohr Bueso

Quoted 12 lines · Sasha Levin

Quoted 12 lines · Davidlohr Bueso

Quoted 10 lines

Quoted 10 lines

Quoted 8 lines

Quoted 8 lines

Bingo! With the above patch:

Quoted 7 lines

Quoted 7 lines

[  243.565794] kernel BUG at mm/vmacache.c:76!
[  243.566720] invalid opcode: 0000 [#1] PREEMPT SMP DEBUG_PAGEALLOC
[  243.568048] Dumping ftrace buffer:
[  243.568740]    (ftrace buffer empty)
[  243.569481] Modules linked in:
[  243.570203] CPU: 10 PID: 10073 Comm: trinity-c332 Tainted: G        W    3.14.0-rc5-next-20140307-sasha-00010-g1f812cb-dirty #143

and this is also part of the DEBUG_PAGEALLOC + trinity combo! I suspect the root cause it the same as Fengguang's report.

Quoted 5 lines

Quoted 1 line

Quoted 1 line

The BUG still happens without DEBUG_PAGEALLOC.

Any idea what trinity itself is doing?

Could you add the following, I just want to make sure the bug isn't being caused by an overflow:

Not hitting that WARN.

Quoted 17 lines · Sasha Levin

Quoted 16 lines · Davidlohr Bueso

Quoted 9 lines · Sasha Levin

Quoted 9 lines · Davidlohr Bueso

Quoted 8 lines

Quoted 8 lines

Quoted 8 lines

Quoted 8 lines

Bingo! With the above patch:

Quoted 7 lines

Quoted 7 lines

[  243.565794] kernel BUG at mm/vmacache.c:76!
[  243.566720] invalid opcode: 0000 [#1] PREEMPT SMP DEBUG_PAGEALLOC
[  243.568048] Dumping ftrace buffer:
[  243.568740]    (ftrace buffer empty)
[  243.569481] Modules linked in:
[  243.570203] CPU: 10 PID: 10073 Comm: trinity-c332 Tainted: G        W    3.14.0-rc5-next-20140307-sasha-00010-g1f812cb-dirty #143

Quoted 4 lines

Quoted 4 lines

Quoted 2 lines

Quoted 2 lines

and this is also part of the DEBUG_PAGEALLOC + trinity combo! I suspect the root cause it the same as Fengguang's report.

The BUG still happens without DEBUG_PAGEALLOC.

Any idea what trinity itself is doing?

Quoted 4 lines

Quoted 2 lines

Could you add the following, I just want to make sure the bug isn't being caused by an overflow:

Not hitting that WARN.

Sasha, could you please try the following patch:
https://lkml.org/lkml/2014/3/13/312

Quoted 21 lines · Davidlohr Bueso

Quoted 20 lines · Sasha Levin

Quoted 18 lines · Davidlohr Bueso

Quoted 9 lines · Sasha Levin

Quoted 9 lines · Davidlohr Bueso

Quoted 8 lines

Quoted 8 lines

Quoted 8 lines

Quoted 8 lines

Bingo! With the above patch:

Quoted 7 lines

Quoted 7 lines

[  243.565794] kernel BUG at mm/vmacache.c:76!
[  243.566720] invalid opcode: 0000 [#1] PREEMPT SMP DEBUG_PAGEALLOC
[  243.568048] Dumping ftrace buffer:
[  243.568740]    (ftrace buffer empty)
[  243.569481] Modules linked in:
[  243.570203] CPU: 10 PID: 10073 Comm: trinity-c332 Tainted: G        W    3.14.0-rc5-next-20140307-sasha-00010-g1f812cb-dirty #143

Quoted 4 lines

Quoted 4 lines

Quoted 2 lines

Quoted 2 lines

and this is also part of the DEBUG_PAGEALLOC + trinity combo! I suspect the root cause it the same as Fengguang's report.

The BUG still happens without DEBUG_PAGEALLOC.

Any idea what trinity itself is doing?

Could you add the following, I just want to make sure the bug isn't being caused by an overflow:

Quoted 4 lines

Quoted 1 line

Not hitting that WARN.

Sasha, could you please try the following patch:
https://lkml.org/lkml/2014/3/13/312

I was getting the "kernel BUG at mm/vmacache.c:76!" running KSM on mmotm: Oleg's patch (buildable version below) fixes it for me.