[postgis-tickets] [PostGIS] #2985: server crash when analyzing table with 1 row

PostGIS trac at osgeo.org
Tue Sep 13 13:44:49 PDT 2016 

#2985: server crash when analyzing table with 1 row
-----------------------+------------------------------------------
  Reporter:  nkiraly   |      Owner:  pramsey
      Type:  defect    |     Status:  reopened
  Priority:  critical  |  Milestone:  PostGIS 2.2.3
 Component:  postgis   |    Version:  2.1.x
Resolution:            |   Keywords:  analyze server crash freebsd
-----------------------+------------------------------------------

Comment (by ofca):

 OK, after trying million different things, this is what I came up with.

 Good analyze run:
 {{{
  DEBUG: StartTransactionCommand
  DEBUG: StartTransaction
  DEBUG: name: unnamed; blockState: DEFAULT; state: INPROGR, xid/subid/cid:
 0/1/0, nestlvl: 1, children:
  DEBUG: ProcessUtility
  DEBUG: CommitTransaction
  DEBUG: name: unnamed; blockState: STARTED; state: INPROGR, xid/subid/cid:
 0/1/0, nestlvl: 1, children:
  DEBUG: StartTransaction
  DEBUG: name: unnamed; blockState: DEFAULT; state: INPROGR, xid/subid/cid:
 0/1/0, nestlvl: 1, children:
  DEBUG: building index "pg_toast_909285_index" on table "pg_toast_909285"
  INFO: vacuuming "public.test"
  INFO: "test": found 1 removable, 1 nonremovable row versions in 1 pages
  DETAIL: 0 dead row versions cannot be removed yet.
  CPU 0.00s/0.00u sec elapsed 0.00 sec.
  DEBUG: drop auto-cascades to type pg_temp_623595
  DEBUG: drop auto-cascades to type pg_temp_623595[]
  DEBUG: drop auto-cascades to toast table pg_toast.pg_toast_909285
  DEBUG: drop auto-cascades to index pg_toast.pg_toast_909285_index
  DEBUG: drop auto-cascades to type pg_toast.pg_toast_909285
  DEBUG: CommitTransaction
  DEBUG: name: unnamed; blockState: STARTED; state: INPROGR, xid/subid/cid:
 13757591/1/12, nestlvl: 1, children:
  DEBUG: StartTransaction
  DEBUG: name: unnamed; blockState: DEFAULT; state: INPROGR, xid/subid/cid:
 0/1/0, nestlvl: 1, children:
  INFO: analyzing "public.test"
  DEBUG: [gserialized_estimate.c:gserialized_analyze_nd:1770]
 gserialized_analyze_nd called
  DEBUG: [gserialized_estimate.c:gserialized_analyze_nd:1777] attribute
 stat target: 100
  DEBUG: [gserialized_estimate.c:gserialized_analyze_nd:1783] minrows:
 30000
  INFO: "test": scanned 1 of 1 pages, containing 1 live rows and 0 dead
 rows; 1 rows in sample, 1 estimated total rows
  DEBUG: [gserialized_estimate.c:compute_gserialized_stats_mode:1282]
 compute_gserialized_stats called
  DEBUG: [gserialized_estimate.c:compute_gserialized_stats_mode:1283] #
 sample_rows: 1
  DEBUG: [gserialized_estimate.c:compute_gserialized_stats_mode:1284]
 estimate of total_rows: 1
  DEBUG: [gserialized_estimate.c:nd_box_from_gbox:511]
 GBOX((20.900011,52.199986),(20.915567,52.208111))
  DEBUG: [gserialized_estimate.c:compute_gserialized_stats_mode:1395]
 stats->attr->attstattarget: 100
  DEBUG: [gserialized_estimate.c:compute_gserialized_stats_mode:1396]
 target # of histogram cells: 0
  DEBUG: [gserialized_estimate.c:compute_gserialized_stats_mode:1406]
 sample_extent: {"min":[20.9,52.2],"max":[20.9156,52.2081]}
  DEBUG: [gserialized_estimate.c:nd_box_array_distribution:745] dimension
 0, feature 0: bin 0 to bin 49
  DEBUG: [gserialized_estimate.c:nd_box_array_distribution:763] dimension
 0: range = 0
  DEBUG: [gserialized_estimate.c:nd_box_array_distribution:764] dimension
 0: average = 1
  DEBUG: [gserialized_estimate.c:nd_box_array_distribution:765] dimension
 0: stddev = 0
  DEBUG: [gserialized_estimate.c:nd_box_array_distribution:766] dimension
 0: stddev_ratio = 0
  DEBUG: [gserialized_estimate.c:nd_box_array_distribution:745] dimension
 1, feature 0: bin 0 to bin 49
  DEBUG: [gserialized_estimate.c:nd_box_array_distribution:763] dimension
 1: range = 0
  DEBUG: [gserialized_estimate.c:nd_box_array_distribution:764] dimension
 1: average = 1
  DEBUG: [gserialized_estimate.c:nd_box_array_distribution:765] dimension
 1: stddev = 0
  DEBUG: [gserialized_estimate.c:nd_box_array_distribution:766] dimension
 1: stddev_ratio = 0
  DEBUG: [gserialized_estimate.c:compute_gserialized_stats_mode:1498]
 special case: no axes have variability
  DEBUG: [gserialized_estimate.c:compute_gserialized_stats_mode:1503]
 histo_size[d]: 0
  DEBUG: [gserialized_estimate.c:compute_gserialized_stats_mode:1503]
 histo_size[d]: 0
  DEBUG: [gserialized_estimate.c:compute_gserialized_stats_mode:1506]
 histo_cells_new: 0
  DEBUG: [gserialized_estimate.c:compute_gserialized_stats_mode:1546]
 histo_cells: 0
  DEBUG: [gserialized_estimate.c:nd_box_overlap:599] nd_box:
 {"min":[20.9,52.2],"max":[20.9156,52.2081]}
  DEBUG: [gserialized_estimate.c:compute_gserialized_stats_mode:1604]
 feature 0: ibox (0, 0, 0, 0) (-1, -1, 0, 0)
  DEBUG: [gserialized_estimate.c:nd_stats_value_index:357] bad index at (0,
 0)
  DEBUG: [gserialized_estimate.c:compute_gserialized_stats_mode:1644] ratio
 (1) num_cells (1)
  DEBUG: [gserialized_estimate.c:compute_gserialized_stats_mode:1645] at
 (0, 0, 0, 0)
  DEBUG: [gserialized_estimate.c:compute_gserialized_stats_mode:1655]
 histogram_features: 1
  DEBUG: [gserialized_estimate.c:compute_gserialized_stats_mode:1656]
 sample_rows: 1
  DEBUG: [gserialized_estimate.c:compute_gserialized_stats_mode:1657]
 table_rows: 1
  DEBUG: [gserialized_estimate.c:compute_gserialized_stats_mode:1694] out:
 slot 0: kind 0 (STATISTIC_KIND_ND)
  DEBUG: [gserialized_estimate.c:compute_gserialized_stats_mode:1695] out:
 slot 0: op 0 (InvalidOid)
  DEBUG: [gserialized_estimate.c:compute_gserialized_stats_mode:1696] out:
 slot 0: numnumbers 0
  DEBUG: [gserialized_estimate.c:compute_gserialized_stats_mode:1697] out:
 null fraction: 0.000000=0/1
  DEBUG: [gserialized_estimate.c:compute_gserialized_stats_mode:1698] out:
 average width: 944 bytes
  DEBUG: [gserialized_estimate.c:compute_gserialized_stats_mode:1699] out:
 distinct values: all (no check done)
  DEBUG: [gserialized_estimate.c:compute_gserialized_stats_mode:1700] out:
 {"ndims":2,"size":[0,0],"extent":{"min":[20.8999,52.1999],"max":[20.9156,52.2082]},"table_features":1,"sample_features":1,"not_null_features":1,"histogram_features":1,"histogram_cells":0,"cells_covered":1}
  DEBUG: [gserialized_estimate.c:compute_gserialized_stats_mode:1282]
 compute_gserialized_stats called
  DEBUG: [gserialized_estimate.c:compute_gserialized_stats_mode:1283] #
 sample_rows: 1
  DEBUG: [gserialized_estimate.c:compute_gserialized_stats_mode:1284]
 estimate of total_rows: 1
  DEBUG: [gserialized_estimate.c:nd_box_from_gbox:511]
 GBOX((20.900011,52.199986),(20.915567,52.208111))
  DEBUG: [gserialized_estimate.c:compute_gserialized_stats_mode:1395]
 stats->attr->attstattarget: 100
  DEBUG: [gserialized_estimate.c:compute_gserialized_stats_mode:1396]
 target # of histogram cells: 0
  DEBUG: [gserialized_estimate.c:compute_gserialized_stats_mode:1406]
 sample_extent: {"min":[20.9,52.2],"max":[20.9156,52.2081]}
  DEBUG: [gserialized_estimate.c:nd_box_array_distribution:745] dimension
 0, feature 0: bin 0 to bin 49
  DEBUG: [gserialized_estimate.c:nd_box_array_distribution:763] dimension
 0: range = 0
  DEBUG: [gserialized_estimate.c:nd_box_array_distribution:764] dimension
 0: average = 1
  DEBUG: [gserialized_estimate.c:nd_box_array_distribution:765] dimension
 0: stddev = 0
  DEBUG: [gserialized_estimate.c:nd_box_array_distribution:766] dimension
 0: stddev_ratio = 0
  DEBUG: [gserialized_estimate.c:nd_box_array_distribution:745] dimension
 1, feature 0: bin 0 to bin 49
  DEBUG: [gserialized_estimate.c:nd_box_array_distribution:763] dimension
 1: range = 0
  DEBUG: [gserialized_estimate.c:nd_box_array_distribution:764] dimension
 1: average = 1
  DEBUG: [gserialized_estimate.c:nd_box_array_distribution:765] dimension
 1: stddev = 0
  DEBUG: [gserialized_estimate.c:nd_box_array_distribution:766] dimension
 1: stddev_ratio = 0
  DEBUG: [gserialized_estimate.c:compute_gserialized_stats_mode:1498]
 special case: no axes have variability
  DEBUG: [gserialized_estimate.c:compute_gserialized_stats_mode:1503]
 histo_size[d]: 0
  DEBUG: [gserialized_estimate.c:compute_gserialized_stats_mode:1503]
 histo_size[d]: 0
  DEBUG: [gserialized_estimate.c:compute_gserialized_stats_mode:1506]
 histo_cells_new: 0
  DEBUG: [gserialized_estimate.c:compute_gserialized_stats_mode:1546]
 histo_cells: 0
  DEBUG: [gserialized_estimate.c:nd_box_overlap:599] nd_box:
 {"min":[20.9,52.2],"max":[20.9156,52.2081]}
  DEBUG: [gserialized_estimate.c:compute_gserialized_stats_mode:1604]
 feature 0: ibox (0, 0, 0, 0) (-1, -1, 0, 0)
  DEBUG: [gserialized_estimate.c:nd_stats_value_index:357] bad index at (0,
 0)
  DEBUG: [gserialized_estimate.c:compute_gserialized_stats_mode:1644] ratio
 (1) num_cells (1)
  DEBUG: [gserialized_estimate.c:compute_gserialized_stats_mode:1645] at
 (0, 0, 0, 0)
  DEBUG: [gserialized_estimate.c:compute_gserialized_stats_mode:1655]
 histogram_features: 1
  DEBUG: [gserialized_estimate.c:compute_gserialized_stats_mode:1656]
 sample_rows: 1
  DEBUG: [gserialized_estimate.c:compute_gserialized_stats_mode:1657]
 table_rows: 1
  DEBUG: [gserialized_estimate.c:compute_gserialized_stats_mode:1694] out:
 slot 0: kind 102 (STATISTIC_KIND_ND)
  DEBUG: [gserialized_estimate.c:compute_gserialized_stats_mode:1695] out:
 slot 0: op 0 (InvalidOid)
  DEBUG: [gserialized_estimate.c:compute_gserialized_stats_mode:1696] out:
 slot 0: numnumbers 19
  DEBUG: [gserialized_estimate.c:compute_gserialized_stats_mode:1697] out:
 null fraction: 0.000000=0/1
  DEBUG: [gserialized_estimate.c:compute_gserialized_stats_mode:1698] out:
 average width: 944 bytes
  DEBUG: [gserialized_estimate.c:compute_gserialized_stats_mode:1699] out:
 distinct values: all (no check done)
  DEBUG: [gserialized_estimate.c:compute_gserialized_stats_mode:1700] out:
 {"ndims":2,"size":[0,0],"extent":{"min":[20.8999,52.1999],"max":[20.9156,52.2082]},"table_features":1,"sample_features":1,"not_null_features":1,"histogram_features":1,"histogram_cells":0,"cells_covered":1}
  DEBUG: CommitTransaction
  DEBUG: name: unnamed; blockState: STARTED; state: INPROGR, xid/subid/cid:
 13757592/1/0 (used), nestlvl: 1, children:
  DEBUG: StartTransaction
  DEBUG: name: unnamed; blockState: DEFAULT; state: INPROGR, xid/subid/cid:
 0/1/0, nestlvl: 1, children:
  DEBUG: CommitTransactionCommand
  DEBUG: CommitTransaction
  DEBUG: name: unnamed; blockState: STARTED; state: INPROGR, xid/subid/cid:
 0/1/0, nestlvl: 1, children:
 }}}

 Fail analyze run:
 {{{
  DEBUG: StartTransactionCommand
  DEBUG: StartTransaction
  DEBUG: name: unnamed; blockState: DEFAULT; state: INPROGR, xid/subid/cid:
 0/1/0, nestlvl: 1, children:
  DEBUG: ProcessUtility
  DEBUG: CommitTransaction
  DEBUG: name: unnamed; blockState: STARTED; state: INPROGR, xid/subid/cid:
 0/1/0, nestlvl: 1, children:
  DEBUG: StartTransaction
  DEBUG: name: unnamed; blockState: DEFAULT; state: INPROGR, xid/subid/cid:
 0/1/0, nestlvl: 1, children:
  DEBUG: building index "pg_toast_901093_index" on table "pg_toast_901093"
  INFO: vacuuming "public.test"
  INFO: "test": found 0 removable, 1 nonremovable row versions in 1 pages
  DETAIL: 0 dead row versions cannot be removed yet.
  CPU 0.00s/0.00u sec elapsed 0.00 sec.
  DEBUG: drop auto-cascades to type pg_temp_623595
  DEBUG: drop auto-cascades to type pg_temp_623595[]
  DEBUG: drop auto-cascades to toast table pg_toast.pg_toast_901093
  DEBUG: drop auto-cascades to index pg_toast.pg_toast_901093_index
  DEBUG: drop auto-cascades to type pg_toast.pg_toast_901093
  DEBUG: CommitTransaction
  DEBUG: name: unnamed; blockState: STARTED; state: INPROGR, xid/subid/cid:
 13757589/1/12, nestlvl: 1, children:
  DEBUG: StartTransaction
  DEBUG: name: unnamed; blockState: DEFAULT; state: INPROGR, xid/subid/cid:
 0/1/0, nestlvl: 1, children:
  INFO: analyzing "public.test"
  DEBUG: [gserialized_estimate.c:gserialized_analyze_nd:1770]
 gserialized_analyze_nd called
  DEBUG: [gserialized_estimate.c:gserialized_analyze_nd:1777] attribute
 stat target: 100
  DEBUG: [gserialized_estimate.c:gserialized_analyze_nd:1783] minrows:
 30000
  INFO: "test": scanned 1 of 1 pages, containing 1 live rows and 0 dead
 rows; 1 rows in sample, 1 estimated total rows
  DEBUG: [gserialized_estimate.c:compute_gserialized_stats_mode:1282]
 compute_gserialized_stats called
  DEBUG: [gserialized_estimate.c:compute_gserialized_stats_mode:1283] #
 sample_rows: 1
  DEBUG: [gserialized_estimate.c:compute_gserialized_stats_mode:1284]
 estimate of total_rows: 1
  DEBUG: [g_serialized.c:gserialized_get_type:60] entered
  DEBUG: [g_serialized.c:gserialized_get_type:60] entered
  DEBUG: [g_serialized.c:lwgeom_from_gserialized:1265] Got type 2
 (LineString), srid=4326
  DEBUG: [g_serialized.c:lwgeom_from_gserialized_buffer:1219] Got type 2
 (LineString), hasz=0 hasm=0 geodetic=0 hasbox=0
  DEBUG: [lwgeom.c:lwgeom_count_vertices:1148] lwgeom_count_vertices got
 type LineString
  DEBUG: [lwgeom.c:lwgeom_is_empty:1301] lwgeom_is_empty: got type
 LineString
  DEBUG: [lwgeom.c:lwgeom_count_vertices:1183] counted 1 vertices
  DEBUG: [lwgeom.c:lwgeom_set_srid:1543] entered with srid=4326
  DEBUG: [g_box.c:lwgeom_calculate_gbox_cartesian:651]
 lwgeom_calculate_gbox got type (2) - LineString
  DEBUG: [g_box.c:ptarray_calculate_gbox_cartesian:525]
 ptarray_calculate_gbox Z: 0 M: 0
  DEBUG: [lwgeom_api.c:getPoint4d_p:245] getPoint4d_p called.
  DEBUG: [lwgeom_api.c:getPoint4d_p:251] ptr 0x8032ae058, zmflag 0
  DEBUG: [gserialized_estimate.c:nd_box_from_gbox:511]
 GBOX((20.951166,52.398453),(20.951168,52.398457))
  DEBUG: [gserialized_estimate.c:compute_gserialized_stats_mode:1395]
 stats->attr->attstattarget: 100
  DEBUG: [gserialized_estimate.c:compute_gserialized_stats_mode:1396]
 target # of histogram cells: 0
  DEBUG: [gserialized_estimate.c:compute_gserialized_stats_mode:1406]
 sample_extent: {"min":[20.9512,52.3985],"max":[20.9512,52.3985]}
  DEBUG: [gserialized_estimate.c:nd_box_array_distribution:745] dimension
 0, feature 0: bin 0 to bin 50
  DEBUG: [gserialized_estimate.c:nd_box_array_distribution:763] dimension
 0: range = 0
  DEBUG: [gserialized_estimate.c:nd_box_array_distribution:764] dimension
 0: average = 1
  DEBUG: [gserialized_estimate.c:nd_box_array_distribution:765] dimension
 0: stddev = 0
  DEBUG: [gserialized_estimate.c:nd_box_array_distribution:766] dimension
 0: stddev_ratio = 0
  DEBUG: [gserialized_estimate.c:nd_box_array_distribution:745] dimension
 1, feature 0: bin 0 to bin 50
  DEBUG: [gserialized_estimate.c:nd_box_array_distribution:763] dimension
 1: range = 0
  DEBUG: [gserialized_estimate.c:nd_box_array_distribution:764] dimension
 1: average = 1
  DEBUG: [gserialized_estimate.c:nd_box_array_distribution:765] dimension
 1: stddev = 0
  DEBUG: [gserialized_estimate.c:nd_box_array_distribution:766] dimension
 1: stddev_ratio = 0
  DEBUG: [gserialized_estimate.c:compute_gserialized_stats_mode:1498]
 special case: no axes have variability
  DEBUG: [gserialized_estimate.c:compute_gserialized_stats_mode:1503]
 histo_size[d]: 0
  DEBUG: [gserialized_estimate.c:compute_gserialized_stats_mode:1503]
 histo_size[d]: 0
  DEBUG: [gserialized_estimate.c:compute_gserialized_stats_mode:1506]
 histo_cells_new: 0
  DEBUG: [gserialized_estimate.c:compute_gserialized_stats_mode:1546]
 histo_cells: 0
  DEBUG: [gserialized_estimate.c:nd_box_overlap:599] nd_box:
 {"min":[20.9512,52.3985],"max":[20.9512,52.3985]}
  DEBUG: [gserialized_estimate.c:compute_gserialized_stats_mode:1604]
 feature 0: ibox (0, 0, 0, 0) (-1, -1, 0, 0)
  DEBUG: [gserialized_estimate.c:nd_stats_value_index:357] bad index at (0,
 0)
  DEBUG: [gserialized_estimate.c:compute_gserialized_stats_mode:1644] ratio
 (1) num_cells (1)
  DEBUG: [gserialized_estimate.c:compute_gserialized_stats_mode:1645] at
 (0, 0, 0, 0)
  DEBUG: [gserialized_estimate.c:compute_gserialized_stats_mode:1655]
 histogram_features: 1
  DEBUG: [gserialized_estimate.c:compute_gserialized_stats_mode:1656]
 sample_rows: 1
  DEBUG: [gserialized_estimate.c:compute_gserialized_stats_mode:1657]
 table_rows: 1
  DEBUG: [gserialized_estimate.c:compute_gserialized_stats_mode:1694] out:
 slot 0: kind 0 (STATISTIC_KIND_ND)
  DEBUG: [gserialized_estimate.c:compute_gserialized_stats_mode:1695] out:
 slot 0: op 0 (InvalidOid)
  DEBUG: [gserialized_estimate.c:compute_gserialized_stats_mode:1696] out:
 slot 0: numnumbers 0
  DEBUG: [gserialized_estimate.c:compute_gserialized_stats_mode:1697] out:
 null fraction: 0.000000=0/1
  DEBUG: [gserialized_estimate.c:compute_gserialized_stats_mode:1698] out:
 average width: 32 bytes
  DEBUG: [gserialized_estimate.c:compute_gserialized_stats_mode:1699] out:
 distinct values: all (no check done)
  DEBUG: [gserialized_estimate.c:compute_gserialized_stats_mode:1700] out:
 {"ndims":2,"size":[0,0],"extent":{"min":[20.9512,52.3985],"max":[20.9512,52.3985]},"table_features":1,"sample_features":1,"not_null_features":1,"histogram_features":1,"histogram_cells":0,"cells_covered":1}
  DEBUG: [gserialized_estimate.c:compute_gserialized_stats_mode:1282]
 compute_gserialized_stats called
  DEBUG: [gserialized_estimate.c:compute_gserialized_stats_mode:1283] #
 sample_rows: 1
  DEBUG: [gserialized_estimate.c:compute_gserialized_stats_mode:1284]
 estimate of total_rows: 1

  DEBUG: forked new backend, pid=37855 socket=12
  kernel: pid 37854 (postgres), uid 70: exited on signal 10 (core dumped)
 }}}

--
Ticket URL: <https://trac.osgeo.org/postgis/ticket/2985#comment:25>
PostGIS <http://trac.osgeo.org/postgis/>
The PostGIS Trac is used for bug, enhancement & task tracking, a user and developer wiki, and a view into the subversion code repository of PostGIS project.

More information about the postgis-tickets mailing list