[MCOL-4957] Functions on TIMESTAMP columns in projection, e.g. year(timestamp_col) slows down SELECT 50x. - Jira

Details

Type: Bug
Status: Closed (View Workflow)
Priority: Major
Resolution: Fixed
Affects Version/s: 6.2.2
Fix Version/s: 6.3.1
Component/s: ExeMgr, PrimProc
Labels:
None

Sprint:
2021-16, 2021-17

Description

Testing Uber's taxi rides dataset [1] [2] I found out we have a serious drawback in time-related functions. Here is the query that I run with the develop-6 HEAD twice to get the timings.

MariaDB [test]> SELECT      passenger_count,      year(pickup_datetime) AS year,      count(*) FROM trips GROUP BY      passenger_count,      year;

140 rows in set (5 min 19.003 sec)

MariaDB [test]> SELECT      passenger_count,      year(pickup_datetime) AS year,      count(*) FROM trips GROUP BY      passenger_count,      year;

140 rows in set (5 min 19.246 sec)

CPU cores were fully utilized but poor man's profiling technic tells me OS spinlocks burn CPU. Here are two related callstacks:

#0  0x00007f1cee7d3d1c in __tz_convert (timer=1434735776, use_localtime=use_localtime@entry=1, tp=<optimized out>, tp@entry=0x7f1cc81b7cb0) at tzset.c:592

#1  0x00007f1cee7d1484 in __localtime_r (t=t@entry=0x7f1cc81b7c98, tp=tp@entry=0x7f1cc81b7cb0) at localtime.c:30

#2  0x00007f1cef6d71f8 in dataconvert::gmtSecToMySQLTime (timeZone="SYSTEM", time=<synthetic pointer>..., seconds=1434735776) at /data/mdb-server/storage/columnstore/columnstore/utils/dataconvert/dataconvert.h:527

#3  funcexp::Func_year::getIntVal (this=0x7f1489658400, row=..., parm=..., isNull=<optimized out>, op_ct=...) at /data/mdb-server/storage/columnstore/columnstore/utils/funcexp/func_year.cpp:69

#4  0x00007f1cef647f99 in funcexp::FuncExp::evaluate (this=<optimized out>, row=..., expression=std::vector of length 1, capacity 1 = {...}) at /usr/include/boost/smart_ptr/shared_ptr.hpp:732

#5  0x00007f1cef655cda in funcexp::FuncExpWrapper::evaluate (this=0x7f148bb24a00, r=r@entry=0x7f145ee578b0) at /data/mdb-server/storage/columnstore/columnstore/utils/funcexp/funcexpwrapper.cpp:122

#6  0x0000560cb87168e7 in primitiveprocessor::BatchPrimitiveProcessor::execute (this=0x7f145ee02900) at /usr/include/boost/smart_ptr/scoped_ptr.hpp:103

#7  0x0000560cb87170c1 in primitiveprocessor::BatchPrimitiveProcessor::operator() (this=0x7f145ee02900) at /data/mdb-server/storage/columnstore/columnstore/primitives/primproc/batchprimitiveprocessor.cpp:2244

#8  0x0000560cb872c065 in primitiveprocessor::BPPSeeder::operator() (this=0x7f147c1c1080) at /usr/include/boost/smart_ptr/shared_ptr.hpp:726

#9  0x00007f1ceecdaac9 in threadpool::PriorityThreadPool::threadFcn (this=0x7f1cebf29000, preferredQueue=threadpool::PriorityThreadPool::LOW) at /usr/include/boost/smart_ptr/shared_ptr.hpp:726

#10 0x00007f1cef05e43b in ?? () from /lib/x86_64-linux-gnu/libboost_thread.so.1.71.0

#11 0x00007f1ceed50609 in start_thread (arg=<optimized out>) at pthread_create.c:477

#12 0x00007f1cee820293 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

Thread 38 (Thread 0x7f1cd91de700 (LWP 15206)):

#0  __pthread_mutex_unlock_usercnt (decr=1, mutex=0x7f1489658470) at pthread_mutex_unlock.c:58

#1  __GI___pthread_mutex_unlock (mutex=0x7f1489658470) at pthread_mutex_unlock.c:357

#2  0x00007f1cef6d70f1 in __gthread_mutex_unlock (__mutex=0x7f1489658470) at /usr/include/x86_64-linux-gnu/c++/9/bits/gthr-default.h:779

#3  std::mutex::unlock (this=0x7f1489658470) at /usr/include/c++/9/bits/std_mutex.h:118

#4  std::unique_lock<std::mutex>::unlock (this=<synthetic pointer>, this=<synthetic pointer>) at /usr/include/c++/9/bits/unique_lock.h:197

