lock issue when using fcntl when mounting with vers=4.0.
All, Given two threads (1 and 2) of the same process - that are using fcntl to lock the same file - and operations issued in the following order open1 open2 lock1 lock2 unlock1 close1 unlock2 close2 close1 seems to be unlocking lock2 Ganesha is getting into a state when it gets the unlock2 in which it starts failing subsequent lock requests This happens when mounting with vers=4.0 This happens with both Ganesha 3.5 and Ganesha 5.9 This does not happen if flock is used instead of fcntl This does not happen when mounting with vers=4.1 Here too, close1 seems to be unlocking lock2 However when Ganesha gets unlock2, it logs the following, but honours subsequent lock requests "Unlock success on file with no locks" Linux Kernel Client is 4.18 Here is the simple program to reproduce the problem #include <stdio.h> #include <pthread.h> #include <stdlib.h> #include <unistd.h> #include <sys/stat.h> #include <fcntl.h> #include <errno.h> #include <string.h> #include <sys/syscall.h> #define BUF_SIZE 512 int a = 0; void *func_thread(void *p) { printf("start %s\n", p); int fd; struct flock fl; int microsecond = 0.1 * 1000000; int byte_num; char buf[BUF_SIZE]; pid_t tid; tid = syscall(SYS_gettid); fd = open(p, O_RDWR); if (fd == -1) { /* Handle error */; printf("[%d] open err.\n", tid); } fl.l_type = F_RDLCK; fl.l_whence = SEEK_SET; fl.l_start = 0; fl.l_len = 0; printf("[%d] start F_SETLK.\n", tid); if (fcntl(fd, F_SETLK, &fl) == -1) { if (errno == EACCES || errno == EAGAIN) { printf("[%d] Already locked by another process\n", tid); /* We can't get the lock at the moment */ } else { /* Handle unexpected error */ printf("fcntl F_RDLCK err.\n"); fprintf(stderr,"[%d] func_thread : %s\n",tid, strerror(errno)); close(fd); pthread_exit(0); } } else { /* Lock was granted... / / Unlock the locked bytes */ printf("[%d] start F_UNLCK.\n", tid); fl.l_type = F_UNLCK; fl.l_whence = SEEK_SET; fl.l_start = 0; fl.l_len = 0; if (fcntl(fd, F_SETLK, &fl) == -1) { /* Handle error */; printf("fcntl F_UNLCK err.\n"); fprintf(stderr,"[%d] func_thread : %s\n", tid, strerror(errno)); close(fd); pthread_exit(0); } } close(fd); printf("[%d] success.\n", tid); pthread_exit(0); } int main(int argc, char *argv[]) { pthread_t pthread0, pthread1, pthread2, pthread3, pthread4; int status; status = pthread_create( &pthread0, NULL, &func_thread, argv[1]); if(status!=0){ fprintf(stderr,"pthread_create : %s\n",strerror(status)); } else{ printf("pthread0=%d\n", pthread0); } status = pthread_create( &pthread1, NULL, &func_thread, argv[1]); if(status!=0){ fprintf(stderr,"pthread_create : %s\n",strerror(status)); } else{ printf("pthread1=%d\n", pthread1); } pthread_join(pthread0, NULL); pthread_join(pthread1, NULL); return 0; }
All,
Given two threads (1 and 2) of the same process - that are using fcntl to lock the same file - and operations issued in the following order
open1 open2 lock1 lock2 unlock1 close1 unlock2 close2
close1 seems to be unlocking lock2
That is happening because of a lovely feature of POSIX locks where any close releases all the locks on the file held by the process. Also, the process is the lock owner, so you can't use locks to synchronize between two threads.
Ganesha is getting into a state when it gets the unlock2 in which it starts failing subsequent lock requests This happens when mounting with vers=4.0 This happens with both Ganesha 3.5 and Ganesha 5.9 This does not happen if flock is used instead of fcntl
Can you get a tcpdump trace? It would also be helpful to open an issue on github if you are able to. I suspect something is going wrong with the lock and open owners. It may be a client bug.
This does not happen when mounting with vers=4.1 Here too, close1 seems to be unlocking lock2 However when Ganesha gets unlock2, it logs the following, but honours subsequent lock requests "Unlock success on file with no locks"
4.1 handles open and lock owners slightly differently in a way that doesn't get tripped up.
Linux Kernel Client is 4.18
Here is the simple program to reproduce the problem
#include <stdio.h> #include <pthread.h> #include <stdlib.h> #include <unistd.h> #include <sys/stat.h> #include <fcntl.h> #include <errno.h> #include <string.h> #include <sys/syscall.h> #define BUF_SIZE 512 int a = 0; void *func_thread(void *p) { printf("start %s\n", p); int fd; struct flock fl; int microsecond = 0.1 * 1000000; int byte_num; char buf[BUF_SIZE]; pid_t tid; tid = syscall(SYS_gettid); fd = open(p, O_RDWR); if (fd == -1) { /* Handle error */; printf("[%d] open err.\n", tid); } fl.l_type = F_RDLCK; fl.l_whence = SEEK_SET; fl.l_start = 0; fl.l_len = 0; printf("[%d] start F_SETLK.\n", tid); if (fcntl(fd, F_SETLK, &fl) == -1) { if (errno == EACCES || errno == EAGAIN) { printf("[%d] Already locked by another process\n", tid); /* We can't get the lock at the moment */ } else { /* Handle unexpected error */ printf("fcntl F_RDLCK err.\n"); fprintf(stderr,"[%d] func_thread : %s\n",tid, strerror(errno)); close(fd); pthread_exit(0); } } else { /* Lock was granted... / / Unlock the locked bytes */ printf("[%d] start F_UNLCK.\n", tid); fl.l_type = F_UNLCK; fl.l_whence = SEEK_SET; fl.l_start = 0; fl.l_len = 0; if (fcntl(fd, F_SETLK, &fl) == -1) { /* Handle error */; printf("fcntl F_UNLCK err.\n"); fprintf(stderr,"[%d] func_thread : %s\n", tid, strerror(errno)); close(fd); pthread_exit(0); } } close(fd); printf("[%d] success.\n", tid); pthread_exit(0); } int main(int argc, char *argv[]) { pthread_t pthread0, pthread1, pthread2, pthread3, pthread4; int status; status = pthread_create( &pthread0, NULL, &func_thread, argv[1]); if(status!=0){ fprintf(stderr,"pthread_create : %s\n",strerror(status)); } else{ printf("pthread0=%d\n", pthread0); } status = pthread_create( &pthread1, NULL, &func_thread, argv[1]); if(status!=0){ fprintf(stderr,"pthread_create : %s\n",strerror(status)); } else{ printf("pthread1=%d\n", pthread1); } pthread_join(pthread0, NULL); pthread_join(pthread1, NULL); return 0; } _______________________________________________ Support mailing list -- support@lists.nfs-ganesha.org To unsubscribe send an email to support-leave@lists.nfs-ganesha.org
Ganesha server log when this happens, 11/06/2024 02:58:44 : epoch 66681f04 : minnie-shared-736 : ganesha.nfsd-23[svc_10] nfs4_op_open :STATE :DEBUG :Entering NFS v4 OPEN handler ----------------------------- 11/06/2024 02:58:44 : epoch 66681f04 : minnie-shared-736 : ganesha.nfsd-23[svc_10] nfs4_op_open :STATE :DEBUG :OPEN Client id = 66681f0400000001 11/06/2024 02:58:44 : epoch 66681f04 : minnie-shared-736 : ganesha.nfsd-23[svc_10] nfs4_State_Get_Obj :STATE :DEBUG :HashTable_Get returned 2 11/06/2024 02:58:44 : epoch 66681f04 : minnie-shared-736 : ganesha.nfsd-23[svc_12] nfs4_op_open :STATE :DEBUG :Entering NFS v4 OPEN handler ----------------------------- 11/06/2024 02:58:44 : epoch 66681f04 : minnie-shared-736 : ganesha.nfsd-23[svc_12] nfs4_op_open :STATE :DEBUG :OPEN Client id = 66681f0400000001 11/06/2024 02:58:44 : epoch 66681f04 : minnie-shared-736 : ganesha.nfsd-23[svc_12] create_nfs4_owner :STATE :DEBUG :Previously known owner {STATE_OPEN_OWNER_NFSV4 0x7f9a64009020: clientid={0x7f9a68003300 ClientID={Epoch=0x66681f04 Counter=0x00000001} CONFIRMED Client={0x7f9a68003260 name=(60:Linux NFSv4.0 pluto.disneyworld.com/198.168.2.19) refcount=1} t_delta=0 reservations=1 refcount=3 cb_prog=1073741824 r_addr=12.7.61.42.140.53 r_netid=tcp} owner=(24:0x6f70656e2069643a0000018a000000010005df06ed3b8253) confirmed=1 seqid=1 refcount=2} is being reused 11/06/2024 02:58:44 : epoch 66681f04 : minnie-shared-736 : ganesha.nfsd-23[svc_4] nfs4_op_lock :NFS4 LOCK :DEBUG :Entering NFS v4 LOCK handler ---------------------- 11/06/2024 02:58:44 : epoch 66681f04 : minnie-shared-736 : ganesha.nfsd-23[svc_2] nfs4_op_lock :NFS4 LOCK :DEBUG :Entering NFS v4 LOCK handler ---------------------- 11/06/2024 02:58:44 : epoch 66681f04 : minnie-shared-736 : ganesha.nfsd-23[svc_3] nfs4_op_locku :NFS4 LOCK :DEBUG :Entering NFS v4 LOCKU handler ---------------------------- 11/06/2024 02:58:44 : epoch 66681f04 : minnie-shared-736 : ganesha.nfsd-23[svc_3] nfs4_Check_Stateid :STATE :DEBUG :Check LOCKU stateid found OLD stateid OTHER=0x01000000041f68660f000000 {{CLIENTID Epoch=0x66681f04 Counter=0x00000001} StateIdCounter=0x0000000f} seqid=1, expected seqid 2 11/06/2024 02:58:44 : epoch 66681f04 : minnie-shared-736 : ganesha.nfsd-23[svc_7] nfs4_op_locku :NFS4 LOCK :DEBUG :Entering NFS v4 LOCKU handler ---------------------------- 11/06/2024 02:58:44 : epoch 66681f04 : minnie-shared-736 : ganesha.nfsd-23[svc_7] Check_nfs4_seqid :STATE :DEBUG :LOCKU: Invalid seqid 3 in request (not replay), expected seqid for {STATE_LOCK_OWNER_NFSV4 0x7f9a7c009820: clientid={0x7f9a68003300 ClientID={Epoch=0x66681f04 Counter=0x00000001} CONFIRMED Client={0x7f9a68003260 name=(60:Linux NFSv4.0 pluto.disneyworld.com/198.168.2.19) refcount=1} t_delta=0 reservations=1 refcount=3 cb_prog=1073741824 r_addr=12.7.61.42.140.53 r_netid=tcp} owner=(20:0x6c6f636b2069643a0000018a0000000000000000) confirmed=1 seqid=1 related_owner={STATE_OPEN_OWNER_NFSV4 0x7f9a64009020: clientid={0x7f9a68003300 ClientID={Epoch=0x66681f04 Counter=0x00000001} CONFIRMED Client={0x7f9a68003260 name=(60:Linux NFSv4.0 pluto.disneyworld.com/198.168.2.19) refcount=1} t_delta=0 reservations=1 refcount=3 cb_prog=1073741824 r_addr=12.7.61.42.140.53 r_netid=tcp} owner=(24:0x6f70656e2069643a0000018a000000010005df06ed3b8253) confirmed=1 seqid=3 refcount=2} refcount=3}, retu rning NFS4ERR_BAD_SEQID 11/06/2024 02:58:44 : epoch 66681f04 : minnie-shared-736 : ganesha.nfsd-23[svc_13] nfs4_op_locku :NFS4 LOCK :DEBUG :Entering NFS v4 LOCKU handler ---------------------------- 11/06/2024 02:58:44 : epoch 66681f04 : minnie-shared-736 : ganesha.nfsd-23[svc_13] Check_nfs4_seqid :STATE :DEBUG :LOCKU: Invalid seqid 3 in request (not replay), expected seqid for {STATE_LOCK_OWNER_NFSV4 0x7f9a7c009820: clientid={0x7f9a68003300 ClientID={Epoch=0x66681f04 Counter=0x00000001} CONFIRMED Client={0x7f9a68003260 name=(60:Linux NFSv4.0 pluto.disneyworld.com/198.168.2.19) refcount=1} t_delta=0 reservations=1 refcount=3 cb_prog=1073741824 r_addr=12.7.61.42.140.53 r_netid=tcp} owner=(20:0x6c6f636b2069643a0000018a0000000000000000) confirmed=1 seqid=1 related_owner={STATE_OPEN_OWNER_NFSV4 0x7f9a64009020: clientid={0x7f9a68003300 ClientID={Epoch=0x66681f04 Counter=0x00000001} CONFIRMED Client={0x7f9a68003260 name=(60:Linux NFSv4.0 pluto.disneyworld.com/198.168.2.19) refcount=1} t_delta=0 reservations=1 refcount=3 cb_prog=1073741824 r_addr=12.7.61.42.140.53 r_netid=tcp} owner=(24:0x6f70656e2069643a0000018a000000010005df06ed3b8253) confirmed=1 seqid=3 refcount=2} refcount=3}, ret urning NFS4ERR_BAD_SEQID 11/06/2024 02:58:44 : epoch 66681f04 : minnie-shared-736 : ganesha.nfsd-23[svc_11] nfs4_op_release_lockowner :NFS4 LOCK :DEBUG :Entering NFS v4 RELEASE_LOCKOWNER handler ---------------------- 11/06/2024 02:58:44 : epoch 66681f04 : minnie-shared-736 : ganesha.nfsd-23[svc_11] nfs4_op_release_lockowner :NFS4 LOCK :DEBUG :Leaving NFS v4 RELEASE_LOCKOWNER handler ----------------------- 11/06/2024 02:58:44 : epoch 66681f04 : minnie-shared-736 : ganesha.nfsd-23[svc_6] nfs4_op_close :STATE :DEBUG :Entering NFS v4 CLOSE handler ---------------------------- 11/06/2024 02:58:44 : epoch 66681f04 : minnie-shared-736 : ganesha.nfsd-23[svc_6] nfs4_op_close :STATE :DEBUG :NFS4 Close with existing locks 11/06/2024 03:05:53 : epoch 66681f04 : minnie-shared-736 : ganesha.nfsd-23[svc_16] nfs4_op_open :STATE :DEBUG :Entering NFS v4 OPEN handler ----------------------------- 11/06/2024 03:05:53 : epoch 66681f04 : minnie-shared-736 : ganesha.nfsd-23[svc_16] nfs4_op_open :STATE :DEBUG :OPEN Client id = 66681f0400000001 11/06/2024 03:05:53 : epoch 66681f04 : minnie-shared-736 : ganesha.nfsd-23[svc_16] create_nfs4_owner :STATE :DEBUG :Previously known owner {STATE_OPEN_OWNER_NFSV4 0x7f9a64009020: clientid={0x7f9a68003300 ClientID={Epoch=0x66681f04 Counter=0x00000001} CONFIRMED Client={0x7f9a68003260 name=(60:Linux NFSv4.0 pluto.disneyworld.com/198.168.2.19) refcount=1} t_delta=0 reservations=1 refcount=4 cb_prog=1073741824 r_addr=12.7.61.42.140.53 r_netid=tcp} owner=(24:0x6f70656e2069643a0000018a000000010005df06ed3b8253) confirmed=1 seqid=4 refcount=3} is being reused 11/06/2024 03:05:53 : epoch 66681f04 : minnie-shared-736 : ganesha.nfsd-23[svc_10] nfs4_op_open :STATE :DEBUG :Entering NFS v4 OPEN handler ----------------------------- 11/06/2024 03:05:53 : epoch 66681f04 : minnie-shared-736 : ganesha.nfsd-23[svc_10] nfs4_op_open :STATE :DEBUG :OPEN Client id = 66681f0400000001 11/06/2024 03:05:53 : epoch 66681f04 : minnie-shared-736 : ganesha.nfsd-23[svc_10] create_nfs4_owner :STATE :DEBUG :Previously known owner {STATE_OPEN_OWNER_NFSV4 0x7f9a64009020: clientid={0x7f9a68003300 ClientID={Epoch=0x66681f04 Counter=0x00000001} CONFIRMED Client={0x7f9a68003260 name=(60:Linux NFSv4.0 pluto.disneyworld.com/198.168.2.19) refcount=1} t_delta=0 reservations=1 refcount=4 cb_prog=1073741824 r_addr=12.7.61.42.140.53 r_netid=tcp} owner=(24:0x6f70656e2069643a0000018a000000010005df06ed3b8253) confirmed=1 seqid=5 refcount=3} is being reused 11/06/2024 03:05:53 : epoch 66681f04 : minnie-shared-736 : ganesha.nfsd-23[svc_9] nfs4_op_lock :NFS4 LOCK :DEBUG :Entering NFS v4 LOCK handler ---------------------- 11/06/2024 03:05:53 : epoch 66681f04 : minnie-shared-736 : ganesha.nfsd-23[svc_9] create_nfs4_owner :STATE :DEBUG :Previously known owner {STATE_LOCK_OWNER_NFSV4 0x7f9a7c009820: clientid={0x7f9a68003300 ClientID={Epoch=0x66681f04 Counter=0x00000001} CONFIRMED Client={0x7f9a68003260 name=(60:Linux NFSv4.0 pluto.disneyworld.com/198.168.2.19) refcount=1} t_delta=0 reservations=1 refcount=4 cb_prog=1073741824 r_addr=12.7.61.42.140.53 r_netid=tcp} owner=(20:0x6c6f636b2069643a0000018a0000000000000000) confirmed=1 seqid=1 related_owner={STATE_OPEN_OWNER_NFSV4 0x7f9a64009020: clientid={0x7f9a68003300 ClientID={Epoch=0x66681f04 Counter=0x00000001} CONFIRMED Client={0x7f9a68003260 name=(60:Linux NFSv4.0 pluto.disneyworld.com/198.168.2.19) refcount=1} t_delta=0 reservations=1 refcount=4 cb_prog=1073741824 r_addr=12.7.61.42.140.53 r_netid=tcp} owner=(24:0x6f70656e2069643a0000018a000000010005df06ed3b8253) confirmed=1 seqid=6 refcount=3} refcount=3} is being reused 11/06/2024 03:05:53 : epoch 66681f04 : minnie-shared-736 : ganesha.nfsd-23[svc_9] Check_nfs4_seqid :STATE :DEBUG :LOCK: Invalid seqid 0 in request (not replay), expected seqid for {STATE_LOCK_OWNER_NFSV4 0x7f9a7c009820: clientid={0x7f9a68003300 ClientID={Epoch=0x66681f04 Counter=0x00000001} CONFIRMED Client={0x7f9a68003260 name=(60:Linux NFSv4.0 pluto.disneyworld.com/198.168.2.19) refcount=1} t_delta=0 reservations=1 refcount=4 cb_prog=1073741824 r_addr=12.7.61.42.140.53 r_netid=tcp} owner=(20:0x6c6f636b2069643a0000018a0000000000000000) confirmed=1 seqid=1 related_owner={STATE_OPEN_OWNER_NFSV4 0x7f9a64009020: clientid={0x7f9a68003300 ClientID={Epoch=0x66681f04 Counter=0x00000001} CONFIRMED Client={0x7f9a68003260 name=(60:Linux NFSv4.0 pluto.disneyworld.com/198.168.2.19) refcount=1} t_delta=0 reservations=1 refcount=4 cb_prog=1073741824 r_addr=12.7.61.42.140.53 r_netid=tcp} owner=(24:0x6f70656e2069643a0000018a000000010005df06ed3b8253) confirmed=1 seqid=6 refcount=3} refcount=3}, retur ning NFS4ERR_BAD_SEQID 11/06/2024 03:05:53 : epoch 66681f04 : minnie-shared-736 : ganesha.nfsd-23[svc_9] nfs4_op_lock :NFS4 LOCK :DEBUG :LOCK failed to create new lock owner, re-use Lock: obj=0x7f9a8400d5f8, fileid=134, type=READ , start=0x0, end=0xffffffffffffffff, owner={STATE_OPEN_OWNER_NFSV4 0x7f9a64009020: clientid={0x7f9a68003300 ClientID={Epoch=0x66681f04 Counter=0x00000001} CONFIRMED Client={0x7f9a68003260 name=(60:Linux NFSv4.0 pluto.disneyworld.com/198.168.2.19) refcount=1} t_delta=0 reservations=1 refcount=4 cb_prog=1073741824 r_addr=12.7.61.42.140.53 r_netid=tcp} owner=(24:0x6f70656e2069643a0000018a000000010005df06ed3b8253) confirmed=1 seqid=6 refcount=3} 11/06/2024 03:05:53 : epoch 66681f04 : minnie-shared-736 : ganesha.nfsd-23[svc_11] nfs4_op_lock :NFS4 LOCK :DEBUG :Entering NFS v4 LOCK handler ---------------------- 11/06/2024 03:05:53 : epoch 66681f04 : minnie-shared-736 : ganesha.nfsd-23[svc_11] create_nfs4_owner :STATE :DEBUG :Previously known owner {STATE_LOCK_OWNER_NFSV4 0x7f9a7c009820: clientid={0x7f9a68003300 ClientID={Epoch=0x66681f04 Counter=0x00000001} CONFIRMED Client={0x7f9a68003260 name=(60:Linux NFSv4.0 pluto.disneyworld.com/198.168.2.19) refcount=1} t_delta=0 reservations=1 refcount=4 cb_prog=1073741824 r_addr=12.7.61.42.140.53 r_netid=tcp} owner=(20:0x6c6f636b2069643a0000018a0000000000000000) confirmed=1 seqid=1 related_owner={STATE_OPEN_OWNER_NFSV4 0x7f9a64009020: clientid={0x7f9a68003300 ClientID={Epoch=0x66681f04 Counter=0x00000001} CONFIRMED Client={0x7f9a68003260 name=(60:Linux NFSv4.0 pluto.disneyworld.com/198.168.2.19) refcount=1} t_delta=0 reservations=1 refcount=4 cb_prog=1073741824 r_addr=12.7.61.42.140.53 r_netid=tcp} owner=(24:0x6f70656e2069643a0000018a000000010005df06ed3b8253) confirmed=1 seqid=6 refcount=3} refcount=3} is being reused 11/06/2024 03:05:53 : epoch 66681f04 : minnie-shared-736 : ganesha.nfsd-23[svc_11] Check_nfs4_seqid :STATE :DEBUG :LOCK: Invalid seqid 0 in request (not replay), expected seqid for {STATE_LOCK_OWNER_NFSV4 0x7f9a7c009820: clientid={0x7f9a68003300 ClientID={Epoch=0x66681f04 Counter=0x00000001} CONFIRMED Client={0x7f9a68003260 name=(60:Linux NFSv4.0 pluto.disneyworld.com/198.168.2.19) refcount=1} t_delta=0 reservations=1 refcount=4 cb_prog=1073741824 r_addr=12.7.61.42.140.53 r_netid=tcp} owner=(20:0x6c6f636b2069643a0000018a0000000000000000) confirmed=1 seqid=1 related_owner={STATE_OPEN_OWNER_NFSV4 0x7f9a64009020: clientid={0x7f9a68003300 ClientID={Epoch=0x66681f04 Counter=0x00000001} CONFIRMED Client={0x7f9a68003260 name=(60:Linux NFSv4.0 pluto.disneyworld.com/198.168.2.19) refcount=1} t_delta=0 reservations=1 refcount=4 cb_prog=1073741824 r_addr=12.7.61.42.140.53 r_netid=tcp} owner=(24:0x6f70656e2069643a0000018a000000010005df06ed3b8253) confirmed=1 seqid=6 refcount=3} refcount=3}, retu rning NFS4ERR_BAD_SEQID 11/06/2024 03:05:53 : epoch 66681f04 : minnie-shared-736 : ganesha.nfsd-23[svc_11] nfs4_op_lock :NFS4 LOCK :DEBUG :LOCK failed to create new lock owner, re-use Lock: obj=0x7f9a8400d5f8, fileid=134, type=READ , start=0x0, end=0xffffffffffffffff, owner={STATE_OPEN_OWNER_NFSV4 0x7f9a64009020: clientid={0x7f9a68003300 ClientID={Epoch=0x66681f04 Counter=0x00000001} CONFIRMED Client={0x7f9a68003260 name=(60:Linux NFSv4.0 pluto.disneyworld.com/198.168.2.19) refcount=1} t_delta=0 reservations=1 refcount=4 cb_prog=1073741824 r_addr=12.7.61.42.140.53 r_netid=tcp} owner=(24:0x6f70656e2069643a0000018a000000010005df06ed3b8253) confirmed=1 seqid=6 refcount=3} 11/06/2024 03:05:53 : epoch 66681f04 : minnie-shared-736 : ganesha.nfsd-23[svc_7] nfs4_op_close :STATE :DEBUG :Entering NFS v4 CLOSE handler ---------------------------- 11/06/2024 03:05:53 : epoch 66681f04 : minnie-shared-736 : ganesha.nfsd-23[svc_7] nfs4_op_close :STATE :DEBUG :NFS4 Close with existing locks 11/06/2024 03:13:19 : epoch 66681f04 : minnie-shared-736 : ganesha.nfsd-23[svc_11] nfs4_op_open :STATE :DEBUG :Entering NFS v4 OPEN handler ----------------------------- 11/06/2024 03:13:19 : epoch 66681f04 : minnie-shared-736 : ganesha.nfsd-23[svc_11] nfs4_op_open :STATE :DEBUG :OPEN Client id = 66681f0400000001 11/06/2024 03:13:19 : epoch 66681f04 : minnie-shared-736 : ganesha.nfsd-23[svc_11] nfs4_State_Get_Obj :STATE :DEBUG :HashTable_Get returned 2 11/06/2024 03:13:19 : epoch 66681f04 : minnie-shared-736 : ganesha.nfsd-23[svc_14] nfs4_op_open :STATE :DEBUG :Entering NFS v4 OPEN handler ----------------------------- 11/06/2024 03:13:19 : epoch 66681f04 : minnie-shared-736 : ganesha.nfsd-23[svc_14] nfs4_op_open :STATE :DEBUG :OPEN Client id = 66681f0400000001 11/06/2024 03:13:19 : epoch 66681f04 : minnie-shared-736 : ganesha.nfsd-23[svc_14] create_nfs4_owner :STATE :DEBUG :Previously known owner {STATE_OPEN_OWNER_NFSV4 0x7f9a6800c1a0: clientid={0x7f9a68003300 ClientID={Epoch=0x66681f04 Counter=0x00000001} CONFIRMED Client={0x7f9a68003260 name=(60:Linux NFSv4.0 pluto.disneyworld.com/198.168.2.19) refcount=1} t_delta=0 reservations=1 refcount=5 cb_prog=1073741824 r_addr=12.7.61.42.140.53 r_netid=tcp} owner=(24:0x6f70656e2069643a0000018a000000010005df6aef133d49) confirmed=1 seqid=9 refcount=2} is being reused 11/06/2024 03:13:19 : epoch 66681f04 : minnie-shared-736 : ganesha.nfsd-23[svc_4] nfs4_op_lock :NFS4 LOCK :DEBUG :Entering NFS v4 LOCK handler ---------------------- 11/06/2024 03:13:19 : epoch 66681f04 : minnie-shared-736 : ganesha.nfsd-23[svc_4] create_nfs4_owner :NFS4 LOCK :CRIT :Related {STATE_OPEN_OWNER_NFSV4 0x7f9a6800c1a0: clientid={0x7f9a68003300 ClientID={Epoch=0x66681f04 Counter=0x00000001} CONFIRMED Client={0x7f9a68003260 name=(60:Linux NFSv4.0 pluto.disneyworld.com/198.168.2.19) refcount=1} t_delta=0 reservations=1 refcount=5 cb_prog=1073741824 r_addr=12.7.61.42.140.53 r_netid=tcp} owner=(24:0x6f70656e2069643a0000018a000000010005df6aef133d49) confirmed=1 seqid=10 refcount=2} doesn't match for {STATE_LOCK_OWNER_NFSV4 0x7f9a7c009820: clientid={0x7f9a68003300 ClientID={Epoch=0x66681f04 Counter=0x00000001} CONFIRMED Client={0x7f9a68003260 name=(60:Linux NFSv4.0 pluto.disneyworld.com/198.168.2.19) refcount=1} t_delta=0 reservations=1 refcount=5 cb_prog=1073741824 r_addr=12.7.61.42.140.53 r_netid=tcp} owner=(20:0x6c6f636b2069643a0000018a0000000000000000) confirmed=1 seqid=1 related_owner={STATE_OPEN_OWNER_NFSV4 0x7f9a64009020: clientid={0x7 f9a68003300 ClientID={Epoch=0x66681f04 Counter=0x00000001} CONFIRMED Client={0x7f9a68003260 name=(60:Linux NFSv4.0 pluto.disneyworld.com/198.168.2.19) refcount=1} t_delta=0 reservations=1 refcount=5 cb_prog=1073741824 r_addr=12.7.61.42.140.53 r_netid=tcp} owner=(24:0x6f70656e2069643a0000018a000000010005df06ed3b8253) confirmed=1 seqid=7 refcount=2} refcount=3} 11/06/2024 03:13:19 : epoch 66681f04 : minnie-shared-736 : ganesha.nfsd-23[svc_4] nfs4_op_lock :NFS4 LOCK :EVENT :LOCK failed to create new lock owner Lock: obj=0x7f9a8400d5f8, fileid=134, type=READ , start=0x0, end=0xffffffffffffffff, owner={STATE_OPEN_OWNER_NFSV4 0x7f9a6800c1a0: clientid={0x7f9a68003300 ClientID={Epoch=0x66681f04 Counter=0x00000001} CONFIRMED Client={0x7f9a68003260 name=(60:Linux NFSv4.0 pluto.disneyworld.com/198.168.2.19) refcount=1} t_delta=0 reservations=1 refcount=5 cb_prog=1073741824 r_addr=12.7.61.42.140.53 r_netid=tcp} owner=(24:0x6f70656e2069643a0000018a000000010005df6aef133d49) confirmed=1 seqid=10 refcount=2} 11/06/2024 03:13:19 : epoch 66681f04 : minnie-shared-736 : ganesha.nfsd-23[svc_13] nfs4_op_lock :NFS4 LOCK :DEBUG :Entering NFS v4 LOCK handler ---------------------- 11/06/2024 03:13:19 : epoch 66681f04 : minnie-shared-736 : ganesha.nfsd-23[svc_13] create_nfs4_owner :NFS4 LOCK :CRIT :Related {STATE_OPEN_OWNER_NFSV4 0x7f9a6800c1a0: clientid={0x7f9a68003300 ClientID={Epoch=0x66681f04 Counter=0x00000001} CONFIRMED Client={0x7f9a68003260 name=(60:Linux NFSv4.0 pluto.disneyworld.com/198.168.2.19) refcount=1} t_delta=0 reservations=1 refcount=5 cb_prog=1073741824 r_addr=12.7.61.42.140.53 r_netid=tcp} owner=(24:0x6f70656e2069643a0000018a000000010005df6aef133d49) confirmed=1 seqid=10 refcount=2} doesn't match for {STATE_LOCK_OWNER_NFSV4 0x7f9a7c009820: clientid={0x7f9a68003300 ClientID={Epoch=0x66681f04 Counter=0x00000001} CONFIRMED Client={0x7f9a68003260 name=(60:Linux NFSv4.0 pluto.disneyworld.com/198.168.2.19) refcount=1} t_delta=0 reservations=1 refcount=5 cb_prog=1073741824 r_addr=12.7.61.42.140.53 r_netid=tcp} owner=(20:0x6c6f636b2069643a0000018a0000000000000000) confirmed=1 seqid=1 related_owner={STATE_OPEN_OWNER_NFSV4 0x7f9a64009020: clientid={0x 7f9a68003300 ClientID={Epoch=0x66681f04 Counter=0x00000001} CONFIRMED Client={0x7f9a68003260 name=(60:Linux NFSv4.0 pluto.disneyworld.com/198.168.2.19) refcount=1} t_delta=0 reservations=1 refcount=5 cb_prog=1073741824 r_addr=12.7.61.42.140.53 r_netid=tcp} owner=(24:0x6f70656e2069643a0000018a000000010005df06ed3b8253) confirmed=1 seqid=7 refcount=2} refcount=3} 11/06/2024 03:13:19 : epoch 66681f04 : minnie-shared-736 : ganesha.nfsd-23[svc_13] nfs4_op_lock :NFS4 LOCK :EVENT :LOCK failed to create new lock owner Lock: obj=0x7f9a8400d5f8, fileid=134, type=READ , start=0x0, end=0xffffffffffffffff, owner={STATE_OPEN_OWNER_NFSV4 0x7f9a6800c1a0: clientid={0x7f9a68003300 ClientID={Epoch=0x66681f04 Counter=0x00000001} CONFIRMED Client={0x7f9a68003260 name=(60:Linux NFSv4.0 pluto.disneyworld.com/198.168.2.19) refcount=1} t_delta=0 reservations=1 refcount=5 cb_prog=1073741824 r_addr=12.7.61.42.140.53 r_netid=tcp} owner=(24:0x6f70656e2069643a0000018a000000010005df6aef133d49) confirmed=1 seqid=10 refcount=2} 11/06/2024 03:13:19 : epoch 66681f04 : minnie-shared-736 : ganesha.nfsd-23[svc_17] nfs4_op_close :STATE :DEBUG :Entering NFS v4 CLOSE handler ---------------------------- 11/06/2024 03:57:02 : epoch 66681f04 : minnie-shared-736 : ganesha.nfsd-23[dbus_heartbeat] release_posix_file_system :FSAL :WARN :Filesystem /etc/ganesha/abc-xyz is still claimed
participants (2)
-
Frank Filz -
pragash2here＠gmail.com