Debian Bug report logs - #666021
linux-image-3.2.0-2-powerpc64: Kernel reports page allocation failure: order:1, mode:0x20

Reply or subscribe to this bug.

Toggle useless messages

Message #5 received at submit@bugs.debian.org (full text, mbox, reply):

From: Petr Tichy <spaceboy@spaceboy.cz>

To: Debian Bug Tracking System <submit@bugs.debian.org>

Subject: linux-image-3.2.0-2-powerpc64: Kernel reports page allocation failure: order:1, mode:0x20

Date: Tue, 27 Mar 2012 23:00:54 +0200

Package: linux-2.6
Version: 3.2.12-1
Severity: normal



-- Package-specific info:
** Version:
Linux version 3.2.0-2-powerpc64 (Debian 3.2.9-1) (debian-kernel@lists.debian.org) (gcc version 4.6.2 (Debian 4.6.2-11) ) #1 SMP Sun Mar 4 22:46:58 UTC 2012

** Command line:
ro root=UUID=164e826d-0477-46ef-b426-5b06bc352dbe 

** Not tainted

** Kernel log:
Mar 27 16:36:25 addict kernel: [958021.754593] afpd: page allocation failure: order:1, mode:0x20
Mar 27 16:36:25 addict kernel: [958021.759018] Call Trace:
Mar 27 16:36:25 addict kernel: [958021.763346] [c00000000fffee10] [c0000000000134f4] .show_stack+0x80/0x130 (unreliable)
Mar 27 16:36:25 addict kernel: [958021.772169] [c00000000fffeec0] [c000000000118ea0] .warn_alloc_failed+0xf0/0x108
Mar 27 16:36:25 addict kernel: [958021.781514] [c00000000fffef80] [c00000000011c170] .__alloc_pages_nodemask+0x700/0x7c4
Mar 27 16:36:25 addict kernel: [958021.791170] [c00000000ffff110] [c000000000158754] .kmem_getpages+0x5c/0x140
Mar 27 16:36:25 addict kernel: [958021.796193] [c00000000ffff1b0] [c000000000158a78] .fallback_alloc+0x174/0x200
Mar 27 16:36:25 addict kernel: [958021.805902] [c00000000ffff290] [c00000000015a474] .kmem_cache_alloc+0x104/0x1f8
Mar 27 16:36:25 addict kernel: [958021.815720] [c00000000ffff350] [c0000000003c2970] .sk_prot_alloc+0x38/0x1c4
Mar 27 16:36:25 addict kernel: [958021.820730] [c00000000ffff400] [c0000000003c3a0c] .sk_clone+0x20/0x2cc
Mar 27 16:36:25 addict kernel: [958021.825597] [c00000000ffff4a0] [c000000000412bcc] .inet_csk_clone+0x1c/0x94
Mar 27 16:36:25 addict kernel: [958021.830363] [c00000000ffff530] [c00000000042bb14] .tcp_create_openreq_child+0x24/0x3e8
Mar 27 16:36:25 addict kernel: [958021.839509] [c00000000ffff5e0] [c00000000042a044] .tcp_v4_syn_recv_sock+0x3c/0x31c
Mar 27 16:36:25 addict kernel: [958021.848762] [c00000000ffff680] [c00000000042b91c] .tcp_check_req+0x350/0x524
Mar 27 16:36:25 addict kernel: [958021.853539] [c00000000ffff770] [c000000000428e54] .tcp_v4_do_rcv+0x200/0x3c8
Mar 27 16:36:25 addict kernel: [958021.858296] [c00000000ffff850] [c00000000042af18] .tcp_v4_rcv+0x558/0x940
Mar 27 16:36:25 addict kernel: [958021.862960] [c00000000ffff940] [c000000000408148] .ip_local_deliver_finish+0x1d0/0x2d8
Mar 27 16:36:25 addict kernel: [958021.872130] [c00000000ffff9e0] [c000000000407f58] .ip_rcv_finish+0x374/0x394
Mar 27 16:36:25 addict kernel: [958021.877041] [c00000000ffffa70] [c0000000003d098c] .__netif_receive_skb+0x698/0x6e8
Mar 27 16:36:25 addict kernel: [958021.886864] [c00000000ffffb60] [c0000000003d1fe4] .netif_receive_skb+0x90/0x98
Mar 27 16:36:25 addict kernel: [958021.897170] [c00000000ffffc00] [c0000000003d4a04] .napi_skb_finish+0x34/0x58
Mar 27 16:36:25 addict kernel: [958021.902610] [c00000000ffffc80] [d000000000b44bfc] .gem_poll+0x1c04/0x1ea4 [sungem]
Mar 27 16:36:25 addict kernel: [958021.912974] [c00000000ffffdc0] [c0000000003d2244] .net_rx_action+0xd0/0x30c
Mar 27 16:36:25 addict kernel: [958021.918263] [c00000000ffffeb0] [c00000000008b718] .__do_softirq+0x158/0x2a0
Mar 27 16:36:25 addict kernel: [958021.923431] [c00000000fffff90] [c00000000001c674] .call_do_softirq+0x14/0x24
Mar 27 16:36:25 addict kernel: [958021.928489] [c00000007732ef40] [c00000000000eda4] .do_softirq+0x7c/0xec
Mar 27 16:36:25 addict kernel: [958021.933423] [c00000007732efe0] [c00000000008ba6c] .irq_exit+0x4c/0x9c
Mar 27 16:36:25 addict kernel: [958021.938229] [c00000007732f060] [c00000000000ec04] .do_IRQ+0x1c4/0x240
Mar 27 16:36:25 addict kernel: [958021.943028] [c00000007732f110] [c00000000000553c] hardware_interrupt_entry+0x18/0x1c
Mar 27 16:36:25 addict kernel: [958021.952224] --- Exception: 501 at _savegpr0_31+0x8/0xc
Mar 27 16:36:25 addict kernel: [958021.952227]     LR = .bit_waitqueue+0x10/0x9c
Mar 27 16:36:25 addict kernel: [958021.961229] [c00000007732f400] [c0000000000a608c] .wake_up_bit+0x18/0x38 (unreliable)
Mar 27 16:36:25 addict kernel: [958021.970406] [c00000007732f490] [c000000000182aa4] .evict+0x190/0x1f8
Mar 27 16:36:25 addict kernel: [958021.975227] [c00000007732f530] [c000000000182b40] .dispose_list+0x34/0x48
Mar 27 16:36:25 addict kernel: [958021.979938] [c00000007732f5b0] [c000000000184084] .prune_icache_sb+0x334/0x33c
Mar 27 16:36:25 addict kernel: [958021.988908] [c00000007732f690] [c00000000016bd10] .prune_super+0x110/0x1bc
Mar 27 16:36:25 addict kernel: [958021.993499] [c00000007732f730] [c000000000124fa4] .shrink_slab+0x218/0x334
Mar 27 16:36:25 addict kernel: [958021.998102] [c00000007732f850] [c000000000127bc4] .do_try_to_free_pages+0x2b4/0x498
Mar 27 16:36:25 addict kernel: [958022.007246] [c00000007732f950] [c000000000128100] .try_to_free_pages+0xf8/0x16c
Mar 27 16:36:25 addict kernel: [958022.016489] [c00000007732fa60] [c00000000011bf60] .__alloc_pages_nodemask+0x4f0/0x7c4
Mar 27 16:36:25 addict kernel: [958022.025982] [c00000007732fbf0] [c000000000081d24] .copy_process+0x110/0x10a4
Mar 27 16:36:25 addict kernel: [958022.030829] [c00000007732fce0] [c000000000082df4] .do_fork+0xfc/0x30c
Mar 27 16:36:25 addict kernel: [958022.035530] [c00000007732fdc0] [c000000000013298] .sys_clone+0x54/0x6c
Mar 27 16:36:25 addict kernel: [958022.040108] [c00000007732fe30] [c000000000009aa4] .ppc_clone+0x8/0xc
Mar 27 16:36:25 addict kernel: [958022.044642] Mem-Info:
Mar 27 16:36:25 addict kernel: [958022.048993] Node 0 DMA per-cpu:
Mar 27 16:36:25 addict kernel: [958022.053231] CPU    0: hi:  186, btch:  31 usd:  82
Mar 27 16:36:25 addict kernel: [958022.057531] active_anon:2066 inactive_anon:713 isolated_anon:0
Mar 27 16:36:25 addict kernel: [958022.057534]  active_file:91213 inactive_file:338749 isolated_file:0
Mar 27 16:36:25 addict kernel: [958022.057538]  unevictable:0 dirty:0 writeback:0 unstable:0
Mar 27 16:36:25 addict kernel: [958022.057540]  free:2485 slab_reclaimable:40051 slab_unreclaimable:12370
Mar 27 16:36:25 addict kernel: [958022.057544]  mapped:3751 shmem:113 pagetables:404 bounce:0
Mar 27 16:36:25 addict kernel: [958022.079936] Node 0 DMA free:9940kB min:5752kB low:7188kB high:8628kB active_anon:8264kB inactive_anon:2852kB active_file:364852kB inactive_file:1354996kB une
Mar 27 16:36:25 addict kernel: [958022.108486] lowmem_reserve[]: 0 0 0
Mar 27 16:36:25 addict kernel: [958022.113305] Node 0 DMA: 2405*4kB 12*8kB 14*16kB 0*32kB 0*64kB 0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB 0*8192kB 0*16384kB = 9940kB
Mar 27 16:36:25 addict kernel: [958022.123311] 431155 total pagecache pages
Mar 27 16:36:25 addict kernel: [958022.128153] 1074 pages in swap cache
Mar 27 16:36:25 addict kernel: [958022.132993] Swap cache stats: add 87048, delete 85974, find 698048/712309
Mar 27 16:36:25 addict kernel: [958022.138002] Free swap  = 2074064kB
Mar 27 16:36:25 addict kernel: [958022.142852] Total swap = 2097148kB
Mar 27 16:36:25 addict kernel: [958022.163599] 524288 pages RAM
Mar 27 16:36:25 addict kernel: [958022.168151] 22936 pages reserved
Mar 27 16:36:25 addict kernel: [958022.172553] 306940 pages shared
Mar 27 16:36:25 addict kernel: [958022.176808] 194707 pages non-shared

** Model information
revision	: 2.2 (pvr 0039 0202)
platform	: PowerMac
model		: PowerMac7,2
machine		: PowerMac7,2
motherboard	: PowerMac7,2 MacRISC4 Power Macintosh

** Loaded modules:
sha1_generic
arc4
ecb
ppp_mppe
ppp_async
crc_ccitt
ppp_generic
slhc
iptable_filter
ip_tables
cpufreq_stats
cpufreq_powersave
cpufreq_userspace
cpufreq_conservative
cpufreq_ondemand
tun
sit
tunnel4
ip6_queue
act_police
cls_flow
cls_fw
cls_u32
sch_htb
sch_ingress
sch_sfq
ip6t_LOG
xt_connlimit
ip6table_raw
xt_comment
ip6t_REJECT
xt_recent
ip6table_mangle
nf_conntrack_ipv6
nf_conntrack_tftp
nf_conntrack_sip
nf_conntrack_sane
nf_conntrack_proto_udplite
nf_conntrack_proto_sctp
nf_conntrack_pptp
nf_conntrack_proto_gre
nf_conntrack_netlink
nf_conntrack_netbios_ns
nf_conntrack_broadcast
nf_conntrack_irc
nf_conntrack_h323
nf_conntrack_ftp
ts_kmp
nf_conntrack_amanda
xt_TPROXY
nf_tproxy_core
nf_defrag_ipv6
nf_defrag_ipv4
xt_time
xt_TCPMSS
xt_tcpmss
xt_sctp
xt_policy
xt_pkttype
xt_physdev
xt_owner
xt_NFQUEUE
xt_multiport
xt_mark
xt_mac
xt_limit
xt_length
xt_iprange
xt_helper
xt_hashlimit
xt_DSCP
xt_dscp
xt_dccp
xt_connmark
xt_CLASSIFY
xt_tcpudp
xt_state
xt_conntrack
nf_conntrack
nfnetlink
ip6table_filter
ip6_tables
x_tables
adm1021
loop
pl2303
snd_aoa_codec_tas
snd_aoa_fabric_layout
snd_aoa
snd_aoa_i2sbus
snd_aoa_soundbus
snd_pcm
evdev
snd_page_alloc
snd_timer
i2c_powermac
snd
usbserial
soundcore
xfs
dm_mod
raid1
md_mod
ses
enclosure
sd_mod
sg
firewire_sbp2
crc_t10dif
ata_generic
ohci_hcd
ehci_hcd
usbcore
firewire_ohci
firewire_core
sr_mod
sungem
sungem_phy
therm_pm72
sata_svw
cdrom
crc_itu_t
usb_common
sata_sil

** PCI devices:
0000:f0:0b.0 Host bridge [0600]: Apple Computer Inc. U3 AGP [106b:004b]
	Control: I/O- Mem+ BusMaster+ SpecCycle- MemWINV+ VGASnoop- ParErr- Stepping- SERR- FastB2B- DisINTx-
	Status: Cap+ 66MHz+ UDF- FastB2B+ ParErr- DEVSEL=medium >TAbort- <TAbort- <MAbort+ >SERR- <PERR- INTx-
	Latency: 16, Cache Line Size: 32 bytes
	Capabilities: <access denied>
	Kernel driver in use: agpgart-uninorth