#5  std::unique_lock<std::mutex>::~unique_lock (this=<synthetic pointer>, __in_chrg=<optimized out>) at /usr/include/c++/9/bits/unique_lock.h:106

#6  funcexp::Func::timeZone[abi:cxx11]() const (this=0x7f1489658400) at /data/mdb-server/storage/columnstore/columnstore/utils/funcexp/functor.h:78

#7  funcexp::Func_year::getIntVal (this=0x7f1489658400, row=..., parm=..., isNull=<optimized out>, op_ct=...) at /data/mdb-server/storage/columnstore/columnstore/utils/funcexp/func_year.cpp:69

#8  0x00007f1cef647f99 in funcexp::FuncExp::evaluate (this=<optimized out>, row=..., expression=std::vector of length 1, capacity 1 = {...}) at /usr/include/boost/smart_ptr/shared_ptr.hpp:732

#9  0x00007f1cef655cda in funcexp::FuncExpWrapper::evaluate (this=0x7f148bb24640, r=r@entry=0x7f14666570f0) at /data/mdb-server/storage/columnstore/columnstore/utils/funcexp/funcexpwrapper.cpp:122

#10 0x0000560cb87168e7 in primitiveprocessor::BatchPrimitiveProcessor::execute (this=0x7f1466602140) at /usr/include/boost/smart_ptr/scoped_ptr.hpp:103

#11 0x0000560cb87170c1 in primitiveprocessor::BatchPrimitiveProcessor::operator() (this=0x7f1466602140) at /data/mdb-server/storage/columnstore/columnstore/primitives/primproc/batchprimitiveprocessor.cpp:2244

#12 0x0000560cb872c065 in primitiveprocessor::BPPSeeder::operator() (this=0x7f147c1c0540) at /usr/include/boost/smart_ptr/shared_ptr.hpp:726

--Type <RET> for more, q to quit, c to continue without paging--

#13 0x00007f1ceecdaac9 in threadpool::PriorityThreadPool::threadFcn (this=0x7f1cebf29000, preferredQueue=threadpool::PriorityThreadPool::HIGH) at /usr/include/boost/smart_ptr/shared_ptr.hpp:726

#14 0x00007f1cef05e43b in ?? () from /lib/x86_64-linux-gnu/libboost_thread.so.1.71.0

#15 0x00007f1ceed50609 in start_thread (arg=<optimized out>) at pthread_create.c:477

#16 0x00007f1cee820293 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

With a hacky patch [3] that removes both localtime_r() calls and the mutex I was able to reduce the timings to this. First is a cold cache run:

 MariaDB [test]> SELECT      passenger_count,      year(pickup_datetime) AS year,      count(*) FROM trips GROUP BY      passenger_count,      year;

50 rows in set (43.224 sec)

MariaDB [test]> SELECT      passenger_count,      year(pickup_datetime) AS year,      count(*) FROM trips GROUP BY      passenger_count,      year;

50 rows in set (6.454 sec)

*The suggested solution is to reduce a number of localtime_r() calls down to one and remove mutex in the Func class. *

1. https://tech.marksblogg.com/billion-nyc-taxi-rides-redshift.html
2. https://clemenswinter.com/2018/07/09/how-to-analyze-billions-of-records-per-second-on-a-single-desktop-pc/2/
3.

diff --git a/utils/dataconvert/dataconvert.h b/utils/dataconvert/dataconvert.h

index 123c90f65..0916d8057 100644

--- a/utils/dataconvert/dataconvert.h

+++ b/utils/dataconvert/dataconvert.h

