Kernel: INFO: task txg_sync:3757 blocked for more than 240 seconds

TrueNAS General
,
1

I know the message above is just an INFO message but I wonder if I have a hardware problem. I seem to get them at regular intervals when there is heavy writing to the system. TrueNAS version: ElectricEel-24.10.0.2.

I recently upgraded my system with an ASUS X670 Prime-X-CSM motherboard as I needed additional PCIe lanes for future upgrades. The motherboard has 6 SATA ports (two of them are unavailable when the 1xPCIe slot is populated; that slot is currently unpopulated). In addition I have a Startech 8P6G-PCIE-SATA-CARD card (8 Port SATA).

I have had problems when putting drives on both the build-in AMD SATA controller and on the Startech controller. In that case the drives on the AMD SATA controller are missing when running Linux based OS (TrueNAS, Ubuntu). They are visible in the BIOS. Thus I have temporarily disabled the built-in AMD SATA controller and attached all drives to the Startech SATA controller.

The system seems to be running fine now, but I wonder if the message above is an indication of an underlying problem. Is there any way to know if there is a drive slowing writing transactions?

1 Like
2

The Startech 8P6G is not a recommended HBA SATA controller - it is a mux card.

Others should be able to explain better than I can why this is a bad card for TrueNAS / ZFS, but a decent HBA card might give you a more reliable system.

3

A txg blocking for 240 seconds (four minutes) is really bad.

Your Startech card is likely to be a contributing factor as it looks like it runs four ASM1061 chips behind a PCIe x4 switch, but check the SMART logs to see if there is a drive that’s throwing errors and/or backing things up.

4

I checked the SMART data for all drives. Nothing stands out. No warnings. No issues from what I could see.

To check to see if the Startech 8 Port SATA controller is a bottleneck I ran a few test. Essentially I ran the linux “dd” program reading sequentially from each disk and writing to /dev/null. I read about 100G in 100M chunks. This to ensure that the cache in the OS wouldn’t impact the numbers (I have 64GB RAM). I loaded up the machine with all the drives I had laying around to see what would happen.

Drives:

Name Model Size
sda KIOXIA-EXCERIA SATA SSD 447.1G
sdb WDC WDS500G2B0B-00YS70 465.8G
sdc TOSHIBA MG05ACA800E 7.3T
sdd TOSHIBA MG05ACA800E 7.3T
sde TOSHIBA HDWF180 7.3T
sdf TOSHIBA HDWF180 7.3T
sdg TOSHIBA MG08ACA16TE 14.6T
nvme0n1 PC711 NVMe SK hynix 1TB 953.9G
nvme1n1 WD_BLACK SN850X 2000GB 1.8T

First I read exclusively from each drive (one drive at a time). Then I re-ran the test reading from all drives at the same time.

The short story is:

  • NVME: Speed: Always 1.6-2.6 GB/s - not impacted by read from other drives
  • SATA SSD: Speed: ~400 MB/s - dropped to 200MB/s when also reading from other drives
  • SATA HDD: Speed: 240-270MB/s - dropped to 200MB/s when also reading from other drives

This is an extreme situation where I am reading sequentially from every drive at the same time. Thus there is very little track-to-track seek in the HDD. Thus I conclude that my Startech 8 port SATA controller have a neglible impact on performance.

Here are the raw numbers:

Commands:
dd if=/dev/sda of=/dev/null bs=100M count=1000
dd if=/dev/sdb of=/dev/null bs=100M count=1000
dd if=/dev/sdc of=/dev/null bs=100M count=1000
dd if=/dev/sdd of=/dev/null bs=100M count=1000
dd if=/dev/sde of=/dev/null bs=100M count=1000
dd if=/dev/sdf of=/dev/null bs=100M count=1000
dd if=/dev/sdg of=/dev/null bs=100M count=1000
dd if=/dev/nvme0n1 of=/dev/null bs=100M count=1000
dd if=/dev/nvme1n1 of=/dev/null bs=100M count=1000

Results: One disk at a time:
sda: 104857600000 bytes (105 GB, 98 GiB) copied, 270.327 s, 388 MB/s
sdb: 104857600000 bytes (105 GB, 98 GiB) copied, 259.392 s, 404 MB/s
sdc: 104857600000 bytes (105 GB, 98 GiB) copied, 435.233 s, 241 MB/s
sdd: 104857600000 bytes (105 GB, 98 GiB) copied, 419.085 s, 250 MB/s
sde: 104857600000 bytes (105 GB, 98 GiB) copied, 432.379 s, 243 MB/s
sdf: 104857600000 bytes (105 GB, 98 GiB) copied, 429.797 s, 244 MB/s
sdg: 104857600000 bytes (105 GB, 98 GiB) copied, 381.162 s, 275 MB/s
nvme0n1: 104857600000 bytes (105 GB, 98 GiB) copied, 64.8062 s, 1.6 GB/s
nvme1n1: 104857600000 bytes (105 GB, 98 GiB) copied, 39.8907 s, 2.6 GB/s

