You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@hawq.apache.org by "Lei Chang (JIRA)" <ji...@apache.org> on 2016/01/24 03:24:39 UTC

[jira] [Updated] (HAWQ-198) Build-in functions will be executed in resource_negotiator stage which causes it will be executed twice

     [ https://issues.apache.org/jira/browse/HAWQ-198?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Lei Chang updated HAWQ-198:
---------------------------
    Fix Version/s: 2.0.0

> Build-in functions will be executed in resource_negotiator  stage which causes it will be executed twice 
> ---------------------------------------------------------------------------------------------------------
>
>                 Key: HAWQ-198
>                 URL: https://issues.apache.org/jira/browse/HAWQ-198
>             Project: Apache HAWQ
>          Issue Type: Bug
>          Components: Core
>            Reporter: Dong Li
>            Assignee: Ruilong Huo
>             Fix For: 2.0.0
>
>
> Build-in functions will be executed twice as it will be executed in resource_negotiator stage.
> I use function gp_elog() to make a demo. Function gp_elog() permit superuser to insert elog information into pg_log.
> {code}
> select gp_elog('!!!!!!!!!!again test !!!!!!');
> {code}
> When I vim the pg_log file, I find that the log information display twice.
> 2015-11-27 16:35:15.912111 CST,"intern","ff",p40030,th-1593601580,"[local]",,2015-11-25 18:17:21 CST,1080,con25,cmd42,seg-10000,,,x1080,sx1,"LOG","XX100","!!!!!!!!!!again test !!!!!!",,,,,,,0,,,,
> 2015-11-27 16:35:45.985348 CST,"intern","ff",p40030,th-1593601580,"[local]",,2015-11-25 18:17:21 CST,1080,con25,cmd42,seg-10000,,,x1080,sx1,"LOG","XX100","!!!!!!!!!!again test !!!!!!",,,,,,,0,,,,
> When I use lldb to debug and set breakpoint in function gp_elog. I find gp_elog is executed twice. And I put the bt information for the two times calling below, and you will find  it was exectuted in the resource_negotiator stage when it  should not be actually executed. 
> The first calling for gp_elog
> {code}
> * thread #1: tid = 0xe078b, 0x0056ca0d postgres`gp_elog(fcinfo=0xbfffd6bc) + 17 at elog.c:4130, queue = 'com.apple.main-thread', stop reason = breakpoint 1.1
>   * frame #0: 0x0056ca0d postgres`gp_elog(fcinfo=0xbfffd6bc) + 17 at elog.c:4130
>     frame #1: 0x00294ab8 postgres`ExecMakeFunctionResult(fcache=0x049237c0, econtext=0x04923c58, isNull=0xbfffdb0b, isDone=0x00000000) + 1730 at execQual.c:1749
>     frame #2: 0x002957e1 postgres`ExecEvalFunc(fcache=0x049237c0, econtext=0x04923c58, isNull=0xbfffdb0b, isDone=0x00000000) + 104 at execQual.c:2197
>     frame #3: 0x0029a3dd postgres`ExecEvalExprSwitchContext(expression=0x049237c0, econtext=0x04923c58, isNull=0xbfffdb0b, isDone=0x00000000) + 58 at execQual.c:4426
>     frame #4: 0x003db70a postgres`evaluate_expr(expr=0x04921f14, result_type=2278) + 111 at clauses.c:3354
>     frame #5: 0x003dac9a postgres`evaluate_function(funcid=5044, result_type=2278, args=0x04921e8c, func_tuple=0x040e84d0, context=0xbfffe598) + 388 at clauses.c:2960
>     frame #6: 0x003daa1e postgres`simplify_function(funcid=5044, result_type=2278, args=0x04921e8c, allow_inline='\x01', context=0xbfffe598) + 208 at clauses.c:2816
>     frame #7: 0x003d8a88 postgres`eval_const_expressions_mutator(node=0x04921b18, context=0xbfffe598) + 757 at clauses.c:1757
>     frame #8: 0x003dd606 postgres`expression_tree_mutator(node=0x04921adc, mutator=0x003d8793, context=0xbfffe598) + 7705 at clauses.c:3922
>     frame #9: 0x003da4b8 postgres`eval_const_expressions_mutator(node=0x04921adc, context=0xbfffe598) + 7461 at clauses.c:2519
>     frame #10: 0x003dd6d4 postgres`expression_tree_mutator(node=0x04921c40, mutator=0x003d8793, context=0xbfffe598) + 7911 at clauses.c:3958
>     frame #11: 0x003da4b8 postgres`eval_const_expressions_mutator(node=0x04921c40, context=0xbfffe598) + 7461 at clauses.c:2519
>     frame #12: 0x003d8742 postgres`eval_const_expressions(root=0x04921c98, node=0x04921c40) + 92 at clauses.c:1643
>     frame #13: 0x003b6ee5 postgres`preprocess_expression(root=0x04921c98, expr=0x04921c40, kind=1) + 143 at planner.c:1117
>     frame #14: 0x003b690d postgres`subquery_planner(glob=0x050310e8, parse=0x04921a40, parent_root=0x00000000, tuple_fraction=0, subroot=0xbfffe698, config=0x05030aa0) + 896 at planner.c:857
>     frame #15: 0x003b60d1 postgres`standard_planner(parse=0x04921a40, cursorOptions=0, boundParams=0x00000000) + 494 at planner.c:587
>     frame #16: 0x003b5df4 postgres`resource_negotiator(parse=0x05030ee8, cursorOptions=0, boundParams=0x00000000, resourceLife=QRL_ONCE, result=0xbfffe7b4) + 79 at planner.c:476
>     frame #17: 0x003b566b postgres`planner(parse=0x05030ee8, cursorOptions=0, boundParams=0x00000000, resourceLife=QRL_ONCE) + 466 at planner.c:303
>     frame #18: 0x0046c773 postgres`pg_plan_query(querytree=0x05030ee8, boundParams=0x00000000, resource_life=QRL_ONCE) + 86 at postgres.c:816
>     frame #19: 0x0046c89e postgres`pg_plan_queries(querytrees=0x05031654, boundParams=0x00000000, needSnapshot='\0', resource_life=QRL_ONCE) + 131 at postgres.c:889
>     frame #20: 0x0046dfc0 postgres`exec_simple_query(query_string=0x0503022c, seqServerHost=0x00000000, seqServerPort=-1) + 1357 at postgres.c:1647
>     frame #21: 0x00473bcc postgres`PostgresMain(argc=4, argv=0x05005d28, username=0x05005c48) + 7964 at postgres.c:4691
>     frame #22: 0x0041072d postgres`BackendRun(port=0x0431bc80) + 1008 at postmaster.c:5844
>     frame #23: 0x0040fac7 postgres`BackendStartup(port=0x0431bc80) + 381 at postmaster.c:5437
>     frame #24: 0x00409259 postgres`ServerLoop + 1111 at postmaster.c:2139
>     frame #25: 0x00407fe6 postgres`PostmasterMain(argc=9, argv=0x04319560) + 5127 at postmaster.c:1431
>     frame #26: 0x0031f553 postgres`main(argc=9, argv=0x04319560) + 1007 at main.c:226
>     frame #27: 0x00001fad postgres`_start + 212
>     frame #28: 0x00001ed8 postgres`start + 40
> {code}
> The second calling for gp_elog
> {code}
> thread #1: tid = 0xe078b, 0x0056ca0d postgres`gp_elog(fcinfo=0xbfffd76c) + 17 at elog.c:4130, queue = 'com.apple.main-thread', stop reason = breakpoint 1.1
>   * frame #0: 0x0056ca0d postgres`gp_elog(fcinfo=0xbfffd76c) + 17 at elog.c:4130
>     frame #1: 0x00294ab8 postgres`ExecMakeFunctionResult(fcache=0x0491f3c0, econtext=0x0491f858, isNull=0xbfffdbbb, isDone=0x00000000) + 1730 at execQual.c:1749
>     frame #2: 0x002957e1 postgres`ExecEvalFunc(fcache=0x0491f3c0, econtext=0x0491f858, isNull=0xbfffdbbb, isDone=0x00000000) + 104 at execQual.c:2197
>     frame #3: 0x0029a3dd postgres`ExecEvalExprSwitchContext(expression=0x0491f3c0, econtext=0x0491f858, isNull=0xbfffdbbb, isDone=0x00000000) + 58 at execQual.c:4426
>     frame #4: 0x003db70a postgres`evaluate_expr(expr=0x05035954, result_type=2278) + 111 at clauses.c:3354
>     frame #5: 0x003dac9a postgres`evaluate_function(funcid=5044, result_type=2278, args=0x05035928, func_tuple=0x040e84d0, context=0xbfffe6a8) + 388 at clauses.c:2960
>     frame #6: 0x003daa1e postgres`simplify_function(funcid=5044, result_type=2278, args=0x05035928, allow_inline='\x01', context=0xbfffe6a8) + 208 at clauses.c:2816
>     frame #7: 0x003d8a88 postgres`eval_const_expressions_mutator(node=0x0503535c, context=0xbfffe6a8) + 757 at clauses.c:1757
>     frame #8: 0x003dd606 postgres`expression_tree_mutator(node=0x05035320, mutator=0x003d8793, context=0xbfffe6a8) + 7705 at clauses.c:3922
>     frame #9: 0x003da4b8 postgres`eval_const_expressions_mutator(node=0x05035320, context=0xbfffe6a8) + 7461 at clauses.c:2519
>     frame #10: 0x003dd6d4 postgres`expression_tree_mutator(node=0x050352f4, mutator=0x003d8793, context=0xbfffe6a8) + 7911 at clauses.c:3958
>     frame #11: 0x003da4b8 postgres`eval_const_expressions_mutator(node=0x050352f4, context=0xbfffe6a8) + 7461 at clauses.c:2519
>     frame #12: 0x003ddb92 postgres`query_tree_mutator(query=0x05035758, mutator=0x003d8793, context=0xbfffe6a8, flags=0) + 222 at clauses.c:4066
>     frame #13: 0x003de4b0 postgres`query_or_expression_tree_mutator(node=0x0503521c, mutator=0x003d8793, context=0xbfffe6a8, flags=0) + 56 at clauses.c:4313
>     frame #14: 0x003d8674 postgres`fold_constants(q=0x0503521c, boundParams=0x00000000, max_size=102400) + 113 at clauses.c:1550
>     frame #15: 0x003cf449 postgres`preprocess_query_optimizer(query=0x0503521c, boundParams=0x00000000) + 52 at transform.c:49
>     frame #16: 0x003b5455 postgres`optimize_query(parse=0x05030ee8, boundParams=0x00000000) + 42 at planner.c:247
>     frame #17: 0x003b58d2 postgres`planner(parse=0x05030ee8, cursorOptions=0, boundParams=0x00000000, resourceLife=QRL_ONCE) + 1081 at planner.c:356
>     frame #18: 0x0046c773 postgres`pg_plan_query(querytree=0x05030ee8, boundParams=0x00000000, resource_life=QRL_ONCE) + 86 at postgres.c:816
>     frame #19: 0x0046c89e postgres`pg_plan_queries(querytrees=0x05031654, boundParams=0x00000000, needSnapshot='\0', resource_life=QRL_ONCE) + 131 at postgres.c:889
>     frame #20: 0x0046dfc0 postgres`exec_simple_query(query_string=0x0503022c, seqServerHost=0x00000000, seqServerPort=-1) + 1357 at postgres.c:1647
>     frame #21: 0x00473bcc postgres`PostgresMain(argc=4, argv=0x05005d28, username=0x05005c48) + 7964 at postgres.c:4691
>     frame #22: 0x0041072d postgres`BackendRun(port=0x0431bc80) + 1008 at postmaster.c:5844
>     frame #23: 0x0040fac7 postgres`BackendStartup(port=0x0431bc80) + 381 at postmaster.c:5437
>     frame #24: 0x00409259 postgres`ServerLoop + 1111 at postmaster.c:2139
>     frame #25: 0x00407fe6 postgres`PostmasterMain(argc=9, argv=0x04319560) + 5127 at postmaster.c:1431
>     frame #26: 0x0031f553 postgres`main(argc=9, argv=0x04319560) + 1007 at main.c:226
>     frame #27: 0x00001fad postgres`_start + 212
>     frame #28: 0x00001ed8 postgres`start + 40
> {code}



--
This message was sent by Atlassian JIRA
(v6.3.4#6332)