[ https://issues.apache.org/jira/browse/TEZ-4507?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17750146#comment-17750146 ]
László Bodor commented on TEZ-4507: ----------------------------------- thanks for reporting this [~ankur_raj_134] this malloc/free message is confusing in container logs, I thought in case of a low-level error it creates a dump, so I cannot really tell for the first sight what's happening there, 2 notes: 1. I guess it's hive that does IOW, isn't it? 2. which java version is the customer using? is different from yours? 3. there is a trace message [here|https://github.com/apache/tez/commit/28cf7dcd3b5cd422755e61b21848c31397c157d7#diff-85b3e25937d042db2d58b098d14a4d0db57e2bc4e44e707c68746da290994048R875] for the buffer size, could they enable trace logging in container to see if the problem is related to a particular sized compressed payload? 4. which compression are they using? can they try if changing the compression algorithm helps? > Task failure due to memory issues in 0.10+ > ------------------------------------------ > > Key: TEZ-4507 > URL: https://issues.apache.org/jira/browse/TEZ-4507 > Project: Apache Tez > Issue Type: Bug > Affects Versions: 0.10.0, 0.10.1, 0.10.2 > Reporter: Ankur Raj > Priority: Major > > This issue is seen on clusters which have tez-0.10.2 branch. on running > insert overwrite queries on huge amount of data; user in this case was using > insert overwrite on 9 TB data. > *Reduce tasks fail to read shuffle data and Hive query ultimately fails with > corrupted memory errors.* > Logs: > > {code:java} > Map 1: 1392(+495)/1922 Reducer 2: 0(+0,-67)/78414 Map 1: 1392(+490)/1922 > Reducer 2: 0(+0,-67)/78414 Map 1: 1402(+0)/1922 Reducer 2: 0(+0,-67)/78414 > Status: Failed Vertex failed, vertexName=Reducer 2, > vertexId=vertex_1686949228586_0003_1_01, diagnostics=[Task failed, > taskId=task_1686949228586_0003_1_01_002253, diagnostics=[TaskAttempt 0 > failed, info=[Container container_1686949228586_0003_01_000050 finished with > diagnostics set to [Container failed, exitCode=134. [2023-06-16 > 21:54:04.463]Exception from container-launch. Container id: > container_1686949228586_0003_01_000050 Exit code: 134 [2023-06-16 > 21:54:04.468]Container exited with a non-zero exit code 134. Error file: > prelaunch.err. Last 4096 bytes of prelaunch.err : /bin/bash: line 1: 28148 > Aborted /usr/lib/jvm/java-1.8.0/bin/java -Xmx14745m -server > -Djava.net.preferIPv4Stack=true -Dhadoop.metrics.log.level=WARN > -Dlog4j.configuratorClass=org.apache.tez.common.TezLog4jConfigurator > -Dlog4j.configuration=tez-container-log4j.properties > -Dyarn.app.container.log.dir=/var/log/hadoop-yarn/containers/application_1686949228586_0003/container_1686949228586_0003_01_000050 > -Dtez.root.logger=INFO,CLA > -Dlog4j.configuratorClass=org.apache.tez.common.TezLog4jConfigurator > -Dlog4j.configuration=tez-container-log4j.properties > -Dyarn.app.container.log.dir=/var/log/hadoop-yarn/containers/application_1686949228586_0003/container_1686949228586_0003_01_000050 > > -Djava.io.tmpdir=/mnt/yarn/usercache/hadoop/appcache/application_1686949228586_0003/container_1686949228586_0003_01_000050/tmp > org.apache.tez.runtime.task.TezChild ip-10-1-14-249.ec2.internal 35871 > container_1686949228586_0003_01_000050 application_1686949228586_0003 1 > > /var/log/hadoop-yarn/containers/application_1686949228586_0003/container_1686949228586_0003_01_000050/stdout > 2> > /var/log/hadoop-yarn/containers/application_1686949228586_0003/container_1686949228586_0003_01_000050/stderr > Last 4096 bytes of stderr : 2023-06-16 21:03:28 Starting to run new task > attempt: attempt_1686949228586_0003_1_00_000062_0 2023-06-16 21:29:21 > Completed running task attempt: attempt_1686949228586_0003_1_00_000062_0 > 2023-06-16 21:29:22 Starting to run new task attempt: > attempt_1686949228586_0003_1_00_001083_0 2023-06-16 21:43:06 Completed > running task attempt: attempt_1686949228586_0003_1_00_001083_0 2023-06-16 > 21:43:07 Starting to run new task attempt: > attempt_1686949228586_0003_1_00_001424_0 2023-06-16 21:53:57 Completed > running task attempt: attempt_1686949228586_0003_1_00_001424_0 2023-06-16 > 21:53:58 Starting to run new task attempt: > attempt_1686949228586_0003_1_01_002253_0 [2023-06-16 21:54:04.469]Container > exited with a non-zero exit code 134. Error file: prelaunch.err. Last 4096 > bytes of prelaunch.err : /bin/bash: line 1: 28148 Aborted > /usr/lib/jvm/java-1.8.0/bin/java -Xmx14745m -server > -Djava.net.preferIPv4Stack=true -Dhadoop.metrics.log.level=WARN > -Dlog4j.configuratorClass=org.apache.tez.common.TezLog4jConfigurator > -Dlog4j.configuration=tez-container-log4j.properties > -Dyarn.app.container.log.dir=/var/log/hadoop-yarn/containers/application_1686949228586_0003/container_1686949228586_0003_01_000050 > -Dtez.root.logger=INFO,CLA > -Dlog4j.configuratorClass=org.apache.tez.common.TezLog4jConfigurator > -Dlog4j.configuration=tez-container-log4j.properties > -Dyarn.app.container.log.dir=/var/log/hadoop-yarn/containers/application_1686949228586_0003/container_1686949228586_0003_01_000050 > > -Djava.io.tmpdir=/mnt/yarn/usercache/hadoop/appcache/application_1686949228586_0003/container_1686949228586_0003_01_000050/tmp > org.apache.tez.runtime.task.TezChild ip-10-1-14-249.ec2.internal 35871 > container_1686949228586_0003_01_000050 application_1686949228586_0003 1 > > /var/log/hadoop-yarn/containers/application_1686949228586_0003/container_1686949228586_0003_01_000050/stdout > 2> > /var/log/hadoop-yarn/containers/application_1686949228586_0003/container_1686949228586_0003_01_000050/stderr > Last 4096 bytes of stderr : 2023-06-16 21:03:28 Starting to run new task > attempt: attempt_1686949228586_0003_1_00_000062_0 2023-06-16 21:29:21 > Completed running task attempt: attempt_1686949228586_0003_1_00_000062_0 > 2023-06-16 21:29:22 Starting to run new task attempt: > attempt_1686949228586_0003_1_00_001083_0 2023-06-16 21:43:06 Completed > running task attempt: attempt_1686949228586_0003_1_00_001083_0 > > {code} > Container logs : > > {code:java} > [2023-06-22 12:50:56.419]Container exited with a non-zero exit code 134. > Error file: prelaunch.err. > Last 4096 bytes of prelaunch.err : > /bin/bash: line 1: 33001 Aborted > /usr/lib/jvm/java-1.8.0/bin/java -Xmx16384m -server > -Djava.net.preferIPv4Stack=true -Dhadoop.metrics.log.level=WARN > -Dlog4j.configuratorClass=org.apache.tez.common.TezLog4jConfigurator > -Dlog4j.configuration=tez-container-log4j.properties > -Dyarn.app.container.log.dir=/var/log/hadoop-yarn/containers/application_1687437498460_0002/container_1687437498460_0002_01_000099 > -Dtez.root.logger=INFO,CLA > -Dlog4j.configuratorClass=org.apache.tez.common.TezLog4jConfigurator > -Dlog4j.configuration=tez-container-log4j.properties > -Dyarn.app.container.log.dir=/var/log/hadoop-yarn/containers/application_1687437498460_0002/container_1687437498460_0002_01_000099 > > -Djava.io.tmpdir=/mnt/yarn/usercache/hadoop/appcache/application_1687437498460_0002/container_1687437498460_0002_01_000099/tmp > org.apache.tez.runtime.task.TezChild ip-10-1-15-66.ec2.internal 36193 > container_1687437498460_0002_01_000099 application_1687437498460_0002 1 > > /var/log/hadoop-yarn/containers/application_1687437498460_0002/container_1687437498460_0002_01_000099/stdout > 2> > /var/log/hadoop-yarn/containers/application_1687437498460_0002/container_1687437498460_0002_01_000099/stderr > Last 4096 bytes of stderr : > 2023-06-22 12:50:55 Starting to run new task attempt: > attempt_1687437498460_0002_1_01_000732_0 > malloc(): memory corruption{code} > > > {code:java} > [2023-06-22 12:51:07.026]Container exited with a non-zero exit code 134. > Error file: prelaunch.err. > Last 4096 bytes of prelaunch.err : > /bin/bash: line 1: 42026 Aborted > /usr/lib/jvm/java-1.8.0/bin/java -Xmx16384m -server > -Djava.net.preferIPv4Stack=true -Dhadoop.metrics.log.level=WARN > -Dlog4j.configuratorClass=org.apache.tez.common.TezLog4jConfigurator > -Dlog4j.configuration=tez-container-log4j.properties > -Dyarn.app.container.log.dir=/var/log/hadoop-yarn/containers/application_1687437498460_0002/container_1687437498460_0002_01_000265 > -Dtez.root.logger=INFO,CLA > -Dlog4j.configuratorClass=org.apache.tez.common.TezLog4jConfigurator > -Dlog4j.configuration=tez-container-log4j.properties > -Dyarn.app.container.log.dir=/var/log/hadoop-yarn/containers/application_1687437498460_0002/container_1687437498460_0002_01_000265 > > -Djava.io.tmpdir=/mnt/yarn/usercache/hadoop/appcache/application_1687437498460_0002/container_1687437498460_0002_01_000265/tmp > org.apache.tez.runtime.task.TezChild ip-10-1-15-66.ec2.internal 36193 > container_1687437498460_0002_01_000265 application_1687437498460_0002 1 > > /var/log/hadoop-yarn/containers/application_1687437498460_0002/container_1687437498460_0002_01_000265/stdout > 2> > /var/log/hadoop-yarn/containers/application_1687437498460_0002/container_1687437498460_0002_01_000265/stderr > Last 4096 bytes of stderr : > 2023-06-22 12:51:06 Starting to run new task attempt: > attempt_1687437498460_0002_1_01_000732_2 > free(): invalid next size (normal){code} > > > > {code:java} > [2023-06-22 12:50:56.401]Container exited with a non-zero exit code 134. > Error file: prelaunch.err. > Last 4096 bytes of prelaunch.err : > /bin/bash: line 1: 35840 Aborted > /usr/lib/jvm/java-1.8.0/bin/java -Xmx16384m -server > -Djava.net.preferIPv4Stack=true -Dhadoop.metrics.log.level=WARN > -Dlog4j.configuratorClass=org.apache.tez.common.TezLog4jConfigurator > -Dlog4j.configuration=tez-container-log4j.properties > -Dyarn.app.container.log.dir=/var/log/hadoop-yarn/containers/application_1687437498460_0002/container_1687437498460_0002_01_000105 > -Dtez.root.logger=INFO,CLA > -Dlog4j.configuratorClass=org.apache.tez.common.TezLog4jConfigurator > -Dlog4j.configuration=tez-container-log4j.properties > -Dyarn.app.container.log.dir=/var/log/hadoop-yarn/containers/application_1687437498460_0002/container_1687437498460_0002_01_000105 > > -Djava.io.tmpdir=/mnt/yarn/usercache/hadoop/appcache/application_1687437498460_0002/container_1687437498460_0002_01_000105/tmp > org.apache.tez.runtime.task.TezChild ip-10-1-15-66.ec2.internal 36193 > container_1687437498460_0002_01_000105 application_1687437498460_0002 1 > > /var/log/hadoop-yarn/containers/application_1687437498460_0002/container_1687437498460_0002_01_000105/stdout > 2> > /var/log/hadoop-yarn/containers/application_1687437498460_0002/container_1687437498460_0002_01_000105/stderr > Last 4096 bytes of stderr : > 2023-06-22 12:50:55 Starting to run new task attempt: > attempt_1687437498460_0002_1_01_000857_0 > java: malloc.c:4032: _int_malloc: Assertion `(unsigned long) (size) >= > (unsigned long) (nb)' failed. > > {code} > This seems to point to memory corruption. > A private patch was created by reverting changes in TEZ-4135 and related > commits, which fixed this issue. > This is not reproduced on using around 100 GB of data. We are trying to > reproduce this in our test environment, and have been unsuccesful so far. But > issue always occurs in customer's env. User was unable to share more logs. I > will add more logs once i am able to reproduce it in my environment. Opening > this ticket now to get initial ideas from the community. -- This message was sent by Atlassian Jira (v8.20.10#820010)