tests.system.test_session_api: test_transaction_execute_update_then_insert_commit failed

This test failed!

To configure my behavior, see the Flaky Bot documentation.

If I'm commenting on this issue too often, add the flakybot: quiet label and
I will stop commenting.

commit: 5629bac
buildURL: Build Status, Sponge
status: failed

Test output

args = (session: "projects/precise-truck-742/instances/google-cloud-1628673888891/databases/test_sessions_1628676428092/sessi...    string_value: "Phlyntstone"
      }
      values {
        string_value: "wylma@example.com"
      }
    }
  }
}
,)
kwargs = {'metadata': [('google-cloud-resource-prefix', 'projects/precise-truck-742/instances/google-cloud-1628673888891/databa...axZl0EgaLfm_VRoTVUUUzobMWu17ImOQFfnSBEQ'), ('x-goog-api-client', 'gl-python/3.8.6 grpc/1.39.0 gax/1.31.1 gccl/3.7.0')]}
@six.wraps(callable_)
def error_remapped_callable(*args, **kwargs):
    try:


      return callable_(*args, **kwargs)


.nox/system-3-8/lib/python3.8/site-packages/google/api_core/grpc_helpers.py:67:

self = <grpc._channel._UnaryUnaryMultiCallable object at 0x7f581f1ebe50>

request = session: "projects/precise-truck-742/instances/google-cloud-1628673888891/databases/test_sessions_1628676428092/sessio...      string_value: "Phlyntstone"

}

values {

string_value: "wylma@example.com"

}

}

}

}
timeout = None

metadata = [('google-cloud-resource-prefix', 'projects/precise-truck-742/instances/google-cloud-1628673888891/databases/test_sess...6axZl0EgaLfm_VRoTVUUUzobMWu17ImOQFfnSBEQ'), ('x-goog-api-client', 'gl-python/3.8.6 grpc/1.39.0 gax/1.31.1 gccl/3.7.0')]

credentials = None, wait_for_ready = None, compression = None
def __call__(self,
             request,
             timeout=None,
             metadata=None,
             credentials=None,
             wait_for_ready=None,
             compression=None):
    state, call, = self._blocking(request, timeout, metadata, credentials,
                                  wait_for_ready, compression)


  return _end_unary_response_blocking(state, call, False, None)


.nox/system-3-8/lib/python3.8/site-packages/grpc/_channel.py:946:

state = <grpc._channel._RPCState object at 0x7f581f2b4220>

call = <grpc._cython.cygrpc.SegregatedCall object at 0x7f581f287b40>

with_call = False, deadline = None
def _end_unary_response_blocking(state, call, with_call, deadline):
    if state.code is grpc.StatusCode.OK:
        if with_call:
            rendezvous = _MultiThreadedRendezvous(state, call, None, deadline)
            return state.response, rendezvous
        else:
            return state.response
    else:


      raise _InactiveRpcError(state)


E           grpc._channel._InactiveRpcError: <_InactiveRpcError of RPC that terminated with:

E           	status = StatusCode.ABORTED

E           	details = "Transaction aborted. Database schema probably changed during transaction, retry may succeed."

E           	debug_error_string = "{"created":"@1628676436.164783797","description":"Error received from peer ipv4:74.125.195.95:443","file":"src/core/lib/surface/call.cc","file_line":1069,"grpc_message":"Transaction aborted. Database schema probably changed during transaction, retry may succeed.","grpc_status":10}"

E           >
.nox/system-3-8/lib/python3.8/site-packages/grpc/_channel.py:849: _InactiveRpcError
The above exception was the direct cause of the following exception:
sessions_database = <google.cloud.spanner_v1.database.Database object at 0x7f581f1f95e0>

sessions_to_delete = [<google.cloud.spanner_v1.session.Session object at 0x7f581f2b4640>]
@_helpers.retry_mabye_conflict
def test_transaction_execute_update_then_insert_commit(
    sessions_database, sessions_to_delete
):
    # [START spanner_test_dml_with_mutation]
    # [START spanner_test_dml_update]
    sd = _sample_data

    session = sessions_database.session()
    session.create()
    sessions_to_delete.append(session)

    with session.batch() as batch:
        batch.delete(sd.TABLE, sd.ALL)

    insert_statement = list(_generate_insert_statements())[0]

    with session.transaction() as transaction:
        rows = list(transaction.read(sd.TABLE, sd.COLUMNS, sd.ALL))
        assert rows == []

        row_count = transaction.execute_update(insert_statement)
        assert row_count == 1


      transaction.insert(sd.TABLE, sd.COLUMNS, sd.ROW_DATA[1:])


tests/system/test_session_api.py:654:

google/cloud/spanner_v1/transaction.py:375: in exit

self.commit()

google/cloud/spanner_v1/transaction.py:162: in commit

response = api.commit(request=request, metadata=metadata,)

google/cloud/spanner_v1/services/spanner/client.py:1323: in commit

response = rpc(request, retry=retry, timeout=timeout, metadata=metadata,)