0000:f0:10.0 VGA compatible controller [0300]: nVidia Corporation NV34 [GeForce FX 5200 Ultra] [10de:0321] (rev a1) (prog-if 00 [VGA controller])
	Subsystem: nVidia Corporation Device [10de:0010]
	Control: I/O- Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr- Stepping- SERR- FastB2B- DisINTx-
	Status: Cap+ 66MHz+ UDF- FastB2B+ ParErr- DEVSEL=medium >TAbort- <TAbort- <MAbort- >SERR- <PERR- INTx-
	Latency: 16 (1250ns min, 250ns max)
	Interrupt: pin A routed to IRQ 48
	Region 0: Memory at a1000000 (32-bit, non-prefetchable) [size=16M]
	Region 1: Memory at a8000000 (32-bit, prefetchable) [size=128M]
	Expansion ROM at a0000000 [disabled] [size=128K]
	Capabilities: <access denied>

0001:00:00.0 Host bridge [0600]: Apple Computer Inc. CPC945 HT Bridge [106b:004a]
	Control: I/O- Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr- Stepping- SERR- FastB2B- DisINTx-
	Status: Cap+ 66MHz- UDF- FastB2B- ParErr- DEVSEL=fast >TAbort- <TAbort- <MAbort- >SERR- <PERR- INTx-
	Latency: 0
	Capabilities: <access denied>

0001:00:01.0 PCI bridge [0604]: Advanced Micro Devices [AMD] AMD-8131 PCI-X Bridge [1022:7450] (rev 12) (prog-if 00 [Normal decode])
	Control: I/O+ Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr- Stepping- SERR+ FastB2B- DisINTx-
	Status: Cap+ 66MHz+ UDF- FastB2B- ParErr- DEVSEL=medium >TAbort- <TAbort- <MAbort- >SERR- <PERR- INTx-
	Latency: 32
	Bus: primary=00, secondary=06, subordinate=06, sec-latency=32
	I/O behind bridge: 00001000-00001fff
	Memory behind bridge: 90000000-900fffff
	Secondary status: 66MHz+ FastB2B- ParErr- DEVSEL=medium >TAbort- <TAbort- <MAbort- <SERR- <PERR-
	BridgeCtl: Parity- SERR- NoISA- VGA- MAbort- >Reset- FastB2B-
		PriDiscTmr- SecDiscTmr- DiscTmrStat+ DiscTmrSERREn-
	Capabilities: <access denied>

0001:00:02.0 PCI bridge [0604]: Advanced Micro Devices [AMD] AMD-8131 PCI-X Bridge [1022:7450] (rev 12) (prog-if 00 [Normal decode])
	Control: I/O+ Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr- Stepping- SERR+ FastB2B- DisINTx-
	Status: Cap+ 66MHz+ UDF- FastB2B- ParErr- DEVSEL=medium >TAbort- <TAbort- <MAbort- >SERR- <PERR- INTx-
	Latency: 32
	Bus: primary=00, secondary=07, subordinate=07, sec-latency=32
	Secondary status: 66MHz+ FastB2B- ParErr- DEVSEL=medium >TAbort- <TAbort- <MAbort+ <SERR- <PERR-
	BridgeCtl: Parity- SERR- NoISA- VGA- MAbort- >Reset- FastB2B-
		PriDiscTmr- SecDiscTmr- DiscTmrStat- DiscTmrSERREn-
	Capabilities: <access denied>

0001:00:03.0 PCI bridge [0604]: Apple Computer Inc. K2 HT-PCI Bridge [106b:0045] (prog-if 00 [Normal decode])
	Control: I/O+ Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr- Stepping- SERR+ FastB2B- DisINTx-
	Status: Cap+ 66MHz- UDF- FastB2B- ParErr- DEVSEL=fast >TAbort- <TAbort- <MAbort- >SERR- <PERR- INTx-
	Latency: 0, Cache Line Size: 64 bytes
	Bus: primary=00, secondary=01, subordinate=01, sec-latency=32
	Memory behind bridge: 80000000-800fffff
	Prefetchable memory behind bridge: 00000000-000fffff
	Secondary status: 66MHz+ FastB2B+ ParErr- DEVSEL=medium >TAbort- <TAbort- <MAbort- <SERR- <PERR-
	BridgeCtl: Parity- SERR- NoISA- VGA- MAbort- >Reset- FastB2B-
		PriDiscTmr- SecDiscTmr- DiscTmrStat- DiscTmrSERREn-
	Capabilities: <access denied>

0001:00:04.0 PCI bridge [0604]: Apple Computer Inc. K2 HT-PCI Bridge [106b:0046] (prog-if 00 [Normal decode])
	Control: I/O+ Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr- Stepping- SERR- FastB2B- DisINTx-
	Status: Cap+ 66MHz- UDF- FastB2B- ParErr- DEVSEL=fast >TAbort- <TAbort- <MAbort- >SERR- <PERR- INTx-
	Latency: 0, Cache Line Size: 64 bytes
	Bus: primary=00, secondary=02, subordinate=02, sec-latency=32
	Memory behind bridge: 80100000-801fffff
	Prefetchable memory behind bridge: 00000000-000fffff
	Secondary status: 66MHz+ FastB2B+ ParErr- DEVSEL=medium >TAbort- <TAbort- <MAbort+ <SERR- <PERR-
	BridgeCtl: Parity- SERR- NoISA- VGA- MAbort- >Reset- FastB2B-
		PriDiscTmr- SecDiscTmr- DiscTmrStat- DiscTmrSERREn-
	Capabilities: <access denied>

0001:00:05.0 PCI bridge [0604]: Apple Computer Inc. K2 HT-PCI Bridge [106b:0047] (prog-if 00 [Normal decode])
	Control: I/O+ Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr- Stepping- SERR- FastB2B- DisINTx-
	Status: Cap+ 66MHz- UDF- FastB2B- ParErr- DEVSEL=fast >TAbort- <TAbort- <MAbort- >SERR- <PERR- INTx-
	Latency: 0, Cache Line Size: 64 bytes
	Bus: primary=00, secondary=03, subordinate=03, sec-latency=32
	Memory behind bridge: 80200000-802fffff
	Prefetchable memory behind bridge: 00000000-000fffff
	Secondary status: 66MHz+ FastB2B+ ParErr- DEVSEL=medium >TAbort- <TAbort- <MAbort- <SERR- <PERR-
	BridgeCtl: Parity- SERR- NoISA- VGA- MAbort- >Reset- FastB2B-
		PriDiscTmr- SecDiscTmr- DiscTmrStat- DiscTmrSERREn-
	Capabilities: <access denied>

0001:00:06.0 PCI bridge [0604]: Apple Computer Inc. K2 HT-PCI Bridge [106b:0048] (prog-if 00 [Normal decode])
	Control: I/O+ Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr- Stepping- SERR- FastB2B- DisINTx-
	Status: Cap+ 66MHz- UDF- FastB2B- ParErr- DEVSEL=fast >TAbort- <TAbort- <MAbort- >SERR- <PERR- INTx-
	Latency: 0, Cache Line Size: 64 bytes
	Bus: primary=00, secondary=04, subordinate=04, sec-latency=32
	Memory behind bridge: 80300000-805fffff
	Prefetchable memory behind bridge: 00000000-000fffff
	Secondary status: 66MHz+ FastB2B+ ParErr- DEVSEL=medium >TAbort- <TAbort- <MAbort- <SERR- <PERR-
	BridgeCtl: Parity- SERR- NoISA- VGA- MAbort- >Reset- FastB2B-
		PriDiscTmr- SecDiscTmr- DiscTmrStat- DiscTmrSERREn-
	Capabilities: <access denied>

0001:00:07.0 PCI bridge [0604]: Apple Computer Inc. K2 HT-PCI Bridge [106b:0049] (prog-if 00 [Normal decode])
	Control: I/O+ Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr- Stepping- SERR- FastB2B- DisINTx-
	Status: Cap+ 66MHz- UDF- FastB2B- ParErr- DEVSEL=fast >TAbort- <TAbort- <MAbort- >SERR- <PERR- INTx-
	Latency: 0, Cache Line Size: 64 bytes
	Bus: primary=00, secondary=05, subordinate=05, sec-latency=32
	Memory behind bridge: 80600000-806fffff
	Prefetchable memory behind bridge: 00000000-000fffff
	Secondary status: 66MHz+ FastB2B+ ParErr- DEVSEL=medium >TAbort- <TAbort- <MAbort+ <SERR- <PERR-
	BridgeCtl: Parity- SERR- NoISA- VGA- MAbort- >Reset- FastB2B-
		PriDiscTmr- SecDiscTmr- DiscTmrStat- DiscTmrSERREn-
	Capabilities: <access denied>

0001:01:07.0 Unassigned class [ff00]: Apple Computer Inc. K2 KeyLargo Mac/IO [106b:0041] (rev 20)
	Control: I/O- Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr- Stepping- SERR- FastB2B- DisINTx-
	Status: Cap- 66MHz- UDF- FastB2B- ParErr- DEVSEL=medium >TAbort- <TAbort- <MAbort- >SERR- <PERR- INTx-
	Latency: 16, Cache Line Size: 64 bytes
	Region 0: Memory at 80000000 (32-bit, non-prefetchable) [size=512K]
	Kernel driver in use: macio

0001:01:08.0 USB Controller [0c03]: Apple Computer Inc. K2 KeyLargo USB [106b:0040] (prog-if 10 [OHCI])
	Control: I/O- Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr- Stepping- SERR- FastB2B- DisINTx-
	Status: Cap- 66MHz- UDF- FastB2B- ParErr- DEVSEL=medium >TAbort- <TAbort- <MAbort- >SERR- <PERR- INTx-
	Latency: 16 (750ns min, 21500ns max), Cache Line Size: 64 bytes
	Interrupt: pin A routed to IRQ 27
	Region 0: Memory at 80081000 (32-bit, non-prefetchable) [size=4K]
	Kernel driver in use: ohci_hcd

0001:01:09.0 USB Controller [0c03]: Apple Computer Inc. K2 KeyLargo USB [106b:0040] (prog-if 10 [OHCI])
	Control: I/O- Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr- Stepping- SERR- FastB2B- DisINTx-
	Status: Cap- 66MHz- UDF- FastB2B- ParErr- DEVSEL=medium >TAbort- <TAbort- <MAbort- >SERR- <PERR- INTx-
	Latency: 16 (750ns min, 21500ns max), Cache Line Size: 64 bytes
	Interrupt: pin A routed to IRQ 28
	Region 0: Memory at 80080000 (32-bit, non-prefetchable) [size=4K]
	Kernel driver in use: ohci_hcd

0001:02:0b.0 USB Controller [0c03]: NEC Corporation USB [1033:0035] (rev 43) (prog-if 10 [OHCI])
	Subsystem: NEC Corporation Hama USB 2.0 CardBus [1033:0035]
	Control: I/O- Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr- Stepping- SERR- FastB2B- DisINTx-
	Status: Cap+ 66MHz- UDF- FastB2B- ParErr- DEVSEL=medium >TAbort- <TAbort- <MAbort- >SERR- <PERR- INTx-
	Latency: 16 (250ns min, 10500ns max), Cache Line Size: 64 bytes
	Interrupt: pin A routed to IRQ 63
	Region 0: Memory at 80102000 (32-bit, non-prefetchable) [size=4K]
	Capabilities: <access denied>
	Kernel driver in use: ohci_hcd

0001:02:0b.1 USB Controller [0c03]: NEC Corporation USB [1033:0035] (rev 43) (prog-if 10 [OHCI])
	Subsystem: NEC Corporation Hama USB 2.0 CardBus [1033:0035]
	Control: I/O- Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr- Stepping- SERR- FastB2B- DisINTx-
	Status: Cap+ 66MHz- UDF- FastB2B- ParErr- DEVSEL=medium >TAbort- <TAbort- <MAbort- >SERR- <PERR- INTx-
	Latency: 16 (250ns min, 10500ns max), Cache Line Size: 64 bytes
	Interrupt: pin B routed to IRQ 63
	Region 0: Memory at 80101000 (32-bit, non-prefetchable) [size=4K]
	Capabilities: <access denied>
	Kernel driver in use: ohci_hcd

0001:02:0b.2 USB Controller [0c03]: NEC Corporation USB 2.0 [1033:00e0] (rev 04) (prog-if 20 [EHCI])
	Subsystem: NEC Corporation USB 2.0 [1033:00e0]
	Control: I/O- Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr- Stepping- SERR- FastB2B- DisINTx-
	Status: Cap+ 66MHz- UDF- FastB2B- ParErr- DEVSEL=medium >TAbort- <TAbort- <MAbort- >SERR- <PERR- INTx-
	Latency: 16 (4000ns min, 8500ns max), Cache Line Size: 64 bytes
	Interrupt: pin C routed to IRQ 63
	Region 0: Memory at 80100000 (32-bit, non-prefetchable) [size=256]
	Capabilities: <access denied>
	Kernel driver in use: ehci_hcd

0001:03:0d.0 Unassigned class [ff00]: Apple Computer Inc. K2 ATA/100 [106b:0043]
	Control: I/O- Mem+ BusMaster+ SpecCycle- MemWINV+ VGASnoop- ParErr- Stepping- SERR- FastB2B- DisINTx-
	Status: Cap- 66MHz- UDF- FastB2B- ParErr- DEVSEL=medium >TAbort- <TAbort- <MAbort- >SERR- <PERR- INTx-
	Latency: 32, Cache Line Size: 32 bytes
	Interrupt: pin ? routed to IRQ 39
	Region 0: Memory at 80204000 (32-bit, non-prefetchable) [size=16K]
	Kernel driver in use: pata-pci-macio

