[Pvfs2-developers] iozone sanity check fails

Sam Lang slang at mcs.anl.gov
Tue Jul 18 15:04:52 EDT 2006


On Jul 18, 2006, at 1:21 PM, Sam Lang wrote:

>
> On Jul 18, 2006, at 12:54 PM, Murali Vilayannur wrote:
>
>> Hi Dean,
>> I think this might be related to an assertion failure that Julian  
>> fixed..
>> I dont know if it has been committed to tree or not yet?
>>
>
> Yep.  Committed this morning.
>

There were actually a couple other missed asserts that I neglected to  
fix in the same code.  I think I've caught all them now...let me know  
if you still have problems.

-sam

> -sam
>
>> Thanks,
>> Murali
>>
>> On Tue, 18 Jul 2006, Dean Hildebrand wrote:
>>
>>> Hi All,
>>>
>>> I'm noticing that a iozone sanity check fails on the latest cvs code
>>> with 2.6.16 (fedora core 4).  I think the server is crashing.   
>>> I'm doing
>>> this all on one node.  This works successfully with 1.5.1.
>>>
>>> In /var/log/messages:
>>> Jul 18 13:19:22 foufoune kernel: pvfs2_permission: inode:  
>>> e4225e10 mask
>>> = 1 mode = 43ff current->fsuid = 0 inode->i_uid = 0, inode->i_gid  
>>> = 0
>>> ret = 0
>>> Jul 18 13:19:22 foufoune kernel: pvfs2_permission: mode [43ff] &  
>>> mask
>>> [1] & S_IRWXO [7] = 1 == mask [1]?
>>> Jul 18 13:19:22 foufoune kernel: pvfs2_permission: inode:  
>>> e4225e10 mask
>>> = 1 mode = 43ff current->fsuid = 0 inode->i_uid = 0, inode->i_gid  
>>> = 0
>>> ret = 0
>>> Jul 18 13:19:22 foufoune kernel: pvfs2_permission: mode [43ff] &  
>>> mask
>>> [1] & S_IRWXO [7] = 1 == mask [1]?
>>> Jul 18 13:19:22 foufoune kernel: pvfs2_lookup called on a2
>>> Jul 18 13:19:22 foufoune kernel: Alloced OP (e02543a0: 121  
>>> OP_LOOKUP)
>>> Jul 18 13:19:22 foufoune kernel: pvfs2_lookup: doing lookup on a2
>>> Jul 18 13:19:22 foufoune kernel:   under 1048576,408205455  
>>> (follow=no)
>>> Jul 18 13:19:22 foufoune kernel: pvfs2: service_operation:  
>>> pvfs2_lookup
>>> e02543a0
>>> Jul 18 13:19:22 foufoune kernel: client-core: reading op tag 121  
>>> OP_LOOKUP
>>> Jul 18 13:19:22 foufoune kernel: (get) Alloced OP (e02543a0:121)
>>> Jul 18 13:19:22 foufoune kernel: pvfs2: service_operation  
>>> pvfs2_lookup
>>> returning: -2 for e02543a0.
>>> Jul 18 13:19:22 foufoune kernel: Lookup Got 0, fsid 0 (ret=-2)
>>> Jul 18 13:19:22 foufoune kernel: pvfs2_lookup: Adding *negative*  
>>> dentry
>>> e4d28914Jul 18 13:19:22 foufoune kernel:   for a2
>>> Jul 18 13:19:22 foufoune kernel: Releasing OP (e02543a0: 121)
>>> Jul 18 13:19:22 foufoune kernel: pvfs2_permission: inode:  
>>> e4225e10 mask
>>> = 3 mode = 43ff current->fsuid = 0 inode->i_uid = 0, inode->i_gid  
>>> = 0
>>> ret = 0
>>> Jul 18 13:19:22 foufoune kernel: pvfs2_create: called
>>> Jul 18 13:19:22 foufoune kernel: Alloced OP (e02543a0: 122  
>>> OP_CREATE)
>>> Jul 18 13:19:22 foufoune kernel: pvfs2: service_operation:
>>> pvfs2_create_file e02543a0
>>> Jul 18 13:19:22 foufoune kernel: client-core: reading op tag 122  
>>> OP_CREATE
>>> Jul 18 13:19:22 foufoune kernel: (get) Alloced OP (e02543a0:122)
>>> Jul 18 13:19:22 foufoune kernel: pvfs2: service_operation
>>> pvfs2_create_file returning: 0 for e02543a0.
>>> Jul 18 13:19:22 foufoune kernel: Create Got PVFS2 handle 1048573  
>>> on fsid
>>> 408205455 (ret=0)
>>> Jul 18 13:19:22 foufoune kernel: pvfs2_get_custom_inode: called
>>> Jul 18 13:19:22 foufoune kernel:   (sb is f6e98600 | MAJOR(dev)=0 |
>>> MINOR(dev)=0)
>>> Jul 18 13:19:22 foufoune kernel: pvfs2_alloc_inode: allocated  
>>> e42251f4
>>> Jul 18 13:19:22 foufoune kernel: pvfs2_read_inode: e42251f4 (inode =
>>> 1048573 | ct = 1)
>>> Jul 18 13:19:22 foufoune kernel: pvfs2_inode_getattr: called on  
>>> inode
>>> 1048573
>>> Jul 18 13:19:22 foufoune kernel: Alloced OP (e0260420: 123  
>>> OP_GETATTR)
>>> Jul 18 13:19:22 foufoune kernel: pvfs2: service_operation:
>>> pvfs2_inode_getattr e0260420
>>> Jul 18 13:19:22 foufoune kernel: client-core: reading op tag 123  
>>> OP_GETATTR
>>> Jul 18 13:19:22 foufoune kernel: (get) Alloced OP (e0260420:123)
>>> Jul 18 13:19:22 foufoune kernel: pvfs2: service_operation
>>> pvfs2_inode_getattr returning: 0 for e0260420.
>>> Jul 18 13:19:22 foufoune kernel: attrs->mask = 710007f (1048576,  
>>> objtype
>>> = 1), size = 0
>>> Jul 18 13:19:22 foufoune kernel: pvfs2: copy_attributes_to_inode:
>>> setting inode->i_mode to 8000 from 0
>>> Jul 18 13:19:22 foufoune kernel: Getattr on handle 1048573, fsid  
>>> 408205455
>>> Jul 18 13:19:22 foufoune kernel:   (inode ct = 1) returned 0
>>> Jul 18 13:19:22 foufoune kernel: Releasing OP (e0260420: 123)
>>> Jul 18 13:19:22 foufoune kernel: pvfs2_get_custom_inode: inode  
>>> e4225224
>>> allocated
>>> Jul 18 13:19:22 foufoune kernel:   (pvfs2_inode is e42251f4 | sb is
>>> f6e98600)
>>> Jul 18 13:19:22 foufoune kernel: Assigned file inode new number  
>>> of 1048573
>>> Jul 18 13:19:22 foufoune kernel: pvfs2_create_file: Instantiating
>>> Jul 18 13:19:22 foufoune kernel:  *negative* dentry e4d28914 for a2
>>> Jul 18 13:19:22 foufoune kernel: Releasing OP (e02543a0: 122)
>>> Jul 18 13:19:22 foufoune kernel: pvfs2_create: returning 0
>>> Jul 18 13:19:22 foufoune kernel: pvfs2_permission: inode:  
>>> e4225224 mask
>>> = 0 mode = 8000 current->fsuid = 0 inode->i_uid = 0, inode->i_gid  
>>> = 0
>>> ret = 0
>>> Jul 18 13:19:22 foufoune kernel: pvfs2_permission: mode [8000] &  
>>> mask
>>> [0] & S_IRWXO [7] = 0 == mask [0]?
>>> Jul 18 13:19:22 foufoune kernel: pvfs2_file_open: called on a2  
>>> (inode is
>>> 1048573)
>>> Jul 18 13:19:22 foufoune kernel: pvfs2_file_open returning  
>>> normally: 0
>>> Jul 18 13:19:22 foufoune kernel: pvfs2_setattr: called on a2
>>> Jul 18 13:19:22 foufoune kernel: pvfs2: pvfs2_truncate called on  
>>> inode
>>> 1048573 with size 0
>>> Jul 18 13:19:22 foufoune kernel: pvfs2: pvfs2_truncate_inode  
>>> 1048573:
>>> Handle is 1048573 | fs_id 408205455 | size is 0
>>> Jul 18 13:19:22 foufoune kernel: Alloced OP (e02543a0: 124  
>>> OP_TRUNCATE)
>>> Jul 18 13:19:22 foufoune kernel: pvfs2: service_operation:
>>> pvfs2_truncate_inode e02543a0
>>> Jul 18 13:19:22 foufoune kernel: client-core: reading op tag 124  
>>> OP_TRUNCATE
>>> Jul 18 13:19:32 foufoune kernel: (get) Alloced OP (e02543a0:124)
>>> Jul 18 13:19:32 foufoune kernel: pvfs2: service_operation
>>> pvfs2_truncate_inode returning: -111 for e02543a0.
>>> Jul 18 13:19:32 foufoune kernel: pvfs2: pvfs2_truncate got return  
>>> value
>>> of -111
>>> Jul 18 13:19:32 foufoune kernel: Releasing OP (e02543a0: 124)
>>> Jul 18 13:19:32 foufoune kernel: pvfs2_setattr: inode_setattr  
>>> returned 0
>>> Jul 18 13:19:32 foufoune kernel: Alloced OP (e02543a0: 125  
>>> OP_SETATTR)
>>> Jul 18 13:19:32 foufoune kernel: mode is 32768 | translated perms  
>>> is 0
>>> Jul 18 13:19:32 foufoune kernel: pvfs2: service_operation:
>>> pvfs2_inode_setattr e02543a0
>>> Jul 18 13:19:32 foufoune kernel: client-core: reading op tag 125  
>>> OP_SETATTR
>>> Jul 18 13:19:42 foufoune kernel: (get) Alloced OP (e02543a0:125)
>>> Jul 18 13:19:42 foufoune kernel: pvfs2: service_operation
>>> pvfs2_inode_setattr returning: -111 for e02543a0.
>>> Jul 18 13:19:42 foufoune kernel: pvfs2_inode_setattr: returning -111
>>> Jul 18 13:19:42 foufoune kernel: Releasing OP (e02543a0: 125)
>>> Jul 18 13:19:42 foufoune kernel: pvfs2_setattr: returning -111
>>> Jul 18 13:19:42 foufoune kernel: pvfs2_file_release: called on a2
>>>
>>> I attached the /tmp/pvfs2-client.log:
>>>
>>> I didn't have logging on the server, but there isn't any errors  
>>> in the
>>> server log.
>>>
>>> The code that fails (from iozone.c) is below.  I just ran 'iozone  
>>> -aec
>>> -i 0 -i 1 -+n -f /mnt/pvfs2/a2'
>>> /* Sanity check */
>>> /* Some filesystems do not behave correctly and fail
>>>  * when this sequence is performned. This is a very
>>>  * bad thing. It breaks many applications and lurks
>>>  * around quietly. This code should never get
>>>  * triggered, but in the case of running iozone on
>>>  * an NFS client, the filesystem type on the server
>>>  * that is being exported can cause this failure.
>>>  * If this failure happens, then the NFS client is
>>>  * going to going to have problems, but the acutal
>>>  * problem is the filesystem on the NFS server.
>>>  * It's not NFS, it's the local filesystem on the
>>>  * NFS server that is not correctly permitting
>>>  * the sequence to function.
>>>  */
>>>         if((fd = I_OPEN(filename, (int)O_CREAT|O_WRONLY,0))<0)
>>>         {
>>>                 printf("\nCan not open temp file: %s\n",
>>>                         filename);
>>>                 perror("open");
>>>                 exit(44);
>>>         }
>>>         wval=ftruncate(fd,0);
>>>         if(wval < 0)
>>>         {
>>>                 printf("Sanity check failed. Do not deploy this
>>> filesystem in a production environment !\n");
>>>                 exit(44);
>>>         }
>>>         close(fd);
>>>         unlink(filename);
>>> /* Sanity check */
>>>
>>> --
>>> Dean Hildebrand
>>> Ph.D. Candidate
>>> University of Michigan
>>>
>>>
>> _______________________________________________
>> Pvfs2-developers mailing list
>> Pvfs2-developers at beowulf-underground.org
>> http://www.beowulf-underground.org/mailman/listinfo/pvfs2-developers
>>
>
> _______________________________________________
> Pvfs2-developers mailing list
> Pvfs2-developers at beowulf-underground.org
> http://www.beowulf-underground.org/mailman/listinfo/pvfs2-developers
>



More information about the Pvfs2-developers mailing list