Accelerated queries are blocked on downstream

Some accelerated queries still took more than 1min. The job profile shows that most of effort is taken on ‘Blocked On Downstream’.

Here are threads information.

Phase Thread Reporting First Start Last Start First End Last End Min First-run Avg First-run Max First-run Min Wall-clock Avg Wall-clock Max Wall-clock Min Sleep Avg Sleep Max Sleep Min Blocked Avg Blocked Max Blocked Last Update Last Progress Max Peak Memory
00-xx-xx 1 / 1 1.275s 1.275s 1m25s 1m25s 0.000s 0.000s 0.000s 1m24s 1m24s 1m24s 0.017s 0.017s 0.017s 1m23s 1m23s 1m23s 08:18:04 08:18:04 22MB
01-xx-xx 2 / 2 1.275s 1.276s 1m18s 1m25s 0.000s 0.000s 0.001s 1m17s 1m20s 1m24s 0.007s 0.008s 0.009s 1m15s 1m18s 1m21s 08:18:04 08:18:04 81MB
Phase: 00-xx-xx
Thread ID Host Name Start End Wall-clock time First-run Setup Runtime Finish Waiting Blocked On Downstream Blocked On Upstream Blocked On other Num-runs Max Records Max Batches Last Update Last Progress Peak Memory State
00-00-xx xxxxxxxxxxxxxxxx 1.275s 1m25s 1m24s 0.000s 0.002s 0.573s 0.001s 0.017s 1m23s 0.045s 0.000s 2,932 1,978,504 974 08:18:04 08:18:04 22MB FINISHED
Phase Metrics
Phase: 01-xx-xx
Thread ID Host Name Start End Wall-clock time First-run Setup Runtime Finish Waiting Blocked On Downstream Blocked On Upstream Blocked On other Num-runs Max Records Max Batches Last Update Last Progress Peak Memory State
01-00-xx xxxxxxxxxxxxxxxx 1.275s 1m18s 1m17s 0.001s 0.013s 1.898s 0.001s 0.007s 1m15s 0.000s 0.000s 1,451 726,992 362 08:17:57 08:17:57 34MB FINISHED
01-01-xx xxxxxxxxxxxxxxxx 1.276s 1m25s 1m24s 0.000s 0.025s 2.614s 0.003s 0.009s 1m21s 0.000s 0.000s 2,461 1,255,567 615 08:18:04 08:18:04 81MB FINISHED

Hi @pisces312

Can we please have the complete profile ?

Share a Query Profile

Thanks
@balaji.ramaswamy

Sorry that I cannot share the raw job profile. You can let me know which part is useful for you.

Same problem here, @balaji.ramaswamy. Randomly, the query that usually takes <1s, start to take 19s or more.

Using 4.0.2-201910020123580864-a98a0b9 build.

Profile attached.60622d82-ec15-48bf-b672-7908e20b2aaf.zip (9.0 KB)

2 Likes

@allan.sene

Can you please check the coordinator metrics and see if there was a CPU spike at the time the query ran? Can you also please check GC logs and see if there is full GC at that time. GC logs are recorded in UTC, the time the query ran in UTC time is “Thursday, October 24, 2019 2:23:16.121 PM”

Thanks
@balaji.ramaswamy