0001:03:0e.0 FireWire (IEEE 1394) [0c00]: Apple Computer Inc. K2 FireWire [106b:0042] (prog-if 10 [OHCI])
	Subsystem: Apple Computer Inc. Device [106b:5811]
	Control: I/O- Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr- Stepping- SERR- FastB2B- DisINTx-
	Status: Cap+ 66MHz- UDF- FastB2B+ ParErr- DEVSEL=medium >TAbort- <TAbort- <MAbort- >SERR- <PERR- INTx-
	Latency: 248 (3000ns min, 6000ns max), Cache Line Size: 64 bytes
	Interrupt: pin A routed to IRQ 40
	Region 0: Memory at 80200000 (32-bit, non-prefetchable) [size=4K]
	Capabilities: <access denied>
	Kernel driver in use: firewire_ohci

0001:04:0f.0 Ethernet controller [0200]: Apple Computer Inc. K2 GMAC (Sun GEM) [106b:004c]
	Control: I/O- Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr- Stepping- SERR- FastB2B- DisINTx-
	Status: Cap- 66MHz+ UDF- FastB2B+ ParErr- DEVSEL=slow >TAbort- <TAbort- <MAbort- >SERR- <PERR+ INTx-
	Latency: 16 (16000ns min, 16000ns max), Cache Line Size: 64 bytes
	Interrupt: pin A routed to IRQ 41
	Region 0: Memory at 80400000 (32-bit, non-prefetchable) [size=2M]
	Expansion ROM at 80300000 [disabled] [size=1M]
	Kernel driver in use: gem

0001:05:0c.0 IDE interface [0101]: Broadcom K2 SATA [1166:0240] (prog-if 8f [Master SecP SecO PriP PriO])
	Subsystem: Broadcom K2 SATA [1166:0240]
	Control: I/O- Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr- Stepping- SERR- FastB2B- DisINTx-
	Status: Cap- 66MHz- UDF- FastB2B- ParErr- DEVSEL=medium >TAbort- <TAbort- <MAbort- >SERR- <PERR- INTx-
	Latency: 16
	Interrupt: pin ? routed to IRQ 16
	Region 0: I/O ports at <unassigned> [disabled]
	Region 1: I/O ports at <unassigned> [disabled]
	Region 2: I/O ports at <unassigned> [disabled]
	Region 3: I/O ports at <unassigned> [disabled]
	Region 4: I/O ports at <unassigned> [disabled]
	Region 5: Memory at 80600000 (32-bit, non-prefetchable) [size=8K]
	Kernel driver in use: sata_svw

0001:06:03.0 Mass storage controller [0180]: Silicon Image, Inc. SiI 3112 [SATALink/SATARaid] Serial ATA Controller [1095:3112] (rev 02)
	Subsystem: Silicon Image, Inc. SiI 3112 SATALink Controller [1095:3112]
	Control: I/O+ Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr- Stepping- SERR- FastB2B- DisINTx-
	Status: Cap+ 66MHz+ UDF- FastB2B+ ParErr- DEVSEL=medium >TAbort- <TAbort- <MAbort- >SERR- <PERR- INTx-
	Latency: 16, Cache Line Size: 4 bytes
	Interrupt: pin A routed to IRQ 53
	Region 0: I/O ports at 1010 [size=8]
	Region 1: I/O ports at 1020 [size=4]
	Region 2: I/O ports at 1018 [size=8]
	Region 3: I/O ports at 1024 [size=4]
	Region 4: I/O ports at 1000 [size=16]
	Region 5: Memory at 90000000 (32-bit, non-prefetchable) [size=512]
	Expansion ROM at 90080000 [disabled] [size=512K]
	Capabilities: <access denied>
	Kernel driver in use: sata_sil


** USB devices:
Bus 005 Device 002: ID 067b:2303 Prolific Technology, Inc. PL2303 Serial Port
Bus 005 Device 001: ID 1d6b:0001 Linux Foundation 1.1 root hub
Bus 004 Device 001: ID 1d6b:0001 Linux Foundation 1.1 root hub
Bus 003 Device 001: ID 1d6b:0001 Linux Foundation 1.1 root hub
Bus 002 Device 001: ID 1d6b:0001 Linux Foundation 1.1 root hub
Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub


-- System Information:
Debian Release: 6.0.4
  APT prefers stable-updates
  APT policy: (500, 'stable-updates'), (500, 'stable'), (100, 'unstable'), (100, 'testing')
Architecture: powerpc (ppc64)

Kernel: Linux 3.2.0-2-powerpc64 (SMP w/1 CPU core)
Locale: LANG=cs_CZ.UTF-8, LC_CTYPE=cs_CZ.UTF-8 (charmap=UTF-8)
Shell: /bin/sh linked to /bin/dash

