Re: Out of Memory errors are frustrating as heck! - Mailing list pgsql-performance

From Gunther
Subject Re: Out of Memory errors are frustrating as heck!
Date
Msg-id 4d4ba149-5c52-684f-1185-1949693be5a7@gusw.net
Whole thread Raw
In response to Re: Out of Memory errors are frustrating as heck!  (Justin Pryzby <pryzby@telsasoft.com>)
Responses Re: Out of Memory errors are frustrating as heck!  (Tom Lane <tgl@sss.pgh.pa.us>)
Re: Out of Memory errors are frustrating as heck!  (Jeff Janes <jeff.janes@gmail.com>)
List pgsql-performance
Thanks Justin Pryzby too, and Jeff Janes, responding to both of you for efficiency. Answers and more logs and the gdb backtrace below.
The version is 10.2 latest.
v10.7 is available; could you upgrade ?
Sorry I meant 11.2 actually latest.
What are these set to ?  shared_buffers? work_mem?

shared_buffers=2G (of 8 total), then 1G, didn't help.

work_mem=4M by now (I had once been successful of avoiding out of memory by reducing work mem from 64M to 8M. But as Tom Lane says, it shouldn't be using more than 5 x work_mem in this query plan.

Jeff Janes said:

 I don't know why a 8GB system with a lot of cache that could be evicted would get an OOM when something using 1.5GB asks for 8272 bytes more.  But that is a question of how the kernel works, rather than how PostgreSQL works.  But I also think the log you quote above belongs to a different event than the vmstat trace in your first email.
and I agree, except that the vmstat log and the error really belong together, same timestamp. Nothing else running on that machine this Sunday. Yes I ran this several times with different parameters, so some mixup is possible, but always ending in the same crash anyway. So here again, without the vmstat log, which really wouldn't be any different than I showed you. (See below for the ENABLE_NESTLOOP=off setting, not having those settings same between explain and actual execution might account for the discrepancy that you saw.)
integrator=# SET ENABLE_NESTLOOP TO OFF;
SET
integrator=# \set VERBOSITY verbose
integrator=# explain INSERT INTO reports.BusinessOperation SELECT * FROM reports.v_BusinessOperation;
integrator=# \pset pager off
Pager usage is off.
integrator=# \pset format unaligned
Output format is unaligned.
integrator=# explain INSERT INTO reports.BusinessOperation SELECT * FROM reports.v_BusinessOperation;
QUERY PLAN
Insert on businessoperation  (cost=5850091.58..5853120.74 rows=34619 width=1197) ->  Unique  (cost=5850091.58..5852774.55 rows=34619 width=1197)       ->  Sort  (cost=5850091.58..5850178.13 rows=34619 width=1197)             Sort Key: documentinformationsubject.documentinternalid, documentinformationsubject.is_current, documentinformationsubject.documentid, documentinformationsubject.documenttypecode, documentinformationsubject.subjectroleinternalid, documentinformationsubject.subjectentityinternalid, documentinformationsubject.subjectentityid, documentinformationsubject.subjectentityidroot, documentinformationsubject.subjectentityname, documentinformationsubject.subjectentitytel, documentinformationsubject.subjectentityemail, documentinformationsubject.otherentityinternalid, documentinformationsubject.confidentialitycode, documentinformationsubject.actinternalid, documentinformationsubject.code_code, documentinformationsubject.code_displayname, q.code_code, q.code_displayname, an.extension, an.root, documentinformationsubject_2.subjectentitycode, documentinformationsubject_2.subjectentitycodesystem, documentinformationsubject_2.effectivetime_low, documentinformationsubject_2.effectivetime_high, documentinformationsubject_2.statuscode, documentinformationsubject_2.code_code, agencyid.extension, agencyname.trivialname, documentinformationsubject_1.subjectentitycode, documentinformationsubject_1.subjectentityinternalid             ->  Hash Right Join  (cost=4489522.06..5829375.93 rows=34619 width=1197)                   Hash Cond: (((q.documentinternalid)::text = (documentinformationsubject.documentinternalid)::text) AND ((r.targetinternalid)::text = (documentinformationsubject.actinternalid)::text))                   ->  Hash Right Join  (cost=1473632.24..2808301.92 rows=13 width=341)                         Hash Cond: (((documentinformationsubject_2.documentinternalid)::text = (q.documentinternalid)::text) AND ((documentinformationsubject_2.actinternalid)::text = (q.actinternalid)::text))                         ->  Hash Left Join  (cost=38864.03..1373533.69 rows=1 width=219)                               Hash Cond: ((documentinformationsubject_2.otherentityinternalid)::text = (agencyname.entityinternalid)::text)                               ->  Hash Left Join  (cost=2503.10..1332874.75 rows=1 width=229)                                     Hash Cond: ((documentinformationsubject_2.otherentityinternalid)::text = (agencyid.entityinternalid)::text)                                     ->  Seq Scan on documentinformationsubject documentinformationsubject_2  (cost=0.00..1329868.64 rows=1 width=177)                                           Filter: ((participationtypecode)::text = 'AUT'::text)                                     ->  Hash  (cost=1574.82..1574.82 rows=34182 width=89)                                           ->  Seq Scan on entity_id agencyid  (cost=0.00..1574.82 rows=34182 width=89)                               ->  Hash  (cost=27066.08..27066.08 rows=399908 width=64)                                     ->  Seq Scan on bestname agencyname  (cost=0.00..27066.08 rows=399908 width=64)                         ->  Hash  (cost=1434768.02..1434768.02 rows=13 width=233)                               ->  Hash Right Join  (cost=953906.58..1434768.02 rows=13 width=233)                                     Hash Cond: ((an.actinternalid)::text = (q.actinternalid)::text)                                     ->  Seq Scan on act_id an  (cost=0.00..425941.04 rows=14645404 width=134)                                     ->  Hash  (cost=953906.57..953906.57 rows=1 width=136)                                           ->  Hash Join  (cost=456015.28..953906.57 rows=1 width=136)                                                 Hash Cond: ((q.actinternalid)::text = (r.sourceinternalid)::text)                                                 ->  Seq Scan on documentinformation q  (cost=0.00..497440.84 rows=120119 width=99)                                                       Filter: (((classcode)::text = 'CNTRCT'::text) AND ((moodcode)::text = 'EVN'::text) AND ((code_codesystem)::text = '2.16.840.1.113883.3.26.1.1'::text))                                                 ->  Hash  (cost=456015.26..456015.26 rows=1 width=74)                                                       ->  Seq Scan on actrelationship r  (cost=0.00..456015.26 rows=1 width=74)                                                             Filter: ((typecode)::text = 'SUBJ'::text)                   ->  Hash  (cost=3011313.54..3011313.54 rows=34619 width=930)                         ->  Merge Left Join  (cost=2998334.98..3011313.54 rows=34619 width=930)                               Merge Cond: (((documentinformationsubject.documentinternalid)::text = (documentinformationsubject_1.documentinternalid)::text) AND ((documentinformationsubject.documentid)::text = (documentinformationsubject_1.documentid)::text) AND ((documentinformationsubject.actinternalid)::text = (documentinformationsubject_1.actinternalid)::text))                               ->  Sort  (cost=1408783.87..1408870.41 rows=34619 width=882)                                     Sort Key: documentinformationsubject.documentinternalid, documentinformationsubject.documentid, documentinformationsubject.actinternalid                                     ->  Seq Scan on documentinformationsubject  (cost=0.00..1392681.22 rows=34619 width=882)                                           Filter: (((participationtypecode)::text = ANY ('{PPRF,PRF}'::text[])) AND ((classcode)::text = 'ACT'::text) AND ((moodcode)::text = 'DEF'::text) AND ((code_codesystem)::text = '2.16.840.1.113883.3.26.1.1'::text))                               ->  Materialize  (cost=1589551.12..1594604.04 rows=1010585 width=159)                                     ->  Sort  (cost=1589551.12..1592077.58 rows=1010585 width=159)                                           Sort Key: documentinformationsubject_1.documentinternalid, documentinformationsubject_1.documentid, documentinformationsubject_1.actinternalid                                           ->  Seq Scan on documentinformationsubject documentinformationsubject_1  (cost=0.00..1329868.64 rows=1010585 width=159)                                                 Filter: ((participationtypecode)::text = 'PRD'::text)

and the error memory status dump (I hope my grey boxes help a bit to lighten this massive amount of data...

TopMemoryContext: 4294552 total in 7 blocks; 42952 free (15 chunks); 4251600 used TableSpace cache: 8192 total in 1 blocks; 2096 free (0 chunks); 6096 used Type information cache: 24352 total in 2 blocks; 2624 free (0 chunks); 21728 used pgstat TabStatusArray lookup hash table: 8192 total in 1 blocks; 416 free (0 chunks); 7776 used TopTransactionContext: 8192 total in 1 blocks; 7720 free (2 chunks); 472 used RowDescriptionContext: 8192 total in 1 blocks; 6896 free (0 chunks); 1296 used MessageContext: 2097152 total in 9 blocks; 396480 free (10 chunks); 1700672 used Operator class cache: 8192 total in 1 blocks; 560 free (0 chunks); 7632 used smgr relation table: 32768 total in 3 blocks; 16832 free (8 chunks); 15936 used TransactionAbortContext: 32768 total in 1 blocks; 32512 free (0 chunks); 256 used Portal hash: 8192 total in 1 blocks; 560 free (0 chunks); 7632 used TopPortalContext: 8192 total in 1 blocks; 7664 free (0 chunks); 528 used   PortalContext: 1024 total in 1 blocks; 624 free (0 chunks); 400 used:     ExecutorState: 2234123384 total in 266261 blocks; 3782328 free (17244 chunks); 2230341056 used       HashTableContext: 8192 total in 1 blocks; 7752 free (0 chunks); 440 used         HashBatchContext: 57432 total in 3 blocks; 16072 free (6 chunks); 41360 used       HashTableContext: 8192 total in 1 blocks; 7752 free (0 chunks); 440 used         HashBatchContext: 90288 total in 4 blocks; 16072 free (6 chunks); 74216 used       HashTableContext: 8192 total in 1 blocks; 7624 free (0 chunks); 568 used         HashBatchContext: 90288 total in 4 blocks; 16072 free (6 chunks); 74216 used       TupleSort main: 286912 total in 8 blocks; 246792 free (39 chunks); 40120 used       TupleSort main: 286912 total in 8 blocks; 246792 free (39 chunks); 40120 used       HashTableContext: 8454256 total in 6 blocks; 64848 free (32 chunks); 8389408 used         HashBatchContext: 100711712 total in 3065 blocks; 7936 free (0 chunks); 100703776 used       TupleSort main: 452880 total in 8 blocks; 126248 free (27 chunks); 326632 used         Caller tuples: 1048576 total in 8 blocks; 21608 free (14 chunks); 1026968 used       ExprContext: 8192 total in 1 blocks; 7936 free (0 chunks); 256 used       ExprContext: 8192 total in 1 blocks; 7936 free (0 chunks); 256 used       ExprContext: 8192 total in 1 blocks; 7936 free (0 chunks); 256 used       ExprContext: 8192 total in 1 blocks; 7936 free (0 chunks); 256 used       ExprContext: 8192 total in 1 blocks; 7936 free (0 chunks); 256 used       ExprContext: 8192 total in 1 blocks; 7936 free (0 chunks); 256 used       ExprContext: 8192 total in 1 blocks; 7936 free (0 chunks); 256 used       ExprContext: 8192 total in 1 blocks; 7936 free (0 chunks); 256 used       ExprContext: 8192 total in 1 blocks; 7936 free (0 chunks); 256 used       ExprContext: 8192 total in 1 blocks; 7936 free (0 chunks); 256 used       ExprContext: 8192 total in 1 blocks; 7936 free (0 chunks); 256 used       ExprContext: 8192 total in 1 blocks; 7936 free (0 chunks); 256 used       ExprContext: 8192 total in 1 blocks; 7936 free (0 chunks); 256 used       ExprContext: 8192 total in 1 blocks; 7936 free (0 chunks); 256 used       ExprContext: 8192 total in 1 blocks; 7936 free (0 chunks); 256 used       ExprContext: 8192 total in 1 blocks; 7936 free (0 chunks); 256 used       ExprContext: 8192 total in 1 blocks; 7936 free (0 chunks); 256 used       ExprContext: 8192 total in 1 blocks; 7936 free (0 chunks); 256 used       ExprContext: 8192 total in 1 blocks; 7936 free (0 chunks); 256 used       ExprContext: 8192 total in 1 blocks; 7936 free (0 chunks); 256 used       ExprContext: 8192 total in 1 blocks; 7936 free (0 chunks); 256 used       ExprContext: 8192 total in 1 blocks; 7936 free (0 chunks); 256 used       ExprContext: 8192 total in 1 blocks; 7936 free (0 chunks); 256 used       ExprContext: 8192 total in 1 blocks; 7936 free (0 chunks); 256 used Relcache by OID: 16384 total in 2 blocks; 3512 free (2 chunks); 12872 used CacheMemoryContext: 1101328 total in 14 blocks; 386840 free (1 chunks); 714488 used   index info: 1024 total in 1 blocks; 48 free (0 chunks); 976 used: businessop_docid_ndx   index info: 1024 total in 1 blocks; 48 free (0 chunks); 976 used: businessop_sbjentityidroot_ndx   index info: 2048 total in 2 blocks; 704 free (1 chunks); 1344 used: businessop_sbjroleiid_ndx   index info: 2048 total in 2 blocks; 680 free (1 chunks); 1368 used: pg_toast_2619_index   index info: 2048 total in 2 blocks; 968 free (1 chunks); 1080 used: entity_id_fkidx   index info: 2048 total in 2 blocks; 696 free (1 chunks); 1352 used: entity_id_idx   index info: 2048 total in 2 blocks; 968 free (1 chunks); 1080 used: act_id_fkidx   index info: 2048 total in 2 blocks; 696 free (1 chunks); 1352 used: act_id_idx   index info: 2048 total in 2 blocks; 592 free (1 chunks); 1456 used: pg_constraint_conrelid_contypid_conname_index   index info: 2048 total in 2 blocks; 952 free (1 chunks); 1096 used: actrelationship_pkey   index info: 2048 total in 2 blocks; 624 free (1 chunks); 1424 used: actrelationship_target_idx   index info: 2048 total in 2 blocks; 624 free (1 chunks); 1424 used: actrelationship_source_idx   index info: 2048 total in 2 blocks; 680 free (1 chunks); 1368 used: documentinformation_pk   index info: 1024 total in 1 blocks; 48 free (0 chunks); 976 used: pg_statistic_ext_relid_index   index info: 2048 total in 2 blocks; 952 free (1 chunks); 1096 used: docinfsubj_ndx_seii   index info: 2048 total in 2 blocks; 952 free (1 chunks); 1096 used: docinfsubj_ndx_sbjentcodeonly   index info: 2048 total in 2 blocks; 680 free (1 chunks); 1368 used: pg_toast_2618_index   index info: 2048 total in 2 blocks; 952 free (1 chunks); 1096 used: pg_index_indrelid_index   relation rules: 229376 total in 31 blocks; 5136 free (0 chunks); 224240 used: v_businessoperation   index info: 2048 total in 2 blocks; 648 free (2 chunks); 1400 used: pg_db_role_setting_databaseid_rol_index   index info: 2048 total in 2 blocks; 624 free (2 chunks); 1424 used: pg_opclass_am_name_nsp_index   index info: 1024 total in 1 blocks; 16 free (0 chunks); 1008 used: pg_foreign_data_wrapper_name_index   index info: 1024 total in 1 blocks; 48 free (0 chunks); 976 used: pg_enum_oid_index   index info: 2048 total in 2 blocks; 680 free (2 chunks); 1368 used: pg_class_relname_nsp_index   index info: 1024 total in 1 blocks; 48 free (0 chunks); 976 used: pg_foreign_server_oid_index   index info: 1024 total in 1 blocks; 48 free (0 chunks); 976 used: pg_publication_pubname_index   index info: 2048 total in 2 blocks; 592 free (3 chunks); 1456 used: pg_statistic_relid_att_inh_index   index info: 2048 total in 2 blocks; 680 free (2 chunks); 1368 used: pg_cast_source_target_index   index info: 1024 total in 1 blocks; 48 free (0 chunks); 976 used: pg_language_name_index   index info: 1024 total in 1 blocks; 48 free (0 chunks); 976 used: pg_transform_oid_index   index info: 1024 total in 1 blocks; 48 free (0 chunks); 976 used: pg_collation_oid_index   index info: 3072 total in 2 blocks; 1136 free (2 chunks); 1936 used: pg_amop_fam_strat_index   index info: 2048 total in 2 blocks; 952 free (1 chunks); 1096 used: pg_index_indexrelid_index   index info: 2048 total in 2 blocks; 760 free (2 chunks); 1288 used: pg_ts_template_tmplname_index   index info: 2048 total in 2 blocks; 704 free (3 chunks); 1344 used: pg_ts_config_map_index   index info: 2048 total in 2 blocks; 952 free (1 chunks); 1096 used: pg_opclass_oid_index   index info: 1024 total in 1 blocks; 16 free (0 chunks); 1008 used: pg_foreign_data_wrapper_oid_index   index info: 1024 total in 1 blocks; 48 free (0 chunks); 976 used: pg_event_trigger_evtname_index   index info: 2048 total in 2 blocks; 760 free (2 chunks); 1288 used: pg_statistic_ext_name_index   index info: 1024 total in 1 blocks; 48 free (0 chunks); 976 used: pg_publication_oid_index   index info: 1024 total in 1 blocks; 48 free (0 chunks); 976 used: pg_ts_dict_oid_index   index info: 1024 total in 1 blocks; 48 free (0 chunks); 976 used: pg_event_trigger_oid_index   index info: 3072 total in 2 blocks; 1216 free (3 chunks); 1856 used: pg_conversion_default_index   index info: 3072 total in 2 blocks; 1216 free (3 chunks); 1856 used: pg_operator_oprname_l_r_n_index   index info: 2048 total in 2 blocks; 680 free (2 chunks); 1368 used: pg_trigger_tgrelid_tgname_index   index info: 2048 total in 2 blocks; 760 free (2 chunks); 1288 used: pg_enum_typid_label_index   index info: 1024 total in 1 blocks; 48 free (0 chunks); 976 used: pg_ts_config_oid_index   index info: 1024 total in 1 blocks; 48 free (0 chunks); 976 used: pg_user_mapping_oid_index   index info: 2048 total in 2 blocks; 704 free (3 chunks); 1344 used: pg_opfamily_am_name_nsp_index   index info: 1024 total in 1 blocks; 48 free (0 chunks); 976 used: pg_foreign_table_relid_index   index info: 2048 total in 2 blocks; 952 free (1 chunks); 1096 used: pg_type_oid_index   index info: 1024 total in 1 blocks; 48 free (0 chunks); 976 used: pg_aggregate_fnoid_index   index info: 1024 total in 1 blocks; 48 free (0 chunks); 976 used: pg_constraint_oid_index   index info: 2048 total in 2 blocks; 680 free (2 chunks); 1368 used: pg_rewrite_rel_rulename_index   index info: 2048 total in 2 blocks; 760 free (2 chunks); 1288 used: pg_ts_parser_prsname_index   index info: 2048 total in 2 blocks; 760 free (2 chunks); 1288 used: pg_ts_config_cfgname_index   index info: 1024 total in 1 blocks; 48 free (0 chunks); 976 used: pg_ts_parser_oid_index   index info: 2048 total in 2 blocks; 728 free (1 chunks); 1320 used: pg_publication_rel_prrelid_prpubid_index   index info: 2048 total in 2 blocks; 952 free (1 chunks); 1096 used: pg_operator_oid_index   index info: 2048 total in 2 blocks; 952 free (1 chunks); 1096 used: pg_namespace_nspname_index   index info: 1024 total in 1 blocks; 48 free (0 chunks); 976 used: pg_ts_template_oid_index   index info: 2048 total in 2 blocks; 624 free (2 chunks); 1424 used: pg_amop_opr_fam_index   index info: 2048 total in 2 blocks; 672 free (3 chunks); 1376 used: pg_default_acl_role_nsp_obj_index   index info: 2048 total in 2 blocks; 704 free (3 chunks); 1344 used: pg_collation_name_enc_nsp_index   index info: 1024 total in 1 blocks; 48 free (0 chunks); 976 used: pg_publication_rel_oid_index   index info: 1024 total in 1 blocks; 48 free (0 chunks); 976 used: pg_range_rngtypid_index   index info: 2048 total in 2 blocks; 760 free (2 chunks); 1288 used: pg_ts_dict_dictname_index   index info: 2048 total in 2 blocks; 760 free (2 chunks); 1288 used: pg_type_typname_nsp_index   index info: 1024 total in 1 blocks; 48 free (0 chunks); 976 used: pg_opfamily_oid_index   index info: 1024 total in 1 blocks; 48 free (0 chunks); 976 used: pg_statistic_ext_oid_index   index info: 2048 total in 2 blocks; 952 free (1 chunks); 1096 used: pg_class_oid_index   index info: 2048 total in 2 blocks; 704 free (3 chunks); 1344 used: pg_proc_proname_args_nsp_index   index info: 1024 total in 1 blocks; 16 free (0 chunks); 1008 used: pg_partitioned_table_partrelid_index   index info: 2048 total in 2 blocks; 760 free (2 chunks); 1288 used: pg_transform_type_lang_index   index info: 2048 total in 2 blocks; 680 free (2 chunks); 1368 used: pg_attribute_relid_attnum_index   index info: 2048 total in 2 blocks; 952 free (1 chunks); 1096 used: pg_proc_oid_index   index info: 1024 total in 1 blocks; 48 free (0 chunks); 976 used: pg_language_oid_index   index info: 1024 total in 1 blocks; 48 free (0 chunks); 976 used: pg_namespace_oid_index   index info: 3072 total in 2 blocks; 1136 free (2 chunks); 1936 used: pg_amproc_fam_proc_index   index info: 1024 total in 1 blocks; 48 free (0 chunks); 976 used: pg_foreign_server_name_index   index info: 2048 total in 2 blocks; 760 free (2 chunks); 1288 used: pg_attribute_relid_attnam_index   index info: 1024 total in 1 blocks; 48 free (0 chunks); 976 used: pg_conversion_oid_index   index info: 2048 total in 2 blocks; 728 free (1 chunks); 1320 used: pg_user_mapping_user_server_index   index info: 2048 total in 2 blocks; 728 free (1 chunks); 1320 used: pg_subscription_rel_srrelid_srsubid_index   index info: 1024 total in 1 blocks; 48 free (0 chunks); 976 used: pg_sequence_seqrelid_index   index info: 2048 total in 2 blocks; 760 free (2 chunks); 1288 used: pg_conversion_name_nsp_index   index info: 2048 total in 2 blocks; 952 free (1 chunks); 1096 used: pg_authid_oid_index   index info: 2048 total in 2 blocks; 728 free (1 chunks); 1320 used: pg_auth_members_member_role_index   index info: 1024 total in 1 blocks; 48 free (0 chunks); 976 used: pg_subscription_oid_index   index info: 2048 total in 2 blocks; 952 free (1 chunks); 1096 used: pg_tablespace_oid_index   index info: 2048 total in 2 blocks; 704 free (3 chunks); 1344 used: pg_shseclabel_object_index   index info: 1024 total in 1 blocks; 16 free (0 chunks); 1008 used: pg_replication_origin_roname_index   index info: 2048 total in 2 blocks; 952 free (1 chunks); 1096 used: pg_database_datname_index   index info: 2048 total in 2 blocks; 760 free (2 chunks); 1288 used: pg_subscription_subname_index   index info: 1024 total in 1 blocks; 16 free (0 chunks); 1008 used: pg_replication_origin_roiident_index   index info: 2048 total in 2 blocks; 728 free (1 chunks); 1320 used: pg_auth_members_role_member_index   index info: 2048 total in 2 blocks; 952 free (1 chunks); 1096 used: pg_database_oid_index   index info: 2048 total in 2 blocks; 952 free (1 chunks); 1096 used: pg_authid_rolname_index WAL record construction: 49768 total in 2 blocks; 6368 free (0 chunks); 43400 used PrivateRefCount: 8192 total in 1 blocks; 2624 free (0 chunks); 5568 used MdSmgr: 8192 total in 1 blocks; 7256 free (1 chunks); 936 used LOCALLOCK hash: 16384 total in 2 blocks; 4600 free (2 chunks); 11784 used Timezones: 104120 total in 2 blocks; 2624 free (0 chunks); 101496 used ErrorContext: 8192 total in 1 blocks; 7936 free (4 chunks); 256 used
Grand total: 2354072632 bytes in 269647 blocks; 5754640 free (17559 chunks); 2348317992 used

Was postgres locally compiled, packaged by distribution, or PGDG RPM/DEB ?
Locally compiled. I just recompiled with --enable-debug, ready to deploy that to create a core dump and check it out.
Can you show \d businessoperation ?
               Table "reports.businessoperation"         Column           |          Type          | Modifiers
---------------------------+------------------------+-----------documentinternalid        | character varying(255) |is_current                | character(1)           |documentid                | character varying(555) |documenttypecode          | character varying(512) |subjectroleinternalid     | character varying(255) |subjectentityinternalid   | character varying(255) |subjectentityid           | character varying(555) |subjectentityidroot       | character varying(555) |subjectentityname         | character varying      |subjectentitytel          | text                   |subjectentityemail        | text                   |otherentityinternalid     | character varying(255) |confidentialitycode       | character varying(512) |actinternalid             | character varying(255) |operationcode             | character varying(512) |operationname             | text                   |operationqualifiercode    | character varying(512) |operationqualifiername    | character varying(512) |approvalnumber            | character varying(555) |approvalnumbersystem      | character varying(555) |approvalstatecode         | character varying(512) |approvalstatecodesystem   | character varying(512) |approvaleffectivetimelow  | character varying(512) |approvaleffectivetimehigh | character varying(512) |approvalstatuscode        | character varying(32)  |licensecode               | character varying(512) |agencyid                  | character varying(555) |agencyname                | text                   |productitemcode           | character varying(512) |productinternalid         | character varying(255) |

Could you rerun the query with \set VERBOSITY verbose to show the file/line
that's failing ?

Here goes:

integrator=# \set VERBOSITY verbose
integrator=# SET ENABLE_NESTLOOP TO OFF;
SET
integrator=# INSERT INTO reports.BusinessOperation SELECT * FROM reports.v_BusinessOperation;
ERROR:  53200: out of memory
DETAIL:  Failed on request of size 32800 in memory context "HashBatchContext".
LOCATION:  MemoryContextAlloc, mcxt.c:798

you notice that I set ENABLE_NESTLOOP to off, that is because the planner goes off thinking the NL plan is marginally more efficient, but in fact it will take 5 hours to get to the same out of memory crash, while the no NL plan gets there in half an hour. That verbose setting didn't help much I guess.

If you wanted to show a stack trace, you could attach gdb to PID from SELECT
pg_backend_pid(), "b"reak on errdetail, run the query, and then "bt" when it
fails.
gdb -p 27930
GNU gdb (GDB) Red Hat Enterprise Linux 8.0.1-30.amzn2.0.3
...
Attaching to process 27930
Reading symbols from /usr/local/pgsql/bin/postgres...done.
...
(gdb) b errdetail
Breakpoint 1 at 0x82b210: file elog.c, line 872.
(gdb) cont
Continuing.
Breakpoint 1, errdetail (fmt=fmt@entry=0x9d9958 "Failed on request of size %zu in memory context \"%s\".") at elog.c:872
872     {
(gdb) bt
#0  errdetail (fmt=fmt@entry=0x9d9958 "Failed on request of size %zu in memory context \"%s\".") at elog.c:872
#1  0x000000000084e320 in MemoryContextAlloc (context=0x1111600, size=size@entry=32800) at mcxt.c:794
#2  0x000000000060ce7a in dense_alloc (size=384, size@entry=381, hashtable=<optimized out>, hashtable=<optimized out>)   at nodeHash.c:2696
#3  0x000000000060d788 in ExecHashTableInsert (hashtable=hashtable@entry=0x10ead08, slot=<optimized out>, hashvalue=194758122)   at nodeHash.c:1614
#4  0x0000000000610c6f in ExecHashJoinNewBatch (hjstate=0x10806b0) at nodeHashjoin.c:1051
#5  ExecHashJoinImpl (parallel=false, pstate=0x10806b0) at nodeHashjoin.c:539
#6  ExecHashJoin (pstate=0x10806b0) at nodeHashjoin.c:565
#7  0x000000000061ce4e in ExecProcNode (node=0x10806b0) at ../../../src/include/executor/executor.h:247
#8  ExecSort (pstate=0x1080490) at nodeSort.c:107
#9  0x000000000061d2c4 in ExecProcNode (node=0x1080490) at ../../../src/include/executor/executor.h:247
#10 ExecUnique (pstate=0x107ff60) at nodeUnique.c:73
#11 0x0000000000619732 in ExecProcNode (node=0x107ff60) at ../../../src/include/executor/executor.h:247
#12 ExecModifyTable (pstate=0x107fd20) at nodeModifyTable.c:2025
#13 0x00000000005f75ba in ExecProcNode (node=0x107fd20) at ../../../src/include/executor/executor.h:247
#14 ExecutePlan (execute_once=<optimized out>, dest=0x7f0442721998, direction=<optimized out>, numberTuples=0,   sendTuples=<optimized out>, operation=CMD_INSERT, use_parallel_mode=<optimized out>, planstate=0x107fd20, estate=0x107f830)   at execMain.c:1723
#15 standard_ExecutorRun (queryDesc=0x1086880, direction=<optimized out>, count=0, execute_once=<optimized out>) at execMain.c:364
#16 0x000000000072a972 in ProcessQuery (plan=<optimized out>,   sourceText=0xf4a710 "INSERT INTO reports.BusinessOperation SELECT * FROM reports.v_BusinessOperation;", params=0x0,   queryEnv=0x0, dest=0x7f0442721998, completionTag=0x7fff2e4cad30 "") at pquery.c:161
#17 0x000000000072abb0 in PortalRunMulti (portal=portal@entry=0xfb06b0, isTopLevel=isTopLevel@entry=true,   setHoldSnapshot=setHoldSnapshot@entry=false, dest=dest@entry=0x7f0442721998, altdest=altdest@entry=0x7f0442721998,   completionTag=completionTag@entry=0x7fff2e4cad30 "") at pquery.c:1286
#18 0x000000000072b661 in PortalRun (portal=portal@entry=0xfb06b0, count=count@entry=9223372036854775807,   isTopLevel=isTopLevel@entry=true, run_once=run_once@entry=true, dest=dest@entry=0x7f0442721998,   altdest=altdest@entry=0x7f0442721998, completionTag=0x7fff2e4cad30 "") at pquery.c:799
#19 0x00000000007276e8 in exec_simple_query (   query_string=0xf4a710 "INSERT INTO reports.BusinessOperation SELECT * FROM reports.v_BusinessOperation;") at postgres.c:1145
#20 0x0000000000729534 in PostgresMain (argc=<optimized out>, argv=argv@entry=0xf76ce8, dbname=<optimized out>,   username=<optimized out>) at postgres.c:4182
#21 0x00000000006be215 in BackendRun (port=0xf6dfe0) at postmaster.c:4361
#22 BackendStartup (port=0xf6dfe0) at postmaster.c:4033
#23 ServerLoop () at postmaster.c:1706
#24 0x00000000006bf122 in PostmasterMain (argc=argc@entry=3, argv=argv@entry=0xf45320) at postmaster.c:1379
#25 0x00000000004822dc in main (argc=3, argv=0xf45320) at main.c:228

That's it.

Thank you all very much for your interest in this case.

-Gunther


pgsql-performance by date:

Previous
From: Jeff Janes
Date:
Subject: Re: Out of Memory errors are frustrating as heck!
Next
From: Tom Lane
Date:
Subject: Re: Out of Memory errors are frustrating as heck!