[Impala-ASF-CR] IMPALA-6664: Tag log statements with fragment or query ids.

2019-01-24 Thread Impala Public Jenkins (Code Review) 
Impala Public Jenkins has posted comments on this change. ( 
http://gerrit.cloudera.org:8080/12129 )

Change subject: IMPALA-6664: Tag log statements with fragment or query ids.
..


Patch Set 8: Verified+1


--
To view, visit http://gerrit.cloudera.org:8080/12129
To unsubscribe, visit http://gerrit.cloudera.org:8080/settings

Gerrit-Project: Impala-ASF
Gerrit-Branch: master
Gerrit-MessageType: comment
Gerrit-Change-Id: I6634ef9d1a7346339f24f2d40a7a3aa36a535da8
Gerrit-Change-Number: 12129
Gerrit-PatchSet: 8
Gerrit-Owner: Philip Zeyliger 
Gerrit-Reviewer: Impala Public Jenkins 
Gerrit-Reviewer: Paul Rogers 
Gerrit-Reviewer: Philip Zeyliger 
Gerrit-Reviewer: Tim Armstrong 
Gerrit-Reviewer: Zoltan Borok-Nagy 
Gerrit-Reviewer: Zoram Thanga 
Gerrit-Comment-Date: Fri, 25 Jan 2019 00:47:08 +
Gerrit-HasComments: No

[Impala-ASF-CR] IMPALA-6664: Tag log statements with fragment or query ids.

2019-01-24 Thread Impala Public Jenkins (Code Review) 
Impala Public Jenkins has submitted this change and it was merged. ( 
http://gerrit.cloudera.org:8080/12129 )

Change subject: IMPALA-6664: Tag log statements with fragment or query ids.
..

IMPALA-6664: Tag log statements with fragment or query ids.

This implements much of the desire in IMPALA-6664 to tag all log
statements with their query ids. It re-uses the existing ThreadDebugInfo
infrastructure as well as the existing
InstallLogMessageListenerFunction() patch to glog (currently used for
log redaction) to prefix log messages with fragment ids or query ids,
when available. The fragment id is the query id with the last bits
incremented, so it's possible to correlate a given query's log messages.
For example:

  $ grep 85420d575b9ff4b9:402b8868 logs/cluster/impalad.INFO
  I0108 10:39:16.453958 14752 impala-server.cc:1052] 
85420d575b9ff4b9:402b8868] Registered query 
query_id=85420d575b9ff4b9:402b8868 
session_id=aa45e480434f0516:101ae5ac12679d94
  I0108 10:39:16.454738 14752 Frontend.java:1242] 
85420d575b9ff4b9:402b8868] Analyzing query: select count(*) from 
tpcds.web_sales
  I0108 10:39:16.456627 14752 Frontend.java:1282] 
85420d575b9ff4b9:402b8868] Analysis finished.
  I0108 10:39:16.463538 14818 admission-controller.cc:598] 
85420d575b9ff4b9:402b8868] Schedule for 
id=85420d575b9ff4b9:402b8868 in pool_name=default-pool 
per_host_mem_estimate=180.02 MB PoolConfig: max_requests=-1 max_queued=200 
max_mem=-1.00 B
  I0108 10:39:16.463603 14818 admission-controller.cc:603] 
85420d575b9ff4b9:402b8868] Stats: agg_num_running=0, agg_num_queued=0, 
agg_mem_reserved=0,  local_host(local_mem_admitted=0, num_admitted_running=0, 
num_queued=0, backend_mem_reserved=0)
  I0108 10:39:16.463780 14818 admission-controller.cc:635] 
85420d575b9ff4b9:402b8868] Admitted query 
id=85420d575b9ff4b9:402b8868
  I0108 10:39:16.463896 14818 coordinator.cc:93] 
85420d575b9ff4b9:402b8868] Exec() 
query_id=85420d575b9ff4b9:402b8868 stmt=select count(*) from 
tpcds.web_sales
  I0108 10:39:16.464795 14818 coordinator.cc:356] 
85420d575b9ff4b9:402b8868] starting execution on 2 backends for 
query_id=85420d575b9ff4b9:402b8868
  I0108 10:39:16.466384 24891 impala-internal-service.cc:49] 
ExecQueryFInstances(): query_id=85420d575b9ff4b9:402b8868 
coord=pannier.sf.cloudera.com:22000 #instances=2
  I0108 10:39:16.467339 14818 coordinator.cc:370] 
85420d575b9ff4b9:402b8868] started execution on 2 backends for 
query_id=85420d575b9ff4b9:402b8868
  I0108 10:39:16.467536 14823 query-state.cc:579] 
85420d575b9ff4b9:402b8868] Executing instance. 
instance_id=85420d575b9ff4b9:402b8868 fragment_idx=0 
per_fragment_instance_idx=0 coord_state_idx=0 #in-flight=1
  I0108 10:39:16.467627 14824 query-state.cc:579] 
85420d575b9ff4b9:402b88680001] Executing instance. 
instance_id=85420d575b9ff4b9:402b88680001 fragment_idx=1 
per_fragment_instance_idx=0 coord_state_idx=0 #in-flight=2
  I0108 10:39:16.820933 14824 query-state.cc:587] 
85420d575b9ff4b9:402b88680001] Instance completed. 
instance_id=85420d575b9ff4b9:402b88680001 #in-flight=1 status=OK
  I0108 10:39:17.122299 14823 krpc-data-stream-mgr.cc:294] 
85420d575b9ff4b9:402b8868] DeregisterRecvr(): 
fragment_instance_id=85420d575b9ff4b9:402b8868, node=2
  I0108 10:39:17.123500 24038 coordinator.cc:709] Backend completed: 
host=pannier.sf.cloudera.com:22001 remaining=2 
query_id=85420d575b9ff4b9:402b8868
  I0108 10:39:17.123509 24038 coordinator-backend-state.cc:265] 
query_id=85420d575b9ff4b9:402b8868: first in-progress backend: 
pannier.sf.cloudera.com:22000
  I0108 10:39:17.167752 14752 impala-beeswax-server.cc:197] 
85420d575b9ff4b9:402b8868] get_results_metadata(): 
query_id=85420d575b9ff4b9:402b8868
  I0108 10:39:17.168762 14752 coordinator.cc:483] 
85420d575b9ff4b9:402b8868] ExecState: query 
id=85420d575b9ff4b9:402b8868 execution completed
  I0108 10:39:17.168808 14752 coordinator.cc:608] 
85420d575b9ff4b9:402b8868] Coordinator waiting for backends to finish, 
1 remaining. query_id=85420d575b9ff4b9:402b8868
  I0108 10:39:17.168880 14823 query-state.cc:587] 
85420d575b9ff4b9:402b8868] Instance completed. 
instance_id=85420d575b9ff4b9:402b8868 #in-flight=0 status=OK
  I0108 10:39:17.168977 14821 query-state.cc:252] UpdateBackendExecState(): 
last report for 85420d575b9ff4b9:402b8868
  I0108 10:39:17.174401 24038 coordinator.cc:709] Backend completed: 
host=pannier.sf.cloudera.com:22000 remaining=1 
query_id=85420d575b9ff4b9:402b8868
  I0108 10:39:17.174513 14752 coordinator.cc:814] 
85420d575b9ff4b9:402b8868] Release admission control resources for 
query_id=85420d575b9ff4b9:402b8868
  I0108 10:39:17.174815 14821 query-state.cc:604] Cancel:

[Impala-ASF-CR] IMPALA-6664: Tag log statements with fragment or query ids.

2019-01-24 Thread Impala Public Jenkins (Code Review) 
Impala Public Jenkins has posted comments on this change. ( 
http://gerrit.cloudera.org:8080/12129 )

Change subject: IMPALA-6664: Tag log statements with fragment or query ids.
..


Patch Set 8:

Build Successful

https://jenkins.impala.io/job/gerrit-code-review-checks/1877/ : Initial code 
review checks passed. Use gerrit-verify-dryrun-external or gerrit-verify-dryrun 
to run full precommit tests.


--
To view, visit http://gerrit.cloudera.org:8080/12129
To unsubscribe, visit http://gerrit.cloudera.org:8080/settings

Gerrit-Project: Impala-ASF
Gerrit-Branch: master
Gerrit-MessageType: comment
Gerrit-Change-Id: I6634ef9d1a7346339f24f2d40a7a3aa36a535da8
Gerrit-Change-Number: 12129
Gerrit-PatchSet: 8
Gerrit-Owner: Philip Zeyliger 
Gerrit-Reviewer: Impala Public Jenkins 
Gerrit-Reviewer: Paul Rogers 
Gerrit-Reviewer: Philip Zeyliger 
Gerrit-Reviewer: Tim Armstrong 
Gerrit-Reviewer: Zoltan Borok-Nagy 
Gerrit-Reviewer: Zoram Thanga 
Gerrit-Comment-Date: Thu, 24 Jan 2019 21:23:08 +
Gerrit-HasComments: No

[Impala-ASF-CR] IMPALA-6664: Tag log statements with fragment or query ids.

2019-01-24 Thread Philip Zeyliger (Code Review) 
Philip Zeyliger has posted comments on this change. ( 
http://gerrit.cloudera.org:8080/12129 )

Change subject: IMPALA-6664: Tag log statements with fragment or query ids.
..


Patch Set 8: Code-Review+2

Carry +2. I had to make a minor change to the test because the log directory is 
actually in $IMPALA_EE_LOG_DIR (-ish). Also, functional.alltypes has more 
partitions/files, so serves as a more reliable test case. The tpcds table I was 
using was only running on two hosts, so had a bit more trouble.


--
To view, visit http://gerrit.cloudera.org:8080/12129
To unsubscribe, visit http://gerrit.cloudera.org:8080/settings

Gerrit-Project: Impala-ASF
Gerrit-Branch: master
Gerrit-MessageType: comment
Gerrit-Change-Id: I6634ef9d1a7346339f24f2d40a7a3aa36a535da8
Gerrit-Change-Number: 12129
Gerrit-PatchSet: 8
Gerrit-Owner: Philip Zeyliger 
Gerrit-Reviewer: Impala Public Jenkins 
Gerrit-Reviewer: Paul Rogers 
Gerrit-Reviewer: Philip Zeyliger 
Gerrit-Reviewer: Tim Armstrong 
Gerrit-Reviewer: Zoltan Borok-Nagy 
Gerrit-Reviewer: Zoram Thanga 
Gerrit-Comment-Date: Thu, 24 Jan 2019 20:17:15 +
Gerrit-HasComments: No

[Impala-ASF-CR] IMPALA-6664: Tag log statements with fragment or query ids.

2019-01-24 Thread Impala Public Jenkins (Code Review) 
Impala Public Jenkins has posted comments on this change. ( 
http://gerrit.cloudera.org:8080/12129 )

Change subject: IMPALA-6664: Tag log statements with fragment or query ids.
..


Patch Set 8:

Build started: https://jenkins.impala.io/job/gerrit-verify-dryrun/3671/ 
DRY_RUN=false


--
To view, visit http://gerrit.cloudera.org:8080/12129
To unsubscribe, visit http://gerrit.cloudera.org:8080/settings

Gerrit-Project: Impala-ASF
Gerrit-Branch: master
Gerrit-MessageType: comment
Gerrit-Change-Id: I6634ef9d1a7346339f24f2d40a7a3aa36a535da8
Gerrit-Change-Number: 12129
Gerrit-PatchSet: 8
Gerrit-Owner: Philip Zeyliger 
Gerrit-Reviewer: Impala Public Jenkins 
Gerrit-Reviewer: Paul Rogers 
Gerrit-Reviewer: Philip Zeyliger 
Gerrit-Reviewer: Tim Armstrong 
Gerrit-Reviewer: Zoltan Borok-Nagy 
Gerrit-Reviewer: Zoram Thanga 
Gerrit-Comment-Date: Thu, 24 Jan 2019 20:17:25 +
Gerrit-HasComments: No

[Impala-ASF-CR] IMPALA-6664: Tag log statements with fragment or query ids.

2019-01-24 Thread Philip Zeyliger (Code Review) 
Hello Paul Rogers, Zoltan Borok-Nagy, Zoram Thanga, Tim Armstrong, Impala 
Public Jenkins,

I'd like you to reexamine a change. Please visit

http://gerrit.cloudera.org:8080/12129

to look at the new patch set (#8).

Change subject: IMPALA-6664: Tag log statements with fragment or query ids.
..

IMPALA-6664: Tag log statements with fragment or query ids.

This implements much of the desire in IMPALA-6664 to tag all log
statements with their query ids. It re-uses the existing ThreadDebugInfo
infrastructure as well as the existing
InstallLogMessageListenerFunction() patch to glog (currently used for
log redaction) to prefix log messages with fragment ids or query ids,
when available. The fragment id is the query id with the last bits
incremented, so it's possible to correlate a given query's log messages.
For example:

  $ grep 85420d575b9ff4b9:402b8868 logs/cluster/impalad.INFO
  I0108 10:39:16.453958 14752 impala-server.cc:1052] 
85420d575b9ff4b9:402b8868] Registered query 
query_id=85420d575b9ff4b9:402b8868 
session_id=aa45e480434f0516:101ae5ac12679d94
  I0108 10:39:16.454738 14752 Frontend.java:1242] 
85420d575b9ff4b9:402b8868] Analyzing query: select count(*) from 
tpcds.web_sales
  I0108 10:39:16.456627 14752 Frontend.java:1282] 
