Why does printk() work only in the init/exit method of a kernel module? (Priority should be fine)

Question

My goal is to write a kernel-module. I am following the memory tutorial of the freesoftware magazine.

The tutorial works fine. I am able to compile the code. When loaded with insmod, the kernel prints <1>Inserting memory module as expected. When I remove the module using rmmod the kernel prints <1>Removing memory module.

For debugging purposes, I am trying to add printk() to the other methods. But they are never printed.

The priority of all the messages is <1>.

I write into the device by: echo -n test1234 > /dev/memory And use cat /dev/memory to get back the data.

cat /var/log/messages and dmesg don´t print anymore information

[ 5550.651221] <1>Inserting memory module [ 5550.655396] <1>Inserting memory module !!!!!!!!!!!!!!! [12230.130847] <1>Removing memory module

cat /proc/sys/kernel/printk 7 4 1 7

uname- a Linux generic-armv7a-hf 3.14.0-163850-g775a3df-dirty #2 SMP Mon Jan 12 13:53:50 CET 2015 armv7l GNU/Linux

Why does printk() only work in the init and exit method?

Is there any (better) way to print variable values than printk()?

Here the code:

/* Necessary includes for device drivers */
#include <linux/init.h>
//#include <linux/config.h>
#include <linux/module.h>
#include <linux/kernel.h> /* printk() */
#include <linux/slab.h> /* kmalloc() */
#include <linux/fs.h> /* everything... */
#include <linux/errno.h> /* error codes */
#include <linux/types.h> /* size_t */
#include <linux/proc_fs.h>
#include <linux/fcntl.h> /* O_ACCMODE */
#include <asm/system.h> /* cli(), *_flags */
#include <asm/uaccess.h> /* copy_from/to_user */

MODULE_LICENSE("Dual BSD/GPL");

/* Declaration of memory.c functions */
int memory_open(struct inode *inode, struct file *filp);
int memory_release(struct inode *inode, struct file *filp);
ssize_t memory_read(struct file *filp, char *buf, size_t count, loff_t *f_pos);
ssize_t memory_write(struct file *filp, char *buf, size_t count, loff_t *f_pos);
void memory_exit(void);
int memory_init(void);

/* Structure that declares the usual file */
/* access functions */
struct file_operations memory_fops = {
  read: memory_read,
  write: memory_write,
  open: memory_open,
  release: memory_release
};

/* Declaration of the init and exit functions */
module_init(memory_init);
module_exit(memory_exit);

/* Global variables of the driver */
/* Major number */
int memory_major = 60;
/* Buffer to store data */
char *memory_buffer;


int memory_init(void) {
  int result;

  /* Registering device */
  result = register_chrdev(memory_major, "memory", &memory_fops);
  if (result < 0) {
    printk(
      "<1>memory: cannot obtain major number %d\n", memory_major);
    return result;
  }

  /* Allocating memory for the buffer */
  memory_buffer = kmalloc(1, GFP_KERNEL); 
  if (!memory_buffer) { 
    result = -ENOMEM;
    goto fail; 
  } 
  memset(memory_buffer, 0, 1);

  printk("<1>Inserting memory module\n"); ///this works fine
  printk("<1>Inserting memory module !!!!!!!!!!!!!!!\n"); ///this works fine too
  return 0;

  fail: 
    memory_exit(); 
    return result;
}


void memory_exit(void) {
  /* Freeing the major number */
  unregister_chrdev(memory_major, "memory");

  /* Freeing buffer memory */
  if (memory_buffer) {
    kfree(memory_buffer);
  }

  printk("<1>Removing memory module\n"); //never printed

}


int memory_open(struct inode *inode, struct file *filp) {

      printk("<1>memory open\n"); //never printed

  /* Success */
  return 0;
}

int memory_release(struct inode *inode, struct file *filp) {

  printk("<1>memory_release\n"); //never printed

  /* Success */
  return 0;
}


ssize_t memory_read(struct file *filp, char *buf, 
                    size_t count, loff_t *f_pos) { 


  printk("<1>mem read\n"); //never printed

  /* Transfering data to user space */ 
  copy_to_user(buf,memory_buffer,1);




  /* Changing reading position as best suits */ 
  if (*f_pos == 0) { 
    *f_pos+=1; 
    return 1; 
  } else { 
    return 0; 
  }
}

ssize_t memory_write( struct file *filp, char *buf,
                      size_t count, loff_t *f_pos) {

  printk("<1>mem write\n"); //never printed

  char *tmp;

  tmp=buf+count-1;
  copy_from_user(memory_buffer,tmp,1);
  return 1;
}

Answer 1

Your driver seems fine, but you aren't actually talking to it with your test commands, so the functions with printks aren't being called. Once the module is loaded, it registers a major and minor number, 60 and 0 in your case. (Down the road you should update the module to request an available major number instead of using a hard-coded one.)

You need to create a file system node with mknod in order to actually use the driver. This will create the /dev/memory node and connect it to the module you have loaded. Then when it is opened, closed, read from, or written to, the file_operations in your module will be called, and the printks will work.

For your module, you should be able to use

mknod /dev/memory c 60 0

You can also chmod 666 /dev/memory to allow any user to use the device, rather than running as root all the time.

Here's a script based on the one I use with modules I develop:

#!/bin/sh
device="memory"
mode="666"
major=$(awk "\$2==\"$device\" {print \$1}" /proc/devices}
mknod /dev/${device} c $major 0
chmod $mode /dev/${device}

It will look up the major number associated with your module and create a file system node for it automatically.

Once you have loaded the module and run mknod or the script, you should be able to use the driver. You will know that it is working becase cat will only return the last character written to the device - your driver only has a one character buffer, and it is automatically overwritten each time a new character comes in. Then dmesg should show the printk's associated with the functions in your module.

The reason your driver seemed to work is because you were creating a regular file with your echo command, which cat happily printed right back to you. It's the same thing that would have happened if you ran those commands on a file in your home directory, you just happened to be in /dev instead.