Open andamian opened 7 years ago
Using the latest install of vofs I did not get this failure. Is this failure intermittent and dependent on the server that is being communicated with? Would be good to have some way in vofs to force it to talk to a particular server when doing puts.
Problem seems to be related to flushing files of size 0 to the server that takes excessive time. I remember that there is a work around for pushing files of size 0 in vos. Isn't vofs using that mechanism?
To reproduce it just run the touch command on the vofs mount directory and follow the logs.
unique: 4, opcode: LOOKUP (1), nodeid: 2, insize: 48, pid: 28078 LOOKUP /sometest/abc.txt getattr /sometest/abc.txt DEBUG 2017-08-18 16:05:58,826 123145506111488 vos-3.0.0b6 vofs.call.265 -> getattr ('/sometest/abc.txt', None) DEBUG 2017-08-18 16:05:58,826 123145506111488 vos-3.0.0b6 vofs.get_node.410 requesting node /sometest/abc.txt from VOSpace. Force: False DEBUG 2017-08-18 16:05:58,831 123145506111488 vos-3.0.0b6 ws.send.420 Sending request <PreparedRequest [GET]> to server. DEBUG 2017-08-18 16:05:58,850 123145506111488 vos-3.0.0b6 ws.send.420 Sending request <PreparedRequest [GET]> to server. DEBUG 2017-08-18 16:05:58,871 123145506111488 vos-3.0.0b6 ws._get_url.328 Resolved URL: https://www.canfar.phys.uvic.ca/vospace/nodes DEBUG 2017-08-18 16:05:58,873 123145506111488 vos-3.0.0b6 ws.send.420 Sending request <PreparedRequest [GET]> to server. DEBUG 2017-08-18 16:05:58,969 123145506111488 vos-3.0.0b6 vofs.call.279 NodeNotFound: vos://cadc.nrc.ca!vospace/CADCRegtest1/atest/sometest/abc.txt
File "/Users/adriand/work/github/vostools/vofs/.tox/py34/lib/python3.4/site-packages/fuse.py", line 495, in _wrapper return func(*args, *kwargs) or 0 File "/Users/adriand/work/github/vostools/vofs/.tox/py34/lib/python3.4/site-packages/fuse.py", line 511, in getattr return self.fgetattr(path, buf, None) File "/Users/adriand/work/github/vostools/vofs/.tox/py34/lib/python3.4/site-packages/fuse.py", line 759, in fgetattr attrs = self.operations('getattr', self._decode_optional_path(path), fh) File "/Users/adriand/Documents/work/github/vostools/vofs/vofs/vofs.py", line 270, in call ret = getattr(self, op)(args) File "/Users/adriand/Documents/work/github/vostools/vofs/vofs/vofs.py", line 425, in getattr return attr is not None and attr or self.getNode(path, limit=0, force=False).attr File "/Users/adriand/Documents/work/github/vostools/vofs/vofs/vofs.py", line 411, in get_node node = self.client.get_node(path, force=force, limit=limit) File "/Users/adriand/Documents/work/github/vostools/vos/vos/vos.py", line 1581, in get_node vo_xml_string = vo_fobj.read().decode('UTF-8') File "/Users/adriand/Documents/work/github/vostools/vos/vos/vos.py", line 1005, in read self.resp = self.connector.session.send(self.request, stream=True, verify=False) File "/Users/adriand/work/github/vostools/vofs/.tox/py34/lib/python3.4/site-packages/cadcutils/net/ws.py", line 425, in send self.check_status(response) File "/Users/adriand/work/github/vostools/vofs/.tox/py34/lib/python3.4/site-packages/cadcutils/net/ws.py", line 472, in check_status raise exceptions.NotFoundException(orig_exception=e) File "/Users/adriand/work/github/vostools/vofs/.tox/py34/lib/python3.4/site-packages/cadcutils/exceptions.py", line 134, in init HttpException.init(self, msg, orig_exception) File "/Users/adriand/work/github/vostools/vofs/.tox/py34/lib/python3.4/site-packages/cadcutils/exceptions.py", line 98, in init self._msg = '{}\n{}'.format(self._msg, ''.join(traceback.format_stack()))
DEBUG 2017-08-18 16:05:58,969 123145506111488 vos-3.0.0b6 vofs.call.280 <- getattr 'NodeNotFound: vos://cadc.nrc.ca!vospace/CADCRegtest1/atest/sometest/abc.txt\n\n File "/Users/adriand/work/github/vostools/vofs/.tox/py34/lib/python3.4/site-packages/fuse.py", line 495, in _wrapper\n return func(*args, *kwargs) or 0\n File "/Users/adriand/work/github/vostools/vofs/.tox/py34/lib/python3.4/site-packages/fuse.py", line 511, in getattr\n return self.fgetattr(path, buf, None)\n File "/Users/adriand/work/github/vostools/vofs/.tox/py34/lib/python3.4/site-packages/fuse.py", line 759, in fgetattr\n attrs = self.operations(\'getattr\', self._decode_optional_path(path), fh)\n File "/Users/adriand/Documents/work/github/vostools/vofs/vofs/vofs.py", line 270, in call\n ret = getattr(self, op)(args)\n File "/Users/adriand/Documents/work/github/vostools/vofs/vofs/vofs.py", line 425, in getattr\n return attr is not None and attr or self.getNode(path, limit=0, force=False).attr\n File "/Users/adriand/Documents/work/github/vostools/vofs/vofs/vofs.py", line 411, in get_node\n node = self.client.get_node(path, force=force, limit=limit)\n File "/Users/adriand/Documents/work/github/vostools/vos/vos/vos.py", line 1581, in get_node\n vo_xml_string = vo_fobj.read().decode(\'UTF-8\')\n File "/Users/adriand/Documents/work/github/vostools/vos/vos/vos.py", line 1005, in read\n self.resp = self.connector.session.send(self.request, stream=True, verify=False)\n File "/Users/adriand/work/github/vostools/vofs/.tox/py34/lib/python3.4/site-packages/cadcutils/net/ws.py", line 425, in send\n self.check_status(response)\n File "/Users/adriand/work/github/vostools/vofs/.tox/py34/lib/python3.4/site-packages/cadcutils/net/ws.py", line 472, in check_status\n raise exceptions.NotFoundException(orig_exception=e)\n File "/Users/adriand/work/github/vostools/vofs/.tox/py34/lib/python3.4/site-packages/cadcutils/exceptions.py", line 134, in init\n HttpException.init(self, msg, orig_exception)\n File "/Users/adriand/work/github/vostools/vofs/.tox/py34/lib/python3.4/site-packages/cadcutils/exceptions.py", line 98, in init\n self._msg = \'{}\n{}\'.format(self._msg, \'\'.join(traceback.format_stack()))\n' unique: 4, error: -2 (No such file or directory), outsize: 16 unique: 2, opcode: LOOKUP (1), nodeid: 2, insize: 48, pid: 28078 LOOKUP /sometest/abc.txt getattr /sometest/abc.txt DEBUG 2017-08-18 16:05:58,970 123145429950464 vos-3.0.0b6 vofs.call.265 -> getattr ('/sometest/abc.txt', None) DEBUG 2017-08-18 16:05:58,970 123145429950464 vos-3.0.0b6 vofs.get_node.410 requesting node /sometest/abc.txt from VOSpace. Force: False DEBUG 2017-08-18 16:05:58,970 123145429950464 vos-3.0.0b6 ws._get_url.328 Resolved URL: https://www.canfar.phys.uvic.ca/vospace/nodes DEBUG 2017-08-18 16:05:58,973 123145429950464 vos-3.0.0b6 ws.send.420 Sending request <PreparedRequest [GET]> to server. DEBUG 2017-08-18 16:05:59,063 123145429950464 vos-3.0.0b6 vofs.call.279 NodeNotFound: vos://cadc.nrc.ca!vospace/CADCRegtest1/atest/sometest/abc.txt
File "/Users/adriand/work/github/vostools/vofs/.tox/py34/lib/python3.4/site-packages/fuse.py", line 495, in _wrapper return func(*args, *kwargs) or 0 File "/Users/adriand/work/github/vostools/vofs/.tox/py34/lib/python3.4/site-packages/fuse.py", line 511, in getattr return self.fgetattr(path, buf, None) File "/Users/adriand/work/github/vostools/vofs/.tox/py34/lib/python3.4/site-packages/fuse.py", line 759, in fgetattr attrs = self.operations('getattr', self._decode_optional_path(path), fh) File "/Users/adriand/Documents/work/github/vostools/vofs/vofs/vofs.py", line 270, in call ret = getattr(self, op)(args) File "/Users/adriand/Documents/work/github/vostools/vofs/vofs/vofs.py", line 425, in getattr return attr is not None and attr or self.getNode(path, limit=0, force=False).attr File "/Users/adriand/Documents/work/github/vostools/vofs/vofs/vofs.py", line 411, in get_node node = self.client.get_node(path, force=force, limit=limit) File "/Users/adriand/Documents/work/github/vostools/vos/vos/vos.py", line 1581, in get_node vo_xml_string = vo_fobj.read().decode('UTF-8') File "/Users/adriand/Documents/work/github/vostools/vos/vos/vos.py", line 1005, in read self.resp = self.connector.session.send(self.request, stream=True, verify=False) File "/Users/adriand/work/github/vostools/vofs/.tox/py34/lib/python3.4/site-packages/cadcutils/net/ws.py", line 425, in send self.check_status(response) File "/Users/adriand/work/github/vostools/vofs/.tox/py34/lib/python3.4/site-packages/cadcutils/net/ws.py", line 472, in check_status raise exceptions.NotFoundException(orig_exception=e) File "/Users/adriand/work/github/vostools/vofs/.tox/py34/lib/python3.4/site-packages/cadcutils/exceptions.py", line 134, in init HttpException.init(self, msg, orig_exception) File "/Users/adriand/work/github/vostools/vofs/.tox/py34/lib/python3.4/site-packages/cadcutils/exceptions.py", line 98, in init self._msg = '{}\n{}'.format(self._msg, ''.join(traceback.format_stack()))
DEBUG 2017-08-18 16:05:59,063 123145429950464 vos-3.0.0b6 vofs.call.280 <- getattr 'NodeNotFound: vos://cadc.nrc.ca!vospace/CADCRegtest1/atest/sometest/abc.txt\n\n File "/Users/adriand/work/github/vostools/vofs/.tox/py34/lib/python3.4/site-packages/fuse.py", line 495, in _wrapper\n return func(*args, *kwargs) or 0\n File "/Users/adriand/work/github/vostools/vofs/.tox/py34/lib/python3.4/site-packages/fuse.py", line 511, in getattr\n return self.fgetattr(path, buf, None)\n File "/Users/adriand/work/github/vostools/vofs/.tox/py34/lib/python3.4/site-packages/fuse.py", line 759, in fgetattr\n attrs = self.operations(\'getattr\', self._decode_optional_path(path), fh)\n File "/Users/adriand/Documents/work/github/vostools/vofs/vofs/vofs.py", line 270, in call\n ret = getattr(self, op)(args)\n File "/Users/adriand/Documents/work/github/vostools/vofs/vofs/vofs.py", line 425, in getattr\n return attr is not None and attr or self.getNode(path, limit=0, force=False).attr\n File "/Users/adriand/Documents/work/github/vostools/vofs/vofs/vofs.py", line 411, in get_node\n node = self.client.get_node(path, force=force, limit=limit)\n File "/Users/adriand/Documents/work/github/vostools/vos/vos/vos.py", line 1581, in get_node\n vo_xml_string = vo_fobj.read().decode(\'UTF-8\')\n File "/Users/adriand/Documents/work/github/vostools/vos/vos/vos.py", line 1005, in read\n self.resp = self.connector.session.send(self.request, stream=True, verify=False)\n File "/Users/adriand/work/github/vostools/vofs/.tox/py34/lib/python3.4/site-packages/cadcutils/net/ws.py", line 425, in send\n self.check_status(response)\n File "/Users/adriand/work/github/vostools/vofs/.tox/py34/lib/python3.4/site-packages/cadcutils/net/ws.py", line 472, in check_status\n raise exceptions.NotFoundException(orig_exception=e)\n File "/Users/adriand/work/github/vostools/vofs/.tox/py34/lib/python3.4/site-packages/cadcutils/exceptions.py", line 134, in init\n HttpException.init(self, msg, orig_exception)\n File "/Users/adriand/work/github/vostools/vofs/.tox/py34/lib/python3.4/site-packages/cadcutils/exceptions.py", line 98, in init\n self._msg = \'{}\n{}\'.format(self._msg, \'\'.join(traceback.format_stack()))\n' unique: 2, error: -2 (No such file or directory), outsize: 16 unique: 9, opcode: GETATTR (3), nodeid: 2, insize: 56, pid: 28078 getattr /sometest DEBUG 2017-08-18 16:05:59,064 123145487331328 vos-3.0.0b6 vofs.call.265 -> getattr ('/sometest', None) DEBUG 2017-08-18 16:05:59,064 123145487331328 vos-3.0.0b6 vofs.get_node.410 requesting node /sometest from VOSpace. Force: False DEBUG 2017-08-18 16:05:59,064 123145487331328 vos-3.0.0b6 vofs.get_node.412 Got node sometest DEBUG 2017-08-18 16:05:59,064 123145487331328 vos-3.0.0b6 vofs.call.279 {'st_mtime': 1503086592.0, 'st_mode': 16837, 'st_uid': 501, 'st_ctime': 1503086592.0, 'st_atime': 1503097294.125806, 'st_blocks': 0, 'st_gid': 20, 'st_size': 6, 'st_nlink': 2} DEBUG 2017-08-18 16:05:59,064 123145487331328 vos-3.0.0b6 vofs.call.280 <- getattr {'st_mtime': 1503086592.0, 'st_mode': 16837, 'st_uid': 501, 'st_ctime': 1503086592.0, 'st_atime': 1503097294.125806, 'st_blocks': 0, 'st_gid': 20, 'st_size': 6, 'st_nlink': 2} unique: 9, success, outsize: 136 unique: 7, opcode: CREATE (35), nodeid: 2, insize: 64, pid: 28078 create flags: 0xa02 /sometest/abc.txt 0100644 umask=0000 DEBUG 2017-08-18 16:05:59,064 123145483575296 vos-3.0.0b6 vofs.call.265 -> create ('/sometest/abc.txt', 33188) DEBUG 2017-08-18 16:05:59,065 123145483575296 vos-3.0.0b6 vofs.create.347 Creating a node: /sometest/abc.txt with flags 33188 DEBUG 2017-08-18 16:05:59,065 123145483575296 vos-3.0.0b6 ws._get_url.328 Resolved URL: https://www.canfar.phys.uvic.ca/vospace/nodes DEBUG 2017-08-18 16:05:59,069 123145483575296 vos-3.0.0b6 ws.send.420 Sending request <PreparedRequest [PUT]> to server. DEBUG 2017-08-18 16:05:59,174 123145483575296 vos-3.0.0b6 vofs.get_node.410 requesting node /sometest from VOSpace. Force: False DEBUG 2017-08-18 16:05:59,174 123145483575296 vos-3.0.0b6 vofs.get_node.412 Got node sometest DEBUG 2017-08-18 16:05:59,174 123145483575296 vos-3.0.0b6 vofs.open.456 Opening /sometest/abc.txt with flags a DEBUG 2017-08-18 16:05:59,174 123145483575296 vos-3.0.0b6 vofs.get_node.410 requesting node /sometest/abc.txt from VOSpace. Force: False DEBUG 2017-08-18 16:05:59,175 123145483575296 vos-3.0.0b6 ws._get_url.328 Resolved URL: https://www.canfar.phys.uvic.ca/vospace/nodes DEBUG 2017-08-18 16:05:59,177 123145483575296 vos-3.0.0b6 ws.send.420 Sending request <PreparedRequest [GET]> to server. DEBUG 2017-08-18 16:05:59,271 123145483575296 vos-3.0.0b6 vofs.get_node.412 Got node abc.txt DEBUG 2017-08-18 16:05:59,271 123145483575296 vos-3.0.0b6 vofs.get_node.410 requesting node /sometest from VOSpace. Force: False DEBUG 2017-08-18 16:05:59,271 123145483575296 vos-3.0.0b6 vofs.get_node.412 Got node sometest DEBUG 2017-08-18 16:05:59,271 123145483575296 vos-3.0.0b6 vofs.open.527 IO Proxy initialized:Path:/sometest/abc.txt Size:0 MD5:None condition:<vofs.CadcCache.CacheCondition object at 0x114d5dc50> in backing. DEBUG 2017-08-18 16:05:59,272 123145483575296 vos-3.0.0b6 CadcCache.setHeader.832 set header called with size: 0 and md5: d41d8cd98f00b204e9800998ecf8427e DEBUG 2017-08-18 16:05:59,273 123145483575296 vos-3.0.0b6 CadcCache.fullyCached.817 setHeader set to fullyCached to: False DEBUG 2017-08-18 16:05:59,274 123145483575296 vos-3.0.0b6 CadcCache.fullyCached.817 setHeader set to fullyCached to: True DEBUG 2017-08-18 16:05:59,274 123145483575296 vos-3.0.0b6 vofs.open.532 Creating file:/sometest/abc.txt in backing. DEBUG 2017-08-18 16:05:59,274 123145483575296 vos-3.0.0b6 vofs.get_node.410 requesting node /sometest/abc.txt from VOSpace. Force: False DEBUG 2017-08-18 16:05:59,275 123145483575296 vos-3.0.0b6 vofs.get_node.412 Got node abc.txt DEBUG 2017-08-18 16:05:59,275 123145483575296 vos-3.0.0b6 CadcCache.setHeader.832 set header called with size: 0 and md5: None DEBUG 2017-08-18 16:05:59,275 123145483575296 vos-3.0.0b6 vofs.call.279 4517565552 DEBUG 2017-08-18 16:05:59,275 123145483575296 vos-3.0.0b6 vofs.call.280 <- create 4517565552 create[4517565552] flags: 0xa02 /sometest/abc.txt getattr /sometest/abc.txt DEBUG 2017-08-18 16:05:59,275 123145483575296 vos-3.0.0b6 vofs.call.265 -> getattr ('/sometest/abc.txt', None) DEBUG 2017-08-18 16:05:59,276 123145483575296 vos-3.0.0b6 vofs.call.279 {'st_dev': 16777220, 'st_mode': 33261, 'st_ctime': 1503097559.0, 'st_mtime_ns': 1503097559000000000, 'st_gid': 0, 'st_size': 0, 'st_ino': 6888127, 'st_birthtime': 1503097559.0, 'n_unnamed_fields': 3, 'count': <built-in method count of os.stat_result object at 0x10e56e828>, 'st_blksize': 4096, 'st_flags': 0, 'n_sequence_fields': 10, 'st_rdev': 0, 'st_atime_ns': 1503097559000000000, 'st_uid': 501, 'st_atime': 1503097559.0, 'st_blocks': 0, 'st_mtime': 1503097559.0, 'st_ctime_ns': 1503097559000000000, 'n_fields': 22, 'index': <built-in method index of os.stat_result object at 0x10e56e828>, 'st_gen': 0, 'st_nlink': 1} DEBUG 2017-08-18 16:05:59,276 123145483575296 vos-3.0.0b6 vofs.call.280 <- getattr {'st_dev': 16777220, 'st_mode': 33261, 'st_ctime': 1503097559.0, 'st_mtime_ns': 1503097559000000000, 'st_gid': 0, 'st_size': 0, 'st_ino': 6888127, 'st_birthtime': 1503097559.0, 'n_unnamed_fields': 3, 'count': <built-in method count of os.stat_result object at 0x10e56e828>, 'st_blksize': 4096, 'st_flags': 0, 'n_sequence_fields': 10, 'st_rdev': 0, 'st_atime_ns': 1503097559000000000, 'st_uid': 501, 'st_atime': 1503097559.0, 'st_blocks': 0, 'st_mtime': 1503097559.0, 'st_ctime_ns': 1503097559000000000, 'n_fields': 22, 'index': <built-in method index of os.stat_result object at 0x10e56e828>, 'st_gen': 0, 'st_nlink': 1} NODEID: 12 unique: 7, success, outsize: 176 unique: 3, opcode: FLUSH (25), nodeid: 12, insize: 64, pid: 28078 flush[4517565552] DEBUG 2017-08-18 16:05:59,276 123145484111872 vos-3.0.0b6 vofs.call.265 -> flush ('/sometest/abc.txt', 4517565552) DEBUG 2017-08-18 16:05:59,276 123145484111872 vos-3.0.0b6 vofs.flush.615 flushing 4517565552 DEBUG 2017-08-18 16:05:59,277 123145466736640 vos-3.0.0b6 vofs.writeToBacking.69 PUSHING /tmp/vos_cache/data/sometest/abc.txt to VOSpace @ /sometest/abc.txt DEBUG 2017-08-18 16:05:59,277 123145466736640 vos-3.0.0b6 vofs.writeToBacking.70 opening a new vo file for /sometest/abc.txt DEBUG 2017-08-18 16:05:59,277 123145466736640 vos-3.0.0b6 vofs.get_node.410 requesting node /sometest/abc.txt from VOSpace. Force: False DEBUG 2017-08-18 16:05:59,278 123145466736640 vos-3.0.0b6 vofs.get_node.412 Got node abc.txt DEBUG 2017-08-18 16:05:59,279 123145466736640 vos-3.0.0b6 ws._get_url.328 Resolved URL: https://www.canfar.phys.uvic.ca/vospace/synctrans DEBUG 2017-08-18 16:05:59,279 123145466736640 vos-3.0.0b6 ws._get_url.328 Resolved URL: https://www.canfar.phys.uvic.ca/vospace/synctrans DEBUG 2017-08-18 16:05:59,287 123145466736640 vos-3.0.0b6 ws.send.420 Sending request <PreparedRequest [GET]> to server. unique: 8, opcode: GETATTR (3), nodeid: 2, insize: 56, pid: 45 getattr /sometest DEBUG 2017-08-18 16:05:59,348 123145489477632 vos-3.0.0b6 vofs.call.265 -> getattr ('/sometest', None) DEBUG 2017-08-18 16:05:59,348 123145489477632 vos-3.0.0b6 vofs.get_node.410 requesting node /sometest from VOSpace. Force: False DEBUG 2017-08-18 16:05:59,349 123145489477632 vos-3.0.0b6 vofs.get_node.412 Got node sometest DEBUG 2017-08-18 16:05:59,349 123145489477632 vos-3.0.0b6 vofs.call.279 {'st_mtime': 1503086592.0, 'st_mode': 16837, 'st_uid': 501, 'st_ctime': 1503086592.0, 'st_atime': 1503097294.125806, 'st_blocks': 0, 'st_gid': 20, 'st_size': 6, 'st_nlink': 2} DEBUG 2017-08-18 16:05:59,349 123145489477632 vos-3.0.0b6 vofs.call.280 <- getattr {'st_mtime': 1503086592.0, 'st_mode': 16837, 'st_uid': 501, 'st_ctime': 1503086592.0, 'st_atime': 1503097294.125806, 'st_blocks': 0, 'st_gid': 20, 'st_size': 6, 'st_nlink': 2} unique: 8, success, outsize: 136 DEBUG 2017-08-18 16:05:59,478 123145466736640 vos-3.0.0b6 vos.get_node_url.1736 Transfer Server said: b'' DEBUG 2017-08-18 16:05:59,487 123145466736640 vos-3.0.0b6 ws.send.420 Sending request <PreparedRequest [PUT]> to server. CRITICAL 2017-08-18 16:06:29,278 123145484111872 vos-3.0.0b6 vofs.flush.621 'Condition variable timeout' CRITICAL 2017-08-18 16:06:29,278 123145484111872 vos-3.0.0b6 vofs.flush.622 Push to VOSpace reached FUSE timeout, continuing VOSpace push in background. DEBUG 2017-08-18 16:06:29,278 123145484111872 vos-3.0.0b6 vofs.call.279 0 DEBUG 2017-08-18 16:06:29,278 123145484111872 vos-3.0.0b6 vofs.call.280 <- flush 0 unique: 3, success, outsize: 16 unique: 6, opcode: RELEASE (18), nodeid: 12, insize: 64, pid: 28078 release[4517565552] flags: 0x0 DEBUG 2017-08-18 16:06:29,278 123145486258176 vos-3.0.0b6 vofs.call.265 -> release ('/sometest/abc.txt', 4517565552) DEBUG 2017-08-18 16:06:29,278 123145486258176 vos-3.0.0b6 vofs.release.633 releasing file 4517565552 DEBUG 2017-08-18 16:06:29,279 123145486258176 vos-3.0.0b6 vofs.call.279 None DEBUG 2017-08-18 16:06:29,279 123145486258176 vos-3.0.0b6 vofs.call.280 <- release None unique: 6, success, outsize: 16 unique: 26, opcode: GETATTR (3), nodeid: 12, insize: 56, pid: 45 getattr /sometest/abc.txt DEBUG 2017-08-18 16:06:29,279 123145498062848 vos-3.0.0b6 vofs.call.265 -> getattr ('/sometest/abc.txt', None) DEBUG 2017-08-18 16:06:29,279 123145498062848 vos-3.0.0b6 vofs.call.279 {'st_dev': 16777220, 'st_mode': 33261, 'st_ctime': 1503097559.0, 'st_mtime_ns': 1503097559000000000, 'st_gid': 0, 'st_size': 0, 'st_ino': 6888127, 'st_birthtime': 1503097559.0, 'n_unnamed_fields': 3, 'count': <built-in method count of os.stat_result object at 0x10e56e9e8>, 'st_blksize': 4096, 'st_flags': 0, 'n_sequence_fields': 10, 'st_rdev': 0, 'st_atime_ns': 1503097559000000000, 'st_uid': 501, 'st_atime': 1503097559.0, 'st_blocks': 0, 'st_mtime': 1503097559.0, 'st_ctime_ns': 1503097559000000000, 'n_fields': 22, 'index': <built-in method index of os.stat_result object at 0x10e56e9e8>, 'st_gen': 0, 'st_nlink': 1} DEBUG 2017-08-18 16:06:29,279 123145498062848 vos-3.0.0b6 vofs.call.280 <- getattr {'st_dev': 16777220, 'st_mode': 33261, 'st_ctime': 1503097559.0, 'st_mtime_ns': 1503097559000000000, 'st_gid': 0, 'st_size': 0, 'st_ino': 6888127, 'st_birthtime': 1503097559.0, 'n_unnamed_fields': 3, 'count': <built-in method count of os.stat_result object at 0x10e56e9e8>, 'st_blksize': 4096, 'st_flags': 0, 'n_sequence_fields': 10, 'st_rdev': 0, 'st_atime_ns': 1503097559000000000, 'st_uid': 501, 'st_atime': 1503097559.0, 'st_blocks': 0, 'st_mtime': 1503097559.0, 'st_ctime_ns': 1503097559000000000, 'n_fields': 22, 'index': <built-in method index of os.stat_result object at 0x10e56e9e8>, 'st_gen': 0, 'st_nlink': 1} unique: 26, success, outsize: 136