Thread: Perl function leading to out of memory error
Hi, we have a Java daemon that=C2=B4s repeatedly calling a Perl function insi= de=20 our database (version 9.1.8). The function is called about 200 times per=20 second. While the Java program is running you can watch the memory usage=20 of the postmaster grow continuously until after a few hours we get an=20 out of memory error from Postgres. In the log you see a lot of=20 "ExprContext..." messages. When the daemon is killed the memory is=20 freed.The daemon is using a single database connection during it=C2=B4s r= untime. You can see the function definition here:=20 http://www.deriva.de/tmp/get_comment.txt Does anyone have an idea what could be wrong here or how I can find out=20 where the memory is spend? Thanks a lot, Jan P.S.: Here=C2=B4s the log: <2013-02-18 16:51:26 CET - idms_export> CONTEXT: PL/Perl function=20 "get_comment" TopMemoryContext: 1272045600 total in 657683 blocks; 419880 free (42=20 chunks); 1271625720 used TopTransactionContext: 8192 total in 1 blocks; 7304 free (0 chunks); 888=20 used ExprContext: 8192 total in 1 blocks; 8160 free (0 chunks); 32 used ExprContext: 8192 total in 1 blocks; 8160 free (0 chunks); 32 used ...About 290.000 more of the same lines... ExprContext: 8192 total in 1 blocks; 8160 free (0 chunks); 32 used ExprContext: 8192 total in 1 blocks; 8160 free (0 chunks); 32 used Prepared Queries: 24576 total in 2 blocks; 15984 free (5 chunks); 8592 us= ed ExprContext: 8192 total in 1 blocks; 8160 free (0 chunks); 32 used ExprContext: 8192 total in 1 blocks; 8160 free (0 chunks); 32 used ExprContext: 8192 total in 1 blocks; 8160 free (0 chunks); 32 used RI compare cache: 8192 total in 1 blocks; 3744 free (0 chunks); 4448 used RI query cache: 24576 total in 2 blocks; 11888 free (5 chunks); 12688 use= d ExprContext: 8192 total in 1 blocks; 8160 free (0 chunks); 32 used PL/pgSQL function context: 57344 total in 3 blocks; 40176 free (3=20 chunks); 17168 used PL/Perl queries: 24576 total in 2 blocks; 15984 free (5 chunks); 8592 use= d PL/Perl procedures: 8192 total in 1 blocks; 1680 free (0 chunks); 6512 us= ed PL/Perl interpreters: 8192 total in 1 blocks; 3216 free (0 chunks); 4976=20 used PL/pgSQL function context: 57344 total in 3 blocks; 30072 free (4=20 chunks); 27272 used PL/pgSQL function context: 24576 total in 2 blocks; 17976 free (6=20 chunks); 6600 used CFuncHash: 8192 total in 1 blocks; 1680 free (0 chunks); 6512 used Rendezvous variable hash: 8192 total in 1 blocks; 1680 free (0 chunks);=20 6512 used PLpgSQL function cache: 24520 total in 2 blocks; 3744 free (0 chunks);=20 20776 used TableSpace cache: 8192 total in 1 blocks; 3216 free (0 chunks); 4976 used Type information cache: 24576 total in 2 blocks; 11888 free (5 chunks);=20 12688 used Operator lookup cache: 24576 total in 2 blocks; 11888 free (5 chunks);=20 12688 used MessageContext: 8192 total in 1 blocks; 6976 free (0 chunks); 1216 used Operator class cache: 8192 total in 1 blocks; 1680 free (0 chunks); 6512=20 used smgr relation table: 24576 total in 2 blocks; 5696 free (4 chunks);=20 18880 used TransactionAbortContext: 32768 total in 1 blocks; 32736 free (0 chunks);=20 32 used Portal hash: 8192 total in 1 blocks; 1680 free (0 chunks); 6512 used PortalMemory: 8192 total in 1 blocks; 7888 free (1 chunks); 304 used PortalHeapMemory: 1024 total in 1 blocks; 552 free (0 chunks); 472 used ExecutorState: 32864 total in 3 blocks; 7688 free (0 chunks); 25176 used HashTableContext: 8192 total in 1 blocks; 8096 free (1 chunks); 96 used HashBatchContext: 51372080 total in 16 blocks; 336 free (5 chunks);=20 51371744 used ExprContext: 0 total in 0 blocks; 0 free (0 chunks); 0 used ExprContext: 0 total in 0 blocks; 0 free (0 chunks); 0 used ExprContext: 0 total in 0 blocks; 0 free (0 chunks); 0 used ExprContext: 0 total in 0 blocks; 0 free (0 chunks); 0 used Relcache by OID: 24576 total in 2 blocks; 12832 free (3 chunks); 11744 us= ed CacheMemoryContext: 1377288 total in 24 blocks; 94352 free (3 chunks);=20 1282936 used unnamed prepared statement: 122880 total in 4 blocks; 39504 free (5=20 chunks); 83376 used cached_comments_pkey: 2048 total in 1 blocks; 728 free (0 chunks); 1320 u= sed Z_BASE_COUNTRY_STATUS: 2048 total in 1 blocks; 776 free (0 chunks); 1272=20 used Z_BASE_COUNTRY_NSIN_ID_COUNTRY: 2048 total in 1 blocks; 176 free (0=20 chunks); 1872 used Z_BASE_COUNTRY_NSIN: 2048 total in 1 blocks; 776 free (0 chunks); 1272 us= ed Z_BASE_COUNTRY_ISIN: 2048 total in 1 blocks; 776 free (0 chunks); 1272 us= ed Z_BASE_COUNTRY_ID_COUNTRY: 2048 total in 1 blocks; 776 free (0 chunks);=20 1272 used Z_BASE_COUNTRY_pkey: 2048 total in 1 blocks; 664 free (0 chunks); 1384 us= ed CachedPlan: 15360 total in 4 blocks; 5272 free (0 chunks); 10088 used CachedPlanSource: 7168 total in 3 blocks; 3928 free (2 chunks); 3240 used SPI Plan: 1024 total in 1 blocks; 808 free (0 chunks); 216 used Z_UL_ID_NOTATION: 2048 total in 1 blocks; 728 free (0 chunks); 1320 used Z_UL_pkey: 2048 total in 1 blocks; 664 free (0 chunks); 1384 used BASKET_ISIN_UNIQUE: 4096 total in 2 blocks; 1792 free (0 chunks); 2304 us= ed UL_NOTATIONS_pkey: 2048 total in 1 blocks; 728 free (0 chunks); 1320 used UL_BASE_pkey: 2048 total in 1 blocks; 728 free (0 chunks); 1320 used Z_BARRIER_ISIN_key: 2048 total in 1 blocks; 728 free (0 chunks); 1320 use= d Z_BARRIER_ISIN_ID_NOTATION_key: 2048 total in 1 blocks; 712 free (0=20 chunks); 1336 used Z_BARRIER_ISIN_ID_NOTATION_ID_TYPE_BARRIER_key: 2048 total in 1 blocks;=20 344 free (0 chunks); 1704 used Z_BARRIER_ISIN_ID_NOTATION_ID_TYPE_BARRIER_DATE_START_key: 2048 total in=20 1 blocks; 344 free (0 chunks); 1704 used Z_BARRIER_ID_TYPE_BARRIER: 2048 total in 1 blocks; 776 free (0 chunks);=20 1272 used Z_BARRIER_pkey: 2048 total in 1 blocks; 776 free (0 chunks); 1272 used CachedPlan: 1024 total in 1 blocks; 312 free (0 chunks); 712 used CachedPlanSource: 3072 total in 2 blocks; 1832 free (1 chunks); 1240 used SPI Plan: 1024 total in 1 blocks; 832 free (0 chunks); 192 used PRODUCT_GROUPS_pkey: 2048 total in 1 blocks; 728 free (0 chunks); 1320 us= ed CachedPlan: 1024 total in 1 blocks; 312 free (0 chunks); 712 used CachedPlanSource: 3072 total in 2 blocks; 1832 free (1 chunks); 1240 used SPI Plan: 1024 total in 1 blocks; 832 free (0 chunks); 192 used CachedPlan: 3072 total in 2 blocks; 1264 free (0 chunks); 1808 used CachedPlanSource: 3072 total in 2 blocks; 376 free (0 chunks); 2696 used SPI Plan: 1024 total in 1 blocks; 832 free (0 chunks); 192 used CachedPlan: 3072 total in 2 blocks; 1272 free (0 chunks); 1800 used CachedPlanSource: 3072 total in 2 blocks; 200 free (0 chunks); 2872 used SPI Plan: 1024 total in 1 blocks; 832 free (0 chunks); 192 used CachedPlan: 3072 total in 2 blocks; 1888 free (1 chunks); 1184 used CachedPlanSource: 3072 total in 2 blocks; 1256 free (0 chunks); 1816 used SPI Plan: 1024 total in 1 blocks; 832 free (0 chunks); 192 used CachedPlan: 1024 total in 1 blocks; 272 free (0 chunks); 752 used CachedPlanSource: 3072 total in 2 blocks; 1968 free (2 chunks); 1104 used SPI Plan: 1024 total in 1 blocks; 832 free (0 chunks); 192 used CachedPlan: 3072 total in 2 blocks; 1040 free (0 chunks); 2032 used CachedPlanSource: 7168 total in 3 blocks; 4000 free (2 chunks); 3168 used SPI Plan: 1024 total in 1 blocks; 832 free (0 chunks); 192 used tmp_idx: 2048 total in 1 blocks; 72 free (0 chunks); 1976 used PRODUCT_TYPES_pkey: 2048 total in 1 blocks; 728 free (0 chunks); 1320 use= d PRODUCT_TYPES_ID_PRODUCT_TYPE_key: 2048 total in 1 blocks; 712 free (0=20 chunks); 1336 used CachedPlan: 3072 total in 2 blocks; 1400 free (0 chunks); 1672 used CachedPlanSource: 3072 total in 2 blocks; 680 free (0 chunks); 2392 used SPI Plan: 1024 total in 1 blocks; 832 free (0 chunks); 192 used CachedPlan: 1024 total in 1 blocks; 256 free (0 chunks); 768 used CachedPlanSource: 3072 total in 2 blocks; 1768 free (1 chunks); 1304 used SPI Plan: 1024 total in 1 blocks; 832 free (0 chunks); 192 used CachedPlan: 3072 total in 2 blocks; 1504 free (0 chunks); 1568 used CachedPlanSource: 3072 total in 2 blocks; 1024 free (0 chunks); 2048 used SPI Plan: 1024 total in 1 blocks; 832 free (0 chunks); 192 used CachedPlan: 3072 total in 2 blocks; 1296 free (0 chunks); 1776 used CachedPlanSource: 3072 total in 2 blocks; 488 free (0 chunks); 2584 used SPI Plan: 1024 total in 1 blocks; 832 free (0 chunks); 192 used CachedPlan: 3072 total in 2 blocks; 1840 free (0 chunks); 1232 used CachedPlanSource: 3072 total in 2 blocks; 1016 free (0 chunks); 2056 used SPI Plan: 1024 total in 1 blocks; 832 free (0 chunks); 192 used CachedPlan: 3072 total in 2 blocks; 1808 free (0 chunks); 1264 used CachedPlanSource: 3072 total in 2 blocks; 1152 free (0 chunks); 1920 used SPI Plan: 1024 total in 1 blocks; 832 free (0 chunks); 192 used CachedPlan: 3072 total in 2 blocks; 1264 free (0 chunks); 1808 used CachedPlanSource: 3072 total in 2 blocks; 624 free (0 chunks); 2448 used SPI Plan: 1024 total in 1 blocks; 832 free (0 chunks); 192 used CachedPlan: 3072 total in 2 blocks; 1672 free (0 chunks); 1400 used CachedPlanSource: 3072 total in 2 blocks; 784 free (0 chunks); 2288 used SPI Plan: 1024 total in 1 blocks; 832 free (0 chunks); 192 used CachedPlan: 1024 total in 1 blocks; 312 free (0 chunks); 712 used CachedPlanSource: 3072 total in 2 blocks; 1832 free (1 chunks); 1240 used SPI Plan: 1024 total in 1 blocks; 832 free (0 chunks); 192 used CachedPlan: 1024 total in 1 blocks; 272 free (0 chunks); 752 used CachedPlanSource: 3072 total in 2 blocks; 1968 free (2 chunks); 1104 used SPI Plan: 1024 total in 1 blocks; 832 free (0 chunks); 192 used CachedPlan: 1024 total in 1 blocks; 144 free (0 chunks); 880 used CachedPlanSource: 3072 total in 2 blocks; 1512 free (0 chunks); 1560 used SPI Plan: 1024 total in 1 blocks; 832 free (0 chunks); 192 used CachedPlan: 3072 total in 2 blocks; 1920 free (0 chunks); 1152 used CachedPlanSource: 3072 total in 2 blocks; 1432 free (0 chunks); 1640 used SPI Plan: 1024 total in 1 blocks; 832 free (0 chunks); 192 used CachedPlan: 3072 total in 2 blocks; 1192 free (0 chunks); 1880 used CachedPlanSource: 3072 total in 2 blocks; 424 free (0 chunks); 2648 used SPI Plan: 1024 total in 1 blocks; 832 free (0 chunks); 192 used CachedPlan: 3072 total in 2 blocks; 1520 free (0 chunks); 1552 used CachedPlanSource: 3072 total in 2 blocks; 976 free (0 chunks); 2096 used SPI Plan: 1024 total in 1 blocks; 832 free (0 chunks); 192 used CachedPlan: 3072 total in 2 blocks; 1520 free (0 chunks); 1552 used CachedPlanSource: 3072 total in 2 blocks; 976 free (0 chunks); 2096 used SPI Plan: 1024 total in 1 blocks; 832 free (0 chunks); 192 used CachedPlan: 3072 total in 2 blocks; 1976 free (1 chunks); 1096 used CachedPlanSource: 3072 total in 2 blocks; 1376 free (0 chunks); 1696 used SPI Plan: 1024 total in 1 blocks; 832 free (0 chunks); 192 used CachedPlan: 1024 total in 1 blocks; 272 free (0 chunks); 752 used CachedPlanSource: 3072 total in 2 blocks; 1968 free (2 chunks); 1104 used SPI Plan: 1024 total in 1 blocks; 832 free (0 chunks); 192 used CachedPlan: 1024 total in 1 blocks; 272 free (0 chunks); 752 used CachedPlanSource: 3072 total in 2 blocks; 1968 free (2 chunks); 1104 used SPI Plan: 1024 total in 1 blocks; 832 free (0 chunks); 192 used CachedPlan: 3072 total in 2 blocks; 752 free (0 chunks); 2320 used CachedPlanSource: 3072 total in 2 blocks; 336 free (0 chunks); 2736 used SPI Plan: 1024 total in 1 blocks; 832 free (0 chunks); 192 used CachedPlan: 3072 total in 2 blocks; 1888 free (1 chunks); 1184 used CachedPlanSource: 3072 total in 2 blocks; 1400 free (0 chunks); 1672 used SPI Plan: 1024 total in 1 blocks; 832 free (0 chunks); 192 used CachedPlan: 1024 total in 1 blocks; 272 free (0 chunks); 752 used CachedPlanSource: 3072 total in 2 blocks; 1968 free (2 chunks); 1104 used SPI Plan: 1024 total in 1 blocks; 832 free (0 chunks); 192 used CachedPlan: 1024 total in 1 blocks; 248 free (0 chunks); 776 used CachedPlanSource: 3072 total in 2 blocks; 1944 free (2 chunks); 1128 used SPI Plan: 1024 total in 1 blocks; 832 free (0 chunks); 192 used CachedPlan: 3072 total in 2 blocks; 1672 free (0 chunks); 1400 used CachedPlanSource: 3072 total in 2 blocks; 1096 free (0 chunks); 1976 used SPI Plan: 1024 total in 1 blocks; 832 free (0 chunks); 192 used CachedPlan: 3072 total in 2 blocks; 240 free (0 chunks); 2832 used CachedPlanSource: 7168 total in 3 blocks; 3656 free (0 chunks); 3512 used SPI Plan: 1024 total in 1 blocks; 832 free (0 chunks); 192 used pg_constraint_contypid_index: 2048 total in 1 blocks; 728 free (0=20 chunks); 1320 used pg_toast_1255_index: 2048 total in 1 blocks; 664 free (0 chunks); 1384 us= ed pg_toast_2619_index: 2048 total in 1 blocks; 664 free (0 chunks); 1384 us= ed Z_BASE_IS_INDICATIVE: 2048 total in 1 blocks; 776 free (0 chunks); 1272 u= sed Z_BASE_ID_PRODUCT_TYPE_index: 2048 total in 1 blocks; 776 free (0=20 chunks); 1272 used Z_BASE_ID_ISSUER_GROUP_index: 2048 total in 1 blocks; 776 free (0=20 chunks); 1272 used Z_BASE_ID_ISSUER_GROUP_ID_PRODUCT_TYPE_index: 2048 total in 1 blocks;=20 712 free (0 chunks); 1336 used Z_BASE_pkey: 2048 total in 1 blocks; 728 free (0 chunks); 1320 used pg_index_indrelid_index: 2048 total in 1 blocks; 728 free (0 chunks);=20 1320 used pg_constraint_conrelid_index: 2048 total in 1 blocks; 728 free (0=20 chunks); 1320 used pg_attrdef_adrelid_adnum_index: 2048 total in 1 blocks; 664 free (0=20 chunks); 1384 used pg_db_role_setting_databaseid_rol_index: 2048 total in 1 blocks; 664=20 free (0 chunks); 1384 used pg_opclass_am_name_nsp_index: 3072 total in 2 blocks; 1496 free (2=20 chunks); 1576 used pg_foreign_data_wrapper_name_index: 3072 total in 2 blocks; 1768 free (4=20 chunks); 1304 used pg_enum_oid_index: 3072 total in 2 blocks; 1720 free (3 chunks); 1352 use= d pg_class_relname_nsp_index: 3072 total in 2 blocks; 1656 free (3=20 chunks); 1416 used pg_foreign_server_oid_index: 3072 total in 2 blocks; 1768 free (4=20 chunks); 1304 used pg_statistic_relid_att_inh_index: 3072 total in 2 blocks; 1496 free (2=20 chunks); 1576 used pg_cast_source_target_index: 3072 total in 2 blocks; 1656 free (3=20 chunks); 1416 used pg_language_name_index: 3072 total in 2 blocks; 1768 free (4 chunks);=20 1304 used pg_collation_oid_index: 3072 total in 2 blocks; 1768 free (4 chunks);=20 1304 used pg_amop_fam_strat_index: 3072 total in 2 blocks; 1496 free (2 chunks);=20 1576 used pg_index_indexrelid_index: 3072 total in 2 blocks; 1720 free (3 chunks);=20 1352 used pg_ts_template_tmplname_index: 3072 total in 2 blocks; 1704 free (4=20 chunks); 1368 used pg_ts_config_map_index: 3072 total in 2 blocks; 1544 free (2 chunks);=20 1528 used pg_opclass_oid_index: 3072 total in 2 blocks; 1720 free (3 chunks); 1352=20 used pg_foreign_data_wrapper_oid_index: 3072 total in 2 blocks; 1768 free (4=20 chunks); 1304 used pg_ts_dict_oid_index: 3072 total in 2 blocks; 1768 free (4 chunks); 1304=20 used pg_conversion_default_index: 3072 total in 2 blocks; 1544 free (2=20 chunks); 1528 used pg_operator_oprname_l_r_n_index: 3072 total in 2 blocks; 1496 free (2=20 chunks); 1576 used pg_trigger_tgrelid_tgname_index: 3072 total in 2 blocks; 1656 free (3=20 chunks); 1416 used pg_enum_typid_label_index: 3072 total in 2 blocks; 1704 free (4 chunks);=20 1368 used pg_ts_config_oid_index: 3072 total in 2 blocks; 1768 free (4 chunks);=20 1304 used pg_user_mapping_oid_index: 3072 total in 2 blocks; 1768 free (4 chunks);=20 1304 used pg_opfamily_am_name_nsp_index: 3072 total in 2 blocks; 1544 free (2=20 chunks); 1528 used pg_foreign_table_relid_index: 3072 total in 2 blocks; 1768 free (4=20 chunks); 1304 used pg_type_oid_index: 3072 total in 2 blocks; 1720 free (3 chunks); 1352 use= d pg_aggregate_fnoid_index: 3072 total in 2 blocks; 1768 free (4 chunks);=20 1304 used pg_constraint_oid_index: 3072 total in 2 blocks; 1720 free (3 chunks);=20 1352 used pg_rewrite_rel_rulename_index: 3072 total in 2 blocks; 1704 free (4=20 chunks); 1368 used pg_ts_parser_prsname_index: 3072 total in 2 blocks; 1704 free (4=20 chunks); 1368 used pg_ts_config_cfgname_index: 3072 total in 2 blocks; 1704 free (4=20 chunks); 1368 used pg_ts_parser_oid_index: 3072 total in 2 blocks; 1768 free (4 chunks);=20 1304 used pg_operator_oid_index: 3072 total in 2 blocks; 1720 free (3 chunks);=20 1352 used pg_namespace_nspname_index: 3072 total in 2 blocks; 1720 free (3=20 chunks); 1352 used pg_ts_template_oid_index: 3072 total in 2 blocks; 1768 free (4 chunks);=20 1304 used pg_amop_opr_fam_index: 3072 total in 2 blocks; 1496 free (2 chunks);=20 1576 used pg_default_acl_role_nsp_obj_index: 3072 total in 2 blocks; 1544 free (2=20 chunks); 1528 used pg_collation_name_enc_nsp_index: 3072 total in 2 blocks; 1544 free (2=20 chunks); 1528 used pg_ts_dict_dictname_index: 3072 total in 2 blocks; 1704 free (4 chunks);=20 1368 used pg_type_typname_nsp_index: 3072 total in 2 blocks; 1656 free (3 chunks);=20 1416 used pg_opfamily_oid_index: 3072 total in 2 blocks; 1768 free (4 chunks);=20 1304 used pg_class_oid_index: 3072 total in 2 blocks; 1720 free (3 chunks); 1352 us= ed pg_proc_proname_args_nsp_index: 3072 total in 2 blocks; 1496 free (2=20 chunks); 1576 used pg_attribute_relid_attnum_index: 3072 total in 2 blocks; 1656 free (3=20 chunks); 1416 used pg_proc_oid_index: 3072 total in 2 blocks; 1720 free (3 chunks); 1352 use= d pg_language_oid_index: 3072 total in 2 blocks; 1720 free (3 chunks);=20 1352 used pg_namespace_oid_index: 3072 total in 2 blocks; 1720 free (3 chunks);=20 1352 used pg_amproc_fam_proc_index: 3072 total in 2 blocks; 1496 free (2 chunks);=20 1576 used pg_foreign_server_name_index: 3072 total in 2 blocks; 1768 free (4=20 chunks); 1304 used pg_attribute_relid_attnam_index: 3072 total in 2 blocks; 1704 free (4=20 chunks); 1368 used pg_conversion_oid_index: 3072 total in 2 blocks; 1768 free (4 chunks);=20 1304 used pg_user_mapping_user_server_index: 3072 total in 2 blocks; 1704 free (4=20 chunks); 1368 used pg_conversion_name_nsp_index: 3072 total in 2 blocks; 1704 free (4=20 chunks); 1368 used pg_authid_oid_index: 3072 total in 2 blocks; 1720 free (3 chunks); 1352 u= sed pg_auth_members_member_role_index: 3072 total in 2 blocks; 1656 free (3=20 chunks); 1416 used pg_tablespace_oid_index: 3072 total in 2 blocks; 1720 free (3 chunks);=20 1352 used pg_database_datname_index: 3072 total in 2 blocks; 1720 free (3 chunks);=20 1352 used pg_auth_members_role_member_index: 3072 total in 2 blocks; 1704 free (4=20 chunks); 1368 used pg_database_oid_index: 3072 total in 2 blocks; 1720 free (3 chunks);=20 1352 used pg_authid_rolname_index: 3072 total in 2 blocks; 1720 free (3 chunks);=20 1352 used MdSmgr: 8192 total in 1 blocks; 5024 free (2 chunks); 3168 used LOCALLOCK hash: 24576 total in 2 blocks; 13920 free (4 chunks); 10656 use= d Timezones: 83472 total in 2 blocks; 3744 free (0 chunks); 79728 used ErrorContext: 8192 total in 1 blocks; 8160 free (4 chunks); 32 used <2013-02-18 16:51:55 CET - idms_export> ERROR: out of memory <2013-02-18 16:51:55 CET - idms_export> DETAIL: Failed on request of=20 size 56. <2013-02-18 16:51:55 CET - idms_export> STATEMENT: SELECT b."ISIN" FROM=20 dtng."Z_BASE" b LEFT OUTER JOIN dtng.cached_comments cc USING ("ISIN")=20 WHERE b."COMMENT" IS NULL AND (cc.cache_time IS NULL OR cc.cache_time <=20 b._last_modified)
Jan Strube <js@deriva.de> writes:
> we have a Java daemon that´s repeatedly calling a Perl function inside
> our database (version 9.1.8). The function is called about 200 times per
> second. While the Java program is running you can watch the memory usage
> of the postmaster grow continuously until after a few hours we get an
> out of memory error from Postgres. In the log you see a lot of
> "ExprContext..." messages.
I tried to reproduce this, without much success. Can you extract a
self-contained test case?
regards, tom lane
Le mardi 19 février 2013 à 12:05 +0100, Jan Strube a écrit : > Hi, > > we have a Java daemon that´s repeatedly calling a Perl function inside > our database (version 9.1.8). The function is called about 200 times per > second. While the Java program is running you can watch the memory usage > of the postmaster grow continuously until after a few hours we get an > out of memory error from Postgres. In the log you see a lot of > "ExprContext..." messages. When the daemon is killed the memory is > freed.The daemon is using a single database connection during it´s runtime. > > You can see the function definition here: > http://www.deriva.de/tmp/get_comment.txt > > Does anyone have an idea what could be wrong here or how I can find out > where the memory is spend? > Not sure, but have you considered closures? I wonder if your use of %data in $get_value = sub {...} is creating one. See Merlyn's reply in this thread : http://www.gossamer-threads.com/lists/modperl/modperl/27667?search_string=closure;#27667 for a way to find out. If so, you can probably do my $get_value = sub { my ($data, $table, $cond, $field) = @_; (where $data is a reference to %data) ... } and call it with my $value = $get_value->(\%data, $1, $2, $3); instead of my $value = $get_value->($1, $2, $3); -- Salutations, Vincent Veyron http://marica.fr/site/demonstration Progiciel de gestion des sinistres assurance et des dossiers contentieux pour le service juridique
On 19.02.2013 12:41, Tom Lane wrote:
> Jan Strube <js@deriva.de> writes:
>> we have a Java daemon that´s repeatedly calling a Perl function inside
>> our database (version 9.1.8). The function is called about 200 times per
>> second. While the Java program is running you can watch the memory usage
>> of the postmaster grow continuously until after a few hours we get an
>> out of memory error from Postgres. In the log you see a lot of
>> "ExprContext..." messages.
> I tried to reproduce this, without much success. Can you extract a
> self-contained test case?
after some investigation it seems that the error has to do with a domain
type that we have defined in our database. We have defined the following
helper functions:
CREATE OR REPLACE FUNCTION isin_pz(text) RETURNS integer AS $$
DECLARE c char; s text := ''; l integer; d integer; w integer; sum integer := 0;
BEGIN IF char_length($1) != 11 THEN RETURN null; END IF;
IF substr($1, 1, 2) < 'AA' OR substr($1, 1, 2) > 'ZZ' THEN RETURN null; END IF;
FOR pos IN 1 .. 11 LOOP c := substr($1, pos, 1); IF c >= '0' AND c <= '9' THEN s := s ||
c; ELSE IF c >= 'A' AND c <= 'Z' THEN s := s || to_char(ascii(c) - 55, 'FM99');
ELSE RETURN null; END IF; END IF; END LOOP;
l := char_length(s); FOR pos IN 1 .. l LOOP d := to_number(substr(s, pos, 1), '0'); w :=
((l-pos+1)% 2) + 1; IF w * d >= 10 THEN sum := sum + (w * d) % 10 + 1; ELSE sum :=
sum+ (w * d); END IF; END LOOP;
RETURN (10 - (sum % 10)) % 10;
END;
$$
LANGUAGE 'plpgsql' IMMUTABLE STRICT;
CREATE OR REPLACE FUNCTION isin_ok(text) RETURNS boolean AS $$
DECLARE pz integer;
BEGIN IF char_length($1) != 12 OR substr($1, 1, 2) < 'AA' OR substr($1,
1, 2) > 'ZZ' THEN RETURN false; END IF;
pz := public.isin_pz(substr($1, 1, 11)); IF pz IS NULL THEN RETURN false; END IF;
RETURN to_char(pz, 'FM9') = substr($1, 12, 1);
END;
$$
LANGUAGE 'plpgsql' IMMUTABLE STRICT;
They are used to define the domain type "isin" as follows:
CREATE DOMAIN isin AS char(12) CHECK (isin_ok(value));
Now we can create our test case. Create the following table:
CREATE TABLE foo (isin char(12) NOT NULL);
And this function:
CREATE OR REPLACE FUNCTION foo(isin char(12)) RETURNS void AS $$
my ($isin) = @_;
my $stmt = spi_prepare(' INSERT INTO foo (isin) VALUES ($1)', 'isin');
spi_exec_prepared($stmt, $isin);
spi_freeplan($stmt);
$$ LANGUAGE plperl VOLATILE STRICT;
If we now repeatedly call this function (e.g. using a Perl script) we
can see the memory consumption rise continuously until the out of memory
error occurs.
Interestingly, if we change the type specification in the call to
"spi_prepare" from "isin" to "char(12)" the problem no longer occurs.
Can you explain this behavior?
Regards,
Christian
--
Deriva GmbH Tel.: +49 551 489500-42
Financial IT and Consulting Fax: +49 551 489500-91
Hans-Böckler-Straße 2 http://www.deriva.de
D-37079 Göttingen
Amtsgericht Göttingen | HRB 3240
Geschäftsführer: Dirk Baule, Christian Schröder
Deriva CA Certificate: http://www.deriva.de/deriva-ca.cer
On 19/02/13 22:05, Jan Strube wrote: > we have a Java daemon that´s repeatedly calling a Perl function inside > our database (version 9.1.8). The function is called about 200 times per > second. While the Java program is running you can watch the memory usage > of the postmaster grow continuously until after a few hours we get an > out of memory error from Postgres. In the log you see a lot of > "ExprContext..." messages. When the daemon is killed the memory is > freed.The daemon is using a single database connection during it´s runtime. > > You can see the function definition here: > http://www.deriva.de/tmp/get_comment.txt A minor point, but are you aware that Perl has a switch syntax (given/where keywords) which could replace the "for($table) /regex/ && do { ... last; }" stuff? perldoc -f given On a more useful point, can I suggest that you extract your program into a standalone script (mock up something to provide the elog/spi_exec calls). Then you can run that thousands of times to check if it is leaking memory. You can also run it up against something such as Devel::Leak: http://search.cpan.org/~srezic/Devel-Leak/Leak.pm As another posted commented, you may well be leaking the %data structure, since it's being referenced from inside a closure. Perl isn't totally stupid, and should clean up %data once $get_value goes out of scope, but it's worth checking you aren't keeping a reference somewhere. Cheers, Toby
On Wed, Feb 20, 2013 at 9:31 AM, Christian Schr=F6der <cs@deriva.de> wrote:
> after some investigation it seems that the error has to do with a domain
> type that we have defined in our database. We have defined the following
> helper functions:
>
...
>
> CREATE DOMAIN isin AS char(12) CHECK (isin_ok(value));
Could you give some example values that meet this criteria? Trying to
reverse engineer your helper functions is no fun.
>
> Now we can create our test case. Create the following table:
>
> CREATE TABLE foo (isin char(12) NOT NULL);
>
> And this function:
>
> CREATE OR REPLACE FUNCTION foo(isin char(12)) RETURNS void AS $$
> my ($isin) =3D @_;
>
> my $stmt =3D spi_prepare('
> INSERT INTO foo (isin)
> VALUES ($1)', 'isin');
> spi_exec_prepared($stmt, $isin);
> spi_freeplan($stmt);
> $$ LANGUAGE plperl VOLATILE STRICT;
That should be easy enough to re-write as plpgsql. If you do, does it
still leak?
Cheers,
Jeff
On 21.02.2013 01:02, Jeff Janes wrote:
>> CREATE DOMAIN isin AS char(12) CHECK (isin_ok(value));
> Could you give some example values that meet this criteria? Trying to
> reverse engineer your helper functions is no fun.
A valid example is "DE0007100000". The same with another check digit is
of course invalid (e.g. "DE0007100001").
>> CREATE OR REPLACE FUNCTION foo(isin char(12)) RETURNS void AS $$
>> my ($isin) = @_;
>>
>> my $stmt = spi_prepare('
>> INSERT INTO foo (isin)
>> VALUES ($1)', 'isin');
>> spi_exec_prepared($stmt, $isin);
>> spi_freeplan($stmt);
>> $$ LANGUAGE plperl VOLATILE STRICT;
> That should be easy enough to re-write as plpgsql. If you do, does it
> still leak?
I have no idea how to create a prepared statement in plpgsql. I have
tested the following function:
CREATE OR REPLACE FUNCTION foo(isin char(12)) RETURNS void AS $$
BEGIN INSERT INTO foo (isin) VALUES (isin);
END;
$$ LANGUAGE plpgsql VOLATILE STRICT;
This works without any problem.
Regards,
Christian
--
Deriva GmbH Tel.: +49 551 489500-42
Financial IT and Consulting Fax: +49 551 489500-91
Hans-Böckler-Straße 2 http://www.deriva.de
D-37079 Göttingen
Amtsgericht Göttingen | HRB 3240
Geschäftsführer: Dirk Baule, Christian Schröder
Deriva CA Certificate: http://www.deriva.de/deriva-ca.cer