Versions of packages linux-image-3.2.0-2-powerpc64 depends on:
ii  debconf [debconf-2.0]         1.5.36.1   Debian configuration management sy
ii  initramfs-tools [linux-initra 0.101      generic modular initramfs generato
ii  linux-base                    3.5        Linux image base package
ii  module-init-tools             3.12-2     tools for managing Linux kernel mo

Versions of packages linux-image-3.2.0-2-powerpc64 recommends:
ii  firmware-linux-free    2.6.32-41squeeze2 Binary firmware for various driver

Versions of packages linux-image-3.2.0-2-powerpc64 suggests:
pn  linux-doc-3.2                 <none>     (no description available)
pn  mkvmlinuz                     <none>     (no description available)

Versions of packages linux-image-3.2.0-2-powerpc64 is related to:
pn  firmware-atheros              <none>     (no description available)
pn  firmware-bnx2                 <none>     (no description available)
pn  firmware-bnx2x                <none>     (no description available)
pn  firmware-brcm80211            <none>     (no description available)
pn  firmware-intelwimax           <none>     (no description available)
pn  firmware-ipw2x00              <none>     (no description available)
pn  firmware-ivtv                 <none>     (no description available)
pn  firmware-iwlwifi              <none>     (no description available)
pn  firmware-libertas             <none>     (no description available)
pn  firmware-linux                <none>     (no description available)
pn  firmware-linux-nonfree        <none>     (no description available)
pn  firmware-myricom              <none>     (no description available)
pn  firmware-netxen               <none>     (no description available)
pn  firmware-qlogic               <none>     (no description available)
pn  firmware-ralink               <none>     (no description available)
pn  firmware-realtek              <none>     (no description available)
pn  xen-hypervisor                <none>     (no description available)

-- debconf information:
  linux-image-3.2.0-2-powerpc64/prerm/removing-running-kernel-3.2.0-2-powerpc64: true
  linux-image-3.2.0-2-powerpc64/postinst/depmod-error-initrd-3.2.0-2-powerpc64: false
  linux-image-3.2.0-2-powerpc64/postinst/missing-firmware-3.2.0-2-powerpc64:
  linux-image-3.2.0-2-powerpc64/postinst/ignoring-ramdisk:

Message #10 received at 666021@bugs.debian.org (full text, mbox, reply):

From: Jonathan Nieder <jrnieder@gmail.com>

To: Petr Tichy <spaceboy@spaceboy.cz>

Cc: 666021@bugs.debian.org

Subject: Re: [powerpc] Kernel reports page allocation failure: order:1, mode:0x20

Date: Tue, 27 Mar 2012 16:22:21 -0500

Hi Petr,

Petr Tichy wrote:

> [958021.754593] afpd: page allocation failure: order:1, mode:0x20
> [958021.759018] Call Trace:
> [958021.763346] [c00000000fffee10] [c0000000000134f4] .show_stack+0x80/0x130 (unreliable)
> [958021.772169] [c00000000fffeec0] [c000000000118ea0] .warn_alloc_failed+0xf0/0x108
> [958021.781514] [c00000000fffef80] [c00000000011c170] .__alloc_pages_nodemask+0x700/0x7c4
> [958021.791170] [c00000000ffff110] [c000000000158754] .kmem_getpages+0x5c/0x140
> [958021.796193] [c00000000ffff1b0] [c000000000158a78] .fallback_alloc+0x174/0x200
> [958021.805902] [c00000000ffff290] [c00000000015a474] .kmem_cache_alloc+0x104/0x1f8
> [958021.815720] [c00000000ffff350] [c0000000003c2970] .sk_prot_alloc+0x38/0x1c4
> [958021.820730] [c00000000ffff400] [c0000000003c3a0c] .sk_clone+0x20/0x2cc
> [958021.825597] [c00000000ffff4a0] [c000000000412bcc] .inet_csk_clone+0x1c/0x94
> [958021.830363] [c00000000ffff530] [c00000000042bb14] .tcp_create_openreq_child+0x24/0x3e8
> [958021.839509] [c00000000ffff5e0] [c00000000042a044] .tcp_v4_syn_recv_sock+0x3c/0x31c
[...]

Interesting.  What was happening when this happened?  (Were you using
the machine?  Was it idle or busy?  What is the usual workload like?
Had you just upgraded the kernel recently?)  Is this reproducible?

Thanks for writing,
Jonathan

Message #15 received at 666021@bugs.debian.org (full text, mbox, reply):

From: Jonathan Nieder <jrnieder@gmail.com>

To: Petr Tichy <spaceboy@spaceboy.cz>

Cc: 666021@bugs.debian.org

Subject: Re: [powerpc] Kernel reports page allocation failure: order:1, mode:0x20

Date: Tue, 27 Mar 2012 16:33:10 -0500

reassign 666021 src:linux-2.6 3.2.9-1
tags 666021 + moreinfo
quit

Petr Tichy wrote:

> Version: 3.2.12-1
[...]
> Linux version 3.2.0-2-powerpc64 (Debian 3.2.9-1) [...]
[...]
> [958021.754593] afpd: page allocation failure: order:1, mode:0x20

11 days ago version 3.2.12-1 hadn't been uploaded to Debian yet.
This is probably one of the tcp-related bugs fixed in 3.2.12-1.

Hope that helps,
Jonathan

Message #28 received at 666021@bugs.debian.org (full text, mbox, reply):

From: Petr Tichý <spaceboy@spaceboy.cz>

Cc: 666021@bugs.debian.org

Subject: Re: [powerpc] Kernel reports page allocation failure: order:1, mode:0x20

Date: Tue, 27 Mar 2012 23:55:51 +0200

Hi Jonathan

thanks and sorry for my mistake. I'm installing the 3.2.12-1 and hope it's fixed there.

Thanks again

Petr

27. 3. 2012 v 23:33, Jonathan Nieder:

> reassign 666021 src:linux-2.6 3.2.9-1
> tags 666021 + moreinfo
> quit
> 
> Petr Tichy wrote:
> 
>> Version: 3.2.12-1
> [...]
>> Linux version 3.2.0-2-powerpc64 (Debian 3.2.9-1) [...]
> [...]
>> [958021.754593] afpd: page allocation failure: order:1, mode:0x20
> 
> 11 days ago version 3.2.12-1 hadn't been uploaded to Debian yet.
> This is probably one of the tcp-related bugs fixed in 3.2.12-1.
> 
> Hope that helps,
> Jonathan

Message #35 received at 666021-done@bugs.debian.org (full text, mbox, reply):

From: Jonathan Nieder <jrnieder@gmail.com>

To: Petr Tichý <spaceboy@spaceboy.cz>

Cc: 666021-done@bugs.debian.org

Subject: Re: [powerpc] Kernel reports page allocation failure: order:1, mode:0x20

Date: Tue, 27 Mar 2012 17:42:04 -0500

Version: 3.2.12-1
tags 666021 - moreinfo
quit

Petr Tichý wrote:

> I'm installing the 3.2.12-1 and hope it's fixed there.

Excellent.  Closing optimistically, but confirmation either
way will be welcome.

Thanks again,
Jonathan

Message #40 received at 666021@bugs.debian.org (full text, mbox, reply):

From: Ben Hutchings <ben@decadent.org.uk>

To: Jonathan Nieder <jrnieder@gmail.com>, 666021@bugs.debian.org

Cc: Petr Tichy <spaceboy@spaceboy.cz>

Subject: Re: Bug#666021: [powerpc] Kernel reports page allocation failure: order:1, mode:0x20

Date: Wed, 28 Mar 2012 00:13:08 +0100

On Tue, Mar 27, 2012 at 04:33:10PM -0500, Jonathan Nieder wrote:
> reassign 666021 src:linux-2.6 3.2.9-1
> tags 666021 + moreinfo
> quit
> 
> Petr Tichy wrote:
> 
> > Version: 3.2.12-1
> [...]
> > Linux version 3.2.0-2-powerpc64 (Debian 3.2.9-1) [...]
> [...]
> > [958021.754593] afpd: page allocation failure: order:1, mode:0x20
> 
> 11 days ago version 3.2.12-1 hadn't been uploaded to Debian yet.
> This is probably one of the tcp-related bugs fixed in 3.2.12-1.
 
I don't think so.  I think it's likely to be a case of running too
many network services in too little memory.

Ben.

-- 
Ben Hutchings
We get into the habit of living before acquiring the habit of thinking.
                                                              - Albert Camus

Message #45 received at 666021@bugs.debian.org (full text, mbox, reply):

From: Jonathan Nieder <jrnieder@gmail.com>

To: Ben Hutchings <ben@decadent.org.uk>

Cc: 666021@bugs.debian.org, Petr Tichy <spaceboy@spaceboy.cz>

Subject: Re: [powerpc] Kernel reports page allocation failure: order:1, mode:0x20

Date: Tue, 27 Mar 2012 18:26:50 -0500

reopen 666021
tags 666021 + moreinfo
quit

Ben Hutchings wrote:
> On Tue, Mar 27, 2012 at 04:33:10PM -0500, Jonathan Nieder wrote:

>> This is probably one of the tcp-related bugs fixed in 3.2.12-1.
>
> I don't think so.  I think it's likely to be a case of running too
> many network services in too little memory.

Sure, that's what an allocation failure usually would suggest.
Reopening, but I'm not sure what to suggest to track this down
further.

Petr, did you only get the page allocation failure once, or did it
happen on multiple occasions?

Message #56 received at 666021@bugs.debian.org (full text, mbox, reply):

From: Petr Tichý <spaceboy@spaceboy.cz>

To: 666021@bugs.debian.org

Subject: Re: [powerpc] Kernel reports page allocation failure: order:1, mode:0x20

Date: Thu, 5 Apr 2012 13:08:39 +0200

I installed the 3.2.12-1 and within within 2 hours around midnight there was this:

Mar 27 23:47:40 addict kernel: [    0.000000] Linux version 3.2.0-2-powerpc64 (Debian 3.2.12-1) (debian-kernel@lists.debian.org) (gcc version 4.6.2 (Debian 4.6.2-11) ) #1 SMP Tue Mar 20 20:35:04 UTC 2012
...
Mar 28 00:37:11 addict kernel: [ 3010.104653] swapper/0: page allocation failure: order:1, mode:0x20
Mar 28 00:37:11 addict kernel: [ 3010.108757] Call Trace:
Mar 28 00:37:11 addict kernel: [ 3010.112765] [c00000000ffff350] [c0000000000134f4] .show_stack+0x80/0x130 (unreliable)
Mar 28 00:37:11 addict kernel: [ 3010.121163] [c00000000ffff400] [c000000000119104] .warn_alloc_failed+0xf0/0x108
Mar 28 00:37:11 addict kernel: [ 3010.130015] [c00000000ffff4c0] [c00000000011c3d4] .__alloc_pages_nodemask+0x700/0x7c4
Mar 28 00:37:11 addict kernel: [ 3010.139288] [c00000000ffff650] [c0000000001589b8] .kmem_getpages+0x5c/0x140
Mar 28 00:37:11 addict kernel: [ 3010.144125] [c00000000ffff6f0] [c000000000158cdc] .fallback_alloc+0x174/0x200
Mar 28 00:37:11 addict kernel: [ 3010.148945] [c00000000ffff7d0] [c000000000159bf8] .__kmalloc+0x148/0x248
Mar 28 00:37:11 addict kernel: [ 3010.153672] [c00000000ffff890] [c0000000003c8de8] .pskb_expand_head+0xec/0x2cc
Mar 28 00:37:11 addict kernel: [ 3010.162737] [c00000000ffff950] [c00000000040a0b8] .ip_forward+0x2ec/0x454
Mar 28 00:37:11 addict kernel: [ 3010.167403] [c00000000ffff9e0] [c000000000408318] .ip_rcv_finish+0x374/0x394
Mar 28 00:37:11 addict kernel: [ 3010.171991] [c00000000ffffa70] [c0000000003d0d48] .__netif_receive_skb+0x698/0x6e8
Mar 28 00:37:11 addict kernel: [ 3010.180975] [c00000000ffffb60] [c0000000003d23a0] .netif_receive_skb+0x90/0x98
Mar 28 00:37:11 addict kernel: [ 3010.190225] [c00000000ffffc00] [c0000000003d4dc0] .napi_skb_finish+0x34/0x58
Mar 28 00:37:11 addict kernel: [ 3010.195132] [c00000000ffffc80] [d000000000aaebfc] .gem_poll+0x1c04/0x1ea4 [sungem]
Mar 28 00:37:11 addict kernel: [ 3010.204418] [c00000000ffffdc0] [c0000000003d2600] .net_rx_action+0xd0/0x30c
Mar 28 00:37:11 addict kernel: [ 3010.209294] [c00000000ffffeb0] [c00000000008b998] .__do_softirq+0x158/0x2a0
Mar 28 00:37:11 addict kernel: [ 3010.214192] [c00000000fffff90] [c00000000001c674] .call_do_softirq+0x14/0x24
Mar 28 00:37:11 addict kernel: [ 3010.219122] [c0000000007ef910] [c00000000000eda4] .do_softirq+0x7c/0xec
Mar 28 00:37:11 addict kernel: [ 3010.224051] [c0000000007ef9b0] [c00000000008bcec] .irq_exit+0x4c/0x9c
Mar 28 00:37:11 addict kernel: [ 3010.228983] [c0000000007efa30] [c00000000000ec04] .do_IRQ+0x1c4/0x240
Mar 28 00:37:11 addict kernel: [ 3010.233844] [c0000000007efae0] [c00000000000553c] hardware_interrupt_entry+0x18/0x1c
Mar 28 00:37:11 addict kernel: [ 3010.243320] --- Exception: 501 at .cpu_idle+0x10c/0x1cc
Mar 28 00:37:11 addict kernel: [ 3010.243323]     LR = .cpu_idle+0x10c/0x1cc
Mar 28 00:37:11 addict kernel: [ 3010.252811] [c0000000007efdd0] [c0000000000150f4] .cpu_idle+0x64/0x1cc (unreliable)
Mar 28 00:37:11 addict kernel: [ 3010.262134] [c0000000007efe60] [c00000000000ae54] .rest_init+0x84/0x90
Mar 28 00:37:11 addict kernel: [ 3010.266863] [c0000000007efee0] [c000000000676918] .start_kernel+0x454/0x45c
Mar 28 00:37:11 addict kernel: [ 3010.271492] [c0000000007eff90] [c0000000000096e8] .start_here_common+0x1c/0x34
Mar 28 00:37:11 addict kernel: [ 3010.280281] Mem-Info:
Mar 28 00:37:11 addict kernel: [ 3010.284602] Node 0 DMA per-cpu:
Mar 28 00:37:11 addict kernel: [ 3010.288923] CPU    0: hi:  186, btch:  31 usd:  94
Mar 28 00:37:11 addict kernel: [ 3010.293292] active_anon:3232 inactive_anon:2031 isolated_anon:0
Mar 28 00:37:11 addict kernel: [ 3010.293296]  active_file:29875 inactive_file:28307 isolated_file:0
Mar 28 00:37:11 addict kernel: [ 3010.293299]  unevictable:0 dirty:0 writeback:0 unstable:0
Mar 28 00:37:11 addict kernel: [ 3010.293301]  free:4180 slab_reclaimable:210472 slab_unreclaimable:38368
Mar 28 00:37:11 addict kernel: [ 3010.293304]  mapped:2564 shmem:83 pagetables:360 bounce:0
Mar 28 00:37:11 addict kernel: [ 3010.315010] Node 0 DMA free:16720kB min:5752kB low:7188kB high:8628kB active_anon:12928kB inactive_anon:8124kB active_file:119500kB inactive_file:113228kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:2068480kB mlocked:0kB dirty:0kB writeback:0kB mapped:10256kB shmem:332kB slab_reclaimable:841888kB slab_unreclaimable:153472kB kernel_stack:1792kB pagetables:1440kB unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
Mar 28 00:37:11 addict kernel: [ 3010.341624] lowmem_reserve[]: 0 0 0
Mar 28 00:37:11 addict kernel: [ 3010.346100] Node 0 DMA: 4180*4kB 0*8kB 0*16kB 0*32kB 0*64kB 0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB 0*8192kB 0*16384kB = 16720kB
Mar 28 00:37:11 addict kernel: [ 3010.355529] 58769 total pagecache pages
Mar 28 00:37:11 addict kernel: [ 3010.360256] 500 pages in swap cache
Mar 28 00:37:11 addict kernel: [ 3010.364980] Swap cache stats: add 2284, delete 1784, find 338/418
Mar 28 00:37:11 addict kernel: [ 3010.369828] Free swap  = 2091148kB
Mar 28 00:37:11 addict kernel: [ 3010.374520] Total swap = 2097148kB
Mar 28 00:37:11 addict kernel: [ 3010.394630] 524288 pages RAM
Mar 28 00:37:11 addict kernel: [ 3010.399171] 22937 pages reserved
Mar 28 00:37:11 addict kernel: [ 3010.403595] 31296 pages shared
Mar 28 00:37:11 addict kernel: [ 3010.407858] 471269 pages non-shared


So installed 3.2.13-1 and since then everything seems to be fine. I'll keep an eye on it.

Mar 30 22:56:53 addict kernel: [    0.000000] Linux version 3.2.0-2-powerpc64 (Debian 3.2.13-1) (debian-kernel@lists.debian.org) (gcc version 4.6.2 (Debian 4.6.2-11) ) #1 SMP Thu Mar 29 01:04:30 UTC 2012

BTW it's PowerMac7,2 with 2 GB RAM

28. 3. 2012 v 1:26, Jonathan Nieder:

> reopen 666021
> tags 666021 + moreinfo
> quit
> 
> Ben Hutchings wrote:
>> On Tue, Mar 27, 2012 at 04:33:10PM -0500, Jonathan Nieder wrote:
> 
>>> This is probably one of the tcp-related bugs fixed in 3.2.12-1.
>> 
>> I don't think so.  I think it's likely to be a case of running too
>> many network services in too little memory.
> 
> Sure, that's what an allocation failure usually would suggest.
> Reopening, but I'm not sure what to suggest to track this down
> further.
> 
> Petr, did you only get the page allocation failure once, or did it
> happen on multiple occasions?

Message #61 received at 666021@bugs.debian.org (full text, mbox, reply):

From: Petr Tichý <spaceboy@spaceboy.cz>

To: 666021@bugs.debian.org

Subject: Re: [powerpc] Kernel reports page allocation failure: order:1, mode:0x20

Date: Fri, 6 Apr 2012 00:45:53 +0200

Oops, too early:

Apr  6 00:14:06 addict kernel: [523091.737097] du: page allocation failure: order:1, mode:0x20
Apr  6 00:14:07 addict kernel: [523091.741695] Call Trace:
Apr  6 00:14:07 addict kernel: [523091.746108] [c00000000fffee10] [c0000000000134f4] .show_stack+0x80/0x130 (unreliable)
Apr  6 00:14:07 addict kernel: [523091.755208] [c00000000fffeec0] [c000000000119104] .warn_alloc_failed+0xf0/0x108
Apr  6 00:14:07 addict kernel: [523091.764456] [c00000000fffef80] [c00000000011c3d4] .__alloc_pages_nodemask+0x700/0x7c4
Apr  6 00:14:07 addict kernel: [523091.774024] [c00000000ffff110] [c0000000001589b8] .kmem_getpages+0x5c/0x140
Apr  6 00:14:07 addict kernel: [523091.778950] [c00000000ffff1b0] [c000000000158cdc] .fallback_alloc+0x174/0x200
Apr  6 00:14:07 addict kernel: [523091.788476] [c00000000ffff290] [c00000000015a6d8] .kmem_cache_alloc+0x104/0x1f8
Apr  6 00:14:07 addict kernel: [523091.798186] [c00000000ffff350] [c0000000003c2d2c] .sk_prot_alloc+0x38/0x1c4
Apr  6 00:14:07 addict kernel: [523091.803320] [c00000000ffff400] [c0000000003c3dc8] .sk_clone+0x20/0x2cc
Apr  6 00:14:07 addict kernel: [523091.808393] [c00000000ffff4a0] [c000000000412f8c] .inet_csk_clone+0x1c/0x94
Apr  6 00:14:07 addict kernel: [523091.813405] [c00000000ffff530] [c00000000042bee4] .tcp_create_openreq_child+0x24/0x3e8
Apr  6 00:14:07 addict kernel: [523091.823106] [c00000000ffff5e0] [c00000000042a414] .tcp_v4_syn_recv_sock+0x3c/0x31c
Apr  6 00:14:07 addict kernel: [523091.832949] [c00000000ffff680] [c00000000042bcec] .tcp_check_req+0x350/0x524
Apr  6 00:14:07 addict kernel: [523091.838085] [c00000000ffff770] [c000000000429224] .tcp_v4_do_rcv+0x200/0x3c8
Apr  6 00:14:07 addict kernel: [523091.843196] [c00000000ffff850] [c00000000042b2e8] .tcp_v4_rcv+0x558/0x940
Apr  6 00:14:07 addict kernel: [523091.848247] [c00000000ffff940] [c000000000408508] .ip_local_deliver_finish+0x1d0/0x2d8
Apr  6 00:14:07 addict kernel: [523091.858056] [c00000000ffff9e0] [c000000000408318] .ip_rcv_finish+0x374/0x394
Apr  6 00:14:07 addict kernel: [523091.863133] [c00000000ffffa70] [c0000000003d0d48] .__netif_receive_skb+0x698/0x6e8
Apr  6 00:14:07 addict kernel: [523091.873063] [c00000000ffffb60] [c0000000003d23a0] .netif_receive_skb+0x90/0x98
Apr  6 00:14:07 addict kernel: [523091.883348] [c00000000ffffc00] [c0000000003d4dc0] .napi_skb_finish+0x34/0x58
Apr  6 00:14:07 addict kernel: [523091.888784] [c00000000ffffc80] [d000000000994bfc] .gem_poll+0x1c04/0x1ea4 [sungem]
Apr  6 00:14:07 addict kernel: [523091.899134] [c00000000ffffdc0] [c0000000003d2600] .net_rx_action+0xd0/0x30c
Apr  6 00:14:07 addict kernel: [523091.904416] [c00000000ffffeb0] [c00000000008b998] .__do_softirq+0x158/0x2a0
Apr  6 00:14:07 addict kernel: [523091.909582] [c00000000fffff90] [c00000000001c674] .call_do_softirq+0x14/0x24
Apr  6 00:14:07 addict kernel: [523091.914636] [c00000002e6cf240] [c00000000000eda4] .do_softirq+0x7c/0xec
Apr  6 00:14:07 addict kernel: [523091.919571] [c00000002e6cf2e0] [c00000000008bcec] .irq_exit+0x4c/0x9c
Apr  6 00:14:07 addict kernel: [523091.924378] [c00000002e6cf360] [c00000000000ec04] .do_IRQ+0x1c4/0x240
Apr  6 00:14:07 addict kernel: [523091.929172] [c00000002e6cf410] [c00000000000553c] hardware_interrupt_entry+0x18/0x1c
Apr  6 00:14:07 addict kernel: [523091.938354] --- Exception: 501 at .d_splice_alias+0x30/0x124
Apr  6 00:14:07 addict kernel: [523091.938357]     LR = .d_splice_alias+0x8/0x124
Apr  6 00:14:07 addict kernel: [523091.947411] [c00000002e6cf700] [c00000000017ffb8] .__d_alloc+0x120/0x140 (unreliable)
Apr  6 00:14:07 addict kernel: [523091.956675] [c00000002e6cf790] [d000000000ed9a0c] .xfs_vn_lookup+0x98/0xa4 [xfs]
Apr  6 00:14:07 addict kernel: [523091.966221] [c00000002e6cf830] [c000000000173a10] .d_alloc_and_lookup+0x60/0x90
Apr  6 00:14:07 addict kernel: [523091.975772] [c00000002e6cf8d0] [c000000000174708] .do_lookup+0x24c/0x3a8
Apr  6 00:14:07 addict kernel: [523091.980644] [c00000002e6cf9b0] [c00000000017631c] .path_lookupat+0xf8/0x838
Apr  6 00:14:07 addict kernel: [523091.985559] [c00000002e6cfac0] [c000000000176a84] .do_path_lookup+0x28/0xec
Apr  6 00:14:07 addict kernel: [523091.990492] [c00000002e6cfb60] [c0000000001788f8] .user_path_at_empty+0x5c/0x8c
Apr  6 00:14:07 addict kernel: [523092.000141] [c00000002e6cfca0] [c00000000016da48] .vfs_fstatat+0x54/0x8c
Apr  6 00:14:07 addict kernel: [523092.005058] [c00000002e6cfd40] [c00000000016ddd0] .SyS_fstatat64+0x20/0x3c
Apr  6 00:14:07 addict kernel: [523092.009951] [c00000002e6cfe30] [c00000000000986c] syscall_exit+0x0/0x40
Apr  6 00:14:07 addict kernel: [523092.014709] Mem-Info:
Apr  6 00:14:07 addict kernel: [523092.019284] Node 0 DMA per-cpu:
Apr  6 00:14:07 addict kernel: [523092.023744] CPU    0: hi:  186, btch:  31 usd:  54
Apr  6 00:14:07 addict kernel: [523092.028143] active_anon:1215 inactive_anon:533 isolated_anon:0
Apr  6 00:14:07 addict kernel: [523092.028146]  active_file:46073 inactive_file:46110 isolated_file:0
Apr  6 00:14:07 addict kernel: [523092.028149]  unevictable:0 dirty:1 writeback:0 unstable:0
Apr  6 00:14:07 addict kernel: [523092.028152]  free:2035 slab_reclaimable:208648 slab_unreclaimable:33895
Apr  6 00:14:07 addict kernel: [523092.028155]  mapped:2902 shmem:1 pagetables:440 bounce:0
Apr  6 00:14:07 addict kernel: [523092.050239] Node 0 DMA free:8140kB min:5752kB low:7188kB high:8628kB active_anon:4860kB inactive_anon:2132kB active_file:184292kB inactive_file:184440kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:2068480kB mlocked:0kB dirty:4kB writeback:0kB mapped:11608kB shmem:4kB slab_reclaimable:834592kB slab_unreclaimable:135580kB kernel_stack:1920kB pagetables:1760kB unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
Apr  6 00:14:07 addict kernel: [523092.079290] lowmem_reserve[]: 0 0 0
Apr  6 00:14:07 addict kernel: [523092.084238] Node 0 DMA: 2035*4kB 0*8kB 0*16kB 0*32kB 0*64kB 0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB 0*8192kB 0*16384kB = 8140kB
Apr  6 00:14:07 addict kernel: [523092.094321] 92665 total pagecache pages
Apr  6 00:14:07 addict kernel: [523092.099198] 481 pages in swap cache
Apr  6 00:14:07 addict kernel: [523092.103939] Swap cache stats: add 42593, delete 42112, find 295394/300681
Apr  6 00:14:07 addict kernel: [523092.108744] Free swap  = 2067276kB
Apr  6 00:14:07 addict kernel: [523092.113391] Total swap = 2097148kB
Apr  6 00:14:07 addict kernel: [523092.133689] 524288 pages RAM
Apr  6 00:14:07 addict kernel: [523092.138161] 22937 pages reserved
Apr  6 00:14:07 addict kernel: [523092.142599] 86458 pages shared
Apr  6 00:14:07 addict kernel: [523092.146982] 419580 pages non-shared
Apr  6 00:22:27 addict kernel: [523593.639706] du: page allocation failure: order:1, mode:0x20
Apr  6 00:22:29 addict kernel: [523593.644007] Call Trace:
Apr  6 00:22:29 addict kernel: [523593.648253] [c00000000fffee10] [c0000000000134f4] .show_stack+0x80/0x130 (unreliable)
Apr  6 00:22:29 addict kernel: [523593.657050] [c00000000fffeec0] [c000000000119104] .warn_alloc_failed+0xf0/0x108
Apr  6 00:22:29 addict kernel: [523593.666275] [c00000000fffef80] [c00000000011c3d4] .__alloc_pages_nodemask+0x700/0x7c4
Apr  6 00:22:29 addict kernel: [523593.675836] [c00000000ffff110] [c0000000001589b8] .kmem_getpages+0x5c/0x140
Apr  6 00:22:29 addict kernel: [523593.680819] [c00000000ffff1b0] [c000000000158cdc] .fallback_alloc+0x174/0x200
Apr  6 00:22:29 addict kernel: [523593.690465] [c00000000ffff290] [c00000000015a6d8] .kmem_cache_alloc+0x104/0x1f8
Apr  6 00:22:29 addict kernel: [523593.700226] [c00000000ffff350] [c0000000003c2d2c] .sk_prot_alloc+0x38/0x1c4
Apr  6 00:22:29 addict kernel: [523593.705212] [c00000000ffff400] [c0000000003c3dc8] .sk_clone+0x20/0x2cc
Apr  6 00:22:29 addict kernel: [523593.710046] [c00000000ffff4a0] [c000000000412f8c] .inet_csk_clone+0x1c/0x94
Apr  6 00:22:29 addict kernel: [523593.714777] [c00000000ffff530] [c00000000042bee4] .tcp_create_openreq_child+0x24/0x3e8
Apr  6 00:22:29 addict kernel: [523593.723881] [c00000000ffff5e0] [c00000000042a414] .tcp_v4_syn_recv_sock+0x3c/0x31c
Apr  6 00:22:29 addict kernel: [523593.733106] [c00000000ffff680] [c00000000042bcec] .tcp_check_req+0x350/0x524
Apr  6 00:22:29 addict kernel: [523593.737882] [c00000000ffff770] [c000000000429224] .tcp_v4_do_rcv+0x200/0x3c8
Apr  6 00:22:29 addict kernel: [523593.742635] [c00000000ffff850] [c00000000042b2e8] .tcp_v4_rcv+0x558/0x940
Apr  6 00:22:29 addict kernel: [523593.747286] [c00000000ffff940] [c000000000408508] .ip_local_deliver_finish+0x1d0/0x2d8
Apr  6 00:22:29 addict kernel: [523593.756423] [c00000000ffff9e0] [c000000000408318] .ip_rcv_finish+0x374/0x394
Apr  6 00:22:29 addict kernel: [523593.761321] [c00000000ffffa70] [c0000000003d0d48] .__netif_receive_skb+0x698/0x6e8
Apr  6 00:22:29 addict kernel: [523593.771104] [c00000000ffffb60] [c0000000003d23a0] .netif_receive_skb+0x90/0x98
Apr  6 00:22:29 addict kernel: [523593.781383] [c00000000ffffc00] [c0000000003d4dc0] .napi_skb_finish+0x34/0x58
Apr  6 00:22:29 addict kernel: [523593.786817] [c00000000ffffc80] [d000000000994bfc] .gem_poll+0x1c04/0x1ea4 [sungem]
Apr  6 00:22:29 addict kernel: [523593.797162] [c00000000ffffdc0] [c0000000003d2600] .net_rx_action+0xd0/0x30c
Apr  6 00:22:29 addict kernel: [523593.802441] [c00000000ffffeb0] [c00000000008b998] .__do_softirq+0x158/0x2a0
Apr  6 00:22:29 addict kernel: [523593.807605] [c00000000fffff90] [c00000000001c674] .call_do_softirq+0x14/0x24
Apr  6 00:22:29 addict kernel: [523593.812656] [c00000002ad17c60] [c00000000000eda4] .do_softirq+0x7c/0xec
Apr  6 00:22:29 addict kernel: [523593.817585] [c00000002ad17d00] [c00000000008bcec] .irq_exit+0x4c/0x9c
Apr  6 00:22:29 addict kernel: [523593.822387] [c00000002ad17d80] [c00000000000ec04] .do_IRQ+0x1c4/0x240
Apr  6 00:22:29 addict kernel: [523593.827172] [c00000002ad17e30] [c00000000000553c] hardware_interrupt_entry+0x18/0x1c
Apr  6 00:22:29 addict kernel: [523593.836342] Mem-Info:
Apr  6 00:22:29 addict kernel: [523593.840733] Node 0 DMA per-cpu:
Apr  6 00:22:29 addict kernel: [523593.845014] CPU    0: hi:  186, btch:  31 usd: 192
Apr  6 00:22:29 addict kernel: [523593.849375] active_anon:983 inactive_anon:342 isolated_anon:0
Apr  6 00:22:29 addict kernel: [523593.849378]  active_file:6036 inactive_file:6033 isolated_file:0
Apr  6 00:22:29 addict kernel: [523593.849381]  unevictable:0 dirty:1 writeback:0 unstable:0
Apr  6 00:22:29 addict kernel: [523593.849384]  free:1999 slab_reclaimable:252025 slab_unreclaimable:39637
Apr  6 00:22:29 addict kernel: [523593.849387]  mapped:2572 shmem:3 pagetables:438 bounce:0
Apr  6 00:22:29 addict kernel: [523593.871375] Node 0 DMA free:7996kB min:5752kB low:7188kB high:8628kB active_anon:3932kB inactive_anon:1368kB active_file:24144kB inactive_file:24132kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:2068480kB mlocked:0kB dirty:4kB writeback:0kB mapped:10288kB shmem:12kB slab_reclaimable:1008100kB slab_unreclaimable:158548kB kernel_stack:1920kB pagetables:1752kB unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
Apr  6 00:22:29 addict kernel: [523593.898888] lowmem_reserve[]: 0 0 0
Apr  6 00:22:29 addict kernel: [523593.903568] Node 0 DMA: 1999*4kB 0*8kB 0*16kB 0*32kB 0*64kB 0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB 0*8192kB 0*16384kB = 7996kB
Apr  6 00:22:29 addict kernel: [523593.913052] 12523 total pagecache pages
Apr  6 00:22:29 addict kernel: [523593.917624] 451 pages in swap cache
Apr  6 00:22:29 addict kernel: [523593.922059] Swap cache stats: add 44082, delete 43631, find 296052/301638
Apr  6 00:22:29 addict kernel: [523593.926672] Free swap  = 2068748kB
Apr  6 00:22:29 addict kernel: [523593.931130] Total swap = 2097148kB
Apr  6 00:22:29 addict kernel: [523593.950820] 524288 pages RAM
Apr  6 00:22:29 addict kernel: [523593.955090] 22937 pages reserved
Apr  6 00:22:29 addict kernel: [523593.959323] 17119 pages shared
Apr  6 00:22:29 addict kernel: [523593.963495] 488598 pages non-shared
Apr  6 00:22:29 addict kernel: [523594.837904] kswapd0: page allocation failure: order:1, mode:0x20
Apr  6 00:22:29 addict kernel: [523594.842272] Call Trace:
Apr  6 00:22:29 addict kernel: [523594.846547] [c00000000fffee10] [c0000000000134f4] .show_stack+0x80/0x130 (unreliable)
Apr  6 00:22:29 addict kernel: [523594.855260] [c00000000fffeec0] [c000000000119104] .warn_alloc_failed+0xf0/0x108
Apr  6 00:22:29 addict kernel: [523594.864495] [c00000000fffef80] [c00000000011c3d4] .__alloc_pages_nodemask+0x700/0x7c4
Apr  6 00:22:29 addict kernel: [523594.874057] [c00000000ffff110] [c0000000001589b8] .kmem_getpages+0x5c/0x140
Apr  6 00:22:29 addict kernel: [523594.879045] [c00000000ffff1b0] [c000000000158cdc] .fallback_alloc+0x174/0x200
Apr  6 00:22:29 addict kernel: [523594.888700] [c00000000ffff290] [c00000000015a6d8] .kmem_cache_alloc+0x104/0x1f8
Apr  6 00:22:29 addict kernel: [523594.898467] [c00000000ffff350] [c0000000003c2d2c] .sk_prot_alloc+0x38/0x1c4
Apr  6 00:22:29 addict kernel: [523594.903460] [c00000000ffff400] [c0000000003c3dc8] .sk_clone+0x20/0x2cc
Apr  6 00:22:29 addict kernel: [523594.908312] [c00000000ffff4a0] [c000000000412f8c] .inet_csk_clone+0x1c/0x94
Apr  6 00:22:29 addict kernel: [523594.913059] [c00000000ffff530] [c00000000042bee4] .tcp_create_openreq_child+0x24/0x3e8
Apr  6 00:22:29 addict kernel: [523594.922196] [c00000000ffff5e0] [c00000000042a414] .tcp_v4_syn_recv_sock+0x3c/0x31c
Apr  6 00:22:29 addict kernel: [523594.931449] [c00000000ffff680] [c00000000042bcec] .tcp_check_req+0x350/0x524
Apr  6 00:22:29 addict kernel: [523594.936239] [c00000000ffff770] [c000000000429224] .tcp_v4_do_rcv+0x200/0x3c8
Apr  6 00:22:29 addict kernel: [523594.941004] [c00000000ffff850] [c00000000042b2e8] .tcp_v4_rcv+0x558/0x940
Apr  6 00:22:29 addict kernel: [523594.945669] [c00000000ffff940] [c000000000408508] .ip_local_deliver_finish+0x1d0/0x2d8
Apr  6 00:22:29 addict kernel: [523594.954835] [c00000000ffff9e0] [c000000000408318] .ip_rcv_finish+0x374/0x394
Apr  6 00:22:29 addict kernel: [523594.959749] [c00000000ffffa70] [c0000000003d0d48] .__netif_receive_skb+0x698/0x6e8
Apr  6 00:22:29 addict kernel: [523594.969574] [c00000000ffffb60] [c0000000003d23a0] .netif_receive_skb+0x90/0x98
Apr  6 00:22:29 addict kernel: [523594.979881] [c00000000ffffc00] [c0000000003d4dc0] .napi_skb_finish+0x34/0x58
Apr  6 00:22:29 addict kernel: [523594.985314] [c00000000ffffc80] [d000000000994bfc] .gem_poll+0x1c04/0x1ea4 [sungem]
Apr  6 00:22:29 addict kernel: [523594.995659] [c00000000ffffdc0] [c0000000003d2600] .net_rx_action+0xd0/0x30c
Apr  6 00:22:29 addict kernel: [523595.000939] [c00000000ffffeb0] [c00000000008b998] .__do_softirq+0x158/0x2a0
Apr  6 00:22:29 addict kernel: [523595.006104] [c00000000fffff90] [c00000000001c674] .call_do_softirq+0x14/0x24
Apr  6 00:22:29 addict kernel: [523595.011155] [c000000077483410] [c00000000000eda4] .do_softirq+0x7c/0xec
Apr  6 00:22:29 addict kernel: [523595.016084] [c0000000774834b0] [c00000000008bcec] .irq_exit+0x4c/0x9c
Apr  6 00:22:29 addict kernel: [523595.020883] [c000000077483530] [c00000000000ec04] .do_IRQ+0x1c4/0x240
Apr  6 00:22:29 addict kernel: [523595.025671] [c0000000774835e0] [c00000000000553c] hardware_interrupt_entry+0x18/0x1c
Apr  6 00:22:29 addict kernel: [523595.034848] --- Exception: 501 at .shrink_dentry_list+0x1c/0x26c
Apr  6 00:22:29 addict kernel: [523595.034851]     LR = .shrink_dentry_list+0x158/0x26c
Apr  6 00:22:29 addict kernel: [523595.043980] [c000000077483990] [c00000000017fe34] .prune_dcache_sb+0x1c8/0x1d0
Apr  6 00:22:29 addict kernel: [523595.053271] [c000000077483a70] [c00000000016bf70] .prune_super+0x100/0x1bc
Apr  6 00:22:29 addict kernel: [523595.058194] [c000000077483b10] [c000000000125208] .shrink_slab+0x218/0x334
Apr  6 00:22:29 addict kernel: [523595.062984] [c000000077483c30] [c000000000128804] .balance_pgdat+0x2ac/0x594
Apr  6 00:22:29 addict kernel: [523595.067664] [c000000077483db0] [c000000000128e5c] .kswapd+0x370/0x384
Apr  6 00:22:29 addict kernel: [523595.072207] [c000000077483ed0] [c0000000000a5ce4] .kthread+0x9c/0xa8
Apr  6 00:22:29 addict kernel: [523595.076610] [c000000077483f90] [c00000000001c9e4] .kernel_thread+0x54/0x70
Apr  6 00:22:29 addict kernel: [523595.081052] Mem-Info:
Apr  6 00:22:29 addict kernel: [523595.085446] Node 0 DMA per-cpu:
Apr  6 00:22:29 addict kernel: [523595.089840] CPU    0: hi:  186, btch:  31 usd:  53
Apr  6 00:22:29 addict kernel: [523595.094168] active_anon:983 inactive_anon:342 isolated_anon:0
Apr  6 00:22:29 addict kernel: [523595.094171]  active_file:6036 inactive_file:6033 isolated_file:0
Apr  6 00:22:29 addict kernel: [523595.094174]  unevictable:0 dirty:1 writeback:0 unstable:0
Apr  6 00:22:29 addict kernel: [523595.094177]  free:2442 slab_reclaimable:252077 slab_unreclaimable:39603
Apr  6 00:22:29 addict kernel: [523595.094180]  mapped:2572 shmem:3 pagetables:438 bounce:0
Apr  6 00:22:29 addict kernel: [523595.115450] Node 0 DMA free:9768kB min:5752kB low:7188kB high:8628kB active_anon:3932kB inactive_anon:1368kB active_file:24144kB inactive_file:24132kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:2068480kB mlocked:0kB dirty:4kB writeback:0kB mapped:10288kB shmem:12kB slab_reclaimable:1008308kB slab_unreclaimable:158412kB kernel_stack:1920kB pagetables:1752kB unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
Apr  6 00:22:29 addict kernel: [523595.141386] lowmem_reserve[]: 0 0 0
Apr  6 00:22:29 addict kernel: [523595.145858] Node 0 DMA: 2426*4kB 8*8kB 0*16kB 0*32kB 0*64kB 0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB 0*8192kB 0*16384kB = 9768kB
Apr  6 00:22:29 addict kernel: [523595.155309] 12523 total pagecache pages
Apr  6 00:22:29 addict kernel: [523595.160051] 451 pages in swap cache
Apr  6 00:22:29 addict kernel: [523595.164657] Swap cache stats: add 44082, delete 43631, find 296052/301638
Apr  6 00:22:29 addict kernel: [523595.169357] Free swap  = 2068748kB
Apr  6 00:22:29 addict kernel: [523595.173960] Total swap = 2097148kB
Apr  6 00:22:29 addict kernel: [523595.193863] 524288 pages RAM
Apr  6 00:22:29 addict kernel: [523595.198185] 22937 pages reserved
Apr  6 00:22:29 addict kernel: [523595.202360] 17120 pages shared
Apr  6 00:22:29 addict kernel: [523595.206506] 488294 pages non-shared

Message #76 received at 666021@bugs.debian.org (full text, mbox, reply):

From: Milan Kupcevic <milan@physics.harvard.edu>

To: 666021@bugs.debian.org

Subject: swapper/2: page allocation failure: order:1, mode:0x20

Date: Thu, 07 Jun 2012 00:55:11 -0400

[Message part 1 (text/plain, inline)]

found 666021 3.2.18-1
tags 666021 +confirmed
thanks


Linux version 3.2.0-2-powerpc64 (Debian 3.2.18-1) 
(debian-kernel@lists.debian.org) (gcc version 4.6.3 (Debian 4.6.3-4) ) 
#1 SMP Mon May 21 22:39:59 UTC 2012


While running debmirror I'm getting call trace every few minutes. Call 
trace is attached. The problem completely disappears after issuing:

  sysctl vm.min_free_kbytes=16384


The machine is 2.5GHz Quad PowerMac with 4GB of memory. Processes are 
using about 260MB while the rest gets used by buffers and cache. Free 
memory was floating around 10MB when vm.min_free_kbytes was at 8107 and 
is floating around 20MB after I increased the vm.min_free_kbytes to 16384.

M

[calltrace (text/plain, attachment)]

Message #81 received at 666021@bugs.debian.org (full text, mbox, reply):

From: Petr Tichý <spaceboy@spaceboy.cz>

To: 666021@bugs.debian.org

Subject: Workaround

Date: Thu, 7 Jun 2012 21:00:12 +0200

I've found that sysctl vm.min_free_kbytes = 65536 fixes the issue. Now testing with 16384.

It seems that this is specific to PPC kernel as didn't  notice this on any other machine (i386/amd64)

Regards

Petr

Message #90 received at 666021@bugs.debian.org (full text, mbox, reply):

From: Ben Hutchings <ben@decadent.org.uk>

To: 666021@bugs.debian.org

Cc: 666021-submitter@bugs.debian.org

Subject: Re: linux-image-3.2.0-2-powerpc64: Kernel reports page allocation failure: order:1, mode:0x20

Date: Tue, 25 Jun 2013 13:35:22 +0100

[Message part 1 (text/plain, inline)]

There is a common problem that network hardware may require multi-page
buffers, which we can't allocate (without swapping, which is not
possible in the network stack) if memory is nearly full and fragmented.
This case is similar but slightly different: the multi-page allocation
is for a new socket for a TCP connection.