Results: Parallel read from all drives at the same time:
sda: 104857600000 bytes (105 GB, 98 GiB) copied, 500.039 s, 210 MB/s
sdb: 104857600000 bytes (105 GB, 98 GiB) copied, 504.141 s, 208 MB/s
sdc: 104857600000 bytes (105 GB, 98 GiB) copied, 511.256 s, 205 MB/s
sdd: 104857600000 bytes (105 GB, 98 GiB) copied, 417.932 s, 251 MB/s
sde: 104857600000 bytes (105 GB, 98 GiB) copied, 510.684 s, 205 MB/s
sdf: 104857600000 bytes (105 GB, 98 GiB) copied, 516.597 s, 203 MB/s
sdg: 104857600000 bytes (105 GB, 98 GiB) copied, 493.800 s, 212 MB/s
nvme0n1: 104857600000 bytes (105 GB, 98 GiB) copied, 65.2209 s, 1.6 > GB/s
nvme1n1: 104857600000 bytes (105 GB, 98 GiB) copied, 40.0897 s, 2.6 GB/s

1 Like
5

Good work.
Solnet-array-test can automate this testing for you.

2 Likes
6

Those are good read tests, but txg_sync is write-bound - it’s basically ZFS saying “I couldn’t flush that transaction for 240 seconds” - considering the default upper bound for flushes is 5s, that’s a significantly longer time than you want to be sitting there with outstanding data.

Can you attach the output of cat /proc/spl/kstat/zfs/yourpoolname/txgs as a text file?

7

The test was mostly to see if the 8 port SATA controller was slowing stuff down. I assume that reads and writes take up about the same bandwidth.

Overnight I did a replication of 10 TB from my main pool to a new pool on a single 16 TB drive. All attached to the same 8 port SATA controller. It gave me a transfer speed of 250 MB/s which means 500 MB/s on the controller (250 MB/s read, 250 MB/s write).

I should note that I run all of pools with syncronization disabled. I can live with losing a few minutes of data. What I cannot live with is data corruption. Thus my worry isn’t really about that things are taking a long time to get written. My worry is that there is something else wrong and that that is causing some conflict somewhere.

First for the mirrored+striped pool:

