* Negative queue lengths in btt "iostat" output?
@ 2008-05-28 0:35 M. Edward (Ed) Borasky
2008-05-28 11:03 ` Alan D. Brunelle
2008-05-30 15:30 ` Alan D. Brunelle
0 siblings, 2 replies; 3+ messages in thread
From: M. Edward (Ed) Borasky @ 2008-05-28 0:35 UTC (permalink / raw)
To: linux-btrace
[-- Attachment #1: Type: text/plain, Size: 372 bytes --]
I'm experimenting with "btt" and I have a case where the "iostat"
emulation is generating negative queue lengths. They seem to be steadily
increasing in magnitude. The utilizations don't look right, either -- I
don't think this device was 100 percent busy for the entire run.
I've attached a sample -- the input files are huge, but I'll post them
if you need them.
[-- Attachment #2: LAMP_rebuild.iostat --]
[-- Type: text/plain, Size: 24220 bytes --]
Device: rrqm/s wrqm/s r/s w/s rsec/s wsec/s rkB/s wkB/s avgrq-sz avgqu-sz await svctm %util Stamp
( 8, 0) 1.70 13.40 88.87 4.00 2558.26 139.15 1279.13 69.57 29.05 -61.54 29.44 34.23 96.55 10.00
( 8, 0) 0.00 9.60 76.19 6.20 610.34 126.39 305.17 63.19 8.94 -175.09 44.63 49.84 99.80 20.00
( 8, 0) 0.00 7.99 74.62 2.20 601.00 81.52 300.50 40.76 8.88 -261.61 39.12 43.20 99.83 30.01
( 8, 0) 1.00 1577.91 60.38 25.59 961.24 12828.83 480.62 6414.41 160.41 -4705.21 1248.41 24177.05 99.88 40.02
( 8, 0) 0.00 34.26 100.18 2.20 801.43 291.65 400.71 145.82 10.68 -16283.51 38.97 52.02 99.86 50.03
( 8, 0) 0.30 26.68 100.34 3.10 1066.53 238.25 533.27 119.13 12.61 -16579.40 24.73 31.20 99.87 60.04
( 8, 0) 0.20 219.01 95.57 12.58 1044.21 1852.73 522.10 926.37 26.78 -17508.77 135.34 409.65 99.85 70.05
( 8, 0) 0.00 31.90 98.10 6.20 945.58 304.79 472.79 152.40 11.99 -19060.15 47.19 61.63 99.99 80.05
( 8, 0) 0.20 22.78 98.53 10.89 1248.72 269.41 624.36 134.71 13.87 -19359.59 24.85 30.08 99.85 90.06
( 8, 0) 0.00 28.76 181.54 25.66 1540.23 435.39 770.11 217.69 9.53 -19577.10 49.43 56.30 99.86 100.07
( 8, 0) 7.66 47.31 103.45 11.78 5786.01 477.39 2893.01 238.70 54.36 -19927.04 60.02 88.66 96.20 110.26
( 8, 0) 0.10 1931.07 26.10 40.60 699.12 13434.37 349.56 6717.19 211.92 -25855.88 495.14 14832.74 99.83 120.26
( 8, 0) 0.20 1723.27 28.99 90.98 461.49 16452.73 230.74 8226.36 140.99 -46607.45 624.48 9597.11 99.90 130.26
( 8, 0) 0.00 424.17 5.10 41.58 99.15 4256.07 49.57 2128.04 93.31 -59252.28 407.73 4113.57 99.91 140.27
( 8, 0) 0.00 113.91 8.77 16.54 195.34 1044.44 97.67 522.22 48.98 -61685.24 17.77 97.73 98.27 150.30
( 8, 0) 0.00 149.06 4.28 34.75 114.71 1471.28 57.35 735.64 40.63 -62912.87 67.28 324.21 99.32 160.35
( 8, 0) 0.10 318.82 10.71 33.43 288.06 2819.54 144.03 1409.77 70.40 -65548.43 79.33 652.47 97.58 170.43
( 8, 0) 0.00 178.18 6.52 22.55 151.34 1606.58 75.67 803.29 60.46 -67599.48 40.24 286.88 91.03 181.16
( 8, 0) 0.00 133.65 4.60 28.59 135.15 1299.53 67.58 649.77 43.23 -69515.39 26.26 132.02 99.91 191.16
( 8, 0) 0.19 223.91 14.00 26.56 381.26 2004.52 190.63 1002.26 58.82 -71763.68 43.16 281.63 93.54 201.59
( 8, 0) 0.00 140.77 7.40 21.20 175.16 1295.70 87.58 647.85 51.44 -73415.91 31.64 187.42 99.96 211.59
( 8, 0) 0.10 56.59 11.00 34.68 227.91 730.11 113.96 365.06 20.97 -74281.84 56.98 127.69 98.17 221.77
( 8, 0) 0.10 41.69 10.37 26.77 243.43 549.30 121.71 274.65 21.34 -74787.43 15.52 32.98 92.09 231.89
( 8, 0) 0.00 91.41 5.95 20.42 207.01 894.66 103.50 447.33 41.77 -75655.57 20.91 93.40 97.42 241.98
( 8, 0) 0.10 30.85 10.45 19.82 412.42 405.39 206.21 202.70 27.02 -76077.22 6.89 13.95 96.36 252.22
( 8, 0) 0.00 33.57 4.70 23.98 90.02 460.43 45.01 230.21 19.19 -76426.60 23.10 50.18 90.68 263.06
( 8, 0) 0.00 33.62 6.53 16.76 125.50 403.01 62.75 201.51 22.69 -76795.24 7.64 18.69 96.86 273.33
( 8, 0) 0.00 34.72 3.87 17.26 88.09 419.80 44.04 209.90 24.04 -77203.41 7.48 19.77 97.92 283.41
( 8, 0) 0.00 133.46 5.19 37.77 116.63 1373.00 58.32 686.50 34.68 -78042.84 60.66 249.13 95.91 293.63
( 8, 0) 0.00 52.99 4.87 21.18 116.13 594.16 58.06 297.08 27.27 -78983.70 9.37 28.45 97.10 303.69
( 8, 0) 0.00 36.97 6.40 22.08 195.07 474.08 97.53 237.04 23.49 -79424.05 15.60 35.87 97.75 313.69
( 8, 0) 0.30 50.82 10.18 30.65 250.75 658.11 125.37 329.06 22.26 -79878.15 42.87 96.54 90.25 323.81
( 8, 0) 0.00 45.94 2.33 25.88 53.50 576.92 26.75 288.46 22.35 -80366.92 38.53 101.30 90.94 334.12
( 8, 0) 0.00 32.52 3.28 19.49 63.64 417.63 31.82 208.82 21.14 -80770.80 8.61 20.92 84.39 344.18
( 8, 0) 0.00 101.03 2.77 22.46 78.37 994.25 39.18 497.13 42.51 -81759.64 35.56 177.94 94.79 354.29
( 8, 0) 0.00 33.00 1.99 15.35 55.83 391.63 27.92 195.81 25.79 -82093.99 5.43 15.78 87.78 364.32
( 8, 0) 0.20 30.63 12.37 15.17 511.62 369.55 255.81 184.78 32.00 -82425.20 5.57 11.81 84.37 374.34
( 8, 0) 0.00 43.46 1.98 19.11 51.48 506.88 25.74 253.44 26.48 -82800.96 12.97 39.71 86.54 384.44
( 8, 0) 0.00 32.87 6.14 24.55 133.85 461.74 66.92 230.87 19.41 -83190.27 40.69 84.27 98.63 394.54
( 8, 0) 0.20 32.66 6.17 17.92 250.15 406.29 125.07 203.15 27.24 -83562.34 18.90 44.67 80.67 404.58
( 8, 0) 0.10 36.22 2.79 20.65 104.56 462.14 52.28 231.07 24.17 -83891.18 15.76 40.18 98.95 414.61
( 8, 0) 0.00 51.89 2.60 29.30 61.59 653.52 30.80 326.76 22.42 -84324.10 81.31 213.62 96.20 424.61
( 8, 0) 0.20 37.59 11.56 18.54 467.38 452.23 233.69 226.11 30.54 -84780.84 12.70 28.64 98.02 434.64
( 8, 0) 0.00 85.48 3.54 22.53 118.04 868.02 59.02 434.01 37.83 -85387.09 13.64 58.39 98.09 444.80
( 8, 0) 0.10 63.97 1.34 26.22 69.92 726.14 34.96 363.07 28.88 -86282.53 40.45 134.46 82.76 455.21
( 8, 0) 0.00 312.04 3.58 25.32 119.83 2703.49 59.91 1351.75 97.71 -89256.66 177.05 2089.09 90.17 465.56
( 8, 0) 0.00 77.67 6.75 17.25 239.75 762.42 119.88 381.21 41.77 -90109.56 22.50 95.35 89.96 475.94
( 8, 0) 0.00 106.58 4.34 45.25 100.96 1220.95 50.48 610.47 26.66 -91060.21 111.92 352.45 96.92 486.08
( 8, 0) 0.00 35.09 4.96 18.84 109.45 433.82 54.72 216.91 22.83 -91801.93 6.89 17.07 97.56 496.17
( 8, 0) 0.20 46.98 2.67 18.60 155.09 525.42 77.55 262.71 32.00 -92251.89 6.65 21.40 98.77 506.28
( 8, 0) 0.00 29.09 2.49 19.53 125.14 390.55 62.57 195.28 23.42 -92576.38 13.46 31.25 96.74 516.32
( 8, 0) 0.00 48.35 3.74 36.53 96.11 679.86 48.06 339.93 19.27 -93001.23 68.00 149.64 96.70 526.47
( 8, 0) 0.00 44.74 5.21 21.83 115.62 534.86 57.81 267.43 24.06 -93519.87 18.31 48.62 96.09 536.64
( 8, 0) 0.90 49.78 8.00 20.89 272.68 565.36 136.34 282.68 29.01 -93960.39 8.38 23.11 99.90 546.65
( 8, 0) 1.17 116.67 36.80 34.65 2157.99 1211.32 1078.99 605.66 47.16 -95108.83 98.93 262.10 96.66 556.86
( 8, 0) 0.19 72.50 15.15 27.33 342.17 798.65 171.08 399.32 26.85 -95916.97 47.76 129.48 94.99 567.29
( 8, 0) 0.00 88.95 3.30 15.63 109.54 839.04 54.77 419.52 50.09 -96838.54 24.45 139.34 93.54 577.59
( 8, 0) 0.00 33.97 5.90 19.16 142.45 425.01 71.22 212.51 22.64 -97232.26 10.61 24.99 95.87 587.92
( 8, 0) 0.10 23.47 2.44 22.98 86.84 372.41 43.42 186.20 18.06 -97516.28 47.59 91.71 97.24 598.15
( 8, 0) 0.00 27.83 3.18 13.02 100.99 326.83 50.50 163.41 26.40 -97793.33 2.60 7.08 91.50 608.21
( 8, 0) 0.10 33.71 2.97 13.19 83.28 375.14 41.64 187.57 28.37 -98137.83 2.35 7.27 95.41 618.30
( 8, 0) 0.00 33.71 2.19 16.26 74.21 399.79 37.11 199.90 25.69 -98455.62 11.73 33.16 93.38 628.32
( 8, 0) 0.10 26.15 2.00 12.48 86.23 308.98 43.11 154.49 27.31 -98740.96 1.79 5.06 98.30 638.34
( 8, 0) 0.00 430.95 3.89 24.21 54.19 3641.24 27.10 1820.62 131.55 -100808.67 225.39 3683.04 97.25 648.38
( 8, 0) 0.00 65.36 4.90 34.28 85.55 797.16 42.78 398.58 22.53 -103519.55 59.81 159.61 99.92 658.38
( 8, 0) 0.20 36.89 15.07 19.73 183.25 452.96 91.62 226.48 18.28 -104016.50 31.55 65.17 94.12 668.47
( 8, 0) 0.00 379.42 8.73 69.86 115.94 3595.71 57.97 1797.86 47.22 -107035.31 261.49 1525.20 91.24 679.23
( 8, 0) 0.10 42.29 14.76 13.36 234.57 445.20 117.28 222.60 24.17 -108423.66 4.81 12.08 98.84 689.26
( 8, 0) 0.19 139.89 6.26 28.11 146.34 1343.98 73.17 671.99 43.36 -109612.14 35.27 179.05 94.96 699.65
( 8, 0) 0.00 39.90 2.20 16.30 70.40 451.19 35.20 225.60 28.19 -110318.79 5.65 17.86 98.83 709.65
( 8, 0) 0.00 28.00 2.60 24.30 68.00 418.38 34.00 209.19 18.08 -110684.10 56.82 115.97 96.78 719.65
( 8, 0) 0.00 866.82 0.40 101.94 4.00 7750.92 2.00 3875.46 75.77 -113968.59 315.00 2984.19 98.05 729.65
( 8, 0) 0.00 708.88 3.40 58.00 39.20 6136.59 19.60 3068.29 100.59 -122703.15 416.06 5221.48 99.99 739.65
( 8, 0) 0.10 641.77 6.50 73.70 109.20 5722.97 54.60 2861.48 72.72 -131662.96 298.28 2686.12 99.99 749.65
( 8, 0) 0.00 72.89 2.10 16.30 81.59 725.52 40.80 362.76 43.87 -133263.91 11.18 55.48 99.98 759.66
( 8, 0) 0.00 74.50 3.30 14.80 91.20 700.80 45.60 350.40 43.76 -134007.08 3.58 18.32 100.00 769.66
( 8, 0) 0.00 145.66 6.30 28.29 135.16 2221.96 67.58 1110.98 68.14 -135177.74 44.83 233.63 99.97 779.66
( 8, 0) 0.00 71.45 4.50 13.02 90.65 676.50 45.32 338.25 43.81 -136235.41 4.54 23.09 93.61 790.34
( 8, 0) 0.00 69.81 3.36 15.08 99.87 679.89 49.94 339.94 42.29 -137036.06 5.04 24.13 95.78 800.75
( 8, 0) 0.10 71.41 7.61 17.21 208.44 710.52 104.22 355.26 37.03 -137753.33 8.57 33.28 84.68 811.27
( 8, 0) 0.00 59.69 12.13 23.78 225.44 668.49 112.72 334.25 24.89 -138463.36 26.14 69.60 97.78 821.49
( 8, 0) 0.00 84.97 2.43 22.97 102.78 863.52 51.39 431.76 38.04 -139311.98 18.93 82.25 96.27 831.76
( 8, 0) 0.09 91.47 3.58 15.65 105.61 856.94 52.80 428.47 50.04 -140229.25 7.19 41.45 93.89 842.37
( 8, 0) 0.20 88.69 4.28 14.33 192.71 824.21 96.36 412.10 54.63 -141192.42 4.32 24.95 98.64 852.41
( 8, 0) 0.00 919.02 2.79 20.04 62.23 7512.54 31.11 3756.27 331.70 -145538.83 522.26 21540.66 94.10 862.44
( 8, 0) 0.00 77.42 2.27 17.28 48.98 758.44 24.49 379.22 41.29 -151211.57 14.77 73.26 97.36 872.57
( 8, 0) 0.00 65.39 5.57 18.91 121.03 674.43 60.52 337.22 32.49 -151895.89 7.03 25.82 98.53 882.61
( 8, 0) 0.00 91.64 4.19 19.35 109.29 889.51 54.65 444.75 42.44 -152732.70 13.49 66.04 98.40 892.64
( 8, 0) 0.00 124.29 3.29 13.54 115.53 1103.48 57.76 551.74 72.43 -154040.19 13.26 111.21 95.35 902.68
( 8, 0) 0.00 70.64 2.79 14.05 88.47 678.29 44.24 339.15 45.54 -154788.00 5.76 29.96 95.32 912.72
( 8, 0) 0.00 78.10 2.30 14.30 52.80 739.18 26.40 369.59 47.71 -155547.71 4.58 26.16 99.84 922.72
( 8, 0) 0.00 102.95 3.00 19.39 102.35 979.56 51.18 489.78 48.32 -156469.91 13.46 75.39 95.74 932.72
( 8, 0) 0.10 78.46 4.17 26.38 137.28 839.55 68.64 419.78 31.97 -157344.70 35.24 125.87 98.80 942.81
( 8, 0) 0.10 80.42 3.49 16.24 125.96 773.31 62.98 386.65 45.58 -158214.85 3.73 18.96 92.01 952.84
( 8, 0) 0.00 69.67 2.35 22.34 61.93 736.90 30.97 368.45 32.35 -158913.16 14.28 54.57 97.48 963.05
( 8, 0) 0.00 357.17 3.83 21.09 99.67 3026.12 49.83 1513.06 125.45 -160904.79 141.05 2162.94 96.55 973.24
( 8, 0) 0.00 554.75 3.62 22.13 101.84 4616.64 50.92 2308.32 183.21 -166135.50 197.98 4462.47 96.43 983.45
( 8, 0) 0.00 276.21 3.26 30.01 141.12 2450.50 70.56 1225.25 77.90 -170515.38 159.75 1486.14 86.43 993.88
( 8, 0) 0.10 159.00 2.40 25.59 176.99 1478.99 88.49 739.49 59.16 -172085.24 46.58 311.32 92.78 1004.28
( 8, 0) 0.10 23.39 29.89 16.79 591.81 325.49 295.90 162.75 19.65 -173142.26 7.11 10.70 99.89 1014.28
( 8, 0) 0.00 54.49 22.60 16.90 321.55 571.12 160.78 285.56 22.60 -173546.42 11.52 27.43 99.84 1024.28
( 8, 0) 0.10 932.82 6.30 102.16 171.93 8286.21 85.96 4143.11 77.99 -176472.13 329.25 3163.31 99.94 1034.29
( 8, 0) 0.00 414.08 23.18 72.83 394.00 3894.46 197.00 1947.23 44.67 -184517.95 642.99 3421.14 99.89 1044.30
( 8, 0) 0.00 180.07 21.18 24.59 342.84 1647.34 171.42 823.67 43.48 -188806.39 141.79 700.18 94.05 1054.59
( 8, 0) 0.20 93.30 7.42 30.94 364.60 995.44 182.30 497.72 35.46 -189940.15 75.32 258.94 97.57 1064.83
( 8, 0) 0.00 378.17 6.89 19.30 222.17 3179.75 111.09 1589.87 129.86 -192102.69 154.53 2385.35 95.56 1074.99
( 8, 0) 0.30 48.89 6.80 34.29 329.54 666.28 164.77 333.14 24.23 -194249.61 34.39 75.56 96.73 1084.99
( 8, 0) 0.10 41.19 5.25 17.68 273.57 471.75 136.79 235.88 32.51 -194696.46 6.16 17.25 95.77 1095.28
( 8, 0) 0.10 95.92 5.82 27.31 191.65 985.86 95.83 492.93 35.55 -195428.86 26.37 102.89 94.64 1105.43
( 8, 0) 0.00 46.86 7.39 33.67 161.46 647.45 80.73 323.73 19.70 -196126.43 29.66 63.52 99.87 1115.44
( 8, 0) 0.00 53.63 6.88 27.01 126.51 645.91 63.25 322.95 22.79 -196619.57 15.50 40.05 96.34 1125.62
( 8, 0) 0.00 40.25 8.39 27.96 197.35 547.31 98.68 273.66 20.48 -197107.38 31.08 65.49 99.36 1135.63
( 8, 0) 0.20 33.01 5.88 29.52 176.33 502.65 88.16 251.32 19.18 -197454.31 44.76 86.75 99.64 1145.66
( 8, 0) 0.00 42.06 5.97 20.25 158.83 500.76 79.42 250.38 25.16 -197862.09 13.14 34.25 95.46 1155.88
( 8, 0) 0.00 51.21 5.82 27.23 129.46 629.12 64.73 314.56 22.95 -198382.36 54.58 139.15 96.20 1166.01
( 8, 0) 0.10 51.65 7.97 26.07 145.59 621.73 72.80 310.86 22.54 -198876.26 26.83 67.63 96.65 1176.18
( 8, 0) 0.10 61.72 3.46 22.42 131.92 674.63 65.96 337.32 31.18 -199473.60 11.09 37.61 98.02 1186.31
( 8, 0) 0.10 30.94 5.99 20.06 219.56 411.98 109.78 205.99 24.25 -199882.38 15.48 33.94 97.93 1196.33
( 8, 0) 0.00 36.74 4.08 26.59 104.35 506.62 52.18 253.31 19.92 -200241.10 39.72 87.32 96.01 1206.37
( 8, 0) 0.00 92.06 3.49 18.55 93.36 884.90 46.68 442.45 44.38 -201143.47 19.66 101.77 99.06 1216.40
( 8, 0) 0.00 26.84 2.20 13.47 95.00 323.32 47.50 161.66 26.70 -201447.81 3.17 8.61 95.97 1226.42
( 8, 0) 0.20 35.51 2.39 24.94 196.33 484.44 98.16 242.22 24.91 -201797.81 46.46 107.18 99.12 1236.44
( 8, 0) 0.20 33.53 3.09 14.67 152.46 387.15 76.23 193.57 30.38 -202095.88 2.37 6.88 99.56 1246.46
( 8, 0) 0.20 28.14 2.00 17.76 190.02 367.27 95.01 183.63 28.20 -202421.87 26.84 65.35 94.97 1256.48
( 8, 0) 0.50 38.61 4.09 18.56 374.34 457.35 187.17 228.67 36.72 -202811.51 14.69 40.08 95.12 1266.51
( 8, 0) 0.00 36.61 2.99 14.66 128.49 410.21 64.25 205.11 30.51 -203162.58 3.04 9.36 91.57 1276.53
( 8, 0) 0.10 37.80 2.79 13.16 135.63 408.50 67.82 204.25 34.10 -203567.77 3.21 10.85 99.59 1286.56
( 8, 0) 0.10 34.52 3.09 36.22 165.24 565.96 82.62 282.98 18.60 -203908.52 124.59 234.33 97.71 1296.58
( 8, 0) 0.00 38.91 3.29 16.06 92.60 439.83 46.30 219.92 27.51 -204231.57 3.06 9.23 96.64 1306.60
( 8, 0) 0.10 45.69 4.49 15.56 142.04 490.77 71.02 245.39 31.56 -204711.46 4.64 15.26 96.85 1316.63
( 8, 0) 0.30 45.06 4.88 19.24 159.51 514.41 79.75 257.20 27.93 -205203.28 6.91 19.92 98.21 1326.66
( 8, 0) 0.00 47.06 6.18 20.94 168.30 544.77 84.15 272.38 26.29 -205646.54 12.18 33.33 95.86 1336.69
( 8, 0) 0.20 36.20 3.29 16.56 201.85 422.06 100.93 211.03 31.44 -206043.06 5.73 16.27 99.39 1346.71
( 8, 0) 0.00 37.91 3.19 15.76 96.56 429.33 48.28 214.66 27.75 -206431.97 4.09 12.27 98.05 1356.74
( 8, 0) 0.00 94.15 5.29 25.43 196.27 958.21 98.13 479.11 37.58 -207310.01 41.06 166.91 97.58 1366.77
( 8, 0) 0.00 31.01 5.18 15.95 156.35 376.51 78.17 188.25 25.21 -207676.31 6.34 15.66 95.63 1376.80
( 8, 0) 0.10 30.37 2.80 16.58 134.26 376.41 67.13 188.21 26.35 -208001.59 7.21 18.56 96.54 1386.81
( 8, 0) 0.10 48.38 3.80 24.49 149.54 582.97 74.77 291.49 25.89 -208433.52 25.37 68.87 99.85 1396.81
( 8, 0) 0.10 31.38 2.18 17.12 102.15 388.02 51.08 194.01 25.39 -208798.23 6.11 16.09 94.90 1406.91
( 8, 0) 0.00 31.30 2.89 15.65 114.03 375.57 57.01 187.78 26.41 -209093.94 4.57 12.29 98.30 1416.94
( 8, 0) 0.00 46.36 3.39 18.04 124.41 518.39 62.21 259.20 29.99 -209497.48 6.20 19.63 99.29 1426.98
( 8, 0) 0.00 35.33 4.38 21.99 150.47 460.18 75.24 230.09 23.15 -209915.00 14.24 33.34 98.40 1437.02
( 8, 0) 0.00 38.10 4.79 15.26 98.14 429.24 49.07 214.62 26.31 -210285.60 3.67 10.65 98.94 1447.05
( 8, 0) 0.00 40.48 2.99 26.42 105.28 537.59 52.64 268.79 21.86 -210681.45 36.89 87.68 89.58 1457.08
( 8, 0) 0.30 35.51 2.99 20.55 295.23 449.23 147.62 224.62 31.63 -211058.87 16.56 41.77 99.71 1467.11
( 8, 0) 0.30 37.10 2.39 14.56 223.42 413.33 111.71 206.66 37.55 -211430.69 4.03 12.93 95.40 1477.13
( 8, 0) 0.10 40.21 4.09 19.26 232.27 478.10 116.13 239.05 30.43 -211788.84 7.73 21.10 99.57 1487.16
( 8, 0) 0.20 28.94 3.29 13.37 233.91 338.49 116.95 169.24 34.35 -212147.79 3.09 8.51 95.79 1497.18
( 8, 0) 0.00 26.85 3.29 12.57 151.69 316.16 75.85 158.08 29.48 -212421.26 3.08 8.31 99.56 1507.20
( 8, 0) 0.40 34.29 6.00 15.59 291.89 399.85 145.95 199.92 32.04 -212725.54 8.10 21.12 99.80 1517.20
( 8, 0) 0.10 48.19 6.74 12.00 211.79 483.08 105.90 241.54 37.08 -213197.64 3.80 13.62 94.51 1527.29
( 8, 0) 0.10 90.32 5.39 21.98 203.01 898.36 101.51 449.18 40.23 -214101.49 35.49 152.74 96.27 1537.30
( 8, 0) 0.00 34.66 5.43 22.42 289.95 456.65 144.97 228.33 26.81 -214474.30 30.93 69.44 98.37 1547.42
( 8, 0) 0.10 48.92 2.98 16.01 132.85 521.04 66.42 260.52 34.43 -214939.83 5.91 21.19 89.34 1557.48
( 8, 0) 0.00 320.93 0.37 33.39 2.98 2837.48 1.49 1418.74 84.14 -218246.99 152.62 1603.63 84.34 1568.23
( 8, 0) 0.00 227.41 0.00 27.33 0.00 2037.89 0.00 1018.94 74.57 -220727.99 86.71 808.23 53.25 1578.84
( 8, 0) 0.00 50.37 0.00 24.01 0.00 595.04 0.00 297.52 24.79 -221331.97 17.01 52.73 51.09 1589.01
( 8, 0) 0.00 54.43 0.00 36.22 0.00 728.39 0.00 364.20 20.11 -221856.86 37.09 92.84 52.23 1599.17
( 8, 0) 0.00 60.17 0.00 33.13 0.00 753.61 0.00 376.80 22.75 -222442.38 17.59 49.54 65.58 1609.19
( 8, 0) 0.00 108.26 0.00 38.97 0.00 1188.74 0.00 594.37 30.50 -223548.80 55.43 209.44 52.48 1619.48
( 8, 0) 0.00 367.22 2.85 206.93 30.64 4600.30 15.32 2300.15 22.07 -225308.57 144.81 399.12 79.89 1629.66
( 8, 0) 0.70 1474.82 7.60 267.50 601.37 14066.51 300.68 7033.25 53.32 -235373.95 346.81 2207.40 98.11 1639.66
( 8, 0) 0.00 443.80 1.10 30.70 9.60 3798.40 4.80 1899.20 119.75 -244768.43 172.11 2574.17 81.90 1649.66
( 8, 0) 0.00 213.35 5.40 25.58 57.56 1913.86 28.78 956.93 63.64 -248528.71 66.08 521.24 90.83 1659.67
( 8, 0) 0.30 953.90 10.60 42.00 313.60 7970.40 156.80 3985.20 157.49 -254549.52 321.54 6154.81 97.15 1669.67
( 8, 0) 0.00 406.40 1.40 21.20 10.40 3420.79 5.20 1710.39 151.82 -260587.81 67.45 1280.41 97.38 1679.67
( 8, 0) 0.10 166.30 5.30 6.50 136.00 1382.40 68.00 691.20 128.68 -263037.59 46.19 697.59 75.81 1689.67
( 8, 0) 0.00 21.20 2.60 18.00 44.80 313.60 22.40 156.80 17.40 -264169.33 65.73 133.38 79.82 1699.67
( 8, 0) 0.00 98.80 0.10 23.20 0.80 976.00 0.40 488.00 41.92 -264905.83 49.76 260.77 86.69 1709.67
( 8, 0) 6.00 124.60 13.90 11.30 3158.38 1616.19 1579.19 808.09 189.47 -265912.95 13.45 83.20 82.11 1719.67
( 8, 0) 0.00 1181.70 0.80 16.40 26.40 9584.80 13.20 4792.40 558.79 -274429.73 536.07 37366.15 87.55 1729.67
( 8, 0) 0.00 1224.80 2.70 31.10 23.20 10047.20 11.60 5023.60 297.94 -285148.06 649.35 24179.79 99.00 1739.67
( 8, 0) 0.00 2013.38 6.20 70.90 276.80 16671.19 138.40 8335.60 219.82 -301975.28 311.07 8434.99 83.13 1749.67
Device: rrqm/s wrqm/s r/s w/s rsec/s wsec/s rkB/s wkB/s avgrq-sz avgqu-sz await svctm %util Stamp
( 8, 0) 0.17 177.01 11.51 26.47 275.39 1638.35 137.70 819.17 50.39 -145959.92 286.64 1624.03 94.38 TOTAL
^ permalink raw reply [flat|nested] 3+ messages in thread
* Re: Negative queue lengths in btt "iostat" output?
2008-05-28 0:35 Negative queue lengths in btt "iostat" output? M. Edward (Ed) Borasky
@ 2008-05-28 11:03 ` Alan D. Brunelle
2008-05-30 15:30 ` Alan D. Brunelle
1 sibling, 0 replies; 3+ messages in thread
From: Alan D. Brunelle @ 2008-05-28 11:03 UTC (permalink / raw)
To: linux-btrace
M. Edward (Ed) Borasky wrote:
> I'm experimenting with "btt" and I have a case where the "iostat"
> emulation is generating negative queue lengths. They seem to be
> steadily increasing in magnitude. The utilizations don't look right,
> either -- I don't think this device was 100 percent busy for the
> entire run.
>
> I've attached a sample -- the input files are huge, but I'll post them
> if you need them.
>
>
I'll take a look at this later this morning - haven't looked at the
iostat stuff in quite some time... :-)
Alan
^ permalink raw reply [flat|nested] 3+ messages in thread
* Re: Negative queue lengths in btt "iostat" output?
2008-05-28 0:35 Negative queue lengths in btt "iostat" output? M. Edward (Ed) Borasky
2008-05-28 11:03 ` Alan D. Brunelle
@ 2008-05-30 15:30 ` Alan D. Brunelle
1 sibling, 0 replies; 3+ messages in thread
From: Alan D. Brunelle @ 2008-05-30 15:30 UTC (permalink / raw)
To: linux-btrace
[-- Attachment #1: Type: text/plain, Size: 652 bytes --]
M. Edward (Ed) Borasky wrote:
> I'm experimenting with "btt" and I have a case where the "iostat"
> emulation is generating negative queue lengths. They seem to be steadily
> increasing in magnitude. The utilizations don't look right, either -- I
> don't think this device was 100 percent busy for the entire run.
>
> I've attached a sample -- the input files are huge, but I'll post them
> if you need them.
>
>
Hi Ed -
If you get a chance, could you try the attached patch - I have not
committed it, although it looks solid enough. I'm going to keep plugging
on this. [Note the stuff about await & svctm in the patch description.]
Thanks,
Alan
[-- Attachment #2: 0001-Massive-re-write-of-iostat-capability.patch --]
[-- Type: text/x-diff, Size: 22965 bytes --]
From c66b8b2a18b467e5f3205f7187c37f5d7d58fc52 Mon Sep 17 00:00:00 2001
From: Alan D. Brunelle <alan.brunelle@hp.com>
Date: Fri, 30 May 2008 11:25:11 -0400
Subject: [PATCH] Massive re-write of iostat capability
rrqm/s, wrqm/s, r/s, w/s, rkB/s, wkB/s, avgrq-sz, avgqu-sz, and %util
all look good -- match up well w/ iostat. await & svctm do /not/ match
up well w/ iostat, but "look" right when looking at the raw data.
For the record:
await == Average time between GETRQ and COMPLETION for all I/O requests
completed in that sample.
svctm == Averate time between ISSUE and COMPLETION for all I/O requests
completed in that sample
Signed-off-by: Alan D. Brunelle <alan.brunelle@hp.com>
---
btt/bt_timeline.c | 6 +-
btt/devs.c | 3 +
btt/globals.h | 50 +++---
btt/iostat.c | 467 ++++++++++++++++++++++++++++----------------------
btt/trace_complete.c | 16 ++-
btt/trace_im.c | 5 +-
btt/trace_issue.c | 2 +-
7 files changed, 310 insertions(+), 239 deletions(-)
diff --git a/btt/bt_timeline.c b/btt/bt_timeline.c
index 2eed087..8c5739e 100644
--- a/btt/bt_timeline.c
+++ b/btt/bt_timeline.c
@@ -60,14 +60,10 @@ int main(int argc, char *argv[])
handle_args(argc, argv);
init_dev_heads();
- iostat_init();
if (process() || output_avgs(avgs_ofp) || output_ranges(ranges_ofp))
return 1;
- if (iostat_ofp) {
- fprintf(iostat_ofp, "\n");
- iostat_dump_stats(iostat_last_stamp, 1);
- }
+ iostat_dump_stats();
if (msgs_ofp != stdout)
fclose(msgs_ofp);
diff --git a/btt/devs.c b/btt/devs.c
index 3cf7a6c..4e2ca4c 100644
--- a/btt/devs.c
+++ b/btt/devs.c
@@ -89,6 +89,7 @@ void dip_exit(void)
unplug_hist_exit(dip->unplug_hist_handle);
if (output_all_data)
q2d_release(dip->q2d_priv);
+ iostat_free(dip->stats);
free(dip);
}
}
@@ -127,6 +128,8 @@ struct d_info *dip_add(__u32 device, struct io *iop)
dip->pre_culling = 1;
if (output_all_data)
dip->q2d_priv = q2d_init();
+ make_dev_hdr(str, 256, dip, 1);
+ dip->stats = iostat_alloc(str);
n_devs++;
}
diff --git a/btt/globals.h b/btt/globals.h
index c4b7674..fc358b6 100644
--- a/btt/globals.h
+++ b/btt/globals.h
@@ -41,7 +41,7 @@
#define BIT_START(iop) ((iop)->t.sector)
#define BIT_END(iop) ((iop)->t.sector + ((iop)->t.bytes >> 9))
#define IOP_READ(iop) ((iop)->t.action & BLK_TC_ACT(BLK_TC_READ))
-#define IOP_RW(iop) (IOP_READ(iop) ? 1 : 0)
+#define IOP_RW(iop) (IOP_READ(iop) ? 0 : 1)
#define TO_SEC(nanosec) ((double)(nanosec) / 1.0e9)
#define TO_MSEC(nanosec) (1000.0 * TO_SEC(nanosec))
@@ -128,18 +128,6 @@ struct devmap {
char device[32], node[32], pci[32], devno[32];
};
-struct stats {
- __u64 rqm[2], ios[2], sec[2], wait, svctm;
- double last_qu_change, last_dev_change, tot_qusz, idle_time;
- int cur_qusz, cur_dev;
-};
-
-struct stats_t {
- double n;
- double rqm_s[2], ios_s[2], sec_s[2];
- double avgrq_sz, avgqu_sz, await, svctm, p_util;
-};
-
struct d_info {
struct list_head all_head, hash_head;
void *heads;
@@ -149,7 +137,7 @@ struct d_info {
void *q2d_priv;
FILE *d2c_ofp, *q2c_ofp;
struct avgs_info avgs;
- struct stats stats, all_stats;
+ void *stats;
__u64 last_q, n_qs, n_ds;
__u64 n_act_q, t_act_q; /* # currently active when Q comes in */
__u32 device;
@@ -193,7 +181,7 @@ extern struct avgs_info all_avgs;
extern __u64 last_q;
extern struct region_info all_regions;
extern struct list_head all_ios, free_ios;
-extern __u64 iostat_interval, iostat_last_stamp;
+extern __u64 iostat_interval;
extern time_t genesis, last_vtrace;
extern double t_astart, t_aend;
extern __u64 q_histo[N_HIST_BKTS], d_histo[N_HIST_BKTS];
@@ -221,6 +209,10 @@ void dip_plug(__u32 dev, double cur_time);
void dip_unplug(__u32 dev, double cur_time, __u64 nio_ups);
void dip_unplug_tm(__u32 dev, __u64 nio_ups);
void dip_exit(void);
+static inline void *dip_get_stats(struct d_info *dip)
+{
+ return dip->stats;
+}
/* dip_rb.c */
int rb_insert(struct rb_root *root, struct io *iop);
@@ -230,14 +222,26 @@ void rb_foreach(struct rb_node *n, struct io *iop,
struct list_head *head);
/* iostat.c */
-void iostat_init(void);
-void iostat_getrq(struct io *iop);
-void iostat_merge(struct io *iop);
-void iostat_issue(struct io *iop);
-void iostat_unissue(struct io *iop);
-void iostat_complete(struct io *d_iop, struct io *c_iop);
-void iostat_check_time(__u64 stamp);
-void iostat_dump_stats(__u64 stamp, int all);
+void *iostat_alloc(char *hdr);
+void iostat_free(void *dsp);
+void iostat_insert(void *arg, struct io *i_iop);
+void iostat_issue(void *arg, struct io *d_iop);
+void iostat_merge(void *arg, struct io *iop);
+void iostat_complete(void *arg, struct io *c_iop, __u64 d2c, __u64 g2c,
+ unsigned int nqs);
+void __iostat_check_time(__u64 now);
+void __iostat_dump_stats(void);
+
+static inline void iostat_check_time(__u64 now)
+{
+ if (iostat_ofp)
+ __iostat_check_time(now);
+}
+static inline void iostat_dump_stats(void)
+{
+ if (iostat_ofp)
+ __iostat_dump_stats();
+}
/* latency.c */
void latency_init(struct d_info *dip);
diff --git a/btt/iostat.c b/btt/iostat.c
index d701e2f..88373be 100644
--- a/btt/iostat.c
+++ b/btt/iostat.c
@@ -1,7 +1,7 @@
/*
* blktrace output analysis: generate a timeline & gather statistics
*
- * Copyright (C) 2006 Alan D. Brunelle <Alan.Brunelle@hp.com>
+ * Copyright (C) 2006-2008 Alan D. Brunelle <Alan.Brunelle@hp.com>
*
* This program is free software; you can redistribute it and/or modify
* it under the terms of the GNU General Public License as published by
@@ -18,194 +18,244 @@
* Foundation, Inc., 59 Temple Place, Suite 330, Boston, MA 02111-1307 USA
*
*/
-#include <stdio.h>
-#include <unistd.h>
+
+#include <float.h>
#include "globals.h"
-#define INC_STAT(dip, fld) \
- do { \
- (dip)->stats. fld ++; \
- (dip)->all_stats. fld ++; \
- } while (0)
-
-#define DEC_STAT(dip, fld) \
- do { \
- (dip)->stats. fld --; \
- (dip)->all_stats. fld --; \
- } while (0)
-
-#define ADD_STAT(dip, fld, val) \
- do { \
- __u64 __v = (val); \
- (dip)->stats. fld += __v; \
- (dip)->all_stats. fld += __v; \
- } while (0)
-
-#define SUB_STAT(dip, fld, val) \
- do { \
- __u64 __v = (val); \
- (dip)->stats. fld -= __v; \
- (dip)->all_stats. fld -= __v; \
- } while (0)
-
-__u64 last_start, iostat_last_stamp;
+struct __stats {
+ __u64 sectors[2], ios[2], merges[2]; // READ & WRITE
+};
+
+struct disk_stats {
+ struct list_head head;
+ char *hdr;
+ __u64 stamp;
+ __u64 last_q, last_idle, busy_ticks;
+ __u64 rq_ticks, nqs, io_ticks;
+ long long in_flight, qusz;
+ double avgqsz;
+ struct __stats stats[2]; /* 0 == last values */
+
+ double sum_merges[2], sum_ios[2], sum_secs[2];
+ double sum_avgqsz, sum_await, sum_svctm, sum_util;
+};
+
+static __u64 last_seen = (__u64)-1;
+static __u64 last_start = (__u64)-1;
+static int ndumps = 0;
+
__u64 iostat_interval = 1000000000;
char *iostat_name = NULL;
FILE *iostat_ofp = NULL;
-void dump_hdr(void)
+#define delta_fld(dsp, fld) ((dsp)->stats[1]. fld - (dsp)->stats[0]. fld)
+
+static void clear_stats(struct __stats *sp)
{
- fprintf(iostat_ofp, "Device: rrqm/s wrqm/s r/s w/s "
- "rsec/s wsec/s rkB/s wkB/s "
- "avgrq-sz avgqu-sz await svctm %%util Stamp\n");
+ memset(sp, 0, sizeof(*sp));
}
-void iostat_init(void)
+void *iostat_alloc(char *hdr)
{
- last_start = (__u64)-1;
- if (iostat_ofp)
- dump_hdr();
+ struct disk_stats *dsp = malloc(sizeof(*dsp));
+
+ memset(dsp, 0, sizeof(*dsp));
+ dsp->hdr = strdup(hdr);
+
+ return dsp;
}
-void update_tot_qusz(struct d_info *dip, double now)
+void iostat_free(void *arg)
{
- dip->stats.tot_qusz += ((now - dip->stats.last_qu_change) *
- dip->stats.cur_qusz);
- dip->all_stats.tot_qusz += ((now - dip->all_stats.last_qu_change) *
- dip->all_stats.cur_qusz);
+ struct disk_stats *dsp = arg;
- dip->stats.last_qu_change = dip->all_stats.last_qu_change = now;
+ free(dsp->hdr);
+ free(dsp);
}
-void update_idle_time(struct d_info *dip, double now, int force)
+void iostat_insert(void *arg, struct io *i_iop)
{
- if (dip->stats.cur_dev == 0 || force) {
- dip->stats.idle_time += (now - dip->stats.last_dev_change);
- dip->all_stats.idle_time +=
- (now - dip->all_stats.last_dev_change);
+ struct disk_stats *dsp = arg;
+
+ if (dsp->qusz > 0) {
+ double dt = TO_SEC(i_iop->t.time - dsp->last_q);
+ dsp->avgqsz += ((double)(dsp->qusz) * dt);
}
- dip->stats.last_dev_change = dip->all_stats.last_dev_change = now;
+
+ dsp->qusz++;
+ dsp->last_q = i_iop->t.time;
}
-void __dump_stats(__u64 stamp, int all, struct d_info *dip, struct stats_t *asp)
+void iostat_issue(void *arg, struct io *d_iop)
{
- char hdr[16];
- struct stats *sp;
- double dt, nios, avgrq_sz, p_util, nrqm, await, svctm;
- double now = TO_SEC(stamp);
-
- if (all) {
- dt = (double)stamp / 1.0e9;
- sp = &dip->all_stats;
- }
- else {
- dt = (double)(stamp-last_start) / 1.0e9;
- sp = &dip->stats;
- }
+ struct disk_stats *dsp = arg;
+
+ if (dsp->in_flight == 0)
+ dsp->last_idle = d_iop->t.time;
+
+ dsp->in_flight++;
+}
+
+void iostat_merge(void *arg, struct io *iop)
+{
+ struct disk_stats *dsp = arg;
+ dsp->stats[1].merges[IOP_RW(iop)]++;
+}
+
+void iostat_complete(void *arg, struct io *c_iop, __u64 d2c, __u64 g2c,
+ unsigned int nqs)
+{
+ struct disk_stats *dsp = arg;
+ int rw = IOP_RW(c_iop);
+
+ dsp->stats[1].sectors[rw] += (c_iop->t.bytes >> 9);
+ dsp->stats[1].ios[rw]++;
- nios = (double)(sp->ios[0] + sp->ios[1]);
- nrqm = (double)(sp->rqm[0] + sp->rqm[1]);
- update_idle_time(dip, now, 1);
- update_tot_qusz(dip, now);
+ dsp->nqs += nqs;
+ if (g2c != (__u64)-1)
+ dsp->rq_ticks += g2c;
+ if (d2c != (__u64)-1)
+ dsp->io_ticks += d2c;
- if (nios > 0.0) {
- avgrq_sz = (double)(sp->sec[0] + sp->sec[1]) / nios;
- svctm = TO_MSEC(sp->svctm) / nios;
+ if (dsp->in_flight == 1)
+ dsp->busy_ticks += (c_iop->t.time - dsp->last_idle);
+ dsp->in_flight--;
+
+ if (dsp->qusz > 0) {
+ double dt = TO_SEC(c_iop->t.time - dsp->last_q);
+ dsp->avgqsz += ((double)(dsp->qusz) * dt);
}
- else
- avgrq_sz = svctm = 0.0;
- await = ((nios + nrqm) > 0.0) ? TO_MSEC(sp->wait) / (nios+nrqm) : 0.0;
- p_util = (sp->idle_time <= dt) ? 100.0 * (1.0 - (sp->idle_time / dt)) :
- 0.0;
+ dsp->qusz--;
+ dsp->last_q = c_iop->t.time;
+}
- /*
- * For AWAIT: nios should be the same as number of inserts
- * and we add in nrqm (number of merges), which should give
- * us the total number of IOs sent to the block IO layer.
- */
- fprintf(iostat_ofp, "%-11s ", make_dev_hdr(hdr, 11, dip, 1));
- fprintf(iostat_ofp, "%8.2lf ", (double)sp->rqm[1] / dt);
- fprintf(iostat_ofp, "%8.2lf ", (double)sp->rqm[0] / dt);
- fprintf(iostat_ofp, "%7.2lf ", (double)sp->ios[1] / dt);
- fprintf(iostat_ofp, "%7.2lf ", (double)sp->ios[0] / dt);
- fprintf(iostat_ofp, "%9.2lf ", (double)sp->sec[1] / dt);
- fprintf(iostat_ofp, "%9.2lf ", (double)sp->sec[0] / dt);
- fprintf(iostat_ofp, "%9.2lf ", (double)(sp->sec[1] / 2) / dt);
- fprintf(iostat_ofp, "%9.2lf ", (double)(sp->sec[0] / 2) / dt);
- fprintf(iostat_ofp, "%8.2lf ", avgrq_sz);
- fprintf(iostat_ofp, "%8.2lf ", (double)sp->tot_qusz / dt);
- fprintf(iostat_ofp, "%7.2lf ", await);
- fprintf(iostat_ofp, "%7.2lf ", svctm);
- fprintf(iostat_ofp, "%6.2lf", p_util);
- if (all)
- fprintf(iostat_ofp, "%8s\n", "TOTAL");
- else {
- fprintf(iostat_ofp, "%8.2lf\n", TO_SEC(stamp));
- sp->rqm[0] = sp->rqm[1] = 0;
- sp->ios[0] = sp->ios[1] = 0;
- sp->sec[0] = sp->sec[1] = 0;
- sp->wait = sp->svctm = 0;
+void sum_results(struct disk_stats *dsp, double *merges, double *ios,
+ double *secs, double avgqsz, double await,
+ double svctm, double util)
+{
+ int i;
- sp->tot_qusz = sp->idle_time = 0.0;
+ for (i = 0; i < 2; i++) {
+ dsp->sum_merges[i] += merges[i];
+ dsp->sum_ios[i] += ios[i];
+ dsp->sum_secs[i] += secs[i];
}
- if (asp) {
- int i;
+ dsp->sum_avgqsz += avgqsz;
+ dsp->sum_await += await;
+ dsp->sum_svctm += svctm;
+ dsp->sum_util += util;
+}
- asp->n += 1.0;
- for (i = 0; i < 2; i++) {
- asp->rqm_s[i] += ((double)sp->rqm[i] / dt);
- asp->ios_s[i] += ((double)sp->ios[i] / dt);
- asp->sec_s[i] += ((double)sp->sec[i] / dt);
- }
- asp->avgrq_sz += avgrq_sz;
- asp->avgqu_sz += (double)sp->tot_qusz / dt;
- asp->await += await;
- asp->svctm += svctm;
- asp->p_util += p_util;
+void dump_hdr(FILE *ofp)
+{
+ fprintf(ofp,
+ "%13s %8s %8s %8s %8s %8s %8s %8s %8s %8s %8s %6s %s\n",
+ "Device", "rrqm/s", "wrqm/s", "r/s", "w/s",
+ "rkB/s", "wkB/s", "avgrq-sz", "avgqu-sz", "await",
+ "svctm", "%util", "Stamp");
+}
+
+void dump(struct disk_stats *dsp, struct disk_stats *adsp, __u64 now,
+ double dt, char *tail)
+{
+ FILE *ofp = iostat_ofp;
+ double await, arqsz, busy_ticks, util, svctm;
+ double merges[2] = {
+ (double)delta_fld(dsp, merges[0]),
+ (double)delta_fld(dsp, merges[1])
+ };
+ double secs[2] = {
+ (double)delta_fld(dsp, sectors[0]),
+ (double)delta_fld(dsp, sectors[1])
+ };
+ double ios[2] = {
+ (double)delta_fld(dsp, ios[0]),
+ (double)delta_fld(dsp, ios[1])
+ };
+ double nios = ios[0] + ios[1];
+ double avgqsz = dsp->avgqsz / dt;
+
+ busy_ticks = TO_SEC(dsp->busy_ticks);
+ util = 100.0 * (busy_ticks / dt);
+
+ if (ios[0] || ios[1]) {
+ arqsz = (secs[0] + secs[1]) / nios;
+ await = 1000.0 * (TO_SEC(dsp->rq_ticks) / dsp->nqs);
+ svctm = 1000.0 * (TO_SEC(dsp->io_ticks) / nios);
}
+ else
+ await = arqsz = svctm = 0.0;
+
+ fprintf(ofp, "%13s ", dsp->hdr);
+ fprintf(ofp, "%8.2f %8.2f ", merges[0] / dt, merges[1] / dt);
+ fprintf(ofp, "%8.2f %8.2f ", ios[0] / dt, ios[1] / dt);
+ fprintf(ofp, "%8.1f %8.1f ", secs[0] / (2 * dt), secs[1] / (2 * dt));
+ fprintf(ofp, "%8.2f ", arqsz);
+ fprintf(ofp, "%8.2f ", avgqsz);
+ fprintf(ofp, "%8.2f ", await);
+ fprintf(ofp, "%8.2f ", svctm);
+ fprintf(ofp, "%6.2f ", util);
+ fprintf(ofp, "%6s\n", tail);
+
+ /*
+ * Accumulate results
+ */
+ sum_results(dsp, merges, ios, secs, avgqsz, await, svctm, util);
+ sum_results(adsp, merges, ios, secs, avgqsz, await, svctm, util);
+
+ /*
+ * Clear out counters, save current stats as previous.
+ */
+ dsp->busy_ticks = 0;
+ dsp->last_idle = now;
+ dsp->rq_ticks = dsp->io_ticks = 0;
+ dsp->nqs = 0;
+ dsp->last_q = now;
+ dsp->avgqsz = 0.0;
+
+ memcpy(&dsp->stats[0], &dsp->stats[1], sizeof(dsp->stats[1]));
}
-void __dump_stats_t(__u64 stamp, struct stats_t *asp, int all)
+void dump_a(struct disk_stats *dsp, double dt, int ndevs, int ndumps,
+ char *pre, char *pst)
{
- if (asp->n < 2.0) return; // What's the point?
-
- fprintf(iostat_ofp, "%-11s ", "TOTAL");
- fprintf(iostat_ofp, "%8.2lf ", asp->rqm_s[0]);
- fprintf(iostat_ofp, "%8.2lf ", asp->rqm_s[1]);
- fprintf(iostat_ofp, "%7.2lf ", asp->ios_s[0]);
- fprintf(iostat_ofp, "%7.2lf ", asp->ios_s[1]);
- fprintf(iostat_ofp, "%9.2lf ", asp->sec_s[0]);
- fprintf(iostat_ofp, "%9.2lf ", asp->sec_s[1]);
- fprintf(iostat_ofp, "%9.2lf ", asp->sec_s[0] / 2.0);
- fprintf(iostat_ofp, "%9.2lf ", asp->sec_s[1] / 2.0);
- fprintf(iostat_ofp, "%8.2lf ", asp->avgrq_sz / asp->n);
- fprintf(iostat_ofp, "%8.2lf ", asp->avgqu_sz / asp->n);
- fprintf(iostat_ofp, "%7.2lf ", asp->await / asp->n);
- fprintf(iostat_ofp, "%7.2lf ", asp->svctm / asp->n);
- fprintf(iostat_ofp, "%6.2lf", asp->p_util / asp->n);
- if (all)
- fprintf(iostat_ofp, "%8s\n", "TOTAL");
- else
- fprintf(iostat_ofp, "%8.2lf\n", TO_SEC(stamp));
+ FILE *ofp = iostat_ofp;
+ double rd_merges = dsp->sum_merges[0];
+ double wr_merges = dsp->sum_merges[1];
+ double rd_ios = dsp->sum_ios[0];
+ double wr_ios = dsp->sum_ios[1];
+ double nios = rd_ios + wr_ios;
+ double rd_sec = dsp->sum_secs[0];
+ double wr_sec = dsp->sum_secs[1];
+ double arqsz = (rd_ios || wr_ios) ? (rd_sec + wr_sec) / nios : 0.0;
+
+ fprintf(ofp, "%13s ", pre);
+ fprintf(ofp, "%8.2f %8.2f ", rd_merges / dt, wr_merges / dt);
+ fprintf(ofp, "%8.2f %8.2f ", rd_ios / dt, wr_ios / dt);
+ fprintf(ofp, "%8.1f %8.1f ", rd_sec / (2 * dt), wr_sec / (2 * dt));
+ fprintf(ofp, "%8.2f ", arqsz);
+ fprintf(ofp, "%8.2f ", dsp->sum_avgqsz / (double)(ndevs * ndumps));
+ fprintf(ofp, "%8.2f ", dsp->sum_await / (double)(ndevs * ndumps));
+ fprintf(ofp, "%8.2f ", dsp->sum_svctm / (double)(ndevs * ndumps));
+ fprintf(ofp, "%6.2f ", dsp->sum_util / (double)(ndevs * ndumps));
+ fprintf(ofp, "%6s\n", pst);
}
-void iostat_dump_stats(__u64 stamp, int all)
+void collect_dsps(struct list_head *head)
{
struct d_info *dip;
- struct stats_t as;
-
- memset(&as, 0, sizeof(struct stats_t));
- if (all)
- dump_hdr();
+ struct disk_stats *dsp;
if (devices == NULL) {
struct list_head *p;
__list_for_each(p, &all_devs) {
dip = list_entry(p, struct d_info, all_head);
- __dump_stats(stamp, all, dip, &as);
+ dsp = dip_get_stats(dip);
+
+ list_add_tail(&dsp->head, head);
}
}
else {
@@ -215,82 +265,91 @@ void iostat_dump_stats(__u64 stamp, int all)
while (p && ((i = sscanf(p, "%u,%u", &mjr, &mnr)) == 2)) {
dip = __dip_find((__u32)((mjr << MINORBITS) | mnr));
- __dump_stats(stamp, all, dip, &as);
+ dsp = dip_get_stats(dip);
+
+ list_add_tail(&dsp->head, head);
p = strchr(p, ';');
if (p) p++;
}
}
-
- __dump_stats_t(stamp, &as, all);
-
- if (!all && iostat_ofp)
- fprintf(iostat_ofp, "\n");
}
-void iostat_check_time(__u64 stamp)
+void dump_stats(__u64 now, int clear0)
{
- if (iostat_ofp) {
- if (last_start == (__u64)-1)
- last_start = stamp;
- else if ((stamp - last_start) >= iostat_interval) {
- iostat_dump_stats(stamp, 0);
- last_start = stamp;
- }
-
- iostat_last_stamp = stamp;
+ double dt = TO_SEC(now - last_start);
+ int ndevs = 0;
+ char buf[128];
+ struct disk_stats adsp, *dsp;
+ struct list_head *p, *q;
+ LIST_HEAD(dsps);
+
+ memset(&adsp, 0, sizeof(adsp));
+ adsp.hdr = "TOTAL";
+
+ sprintf(buf, "%6.1lf", TO_SEC(now));
+ collect_dsps(&dsps);
+
+ list_for_each_safe(p, q, &dsps) {
+ dsp = list_entry(p, struct disk_stats, head);
+ list_del(&dsp->head);
+
+ if (dsp->in_flight)
+ dsp->busy_ticks += (now - dsp->last_idle);
+ if (clear0)
+ clear_stats(&dsp->stats[0]);
+ dump(dsp, &adsp, now, dt, buf);
+ ndevs++;
}
-}
-
-void iostat_getrq(struct io *iop)
-{
- update_tot_qusz(iop->dip, TO_SEC(iop->t.time));
- INC_STAT(iop->dip, cur_qusz);
-}
-
-void iostat_merge(struct io *iop)
-{
- INC_STAT(iop->dip, rqm[IOP_RW(iop)]);
-}
-
-void iostat_issue(struct io *iop)
-{
- int rw = IOP_RW(iop);
- struct d_info *dip = iop->dip;
- double now = TO_SEC(iop->t.time);
- INC_STAT(dip, ios[rw]);
- ADD_STAT(dip, sec[rw], iop->t.bytes >> 9);
+ if (ndevs > 1) {
+ dump_a(&adsp, dt, ndevs, 1, "ITER", "AVG");
+ fprintf(iostat_ofp, "\n");
+ }
- update_idle_time(dip, now, 0);
- INC_STAT(dip, cur_dev);
+ ndumps++;
}
-void iostat_unissue(struct io *iop)
+void __iostat_check_time(__u64 now)
{
- int rw = IOP_RW(iop);
- struct d_info *dip = iop->dip;
+ if (!iostat_ofp)
+ return;
+ if (last_start == (__u64)-1) {
+ dump_hdr(iostat_ofp);
+ last_start = now;
+ }
+ else if ((now - last_start) >= iostat_interval) {
+ dump_stats(now, 0);
+ last_start = now;
+ }
- DEC_STAT(dip, ios[rw]);
- SUB_STAT(dip, sec[rw], iop->t.bytes >> 9);
- DEC_STAT(dip, cur_dev);
+ last_seen = now;
}
-void iostat_complete(struct io *q_iop, struct io *c_iop)
+void __iostat_dump_stats(void)
{
- double now = TO_SEC(c_iop->t.time);
- struct d_info *dip = q_iop->dip;
-
- if (q_iop->i_time != (__u64)-1)
- ADD_STAT(c_iop->dip, wait, tdelta(q_iop->i_time,c_iop->t.time));
- else if (q_iop->m_time != (__u64)-1)
- ADD_STAT(c_iop->dip, wait, tdelta(q_iop->m_time,c_iop->t.time));
-
- update_tot_qusz(dip, now);
- DEC_STAT(dip, cur_qusz);
-
- update_idle_time(dip, now, 0);
- DEC_STAT(dip, cur_dev);
+ int ndevs = 0;
+ LIST_HEAD(dsps);
+ struct list_head *p, *q;
+ struct disk_stats adsp, *dsp;
+
+ dump_stats(last_seen, 0);
+ fprintf(iostat_ofp, "\n");
+
+ memset(&adsp, 0, sizeof(adsp));
+ adsp.hdr = "TOTAL";
+
+ collect_dsps(&dsps);
+ list_for_each_safe(p, q, &dsps) {
+ dsp = list_entry(p, struct disk_stats, head);
+ list_del(&dsp->head);
+ ndevs++;
+
+ sum_results(&adsp, dsp->sum_merges, dsp->sum_ios,
+ dsp->sum_secs, dsp->sum_avgqsz,
+ dsp->sum_await, dsp->sum_svctm, dsp->sum_util);
+ }
- ADD_STAT(dip, svctm, tdelta(q_iop->t.time, c_iop->t.time));
+ dump_hdr(iostat_ofp);
+ dump_a(&adsp, TO_SEC(last_seen), ndevs, ndumps, "TOTAL", "AVG");
}
diff --git a/btt/trace_complete.c b/btt/trace_complete.c
index 41bcb7d..2afda15 100644
--- a/btt/trace_complete.c
+++ b/btt/trace_complete.c
@@ -51,8 +51,11 @@ static void display_io_track(FILE *ofp, struct io *iop)
static void handle_complete(struct io *c_iop)
{
+ unsigned int nqs = 0;
LIST_HEAD(head);
struct list_head *p, *q;
+ __u64 g2c = (__u64)-1;
+ __u64 d2c = (__u64)-1;
update_blks(c_iop);
update_cregion(&all_regions, c_iop->t.time);
@@ -71,11 +74,10 @@ static void handle_complete(struct io *c_iop)
latency_q2c(q_iop->dip, q_iop->t.time, q2c);
if (q_iop->d_time != (__u64)-1) {
- __u64 d2c = tdelta(q_iop->d_time, c_iop->t.time);
-
+ if (d2c == (__u64)-1)
+ d2c = tdelta(q_iop->d_time, c_iop->t.time);
update_d2c(q_iop, d2c);
latency_d2c(q_iop->dip, c_iop->t.time, d2c);
- iostat_complete(q_iop, c_iop);
}
if (per_io_ofp) {
@@ -85,9 +87,17 @@ static void handle_complete(struct io *c_iop)
display_io_track(per_io_ofp, q_iop);
}
+ if (q_iop->g_time != (__u64)-1) {
+ if (g2c == (__u64)-1)
+ g2c = tdelta(q_iop->g_time, c_iop->t.time);
+ nqs++;
+ }
+
list_del(&q_iop->f_head);
io_release(q_iop);
}
+
+ iostat_complete(dip_get_stats(c_iop->dip), c_iop, d2c, g2c, nqs);
}
void trace_complete(struct io *c_iop)
diff --git a/btt/trace_im.c b/btt/trace_im.c
index 49c876c..0cb6690 100644
--- a/btt/trace_im.c
+++ b/btt/trace_im.c
@@ -24,8 +24,6 @@ static void handle_g(struct io *g_iop)
{
struct io *q_iop;
- iostat_getrq(g_iop);
-
q_iop = dip_find_sec(g_iop->dip, IOP_Q, g_iop->t.sector);
if (q_iop) {
q_iop->g_time = g_iop->t.time;
@@ -52,13 +50,14 @@ static void handle_i(struct io *i_iop)
if (q_iop->g_time != (__u64)-1)
update_g2i(q_iop, tdelta(q_iop->g_time, i_iop->t.time));
}
+ iostat_insert(dip_get_stats(i_iop->dip), i_iop);
}
static void handle_m(struct io *m_iop)
{
struct io *q_iop;
- iostat_merge(m_iop);
+ iostat_merge(dip_get_stats(m_iop->dip), m_iop);
q_iop = dip_find_sec(m_iop->dip, IOP_Q, m_iop->t.sector);
if (q_iop) {
diff --git a/btt/trace_issue.c b/btt/trace_issue.c
index a18d44d..1a4a203 100644
--- a/btt/trace_issue.c
+++ b/btt/trace_issue.c
@@ -30,8 +30,8 @@ static void handle_issue(struct io *d_iop)
seeki_add(d_iop->dip->seek_handle, d_iop);
bno_dump_add(d_iop->dip->bno_dump_handle, d_iop);
- iostat_issue(d_iop);
d_iop->dip->n_ds++;
+ iostat_issue(dip_get_stats(d_iop->dip), d_iop);
if (!remapper_dev(d_iop->t.device))
update_d_histo(d_iop->t.bytes);
--
1.5.4.3
^ permalink raw reply related [flat|nested] 3+ messages in thread
end of thread, other threads:[~2008-05-30 15:30 UTC | newest]
Thread overview: 3+ messages (download: mbox.gz follow: Atom feed
-- links below jump to the message on this page --
2008-05-28 0:35 Negative queue lengths in btt "iostat" output? M. Edward (Ed) Borasky
2008-05-28 11:03 ` Alan D. Brunelle
2008-05-30 15:30 ` Alan D. Brunelle
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).