1

I am having a bit of trouble trying to figure out why a query is taking long to execute. When I check log it seems the log may be either incomplete. postgresql log

My question is, what is ^M? I see an error related with account_invoice before the Select Statement, is it related with the issue?

I am sure the statement is bad, it takes a lot of time, I did some research with Explain and found out this. enter image description here

This is the first time I had experienced this issue and it seems to consume lot of cpu (cpu load is more than 10). I currently restart the postgresql server to get things back to working and it is really not the solution I want to implement in future. Any suggestion is much appreciated.

[2017-05-31 13:32:26 ICT] app=x db=y user=z command=SELECTSTATEMENT:  SELECT province.name,district.name,subdistrict.name,district.icc_ship_area_code^M
    FROM province,district,subdistrict,account_invoice,contact^M
    WHERE province.id = province_id^M
    AND district.id = subdistrict.district_id^M


database=# EXPLAIN SELECT 

province.name,district.name,subdistrict.name,district.icc_ship_area_code FROM province,district,subdistrict,account_invoice,contact WHERE provi
nce.id = province_id AND district.id = subdistrict.district_id;                                                                                                                                                                QUERY PLAN
----------------------------------------------------------------------------------------------------
 Hash Join  (cost=7771211730.77..272930003461.72 rows=23422097264624 width=74)
   Hash Cond: (district.province_id = province.id)
   ->  Hash Join  (cost=35.61..301.98 rows=7426 width=55)
         Hash Cond: (subdistrict.district_id = district.id)
         ->  Seq Scan on subdistrict  (cost=0.00..164.26 rows=7426 width=27)
         ->  Hash  (cost=23.05..23.05 rows=1005 width=36)
               ->  Seq Scan on district  (cost=0.00..23.05 rows=1005 width=36)
   ->  Hash  (cost=3075225689.05..3075225689.05 rows=242863114648 width=27)
         ->  Nested Loop  (cost=0.00..3075225689.05 rows=242863114648 width=27)
               ->  Nested Loop  (cost=0.00..39436753.99 rows=3154066424 width=0)
                     ->  Seq Scan on contact  (cost=0.00..3646.99 rows=78899 width=0)
                     ->  Materialize  (cost=0.00..7376.64 rows=39976 width=0)
                           ->  Seq Scan on account_invoice  (cost=0.00..7176.76 rows=39976 width=0)
               ->  Materialize  (cost=0.00..2.16 rows=77 width=27)
                     ->  Seq Scan on province  (cost=0.00..1.77 rows=77 width=27)
(15 rows)
  • 2
    Could you please post text instead of images ? I can't read them... – Arkhena May 31 '17 at 7:30
8

Your log file is created with the 'Windows End-of-Line' way. When you check it with Vi or Vim then the ^M (= CR = Carridge Return) is show because it is not part of the 'Linux End-of-Line' way. You can ignore it.

  • 3
    And the query is slow probably because you have joined 5 tables: FROM province, district, subdistrict, account_invoice, contact, with only 2 joining conditions. That creates a cross join and lots of rows returned. – ypercubeᵀᴹ May 31 '17 at 8:17
  • 2
    More specifically, the query contains Windows line endings (CR+LF), and the surrounding log file has Unix line endings (just LF). Vim (if it is indeed Vim) highlights the extra CR characters because they're not consistent with the mode it opened the file in; if you opened a file with all Windows line endings, it would just read it in that mode. – IMSoP May 31 '17 at 9:06

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service, privacy policy and cookie policy

Not the answer you're looking for? Browse other questions tagged or ask your own question.