{"action":"created","issue":{"url":"https://api.github.com/repos/zfsonlinux/zfs/issues/4306","repository_url":"https://api.github.com/repos/zfsonlinux/zfs","labels_url":"https://api.github.com/repos/zfsonlinux/zfs/issues/4306/labels{/name}","comments_url":"https://api.github.com/repos/zfsonlinux/zfs/issues/4306/comments","events_url":"https://api.github.com/repos/zfsonlinux/zfs/issues/4306/events","html_url":"https://github.com/zfsonlinux/zfs/issues/4306","id":131314101,"number":4306,"title":"lseek(..., ..., SEEK_HOLE) extremely slow under heavy I/O load.","user":{"login":"bucko909","id":7436550,"avatar_url":"https://avatars.githubusercontent.com/u/7436550?v=3","gravatar_id":"","url":"https://api.github.com/users/bucko909","html_url":"https://github.com/bucko909","followers_url":"https://api.github.com/users/bucko909/followers","following_url":"https://api.github.com/users/bucko909/following{/other_user}","gists_url":"https://api.github.com/users/bucko909/gists{/gist_id}","starred_url":"https://api.github.com/users/bucko909/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/bucko909/subscriptions","organizations_url":"https://api.github.com/users/bucko909/orgs","repos_url":"https://api.github.com/users/bucko909/repos","events_url":"https://api.github.com/users/bucko909/events{/privacy}","received_events_url":"https://api.github.com/users/bucko909/received_events","type":"User","site_admin":false},"labels":[{"url":"https://api.github.com/repos/zfsonlinux/zfs/labels/Performance","name":"Performance","color":"DDDDDD"}],"state":"open","locked":false,"assignee":null,"milestone":null,"comments":1,"created_at":"2016-02-04T11:06:14Z","updated_at":"2016-02-04T23:01:51Z","closed_at":null,"body":"I've been experiencing random hangs in syscalls (ie. cannot even `^C` the process) when running `grep` and `less` on our log server which runs on (`gzip` compressed) ZFS. It appears to be correlated with high load averages possibly as a result of compression jobs, and I've mostly (only?) observed it on files which are actively being appended. I've been able to reproduce 7 second delays running these tools in testing during heavy load, and I've *experienced* delays in the minutes. I have no proof that the longer delays are due to the same, but it seems likely.\r\n\r\nI can't guarantee that the long and short delays are the same problem, but I have observed via `strace` that the hangs are in `lseek` with a `whence` of `SEEK_HOLE`. I confirmed this with a simple C program which just opened my file and ran `lseek(fd, 32768, SEEK_HOLE);` -- which was the exact syscall `grep` hung on.\r\n\r\nMore evidence is that `SEEK_HOLE` isn't used in cat, which means that `cat FILE | grep SEARCH` is much faster than `grep SEARCH FILE`. When the server was busy enough to reproduce this yesterday, I recorded ~7s to `grep` an 80MB file, and 0.1s to `cat | grep`.\r\n\r\nFor now I've instigated a workaround which is an `LD_PRELOAD` library which rewrites `lseek(fd, offset, SEEK_HOLE)` to `lseek(fd, 0, SEEK_END)` -- I've not been able to reproduce these delays with the library loaded.\r\n\r\nLooking at the source, I see that `SEEK_HOLE` and `SEEK_DATA` ultimately end up here:\r\n\r\nhttps://github.com/zfsonlinux/zfs/blob/19d55079aecb5c022c1c09e0eace4f7da7381a62/module/zfs/dmu.c#L1812\r\n\r\nWhich does `txg_wait_synced` if the file has dirty data. I've observed `sync` take 15 minutes on this server when it's under heavy load, so that would probably explain the delay. Is there any way around this beyond my stupid `LD_PRELOAD` hack?"},"comment":{"url":"https://api.github.com/repos/zfsonlinux/zfs/issues/comments/180094044","html_url":"https://github.com/zfsonlinux/zfs/issues/4306#issuecomment-180094044","issue_url":"https://api.github.com/repos/zfsonlinux/zfs/issues/4306","id":180094044,"user":{"login":"behlendorf","id":148917,"avatar_url":"https://avatars.githubusercontent.com/u/148917?v=3","gravatar_id":"","url":"https://api.github.com/users/behlendorf","html_url":"https://github.com/behlendorf","followers_url":"https://api.github.com/users/behlendorf/followers","following_url":"https://api.github.com/users/behlendorf/following{/other_user}","gists_url":"https://api.github.com/users/behlendorf/gists{/gist_id}","starred_url":"https://api.github.com/users/behlendorf/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/behlendorf/subscriptions","organizations_url":"https://api.github.com/users/behlendorf/orgs","repos_url":"https://api.github.com/users/behlendorf/repos","events_url":"https://api.github.com/users/behlendorf/events{/privacy}","received_events_url":"https://api.github.com/users/behlendorf/received_events","type":"User","site_admin":false},"created_at":"2016-02-04T23:01:51Z","updated_at":"2016-02-04T23:01:51Z","body":"@bucko909 you've definitely put your finger on an issue.  In order for SEEK_HOLE to authoritatively return the next on-disk hole it needs to make sure that all dirty blocks for that file are on-disk.  Where those blocks end up getting written, or even if they get written, isn't determined until the txg they're part of is written.  Which means this function has to block waiting for that txg to be sync'd when a process is appending to the file.\r\n\r\nThere's probably room for some additional optimization here but it'll take some work.  One  thing you might try in your test application, and I'm not sure this will work, is to `fsync()` the file before calling `lseek()`.\r\n\r\n\r\n\r\n"}}