Table of data (updated) 
txg      birth            state ndirty       nread        nwritten     reads    writes   otime        qtime        wtime        stime
14834271 103089700741767  C     0            0            0            0        0        5120119263   3867         25047        44183
14834272 103094820861030  C     0            0            0            0        0        5120032540   3326         14748        45445
14834273 103099940893570  C     0            0            0            0        0        5119888771   3216         14166        45436
14834274 103105060782341  C     0            0            0            0        0        5120073978   3146         14597        44303
14834275 103110180856319  C     0            0            0            0        0        5120074639   3376         17162        62768
14834276 103115300930958  C     0            0            0            0        0        5120247904   4067         17102        56136
14834277 103120421178862  C     0            0            0            0        0        5120112951   3386         14908        45155
14834278 103125541291813  C     0            0            0            0        0        5119859014   3176         14918        45726
14834279 103130661150827  C     0            0            0            0        0        5120213720   3206         94347        43732
14834280 103135781364547  C     0            0            0            0        0        5120098133   3387         25618        44553
14834281 103140901462680  C     0            0            0            0        0        5119991514   3146         25006        42420
14834282 103146021454194  C     0            0            0            0        0        5120002083   3286         11351        33703
14834283 103151141456277  C     0            0            0            0        0        5120067215   3456         11542        32832
14834284 103156261523492  C     0            0            0            0        0        5120082043   3316         14287        45555
14834285 103161381605535  C     0            0            0            0        0        5120143989   3146         19056        32881
14834286 103166501749524  C     0            0            0            0        0        5120349474   3236         24436        43582
14834287 103171622098998  C     0            0            0            0        0        5119742998   4027         16581        55524
14834288 103176741841996  C     0            0            0            0        0        5120073597   3997         15870        57618
14834289 103181861915593  C     0            0            0            0        0        5120385141   3937         26650        54713
14834290 103186982300734  C     0            0            0            0        0        5119921091   4008         93385        52769
14834291 103192102221825  C     0            0            0            0        0        5120111098   3486         14798        44984
14834292 103197222332923  C     0            0            0            0        0        5120058799   3527         24466        45234
14834293 103202342391722  C     0            0            0            0        0        5120197109   3226         24806        44844
14834294 103207462588831  C     0            0            0            0        0        5119947981   3407         24886        43742
14834295 103212582536812  C     0            0            0            0        0        5120073367   3166         25197        44143
14834296 103217702610179  C     0            0            0            0        0        5120113181   3477         16040        56666
14834297 103222822723360  C     0            0            0            0        0        5120245540   3487         24205        44473
14834298 103227942968900  C     677376       0            3145728      0        258      5119891416   3236         14757        302708382
14834299 103233062860316  C     0            0            0            0        0        5119892507   4639         17683        139041
14834300 103238182752823  C     0            0            0            0        0        5120069780   3787         11933        176300
14834301 103243302822603  C     0            0            0            0        0        5120374702   3196         24676        48421
14834302 103248423197305  C     0            0            0            0        0        5119866990   3185         14588        44954
14834303 103253543064295  C     0            0            0            0        0        5119988788   3336         15479        46297
14834304 103258663053083  C     0            0            0            0        0        5120318887   3236         24846        46197
14834305 103263783371970  C     0            0            0            0        0        5120035004   3176         14347        44995
14834306 103268903406974  C     0            0            0            0        0        5119860859   2284         14317        44263
14834307 103274023267833  C     0            0            0            0        0        5120083846   3266         14918        45385
14834308 103279143351679  C     0            0            0            0        0        5120148868   2665         87464        45015
14834309 103284263500547  C     0            0            0            0        0        5120001532   3076         14287        45856
14834310 103289383502079  C     0            0            0            0        0        5120167323   4288         17533        59943
14834311 103294503669402  C     0            0            0            0        0        5120003175   3797         16401        59412
14834312 103299623672577  C     0            0            0            0        0        5120126597   3396         94778        45796
14834313 103304743799174  C     0            0            0            0        0        5120009056   3136         14357        44673
14834314 103309863808230  C     0            0            0            0        0        5120073577   3336         14578        46557
14834315 103314983881807  C     0            0            0            0        0        5120063368   2294         14057        44683
14834316 103320103945175  C     0            0            0            0        0        5120077504   2275         14046        44283
14834317 103325224022679  C     0            0            0            0        0        5120071924   2365         13826        44383
14834318 103330344094603  C     0            0            0            0        0        5120259847   3256         24666        45636
14834319 103335464354450  C     0            0            0            0        0        5119884462   3246         14077        47298
14834320 103340584238912  C     0            0            0            0        0        5120088175   3897         13305        41959
14834321 103345704327087  C     0            0            0            0        0        5120133770   4007         10660        34224
14834322 103350824460857  C     0            0            0            0        0        5119999969   3286         12724        42610
14834323 103355944460826  C     0            0            0            0        0        5120087323   3727         16210        231394
14834324 103361064548149  C     0            65536        0            5        0        5120084748   3927         14567        34391084
14834325 103366184632897  C     0            0            0            0        0        5120063859   3085         13716        48200
14834326 103371304696756  C     0            69632        0            6        0        5120075460   3607         13686        45869018
14834327 103376424772216  C     0            4096         0            1        0        5120068538   4158         13896        4047430
14834328 103381544840754  C     0            0            0            0        0        5120079147   3166         14297        299141
14834329 103386664919901  C     0            0            0            0        0        5120080701   3536         13606        171682
14834330 103391785000602  C     0            0            0            0        0        5120393126   3958         13946        43882
14834331 103396905393728  C     0            0            0            0        0        5119834870   3156         11671        31780
14834332 103402025228598  C     0            0            0            0        0        5120010178   4218         11521        35477
14834333 103407145238776  C     0            0            0            0        0        5120361998   3256         11091        31759
14834334 103412265600774  C     0            0            0            0        0        5123781280   3957         16010        54052
14834335 103417389382054  C     0            0            0            0        0        5116099234   4098         16551        59481
14834336 103422505481288  C     0            0            0            0        0        5120075270   3707         11983        45745
14834337 103427625556558  C     0            0            0            0        0        5120073147   3386         11481        35447
14834338 103432745629705  C     0            0            0            0        0        5120078316   3226         11702        35456
14834339 103437865708021  C     0            0            0            0        0        5120140713   3356         11762        33322
14834340 103442985848734  C     0            0            0            0        0        5120247723   5290         31489        69691
14834341 103448106096457  C     0            0            0            0        0        5119901655   3306         10981        31819
14834342 103453225998112  C     0            0            0            0        0        5120077184   3436         69561        32621
14834343 103458346075296  C     0            0            0            0        0        5120076502   3447         11151        36959
14834344 103463466151798  C     0            0            0            0        0        5120078457   3155         90340        33853
14834345 103468586230255  C     0            12288        2842624      3        187      2514788709   3607         9317         315318540
14834346 103471101018964  C     0            0            2326528      0        189      5169536014   3687         12684        251808299
14834347 103476270554978  C     0            0            0            0        0        5115786438   4057         12855        239348
14834348 103481386341416  C     0            0            0            0        0        5120084237   4268         15168        193403
14834349 103486506425653  C     0            0            0            0        0        5120071423   3867         13616        43882
14834350 103491626497076  C     0            0            0            0        0        5120075611   3276         11512        35997
14834351 103496746572687  C     0            0            0            0        0        5120065071   3376         10831        33342
14834352 103501866637758  C     0            0            0            0        0        5120076753   3346         13806        40666
14834353 103506986714511  C     0            0            0            0        0        5120082324   3376         13175        41517
14834354 103512106796835  C     0            0            0            0        0        5120063448   2374         10820        30387
14834355 103517226860283  C     0            0            0            0        0        5120141234   3196         10850        31028
14834356 103522347001517  C     0            0            0            0        0        5120011590   3166         11252        30857
14834357 103527467013107  C     0            0            0            0        0        5120150662   3216         11101        33142
14834358 103532587163769  C     0            0            0            0        0        5123992496   3156         12293        39404
14834359 103537711156265  C     0            0            0            0        0        5116080429   3948         16430        42340
14834360 103542827236694  C     0            0            0            0        0        5120181780   4068         15258        40556
14834361 103547947418474  C     0            0            0            0        0        5119972918   2455         10770        33683
14834362 103553067391392  C     0            0            0            0        0        5120146605   3917         13145        37931
14834363 103558187537997  C     0            0            0            0        0        5120001782   3236         10770        30457
14834364 103563307539779  C     0            0            0            0        0        5124377929   3887         13676        41247
14834365 103568431917708  C     0            0            0            0        0        5115773463   3968         14507        51727
14834366 103573547691171  C     0            0            0            0        0        5120074890   3486         11882        39034
14834367 103578667766061  C     0            0            0            0        0        5120074328   3627         11401        38713
14834368 103583787840389  C     0            0            0            0        0        5120476773   2335         11351        33182
14834369 103588908317162  C     0            0            0            0        0        5119683526   3076         14367        49933