85420d575b9ff4b9:402b8868] Analysis finished.
  I0108 10:39:16.463538 14818 admission-controller.cc:598] 
85420d575b9ff4b9:402b8868] Schedule for 
id=85420d575b9ff4b9:402b8868 in pool_name=default-pool 
per_host_mem_estimate=180.02 MB PoolConfig: max_requests=-1 max_queued=200 
max_mem=-1.00 B
  I0108 10:39:16.463603 14818 admission-controller.cc:603] 
85420d575b9ff4b9:402b8868] Stats: agg_num_running=0, agg_num_queued=0, 
agg_mem_reserved=0,  local_host(local_mem_admitted=0, num_admitted_running=0, 
num_queued=0, backend_mem_reserved=0)
  I0108 10:39:16.463780 14818 admission-controller.cc:635] 
85420d575b9ff4b9:402b8868] Admitted query 
id=85420d575b9ff4b9:402b8868
  I0108 10:39:16.463896 14818 coordinator.cc:93] 
85420d575b9ff4b9:402b8868] Exec() 
query_id=85420d575b9ff4b9:402b8868 stmt=select count(*) from 
tpcds.web_sales
  I0108 10:39:16.464795 14818 coordinator.cc:356] 
85420d575b9ff4b9:402b8868] starting execution on 2 backends for 
query_id=85420d575b9ff4b9:402b8868
  I0108 10:39:16.466384 24891 impala-internal-service.cc:49] 
ExecQueryFInstances(): query_id=85420d575b9ff4b9:402b8868 
coord=pannier.sf.cloudera.com:22000 #instances=2
  I0108 10:39:16.467339 14818 coordinator.cc:370] 
85420d575b9ff4b9:402b8868] started execution on 2 backends for 
query_id=85420d575b9ff4b9:402b8868
  I0108 10:39:16.467536 14823 query-state.cc:579] 
85420d575b9ff4b9:402b8868] Executing instance. 
instance_id=85420d575b9ff4b9:402b8868 fragment_idx=0 
per_fragment_instance_idx=0 coord_state_idx=0 #in-flight=1
  I0108 10:39:16.467627 14824 query-state.cc:579] 
85420d575b9ff4b9:402b88680001] Executing instance. 
instance_id=85420d575b9ff4b9:402b88680001 fragment_idx=1 
per_fragment_instance_idx=0 coord_state_idx=0 #in-flight=2
  I0108 10:39:16.820933 14824 query-state.cc:587] 
85420d575b9ff4b9:402b88680001] Instance completed. 
instance_id=85420d575b9ff4b9:402b88680001 #in-flight=1 status=OK
  I0108 10:39:17.122299 14823 krpc-data-stream-mgr.cc:294] 
85420d575b9ff4b9:402b8868] DeregisterRecvr(): 
fragment_instance_id=85420d575b9ff4b9:402b8868, node=2
  I0108 10:39:17.123500 24038 coordinator.cc:709] Backend completed: 
host=pannier.sf.cloudera.com:22001 remaining=2 
query_id=85420d575b9ff4b9:402b8868
  I0108 10:39:17.123509 24038 coordinator-backend-state.cc:265] 
query_id=85420d575b9ff4b9:402b8868: first in-progress backend: 
pannier.sf.cloudera.com:22000
  I0108 10:39:17.167752 14752 impala-beeswax-server.cc:197] 
85420d575b9ff4b9:402b8868] get_results_metadata(): 
query_id=85420d575b9ff4b9:402b8868
  I0108 10:39:17.168762 14752 coordinator.cc:483] 
85420d575b9ff4b9:402b8868] ExecState: query 
id=85420d575b9ff4b9:402b8868 execution completed
  I0108 10:39:17.168808 14752 coordinator.cc:608] 
85420d575b9ff4b9:402b8868] Coordinator waiting for backends to finish, 
1 remaining. query_id=85420d575b9ff4b9:402b8868
  I0108 10:39:17.168880 14823 query-state.cc:587] 
85420d575b9ff4b9:402b8868] Instance completed. 
instance_id=85420d575b9ff4b9:402b8868 #in-flight=0 status=OK
  I0108 10:39:17.168977 14821 query-state.cc:252] UpdateBackendExecState(): 
last report for 85420d575b9ff4b9:402b8868
  I0108 10:39:17.174401 24038 coordinator.cc:709] Backend completed: 
host=pannier.sf.cloudera.com:22000 remaining=1 
query_id=85420d575b9ff4b9:402b8868
  I0108 10:39:17.174513 14752 coordinator.cc:814] 
85420d575b9ff4b9:402b8868] Release admission control

[Impala-ASF-CR] IMPALA-6664: Tag log statements with fragment or query ids.

2019-01-22 Thread Impala Public Jenkins (Code Review) 
Impala Public Jenkins has posted comments on this change. ( 
http://gerrit.cloudera.org:8080/12129 )

Change subject: IMPALA-6664: Tag log statements with fragment or query ids.
..


Patch Set 7: Verified-1

Build failed: https://jenkins.impala.io/job/gerrit-verify-dryrun/3660/


--
To view, visit http://gerrit.cloudera.org:8080/12129
To unsubscribe, visit http://gerrit.cloudera.org:8080/settings

Gerrit-Project: Impala-ASF
Gerrit-Branch: master
Gerrit-MessageType: comment
Gerrit-Change-Id: I6634ef9d1a7346339f24f2d40a7a3aa36a535da8
Gerrit-Change-Number: 12129
Gerrit-PatchSet: 7
Gerrit-Owner: Philip Zeyliger 
Gerrit-Reviewer: Impala Public Jenkins 
Gerrit-Reviewer: Paul Rogers 
Gerrit-Reviewer: Philip Zeyliger 
Gerrit-Reviewer: Tim Armstrong 
Gerrit-Reviewer: Zoltan Borok-Nagy 
Gerrit-Reviewer: Zoram Thanga 
Gerrit-Comment-Date: Wed, 23 Jan 2019 01:23:31 +
Gerrit-HasComments: No

[Impala-ASF-CR] IMPALA-6664: Tag log statements with fragment or query ids.

2019-01-22 Thread Impala Public Jenkins (Code Review) 
Impala Public Jenkins has posted comments on this change. ( 
http://gerrit.cloudera.org:8080/12129 )

Change subject: IMPALA-6664: Tag log statements with fragment or query ids.
..


Patch Set 7: Code-Review+2


--
To view, visit http://gerrit.cloudera.org:8080/12129
To unsubscribe, visit http://gerrit.cloudera.org:8080/settings

Gerrit-Project: Impala-ASF
Gerrit-Branch: master
Gerrit-MessageType: comment
Gerrit-Change-Id: I6634ef9d1a7346339f24f2d40a7a3aa36a535da8
Gerrit-Change-Number: 12129
Gerrit-PatchSet: 7
Gerrit-Owner: Philip Zeyliger 
Gerrit-Reviewer: Impala Public Jenkins 
Gerrit-Reviewer: Paul Rogers 
Gerrit-Reviewer: Philip Zeyliger 
Gerrit-Reviewer: Tim Armstrong 
Gerrit-Reviewer: Zoltan Borok-Nagy 
Gerrit-Reviewer: Zoram Thanga 
Gerrit-Comment-Date: Tue, 22 Jan 2019 20:47:12 +
Gerrit-HasComments: No

[Impala-ASF-CR] IMPALA-6664: Tag log statements with fragment or query ids.

2019-01-22 Thread Philip Zeyliger (Code Review) 
Philip Zeyliger has posted comments on this change. ( 
http://gerrit.cloudera.org:8080/12129 )

Change subject: IMPALA-6664: Tag log statements with fragment or query ids.
..


Patch Set 5:

(3 comments)

http://gerrit.cloudera.org:8080/#/c/12129/2/be/src/common/thread-debug-info.h
File be/src/common/thread-debug-info.h:

http://gerrit.cloudera.org:8080/#/c/12129/2/be/src/common/thread-debug-info.h@a116
PS2, Line 116:
> Thanks! Do you plan to fix it in this change, or in a follow-up commit?
Thanks for catching that I didn't do this. I fixed it. Turned out to be nice 
and easy.


http://gerrit.cloudera.org:8080/#/c/12129/5/be/src/service/impala-hs2-server.cc
File be/src/service/impala-hs2-server.cc:

http://gerrit.cloudera.org:8080/#/c/12129/5/be/src/service/impala-hs2-server.cc@126
PS5, Line 126: ScopedThreadContext(GetThreadDebugInfo(), query_ctx.query_id);
> Currently it creates a temporary object that is deleted promptly.
Whoops. Thanks for catching this. Done.


http://gerrit.cloudera.org:8080/#/c/12129/5/be/src/service/impala-internal-service.cc
File be/src/service/impala-internal-service.cc:

http://gerrit.cloudera.org:8080/#/c/12129/5/be/src/service/impala-internal-service.cc@49
PS5, Line 49:   ScopedThreadContext(GetThreadDebugInfo(), 
params.query_ctx.query_id);
> It creates a temporary that is deleted promptly.
Done



--
To view, visit http://gerrit.cloudera.org:8080/12129
To unsubscribe, visit http://gerrit.cloudera.org:8080/settings

Gerrit-Project: Impala-ASF
Gerrit-Branch: master
Gerrit-MessageType: comment
Gerrit-Change-Id: I6634ef9d1a7346339f24f2d40a7a3aa36a535da8
Gerrit-Change-Number: 12129
Gerrit-PatchSet: 5
Gerrit-Owner: Philip Zeyliger 
Gerrit-Reviewer: Impala Public Jenkins 
Gerrit-Reviewer: Paul Rogers 
Gerrit-Reviewer: Philip Zeyliger 
Gerrit-Reviewer: Tim Armstrong 
Gerrit-Reviewer: Zoltan Borok-Nagy 
Gerrit-Reviewer: Zoram Thanga 
Gerrit-Comment-Date: Tue, 22 Jan 2019 20:46:54 +
Gerrit-HasComments: Yes

[Impala-ASF-CR] IMPALA-6664: Tag log statements with fragment or query ids.

2019-01-22 Thread Impala Public Jenkins (Code Review) 
Impala Public Jenkins has posted comments on this change. ( 
http://gerrit.cloudera.org:8080/12129 )

Change subject: IMPALA-6664: Tag log statements with fragment or query ids.
..


Patch Set 7:

Build started: https://jenkins.impala.io/job/gerrit-verify-dryrun/3660/ 
DRY_RUN=false


--
To view, visit http://gerrit.cloudera.org:8080/12129
To unsubscribe, visit http://gerrit.cloudera.org:8080/settings

Gerrit-Project: Impala-ASF
Gerrit-Branch: master
Gerrit-MessageType: comment
Gerrit-Change-Id: I6634ef9d1a7346339f24f2d40a7a3aa36a535da8
Gerrit-Change-Number: 12129
Gerrit-PatchSet: 7
Gerrit-Owner: Philip Zeyliger 
Gerrit-Reviewer: Impala Public Jenkins 
Gerrit-Reviewer: Paul Rogers 
Gerrit-Reviewer: Philip Zeyliger 
Gerrit-Reviewer: Tim Armstrong 
Gerrit-Reviewer: Zoltan Borok-Nagy 
Gerrit-Reviewer: Zoram Thanga 
Gerrit-Comment-Date: Tue, 22 Jan 2019 20:47:13 +
Gerrit-HasComments: No

[Impala-ASF-CR] IMPALA-6664: Tag log statements with fragment or query ids.

2019-01-21 Thread Zoltan Borok-Nagy (Code Review) 
Zoltan Borok-Nagy has posted comments on this change. ( 
http://gerrit.cloudera.org:8080/12129 )

Change subject: IMPALA-6664: Tag log statements with fragment or query ids.
..


Patch Set 6: Code-Review+2

Thanks for applying the changes!


--
To view, visit http://gerrit.cloudera.org:8080/12129
To unsubscribe, visit http://gerrit.cloudera.org:8080/settings

Gerrit-Project: Impala-ASF
Gerrit-Branch: master
Gerrit-MessageType: comment
Gerrit-Change-Id: I6634ef9d1a7346339f24f2d40a7a3aa36a535da8
Gerrit-Change-Number: 12129
Gerrit-PatchSet: 6
Gerrit-Owner: Philip Zeyliger 
Gerrit-Reviewer: Impala Public Jenkins 
Gerrit-Reviewer: Paul Rogers 
Gerrit-Reviewer: Philip Zeyliger 
Gerrit-Reviewer: Tim Armstrong 
Gerrit-Reviewer: Zoltan Borok-Nagy 
Gerrit-Reviewer: Zoram Thanga 
Gerrit-Comment-Date: Mon, 21 Jan 2019 10:54:41 +
Gerrit-HasComments: No

[Impala-ASF-CR] IMPALA-6664: Tag log statements with fragment or query ids.

2019-01-18 Thread Impala Public Jenkins (Code Review) 
Impala Public Jenkins has posted comments on this change. ( 
http://gerrit.cloudera.org:8080/12129 )

Change subject: IMPALA-6664: Tag log statements with fragment or query ids.
..


Patch Set 6:

Build Successful

https://jenkins.impala.io/job/gerrit-code-review-checks/1822/ : Initial code 
review checks passed. Use gerrit-verify-dryrun-external or gerrit-verify-dryrun 
to run full precommit tests.


--
To view, visit http://gerrit.cloudera.org:8080/12129
To unsubscribe, visit http://gerrit.cloudera.org:8080/settings

Gerrit-Project: Impala-ASF
Gerrit-Branch: master
Gerrit-MessageType: comment
Gerrit-Change-Id: I6634ef9d1a7346339f24f2d40a7a3aa36a535da8
Gerrit-Change-Number: 12129
Gerrit-PatchSet: 6
Gerrit-Owner: Philip Zeyliger 
Gerrit-Reviewer: Impala Public Jenkins 
Gerrit-Reviewer: Paul Rogers 
Gerrit-Reviewer: Philip Zeyliger 
Gerrit-Reviewer: Tim Armstrong 
Gerrit-Reviewer: Zoltan Borok-Nagy 
Gerrit-Reviewer: Zoram Thanga 
Gerrit-Comment-Date: Fri, 18 Jan 2019 21:08:02 +
Gerrit-HasComments: No

[Impala-ASF-CR] IMPALA-6664: Tag log statements with fragment or query ids.

2019-01-18 Thread Philip Zeyliger (Code Review) 
Hello Paul Rogers, Zoltan Borok-Nagy, Zoram Thanga, Tim Armstrong, Impala 
Public Jenkins,

I'd like you to reexamine a change. Please visit

http://gerrit.cloudera.org:8080/12129

to look at the new patch set (#6).

Change subject: IMPALA-6664: Tag log statements with fragment or query ids.
..

IMPALA-6664: Tag log statements with fragment or query ids.

This implements much of the desire in IMPALA-6664 to tag all log
statements with their query ids. It re-uses the existing ThreadDebugInfo
infrastructure as well as the existing
InstallLogMessageListenerFunction() patch to glog (currently used for
log redaction) to prefix log messages with fragment ids or query ids,
when available. The fragment id is the query id with the last bits
incremented, so it's possible to correlate a given query's log messages.
For example:

  $ grep 85420d575b9ff4b9:402b8868 logs/cluster/impalad.INFO
  I0108 10:39:16.453958 14752 impala-server.cc:1052] 
85420d575b9ff4b9:402b8868] Registered query 
query_id=85420d575b9ff4b9:402b8868 
session_id=aa45e480434f0516:101ae5ac12679d94
  I0108 10:39:16.454738 14752 Frontend.java:1242] 
85420d575b9ff4b9:402b8868] Analyzing query: select count(*) from 
tpcds.web_sales
  I0108 10:39:16.456627 14752 Frontend.java:1282] 
85420d575b9ff4b9:402b8868] Analysis finished.
  I0108 10:39:16.463538 14818 admission-controller.cc:598] 