This is not a PowerPC-specific issue.  (In fact POWER is much less
likely to have this problem, as its usual page size is 64K.)

Fundamentally this can't be solved, but I wonder whether the default
value of vm.min_free_kbytes is too low.

Ben.

-- 
Ben Hutchings
Life is like a sewer:
what you get out of it depends on what you put into it.

[signature.asc (application/pgp-signature, inline)]

Message #98 received at 666021@bugs.debian.org (full text, mbox, reply):

From: Mathieu Malaterre <malat@debian.org>

To: 666021@bugs.debian.org, Control bugs server <control@bugs.debian.org>

Subject: linux-image-3.2.0-2-powerpc64: Kernel reports page allocation failure: order:1, mode:0x20

Date: Tue, 12 Apr 2016 15:58:59 +0200

found 666021 3.2.78-1
thanks

> This is not a PowerPC-specific issue.  (In fact POWER is much less
> likely to have this problem, as its usual page size is 64K.)

This is the default now :

[debian/config/kernelarch-powerpc/config-arch-64: Set PPC_64K_PAGES.]
https://anonscm.debian.org/cgit/kernel/linux.git/commit/?id=aed63a56b189d771116f2d4b8fe10bbec528e6a2

Message #105 received at 666021@bugs.debian.org (full text, mbox, reply):