And for my experimental single drive pool:

Table of data 
txg      birth            state ndirty       nread        nwritten     reads    writes   otime        qtime        wtime        stime
3009     66533124490475   C     4139302912   0            4134899712   0        4107     20587792080  2885         3587         19522907691
3010     66553712282555   C     4137808384   0            4135497728   0        4706     19522920355  2334         3737         21063662355
3011     66573235202910   C     4133913600   0            4130111488   0        4257     21063675489  1823         3447         21875363306
3012     66594298878399   C     4147577856   0            4132270080   0        4706     21875376150  2695         4779         20900594502
3013     66616174254549   C     4138270720   0            4136464384   0        4799     20900609830  2505         3847         20888486195
3014     66637074864379   C     4133302784   0            4130205696   0        4484     20888509729  3477         4448         21024577569
3015     66657963374108   C     4138745344   0            4137443328   0        4851     21024592737  3457         3536         21101253109
3016     66678987966845   C     4144751616   0            4138647552   0        4469     21101267566  2896         4668         20506317340
3017     66700089234411   C     4144782848   0            4142051328   0        4194     20506331046  2474         3557         21580318285
3018     66720595565457   C     4151178752   0            4133974016   0        4859     21580330307  2414         3477         20847375409
3019     66742175895764   C     4145398784   0            4142571520   0        4502     20847387492  1893         5110         21543962406
3020     66763023283256   C     4143642112   0            4140969984   0        4668     21543976823  2505         4188         20675903877
3021     66784567260079   C     4084711424   0            4079247360   0        4039     20675917182  2084         3226         19586958126
3022     66805243177261   C     4146164224   0            4143554560   0        4758     19586971070  2315         3426         20875965855
3023     66824830148331   C     4143957504   0            4124356608   0        4748     20875979191  2905         4238         21768403733
3024     66845706127522   C     4140745728   0            4136824832   0        4623     21768418310  3066         4088         21941069064
3025     66867474545832   C     4148772864   0            4144623616   0        5079     21941083752  3016         5941         19445596138
3026     66889415629584   C     4135286272   0            4133294080   0        4736     19445611858  1873         3337         20873013589
3027     66908861241442   C     4148496896   0            4145307648   0        4172     20873025822  2384         4829         21300484790
3028     66929734267264   C     4141877760   0            4134449152   0        4949     21300499377  3186         4639         20917041154
3029     66951034766641   C     4145264128   0            4141121536   0        4586     20917055091  1813         3927         21565353562
3030     66971951821732   C     4150114816   0            4147445760   0        4551     21565367567  2585         3927         21574274170
3031     66993517189299   C     4142448640   0            4139765760   0        4101     21574298376  3356         4599         20027711735
3032     67015091487675   C     4138516480   0            4135657472   0        4091     20027732194  2454         3898         21038634329
3033     67035119219869   C     4154418688   0            4147924992   0        4348     21038647514  2274         3707         21412523307
3034     67056157867383   C     4130598400   0            4127199232   0        4239     21412536762  3146         3787         23853525734
3035     67077570404145   C     4156122624   0            4140015616   0        4523     23853538478  2304         3988         22412557692
3036     67101423942623   C     4153058304   0            4150362112   0        4774     22412570516  2755         3707         22173171799
3037     67123836513139   C     4156699648   0            4154945536   0        4520     22173196025  3366         4839         21875518357
3038     67146009709164   C     4145155072   0            4142821376   0        4307     21875540407  2495         3697         21126615732
3039     67167885249571   C     4143370752   0            4141867008   0        4162     21126627915  2865         3747         21919963415
3040     67189011877486   C     4136620032   0            4133474304   0        4254     21919987149  3878         4177         22387740963
3041     67210931864635   C     4157210624   0            4154970112   0        4182     22387756643  2204         3546         21747308363
3042     67233319621278   C     4142270976   0            4139986944   0        4251     21747324152  3166         5851         24135901897
3043     67255066945430   C     4143444992   0            4141551616   0        4559     24135917036  1833         3567         23298012464
3044     67279202862466   C     4156310016   0            4153495552   0        4936     23298024357  2053         3557         20665607889
3045     67302500886823   C     4140840448   0            4137914368   0        4510     20665619540  1934         4378         22038740298
3046     67323166506363   C     4163812864   0            4161191936   0        4348     22038763252  3406         8706         23278453876
3047     67345205269615   C     4167787520   0            4165627904   0        4485     23278474524  3076         4278         23797352011
3048     67368483744139   C     4160503296   0            4158738432   0        4647     23797376798  3346         5110         23092358058
3049     67392281120937   C     4152869376   0            4151148544   0        4344     23092373618  1783         3517         21607173787
3050     67415373494555   C     4149943296   0            4146851840   0        4315     21607186521  2254         3547         22479557177
3051     67436980681076   C     4150057984   0            4147408896   0        4668     22479569229  1914         2705         25650787277
3052     67459460250305   C     4183716864   0            4175601664   0        5040     25650798429  2354         3266         25840936056
3053     67485111048734   C     4177523200   0            4174868480   0        4876     25840951664  2585         4769         27362777681
3054     67510952000398   C     4187012096   0            4185579520   0        4595     27362791537  2034         3256         26062021169
3055     67538314791935   C     4186584576   0            4185260032   0        4766     26062034223  3307         4608         25577416364
3056     67564376826158   C     4185263616   0            4181626880   0        4789     25577433397  3476         5420         25113048310
3057     67589954259555   C     4146479104   0            4142645248   0        4682     25113063368  1813         3627         21557559405
3058     67615067322923   C     4143798784   0            4139163648   0        4265     21557572840  2495         3757         21918893668
3059     67636624895763   C     4144793600   0            4142227456   0        4394     21918918585  3226         4679         21826277565
3060     67658543814348   C     4149558272   0            4147503104   0        4327     21826294136  3166         3567         22951731229
3061     67680370108484   C     4149798400   0            4147965952   0        4539     22951744605  2935         3577         21914149382
3062     67703321853089   C     4148103168   0            4145987584   0        4525     21914163067  2465         3687         23168607600
3063     67725236016156   C     4154102784   0            4152807424   0        4504     23168619813  1914         3667         23287747404
3064     67748404635969   C     4151204352   0            4149477376   0        4310     23287759868  2234         5060         23933720654
3065     67771692395837   C     4150547968   0            4147515392   0        4699     23933734420  2245         4077         22835399873
3066     67795626130257   C     4147462144   0            4145463296   0        4893     22835415011  11732        4068         22241487682
3067     67818461545268   C     4148752384   0            4146704384   0        4904     22241509453  2455         3417         21664155936
3068     67840703054721   C     4144594432   0            4141129728   0        4563     21664168280  2625         3717         22341552675
3069     67862367223001   C     4144672256   0            4142415872   0        4507     22341566892  3066         5460         22493422649
3070     67884708789893   C     4140730880   0            4137676800   0        4237     22493437467  1843         3096         22611963460
3071     67907202227360   C     4146971648   0            4144652288   0        4429     22611976384  3566         7074         22675538152
3072     67929814203744   C     4149519872   0            4147097600   0        4802     22675555113  3036         3978         22053584866
3073     67952489758857   C     4148263424   0            4146270208   0        4757     22053597491  2184         8085         21805712389
3074     67974543356348   C     4151035904   0            4148948992   0        4567     21805729350  1773         4098         22850001485
3075     67996349085698   C     4148067328   0            4145713152   0        4286     22850014539  2104         3647         22043562271
3076     68019199100237   C     4145984000   0            4141449216   0        4216     22043574715  2875         5250         23359101305
3077     68041242674952   C     4225219072   0            4222328832   0        4710     23359117505  2355         3877         22854910100
3078     68064601792457   C     4145329152   0            4143652864   0        4636     22854925239  3105         4819         23070150513
3079     68087456717696   C     4143129600   0            4141223936   0        4818     23070166182  2524         3377         22657204280
3080     68110526883878   C     4148346368   0            4145557504   0        4236     22657216803  2515         3416         22566265011
3081     68133184100681   C     3562998784   0            3559997440   0        3698     22566288195  3777         5260         20644587619
3082     68155750388876   C     0            0            0            0        0        20644609610  2605         5180         828544
3083     68176394998486   C     0            0            643072       0        55       21393730     1753         7274         23281550
3084     68176416392216   C     0            0            569344       0        45       199709728    2324         7374         17722535
3085     68176616101944   C     0            0            507904       0        41       19788610     1863         4499         16362394
3086     68176635890554   C     0            0            679936       0        51       16965776     1703         3196         21347904
3087     68176652856330   C     0            0            655360       0        68       22472372     2605         3657         26000138
3088     68176675328702   C     0            0            745472       0        56       57734210     2434         5821         19480092
3089     68176733062912   C     0            0            483328       0        42       19598503     2475         3577         18985273
3090     68176752661415   C     0            0            507904       0        38       19020550     1653         3416         18642451
3091     68176771681965   C     860830720    0            858542080    0        895      3820328551   5391         8325         4354938822
3092     68180592010516   C     1068221440   0            1066680320   0        1087     4354957888   2104         4108         5396135358
3093     68184946968404   C     1159819776   0            1142349824   0        1178     5396147672   2134         4759         5795067480
3094     68190343116076   C     1524776960   0            1500516352   0        1518     5795081176   3146         4007         7715507712
3095     68196138197252   C     1851637760   0            1780830208   0        2035     7715522579   2625         3727         9034608615
3096     68203853719831   C     2354987008   0            2351247360   0        2655     9034622652   1923         3236         11768195259
3097     68212888342483   C     3078668288   0            2831663104   0        3146     11768206800  1753         3617         14328839682
3098     68224656549283   C     3663777280   0            3571875840   0        4324     14328850372  2124         3456         18100869128
3099     68238985399655   C     3360278528   0            3105202176   0        3553     18100881170  2144         8576         16554810979
3100     68257086280825   C     3902042624   0            3689975808   0        3963     16554828712  2104         3437         18545311625
3101     68273641109537   C     3278023680   0            3002261504   0        3319     18545322907  1703         3877         16087734826
3102     68292186432444   C     3731851776   0            3515756544   0        3716     16087747870  2615         5520         18468176453
3103     68308274180314   C     4139278848   0            4008427520   0        4194     18468191251  2194         3837         21807932322
3104     68326742371565   C     4150870016   0            4141068288   0        4102     21807945486  3036         4248         21119460443
3105     68348550317051   C     4156278272   0            3512233984   0        4566     21119476163  3917         4939         18035967447
3106     68369669793214   C     4147691520   0            4115865600   0        4114     18035984288  3607         7003         21109519160