85420d575b9ff4b9:402b8868] Schedule for 
id=85420d575b9ff4b9:402b8868 in pool_name=default-pool 
per_host_mem_estimate=180.02 MB PoolConfig: max_requests=-1 max_queued=200 
max_mem=-1.00 B
  I0108 10:39:16.463603 14818 admission-controller.cc:603] 
85420d575b9ff4b9:402b8868] Stats: agg_num_running=0, agg_num_queued=0, 
agg_mem_reserved=0,  local_host(local_mem_admitted=0, num_admitted_running=0, 
num_queued=0, backend_mem_reserved=0)
  I0108 10:39:16.463780 14818 admission-controller.cc:635] 
85420d575b9ff4b9:402b8868] Admitted query 
id=85420d575b9ff4b9:402b8868
  I0108 10:39:16.463896 14818 coordinator.cc:93] 
85420d575b9ff4b9:402b8868] Exec() 
query_id=85420d575b9ff4b9:402b8868 stmt=select count(*) from 
tpcds.web_sales
  I0108 10:39:16.464795 14818 coordinator.cc:356] 
85420d575b9ff4b9:402b8868] starting execution on 2 backends for 
query_id=85420d575b9ff4b9:402b8868
  I0108 10:39:16.466384 24891 impala-internal-service.cc:49] 
ExecQueryFInstances(): query_id=85420d575b9ff4b9:402b8868 
coord=pannier.sf.cloudera.com:22000 #instances=2
  I0108 10:39:16.467339 14818 coordinator.cc:370] 
85420d575b9ff4b9:402b8868] started execution on 2 backends for 
query_id=85420d575b9ff4b9:402b8868
  I0108 10:39:16.467536 14823 query-state.cc:579] 
85420d575b9ff4b9:402b8868] Executing instance. 
instance_id=85420d575b9ff4b9:402b8868 fragment_idx=0 
per_fragment_instance_idx=0 coord_state_idx=0 #in-flight=1
  I0108 10:39:16.467627 14824 query-state.cc:579] 
85420d575b9ff4b9:402b88680001] Executing instance. 
instance_id=85420d575b9ff4b9:402b88680001 fragment_idx=1 
per_fragment_instance_idx=0 coord_state_idx=0 #in-flight=2
  I0108 10:39:16.820933 14824 query-state.cc:587] 
85420d575b9ff4b9:402b88680001] Instance completed. 
instance_id=85420d575b9ff4b9:402b88680001 #in-flight=1 status=OK
  I0108 10:39:17.122299 14823 krpc-data-stream-mgr.cc:294] 
85420d575b9ff4b9:402b8868] DeregisterRecvr(): 
fragment_instance_id=85420d575b9ff4b9:402b8868, node=2
  I0108 10:39:17.123500 24038 coordinator.cc:709] Backend completed: 
host=pannier.sf.cloudera.com:22001 remaining=2 
query_id=85420d575b9ff4b9:402b8868
  I0108 10:39:17.123509 24038 coordinator-backend-state.cc:265] 
query_id=85420d575b9ff4b9:402b8868: first in-progress backend: 
pannier.sf.cloudera.com:22000
  I0108 10:39:17.167752 14752 impala-beeswax-server.cc:197] 
85420d575b9ff4b9:402b8868] get_results_metadata(): 
query_id=85420d575b9ff4b9:402b8868
  I0108 10:39:17.168762 14752 coordinator.cc:483] 
85420d575b9ff4b9:402b8868] ExecState: query 
id=85420d575b9ff4b9:402b8868 execution completed
  I0108 10:39:17.168808 14752 coordinator.cc:608] 
85420d575b9ff4b9:402b8868] Coordinator waiting for backends to finish, 
1 remaining. query_id=85420d575b9ff4b9:402b8868
  I0108 10:39:17.168880 14823 query-state.cc:587] 
85420d575b9ff4b9:402b8868] Instance completed. 
instance_id=85420d575b9ff4b9:402b8868 #in-flight=0 status=OK
  I0108 10:39:17.168977 14821 query-state.cc:252] UpdateBackendExecState(): 
last report for 85420d575b9ff4b9:402b8868
  I0108 10:39:17.174401 24038 coordinator.cc:709] Backend completed: 
host=pannier.sf.cloudera.com:22000 remaining=1 
query_id=85420d575b9ff4b9:402b8868
  I0108 10:39:17.174513 14752 coordinator.cc:814] 
85420d575b9ff4b9:402b8868] Release admission control

[Impala-ASF-CR] IMPALA-6664: Tag log statements with fragment or query ids.

