* Log Bug with fio-2.1.14 and Higher Causing fio Jobs to Time Out @ 2015-01-09 16:04 George T Seese 2015-01-12 23:50 ` Jens Axboe 0 siblings, 1 reply; 4+ messages in thread From: George T Seese @ 2015-01-09 16:04 UTC (permalink / raw) To: fio fio team, I've found a bug that results in fio hanging at the end of a workload involving log generation, in this case specific to latency log generation. The bug appears in version 2.1.14, 2.2.4, and possibly others. I have tested these scripts with 2.0.9 and they work. Slightly different scripts work on 2.0.14 as well. Error message and script file are copy-pasted below. The job that times out is not always the same job but, usually at least one does time out, it's worse with more targets. fio: pid=37182, got signal=11 fio: job '/dev/sdc' hasn't exited in 60 seconds, it appears to be stuck. Doing forceful exit of this job. [global] bs=4k runtime=1800 rw=randread ;thread=1 direct=1 ioengine=libaio ;offset=0 ;randommap=1 ;time_based=1 bwavgtime=5000 ;write_lat_log ;stonewall=1 iodepth=1 ;TargetDriveMarker [/dev/sdc] filename=/dev/sdc write_lat_log=sdc [/dev/sdd] filename=/dev/sdd write_lat_log=sdd Thanks, George ^ permalink raw reply [flat|nested] 4+ messages in thread
* Re: Log Bug with fio-2.1.14 and Higher Causing fio Jobs to Time Out 2015-01-09 16:04 Log Bug with fio-2.1.14 and Higher Causing fio Jobs to Time Out George T Seese @ 2015-01-12 23:50 ` Jens Axboe 2015-01-14 2:49 ` Jens Axboe 0 siblings, 1 reply; 4+ messages in thread From: Jens Axboe @ 2015-01-12 23:50 UTC (permalink / raw) To: George T Seese, fio On 01/09/2015 09:04 AM, George T Seese wrote: > fio team, > > I've found a bug that results in fio hanging at the end of a workload > involving log generation, in this case specific to latency log > generation. The bug appears in version 2.1.14, 2.2.4, and possibly > others. I have tested these scripts with 2.0.9 and they work. Slightly > different scripts work on 2.0.14 as well. > > Error message and script file are copy-pasted below. The job that > times out is not always the same job but, usually at least one does > time out, it's worse with more targets. > > fio: pid=37182, got signal=11 > fio: job '/dev/sdc' hasn't exited in 60 seconds, it appears to be > stuck. Doing forceful exit of this job. > > [global] > bs=4k > runtime=1800 > rw=randread > ;thread=1 > direct=1 > ioengine=libaio > ;offset=0 > ;randommap=1 > ;time_based=1 > bwavgtime=5000 > ;write_lat_log > ;stonewall=1 > iodepth=1 > > ;TargetDriveMarker > [/dev/sdc] > filename=/dev/sdc > write_lat_log=sdc > > [/dev/sdd] > filename=/dev/sdd > write_lat_log=sdd Thanks, I'll take a look at this. -- Jens Axboe ^ permalink raw reply [flat|nested] 4+ messages in thread
* Re: Log Bug with fio-2.1.14 and Higher Causing fio Jobs to Time Out 2015-01-12 23:50 ` Jens Axboe @ 2015-01-14 2:49 ` Jens Axboe 2015-01-14 4:02 ` Jens Axboe 0 siblings, 1 reply; 4+ messages in thread From: Jens Axboe @ 2015-01-14 2:49 UTC (permalink / raw) To: George T Seese, fio [-- Attachment #1: Type: text/plain, Size: 1206 bytes --] On 01/12/2015 04:50 PM, Jens Axboe wrote: > On 01/09/2015 09:04 AM, George T Seese wrote: >> fio team, >> >> I've found a bug that results in fio hanging at the end of a workload >> involving log generation, in this case specific to latency log >> generation. The bug appears in version 2.1.14, 2.2.4, and possibly >> others. I have tested these scripts with 2.0.9 and they work. Slightly >> different scripts work on 2.0.14 as well. >> >> Error message and script file are copy-pasted below. The job that >> times out is not always the same job but, usually at least one does >> time out, it's worse with more targets. >> >> fio: pid=37182, got signal=11 >> fio: job '/dev/sdc' hasn't exited in 60 seconds, it appears to be >> stuck. Doing forceful exit of this job. >> >> [global] >> bs=4k >> runtime=1800 >> rw=randread >> ;thread=1 >> direct=1 >> ioengine=libaio >> ;offset=0 >> ;randommap=1 >> ;time_based=1 >> bwavgtime=5000 >> ;write_lat_log >> ;stonewall=1 >> iodepth=1 >> >> ;TargetDriveMarker >> [/dev/sdc] >> filename=/dev/sdc >> write_lat_log=sdc >> >> [/dev/sdd] >> filename=/dev/sdd >> write_lat_log=sdd > > Thanks, I'll take a look at this. Can you try the attached patch? -- Jens Axboe [-- Attachment #2: filelock.patch --] [-- Type: text/x-patch, Size: 4832 bytes --] diff --git a/filelock.c b/filelock.c index 18e8875ed942..678db03be99e 100644 --- a/filelock.c +++ b/filelock.c @@ -20,21 +20,59 @@ struct fio_filelock { struct flist_head list; unsigned int references; }; + +#define MAX_FILELOCKS 128 -static struct flist_head *filelock_list; -static struct fio_mutex *filelock_lock; +struct filelock_data { + struct flist_head list; + struct fio_mutex lock; + + struct fio_filelock ffs[MAX_FILELOCKS]; + struct flist_head free_list; +}; + +static struct filelock_data *fld; + +static void put_filelock(struct fio_filelock *ff) +{ + flist_add(&ff->list, &fld->free_list); +} + +static struct fio_filelock *get_filelock(int trylock) +{ + if (!flist_empty(&fld->free_list)) { + struct fio_filelock *ff; + + ff = flist_first_entry(&fld->free_list, struct fio_filelock, list); + flist_del_init(&ff->list); + return ff; + } + + if (trylock) + return NULL; + + log_err("fio: should wait...\n"); + return NULL; +} int fio_filelock_init(void) { - filelock_list = smalloc(sizeof(*filelock_list)); - if (!filelock_list) - return 1; + int i; - INIT_FLIST_HEAD(filelock_list); - filelock_lock = fio_mutex_init(FIO_MUTEX_UNLOCKED); - if (!filelock_lock) { - sfree(filelock_list); + fld = smalloc(sizeof(*fld)); + if (!fld) return 1; + + INIT_FLIST_HEAD(&fld->list); + INIT_FLIST_HEAD(&fld->free_list); + + __fio_mutex_init(&fld->lock, FIO_MUTEX_UNLOCKED); + + for (i = 0; i < MAX_FILELOCKS; i++) { + struct fio_filelock *ff = &fld->ffs[i]; + + __fio_mutex_init(&ff->lock, FIO_MUTEX_UNLOCKED); + flist_add_tail(&ff->list, &fld->free_list); } return 0; @@ -42,14 +80,23 @@ int fio_filelock_init(void) void fio_filelock_exit(void) { - if (!filelock_list) + if (!fld) return; - assert(flist_empty(filelock_list)); - sfree(filelock_list); - filelock_list = NULL; - fio_mutex_remove(filelock_lock); - filelock_lock = NULL; + assert(flist_empty(&fld->list)); + fio_mutex_remove(&fld->lock); + + while (!flist_empty(&fld->free_list)) { + struct fio_filelock *ff; + + ff = flist_first_entry(&fld->free_list, struct fio_filelock, list); + + flist_del_init(&ff->list); + fio_mutex_remove(&ff->lock); + } + + sfree(fld); + fld = NULL; } static struct fio_filelock *fio_hash_find(uint32_t hash) @@ -57,7 +104,7 @@ static struct fio_filelock *fio_hash_find(uint32_t hash) struct flist_head *entry; struct fio_filelock *ff; - flist_for_each(entry, filelock_list) { + flist_for_each(entry, &fld->list) { ff = flist_entry(entry, struct fio_filelock, list); if (ff->hash == hash) return ff; @@ -72,32 +119,36 @@ static struct fio_filelock *fio_hash_get(uint32_t hash) ff = fio_hash_find(hash); if (!ff) { - ff = smalloc(sizeof(*ff)); + ff = get_filelock(0); ff->hash = hash; - __fio_mutex_init(&ff->lock, FIO_MUTEX_UNLOCKED); ff->references = 0; - flist_add(&ff->list, filelock_list); + flist_add(&ff->list, &fld->list); } return ff; } -int fio_trylock_file(const char *fname) +static int __fio_lock_file(const char *fname, int trylock) { struct fio_filelock *ff; uint32_t hash; hash = jhash(fname, strlen(fname), 0); - fio_mutex_down(filelock_lock); + fio_mutex_down(&fld->lock); ff = fio_hash_get(hash); ff->references++; - fio_mutex_up(filelock_lock); + fio_mutex_up(&fld->lock); + + if (!trylock) { + fio_mutex_down(&ff->lock); + return 0; + } if (!fio_mutex_down_trylock(&ff->lock)) return 0; - fio_mutex_down(filelock_lock); + fio_mutex_down(&fld->lock); /* * If we raced and the only reference to the lock is us, we can @@ -108,7 +159,7 @@ int fio_trylock_file(const char *fname) ff = NULL; } - fio_mutex_up(filelock_lock); + fio_mutex_up(&fld->lock); if (ff) { fio_mutex_down(&ff->lock); @@ -118,19 +169,14 @@ int fio_trylock_file(const char *fname) return 1; } -void fio_lock_file(const char *fname) +int fio_trylock_file(const char *fname) { - struct fio_filelock *ff; - uint32_t hash; - - hash = jhash(fname, strlen(fname), 0); - - fio_mutex_down(filelock_lock); - ff = fio_hash_get(hash); - ff->references++; - fio_mutex_up(filelock_lock); + return __fio_lock_file(fname, 1); +} - fio_mutex_down(&ff->lock); +void fio_lock_file(const char *fname) +{ + __fio_lock_file(fname, 0); } void fio_unlock_file(const char *fname) @@ -140,19 +186,18 @@ void fio_unlock_file(const char *fname) hash = jhash(fname, strlen(fname), 0); - fio_mutex_down(filelock_lock); + fio_mutex_down(&fld->lock); ff = fio_hash_find(hash); if (ff) { int refs = --ff->references; fio_mutex_up(&ff->lock); if (!refs) { - flist_del(&ff->list); - __fio_mutex_remove(&ff->lock); - sfree(ff); + flist_del_init(&ff->list); + put_filelock(ff); } } else log_err("fio: file not found for unlocking\n"); - fio_mutex_up(filelock_lock); + fio_mutex_up(&fld->lock); } ^ permalink raw reply related [flat|nested] 4+ messages in thread
* Re: Log Bug with fio-2.1.14 and Higher Causing fio Jobs to Time Out 2015-01-14 2:49 ` Jens Axboe @ 2015-01-14 4:02 ` Jens Axboe 0 siblings, 0 replies; 4+ messages in thread From: Jens Axboe @ 2015-01-14 4:02 UTC (permalink / raw) To: George T Seese, fio [-- Attachment #1: Type: text/plain, Size: 1439 bytes --] On 01/13/2015 07:49 PM, Jens Axboe wrote: > On 01/12/2015 04:50 PM, Jens Axboe wrote: >> On 01/09/2015 09:04 AM, George T Seese wrote: >>> fio team, >>> >>> I've found a bug that results in fio hanging at the end of a workload >>> involving log generation, in this case specific to latency log >>> generation. The bug appears in version 2.1.14, 2.2.4, and possibly >>> others. I have tested these scripts with 2.0.9 and they work. Slightly >>> different scripts work on 2.0.14 as well. >>> >>> Error message and script file are copy-pasted below. The job that >>> times out is not always the same job but, usually at least one does >>> time out, it's worse with more targets. >>> >>> fio: pid=37182, got signal=11 >>> fio: job '/dev/sdc' hasn't exited in 60 seconds, it appears to be >>> stuck. Doing forceful exit of this job. >>> >>> [global] >>> bs=4k >>> runtime=1800 >>> rw=randread >>> ;thread=1 >>> direct=1 >>> ioengine=libaio >>> ;offset=0 >>> ;randommap=1 >>> ;time_based=1 >>> bwavgtime=5000 >>> ;write_lat_log >>> ;stonewall=1 >>> iodepth=1 >>> >>> ;TargetDriveMarker >>> [/dev/sdc] >>> filename=/dev/sdc >>> write_lat_log=sdc >>> >>> [/dev/sdd] >>> filename=/dev/sdd >>> write_lat_log=sdd >> >> Thanks, I'll take a look at this. > > Can you try the attached patch? This one should be more complete (though the first one should also work for you, but try this one instead if you haven't used the first one). -- Jens Axboe [-- Attachment #2: filelock-v2.patch --] [-- Type: text/x-patch, Size: 5874 bytes --] diff --git a/filelock.c b/filelock.c index 18e8875ed942..544196daba04 100644 --- a/filelock.c +++ b/filelock.c @@ -5,6 +5,7 @@ */ #include <inttypes.h> #include <string.h> +#include <unistd.h> #include <assert.h> #include "flist.h" @@ -20,36 +21,101 @@ struct fio_filelock { struct flist_head list; unsigned int references; }; + +#define MAX_FILELOCKS 128 -static struct flist_head *filelock_list; -static struct fio_mutex *filelock_lock; +struct filelock_data { + struct flist_head list; + struct fio_mutex lock; + + struct fio_filelock ffs[MAX_FILELOCKS]; + struct flist_head free_list; +}; + +static struct filelock_data *fld; + +static void put_filelock(struct fio_filelock *ff) +{ + flist_add(&ff->list, &fld->free_list); +} + +static struct fio_filelock *__get_filelock(void) +{ + struct fio_filelock *ff; + + if (flist_empty(&fld->free_list)) + return NULL; + + ff = flist_first_entry(&fld->free_list, struct fio_filelock, list); + flist_del_init(&ff->list); + return ff; +} + +static struct fio_filelock *get_filelock(int trylock, int *retry) +{ + struct fio_filelock *ff; + + do { + ff = __get_filelock(); + if (ff || trylock) + break; + + fio_mutex_up(&fld->lock); + usleep(1000); + fio_mutex_down(&fld->lock); + *retry = 1; + } while (1); + + return ff; +} int fio_filelock_init(void) { - filelock_list = smalloc(sizeof(*filelock_list)); - if (!filelock_list) - return 1; + int i; - INIT_FLIST_HEAD(filelock_list); - filelock_lock = fio_mutex_init(FIO_MUTEX_UNLOCKED); - if (!filelock_lock) { - sfree(filelock_list); + fld = smalloc(sizeof(*fld)); + if (!fld) return 1; + + INIT_FLIST_HEAD(&fld->list); + INIT_FLIST_HEAD(&fld->free_list); + + if (__fio_mutex_init(&fld->lock, FIO_MUTEX_UNLOCKED)) + goto err; + + for (i = 0; i < MAX_FILELOCKS; i++) { + struct fio_filelock *ff = &fld->ffs[i]; + + if (__fio_mutex_init(&ff->lock, FIO_MUTEX_UNLOCKED)) + goto err; + flist_add_tail(&ff->list, &fld->free_list); } return 0; +err: + fio_filelock_exit(); + return 1; } void fio_filelock_exit(void) { - if (!filelock_list) + if (!fld) return; - assert(flist_empty(filelock_list)); - sfree(filelock_list); - filelock_list = NULL; - fio_mutex_remove(filelock_lock); - filelock_lock = NULL; + assert(flist_empty(&fld->list)); + fio_mutex_remove(&fld->lock); + + while (!flist_empty(&fld->free_list)) { + struct fio_filelock *ff; + + ff = flist_first_entry(&fld->free_list, struct fio_filelock, list); + + flist_del_init(&ff->list); + fio_mutex_remove(&ff->lock); + } + + sfree(fld); + fld = NULL; } static struct fio_filelock *fio_hash_find(uint32_t hash) @@ -57,7 +123,7 @@ static struct fio_filelock *fio_hash_find(uint32_t hash) struct flist_head *entry; struct fio_filelock *ff; - flist_for_each(entry, filelock_list) { + flist_for_each(entry, &fld->list) { ff = flist_entry(entry, struct fio_filelock, list); if (ff->hash == hash) return ff; @@ -66,38 +132,68 @@ static struct fio_filelock *fio_hash_find(uint32_t hash) return NULL; } -static struct fio_filelock *fio_hash_get(uint32_t hash) +static struct fio_filelock *fio_hash_get(uint32_t hash, int trylock) { struct fio_filelock *ff; ff = fio_hash_find(hash); if (!ff) { - ff = smalloc(sizeof(*ff)); + int retry = 0; + + ff = get_filelock(trylock, &retry); + if (!ff) + return NULL; + + /* + * If we dropped the main lock, re-lookup the hash in case + * someone else added it meanwhile. If it's now there, + * just return that. + */ + if (retry) { + struct fio_filelock *__ff; + + __ff = fio_hash_find(hash); + if (__ff) { + put_filelock(ff); + return __ff; + } + } + ff->hash = hash; - __fio_mutex_init(&ff->lock, FIO_MUTEX_UNLOCKED); ff->references = 0; - flist_add(&ff->list, filelock_list); + flist_add(&ff->list, &fld->list); } return ff; } -int fio_trylock_file(const char *fname) +static int __fio_lock_file(const char *fname, int trylock) { struct fio_filelock *ff; uint32_t hash; hash = jhash(fname, strlen(fname), 0); - fio_mutex_down(filelock_lock); - ff = fio_hash_get(hash); - ff->references++; - fio_mutex_up(filelock_lock); + fio_mutex_down(&fld->lock); + ff = fio_hash_get(hash, trylock); + if (ff) + ff->references++; + fio_mutex_up(&fld->lock); + + if (!ff) { + assert(!trylock); + return 1; + } + + if (!trylock) { + fio_mutex_down(&ff->lock); + return 0; + } if (!fio_mutex_down_trylock(&ff->lock)) return 0; - fio_mutex_down(filelock_lock); + fio_mutex_down(&fld->lock); /* * If we raced and the only reference to the lock is us, we can @@ -108,7 +204,7 @@ int fio_trylock_file(const char *fname) ff = NULL; } - fio_mutex_up(filelock_lock); + fio_mutex_up(&fld->lock); if (ff) { fio_mutex_down(&ff->lock); @@ -118,19 +214,14 @@ int fio_trylock_file(const char *fname) return 1; } -void fio_lock_file(const char *fname) +int fio_trylock_file(const char *fname) { - struct fio_filelock *ff; - uint32_t hash; - - hash = jhash(fname, strlen(fname), 0); - - fio_mutex_down(filelock_lock); - ff = fio_hash_get(hash); - ff->references++; - fio_mutex_up(filelock_lock); + return __fio_lock_file(fname, 1); +} - fio_mutex_down(&ff->lock); +void fio_lock_file(const char *fname) +{ + __fio_lock_file(fname, 0); } void fio_unlock_file(const char *fname) @@ -140,19 +231,18 @@ void fio_unlock_file(const char *fname) hash = jhash(fname, strlen(fname), 0); - fio_mutex_down(filelock_lock); + fio_mutex_down(&fld->lock); ff = fio_hash_find(hash); if (ff) { int refs = --ff->references; fio_mutex_up(&ff->lock); if (!refs) { - flist_del(&ff->list); - __fio_mutex_remove(&ff->lock); - sfree(ff); + flist_del_init(&ff->list); + put_filelock(ff); } } else log_err("fio: file not found for unlocking\n"); - fio_mutex_up(filelock_lock); + fio_mutex_up(&fld->lock); } ^ permalink raw reply related [flat|nested] 4+ messages in thread
end of thread, other threads:[~2015-01-14 4:02 UTC | newest] Thread overview: 4+ messages (download: mbox.gz follow: Atom feed -- links below jump to the message on this page -- 2015-01-09 16:04 Log Bug with fio-2.1.14 and Higher Causing fio Jobs to Time Out George T Seese 2015-01-12 23:50 ` Jens Axboe 2015-01-14 2:49 ` Jens Axboe 2015-01-14 4:02 ` Jens Axboe
This is a public inbox, see mirroring instructions for how to clone and mirror all data and code used for this inbox