.nox/system-3-8/lib/python3.8/site-packages/google/api_core/gapic_v1/method.py:145: in call

return wrapped_func(*args, **kwargs)

.nox/system-3-8/lib/python3.8/site-packages/google/api_core/retry.py:286: in retry_wrapped_func

return retry_target(

.nox/system-3-8/lib/python3.8/site-packages/google/api_core/retry.py:189: in retry_target

return target()

.nox/system-3-8/lib/python3.8/site-packages/google/api_core/grpc_helpers.py:69: in error_remapped_callable

six.raise_from(exceptions.from_grpc_error(exc), exc)

value = None

from_value = <_InactiveRpcError of RPC that terminated with:

status = StatusCode.ABORTED

details = "Transaction aborted. Database...ge":"Transaction aborted. Database schema probably changed during transaction, retry may succeed.","grpc_status":10}"



???

E   google.api_core.exceptions.Aborted: 409 Transaction aborted. Database schema probably changed during transaction, retry may succeed.

:3: Aborted

Test passed for commit 9746062 (Build Status, Sponge)! Closing this issue.

@tseaver

@tseaver This test failed due to:

E   google.api_core.exceptions.Aborted: 409 Transaction aborted. Database schema probably changed during transaction, retry may succeed.

Cloud Spanner has a high ABORTED rate and so the client automatically retries transaction when using run_in_transaction. I think the five tests that directly call session.transaction should be marked with @_helpers.retry_mabye_aborted_txn (note: could also fix the maybe typo) to prevent these flakes. I wonder if the reason this didn't come up previously was related to the test order.

@larkee

@larkee That sounds like a good diagnosis.

Note that on master, that helper has already been renamed, and that the functions which call session.transaction directly (without raising an error) are already wrapped. The flaky-bot, however, runs its nightly continuous job against the last release tag: we would need to get a new release made to get it running with those changes: see PR #480.

Looks like this issue is flaky. 😟

I'm going to leave this open and stop commenting.

A human should fix and close this.

commit: d557a8d
buildURL: Build Status, Sponge
status: failed

Test output

args = (session: "projects/precise-truck-742/instances/google-cloud-1628791402371/databases/test_sessions_1628795131656/sessi...contacts"
columns: "contact_id"
columns: "first_name"
columns: "last_name"
columns: "email"
key_set {
  all_: true
}
,)
kwargs = {'metadata': [('google-cloud-resource-prefix', 'projects/precise-truck-742/instances/google-cloud-1628791402371/databa...BJMZ0Hxg2geSpNHMoGGg'), ('x-goog-api-client', 'gl-python/3.8.6 grpc/1.39.0 gax/1.31.1 gccl/3.7.0')], 'timeout': 3600.0}
result = <_MultiThreadedRendezvous of RPC that terminated with:
	status = StatusCode.ABORTED
	details = "Transaction was aborte...","file":"src/core/lib/surface/call.cc","file_line":1069,"grpc_message":"Transaction was aborted.","grpc_status":10}"
>
prefetch_first = True
@general_helpers.wraps(callable_)
def error_remapped_callable(*args, **kwargs):
    try:
        result = callable_(*args, **kwargs)
        # Auto-fetching the first result causes PubSub client's streaming pull
        # to hang when re-opening the stream, thus we need examine the hacky
        # hidden flag to see if pre-fetching is disabled.
        # https://github.com/googleapis/python-pubsub/issues/93#issuecomment-630762257
        prefetch_first = getattr(callable_, "_prefetch_first_result_", True)


      return _StreamingResponseIterator(


            result, prefetch_first_result=prefetch_first
        )

.nox/system-3-8/lib/python3.8/site-packages/google/api_core/grpc_helpers.py:160:

self = <google.api_core.grpc_helpers._StreamingResponseIterator object at 0x7f8b51fd6550>

wrapped = <_MultiThreadedRendezvous of RPC that terminated with:

status = StatusCode.ABORTED

details = "Transaction was aborte...","file":"src/core/lib/surface/call.cc","file_line":1069,"grpc_message":"Transaction was aborted.","grpc_status":10}"


prefetch_first_result = True
def __init__(self, wrapped, prefetch_first_result=True):
    self._wrapped = wrapped

    # This iterator is used in a retry context, and returned outside after init.
    # gRPC will not throw an exception until the stream is consumed, so we need
    # to retrieve the first result, in order to fail, in order to trigger a retry.
    try:
        if prefetch_first_result:


          self._stored_first_result = six.next(self._wrapped)


.nox/system-3-8/lib/python3.8/site-packages/google/api_core/grpc_helpers.py:83:

self = <_MultiThreadedRendezvous of RPC that terminated with:

status = StatusCode.ABORTED

details = "Transaction was aborte...","file":"src/core/lib/surface/call.cc","file_line":1069,"grpc_message":"Transaction was aborted.","grpc_status":10}"


def __next__(self):


  return self._next()


