Date: Mon 05/31/2004 22:54:04 New SrvLog started at Mon May 31 22:54:04 2004 22:54:04 Resource limit on data size are set to -1 22:54:04 RvmType is Rvm 22:54:04 Main process doing a LWP_Init() 22:54:04 Main thread just did a RVM_SET_THREAD_DATA 22:54:04 Setting Rvm Truncate threshhold to 5. Partition /vicepa: inodes in use: 371, total: 16777216. 22:54:18 Partition /vicepa: 32298296K available (minfree=5%), 29774640K free. 22:54:18 The server (pid 588) can be controlled using volutil commands 22:54:18 "volutil -help" will give you a list of these commands 22:54:18 If desperate, "kill -SIGWINCH 588" will increase debugging level 22:54:18 "kill -SIGUSR2 588" will set debugging level to zero 22:54:18 "kill -9 588" will kill a runaway server 22:54:18 Vice file system salvager, version 3.0. 22:54:18 SanityCheckFreeLists: Checking RVM Vnode Free lists. 22:54:18 DestroyBadVolumes: Checking for destroyed volumes. 22:54:18 Salvaging file system partition /vicepa 22:54:18 Force salvage of all volumes on this partition 22:54:18 Scanning inodes in directory /vicepa... 22:54:18 SFS: There are some volumes without any inodes in them 22:54:18 SalvageIndex: Vnode 0xb14 has no inodeNumber 22:54:18 SalvageIndex: Creating an empty object for it 22:54:18 Entering DCC(0x1000003) 22:54:18 done: 382 files/dirs, 8951 blocks 22:54:18 SalvageFileSys: unclaimed volume header file or no Inodes in volume 1000004 22:54:18 SalvageFileSys: Therefore only resetting inUse flag 22:54:18 SalvageFileSys completed on /vicepa 22:54:18 VAttachVolumeById: vol 1000003 (coda.root.0) attached and online 22:54:18 VAttachVolumeById: vol 1000004 (mta.pending.0) attached and online 22:54:18 Attached 2 volumes; 0 volumes not attached lqman: Creating LockQueue Manager.....LockQueue Manager starting ..... 22:54:18 LockQueue Manager just did a rvmlib_set_thread_data() done 22:54:18 CallBackCheckLWP just did a rvmlib_set_thread_data() 22:54:18 CheckLWP just did a rvmlib_set_thread_data() 22:54:18 ServerLWP 0 just did a rvmlib_set_thread_data() 22:54:18 ServerLWP 1 just did a rvmlib_set_thread_data() 22:54:18 ServerLWP 2 just did a rvmlib_set_thread_data() 22:54:18 ServerLWP 3 just did a rvmlib_set_thread_data() 22:54:18 ServerLWP 4 just did a rvmlib_set_thread_data() 22:54:18 ServerLWP 5 just did a rvmlib_set_thread_data() 22:54:18 ResLWP-0 just did a rvmlib_set_thread_data() 22:54:18 ResLWP-1 just did a rvmlib_set_thread_data() 22:54:18 VolUtilLWP 0 just did a rvmlib_set_thread_data() 22:54:18 VolUtilLWP 1 just did a rvmlib_set_thread_data() 22:54:18 Starting SmonDaemon timer 22:54:18 File Server started Mon May 31 22:54:18 2004 22:54:19 client_GetVenusId: got new host 212.85.15.251:32769 22:54:19 Building callback conn. 22:54:26 Worker4: Unbinding RPC connection 16091 22:54:34 GetAttrPlusSHA: Computing SHA 1000003.b14.1068, disk.inode=16b 22:54:34 GetAttrPlusSHA: Computing SHA 1000003.b00.105e, disk.inode=6 22:54:34 GetAttrPlusSHA: Computing SHA 1000003.b02.105f, disk.inode=e 22:54:34 GetAttrPlusSHA: Computing SHA 1000003.b04.1060, disk.inode=160 22:54:34 GetAttrPlusSHA: Computing SHA 1000003.b06.1061, disk.inode=162 22:54:34 GetAttrPlusSHA: Computing SHA 1000003.b08.1062, disk.inode=163 22:54:34 GetAttrPlusSHA: Computing SHA 1000003.b0a.1063, disk.inode=164 22:54:34 GetAttrPlusSHA: Computing SHA 1000003.b0c.1064, disk.inode=166 22:54:34 GetAttrPlusSHA: Computing SHA 1000003.b0e.1065, disk.inode=167 22:54:34 GetAttrPlusSHA: Computing SHA 1000003.b10.1066, disk.inode=169 22:54:34 GetAttrPlusSHA: Computing SHA 1000003.422.492, disk.inode=fc 22:54:34 New Data Base received 22:54:41 client_GetVenusId: got new host 212.85.15.253:32770 22:54:41 Building callback conn. 22:54:43 GetAttrPlusSHA: Computing SHA 1000003.426.494, disk.inode=8e 22:55:35 GetAttrPlusSHA: Computing SHA 1000003.ab8.9fa, disk.inode=161 22:55:35 GetAttrPlusSHA: Computing SHA 1000003.b12.1067, disk.inode=16a 22:55:44 GetAttrPlusSHA: Computing SHA 1000003.86a.1249, disk.inode=16c 22:55:44 GetAttrPlusSHA: Computing SHA 1000003.87c.1252, disk.inode=167 22:55:44 GetAttrPlusSHA: Computing SHA 1000003.86c.124a, disk.inode=16d 22:55:44 GetAttrPlusSHA: Computing SHA 1000003.86e.124b, disk.inode=6 22:55:44 GetAttrPlusSHA: Computing SHA 1000003.870.124c, disk.inode=e 22:55:44 GetAttrPlusSHA: Computing SHA 1000003.872.124d, disk.inode=160 22:55:44 GetAttrPlusSHA: Computing SHA 1000003.874.124e, disk.inode=162 22:55:44 GetAttrPlusSHA: Computing SHA 1000003.876.124f, disk.inode=163 22:55:44 GetAttrPlusSHA: Computing SHA 1000003.878.1250, disk.inode=164 22:55:44 GetAttrPlusSHA: Computing SHA 1000003.87a.1251, disk.inode=166 22:56:45 VGetVnode: vnode 1000003.b02 is not allocated 22:56:45 VGetVnode: vnode 1000003.b04 is not allocated 22:56:45 VGetVnode: vnode 1000003.b06 is not allocated 22:56:45 VGetVnode: vnode 1000003.b08 is not allocated 22:56:45 VGetVnode: vnode 1000003.b0a is not allocated 22:56:45 VGetVnode: vnode 1000003.b0c is not allocated 22:56:45 VGetVnode: vnode 1000003.b0e is not allocated 22:56:45 VGetVnode: vnode 1000003.b10 is not allocated 22:56:45 VGetVnode: vnode 1000003.b00 is not allocated 23:04:17 GetAttrPlusSHA: Computing SHA 1000003.3ca.466, disk.inode=b4 23:04:17 GetAttrPlusSHA: Computing SHA 1000003.3c8.465, disk.inode=74 23:04:17 GetAttrPlusSHA: Computing SHA 1000003.328.415, disk.inode=88 23:04:17 GetAttrPlusSHA: Computing SHA 1000003.326.414, disk.inode=87 23:04:17 GetAttrPlusSHA: Computing SHA 1000003.25a.3ae, disk.inode=8d 23:04:17 GetAttrPlusSHA: Computing SHA 1000003.254.3ab, disk.inode=8b 23:04:17 GetAttrPlusSHA: Computing SHA 1000003.17a.33e, disk.inode=49 23:04:17 GetAttrPlusSHA: Computing SHA 1000003.174.33b, disk.inode=2f 23:04:17 GetAttrPlusSHA: Computing SHA 1000003.866.1247, disk.inode=15f 23:04:42 GetAttrPlusSHA: Computing SHA 1000003.2b2.3da, disk.inode=a8 23:04:42 GetAttrPlusSHA: Computing SHA 1000003.2aa.3d6, disk.inode=a5 23:04:42 GetAttrPlusSHA: Computing SHA 1000003.1d0.369, disk.inode=41 23:04:42 GetAttrPlusSHA: Computing SHA 1000003.1cc.367, disk.inode=62 23:04:42 GetAttrPlusSHA: Computing SHA 1000003.b4.2db, disk.inode=3 23:04:42 GetAttrPlusSHA: Computing SHA 1000003.b2.2da, disk.inode=d 23:31:02 VAllocFid: volume disk uniquifier being extended 23:31:17 VAllocFid: volume disk uniquifier being extended 23:31:19 GetAttrPlusSHA: Computing SHA 1000003.882.1255, disk.inode=16f 23:31:19 GetAttrPlusSHA: Computing SHA 1000003.888.1258, disk.inode=172 23:31:19 GetAttrPlusSHA: Computing SHA 1000003.36.1283, disk.inode=174 23:31:19 GetAttrPlusSHA: Computing SHA 1000003.3c.1286, disk.inode=177 23:31:19 GetAttrPlusSHA: Computing SHA 1000003.42.1289, disk.inode=179 23:31:19 GetAttrPlusSHA: Computing SHA 1000003.46.128b, disk.inode=173 23:31:19 GetAttrPlusSHA: Computing SHA 1000003.4c.128e, disk.inode=17c 23:31:19 GetAttrPlusSHA: Computing SHA 1000003.52.1291, disk.inode=17e 23:31:19 GetAttrPlusSHA: Computing SHA 1000003.58.1294, disk.inode=181 23:31:19 GetAttrPlusSHA: Computing SHA 1000003.5c.1296, disk.inode=178 23:31:19 GetAttrPlusSHA: Computing SHA 1000003.62.1299, disk.inode=184 23:31:19 GetAttrPlusSHA: Computing SHA 1000003.66.129b, disk.inode=17a 23:31:19 GetAttrPlusSHA: Computing SHA 1000003.6c.129e, disk.inode=188 23:31:19 GetAttrPlusSHA: Computing SHA 1000003.70.12a0, disk.inode=16e 23:31:19 GetAttrPlusSHA: Computing SHA 1000003.63c.12a3, disk.inode=18b 23:31:19 GetAttrPlusSHA: Computing SHA 1000003.642.12a6, disk.inode=18d 23:31:19 GetAttrPlusSHA: Computing SHA 1000003.646.12a8, disk.inode=17f 23:31:19 GetAttrPlusSHA: Computing SHA 1000003.64c.12ab, disk.inode=190 23:31:19 GetAttrPlusSHA: Computing SHA 1000003.652.12ae, disk.inode=192 23:31:19 GetAttrPlusSHA: Computing SHA 1000003.656.12b0, disk.inode=183 23:31:20 GetAttrPlusSHA: Computing SHA 1000003.65c.12b3, disk.inode=195 23:31:20 GetAttrPlusSHA: Computing SHA 1000003.662.12b6, disk.inode=198 23:31:20 GetAttrPlusSHA: Computing SHA 1000003.668.12b9, disk.inode=19a 23:31:20 GetAttrPlusSHA: Computing SHA 1000003.66c.12bb, disk.inode=17b 23:31:20 GetAttrPlusSHA: Computing SHA 1000003.672.12be, disk.inode=19d 23:31:20 GetAttrPlusSHA: Computing SHA 1000003.688.12c2, disk.inode=1a1 23:31:20 GetAttrPlusSHA: Computing SHA 1000003.68e.12c5, disk.inode=1a3 23:31:20 GetAttrPlusSHA: Computing SHA 1000003.692.12c7, disk.inode=18c 23:31:20 GetAttrPlusSHA: Computing SHA 1000003.696.12c9, disk.inode=176 23:31:20 GetAttrPlusSHA: Computing SHA 1000003.69a.12cb, disk.inode=18e 23:31:20 GetAttrPlusSHA: Computing SHA 1000003.6a0.12ce, disk.inode=1a8 23:31:20 GetAttrPlusSHA: Computing SHA 1000003.6a4.12d0, disk.inode=171 23:31:20 GetAttrPlusSHA: Computing SHA 1000003.6a8.12d2, disk.inode=191 23:31:20 GetAttrPlusSHA: Computing SHA 1000003.6ac.12d4, disk.inode=182 23:31:20 GetAttrPlusSHA: Computing SHA 1000003.6b0.12d6, disk.inode=193 23:31:20 GetAttrPlusSHA: Computing SHA 1000003.6b4.12d8, disk.inode=194 23:31:20 GetAttrPlusSHA: Computing SHA 1000003.6ba.12db, disk.inode=1af 23:31:20 GetAttrPlusSHA: Computing SHA 1000003.6be.12dd, disk.inode=196 23:31:20 GetAttrPlusSHA: Computing SHA 1000003.6c2.12df, disk.inode=186 23:31:20 GetAttrPlusSHA: Computing SHA 1000003.6c6.12e1, disk.inode=199 23:31:20 GetAttrPlusSHA: Computing SHA 1000003.6ca.12e3, disk.inode=187 23:31:20 GetAttrPlusSHA: Computing SHA 1000003.6d0.12e6, disk.inode=1b5 23:31:20 GetAttrPlusSHA: Computing SHA 1000003.6d4.12e8, disk.inode=19c 23:31:20 GetAttrPlusSHA: Computing SHA 1000003.6da.12eb, disk.inode=1b8 23:31:20 GetAttrPlusSHA: Computing SHA 1000003.6e2.12ef, disk.inode=1bb 23:31:20 GetAttrPlusSHA: Computing SHA 1000003.6e8.12f2, disk.inode=1bd 23:31:20 GetAttrPlusSHA: Computing SHA 1000003.6ee.12f5, disk.inode=1bf 23:31:20 GetAttrPlusSHA: Computing SHA 1000003.6f4.12f8, disk.inode=1c1 23:31:20 GetAttrPlusSHA: Computing SHA 1000003.6f8.12fa, disk.inode=17d 23:31:20 GetAttrPlusSHA: Computing SHA 1000003.6fc.12fc, disk.inode=1a4 23:31:20 GetAttrPlusSHA: Computing SHA 1000003.700.12fe, disk.inode=1a5 23:31:20 GetAttrPlusSHA: Computing SHA 1000003.706.1301, disk.inode=1c7 23:31:20 GetAttrPlusSHA: Computing SHA 1000003.70a.1303, disk.inode=1a7 23:31:20 GetAttrPlusSHA: Computing SHA 1000003.710.1306, disk.inode=1ca 23:31:20 GetAttrPlusSHA: Computing SHA 1000003.714.1308, disk.inode=1a9 23:31:20 GetAttrPlusSHA: Computing SHA 1000003.71a.130b, disk.inode=1ce 23:31:20 GetAttrPlusSHA: Computing SHA 1000003.71e.130d, disk.inode=1ab 23:31:20 GetAttrPlusSHA: Computing SHA 1000003.724.1310, disk.inode=1d1 23:31:20 GetAttrPlusSHA: Computing SHA 1000003.728.1312, disk.inode=1ad 23:31:20 GetAttrPlusSHA: Computing SHA 1000003.72e.1315, disk.inode=1d4 23:31:20 GetAttrPlusSHA: Computing SHA 1000003.732.1317, disk.inode=169 23:31:20 GetAttrPlusSHA: Computing SHA 1000003.738.131a, disk.inode=1d8 23:31:20 GetAttrPlusSHA: Computing SHA 1000003.73c.131c, disk.inode=1b1 23:31:20 GetAttrPlusSHA: Computing SHA 1000003.742.131f, disk.inode=1db 23:31:20 GetAttrPlusSHA: Computing SHA 1000003.748.1322, disk.inode=1dd 23:31:20 GetAttrPlusSHA: Computing SHA 1000003.74c.1324, disk.inode=1b4 23:31:20 GetAttrPlusSHA: Computing SHA 1000003.752.1327, disk.inode=1e0 23:31:20 GetAttrPlusSHA: Computing SHA 1000003.756.1329, disk.inode=1b6 23:31:20 GetAttrPlusSHA: Computing SHA 1000003.75c.132c, disk.inode=1e3 23:31:20 GetAttrPlusSHA: Computing SHA 1000003.760.132e, disk.inode=189 23:31:20 GetAttrPlusSHA: Computing SHA 1000003.766.1331, disk.inode=1e6 23:31:20 GetAttrPlusSHA: Computing SHA 1000003.76c.1334, disk.inode=1e8 23:31:20 GetAttrPlusSHA: Computing SHA 1000003.770.1336, disk.inode=1ba 23:31:20 GetAttrPlusSHA: Computing SHA 1000003.776.1339, disk.inode=1eb 23:31:20 GetAttrPlusSHA: Computing SHA 1000003.77a.133b, disk.inode=18a 23:31:20 GetAttrPlusSHA: Computing SHA 1000003.780.133e, disk.inode=1ee 23:31:20 GetAttrPlusSHA: Computing SHA 1000003.784.1340, disk.inode=1ef 23:31:20 GetAttrPlusSHA: Computing SHA 1000003.788.1342, disk.inode=1f0 23:31:20 GetAttrPlusSHA: Computing SHA 1000003.78e.1345, disk.inode=1f2 23:31:20 GetAttrPlusSHA: Computing SHA 1000003.792.1347, disk.inode=1f3 23:31:20 GetAttrPlusSHA: Computing SHA 1000003.796.1349, disk.inode=1f4 23:32:20 GetAttrPlusSHA: Computing SHA 1000003.79a.134b, disk.inode=1c5 23:32:20 GetAttrPlusSHA: Computing SHA 1000003.7a0.134e, disk.inode=1f7 23:32:20 GetAttrPlusSHA: Computing SHA 1000003.7a4.1350, disk.inode=1a6 23:32:20 GetAttrPlusSHA: Computing SHA 1000003.7a8.1352, disk.inode=1c8 23:32:20 GetAttrPlusSHA: Computing SHA 1000003.7aa.1353, disk.inode=1c9 23:32:20 GetAttrPlusSHA: Computing SHA 1000003.7ac.1354, disk.inode=18f 23:32:20 GetAttrPlusSHA: Computing SHA 1000003.7ae.1355, disk.inode=1cb 23:32:20 GetAttrPlusSHA: Computing SHA 1000003.7b0.1356, disk.inode=1cc 23:32:20 GetAttrPlusSHA: Computing SHA 1000003.7b2.1357, disk.inode=1aa 23:32:20 GetAttrPlusSHA: Computing SHA 1000003.7b4.1358, disk.inode=1cf 23:32:20 GetAttrPlusSHA: Computing SHA 1000003.7b6.1359, disk.inode=1d0 23:32:20 GetAttrPlusSHA: Computing SHA 1000003.7b8.135a, disk.inode=1ac 23:32:20 GetAttrPlusSHA: Computing SHA 1000003.7ba.135b, disk.inode=1d2 23:32:20 GetAttrPlusSHA: Computing SHA 1000003.7bc.135c, disk.inode=1d3 23:32:20 GetAttrPlusSHA: Computing SHA 1000003.7be.135d, disk.inode=1ae 23:32:21 GetAttrPlusSHA: Computing SHA 1000003.88e.1384, disk.inode=1fc 23:32:21 GetAttrPlusSHA: Computing SHA 1000003.892.1386, disk.inode=1e5 23:32:21 GetAttrPlusSHA: Computing SHA 1000003.898.1389, disk.inode=1ff 23:32:21 GetAttrPlusSHA: Computing SHA 1000003.89e.138c, disk.inode=201 23:33:22 GetAttrPlusSHA: Computing SHA 1000003.8a0.138d, disk.inode=1fd 23:33:22 GetAttrPlusSHA: Computing SHA 1000003.8a4.138f, disk.inode=202 23:33:22 GetAttrPlusSHA: Computing SHA 1000003.8a8.1391, disk.inode=1fb 23:33:22 GetAttrPlusSHA: Computing SHA 1000003.8aa.1392, disk.inode=200 23:33:22 GetAttrPlusSHA: Computing SHA 1000003.8ac.1393, disk.inode=1f9 23:33:22 GetAttrPlusSHA: Computing SHA 1000003.8ae.1394, disk.inode=1fe 23:33:22 GetAttrPlusSHA: Computing SHA 1000003.8b4.1397, disk.inode=205 23:33:22 GetAttrPlusSHA: Computing SHA 1000003.8b6.1398, disk.inode=203 23:33:22 GetAttrPlusSHA: Computing SHA 1000003.8ba.139a, disk.inode=206 23:33:22 GetAttrPlusSHA: Computing SHA 1000003.8be.139c, disk.inode=207 23:33:22 GetAttrPlusSHA: Computing SHA 1000003.8c2.139e, disk.inode=208 23:33:22 GetAttrPlusSHA: Computing SHA 1000003.8c6.13a0, disk.inode=209 23:33:22 GetAttrPlusSHA: Computing SHA 1000003.8ca.13a2, disk.inode=20a 23:33:22 GetAttrPlusSHA: Computing SHA 1000003.8ce.13a4, disk.inode=20b 23:33:22 GetAttrPlusSHA: Computing SHA 1000003.8d2.13a6, disk.inode=20c 23:33:22 GetAttrPlusSHA: Computing SHA 1000003.8d6.13a8, disk.inode=20d 23:33:22 GetAttrPlusSHA: Computing SHA 1000003.8da.13aa, disk.inode=20e 23:33:22 GetAttrPlusSHA: Computing SHA 1000003.8de.13ac, disk.inode=20f 23:33:22 GetAttrPlusSHA: Computing SHA 1000003.8e2.13ae, disk.inode=210 23:33:22 GetAttrPlusSHA: Computing SHA 1000003.8e6.13b0, disk.inode=211 23:33:22 GetAttrPlusSHA: Computing SHA 1000003.8ea.13b2, disk.inode=212 23:33:22 GetAttrPlusSHA: Computing SHA 1000003.8ee.13b4, disk.inode=213 23:33:22 GetAttrPlusSHA: Computing SHA 1000003.8f2.13b6, disk.inode=214 23:33:22 GetAttrPlusSHA: Computing SHA 1000003.8f6.13b8, disk.inode=215 23:33:22 GetAttrPlusSHA: Computing SHA 1000003.8fa.13ba, disk.inode=216 23:33:22 GetAttrPlusSHA: Computing SHA 1000003.8fe.13bc, disk.inode=217 23:33:22 GetAttrPlusSHA: Computing SHA 1000003.902.13be, disk.inode=218 23:33:22 GetAttrPlusSHA: Computing SHA 1000003.906.13c0, disk.inode=219 23:33:22 GetAttrPlusSHA: Computing SHA 1000003.90a.13c2, disk.inode=21a 23:33:22 GetAttrPlusSHA: Computing SHA 1000003.90e.13c4, disk.inode=21b 23:33:22 GetAttrPlusSHA: Computing SHA 1000003.912.13c6, disk.inode=21c 23:33:22 GetAttrPlusSHA: Computing SHA 1000003.916.13c8, disk.inode=21d 23:33:22 GetAttrPlusSHA: Computing SHA 1000003.926.13d0, disk.inode=221 23:33:22 GetAttrPlusSHA: Computing SHA 1000003.92a.13d2, disk.inode=222 23:33:22 GetAttrPlusSHA: Computing SHA 1000003.92e.13d4, disk.inode=223 23:33:22 GetAttrPlusSHA: Computing SHA 1000003.932.13d6, disk.inode=224 23:33:22 GetAttrPlusSHA: Computing SHA 1000003.936.13d8, disk.inode=225 23:33:22 GetAttrPlusSHA: Computing SHA 1000003.93a.13da, disk.inode=226 23:33:22 GetAttrPlusSHA: Computing SHA 1000003.93e.13dc, disk.inode=227 23:33:22 GetAttrPlusSHA: Computing SHA 1000003.942.13de, disk.inode=228 23:33:22 GetAttrPlusSHA: Computing SHA 1000003.946.13e0, disk.inode=229 23:33:22 GetAttrPlusSHA: Computing SHA 1000003.958.13e2, disk.inode=22a 23:34:03 Worker5: Unbinding RPC connection 10127 23:34:03 Worker2: Unbinding RPC connection 7371 23:34:22 GetAttrPlusSHA: Computing SHA 1000003.7c0.135e, disk.inode=1d6 23:34:22 GetAttrPlusSHA: Computing SHA 1000003.7c2.135f, disk.inode=1d7 23:34:22 GetAttrPlusSHA: Computing SHA 1000003.7c4.1360, disk.inode=1b0 23:34:22 GetAttrPlusSHA: Computing SHA 1000003.7c6.1361, disk.inode=1d9 23:35:23 GetAttrPlusSHA: Computing SHA 1000003.91a.13ca, disk.inode=21e 23:35:27 Worker5: Unbinding RPC connection 830 23:35:27 Worker2: Unbinding RPC connection 12215 23:35:27 Worker4: Unbinding RPC connection 3818 23:36:24 VGetVnode: memory vnode was snatched away 23:36:24 VGetVnode: memory vnode was snatched away 23:36:25 VGetVnode: memory vnode was snatched away 23:36:25 VGetVnode: memory vnode was snatched away 23:36:25 VGetVnode: memory vnode was snatched away 23:36:25 VGetVnode: memory vnode was snatched away 23:36:25 VGetVnode: memory vnode was snatched away 23:36:25 VGetVnode: memory vnode was snatched away 23:36:25 VGetVnode: memory vnode was snatched away 23:36:25 VGetVnode: vnode 1000003.958 is not allocated 23:36:26 ****** WARNING entry at 0x813cd98 already has deqing set! 23:36:36 ****** WARNING entry at 0x813cd98 already has deqing set! 23:47:01 Worker3: Unbinding RPC connection 5427 23:47:01 Worker0: Unbinding RPC connection 6279 23:47:50 Worker1: Unbinding RPC connection 11787 23:47:50 Worker3: Unbinding RPC connection 15560 23:47:50 Worker0: Unbinding RPC connection 15851 23:54:18 SmonDaemon timer expired 23:54:18 Entered CheckRVMResStat 23:54:18 Starting SmonDaemon timer Date: Tue 06/01/2004 00:08:59 Shutdown received 00:08:59 Shutdown received 00:09:18 Shutting down the File Server Tue Jun 1 00:09:18 2004 00:09:18 Total operations for File Server = 1709 : time = Tue Jun 1 00:09:18 2004 00:09:18 Vice was last started at Mon May 31 22:54:18 2004 00:09:18 NewConnectFS 22 00:09:18 DisconnectFS 11 00:09:18 GetAttr 0 00:09:18 GetAcl 0 00:09:18 Fetch 227 00:09:18 SetAttr 0 00:09:18 SetAcl 0 00:09:18 Store 383 00:09:18 ValidateAttrs 0 00:09:18 Remove 204 00:09:18 Create 382 00:09:18 Rename 0 00:09:18 SymLink 0 00:09:18 Link 0 00:09:18 MakeDir 1 00:09:18 RemoveDir 0 00:09:18 GetRootVolume 1 00:09:18 SetRootVolume 0 00:09:18 GetVolumeStatus 2 00:09:18 SetVolumeStatus 0 00:09:18 GetTime 98 00:09:18 GetStatistics 0 00:09:18 GetVolumeInfo 2 00:09:18 AllocFids 12 00:09:18 COP2 8 00:09:18 Resolve 0 00:09:18 Repair 0 00:09:18 SetVV 0 00:09:18 Reintegrate 0 00:09:18 OpenReintHandle 0 00:09:18 QueryReintHandle 0 00:09:18 SendReintFragment 0 00:09:18 CloseReintHandle 0 00:09:18 GetVolVS 5 00:09:18 ValidateVols 0 00:09:18 GetWBPermit 0 00:09:18 TossWBPermit 0 00:09:18 RejectWBPermit 0 00:09:18 GetAttrPlusSHA 194 00:09:18 ValidateAttrsPlusSHA 157 00:09:18 Total FetchDatas = 227, bytes transfered = 631277, transfer rate = 631277 bps 00:09:18 Fetched files <1k = 2; <8k = 223; <64k = 2; <512k = 0; >512k = 0. 00:09:18 Total StoreDatas = 382, bytes transfered = 1462401, transfer rate = 1462401 bps 00:09:18 Stored files <1k = 3; <8k = 379; <64k = 0; <512k = 0; >512k = 0. 00:09:18 Large vnode cache, 500 entries, 1 allocs, 2186 gets (10 reads), 1171 writes 00:09:18 Small vnode cache,500 entries, 381 allocs, 2407 gets (376 reads), 1728 writes 00:09:18 Volume header cache, 50 entries, 2583 gets, 0 replacements 00:09:18 Partition /vicepa: 32298296K available (minfree=5%), 29780200K free. Dirstats: get 0, put 0, flush 0 00:09:18 RPC Total bytes: sent = 1166701, received = 2534666 00:09:18 bytes sent: rpc = 429721, multirpc = 0, sftp = 736980, sftp multicasted = 0 00:09:18 bytes received: rpc = 956585, multirpc = 0, sftp = 1578081, sftp multicasted = 0 00:09:18 RPC Total packets: sent = 4652, received = 5066 00:09:18 packets sent: rpc = 3141, multirpc = 0, sftp = 1511, sftp multicasted = 0 00:09:18 packets received: rpc = 3138, multirpc = 0, sftp = 1928, sftp multicasted = 0 00:09:18 RPC Packets retried = 0, Invalid packets received = 1221, Busies sent = 1161 00:09:18 RPC Requests 2933, Good Requests 1712, Replies 205, Busies 0 00:09:18 RPC Counters: CCount 19; Unbinds 11; FConns 11; AConns 30; GCConns 0 00:09:18 RPC Creation counts: Conn 19; SL 23; PB Small 7, Med 10, Large 6; SS 3 00:09:18 RPC2 In Use: Conn 19; SS 3 00:09:18 RPC2 PB: InUse 5, Hold 0, Freeze 0, SFree 5, MFree 7, LFree 6 00:09:18 RPC2 HW: Freeze 0, Hold 0 00:09:18 SFTP: datas 751, datar 1699, acks 380, ackr 229, retries 0, duplicates 0 00:09:18 SFTP: timeouts 0, windowfulls 0, bogus 0, didpiggy 4 00:09:18 Total CB entries= 1260, blocks = 2; and total file entries = 759, blocks = 4 00:09:18 There are currently 11 connections in use 00:09:18 There are 2 workstations and 1 are active (req in < 15 mins) 00:09:18 Ether Total bytes: sent = 0, received = 0 00:09:18 Ether Packets: sent = 0, received = 0, errors = 0 00:09:18 Printing RVM statistics Transaction statistics current cumulative Started: 618 30195 Aborted: 0 0 Committed, flush: 557 27332 Committed, no_flush: 61 2863 Total committed: 618 30195 Committed, but not flushed: 0 Unflushed transactions length: 0 Not committed: 0 Split by log wrap: 0 3 Delayed by truncation: 0 0 Log function statistics current cumulative rvm_flush calls: 0 1 Internal flushes, incl. commit: 557 27097 Total flushes: 557 27098 Average flush time (msec): 3 3 Last flush time (msec): 8 rvm_truncate calls: 2 Automatic truncations: 61 Forced synch. truncations: 0 Recovery truncations: 23 Total truncations: 86 Average truncation time (sec): 0 Last truncation time (sec): 0 Last tree build time (sec): 0 Last tree apply time (sec): 0 Transaction records: 618 30198 Bookeeping records: 1 87 Log wrap-arounds: 0 3 Total records: 619 30288 Log used: 3% 5% Log written (bytes): 1077044 98204268 Timing Histograms Current Flush Timings (msec): <=25 <=50 <=100 <=250 <=500 <=1000 <=2500 <=5000 <=10000 > 10000 557 1 0 0 0 0 0 0 0 0 Cummulative Flush Timings (msec): <=25 <=50 <=100 <=250 <=500 <=1000 <=2500 <=5000 <=10000 > 10000 26508 18 11 0 0 0 0 0 0 0 Truncation Timings for Tree Build (sec): <=1 <=10 <=100 <=500 > 500 89 0 0 0 0 Truncation Timings for Tree Apply (sec): <=1 <=10 <=100 <=500 > 500 88 0 1 0 0 Total Truncation Timings (sec): <=1 <=10 <=100 <=500 > 500 88 0 1 0 0 Transaction Optimization Statistics current cumulative Ranges eliminated Range coalesce: 0 0 Trans coalesce: 0 0 Totals: 0 0 Avg. number eliminated per transaction Range coalesce: 0 0 Trans coalesce: 0 0 Totals: 0 0 Range length eliminated Range coalesce: 0 0 Trans coalesce: 0 0 Totals: 0 0 Log savings Range coalesce: 0 0 Trans coalesce: 0 0 Totals: 0 0 Transactions coalesced per flush: 0 0 Tranasction Modification Range Distributions Current Range Lengths (bytes): <=0 <=4 <=8 <=16 <=32 <=64 <=128 0 696 143 291 13 162 503 <=256 <=512 <=1024 <=2048 <=4096 > 4096 0 321 173 272 0 0 Cumulative Range Lengths (bytes): <=0 <=4 <=8 <=16 <=32 <=64 <=128 0 37926 7823 13109 1249 7016 19181 <=256 <=512 <=1024 <=2048 <=4096 > 4096 0 13197 6898 36226 3 2 Current Range Lengths Eliminated (bytes): Range coalesce: <=0 <=4 <=8 <=16 <=32 <=64 <=128 619 0 0 0 0 0 0 <=256 <=512 <=1024 <=2048 <=4096 > 4096 0 0 0 0 0 0 Trans coalesce: <=0 <=4 <=8 <=16 <=32 <=64 <=128 619 0 0 0 0 0 0 <=256 <=512 <=1024 <=2048 <=4096 > 4096 0 0 0 0 0 0 Totals: <=0 <=4 <=8 <=16 <=32 <=64 <=128 1238 0 0 0 0 0 0 <=256 <=512 <=1024 <=2048 <=4096 > 4096 0 0 0 0 0 0 Cumulative Range Lengths Eliminated (bytes): Range coalesce: <=0 <=4 <=8 <=16 <=32 <=64 <=128 29308 0 0 0 0 0 0 <=256 <=512 <=1024 <=2048 <=4096 > 4096 0 0 0 0 0 0 Trans coalesce: <=0 <=4 <=8 <=16 <=32 <=64 <=128 29308 0 0 0 0 0 0 <=256 <=512 <=1024 <=2048 <=4096 > 4096 0 0 0 0 0 0 Totals: <=0 <=4 <=8 <=16 <=32 <=64 <=128 58616 0 0 0 0 0 0 <=256 <=512 <=1024 <=2048 <=4096 > 4096 0 0 0 0 0 0 Current Number of Eliminated Ranges per Transaction Range coalesce: <=0 <=5 <=10 <=50 <=100 > 100 619 0 0 0 0 0 Trans coalesce: <=0 <=5 <=10 <=50 <=100 > 100 619 0 0 0 0 0 Totals: <=0 <=5 <=10 <=50 <=100 > 100 1238 0 0 0 0 0 Cummulative Number of Eliminated Ranges per Transaction Range coalesce: <=0 <=5 <=10 <=50 <=100 > 100 29308 0 0 0 0 0 Trans coalesce: <=0 <=5 <=10 <=50 <=100 > 100 29308 0 0 0 0 0 Totals: <=0 <=5 <=10 <=50 <=100 > 100 58616 0 0 0 0 0 Cummulative Number of Transactions Coalesced per flush Cycle <=0 <=5 <=10 <=50 <=100 > 100 29927 0 0 0 0 0 00:09:18 Printing RDS statistics Number of Free bytes: 3fed3340 Alloced bytes: 2c960 Mallocs: 4423 Frees: 3782 Preallocs: 0 Hits: 2461 Misses: 1957 Large Hits: 0 Large Misses: 5 Coalesces: 2862 Merges 1288 Not Merged: 70681 Times the Large List pointer has changed: 0 00:09:18 done 00:09:18 VShutdown: shutting down on-line volumes... 00:09:18 VShutdown: Taking volume coda.root.0(0x1000003) offline... 00:14:23 Callback failed RPC2_DEAD (F) for ws 212.85.15.251:32769 00:14:23 Unbinding RPC2 connection 14691 00:14:23 Unbinding RPC2 connection 11729 00:14:23 Unbinding RPC2 connection 2108 00:14:23 Unbinding RPC2 connection 8210 00:14:28 Callback failed RPC2_DEAD (F) for ws 212.85.15.253:32770 00:14:28 Unbinding RPC2 connection 11763 00:14:28 Unbinding RPC2 connection 309 00:14:28 Unbinding RPC2 connection 5492 00:14:28 Unbinding RPC2 connection 13647 00:54:18 SmonDaemon timer expired 00:54:18 Entered CheckRVMResStat 00:54:18 Starting SmonDaemon timer 01:54:18 SmonDaemon timer expired 01:54:18 Entered CheckRVMResStat 01:54:18 Starting SmonDaemon timer 02:54:18 SmonDaemon timer expired 02:54:18 Entered CheckRVMResStat 02:54:18 Starting SmonDaemon timer 03:54:19 SmonDaemon timer expired 03:54:19 Entered CheckRVMResStat 03:54:19 Starting SmonDaemon timer 04:54:19 SmonDaemon timer expired 04:54:19 Entered CheckRVMResStat 04:54:19 Starting SmonDaemon timer 05:54:19 SmonDaemon timer expired 05:54:19 Entered CheckRVMResStat 05:54:19 Starting SmonDaemon timer 06:54:19 SmonDaemon timer expired 06:54:19 Entered CheckRVMResStat 06:54:19 Starting SmonDaemon timer