CacheFiles: Catch an overly long wait for an old active object
[pandora-kernel.git] / fs / cachefiles / namei.c
index 4ce818a..14ac480 100644 (file)
 #include <linux/security.h>
 #include "internal.h"
 
-static int cachefiles_wait_bit(void *flags)
+#define CACHEFILES_KEYBUF_SIZE 512
+
+/*
+ * dump debugging info about an object
+ */
+static noinline
+void __cachefiles_printk_object(struct cachefiles_object *object,
+                               const char *prefix,
+                               u8 *keybuf)
 {
-       schedule();
-       return 0;
+       struct fscache_cookie *cookie;
+       unsigned keylen, loop;
+
+       printk(KERN_ERR "%sobject: OBJ%x\n",
+              prefix, object->fscache.debug_id);
+       printk(KERN_ERR "%sobjstate=%s fl=%lx swfl=%lx ev=%lx[%lx]\n",
+              prefix, fscache_object_states[object->fscache.state],
+              object->fscache.flags, object->fscache.work.flags,
+              object->fscache.events,
+              object->fscache.event_mask & FSCACHE_OBJECT_EVENTS_MASK);
+       printk(KERN_ERR "%sops=%u inp=%u exc=%u\n",
+              prefix, object->fscache.n_ops, object->fscache.n_in_progress,
+              object->fscache.n_exclusive);
+       printk(KERN_ERR "%sparent=%p\n",
+              prefix, object->fscache.parent);
+
+       spin_lock(&object->fscache.lock);
+       cookie = object->fscache.cookie;
+       if (cookie) {
+               printk(KERN_ERR "%scookie=%p [pr=%p nd=%p fl=%lx]\n",
+                      prefix,
+                      object->fscache.cookie,
+                      object->fscache.cookie->parent,
+                      object->fscache.cookie->netfs_data,
+                      object->fscache.cookie->flags);
+               if (keybuf)
+                       keylen = cookie->def->get_key(cookie->netfs_data, keybuf,
+                                                     CACHEFILES_KEYBUF_SIZE);
+               else
+                       keylen = 0;
+       } else {
+               printk(KERN_ERR "%scookie=NULL\n", prefix);
+               keylen = 0;
+       }
+       spin_unlock(&object->fscache.lock);
+
+       if (keylen) {
+               printk(KERN_ERR "%skey=[%u] '", prefix, keylen);
+               for (loop = 0; loop < keylen; loop++)
+                       printk("%02x", keybuf[loop]);
+               printk("'\n");
+       }
+}
+
+/*
+ * dump debugging info about a pair of objects
+ */
+static noinline void cachefiles_printk_object(struct cachefiles_object *object,
+                                             struct cachefiles_object *xobject)
+{
+       u8 *keybuf;
+
+       keybuf = kmalloc(CACHEFILES_KEYBUF_SIZE, GFP_NOIO);
+       if (object)
+               __cachefiles_printk_object(object, "", keybuf);
+       if (xobject)
+               __cachefiles_printk_object(xobject, "x", keybuf);
+       kfree(keybuf);
 }
 
 /*
  * record the fact that an object is now active
  */
