Bug 675299

Summary: 'tail -f' waits forever for inotify
Product: Red Hat Enterprise Linux 6 Reporter: Eduardo Habkost <ehabkost>
Component: kernelAssignee: Eric Paris <eparis>
Status: CLOSED ERRATA QA Contact: Red Hat Kernel QE team <kernel-qe>
Severity: unspecified Docs Contact:
Priority: unspecified    
Version: 6.1CC: arozansk, eparis, tburke
Target Milestone: rc   
Target Release: ---   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: 675299 Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2011-05-19 12:43:11 UTC Type: ---
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Bug Depends On:    
Bug Blocks: 676037    
Attachments:
Description Flags
strace of script under 2.6.32-112.el6.x86_64
none
strace of script under 2.6.32-108.el6.x86_64 (working)
none
strace of script under 2.6.32-109.el6.x86_64 (broken) none

Description Eduardo Habkost 2011-02-04 20:10:47 UTC
Description of problem:
when running 'tail -f' on some scenarios, it is failing to show new contents on files.

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

2.6.32-112.el6.x86_64

How reproducible:
Always.



Steps to Reproduce:
Run the following script:
----------------
#!/bin/bash
f=/tmp/tail-test
echo file: $f
echo ok > "$f"
sleep 1
tail -f "$f" &
sleep 1
echo ok2 > "$f"
wait
------------------


Actual results:
tail shows "ok"


Expected results:
tail shows "ok" and "ok2" lines.


Additional info:
strace output:


[pid 30838] inotify_init()              = 4
[pid 30838] inotify_add_watch(4, "/tmp/tail-test", IN_MODIFY|IN_ATTRIB|IN_DELETE_SELF|IN_MOVE_SELF) = 1
[pid 30838] fstat(3, {st_mode=S_IFREG|0644, st_size=3, ...}) = 0
[pid 30838] read(4,  <unfinished ...>
[pid 30839] <... nanosleep resumed> NULL) = 0
[pid 30839] close(1)                    = 0
[pid 30839] close(2)                    = 0
[pid 30839] exit_group(0)               = ?
Process 30835 resumed
Process 30839 detached
[pid 30835] <... wait4 resumed> [{WIFEXITED(s) && WEXITSTATUS(s) == 0}], 0, NULL) = 30839
[pid 30835] rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
[pid 30835] --- SIGCHLD (Child exited) @ 0 (0) ---
[pid 30835] wait4(-1, 0x7fff9ffbc25c, WNOHANG, NULL) = 0
[pid 30835] rt_sigreturn(0xffffffffffffffff) = 0
[pid 30835] rt_sigaction(SIGINT, {SIG_DFL, [], SA_RESTORER, 0x3bb2e32a20}, {0x43d220, [], SA_RESTORER, 0x3bb2e32a20}, 8) = 0
[pid 30835] rt_sigprocmask(SIG_BLOCK, NULL, [], 8) = 0
[pid 30835] read(255, "echo ok2 > \"$f\"\nwait\n", 110) = 21
[pid 30835] write(2, "+ echo ok2\n", 11+ echo ok2
) = 11
[pid 30835] open("/tmp/tail-test", O_WRONLY|O_CREAT|O_TRUNC, 0666) = 3
[pid 30835] fcntl(1, F_GETFD)           = 0
[pid 30835] fcntl(1, F_DUPFD, 10)       = 10
[pid 30835] fcntl(1, F_GETFD)           = 0
[pid 30835] fcntl(10, F_SETFD, FD_CLOEXEC) = 0
[pid 30835] dup2(3, 1)                  = 1
[pid 30835] close(3)                    = 0
[pid 30835] write(1, "ok2\n", 4)        = 4
[pid 30835] dup2(10, 1)                 = 1
[pid 30835] fcntl(10, F_GETFD)          = 0x1 (flags FD_CLOEXEC)
[pid 30835] close(10)                   = 0
[pid 30835] rt_sigprocmask(SIG_BLOCK, NULL, [], 8) = 0
[pid 30835] write(2, "+ wait\n", 7+ wait

Comment 1 Eduardo Habkost 2011-02-04 20:16:02 UTC
oops, my sample script is wrong (it was supposed to use ">""). I'll send a better one in a few moments.

Comment 2 Eduardo Habkost 2011-02-04 20:19:50 UTC
Created attachment 477106 [details]
strace of script under 2.6.32-112.el6.x86_64

Updated script:
------------------
#!/bin/bash
f=/tmp/tail-test
echo file: $f
echo ok > "$f"
sleep 1
tail -f "$f" &
sleep 1
echo ok2 >> "$f"
wait
----------------

Updated strace output attached.

Comment 3 Eduardo Habkost 2011-02-04 20:22:38 UTC
Created attachment 477108 [details]
strace of script under 2.6.32-108.el6.x86_64 (working)

2.6.32-108.el6.x86_64 seems to be working. strace attached.

Comment 4 Eduardo Habkost 2011-02-04 20:33:13 UTC
Created attachment 477113 [details]
strace of script under 2.6.32-109.el6.x86_64 (broken)

Reproduced under 2.6.32-109.el6.x86_64.

Comment 5 Dor Laor 2011-02-09 11:52:08 UTC
This kernel bug breaks kvm autotest which is our main QA tool. It's a blocker from our POV.

Comment 6 Eric Paris 2011-02-09 18:50:13 UTC
This was caused by my broken fix for BZ 582109.  I have requested that the patch applied be reverted.  I'm going to put this bug into the 'POST' state as a request to fix has been posted to the internal list.

Comment 9 RHEL Program Management 2011-02-21 20:20:21 UTC
This request was evaluated by Red Hat Product Management for inclusion
in a Red Hat Enterprise Linux maintenance release. Product Management has 
requested further review of this request by Red Hat Engineering, for potential
inclusion in a Red Hat Enterprise Linux Update release for currently deployed 
products. This request is not yet committed for inclusion in an Update release.

Comment 11 Mike Gahagan 2011-02-22 16:13:33 UTC
reproduced on -115, confirmed it's fixed on -117.

Comment 12 errata-xmlrpc 2011-05-19 12:43:11 UTC
An advisory has been issued which should help the problem
described in this bug report. This report is therefore being
closed with a resolution of ERRATA. For more information
on therefore solution and/or where to find the updated files,
please follow the link below. You may reopen this bug report
if the solution does not work for you.

http://rhn.redhat.com/errata/RHSA-2011-0542.html