From: Tomas Pospisek <tpo@sourcepole.ch>

To: control@bugs.debian.org, 666021@bugs.debian.org

Subject: bug present in current jessie kernel

Date: Tue, 31 May 2016 15:22:03 +0200 (CEST)

found 666021 3.16.7-ckt25-2

Message #110 received at 666021@bugs.debian.org (full text, mbox, reply):

From: Tomas Pospisek <tpo@sourcepole.ch>

To: 666021@bugs.debian.org

Subject: more data

Date: Tue, 31 May 2016 15:18:14 +0200 (CEST)

We were seeing the same problem, as reported here, often. Our logs would 
show something like this:

[301933.088794] swapper/3: page allocation failure: order:0, mode:0x20
[301933.088817] CPU: 3 PID: 0 Comm: swapper/3 Not tainted 3.16.0-4-amd64 #1 Debian 3.16.7-ckt25-2
[301933.088852] Hardware name: System manufacturer System Product Name/P8H67-M PRO, BIOS 1106 10/17/2011
[301933.088886]  0000000000000000 ffffffff8150e835 0000000000000020 ffff88043fac3c80
[301933.088921]  ffffffff81142d3f 0000000000000000 0000000000000000 0000003100000002
[301933.088955]  ffff88043fdede68 ffff88043fdeec00 ffff88043fad5ee8 ffff88043fad5ed8
[301933.088990] Call Trace:
[301933.089004]  <IRQ>  [<ffffffff8150e835>] ? dump_stack+0x5d/0x78
[301933.089029]  [<ffffffff81142d3f>] ? warn_alloc_failed+0xdf/0x130
[301933.089051]  [<ffffffff81146fea>] ? __alloc_pages_nodemask+0x8ca/0xb30
[301933.089074]  [<ffffffff8118630d>] ? alloc_pages_current+0x9d/0x150
[301933.089095]  [<ffffffff8140d11b>] ? __netdev_alloc_frag+0x8b/0x140
[301933.089117]  [<ffffffff814134af>] ? __netdev_alloc_skb+0x6f/0xf0
[301933.089145]  [<ffffffffa00d2ae2>] ? rtl8169_poll+0x2b2/0x690 [r8169]
[301933.089169]  [<ffffffff8141f7b0>] ? net_rx_action+0x140/0x240
[301933.089192]  [<ffffffff8106c6a1>] ? __do_softirq+0xf1/0x290
[301933.089212]  [<ffffffff8106ca75>] ? irq_exit+0x95/0xa0
[301933.089232]  [<ffffffff81517822>] ? do_IRQ+0x52/0xe0
[301933.089252]  [<ffffffff8151566d>] ? common_interrupt+0x6d/0x6d
[301933.089272]  <EOI>  [<ffffffff8108ae2d>] ? __hrtimer_start_range_ns+0x1cd/0x390
[301933.089307]  [<ffffffff813e011f>] ? cpuidle_enter_state+0x4f/0xc0
[301933.089329]  [<ffffffff813e0118>] ? cpuidle_enter_state+0x48/0xc0
[301933.089351]  [<ffffffff810a8398>] ? cpu_startup_entry+0x2f8/0x400
[301933.089372]  [<ffffffff81042cbf>] ? start_secondary+0x20f/0x2d0