.nox/system-3-8/lib/python3.8/site-packages/grpc/_channel.py:426:

self = <_MultiThreadedRendezvous of RPC that terminated with:

status = StatusCode.ABORTED

details = "Transaction was aborte...","file":"src/core/lib/surface/call.cc","file_line":1069,"grpc_message":"Transaction was aborted.","grpc_status":10}"


def _next(self):
    with self._state.condition:
        if self._state.code is None:
            event_handler = _event_handler(self._state,
                                           self._response_deserializer)
            self._state.due.add(cygrpc.OperationType.receive_message)
            operating = self._call.operate(
                (cygrpc.ReceiveMessageOperation(_EMPTY_FLAGS),),
                event_handler)
            if not operating:
                self._state.due.remove(cygrpc.OperationType.receive_message)
        elif self._state.code is grpc.StatusCode.OK:
            raise StopIteration()
        else:
            raise self

        def _response_ready():
            return (self._state.response is not None or
                    (cygrpc.OperationType.receive_message
                     not in self._state.due and
                     self._state.code is not None))

        _common.wait(self._state.condition.wait, _response_ready)
        if self._state.response is not None:
            response = self._state.response
            self._state.response = None
            return response
        elif cygrpc.OperationType.receive_message not in self._state.due:
            if self._state.code is grpc.StatusCode.OK:
                raise StopIteration()
            elif self._state.code is not None:


              raise self


E                   grpc._channel._MultiThreadedRendezvous: <_MultiThreadedRendezvous of RPC that terminated with:

E                   	status = StatusCode.ABORTED

E                   	details = "Transaction was aborted."

E                   	debug_error_string = "{"created":"@1628795137.281355071","description":"Error received from peer ipv4:74.125.195.95:443","file":"src/core/lib/surface/call.cc","file_line":1069,"grpc_message":"Transaction was aborted.","grpc_status":10}"

E                   >
.nox/system-3-8/lib/python3.8/site-packages/grpc/_channel.py:826: _MultiThreadedRendezvous
The above exception was the direct cause of the following exception:
sessions_database = <google.cloud.spanner_v1.database.Database object at 0x7f8b5223c700>

sessions_to_delete = [<google.cloud.spanner_v1.session.Session object at 0x7f8b5221ba60>]
@_helpers.retry_mabye_conflict
def test_transaction_execute_update_then_insert_commit(
    sessions_database, sessions_to_delete
):
    # [START spanner_test_dml_with_mutation]
    # [START spanner_test_dml_update]
    sd = _sample_data

    session = sessions_database.session()
    session.create()
    sessions_to_delete.append(session)

    with session.batch() as batch:
        batch.delete(sd.TABLE, sd.ALL)

    insert_statement = list(_generate_insert_statements())[0]

    with session.transaction() as transaction:


      rows = list(transaction.read(sd.TABLE, sd.COLUMNS, sd.ALL))


tests/system/test_session_api.py:648:

google/cloud/spanner_v1/streamed.py:149: in iter

self._consume_next()

google/cloud/spanner_v1/streamed.py:121: in _consume_next

response = six.next(self._response_iterator)

google/cloud/spanner_v1/snapshot.py:59: in _restart_on_unavailable

iterator = method(request=request)

google/cloud/spanner_v1/services/spanner/client.py:1112: in streaming_read

response = rpc(request, retry=retry, timeout=timeout, metadata=metadata,)

.nox/system-3-8/lib/python3.8/site-packages/google/api_core/gapic_v1/method.py:145: in call

return wrapped_func(*args, **kwargs)

.nox/system-3-8/lib/python3.8/site-packages/google/api_core/timeout.py:102: in func_with_timeout

return func(*args, **kwargs)

.nox/system-3-8/lib/python3.8/site-packages/google/api_core/grpc_helpers.py:164: in error_remapped_callable

six.raise_from(exceptions.from_grpc_error(exc), exc)

value = None

from_value = <_MultiThreadedRendezvous of RPC that terminated with:

status = StatusCode.ABORTED

details = "Transaction was aborte...","file":"src/core/lib/surface/call.cc","file_line":1069,"grpc_message":"Transaction was aborted.","grpc_status":10}"



???

E   google.api_core.exceptions.Aborted: 409 Transaction was aborted.

:3: Aborted

Again, making a new release will cause the continuous build to use the fixed test code.

Navigation Menu

Repository navigation

tests.system.test_session_api: test_transaction_execute_update_then_insert_commit failed #485

Metadata

Assignees

Labels

Type

Projects

Milestone

Relationships

Development

tests.system.test_session_api: test_transaction_execute_update_then_insert_commit failed #485

Description

Activity

flaky-bot commented on Aug 12, 2021

larkee commented on Aug 12, 2021

tseaver commented on Aug 12, 2021

tseaver commented on Aug 12, 2021

flaky-bot commented on Aug 12, 2021

tseaver commented on Aug 13, 2021

Metadata

Metadata

Assignees

Labels

Type

Projects

Milestone

Relationships

Development

Issue actions