-static void cachefiles_mark_object_active(struct cachefiles_cache *cache,
-                                         struct cachefiles_object *object)
+static int cachefiles_mark_object_active(struct cachefiles_cache *cache,
+                                        struct cachefiles_object *object)
 {
        struct cachefiles_object *xobject;
        struct rb_node **_p, *_parent = NULL;
@@ -42,8 +106,11 @@ static void cachefiles_mark_object_active(struct cachefiles_cache *cache,
 try_again:
        write_lock(&cache->active_lock);
 
-       if (test_and_set_bit(CACHEFILES_OBJECT_ACTIVE, &object->flags))
+       if (test_and_set_bit(CACHEFILES_OBJECT_ACTIVE, &object->flags)) {
+               printk(KERN_ERR "CacheFiles: Error: Object already active\n");
+               cachefiles_printk_object(object, NULL);
                BUG();
+       }
 
        dentry = object->dentry;
        _p = &cache->active_nodes.rb_node;
@@ -66,8 +133,8 @@ try_again:
        rb_insert_color(&object->active_node, &cache->active_nodes);
 
        write_unlock(&cache->active_lock);
-       _leave("");
-       return;
+       _leave(" = 0");
+       return 0;
 
        /* an old object from a previous incarnation is hogging the slot - we
         * need to wait for it to be destroyed */
@@ -76,44 +143,70 @@ wait_for_old_object:
                printk(KERN_ERR "\n");
                printk(KERN_ERR "CacheFiles: Error:"
                       " Unexpected object collision\n");
-               printk(KERN_ERR "xobject: OBJ%x\n",
-                      xobject->fscache.debug_id);
-               printk(KERN_ERR "xobjstate=%s\n",
-                      fscache_object_states[xobject->fscache.state]);
-               printk(KERN_ERR "xobjflags=%lx\n", xobject->fscache.flags);
-               printk(KERN_ERR "xobjevent=%lx [%lx]\n",
-                      xobject->fscache.events, xobject->fscache.event_mask);
-               printk(KERN_ERR "xops=%u inp=%u exc=%u\n",
-                      xobject->fscache.n_ops, xobject->fscache.n_in_progress,
-                      xobject->fscache.n_exclusive);
-               printk(KERN_ERR "xcookie=%p [pr=%p nd=%p fl=%lx]\n",
-                      xobject->fscache.cookie,
-                      xobject->fscache.cookie->parent,
-                      xobject->fscache.cookie->netfs_data,
-                      xobject->fscache.cookie->flags);
-               printk(KERN_ERR "xparent=%p\n",
-                      xobject->fscache.parent);
-               printk(KERN_ERR "object: OBJ%x\n",
-                      object->fscache.debug_id);
-               printk(KERN_ERR "cookie=%p [pr=%p nd=%p fl=%lx]\n",
-                      object->fscache.cookie,
-                      object->fscache.cookie->parent,
-                      object->fscache.cookie->netfs_data,
-                      object->fscache.cookie->flags);
-               printk(KERN_ERR "parent=%p\n",
-                      object->fscache.parent);
+               cachefiles_printk_object(object, xobject);
                BUG();
        }
        atomic_inc(&xobject->usage);
        write_unlock(&cache->active_lock);
 
-       _debug(">>> wait");
-       wait_on_bit(&xobject->flags, CACHEFILES_OBJECT_ACTIVE,
-                   cachefiles_wait_bit, TASK_UNINTERRUPTIBLE);
-       _debug("<<< waited");
+       if (test_bit(CACHEFILES_OBJECT_ACTIVE, &xobject->flags)) {
+               wait_queue_head_t *wq;
+
+               signed long timeout = 60 * HZ;
+               wait_queue_t wait;
+               bool requeue;
+
+               /* if the object we're waiting for is queued for processing,
+                * then just put ourselves on the queue behind it */
+               if (slow_work_is_queued(&xobject->fscache.work)) {
+                       _debug("queue OBJ%x behind OBJ%x immediately",
+                              object->fscache.debug_id,
+                              xobject->fscache.debug_id);
+                       goto requeue;
+               }
+
+               /* otherwise we sleep until either the object we're waiting for
+                * is done, or the slow-work facility wants the thread back to
+                * do other work */
+               wq = bit_waitqueue(&xobject->flags, CACHEFILES_OBJECT_ACTIVE);
+               init_wait(&wait);
+               requeue = false;
+               do {
+                       prepare_to_wait(wq, &wait, TASK_UNINTERRUPTIBLE);
+                       if (!test_bit(CACHEFILES_OBJECT_ACTIVE, &xobject->flags))
+                               break;
+                       requeue = slow_work_sleep_till_thread_needed(
+                               &object->fscache.work, &timeout);
+               } while (timeout > 0 && !requeue);
+               finish_wait(wq, &wait);
+
+               if (requeue &&
+                   test_bit(CACHEFILES_OBJECT_ACTIVE, &xobject->flags)) {
+                       _debug("queue OBJ%x behind OBJ%x after wait",
+                              object->fscache.debug_id,
+                              xobject->fscache.debug_id);
+                       goto requeue;
+               }
+
+               if (timeout <= 0) {
+                       printk(KERN_ERR "\n");
+                       printk(KERN_ERR "CacheFiles: Error: Overlong"
+                              " wait for old active object to go away\n");
+                       cachefiles_printk_object(object, xobject);
+                       goto requeue;
+               }
+       }
+
+       ASSERT(!test_bit(CACHEFILES_OBJECT_ACTIVE, &xobject->flags));
 
        cache->cache.ops->put_object(&xobject->fscache);
        goto try_again;
+
+requeue:
+       clear_bit(CACHEFILES_OBJECT_ACTIVE, &object->flags);
+       cache->cache.ops->put_object(&xobject->fscache);
+       _leave(" = -ETIMEDOUT");
+       return -ETIMEDOUT;
 }
 
 /*
@@ -254,7 +347,7 @@ int cachefiles_delete_object(struct cachefiles_cache *cache,
 
        dir = dget_parent(object->dentry);
 
-       mutex_lock(&dir->d_inode->i_mutex);
+       mutex_lock_nested(&dir->d_inode->i_mutex, I_MUTEX_PARENT);
        ret = cachefiles_bury_object(cache, dir, object->dentry);
 
        dput(dir);
@@ -307,7 +400,7 @@ lookup_again:
        /* search the current directory for the element name */
        _debug("lookup '%s'", name);
 
-       mutex_lock(&dir->d_inode->i_mutex);
+       mutex_lock_nested(&dir->d_inode->i_mutex, I_MUTEX_PARENT);
 
        start = jiffies;
        next = lookup_one_len(name, dir, nlen);
@@ -418,12 +511,15 @@ lookup_again:
        }
 
        /* note that we're now using this object */
-       cachefiles_mark_object_active(cache, object);
+       ret = cachefiles_mark_object_active(cache, object);
 
        mutex_unlock(&dir->d_inode->i_mutex);
        dput(dir);
        dir = NULL;
 
+       if (ret == -ETIMEDOUT)
+               goto mark_active_timed_out;
+
        _debug("=== OBTAINED_OBJECT ===");
 
        if (object->new) {
@@ -467,6 +563,10 @@ create_error:
                cachefiles_io_error(cache, "Create/mkdir failed");
        goto error;
 
+mark_active_timed_out:
+       _debug("mark active timed out");
+       goto release_dentry;
+
 check_error:
        _debug("check error %d", ret);
        write_lock(&cache->active_lock);
@@ -474,7 +574,7 @@ check_error:
        clear_bit(CACHEFILES_OBJECT_ACTIVE, &object->flags);
        wake_up_bit(&object->flags, CACHEFILES_OBJECT_ACTIVE);
        write_unlock(&cache->active_lock);
-
+release_dentry:
        dput(object->dentry);
        object->dentry = NULL;
        goto error_out;
@@ -495,9 +595,6 @@ error:
 error_out2:
        dput(dir);
 error_out:
-       if (ret == -ENOSPC)
-               ret = -ENOBUFS;
-
        _leave(" = error %d", -ret);
        return ret;
 }