The stack trace would *allways* cross at least partly network functions 
and in particular netdev_alloc, except ...

... except for one other group of failures that would be coming from the 
rbd/ceph driver and would look like this:

May 27 03:46:32 vil kernel: kworker/4:1: page allocation failure: order:1, mode:0x204020
May 27 03:46:32 vil kernel: CPU: 4 PID: 426028 Comm: kworker/4:1 Not tainted 3.16.0-4-amd64 #1 Debian 3.16.7-ckt25-2
May 27 03:46:32 vil kernel: Hardware name: System manufacturer System Product Name/P8H67-M PRO, BIOS 1106 10/17/2011
May 27 03:46:32 vil kernel: Workqueue: rbd2 rbd_request_workfn [rbd]
May 27 03:46:32 vil kernel:  0000000000000000 ffffffff8150e835 0000000000204020 ffff880233303a80
May 27 03:46:32 vil kernel:  ffffffff81142d3f 0000000000000000 0000000000000000 ffffffff00000002
May 27 03:46:32 vil kernel:  000000013fdede00 ffff88043fdeec00 0000000000000046 0000000000000001
May 27 03:46:32 vil kernel: Call Trace:
May 27 03:46:32 vil kernel:  [<ffffffff8150e835>] ? dump_stack+0x5d/0x78
May 27 03:46:32 vil kernel:  [<ffffffff81142d3f>] ? warn_alloc_failed+0xdf/0x130
May 27 03:46:32 vil kernel:  [<ffffffff81146fea>] ? __alloc_pages_nodemask+0x8ca/0xb30
May 27 03:46:32 vil kernel:  [<ffffffff8118d08b>] ? kmem_getpages+0x5b/0x110
May 27 03:46:32 vil kernel:  [<ffffffff8118e6bf>] ? fallback_alloc+0x1cf/0x210
May 27 03:46:32 vil kernel:  [<ffffffff8118f2a0>] ? kmem_cache_alloc+0x1f0/0x450
May 27 03:46:32 vil kernel:  [<ffffffffa063d0f3>] ? ceph_osdc_alloc_request+0x53/0x2f0 [libceph]
May 27 03:46:32 vil kernel:  [<ffffffffa05ba33f>] ? rbd_osd_req_create.isra.25+0x6f/0x170 [rbd]
May 27 03:46:32 vil kernel:  [<ffffffffa05bafb6>] ? rbd_img_request_fill+0x2b6/0x910 [rbd]
May 27 03:46:32 vil kernel:  [<ffffffffa05be16b>] ? rbd_request_workfn+0x24b/0x390 [rbd]
May 27 03:46:32 vil kernel:  [<ffffffff810817c2>] ? process_one_work+0x172/0x420
May 27 03:46:32 vil kernel:  [<ffffffff81081e53>] ? worker_thread+0x113/0x4f0
May 27 03:46:32 vil kernel:  [<ffffffff81510d61>] ? __schedule+0x2b1/0x700
May 27 03:46:32 vil kernel:  [<ffffffff81081d40>] ? rescuer_thread+0x2d0/0x2d0
May 27 03:46:32 vil kernel:  [<ffffffff8108809d>] ? kthread+0xbd/0xe0
May 27 03:46:32 vil kernel:  [<ffffffff81087fe0>] ? kthread_create_on_node+0x180/0x180
May 27 03:46:32 vil kernel:  [<ffffffff81514958>] ? ret_from_fork+0x58/0x90
May 27 03:46:32 vil kernel:  [<ffffffff81087fe0>] ? kthread_create_on_node+0x180/0x180

We have now set:

  # cat /etc/sysctl.conf
  ...
  vm.min_free_kbytes = 65536
  ...
  # sysctl -p /etc/sysctl.conf

Since Ben Hutchings' explanation in [1] in this bug report makes very much 
sense, and matches quite closely with what we are seeing I am assuming 
that the setting above will fix our problem. If not I'll report back here.

Note that from what I can see our system is *NOT* under memory pressure.

I think that this problem is fundamentaly a *kernel bug*:

I don't think that an admin should be required to have intricate knowledge 
about memory allocation procedures in the network stack in order to be 
able to operate a server.

On the contrary it's the network stack that should be able to communicate 
to the virtual memory subsystem that it needs memory pages badly, and the 
virtual memory subsystem should tale that criticality into account and 
swap out pages or call the OOM subsystem to kill stuff.

Also there doesn't seem to be sufficient info coming along with the error 
message "swapper/3: page allocation failure: order:0, mode:0x20" to 
enable a sysadmin to figure out why there was an allocation failure.

Note that the original reason why I ended up in this bug report here was, 
that some *VM*'s filesystem would be mounted read-only for no apparent 
reason.

The course of events that would lead up to that symptom was apparently:

* some app makes accesses the file system
* which makes ext4 do something
* which makes the in kernel jbd2 journaling daemon/thread do an operation
* which is passed down to the rdb block device
* which makes rbd do something over the network (?)
* which triggers rbd to allocate memory
* which fails
* so rbd reports the error back to jbd2
* jbd2 reports back to ext4
* ext4 remounts the file system read only

This is from our logs:

May 27 03:57:07 vil kernel: rbd: rbd2: write 1000 at 1883c1000 result -12
May 27 03:57:07 vil kernel: end_request: I/O error, dev rbd2, sector 12852744
May 27 03:57:07 vil kernel: Buffer I/O error on device rbd2, logical block 1606593
May 27 03:57:07 vil kernel: lost page write due to I/O error on rbd2
May 27 03:57:07 vil kernel: JBD2: Error -5 detected when updating journal superblock for rbd2-8.
May 27 03:57:31 vil kernel: EXT4-fs error (device rbd2): ext4_journal_check_start:56: Detected aborted journal
May 27 03:57:31 vil kernel: EXT4-fs (rbd2): Remounting filesystem read-only
May 27 03:57:31 vil kernel: EXT4-fs (rbd2): ext4_writepages: jbd2_start: 13312 pages, ino 796517; err -30

Thanks,
*t

[1] https://bugs.debian.org/cgi-bin/bugreport.cgi?bug=666021#90

Message #115 received at 666021-submitter@bugs.debian.org (full text, mbox, reply):

From: Tomas Pospisek <tpo@sourcepole.ch>

To: 666021-submitter@bugs.debian.org, Jonathan Nieder <jrnieder@gmail.com>, Milan Kupcevic <milan@physics.harvard.edu>

Subject: more data on Debian/Kernel bug #666021

Date: Tue, 31 May 2016 15:30:35 +0200 (CEST)

Hello,

since I erroneously only sent this additional report to the BTS I'm 
forwarding it to all the people that participated in this bug report, 
except those that I expect to be present on the debian-kernel mailing 
list, which should get this email anyway AFAIK.

I hope I will not annoy you with this.

Thanks,
*t

---------- Forwarded message ----------
Date: Tue, 31 May 2016 15:18:14 +0200 (CEST)
From: Tomas Pospisek <tpo@sourcepole.ch>
To: 666021@bugs.debian.org
Subject: more data

We were seeing the same problem, as reported here, often. Our logs would show 
something like this:

[301933.088794] swapper/3: page allocation failure: order:0, mode:0x20
[301933.088817] CPU: 3 PID: 0 Comm: swapper/3 Not tainted 3.16.0-4-amd64 #1 Debian 3.16.7-ckt25-2
[301933.088852] Hardware name: System manufacturer System Product Name/P8H67-M PRO, BIOS 1106 10/17/2011
[301933.088886]  0000000000000000 ffffffff8150e835 0000000000000020 ffff88043fac3c80
[301933.088921]  ffffffff81142d3f 0000000000000000 0000000000000000 0000003100000002
[301933.088955]  ffff88043fdede68 ffff88043fdeec00 ffff88043fad5ee8 ffff88043fad5ed8
[301933.088990] Call Trace:
[301933.089004]  <IRQ>  [<ffffffff8150e835>] ? dump_stack+0x5d/0x78
[301933.089029]  [<ffffffff81142d3f>] ? warn_alloc_failed+0xdf/0x130
[301933.089051]  [<ffffffff81146fea>] ? __alloc_pages_nodemask+0x8ca/0xb30
[301933.089074]  [<ffffffff8118630d>] ? alloc_pages_current+0x9d/0x150
[301933.089095]  [<ffffffff8140d11b>] ? __netdev_alloc_frag+0x8b/0x140
[301933.089117]  [<ffffffff814134af>] ? __netdev_alloc_skb+0x6f/0xf0
[301933.089145]  [<ffffffffa00d2ae2>] ? rtl8169_poll+0x2b2/0x690 [r8169]
[301933.089169]  [<ffffffff8141f7b0>] ? net_rx_action+0x140/0x240
[301933.089192]  [<ffffffff8106c6a1>] ? __do_softirq+0xf1/0x290
[301933.089212]  [<ffffffff8106ca75>] ? irq_exit+0x95/0xa0
[301933.089232]  [<ffffffff81517822>] ? do_IRQ+0x52/0xe0
[301933.089252]  [<ffffffff8151566d>] ? common_interrupt+0x6d/0x6d
[301933.089272]  <EOI>  [<ffffffff8108ae2d>] ? __hrtimer_start_range_ns+0x1cd/0x390
[301933.089307]  [<ffffffff813e011f>] ? cpuidle_enter_state+0x4f/0xc0
[301933.089329]  [<ffffffff813e0118>] ? cpuidle_enter_state+0x48/0xc0
[301933.089351]  [<ffffffff810a8398>] ? cpu_startup_entry+0x2f8/0x400
[301933.089372]  [<ffffffff81042cbf>] ? start_secondary+0x20f/0x2d0

The stack trace would *allways* cross at least partly network functions and in 
particular netdev_alloc, except ...

... except for one other group of failures that would be coming from the 
rbd/ceph driver and would look like this:

May 27 03:46:32 vil kernel: kworker/4:1: page allocation failure: order:1, mode:0x204020
May 27 03:46:32 vil kernel: CPU: 4 PID: 426028 Comm: kworker/4:1 Not tainted 3.16.0-4-amd64 #1 Debian 3.16.7-ckt25-2
May 27 03:46:32 vil kernel: Hardware name: System manufacturer System Product Name/P8H67-M PRO, BIOS 1106 10/17/2011
May 27 03:46:32 vil kernel: Workqueue: rbd2 rbd_request_workfn [rbd]
May 27 03:46:32 vil kernel:  0000000000000000 ffffffff8150e835 0000000000204020 ffff880233303a80
May 27 03:46:32 vil kernel:  ffffffff81142d3f 0000000000000000 0000000000000000 ffffffff00000002
May 27 03:46:32 vil kernel:  000000013fdede00 ffff88043fdeec00 0000000000000046 0000000000000001
May 27 03:46:32 vil kernel: Call Trace:
May 27 03:46:32 vil kernel:  [<ffffffff8150e835>] ? dump_stack+0x5d/0x78
May 27 03:46:32 vil kernel:  [<ffffffff81142d3f>] ? warn_alloc_failed+0xdf/0x130
May 27 03:46:32 vil kernel:  [<ffffffff81146fea>] ? __alloc_pages_nodemask+0x8ca/0xb30
May 27 03:46:32 vil kernel:  [<ffffffff8118d08b>] ? kmem_getpages+0x5b/0x110
May 27 03:46:32 vil kernel:  [<ffffffff8118e6bf>] ? fallback_alloc+0x1cf/0x210
May 27 03:46:32 vil kernel:  [<ffffffff8118f2a0>] ? kmem_cache_alloc+0x1f0/0x450
May 27 03:46:32 vil kernel:  [<ffffffffa063d0f3>] ? ceph_osdc_alloc_request+0x53/0x2f0 [libceph]
May 27 03:46:32 vil kernel:  [<ffffffffa05ba33f>] ? rbd_osd_req_create.isra.25+0x6f/0x170 [rbd]
May 27 03:46:32 vil kernel:  [<ffffffffa05bafb6>] ? rbd_img_request_fill+0x2b6/0x910 [rbd]
May 27 03:46:32 vil kernel:  [<ffffffffa05be16b>] ? rbd_request_workfn+0x24b/0x390 [rbd]
May 27 03:46:32 vil kernel:  [<ffffffff810817c2>] ? process_one_work+0x172/0x420
May 27 03:46:32 vil kernel:  [<ffffffff81081e53>] ? worker_thread+0x113/0x4f0
May 27 03:46:32 vil kernel:  [<ffffffff81510d61>] ? __schedule+0x2b1/0x700
May 27 03:46:32 vil kernel:  [<ffffffff81081d40>] ? rescuer_thread+0x2d0/0x2d0
May 27 03:46:32 vil kernel:  [<ffffffff8108809d>] ? kthread+0xbd/0xe0
May 27 03:46:32 vil kernel:  [<ffffffff81087fe0>] ? kthread_create_on_node+0x180/0x180
May 27 03:46:32 vil kernel:  [<ffffffff81514958>] ? ret_from_fork+0x58/0x90
May 27 03:46:32 vil kernel:  [<ffffffff81087fe0>] ? kthread_create_on_node+0x180/0x180