2019-01-18 Thread Zoltan Borok-Nagy (Code Review) 
Zoltan Borok-Nagy has posted comments on this change. ( 
http://gerrit.cloudera.org:8080/12129 )

Change subject: IMPALA-6664: Tag log statements with fragment or query ids.
..


Patch Set 5:

(3 comments)

http://gerrit.cloudera.org:8080/#/c/12129/2/be/src/common/thread-debug-info.h
File be/src/common/thread-debug-info.h:

http://gerrit.cloudera.org:8080/#/c/12129/2/be/src/common/thread-debug-info.h@a116
PS2, Line 116:
> Cool. I'll take a look at impala-gdb.py and fix it appropriately. Printing
Thanks! Do you plan to fix it in this change, or in a follow-up commit?


http://gerrit.cloudera.org:8080/#/c/12129/5/be/src/service/impala-hs2-server.cc
File be/src/service/impala-hs2-server.cc:

http://gerrit.cloudera.org:8080/#/c/12129/5/be/src/service/impala-hs2-server.cc@126
PS5, Line 126: ScopedThreadContext(GetThreadDebugInfo(), query_ctx.query_id);
Currently it creates a temporary object that is deleted promptly.

You need to create a variable so the TDI object only gets reset at the end of 
the function.


http://gerrit.cloudera.org:8080/#/c/12129/5/be/src/service/impala-internal-service.cc
File be/src/service/impala-internal-service.cc:

http://gerrit.cloudera.org:8080/#/c/12129/5/be/src/service/impala-internal-service.cc@49
PS5, Line 49:   ScopedThreadContext(GetThreadDebugInfo(), 
params.query_ctx.query_id);
It creates a temporary that is deleted promptly.



--
To view, visit http://gerrit.cloudera.org:8080/12129
To unsubscribe, visit http://gerrit.cloudera.org:8080/settings

Gerrit-Project: Impala-ASF
Gerrit-Branch: master
Gerrit-MessageType: comment
Gerrit-Change-Id: I6634ef9d1a7346339f24f2d40a7a3aa36a535da8
Gerrit-Change-Number: 12129
Gerrit-PatchSet: 5
Gerrit-Owner: Philip Zeyliger 
Gerrit-Reviewer: Impala Public Jenkins 
Gerrit-Reviewer: Paul Rogers 
Gerrit-Reviewer: Philip Zeyliger 
Gerrit-Reviewer: Tim Armstrong 
Gerrit-Reviewer: Zoltan Borok-Nagy 
Gerrit-Reviewer: Zoram Thanga 
Gerrit-Comment-Date: Fri, 18 Jan 2019 13:48:41 +
Gerrit-HasComments: Yes

[Impala-ASF-CR] IMPALA-6664: Tag log statements with fragment or query ids.

2019-01-17 Thread Tim Armstrong (Code Review) 
Tim Armstrong has posted comments on this change. ( 
http://gerrit.cloudera.org:8080/12129 )

Change subject: IMPALA-6664: Tag log statements with fragment or query ids.
..


Patch Set 5: Code-Review+1

Will let ZBN promote to +2


-- 
To view, visit http://gerrit.cloudera.org:8080/12129
To unsubscribe, visit http://gerrit.cloudera.org:8080/settings

Gerrit-Project: Impala-ASF
Gerrit-Branch: master
Gerrit-MessageType: comment
Gerrit-Change-Id: I6634ef9d1a7346339f24f2d40a7a3aa36a535da8
Gerrit-Change-Number: 12129
Gerrit-PatchSet: 5
Gerrit-Owner: Philip Zeyliger 
Gerrit-Reviewer: Impala Public Jenkins 
Gerrit-Reviewer: Paul Rogers 
Gerrit-Reviewer: Philip Zeyliger 
Gerrit-Reviewer: Tim Armstrong 
Gerrit-Reviewer: Zoltan Borok-Nagy 
Gerrit-Reviewer: Zoram Thanga 
Gerrit-Comment-Date: Thu, 17 Jan 2019 23:54:29 +
Gerrit-HasComments: No

[Impala-ASF-CR] IMPALA-6664: Tag log statements with fragment or query ids.

2019-01-17 Thread Impala Public Jenkins (Code Review) 
Impala Public Jenkins has posted comments on this change. ( 
http://gerrit.cloudera.org:8080/12129 )

Change subject: IMPALA-6664: Tag log statements with fragment or query ids.
..


Patch Set 5:

Build Successful

https://jenkins.impala.io/job/gerrit-code-review-checks/1804/ : Initial code 
review checks passed. Use gerrit-verify-dryrun-external or gerrit-verify-dryrun 
to run full precommit tests.


--
To view, visit http://gerrit.cloudera.org:8080/12129
To unsubscribe, visit http://gerrit.cloudera.org:8080/settings

Gerrit-Project: Impala-ASF
Gerrit-Branch: master
Gerrit-MessageType: comment
Gerrit-Change-Id: I6634ef9d1a7346339f24f2d40a7a3aa36a535da8
Gerrit-Change-Number: 12129
Gerrit-PatchSet: 5
Gerrit-Owner: Philip Zeyliger 
Gerrit-Reviewer: Impala Public Jenkins 
Gerrit-Reviewer: Paul Rogers 
Gerrit-Reviewer: Philip Zeyliger 
Gerrit-Reviewer: Tim Armstrong 
Gerrit-Reviewer: Zoltan Borok-Nagy 
Gerrit-Reviewer: Zoram Thanga 
Gerrit-Comment-Date: Thu, 17 Jan 2019 21:11:36 +
Gerrit-HasComments: No

[Impala-ASF-CR] IMPALA-6664: Tag log statements with fragment or query ids.

2019-01-17 Thread Philip Zeyliger (Code Review) 
Hello Paul Rogers, Zoltan Borok-Nagy, Zoram Thanga, Tim Armstrong, Impala 
Public Jenkins,

I'd like you to reexamine a change. Please visit

http://gerrit.cloudera.org:8080/12129

to look at the new patch set (#5).

Change subject: IMPALA-6664: Tag log statements with fragment or query ids.
..

IMPALA-6664: Tag log statements with fragment or query ids.

This implements much of the desire in IMPALA-6664 to tag all log
statements with their query ids. It re-uses the existing ThreadDebugInfo
infrastructure as well as the existing
InstallLogMessageListenerFunction() patch to glog (currently used for
log redaction) to prefix log messages with fragment ids or query ids,
when available. The fragment id is the query id with the last bits
incremented, so it's possible to correlate a given query's log messages.
For example:

  $ grep 85420d575b9ff4b9:402b8868 logs/cluster/impalad.INFO
  I0108 10:39:16.453958 14752 impala-server.cc:1052] 
85420d575b9ff4b9:402b8868] Registered query 
query_id=85420d575b9ff4b9:402b8868 
session_id=aa45e480434f0516:101ae5ac12679d94
  I0108 10:39:16.454738 14752 Frontend.java:1242] 
85420d575b9ff4b9:402b8868] Analyzing query: select count(*) from 
tpcds.web_sales
  I0108 10:39:16.456627 14752 Frontend.java:1282] 
85420d575b9ff4b9:402b8868] Analysis finished.
  I0108 10:39:16.463538 14818 admission-controller.cc:598] 
85420d575b9ff4b9:402b8868] Schedule for 
id=85420d575b9ff4b9:402b8868 in pool_name=default-pool 
per_host_mem_estimate=180.02 MB PoolConfig: max_requests=-1 max_queued=200 
max_mem=-1.00 B
  I0108 10:39:16.463603 14818 admission-controller.cc:603] 
85420d575b9ff4b9:402b8868] Stats: agg_num_running=0, agg_num_queued=0, 
agg_mem_reserved=0,  local_host(local_mem_admitted=0, num_admitted_running=0, 
num_queued=0, backend_mem_reserved=0)
  I0108 10:39:16.463780 14818 admission-controller.cc:635] 
85420d575b9ff4b9:402b8868] Admitted query 
id=85420d575b9ff4b9:402b8868
  I0108 10:39:16.463896 14818 coordinator.cc:93] 
85420d575b9ff4b9:402b8868] Exec() 
query_id=85420d575b9ff4b9:402b8868 stmt=select count(*) from 
tpcds.web_sales
  I0108 10:39:16.464795 14818 coordinator.cc:356] 
85420d575b9ff4b9:402b8868] starting execution on 2 backends for 
query_id=85420d575b9ff4b9:402b8868
  I0108 10:39:16.466384 24891 impala-internal-service.cc:49] 
ExecQueryFInstances(): query_id=85420d575b9ff4b9:402b8868 
coord=pannier.sf.cloudera.com:22000 #instances=2
  I0108 10:39:16.467339 14818 coordinator.cc:370] 
85420d575b9ff4b9:402b8868] started execution on 2 backends for 
query_id=85420d575b9ff4b9:402b8868
  I0108 10:39:16.467536 14823 query-state.cc:579] 
85420d575b9ff4b9:402b8868] Executing instance. 
instance_id=85420d575b9ff4b9:402b8868 fragment_idx=0 
per_fragment_instance_idx=0 coord_state_idx=0 #in-flight=1
  I0108 10:39:16.467627 14824 query-state.cc:579] 
85420d575b9ff4b9:402b88680001] Executing instance. 
instance_id=85420d575b9ff4b9:402b88680001 fragment_idx=1 
per_fragment_instance_idx=0 coord_state_idx=0 #in-flight=2
  I0108 10:39:16.820933 14824 query-state.cc:587] 
85420d575b9ff4b9:402b88680001] Instance completed. 
instance_id=85420d575b9ff4b9:402b88680001 #in-flight=1 status=OK
  I0108 10:39:17.122299 14823 krpc-data-stream-mgr.cc:294] 
85420d575b9ff4b9:402b8868] DeregisterRecvr(): 
fragment_instance_id=85420d575b9ff4b9:402b8868, node=2
  I0108 10:39:17.123500 24038 coordinator.cc:709] Backend completed: 
host=pannier.sf.cloudera.com:22001 remaining=2 
query_id=85420d575b9ff4b9:402b8868
  I0108 10:39:17.123509 24038 coordinator-backend-state.cc:265] 
query_id=85420d575b9ff4b9:402b8868: first in-progress backend: 
pannier.sf.cloudera.com:22000
  I0108 10:39:17.167752 14752 impala-beeswax-server.cc:197] 
85420d575b9ff4b9:402b8868] get_results_metadata(): 
query_id=85420d575b9ff4b9:402b8868
  I0108 10:39:17.168762 14752 coordinator.cc:483] 
85420d575b9ff4b9:402b8868] ExecState: query 
id=85420d575b9ff4b9:402b8868 execution completed
  I0108 10:39:17.168808 14752 coordinator.cc:608] 
85420d575b9ff4b9:402b8868] Coordinator waiting for backends to finish, 
1 remaining. query_id=85420d575b9ff4b9:402b8868
  I0108 10:39:17.168880 14823 query-state.cc:587] 
85420d575b9ff4b9:402b8868] Instance completed. 
instance_id=85420d575b9ff4b9:402b8868 #in-flight=0 status=OK
  I0108 10:39:17.168977 14821 query-state.cc:252] UpdateBackendExecState(): 
last report for 85420d575b9ff4b9:402b8868
  I0108 10:39:17.174401 24038 coordinator.cc:709] Backend completed: 
host=pannier.sf.cloudera.com:22000 remaining=1 
query_id=85420d575b9ff4b9:402b8868
  I0108 10:39:17.174513 14752 coordinator.cc:814] 
85420d575b9ff4b9:402b8868] Release admission control

[Impala-ASF-CR] IMPALA-6664: Tag log statements with fragment or query ids.

