Timer with spinlocks freezes

Question

I'm working over Debian 6 using a timer in a kernel module that auto programs itself to get n "peudo-random" numbers from the jiffies and insert them into a circular buffer. The problem comes when fire_timer is triggered by 7th time (when items_cbuf == 7), when that happens, the OS execution crashes in the line:

    mod_timer(&my_timer, my_timer.expires);

but not before, so i do not know why is this happening. Any tip? The expected working way is that when the buffer would be at 80% of it's capacity, the whole content would be translated into a list (that is the workqueue task)

EDIT: I have put my complete code, the peoblem could be anywhere and i do not wanto to limitate the resolution. I'm not sure but the relevant functions should be: install_module, Open_module, Fire_timer and release_module. The exact use i make just is open and wait ten seconds, after that i read from the proc entry, but i cannot read because of the system, that freezes

DEFINITIONS

#define PROC_ENTRY "modtimer"
#define PROC_ENTRY_OPS "modconfig"
#define CBUFFER_SIZE 10
#define MAX_BUFFER 512

[...]

/**********************************************************/
/*********** Open-close-read-write functions **************/
/**********************************************************/

/*Module instalation*/
int install_module(void){
    int ret = 0;

    /*Buffer treshold*/
    TRESHOLD_SIZE = 80;
    /*Delay in ticks*/
    DELAY = 125;

    /*timer init*/
    my_timer.expires = jiffies + DELAY;
    my_timer.data = 0;
    my_timer.function = fire_timer;
    init_timer(&my_timer);


    /*workqueue init*/
    workqueue_pendiente = 0;    
    INIT_WORK(&my_workqueue, copy_items_into_list);

    /* semaphore init */    
    sema_init(&mtx,1);
    openDevices = 0;

    /*del spin_lock init*/
    spin_lock_init(&spinlock);

    /*buffer init*/
    cbuf = create_cbuffer_t(CBUFFER_SIZE);
    printk(KERN_INFO "buffer creado");
    items_cbuf = 0;
    /*list init*/
    list_num_items = 0;

    // another initializations

    return ret;
}

[...]

static int modtimer_open (struct inode *inod, struct file *f){
    int ret = 0;

    //Iniciar el timer
    if(openDevices==0){
        my_timer.expires = jiffies + DELAY;
        add_timer(&my_timer);
    }

    try_module_get(THIS_MODULE);       
    openDevices++;

    return ret;
}

static int modtimer_release (struct inode *inod, struct file *f){

    del_timer_sync(&my_timer);
    flush_scheduled_work();

    remove_cbuffer_t (cbuf); //delete the buffer
    vacia_list_item(); //removes every element from the list

    openDevices--;  
    module_put(THIS_MODULE);

    return 0;
}

static ssize_t modtimer_read (struct file *file, char *user, size_t nbits, loff_t * offset){
    struct list_head* pos = mylist.next;
    struct list_head* auxpos; 
    list_item_t* item;
    char aux[MAX_BUFFER];
    char aux2[10];
    int total =0;
    int subt =0;
    int hecho = 0;


    if(down_interruptible(&mtx)){
        return -EINTR;
    }

    while (hecho == 0){
        if(pos == pos->next || list_num_items ==0){
            hecho++;
        }else{
            item = list_entry(pos, list_item_t, links);
            subt=sprintf(aux2, "%d\n",item->data);
            auxpos = pos->next;
            if(subt + total > MAX_BUFFER )  {           
                hecho++;

            }else {

                total+= sprintf(&aux[total],"%i\n",item->data);
                list_del(pos);
                vfree(item);
                list_num_items--;
            }
            subt = 0;
            pos = auxpos;
        }
    }

    aux[total] = '\0';
    up(&mtx);

    copy_to_user(user,aux,total);

    return total;
}

/*********************************************************/
/****************** Planified functions ******************/
/*********************************************************/

