Hello Alex Behm, Mostafa Mokhtar,
I'd like you to reexamine a change. Please visit
http://gerrit.cloudera.org:8080/8100
to look at the new patch set (#3).
Change subject: IMPALA-5940: Avoid log spew by using Status::Expected.
......................................................................
IMPALA-5940: Avoid log spew by using Status::Expected.
In IMPALA-5926, we fixed a case where closing the session triggered a
stack trace in the logs which impacted performance for short-running
queries. Looking at log files from several active clusters, I identified a few
other cases where we could clean up log spew with the same (trivial)
approach.
The following messages will no longer log:
"Failed to codegen MaterializeTuple() due to unsupported type: $0"
"Not implemented for this format."
"ScalarFnCall Codegen not supported for CHAR"
"Could not codegen CodegenMaterializeExprs: "
"Could not codegen TupleRowComparator::Compare(): $0"
These codegen related messages were happening at every execution node, and were
therefore very common.
In addition, the following messages, which were very frequent in the logs, now
will log, but without the back trace:
"... Client ... timed-out during recv call."
"Query Id ... not found."
To do this, I changed them from logging implicitly via Status(...)
to logging explicitly.
The snippet I used to identify these was:
find . -type f -name '*IMPALAD*.gz' | xargs gzcat | awk '/^I/ { if(x) {
print x; } x = "" } /status.cc/ { x=" "; } { if(x) { x=x $0 } }' | sed -e
's/0x[0-9a-fx]* //g' | sed -e 's/[0-9a-f]\{16\}:[0-9a-f]*/QUERYID/g' | tr -s
'\t' ' ' | tr '[0-9]' 'N' | sort | uniq -c | sort -n | tee output.txt
I also analyzed some logs using SQL, against a pre-processed logs table:
with v as (
select regexp_replace(
regexp_replace(
translate(substr(message, 42), "\n\t", " "),
"[a-zA-Z0-9.-]*[.][a-zA-Z0-9-]*:[0-9]*",
"<host>"),
"@.*$", "@@@...") as m
from logs_table where `class`="status.cc")
select m, count(*) from v group by 1 order by 2 desc limit 100
Testing:
* Automated tests.
* Manual testing for one of the new back-trace-suppressed paths:
$ impala-python shell/gen-py/ImpalaService/ImpalaService-remote -h
localhost:21000 GetRuntimeProfile 'beeswaxd.ttypes.QueryHandle()'
Traceback (most recent call last):
File "shell/gen-py/ImpalaService/ImpalaService-remote", line 106, in
<module>
pp.pprint(client.GetRuntimeProfile(eval(args[0]),))
File "/home/philip/src/impala/shell/gen-py/ImpalaService/ImpalaService.py",
line 161, in GetRuntimeProfile
return self.recv_GetRuntimeProfile()
File "/home/philip/src/impala/shell/gen-py/ImpalaService/ImpalaService.py",
line 184, in recv_GetRuntimeProfile
raise result.error
beeswaxd.ttypes.BeeswaxException:
BeeswaxException(handle=QueryHandle(log_context='', id=''), log_context='',
SQLState='HY000', _message='GetRuntimeProfile error: Query id 0:0 not
found.\n', errorCode=0)
$ grep 'Query id' logs/cluster/impalad.INFO | tail -n 1
I0926 20:29:09.999944 6787 impala-server.cc:642] Query id 0:0 not found.
Change-Id: I38088482377a1c3e794a9c8178ef83f29957a330
---
M be/src/exec/hdfs-avro-scanner.cc
M be/src/exec/hdfs-scan-node-base.cc
M be/src/exprs/scalar-fn-call.cc
M be/src/runtime/client-cache.h
M be/src/runtime/tuple.cc
M be/src/service/impala-server.cc
M be/src/util/tuple-row-compare.cc
7 files changed, 23 insertions(+), 17 deletions(-)
git pull ssh://gerrit.cloudera.org:29418/Impala-ASF refs/changes/00/8100/3
--
To view, visit http://gerrit.cloudera.org:8080/8100
To unsubscribe, visit http://gerrit.cloudera.org:8080/settings
Gerrit-Project: Impala-ASF
Gerrit-Branch: master
Gerrit-MessageType: newpatchset
Gerrit-Change-Id: I38088482377a1c3e794a9c8178ef83f29957a330
Gerrit-Change-Number: 8100
Gerrit-PatchSet: 3
Gerrit-Owner: Philip Zeyliger <phi...@cloudera.com>
Gerrit-Reviewer: Alex Behm <alex.b...@cloudera.com>
Gerrit-Reviewer: Mostafa Mokhtar <mmokh...@cloudera.com>
Gerrit-Reviewer: Philip Zeyliger <phi...@cloudera.com>
