On Wed, May 30, 2018 at 9:54 AM, Yavuz Selim Sertoğlu <yavuzselim.sertoglu@xxxxxxxxxxxxx> wrote:
I am just a regular dba so I dont know what's sent from application exactly but I assume now()-1 week.In the log file, there are two more same queries. And their value is 2018-05-23 02:00:00
Here are todays log lines for that query.tarih=2018-05-30 02:12:19 +03,session_number=1,db=mydb,user=myuser,app=[unknown], client=myip,port=7128,xid=0, sid=5b0ddb70.1bd8 ,LOG: duration: 739797.540 ms execute <unnamed>: select this_.ID as ID107_1_, this_.islemTuru as islemTuru107_1_, this_.kullanici_ID as kullanici7_107_1_, this_.loglananIslem as loglanan3_107_1_, this_.oncekiVeri as oncekiVeri107_1_, this_.tarih as tarih107_1_, this_.veri as veri107_1_, kullanici2_.ID as ID103_0_, kullanici2_.ad as ad103_0_, kullanici2_.aktif as aktif103_0_, kullanici2_.dbUser as dbUser103_0_, kullanici2_.ePosta as ePosta103_0_, kullanici2_.kullaniciAdi as kullanic6_103_0_, kullanici2_.kullaniciTipiEnum as kullanic7_103_0_, kullanici2_.parola as parola103_0_, kullanici2_.soyad as soyad103_0_ from t_log_kaydi this_ left outer join t_kullanici kullanici2_ on this_.kullanici_ID=kullanici2_ .ID where this_.tarih<$1 tarih=2018-05-30 02:12:19 +03,session_number=2,db=mydb,user=myuser,app=[unknown], client=myip,port=7128,xid=0, sid=5b0ddb70.1bd8 ,DETAIL: parameters: $1 = '2018-05-23 02:00:00.023' tarih=2018-05-30 08:48:18 +03,session_number=4725,db=mydb,user=myuser,app=[unknown] ,client=myip,port=24169,xid=0, sid=5b0d365c.5e69 ,LOG: duration: 24498773.468 ms execute <unnamed>: select this_.ID as ID4_1_, this_.islemTuru as islemTuru4_1_, this_.kullanici_ID as kullanici7_4_1_, this_.loglananIslem as loglanan3_4_1_, this_.oncekiVeri as oncekiVeri4_1_, this_.tarih as tarih4_1_, this_.veri as veri4_1_, kullanici2_.ID as ID0_0_, kullanici2_.ad as ad0_0_, kullanici2_.aktif as aktif0_0_, kullanici2_.dbUser as dbUser0_0_, kullanici2_.ePosta as ePosta0_0_, kullanici2_.kullaniciAdi as kullanic6_0_0_, kullanici2_.kullaniciTipiEnum as kullanic7_0_0_, kullanici2_.parola as parola0_0_, kullanici2_.soyad as soyad0_0_ from t_log_kaydi this_ left outer join t_kullanici kullanici2_ on this_.kullanici_ID=kullanici2_ .ID where this_.tarih<$1 tarih=2018-05-30 08:48:18 +03,session_number=4726,db=mydb,user=myuser,app=[unknown] ,client=myip,port=24169,xid=0, sid=5b0d365c.5e69 ,DETAIL: parameters: $1 = '2018-05-23 02:00:00' I explain analyzed same query with that value and its completed in 6 seconds.------------------------------------------------------------ ------------------------------ ------------------------------ ------------------------------ ------------------------------ ----------------- ------------------------------------------------------------ ------------------------------ --------------------- Hash Left Join (cost=388.90..60022.26 rows=1165585 width=503) (actual time=34.951..4338.432 rows=1167885 loops=1)Output: this_.id, this_.islemturu, this_.kullanici_id, this_.loglananislem, this_.oncekiveri, this_.tarih, this_.veri, kullanici2_.id, kullanici2_.ad, kullanici2_.aktif, kullanici2_.dbuser, kullanici2_.eposta, kullanici2_.kullaniciadi, kullanici2_.kullanicitipienum, kullanici2_.parola, kullanici2_.soyadHash Cond: (this_.kullanici_id = kullanici2_.id)Buffers: shared hit=29227-> Seq Scan on public.t_log_kaydi this_ (cost=0.00..43626.00 rows=1165585 width=374) (actual time=0.010..1611.388 rows=1167885 loops=1)Output: this_.id, this_.islemturu, this_.loglananislem, this_.oncekiveri, this_.tarih, this_.veri, this_.kullanici_idFilter: (this_.tarih < '2018-05-23 02:00:00.023'::timestamp without time zone)Rows Removed by Filter: 3178Buffers: shared hit=29034-> Hash (cost=278.40..278.40 rows=8840 width=129) (actual time=34.770..34.770 rows=9134 loops=1)Output: kullanici2_.id, kullanici2_.ad, kullanici2_.aktif, kullanici2_.dbuser, kullanici2_.eposta, kullanici2_.kullaniciadi, kullanici2_.kullanicitipienum, kullanici2_.parola, kullanici2_.soyadBuckets: 16384 Batches: 1 Memory Usage: 1604kBBuffers: shared hit=190-> Seq Scan on public.t_kullanici kullanici2_ (cost=0.00..278.40 rows=8840 width=129) (actual time=0.005..16.630 rows=9134 loops=1)Output: kullanici2_.id, kullanici2_.ad, kullanici2_.aktif, kullanici2_.dbuser, kullanici2_.eposta, kullanici2_.kullaniciadi, kullanici2_.kullanicitipienum, kullanici2_.parola, kullanici2_.soyadBuffers: shared hit=190Planning time: 2.331 msExecution time: 5431.817 ms
Two things:
From your explain, it looks like you need an index on
this_.tarih, since it is doing a sequential scan when it should be using an index.
Also, your main problem is that when you have two exact same queries executing at the same time, they will cause contention in
the disk, and neither one will make much progress.
--
Melvin Davidson
Maj. Database & Exploration Specialist
Universe Exploration Command – UXC
Employment by invitation only!
Maj. Database & Exploration Specialist
Universe Exploration Command – UXC
Employment by invitation only!
