Bug 167133

Summary: ENOMEM reading /dev/nst0
Product: Red Hat Enterprise Linux 4 Reporter: Charlie Brady <charlieb-redhat-bugzilla>
Component: kernelAssignee: Larry Woodman <lwoodman>
Status: CLOSED CURRENTRELEASE QA Contact: Brian Brock <bbrock>
Severity: medium Docs Contact:
Priority: medium    
Version: 4.0CC: jbaron
Target Milestone: ---   
Target Release: ---   
Hardware: i686   
OS: Linux   
Whiteboard:
Fixed In Version: RHEL4-U2 Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2005-10-17 18:54:54 UTC Type: ---
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:

Description Charlie Brady 2005-08-30 20:07:54 UTC
Description of problem:

Various commands fail with "Cannot allocate memory" when reading from the SCSI
tape device. 

Version-Release number of selected component (if applicable):

2.6.9-11.ELsmp

How reproducible:

Always.

Steps to Reproduce:
[root@server flexbackup]# mt rewind ; mt fsf 1 ; mt tell
At block 1.
[root@server flexbackup]# dd if=/dev/nst0 bs=10k count=1 of=/dev/null
dd: reading `/dev/nst0': Cannot allocate memory
0+0 records in
0+0 records out
[root@server flexbackup]# mt rewind ; mt fsf 1 ; mt tell
At block 1.
[root@server flexbackup]# star -t -v -f /dev/nst0
star: Cannot allocate memory. Error reading '/dev/nst0'.
star: 0 blocks + 0 bytes (total of 0 bytes = 0.00k).
[root@server flexbackup]#

Some commands succeed:

[root@server flexbackup]# gzip -dc < /dev/nst0 | tar tvf -
V--------- 0/0               0 2005-08-30 23:30:14 level 0 / Tue Aug 30 23:30:14
2005 tar+gzip from server--Volume Header--
drwx------ root/root         0 2003-10-21 02:14:32 ./lost+found/
drwxr-xr-x root/root         0 2005-07-07 11:39:41 ./boot/
drwxr-xr-x root/root         0 2005-08-29 11:59:45 ./dev/
dr-xr-xr-x root/root         0 2005-07-07 11:36:50 ./proc/
-rw-r--r-- root/root     16384 2005-07-07 11:38:37 ./var/lib/rpm/__db.001
-rw-r--r-- root/root   1318912 2005-07-07 11:38:37 ./var/lib/rpm/__db.002
-rw-r--r-- rpm/rpm    12791808 2005-08-29 11:59:20 ./var/lib/rpm/Packages
...

strace of the star command shows:

close(7)                                = 0
open("/dev/nst0", O_RDONLY|O_LARGEFILE) = 7
fcntl64(7, F_GETFL)                     = 0x8000 (flags O_RDONLY|O_LARGEFILE)
fstat64(7, {st_mode=S_IFCHR|0660, st_rdev=makedev(9, 128), ...}) = 0
ioctl(7, SNDCTL_TMR_TIMEBASE or TCGETS, 0xbff47194) = -1 EINVAL (Invalid argument)
mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) =
0xb77f2000
_llseek(7, 0, 0xbff4726c, SEEK_CUR)     = -1 ESPIPE (Illegal seek)
munmap(0xb77f2000, 4096)                = 0
fstat64(7, {st_mode=S_IFCHR|0660, st_rdev=makedev(9, 128), ...}) = 0
geteuid32()                             = 0
...
open("/etc/group", O_RDONLY)            = 8
fcntl64(8, F_GETFD)                     = 0
fcntl64(8, F_SETFD, FD_CLOEXEC)         = 0
fstat64(8, {st_mode=S_IFREG|0644, st_size=4249, ...}) = 0
mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) =
0xb77f2000
read(8, "root:x:0:admin,root\nbin:x:1:bin,"..., 4096) = 4096
close(8)                                = 0
munmap(0xb77f2000, 4096)                = 0
time(NULL)                              = 1125431335
clone(Process 12933 attached
child_stack=0, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD,
child_tidptr=0xb7ff7708) = 12933
[pid 12932] close(4 <unfinished ...>
[pid 12933] close(3 <unfinished ...>
[pid 12932] <... close resumed> )       = 0
[pid 12933] <... close resumed> )       = 0
[pid 12932] close(5 <unfinished ...>
[pid 12933] close(6 <unfinished ...>
[pid 12932] <... close resumed> )       = 0
[pid 12933] <... close resumed> )       = 0
[pid 12932] close(7)                    = 0
[pid 12932] read(3,  <unfinished ...>
[pid 12933] read(7, 0xb77f4000, 10240)  = -1 ENOMEM (Cannot allocate memory)
[pid 12933] write(2, "star: Cannot allocate memory. Er"..., 57star: Cannot
allocate memory. Error reading '/dev/nst0'.
) = 57
[pid 12933] close(4)                    = 0
[pid 12932] <... read resumed> "", 1)   = 0
[pid 12932] write(2, "star: 0 blocks + 0 bytes (total "..., 53 <unfinished ...>
[pid 12933] close(5star: 0 blocks + 0 bytes (total of 0 bytes = 0.00k).
 <unfinished ...>
[pid 12932] <... write resumed> )       = 53
[pid 12933] <... close resumed> )       = 0
[pid 12932] exit_group(12)              = ?
[pid 12933] exit_group(12)              = ?

Here's some system info - let me know what else you need:

[root@server flexbackup]# free
             total       used       free     shared    buffers     cached
Mem:       1034676     998908      35768          0     198660     148960
-/+ buffers/cache:     651288     383388
Swap:       264952         96     264856
[root@server flexbackup]# cat /proc/cpuinfo
processor       : 0
vendor_id       : GenuineIntel
cpu family      : 15
model           : 2
model name      : Intel(R) Xeon(TM) CPU 2.40GHz
stepping        : 9
cpu MHz         : 2393.414
cache size      : 512 KB
physical id     : 0
siblings        : 2
fdiv_bug        : no
hlt_bug         : no
f00f_bug        : no
coma_bug        : no
fpu             : yes
fpu_exception   : yes
cpuid level     : 2
wp              : yes
flags           : fpu vme de pse tsc msr pae mce cx8 apic mtrr pge mca cmov pat
pse36 clflush dts acpi mmx fxsr sse sse2 ss ht tm pbe cid xtpr
bogomips        : 4718.59

processor       : 1
vendor_id       : GenuineIntel
cpu family      : 15
model           : 2
model name      : Intel(R) Xeon(TM) CPU 2.40GHz
stepping        : 9
cpu MHz         : 2393.414
cache size      : 512 KB
physical id     : 0
siblings        : 2
fdiv_bug        : no
hlt_bug         : no
f00f_bug        : no
coma_bug        : no
fpu             : yes
fpu_exception   : yes
cpuid level     : 2
wp              : yes
flags           : fpu vme de pse tsc msr pae mce cx8 apic mtrr pge mca cmov pat
pse36 clflush dts acpi mmx fxsr sse sse2 ss ht tm pbe cid xtpr
bogomips        : 4767.74

[root@server flexbackup]#

[root@server flexbackup]# cat /proc/slabinfo
slabinfo - version: 2.0
# name            <active_objs> <num_objs> <objsize> <objperslab> <pagesperslab>
: tunables <batchcount> <limit> <sharedfactor> : slabdata <active_slabs>
<num_slabs> <sharedavail>
ip_fib_alias          14    226     16  226    1 : tunables  120   60    8 :
slabdata      1      1      0
ip_fib_hash           14    119     32  119    1 : tunables  120   60    8 :
slabdata      1      1      0
ip_conntrack_expect      0      0    256   15    1 : tunables  120   60    8 :
slabdata      0      0      0
ip_conntrack          54    170    384   10    1 : tunables   54   27    8 :
slabdata     17     17      0
fib6_nodes             7    119     32  119    1 : tunables  120   60    8 :
slabdata      1      1      0
ip6_dst_cache          7     15    256   15    1 : tunables  120   60    8 :
slabdata      1      1      0
ndisc_cache            1     15    256   15    1 : tunables  120   60    8 :
slabdata      1      1      0
rawv6_sock             4      5    768    5    1 : tunables   54   27    8 :
slabdata      1      1      0
udpv6_sock             1      5    768    5    1 : tunables   54   27    8 :
slabdata      1      1      0
tcpv6_sock             2      3   1280    3    1 : tunables   24   12    8 :
slabdata      1      1      0
dm_tio                 0      0     16  226    1 : tunables  120   60    8 :
slabdata      0      0      0
dm_io                  0      0     16  226    1 : tunables  120   60    8 :
slabdata      0      0      0
ext3_inode_cache  470374 470386    552    7    1 : tunables   54   27    8 :
slabdata  67198  67198      0
ext3_xattr             1     81     48   81    1 : tunables  120   60    8 :
slabdata      1      1      0
journal_handle        87    135     28  135    1 : tunables  120   60    8 :
slabdata      1      1      0
journal_head         160    324     48   81    1 : tunables  120   60    8 :
slabdata      4      4      0
revoke_table           4    290     12  290    1 : tunables  120   60    8 :
slabdata      1      1      0
revoke_record          0      0     16  226    1 : tunables  120   60    8 :
slabdata      0      0      0
scsi_cmd_cache        20     20    384   10    1 : tunables   54   27    8 :
slabdata      2      2      0
sgpool-128            32     33   2560    3    2 : tunables   24   12    8 :
slabdata     11     11      0
sgpool-64             32     33   1280    3    1 : tunables   24   12    8 :
slabdata     11     11      0
sgpool-32             32     36    640    6    1 : tunables   54   27    8 :
slabdata      6      6      0
sgpool-16             33     40    384   10    1 : tunables   54   27    8 :
slabdata      4      4      0
sgpool-8              52     60    256   15    1 : tunables  120   60    8 :
slabdata      4      4      0
unix_sock             37     63    512    7    1 : tunables   54   27    8 :
slabdata      9      9      0
ip_mrt_cache           0      0    128   31    1 : tunables  120   60    8 :
slabdata      0      0      0
tcp_tw_bucket         13     62    128   31    1 : tunables  120   60    8 :
slabdata      2      2      0
tcp_bind_bucket       24    226     16  226    1 : tunables  120   60    8 :
slabdata      1      1      0
tcp_open_request       0      0    128   31    1 : tunables  120   60    8 :
slabdata      0      0      0
inet_peer_cache        3     61     64   61    1 : tunables  120   60    8 :
slabdata      1      1      0
secpath_cache          0      0    128   31    1 : tunables  120   60    8 :
slabdata      0      0      0
xfrm_dst_cache         0      0    256   15    1 : tunables  120   60    8 :
slabdata      0      0      0
ip_dst_cache         264    315    256   15    1 : tunables  120   60    8 :
slabdata     21     21      0
arp_cache             14     45    256   15    1 : tunables  120   60    8 :
slabdata      3      3      0
raw_sock               4      6    640    6    1 : tunables   54   27    8 :
slabdata      1      1      0
udp_sock              28     78    640    6    1 : tunables   54   27    8 :
slabdata     13     13      0
tcp_sock              43    105   1152    7    2 : tunables   24   12    8 :
slabdata     15     15      0
flow_cache             0      0    128   31    1 : tunables  120   60    8 :
slabdata      0      0      0
mqueue_inode_cache      1      6    640    6    1 : tunables   54   27    8 :
slabdata      1      1      0
isofs_inode_cache      0      0    372   10    1 : tunables   54   27    8 :
slabdata      0      0      0
hugetlbfs_inode_cache      1     11    344   11    1 : tunables   54   27    8 :
slabdata      1      1      0
ext2_inode_cache       0      0    488    8    1 : tunables   54   27    8 :
slabdata      0      0      0
ext2_xattr             0      0     48   81    1 : tunables  120   60    8 :
slabdata      0      0      0
dquot                164    189    144   27    1 : tunables  120   60    8 :
slabdata      7      7      0
eventpoll_pwq          0      0     36  107    1 : tunables  120   60    8 :
slabdata      0      0      0
eventpoll_epi          0      0    128   31    1 : tunables  120   60    8 :
slabdata      0      0      0
kioctx                 0      0    256   15    1 : tunables  120   60    8 :
slabdata      0      0      0
kiocb                  0      0    128   31    1 : tunables  120   60    8 :
slabdata      0      0      0
dnotify_cache          1    185     20  185    1 : tunables  120   60    8 :
slabdata      1      1      0
fasync_cache          33    678     16  226    1 : tunables  120   60    8 :
slabdata      3      3      0
shmem_inode_cache    278    297    444    9    1 : tunables   54   27    8 :
slabdata     33     33      0
posix_timers_cache      0      0    112   35    1 : tunables  120   60    8 :
slabdata      0      0      0
uid_cache             29    122     64   61    1 : tunables  120   60    8 :
slabdata      2      2      0
cfq_pool             100    238     32  119    1 : tunables  120   60    8 :
slabdata      2      2      0
crq_pool              42    192     40   96    1 : tunables  120   60    8 :
slabdata      2      2      0
deadline_drq           0      0     52   75    1 : tunables  120   60    8 :
slabdata      0      0      0
as_arq                 0      0     64   61    1 : tunables  120   60    8 :
slabdata      0      0      0
blkdev_ioc           177    370     20  185    1 : tunables  120   60    8 :
slabdata      2      2      0
blkdev_queue          24     32    488    8    1 : tunables   54   27    8 :
slabdata      4      4      0
blkdev_requests       38     75    160   25    1 : tunables  120   60    8 :
slabdata      3      3      0
biovec-(256)         256    256   3072    2    2 : tunables   24   12    8 :
slabdata    128    128      0
biovec-128           256    260   1536    5    2 : tunables   24   12    8 :
slabdata     52     52      0
biovec-64            256    260    768    5    1 : tunables   54   27    8 :
slabdata     52     52      0
biovec-16            256    270    256   15    1 : tunables  120   60    8 :
slabdata     18     18      0
biovec-4             256    305     64   61    1 : tunables  120   60    8 :
slabdata      5      5      0
biovec-1             336   3842     16  226    1 : tunables  120   60    8 :
slabdata     17     17      0
bio                  343    651    128   31    1 : tunables  120   60    8 :
slabdata     21     21      0
file_lock_cache      175    492     96   41    1 : tunables  120   60    8 :
slabdata     12     12      0
sock_inode_cache     140    259    512    7    1 : tunables   54   27    8 :
slabdata     37     37      0
skbuff_head_cache    553    735    256   15    1 : tunables  120   60    8 :
slabdata     49     49      0
sock                   8     20    384   10    1 : tunables   54   27    8 :
slabdata      2      2      0
proc_inode_cache     377   2398    360   11    1 : tunables   54   27    8 :
slabdata    218    218      0
sigqueue              22     27    148   27    1 : tunables  120   60    8 :
slabdata      1      1      0
radix_tree_node    10728  18648    276   14    1 : tunables   54   27    8 :
slabdata   1332   1332      0
bdev_cache            12     14    512    7    1 : tunables   54   27    8 :
slabdata      2      2      0
mnt_cache             26     31    128   31    1 : tunables  120   60    8 :
slabdata      1      1      0
inode_cache         2167   2167    344   11    1 : tunables   54   27    8 :
slabdata    197    197      0
dentry_cache      451644 451646    152   26    1 : tunables  120   60    8 :
slabdata  17371  17371      0
filp                2595   3585    256   15    1 : tunables  120   60    8 :
slabdata    239    239      0
names_cache            6      6   4096    1    1 : tunables   24   12    8 :
slabdata      6      6      0
avc_node              12    600     52   75    1 : tunables  120   60    8 :
slabdata      8      8      0
idr_layer_cache       83     87    136   29    1 : tunables  120   60    8 :
slabdata      3      3      0
buffer_head        64136  64200     52   75    1 : tunables  120   60    8 :
slabdata    856    856      0
mm_struct            202    220    768    5    1 : tunables   54   27    8 :
slabdata     44     44      0
vm_area_struct      7801  11070     88   45    1 : tunables  120   60    8 :
slabdata    246    246      0
fs_cache             186    366     64   61    1 : tunables  120   60    8 :
slabdata      6      6      0
files_cache          187    224    512    7    1 : tunables   54   27    8 :
slabdata     32     32      0
signal_cache         214    341    128   31    1 : tunables  120   60    8 :
slabdata     11     11      0
sighand_cache        207    225   1408    5    2 : tunables   24   12    8 :
slabdata     45     45      0
task_struct          216    245   1408    5    2 : tunables   24   12    8 :
slabdata     49     49      0
anon_vma            1875   3164     16  226    1 : tunables  120   60    8 :
slabdata     14     14      0
pgd                  202    476     32  119    1 : tunables  120   60    8 :
slabdata      4      4      0
pmd                  516    516   4096    1    1 : tunables   24   12    8 :
slabdata    516    516      0
size-131072(DMA)       0      0 131072    1   32 : tunables    8    4    0 :
slabdata      0      0      0
size-131072            0      0 131072    1   32 : tunables    8    4    0 :
slabdata      0      0      0
size-65536(DMA)        0      0  65536    1   16 : tunables    8    4    0 :
slabdata      0      0      0
size-65536             1      1  65536    1   16 : tunables    8    4    0 :
slabdata      1      1      0
size-32768(DMA)        0      0  32768    1    8 : tunables    8    4    0 :
slabdata      0      0      0
size-32768             2      2  32768    1    8 : tunables    8    4    0 :
slabdata      2      2      0
size-16384(DMA)        0      0  16384    1    4 : tunables    8    4    0 :
slabdata      0      0      0
size-16384             2      2  16384    1    4 : tunables    8    4    0 :
slabdata      2      2      0
size-8192(DMA)         0      0   8192    1    2 : tunables    8    4    0 :
slabdata      0      0      0
size-8192             10     12   8192    1    2 : tunables    8    4    0 :
slabdata     10     12      0
size-4096(DMA)         0      0   4096    1    1 : tunables   24   12    8 :
slabdata      0      0      0
size-4096            824    824   4096    1    1 : tunables   24   12    8 :
slabdata    824    824      0
size-2048(DMA)         0      0   2048    2    1 : tunables   24   12    8 :
slabdata      0      0      0
size-2048             90     90   2048    2    1 : tunables   24   12    8 :
slabdata     45     45      0
size-1620(DMA)         0      0   1664    4    2 : tunables   24   12    8 :
slabdata      0      0      0
size-1620             90     92   1664    4    2 : tunables   24   12    8 :
slabdata     23     23      0
size-1024(DMA)         0      0   1024    4    1 : tunables   54   27    8 :
slabdata      0      0      0
size-1024            274    292   1024    4    1 : tunables   54   27    8 :
slabdata     73     73      0
size-512(DMA)          0      0    512    8    1 : tunables   54   27    8 :
slabdata      0      0      0
size-512             303   1112    512    8    1 : tunables   54   27    8 :
slabdata    139    139      0
size-256(DMA)          0      0    256   15    1 : tunables  120   60    8 :
slabdata      0      0      0
size-256             348    870    256   15    1 : tunables  120   60    8 :
slabdata     58     58      0
size-128(DMA)          0      0    128   31    1 : tunables  120   60    8 :
slabdata      0      0      0
size-128            1973   2232    128   31    1 : tunables  120   60    8 :
slabdata     72     72      0
size-64(DMA)           0      0     64   61    1 : tunables  120   60    8 :
slabdata      0      0      0
size-64            80376  80520     64   61    1 : tunables  120   60    8 :
slabdata   1320   1320      0
size-32(DMA)           0      0     32  119    1 : tunables  120   60    8 :
slabdata      0      0      0
size-32             3193   3808     32  119    1 : tunables  120   60    8 :
slabdata     32     32      0
kmem_cache           135    135    256   15    1 : tunables  120   60    8 :
slabdata      9      9      0
[root@server flexbackup]#


Actual results:

See above - reads of the device file fail, with ENOMEM return status.

Expected results:

Reads of the device file should succeed, returning the data read.

Additional info:

The reason I'm investigating this is because I'm getting corrupted gzip data
back off tape. I don't know whether I'm seeing corruption during the gzip, write
to tape, read from tape, or gunzip phase, but it's one of the four.

See:
https://sourceforge.net/tracker/index.php?func=detail&aid=1276860&group_id=96750&atid=615772
and
https://sourceforge.net/tracker/?func=detail&atid=615772&aid=1267676&group_id=96750

Kernel BTW was built by CentOS, from RH source.

Comment 1 Charlie Brady 2005-08-31 19:03:34 UTC
I missed this message in syslog:

st0: Failed to read 32768 byte block with 10240 byte transfer.

So the kernel isn't doing any blocking/deblocking for me. OK.

Comment 3 Larry Woodman 2005-10-17 18:54:54 UTC
I dont think we support these kernels: 

>>>"Kernel BTW was built by CentOS, from RH source"

In addition, this is also a fairly old kernel and many fixes have been made to
the memory allocation failure path especially under low memory and heavy IO load
pressure.  If you can reproduce this problem with the official RHEL4-U2 kernel,
please reopen this bug.


Larry Woodman


Comment 4 Charlie Brady 2005-10-17 19:13:51 UTC
> I dont think we support these kernels: 
>
>>>>"Kernel BTW was built by CentOS, from RH source"

I expect the exact same behaviour from RedHat built kernels, but I can't verify
that myself.

> In addition, this is also a fairly old kernel...

??? Fairly old? It was the latest for RHEL4 until less than two weeks ago. :-)

> If you can reproduce this problem with the official RHEL4-U2 kernel,

Would you care to send me one?


Comment 5 Charlie Brady 2005-10-17 19:16:14 UTC
> many fixes have been made to the memory allocation failure path especially
under > low memory and heavy IO load pressure.

I don't see anything in the change log which suggests there are new block
buffers for tape access.