Unable to clean up log entries created during system testing

[tseaver]

The projects.logs.delete API is returning 404s for logs which plainly exist.

>>> from gcloud.logging import Client
>>> client = Client()
>>> entries, token = client.list_entries(filter_='logName:system-tests')
>>> len(entries)
6
>>> loggers = set([entry.logger for entry in entries])
>>> len(loggers)
3
>>> [logger.name for logger in loggers]
[u'system-tests-logger-1458748033415', u'system-tests-logger-1458757743657', u'system-tests-logger-1458843354552']
>>> for logger in loggers:
...     logger.delete()
... 
Traceback (most recent call last):
  File "<stdin>", line 2, in <module>
  File "gcloud/logging/logger.py", line 130, in delete
    method='DELETE', path='/%s' % self.full_name)
  File "gcloud/connection.py", line 343, in api_request
    error_info=method + ' ' + url)
gcloud.exceptions.NotFound: 404 Requested entity was not found. (DELETE https://logging.googleapis.com/v2beta1/projects/citric-celerity-697/logs/system-tests-logger-1458748033415)

I can't delete those logs via the "Try It!" form for projects.logs.delete, either.

@jgeewax who is the back-end API contact person for logging?

[dhermes]

@jgeewax Bump

[tseaver]

@jgeewax who is the back-end API contact person for logging?

[tseaver]

@jgeewax this issue blocks merging the logging-api branch by EOQ (we have consistent system test failures).

[jgeewax]

@munangst can you help out with this? Apparently logs that exist are 404'ing when we try to delete them ?

[tseaver]

Weird, my logging system tests just started passing:

$ PYTHONPATH="_testing" .tox/system-tests/bin/python system_tests/run_system_test.py --package=logging
test_create_metric (logging_.TestLogging) ... ok
test_create_sink_bigquery_dataset (logging_.TestLogging) ... ok
test_create_sink_storage_bucket (logging_.TestLogging) ... ok
test_list_metrics (logging_.TestLogging) ... ok
test_log_struct (logging_.TestLogging) ... ok
test_log_text (logging_.TestLogging) ... ok
test_reload_metric (logging_.TestLogging) ... ok
test_reload_sink (logging_.TestLogging) ... ok
test_update_metric (logging_.TestLogging) ... ok
test_update_sink (logging_.TestLogging) ... ok

----------------------------------------------------------------------
Ran 10 tests in 33.164s

OK

[tseaver]

The teardown for test_log_struct and test_log_text had been failing with a 404 consistently until just now.

[munangst]

My first guess is that there's some sort of eventual-consistency race condition between creating a log stream (by writing the first entry to it) and deleting it. I checked our API logs and I couldn't find any entries being written to the log name in the original problem report, but for another log in your project projects/citric-celerity-697/logs/system-tests-logger-1459356049383 I see the following API calls:

2016-03-30 09:41:02.568378 200 POST /v2beta1/entries:write HTTP/1.1
2016-03-30 09:41:04.824128 404 DELETE /v2beta1/projects/citric-celerity-697/logs/system-tests-logger-1459356049383 HTTP/1.1
2016-03-30 09:41:05.031395 200 POST /v2beta1/entries:write HTTP/1.1
2016-03-30 09:41:09.191566 404 DELETE /v2beta1/projects/citric-celerity-697/logs/system-tests-logger-1459356049383 HTTP/1.1

That's not very much time between the initial write and the delete (2-4 sec), so you might be tickling a consistency problem between two backends. We'll investigate and see if we can reproduce it.

[munangst]

Opened Google internal bug 27931629 to track this.

[tseaver]

@munangst FWIW, note that in between the write and the delete, there was also a GET call to list entries for the logName used in the system test: that call succeeds.