Tools for checking incorrect usage of locking techniques in k-space

[gmate.amit@gmail.com (Kumar amit mehta)]

On Mon, Oct 29, 2012 at 12:03:08AM +0530, Srivatsa Bhat wrote:
> You'll need CONFIG_LOCKDEP=y as well. An easy way to configure lock debugging
> checks is to run 'make menuconfig' and enable the required options under the
> "Kernel hacking" section.
> 
> >
> > If above configuration is all that I need, then should I be seeing warning/error
> > messages in kernel logs(/var/log/kern.log) when there is inconsistency in
> > locking ? To test my hypothesis, I modified my simple kernel module to
> > deliberately induce locking error (After initializing read-write semaphore, I call
> > down_write() and do not free this semaphore lock by commenting out up_write()
> > invocation). But still I don't see any error or warning message trace in kernel
> > logs, I think, I'm missing something.

Hi Srivatsa,

Thank you for your mail. As per your suggestion, this time I've enabled
CONFIG_LOCKDEP aslo in my running kernel and did the same experiment, but still 
I dont't see any warning/error messages in the kernel log. To give you more idea
about what I'm doing, Please see the code below.(This is a simple char driver
based on LDD3 examples)

<echo.c>

#include <linux/module.h>
#include <linux/init.h>
#include <linux/types.h> //MAJOR, MINOR
#include <linux/fs.h> //register_chrdev_region, file_operations
#include <linux/moduleparam.h>
#include <linux/kernel.h> //container_of
#include <linux/slab.h> //kmalloc
#include <linux/cdev.h> //struct cdev
#include <linux/version.h>
#include <linux/uaccess.h> //copy_from/to_user()
#include <linux/errno.h> //error code

ssize_t echo_read(struct file *, char __user *, size_t, loff_t *);
ssize_t echo_write(struct file *, const char __user *, size_t, loff_t *);
int echo_open(struct inode *, struct file *);
int echo_release(struct inode *, struct file *);

struct echo_cdev {
	char *data;
	unsigned long size; //amount of data stored
	struct semaphore sem;
	struct cdev cdev;
};
MODULE_LICENSE("GPL v2");
MODULE_AUTHOR("amit");

int nr_major;
module_param(nr_major, int, S_IRUGO);
MODULE_PARM_DESC(nr_major, "major number");

int nr_minor;
char *chrdev_name = "echo";

static dev_t device;
static int echo_dev_count = 1;
struct echo_cdev *echo_dev = NULL;

static struct file_operations echo_fs_ops = {
	.open = echo_open,
	.release = echo_release,
	.read = echo_read,
	.write = echo_write,
	.owner = THIS_MODULE,
};

int echo_open(struct inode *inode, struct file *filp)
{
	struct echo_cdev *dev;
	pr_debug("%s: f_flags: 0x%x\n",__FUNCTION__,filp->f_flags);
	//container_of(pointer, container_type, container_field);
	dev = container_of(inode->i_cdev, struct echo_cdev, cdev);
	filp->private_data = dev;
	if ((filp->f_flags & O_ACCMODE) == O_WRONLY) {
		//trim the device size to 0
		dev->size = 0;
	}
	return 0;
}

int echo_release(struct inode *inode, struct file *filp)
{
	return 0;
}

ssize_t echo_read(struct file *filp, char __user *ubuff, size_t count, loff_t *poffset)
{
	struct echo_cdev *dev = filp->private_data;
	pr_debug("%s: f_flags: 0x%x\n",__FUNCTION__,filp->f_flags);
		
	//user trying to access an offset which is beyond the end of file 
	if (down_interruptible(&dev->sem)) 
		return -ERESTARTSYS;
	if (*poffset >= dev->size) {
		up(&dev->sem);
		return 0;
	}

	//user trying to access more than eof, return bytes read till the eof
	if (*poffset + count >= dev->size) 
		//count = dev->size - *poffset;
		count = dev->size;
	//kspace --> uspace
	if (copy_to_user(ubuff, (dev->data + *poffset), count) < 0) {
		up(&dev->sem);
		return -EFAULT;
	}
	//update the offset
	*poffset += count;
	up(&dev->sem);
	return count;
}

//count is the size of requested data transfer
ssize_t echo_write(struct file *filp, const char __user *ubuff, size_t count, loff_t *poffset)
{
	int ret;
	struct echo_cdev *dev = filp->private_data;
	pr_debug("%s: f_flags: 0x%x\n",__FUNCTION__,filp->f_flags);
	if (down_interruptible(&dev->sem)) 
		return -ERESTARTSYS;
	if (dev->data == NULL) {
		dev->data = (char *)kmalloc(count, GFP_KERNEL);
		if (!dev->data) {
			up(&dev->sem);
			return -ENOMEM;
		} else {
			memset(dev->data, 0, sizeof(count));
		}
	}
	dev->size = count;
	//uspace --> kspace
	if (copy_from_user(dev->data, ubuff, count) < 0) {
		up(&dev->sem);
		return -EFAULT;
	}
	
	*poffset += count;
	ret = count;

	if (dev->size < *poffset)
		dev->size = *poffset;
	//Force lock error
	//up(&dev->sem);
	return ret;
}