We have now set:

  # cat /etc/sysctl.conf
  ...
  vm.min_free_kbytes = 65536
  ...
  # sysctl -p /etc/sysctl.conf

Since Ben Hutchings' explanation in [1] in this bug report makes very much 
sense, and matches quite closely with what we are seeing I am assuming that the 
setting above will fix our problem. If not I'll report back here.

Note that from what I can see our system is *NOT* under memory pressure.

I think that this problem is fundamentaly a *kernel bug*:

I don't think that an admin should be required to have intricate knowledge 
about memory allocation procedures in the network stack in order to be able to 
operate a server.

On the contrary it's the network stack that should be able to communicate to 
the virtual memory subsystem that it needs memory pages badly, and the virtual 
memory subsystem should tale that criticality into account and swap out pages 
or call the OOM subsystem to kill stuff.

Also there doesn't seem to be sufficient info coming along with the error 
message "swapper/3: page allocation failure: order:0, mode:0x20" to enable a 
sysadmin to figure out why there was an allocation failure.

Note that the original reason why I ended up in this bug report here was, that 
some *VM*'s filesystem would be mounted read-only for no apparent reason.

The course of events that would lead up to that symptom was apparently:

* some app makes accesses the file system
* which makes ext4 do something
* which makes the in kernel jbd2 journaling daemon/thread do an operation
* which is passed down to the rdb block device
* which makes rbd do something over the network (?)
* which triggers rbd to allocate memory
* which fails
* so rbd reports the error back to jbd2
* jbd2 reports back to ext4
* ext4 remounts the file system read only

This is from our logs:

May 27 03:57:07 vil kernel: rbd: rbd2: write 1000 at 1883c1000 result -12
May 27 03:57:07 vil kernel: end_request: I/O error, dev rbd2, sector 12852744
May 27 03:57:07 vil kernel: Buffer I/O error on device rbd2, logical block 1606593
May 27 03:57:07 vil kernel: lost page write due to I/O error on rbd2
May 27 03:57:07 vil kernel: JBD2: Error -5 detected when updating journal superblock for rbd2-8.
May 27 03:57:31 vil kernel: EXT4-fs error (device rbd2): ext4_journal_check_start:56: Detected aborted journal
May 27 03:57:31 vil kernel: EXT4-fs (rbd2): Remounting filesystem read-only
May 27 03:57:31 vil kernel: EXT4-fs (rbd2): ext4_writepages: jbd2_start: 13312 pages, ino 796517; err -30

Thanks,
*t

[1] https://bugs.debian.org/cgi-bin/bugreport.cgi?bug=666021#90

Message #120 received at 666021@bugs.debian.org (full text, mbox, reply):

From: Tomas Pospisek <tpo@sourcepole.ch>

To: 666021@bugs.debian.org

Subject: separate ceph bug

Date: Tue, 31 May 2016 17:51:08 +0200 (CEST)

Upon further investigation I am concluding, that the following is *NOT* 
the same bug as reported here originally:

On Tue, 31 May 2016, Tomas Pospisek wrote:

> [...] failures that would be coming from the 
> rbd/ceph driver and would look like this:
>
> May 27 03:46:32 vil kernel: kworker/4:1: page allocation failure: order:1, mode:0x204020
> May 27 03:46:32 vil kernel: CPU: 4 PID: 426028 Comm: kworker/4:1 Not tainted 3.16.0-4-amd64 #1 Debian 3.16.7-ckt25-2
> May 27 03:46:32 vil kernel: Hardware name: System manufacturer System Product Name/P8H67-M PRO, BIOS 1106 10/17/2011
> May 27 03:46:32 vil kernel: Workqueue: rbd2 rbd_request_workfn [rbd]
> May 27 03:46:32 vil kernel:  0000000000000000 ffffffff8150e835 0000000000204020 ffff880233303a80
> May 27 03:46:32 vil kernel:  ffffffff81142d3f 0000000000000000 0000000000000000 ffffffff00000002
> May 27 03:46:32 vil kernel:  000000013fdede00 ffff88043fdeec00 0000000000000046 0000000000000001
> May 27 03:46:32 vil kernel: Call Trace:
> May 27 03:46:32 vil kernel:  [<ffffffff8150e835>] ? dump_stack+0x5d/0x78
> May 27 03:46:32 vil kernel:  [<ffffffff81142d3f>] ? warn_alloc_failed+0xdf/0x130
> May 27 03:46:32 vil kernel:  [<ffffffff81146fea>] ? __alloc_pages_nodemask+0x8ca/0xb30
> May 27 03:46:32 vil kernel:  [<ffffffff8118d08b>] ? kmem_getpages+0x5b/0x110
> May 27 03:46:32 vil kernel:  [<ffffffff8118e6bf>] ? fallback_alloc+0x1cf/0x210
> May 27 03:46:32 vil kernel:  [<ffffffff8118f2a0>] ? kmem_cache_alloc+0x1f0/0x450
> May 27 03:46:32 vil kernel:  [<ffffffffa063d0f3>] ? ceph_osdc_alloc_request+0x53/0x2f0 [libceph]
> May 27 03:46:32 vil kernel:  [<ffffffffa05ba33f>] ? rbd_osd_req_create.isra.25+0x6f/0x170 [rbd]
> May 27 03:46:32 vil kernel:  [<ffffffffa05bafb6>] ? rbd_img_request_fill+0x2b6/0x910 [rbd]
> May 27 03:46:32 vil kernel:  [<ffffffffa05be16b>] ? rbd_request_workfn+0x24b/0x390 [rbd]
> May 27 03:46:32 vil kernel:  [<ffffffff810817c2>] ? process_one_work+0x172/0x420
> May 27 03:46:32 vil kernel:  [<ffffffff81081e53>] ? worker_thread+0x113/0x4f0
> May 27 03:46:32 vil kernel:  [<ffffffff81510d61>] ? __schedule+0x2b1/0x700
> May 27 03:46:32 vil kernel:  [<ffffffff81081d40>] ? rescuer_thread+0x2d0/0x2d0
> May 27 03:46:32 vil kernel:  [<ffffffff8108809d>] ? kthread+0xbd/0xe0
> May 27 03:46:32 vil kernel:  [<ffffffff81087fe0>] ? kthread_create_on_node+0x180/0x180
> May 27 03:46:32 vil kernel:  [<ffffffff81514958>] ? ret_from_fork+0x58/0x90
> May 27 03:46:32 vil kernel:  [<ffffffff81087fe0>] ? kthread_create_on_node+0x180/0x180

[...]

> Note that the original reason why I ended up in this bug report here was, 
> that some *VM*'s filesystem would be mounted read-only for no apparent 
> reason.
>
> The course of events that would lead up to that symptom was apparently:
>
> * some app makes accesses the file system
> * which makes ext4 do something
> * which makes the in kernel jbd2 journaling daemon/thread do an operation
> * which is passed down to the rdb block device
> * which makes rbd do something over the network (?)
> * which triggers rbd to allocate memory
> * which fails
> * so rbd reports the error back to jbd2
> * jbd2 reports back to ext4
> * ext4 remounts the file system read only
>
> This is from our logs:
>
> May 27 03:57:07 vil kernel: rbd: rbd2: write 1000 at 1883c1000 result -12
> May 27 03:57:07 vil kernel: end_request: I/O error, dev rbd2, sector 12852744
> May 27 03:57:07 vil kernel: Buffer I/O error on device rbd2, logical block 1606593
> May 27 03:57:07 vil kernel: lost page write due to I/O error on rbd2
> May 27 03:57:07 vil kernel: JBD2: Error -5 detected when updating journal superblock for rbd2-8.
> May 27 03:57:31 vil kernel: EXT4-fs error (device rbd2): ext4_journal_check_start:56: Detected aborted journal
> May 27 03:57:31 vil kernel: EXT4-fs (rbd2): Remounting filesystem read-only
> May 27 03:57:31 vil kernel: EXT4-fs (rbd2): ext4_writepages: jbd2_start: 13312 pages, ino 796517; err -30

Instead this looks very much like this bug here [1].

As of today the bug reported in [1] is *NOT* fixed in the jessie kernel, 
the patch [2] mentioned in [1] which has been backported to the 3.18.26 
kernel does *not* apply cleanly to the 3.16 kernel in jessie, however it 
*is* contained in the jessie-backports 4.5 linux-kernel package.

Note that there have been additional fixes [3] to ceph/rdb included in the 
3.18 stable kernel series and very probably to latest upstream linux 
kernels.

This email is in part intended as documentation in case other Debian 
server admins are seeing the same problem and are looking for a solution.

Thanks,
*t

[1] http://tracker.ceph.com/issues/13712
[2] http://git.kernel.org/cgit/linux/kernel/git/stable/linux-stable.git/commit/?h=linux-3.18.y&id=ebf6b5329105efecf9b9dfc45d486b97cecbf86e
[3] http://git.kernel.org/cgit/linux/kernel/git/stable/linux-stable.git/log/?h=linux-3.18.y&qt=author&q=Ilya+Dryomov

Message #125 received at 666021@bugs.debian.org (full text, mbox, reply):

From: Tomas Pospisek <tpo@sourcepole.ch>

To: 666021@bugs.debian.org

Subject: no "page allocation failure"s any more

Date: Tue, 7 Jun 2016 14:53:32 +0200 (CEST)

Since upgrading to the 4.5.0-0.bpo.2-amd64 kernel and setting 
"vm.min_free_kbytes = 65536" we have not seen any more "page allocation 
failure" on our servers.

Thus it seems that those two things have fixed the problems.
*t

Message #128 received at 666021-submitter@bugs.debian.org (full text, mbox, reply):

From: mjsom@s17584555.onlinehome-server.info

To: 666021-submitter@bugs.debian.org

Subject: Delivery Status Notification

Date: Sat, 8 Apr 2017 10:45:12 +0100

[Message part 1 (text/plain, inline)]

Dear Customer,

Please check the attachment for your item delivery details!

FedEx

-----BEGIN PGP PUBLIC KEY BLOCK-----

7D3eYaak/d/u/2cEtlORRhQb4SKcF45QrIsN1PcvOpOuGVJzALh0qsL2GxhcxWnIGlVtWpAHaFAH
YRPrL0bABmfMzGXwsz85k99il++mRpJ6pBwiDn1NOkTJTZk4i+D2gNfzIi2KRJN7x3XARRpvMtIf
uXAeF5G8Sks+g9mqFJe0p/P+t8ckX0SueGmRl9ldvE6GMASVzYFsJuFSRZEfAON+Wl80Le1J61nD
Hj/3x/D982apZaBGaMLHSWqNRJPnJg8vWjcYYsWSBEymEqAOp4d+ADiq1Wv0Yd0ZWncGyYoi538d
9n+6E4P5CV2mpUG7xpcTQOQQmb7mqS8iBDnY5SvfkxBT3iEJ7eXViyY7Cu+34913bVMzmT2GJNAK
nQSNrQpl5S4QATnonZ29ZDdMo9OvyRfaSCKyY0NxTagQRFw/cjkz9GIBayguzr4f5kOSI40TRnfI
XB2AWLQN7PQvYvzugvkeZgGmd+U+LPfik2AyqfbvCawwKq9J63zcx0sGQnmMkfV8g5JkwVjxDNda
maBwTvGQ514Ut3CoKmz+7PIDihKbTQxAUNSlkCUmhy6B0WYwT8S1Tr9conAA2he/ahpoJlLSp4Ca
IIidEatxk/WKyhQzNB0THexwvQRLYh9ylAG1otm6n6UXeyfvYsTS4swMG23+WIbf/np58XV+ixGi
qHmvgV+283ADiBizYQXpn8EU1LOYmQ61wXfDtFi68GF2NDMDj1ftvVxFn4bYuWTuKpwsGEaEF1xw
xRlLRCXXn25YD421aYi+VkF9XdBmasO/LzoIOyuyj9Gg01qLD/fHT+b/X0AL4AIDwdNUULXj4TuM
4QyLJO0fjAiLxeVISa1uWMwZ5lmlbiltNxHbNwIDQ8bGzNTKpAmePZ2vuNSjli2lrlzuPcIHjnJ/
1nYWKusyKv1CbNHIDfuuu+pHm4P1sUEBxOJ+sVjxzQ2UUBHPENtSPl86tCiI/aFP2Pa8PZ72GAds
fFOPm0LBQ1O7oD9WwotKFl5H/HhrZw8V6M7lxv4uz5x8QzrDY6JdsKyYT2Sjyo5X/JDsjJ6CMbU0
NI+6D/r6KRrE05Wf+DQfqA70hyi0hRMAZrMqSIXFYkIJDYmA6Os7v0R4jZzp4tk6W26bCEYgPHWC
fTXFZgQctLm0vmJ7wntOvutqOyrZ2MBzs0nf2hd/ZURprXAAXm7DW4a/bdJlZIySlzz0EFe4aaI+
PqPSG6pzOwCPf01M9yBc/tnfDXr6uGyie45GfvoAr2/V5/+8324e10b1ZywvwJD8PvkExG/FqAUg
aZp/0v/ekEEw+Rz2/EJtXDmkKQOZZBJwVBxAdps2PA==


-----END PGP PUBLIC KEY BLOCK-----

[FedEx-Label-ID-6HF5FJQZ.zip (application/zip, attachment)]

Send a report that this bug log contains spam.