From mboxrd@z Thu Jan 1 00:00:00 1970 From: Kay Sievers Date: Wed, 06 Oct 2004 12:00:46 +0000 Subject: Re: Hanging udev process on nfs-mounted /dev Message-Id: <20041006120046.GA9768@vrfy.org> MIME-Version: 1 Content-Type: multipart/mixed; boundary="k1lZvvs/B4yU6o8G" List-Id: References: <415980BF.1020401@bio.ifi.lmu.de> In-Reply-To: <415980BF.1020401@bio.ifi.lmu.de> To: linux-hotplug@vger.kernel.org --k1lZvvs/B4yU6o8G Content-Type: text/plain; charset=us-ascii Content-Disposition: inline On Wed, Oct 06, 2004 at 08:06:29AM +0200, Frank Steiner wrote: > Frank Steiner wrote > > >Kay Sievers wrote > > > > > >>All here known failure paths are now covered in the attached patch by > >>limiting the iteration count for loops over data read from disk. Let's > >>see what happens next :) > > > > > >Ok :-) I'm running this patch in parallel on hosts using tmpfs for /dev > >as well as "old" ones still using NFS. I will report success or failures! > > Well, we are not done yet :-) Another udev hanging with 100% CPU, with > the latest deadlock patch applied. Here's the trace (I removed the "(gdb) s" > lines): Funny, this is not inside the tdb, it's caused by getting garbage from the udev database. You don't use {all_partitions}, right? I expect, that the payload-data from the tdb is corrupt and the record claims, that the udev_add has added > 2.000.000 partition-nodes for the device :) You should have something like this in the syslog: "removing partitions 'sg2[1-24532432]'" Here is a patch for it. It's against the current tree after our patch session yesterday. But it should successfully apply to your tree with offsets. Thanks, Kay --k1lZvvs/B4yU6o8G Content-Type: text/plain; charset=us-ascii Content-Disposition: inline; filename="udev-deadlock-debug-04.patch" ===== namedev.c 1.147 vs edited ===== --- 1.147/namedev.c 2004-09-20 16:01:58 +02:00 +++ edited/namedev.c 2004-10-06 13:09:20 +02:00 @@ -29,7 +29,6 @@ #include #include #include -#include #include #include #include @@ -353,7 +352,6 @@ static struct bus_file { {} }; -#define SECONDS_TO_WAIT_FOR_FILE 10 static void wait_for_device_to_initialize(struct sysfs_device *sysfs_device) { /* sleep until we see the file for this specific bus type show up this @@ -367,14 +365,14 @@ static void wait_for_device_to_initializ struct bus_file *b = &bus_files[0]; struct sysfs_attribute *tmpattr; int found = 0; - int loop = SECONDS_TO_WAIT_FOR_FILE; + int loop = WAIT_FOR_FILE_SECONDS * WAIT_FOR_FILE_RETRY_FREQ; while (1) { if (b->bus == NULL) { if (!found) break; - /* sleep to give the kernel a chance to create the file */ - sleep(1); + /* give the kernel a chance to create the file */ + usleep(1000 * 1000 / WAIT_FOR_FILE_RETRY_FREQ); --loop; if (loop == 0) break; @@ -394,7 +392,8 @@ static void wait_for_device_to_initializ } if (!found) dbg("did not find bus type '%s' on list of bus_id_files, " - "contact greg@kroah.com", sysfs_device->bus); + "please report to ", + sysfs_device->bus); exit: return; /* here to prevent compiler warning... */ } @@ -680,7 +679,6 @@ static struct sysfs_device *get_sysfs_de { struct sysfs_device *sysfs_device; struct sysfs_class_device *class_dev_parent; - struct timespec tspec; int loop; /* Figure out where the device symlink is at. For char devices this will @@ -696,16 +694,14 @@ static struct sysfs_device *get_sysfs_de if (class_dev_parent != NULL) dbg("given class device has a parent, use this instead"); - tspec.tv_sec = 0; - tspec.tv_nsec = 10000000; /* sleep 10 millisec */ - loop = 10; + loop = WAIT_FOR_FILE_SECONDS * WAIT_FOR_FILE_RETRY_FREQ; while (loop--) { if (udev_sleep) { if (whitelist_search(class_dev)) { sysfs_device = NULL; goto exit; } - nanosleep(&tspec, NULL); + usleep(1000 * 1000 / WAIT_FOR_FILE_RETRY_FREQ); } if (class_dev_parent) @@ -727,11 +723,9 @@ device_found: if (sysfs_device->bus[0] != '\0') goto bus_found; - loop = 10; - tspec.tv_nsec = 10000000; while (loop--) { if (udev_sleep) - nanosleep(&tspec, NULL); + usleep(1000 * 1000 / WAIT_FOR_FILE_RETRY_FREQ); sysfs_get_device_bus(sysfs_device); if (sysfs_device->bus[0] != '\0') ===== udev-add.c 1.74 vs edited ===== --- 1.74/udev-add.c 2004-10-06 00:22:36 +02:00 +++ edited/udev-add.c 2004-10-06 13:09:20 +02:00 @@ -348,11 +348,10 @@ exit: /* wait for the "dev" file to show up in the directory in sysfs. * If it doesn't happen in about 10 seconds, give up. */ -#define SECONDS_TO_WAIT_FOR_FILE 10 static int sleep_for_file(const char *path, char* file) { char filename[SYSFS_PATH_MAX + 6]; - int loop = SECONDS_TO_WAIT_FOR_FILE; + int loop = WAIT_FOR_FILE_SECONDS * WAIT_FOR_FILE_RETRY_FREQ; int retval; strfieldcpy(filename, sysfs_path); @@ -368,7 +367,7 @@ static int sleep_for_file(const char *pa goto exit; /* sleep to give the kernel a chance to create the dev file */ - sleep(1); + usleep(1000 * 1000 / WAIT_FOR_FILE_RETRY_FREQ); } retval = -ENODEV; exit: ===== udev-remove.c 1.33 vs edited ===== --- 1.33/udev-remove.c 2004-08-05 00:40:11 +02:00 +++ edited/udev-remove.c 2004-10-06 13:24:28 +02:00 @@ -109,6 +109,7 @@ static int delete_node(struct udevice *d int i; char *pos; int len; + int num; strfieldcpy(filename, udev_root); strfieldcat(filename, dev->name); @@ -118,10 +119,15 @@ static int delete_node(struct udevice *d if (retval) return retval; - /* remove partition nodes */ - if (dev->partitions > 0) { - info("removing partitions '%s[1-%i]'", filename, dev->partitions); - for (i = 1; i <= dev->partitions; i++) { + /* remove all_partitions nodes */ + num = dev->partitions; + if (num > 0) { + info("removing all_partitions '%s[1-%i]'", filename, num); + if (num > PARTITIONS_COUNT) { + info("garbage from udev database, skip all_partitions removal"); + return -1; + } + for (i = 1; i <= num; i++) { strfieldcpy(partitionname, filename); strintcat(partitionname, i); secure_unlink(partitionname); ===== udev.c 1.62 vs edited ===== --- 1.62/udev.c 2004-09-14 02:25:32 +02:00 +++ edited/udev.c 2004-10-06 13:09:20 +02:00 @@ -36,6 +36,9 @@ #include "namedev.h" #include "udevdb.h" +/* timeout flag for udevdb */ +extern sig_atomic_t gotalarm; + /* global variables */ char **main_argv; char **main_envp; @@ -58,6 +61,11 @@ void log_message(int level, const char * asmlinkage static void sig_handler(int signum) { switch (signum) { + case SIGALRM: + gotalarm = 1; + info("error: timeout reached, event probably not handled correctly, " + "please report to "); + break; case SIGINT: case SIGTERM: udevdb_exit(); @@ -94,7 +102,8 @@ int main(int argc, char *argv[], char *e dbg("version %s", UDEV_VERSION); - /* initialize our configuration */ + init_logging("udev"); + udev_init_config(); if (strstr(argv[0], "udevstart")) { @@ -147,15 +156,20 @@ int main(int argc, char *argv[], char *e /* set signal handlers */ act.sa_handler = sig_handler; sigemptyset (&act.sa_mask); + + /* alarm should interrupt */ + sigaction(SIGALRM, &act, NULL); + act.sa_flags = SA_RESTART; sigaction(SIGINT, &act, NULL); sigaction(SIGTERM, &act, NULL); + /* trigger timout to interrupt blocking syscalls */ + alarm(ALARM_TIMEOUT); + /* initialize udev database */ - if (udevdb_init(UDEVDB_DEFAULT) != 0) { - dbg("unable to initialize database"); - goto exit; - } + if (udevdb_init(UDEVDB_DEFAULT) != 0) + info("error: unable to initialize database, continuing without database"); switch(act_type) { case UDEVSTART: ===== udev.h 1.62 vs edited ===== --- 1.62/udev.h 2004-09-14 14:29:10 +02:00 +++ edited/udev.h 2004-10-06 13:09:21 +02:00 @@ -26,6 +26,9 @@ #include #include "libsysfs/sysfs/libsysfs.h" +#define ALARM_TIMEOUT 20 +#define WAIT_FOR_FILE_SECONDS 10 +#define WAIT_FOR_FILE_RETRY_FREQ 10 #define COMMENT_CHARACTER '#' #define NAME_SIZE 256 ===== udevdb.c 1.30 vs edited ===== --- 1.30/udevdb.c 2004-06-29 14:51:35 +02:00 +++ edited/udevdb.c 2004-10-06 13:09:21 +02:00 @@ -42,13 +42,28 @@ #include "tdb/tdb.h" static TDB_CONTEXT *udevdb; +sig_atomic_t gotalarm; +static void tdb_log(TDB_CONTEXT *tdb, int level, const char *format, ...) +{ + va_list args; + + if (!udev_log) + return; + + va_start(args, format); + vsyslog(level, format, args); + va_end(args); +} int udevdb_add_dev(const char *path, const struct udevice *dev) { TDB_DATA key, data; char keystr[SYSFS_PATH_MAX]; + if (udevdb == NULL) + return -1; + if ((path == NULL) || (dev == NULL)) return -ENODEV; @@ -68,6 +83,9 @@ int udevdb_get_dev(const char *path, str { TDB_DATA key, data; + if (udevdb == NULL) + return -1; + if (path == NULL) return -ENODEV; @@ -88,6 +106,9 @@ int udevdb_delete_dev(const char *path) TDB_DATA key; char keystr[SYSFS_PATH_MAX]; + if (udevdb == NULL) + return -1; + if (path == NULL) return -EINVAL; @@ -121,7 +142,9 @@ int udevdb_init(int init_flag) if (init_flag != UDEVDB_DEFAULT && init_flag != UDEVDB_INTERNAL) return -EINVAL; - udevdb = tdb_open(udev_db_filename, 0, init_flag, O_RDWR | O_CREAT, 0644); + tdb_set_lock_alarm(&gotalarm); + + udevdb = tdb_open_ex(udev_db_filename, 0, init_flag, O_RDWR | O_CREAT, 0644, tdb_log); if (udevdb == NULL) { if (init_flag == UDEVDB_INTERNAL) dbg("unable to initialize in-memory database"); @@ -137,7 +160,7 @@ int udevdb_init(int init_flag) */ int udevdb_open_ro(void) { - udevdb = tdb_open(udev_db_filename, 0, 0, O_RDONLY, 0); + udevdb = tdb_open_ex(udev_db_filename, 0, 0, O_RDONLY, 0, tdb_log); if (udevdb == NULL) { dbg("unable to open database at '%s'", udev_db_filename); return -EACCES; @@ -159,6 +182,9 @@ static int traverse_callback(TDB_CONTEXT int udevdb_call_foreach(int (*user_record_handler) (char *path, struct udevice *dev)) { int retval = 0; + + if (udevdb == NULL) + return -1; if (user_record_handler == NULL) { dbg("invalid user record handling function"); ===== tdb/tdb.c 1.4 vs edited ===== --- 1.4/tdb/tdb.c 2004-09-20 16:01:58 +02:00 +++ edited/tdb/tdb.c 2004-10-06 13:09:21 +02:00 @@ -617,8 +617,10 @@ int tdb_printfreelist(TDB_CONTEXT *tdb) static int remove_from_freelist(TDB_CONTEXT *tdb, tdb_off off, tdb_off next) { tdb_off last_ptr, i; + int maxloop; /* read in the freelist top */ + maxloop = 100000; last_ptr = FREELIST_TOP; while (ofs_read(tdb, last_ptr, &i) != -1 && i != 0) { if (i == off) { @@ -627,6 +629,12 @@ static int remove_from_freelist(TDB_CONT } /* Follow chain (next offset is at start of record) */ last_ptr = i; + + maxloop--; + if (maxloop == 0) { + TDB_LOG((tdb, 0, "remove_from_freelist: maxloop reached; corrupt database!\n")); + return TDB_ERRCODE(TDB_ERR_CORRUPT, -1); + } } TDB_LOG((tdb, 0,"remove_from_freelist: not on list at off=%d\n", off)); return TDB_ERRCODE(TDB_ERR_CORRUPT, -1); @@ -853,6 +861,7 @@ static tdb_off tdb_allocate(TDB_CONTEXT { tdb_off rec_ptr, last_ptr, newrec_ptr; struct list_struct newrec; + int maxloop; if (tdb_lock(tdb, -1, F_WRLCK) == -1) return 0; @@ -868,6 +877,7 @@ static tdb_off tdb_allocate(TDB_CONTEXT goto fail; /* keep looking until we find a freelist record big enough */ + maxloop = 100000; while (rec_ptr) { if (rec_free_read(tdb, rec_ptr, rec) == -1) goto fail; @@ -919,6 +929,12 @@ static tdb_off tdb_allocate(TDB_CONTEXT /* move to the next record */ last_ptr = rec_ptr; rec_ptr = rec->next; + + maxloop--; + if (maxloop == 0) { + TDB_LOG((tdb, 0, "tdb_allocate: maxloop reached; corrupt database!\n")); + return TDB_ERRCODE(TDB_ERR_CORRUPT, 0); + } } /* we didn't find enough space. See if we can expand the database and if we can then try again */ @@ -981,12 +997,14 @@ static tdb_off tdb_find(TDB_CONTEXT *tdb struct list_struct *r) { tdb_off rec_ptr; - + int maxloop; + /* read in the hash top */ if (ofs_read(tdb, TDB_HASH_TOP(hash), &rec_ptr) == -1) return 0; /* keep looking until we find the right record */ + maxloop = 100000; while (rec_ptr) { if (rec_read(tdb, rec_ptr, r) == -1) return 0; @@ -1006,6 +1024,12 @@ static tdb_off tdb_find(TDB_CONTEXT *tdb SAFE_FREE(k); } rec_ptr = r->next; + + maxloop--; + if (maxloop == 0) { + TDB_LOG((tdb, 0, "tdb_find maxloop reached; corrupt database!\n")); + return TDB_ERRCODE(TDB_ERR_CORRUPT, 0); + } } return TDB_ERRCODE(TDB_ERR_NOEXIST, 0); } @@ -1188,6 +1212,7 @@ static int do_delete(TDB_CONTEXT *tdb, t { tdb_off last_ptr, i; struct list_struct lastrec; + int maxloop; if (tdb->read_only) return -1; @@ -1202,9 +1227,18 @@ static int do_delete(TDB_CONTEXT *tdb, t /* find previous record in hash chain */ if (ofs_read(tdb, TDB_HASH_TOP(rec->full_hash), &i) == -1) return -1; - for (last_ptr = 0; i != rec_ptr; last_ptr = i, i = lastrec.next) + + maxloop = 100000; + for (last_ptr = 0; i != rec_ptr; last_ptr = i, i = lastrec.next) { if (rec_read(tdb, i, &lastrec) == -1) return -1; + + maxloop--; + if (maxloop == 0) { + TDB_LOG((tdb, 0, "(tdb)do_delete: maxloop reached; corrupt database!\n")); + return TDB_ERRCODE(TDB_ERR_CORRUPT, -1); + } + } /* unlink it: next ptr is at start of record. */ if (last_ptr == 0) --k1lZvvs/B4yU6o8G-- ------------------------------------------------------- This SF.net email is sponsored by: IT Product Guide on ITManagersJournal Use IT products in your business? Tell us what you think of them. Give us Your Opinions, Get Free ThinkGeek Gift Certificates! Click to find out more http://productguide.itmanagersjournal.com/guidepromo.tmpl _______________________________________________ Linux-hotplug-devel mailing list http://linux-hotplug.sourceforge.net Linux-hotplug-devel@lists.sourceforge.net https://lists.sourceforge.net/lists/listinfo/linux-hotplug-devel