Project

General

Profile

Download (41.8 KB)

Bug #12684 ยป fuse.log

Brett Smith, 05/08/2023 08:49 PM

 
1 
2023-05-05 16:33:45 arvados.arv-mount[107911] DEBUG: arv-mount debugging enabled
2 
2023-05-05 16:33:45 arvados.arv-mount[107911] INFO: /home/brett/.cache/arvados-test/VENV3DIR/bin/arv-mount 2.7.0.dev20230504223618 started
3 
2023-05-05 16:33:45 arvados.arv-mount[107911] INFO: enable write is True
4 
2023-05-05 16:33:45 arvados.arv-mount[107911] INFO: Storage classes requested for new collections: default
5 
2023-05-05 16:33:45 arvados.arvados_fuse[107911] DEBUG: arv-mount lookup: parent_inode 1 name '.Trash' not found
6 
2023-05-05 16:33:45 arvados.arvados_fuse[107911] DEBUG: arv-mount lookup: parent_inode 1 name '.Trash-1000' not found
7 
2023-05-05 16:33:45 arvados.arvados_fuse[107911] DEBUG: arv-mount lookup: parent_inode 1 name 'by_id' inode 4
8 
2023-05-05 16:33:45 arvados.arvados_fuse[107911] DEBUG: arv-mount lookup: parent_inode 4 name 'README' inode 5
9 
2023-05-05 16:33:45 arvados.arvados_fuse[107911] DEBUG: arv-mount lookup: parent_inode 1 name 'by_id' inode 4
10 
2023-05-05 16:33:45 arvados.arvados_fuse[107911] DEBUG: InodeCache touched inode 6 (size 0) (uuid 8ea82759a04e5ce160fb3b0c7f771b1d+48) total now 0 (1 entries)
11 
2023-05-05 16:33:45 arvados.arvados_fuse[107911] DEBUG: Updating collection 8ea82759a04e5ce160fb3b0c7f771b1d+48 inode 6
12 
2023-05-05 16:34:53 arvados.arv-mount[109400] DEBUG: arv-mount debugging enabled
13 
2023-05-05 16:34:53 arvados.arv-mount[109400] INFO: /home/brett/.cache/arvados-test/VENV3DIR/bin/arv-mount 2.7.0.dev20230504223618 started
14 
2023-05-05 16:34:53 arvados.arv-mount[109400] INFO: enable write is True
15 
2023-05-05 16:34:53 arvados.arv-mount[109400] INFO: Storage classes requested for new collections: default
16 
2023-05-05 16:34:53 arvados.arvados_fuse[109400] DEBUG: arv-mount lookup: parent_inode 1 name '.Trash' not found
17 
2023-05-05 16:34:53 arvados.arvados_fuse[109400] DEBUG: arv-mount lookup: parent_inode 1 name '.Trash-1000' not found
18 
2023-05-05 16:34:53 arvados.arvados_fuse[109400] DEBUG: arv-mount lookup: parent_inode 1 name 'by_id' inode 4
19 
2023-05-05 16:34:53 arvados.arvados_fuse[109400] DEBUG: arv-mount lookup: parent_inode 4 name 'README' inode 5
20 
2023-05-05 16:34:53 arvados.arvados_fuse[109400] DEBUG: arv-mount lookup: parent_inode 1 name 'by_id' inode 4
21 
2023-05-05 16:34:53 arvados.arvados_fuse[109400] DEBUG: InodeCache touched inode 6 (size 0) (uuid b9138a30f7928d48e576e3dd5c79a10f+132) total now 0 (1 entries)
22 
2023-05-05 16:34:53 arvados.arvados_fuse[109400] DEBUG: Updating collection b9138a30f7928d48e576e3dd5c79a10f+132 inode 6
23 
2023-05-05 16:34:53 arvados.arvados_fuse[109400] DEBUG: InodeCache touched inode 6 (size 23424) (uuid b9138a30f7928d48e576e3dd5c79a10f+132) total now 23424 (1 entries)
24 
2023-05-05 16:34:53 arvados.arvados_fuse[109400] DEBUG: arv-mount lookup: parent_inode 4 name 'b9138a30f7928d48e576e3dd5c79a10f+132' inode 6
25 
2023-05-05 16:34:53 arvados.arvados_fuse[109400] DEBUG: arv-mount opendir: inode 6
26 
2023-05-05 16:34:53 arvados.arvados_fuse[109400] DEBUG: InodeCache touched inode 6 (size 23424) (uuid b9138a30f7928d48e576e3dd5c79a10f+132) total now 23424 (1 entries)
27 
2023-05-05 16:34:53 arvados.arvados_fuse[109400] DEBUG: arv-mount readdir: fh 0 off 0
28 
2023-05-05 16:34:53 arvados.arvados_fuse[109400] DEBUG: arv-mount readdir: fh 0 off 3
29 
2023-05-05 16:34:53 arvados.arvados_fuse[109400] DEBUG: arv-mount lookup: parent_inode 1 name 'by_uuid' inode 2
30 
2023-05-05 16:34:53 arvados.arvados_fuse[109400] DEBUG: InodeCache touched inode 8 (size 0) (uuid z1111-4zz18-97johkv32otyfan) total now 23424 (2 entries)
31 
2023-05-05 16:34:53 arvados.arvados_fuse[109400] DEBUG: Updating collection z1111-4zz18-97johkv32otyfan inode 8
32 
2023-05-05 16:34:53 arvados.arvados_fuse[109400] DEBUG: InodeCache touched inode 8 (size 0) (uuid z1111-4zz18-97johkv32otyfan) total now 23424 (2 entries)
33 
2023-05-05 16:34:53 arvados.arvados_fuse[109400] DEBUG: arv-mount lookup: parent_inode 2 name 'z1111-4zz18-97johkv32otyfan' inode 8
34 
2023-05-05 16:34:53 arvados.arvados_fuse[109400] DEBUG: InodeCache touched inode 8 (size 0) (uuid z1111-4zz18-97johkv32otyfan) total now 23424 (2 entries)
35 
2023-05-05 16:34:53 arvados.arvados_fuse[109400] DEBUG: arv-mount lookup: parent_inode 8 name 'image.sif' not found
36 
2023-05-05 16:34:53 arvados.arvados_fuse[109400] DEBUG: arv-mount lookup: parent_inode 1 name 'by_id' inode 4
37 
2023-05-05 16:34:53 arvados.arvados_fuse[109400] DEBUG: arv-mount lookup: parent_inode 4 name 'b9138a30f7928d48e576e3dd5c79a10f+132' inode 6
38 
2023-05-05 16:34:53 arvados.arvados_fuse[109400] DEBUG: InodeCache touched inode 6 (size 23424) (uuid b9138a30f7928d48e576e3dd5c79a10f+132) total now 23424 (2 entries)
39 
2023-05-05 16:34:53 arvados.arvados_fuse[109400] DEBUG: arv-mount lookup: parent_inode 6 name 'sha256:388056c9a6838deea3792e8f00705b35b439cf57b3c9c2634fb4e95cfc896de6.tar' inode 7
40 
2023-05-05 16:34:53 arvados.arvados_fuse[109400] DEBUG: arv-mount lookup: parent_inode 1 name 'by_uuid' inode 2
41 
2023-05-05 16:34:53 arvados.arvados_fuse[109400] DEBUG: arv-mount lookup: parent_inode 2 name 'z1111-4zz18-97johkv32otyfan' inode 8
42 
2023-05-05 16:34:53 arvados.arvados_fuse[109400] DEBUG: InodeCache touched inode 8 (size 0) (uuid z1111-4zz18-97johkv32otyfan) total now 23424 (2 entries)
43 
2023-05-05 16:34:53 arvados.arvados_fuse[109400] DEBUG: arv-mount lookup: parent_inode 8 name 'image.sif' not found
44 
2023-05-05 16:34:53 arvados.arvados_fuse[109400] DEBUG: arv-mount lookup: parent_inode 1 name 'by_id' inode 4
45 
2023-05-05 16:34:53 arvados.arvados_fuse[109400] DEBUG: arv-mount lookup: parent_inode 4 name 'b9138a30f7928d48e576e3dd5c79a10f+132' inode 6
46 
2023-05-05 16:34:53 arvados.arvados_fuse[109400] DEBUG: InodeCache touched inode 6 (size 23424) (uuid b9138a30f7928d48e576e3dd5c79a10f+132) total now 23424 (2 entries)
47 
2023-05-05 16:34:53 arvados.arvados_fuse[109400] DEBUG: arv-mount lookup: parent_inode 6 name 'sha256:388056c9a6838deea3792e8f00705b35b439cf57b3c9c2634fb4e95cfc896de6.tar' inode 7
48 
2023-05-05 16:34:53 arvados.arvados_fuse[109400] DEBUG: InodeCache touched inode 6 (size 23424) (uuid b9138a30f7928d48e576e3dd5c79a10f+132) total now 23424 (2 entries)
49 
2023-05-05 16:34:53 arvados.arvados_fuse[109400] DEBUG: arv-mount open inode 7 flags 8000 fh 1
50 
2023-05-05 16:34:53 arvados.arvados_fuse[109400] DEBUG: arv-mount read fh 1 off 0 size 16384
51 
2023-05-05 16:34:53 arvados.keep[109400] DEBUG: {'z1111-bi6l4-dfa3067b14b9481e': {'href': '/keep_services/z1111-bi6l4-dfa3067b14b9481e', 'kind': 'arvados#keepService', 'etag': 'b9t411vl7m2u5wafh65wzzyx1', 'uuid': 'z1111-bi6l4-dfa3067b14b9481e', 'owner_uuid': 'z1111-tpzed-000000000000000', 'created_at': '2023-05-05T20:33:34.807694000Z', 'modified_by_client_uuid': None, 'modified_by_user_uuid': 'z1111-tpzed-000000000000000', 'modified_at': '2023-05-05T20:33:34.807694000Z', 'service_host': '127.0.0.11', 'service_port': 33869, 'service_ssl_flag': False, 'service_type': 'disk', 'read_only': False, '_service_root': 'http://127.0.0.11:33869/'}, 'z1111-bi6l4-241d13bbbacd1c83': {'href': '/keep_services/z1111-bi6l4-241d13bbbacd1c83', 'kind': 'arvados#keepService', 'etag': '94ry1i0km2ypva2qcst1p7fvi', 'uuid': 'z1111-bi6l4-241d13bbbacd1c83', 'owner_uuid': 'z1111-tpzed-000000000000000', 'created_at': '2023-05-05T20:33:34.807694000Z', 'modified_by_client_uuid': None, 'modified_by_user_uuid': 'z1111-tpzed-000000000000000', 'modified_at': '2023-05-05T20:33:34.807694000Z', 'service_host': '127.0.0.11', 'service_port': 37019, 'service_ssl_flag': False, 'service_type': 'disk', 'read_only': False, '_service_root': 'http://127.0.0.11:37019/'}}
52 
2023-05-05 16:34:53 arvados.keep[109400] DEBUG: 686583e7f8ed6e564c9d8f05424112fb+1458176+A575b31b64a2cbbbe5563ebb38270b697ef61ce24@6467dd6d: ['http://127.0.0.11:37019/', 'http://127.0.0.11:33869/']
53 
2023-05-05 16:34:53 arvados.keep[109400] DEBUG: Request: GET http://127.0.0.11:37019/686583e7f8ed6e564c9d8f05424112fb+1458176+A575b31b64a2cbbbe5563ebb38270b697ef61ce24@6467dd6d
54 
2023-05-05 16:34:53 arvados.keep[109400] INFO: GET 200: 1458176 bytes in 4.210710525512695 msec (330.259 MiB/sec)
55 
2023-05-05 16:34:53 arvados.arvados_fuse[109400] DEBUG: arv-mount lookup: parent_inode 1 name 'by_id' inode 4
56 
2023-05-05 16:34:53 arvados.arvados_fuse[109400] DEBUG: arv-mount lookup: parent_inode 4 name 'b9138a30f7928d48e576e3dd5c79a10f+132' inode 6
57 
2023-05-05 16:34:53 arvados.arvados_fuse[109400] DEBUG: InodeCache touched inode 6 (size 23424) (uuid b9138a30f7928d48e576e3dd5c79a10f+132) total now 23424 (2 entries)
58 
2023-05-05 16:34:53 arvados.arvados_fuse[109400] DEBUG: arv-mount lookup: parent_inode 6 name 'sha256:388056c9a6838deea3792e8f00705b35b439cf57b3c9c2634fb4e95cfc896de6.tar' inode 7
59 
2023-05-05 16:34:53 arvados.arvados_fuse[109400] DEBUG: InodeCache touched inode 6 (size 23424) (uuid b9138a30f7928d48e576e3dd5c79a10f+132) total now 23424 (2 entries)
60 
2023-05-05 16:34:53 arvados.arvados_fuse[109400] DEBUG: arv-mount open inode 7 flags 8000 fh 2
61 
2023-05-05 16:34:53 arvados.arvados_fuse[109400] DEBUG: arv-mount read fh 2 off 16384 size 32768
62 
2023-05-05 16:34:53 arvados.arvados_fuse[109400] DEBUG: arv-mount read fh 2 off 1454080 size 4096
63 
2023-05-05 16:34:53 arvados.arvados_fuse[109400] DEBUG: arv-mount release fh 2
64 
2023-05-05 16:34:53 arvados.arvados_fuse[109400] DEBUG: arv-mount release fh 1
65 
2023-05-05 16:34:53 arvados.arvados_fuse[109400] DEBUG: arv-mount lookup: parent_inode 1 name 'by_id' inode 4
66 
2023-05-05 16:34:53 arvados.arvados_fuse[109400] DEBUG: arv-mount lookup: parent_inode 4 name 'b9138a30f7928d48e576e3dd5c79a10f+132' inode 6
67 
2023-05-05 16:34:53 arvados.arvados_fuse[109400] DEBUG: InodeCache touched inode 6 (size 23424) (uuid b9138a30f7928d48e576e3dd5c79a10f+132) total now 23424 (2 entries)
68 
2023-05-05 16:34:53 arvados.arvados_fuse[109400] DEBUG: arv-mount lookup: parent_inode 6 name 'sha256:388056c9a6838deea3792e8f00705b35b439cf57b3c9c2634fb4e95cfc896de6.tar' inode 7
69 
2023-05-05 16:34:53 arvados.arvados_fuse[109400] DEBUG: InodeCache touched inode 6 (size 23424) (uuid b9138a30f7928d48e576e3dd5c79a10f+132) total now 23424 (2 entries)
70 
2023-05-05 16:34:53 arvados.arvados_fuse[109400] DEBUG: arv-mount open inode 7 flags 8000 fh 3
71 
2023-05-05 16:34:53 arvados.arvados_fuse[109400] DEBUG: arv-mount release fh 3
72 
2023-05-05 16:34:53 arvados.arvados_fuse[109400] DEBUG: arv-mount lookup: parent_inode 1 name 'by_id' inode 4
73 
2023-05-05 16:34:53 arvados.arvados_fuse[109400] DEBUG: arv-mount lookup: parent_inode 4 name 'b9138a30f7928d48e576e3dd5c79a10f+132' inode 6
74 
2023-05-05 16:34:53 arvados.arvados_fuse[109400] DEBUG: InodeCache touched inode 6 (size 23424) (uuid b9138a30f7928d48e576e3dd5c79a10f+132) total now 23424 (2 entries)
75 
2023-05-05 16:34:53 arvados.arvados_fuse[109400] DEBUG: arv-mount lookup: parent_inode 6 name 'sha256:388056c9a6838deea3792e8f00705b35b439cf57b3c9c2634fb4e95cfc896de6.tar' inode 7
76 
2023-05-05 16:34:53 arvados.arvados_fuse[109400] DEBUG: InodeCache touched inode 6 (size 23424) (uuid b9138a30f7928d48e576e3dd5c79a10f+132) total now 23424 (2 entries)
77 
2023-05-05 16:34:53 arvados.arvados_fuse[109400] DEBUG: arv-mount open inode 7 flags 8000 fh 4
78 
2023-05-05 16:34:53 arvados.arvados_fuse[109400] DEBUG: arv-mount release fh 4
79 
2023-05-05 16:34:53 arvados.arvados_fuse[109400] DEBUG: arv-mount lookup: parent_inode 1 name 'by_id' inode 4
80 
2023-05-05 16:34:53 arvados.arvados_fuse[109400] DEBUG: arv-mount lookup: parent_inode 4 name 'b9138a30f7928d48e576e3dd5c79a10f+132' inode 6
81 
2023-05-05 16:34:53 arvados.arvados_fuse[109400] DEBUG: InodeCache touched inode 6 (size 23424) (uuid b9138a30f7928d48e576e3dd5c79a10f+132) total now 23424 (2 entries)
82 
2023-05-05 16:34:53 arvados.arvados_fuse[109400] DEBUG: arv-mount lookup: parent_inode 6 name 'sha256:388056c9a6838deea3792e8f00705b35b439cf57b3c9c2634fb4e95cfc896de6.tar' inode 7
83 
2023-05-05 16:34:53 arvados.arvados_fuse[109400] DEBUG: InodeCache touched inode 6 (size 23424) (uuid b9138a30f7928d48e576e3dd5c79a10f+132) total now 23424 (2 entries)
84 
2023-05-05 16:34:53 arvados.arvados_fuse[109400] DEBUG: arv-mount open inode 7 flags 8000 fh 5
85 
2023-05-05 16:34:53 arvados.arvados_fuse[109400] DEBUG: arv-mount lookup: parent_inode 1 name 'by_id' inode 4
86 
2023-05-05 16:34:53 arvados.arvados_fuse[109400] DEBUG: arv-mount lookup: parent_inode 4 name 'b9138a30f7928d48e576e3dd5c79a10f+132' inode 6
87 
2023-05-05 16:34:53 arvados.arvados_fuse[109400] DEBUG: InodeCache touched inode 6 (size 23424) (uuid b9138a30f7928d48e576e3dd5c79a10f+132) total now 23424 (2 entries)
88 
2023-05-05 16:34:53 arvados.arvados_fuse[109400] DEBUG: arv-mount lookup: parent_inode 6 name 'sha256:388056c9a6838deea3792e8f00705b35b439cf57b3c9c2634fb4e95cfc896de6.tar' inode 7
89 
2023-05-05 16:34:53 arvados.arvados_fuse[109400] DEBUG: InodeCache touched inode 6 (size 23424) (uuid b9138a30f7928d48e576e3dd5c79a10f+132) total now 23424 (2 entries)
90 
2023-05-05 16:34:53 arvados.arvados_fuse[109400] DEBUG: arv-mount open inode 7 flags 8000 fh 6
91 
2023-05-05 16:34:53 arvados.arvados_fuse[109400] DEBUG: arv-mount release fh 6
92 
2023-05-05 16:34:53 arvados.arvados_fuse[109400] DEBUG: arv-mount release fh 5
93 
2023-05-05 16:34:53 arvados.arvados_fuse[109400] DEBUG: arv-mount lookup: parent_inode 1 name 'by_id' inode 4
94 
2023-05-05 16:34:53 arvados.arvados_fuse[109400] DEBUG: arv-mount lookup: parent_inode 4 name 'b9138a30f7928d48e576e3dd5c79a10f+132' inode 6
95 
2023-05-05 16:34:53 arvados.arvados_fuse[109400] DEBUG: InodeCache touched inode 6 (size 23424) (uuid b9138a30f7928d48e576e3dd5c79a10f+132) total now 23424 (2 entries)
96 
2023-05-05 16:34:53 arvados.arvados_fuse[109400] DEBUG: arv-mount lookup: parent_inode 6 name 'sha256:388056c9a6838deea3792e8f00705b35b439cf57b3c9c2634fb4e95cfc896de6.tar' inode 7
97 
2023-05-05 16:34:53 arvados.arvados_fuse[109400] DEBUG: InodeCache touched inode 6 (size 23424) (uuid b9138a30f7928d48e576e3dd5c79a10f+132) total now 23424 (2 entries)
98 
2023-05-05 16:34:53 arvados.arvados_fuse[109400] DEBUG: arv-mount open inode 7 flags 8000 fh 7
99 
2023-05-05 16:34:53 arvados.arvados_fuse[109400] DEBUG: arv-mount release fh 7
100 
2023-05-05 16:34:53 arvados.arvados_fuse[109400] DEBUG: arv-mount lookup: parent_inode 1 name 'by_id' inode 4
101 
2023-05-05 16:34:53 arvados.arvados_fuse[109400] DEBUG: arv-mount lookup: parent_inode 4 name 'b9138a30f7928d48e576e3dd5c79a10f+132' inode 6
102 
2023-05-05 16:34:53 arvados.arvados_fuse[109400] DEBUG: InodeCache touched inode 6 (size 23424) (uuid b9138a30f7928d48e576e3dd5c79a10f+132) total now 23424 (2 entries)
103 
2023-05-05 16:34:53 arvados.arvados_fuse[109400] DEBUG: arv-mount lookup: parent_inode 6 name 'sha256:388056c9a6838deea3792e8f00705b35b439cf57b3c9c2634fb4e95cfc896de6.tar' inode 7
104 
2023-05-05 16:34:53 arvados.arvados_fuse[109400] DEBUG: InodeCache touched inode 6 (size 23424) (uuid b9138a30f7928d48e576e3dd5c79a10f+132) total now 23424 (2 entries)
105 
2023-05-05 16:34:53 arvados.arvados_fuse[109400] DEBUG: arv-mount open inode 7 flags 8000 fh 8
106 
2023-05-05 16:34:53 arvados.arvados_fuse[109400] DEBUG: arv-mount release fh 8
107 
2023-05-05 16:34:53 arvados.arvados_fuse[109400] DEBUG: arv-mount lookup: parent_inode 1 name 'by_id' inode 4
108 
2023-05-05 16:34:53 arvados.arvados_fuse[109400] DEBUG: arv-mount lookup: parent_inode 4 name 'b9138a30f7928d48e576e3dd5c79a10f+132' inode 6
109 
2023-05-05 16:34:53 arvados.arvados_fuse[109400] DEBUG: InodeCache touched inode 6 (size 23424) (uuid b9138a30f7928d48e576e3dd5c79a10f+132) total now 23424 (2 entries)
110 
2023-05-05 16:34:53 arvados.arvados_fuse[109400] DEBUG: arv-mount lookup: parent_inode 6 name 'sha256:388056c9a6838deea3792e8f00705b35b439cf57b3c9c2634fb4e95cfc896de6.tar' inode 7
111 
2023-05-05 16:34:53 arvados.arvados_fuse[109400] DEBUG: InodeCache touched inode 6 (size 23424) (uuid b9138a30f7928d48e576e3dd5c79a10f+132) total now 23424 (2 entries)
112 
2023-05-05 16:34:53 arvados.arvados_fuse[109400] DEBUG: arv-mount open inode 7 flags 8000 fh 9
113 
2023-05-05 16:34:53 arvados.arvados_fuse[109400] DEBUG: arv-mount read fh 9 off 49152 size 131072
114 
2023-05-05 16:34:53 arvados.arvados_fuse[109400] DEBUG: arv-mount read fh 9 off 180224 size 131072
115 
2023-05-05 16:34:53 arvados.arvados_fuse[109400] DEBUG: arv-mount read fh 9 off 311296 size 131072
116 
2023-05-05 16:34:53 arvados.arvados_fuse[109400] DEBUG: arv-mount read fh 9 off 442368 size 131072
117 
2023-05-05 16:34:53 arvados.arvados_fuse[109400] DEBUG: arv-mount read fh 9 off 573440 size 131072
118 
2023-05-05 16:34:53 arvados.arvados_fuse[109400] DEBUG: arv-mount read fh 9 off 704512 size 131072
119 
2023-05-05 16:34:53 arvados.arvados_fuse[109400] DEBUG: arv-mount read fh 9 off 835584 size 131072
120 
2023-05-05 16:34:53 arvados.arvados_fuse[109400] DEBUG: arv-mount read fh 9 off 966656 size 131072
121 
2023-05-05 16:34:53 arvados.arvados_fuse[109400] DEBUG: arv-mount read fh 9 off 1097728 size 131072
122 
2023-05-05 16:34:53 arvados.arvados_fuse[109400] DEBUG: arv-mount read fh 9 off 1228800 size 131072
123 
2023-05-05 16:34:53 arvados.arvados_fuse[109400] DEBUG: arv-mount read fh 9 off 1359872 size 94208
124 
2023-05-05 16:34:53 arvados.arvados_fuse[109400] DEBUG: arv-mount release fh 9
125 
2023-05-05 16:34:54 arvados.arvados_fuse[109400] DEBUG: arv-mount lookup: parent_inode 1 name 'by_uuid' inode 2
126 
2023-05-05 16:34:54 arvados.arvados_fuse[109400] DEBUG: arv-mount lookup: parent_inode 2 name 'z1111-4zz18-97johkv32otyfan' inode 8
127 
2023-05-05 16:34:54 arvados.arvados_fuse[109400] DEBUG: InodeCache touched inode 8 (size 0) (uuid z1111-4zz18-97johkv32otyfan) total now 23424 (2 entries)
128 
2023-05-05 16:34:54 arvados.arvados_fuse[109400] DEBUG: arv-mount lookup: parent_inode 8 name 'image.sif' not found
129 
2023-05-05 16:34:54 arvados.arvados_fuse[109400] DEBUG: arv-mount lookup: parent_inode 1 name 'by_uuid' inode 2
130 
2023-05-05 16:34:54 arvados.arvados_fuse[109400] DEBUG: arv-mount lookup: parent_inode 2 name 'z1111-4zz18-97johkv32otyfan' inode 8
131 
2023-05-05 16:34:54 arvados.arvados_fuse[109400] DEBUG: InodeCache touched inode 8 (size 0) (uuid z1111-4zz18-97johkv32otyfan) total now 23424 (2 entries)
132 
2023-05-05 16:34:54 arvados.arvados_fuse[109400] DEBUG: arv-mount lookup: parent_inode 8 name 'image.sif' not found
133 
2023-05-05 16:34:54 arvados.arvados_fuse[109400] DEBUG: arv-mount lookup: parent_inode 1 name 'by_uuid' inode 2
134 
2023-05-05 16:34:54 arvados.arvados_fuse[109400] DEBUG: arv-mount lookup: parent_inode 2 name 'z1111-4zz18-97johkv32otyfan' inode 8
135 
2023-05-05 16:34:54 arvados.arvados_fuse[109400] DEBUG: InodeCache touched inode 8 (size 0) (uuid z1111-4zz18-97johkv32otyfan) total now 23424 (2 entries)
136 
2023-05-05 16:34:54 arvados.arvados_fuse[109400] DEBUG: arv-mount lookup: parent_inode 8 name 'image.sif' not found
137 
2023-05-05 16:34:54 arvados.arvados_fuse[109400] DEBUG: arv-mount create: parent_inode 8 'image.sif' 100700
138 
2023-05-05 16:34:54 arvados.arvados_fuse[109400] DEBUG: InodeCache touched inode 8 (size 0) (uuid z1111-4zz18-97johkv32otyfan) total now 23424 (2 entries)
139 
2023-05-05 16:34:54 arvados.arvados_fuse[109400] DEBUG: arv-mount write 10 32768 112
140 
2023-05-05 16:34:54 arvados.arvados_fuse[109400] DEBUG: arv-mount write 10 36864 2038
141 
2023-05-05 16:34:54 arvados.arvados_fuse[109400] DEBUG: arv-mount write 10 40960 90
142 
2023-05-05 16:34:54 arvados.arvados_fuse[109400] DEBUG: arv-mount write 10 45056 32768
143 
2023-05-05 16:34:54 arvados.arvados_fuse[109400] DEBUG: arv-mount write 10 77824 32768
144 
2023-05-05 16:34:54 arvados.arvados_fuse[109400] DEBUG: arv-mount write 10 110592 32768
145 
2023-05-05 16:34:54 arvados.arvados_fuse[109400] DEBUG: arv-mount write 10 143360 32768
146 
2023-05-05 16:34:54 arvados.arvados_fuse[109400] DEBUG: arv-mount write 10 176128 32768
147 
2023-05-05 16:34:54 arvados.arvados_fuse[109400] DEBUG: arv-mount write 10 208896 32768
148 
2023-05-05 16:34:54 arvados.arvados_fuse[109400] DEBUG: arv-mount write 10 241664 32768
149 
2023-05-05 16:34:54 arvados.arvados_fuse[109400] DEBUG: arv-mount write 10 274432 32768
150 
2023-05-05 16:34:54 arvados.arvados_fuse[109400] DEBUG: arv-mount write 10 307200 32768
151 
2023-05-05 16:34:54 arvados.arvados_fuse[109400] DEBUG: arv-mount write 10 339968 32768
152 
2023-05-05 16:34:54 arvados.arvados_fuse[109400] DEBUG: arv-mount write 10 372736 32768
153 
2023-05-05 16:34:54 arvados.arvados_fuse[109400] DEBUG: arv-mount write 10 405504 32768
154 
2023-05-05 16:34:54 arvados.arvados_fuse[109400] DEBUG: arv-mount write 10 438272 32768
155 
2023-05-05 16:34:54 arvados.arvados_fuse[109400] DEBUG: arv-mount write 10 471040 32768
156 
2023-05-05 16:34:54 arvados.arvados_fuse[109400] DEBUG: arv-mount write 10 503808 32768
157 
2023-05-05 16:34:54 arvados.arvados_fuse[109400] DEBUG: arv-mount write 10 536576 32768
158 
2023-05-05 16:34:54 arvados.arvados_fuse[109400] DEBUG: arv-mount write 10 569344 32768
159 
2023-05-05 16:34:54 arvados.arvados_fuse[109400] DEBUG: arv-mount write 10 602112 32768
160 
2023-05-05 16:34:54 arvados.arvados_fuse[109400] DEBUG: arv-mount write 10 634880 32768
161 
2023-05-05 16:34:54 arvados.arvados_fuse[109400] DEBUG: arv-mount write 10 667648 32768
162 
2023-05-05 16:34:54 arvados.arvados_fuse[109400] DEBUG: arv-mount write 10 700416 32768
163 
2023-05-05 16:34:54 arvados.arvados_fuse[109400] DEBUG: arv-mount write 10 733184 32768
164 
2023-05-05 16:34:54 arvados.arvados_fuse[109400] DEBUG: arv-mount write 10 765952 24576
165 
2023-05-05 16:34:54 arvados.arvados_fuse[109400] DEBUG: arv-mount write 10 4096 28080
166 
2023-05-05 16:34:54 arvados.arvados_fuse[109400] DEBUG: arv-mount write 10 0 128
167 
2023-05-05 16:34:54 arvados.keep[109400] DEBUG: c4c9bfd05d839602a7022ea303d6a811+775920: ['http://127.0.0.11:33869/', 'http://127.0.0.11:37019/']
168 
2023-05-05 16:34:54 arvados.keep[109400] DEBUG: Pool max threads is 2
169 
2023-05-05 16:34:54 arvados.keep[109400] DEBUG: Request: PUT http://127.0.0.11:33869/c4c9bfd05d839602a7022ea303d6a811
170 
2023-05-05 16:34:54 arvados.keep[109400] DEBUG: Request: PUT http://127.0.0.11:37019/c4c9bfd05d839602a7022ea303d6a811
171 
2023-05-05 16:34:54 arvados.keep[109400] INFO: PUT 200: 775920 bytes in 3.526449203491211 msec (209.836 MiB/sec)
172 
2023-05-05 16:34:54 arvados.keep[109400] DEBUG: KeepWriterThread <KeepWriterThread(Thread-36, started daemon 140364623111936)> succeeded c4c9bfd05d839602a7022ea303d6a811+775920 http://127.0.0.11:33869/
173 
2023-05-05 16:34:54 arvados.keep[109400] INFO: PUT 200: 775920 bytes in 5.240678787231445 msec (141.198 MiB/sec)
174 
2023-05-05 16:34:54 arvados.keep[109400] DEBUG: KeepWriterThread <KeepWriterThread(Thread-37, started daemon 140364614719232)> succeeded c4c9bfd05d839602a7022ea303d6a811+775920 http://127.0.0.11:37019/
175 
2023-05-05 16:34:54 arvados.keep[109400] DEBUG: 7f614da9329cd3aebf59b91aadc30bf0+67108864: ['http://127.0.0.11:33869/', 'http://127.0.0.11:37019/']
176 
2023-05-05 16:34:54 arvados.keep[109400] DEBUG: Pool max threads is 2
177 
2023-05-05 16:34:54 arvados.keep[109400] DEBUG: Request: PUT http://127.0.0.11:33869/7f614da9329cd3aebf59b91aadc30bf0
178 
2023-05-05 16:34:54 arvados.keep[109400] DEBUG: Request: PUT http://127.0.0.11:37019/7f614da9329cd3aebf59b91aadc30bf0
179 
2023-05-05 16:34:54 arvados.keep[109400] INFO: PUT 200: 67108864 bytes in 169.9972152709961 msec (376.477 MiB/sec)
180 
2023-05-05 16:34:54 arvados.keep[109400] DEBUG: KeepWriterThread <KeepWriterThread(Thread-39, started daemon 140364623111936)> succeeded 7f614da9329cd3aebf59b91aadc30bf0+67108864 http://127.0.0.11:37019/
181 
2023-05-05 16:34:54 arvados.keep[109400] INFO: PUT 200: 67108864 bytes in 179.23855781555176 msec (357.066 MiB/sec)
182 
2023-05-05 16:34:54 arvados.keep[109400] DEBUG: KeepWriterThread <KeepWriterThread(Thread-38, started daemon 140364614719232)> succeeded 7f614da9329cd3aebf59b91aadc30bf0+67108864 http://127.0.0.11:33869/
183 
2023-05-05 16:34:54 arvados.arvados_fuse[109400] DEBUG: arv-mount release fh 10
184 
2023-05-05 16:34:54 arvados.arvados_fuse[109400] DEBUG: arv-mount release fh 0
185 
2023-05-05 16:34:54 arvados.arvados_fuse[109400] DEBUG: arv-mount lookup: parent_inode 1 name 'by_id' inode 4
186 
2023-05-05 16:34:54 arvados.arvados_fuse[109400] DEBUG: arv-mount lookup: parent_inode 1 name 'by_id' inode 4
187 
2023-05-05 16:34:54 arvados.arvados_fuse[109400] DEBUG: InodeCache touched inode 10 (size 0) (uuid 4465083aae54f79028d8d291e0dbbcfe+312) total now 23424 (3 entries)
188 
2023-05-05 16:34:54 arvados.arvados_fuse[109400] DEBUG: Updating collection 4465083aae54f79028d8d291e0dbbcfe+312 inode 10
189 
2023-05-05 16:34:54 arvados.arvados_fuse[109400] DEBUG: InodeCache touched inode 10 (size 52992) (uuid 4465083aae54f79028d8d291e0dbbcfe+312) total now 76416 (3 entries)
190 
2023-05-05 16:34:54 arvados.arvados_fuse[109400] DEBUG: arv-mount lookup: parent_inode 4 name '4465083aae54f79028d8d291e0dbbcfe+312' inode 10
191 
2023-05-05 16:34:54 arvados.arvados_fuse[109400] DEBUG: arv-mount lookup: parent_inode 1 name 'by_id' inode 4
192 
2023-05-05 16:34:54 arvados.arvados_fuse[109400] DEBUG: arv-mount lookup: parent_inode 4 name '4465083aae54f79028d8d291e0dbbcfe+312' inode 10
193 
2023-05-05 16:34:54 arvados.arvados_fuse[109400] DEBUG: InodeCache touched inode 10 (size 52992) (uuid 4465083aae54f79028d8d291e0dbbcfe+312) total now 76416 (3 entries)
194 
2023-05-05 16:34:54 arvados.arvados_fuse[109400] DEBUG: arv-mount lookup: parent_inode 10 name 'image.sif' inode 11
195 
2023-05-05 16:34:54 arvados.arvados_fuse[109400] DEBUG: arv-mount lookup: parent_inode 1 name 'by_id' inode 4
196 
2023-05-05 16:34:54 arvados.arvados_fuse[109400] DEBUG: arv-mount lookup: parent_inode 4 name '4465083aae54f79028d8d291e0dbbcfe+312' inode 10
197 
2023-05-05 16:34:54 arvados.arvados_fuse[109400] DEBUG: InodeCache touched inode 10 (size 52992) (uuid 4465083aae54f79028d8d291e0dbbcfe+312) total now 76416 (3 entries)
198 
2023-05-05 16:34:54 arvados.arvados_fuse[109400] DEBUG: arv-mount lookup: parent_inode 10 name 'image.sif' inode 11
199 
2023-05-05 16:34:54 arvados.arvados_fuse[109400] DEBUG: InodeCache touched inode 10 (size 52992) (uuid 4465083aae54f79028d8d291e0dbbcfe+312) total now 76416 (3 entries)
200 
2023-05-05 16:34:54 arvados.arvados_fuse[109400] DEBUG: arv-mount open inode 11 flags 8000 fh 11
201 
2023-05-05 16:34:54 arvados.arvados_fuse[109400] DEBUG: arv-mount release fh 11
202 
2023-05-05 16:34:54 arvados.arvados_fuse[109400] DEBUG: arv-mount lookup: parent_inode 1 name 'by_id' inode 4
203 
2023-05-05 16:34:54 arvados.arvados_fuse[109400] DEBUG: arv-mount lookup: parent_inode 4 name '4465083aae54f79028d8d291e0dbbcfe+312' inode 10
204 
2023-05-05 16:34:54 arvados.arvados_fuse[109400] DEBUG: InodeCache touched inode 10 (size 52992) (uuid 4465083aae54f79028d8d291e0dbbcfe+312) total now 76416 (3 entries)
205 
2023-05-05 16:34:54 arvados.arvados_fuse[109400] DEBUG: arv-mount lookup: parent_inode 10 name 'image.sif' inode 11
206 
2023-05-05 16:34:54 arvados.arvados_fuse[109400] DEBUG: InodeCache touched inode 10 (size 52992) (uuid 4465083aae54f79028d8d291e0dbbcfe+312) total now 76416 (3 entries)
207 
2023-05-05 16:34:54 arvados.arvados_fuse[109400] DEBUG: arv-mount open inode 11 flags 8000 fh 12
208 
2023-05-05 16:34:54 arvados.arvados_fuse[109400] DEBUG: arv-mount read fh 12 off 0 size 16384
209 
2023-05-05 16:34:54 arvados.keep[109400] DEBUG: c4c9bfd05d839602a7022ea303d6a811+775920+Ac1321bf785550fd11b4c8fad2711c3e4b2b23ed7@6467dd6e: ['http://127.0.0.11:33869/', 'http://127.0.0.11:37019/']
210 
2023-05-05 16:34:54 arvados.keep[109400] DEBUG: Request: GET http://127.0.0.11:33869/c4c9bfd05d839602a7022ea303d6a811+775920+Ac1321bf785550fd11b4c8fad2711c3e4b2b23ed7@6467dd6e
211 
2023-05-05 16:34:54 arvados.keep[109400] INFO: GET 200: 775920 bytes in 3.519773483276367 msec (210.234 MiB/sec)
212 
2023-05-05 16:34:54 arvados.keep[109400] DEBUG: 7f614da9329cd3aebf59b91aadc30bf0+67108864+A54d46a964bbf337b28fdd7b6ff18b4230933c223@6467dd6e: ['http://127.0.0.11:33869/', 'http://127.0.0.11:37019/']
213 
2023-05-05 16:34:54 arvados.keep[109400] DEBUG: Request: GET http://127.0.0.11:33869/7f614da9329cd3aebf59b91aadc30bf0+67108864+A54d46a964bbf337b28fdd7b6ff18b4230933c223@6467dd6e
214 
2023-05-05 16:34:54 arvados.keep[109400] INFO: GET 200: 67108864 bytes in 196.4552402496338 msec (325.774 MiB/sec)
215 
2023-05-05 16:34:54 arvados.keep[109400] DEBUG: c4c9bfd05d839602a7022ea303d6a811+775920+Ac1321bf785550fd11b4c8fad2711c3e4b2b23ed7@6467dd6e: ['http://127.0.0.11:33869/', 'http://127.0.0.11:37019/']
216 
2023-05-05 16:34:54 arvados.keep[109400] DEBUG: Request: GET http://127.0.0.11:33869/c4c9bfd05d839602a7022ea303d6a811+775920+Ac1321bf785550fd11b4c8fad2711c3e4b2b23ed7@6467dd6e
217 
2023-05-05 16:34:54 arvados.keep[109400] INFO: GET 200: 775920 bytes in 4.062175750732422 msec (182.162 MiB/sec)
218 
2023-05-05 16:34:54 arvados.arvados_fuse[109400] DEBUG: arv-mount read fh 12 off 16384 size 32768
219 
2023-05-05 16:34:54 arvados.keep[109400] DEBUG: 7f614da9329cd3aebf59b91aadc30bf0+67108864+A54d46a964bbf337b28fdd7b6ff18b4230933c223@6467dd6e: ['http://127.0.0.11:33869/', 'http://127.0.0.11:37019/']
220 
2023-05-05 16:34:54 arvados.arvados_fuse[109400] DEBUG: arv-mount read fh 12 off 49152 size 65536
221 
2023-05-05 16:34:54 arvados.keep[109400] DEBUG: Request: GET http://127.0.0.11:33869/7f614da9329cd3aebf59b91aadc30bf0+67108864+A54d46a964bbf337b28fdd7b6ff18b4230933c223@6467dd6e
222 
2023-05-05 16:34:55 arvados.keep[109400] INFO: GET 200: 67108864 bytes in 190.25635719299316 msec (336.388 MiB/sec)
223 
2023-05-05 16:34:55 arvados.keep[109400] DEBUG: 7f614da9329cd3aebf59b91aadc30bf0+67108864+A54d46a964bbf337b28fdd7b6ff18b4230933c223@6467dd6e: ['http://127.0.0.11:33869/', 'http://127.0.0.11:37019/']
224 
2023-05-05 16:34:55 arvados.keep[109400] DEBUG: Request: GET http://127.0.0.11:33869/7f614da9329cd3aebf59b91aadc30bf0+67108864+A54d46a964bbf337b28fdd7b6ff18b4230933c223@6467dd6e
225 
2023-05-05 16:34:55 arvados.keep[109400] INFO: GET 200: 67108864 bytes in 172.8527545928955 msec (370.257 MiB/sec)
226 
2023-05-05 16:34:55 arvados.keep[109400] DEBUG: c4c9bfd05d839602a7022ea303d6a811+775920+Ac1321bf785550fd11b4c8fad2711c3e4b2b23ed7@6467dd6e: ['http://127.0.0.11:33869/', 'http://127.0.0.11:37019/']
227 
2023-05-05 16:34:55 arvados.keep[109400] DEBUG: Request: GET http://127.0.0.11:33869/c4c9bfd05d839602a7022ea303d6a811+775920+Ac1321bf785550fd11b4c8fad2711c3e4b2b23ed7@6467dd6e
228 
2023-05-05 16:34:55 arvados.keep[109400] INFO: GET 200: 775920 bytes in 1.7864704132080078 msec (414.211 MiB/sec)
229 
2023-05-05 16:34:55 arvados.keep[109400] DEBUG: 7f614da9329cd3aebf59b91aadc30bf0+67108864+A54d46a964bbf337b28fdd7b6ff18b4230933c223@6467dd6e: ['http://127.0.0.11:33869/', 'http://127.0.0.11:37019/']
230 
2023-05-05 16:34:55 arvados.keep[109400] DEBUG: Request: GET http://127.0.0.11:33869/7f614da9329cd3aebf59b91aadc30bf0+67108864+A54d46a964bbf337b28fdd7b6ff18b4230933c223@6467dd6e
231 
2023-05-05 16:34:55 arvados.keep[109400] INFO: GET 200: 67108864 bytes in 136.1525058746338 msec (470.061 MiB/sec)
232 
2023-05-05 16:34:55 arvados.keep[109400] DEBUG: c4c9bfd05d839602a7022ea303d6a811+775920+Ac1321bf785550fd11b4c8fad2711c3e4b2b23ed7@6467dd6e: ['http://127.0.0.11:33869/', 'http://127.0.0.11:37019/']
233 
2023-05-05 16:34:55 arvados.keep[109400] DEBUG: Request: GET http://127.0.0.11:33869/c4c9bfd05d839602a7022ea303d6a811+775920+Ac1321bf785550fd11b4c8fad2711c3e4b2b23ed7@6467dd6e
234 
2023-05-05 16:34:55 arvados.keep[109400] INFO: GET 200: 775920 bytes in 7.557153701782227 msec (97.917 MiB/sec)
235 
2023-05-05 16:34:55 arvados.keep[109400] DEBUG: 7f614da9329cd3aebf59b91aadc30bf0+67108864+A54d46a964bbf337b28fdd7b6ff18b4230933c223@6467dd6e: ['http://127.0.0.11:33869/', 'http://127.0.0.11:37019/']
236 
2023-05-05 16:34:55 arvados.keep[109400] DEBUG: Request: GET http://127.0.0.11:33869/7f614da9329cd3aebf59b91aadc30bf0+67108864+A54d46a964bbf337b28fdd7b6ff18b4230933c223@6467dd6e
237 
2023-05-05 16:34:55 arvados.keep[109400] INFO: GET 200: 67108864 bytes in 185.23716926574707 msec (345.503 MiB/sec)
238 
2023-05-05 16:34:55 arvados.keep[109400] DEBUG: c4c9bfd05d839602a7022ea303d6a811+775920+Ac1321bf785550fd11b4c8fad2711c3e4b2b23ed7@6467dd6e: ['http://127.0.0.11:33869/', 'http://127.0.0.11:37019/']
239 
2023-05-05 16:34:55 arvados.keep[109400] DEBUG: Request: GET http://127.0.0.11:33869/c4c9bfd05d839602a7022ea303d6a811+775920+Ac1321bf785550fd11b4c8fad2711c3e4b2b23ed7@6467dd6e
240 
2023-05-05 16:34:55 arvados.keep[109400] INFO: GET 200: 775920 bytes in 2.0024776458740234 msec (369.530 MiB/sec)
241 
2023-05-05 16:34:55 arvados.arvados_fuse[109400] DEBUG: arv-mount release fh 12
242 
2023-05-05 16:34:56 arvados.arvados_fuse[109400] DEBUG: arv-mount lookup: parent_inode 1 name 'by_id' inode 4
243 
2023-05-05 16:34:56 arvados.arvados_fuse[109400] DEBUG: arv-mount lookup: parent_inode 1 name 'by_id' inode 4
244 
2023-05-05 16:34:56 arvados.arvados_fuse[109400] DEBUG: arv-mount lookup: parent_inode 4 name '4465083aae54f79028d8d291e0dbbcfe+312' inode 10
245 
2023-05-05 16:34:56 arvados.arvados_fuse[109400] DEBUG: arv-mount lookup: parent_inode 1 name 'by_id' inode 4
246 
2023-05-05 16:34:56 arvados.arvados_fuse[109400] DEBUG: arv-mount lookup: parent_inode 4 name '4465083aae54f79028d8d291e0dbbcfe+312' inode 10
247 
2023-05-05 16:34:56 arvados.arvados_fuse[109400] DEBUG: InodeCache touched inode 10 (size 52992) (uuid 4465083aae54f79028d8d291e0dbbcfe+312) total now 76416 (3 entries)
248 
2023-05-05 16:34:56 arvados.arvados_fuse[109400] DEBUG: arv-mount lookup: parent_inode 10 name 'image.sif' inode 11
249 
2023-05-05 16:34:56 arvados.arvados_fuse[109400] DEBUG: arv-mount lookup: parent_inode 1 name 'by_id' inode 4
250 
2023-05-05 16:34:56 arvados.arvados_fuse[109400] DEBUG: arv-mount lookup: parent_inode 4 name '4465083aae54f79028d8d291e0dbbcfe+312' inode 10
251 
2023-05-05 16:34:56 arvados.arvados_fuse[109400] DEBUG: InodeCache touched inode 10 (size 52992) (uuid 4465083aae54f79028d8d291e0dbbcfe+312) total now 76416 (3 entries)
252 
2023-05-05 16:34:56 arvados.arvados_fuse[109400] DEBUG: arv-mount lookup: parent_inode 10 name 'image.sif' inode 11
253 
2023-05-05 16:34:56 arvados.arvados_fuse[109400] DEBUG: InodeCache touched inode 10 (size 52992) (uuid 4465083aae54f79028d8d291e0dbbcfe+312) total now 76416 (3 entries)
254 
2023-05-05 16:34:56 arvados.arvados_fuse[109400] DEBUG: arv-mount open inode 11 flags 8000 fh 13
255 
2023-05-05 16:34:56 arvados.arvados_fuse[109400] DEBUG: arv-mount release fh 13
256 
2023-05-05 16:34:56 arvados.arvados_fuse[109400] DEBUG: arv-mount lookup: parent_inode 1 name 'by_id' inode 4
257 
2023-05-05 16:34:56 arvados.arvados_fuse[109400] DEBUG: arv-mount lookup: parent_inode 4 name '4465083aae54f79028d8d291e0dbbcfe+312' inode 10
258 
2023-05-05 16:34:56 arvados.arvados_fuse[109400] DEBUG: InodeCache touched inode 10 (size 52992) (uuid 4465083aae54f79028d8d291e0dbbcfe+312) total now 76416 (3 entries)
259 
2023-05-05 16:34:56 arvados.arvados_fuse[109400] DEBUG: arv-mount lookup: parent_inode 10 name 'image.sif' inode 11
260 
2023-05-05 16:34:56 arvados.arvados_fuse[109400] DEBUG: InodeCache touched inode 10 (size 52992) (uuid 4465083aae54f79028d8d291e0dbbcfe+312) total now 76416 (3 entries)
261 
2023-05-05 16:34:56 arvados.arvados_fuse[109400] DEBUG: arv-mount open inode 11 flags 8000 fh 14
262 
2023-05-05 16:34:56 arvados.arvados_fuse[109400] DEBUG: arv-mount read fh 14 off 786432 size 4096
263 
2023-05-05 16:34:56 arvados.arvados_fuse[109400] DEBUG: arv-mount read fh 14 off 114688 size 131072
264 
2023-05-05 16:34:56 arvados.arvados_fuse[109400] DEBUG: arv-mount read fh 14 off 307200 size 4096
265 
2023-05-05 16:34:56 arvados.arvados_fuse[109400] DEBUG: arv-mount read fh 14 off 782336 size 4096
266 
2023-05-05 16:34:56 arvados.arvados_fuse[109400] DEBUG: arv-mount read fh 14 off 569344 size 4096
267 
2023-05-05 16:34:56 arvados.arvados_fuse[109400] DEBUG: arv-mount read fh 14 off 745472 size 4096
268 
2023-05-05 16:34:56 arvados.arvados_fuse[109400] DEBUG: arv-mount read fh 14 off 749568 size 16384
269 
2023-05-05 16:34:56 arvados.arvados_fuse[109400] DEBUG: arv-mount read fh 14 off 765952 size 16384
270 
2023-05-05 16:34:56 arvados.arvados_fuse[109400] DEBUG: arv-mount read fh 14 off 311296 size 65536
271 
2023-05-05 16:34:56 arvados.arvados_fuse[109400] DEBUG: arv-mount read fh 14 off 245760 size 61440
272 
2023-05-05 16:34:56 arvados.arvados_fuse[109400] DEBUG: arv-mount read fh 14 off 704512 size 4096
273 
2023-05-05 16:34:56 arvados.arvados_fuse[109400] DEBUG: arv-mount read fh 14 off 708608 size 16384
274 
2023-05-05 16:34:56 arvados.arvados_fuse[109400] DEBUG: arv-mount read fh 14 off 724992 size 20480
275 
2023-05-05 16:34:56 arvados.arvados_fuse[109400] DEBUG: arv-mount read fh 14 off 376832 size 131072
276 
2023-05-05 16:34:56 arvados.arvados_fuse[109400] DEBUG: arv-mount read fh 14 off 548864 size 4096
277 
2023-05-05 16:34:56 arvados.arvados_fuse[109400] DEBUG: arv-mount read fh 14 off 552960 size 16384
278 
2023-05-05 16:34:56 arvados.arvados_fuse[109400] DEBUG: arv-mount read fh 14 off 573440 size 28672
279 
2023-05-05 16:34:56 arvados.arvados_fuse[109400] DEBUG: arv-mount read fh 14 off 602112 size 102400
280 
2023-05-05 16:34:56 arvados.arvados_fuse[109400] DEBUG: arv-mount read fh 14 off 507904 size 16384
281 
2023-05-05 16:34:56 arvados.arvados_fuse[109400] DEBUG: arv-mount read fh 14 off 524288 size 24576
282 
2023-05-05 16:34:56 arvados.arvados_fuse[109400] DEBUG: arv-mount release fh 14
283 
2023-05-05 16:34:56 arvados.arv-mount[109645] DEBUG: arv-mount debugging enabled
284 
2023-05-05 16:34:56 arvados.arv-mount[109645] INFO: /home/brett/.cache/arvados-test/VENV3DIR/bin/arv-mount 2.7.0.dev20230504223618 started
285 
2023-05-05 16:34:56 arvados.arv-mount[109645] INFO: enable write is False
286 
2023-05-05 16:34:56 arvados.arvados_fuse[109645] DEBUG: InodeCache touched inode 5 (size 0) (uuid z1111-tpzed-000000000000000) total now 0 (1 entries)
287 
2023-05-05 16:34:59 arvados.arvados_fuse[107911] DEBUG: arv-mount opendir: inode 1
288 
2023-05-05 16:34:59 arvados.arvados_fuse[107911] DEBUG: arv-mount readdir: fh 0 off 0
289 
2023-05-05 16:34:59 arvados.arvados_fuse[107911] DEBUG: arv-mount readdir: fh 0 off 4
290 
2023-05-05 16:34:59 arvados.arvados_fuse[107911] DEBUG: arv-mount lookup: parent_inode 1 name 'by_uuid' inode 2
291 
2023-05-05 16:34:59 arvados.arvados_fuse[107911] DEBUG: arv-mount lookup: parent_inode 1 name 'by_uuid' inode 2
292 
2023-05-05 16:34:59 arvados.arvados_fuse[107911] DEBUG: arv-mount lookup: parent_inode 1 name 'by_uuid' inode 2
293 
2023-05-05 16:34:59 arvados.arvados_fuse[107911] DEBUG: arv-mount opendir: inode 2
294 
2023-05-05 16:34:59 arvados.arvados_fuse[107911] DEBUG: arv-mount readdir: fh 1 off 0
295 
2023-05-05 16:34:59 arvados.arvados_fuse[107911] DEBUG: arv-mount readdir: fh 1 off 3
296 
2023-05-05 16:34:59 arvados.arvados_fuse[107911] DEBUG: arv-mount lookup: parent_inode 2 name 'README' inode 3
297 
2023-05-05 16:34:59 arvados.arvados_fuse[107911] DEBUG: arv-mount unlink: parent_inode 2 'README'
298 
2023-05-05 16:34:59 arvados.arvados_fuse[107911] DEBUG: arv-mount lookup: parent_inode 2 name 'README' inode 3
299 
2023-05-05 16:34:59 arvados.arvados_fuse[107911] DEBUG: arv-mount release fh 1
300 
2023-05-05 16:34:59 arvados.arvados_fuse[107911] DEBUG: arv-mount lookup: parent_inode 1 name 'by_uuid' inode 2
301 
2023-05-05 16:34:59 arvados.arvados_fuse[107911] DEBUG: arv-mount rmdir: parent_inode 1 'by_uuid'
302 
2023-05-05 16:34:59 arvados.arvados_fuse[107911] DEBUG: arv-mount lookup: parent_inode 1 name 'by_id' inode 4
303 
2023-05-05 16:34:59 arvados.arvados_fuse[107911] DEBUG: arv-mount lookup: parent_inode 1 name 'by_id' inode 4
304 
2023-05-05 16:34:59 arvados.arvados_fuse[107911] DEBUG: arv-mount lookup: parent_inode 1 name 'by_id' inode 4
305 
2023-05-05 16:34:59 arvados.arvados_fuse[107911] DEBUG: arv-mount opendir: inode 4
306 
2023-05-05 16:53:33 arvados.arvados_fuse[107911] ERROR: arv-mount 8ea82759a04e5ce160fb3b0c7f771b1d+48: error
307 
Traceback (most recent call last):
308 
  File "/home/brett/.cache/arvados-test/VENV3DIR/lib/python3.9/site-packages/arvados/api.py", line 116, in _intercept_http_request