Is there is description somewhere of the columns? I tried to find the code for the ZFS kstats to see if it was possible to get more knowledge about the data from the code but I couldn’t find the code.

8

I would need to see the txgs output from the mirror vdev pool under a write workload (because that’s when the txg_sync timeouts will occur) - I assume you did not have any errors during the replication to the single 16T drive, because none of the transactions took more than ~20s.

Your Toshiba drives being formerly “Enterprise” branded makes me want to ask this question:

for disk in /dev/sd?; do; hdparm -W $disk; done

9

I don’t think I am able to trigger it. I saw it in the log files about 30 times over the past 3 days (after I upgraded the system) but I don’t know what I did at the time. It is also a problem to monitor as it seems that the “task txg_sync is block for more than XXX seconds” message is suppressed after having appeared a number of times.

To try to trigger it, I wrote very large amounts of random data to the drives. I tried writing about .5TB from a single process, and from 10, 100, 1000 process. None of the scenarios were able to trigger the situation.

I did manage to run out of memory on the server in one of the scenarios; there the stime in kstats/zfs went to 28s. When it didn’t run out of memory max stime was about 12s.

Here are the numbers though I don’t think they are terribly useful.

Test result 
txg      birth            state ndirty       nread        nwritten     reads    writes   otime        qtime        wtime        stime
14838227 122887463797123  C     0            8192         3235840      2        240      398786578    4419         13335        286219510
14838228 122887862583701  C     0            8192         2646016      2        185      297444231    3486         13315        285782852
14838229 122888160027932  C     0            8192         2793472      2        189      295406478    3227         22622        282248263
14838230 122888455434410  C     0            8192         2449408      2        163      291464286    3687         13335        232497636
14838231 122888746898696  C     0            8192         2793472      2        181      241967765    3417         13164        240572829
14838232 122888988866461  C     0            0            2473984      0        157      5162740200   6893         22643        228096091
14838233 122894151606661  C     0            0            0            0        0        5120115075   6643         21941        322174
14838234 122899271721736  C     0            0            0            0        0        5120041848   4318         17212        227367
14838235 122904391763584  C     0            0            0            0        0        5120124272   6582         22923        74500
14838236 122909511887856  C     0            0            0            0        0        5120088074   5861         21891        74059
14838237 122914631975930  C     0            0            0            0        0        5120072515   8246         27822        72226
14838238 122919752048445  C     0            0            0            0        0        5119864365   6462         21731        73318
14838239 122924871912810  C     0            0            0            0        0        5120314048   7074         22432        70973
14838240 122929992226858  C     0            0            0            0        0        5120063348   6332         21771        73558
14838241 122935112290206  C     0            0            0            0        0        5120196478   7524         21550        71955
14838242 122940232486684  C     0            0            0            0        0        5120043541   7223         22061        72637
14838243 122945352530225  C     0            0            0            0        0        5119989769   6613         21781        71454
14838244 122950472519994  C     0            0            0            0        0        5120069239   8406         22392        78868
14838245 122955592589233  C     0            0            0            0        0        5120130154   6993         23364        72856
14838246 122960712719387  C     0            0            0            0        0        5119955816   3707         16090        45916
14838247 122965832675203  C     0            0            0            0        0        5119925640   4738         21290        64832
14838248 122970952600843  C     0            0            0            0        0        5120314879   6983         21841        70593
14838249 122976072915722  C     0            0            0            0        0        5120242384   4959         21170        66515
14838250 122981193158106  C     0            0            0            0        0        5119842093   7474         21590        71504
14838251 122986313000199  C     0            0            0            0        0        5120242754   7264         21490        71264
14838252 122991433242953  C     0            0            0            0        0        5119994900   6873         21790        71485
14838253 122996553237853  C     0            0            0            0        0        5120140803   9969         23043        74249
14838254 123001673378656  C     0            0            0            0        0        5120001141   6933         23023        70823
14838255 123006793379797  C     0            0            0            0        0        5119844768   6763         21089        71645
14838256 123011913224565  C     0            0            0            0        0        5120372127   7103         23184        69671
14838257 123017033596692  C     0            0            0            0        0        5120015689   6963         21991        70723
14838258 123022153612381  C     0            0            0            0        0        5119973850   4458         27361        61806
14838259 123027273586231  C     0            0            0            0        0        5120193772   7204         21781        70993
14838260 123032393780003  C     0            0            0            0        0        5120252573   4989         21290        64702
14838261 123037514032576  C     0            0            0            0        0        5119878381   7173         21711        72346
14838262 123042633910957  C     0            0            0            0        0        5120063759   7905         23594        77014
14838263 123047753974716  C     0            0            0            0        0        5120080269   6973         21912        71734
14838264 123052874054985  C     0            0            0            0        0        5120202940   6512         25749        75972
14838265 123057994257925  C     0            0            0            0        0        5119726546   7044         22271        74500
14838266 123063113984471  C     0            0            0            0        0        5120338254   7143         22512        71494
14838267 123068234322725  C     0            0            0            0        0        5120141204   6853         21360        71534
14838268 123073354463929  C     0            0            0            0        0        5120007353   6742         22733        71304
14838269 123078474471282  C     0            0            0            0        0        5119983468   3496         16461        47339
14838270 123083594454750  C     754688       0            3063808      0        237      5120096750   6623         43571        219347725
14838271 123088714551500  C     0            0            0            0        0        5120131977   7223         21190        185278
14838272 123093834683477  C     759296       0            2400256      0        173      5120067836   7104         22472        213763092
14838273 123098954751313  C     0            0            0            0        0        5120083947   6342         22382        182171
14838274 123104074835260  C     0            0            0            0        0        5120066694   4859         21140        253866
14838275 123109194901954  C     775168       0            3170304      0        228      5120219260   6903         21821        268768505
14838276 123114315121214  C     870907904    0            1732861952   0        4078     4119278135   83830939     21761        3117658017
14838277 123118434399349  C     3421732864   0            6819225600   0        10004    3201518301   3446         8216         10965166781
14838278 123121635917650  C     3542564864   0            7061479424   0        8789     10965187279  3417         8455         10835401311
14838279 123132601104929  C     3475488768   0            6929571840   0        17411    10835421168  3567         7814         11316100892
14838280 123143436526097  C     3549167616   0            7075209216   0        14804    11316121019  3447         10760        11492964155
14838281 123154752647116  C     3602333696   0            7179116544   0        10375    11492985495  3056         6552         11851080424
14838282 123166245632611  C     3584851968   0            7127744512   0        11153    11851100051  4859         10139        11764461767
14838283 123178096732662  C     3583148032   0            7103447040   0        10480    11764484349  2786         7163         11469081738
14838284 123189861217011  C     3527884800   0            6994501632   0        8554     11469099341  2525         10119        11431657997
14838285 123201330316352  C     3510714368   0            6962692096   0        9010     11431677464  2815         6212         11100507647
14838286 123212761993816  C     3473522688   32768        6892560384   1        9363     11100605731  3536         17533        11167012054
14838287 123223862599547  C     3530211328   0            7015636992   0        9910     11167051377  3647         9307         11016861034
14838288 123235029650924  C     3513892864   0            7000776704   0        11369    11016891521  3547         7975         11333764536
14838289 123246046542445  C     3536027648   0            7048028160   0        8528     11333794533  3496         12373        11583661110
14838290 123257380336978  C     3547086848   0            7070990336   0        10148    11583685305  3687         8416         11470942878
14838291 123268964022283  C     99848704     0            3514368      0        217      11470969778  3928         10990        415229955
14838292 123280434992061  C     0            0            0            0        0        5146604421   6462         24787        507171
14838293 123285581596482  C     0            0            0            0        0        5120119193   6933         22492        6023015
14838294 123290701715675  C     0            0            0            0        0        5120024104   6873         22412        81523
14838295 123295821739779  C     0            0            0            0        0        5120022020   7184         22893        79228
14838296 123300941761799  C     0            0            0            0        0        5120157515   8496         22642        79349
14838297 123306061919314  C     0            0            0            0        0        5120032831   7414         22872        79239
14838298 123311181952145  C     754688       0            3260416      0        218      5120024184   6472         23254        242439780
14838299 123316301976329  C     776192       0            3039232      0        220      5120053660   7203         22713        293523267
14838300 123321422029989  C     859410944    0            1711955968   0        3837     2722874024   8443644      22152        3406452706
14838301 123324144904013  C     3490938880   0            6952730624   0        10325    3414927509   3576         8516         11456396019
14838302 123327559831522  C     3530555392   0            7032750080   0        15320    11456563302  4228         7053         11450222391
14838303 123339016394824  C     3557081088   0            7090069504   0        11793    11450337406  3848         10369        11341901786
14838304 123350466732230  C     3519332352   0            7014694912   0        12926    11342110708  3817         24106        11390898730
14838305 123361808842938  C     3520724992   0            7014981632   0        14902    11390934838  3417         8897         11586112617
14838306 123373199777776  C     3546087424   0            7060037632   0        11331    11586275162  4158         10069        11781255541
14838307 123384786052938  C     3605184512   0            7161036800   0        9281     11781277232  3506         9288         11772370378
14838308 123396567330170  C     3538534400   0            7004037120   0        15257    11772390776  3958         7043         11475607436
14838309 123408339720946  C     3552444416   0            7034609664   0        10943    11475625640  2936         9207         11269912394
14838310 123419815346586  C     3550019584   0            7029276672   0        10049    11269937361  3456         8386         11069501651
14838311 123431085283947  C     3480485888   0            6891577344   0        10277    11069520917  3146         13405        11039789823
14838312 123442154804864  C     3501932544   0            6934077440   0        11199    11039816713  3456         8035         10794095149
14838313 123453194621577  C     3505618944   0            6941155328   0        9745     10794113894  2434         6963         11144552575
14838314 123463988735471  C     3485483008   0            6902153216   0        9559     11144569767  3316         8206         11189727211
14838315 123475133305238  C     3519987712   0            6970081280   0        9236     11189748081  3426         9398         11279515262
14838316 123486323053319  C     3570515968   0            7067164672   0        8816     11279534408  2063         9118         11401870666
14838317 123497602587727  C     3488301056   0            6891732992   0        12696    11401899380  3436         8416         11069670498
14838318 123509004487107  C     3477684224   0            6869008384   0        11929    11069689714  2745         8586         11347705830
14838319 123520074176821  C     3564716032   0            7044341760   0        12728    11347724285  2504         7264         11680961508
14838320 123531421901106  C     3523690496   0            6962978816   0        14834    11680978881  2605         7494         11495057911
14838321 123543102879987  C     3508813824   0            6935904256   0        9484     11495075885  3707         7123         11411328052
14838322 123554597955872  C     3505340416   0            6927704064   0        10127    11411347578  3487         9027         11036868313
14838323 123566009303450  C     3494756352   0            6909378560   0        12053    11036890676  3867         9468         11294314465
14838324 123577046194126  C     3544956928   0            7012114432   0        12784    11294337047  3847         7505         11175235915
14838325 123588340531173  S     0            0            0            0        0        11175253389  2585         6762         0
14838326 123599515784562  O     0            0            0            0        0        0            0            0            0
Test Script 
#!/bin/bash

