On Wed, May 30, 2018 at 9:54 AM, Yavuz Selim Sertoğlu < yavuzselim.serto...@bisoft.com.tr> 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, kull > anici2_.eposta, kullanici2_.kullaniciadi, kullanici2_.kullanicitipienum, > kullanici2_.parola, kullanici2_.soyad > Hash 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_id > Filter: (this_.tarih < '2018-05-23 02:00:00.023'::timestamp > without time zone) > Rows Removed by Filter: 3178 > Buffers: 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_. > soyad > Buckets: 16384 Batches: 1 Memory Usage: 1604kB > Buffers: 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, kullan > ici2_.soyad > Buffers: shared hit=190 > * Planning time: 2.331 ms* > * Execution time: 5431.817 ms* > > > T *wo 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!
