Messages in this thread | | | Subject | Re: [RFC] RT-patch update to remove the global pi_lock | From | Steven Rostedt <> | Date | Wed, 24 Aug 2005 21:13:11 -0400 |
| |
Well, after turning off hrtimers, I keep getting one bug. A possible soft lockup with the ext3 code. But this didn't seem to be caused by the changes I made. So just to be sure, I ran my test on the vanilla 2.6.13-rc6-rt11 and it gave the same bug too. So, it looks like my changes are now at par with what is out there with the rt11 release. They both give the same bug! ;-)
Attached is the test I ran. I did a
while : ; do ./test3a_rt ; done
Where test3a_rt is a C program that does adding, deleting and reading of files, by different tasks that are each at a different priority. Here's the soft lockup I'm getting:
NFSD: starting 90-second grace period BUG: test3a_rt:6138, possible softlockup detected on CPU#0! [<c01043f3>] dump_stack+0x23/0x30 (20) [<c014cf81>] softlockup_detected+0x41/0x60 (24) [<c014d090>] softlockup_tick+0xf0/0x100 (24) [<c012bbbb>] update_process_times+0x5b/0x80 (28) [<c011415e>] smp_apic_timer_interrupt+0xee/0x100 (36) [<c0103ec1>] apic_timer_interrupt+0x21/0x28 (124) [<c01c1641>] ext3_add_entry+0xd1/0x210 (60) [<c01c1e0d>] ext3_add_nondir+0x2d/0x80 (32) [<c01c1f1b>] ext3_create+0xbb/0x110 (40) [<c0180721>] vfs_create+0xf1/0x170 (44) [<c018105b>] open_namei+0x61b/0x6e0 (72) [<c016eb5f>] filp_open+0x3f/0x70 (92) [<c016f033>] sys_open+0x53/0x100 (44) [<c01033da>] syscall_call+0x7/0xb (-8116) --------------------------- | preempt count: 00010000 ] | 0-level deep critical section nesting: ----------------------------------------
------------------------------ | showing all locks held by: | (test3a_rt/6138 [f7ef61a0, 89]): ------------------------------
#001: [f2eaddac] {(struct semaphore *)(&inode->i_sem)} ... acquired at: open_namei+0xf9/0x6e0
NMI show regs on CPU#0:
Pid: 6138, comm: test3a_rt EIP: 0060:[<c0114929>] CPU: 0 EIP is at nmi_show_all_regs+0x89/0xd0 EFLAGS: 00000046 Not tainted (2.6.13-rc6-rt11-real) EAX: 00000000 EBX: 000017fa ECX: 00000060 EDX: 00000080 ESI: 00000000 EDI: 0006c692 EBP: f07dbd48 DS: 007b ES: 007b CR0: 8005003b CR2: b7e37ae0 CR3: 30850000 CR4: 000006d0 [<c01013b4>] show_regs+0x164/0x16c (36) [<c0114a98>] nmi_watchdog_tick+0x128/0x2b0 (56) [<c01054bf>] default_do_nmi+0x7f/0x190 (52) [<c0105630>] do_nmi+0x50/0x60 (24) [<c010405a>] nmi_stack_correct+0x1d/0x22 (72) [<c014cf86>] softlockup_detected+0x46/0x60 (24) [<c014d090>] softlockup_tick+0xf0/0x100 (24) [<c012bbbb>] update_process_times+0x5b/0x80 (28) [<c011415e>] smp_apic_timer_interrupt+0xee/0x100 (36) [<c0103ec1>] apic_timer_interrupt+0x21/0x28 (124) [<c01c1641>] ext3_add_entry+0xd1/0x210 (60) [<c01c1e0d>] ext3_add_nondir+0x2d/0x80 (32) [<c01c1f1b>] ext3_create+0xbb/0x110 (40) [<c0180721>] vfs_create+0xf1/0x170 (44) [<c018105b>] open_namei+0x61b/0x6e0 (72) [<c016eb5f>] filp_open+0x3f/0x70 (92) [<c016f033>] sys_open+0x53/0x100 (44) [<c01033da>] syscall_call+0x7/0xb (-8116) --------------------------- | preempt count: 00010001 ] | 1-level deep critical section nesting: ---------------------------------------- .. [<c0143f5c>] .... add_preempt_count+0x1c/0x20 .....[<c0114a7d>] .. ( <= nmi_watchdog_tick+0x10d/0x2b0)
------------------------------ | showing all locks held by: | (test3a_rt/6138 [f7ef61a0, 89]): ------------------------------
#001: [f2eaddac] {(struct semaphore *)(&inode->i_sem)} ... acquired at: open_namei+0xf9/0x6e0
NMI show regs on CPU#1:
Pid: 6137, comm: test3a_rt EIP: 0060:[<c01cd9c3>] CPU: 1 EIP is at do_get_write_access+0x83/0x560 EFLAGS: 00000206 Not tainted (2.6.13-rc6-rt11-real) EAX: 000e201d EBX: f7ffe000 ECX: f71e49bc EDX: f71e49bc ESI: f7f6b3bc EDI: f71e49bc EBP: f1409e94 DS: 007b ES: 007b CR0: 8005003b CR2: b7fdb000 CR3: 326fb000 CR4: 000006d0 [<c01013b4>] show_regs+0x164/0x16c (36) [<c0114a98>] nmi_watchdog_tick+0x128/0x2b0 (56) [<c01054bf>] default_do_nmi+0x7f/0x190 (52) [<c0105630>] do_nmi+0x50/0x60 (24) [<c010405a>] nmi_stack_correct+0x1d/0x22 (132) [<c01cded5>] journal_get_write_access+0x35/0x50 (28) [<c01c2b02>] ext3_orphan_del+0x1a2/0x230 (80) [<c01bae03>] ext3_delete_inode+0x73/0x110 (24) [<c018cad9>] generic_delete_inode+0x99/0x160 (28) [<c018cd1d>] generic_drop_inode+0x1d/0x30 (12) [<c018cda0>] iput+0x70/0x80 (20) [<c0181ee0>] sys_unlink+0x110/0x140 (96) [<c01033da>] syscall_call+0x7/0xb (-8116) --------------------------- | preempt count: 00000001 ] | 1-level deep critical section nesting: ---------------------------------------- .. [<c0143f5c>] .... add_preempt_count+0x1c/0x20 .....[<c0114a7d>] .. ( <= nmi_watchdog_tick+0x10d/0x2b0)
------------------------------ | showing all locks held by: | (test3a_rt/6137 [f5d437f0, 90]): ------------------------------
#001: [f709cc88] {(struct semaphore *)(&s->s_lock)} ... acquired at: ext3_orphan_del+0x3a/0x230
Well, looking at this further, it seems to release somehow, and continue, since I've got multiple "possible soft lockups", by different threads. But It doesn't seem to go any further. Somethings spinning quite a bit, and something else must be starved. I'll look further into this.
So, Ingo, what do you think of the changes so far? Do you feel that it is stable enough to send you an actual real patch. That way we can work together in cleaning it up and get all the other kinks out.
Also, let me know if you are getting this. The last couple of messages I sent, never reached me on the LKML, and I sent the last one 4 hours ago. :-(
Thomas, I did get your reply.
-- Steve
#include <stdio.h> #include <stdlib.h> #include <string.h> #include <unistd.h> #include <time.h> #include <sys/sem.h> #include <sys/shm.h> #include <sys/time.h> #include <sys/wait.h> #include <sys/types.h> #include <sys/stat.h> #include <dirent.h> #include <fcntl.h> #include <signal.h> #include <ctype.h> #include <sched.h>
#define __USE_GNU #include <sys/ipc.h>
#ifdef SDR_TOOLS #include <dump_log.h> #include <linux/logdev.h> #include <dump_log.h> #include <tracer_xml.h> #include "dump_trace.h" int logfd = -1; #else #define logdev_print(x...) do {} while(0) #define logdev_switch_set(x) (0) #endif
#include <list.h>
static char *testdir = "/tmp/test3a";
static int reader (int i); static int deleter (int i); static int creator (int i);
typedef int (*callfunc_t)(int);
#define NR_PROCS 5 pid_t pids[NR_PROCS]; callfunc_t dofunc[NR_PROCS] = { deleter, creator, reader, reader, reader };
int priorities[NR_PROCS] = { 9, 10, 11, 12, 13, };
key_t semkey; key_t shmkey; int semid = -1; int shmid = -1; int safe = 0; int *flags;
static void remove_testdir(void);
void cleanup(void) { int i;
for (i=0; i < NR_PROCS; i++) { if (pids[i]) kill(pids[i],SIGKILL); }
if (semid >= 0) semctl(semid, 0, IPC_RMID); if (shmid >= 0) shmctl(shmid, IPC_RMID, NULL); remove_testdir();
#ifdef SDR_TOOLS if (logfd >= 0) close_logdev(logfd); #endif }
void catchall(int sig) { cleanup(); psignal(sig,"Caught: "); exit(-1); }
static int compare_timeval(const struct timeval *a, const struct timeval *b) { return (a->tv_sec > b->tv_sec) ? 1 : (a->tv_sec < b->tv_sec) ? -1: (a->tv_usec > b->tv_usec) ? 1: (a->tv_usec < b->tv_usec) ? -1: 0; }
static void add_timeval(const struct timeval *a, const struct timeval *b, struct timeval *c) {
c->tv_usec = a->tv_usec + b->tv_usec; c->tv_sec = a->tv_sec + b->tv_sec; while (c->tv_usec > 1000000) { c->tv_usec -= 1000000; c->tv_sec++; }
}
static void sub_timeval(const struct timeval *a, const struct timeval *b, struct timeval *c) {
c->tv_usec = a->tv_usec - b->tv_usec; c->tv_sec = a->tv_sec - b->tv_sec; while (c->tv_usec < 0) { c->tv_usec += 1000000; c->tv_sec--; }
}
struct dir_item { struct list_head list; char *dir; };
LIST_HEAD_DECLARE(dirs);
static void read_dirs(char *dirname) { DIR *dir; struct dirent *dent; struct stat st; struct dir_item *item; int len = strlen(dirname); char *name; struct sembuf sops; int semid;
memset(&sops,0,sizeof(sops)); if ((semid = semget(semkey,1,0)) < 0) { perror("semget"); return; } if ((dir = opendir(dirname)) == NULL) return;
while ((dent = readdir(dir))) { if (strcmp(dent->d_name,".") == 0 || strcmp(dent->d_name,"..") == 0) continue;
name = malloc(strlen(dent->d_name)+len+2); if (!name) { goto out; }
strcpy(name,dirname); name[len] = '/'; strcpy(name+len+1,dent->d_name);
if (stat(name,&st) < 0) { perror(name); free(name); continue; }
if ((S_ISDIR(st.st_mode))) { item = malloc(sizeof(*item)); if (!item) { free(name); goto out; } item->dir = name; list_add_tail(&item->list,&dirs); } else { free(name); } } out: closedir(dir); } static int reader(int i) { struct sembuf sops; int semid; struct timeval starttv; struct timeval endtv; struct timeval tv; struct timeval lasttv; struct timeval deltatv; struct timespec ts = {0,250000000UL}; time_t t; char timebuf[30]; unsigned long long starttsc, nowtsc;
memset(&sops,0,sizeof(sops)); if ((semid = semget(semkey,1,0)) < 0) { perror("semget"); return -1; }
if (gettimeofday(&starttv,NULL) < 0) { perror("gettimeofday"); return -1; }
memset (&deltatv,0,sizeof(deltatv));
endtv.tv_sec = 10; endtv.tv_usec = 0;
add_timeval(&starttv,&endtv,&endtv); printf("reader %d grabbing waiting on sem\n",i); printf("(id=%d) start time is %ld.%06ld\n",i,starttv.tv_sec,starttv.tv_usec); if (semop(semid, &sops, 1) < 0) { perror("semop"); return -1; }
logdev_print(logfd,"reader %d past semaphore\n",i);
t = time(NULL); ctime_r(&t,timebuf); timebuf[strlen(timebuf)-1] = 0;
printf("reader %d starting loop (%s)\n",i,timebuf); logdev_print(logfd,"reader %d (pid %d) starting loop (%s)\n",i,getpid(),timebuf); lasttv = starttv; asm ("rdtsc" : "=A"(starttsc)); chdir("/"); read_dirs("/tmp"); do { struct list_head *p; struct dir_item *item;
asm ("rdtsc" : "=A"(nowtsc)); if (safe && (nowtsc - starttsc > 8000000000ULL)) { printf("now - start > 8000000000\n"); break; } if (list_empty(&dirs)) { nanosleep(&ts,NULL); read_dirs("/tmp"); if (list_empty(&dirs)) /* ?? */ break; }
p = dirs.next; list_del(p); item = list_entry(p,struct dir_item, list); printf("%d: reading dir %s\n",i,item->dir); read_dirs(item->dir); free(item->dir); free(item); if (gettimeofday(&tv,NULL) < 0) { perror("gettimeofday (in loop)"); return -1; }
sub_timeval(&tv,&lasttv,&lasttv); if (compare_timeval(&deltatv,&lasttv) < 0) deltatv = lasttv; lasttv = tv; } while(compare_timeval(&endtv,&tv) > 0); t = time(NULL); ctime_r(&t,timebuf); timebuf[strlen(timebuf)-1] = 0; logdev_print(logfd,"spinner %d (pid %d) done (%s)\n",i,getpid(),timebuf); printf("spinner %d ended loop (%s) (%d.%06d secs delta)\n", i,timebuf,(int)deltatv.tv_sec,(int)deltatv.tv_usec); printf(" (id=%d) end time is %ld.%06ld\n",i,tv.tv_sec,tv.tv_usec); printf(" (id=%d) end time should be %ld.%06ld\n",i,endtv.tv_sec,endtv.tv_usec);
/* * When the readers are done, stop the others that don't * have any other test to stop with. No locks needed, we * all just set it to one. */ *flags = 1; return 0; }
void delete_all(char *dirname) { DIR *dir; struct dirent *dent; int len = strlen(dirname); char *name; struct sembuf sops; int semid; memset(&sops,0,sizeof(sops)); if ((semid = semget(semkey,1,0)) < 0) { perror("semget"); return; } if ((dir = opendir(dirname)) == NULL) return;
while ((dent = readdir(dir))) { if (strcmp(dent->d_name,".") == 0 || strcmp(dent->d_name,"..") == 0) continue;
name = malloc(strlen(dent->d_name)+len+2); if (!name) { goto out; }
strcpy(name,dirname); name[len] = '/'; strcpy(name+len+1,dent->d_name);
unlink(name); free(name); } out: closedir(dir); }
static int deleter(int i) { struct sembuf sops; int semid;
memset(&sops,0,sizeof(sops)); if ((semid = semget(semkey,1,0)) < 0) { perror("semget"); return -1; }
printf("deleter %d grabbing waiting on sem\n",i); if (semop(semid, &sops, 1) < 0) { perror("semop"); return -1; }
logdev_print(logfd,"deleter %d past semaphore\n",i);
while (!*flags) { delete_all(testdir); }
return 0; }
static int creator(int i) { struct sembuf sops; int semid; int x; char name[100];
memset(&sops,0,sizeof(sops)); if ((semid = semget(semkey,1,0)) < 0) { perror("semget"); return -1; }
mkdir(testdir,0777);
printf("creator %d grabbing waiting on sem\n",i); if (semop(semid, &sops, 1) < 0) { perror("semop"); return -1; }
logdev_print(logfd,"creator %d past semaphore\n",i);
while (!*flags) { int fd; char *garbage = "garbage\n"; snprintf(name,100,"%s/dummy%d",testdir,x++); if ((fd = open(name,O_CREAT|O_WRONLY,0777)) < 0) { perror(name); continue; } write(fd,garbage,strlen(garbage)); close(fd); }
return 0; }
static void remove_testdir(void) { delete_all(testdir); rmdir(testdir); }
void usage(char **argv) { char *arg = argv[0]; char *p = arg+strlen(arg);
while (p >= arg && *p != '/') p--; p++;
printf("\nusage: %s [-sn]\n" " -s : safe mode. Have the readers use the tsc to stop\n" " -n : run without RT\n" "\n",p); exit(-1); }
int main (int argc, char **argv) { int ret=0; int i; int nr_procs=0; int noprio = 0; struct sembuf sops; int c;
opterr = 0; while ((c=getopt(argc,argv,"hsn")) >= 0) { switch (c) { case 's': safe = 1; break; case 'n': noprio = 1; break; case 'h': default: printf("\n"); if (c != ':' && tolower(optopt) != 'h' && optopt != '?') printf("unknown option: %c\n",optopt); usage(argv); } }
semkey = ftok(argv[0],123); shmkey = ftok(argv[0],456); if ((semid = semget(semkey,1,IPC_CREAT|IPC_EXCL|0600)) < 0) { perror("semget"); exit (-1); }
if ((shmid = shmget(shmkey,30,IPC_CREAT|IPC_EXCL|0600)) < 0) { perror("shmget"); goto out; } if ((flags = shmat(shmid, NULL, 0)) == (void*)-1) { perror("shmat"); goto out; }
*flags = 0; #ifdef SDR_TOOLS if ((logfd = open_logdev(NULL,O_RDWR)) < 0) { perror("open_logdev"); goto out; }
if (logdev_switch_set(1)) { perror("logdev_switch_on"); } #endif
/* Grab the semaphore before anyone else can take it. */ memset(&sops,0,sizeof(sops)); // sops.sem_flg = SEM_UNDO; sops.sem_op = 1; if (semop(semid, &sops, 1) < 0) { perror("semop"); ret = -1; goto out; }
for (i=0; i < NR_PROCS; i++) { struct sched_param p;
if ((pids[i] = fork()) < 0) { perror("fork"); ret = -1; goto out; } else if (pids[i] == 0) { /* child */ ret = dofunc[i](i); exit(ret); } nr_procs++;
if (!noprio && priorities[i]) { p.sched_priority = priorities[i]; if (sched_setscheduler(pids[i],SCHED_FIFO,&p)) { perror("sched_setscheduler"); goto out; } }
/* parent */ }
signal(SIGINT,catchall); signal(SIGILL,catchall); signal(SIGFPE,catchall); signal(SIGSEGV,catchall); signal(SIGBUS,catchall);
sleep(1); printf("parent zeroing semaphore\n");
sops.sem_op = -1; if (semop(semid,&sops,1) < 0) { perror("semop"); ret = -1; goto out; }
while (nr_procs) { int status; pid_t pid; if ((pid = wait(&status)) < 0) { perror("wait"); break; } for (i=0; i < NR_PROCS; i++) { if (pids[i] == pid) { pids[i] = 0; nr_procs--; } } }
if (logdev_switch_set(0)) { perror("logdev_switch_off"); }
out: cleanup(); exit(ret); } #ifndef __USER_LIST_H #define __USER_LIST_H
#include <sys/types.h> #include <unistd.h>
#define DEBUG_LIST
#ifdef DEBUG_LIST #include <sys/types.h> #include <signal.h> #ifndef LIST_BUG #define LIST_BUG() do { printf(">>>>> list bug <<<< at %d\n",__LINE__); kill(getpid(),SIGSEGV); } while(0) #endif #define __LIST_MAGIC 0xdeabbeef #define __LIST_MAGIC_POISON 0xbeefdead #define __LIST_MAGIC_COMMA , __LIST_MAGIC #define __LIST_MAGIC_ASSIGN(x) (x).magic = __LIST_MAGIC; #else #define __LIST_MAGIC #define __LIST_MAGIC_COMMA #define __LIST_MAGIC_ASSIGN(x) #endif
#define __LIST_POISON ((struct list_head *)-1)
struct list_head { struct list_head *next; struct list_head *prev; #ifdef DEBUG_LIST int magic; #endif };
#define LIST_HEAD_INIT(x) { &x, &x __LIST_MAGIC_COMMA} #define LIST_HEAD_DECLARE(x) struct list_head x = LIST_HEAD_INIT(x) #define INIT_LIST_HEAD(x) do { (x).next = &x; (x).prev = &x; __LIST_MAGIC_ASSIGN(x)} while (0)
#define list_for_each(p,list) for(p=(list)->next; p != list; p=p->next) #define list_for_each_reverse(p,list) for(p=(list)->prev; p != list; p=p->prev) #define list_for_each_safe(p,n,list) for(p=(list)->next,n=p->next; p != list; p=n,n=p->next)
#ifdef DEBUG_LIST static inline void list_check(struct list_head *x) { struct list_head *p; list_for_each_reverse(p,x) { if (p->magic != __LIST_MAGIC) LIST_BUG(); } list_for_each(p,x) { if (p->magic != __LIST_MAGIC) LIST_BUG(); } } #endif
static inline void list_add(struct list_head *x,struct list_head *list) { #ifdef DEBUG_LIST if (x->magic == __LIST_MAGIC_POISON && (x->next != __LIST_POISON || x->prev != __LIST_POISON)) LIST_BUG(); #endif x->next = list->next; x->prev = list; list->next->prev = x; list->next = x; #ifdef DEBUG_LIST x->magic = __LIST_MAGIC; list_check(list); #endif }
static inline void list_add_tail(struct list_head *x, struct list_head *list) { #ifdef DEBUG_LIST if (x->magic == __LIST_MAGIC && (x->next != __LIST_POISON || x->prev != __LIST_POISON)) LIST_BUG(); #endif x->prev = list->prev; x->next = list; list->prev->next = x; list->prev = x; #ifdef DEBUG_LIST x->magic = __LIST_MAGIC; list_check(list); #endif }
#define list_entry(p,type,list) ((type*)(((char*)(p))-((char*)&(((type*)NULL)->list))))
#define list_empty(list) ((list)->next == (list)) #define list_head(list) ((list)->next)
static inline void list_del(struct list_head *x) { #ifdef DEBUG_LIST if (x->magic != __LIST_MAGIC) LIST_BUG(); list_check(x); x->magic = __LIST_MAGIC_POISON; #endif x->prev->next = x->next; x->next->prev = x->prev; x->next = __LIST_POISON; x->prev = __LIST_POISON; }
static inline struct list_head * pop_list_head(struct list_head *head) { struct list_head *p; if (list_empty(head)) return NULL; p = head->next; list_del(p); #ifdef DEBUG_LIST list_check(head); #endif return p; }
#endif /* __USER_LIST_H */
| |