search

dalibo / pev2

Postgres Explain Visualizer 2
https://explain.dalibo.com
PostgreSQL License
2.56k stars 124 forks source link

`*Actual Duration` calculation issue causing most nodes shown as "Never executed" #23

Closed PikachuEXE closed 5 years ago

PikachuEXE commented 5 years ago

I have a query and most of them are shown as "Never executed" and it seems incorrect

It seems due to issue in *Actual Duration calculation: image

Yup same screenshot as #22 image

SQL Plan

[
  {
    "Plan": {
      "Node Type": "Limit",
      "Parallel Aware": false,
      "Startup Cost": 21.54,
      "Total Cost": 25.72,
      "Plan Rows": 20,
      "Plan Width": 813,
      "Actual Startup Time": 3.170,
      "Actual Total Time": 3.779,
      "Actual Rows": 20,
      "Actual Loops": 1,
      "Output": ["listings.id", "listings.block", "listings.flat", "listings.gross_area", "listings.net_area", "listings.price", "listings.description", "listings.about", "listings.bedrooms_count", "listings.bathrooms_count", "listings.contact_name", "listings.contact_phone", "listings.contact_email", "listings.source_url", "listings.is_rental", "listings.is_listed_by_agent", "listings.building_id", "listings.created_at", "listings.updated_at", "listings.agency_id", "listings.max_sale_price", "listings.min_sale_price", "listings.avg_sale_price", "listings.max_rental_price", "listings.min_rental_price", "listings.avg_rental_price", "listings.max_annual_percentage_yield", "listings.min_annual_percentage_yield", "listings.avg_annual_percentage_yield", "listings.last_calculate_estimate_at", "listings.floor", "listings.avg_price_to_estimate_diff_percentage", "listings.has_feature_car_park", "listings.has_feature_balcony", "listings.has_feature_sea_view", "listings.has_feature_roof", "listings.has_feature_club_house", "listings.has_feature_gym", "listings.has_feature_pool", "listings.has_feature_tennis", "listings.scraping_source_name", "listings.expired_at", "listings.remote_reference_id", "listings.updated_from_remote_source_at", "listings.property_images_count", "listings.click_contact_count", "listings.agent_license_number", "listings.send_contact_email_count", "listings.searching_expired_at", "listings.user_id", "listings.posted_at", "listings.serviced_apartment_provider_building_relationship_id", "listings.has_view_open", "listings.has_view_mountain", "listings.has_view_city", "listings.has_view_racecourse", "listings.has_view_sea", "listings.has_view_garden", "listings.has_view_building", "listings.has_feature_lift", "listings.has_feature_terrace", "listings.has_feature_maids_quarters", "listings.has_feature_garden", "listings.has_feature_pet_friendly", "listings.near_mtr", "listings.has_feature_duplex", "listings.short_rental", "listings.last_renovated", "listings.parking_count", "listings.furnished", "listings.property_agency_team_id", "listings.is_hdb", "listings.property_type", "listings.avg_rental_price_30_days_ago", "listings.avg_sale_price_30_days_ago", "listings.flat_share_allowed", "listings.confirmed_by_poster_at", "listings.source_white_label_real_estate_agency_id", "listings.quality_score", "listings.land_holding_area_size", "listings.marked_as_featured_at", "listings.average_price_per_area_size_unit", "listings.property_type_identifier", "listings.current_price_to_latest_estimated_price_diff_in_percentage", "listings.estimated_percentage_yield", "listings.is_type_commercial_shop", "listings.is_type_commercial_office", "listings.is_type_commercial_industrial", "listings.extra_attributes_json", "listings.price_max_to_min_diff_percentage", "listings.own_in_company_structure", "listings.occupy_by_tenant", "listings.spacious_business_center_entry_id", "listings.neighbourhood_id", "listings.count_of_tracking_event_with_view_page_type", "listings.self_updated_at", "listings.count_of_enquiries_for_trending_listing_notification", "listings.self_updated_at_after_posted_at_in_seconds", "listings.bedroom_count_updated_at", "listings.net_area_size_updated_at", "listings.price_significantly_updated_at", "listings.original_listing_id", "listings.duplication_state_updated_at", "listings.logical_posted_at", "listings.attrs_4_listing_related_digests_updated_at", "listings.city_id", "listings.building_type_identifier", "listings.paused_at", "listings.video_id", "listings.property_images_updated_at", "listings.poster_input_updated_at", "listings.building_built_year", "listings.price_in_hkd", "listings.latitude", "listings.longitude", "listings.has_feature_personal_garden", "listings.contact_phone_2", "listings.currency_alphabetic_code", "listings.whatsapp_contact_phone", "listings.lister_speaking_languages"],
      "Shared Hit Blocks": 128,
      "Shared Read Blocks": 0,
      "Shared Dirtied Blocks": 0,
      "Shared Written Blocks": 0,
      "Local Hit Blocks": 0,
      "Local Read Blocks": 0,
      "Local Dirtied Blocks": 0,
      "Local Written Blocks": 0,
      "Temp Read Blocks": 0,
      "Temp Written Blocks": 0,
      "I/O Read Time": 0.000,
      "I/O Write Time": 0.000,
      "Plans": [
        {
          "Node Type": "Index Scan",
          "Parent Relationship": "Outer",
          "Parallel Aware": false,
          "Scan Direction": "Forward",
          "Index Name": "idx_listings_on_s_expired_at_n_stuff_4_rental_201807121108",
          "Relation Name": "listings",
          "Schema": "public",
          "Alias": "listings",
          "Startup Cost": 0.63,
          "Total Cost": 2725.80,
          "Plan Rows": 13035,
          "Plan Width": 813,
          "Actual Startup Time": 0.221,
          "Actual Total Time": 3.765,
          "Actual Rows": 120,
          "Actual Loops": 1,
          "Output": ["listings.id", "listings.block", "listings.flat", "listings.gross_area", "listings.net_area", "listings.price", "listings.description", "listings.about", "listings.bedrooms_count", "listings.bathrooms_count", "listings.contact_name", "listings.contact_phone", "listings.contact_email", "listings.source_url", "listings.is_rental", "listings.is_listed_by_agent", "listings.building_id", "listings.created_at", "listings.updated_at", "listings.agency_id", "listings.max_sale_price", "listings.min_sale_price", "listings.avg_sale_price", "listings.max_rental_price", "listings.min_rental_price", "listings.avg_rental_price", "listings.max_annual_percentage_yield", "listings.min_annual_percentage_yield", "listings.avg_annual_percentage_yield", "listings.last_calculate_estimate_at", "listings.floor", "listings.avg_price_to_estimate_diff_percentage", "listings.has_feature_car_park", "listings.has_feature_balcony", "listings.has_feature_sea_view", "listings.has_feature_roof", "listings.has_feature_club_house", "listings.has_feature_gym", "listings.has_feature_pool", "listings.has_feature_tennis", "listings.scraping_source_name", "listings.expired_at", "listings.remote_reference_id", "listings.updated_from_remote_source_at", "listings.property_images_count", "listings.click_contact_count", "listings.agent_license_number", "listings.send_contact_email_count", "listings.searching_expired_at", "listings.user_id", "listings.posted_at", "listings.serviced_apartment_provider_building_relationship_id", "listings.has_view_open", "listings.has_view_mountain", "listings.has_view_city", "listings.has_view_racecourse", "listings.has_view_sea", "listings.has_view_garden", "listings.has_view_building", "listings.has_feature_lift", "listings.has_feature_terrace", "listings.has_feature_maids_quarters", "listings.has_feature_garden", "listings.has_feature_pet_friendly", "listings.near_mtr", "listings.has_feature_duplex", "listings.short_rental", "listings.last_renovated", "listings.parking_count", "listings.furnished", "listings.property_agency_team_id", "listings.is_hdb", "listings.property_type", "listings.avg_rental_price_30_days_ago", "listings.avg_sale_price_30_days_ago", "listings.flat_share_allowed", "listings.confirmed_by_poster_at", "listings.source_white_label_real_estate_agency_id", "listings.quality_score", "listings.land_holding_area_size", "listings.marked_as_featured_at", "listings.average_price_per_area_size_unit", "listings.property_type_identifier", "listings.current_price_to_latest_estimated_price_diff_in_percentage", "listings.estimated_percentage_yield", "listings.is_type_commercial_shop", "listings.is_type_commercial_office", "listings.is_type_commercial_industrial", "listings.extra_attributes_json", "listings.price_max_to_min_diff_percentage", "listings.own_in_company_structure", "listings.occupy_by_tenant", "listings.spacious_business_center_entry_id", "listings.neighbourhood_id", "listings.count_of_tracking_event_with_view_page_type", "listings.self_updated_at", "listings.count_of_enquiries_for_trending_listing_notification", "listings.self_updated_at_after_posted_at_in_seconds", "listings.bedroom_count_updated_at", "listings.net_area_size_updated_at", "listings.price_significantly_updated_at", "listings.original_listing_id", "listings.duplication_state_updated_at", "listings.logical_posted_at", "listings.attrs_4_listing_related_digests_updated_at", "listings.city_id", "listings.building_type_identifier", "listings.paused_at", "listings.video_id", "listings.property_images_updated_at", "listings.poster_input_updated_at", "listings.building_built_year", "listings.price_in_hkd", "listings.latitude", "listings.longitude", "listings.has_feature_personal_garden", "listings.contact_phone_2", "listings.currency_alphabetic_code", "listings.whatsapp_contact_phone", "listings.lister_speaking_languages"],
          "Index Cond": "((listings.searching_expired_at >= '2019-08-14 00:00:00'::timestamp without time zone) AND (listings.searching_expired_at <= '3019-08-14 00:00:00'::timestamp without time zone) AND (listings.posted_at IS NOT NULL))",
          "Rows Removed by Index Recheck": 0,
          "Filter": "(NOT (hashed SubPlan 1))",
          "Rows Removed by Filter": 0,
          "Shared Hit Blocks": 128,
          "Shared Read Blocks": 0,
          "Shared Dirtied Blocks": 0,
          "Shared Written Blocks": 0,
          "Local Hit Blocks": 0,
          "Local Read Blocks": 0,
          "Local Dirtied Blocks": 0,
          "Local Written Blocks": 0,
          "Temp Read Blocks": 0,
          "Temp Written Blocks": 0,
          "I/O Read Time": 0.000,
          "I/O Write Time": 0.000,
          "Plans": [
            {
              "Node Type": "Nested Loop",
              "Parent Relationship": "SubPlan",
              "Subplan Name": "SubPlan 1",
              "Parallel Aware": false,
              "Join Type": "Inner",
              "Startup Cost": 0.11,
              "Total Cost": 0.52,
              "Plan Rows": 1,
              "Plan Width": 4,
              "Actual Startup Time": 0.047,
              "Actual Total Time": 0.048,
              "Actual Rows": 0,
              "Actual Loops": 1,
              "Output": ["listing_characteristics.listing_id"],
              "Inner Unique": true,
              "Shared Hit Blocks": 2,
              "Shared Read Blocks": 0,
              "Shared Dirtied Blocks": 0,
              "Shared Written Blocks": 0,
              "Local Hit Blocks": 0,
              "Local Read Blocks": 0,
              "Local Dirtied Blocks": 0,
              "Local Written Blocks": 0,
              "Temp Read Blocks": 0,
              "Temp Written Blocks": 0,
              "I/O Read Time": 0.000,
              "I/O Write Time": 0.000,
              "Plans": [
                {
                  "Node Type": "Index Scan",
                  "Parent Relationship": "Outer",
                  "Parallel Aware": false,
                  "Scan Direction": "Forward",
                  "Index Name": "index_listing_characteristics_on_identifier",
                  "Relation Name": "listing_characteristics",
                  "Schema": "public",
                  "Alias": "listing_characteristics_1",
                  "Startup Cost": 0.06,
                  "Total Cost": 0.26,
                  "Plan Rows": 1,
                  "Plan Width": 4,
                  "Actual Startup Time": 0.047,
                  "Actual Total Time": 0.047,
                  "Actual Rows": 0,
                  "Actual Loops": 1,
                  "Output": ["listing_characteristics_1.id", "listing_characteristics_1.identifier", "listing_characteristics_1.boolean_value", "listing_characteristics_1.string_value", "listing_characteristics_1.time_value", "listing_characteristics_1.integer_value", "listing_characteristics_1.listing_id", "listing_characteristics_1.created_at", "listing_characteristics_1.updated_at"],
                  "Index Cond": "(listing_characteristics_1.identifier = 'spacious_client__weave_coliving__2019_08_price_test__price_version'::text)",
                  "Rows Removed by Index Recheck": 0,
                  "Filter": "(listing_characteristics_1.string_value = 'lower_price'::text)",
                  "Rows Removed by Filter": 0,
                  "Shared Hit Blocks": 2,
                  "Shared Read Blocks": 0,
                  "Shared Dirtied Blocks": 0,
                  "Shared Written Blocks": 0,
                  "Local Hit Blocks": 0,
                  "Local Read Blocks": 0,
                  "Local Dirtied Blocks": 0,
                  "Local Written Blocks": 0,
                  "Temp Read Blocks": 0,
                  "Temp Written Blocks": 0,
                  "I/O Read Time": 0.000,
                  "I/O Write Time": 0.000
                },
                {
                  "Node Type": "Index Scan",
                  "Parent Relationship": "Inner",
                  "Parallel Aware": false,
                  "Scan Direction": "Forward",
                  "Index Name": "listing_characteristics_pkey",
                  "Relation Name": "listing_characteristics",
                  "Schema": "public",
                  "Alias": "listing_characteristics",
                  "Startup Cost": 0.06,
                  "Total Cost": 0.26,
                  "Plan Rows": 1,
                  "Plan Width": 8,
                  "Actual Startup Time": 0.000,
                  "Actual Total Time": 0.000,
                  "Actual Rows": 0,
                  "Actual Loops": 0,
                  "Output": ["listing_characteristics.id", "listing_characteristics.identifier", "listing_characteristics.boolean_value", "listing_characteristics.string_value", "listing_characteristics.time_value", "listing_characteristics.integer_value", "listing_characteristics.listing_id", "listing_characteristics.created_at", "listing_characteristics.updated_at"],
                  "Index Cond": "(listing_characteristics.id = listing_characteristics_1.id)",
                  "Rows Removed by Index Recheck": 0,
                  "Shared Hit Blocks": 0,
                  "Shared Read Blocks": 0,
                  "Shared Dirtied Blocks": 0,
                  "Shared Written Blocks": 0,
                  "Local Hit Blocks": 0,
                  "Local Read Blocks": 0,
                  "Local Dirtied Blocks": 0,
                  "Local Written Blocks": 0,
                  "Temp Read Blocks": 0,
                  "Temp Written Blocks": 0,
                  "I/O Read Time": 0.000,
                  "I/O Write Time": 0.000
                }
              ]
            }
          ]
        }
      ]
    },
    "Planning Time": 12.613,
    "Triggers": [
    ],
    "Execution Time": 3.892
  }
]
gleu commented 5 years ago

Yeah, the index scan on index_listing_characteristics_on_identifier fetches 0 row, so there's no point in doing the other index scan (on listing_characteristics_pkey). So I guess pev2 shouldn't display the "actual" duration.

pgiraud commented 5 years ago

Thanks for the report. It's now fixed and deployed.