Description of problem: In part of the scale out scenario, we faced response time degradation, that mainly caused by CPU time degradation on the DB machine. the following SP getdisksvmguid response time affected from the CPU load on the machine. once the engine have lots of disks the DB CPU raising and same the response time of getdisksvmguid. lots of getdisksvmguid queries were detected during the ramp up, and most of them have long response time around more 10K registered disks. we also found that ovirt-engine-dwh consume lots some of the CPU load. once ovirt-engine-dwhd daemon stopped, DB CPU utilization went down, and the query runs faster (query exec time went from ~8 sec to ~1). adding some spec on the local disk of the DB machine: random-read: (g=0): rw=randread, bs=4K-4K/4K-4K/4K-4K, ioengine=sync, iodepth=1 fio-2.1.10 Starting 1 process random-read: Laying out IO file(s) (1 file(s) / 128MB) Jobs: 1 (f=1): [r] [-.-% done] [60371KB/0KB/0KB /s] [15.1K/0/0 iops] [eta 00m:00s] random-read: (groupid=0, jobs=1): err= 0: pid=41185: Sun Jan 29 16:16:12 2017 read : io=131072KB, bw=60681KB/s, iops=15170, runt= 2160msec clat (usec): min=53, max=18245, avg=61.92, stdev=102.75 lat (usec): min=54, max=18245, avg=62.17, stdev=102.75 clat percentiles (usec): | 1.00th=[ 55], 5.00th=[ 56], 10.00th=[ 56], 20.00th=[ 56], | 30.00th=[ 57], 40.00th=[ 57], 50.00th=[ 58], 60.00th=[ 59], | 70.00th=[ 60], 80.00th=[ 63], 90.00th=[ 73], 95.00th=[ 78], | 99.00th=[ 100], 99.50th=[ 106], 99.90th=[ 117], 99.95th=[ 129], | 99.99th=[ 233] bw (KB /s): min=58944, max=61680, per=100.00%, avg=60790.00, stdev=1276.45 lat (usec) : 100=98.94%, 250=1.05%, 500=0.01% lat (msec) : 4=0.01%, 20=0.01% cpu : usr=9.08%, sys=38.68%, ctx=32769, majf=0, minf=36 IO depths : 1=100.0%, 2=0.0%, 4=0.0%, 8=0.0%, 16=0.0%, 32=0.0%, >=64=0.0% submit : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0% complete : 0=0.0%, 4=100.0%, 8=0.0%, 16=0.0%, 32=0.0%, 64=0.0%, >=64=0.0% issued : total=r=32768/w=0/d=0, short=r=0/w=0/d=0 latency : target=0, window=0, percentile=100.00%, depth=1 Run status group 0 (all jobs): READ: io=131072KB, aggrb=60681KB/s, minb=60681KB/s, maxb=60681KB/s, mint=2160msec, maxt=2160msec Disk stats (read/write): dm-0: ios=30980/98, merge=0/0, ticks=1216/10, in_queue=1226, util=57.02%, aggrios=32768/102, aggrmerge=0/0, aggrticks=1251/11, aggrin_queue=1239, aggrutil=54.13% sda: ios=32768/102, merge=0/0, ticks=1251/11, in_queue=1239, util=54.13% Version-Release number of selected component (if applicable): 4.1.0-8 How reproducible: 100% Steps to Reproduce: 1. engine populated with 250 hosts and 10K vm disks. Actual results: create vm, start vm, add disk to vm - having very long response time which caused by getdiskvmguid Expected results: fast and stable query response Additional info:
Please attach relevant logs and other data. Please open a separate bug on DWH
(In reply to Yaniv Kaul from comment #1) > Please attach relevant logs and other data. > Please open a separate bug on DWH seems like there is no relevant logs beside the DB logs, in order to track the queries. we can have as well profiling session for the JVM. but lets start with this. about the separate bug, I and rgolan decided to address it via this https://bugzilla.redhat.com/show_bug.cgi?id=1395608
Roy, can you have a look?
under load, more than 10000 disks, this query is quite a beast for the planner and may take seconds to complete. It affects specialy create VM which keeps degrading as the num of disks grows. Migrate Vm is also affected by this. Before changing the query we can maybe use more suitable query/s. Examples from RunVmValidator and its internal validator - I find the usages of getVmDisks() and getVmDiskImages method: 1. only need the disk list size here: protected ValidationResult validateStoragePoolUp(VM vm, StoragePool storagePool, List<DiskImage> vmImages) { if (vmImages.isEmpty() || vm.isAutoStartup()) { 2. ImageHandler only needs the domain id of the disks public static Set<Guid> getAllStorageIdsForImageIds(Collection<DiskImage> images) { Set<Guid> domainsIds = new HashSet<>(); for (DiskImage image : images) { domainsIds.addAll(image.getStorageIds()); } 3. Only need disk image status check here private ValidationResult diskImagesNotInStatus(ImageStatus status, EngineMessage failMessage) { Tal can't we use some non view tables for this tasks or perhaps create a thinner view if we don't have something already for that? the amount of info is just no propotional to what we use in this flow.
Liron, isn't this a dup of bug 1412626?
The fix for bz 1412626 should improve this scenario as well. On Eldad db with dwh enabled the query time was 50% lower with that change. Regardless, we should look into improving that query and reduce the usages of it. Eldad, if you can - please confirm that the situation has improved. I believe we can keep this BZ to make the query improvement/lowering its usage. Regards, Liron
Moving to 4.1.3, as it simply waits on scale QE results and only happens on fairly large environments.
(In reply to Liron Aravot from comment #7) > The fix for bz 1412626 should improve this scenario as well. On Eldad db > with dwh enabled the query time was 50% lower with that change. > Regardless, we should look into improving that query and reduce the usages > of it. > > Eldad, if you can - please confirm that the situation has improved. > I believe we can keep this BZ to make the query improvement/lowering its > usage. > > Regards, > Liron Eyal, due to other priorities, we need to coordinate this test in order to reproduce it
(In reply to Yaniv Kaul from comment #8) > Moving to 4.1.3, as it simply waits on scale QE results and only happens on > fairly large environments. Moving to ON_QA to validate if there's a justification for continued dev work.
Eyal, this bug can be reproduced with vdsmfake and high scale env. we need to coordinate it per the severity. currently it's medium, seems like we can push it to 4.2 or coordinate it to 4.1.x
A short feedback about this bug, we have populated the setup with 6500 disks, divided by ~3000 vms. when creating vms in bulks, we still seeing high cpu peaks 40-80%. we're able to reproduce the issue manually with simple script[1] that simulate 50 sql calls of getdisksvmguid simultaneously. while running this script we can identify 80-90% CPU utilization on a 24 cores box. looks like this query generates high cpu, specially for simultaneously SQL's. [1] #!/bin/sh db=$1 sql=$2 parallel=$3 for p in `seq 1 $parallel`; do nohup psql -U $db -c "$sql" > /dev/null 2>&1 & echo ""; done
I wouldn't be surprised if 50 concurrent calls to this SP generate a high load. The question is whether there's a relevant flow that uses the engine that results in such a peak?
(In reply to Allon Mureinik from comment #13) > I wouldn't be surprised if 50 concurrent calls to this SP generate a high > load. The question is whether there's a relevant flow that uses the engine > that results in such a peak? Yes, the flow is when creating \ starting vms in bulk of 50 vms. considering creating \ starting vms in bulks we might faced it. Im pretty sure, some costumers doing it, Moran any insights ?
Moran, please advise per comment https://bugzilla.redhat.com/show_bug.cgi?id=1417471#c14
I don't think this bug is in high priority, but run VM time is probably suffering from this, but it is on large scale ( more than 1000 or 1500 vms and concurrent VM start of > 30 ). For most of the use cases it is less relevant. Moran your welcome to fill in here. emarcian, eberman when you come to test this make sure - run everything with engine, don't simulate parallel using a script - use a good lun disk for the db - check the time it takes to run/create vm
I doubt if this needs an excecption flag.
(In reply to Roy Golan from comment #19) > I doubt if this needs an excecption flag. It doesn't, but then it should not be in 4.1.3. Doesn't matter right now as it is on qa already.
(In reply to Roy Golan from comment #18) > I don't think this bug is in high priority, but run VM time is probably > suffering from this, but it is on large scale ( more than 1000 or 1500 vms > and concurrent VM start of > 30 ). For most of the use cases it is less > relevant. Moran your welcome to fill in here. > > emarcian, eberman when you come to test this make sure > - run everything with engine, don't simulate parallel using a script > - use a good lun disk for the db > - check the time it takes to run/create vm Roy, I profile the engine with scsi lun as disk (flash drive) + run everything from engine. topology (using fake) 12 SD's, 250 hosts, ~1300 vms, ~3800 disks. I used jprofiler to measure the performance on top of this scale. - there is good perfomance for batch creation until but just for few hundred vms. - there is bad performance for ~1000+ vms just for batch calls - 22 sec and above. - single call not affected form this such of scale (currently ~1300 vms 3800 disks). and it runs by sec. bottom line concurrency + high scale = bigger impact. when I breakdown the response time (for batch call in size of 50 threads) I see the "insertnewvm" query runs by 10-15 sec. the sp getdiskvmguid runs by 2-4 sec. it looks like it's all about of concurrency in high scale(1000+ vms, ~3000 disks) there is more room for improvements but for now it is a questions of priority. also, we should consider that we run postgres on top of flash drive, which give us a boost to handle more concurrency, and specially this $SUBJECT SP. also we test this on stronger machine in terms of CPU, than we had on the previous lab.
Based on this comment I think its fair to push this 4.2 as medium. It will be nice to make the use of our queries more efficiently by picking the right places to use them as suggested in comment 5. Indeed we expect that environments that want to > 1500 vms and large number of disk to at least use an SSD disk for db and normal CPU so there is no surprise that the numbers are better on the current test setup.
(In reply to Roy Golan from comment #22) > Based on this comment I think its fair to push this 4.2 as medium. It will > be nice to make the use of our queries more efficiently by picking the right > places to use them as suggested in comment 5. > > Indeed we expect that environments that want to > 1500 vms and large number > of disk to at least use an SSD disk for db and normal CPU so there is no > surprise that the numbers are better on the current test setup. pushing to 4.2, with the suggested changes.
Target release should be placed once a package build is known to fix a issue. Since this bug is not modified, the target version has been reset. Please use target milestone to plan a fix for a oVirt release.
(In reply to Roy Golan from comment #22) > Based on this comment I think its fair to push this 4.2 as medium. It will > be nice to make the use of our queries more efficiently by picking the right > places to use them as suggested in comment 5. Please open a new bug on this, there's way to much stuff going on on this one. E.g., Eldad's verification steps would be meaningless for such an effort, as they call this SP in a loop, and the required behavior is for RHV to use different queries.