"kernel BUG at mm/rmap.c:474!" error on 2.6.9

"kernel BUG at mm/rmap.c:474!" error on 2.6.9

[Daniel Fenert]

What could be the real cause of such messages? (I assume that it was not
really apache or php fault (httpd and php shown in logs below)).

Kernel 2.6.9, SATA drive on intel chipset (ICH5), processor is P4 with HT,
1GB of memory. Glibc 2.3.2, gcc version 3.3.4.

On console I've got:
Message from syslogd@sh at Tue Jan 11 10:01:01 2005 ...
sh kernel: Bad page state at prep_new_page (in process 'php', page c17b4580)

Message from syslogd@sh at Tue Jan 11 10:01:01 2005 ...
sh kernel: flags:0x40000114 mapping:00000000 mapcount:-1 count:0

Message from syslogd@sh at Tue Jan 11 10:01:01 2005 ...
sh kernel: Backtrace:

Message from syslogd@sh at Tue Jan 11 10:01:01 2005 ...
sh kernel: Trying to fix it up, but a reboot is needed

>From logs:
Jan 11 10:00:44 sh kernel: ------------[ cut here ]------------
Jan 11 10:00:44 sh kernel: kernel BUG at mm/rmap.c:474!
Jan 11 10:00:44 sh kernel: invalid operand: 0000 [#1]
Jan 11 10:00:44 sh kernel: PREEMPT SMP
Jan 11 10:00:44 sh kernel: Modules linked in: i8xx_tco ide_scsi e1000
Jan 11 10:00:44 sh kernel: CPU:    0
Jan 11 10:00:44 sh kernel: EIP:    0060:[<c014ea30>]    Not tainted VLI
Jan 11 10:00:44 sh kernel: EFLAGS: 00010286   (2.6.9)
Jan 11 10:00:44 sh kernel: EIP is at page_remove_rmap+0x3f/0x53
Jan 11 10:00:44 sh kernel: eax: ffffffff   ebx: 00000000   ecx: c17b4580 edx: c17b4580
Jan 11 10:00:44 sh kernel: esi: de3dd27c   edi: c17b4580   ebp: 00000020 esp: ce236e84
Jan 11 10:00:44 sh kernel: ds: 007b   es: 007b   ss: 0068
Jan 11 10:00:44 sh kernel: Process httpd (pid: 13984, threadinfo=ce236000 task=d01ff730)
Jan 11 10:00:44 sh kernel: Stack: c01485b5 c17b4580 00000000 e4efcf3c c0125ffc b7c9f000 d6773b7c b78a0000
Jan 11 10:00:44 sh kernel:        00000000 c0148789 c180f400 d6773b78 b789f000 00001000 00000000 c180f400
Jan 11 10:00:44 sh kernel:        b789f000 d6773b7c b78a0000 00000000 c01487f0 c180f400 d6773b78 b789f000
Jan 11 10:00:44 sh kernel: Call Trace:
Jan 11 10:00:44 sh kernel:  [<c01485b5>] zap_pte_range+0x13f/0x2bc
Jan 11 10:00:44 sh kernel:  [<c0125ffc>] update_process_times+0x45/0x51
Jan 11 10:00:44 sh kernel:  [<c0148789>] zap_pmd_range+0x57/0x73
Jan 11 10:00:44 sh kernel:  [<c01487f0>] unmap_page_range+0x4b/0x71
Jan 11 10:00:44 sh kernel:  [<c0148917>] unmap_vmas+0x101/0x20e
Jan 11 10:00:44 sh kernel:  [<c014cd36>] exit_mmap+0xa5/0x187
Jan 11 10:00:44 sh kernel:  [<c011b93b>] mmput+0x66/0x91
Jan 11 10:00:44 sh kernel:  [<c0120015>] do_exit+0x17b/0x42a
Jan 11 10:00:44 sh kernel:  [<c0120370>] do_group_exit+0x3c/0xa7
Jan 11 10:00:44 sh kernel:  [<c01050fb>] syscall_call+0x7/0xb
Jan 11 10:00:44 sh kernel: Code: c0 74 27 8b 42 08 83 c0 01 78 20 9c 59 fa b8 00 f0 ff ff ba 20 7c 47 c0 21 e0 8b 40 10 03 14 85 20 b0 47 c0 83 6a 10 01 51 9d c3 <0f> 0b da 01 1d 31 36 c0 eb d6 0f 0b d7 01 1d 31 36 c0 eb b8 83
Jan 11 10:00:44 sh kernel:  <6>note: httpd[13984] exited with preempt_count 1
Jan 11 10:01:01 sh kernel: Bad page state at prep_new_page (in process 'php', page c17b4580)
Jan 11 10:01:01 sh kernel: flags:0x40000114 mapping:00000000 mapcount:-1 count:0
Jan 11 10:01:01 sh kernel: Backtrace:
Jan 11 10:01:01 sh kernel:  [<c013e547>] bad_page+0x78/0xa4
Jan 11 10:01:01 sh kernel:  [<c013e8a6>] prep_new_page+0x32/0x51
Jan 11 10:01:01 sh kernel:  [<c013edf4>] buffered_rmqueue+0x10f/0x1fa
Jan 11 10:01:01 sh kernel:  [<c013f216>] __alloc_pages+0x337/0x358
Jan 11 10:01:01 sh kernel:  [<c0149c6e>] do_anonymous_page+0x98/0x1a5
Jan 11 10:01:01 sh kernel:  [<c0149dde>] do_no_page+0x63/0x324
Jan 11 10:01:01 sh kernel:  [<c014a29b>] handle_mm_fault+0xf4/0x16c
Jan 11 10:01:01 sh kernel:  [<c011713e>] do_page_fault+0x39d/0x5a4
Jan 11 10:01:01 sh kernel:  [<c01cfaba>] journal_stop+0x1ad/0x26e
Jan 11 10:01:01 sh kernel:  [<c01c4224>] ext3_mark_iloc_dirty+0x29/0x37
Jan 11 10:01:01 sh kernel:  [<c01c434d>] ext3_mark_inode_dirty+0x4f/0x51
Jan 11 10:01:01 sh kernel:  [<c01c862d>] __ext3_journal_stop+0x24/0x50
Jan 11 10:01:01 sh kernel:  [<c01c43b8>] ext3_dirty_inode+0x69/0x87
Jan 11 10:01:01 sh kernel:  [<c0116da1>] do_page_fault+0x0/0x5a4
Jan 11 10:01:01 sh kernel:  [<c0105b85>] error_code+0x2d/0x38
Jan 11 10:01:01 sh kernel:  [<c013b475>] file_read_actor+0x20/0xec
Jan 11 10:01:01 sh kernel:  [<c013b0bc>] do_generic_mapping_read+0x1a6/0x53f
Jan 11 10:01:01 sh kernel:  [<c013b735>] __generic_file_aio_read+0x1f4/0x226
Jan 11 10:01:01 sh kernel:  [<c013b455>] file_read_actor+0x0/0xec
Jan 11 10:01:01 sh kernel:  [<c016f2a0>] dput+0x24/0x1af
Jan 11 10:01:01 sh kernel:  [<c013b7c1>] generic_file_aio_read+0x5a/0x74
Jan 11 10:01:01 sh kernel:  [<c01580de>] do_sync_read+0xbe/0xeb
Jan 11 10:01:01 sh kernel:  [<c014bced>] do_mmap_pgoff+0x44e/0x735
Jan 11 10:01:01 sh kernel:  [<c011b636>] autoremove_wake_function+0x0/0x57
Jan 11 10:01:01 sh kernel:  [<c01581bb>] vfs_read+0xb0/0x119
Jan 11 10:01:01 sh kernel:  [<c0158479>] sys_read+0x51/0x80
Jan 11 10:01:01 sh kernel:  [<c01050fb>] syscall_call+0x7/0xb
Jan 11 10:01:01 sh kernel: Trying to fix it up, but a reboot is needed

And after ~15 minutes machine rebooted (possibly it was caused by i8xx_tco
module and softdog).

-- 
Daniel Fenert                 --==> daniel@fenert.net <==--

Re: "kernel BUG at mm/rmap.c:474!" error on 2.6.9

[Hugh Dickins]

On Tue, 11 Jan 2005, Daniel Fenert wrote:
> What could be the real cause of such messages? (I assume that it was not
> really apache or php fault (httpd and php shown in logs below)).

We still do not know; we'd very much like to know.

It would not be the fault of any userspace program
(unless they corrupt via /dev/mem or something like that).

It may be a core kernel problem, but I've searched repeatedly and
failed.  It may be a driver problem e.g. GregKH's incident suggested
a problem in DRM, and Andrea has pointed to a worrying ioctl there
(looks like it could ClearPageReserved too early): I've been halfway
through following that up for a few weeks now.  Are you using DRM?
(but the hallmarks in your case are different.)

It can be caused by somewhere freeing a page it no longer holds;
but in that case we'd usually expect to see the Bad page state
error coming from free_pages_check rather than prep_new_page,
and to be followed by the rmap.c BUG rather than following it.

It could easily be caused by bad memory bitflipping in a page table
(but in general, we'd expect to be hearing of swap_free errors,
or random corruption, if that were generally the case - I think).
Please give memtest86 a good run to rule out that possibility.

If memtest86 is satifisfied, would you mind running with the patch
below (against 2.6.9, suitable for i386 or x86_64, but not suitable
for the various architectures which use PG_arch_1)?  To give us more
debug info - it's unlikely to solve the mystery on it's own, but I
hope it might help us to look in the right direction.  And send me
any "Bad rmap" and "Bad page state" log entries you find (but
perhaps this was a one-off, and nothing more will appear).

Thanks,
Hugh

> Kernel 2.6.9, SATA drive on intel chipset (ICH5), processor is P4 with HT,
> 1GB of memory. Glibc 2.3.2, gcc version 3.3.4.

> Jan 11 10:00:44 sh kernel: kernel BUG at mm/rmap.c:474!
> Jan 11 10:00:44 sh kernel: EIP is at page_remove_rmap+0x3f/0x53
> Jan 11 10:00:44 sh kernel: eax: ffffffff   ebx: 00000000   ecx: c17b4580 edx: c17b4580
> Jan 11 10:00:44 sh kernel: esi: de3dd27c   edi: c17b4580   ebp: 00000020 esp: ce236e84
> Jan 11 10:01:01 sh kernel: Bad page state at prep_new_page (in process 'php', page c17b4580)
> Jan 11 10:01:01 sh kernel: flags:0x40000114 mapping:00000000 mapcount:-1 count:0

--- 2.6.9/include/linux/rmap.h	2004-10-18 22:55:54.000000000 +0100
+++ linux/include/linux/rmap.h	2005-01-11 13:16:39.000000000 +0000
@@ -71,7 +71,7 @@ void __anon_vma_link(struct vm_area_stru
  */
 void page_add_anon_rmap(struct page *, struct vm_area_struct *, unsigned long);
 void page_add_file_rmap(struct page *);
-void page_remove_rmap(struct page *);
+void page_remove_rmap(struct page *, struct vm_area_struct *, unsigned long);
 
 /**
  * page_dup_rmap - duplicate pte mapping to a page
--- 2.6.9/mm/fremap.c	2004-10-18 22:55:54.000000000 +0100
+++ linux/mm/fremap.c	2005-01-11 13:16:39.000000000 +0000
@@ -36,7 +36,7 @@ static inline void zap_pte(struct mm_str
 			if (!PageReserved(page)) {
 				if (pte_dirty(pte))
 					set_page_dirty(page);
-				page_remove_rmap(page);
+				page_remove_rmap(page, vma, addr);
 				page_cache_release(page);
 				mm->rss--;
 			}
--- 2.6.9/mm/memory.c	2004-10-18 22:56:29.000000000 +0100
+++ linux/mm/memory.c	2005-01-11 13:16:39.000000000 +0000
@@ -356,6 +356,7 @@ nomem:
 }
 
 static void zap_pte_range(struct mmu_gather *tlb,
+		struct vm_area_struct *vma,
 		pmd_t *pmd, unsigned long address,
 		unsigned long size, struct zap_details *details)
 {
@@ -419,7 +420,7 @@ static void zap_pte_range(struct mmu_gat
 			if (pte_young(pte) && !PageAnon(page))
 				mark_page_accessed(page);
 			tlb->freed++;
-			page_remove_rmap(page);
+			page_remove_rmap(page, vma, address+offset);
 			tlb_remove_page(tlb, page);
 			continue;
 		}
@@ -437,6 +438,7 @@ static void zap_pte_range(struct mmu_gat
 }
 
 static void zap_pmd_range(struct mmu_gather *tlb,
+		struct vm_area_struct *vma,
 		pgd_t * dir, unsigned long address,
 		unsigned long size, struct zap_details *details)
 {
@@ -455,7 +457,7 @@ static void zap_pmd_range(struct mmu_gat
 	if (end > ((address + PGDIR_SIZE) & PGDIR_MASK))
 		end = ((address + PGDIR_SIZE) & PGDIR_MASK);
 	do {
-		zap_pte_range(tlb, pmd, address, end - address, details);
+		zap_pte_range(tlb, vma, pmd, address, end - address, details);
 		address = (address + PMD_SIZE) & PMD_MASK; 
 		pmd++;
 	} while (address && (address < end));
@@ -471,7 +473,7 @@ static void unmap_page_range(struct mmu_
 	dir = pgd_offset(vma->vm_mm, address);
 	tlb_start_vma(tlb, vma);
 	do {
-		zap_pmd_range(tlb, dir, address, end - address, details);
+		zap_pmd_range(tlb, vma, dir, address, end - address, details);
 		address = (address + PGDIR_SIZE) & PGDIR_MASK;
 		dir++;
 	} while (address && (address < end));
@@ -1098,7 +1100,7 @@ static int do_wp_page(struct mm_struct *
 		if (PageReserved(old_page))
 			++mm->rss;
 		else
-			page_remove_rmap(old_page);
+			page_remove_rmap(old_page, vma, address);
 		break_cow(vma, new_page, address, page_table);
 		lru_cache_add_active(new_page);
 		page_add_anon_rmap(new_page, vma, address);
--- 2.6.9/mm/rmap.c	2004-10-18 22:57:03.000000000 +0100
+++ linux/mm/rmap.c	2005-01-11 13:20:28.000000000 +0000
@@ -453,8 +453,12 @@ void page_add_anon_rmap(struct page *pag
 void page_add_file_rmap(struct page *page)
 {
 	BUG_ON(PageAnon(page));
-	if (!pfn_valid(page_to_pfn(page)) || PageReserved(page))
+	if (!pfn_valid(page_to_pfn(page)))
 		return;
+	if (PageReserved(page)) {
+		set_bit(PG_arch_1, &page->flags);
+		return;
+	}
 
 	if (atomic_inc_and_test(&page->_mapcount))
 		inc_page_state(nr_mapped);
@@ -466,12 +470,36 @@ void page_add_file_rmap(struct page *pag
  *
  * Caller needs to hold the mm->page_table_lock.
  */
-void page_remove_rmap(struct page *page)
+void page_remove_rmap(struct page *page,
+	struct vm_area_struct *vma, unsigned long address)
 {
+	struct address_space *mapping = NULL;
+	unsigned long index;
+
 	BUG_ON(PageReserved(page));
 
+	index = (address - vma->vm_start) >> PAGE_SHIFT;
+	index += vma->vm_pgoff;
+
+	if (PageAnon(page))
+		mapping = (void *) vma->anon_vma + PAGE_MAPPING_ANON;
+	else if (!(vma->vm_flags & (VM_IO|VM_RESERVED)))
+		mapping = vma->vm_file? vma->vm_file->f_mapping: (void *)(-1);
+
+	if (page_mapcount(page) <= 0 || page_count(page) <= 0 ||
+	    (mapping && (mapping != page->mapping || index != page->index)) ||
+	    test_bit(PG_arch_1, &page->flags)) {
+		printk("Bad rmap in %s: page %p flags %lx "
+			"count %d mapcount %d addr %lx vm_flags %lx\n",
+			current->comm, page, (unsigned long)page->flags,
+			page_count(page), page_mapcount(page), address,
+			vma->vm_flags);
+		printk("\tpage mapping %p index %lx vma mapping %p index %lx\n",
+			page->mapping, page->index, mapping, index);
+		get_page(page);
+		return;
+	}
 	if (atomic_add_negative(-1, &page->_mapcount)) {
-		BUG_ON(page_mapcount(page) < 0);
 		/*
 		 * It would be tidy to reset the PageAnon mapping here,
 		 * but that might overwrite a racing page_add_anon_rmap
@@ -581,7 +609,7 @@ static int try_to_unmap_one(struct page 
 	}
 
 	mm->rss--;
-	page_remove_rmap(page);
+	page_remove_rmap(page, vma, address);
 	page_cache_release(page);
 
 out_unmap:
@@ -678,7 +706,7 @@ static void try_to_unmap_cluster(unsigne
 		if (pte_dirty(pteval))
 			set_page_dirty(page);
 
-		page_remove_rmap(page);
+		page_remove_rmap(page, vma, address);
 		page_cache_release(page);
 		mm->rss--;
 		(*mapcount)--;

Re: "kernel BUG at mm/rmap.c:474!" error on 2.6.9

[Daniel Fenert]

W dniu Tue, Jan 11, 2005 at 02:09:51PM +0000, Hugh Dickins wystukał(a):
>> What could be the real cause of such messages? (I assume that it was not
>> really apache or php fault (httpd and php shown in logs below)).
>
>It could easily be caused by bad memory bitflipping in a page table
>(but in general, we'd expect to be hearing of swap_free errors,
>or random corruption, if that were generally the case - I think).
>Please give memtest86 a good run to rule out that possibility.

I hardly can touch this machine, but I'll try tomorrow morning run memtest86
for some 20 minutes.

>If memtest86 is satifisfied, would you mind running with the patch
>below (against 2.6.9, suitable for i386 or x86_64, but not suitable
>for the various architectures which use PG_arch_1)?  To give us more
>debug info - it's unlikely to solve the mystery on it's own, but I
>hope it might help us to look in the right direction.  And send me
>any "Bad rmap" and "Bad page state" log entries you find (but
>perhaps this was a one-off, and nothing more will appear).

I'll try the patch.
This has happend for the first time (I have some problems with this
machine, but utill now there were only httpd(php) processes eating all
memory until machine is locked - that's why software watchdog is running
there).

-- 
Daniel Fenert                       --==> daniel@fenert.net <==--
====-P o w e r e d--b y--S l a c k w a r e-===-ICQ #37739641-====
Wonderful day. Your hangover just makes it seem terrible.
==========- http://daniel.fenert.net/ -==========< +48604628083 >

Re: "kernel BUG at mm/rmap.c:474!" error on 2.6.9

[Hugh Dickins]

On Tue, 11 Jan 2005, Daniel Fenert wrote:
> 
> I hardly can touch this machine,

Understood: thanks for trying.

> but I'll try tomorrow morning run memtest86 for some 20 minutes.

If it reports an error, that will be significant.  But if it does
not, I don't think we can conclude anything from such a short run.
Anyway, better than nothing.

> I'll try the patch.

Much appreciated.

Hugh