[
https://issues.apache.org/jira/browse/TRAFODION-3106?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
He Zhenxing updated TRAFODION-3106:
-----------------------------------
Description:
create/drop table is slow, usually takes seconds to finish, this problem is
specially severe for tables with blob columns, which will slow down linearly
with the number of blob columns (cqd traf_blob_as_varchar 'off'), which would
make it unusable in case tables need to be created and dropped frequently.
For each blob column, two associated tables will be create, so the time for
creating tables with blob columns will increase linearly. In a local testing
environment, creating a table with 5 blob columns takes 75 seconds, drop the
table without any data takes more than 90 seconds.
For create table, about half of the time are consumed by calls to
createHbaseTable(), and another 30% are consumed by calls to
getSeabaseUserTableDesc(), for drop table, most of the time are spend on the
calls to getSeabaseUserTableDesc() and ENDTRANSACTION_ERR().
For simple table creation, most of the time is spent on createHbaseTable()
function call, while for table dropping, most of the time is spent on
ENDTRANSACTION_ERR(), which I assume is where the HBASE tables are actually
dropped. Please also note that for the first create/drop operation, time will
also be spent on starting compiler processes.
Here is the log for simple create (create table t1 (a int)):
{quote}2018-06-25 05:52:29,076, INFO, SQL.EXE, Node Number: 0, CPU: 0, PIN:
24516, Process Name: $Z000K0G,,,SqlCmd::do_execute entry
2018-06-25 05:52:29,151, INFO, SQL.EXE, Node Number: 0, CPU: 0, PIN: 24516,
Process Name: $Z000K0G,,,CmpSeabaseDDL::createSeabaseTable entry
2018-06-25 05:52:29,151, INFO, SQL.EXE, Node Number: 0, CPU: 0, PIN: 24516,
Process Name: $Z000K0G,,,CmpSeabaseDDL::createSeabaseTable2 entry
2018-06-25 05:52:29,354, INFO, SQL.EXE, Node Number: 0, CPU: 0, PIN: 24516,
Process Name: $Z000K0G,,,CmpSeabaseDDL::updateSeabaseMDTable entry
2018-06-25 05:52:29,765, INFO, SQL.EXE, Node Number: 0, CPU: 0, PIN: 24516,
Process Name: $Z000K0G,,,CmpSeabaseDDL::updateSeabaseMDTable exit
2018-06-25 05:52:29,765, INFO, SQL.EXE, Node Number: 0, CPU: 0, PIN: 24516,
Process Name: $Z000K0G,,,createHbaseTable entry
2018-06-25 05:52:32,051, INFO, SQL.EXE, Node Number: 0, CPU: 0, PIN: 24516,
Process Name: $Z000K0G,,,createHbaseTable exit
2018-06-25 05:52:32,105, INFO, SQL.EXE, Node Number: 0, CPU: 0, PIN: 24516,
Process Name: $Z000K0G,,,CmpSeabaseDDL::createSeabaseTable2 exit
2018-06-25 05:52:32,105, INFO, SQL.EXE, Node Number: 0, CPU: 0, PIN: 24516,
Process Name: $Z000K0G,,,CmpSeabaseDDL::updateObjectRedefTime entry
2018-06-25 05:52:32,153, INFO, SQL.EXE, Node Number: 0, CPU: 0, PIN: 24516,
Process Name: $Z000K0G,,,CmpSeabaseDDL::updateObjectRedefTime entry
2018-06-25 05:52:32,153, INFO, SQL.EXE, Node Number: 0, CPU: 0, PIN: 24516,
Process Name: $Z000K0G,,,CmpSeabaseDDL::createSeabaseTable exit
2018-06-25 05:52:32,179, INFO, SQL.EXE, Node Number: 0, CPU: 0, PIN: 24516,
Process Name: $Z000K0G,,,before ENDTRANSACTION_ERR
2018-06-25 05:52:32,192, INFO, SQL.EXE, Node Number: 0, CPU: 0, PIN: 24516,
Process Name: $Z000K0G,,,after ENDTRANSACTION_ERR
2018-06-25 05:52:32,194, INFO, SQL.EXE, Node Number: 0, CPU: 0, PIN: 24516,
Process Name: $Z000K0G,,,SqlCmd::do_execute exit
{quote}
As we can see total time consume is about 3.1 seconds, and about 2.3 is spent
on createHbaseTable.
Here is the log for dropping the simple table:
{quote}2018-06-25 05:52:40,007, INFO, SQL.EXE, Node Number: 0, CPU: 0, PIN:
24516, Process Name: $Z000K0G,,,SqlCmd::do_execute entry
2018-06-25 05:52:40,062, INFO, SQL.EXE, Node Number: 0, CPU: 0, PIN: 24516,
Process Name: $Z000K0G,,,CmpSeabaseDDL::dropSeabaseTable entry
2018-06-25 05:52:40,062, INFO, SQL.EXE, Node Number: 0, CPU: 0, PIN: 24516,
Process Name: $Z000K0G,,,CmpSeabaseDDL::dropSeabaseTable2 entry
2018-06-25 05:52:40,226, INFO, SQL.EXE, Node Number: 0, CPU: 0, PIN: 24516,
Process Name: $Z000K0G,,,getSeabaseUserTableDesc entry
2018-06-25 05:52:41,359, INFO, SQL.EXE, Node Number: 0, CPU: 0, PIN: 24516,
Process Name: $Z000K0G,,,getSeabaseUserTableDesc exit
2018-06-25 05:52:42,057, INFO, SQL.EXE, Node Number: 0, CPU: 0, PIN: 24516,
Process Name: $Z000K0G,,,CmpSeabaseDDL::dropSeabaseObject entry
2018-06-25 05:52:42,569, INFO, SQL.EXE, Node Number: 0, CPU: 0, PIN: 24516,
Process Name: $Z000K0G,,,CmpSeabaseDDL::dropHbaseTable entry
2018-06-25 05:52:42,588, INFO, SQL.EXE, Node Number: 0, CPU: 0, PIN: 24516,
Process Name: $Z000K0G,,,CmpSeabaseDDL::dropHbaseTable exit
2018-06-25 05:52:42,588, INFO, SQL.EXE, Node Number: 0, CPU: 0, PIN: 24516,
Process Name: $Z000K0G,,,CmpSeabaseDDL::dropSeabaseObject exit
2018-06-25 05:52:42,600, INFO, SQL.EXE, Node Number: 0, CPU: 0, PIN: 24516,
Process Name: $Z000K0G,,,CmpSeabaseDDL::dropSeabaseTable2 exit
2018-06-25 05:52:42,600, INFO, SQL.EXE, Node Number: 0, CPU: 0, PIN: 24516,
Process Name: $Z000K0G,,,CmpSeabaseDDL::dropSeabaseTable exit
2018-06-25 05:52:42,629, INFO, SQL.EXE, Node Number: 0, CPU: 0, PIN: 24516,
Process Name: $Z000K0G,,,before ENDTRANSACTION_ERR
2018-06-25 05:52:46,091, INFO, SQL.EXE, Node Number: 0, CPU: 0, PIN: 24516,
Process Name: $Z000K0G,,,after ENDTRANSACTION_ERR
2018-06-25 05:52:46,163, INFO, SQL.EXE, Node Number: 0, CPU: 0, PIN: 24516,
Process Name: $Z000K0G,,,SqlCmd::do_execute exit
{quote}
For dropping table, most of the time is consumed by ENDTRANSACTION_ERR (3.5
seconds out of 6.1 seconds), which I assume is where the HBase tables are
actually dropped. CmpSeabaseDDL::getSeabaseUserTableDesc also takes 1.1 seconds.
was:
create/drop table is slow, usually takes seconds to finish, this problem is
specially severe for tables with blob columns, which will slow down linearly
with the number of blob columns (cqd traf_blob_as_varchar 'off'), which would
make it unusable in case tables need to be created and dropped frequently.
For each blob column, two associated tables will be create, so the time for
creating tables with blob columns will increase linearly. In a local testing
environment, creating a table with 5 blob columns takes 75 seconds, drop the
table without any data takes more than 90 seconds.
For create table, about half of the time are consumed by calls to
createHbaseTable(), and another 30% are consumed by calls to
getSeabaseUserTableDesc(), for drop table, most of the time are spend on the
calls to getSeabaseUserTableDesc() and ENDTRANSACTION_ERR().
> create/drop table painfully slow with blob columns
> --------------------------------------------------
>
> Key: TRAFODION-3106
> URL: https://issues.apache.org/jira/browse/TRAFODION-3106
> Project: Apache Trafodion
> Issue Type: Improvement
> Components: sql-exe
> Affects Versions: 2.4
> Environment: CentOS 6.9
> Reporter: He Zhenxing
> Priority: Major
>
> create/drop table is slow, usually takes seconds to finish, this problem is
> specially severe for tables with blob columns, which will slow down linearly
> with the number of blob columns (cqd traf_blob_as_varchar 'off'), which would
> make it unusable in case tables need to be created and dropped frequently.
> For each blob column, two associated tables will be create, so the time for
> creating tables with blob columns will increase linearly. In a local testing
> environment, creating a table with 5 blob columns takes 75 seconds, drop the
> table without any data takes more than 90 seconds.
> For create table, about half of the time are consumed by calls to
> createHbaseTable(), and another 30% are consumed by calls to
> getSeabaseUserTableDesc(), for drop table, most of the time are spend on the
> calls to getSeabaseUserTableDesc() and ENDTRANSACTION_ERR().
>
> For simple table creation, most of the time is spent on createHbaseTable()
> function call, while for table dropping, most of the time is spent on
> ENDTRANSACTION_ERR(), which I assume is where the HBASE tables are actually
> dropped. Please also note that for the first create/drop operation, time will
> also be spent on starting compiler processes.
>
> Here is the log for simple create (create table t1 (a int)):
>
> {quote}2018-06-25 05:52:29,076, INFO, SQL.EXE, Node Number: 0, CPU: 0, PIN:
> 24516, Process Name: $Z000K0G,,,SqlCmd::do_execute entry
> 2018-06-25 05:52:29,151, INFO, SQL.EXE, Node Number: 0, CPU: 0, PIN: 24516,
> Process Name: $Z000K0G,,,CmpSeabaseDDL::createSeabaseTable entry
> 2018-06-25 05:52:29,151, INFO, SQL.EXE, Node Number: 0, CPU: 0, PIN: 24516,
> Process Name: $Z000K0G,,,CmpSeabaseDDL::createSeabaseTable2 entry
> 2018-06-25 05:52:29,354, INFO, SQL.EXE, Node Number: 0, CPU: 0, PIN: 24516,
> Process Name: $Z000K0G,,,CmpSeabaseDDL::updateSeabaseMDTable entry
> 2018-06-25 05:52:29,765, INFO, SQL.EXE, Node Number: 0, CPU: 0, PIN: 24516,
> Process Name: $Z000K0G,,,CmpSeabaseDDL::updateSeabaseMDTable exit
> 2018-06-25 05:52:29,765, INFO, SQL.EXE, Node Number: 0, CPU: 0, PIN: 24516,
> Process Name: $Z000K0G,,,createHbaseTable entry
> 2018-06-25 05:52:32,051, INFO, SQL.EXE, Node Number: 0, CPU: 0, PIN: 24516,
> Process Name: $Z000K0G,,,createHbaseTable exit
> 2018-06-25 05:52:32,105, INFO, SQL.EXE, Node Number: 0, CPU: 0, PIN: 24516,
> Process Name: $Z000K0G,,,CmpSeabaseDDL::createSeabaseTable2 exit
> 2018-06-25 05:52:32,105, INFO, SQL.EXE, Node Number: 0, CPU: 0, PIN: 24516,
> Process Name: $Z000K0G,,,CmpSeabaseDDL::updateObjectRedefTime entry
> 2018-06-25 05:52:32,153, INFO, SQL.EXE, Node Number: 0, CPU: 0, PIN: 24516,
> Process Name: $Z000K0G,,,CmpSeabaseDDL::updateObjectRedefTime entry
> 2018-06-25 05:52:32,153, INFO, SQL.EXE, Node Number: 0, CPU: 0, PIN: 24516,
> Process Name: $Z000K0G,,,CmpSeabaseDDL::createSeabaseTable exit
> 2018-06-25 05:52:32,179, INFO, SQL.EXE, Node Number: 0, CPU: 0, PIN: 24516,
> Process Name: $Z000K0G,,,before ENDTRANSACTION_ERR
> 2018-06-25 05:52:32,192, INFO, SQL.EXE, Node Number: 0, CPU: 0, PIN: 24516,
> Process Name: $Z000K0G,,,after ENDTRANSACTION_ERR
> 2018-06-25 05:52:32,194, INFO, SQL.EXE, Node Number: 0, CPU: 0, PIN: 24516,
> Process Name: $Z000K0G,,,SqlCmd::do_execute exit
> {quote}
>
> As we can see total time consume is about 3.1 seconds, and about 2.3 is spent
> on createHbaseTable.
>
> Here is the log for dropping the simple table:
>
> {quote}2018-06-25 05:52:40,007, INFO, SQL.EXE, Node Number: 0, CPU: 0, PIN:
> 24516, Process Name: $Z000K0G,,,SqlCmd::do_execute entry
> 2018-06-25 05:52:40,062, INFO, SQL.EXE, Node Number: 0, CPU: 0, PIN: 24516,
> Process Name: $Z000K0G,,,CmpSeabaseDDL::dropSeabaseTable entry
> 2018-06-25 05:52:40,062, INFO, SQL.EXE, Node Number: 0, CPU: 0, PIN: 24516,
> Process Name: $Z000K0G,,,CmpSeabaseDDL::dropSeabaseTable2 entry
> 2018-06-25 05:52:40,226, INFO, SQL.EXE, Node Number: 0, CPU: 0, PIN: 24516,
> Process Name: $Z000K0G,,,getSeabaseUserTableDesc entry
> 2018-06-25 05:52:41,359, INFO, SQL.EXE, Node Number: 0, CPU: 0, PIN: 24516,
> Process Name: $Z000K0G,,,getSeabaseUserTableDesc exit
> 2018-06-25 05:52:42,057, INFO, SQL.EXE, Node Number: 0, CPU: 0, PIN: 24516,
> Process Name: $Z000K0G,,,CmpSeabaseDDL::dropSeabaseObject entry
> 2018-06-25 05:52:42,569, INFO, SQL.EXE, Node Number: 0, CPU: 0, PIN: 24516,
> Process Name: $Z000K0G,,,CmpSeabaseDDL::dropHbaseTable entry
> 2018-06-25 05:52:42,588, INFO, SQL.EXE, Node Number: 0, CPU: 0, PIN: 24516,
> Process Name: $Z000K0G,,,CmpSeabaseDDL::dropHbaseTable exit
> 2018-06-25 05:52:42,588, INFO, SQL.EXE, Node Number: 0, CPU: 0, PIN: 24516,
> Process Name: $Z000K0G,,,CmpSeabaseDDL::dropSeabaseObject exit
> 2018-06-25 05:52:42,600, INFO, SQL.EXE, Node Number: 0, CPU: 0, PIN: 24516,
> Process Name: $Z000K0G,,,CmpSeabaseDDL::dropSeabaseTable2 exit
> 2018-06-25 05:52:42,600, INFO, SQL.EXE, Node Number: 0, CPU: 0, PIN: 24516,
> Process Name: $Z000K0G,,,CmpSeabaseDDL::dropSeabaseTable exit
> 2018-06-25 05:52:42,629, INFO, SQL.EXE, Node Number: 0, CPU: 0, PIN: 24516,
> Process Name: $Z000K0G,,,before ENDTRANSACTION_ERR
> 2018-06-25 05:52:46,091, INFO, SQL.EXE, Node Number: 0, CPU: 0, PIN: 24516,
> Process Name: $Z000K0G,,,after ENDTRANSACTION_ERR
> 2018-06-25 05:52:46,163, INFO, SQL.EXE, Node Number: 0, CPU: 0, PIN: 24516,
> Process Name: $Z000K0G,,,SqlCmd::do_execute exit
> {quote}
>
> For dropping table, most of the time is consumed by ENDTRANSACTION_ERR (3.5
> seconds out of 6.1 seconds), which I assume is where the HBase tables are
> actually dropped. CmpSeabaseDDL::getSeabaseUserTableDesc also takes 1.1
> seconds.
--
This message was sent by Atlassian JIRA
(v7.6.3#76005)