309 
    response, body = self.orig_http_request(uri, method, headers=headers, **kwargs)
310 
  File "/home/brett/.cache/arvados-test/VENV3DIR/lib/python3.9/site-packages/httplib2/__init__.py", line 1711, in request
311 
    (response, content) = self._request(
312 
  File "/home/brett/.cache/arvados-test/VENV3DIR/lib/python3.9/site-packages/httplib2/__init__.py", line 1427, in _request
313 
    (response, content) = self._conn_request(conn, request_uri, method, body, headers)
314 
  File "/home/brett/.cache/arvados-test/VENV3DIR/lib/python3.9/site-packages/httplib2/__init__.py", line 1349, in _conn_request
315 
    conn.connect()
316 
  File "/home/brett/.cache/arvados-test/VENV3DIR/lib/python3.9/site-packages/httplib2/__init__.py", line 1185, in connect
317 
    raise socket_err
318 
  File "/home/brett/.cache/arvados-test/VENV3DIR/lib/python3.9/site-packages/httplib2/__init__.py", line 1139, in connect
319 
    sock.connect((self.host, self.port))
320 
ConnectionRefusedError: [Errno 111] Connection refused
321 

    		
  

  

    
      322
    
    
      
During handling of the above exception, another exception occurred:


    		
  

  

    
      323
    
    
      

    		
  

  

    
      324
    
    
      
Traceback (most recent call last):


    		
  

  

    
      325
    
    
      
  File "/home/brett/.cache/arvados-test/VENV3DIR/lib/python3.9/site-packages/arvados_fuse/fusedir.py", line 541, in update


    		
  

  

    
      326
    
    
      
    coll_reader = arvados.collection.CollectionReader(


    		
  

  

    
      327
    
    
      
  File "/home/brett/.cache/arvados-test/VENV3DIR/lib/python3.9/site-packages/arvados/collection.py", line 1927, in __init__


    		
  

  

    
      328
    
    
      
    super(CollectionReader, self).__init__(manifest_locator_or_text, *args, **kwargs)


    		
  

  

    
      329
    
    
      
  File "/home/brett/.cache/arvados-test/VENV3DIR/lib/python3.9/site-packages/arvados/collection.py", line 1353, in __init__


    		
  

  

    
      330
    
    
      
    self._populate()


    		
  

  

    
      331
    
    
      
  File "/home/brett/.cache/arvados-test/VENV3DIR/lib/python3.9/site-packages/arvados/collection.py", line 1471, in _populate


    		
  

  

    
      332
    
    
      
    self._populate_from_api_server()


    		
  

  

    
      333
    
    
      
  File "/home/brett/.cache/arvados-test/VENV3DIR/lib/python3.9/site-packages/arvados/collection.py", line 1454, in _populate_from_api_server


    		
  

  

    
      334
    
    
      
    self._remember_api_response(self._my_api().collections().get(


    		
  

  

    
      335
    
    
      
  File "/home/brett/.cache/arvados-test/VENV3DIR/lib/python3.9/site-packages/googleapiclient/_helpers.py", line 130, in positional_wrapper


    		
  

  

    
      336
    
    
      
    return wrapped(*args, **kwargs)


    		
  

  

    
      337
    
    
      
  File "/home/brett/.cache/arvados-test/VENV3DIR/lib/python3.9/site-packages/googleapiclient/http.py", line 923, in execute


    		
  

  

    
      338
    
    
      
    resp, content = _retry_request(


    		
  

  

    
      339
    
    
      
  File "/home/brett/.cache/arvados-test/VENV3DIR/lib/python3.9/site-packages/arvados/api.py", line 87, in _retry_request


    		
  

  

    
      340
    
    
      
    response, body = _orig_retry_request(http, num_retries, *args, **kwargs)


    		
  

  

    
      341
    
    
      
  File "/home/brett/.cache/arvados-test/VENV3DIR/lib/python3.9/site-packages/googleapiclient/http.py", line 222, in _retry_request


    		
  

  

    
      342
    
    
      
    raise exception


    		
  

  

    
      343
    
    
      
  File "/home/brett/.cache/arvados-test/VENV3DIR/lib/python3.9/site-packages/googleapiclient/http.py", line 191, in _retry_request


    		
  

  

    
      344
    
    
      
    resp, content = http.request(uri, method, *args, **kwargs)


    		
  

  

    
      345
    
    
      
  File "/home/brett/.cache/arvados-test/VENV3DIR/lib/python3.9/site-packages/arvados/api.py", line 132, in _intercept_http_request


    		
  

  

    
      346
    
    
      
    raise type(e)(*e.args)


    		
  

  

    
      347
    
    
      
ConnectionRefusedError: [Errno 111] [req-r8kp6ootctrqdr3umsuc] Connection refused


    		
  

  

    
      348
    
    
      
2023-05-05 16:53:33 arvados.arvados_fuse[107911] DEBUG: InodeCache sent kernel invalidate inode 6


    		
  

  

    
      349
    
    
      
2023-05-05 16:53:33 arvados.arvados_fuse[107911] DEBUG: InodeCache cleared inode 6 total now 0


    		
  

  

    
      350
    
    
      
2023-05-05 16:53:33 arvados.arvados_fuse[107911] DEBUG: arv-mount lookup: parent_inode 4 name '8ea82759a04e5ce160fb3b0c7f771b1d+48' not found


    		
  

  

    
      351
    
    
      
2023-05-05 16:53:33 arvados.arvados_fuse[107911] DEBUG: arv-mount release fh 2


    		
  

  

    
      352
    
    
      
2023-05-05 16:53:33 arvados.arvados_fuse[107911] DEBUG: arv-mount release fh 0


    		
  

  

    
      353
    
    
      
2023-05-05 16:53:33 arvados.arv-mount[112042] DEBUG: arv-mount debugging enabled


    		
  

  

    
      354
    
    
      
2023-05-05 16:53:33 arvados.arv-mount[112042] INFO: /home/brett/.cache/arvados-test/VENV3DIR/bin/arv-mount 2.7.0.dev20230504223618 started


    		
  

  

    
      355
    
    
      
2023-05-05 16:53:33 arvados.arv-mount[112042] INFO: enable write is False


    		
  












  
    (1-1/1)