blocksize=1M
blockcount=100
procs=1000
filename=buu.
extension=.tmp

for index in $(seq 1 $procs)
do
        dd if=/dev/urandom of=$filename$index$extension bs=$blocksize count=$blockcount &
done

wait

for index in $(seq 1 $procs)
do
        rm $filename$index$extension
done

PS: I found this description of the txgs output; I assume it is correct: Chris's Wiki :: blog/linux/ZFSPoolTXGsInformation

For every disk it says: write-caching = 1 (on)

However I have discovered that I was wrong saying that all drives are enterprise branded. Half of the drives are Toshiba Enterprise MG05 drives; half are Toshiba High Performance X300 drives.

The X300 have more cache but substantially lower MTBF. I have been using the 24/7 for 4 years now. I will start considering to slowly replace them even though the SMART stats are very good for all drives.

10

Well I think figured out what was causing it. The issue is with my single drive pool (the one with a single 16GB Toshiba Enterprise HDD). I use this drive for backing up multiple other computers.

On this pool i have dedup enabled. It gives me a 2.64x dedup rate. Thus dedup is worth it in this case.

I have two of those drives (exact same model) with very similar SMART stats. I created a pool on this extra drive without dedup and ran the same test. The test would write about 0.1TB random data to the pool using separate 1000 processes.

On the non-dedup pool I got a write throughput around 200MB/s. On the dedup pool the throughput was around 20MB/s. In addition I got a lot of these txg_sync INFO messages. Read speed from both pools were around 200MB/s.

The test above is extreme and not what I usually do with this pool. It seems that the message comes around the time when large snapshots are being deleted. I can live with that.

I am sure more tests could be done but this is the end of it for me. I wish dedup would happen asynchronously whenever the drive wasn’t busy but I suppose that would be a major change in OpenZFS.

1 Like
11

Congratulations for finding the root cause… and incidentally providing another example of why one should describe everything about the system, hardware and software, when asking for help or input.
It was dedup with insufficient RAM for a 16 TB pool… (as a starting point 5 GB/TB, so over 80 GB RAM in your case, with 10GbE round that up to 128 GB)

1 Like