//Fills a buffer with integgers and planifies when is about to be out of space
void fire_timer(unsigned long data){ 
    unsigned long flags;
    int rnd = jiffies & 0xFF;

    spin_lock_irqsave(&spinlock,flags);
    if(!is_full_cbuffer_t(cbuf))
    {
        items_cbuf++;
        insert_cbuffer_t(cbuf, rnd);
    }


    printk(KERN_INFO "workqueue_pendiente = %d, items_cbuf=%d, CBUFFER_SIZE = %d, TRESHOLD_SIZE = %d, umbral = %d", 
                                  workqueue_pendiente, items_cbuf, CBUFFER_SIZE, TRESHOLD_SIZE, (CBUFFER_SIZE*TRESHOLD_SIZE)/100);

    if(workqueue_pendiente == 0 &&
        items_cbuf >= (CBUFFER_SIZE*TRESHOLD_SIZE)/100 )
    {
        workqueue_pendiente=1;

        schedule_work(&my_workqueue);
    }

    my_timer.expires = jiffies + DELAY;
    spin_unlock_irqrestore(&spinlock,flags);
    mod_timer(&my_timer, my_timer.expires);
}

void copy_items_into_list(struct work_struct *work){ //Dumps the buffer into the list
    unsigned long flags;
    list_item_t *items[items_cbuf];
    int numbers[items_cbuf];
    int a = -1;

    while (++a < items_cbuf){
        items[a] = vmalloc(sizeof(list_item_t));
    }
    a = -1;

    spin_lock_irqsave(&spinlock,flags);
    while(++a < items_cbuf){
        numbers[a] = *head_cbuffer_t(cbuf);
        remove_cbuffer_t(cbuf);
    }
    workqueue_pendiente = 0; 
    spin_unlock_irqrestore(&spinlock,flags);

    a = -1;
    if (down_interruptible(&mtx)) /*BLOQUEO*/
        return;


    while (++a < items_cbuf){//size_cbuffer_t(cbuf) > 0){
        items[a]->data = numbers[a];
        list_add_tail(&items[a]->links, &mylist);
        list_num_items++;
    }


    up(&mtx);   
}

This is the code i can get before the system freezes:

The "sleeping, remaining 6 is a message from my testing program, it's content is just

int main(void){
    int l;
    int i=11;
    char bla[512];
    l = open("/proc/modtimer",O_RDONLY);
    bla[2] = '\0';
    while(--i>=0){
        printf("sleeping, remaining %d\n",i);
        sleep(1);
    }
    read(l,bla,128);
    close(l);
    printf("numbers:%s",bla);
}

Answer 1

