Reduce exception info for chadmin output #235

kirillgarbar · 2024-09-23T16:09:53Z

Only last exception without diagnose is printed, but full exception is logged.

Logged example:

Traceback (most recent call last):
  File "/usr/local/lib/python3.8/dist-packages/urllib3/connection.py", line 174, in _new_conn
    conn = connection.create_connection(
  File "/usr/local/lib/python3.8/dist-packages/urllib3/util/connection.py", line 72, in create_connection
    for res in socket.getaddrinfo(host, port, family, socket.SOCK_STREAM):
  File "/usr/lib/python3.8/socket.py", line 918, in getaddrinfo
    for res in _socket.getaddrinfo(host, port, family, type, proto, flags):
socket.gaierror: [Errno -3] Temporary failure in name resolution

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.8/dist-packages/botocore/httpsession.py", line 443, in send
    urllib_response = conn.urlopen(
  File "/usr/local/lib/python3.8/dist-packages/urllib3/connectionpool.py", line 802, in urlopen
    retries = retries.increment(
  File "/usr/local/lib/python3.8/dist-packages/urllib3/util/retry.py", line 527, in increment
    raise six.reraise(type(error), error, _stacktrace)
  File "/usr/local/lib/python3.8/dist-packages/urllib3/packages/six.py", line 770, in reraise
    raise value
  File "/usr/local/lib/python3.8/dist-packages/urllib3/connectionpool.py", line 716, in urlopen
    httplib_response = self._make_request(
  File "/usr/local/lib/python3.8/dist-packages/urllib3/connectionpool.py", line 416, in _make_request
    conn.request(method, url, **httplib_request_kw)
  File "/usr/local/lib/python3.8/dist-packages/urllib3/connection.py", line 244, in request
    super(HTTPConnection, self).request(method, url, body=body, headers=headers)
  File "/usr/lib/python3.8/http/client.py", line 1256, in request
    self._send_request(method, url, body, headers, encode_chunked)
  File "/usr/local/lib/python3.8/dist-packages/botocore/awsrequest.py", line 94, in _send_request
    rval = super()._send_request(
  File "/usr/lib/python3.8/http/client.py", line 1302, in _send_request
    self.endheaders(body, encode_chunked=encode_chunked)
  File "/usr/lib/python3.8/http/client.py", line 1251, in endheaders
    self._send_output(message_body, encode_chunked=encode_chunked)
  File "/usr/local/lib/python3.8/dist-packages/botocore/awsrequest.py", line 123, in _send_output
    self.send(msg)
  File "/usr/local/lib/python3.8/dist-packages/botocore/awsrequest.py", line 218, in send
    return super().send(str)
  File "/usr/lib/python3.8/http/client.py", line 951, in send
    self.connect()
  File "/usr/local/lib/python3.8/dist-packages/urllib3/connection.py", line 205, in connect
    conn = self._new_conn()
  File "/usr/local/lib/python3.8/dist-packages/urllib3/connection.py", line 186, in _new_conn
    raise NewConnectionError(
urllib3.exceptions.NewConnectionError: <botocore.awsrequest.AWSHTTPConnection object at 0x70cccc2aa910>: Failed to establish a new connection: [Errno -3] Temporary failure in name resolution

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.8/dist-packages/ch_tools/chadmin/cli/chadmin_group.py", line 52, in wrapper
    cmd_callback(*a, **kw)
  File "/usr/local/lib/python3.8/dist-packages/click/decorators.py", line 26, in new_func
    return f(get_current_context(), *args, **kwargs)
  File "/usr/local/lib/python3.8/dist-packages/ch_tools/chadmin/cli/object_storage_group.py", line 142, in clean_command
    deleted, total_size = clean(
  File "/usr/local/lib/python3.8/dist-packages/ch_tools/common/commands/clean_object_storage.py", line 75, in clean
    deleted, total_size = _clean_object_storage(
  File "/usr/local/lib/python3.8/dist-packages/ch_tools/common/commands/clean_object_storage.py", line 116, in _clean_object_storage
    _traverse_object_storage(ctx, listing_table, from_time, to_time, prefix)
  File "/usr/local/lib/python3.8/dist-packages/ch_tools/common/commands/clean_object_storage.py", line 202, in _traverse_object_storage
    for obj in s3_object_storage_iterator(
  File "/usr/local/lib/python3.8/dist-packages/ch_tools/chadmin/internal/object_storage/s3_iterator.py", line 27, in s3_object_storage_iterator
    for obj in bucket.objects.filter(Prefix=object_name_prefix):
  File "/usr/local/lib/python3.8/dist-packages/boto3/resources/collection.py", line 81, in __iter__
    for page in self.pages():
  File "/usr/local/lib/python3.8/dist-packages/boto3/resources/collection.py", line 171, in pages
    for page in pages:
  File "/usr/local/lib/python3.8/dist-packages/botocore/paginate.py", line 264, in __iter__
    response = self._make_request(current_kwargs)
  File "/usr/local/lib/python3.8/dist-packages/botocore/paginate.py", line 352, in _make_request
    return self._method(**current_kwargs)
  File "/usr/local/lib/python3.8/dist-packages/botocore/client.py", line 508, in _api_call
    return self._make_api_call(operation_name, kwargs)
  File "/usr/local/lib/python3.8/dist-packages/botocore/client.py", line 894, in _make_api_call
    http, parsed_response = self._make_request(
  File "/usr/local/lib/python3.8/dist-packages/botocore/client.py", line 917, in _make_request
    return self._endpoint.make_request(operation_model, request_dict)
  File "/usr/local/lib/python3.8/dist-packages/botocore/endpoint.py", line 116, in make_request
    return self._send_request(request_dict, operation_model)
  File "/usr/local/lib/python3.8/dist-packages/botocore/endpoint.py", line 199, in _send_request
    while self._needs_retry(
  File "/usr/local/lib/python3.8/dist-packages/botocore/endpoint.py", line 351, in _needs_retry
    responses = self._event_emitter.emit(
  File "/usr/local/lib/python3.8/dist-packages/botocore/hooks.py", line 412, in emit
    return self._emitter.emit(aliased_event_name, **kwargs)
  File "/usr/local/lib/python3.8/dist-packages/botocore/hooks.py", line 256, in emit
    return self._emit(event_name, kwargs)
  File "/usr/local/lib/python3.8/dist-packages/botocore/hooks.py", line 239, in _emit
    response = handler(**kwargs)
  File "/usr/local/lib/python3.8/dist-packages/botocore/retryhandler.py", line 207, in __call__
    if self._checker(**checker_kwargs):
  File "/usr/local/lib/python3.8/dist-packages/botocore/retryhandler.py", line 284, in __call__
    should_retry = self._should_retry(
  File "/usr/local/lib/python3.8/dist-packages/botocore/retryhandler.py", line 320, in _should_retry
    return self._checker(attempt_number, response, caught_exception)
  File "/usr/local/lib/python3.8/dist-packages/botocore/retryhandler.py", line 363, in __call__
    checker_response = checker(
  File "/usr/local/lib/python3.8/dist-packages/botocore/retryhandler.py", line 247, in __call__
    return self._check_caught_exception(
  File "/usr/local/lib/python3.8/dist-packages/botocore/retryhandler.py", line 416, in _check_caught_exception
    raise caught_exception
  File "/usr/local/lib/python3.8/dist-packages/botocore/endpoint.py", line 278, in _do_get_response
    http_response = self._send(request)
  File "/usr/local/lib/python3.8/dist-packages/botocore/endpoint.py", line 374, in _send
    return self.http_session.send(request)
  File "/usr/local/lib/python3.8/dist-packages/botocore/httpsession.py", line 472, in send
    raise EndpointConnectionError(endpoint_url=request.url, error=e)
botocore.exceptions.EndpointConnectionError: Could not connect to the endpoint URL: "http://minio01:9000/cloud-storage-test?prefix=data%2F&encoding-type=url"

Printed example:

Traceback (most recent call last):
  File "/usr/local/lib/python3.8/dist-packages/ch_tools/chadmin/cli/chadmin_group.py", line 52, in wrapper
    cmd_callback(*a, **kw)
  File "/usr/local/lib/python3.8/dist-packages/click/decorators.py", line 26, in new_func
    return f(get_current_context(), *args, **kwargs)
  File "/usr/local/lib/python3.8/dist-packages/ch_tools/chadmin/cli/object_storage_group.py", line 142, in clean_command
    deleted, total_size = clean(
  File "/usr/local/lib/python3.8/dist-packages/ch_tools/common/commands/clean_object_storage.py", line 75, in clean
    deleted, total_size = _clean_object_storage(
  File "/usr/local/lib/python3.8/dist-packages/ch_tools/common/commands/clean_object_storage.py", line 116, in _clean_object_storage
    _traverse_object_storage(ctx, listing_table, from_time, to_time, prefix)
  File "/usr/local/lib/python3.8/dist-packages/ch_tools/common/commands/clean_object_storage.py", line 202, in _traverse_object_storage
    for obj in s3_object_storage_iterator(
  File "/usr/local/lib/python3.8/dist-packages/ch_tools/chadmin/internal/object_storage/s3_iterator.py", line 27, in s3_object_storage_iterator
    for obj in bucket.objects.filter(Prefix=object_name_prefix):
  File "/usr/local/lib/python3.8/dist-packages/boto3/resources/collection.py", line 81, in __iter__
    for page in self.pages():
  File "/usr/local/lib/python3.8/dist-packages/boto3/resources/collection.py", line 171, in pages
    for page in pages:
  File "/usr/local/lib/python3.8/dist-packages/botocore/paginate.py", line 264, in __iter__
    response = self._make_request(current_kwargs)
  File "/usr/local/lib/python3.8/dist-packages/botocore/paginate.py", line 352, in _make_request
    return self._method(**current_kwargs)
  File "/usr/local/lib/python3.8/dist-packages/botocore/client.py", line 508, in _api_call
    return self._make_api_call(operation_name, kwargs)
  File "/usr/local/lib/python3.8/dist-packages/botocore/client.py", line 894, in _make_api_call
    http, parsed_response = self._make_request(
  File "/usr/local/lib/python3.8/dist-packages/botocore/client.py", line 917, in _make_request
    return self._endpoint.make_request(operation_model, request_dict)
  File "/usr/local/lib/python3.8/dist-packages/botocore/endpoint.py", line 116, in make_request
    return self._send_request(request_dict, operation_model)
  File "/usr/local/lib/python3.8/dist-packages/botocore/endpoint.py", line 199, in _send_request
    while self._needs_retry(
  File "/usr/local/lib/python3.8/dist-packages/botocore/endpoint.py", line 351, in _needs_retry
    responses = self._event_emitter.emit(
  File "/usr/local/lib/python3.8/dist-packages/botocore/hooks.py", line 412, in emit
    return self._emitter.emit(aliased_event_name, **kwargs)
  File "/usr/local/lib/python3.8/dist-packages/botocore/hooks.py", line 256, in emit
    return self._emit(event_name, kwargs)
  File "/usr/local/lib/python3.8/dist-packages/botocore/hooks.py", line 239, in _emit
    response = handler(**kwargs)
  File "/usr/local/lib/python3.8/dist-packages/botocore/retryhandler.py", line 207, in __call__
    if self._checker(**checker_kwargs):
  File "/usr/local/lib/python3.8/dist-packages/botocore/retryhandler.py", line 284, in __call__
    should_retry = self._should_retry(
  File "/usr/local/lib/python3.8/dist-packages/botocore/retryhandler.py", line 320, in _should_retry
    return self._checker(attempt_number, response, caught_exception)
  File "/usr/local/lib/python3.8/dist-packages/botocore/retryhandler.py", line 363, in __call__
    checker_response = checker(
  File "/usr/local/lib/python3.8/dist-packages/botocore/retryhandler.py", line 247, in __call__
    return self._check_caught_exception(
  File "/usr/local/lib/python3.8/dist-packages/botocore/retryhandler.py", line 416, in _check_caught_exception
    raise caught_exception
  File "/usr/local/lib/python3.8/dist-packages/botocore/endpoint.py", line 278, in _do_get_response
    http_response = self._send(request)
  File "/usr/local/lib/python3.8/dist-packages/botocore/endpoint.py", line 374, in _send
    return self.http_session.send(request)
  File "/usr/local/lib/python3.8/dist-packages/botocore/httpsession.py", line 472, in send
    raise EndpointConnectionError(endpoint_url=request.url, error=e)
botocore.exceptions.EndpointConnectionError: Could not connect to the endpoint URL: "http://minio01:9000/cloud-storage-test?prefix=data%2F&encoding-type=url"

kirillgarbar · 2024-09-24T11:45:07Z

Test fail is related to #231
Looks like the reason for different exceptions is that the same timeout is set both for requests and SYNC REPLICA query. Sometimes one timeout works faster than the other.
I think we can set request timeout to time_left so it will be bigger than replica_timeout.

ch_tools/chadmin/cli/wait_group.py

MikhailBurdukov · 2024-09-26T13:31:56Z

ch_tools/chadmin/cli/chadmin_group.py

+                logging.disable_stdout_logger()
                logging.exception("Command '{}' failed with error:", cmd.name)
+                logging.print_last_exception(e)


For another logging.exception( calls the behaviour will be as before? Should we log only the latest exc inside logging.exception?

logging.exception behaviour is not changed except for backtrace option which cuts unnecessary part of last stack trace:

File "/usr/bin/chadmin", line 8, in <module> sys.exit(main()) File "/opt/yandex/clickhouse-tools/lib/python3.6/site-packages/ch_tools/chadmin/chadmin_cli.py", line 152, in main cli.main() File "/opt/yandex/clickhouse-tools/lib/python3.6/site-packages/click/core.py", line 1053, in main rv = self.invoke(ctx) File "/opt/yandex/clickhouse-tools/lib/python3.6/site-packages/click/core.py", line 1659, in invoke return _process_result(sub_ctx.command.invoke(sub_ctx)) File "/opt/yandex/clickhouse-tools/lib/python3.6/site-packages/click/core.py", line 1659, in invoke return _process_result(sub_ctx.command.invoke(sub_ctx)) File "/opt/yandex/clickhouse-tools/lib/python3.6/site-packages/click/core.py", line 1395, in invoke return ctx.invoke(self.callback, **ctx.params) File "/opt/yandex/clickhouse-tools/lib/python3.6/site-packages/click/core.py", line 754, in invoke return __callback(*args, **kwargs) File "/opt/yandex/clickhouse-tools/lib/python3.6/site-packages/click/decorators.py", line 26, in new_func

logging.exception still logs all exceptions in case they are needed

Okey, so we don't want to enable it in all cases?
Also, maybe move it to separate method in logging or put it in the logging.exception with option(eg logging.exception(...., show_all_exceptions)) ? Think it will much more beautiful:)

There is no way to tell if we will need all exceptions or just one, that's why I think we should always log all of them. logging.exception is called only once per command, logs will not be flooded with exceptions anyway.

Or did you mean to put logging.print_last_exception(e) inside logging.exception?

Or did you mean to put logging.print_last_exception(e) inside logging.exception?

Yes

MikhailBurdukov · 2024-10-01T09:03:42Z

@kirillgarbar I made small refactoring, could you check and approve if everything is fine

kirillgarbar added 3 commits September 23, 2024 19:04

Reduce exception info for chadmin output

456fb2c

Merge remote-tracking branch 'kirillgarbar/main' into log-exception

8871af3

Fix isort

f034648

Set time_left as request timeout to fix flaky test

899b09a

MikhailBurdukov reviewed Sep 26, 2024

View reviewed changes

kirillgarbar and others added 3 commits September 26, 2024 16:50

Change timeouts

f55eab3

Move print_last_exception to logging.exception

cd44d95

Little bit of refactoring

1b29973

MikhailBurdukov approved these changes Oct 1, 2024

View reviewed changes

MikhailBurdukov merged commit 7a35efe into yandex:main Oct 1, 2024
20 checks passed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Reduce exception info for chadmin output #235

Reduce exception info for chadmin output #235

kirillgarbar commented Sep 23, 2024

kirillgarbar commented Sep 24, 2024

MikhailBurdukov Sep 26, 2024

kirillgarbar Sep 26, 2024

MikhailBurdukov Sep 26, 2024

kirillgarbar Sep 26, 2024

MikhailBurdukov Sep 26, 2024 •

edited

Loading

MikhailBurdukov commented Oct 1, 2024

Reduce exception info for chadmin output #235

Reduce exception info for chadmin output #235

Conversation

kirillgarbar commented Sep 23, 2024

kirillgarbar commented Sep 24, 2024

MikhailBurdukov Sep 26, 2024

Choose a reason for hiding this comment

kirillgarbar Sep 26, 2024

Choose a reason for hiding this comment

MikhailBurdukov Sep 26, 2024

Choose a reason for hiding this comment

kirillgarbar Sep 26, 2024

Choose a reason for hiding this comment

MikhailBurdukov Sep 26, 2024 • edited Loading

Choose a reason for hiding this comment

MikhailBurdukov commented Oct 1, 2024

MikhailBurdukov Sep 26, 2024 •

edited

Loading