static int __init echo_init(void)
{
	int ret;
	printk(KERN_EMERG "entering %s\n",__FUNCTION__);
	//let the user provide the major number.
	if (nr_major) { 
		device = MKDEV(nr_major, nr_minor);
		if ((ret = register_chrdev_region(device, echo_dev_count, chrdev_name)) < 0) {
			pr_debug("%s: failed to register %s\n",__FUNCTION__,
					chrdev_name);
			return ret;
		}
	} else {
		ret = alloc_chrdev_region(&device, 0, echo_dev_count, chrdev_name);
		if (ret < 0) {
			pr_debug("%s: failed to register %s\n",__FUNCTION__,
					chrdev_name);
			return ret;
		}
	}
	nr_major = MAJOR(device);
	nr_minor = MINOR(device);
	//print the major and minor numbers
	pr_debug("%s: major/minor:: %d/%d\n",__FUNCTION__,
			nr_major, nr_minor);
	echo_dev = (struct echo_cdev *)kmalloc(sizeof(struct echo_cdev), GFP_KERNEL);
	if (!echo_dev) {
		printk(KERN_EMERG "Not enough memory\n");
		unregister_chrdev_region(device, echo_dev_count);
		return -ENOMEM;
	}
	memset(echo_dev, 0, sizeof(struct echo_cdev));
	echo_dev->cdev.owner = THIS_MODULE;
	echo_dev->cdev.ops = &echo_fs_ops;
	//initialize the semaphore, before it is presented to the world
	sema_init(&echo_dev->sem,1);
	cdev_init(&echo_dev->cdev, &echo_fs_ops);
	device = MKDEV(nr_major, nr_minor);
	//tell the kernel about this char device
	//telling the VFS layer to associate echo driver's fs operation for file r/w etc.
	ret = cdev_add(&echo_dev->cdev, device, 1);
	if (ret) {
		kfree(echo_dev);
		unregister_chrdev_region(device, echo_dev_count);
		return ret;
	}
	return 0;
}

static void __exit echo_exit(void)
{
	printk(KERN_EMERG "entering %s\n",__FUNCTION__);
	if (echo_dev->data) {
		printk("Inside %s: kfree()\n",__FUNCTION__);
		kfree(echo_dev->data);
	}
	cdev_del(&echo_dev->cdev);
	kfree(echo_dev);
	unregister_chrdev_region(device, echo_dev_count);
}

module_init(echo_init);
module_exit(echo_exit);

<echo.c>

<Makefile>
obj-m := echo.o
CFLAGS_echo.o := -DDEBUG -Wall -Werror -Wmissing-prototypes \
	-Wstrict-prototypes -Wunused-variable -O2 \
	-Wunused-function -g

modules:
	make -C /lib/modules/`uname -r`/build M=`pwd`
clean:
	make -C /lib/modules/`uname -r`/build M=`pwd` clean
<Makefile>

Logs:
root at ubuntu:/boot# egrep -i "debug_kernel|lockdep"
config-3.7.0-rc3-next-20121029 
CONFIG_LOCKDEP_SUPPORT=y
CONFIG_DEBUG_KERNEL=y
CONFIG_LOCKDEP=y
# CONFIG_DEBUG_LOCKDEP is not set

root at ubuntu:/home/amit/ldd3/misc-modules/echo# uname -a
Linux ubuntu 3.7.0-rc3-next-20121029 #1 SMP Mon Oct 29 21:42:20 PDT 2012 i686
i686 i386 GNU/Linux

root at ubuntu:/home/amit/ldd3/misc-modules/echo# dmesg

root at ubuntu:/home/amit/ldd3/misc-modules/echo# insmod echo.ko

root at ubuntu:/home/amit/ldd3/misc-modules/echo# dmesg
[ 1156.704072] entering echo_init
[ 1156.704914] echo_init: major/minor:: 249/0

root at ubuntu:/home/amit/ldd3/misc-modules/echo# mknod /dev/echo c 249 0

root at ubuntu:/home/amit/ldd3/misc-modules/echo# ll /dev/echo
crw-r--r-- 1 root root 249, 0 Oct 29 22:29 /dev/echo

root at ubuntu:/home/amit/ldd3/misc-modules/echo# echo "kernel newbiee" >/dev/echo

root at ubuntu:/home/amit/ldd3/misc-modules/echo# dmesg
[ 1156.704072] entering echo_init
[ 1156.704914] echo_init: major/minor:: 249/0
[ 1237.377205] echo_open: f_flags: 0x8241
[ 1237.377392] echo_write: f_flags: 0x8001

root at ubuntu:/home/amit/ldd3/misc-modules/echo# cat /dev/echo
--> Here the driver read routine gets stuck as I've not reliquished the
semaphore lock

root at ubuntu:/home/amit/ldd3/misc-modules/echo# cat /dev/echo
^C <-- killing the user process

root at ubuntu:/home/amit/ldd3/misc-modules/echo# rmmod echo

root@ubuntu:/home/amit/ldd3/misc-modules/echo# dmesg
[ 1156.704072] entering echo_init
[ 1156.704914] echo_init: major/minor:: 249/0
[ 1237.377205] echo_open: f_flags: 0x8241
[ 1237.377392] echo_write: f_flags: 0x8001
[ 1270.622337] echo_open: f_flags: 0x8000
[ 1270.622477] echo_read: f_flags: 0x8000
[ 1394.180962] entering echo_exit
[ 1394.180996] Inside echo_exit: kfree()

As you can see, no warning/error messages reported by kernel.
-Amit