2019-01-17 Thread Philip Zeyliger (Code Review) 
Philip Zeyliger has posted comments on this change. ( 
http://gerrit.cloudera.org:8080/12129 )

Change subject: IMPALA-6664: Tag log statements with fragment or query ids.
..


Patch Set 4:

(1 comment)

http://gerrit.cloudera.org:8080/#/c/12129/4/tests/observability/test_log_fragments.py
File tests/observability/test_log_fragments.py:

http://gerrit.cloudera.org:8080/#/c/12129/4/tests/observability/test_log_fragments.py@57
PS4, Line 57: e
> flake8: E722 do not use bare except'
Done



--
To view, visit http://gerrit.cloudera.org:8080/12129
To unsubscribe, visit http://gerrit.cloudera.org:8080/settings

Gerrit-Project: Impala-ASF
Gerrit-Branch: master
Gerrit-MessageType: comment
Gerrit-Change-Id: I6634ef9d1a7346339f24f2d40a7a3aa36a535da8
Gerrit-Change-Number: 12129
Gerrit-PatchSet: 4
Gerrit-Owner: Philip Zeyliger 
Gerrit-Reviewer: Impala Public Jenkins 
Gerrit-Reviewer: Paul Rogers 
Gerrit-Reviewer: Philip Zeyliger 
Gerrit-Reviewer: Tim Armstrong 
Gerrit-Reviewer: Zoltan Borok-Nagy 
Gerrit-Reviewer: Zoram Thanga 
Gerrit-Comment-Date: Thu, 17 Jan 2019 20:46:44 +
Gerrit-HasComments: Yes

[Impala-ASF-CR] IMPALA-6664: Tag log statements with fragment or query ids.

2019-01-17 Thread Impala Public Jenkins (Code Review) 
Impala Public Jenkins has posted comments on this change. ( 
http://gerrit.cloudera.org:8080/12129 )

Change subject: IMPALA-6664: Tag log statements with fragment or query ids.
..


Patch Set 4:

Build Successful

https://jenkins.impala.io/job/gerrit-code-review-checks/1800/ : Initial code 
review checks passed. Use gerrit-verify-dryrun-external or gerrit-verify-dryrun 
to run full precommit tests.


--
To view, visit http://gerrit.cloudera.org:8080/12129
To unsubscribe, visit http://gerrit.cloudera.org:8080/settings

Gerrit-Project: Impala-ASF
Gerrit-Branch: master
Gerrit-MessageType: comment
Gerrit-Change-Id: I6634ef9d1a7346339f24f2d40a7a3aa36a535da8
Gerrit-Change-Number: 12129
Gerrit-PatchSet: 4
Gerrit-Owner: Philip Zeyliger 
Gerrit-Reviewer: Impala Public Jenkins 
Gerrit-Reviewer: Paul Rogers 
Gerrit-Reviewer: Philip Zeyliger 
Gerrit-Reviewer: Tim Armstrong 
Gerrit-Reviewer: Zoltan Borok-Nagy 
Gerrit-Reviewer: Zoram Thanga 
Gerrit-Comment-Date: Thu, 17 Jan 2019 20:37:01 +
Gerrit-HasComments: No

[Impala-ASF-CR] IMPALA-6664: Tag log statements with fragment or query ids.

2019-01-17 Thread Impala Public Jenkins (Code Review) 
Impala Public Jenkins has posted comments on this change. ( 
http://gerrit.cloudera.org:8080/12129 )

Change subject: IMPALA-6664: Tag log statements with fragment or query ids.
..


Patch Set 4:

(1 comment)

http://gerrit.cloudera.org:8080/#/c/12129/4/tests/observability/test_log_fragments.py
File tests/observability/test_log_fragments.py:

http://gerrit.cloudera.org:8080/#/c/12129/4/tests/observability/test_log_fragments.py@57
PS4, Line 57: e
flake8: E722 do not use bare except'



--
To view, visit http://gerrit.cloudera.org:8080/12129
To unsubscribe, visit http://gerrit.cloudera.org:8080/settings

Gerrit-Project: Impala-ASF
Gerrit-Branch: master
Gerrit-MessageType: comment
Gerrit-Change-Id: I6634ef9d1a7346339f24f2d40a7a3aa36a535da8
Gerrit-Change-Number: 12129
Gerrit-PatchSet: 4
Gerrit-Owner: Philip Zeyliger 
Gerrit-Reviewer: Impala Public Jenkins 
Gerrit-Reviewer: Paul Rogers 
Gerrit-Reviewer: Philip Zeyliger 
Gerrit-Reviewer: Tim Armstrong 
Gerrit-Reviewer: Zoltan Borok-Nagy 
Gerrit-Reviewer: Zoram Thanga 
Gerrit-Comment-Date: Thu, 17 Jan 2019 20:01:54 +
Gerrit-HasComments: Yes

[Impala-ASF-CR] IMPALA-6664: Tag log statements with fragment or query ids.

2019-01-17 Thread Philip Zeyliger (Code Review) 
Philip Zeyliger has posted comments on this change. ( 
http://gerrit.cloudera.org:8080/12129 )

Change subject: IMPALA-6664: Tag log statements with fragment or query ids.
..


Patch Set 4:

(8 comments)

I think I addressed all the comments. Please take another look.

http://gerrit.cloudera.org:8080/#/c/12129/3/be/src/common/thread-debug-info.h
File be/src/common/thread-debug-info.h:

http://gerrit.cloudera.org:8080/#/c/12129/3/be/src/common/thread-debug-info.h@a94
PS3, Line 94:
> We should copy parent_.thread_name_, or remove it from struct 'ParentInfo'.
This was a bug (found by unit tests). Fixed.


http://gerrit.cloudera.org:8080/#/c/12129/2/be/src/common/thread-debug-info.h
File be/src/common/thread-debug-info.h:

http://gerrit.cloudera.org:8080/#/c/12129/2/be/src/common/thread-debug-info.h@a116
PS2, Line 116:
> Yeah, the idea was to make it readable when debugging a minidump or core fi
Cool. I'll take a look at impala-gdb.py and fix it appropriately. Printing out 
the hex using gdb isn't too bad. I wrote down how to do it in gdb in 
debug-util.h for lack of a better place.

Unit tests will be fixed in the next iteration.


http://gerrit.cloudera.org:8080/#/c/12129/3/be/src/exec/hdfs-scan-node-base.cc
File be/src/exec/hdfs-scan-node-base.cc:

http://gerrit.cloudera.org:8080/#/c/12129/3/be/src/exec/hdfs-scan-node-base.cc@37
PS3, Line 37: #include "exprs/scalar-expr-evaluator.h"
> nit: do we need this include? Might be better to include it in hdfs-scan-no
Done


http://gerrit.cloudera.org:8080/#/c/12129/3/be/src/exec/hdfs-scan-node.cc
File be/src/exec/hdfs-scan-node.cc:

http://gerrit.cloudera.org:8080/#/c/12129/3/be/src/exec/hdfs-scan-node.cc@325
PS3, Line 325: auto fn = [this, first_thread, scanner_thread_reservation]() 
{
 :   this->ScannerThread(first_thread, 
scanner_thread_reservation);
 : };
 : std::unique_ptr t;
 : status = Thread::Create(
> Since we use Thread::Create() later, https://github.com/apache/impala/blob/
No reason to believe it doesn't. I took this from some tracing code that I'm 
still working on. I tested this manually by adding an extra log message at the 
beginning of the scanner thread, and can confirm I can see it tagged.


http://gerrit.cloudera.org:8080/#/c/12129/3/be/src/runtime/io/disk-io-mgr.cc
File be/src/runtime/io/disk-io-mgr.cc:

http://gerrit.cloudera.org:8080/#/c/12129/3/be/src/runtime/io/disk-io-mgr.cc@424
PS3, Line 424: // We are now working on behalf of a query, so set thread 
state appropriately.
 : // See also IMPALA-6254 and IMPALA-6417.
 : ScopedThreadContext tdi_scope(GetThreadDebugInfo(), 
worker_context-
> Fyi, IMPALA-6254 and IMPALA-6417 is about to make this automated. Maybe we
Added a comment.


http://gerrit.cloudera.org:8080/#/c/12129/3/tests/observability/test_log_fragments.py
File tests/observability/test_log_fragments.py:

http://gerrit.cloudera.org:8080/#/c/12129/3/tests/observability/test_log_fragments.py@23
PS3, Line 23:
> flake8: E302 expected 2 blank lines, found 1
Done


http://gerrit.cloudera.org:8080/#/c/12129/3/tests/observability/test_log_fragments.py@26
PS3, Line 26:
> typo:fragments
Done


http://gerrit.cloudera.org:8080/#/c/12129/3/tests/observability/test_log_fragments.py@34
PS3, Line 34: """
> nit: result (since it's not a profile, rather an ImpalaBeeswaxResult)
Done



--
To view, visit http://gerrit.cloudera.org:8080/12129
To unsubscribe, visit http://gerrit.cloudera.org:8080/settings

Gerrit-Project: Impala-ASF
Gerrit-Branch: master
Gerrit-MessageType: comment
Gerrit-Change-Id: I6634ef9d1a7346339f24f2d40a7a3aa36a535da8
Gerrit-Change-Number: 12129
Gerrit-PatchSet: 4
Gerrit-Owner: Philip Zeyliger 
Gerrit-Reviewer: Impala Public Jenkins 
Gerrit-Reviewer: Paul Rogers 
Gerrit-Reviewer: Philip Zeyliger 
Gerrit-Reviewer: Tim Armstrong 
Gerrit-Reviewer: Zoltan Borok-Nagy 
Gerrit-Reviewer: Zoram Thanga 
Gerrit-Comment-Date: Thu, 17 Jan 2019 20:01:09 +
Gerrit-HasComments: Yes

[Impala-ASF-CR] IMPALA-6664: Tag log statements with fragment or query ids.

2019-01-17 Thread Philip Zeyliger (Code Review) 
Hello Paul Rogers, Zoltan Borok-Nagy, Zoram Thanga, Tim Armstrong, Impala 
Public Jenkins,

I'd like you to reexamine a change. Please visit

http://gerrit.cloudera.org:8080/12129

to look at the new patch set (#4).

Change subject: IMPALA-6664: Tag log statements with fragment or query ids.
..

IMPALA-6664: Tag log statements with fragment or query ids.

This implements much of the desire in IMPALA-6664 to tag all log
statements with their query ids. It re-uses the existing ThreadDebugInfo
infrastructure as well as the existing
InstallLogMessageListenerFunction() patch to glog (currently used for
log redaction) to prefix log messages with fragment ids or query ids,
when available. The fragment id is the query id with the last bits
incremented, so it's possible to correlate a given query's log messages.
For example:

  $ grep 85420d575b9ff4b9:402b8868 logs/cluster/impalad.INFO
  I0108 10:39:16.453958 14752 impala-server.cc:1052] 
85420d575b9ff4b9:402b8868] Registered query 
query_id=85420d575b9ff4b9:402b8868 
session_id=aa45e480434f0516:101ae5ac12679d94
  I0108 10:39:16.454738 14752 Frontend.java:1242] 
85420d575b9ff4b9:402b8868] Analyzing query: select count(*) from 
tpcds.web_sales
  I0108 10:39:16.456627 14752 Frontend.java:1282] 
85420d575b9ff4b9:402b8868] Analysis finished.
  I0108 10:39:16.463538 14818 admission-controller.cc:598] 
85420d575b9ff4b9:402b8868] Schedule for 
id=85420d575b9ff4b9:402b8868 in pool_name=default-pool 
per_host_mem_estimate=180.02 MB PoolConfig: max_requests=-1 max_queued=200 
max_mem=-1.00 B
  I0108 10:39:16.463603 14818 admission-controller.cc:603] 
85420d575b9ff4b9:402b8868] Stats: agg_num_running=0, agg_num_queued=0, 
agg_mem_reserved=0,  local_host(local_mem_admitted=0, num_admitted_running=0, 
num_queued=0, backend_mem_reserved=0)
  I0108 10:39:16.463780 14818 admission-controller.cc:635] 
85420d575b9ff4b9:402b8868] Admitted query 
id=85420d575b9ff4b9:402b8868
  I0108 10:39:16.463896 14818 coordinator.cc:93] 
85420d575b9ff4b9:402b8868] Exec() 
query_id=85420d575b9ff4b9:402b8868 stmt=select count(*) from 
tpcds.web_sales
  I0108 10:39:16.464795 14818 coordinator.cc:356] 
85420d575b9ff4b9:402b8868] starting execution on 2 backends for 
query_id=85420d575b9ff4b9:402b8868
  I0108 10:39:16.466384 24891 impala-internal-service.cc:49] 
ExecQueryFInstances(): query_id=85420d575b9ff4b9:402b8868 
coord=pannier.sf.cloudera.com:22000 #instances=2
  I0108 10:39:16.467339 14818 coordinator.cc:370] 
85420d575b9ff4b9:402b8868] started execution on 2 backends for 
query_id=85420d575b9ff4b9:402b8868
  I0108 10:39:16.467536 14823 query-state.cc:579] 
85420d575b9ff4b9:402b8868] Executing instance. 
instance_id=85420d575b9ff4b9:402b8868 fragment_idx=0 
per_fragment_instance_idx=0 coord_state_idx=0 #in-flight=1
  I0108 10:39:16.467627 14824 query-state.cc:579] 
85420d575b9ff4b9:402b88680001] Executing instance. 
instance_id=85420d575b9ff4b9:402b88680001 fragment_idx=1 
per_fragment_instance_idx=0 coord_state_idx=0 #in-flight=2
  I0108 10:39:16.820933 14824 query-state.cc:587] 
85420d575b9ff4b9:402b88680001] Instance completed. 
instance_id=85420d575b9ff4b9:402b88680001 #in-flight=1 status=OK
  I0108 10:39:17.122299 14823 krpc-data-stream-mgr.cc:294] 
85420d575b9ff4b9:402b8868] DeregisterRecvr(): 
fragment_instance_id=85420d575b9ff4b9:402b8868, node=2
  I0108 10:39:17.123500 24038 coordinator.cc:709] Backend completed: 
host=pannier.sf.cloudera.com:22001 remaining=2 
query_id=85420d575b9ff4b9:402b8868
  I0108 10:39:17.123509 24038 coordinator-backend-state.cc:265] 
query_id=85420d575b9ff4b9:402b8868: first in-progress backend: 
pannier.sf.cloudera.com:22000
  I0108 10:39:17.167752 14752 impala-beeswax-server.cc:197] 
85420d575b9ff4b9:402b8868] get_results_metadata(): 
query_id=85420d575b9ff4b9:402b8868
  I0108 10:39:17.168762 14752 coordinator.cc:483] 
85420d575b9ff4b9:402b8868] ExecState: query 
id=85420d575b9ff4b9:402b8868 execution completed
  I0108 10:39:17.168808 14752 coordinator.cc:608] 
85420d575b9ff4b9:402b8868] Coordinator waiting for backends to finish, 
1 remaining. query_id=85420d575b9ff4b9:402b8868
  I0108 10:39:17.168880 14823 query-state.cc:587] 
85420d575b9ff4b9:402b8868] Instance completed. 
instance_id=85420d575b9ff4b9:402b8868 #in-flight=0 status=OK
  I0108 10:39:17.168977 14821 query-state.cc:252] UpdateBackendExecState(): 
last report for 85420d575b9ff4b9:402b8868
  I0108 10:39:17.174401 24038 coordinator.cc:709] Backend completed: 
host=pannier.sf.cloudera.com:22000 remaining=1 
query_id=85420d575b9ff4b9:402b8868
  I0108 10:39:17.174513 14752 coordinator.cc:814] 
85420d575b9ff4b9:402b8868] Release admission control

[Impala-ASF-CR] IMPALA-6664: Tag log statements with fragment or query ids.

2019-01-09 Thread Philip Zeyliger (Code Review) 
Philip Zeyliger has posted comments on this change. ( 
http://gerrit.cloudera.org:8080/12129 )

Change subject: IMPALA-6664: Tag log statements with fragment or query ids.
..


Patch Set 3:

> Does/should this fix up the Java side messages as well? May be some
 > configuration in Log4J that produces a result similar to what
 > you've achieved on the C++ side.

The Java side of Impala logs to Glog via 
fe/src/main/java/org/apache/impala/util/GlogAppender.java which does JNI to 
write to GLOG. As a bonus, the log line below is an example of how we get this 
tagging for free assuming that the Java code isn't creating threads and so on. 
For the planner, it's single-threaded as far as I know, so we don't have to do 
anything special.

  I0108 10:39:16.456627 14752 Frontend.java:1282] 
85420d575b9ff4b9:402b8868] Analysis finished.


--
To view, visit http://gerrit.cloudera.org:8080/12129
To unsubscribe, visit http://gerrit.cloudera.org:8080/settings

Gerrit-Project: Impala-ASF
Gerrit-Branch: master
Gerrit-MessageType: comment
Gerrit-Change-Id: I6634ef9d1a7346339f24f2d40a7a3aa36a535da8
Gerrit-Change-Number: 12129
Gerrit-PatchSet: 3
Gerrit-Owner: Philip Zeyliger 
Gerrit-Reviewer: Impala Public Jenkins 
Gerrit-Reviewer: Paul Rogers 
Gerrit-Reviewer: Philip Zeyliger 
Gerrit-Reviewer: Tim Armstrong 
Gerrit-Reviewer: Zoltan Borok-Nagy 
Gerrit-Reviewer: Zoram Thanga 
Gerrit-Comment-Date: Wed, 09 Jan 2019 19:18:56 +
Gerrit-HasComments: No

[Impala-ASF-CR] IMPALA-6664: Tag log statements with fragment or query ids.

2019-01-09 Thread Zoltan Borok-Nagy (Code Review) 
Zoltan Borok-Nagy has posted comments on this change. ( 
http://gerrit.cloudera.org:8080/12129 )

Change subject: IMPALA-6664: Tag log statements with fragment or query ids.
..


Patch Set 2:

(5 comments)

http://gerrit.cloudera.org:8080/#/c/12129/3/be/src/common/thread-debug-info.h
File be/src/common/thread-debug-info.h:

http://gerrit.cloudera.org:8080/#/c/12129/3/be/src/common/thread-debug-info.h@a94
PS3, Line 94:
We should copy parent_.thread_name_, or remove it from struct 'ParentInfo'.


http://gerrit.cloudera.org:8080/#/c/12129/2/be/src/common/thread-debug-info.h
File be/src/common/thread-debug-info.h:

http://gerrit.cloudera.org:8080/#/c/12129/2/be/src/common/thread-debug-info.h@a116
PS2, Line 116:
> Yep, I'll wait for Zoltan's input.
Yeah, the idea was to make it readable when debugging a minidump or core file 
and you can't invoke PrintId() from GDB.
But since PrintId() just prints the hex of members 'hi' and 'lo', it should be 
fine.

But we also need to update 'lib/python/impala_py_lib/gdb/impala-gdb.py' because 
currently it expects 'instance_id_' to be a string.

It also breaks the unit tests in 'thread-debug-info-test.cc'.


http://gerrit.cloudera.org:8080/#/c/12129/3/be/src/exec/hdfs-scan-node-base.cc
File be/src/exec/hdfs-scan-node-base.cc:

http://gerrit.cloudera.org:8080/#/c/12129/3/be/src/exec/hdfs-scan-node-base.cc@37
PS3, Line 37: #include "common/thread-debug-info.h"
nit: do we need this include? Might be better to include it in hdfs-scan-node.cc


http://gerrit.cloudera.org:8080/#/c/12129/3/be/src/exec/hdfs-scan-node.cc
File be/src/exec/hdfs-scan-node.cc:

http://gerrit.cloudera.org:8080/#/c/12129/3/be/src/exec/hdfs-scan-node.cc@325
PS3, Line 325: ThreadDebugInfo* parent_thread_debug_info = 
GetThreadDebugInfo();
 : DCHECK(parent_thread_debug_info != nullptr);
 : auto fn = [this, first_thread, scanner_thread_reservation,
 :  parent_thread_debug_info]() {
 :   
GetThreadDebugInfo()->SetParentInfo(parent_thread_debug_info);
Since we use Thread::Create() later, 
https://github.com/apache/impala/blob/274e96bd147b5d91872c441c3a600fa8d5295bbe/be/src/util/thread.cc#L317
 and 
https://github.com/apache/impala/blob/274e96bd147b5d91872c441c3a600fa8d5295bbe/be/src/util/thread.cc#L351
 should do this automatically.
Doesn't it happen?


http://gerrit.cloudera.org:8080/#/c/12129/3/be/src/runtime/io/disk-io-mgr.cc
File be/src/runtime/io/disk-io-mgr.cc:

http://gerrit.cloudera.org:8080/#/c/12129/3/be/src/runtime/io/disk-io-mgr.cc@424
PS3, Line 424: // We are now working on behalf of a query, so set thread 
state appropriately.
 : GetThreadDebugInfo()->SetQueryId(worker_context->query_id());
 : 
GetThreadDebugInfo()->SetInstanceId(worker_context->instance_id());
Fyi, IMPALA-6254 and IMPALA-6417 is about to make this automated. Maybe we 
could add a TODO here and mention those Jiras.



--
To view, visit http://gerrit.cloudera.org:8080/12129
To unsubscribe, visit http://gerrit.cloudera.org:8080/settings

Gerrit-Project: Impala-ASF
Gerrit-Branch: master
Gerrit-MessageType: comment
Gerrit-Change-Id: I6634ef9d1a7346339f24f2d40a7a3aa36a535da8
Gerrit-Change-Number: 12129
Gerrit-PatchSet: 2
Gerrit-Owner: Philip Zeyliger 
Gerrit-Reviewer: Impala Public Jenkins 
Gerrit-Reviewer: Paul Rogers 
Gerrit-Reviewer: Philip Zeyliger 
Gerrit-Reviewer: Tim Armstrong 
Gerrit-Reviewer: Zoltan Borok-Nagy 
Gerrit-Reviewer: Zoram Thanga 
Gerrit-Comment-Date: Wed, 09 Jan 2019 11:25:26 +
Gerrit-HasComments: Yes

[Impala-ASF-CR] IMPALA-6664: Tag log statements with fragment or query ids.

2019-01-08 Thread Paul Rogers (Code Review) 
Paul Rogers has posted comments on this change. ( 
http://gerrit.cloudera.org:8080/12129 )

Change subject: IMPALA-6664: Tag log statements with fragment or query ids.
..


Patch Set 3:

Does/should this fix up the Java side messages as well? May be some 
configuration in Log4J that produces a result similar to what you've achieved 
on the C++ side.


--
To view, visit http://gerrit.cloudera.org:8080/12129
To unsubscribe, visit http://gerrit.cloudera.org:8080/settings

Gerrit-Project: Impala-ASF
Gerrit-Branch: master
Gerrit-MessageType: comment
Gerrit-Change-Id: I6634ef9d1a7346339f24f2d40a7a3aa36a535da8
Gerrit-Change-Number: 12129
Gerrit-PatchSet: 3
Gerrit-Owner: Philip Zeyliger 
Gerrit-Reviewer: Impala Public Jenkins 
Gerrit-Reviewer: Paul Rogers 
Gerrit-Reviewer: Philip Zeyliger 
Gerrit-Reviewer: Tim Armstrong 
Gerrit-Reviewer: Zoltan Borok-Nagy 
Gerrit-Reviewer: Zoram Thanga 
Gerrit-Comment-Date: Wed, 09 Jan 2019 06:47:17 +
Gerrit-HasComments: No

[Impala-ASF-CR] IMPALA-6664: Tag log statements with fragment or query ids.

2019-01-08 Thread Philip Zeyliger (Code Review) 
Philip Zeyliger has posted comments on this change. ( 
http://gerrit.cloudera.org:8080/12129 )

Change subject: IMPALA-6664: Tag log statements with fragment or query ids.
..


Patch Set 3:

Turns out that it's kind of bad that we don't "clear" the contexts reliably. 
When the threads get re-used you get confusing results for things like "Found 
local timezone "UTC"". It's fixable with a context wrapper of some sort, so 
I'll write one of those.


--
To view, visit http://gerrit.cloudera.org:8080/12129
To unsubscribe, visit http://gerrit.cloudera.org:8080/settings

Gerrit-Project: Impala-ASF
Gerrit-Branch: master
Gerrit-MessageType: comment
Gerrit-Change-Id: I6634ef9d1a7346339f24f2d40a7a3aa36a535da8
Gerrit-Change-Number: 12129
Gerrit-PatchSet: 3
Gerrit-Owner: Philip Zeyliger 
Gerrit-Reviewer: Impala Public Jenkins 
Gerrit-Reviewer: Philip Zeyliger 
Gerrit-Reviewer: Tim Armstrong 
Gerrit-Reviewer: Zoltan Borok-Nagy 
Gerrit-Reviewer: Zoram Thanga 
Gerrit-Comment-Date: Tue, 08 Jan 2019 21:21:37 +
Gerrit-HasComments: No

[Impala-ASF-CR] IMPALA-6664: Tag log statements with fragment or query ids.

2019-01-08 Thread Impala Public Jenkins (Code Review) 
Impala Public Jenkins has posted comments on this change. ( 
http://gerrit.cloudera.org:8080/12129 )

Change subject: IMPALA-6664: Tag log statements with fragment or query ids.
..


Patch Set 3:

Build Failed

https://jenkins.impala.io/job/gerrit-code-review-checks/1740/ : Initial code 
review checks failed. See linked job for details on the failure.


--
To view, visit http://gerrit.cloudera.org:8080/12129
To unsubscribe, visit http://gerrit.cloudera.org:8080/settings

Gerrit-Project: Impala-ASF
Gerrit-Branch: master
Gerrit-MessageType: comment
Gerrit-Change-Id: I6634ef9d1a7346339f24f2d40a7a3aa36a535da8
Gerrit-Change-Number: 12129
Gerrit-PatchSet: 3
Gerrit-Owner: Philip Zeyliger 
Gerrit-Reviewer: Impala Public Jenkins 
Gerrit-Reviewer: Philip Zeyliger 
Gerrit-Reviewer: Tim Armstrong 
Gerrit-Reviewer: Zoltan Borok-Nagy 
Gerrit-Reviewer: Zoram Thanga 
Gerrit-Comment-Date: Tue, 08 Jan 2019 20:20:35 +
Gerrit-HasComments: No

[Impala-ASF-CR] IMPALA-6664: Tag log statements with fragment or query ids.

2019-01-08 Thread Tim Armstrong (Code Review) 
Tim Armstrong has posted comments on this change. ( 
http://gerrit.cloudera.org:8080/12129 )

Change subject: IMPALA-6664: Tag log statements with fragment or query ids.
..


Patch Set 3:

(3 comments)

http://gerrit.cloudera.org:8080/#/c/12129/2/be/src/runtime/io/request-context.h
File be/src/runtime/io/request-context.h:

http://gerrit.cloudera.org:8080/#/c/12129/2/be/src/runtime/io/request-context.h@403
PS2, Line 403:   TUniqueId instance_id_;
> I didn't do this because I don't think a request-context could be working n
Yeah that is true.

I think if it's an invariant that they're always set we should just pass them 
in via RegisterContext/the constructor.


http://gerrit.cloudera.org:8080/#/c/12129/3/tests/observability/test_log_fragments.py
File tests/observability/test_log_fragments.py:

http://gerrit.cloudera.org:8080/#/c/12129/3/tests/observability/test_log_fragments.py@26
PS3, Line 26:   def test_log_framgnets(self):
typo:fragments


http://gerrit.cloudera.org:8080/#/c/12129/3/tests/observability/test_log_fragments.py@34
PS3, Line 34: profile
nit: result (since it's not a profile, rather an ImpalaBeeswaxResult)



--
To view, visit http://gerrit.cloudera.org:8080/12129
To unsubscribe, visit http://gerrit.cloudera.org:8080/settings

Gerrit-Project: Impala-ASF
Gerrit-Branch: master
Gerrit-MessageType: comment
Gerrit-Change-Id: I6634ef9d1a7346339f24f2d40a7a3aa36a535da8
Gerrit-Change-Number: 12129
Gerrit-PatchSet: 3
Gerrit-Owner: Philip Zeyliger 
Gerrit-Reviewer: Impala Public Jenkins 
Gerrit-Reviewer: Philip Zeyliger 
Gerrit-Reviewer: Tim Armstrong 
Gerrit-Reviewer: Zoltan Borok-Nagy 
Gerrit-Reviewer: Zoram Thanga 
Gerrit-Comment-Date: Tue, 08 Jan 2019 19:59:33 +
Gerrit-HasComments: Yes

[Impala-ASF-CR] IMPALA-6664: Tag log statements with fragment or query ids.

2019-01-08 Thread Impala Public Jenkins (Code Review) 
Impala Public Jenkins has posted comments on this change. ( 
http://gerrit.cloudera.org:8080/12129 )

Change subject: IMPALA-6664: Tag log statements with fragment or query ids.
..


Patch Set 3:

(2 comments)

http://gerrit.cloudera.org:8080/#/c/12129/3/tests/observability/test_log_fragments.py
File tests/observability/test_log_fragments.py:

http://gerrit.cloudera.org:8080/#/c/12129/3/tests/observability/test_log_fragments.py@23
PS3, Line 23: class TestLogFragments(ImpalaTestSuite):
flake8: E302 expected 2 blank lines, found 1


http://gerrit.cloudera.org:8080/#/c/12129/3/tests/observability/test_log_fragments.py@44
PS3, Line 44: e
flake8: E501 line too long (94 > 90 characters)



--
To view, visit http://gerrit.cloudera.org:8080/12129
To unsubscribe, visit http://gerrit.cloudera.org:8080/settings

Gerrit-Project: Impala-ASF
Gerrit-Branch: master
Gerrit-MessageType: comment
Gerrit-Change-Id: I6634ef9d1a7346339f24f2d40a7a3aa36a535da8
Gerrit-Change-Number: 12129
Gerrit-PatchSet: 3
Gerrit-Owner: Philip Zeyliger 
Gerrit-Reviewer: Impala Public Jenkins 
Gerrit-Reviewer: Philip Zeyliger 
Gerrit-Reviewer: Tim Armstrong 
Gerrit-Reviewer: Zoltan Borok-Nagy 
Gerrit-Reviewer: Zoram Thanga 
Gerrit-Comment-Date: Tue, 08 Jan 2019 19:51:44 +
Gerrit-HasComments: Yes

[Impala-ASF-CR] IMPALA-6664: Tag log statements with fragment or query ids.

2019-01-08 Thread Philip Zeyliger (Code Review) 
Philip Zeyliger has posted comments on this change. ( 
http://gerrit.cloudera.org:8080/12129 )

Change subject: IMPALA-6664: Tag log statements with fragment or query ids.
..


Patch Set 2:

(7 comments)

http://gerrit.cloudera.org:8080/#/c/12129/2/be/src/common/logging.cc
File be/src/common/logging.cc:

http://gerrit.cloudera.org:8080/#/c/12129/2/be/src/common/logging.cc@55
PS2, Line 55: kZeroUniqueId
> ZERO_UNIQUE_ID
Done


http://gerrit.cloudera.org:8080/#/c/12129/2/be/src/common/logging.cc@63
PS2, Line 63:   if (id == kZeroUniqueId) {
> nit: one line
Done


http://gerrit.cloudera.org:8080/#/c/12129/2/be/src/common/logging.cc@67
PS2, Line 67:   if (changed != nullptr) {
> nit: one line
Done


http://gerrit.cloudera.org:8080/#/c/12129/2/be/src/common/thread-debug-info.h
File be/src/common/thread-debug-info.h:

http://gerrit.cloudera.org:8080/#/c/12129/2/be/src/common/thread-debug-info.h@a116
PS2, Line 116:
> I think there was some reason this was a human-readable string - maybe to m
Yep, I'll wait for Zoltan's input.


http://gerrit.cloudera.org:8080/#/c/12129/2/be/src/common/thread-debug-info.h@118
PS2, Line 118:   TUniqueId query_id_;
> Can you document that these are 0 if this thread isn't part of a query or i
Done


http://gerrit.cloudera.org:8080/#/c/12129/2/be/src/runtime/io/request-context.h
File be/src/runtime/io/request-context.h:

http://gerrit.cloudera.org:8080/#/c/12129/2/be/src/runtime/io/request-context.h@403
PS2, Line 403:   TUniqueId instance_id_;
> Can you document that these are 0 if we're not working on behalf of a query
I didn't do this because I don't think a request-context could be working not 
on behalf of a query. Happy to comment anyway. Do you think i should set this 
in RegisterContext() rather than around it?


http://gerrit.cloudera.org:8080/#/c/12129/2/tests/common/impala_test_suite.py
File tests/common/impala_test_suite.py:

http://gerrit.cloudera.org:8080/#/c/12129/2/tests/common/impala_test_suite.py@843
PS2, Line 843:   def assert_impalad_log_contains(self, level, line_regex, 
expected_count=1):
> I don't see anything using this.
d'oh; forgot to add the test file.



--
To view, visit http://gerrit.cloudera.org:8080/12129
To unsubscribe, visit http://gerrit.cloudera.org:8080/settings

Gerrit-Project: Impala-ASF
Gerrit-Branch: master
Gerrit-MessageType: comment
Gerrit-Change-Id: I6634ef9d1a7346339f24f2d40a7a3aa36a535da8
Gerrit-Change-Number: 12129
Gerrit-PatchSet: 2
Gerrit-Owner: Philip Zeyliger 
Gerrit-Reviewer: Impala Public Jenkins 
Gerrit-Reviewer: Philip Zeyliger 
Gerrit-Reviewer: Tim Armstrong 
Gerrit-Reviewer: Zoltan Borok-Nagy 
Gerrit-Reviewer: Zoram Thanga 
Gerrit-Comment-Date: Tue, 08 Jan 2019 19:49:54 +
Gerrit-HasComments: Yes

[Impala-ASF-CR] IMPALA-6664: Tag log statements with fragment or query ids.

2019-01-08 Thread Philip Zeyliger (Code Review) 
Hello Zoltan Borok-Nagy, Zoram Thanga, Tim Armstrong, Impala Public Jenkins,

I'd like you to reexamine a change. Please visit

http://gerrit.cloudera.org:8080/12129

to look at the new patch set (#3).

Change subject: IMPALA-6664: Tag log statements with fragment or query ids.
..

IMPALA-6664: Tag log statements with fragment or query ids.

This implements much of the desire in IMPALA-6664 to tag all log
statements with their query ids. It re-uses the existing ThreadDebugInfo
infrastructure as well as the existing
InstallLogMessageListenerFunction() patch to glog (currently used for
log redaction) to prefix log messages with fragment ids or query ids,
when available. The fragment id is the query id with the last bits
incremented, so it's possible to correlate a given query's log messages.
For example:

  $ grep 85420d575b9ff4b9:402b8868 logs/cluster/impalad.INFO
  I0108 10:39:16.453958 14752 impala-server.cc:1052] 
85420d575b9ff4b9:402b8868] Registered query 
query_id=85420d575b9ff4b9:402b8868 
session_id=aa45e480434f0516:101ae5ac12679d94
  I0108 10:39:16.454738 14752 Frontend.java:1242] 
85420d575b9ff4b9:402b8868] Analyzing query: select count(*) from 
tpcds.web_sales
  I0108 10:39:16.456627 14752 Frontend.java:1282] 
85420d575b9ff4b9:402b8868] Analysis finished.
  I0108 10:39:16.463538 14818 admission-controller.cc:598] 
85420d575b9ff4b9:402b8868] Schedule for 
id=85420d575b9ff4b9:402b8868 in pool_name=default-pool 
per_host_mem_estimate=180.02 MB PoolConfig: max_requests=-1 max_queued=200 
max_mem=-1.00 B
  I0108 10:39:16.463603 14818 admission-controller.cc:603] 
85420d575b9ff4b9:402b8868] Stats: agg_num_running=0, agg_num_queued=0, 
agg_mem_reserved=0,  local_host(local_mem_admitted=0, num_admitted_running=0, 
num_queued=0, backend_mem_reserved=0)
  I0108 10:39:16.463780 14818 admission-controller.cc:635] 
85420d575b9ff4b9:402b8868] Admitted query 
id=85420d575b9ff4b9:402b8868
  I0108 10:39:16.463896 14818 coordinator.cc:93] 
85420d575b9ff4b9:402b8868] Exec() 
query_id=85420d575b9ff4b9:402b8868 stmt=select count(*) from 
tpcds.web_sales
  I0108 10:39:16.464795 14818 coordinator.cc:356] 
85420d575b9ff4b9:402b8868] starting execution on 2 backends for 
query_id=85420d575b9ff4b9:402b8868
  I0108 10:39:16.466384 24891 impala-internal-service.cc:49] 
ExecQueryFInstances(): query_id=85420d575b9ff4b9:402b8868 
coord=pannier.sf.cloudera.com:22000 #instances=2
  I0108 10:39:16.467339 14818 coordinator.cc:370] 
85420d575b9ff4b9:402b8868] started execution on 2 backends for 
query_id=85420d575b9ff4b9:402b8868
  I0108 10:39:16.467536 14823 query-state.cc:579] 
85420d575b9ff4b9:402b8868] Executing instance. 
instance_id=85420d575b9ff4b9:402b8868 fragment_idx=0 
per_fragment_instance_idx=0 coord_state_idx=0 #in-flight=1
  I0108 10:39:16.467627 14824 query-state.cc:579] 
85420d575b9ff4b9:402b88680001] Executing instance. 
instance_id=85420d575b9ff4b9:402b88680001 fragment_idx=1 
per_fragment_instance_idx=0 coord_state_idx=0 #in-flight=2
  I0108 10:39:16.820933 14824 query-state.cc:587] 
85420d575b9ff4b9:402b88680001] Instance completed. 
instance_id=85420d575b9ff4b9:402b88680001 #in-flight=1 status=OK
  I0108 10:39:17.122299 14823 krpc-data-stream-mgr.cc:294] 
85420d575b9ff4b9:402b8868] DeregisterRecvr(): 
fragment_instance_id=85420d575b9ff4b9:402b8868, node=2
  I0108 10:39:17.123500 24038 coordinator.cc:709] Backend completed: 
host=pannier.sf.cloudera.com:22001 remaining=2 
query_id=85420d575b9ff4b9:402b8868
  I0108 10:39:17.123509 24038 coordinator-backend-state.cc:265] 
query_id=85420d575b9ff4b9:402b8868: first in-progress backend: 
pannier.sf.cloudera.com:22000
  I0108 10:39:17.167752 14752 impala-beeswax-server.cc:197] 
85420d575b9ff4b9:402b8868] get_results_metadata(): 
query_id=85420d575b9ff4b9:402b8868
  I0108 10:39:17.168762 14752 coordinator.cc:483] 
85420d575b9ff4b9:402b8868] ExecState: query 
id=85420d575b9ff4b9:402b8868 execution completed
  I0108 10:39:17.168808 14752 coordinator.cc:608] 
85420d575b9ff4b9:402b8868] Coordinator waiting for backends to finish, 
1 remaining. query_id=85420d575b9ff4b9:402b8868
  I0108 10:39:17.168880 14823 query-state.cc:587] 
85420d575b9ff4b9:402b8868] Instance completed. 
instance_id=85420d575b9ff4b9:402b8868 #in-flight=0 status=OK
  I0108 10:39:17.168977 14821 query-state.cc:252] UpdateBackendExecState(): 
last report for 85420d575b9ff4b9:402b8868
  I0108 10:39:17.174401 24038 coordinator.cc:709] Backend completed: 
host=pannier.sf.cloudera.com:22000 remaining=1 
query_id=85420d575b9ff4b9:402b8868
  I0108 10:39:17.174513 14752 coordinator.cc:814] 
85420d575b9ff4b9:402b8868] Release admission control resources for

[Impala-ASF-CR] IMPALA-6664: Tag log statements with fragment or query ids.

2019-01-08 Thread Impala Public Jenkins (Code Review) 
Impala Public Jenkins has posted comments on this change. ( 
http://gerrit.cloudera.org:8080/12129 )

Change subject: IMPALA-6664: Tag log statements with fragment or query ids.
..


Patch Set 2:

Build Failed

https://jenkins.impala.io/job/gerrit-code-review-checks/1739/ : Initial code 
review checks failed. See linked job for details on the failure.


--
To view, visit http://gerrit.cloudera.org:8080/12129
To unsubscribe, visit http://gerrit.cloudera.org:8080/settings

Gerrit-Project: Impala-ASF
Gerrit-Branch: master
Gerrit-MessageType: comment
Gerrit-Change-Id: I6634ef9d1a7346339f24f2d40a7a3aa36a535da8
Gerrit-Change-Number: 12129
Gerrit-PatchSet: 2
Gerrit-Owner: Philip Zeyliger 
Gerrit-Reviewer: Impala Public Jenkins 
Gerrit-Reviewer: Philip Zeyliger 
Gerrit-Reviewer: Tim Armstrong 
Gerrit-Reviewer: Zoltan Borok-Nagy 
Gerrit-Reviewer: Zoram Thanga 
Gerrit-Comment-Date: Tue, 08 Jan 2019 19:40:14 +
Gerrit-HasComments: No

[Impala-ASF-CR] IMPALA-6664: Tag log statements with fragment or query ids.

2019-01-08 Thread Tim Armstrong (Code Review) 
Tim Armstrong has posted comments on this change. ( 
http://gerrit.cloudera.org:8080/12129 )

Change subject: IMPALA-6664: Tag log statements with fragment or query ids.
..


Patch Set 2:

(7 comments)

http://gerrit.cloudera.org:8080/#/c/12129/2/be/src/common/logging.cc
File be/src/common/logging.cc:

http://gerrit.cloudera.org:8080/#/c/12129/2/be/src/common/logging.cc@55
PS2, Line 55: kZeroUniqueId
ZERO_UNIQUE_ID

(This is a difference from the google C++ style for better or worse: 
https://cwiki.apache.org/confluence/pages/viewpage.action?pageId=65868536)


http://gerrit.cloudera.org:8080/#/c/12129/2/be/src/common/logging.cc@63
PS2, Line 63:   if (id == kZeroUniqueId) {
nit: one line


http://gerrit.cloudera.org:8080/#/c/12129/2/be/src/common/logging.cc@67
PS2, Line 67:   if (changed != nullptr) {
nit: one line


http://gerrit.cloudera.org:8080/#/c/12129/2/be/src/common/thread-debug-info.h
File be/src/common/thread-debug-info.h:

http://gerrit.cloudera.org:8080/#/c/12129/2/be/src/common/thread-debug-info.h@a116
PS2, Line 116:
I think there was some reason this was a human-readable string - maybe to make 
it more readable if we printed in the minidump handler? Zoltan probably 
remembers. Anyway, this seems OK too.


http://gerrit.cloudera.org:8080/#/c/12129/2/be/src/common/thread-debug-info.h@118
PS2, Line 118:   TUniqueId query_id_;
Can you document that these are 0 if this thread isn't part of a query or 
instanc?


http://gerrit.cloudera.org:8080/#/c/12129/2/be/src/runtime/io/request-context.h
File be/src/runtime/io/request-context.h:

http://gerrit.cloudera.org:8080/#/c/12129/2/be/src/runtime/io/request-context.h@403
PS2, Line 403:   TUniqueId instance_id_;
Can you document that these are 0 if we're not working on behalf of a query?


http://gerrit.cloudera.org:8080/#/c/12129/2/tests/common/impala_test_suite.py
File tests/common/impala_test_suite.py:

http://gerrit.cloudera.org:8080/#/c/12129/2/tests/common/impala_test_suite.py@843
PS2, Line 843:   def assert_impalad_log_contains(self, level, line_regex, 
expected_count=1):
I don't see anything using this.



--
To view, visit http://gerrit.cloudera.org:8080/12129
To unsubscribe, visit http://gerrit.cloudera.org:8080/settings

Gerrit-Project: Impala-ASF
Gerrit-Branch: master
Gerrit-MessageType: comment
Gerrit-Change-Id: I6634ef9d1a7346339f24f2d40a7a3aa36a535da8
Gerrit-Change-Number: 12129
Gerrit-PatchSet: 2
Gerrit-Owner: Philip Zeyliger 
Gerrit-Reviewer: Impala Public Jenkins 
Gerrit-Reviewer: Philip Zeyliger 
Gerrit-Reviewer: Tim Armstrong 
Gerrit-Reviewer: Zoltan Borok-Nagy 
Gerrit-Reviewer: Zoram Thanga 
Gerrit-Comment-Date: Tue, 08 Jan 2019 19:34:01 +
Gerrit-HasComments: Yes

[Impala-ASF-CR] IMPALA-6664: Tag log statements with fragment or query ids.

2019-01-08 Thread Philip Zeyliger (Code Review) 
Hello Zoltan Borok-Nagy, Zoram Thanga, Tim Armstrong, Impala Public Jenkins,

I'd like you to reexamine a change. Please visit

http://gerrit.cloudera.org:8080/12129

to look at the new patch set (#2).

Change subject: IMPALA-6664: Tag log statements with fragment or query ids.
..

IMPALA-6664: Tag log statements with fragment or query ids.

This implements much of the desire in IMPALA-6664 to tag all log
statements with their query ids. It re-uses the existing ThreadDebugInfo
infrastructure as well as the existing
InstallLogMessageListenerFunction() patch to glog (currently used for
log redaction) to prefix log messages with fragment ids or query ids,
when available. The fragment id is the query id with the last bits
incremented, so it's possible to correlate a given query's log messages.
For example:

  $ grep 85420d575b9ff4b9:402b8868 logs/cluster/impalad.INFO
  I0108 10:39:16.453958 14752 impala-server.cc:1052] 
85420d575b9ff4b9:402b8868] Registered query 
query_id=85420d575b9ff4b9:402b8868 
session_id=aa45e480434f0516:101ae5ac12679d94
  I0108 10:39:16.454738 14752 Frontend.java:1242] 
85420d575b9ff4b9:402b8868] Analyzing query: select count(*) from 
tpcds.web_sales
  I0108 10:39:16.456627 14752 Frontend.java:1282] 
85420d575b9ff4b9:402b8868] Analysis finished.
  I0108 10:39:16.463538 14818 admission-controller.cc:598] 
85420d575b9ff4b9:402b8868] Schedule for 
id=85420d575b9ff4b9:402b8868 in pool_name=default-pool 
per_host_mem_estimate=180.02 MB PoolConfig: max_requests=-1 max_queued=200 
max_mem=-1.00 B
  I0108 10:39:16.463603 14818 admission-controller.cc:603] 
85420d575b9ff4b9:402b8868] Stats: agg_num_running=0, agg_num_queued=0, 
agg_mem_reserved=0,  local_host(local_mem_admitted=0, num_admitted_running=0, 
num_queued=0, backend_mem_reserved=0)
  I0108 10:39:16.463780 14818 admission-controller.cc:635] 
85420d575b9ff4b9:402b8868] Admitted query 
id=85420d575b9ff4b9:402b8868
  I0108 10:39:16.463896 14818 coordinator.cc:93] 
85420d575b9ff4b9:402b8868] Exec() 
query_id=85420d575b9ff4b9:402b8868 stmt=select count(*) from 
tpcds.web_sales
  I0108 10:39:16.464795 14818 coordinator.cc:356] 
85420d575b9ff4b9:402b8868] starting execution on 2 backends for 
query_id=85420d575b9ff4b9:402b8868
  I0108 10:39:16.466384 24891 impala-internal-service.cc:49] 
ExecQueryFInstances(): query_id=85420d575b9ff4b9:402b8868 
coord=pannier.sf.cloudera.com:22000 #instances=2
  I0108 10:39:16.467339 14818 coordinator.cc:370] 
85420d575b9ff4b9:402b8868] started execution on 2 backends for 
query_id=85420d575b9ff4b9:402b8868
  I0108 10:39:16.467536 14823 query-state.cc:579] 
85420d575b9ff4b9:402b8868] Executing instance. 
instance_id=85420d575b9ff4b9:402b8868 fragment_idx=0 
per_fragment_instance_idx=0 coord_state_idx=0 #in-flight=1
  I0108 10:39:16.467627 14824 query-state.cc:579] 
85420d575b9ff4b9:402b88680001] Executing instance. 
instance_id=85420d575b9ff4b9:402b88680001 fragment_idx=1 
per_fragment_instance_idx=0 coord_state_idx=0 #in-flight=2
  I0108 10:39:16.820933 14824 query-state.cc:587] 
85420d575b9ff4b9:402b88680001] Instance completed. 
instance_id=85420d575b9ff4b9:402b88680001 #in-flight=1 status=OK
  I0108 10:39:17.122299 14823 krpc-data-stream-mgr.cc:294] 
85420d575b9ff4b9:402b8868] DeregisterRecvr(): 
fragment_instance_id=85420d575b9ff4b9:402b8868, node=2
  I0108 10:39:17.123500 24038 coordinator.cc:709] Backend completed: 
host=pannier.sf.cloudera.com:22001 remaining=2 
query_id=85420d575b9ff4b9:402b8868
  I0108 10:39:17.123509 24038 coordinator-backend-state.cc:265] 
query_id=85420d575b9ff4b9:402b8868: first in-progress backend: 
pannier.sf.cloudera.com:22000
  I0108 10:39:17.167752 14752 impala-beeswax-server.cc:197] 
85420d575b9ff4b9:402b8868] get_results_metadata(): 
query_id=85420d575b9ff4b9:402b8868
  I0108 10:39:17.168762 14752 coordinator.cc:483] 
85420d575b9ff4b9:402b8868] ExecState: query 
id=85420d575b9ff4b9:402b8868 execution completed
  I0108 10:39:17.168808 14752 coordinator.cc:608] 
85420d575b9ff4b9:402b8868] Coordinator waiting for backends to finish, 
1 remaining. query_id=85420d575b9ff4b9:402b8868
  I0108 10:39:17.168880 14823 query-state.cc:587] 
85420d575b9ff4b9:402b8868] Instance completed. 
instance_id=85420d575b9ff4b9:402b8868 #in-flight=0 status=OK
  I0108 10:39:17.168977 14821 query-state.cc:252] UpdateBackendExecState(): 
last report for 85420d575b9ff4b9:402b8868
  I0108 10:39:17.174401 24038 coordinator.cc:709] Backend completed: 
host=pannier.sf.cloudera.com:22000 remaining=1 
query_id=85420d575b9ff4b9:402b8868
  I0108 10:39:17.174513 14752 coordinator.cc:814] 
85420d575b9ff4b9:402b8868] Release admission control resources for

[Impala-ASF-CR] IMPALA-6664: Tag log statements with fragment or query ids.

2019-01-08 Thread Philip Zeyliger (Code Review) 
Philip Zeyliger has posted comments on this change. ( 
http://gerrit.cloudera.org:8080/12129 )

Change subject: IMPALA-6664: Tag log statements with fragment or query ids.
..


Patch Set 2:

(4 comments)

Please take another look!

http://gerrit.cloudera.org:8080/#/c/12129/1/be/src/common/logging.cc
File be/src/common/logging.cc:

http://gerrit.cloudera.org:8080/#/c/12129/1/be/src/common/logging.cc@55
PS1, Line 55: const TUniqueId kZeroUniqueId;
> Nice. I think the next step would be to (re)define VLOG_QUERY or something 
> like it, that would be called for debug logging in the query/FINST lifecycle 
> code?

With the updated change, this is pretty much done. There may be threads (like 
krpc sender) that don't know or haven't annotated what query they're working 
on, but this captures a good chunk of it.


http://gerrit.cloudera.org:8080/#/c/12129/1/be/src/common/logging.cc@55
PS1, Line 55: Uniqu
> std:: not needed
Done


http://gerrit.cloudera.org:8080/#/c/12129/1/be/src/common/logging.cc@65
PS1, Line 65:   }
> The API chosen is a little unfortunate since it requires reallocating 's' t
Indeed. Todd probably says we should use async_logger. If we have an opinion on 
that, that would be a good opportunity to figure out if we want to make this 
interface better. In practice, though, we've not seen this show up in 
profiling, so I'm ignoring it for now.


http://gerrit.cloudera.org:8080/#/c/12129/1/be/src/common/logging.cc@68
PS1, Line 68: ue;
> same here
Done



--
To view, visit http://gerrit.cloudera.org:8080/12129
To unsubscribe, visit http://gerrit.cloudera.org:8080/settings

Gerrit-Project: Impala-ASF
Gerrit-Branch: master
Gerrit-MessageType: comment
Gerrit-Change-Id: I6634ef9d1a7346339f24f2d40a7a3aa36a535da8
Gerrit-Change-Number: 12129
Gerrit-PatchSet: 2
Gerrit-Owner: Philip Zeyliger 
Gerrit-Reviewer: Impala Public Jenkins 
Gerrit-Reviewer: Philip Zeyliger 
Gerrit-Reviewer: Tim Armstrong 
Gerrit-Reviewer: Zoltan Borok-Nagy 
Gerrit-Reviewer: Zoram Thanga 
Gerrit-Comment-Date: Tue, 08 Jan 2019 19:10:47 +
Gerrit-HasComments: Yes