@@ -524,7 +524,7 @@ inline void gmtSecToMySQLTime(int64_t seconds, MySQLTime& time,

         struct tm tmp_tm;

         time_t tmp_t = (time_t)seconds;

-        localtime_r(&tmp_t, &tmp_tm);

+        //localtime_r(&tmp_t, &tmp_tm);

         time.second_part = 0;

         time.year = (int) ((tmp_tm.tm_year + 1900) % 10000);

         time.month = (int) tmp_tm.tm_mon + 1;

@@ -677,7 +677,7 @@ inline int64_t mySQLTimeToGmtSec(const MySQLTime& time,

         int shift = 0;

         struct tm* l_time, tm_tmp;

         int64_t diff;

-        localtime_r(&tmp_t, &tm_tmp);

+        //localtime_r(&tmp_t, &tm_tmp);

         // Get the system timezone offset at 0 seconds since epoch

         int64_t my_time_zone = tm_tmp.tm_gmtoff;

         int day = time.day;

@@ -694,7 +694,7 @@ inline int64_t mySQLTimeToGmtSec(const MySQLTime& time,

         if (!isValid)

             return 0;

-        localtime_r(&tmp_t, &tm_tmp);

+        //localtime_r(&tmp_t, &tm_tmp);

         l_time = &tm_tmp;

         for (loop = 0; loop < 2 && (time.hour != (uint32_t) l_time->tm_hour ||

@@ -712,7 +712,7 @@ inline int64_t mySQLTimeToGmtSec(const MySQLTime& time,

                     (int64_t) (60 * ((int) time.minute - (int) l_time->tm_min)) +

                     (int64_t) ((int) time.second - (int) l_time->tm_sec));

             tmp_t += (time_t) diff;

-            localtime_r(&tmp_t, &tm_tmp);

+            //localtime_r(&tmp_t, &tm_tmp);

             l_time = &tm_tmp;

diff --git a/utils/funcexp/functor.h b/utils/funcexp/functor.h

index 9027ab351..6e943adb6 100644

--- a/utils/funcexp/functor.h

+++ b/utils/funcexp/functor.h

@@ -75,12 +75,12 @@ public:

     const std::string timeZone() const

-        std::unique_lock<std::mutex> l(tzMutex);

+        //std::unique_lock<std::mutex> l(tzMutex);

         return fTimeZone;

     void timeZone(const std::string timeZone)

-        std::unique_lock<std::mutex> l(tzMutex);

+        //std::unique_lock<std::mutex> l(tzMutex);

         fTimeZone = timeZone;

root@ip-172-31-3-254:/data/mdb-server/storage/columnstore/columnstore# git --no-pager stash show -p

diff --git a/utils/dataconvert/dataconvert.h b/utils/dataconvert/dataconvert.h

index 123c90f65..0916d8057 100644

--- a/utils/dataconvert/dataconvert.h

+++ b/utils/dataconvert/dataconvert.h

@@ -524,7 +524,7 @@ inline void gmtSecToMySQLTime(int64_t seconds, MySQLTime& time,

         struct tm tmp_tm;

         time_t tmp_t = (time_t)seconds;

-        localtime_r(&tmp_t, &tmp_tm);

+        //localtime_r(&tmp_t, &tmp_tm);

         time.second_part = 0;

         time.year = (int) ((tmp_tm.tm_year + 1900) % 10000);

         time.month = (int) tmp_tm.tm_mon + 1;

@@ -677,7 +677,7 @@ inline int64_t mySQLTimeToGmtSec(const MySQLTime& time,

         int shift = 0;

         struct tm* l_time, tm_tmp;

         int64_t diff;

-        localtime_r(&tmp_t, &tm_tmp);

+        //localtime_r(&tmp_t, &tm_tmp);

         // Get the system timezone offset at 0 seconds since epoch

         int64_t my_time_zone = tm_tmp.tm_gmtoff;

         int day = time.day;

@@ -694,7 +694,7 @@ inline int64_t mySQLTimeToGmtSec(const MySQLTime& time,

         if (!isValid)

             return 0;

-        localtime_r(&tmp_t, &tm_tmp);

+        //localtime_r(&tmp_t, &tm_tmp);

         l_time = &tm_tmp;

         for (loop = 0; loop < 2 && (time.hour != (uint32_t) l_time->tm_hour ||

@@ -712,7 +712,7 @@ inline int64_t mySQLTimeToGmtSec(const MySQLTime& time,

                     (int64_t) (60 * ((int) time.minute - (int) l_time->tm_min)) +

                     (int64_t) ((int) time.second - (int) l_time->tm_sec));

             tmp_t += (time_t) diff;

-            localtime_r(&tmp_t, &tm_tmp);

+            //localtime_r(&tmp_t, &tm_tmp);

             l_time = &tm_tmp;

diff --git a/utils/funcexp/functor.h b/utils/funcexp/functor.h

index 9027ab351..6e943adb6 100644

--- a/utils/funcexp/functor.h

+++ b/utils/funcexp/functor.h

@@ -75,12 +75,12 @@ public:

     const std::string timeZone() const

-        std::unique_lock<std::mutex> l(tzMutex);

+        //std::unique_lock<std::mutex> l(tzMutex);

         return fTimeZone;

     void timeZone(const std::string timeZone)

-        std::unique_lock<std::mutex> l(tzMutex);

+        //std::unique_lock<std::mutex> l(tzMutex);

         fTimeZone = timeZone;

@@ -233,7 +233,7 @@ private:

     long double fLongDoubleNullVal;

     std::string fTimeZone;

-    mutable std::mutex tzMutex;

+    //mutable std::mutex tzMutex;

};

Attachments

Issue Links

relates to

MCOL-265 TIMESTAMP data type not supported

Closed

MCOL-3776 Follow up on vTpch22.sql hanging

Closed

Functions on TIMESTAMP columns in projection, e.g. year(timestamp_col) slows down SELECT 50x.

Details

Description

Attachments

Issue Links

Activity

People

Dates

Git Integration