vgteam
vg giraffe runs unusually slowly on Illumina paired-end reads on one user's system
Developer, hello! I used vg giraffe to map resequenced data to a graph pan-genome and obtain a gam file, but this step is progressing extremely slowly. Therefore, I would like to ask if this is normal. Below is a portion of the log file content: Guessing that ~/mouse.d2.shortread.zipcodes is Short Read Zipcodes warning[vg::Watchdog]: Thread 6 has been checked in for 10 seconds processing: SRR1174880.372702, SRR1174880.372702 warning[vg::Watchdog]: Thread 7 has been checked in for 10 seconds processing: SRR1174880.622813, SRR1174880.622813 warning[vg::Watchdog]: Thread 3 has been checked in for 10 seconds processing: SRR1174880.646249, SRR1174880.646249 warning[vg::Watchdog]: Thread 7 finally checked out after 21 seconds and 22972 kb memory growth processing: SRR1174880.622813, SRR1174880.622813 warning[vg::Watchdog]: Thread 10 has been checked in for 10 seconds processing: SRR1174880.1150056, SRR1174880.1150056 warning[vg::Watchdog]: Thread 10 finally checked out after 16 seconds and 20596 kb memory growth processing: SRR1174880.1150056, SRR1174880.1150056 warning[vg::Watchdog]: Thread 7 has been checked in for 10 seconds processing: SRR1174880.1335411, SRR1174880.1335411 warning[vg::Watchdog]: Thread 0 has been checked in for 10 seconds processing: SRR1174880.1771197, SRR1174880.1771197 warning[vg::Watchdog]: Thread 4 has been checked in for 10 seconds processing: SRR1174880.1575454, SRR1174880.1575454 warning[vg::Watchdog]: Thread 4 finally checked out after 13 seconds and 0 kb memory growth processing: SRR1174880.1575454, SRR1174880.1575454 warning[vg::Watchdog]: Thread 0 finally checked out after 71 seconds and 0 kb memory growth processing: SRR1174880.1771197, SRR1174880.1771197 warning[vg::Watchdog]: Thread 5 has been checked in for 10 seconds processing: SRR1174880.2794036, SRR1174880.2794036 warning[vg::Watchdog]: Thread 2 has been checked in for 10 seconds processing: SRR1174880.2842518, SRR1174880.2842518 warning[vg::Watchdog]: Thread 1 has been checked in for 10 seconds processing: SRR1174880.2902241, SRR1174880.2902241 warning[vg::Watchdog]: Thread 2 finally checked out after 29 seconds and 4352 kb memory growth processing: SRR1174880.2842518, SRR1174880.2842518 warning[vg::Watchdog]: Thread 1 finally checked out after 32 seconds and 4352 kb memory growth processing: SRR1174880.2902241, SRR1174880.2902241 warning[vg::Watchdog]: Thread 0 has been checked in for 10 seconds processing: SRR1174880.3707850, SRR1174880.3707850 warning[vg::Watchdog]: Thread 11 has been checked in for 10 seconds processing: SRR1174880.3405077, SRR1174880.3405077 warning[vg::Watchdog]: Thread 7 finally checked out after 682 seconds and 203244 kb memory growth processing: SRR1174880.1335411, SRR1174880.1335411 warning[vg::Watchdog]: Thread 5 finally checked out after 1046 seconds and 4352 kb memory growth processing: SRR1174880.2794036, SRR1174880.2794036 warning[vg::Watchdog]: Thread 3 finally checked out after 25102 seconds and 246812 kb memory growth processing: SRR1174880.646249, SRR1174880.646249 warning[vg::Watchdog]: Thread 0 finally checked out after 40747 seconds and 0 kb memory growth processing: SRR1174880.3707850, SRR1174880.3707850 warning[vg::Watchdog]: Thread 10 has been checked in for 10 seconds processing: SRR1174880.3718121, SRR1174880.3718121 warning[vg::Watchdog]: Thread 7 has been checked in for 10 seconds processing: SRR1174880.3832901, SRR1174880.3832901 warning[vg::Watchdog]: Thread 8 has been checked in for 10 seconds processing: SRR1174880.4005631, SRR1174880.4005631 warning[vg::Watchdog]: Thread 2 has been checked in for 10 seconds processing: SRR1174880.4308446, SRR1174880.4308446 warning[vg::Watchdog]: Thread 5 has been checked in for 10 seconds processing: SRR1174880.4336439, SRR1174880.4336439 warning[vg::Watchdog]: Thread 8 finally checked out after 54 seconds and 0 kb memory growth processing: SRR1174880.4005631, SRR1174880.4005631 warning[vg::Watchdog]: Thread 8 has been checked in for 10 seconds processing: SRR1174880.4704492, SRR1174880.4704492 warning[vg::Watchdog]: Thread 9 has been checked in for 10 seconds processing: SRR1174880.4712685, SRR1174880.4712685 warning[vg::Watchdog]: Thread 8 finally checked out after 32 seconds and 0 kb memory growth processing: SRR1174880.4704492, SRR1174880.4704492 warning[vg::Watchdog]: Thread 3 has been checked in for 10 seconds processing: SRR1174880.4946622, SRR1174880.4946622
Sometimes，we can see： warning[vg::giraffe]: Refusing to perform too-large rescue alignment of 125 bp against 13062 bp ordered subgraph for read HWI-D00591:121:C6T49ANXX:1:1101:2716:26626 which would use more than 1572864 cells and might exhaust Dozeu's allocator; suppressing further warnings.
It's difficult to say anything without further information. What kind of data you have in the graph, how did you build it, and what are you trying to align to it? What kind of system are you using?
Have you looked at Giraffe best practices?
One common issue is that the graph is not a useful alignment of the underlying haplotypes. Giraffe prefers graphs that have a linear high-level structure and avoid complex regions, high-degree nodes, long-distance edges, and sequence duplication.
Some distributed/network file systems don't handle memory-mapped files well. Giraffe is sometimes slow if the distance index is on such a file system, especially if multiple jobs are using the same index. In such cases, it may help if you make the distance index file read-only or copy it to a local disk for each job.
Hi. I added "-p" option and launched again the job. nohup: ignoring input 开始处理样本: CRR041289 Preparing Indexes Loading Minimizer Index Loading Zipcodes Loading GBZ Loading Distance Index v2 Paging in Distance Index v2 Initializing MinimizerMapper Loading and initialization: 125.512 seconds Of which Distance Index v2 paging: 0.202229 seconds Mapping reads to "-" (GAM) --watchdog-timeout 10 --batch-size 512 --match 1 --mismatch 4 --gap-open 6 --gap-extend 1 --full-l-bonus 5 --max-multimaps 1 --hit-cap 10 --hard-hit-cap 500 --score-fraction 0.9 --max-min 500 --min-coverage-flank 250 --num-bp-per-min 1000 --downsample-window-length 18446744073709551615 --downsample-window-count 0 --distance-limit 200 --max-extensions 800 --max-alignments 8 --cluster-score 50 --pad-cluster-score 20 --cluster-coverage 0.3 --max-extension-mismatches 4 --extension-score 1 --extension-set 20 --rescue-attempts 15 --max-fragment-length 2000 --paired-distance-limit 2 --rescue-subgraph-size 4 --rescue-seed-limit 100 --mapq-score-window 0 --mapq-score-scale 1 --zipcode-tree-score-threshold 50 --pad-zipcode-tree-score-threshold 20 --zipcode-tree-coverage-threshold 0.3 --zipcode-tree-scale 2 --min-to-fragment 4 --max-to-fragment 10 --max-direct-chain 0 --gapless-extension-limit 0 --fragment-max-graph-lookback-bases 300 --fragment-max-graph-lookback-bases-per-base 0.03 --fragment-max-read-lookback-bases 18446744073709551615 --fragment-max-read-lookback-bases-per-base 1 --max-fragments 18446744073709551615 --fragment-max-indel-bases 2000 --fragment-max-indel-bases-per-base 0.2 --fragment-gap-scale 1 --fragment-points-per-possible-match 0 --fragment-score-fraction 0.1 --fragment-max-min-score 1.79769e+308 --fragment-min-score 60 --fragment-set-score-threshold 0 --min-chaining-problems 1 --max-chaining-problems 2147483647 --max-graph-lookback-bases 3000 --max-graph-lookback-bases-per-base 0.3 --max-read-lookback-bases 18446744073709551615 --max-read-lookback-bases-per-base 1 --max-indel-bases 2000 --max-indel-bases-per-base 0.2 --item-bonus 0 --item-scale 1 --gap-scale 1 --points-per-possible-match 0 --chain-score-threshold 100 --min-chains 4 --min-chain-score-per-base 0.01 --max-min-chain-score 200 --max-skipped-bases 0 --max-chains-per-tree 1 --max-chain-connection 100 --max-tail-length 100 --max-dp-cells 18446744073709551615 --max-tail-gap 18446744073709551615 --max-middle-gap 18446744073709551615 --max-tail-dp-length 30000 --max-middle-dp-length 2147483647 --wfa-max-mismatches 2 --wfa-max-mismatches-per-base 0.1 --wfa-max-max-mismatches 20 --wfa-distance 10 --wfa-distance-per-base 0.1 --wfa-max-distance 200 --min-unique-node-fraction 0 --rescue-algorithm dozeu Not counting CPU instructions because perf events are unavailable: Permission denied Using fragment length estimate: 460.314 +/- 55.4348 warning[vg::Watchdog]: Thread 5 has been checked in for 10 seconds processing: HISEQ:124:C6U8FANXX:5:1101:4875:6797, HISEQ:124:C6U8FANXX:5:1101:4875:6797 warning[vg::Watchdog]: Thread 2 has been checked in for 10 seconds processing: HISEQ:124:C6U8FANXX:5:1101:9106:10263, HISEQ:124:C6U8FANXX:5:1101:9106:10263 warning[vg::Watchdog]: Thread 5 finally checked out after 12 seconds and 561036 kb memory growth processing: HISEQ:124:C6U8FANXX:5:1101:4875:6797, HISEQ:124:C6U8FANXX:5:1101:4875:6797 warning[vg::Watchdog]: Thread 10 has been checked in for 10 seconds processing: HISEQ:124:C6U8FANXX:5:1101:1789:22273, HISEQ:124:C6U8FANXX:5:1101:1789:22273 warning[vg::Watchdog]: Thread 2 finally checked out after 15 seconds and 53132 kb memory growth processing: HISEQ:124:C6U8FANXX:5:1101:9106:10263, HISEQ:124:C6U8FANXX:5:1101:9106:10263 warning[vg::Watchdog]: Thread 0 has been checked in for 10 seconds processing: HISEQ:124:C6U8FANXX:5:1101:13851:89436, HISEQ:124:C6U8FANXX:5:1101:13851:89436 warning[vg::Watchdog]: Thread 11 has been checked in for 10 seconds processing: HISEQ:124:C6U8FANXX:5:1101:17322:30668, HISEQ:124:C6U8FANXX:5:1101:17322:30668 warning[vg::Watchdog]: Thread 0 finally checked out after 14 seconds and 2048 kb memory growth processing: HISEQ:124:C6U8FANXX:5:1101:13851:89436, HISEQ:124:C6U8FANXX:5:1101:13851:89436 warning[vg::Watchdog]: Thread 3 has been checked in for 10 seconds processing: HISEQ:124:C6U8FANXX:5:1101:19972:48886, HISEQ:124:C6U8FANXX:5:1101:19972:48886 warning[vg::Watchdog]: Thread 3 finally checked out after 19 seconds and 270508 kb memory growth processing: HISEQ:124:C6U8FANXX:5:1101:19972:48886, HISEQ:124:C6U8FANXX:5:1101:19972:48886 warning[vg::Watchdog]: Thread 6 has been checked in for 10 seconds processing: HISEQ:124:C6U8FANXX:5:1102:14649:8009, HISEQ:124:C6U8FANXX:5:1102:14649:8009 warning[vg::Watchdog]: Thread 7 has been checked in for 10 seconds processing: HISEQ:124:C6U8FANXX:5:1102:15858:12418, HISEQ:124:C6U8FANXX:5:1102:15858:12418 warning[vg::Watchdog]: Thread 9 has been checked in for 10 seconds processing: HISEQ:124:C6U8FANXX:5:1102:10544:79584, HISEQ:124:C6U8FANXX:5:1102:10544:79584 warning[vg::Watchdog]: Thread 8 has been checked in for 10 seconds processing: HISEQ:124:C6U8FANXX:5:1102:2127:83730, HISEQ:124:C6U8FANXX:5:1102:2127:83730 warning[vg::Watchdog]: Thread 1 has been checked in for 10 seconds processing: HISEQ:124:C6U8FANXX:5:1103:18928:8926, HISEQ:124:C6U8FANXX:5:1103:18928:8926 warning[vg::Watchdog]: Thread 8 finally checked out after 38 seconds and 15792 kb memory growth processing: HISEQ:124:C6U8FANXX:5:1102:2127:83730, HISEQ:124:C6U8FANXX:5:1102:2127:83730 warning[vg::Watchdog]: Thread 4 has been checked in for 10 seconds processing: HISEQ:124:C6U8FANXX:5:1103:19337:55394, HISEQ:124:C6U8FANXX:5:1103:19337:55394 warning[vg::Watchdog]: Thread 0 has been checked in for 10 seconds processing: HISEQ:124:C6U8FANXX:5:1104:3575:72010, HISEQ:124:C6U8FANXX:5:1104:3575:72010 warning[vg::Watchdog]: Thread 2 has been checked in for 10 seconds processing: HISEQ:124:C6U8FANXX:5:1103:18566:89848, HISEQ:124:C6U8FANXX:5:1103:18566:89848 warning[vg::Watchdog]: Thread 5 has been checked in for 10 seconds processing: HISEQ:124:C6U8FANXX:5:1104:10118:10384, HISEQ:124:C6U8FANXX:5:1104:10118:10384 warning[vg::Watchdog]: Thread 5 finally checked out after 14 seconds and 0 kb memory growth processing: HISEQ:124:C6U8FANXX:5:1104:10118:10384, HISEQ:124:C6U8FANXX:5:1104:10118:10384 warning[vg::Watchdog]: Thread 3 has been checked in for 10 seconds processing: HISEQ:124:C6U8FANXX:5:1104:17799:17765, HISEQ:124:C6U8FANXX:5:1104:17799:17765 warning[vg::Watchdog]: Thread 2 finally checked out after 46 seconds and 0 kb memory growth processing: HISEQ:124:C6U8FANXX:5:1103:18566:89848, HISEQ:124:C6U8FANXX:5:1103:18566:89848 warning[vg::Watchdog]: Thread 6 finally checked out after 143 seconds and 30720 kb memory growth processing: HISEQ:124:C6U8FANXX:5:1102:14649:8009, HISEQ:124:C6U8FANXX:5:1102:14649:8009 warning[vg::Watchdog]: Thread 8 has been checked in for 10 seconds processing: HISEQ:124:C6U8FANXX:5:1104:2834:26634, HISEQ:124:C6U8FANXX:5:1104:2834:26634 warning[vg::Watchdog]: Thread 5 has been checked in for 10 seconds processing: HISEQ:124:C6U8FANXX:5:1104:12416:36398, HISEQ:124:C6U8FANXX:5:1104:12416:36398 warning[vg::Watchdog]: Thread 3 finally checked out after 41 seconds and 0 kb memory growth processing: HISEQ:124:C6U8FANXX:5:1104:17799:17765, HISEQ:124:C6U8FANXX:5:1104:17799:17765 warning[vg::Watchdog]: Thread 4 finally checked out after 107 seconds and 0 kb memory growth processing: HISEQ:124:C6U8FANXX:5:1103:19337:55394, HISEQ:124:C6U8FANXX:5:1103:19337:55394 warning[vg::Watchdog]: Thread 8 finally checked out after 198 seconds and 0 kb memory growth processing: HISEQ:124:C6U8FANXX:5:1104:2834:26634, HISEQ:124:C6U8FANXX:5:1104:2834:26634 warning[vg::Watchdog]: Thread 0 finally checked out after 266 seconds and 0 kb memory growth processing: HISEQ:124:C6U8FANXX:5:1104:3575:72010, HISEQ:124:C6U8FANXX:5:1104:3575:72010 warning[vg::Watchdog]: Thread 3 has been checked in for 10 seconds processing: HISEQ:124:C6U8FANXX:5:1105:5834:5894, HISEQ:124:C6U8FANXX:5:1105:5834:5894 warning[vg::Watchdog]: Thread 8 has been checked in for 10 seconds processing: HISEQ:124:C6U8FANXX:5:1105:13377:18875, HISEQ:124:C6U8FANXX:5:1105:13377:18875 warning[vg::Watchdog]: Thread 3 finally checked out after 31 seconds and 0 kb memory growth processing: HISEQ:124:C6U8FANXX:5:1105:5834:5894, HISEQ:124:C6U8FANXX:5:1105:5834:5894 warning[vg::Watchdog]: Thread 6 has been checked in for 10 seconds processing: HISEQ:124:C6U8FANXX:5:1105:20835:51617, HISEQ:124:C6U8FANXX:5:1105:20835:51617 warning[vg::Watchdog]: Thread 7 finally checked out after 405 seconds and 28672 kb memory growth processing: HISEQ:124:C6U8FANXX:5:1102:15858:12418, HISEQ:124:C6U8FANXX:5:1102:15858:12418 warning[vg::Watchdog]: Thread 8 finally checked out after 43 seconds and 0 kb memory growth processing: HISEQ:124:C6U8FANXX:5:1105:13377:18875, HISEQ:124:C6U8FANXX:5:1105:13377:18875 warning[vg::Watchdog]: Thread 7 has been checked in for 10 seconds processing: HISEQ:124:C6U8FANXX:5:1106:2455:9376, HISEQ:124:C6U8FANXX:5:1106:2455:9376 warning[vg::Watchdog]: Thread 7 finally checked out after 17 seconds and 0 kb memory growth processing: HISEQ:124:C6U8FANXX:5:1106:2455:9376, HISEQ:124:C6U8FANXX:5:1106:2455:9376 warning[vg::Watchdog]: Thread 0 has been checked in for 10 seconds processing: HISEQ:124:C6U8FANXX:5:1107:4947:74146, HISEQ:124:C6U8FANXX:5:1107:4947:74146 warning[vg::Watchdog]: Thread 3 has been checked in for 10 seconds processing: HISEQ:124:C6U8FANXX:5:1106:5989:66520, HISEQ:124:C6U8FANXX:5:1106:5989:66520 warning[vg::Watchdog]: Thread 3 finally checked out after 18 seconds and 0 kb memory growth processing: HISEQ:124:C6U8FANXX:5:1106:5989:66520, HISEQ:124:C6U8FANXX:5:1106:5989:66520 warning[vg::Watchdog]: Thread 8 has been checked in for 10 seconds processing: HISEQ:124:C6U8FANXX:5:1107:12423:5598, HISEQ:124:C6U8FANXX:5:1107:12423:5598 warning[vg::Watchdog]: Thread 3 has been checked in for 10 seconds processing: HISEQ:124:C6U8FANXX:5:1107:7942:40596, HISEQ:124:C6U8FANXX:5:1107:7942:40596 warning[vg::Watchdog]: Thread 2 has been checked in for 10 seconds processing: HISEQ:124:C6U8FANXX:5:1107:12146:51406, HISEQ:124:C6U8FANXX:5:1107:12146:51406 warning[vg::Watchdog]: Thread 7 has been checked in for 10 seconds processing: HISEQ:124:C6U8FANXX:5:1107:9367:62351, HISEQ:124:C6U8FANXX:5:1107:9367:62351 warning[vg::Watchdog]: Thread 7 finally checked out after 35 seconds and 0 kb memory growth processing: HISEQ:124:C6U8FANXX:5:1107:9367:62351, HISEQ:124:C6U8FANXX:5:1107:9367:62351 warning[vg::Watchdog]: Thread 1 finally checked out after 630 seconds and 13744 kb memory growth processing: HISEQ:124:C6U8FANXX:5:1103:18928:8926, HISEQ:124:C6U8FANXX:5:1103:18928:8926 warning[vg::Watchdog]: Thread 8 finally checked out after 282 seconds and 0 kb memory growth processing: HISEQ:124:C6U8FANXX:5:1107:12423:5598, HISEQ:124:C6U8FANXX:5:1107:12423:5598 warning[vg::Watchdog]: Thread 2 finally checked out after 354 seconds and 0 kb memory growth processing: HISEQ:124:C6U8FANXX:5:1107:12146:51406, HISEQ:124:C6U8FANXX:5:1107:12146:51406 warning[vg::Watchdog]: Thread 0 finally checked out after 629 seconds and 0 kb memory growth processing: HISEQ:124:C6U8FANXX:5:1107:4947:74146, HISEQ:124:C6U8FANXX:5:1107:4947:74146 warning[vg::Watchdog]: Thread 2 has been checked in for 10 seconds processing: HISEQ:124:C6U8FANXX:5:1107:6524:83125, HISEQ:124:C6U8FANXX:5:1107:6524:83125 warning[vg::Watchdog]: Thread 4 has been checked in for 10 seconds processing: HISEQ:124:C6U8FANXX:5:1108:11172:6667, HISEQ:124:C6U8FANXX:5:1108:11172:6667 warning[vg::Watchdog]: Thread 0 has been checked in for 10 seconds processing: HISEQ:124:C6U8FANXX:5:1109:1349:36047, HISEQ:124:C6U8FANXX:5:1109:1349:36047 warning[vg::Watchdog]: Thread 1 has been checked in for 10 seconds processing: HISEQ:124:C6U8FANXX:5:1108:15792:33501, HISEQ:124:C6U8FANXX:5:1108:15792:33501 warning[vg::Watchdog]: Thread 0 finally checked out after 18 seconds and 0 kb memory growth processing: HISEQ:124:C6U8FANXX:5:1109:1349:36047, HISEQ:124:C6U8FANXX:5:1109:1349:36047 warning[vg::Watchdog]: Thread 7 has been checked in for 10 seconds processing: HISEQ:124:C6U8FANXX:5:1108:2422:51043, HISEQ:124:C6U8FANXX:5:1108:2422:51043 warning[vg::Watchdog]: Thread 3 finally checked out after 678 seconds and 0 kb memory growth processing: HISEQ:124:C6U8FANXX:5:1107:7942:40596, HISEQ:124:C6U8FANXX:5:1107:7942:40596 warning[vg::Watchdog]: Thread 8 has been checked in for 10 seconds processing: HISEQ:124:C6U8FANXX:5:1108:10534:75439, HISEQ:124:C6U8FANXX:5:1108:10534:75439 warning[vg::Watchdog]: Thread 3 has been checked in for 10 seconds processing: HISEQ:124:C6U8FANXX:5:1108:4761:82363, HISEQ:124:C6U8FANXX:5:1108:4761:82363 warning[vg::Watchdog]: Thread 3 finally checked out after 20 seconds and 0 kb memory growth processing: HISEQ:124:C6U8FANXX:5:1108:4761:82363, HISEQ:124:C6U8FANXX:5:1108:4761:82363 warning[vg::Watchdog]: Thread 0 has been checked in for 10 seconds processing: HISEQ:124:C6U8FANXX:5:1110:6845:44636, HISEQ:124:C6U8FANXX:5:1110:6845:44636 warning[vg::Watchdog]: Thread 3 has been checked in for 10 seconds processing: HISEQ:124:C6U8FANXX:5:1109:18875:22264, HISEQ:124:C6U8FANXX:5:1109:18875:22264 warning[vg::Watchdog]: Thread 3 finally checked out after 13 seconds and 0 kb memory growth processing: HISEQ:124:C6U8FANXX:5:1109:18875:22264, HISEQ:124:C6U8FANXX:5:1109:18875:22264 warning[vg::Watchdog]: Thread 3 has been checked in for 10 seconds processing: HISEQ:124:C6U8FANXX:5:1109:8102:41645, HISEQ:124:C6U8FANXX:5:1109:8102:41645 warning[vg::Watchdog]: Thread 8 finally checked out after 265 seconds and 0 kb memory growth processing: HISEQ:124:C6U8FANXX:5:1108:10534:75439, HISEQ:124:C6U8FANXX:5:1108:10534:75439 warning[vg::Watchdog]: Thread 1 finally checked out after 346 seconds and 0 kb memory growth processing: HISEQ:124:C6U8FANXX:5:1108:15792:33501, HISEQ:124:C6U8FANXX:5:1108:15792:33501 warning[vg::Watchdog]: Thread 8 has been checked in for 10 seconds processing: HISEQ:124:C6U8FANXX:5:1109:8687:42369, HISEQ:124:C6U8FANXX:5:1109:8687:42369 warning[vg::Watchdog]: Thread 8 finally checked out after 30 seconds and 0 kb memory growth processing: HISEQ:124:C6U8FANXX:5:1109:8687:42369, HISEQ:124:C6U8FANXX:5:1109:8687:42369 warning[vg::Watchdog]: Thread 8 has been checked in for 10 seconds processing: HISEQ:124:C6U8FANXX:5:1109:7462:67294, HISEQ:124:C6U8FANXX:5:1109:7462:67294 warning[vg::Watchdog]: Thread 1 has been checked in for 10 seconds processing: HISEQ:124:C6U8FANXX:5:1110:13789:20012, HISEQ:124:C6U8FANXX:5:1110:13789:20012 warning[vg::Watchdog]: Thread 1 finally checked out after 72 seconds and 0 kb memory growth processing: HISEQ:124:C6U8FANXX:5:1110:13789:20012, HISEQ:124:C6U8FANXX:5:1110:13789:20012 warning[vg::Watchdog]: Thread 3 finally checked out after 280 seconds and 0 kb memory growth processing: HISEQ:124:C6U8FANXX:5:1109:8102:41645, HISEQ:124:C6U8FANXX:5:1109:8102:41645 warning[vg::Watchdog]: Thread 3 has been checked in for 10 seconds processing: HISEQ:124:C6U8FANXX:5:1110:13939:38091, HISEQ:124:C6U8FANXX:5:1110:13939:38091 warning[vg::Watchdog]: Thread 3 finally checked out after 28 seconds and 0 kb memory growth processing: HISEQ:124:C6U8FANXX:5:1110:13939:38091, HISEQ:124:C6U8FANXX:5:1110:13939:38091 warning[vg::Watchdog]: Thread 6 finally checked out after 1402 seconds and 0 kb memory growth processing: HISEQ:124:C6U8FANXX:5:1105:20835:51617, HISEQ:124:C6U8FANXX:5:1105:20835:51617 warning[vg::Watchdog]: Thread 2 finally checked out after 711 seconds and 0 kb memory growth processing: HISEQ:124:C6U8FANXX:5:1107:6524:83125, HISEQ:124:C6U8FANXX:5:1107:6524:83125 warning[vg::Watchdog]: Thread 4 finally checked out after 1556 seconds and 0 kb memory growth processing: HISEQ:124:C6U8FANXX:5:1108:11172:6667, HISEQ:124:C6U8FANXX:5:1108:11172:6667 warning[vg::Watchdog]: Thread 7 finally checked out after 3337 seconds and 0 kb memory growth processing: HISEQ:124:C6U8FANXX:5:1108:2422:51043, HISEQ:124:C6U8FANXX:5:1108:2422:51043
如果没有进一步的信息，很难说什么。图表中有什么样的数据，你是如何构建的，你试图与它保持一致？您使用什么样的系统？
你看过长颈鹿的最佳实践吗？
一个常见的问题是该图不是底层单倍型的有用对齐方式。长颈鹿更喜欢具有线性高级结构的图，避免复杂区域、高次节点、长距离边和序列重复。
某些分布式/网络文件系统不能很好地处理内存映射文件。如果距离索引位于此类文件系统上，则 Giraffe 有时会很慢，尤其是当多个作业使用相同的索引时。在这种情况下，将距离索引文件设为只读或将其复制到每个作业的本地磁盘可能会有所帮助。
The output file size is not growing at a steady rate. I set -t 12, but after running for a while, the CPU usage suddenly dropped from 1200 to around 700.
That behavior of dropping to 700% CPU usage is consistent with the problem being that a few reads are very slow to map.
Look at this message from the first log:
warning[vg::Watchdog]: Thread 3 finally checked out after 25102 seconds and 246812 kb memory growth processing: SRR1174880.646249, SRR1174880.646249
That's way more time than a read pair ought to take. This is probably one of the very slow reads that are causing the problem.
Can you please share the graph you are using, and the sequences for that read pair, so we can try and reproduce the problem?
As a workaround, you could try chmod -w your_graph.dist, or to move the .dist file to /tmp or another local storage location and pass it on the command line like vg giraffe --dist-name /tmp/your_graph.dist. If your problem is actually coming from a slow network filesystem for the distance index, which then makes all the reads much slower and thus makes what would have been merely somewhat slow reads into pathologically slow reads, then that would solve it. Please let us know if it does.
But I suspect the real problem is with the shape of the graph; if the graph is too tangled in some places, reads that touch those places might take too long to map. We can't diagnose such an issue for you any more specifically without access to the graph or a description of how you got it. Did you build this graph with Minigraph-Cactus, PGGB, or some other tool? Or did you download it from somewhere?
The MC I used is a graph pan-genome constructed from 25 genomes.
I ran chmod -w my_graph.dist, but the issue persists. The sequences for alignment were downloaded from the internet as second-generation sequencing data.
这种下降到 700% CPU 使用率的行为与一些读取映射速度非常慢的问题一致。
查看第一个日志中的此消息：
warning[vg::Watchdog]: Thread 3 finally checked out after 25102 seconds and 246812 kb memory growth processing: SRR1174880.646249, SRR1174880.646249这比阅读对应该花费的时间要多得多。这可能是导致问题的非常慢的读取之一。
您能否分享您正在使用的图形以及该读取对的序列，以便我们可以尝试重现问题？
作为解决方法，您可以尝试 或将文件移动到或其他本地存储位置，并在命令行上传递它，例如 。如果你的问题实际上来自距离索引的慢速网络文件系统，这会使所有读取速度变慢得多，从而使原本只是有点慢的读取变成病态的缓慢读取，那么这将解决它。如果有，请告诉我们。
chmod -w your_graph.dist``.dist``/tmp``vg giraffe --dist-name /tmp/your_graph.dist但我怀疑真正的问题在于图表的形状;如果图形在某些地方过于纠结，则接触这些地方的读取可能需要很长时间才能映射。如果无法访问图表或描述您是如何获得该问题的，我们就无法更具体地为您诊断此类问题。你是用 Minigraph-Cactus、PGGB 还是其他工具构建这个图表的？还是你从某个地方下载的？
Could it be an issue with the sequencing samples? I tested several samples and found that some ran very quickly with stable output, while others did not perform well. However, all these samples were sequenced on the same platform.
"if the graph is too tangled in some places, reads that touch those places might take too long to map." If that's really the case, is there anything we can do about it?
Minigraph-Cactus graphs should be the right shape overall, unless something has gone wrong with their construction.
Is there anything interesting about the quality score or read length distributions between the samples that work well and the samples that don't? Or the genetic distance between them and the assemblies in the graph?
If you want to troubleshoot the graph construction, I think @glennhickey is the right person for support on the Minigraph-Cactus pipeline.
If you could provide some of the very slow reads, and the graph itself, or at least the graph and some linear assembly positions you think some of those very slow reads ought to be near, then we could look and see if it looks like there's something to be fixed in Minigraph-Cactus.
You could also try fiddling with the Giraffe parameters to try and make it lazier, so it does less work and maybe can then map your reads. You could start by trying --parameter-preset fast, and if that's not enough you can start reducing --hard-hit-cap, --max-extensions, and/or --max-alignments. But that's likely to make the mappings less accurate.
@adamnovak @upsm-123 I find the same problem. I tried the last three versions of VG (from 1.66 to 1.68) to be sure it's not related to this, but I see the same pattern. I'm aligning to the cactus clipped pangenome, and it doesn't seem related to the pangenome but rather to some of the Illumina reads used. I tried every preset fast, lower --hard-hit-cap, --max-extension etc, different index etc. but nothing worked.
Then I just noticed that the program starts okay at the beginning but then starts to have this problem. This made me think about the fact that the program estimates the pair reads length with the first 1000 reads. And this was shorter than the expected average of the library. So I just corrected adding the parameters for considering reads length of my library with a big stdev and everything worked fine: --fragment-mean 500 --fragment-stdev 100 (leaving other default parameters and preset fast)
I think the problem is that giraffe start to struggle when find pair of reads with the distance bigger than what he estimate. If you need anything to do a better debugging @adamnovak let me know.
@leone93 I’m encountering the same issue. I’ve adjusted the --fragment-mean and --fragment-stdev parameters based on the first 50,000 reads, but the problem still remains. Could you suggest a better approach?
Dear @zhangyehao, fortunately, in my case, simply increasing those two parameters enables giraffe to work with paired ends. What is the estimated size of your library?
@leone93 My --fragment-mean and --fragment-stdev parameters are determined based on the first 50,000 paired reads. Some samples work fine, but there are still some that don’t. For example, for one sample with “Using fragment length estimate: 781.7 +/- 47.2”, the following messages appear:
warning[vg::Watchdog]: Thread 2 has been checked in for 10 seconds processing: SRR836315.811522, SRR836315.811522
warning[vg::Watchdog]: Thread 2 finally checked out after 3959 seconds and 303096 kb memory growth processing: SRR836315.811522, SRR836315.811522
......................
Did you see if the problem comes after the first 50k reads? Just a silly question You could even try less conservative parameter like --parameter-preset fast --fragment-mean 800 --fragment-stdev 100. Let me know