Created attachment 152841 [details] Test results After deleting a (fairly) large file on an ssd based gmirror, the system becomes inresponsive for a certain period of time. This seems to be caused by the calls to BIO_DELETE on the mirror, which can be monitored with gstat -d. Doing exactly the same on an unmirrored UFS leaves the system unimpacted, as the DELETE operation takes only a fraction of time there. I've also tried tuning the behaviour of the mirror with the sysctl kern.geom.dev.delete_max_sectors. Setting it to 0 oder greater values than the default of 262144 does not significantly affect the performance. A script which I used to test with is attached, also the results reformatted in a better readable way. The system is non productive and can be used to figure out what is going wrong. Any help is appreciated.
Created attachment 152842 [details] Test script
I've added a debug statement to sys/ufs/ffs/ffs_alloc.c to compare the calls between a non-mirrored ufs and a gmirrored one: --- sys/ufs/ffs/ffs_alloc.c.orig 2015-02-09 16:24:06.000000000 +0100 +++ sys/ufs/ffs/ffs_alloc.c 2015-02-11 10:17:13.000000000 +0100 @@ -2313,6 +2313,9 @@ bip->bio_length = size; bip->bio_caller2 = tp; + printf("%s: starting BIO_DELETE for %jd bytes @ offset %jd\n", + __func__, size, bip->bio_offset); + mp = UFSTOVFS(ump); vn_start_secondary_write(NULL, &mp, 0); g_io_request(bip, (struct g_consumer *)devvp->v_bufobj.bo_private); Creating a 100m file and deleting it afterwards results in the same amount of calls to BIO_DELETE in both cases. Changing kern.geom.dev.delete_max_sectors does not influence the calls.
One more thing to add: the behaviour of the delete calls varies extremely. I subsequently created and deleted a 1G file and the whole delete procedure (monitored via iostat) took 32, 14, 10, 80 seconds to complete. I've disabled everything except syslog and ssh. Here is the script: --- 8< ---------------------------------------------- #!/bin/sh FSZ=1000 FILE=/usr/${FSZ}M echo "creating ${FSZ}M file $FILE..." dd if=/dev/random of=$FILE bs=1k count=${FSZ}k sync echo "done, hit enter to delete file..." read noop echo "deleting file..." unlink $FILE sync echo "done" echo "running iostat -w1 ada0 ada1" iostat -w1 ada0 ada1 --- 8< ---------------------------------------------- And the results: 1) 00:32.231 tty ada0 ada1 cpu tin tout KB/t tps MB/s KB/t tps MB/s us ni sy in id 1 115 52.20 591 30.13 52.13 592 30.15 0 0 8 0 91 0 343 32.00 4040 126.24 32.00 4033 126.04 0 0 22 0 78 0 223 32.00 1791 55.98 32.00 1796 56.12 0 0 24 0 76 0 203 32.00 1567 48.98 32.00 1567 48.95 0 0 19 0 81 0 184 32.00 4414 137.94 32.00 4426 138.30 0 0 21 0 79 0 333 32.00 2098 65.57 32.00 2092 65.36 0 0 24 0 75 0 168 32.00 1556 48.61 32.00 1567 48.96 0 0 24 0 76 0 177 32.00 1311 40.98 32.00 1310 40.95 0 0 24 0 76 0 191 32.00 1153 36.04 32.00 1150 35.95 0 0 23 0 77 0 182 32.00 1052 32.88 32.00 1040 32.51 0 0 21 0 78 0 178 32.00 944 29.51 32.00 971 30.33 0 0 24 0 76 0 181 32.00 889 27.78 32.00 882 27.57 0 0 23 0 77 0 179 32.00 811 25.34 32.00 829 25.90 0 0 24 0 76 0 189 32.00 778 24.33 32.00 755 23.58 0 0 24 0 76 0 191 32.00 640 19.99 32.00 624 19.49 0 0 23 0 77 0 164 32.00 469 14.67 32.00 470 14.70 0 0 21 0 79 0 177 32.00 500 15.61 32.00 596 18.64 0 0 22 0 77 0 175 32.00 605 18.90 32.00 572 17.87 0 0 24 0 76 0 183 32.00 565 17.65 32.00 523 16.35 0 0 23 0 77 0 186 32.00 701 21.92 32.00 729 22.77 0 0 23 0 77 0 189 32.00 445 13.91 32.00 491 15.35 0 0 24 0 76 0 177 32.00 467 14.58 32.00 403 12.61 0 0 24 0 76 0 313 32.00 385 12.02 32.00 437 13.65 0 0 24 0 76 0 181 32.00 419 13.11 32.00 351 10.96 0 0 24 0 76 0 175 32.00 366 11.44 32.00 361 11.29 0 0 23 0 77 0 180 32.00 300 9.39 32.00 387 12.10 0 0 25 0 75 0 187 32.00 363 11.34 32.00 285 8.91 0 0 22 0 78 0 178 32.00 310 9.67 32.00 307 9.58 0 0 24 0 76 0 191 32.00 260 8.14 32.00 320 9.99 0 0 24 0 76 0 177 32.00 319 9.96 32.00 254 7.93 0 0 18 0 82 0 194 31.95 1134 35.38 31.95 1125 35.11 0 0 17 0 83 0 210 0.00 0 0.00 0.00 0 0.00 0 0 0 0 100 0 197 0.00 0 0.00 4.00 2 0.01 0 0 0 0 100 0 93 0.00 0 0.00 0.00 0 0.00 0 0 0 0 100 0 94 0.00 0 0.00 0.00 0 0.00 0 0 0 0 100 2) 00:14.720 tty ada0 ada1 cpu tin tout KB/t tps MB/s KB/t tps MB/s us ni sy in id 1 113 52.12 564 28.69 52.06 565 28.71 0 0 8 0 92 0 340 32.00 4035 126.11 32.00 4035 126.11 0 0 23 0 77 0 227 32.00 1867 58.36 32.00 1868 58.38 0 0 23 0 77 0 200 32.00 1602 50.05 32.00 1600 49.99 0 0 19 0 81 0 238 31.99 4647 145.16 31.99 4629 144.60 0 0 22 0 78 0 215 32.00 2156 67.38 32.00 2187 68.35 0 0 25 0 75 0 193 32.00 1618 50.56 32.00 1687 52.71 0 0 24 0 76 0 195 32.00 1305 40.79 32.00 1401 43.77 0 0 25 0 75 0 193 32.00 1194 37.33 32.00 1178 36.80 0 0 25 0 75 0 156 32.00 1180 36.86 32.00 1035 32.34 0 0 22 0 77 0 193 32.00 5468 170.89 32.00 5085 158.89 0 0 21 0 78 0 203 32.00 3108 97.14 32.00 3496 109.24 0 0 23 0 76 0 206 32.00 1798 56.19 32.00 1797 56.16 0 0 21 0 78 0 175 32.00 768 23.99 32.00 767 23.96 0 0 7 0 92 0 165 0.00 0 0.00 0.00 0 0.00 0 0 0 0 100 0 71 0.00 0 0.00 0.00 0 0.00 0 0 0 0 100 0 58 0.00 0 0.00 0.00 0 0.00 0 0 0 0 100 3) 00:10.303 tty ada0 ada1 cpu tin tout KB/t tps MB/s KB/t tps MB/s us ni sy in id 1 111 52.06 560 28.46 52.00 561 28.47 0 0 8 0 92 0 328 32.00 10263 320.71 32.00 10138 316.80 0 0 27 0 73 0 232 32.00 3957 123.65 32.00 3881 121.27 0 0 26 0 74 0 161 32.00 3015 94.21 32.00 2946 92.06 0 0 25 0 75 0 157 32.00 2593 81.02 32.00 2531 79.09 0 0 26 0 74 0 156 32.00 3482 108.82 32.00 3558 111.19 0 0 22 0 78 0 159 32.00 2002 62.57 32.00 1923 60.09 0 0 26 0 74 0 148 32.00 1780 55.62 32.00 1935 60.47 0 0 22 0 78 0 181 32.00 1985 62.03 32.00 2152 67.26 0 0 19 0 81 0 181 32.00 1898 59.33 32.00 1899 59.36 0 0 9 0 91 0 183 0.00 0 0.00 0.00 0 0.00 0 0 0 0 100 0 168 0.00 0 0.00 0.00 0 0.00 0 0 0 0 100 0 58 0.00 0 0.00 0.00 0 0.00 0 0 0 0 100 4) 01:20.279 tty ada0 ada1 cpu tin tout KB/t tps MB/s KB/t tps MB/s us ni sy in id 1 110 52.00 562 28.52 51.94 563 28.54 0 0 8 0 92 0 350 32.00 4955 154.83 32.00 5004 156.39 0 0 27 0 73 0 218 32.00 1917 59.92 32.00 1934 60.45 0 0 26 0 74 0 160 32.00 1483 46.35 32.00 1477 46.14 0 0 25 0 75 0 156 32.00 1226 38.32 32.00 1269 39.67 0 0 24 0 76 0 137 32.00 1104 34.51 32.00 1097 34.28 0 0 25 0 75 0 139 32.00 998 31.19 32.00 994 31.07 0 0 26 0 74 0 138 32.00 908 28.37 32.00 920 28.75 0 0 26 0 74 0 153 32.00 832 25.99 32.00 858 26.81 0 0 25 0 75 0 153 32.00 773 24.17 32.00 786 24.55 0 0 24 0 76 0 142 32.00 721 22.54 32.00 737 23.05 0 0 25 0 75 0 161 32.00 679 21.22 32.00 670 20.95 0 0 25 0 75 0 156 32.00 646 20.20 32.00 608 18.99 0 0 26 0 74 0 183 32.00 584 18.26 32.00 565 17.65 0 0 25 0 75 0 190 32.00 551 17.23 32.00 528 16.51 0 0 26 0 74 0 167 32.00 500 15.63 32.00 496 15.50 0 0 25 0 75 0 173 32.00 460 14.37 32.00 468 14.64 0 0 24 0 76 0 169 32.00 423 13.22 32.00 444 13.87 0 0 24 0 76 0 168 32.00 393 12.29 32.00 413 12.91 0 0 25 0 75 0 172 32.00 379 11.85 32.00 375 11.73 0 0 25 0 75 0 168 32.00 341 10.67 32.00 364 11.37 0 0 26 0 74 0 149 32.00 348 10.88 32.00 318 9.94 0 0 25 0 75 0 280 32.00 303 9.47 32.00 325 10.17 0 0 25 0 75 0 169 32.00 298 9.32 32.00 297 9.29 0 0 24 0 76 0 171 32.00 290 9.05 32.00 271 8.47 0 0 25 0 75 0 177 32.00 269 8.41 32.00 263 8.23 0 0 25 0 75 0 176 32.00 246 7.67 32.00 230 7.20 0 0 25 0 75 0 179 32.00 188 5.88 32.00 191 5.97 0 0 25 0 75 0 175 32.00 185 5.79 32.00 194 6.06 0 0 25 0 75 0 201 31.98 1368 42.72 31.98 1429 44.63 0 0 23 0 77 0 190 32.00 198 6.17 32.00 257 8.03 0 0 26 0 74 0 172 32.00 159 4.97 32.00 233 7.28 0 0 26 0 74 0 170 32.00 151 4.73 32.00 229 7.17 0 0 25 0 75 0 181 32.00 143 4.47 31.88 227 7.06 0 0 26 0 74 0 196 32.00 132 4.14 32.00 228 7.11 0 0 25 0 75 0 133 32.00 125 3.92 32.00 225 7.05 0 0 25 0 75 0 168 32.00 123 3.85 32.00 220 6.88 0 0 25 0 75 0 184 32.00 113 3.53 32.00 221 6.91 0 0 25 0 75 0 188 32.00 116 3.62 32.00 214 6.67 0 0 23 0 77 0 214 31.85 180 5.59 32.00 145 4.53 0 0 24 0 76 0 190 32.00 183 5.70 32.00 135 4.20 0 0 24 0 76 0 161 32.00 182 5.67 32.00 127 3.97 0 0 23 0 77 0 175 32.00 485 15.17 32.00 185 5.78 0 0 24 0 76 0 286 32.00 279 8.73 32.00 261 8.17 0 0 23 0 77 0 173 32.00 171 5.35 32.00 179 5.59 0 0 25 0 75 0 168 32.00 167 5.23 32.00 110 3.44 0 0 24 0 76 0 173 32.00 150 4.68 32.00 123 3.84 0 0 24 0 76 0 169 32.00 152 4.75 32.00 118 3.68 0 0 23 0 77 0 177 32.00 151 4.73 32.00 112 3.51 0 0 24 0 76 0 173 32.00 154 4.81 32.00 109 3.40 0 0 24 0 76 0 171 32.00 151 4.73 32.00 105 3.29 0 0 24 0 76 0 133 32.00 151 4.73 32.00 103 3.20 0 0 24 0 76 0 151 32.00 149 4.64 32.00 101 3.15 0 0 23 0 77 0 185 32.00 132 4.12 32.00 116 3.63 0 0 24 0 76 0 181 32.00 140 4.37 32.00 107 3.35 0 0 24 0 76 0 180 32.00 138 4.30 32.00 104 3.24 0 0 23 0 77 0 183 32.00 137 4.30 32.00 104 3.24 0 0 24 0 76 0 177 32.00 120 3.75 32.00 118 3.69 0 0 24 0 76 0 144 32.00 121 3.79 32.00 115 3.59 0 0 23 0 77 0 174 32.00 123 3.84 32.00 111 3.47 0 0 24 0 76 0 58 32.00 113 3.52 32.00 120 3.76 0 0 25 0 75 0 188 32.00 114 3.57 32.00 113 3.54 0 0 24 0 75 0 292 32.00 123 3.85 32.00 103 3.20 0 0 23 0 77 0 171 32.00 113 3.53 32.00 111 3.47 0 0 25 0 75 0 291 32.00 113 3.53 32.00 109 3.41 0 0 25 0 75 0 174 32.00 87 2.73 32.00 135 4.20 0 0 26 0 74 0 164 32.00 87 2.73 32.00 133 4.15 0 0 24 0 76 0 169 32.00 100 3.12 32.00 118 3.67 0 0 24 0 76 0 172 32.00 120 3.76 32.00 94 2.94 0 0 24 0 76 0 167 32.00 122 3.80 32.00 91 2.85 0 0 20 0 80 0 163 32.00 126 3.94 32.00 87 2.71 0 0 17 0 83 0 207 32.00 124 3.89 32.00 101 3.14 0 0 18 0 82 0 224 32.00 102 3.19 32.00 102 3.19 0 0 19 0 81 0 156 32.00 102 3.20 32.00 101 3.17 0 0 18 0 82 0 60 32.00 101 3.15 32.00 101 3.15 0 0 17 0 83 0 177 32.00 160 5.00 32.00 145 4.52 0 0 21 0 79 0 213 31.90 548 17.08 31.91 563 17.55 0 0 6 0 94 0 209 0.00 0 0.00 0.00 0 0.00 0 0 0 0 100 0 193 0.00 0 0.00 0.00 0 0.00 0 0 0 0 100 Please note that this issue is also mentioned in the forums.
Running the script from comment #3 on a gmirror with only one component, the results are the following: 1) 9s tty ada0 ada1 cpu tin tout KB/t tps MB/s KB/t tps MB/s us ni sy in id 1 96 12.50 7 0.08 111.02 171 18.59 0 0 4 0 96 0 184 0.00 0 0.00 32.00 6613 206.65 0 0 18 0 82 0 59 0.00 0 0.00 32.00 3222 100.70 0 0 18 0 82 0 63 0.00 0 0.00 32.00 2817 88.02 0 0 18 0 82 0 62 0.00 0 0.00 32.00 2447 76.46 0 0 18 0 82 0 58 0.00 0 0.00 32.00 2634 82.31 0 0 16 0 84 0 58 0.00 0 0.00 32.00 3540 110.62 0 0 13 0 87 0 59 0.00 0 0.00 32.00 3682 115.06 0 0 13 0 87 0 59 0.00 0 0.00 32.00 5461 170.65 0 0 6 0 94 0 59 0.00 0 0.00 0.00 0 0.00 0 0 0 0 100 0 58 0.00 0 0.00 0.00 0 0.00 0 0 0 0 100 2) 5s tty ada0 ada1 cpu tin tout KB/t tps MB/s KB/t tps MB/s us ni sy in id 0 61 12.53 3 0.04 62.84 465 28.55 0 0 5 0 95 0 172 0.00 0 0.00 32.00 13636 426.09 0 0 21 0 79 0 60 0.00 0 0.00 32.00 8488 265.26 0 0 20 0 80 0 59 0.00 0 0.00 32.00 6232 194.73 0 0 13 0 87 0 59 0.00 0 0.00 32.00 1755 54.86 0 0 4 0 96 0 58 0.00 0 0.00 0.00 0 0.00 0 0 0 0 100 3) 9s tty ada0 ada1 cpu tin tout KB/t tps MB/s KB/t tps MB/s us ni sy in id 0 46 12.52 2 0.03 57.60 569 32.03 0 0 5 0 95 0 172 0.00 0 0.00 32.00 10313 322.27 0 0 22 0 78 0 60 0.00 0 0.00 32.00 3561 111.27 0 0 17 0 83 0 63 0.00 0 0.00 32.00 2442 76.32 0 0 18 0 82 0 62 0.00 0 0.00 32.00 2167 67.71 0 0 20 0 80 0 62 0.00 0 0.00 32.00 2090 65.32 0 0 20 0 80 0 61 0.00 0 0.00 32.00 2042 63.80 0 0 17 0 83 0 61 0.00 0 0.00 32.00 2368 74.00 0 0 14 0 86 0 61 0.00 0 0.00 32.00 5914 184.81 0 0 10 0 90 0 62 0.00 0 0.00 0.00 0 0.00 0 0 0 0 100 0 61 0.00 0 0.00 0.00 0 0.00 0 0 0 0 100 4) 14s tty ada0 ada1 cpu tin tout KB/t tps MB/s KB/t tps MB/s us ni sy in id 0 38 12.51 2 0.02 55.61 586 31.84 0 0 5 0 95 0 172 0.00 0 0.00 32.00 9241 288.79 0 0 19 0 81 0 63 0.00 0 0.00 32.00 3067 95.85 0 0 19 0 81 0 62 0.00 0 0.00 32.00 2305 72.03 0 0 19 0 81 0 62 0.00 0 0.00 32.00 1994 62.32 0 0 19 0 81 0 61 0.00 0 0.00 32.00 1784 55.75 0 0 18 0 82 0 60 0.00 0 0.00 32.00 1610 50.32 0 0 18 0 82 0 61 0.00 0 0.00 32.00 1446 45.20 0 0 18 0 82 0 62 0.00 0 0.00 32.00 1394 43.58 0 0 19 0 81 0 60 0.00 0 0.00 32.00 1800 56.26 0 0 12 0 88 0 61 0.00 0 0.00 32.00 1840 57.51 0 0 14 0 86 0 61 0.00 0 0.00 32.00 1900 59.37 0 0 12 0 88 0 61 0.00 0 0.00 32.00 1961 61.28 0 0 13 0 87 0 61 0.00 0 0.00 31.93 816 25.46 0 0 5 0 95 0 57 0.00 0 0.00 0.00 0 0.00 0 0 0 0 100 5) 7s tty ada0 ada1 cpu tin tout KB/t tps MB/s KB/t tps MB/s us ni sy in id 0 33 12.50 1 0.02 54.56 581 30.94 0 0 5 0 95 0 183 0.00 0 0.00 32.00 13082 408.80 0 0 23 0 76 0 60 0.00 0 0.00 32.00 4958 154.95 0 0 21 0 79 0 59 0.00 0 0.00 32.00 3581 111.92 0 0 19 0 81 0 59 0.00 0 0.00 32.00 3308 103.36 0 0 13 0 87 0 59 0.00 0 0.00 32.00 3331 104.10 0 0 13 0 87 0 59 0.00 0 0.00 31.98 2621 81.85 0 0 10 0 90 0 58 0.00 0 0.00 0.00 0 0.00 0 0 0 0 100 0 58 0.00 0 0.00 0.00 0 0.00 0 0 0 0 100
r280757 commit in head is supposed to fix this problem. I'll merge in to stable in couple weeks. Please test that change before if you can.
(In reply to Alexander Motin from comment #5) The revision r280757 of g_mirror.c indeed fixes the behaviour. I'd like to thank you very much for your efforts.