After a lot of work i decided to clarify my code, and i discovered a couple of pointer fails, and i had a pair of problems with the copy_to_user/from_user and /proc entries. My whole new code is here for people who could need it (This time i won't remove comentarys nor printk's that are in spanish:

#define PROC_ENTRY "modtimer"
#define PROC_ENTRY_OPS "modconfig"
#define CBUFFER_SIZE 10
#define MAX_BUFFER 512

#include <linux/module.h>
#include <linux/kernel.h>
#include <linux/list.h>
#include <linux/proc_fs.h>
#include <linux/semaphore.h>
#include <linux/vmalloc.h>
#include <linux/timer.h>
#include <linux/spinlock.h>
#include <linux/timer.h>
#include <linux/workqueue.h>
#include <asm-generic/uaccess.h>
#include "cbuffer.h"

MODULE_LICENSE("GPL");
MODULE_DESCRIPTION("Pseudo-Random number generator for DSO");
MODULE_AUTHOR("Kaostias*emphasized text*");

/**********************************************************/
/********************** Declaraciones *********************/
/**********************************************************/

/*Declaracion del timer*/
struct timer_list my_timer;

/*Declaracion del workqueue*/
struct work_struct my_workqueue;

/* Indica si el workqueue está planificado */
int workqueue_pendiente;

/*Entrada en proc*/
static struct proc_dir_entry *proc_entry, *proc_entry_opts;

/*Semáforo utilizado como un spin_lock para poder usar funciones bloqueantes*/
struct semaphore mtx;
int openDevices;

/*Semáforo consumidor*/
struct semaphore consumer;
int cons_waiting;

/*Spinlock*/
DEFINE_SPINLOCK(spinlock);

/*Lista*/
struct list_head mylist = LIST_HEAD_INIT(mylist);
typedef struct {
    int data;
    struct list_head links;
}list_item_t;

/*Buffer de enteros*/
cbuffer_t *cbuf;
/* Umbral de llenado del buffer*/
int TRESHOLD_SIZE; // 80 
/* Cada cuantos ticks se dispara la rutina */
int DELAY;// 125 (1 cada medio seg)

/*Funciones*/
void vacia_list_item(void);
void fire_timer(unsigned long data);
void copy_items_into_list(struct work_struct *work);
static int modtimer_open (struct inode *, struct file *);
static int modtimer_release (struct inode*, struct file *);
static ssize_t modtimer_read (struct file *file, char __user*, size_t nbits, loff_t * offset);
/*Se escribe la entrada PROC_ENTRY_OPS*/
int procOpsWrite( struct file *punterofichero, const char __user *bufferusuario,
                        unsigned long longitud, void *data);
int procOpsRead( char *buffer, char **bufferlocation, off_t offset,
                   int buffer_lenghth, int *eof, void *data );
/*Operaciones de proc PROC_ENTRY*/
static const struct file_operations my_fops = {
    .open = modtimer_open,
    .read = modtimer_read,
    .release = modtimer_release,
};




/**********************************************************/
/********* Funciones de apertura/cierre/lectura ***********/
/**********************************************************/

/*Instalación del módulo*/
int install_module(void){
    int ret = 0;
    printk(KERN_INFO "instalando módulo");
    /*Umbral de vaciado del buffer*/
    TRESHOLD_SIZE = 80;
    /*Cada cuantos tics se dispara la rutina*/
    DELAY = 125;

    /*Inicialización del timer*/
    my_timer.expires = jiffies + DELAY;
    my_timer.data = 0;
    my_timer.function = fire_timer;
    init_timer(&my_timer);
    printk(KERN_INFO "creado timer");

    /*Inicialización de la cola de trabajo*/
    workqueue_pendiente = 0;    
    INIT_WORK(&my_workqueue, copy_items_into_list);
    printk(KERN_INFO "creada workqueue");   

    /* Inicialización del semáforo */   
    sema_init(&mtx,1);
    openDevices = 0;

    sema_init(&consumer,0);
    cons_waiting = 0;
    printk(KERN_INFO "inicializado semáforo");

    /*Inicialización del spin_loc*/
    spin_lock_init(&spinlock);
    printk(KERN_INFO "inicializado spinlock");

    /*Inicialización del buffer*/
    cbuf = create_cbuffer_t(CBUFFER_SIZE);
    printk(KERN_INFO "buffer creado");

    /* Zona de las entradas de /proc */
    proc_entry = create_proc_entry(PROC_ENTRY,0777, NULL);
    if (proc_entry == NULL) {
            ret = -ENOMEM;
            printk(KERN_INFO "Error: No puedo crear la entrada en proc /proc/%s\n",PROC_ENTRY);
    } else {
        proc_entry->proc_fops=&my_fops;
            printk(KERN_INFO "Entrada /proc/%s creada.\n", PROC_ENTRY);
    }

    proc_entry_opts = create_proc_entry(PROC_ENTRY_OPS,0777, NULL);
    if (proc_entry_opts == NULL) {
            ret = -ENOMEM;
            printk(KERN_INFO "Error: No puedo crear la entrada en proc /proc/%s\n",PROC_ENTRY_OPS);
        remove_proc_entry(PROC_ENTRY, NULL);
            printk(KERN_INFO "Entrada /proc/%s eliminada.\n", PROC_ENTRY);      
    } else {
            proc_entry_opts->read_proc = procOpsRead;
            proc_entry_opts->write_proc =procOpsWrite;
            printk(KERN_INFO "Entrada /proc/%s creada.\n", PROC_ENTRY_OPS);
    }

    printk(KERN_INFO "módulo instalado correctamente");
    return ret;
}
/*Al desinstalar el módulo*/
void uninstall_module(void){
    printk(KERN_INFO "Desinstalando módulo");

    /*Quita proc entries*/
    remove_proc_entry(PROC_ENTRY, NULL);
    printk(KERN_INFO "Entrada /proc/%s eliminada.\n", PROC_ENTRY);

    remove_proc_entry(PROC_ENTRY_OPS, NULL);
    printk(KERN_INFO "Entrada /proc/%s eliminada.\n", PROC_ENTRY_OPS);
    printk(KERN_INFO "Desinstalación completa");

}


/*Se escribe la entrada PROC_ENTRY_OPS*/
int procOpsWrite( struct file *punterofichero, const char __user *bufferusuario,
                        unsigned long longitud, void *data){
    //char aux[MAX_BUFFER];
    int period =0;
    int treshold=0;
    char aux[MAX_BUFFER] = "";
    printk(KERN_INFO "entrando en proc_ops_write, deberia ejecutarse al abrir /proc/%s\n",PROC_ENTRY_OPS);


    if (longitud > MAX_BUFFER) return -1;
    printk(KERN_INFO "1");
    if(copy_from_user(aux,bufferusuario,longitud)) 
        return -EINVAL;
    printk(KERN_INFO "2");
    aux[longitud] = '\0';
    if(sscanf(aux,"timer_period=%d",&period) == 1){
        if(period >0 && period < 10000)
            DELAY = period;
    }
    printk(KERN_INFO "2");
    if(sscanf(aux,"emergency_threshold=%d",&treshold) == 1){
        if(treshold > 0 && treshold <=100)
            TRESHOLD_SIZE = treshold;       
    }
    return longitud;
}
/*Se lee la entrada PROC_ENTRY_OPS*/
int procOpsRead( char *buffer, char **bufferlocation, off_t offset,
                   int buffer_lenghth, int *eof, void *data ){
    //char aux[MAX_BUFFER];

    int i = sprintf(buffer,"Timer_period=%d\nEmergency_threshold=%d\n",DELAY,TRESHOLD_SIZE);
    return i;
}
/*Apertura de la entrada PROC_ENTRY*/
static int modtimer_open (struct inode *inod, struct file *f){
    int ret = 0;
    printk(KERN_INFO "entrando en modtimer_open");

    //Iniciar el timer
    if(openDevices==0){
        my_timer.expires = jiffies + DELAY;
        add_timer(&my_timer);
    }

    try_module_get(THIS_MODULE);    

    openDevices++;

    printk(KERN_INFO "saliendo de modtimer_open");
    return ret;
}
/*Se cierra la entrada PROC_ENTRY*/
static int modtimer_release (struct inode *inod, struct file *f){
    int ret = 0;    
    printk(KERN_INFO "modtimer_release abierto");
    //Eliminar temporizador
    del_timer_sync(&my_timer);
    printk(KERN_INFO "timer borrado");
    //Esperar a que todo el trabajo planificado termine
    flush_scheduled_work();
    printk(KERN_INFO "workqueue finalizada");

    /*Vacía el buffer*/
    remove_cbuffer_t (cbuf);

    /*Vacía la lista */
    vacia_list_item();

    printk(KERN_INFO "lista vacia");
    openDevices--;  

    module_put(THIS_MODULE);

    printk(KERN_INFO "modtimer_release cerrado");
    return ret;
}
/*Se lee la entrada PROC_ENTRY*/
static ssize_t modtimer_read (struct file *file, char *user, size_t nbytes, loff_t * offset){
    struct list_head* pos; 
    struct list_head* auxpos; 
    list_item_t* item;
    char aux[MAX_BUFFER]="";
    char aux2[10];
    int total =0;
    int subt =0;

    printk(KERN_INFO "modtimer_read abierto");  

    if(down_interruptible(&mtx)){
        return -EINTR;
    }

    /* SEMAFORO QUE COMPRUEBA QUE HAYA ELEMENTOS QUE LEER ANTES DE LEER */
    while(list_empty(&mylist)){     
        cons_waiting++;
        up(&mtx);
        if(down_interruptible(&consumer)){
            down(&mtx);
            cons_waiting--;
            up(&mtx);   
            return -EINTR;
        }
        if(down_interruptible(&mtx)){
            return -EINTR;
        }
    }


    /* 
     * Vaciar toda la lista que sea posible, dentro del tamaño máximo (512 
     * bytes es el máximo, así que hay que controlar que al copiar en una
     * cadena auxiliar no se sobrepase el buffer.
     */ 

    pos=mylist.next;
    while (pos!=&mylist) {
        auxpos = pos->next;
        item = list_entry(pos, list_item_t, links);
        subt=sprintf(aux2, "%d\n",item->data);

        if (subt+total>nbytes)
            break;

        strcat(aux,aux2); 
        total+=subt;

        list_del(pos);
        vfree(item);
        printk(KERN_INFO "sacado de la lista");     

        pos = auxpos;       

    }

    //printk(KERN_INFO "Fuera del bucle, cadena copiada: %s\nTotal copiado:%d\nSizeof(aux):%d",aux,total,sizeof(aux));
    up(&mtx);

    if (copy_to_user(user,aux,total))
        return -1;

    printk(KERN_INFO "modtimer_read cerrado");
    return total;
}

/*********************************************************/
/**************** Funciones planificadas *****************/
/*********************************************************/

/*Rutina que inserta números en el buffer cada pocos ticks*/
void fire_timer(unsigned long data){
    unsigned long flags;
    int rnd = jiffies & 0xFF;
    int items_cbuf;
    printk(KERN_INFO "Entrando a fire_timer");


    spin_lock_irqsave(&spinlock,flags);
    if(!is_full_cbuffer_t(cbuf))
    {
        insert_cbuffer_t(cbuf, rnd);
        printk(KERN_INFO "Numero aleatorio %d",rnd);
    }


    items_cbuf=size_cbuffer_t(cbuf);
    spin_unlock_irqrestore(&spinlock,flags);

    printk(KERN_INFO "workqueue_pendiente = %d, items_cbuf=%d, CBUFFER_SIZE = %d, TRESHOLD_SIZE = %d, umbral = %d", 
                                  workqueue_pendiente, items_cbuf, CBUFFER_SIZE, TRESHOLD_SIZE, (CBUFFER_SIZE*TRESHOLD_SIZE)/100);

    //Si el trabajo no estaba planificado y hace falta planificarlo
    if(workqueue_pendiente == 0 &&
        items_cbuf >= (CBUFFER_SIZE*TRESHOLD_SIZE)/100 )
    {
        workqueue_pendiente=1;
        //Planificar copy_items_into_list()

        schedule_work(&my_workqueue);
        printk(KERN_INFO "Planificado");
    }


    //Programar el timer

    printk(KERN_INFO "Byob");
    mod_timer(&my_timer, jiffies + DELAY);
    printk(KERN_INFO "Saliendo de Fire_timer");
}
/*Copia desde el cbuffer al list_item_t*/
void copy_items_into_list(struct work_struct *work){
    unsigned long flags;
    list_item_t *items[CBUFFER_SIZE];
    int numbers[CBUFFER_SIZE];
    int i;
    int nr_elems =0;
    printk(KERN_INFO "Entrando en copy_items_into_list");


    spin_lock_irqsave(&spinlock,flags);
    nr_elems  = size_cbuffer_t(cbuf);
    for(i =0; i< nr_elems;i++){
        numbers[i] = *head_cbuffer_t(cbuf);
        remove_cbuffer_t(cbuf);
    }
    workqueue_pendiente = 0; //workqueue no planificado

    spin_unlock_irqrestore(&spinlock,flags);

    for (i=0;i<nr_elems;i++){
        items[i] = (list_item_t*)vmalloc(sizeof(list_item_t));
    }

    if (down_interruptible(&mtx)) /*BLOQUEO*/
        return;

    /* vaciar buffer y llenar cola enlazada */
    for (i=0;i<nr_elems;i++){
        items[i]->data = numbers[i];
        list_add_tail(&items[i]->links, &mylist);
    }


    if (cons_waiting>0){
        cons_waiting--;
        up(&consumer);  
     }
    up(&mtx);   
    printk(KERN_INFO "Saliendo de copy_items_into_list");
}
/*********************************************************/
/********************  Utilidades  ***********************/
/*********************************************************/


/*Vacía la lista de list_item_t*/
void vacia_list_item(void){
    struct list_head* pos = mylist.next;
    struct list_head* posaux;
    list_item_t* item;
    printk(KERN_INFO "Vaciando la lista");

    while(!list_empty(&mylist)){
        item = list_entry(pos, list_item_t, links);
        posaux = pos->next;
        list_del(pos);
        vfree(item);
        pos = posaux;
    }
    printk(KERN_INFO "Lista vacía");
}

module_init(install_module);
module_exit(uninstall_module);

Answer 2

In fire_timer() you call spin_unlock_irqrestore(&spinlock,flags); twice while only having called spin_lock_irqsave() once.