Mostafa Mokhtar created IMPALA-7221: ---------------------------------------
Summary: While reading from object store S3/ADLS at fast rates +500MB/sec TypeArrayKlass::allocate_common becomes a CPU bottleneck Key: IMPALA-7221 URL: https://issues.apache.org/jira/browse/IMPALA-7221 Project: IMPALA Issue Type: Bug Components: Backend Affects Versions: Impala 2.8.0 Reporter: Mostafa Mokhtar >From Perf {code} Samples: 1M of event 'cpu-clock', Event count (approx.): 320058500000 Children Self Command Shared Object Symbol ◆ - 16.46% 0.04% impalad impalad [.] hdfsRead ▒ - 16.45% hdfsRead ▒ - 9.71% jni_NewByteArray ▒ 9.63% TypeArrayKlass::allocate_common ▒ 6.57% __memmove_ssse3_back ▒ + 9.72% 0.03% impalad libjvm.so [.] jni_NewByteArray ▒ + 9.67% 8.79% impalad libjvm.so [.] TypeArrayKlass::allocate_co▒ + 8.82% 0.00% impalad [unknown] [.] 0000000000000000 ▒ + 7.67% 0.04% impalad [kernel.kallsyms] [k] system_call_fastpath ▒ + 7.19% 7.02% impalad impalad [.] impala::ScalarColumnReader<▒ + 7.18% 6.55% impalad libc-2.17.so [.] __memmove_ssse3_back ▒ + 6.32% 0.00% impalad [unknown] [.] 0x00000000001a9458 ▒ + 6.07% 0.00% impalad [kernel.kallsyms] [k] do_softirq ▒ + 6.07% 0.00% impalad [kernel.kallsyms] [k] call_softirq ▒ + 6.05% 0.24% impalad [kernel.kallsyms] [k] __do_softirq ▒ + 5.98% 0.00% impalad [kernel.kallsyms] [k] xen_hvm_callback_vector ▒ + 5.98% 0.00% impalad [kernel.kallsyms] [k] xen_evtchn_do_upcall ▒ + 5.98% 0.00% impalad [kernel.kallsyms] [k] irq_exit ▒ + 5.81% 0.03% impalad [kernel.kallsyms] [k] net_rx_action ▒ {code} {code} #0 0x00007ffa3d78d69b in TypeArrayKlass::allocate_common(int, bool, Thread*) () from /usr/java/jdk1.8.0_121/jre/lib/amd64/server/libjvm.so #1 0x00007ffa3d3e22d2 in jni_NewByteArray () from /usr/java/jdk1.8.0_121/jre/lib/amd64/server/libjvm.so #2 0x00000000020ec13c in hdfsRead () #3 0x0000000001100948 in impala::io::ScanRange::Read(unsigned char*, long, long*, bool*) () #4 0x00000000010fa294 in impala::io::DiskIoMgr::ReadRange(impala::io::DiskIoMgr::DiskQueue*, impala::io::RequestContext*, impala::io::ScanRange*) () #5 0x00000000010fa3f4 in impala::io::DiskIoMgr::WorkLoop(impala::io::DiskIoMgr::DiskQueue*) () #6 0x0000000000d15193 in impala::Thread::SuperviseThread(std::string const&, std::string const&, boost::function<void ()>, impala::Promise<long>*) () #7 0x0000000000d158d4 in boost::detail::thread_data<boost::_bi::bind_t<void, void (*)(std::string const&, std::string const&, boost::function<void ()>, impala::Promise<long>*), boost::_bi::list4<boost::_bi::value<std::string>, boost::_bi::value<std::string>, boost::_bi::value<boost::function<void ()> >, boost::_bi::value<impala::Promise<long>*> > > >::run() () #8 0x00000000012919aa in thread_proxy () #9 0x00007ffa3b6a6e25 in start_thread () from /lib64/libpthread.so.0 #10 0x00007ffa3b3d0bad in clone () from /lib64/libc.so.6 {code} There is also log4j contention in the JVM due to writing error messages to impalad.ERRO like this {code} readDirect: FSDataInputStream#read error: UnsupportedOperationException: Byte-buffer read unsupported by input streamjava.lang.UnsupportedOperationException: Byte-buffer read unsupported by input stream at org.apache.hadoop.fs.FSDataInputStream.read(FSDataInputStream.java:150) readDirect: FSDataInputStream#read error: UnsupportedOperationException: Byte-buffer read unsupported by input streamjava.lang.UnsupportedOperationException: Byte-buffer read unsupported by input stream at org.apache.hadoop.fs.FSDataInputStream.read(FSDataInputStream.java:150) readDirect: FSDataInputStream#read error: UnsupportedOperationException: Byte-buffer read unsupported by input streamjava.lang.UnsupportedOperationException: Byte-buffer read unsupported by input stream {code} Stack {code} "Thread-66" #93 prio=5 os_prio=0 tid=0x0000000010220800 nid=0x3412 waiting for monitor entry [0x00007ff9a3609000] java.lang.Thread.State: BLOCKED (on object monitor) at org.apache.log4j.Category.callAppenders(Category.java:204) - waiting to lock <0x0000000080229658> (a org.apache.log4j.spi.RootLogger) at org.apache.log4j.Category.forcedLog(Category.java:391) at org.apache.log4j.Category.log(Category.java:856) at com.amazonaws.thirdparty.apache.logging.impl.Log4JLogger.warn(Log4JLogger.java:197) at com.amazonaws.services.s3.internal.S3AbortableInputStream.close(S3AbortableInputStream.java:163) at com.amazonaws.internal.SdkFilterInputStream.close(SdkFilterInputStream.java:89) at com.amazonaws.services.s3.model.S3ObjectInputStream.close(S3ObjectInputStream.java:128) at com.amazonaws.internal.SdkFilterInputStream.close(SdkFilterInputStream.java:89) at com.amazonaws.internal.SdkFilterInputStream.close(SdkFilterInputStream.java:89) at com.amazonaws.event.ProgressInputStream.close(ProgressInputStream.java:211) at com.amazonaws.internal.SdkFilterInputStream.close(SdkFilterInputStream.java:89) at com.amazonaws.util.IOUtils.closeQuietly(IOUtils.java:70) at com.amazonaws.services.s3.model.S3ObjectInputStream.abort(S3ObjectInputStream.java:91) at org.apache.hadoop.fs.s3a.S3AInputStream.closeStream(S3AInputStream.java:470) at org.apache.hadoop.fs.s3a.S3AInputStream.close(S3AInputStream.java:427) - locked <0x00000007fee15180> (a org.apache.hadoop.fs.s3a.S3AInputStream) at java.io.FilterInputStream.close(FilterInputStream.java:181) {code} -- This message was sent by Atlassian JIRA (v7.6.3#76005) --------------------------------------------------------------------- To unsubscribe, e-mail: issues-all-unsubscr...@impala.apache.org For additional commands, e-mail: issues-all-h...@impala.apache.org