Repository navigation
Failed to submit <n> logs #4346
Description
We enabled Stackdriver logging for our application this morning and are seeing excessive exceptions since:
Failed to submit 1 logs., due to:
[...]
grpc._channel._Rendezvous: <_Rendezvous of RPC that terminated with (StatusCode.DEADLINE_EXCEEDED, Deadline Exceeded)>
During handling of the above exception, another exception occurred:
[...]
google.gax.errors.RetryError: RetryError(Exception occurred in retry method that was not classified as transient, caused by <_Rendezvous of RPC that terminated with (StatusCode.DEADLINE_EXCEEDED, Deadline Exceeded)>)
I don't think we're hitting the API limit (1k rps, and we're averaging at 60rps). I do see some 403 errors reported in the API console, but not sure those relate to these deadline exceeded.
We're seeing this at an about hourly frequency across our 10 instances. This application itself runs in GCP. This is using the CloudLoggingHandler with async / batching transport.
- Specify the API at the beginning of the title (for example, "BigQuery: ...")
General, Core, and Other are also allowed as types
Stackdriver logging
- OS type and version
Debian 9
- Python version and virtual environment information
python --version
Python 3.5.3
- google-cloud-python version
pip show google-cloud,pip show google-<service>orpip freeze
# pip freeze | grep google
gapic-google-cloud-datastore-v1==0.15.3
gapic-google-cloud-error-reporting-v1beta1==0.15.3
gapic-google-cloud-logging-v2==0.91.3
google-api-core==0.1.1
google-auth==1.2.0
google-auth-httplib2==0.0.2
google-cloud==0.29.0
google-cloud-bigquery==0.28.0
google-cloud-bigtable==0.28.1
google-cloud-core==0.28.0
google-cloud-datastore==1.4.0
google-cloud-dns==0.28.0
google-cloud-error-reporting==0.28.0
google-cloud-firestore==0.28.0
google-cloud-language==0.31.0
google-cloud-logging==1.4.0
google-cloud-monitoring==0.28.0
google-cloud-pubsub==0.29.0
google-cloud-resource-manager==0.28.0
google-cloud-runtimeconfig==0.28.0
google-cloud-spanner==0.29.0
google-cloud-speech==0.30.0
google-cloud-storage==1.6.0
google-cloud-trace==0.16.0
google-cloud-translate==1.3.0
google-cloud-videointelligence==0.28.0
google-cloud-vision==0.28.0
google-gax==0.15.15
google-resumable-media==0.3.1
googleapis-common-protos==1.5.3
grpc-google-iam-v1==0.11.4
proto-google-cloud-datastore-v1==0.90.4
proto-google-cloud-error-reporting-v1beta1==0.15.3
proto-google-cloud-logging-v2==0.91.3
- Stacktrace if available
2017-11-04 14:44:56,211 E Failed to submit 1 logs.
Traceback (most recent call last):
File "/usr/local/lib/python3.5/site-packages/google/gax/retry.py", line 121, in inner
return to_call(*args)
File "/usr/local/lib/python3.5/site-packages/google/gax/retry.py", line 68, in inner
return a_func(*updated_args, **kwargs)
File "/usr/local/lib/python3.5/site-packages/grpc/_channel.py", line 492, in __call__
return _end_unary_response_blocking(state, call, False, deadline)
File "/usr/local/lib/python3.5/site-packages/grpc/_channel.py", line 440, in _end_unary_response_blocking
raise _Rendezvous(state, None, None, deadline)
grpc._channel._Rendezvous: <_Rendezvous of RPC that terminated with (StatusCode.DEADLINE_EXCEEDED, Deadline Exceeded)>
During handling of the above exception, another exception occurred:
Traceback (most recent call last):
File "/usr/local/lib/python3.5/site-packages/google/cloud/logging/handlers/transports/background_thread.py", line 98, in _safely_commit_batch
batch.commit()
File "/usr/local/lib/python3.5/site-packages/google/cloud/logging/logger.py", line 549, in commit
client.logging_api.write_entries(entries, **kwargs)
File "/usr/local/lib/python3.5/site-packages/google/cloud/logging/_gax.py", line 131, in write_entries
partial_success=partial_success, options=options)
File "/usr/local/lib/python3.5/site-packages/google/cloud/gapic/logging/v2/logging_service_v2_client.py", line 353, in write_log_entries
return self._write_log_entries(request, options)
File "/usr/local/lib/python3.5/site-packages/google/gax/api_callable.py", line 452, in inner
return api_caller(api_call, this_settings, request)
File "/usr/local/lib/python3.5/site-packages/google/gax/api_callable.py", line 438, in base_caller
return api_call(*args)
File "/usr/local/lib/python3.5/site-packages/google/gax/api_callable.py", line 376, in inner
return a_func(*args, **kwargs)
File "/usr/local/lib/python3.5/site-packages/google/gax/retry.py", line 127, in inner
' classified as transient', exception)
google.gax.errors.RetryError: RetryError(Exception occurred in retry method that was not classified as transient, caused by <_Rendezvous of RPC that terminated with (StatusCode.DEADLINE_EXCEEDED, Deadline Exceeded)>)
- Steps to reproduce
- Code example
client = cloud_logging.Client()
resource = cloud_resource.Resource(...)
handler = cloud_handlers.CloudLoggingHandler(client,
name=...,
resource=resource)
logger = logging.getLogger()
logger.addHandler(handler)
logger = logging.getLogger('google.cloud.logging.handlers')
logger.setLevel(logging.INFO)
Activity
[-]Stackdriver logging: Failed to submit <n> logs ([/-][+]Failed to submit <n> logs ([/+]sebbov commentedon Nov 18, 2017
What is the ETA for a fix? Our logs are flooding with exceptions of this logging client.
ilrico commentedon Jan 5, 2018
same problem here, same setup (Debian Stretch), python 3.5.3. any fix arose ?
[-]Failed to submit <n> logs ([/-][+]Failed to submit <n> logs[/+]tseaver commentedon Jan 5, 2018
@waprin, do you have any insight here?
waprin commentedon Jan 5, 2018
Historically, the most common reason bugs occur here is either:
This is what the
setup_logginghelper helps avoid, if you don't want to use it, check out what it does and maybe do something similar.If you don't mind making sync logging calls ,switching to using the synchronous transport will will fix 2) (and also be a useful data point if it does. since then the issue is very likely concurrency bug)
handler = CloudLoggingHandler(transport=google.cloud.logging.handlers.transports.SyncTransport)So, you can help verify whether it's 1) by disabling log propagation (see
setup_logging) or 2) by switching toSyncTransport, and then once we know which it is, it will be easier to fix.ilrico commentedon Jan 6, 2018
I would go for 2. because:
hope it helps
theacodes commentedon Jan 8, 2018
Deadline exceeded likely means that the request for some reason or another failed to complete in the allotted time. This doesn't necessarily indicate an issue with the library, rather, it can indicate that either the network was congested and unable to send the requests within the deadline or that the logging service failed to respond within the deadline. Switching transports is unlikely to solve this, as it'll just "move" where the deadline exceeded error is bubbled.
I'm not sure what to do here. One thing we should definitely do is regenerate the underlying code to pick up the new retry/timeout behavior in api_core, which will allow us the possibility of giving users the ability to change the deadline.
theacodes commentedon Jan 26, 2018
logging's underlying code has been regenerated and I suspect this issue may disappear. I'm going to close this issue for now, but please comment if it reappears with the latest version.
Kharms commentedon Feb 8, 2019
I'm periodically getting this error.