Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[AIRFLOW-5322] Fix flaky gcp transfer hook test #5931

Merged
merged 3 commits into from
Aug 28, 2019

Conversation

turbaszek
Copy link
Member

This commit fixes flaky test (occured in python 3.5). I am not yet sure what was the
reason but I simplified the mocking and everything seems to be ok. The error seems to be introduced in this PR #5912

Make sure you have checked all steps below.

Jira

Description

  • Here are some details about my PR, including screenshots of any UI changes:
    This commit fixes flaky test (occured in python 3.5). I am not yet sure what was the
    reason but I simplified the mocking and everything seems to be ok. The error seems to be introduced in this PR [AIRFLOW-5309] Use assert_called_once or has_calls in tests #5912

Tests

  • My PR adds the following unit tests OR does not need testing for this extremely good reason:

Commits

  • My commits all reference Jira issues in their subject lines, and I have squashed multiple commits if they address the same issue. In addition, my commits follow the guidelines from "How to write a good git commit message":
    1. Subject is separated from body by a blank line
    2. Subject is limited to 50 characters (not including Jira issue reference)
    3. Subject does not end with a period
    4. Subject uses the imperative mood ("add", not "adding")
    5. Body wraps at 72 characters
    6. Body explains "what" and "why", not "how"

Documentation

  • In case of new functionality, my PR adds documentation that describes how to use it.
    • All the public functions and the classes in the PR contain docstrings that explain what it does
    • If you implement backwards incompatible changes, please leave a note in the Updating.md so we can assign it to a appropriate release

Code Quality

  • Passes flake8

This commit fixes flaky test (occured in python 3.5). I am not sure what was the
reason but I simplified the mocking and everything seems to be ok.
@turbaszek
Copy link
Member Author

Probably te reason was using json.dumps to create string representation of a dictionary:

json.dumps({"project_id": TEST_PROJECT_ID, "job_names": [job_name]})

and as we already know dictionaries in P3.5 does not preserve order, thus the result was

'{"job_names": ["transferJobs/test-job"], "project_id": "project-id"}'

or

'{"project_id": "project-id", "job_names": ["transferJobs/test-job"]}'

@turbaszek
Copy link
Member Author

@mik-laj @potiuk @kaxil WDYT?

@potiuk
Copy link
Member

potiuk commented Aug 27, 2019

I think it could be rathern another - known problem with has_calls mock library. It won't preserve the order of calls in python 3.5 sometimes if they are run very quickly one after the other. If that's the case, then I think better (and simpler) solution is to add any_order=True to assert_has_calls method. https://docs.python.org/3/library/unittest.mock.html#unittest.mock.Mock.assert_has_calls

@turbaszek
Copy link
Member Author

turbaszek commented Aug 27, 2019

That was one of the errors:

======================================================================
21) FAIL: test_wait_for_transfer_job (tests.gcp.hooks.test_cloud_storage_transfer_service.TestGCPTransferServiceHookWithPassedProjectId)
----------------------------------------------------------------------
   Traceback (most recent call last):
    /usr/local/lib/python3.5/unittest/mock.py line 1159 in patched
      return func(*args, **keywargs)
    tests/gcp/hooks/test_cloud_storage_transfer_service.py line 242 in test_wait_for_transfer_job
      list_method.assert_has_calls(calls)
    /usr/local/lib/python3.5/unittest/mock.py line 826 in assert_has_calls
      ) from cause
   AssertionError: Calls not found.
est-job"], "project_id": "project-id"}', name='transferOperations'), call().execute(num_retries=5)]
   Expected: [call(filter='{"job_names": ["transferJobs/test-job"], "project_id": "project-id"}', name='transferOperations'), call().execute(num_retries=5), call(filter='{"job_names": ["transferJobs/t
   Actual: [call(filter='{"project_id": "project-id", "job_names": ["transferJobs/test-job"]}', name='transferOperations'),
    call().execute(num_retries=5),
    call(filter='{"project_id": "project-id", "job_names": ["transferJobs/test-job"]}', name='transferOperations'),
    call().execute(num_retries=5)]

You can see that the filter parameter differs in key order. But it could be also issue of has_calls so I will add any_order=True.

@mik-laj mik-laj added the provider:google Google (including GCP) related issues label Aug 28, 2019
Copy link
Member

@mik-laj mik-laj left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I ran this test 100 times and now everything works. Personally, I don't like mocking methods from the current class, but I see that the mocked method has tests, so everything is fine.

root@e2d51ab1cdfc:/opt/airflow# seq 1 100 | xargs -n 1 -I {} nosetests tests.gcp.hooks.test_cloud_storage_transfer_service:TestGCPTransferServiceHookWithPassedProjectId.test_wait_for_transfer_job
.
----------------------------------------------------------------------
Ran 1 test in 0.002s

OK
[2019-08-28 13:43:58,828] {settings.py:202} DEBUG - Disposing DB connection pool (PID 1116)
.
----------------------------------------------------------------------
Ran 1 test in 0.002s

OK
[2019-08-28 13:44:00,655] {settings.py:202} DEBUG - Disposing DB connection pool (PID 1124)
.
----------------------------------------------------------------------
Ran 1 test in 0.003s

OK
[2019-08-28 13:44:02,495] {settings.py:202} DEBUG - Disposing DB connection pool (PID 1132)
.
----------------------------------------------------------------------
Ran 1 test in 0.002s

OK
[2019-08-28 13:44:04,326] {settings.py:202} DEBUG - Disposing DB connection pool (PID 1140)
.
----------------------------------------------------------------------
Ran 1 test in 0.002s

OK
[2019-08-28 13:44:06,123] {settings.py:202} DEBUG - Disposing DB connection pool (PID 1148)
.
----------------------------------------------------------------------
Ran 1 test in 0.002s

OK
[2019-08-28 13:44:07,942] {settings.py:202} DEBUG - Disposing DB connection pool (PID 1156)
.
----------------------------------------------------------------------
Ran 1 test in 0.001s

OK
[2019-08-28 13:44:09,751] {settings.py:202} DEBUG - Disposing DB connection pool (PID 1164)
.
----------------------------------------------------------------------
Ran 1 test in 0.002s

OK
[2019-08-28 13:44:11,565] {settings.py:202} DEBUG - Disposing DB connection pool (PID 1172)
.
----------------------------------------------------------------------
Ran 1 test in 0.001s

OK
[2019-08-28 13:44:13,376] {settings.py:202} DEBUG - Disposing DB connection pool (PID 1180)
.
----------------------------------------------------------------------
Ran 1 test in 0.001s

OK
[2019-08-28 13:44:15,243] {settings.py:202} DEBUG - Disposing DB connection pool (PID 1188)
.
----------------------------------------------------------------------
Ran 1 test in 0.002s

OK
[2019-08-28 13:44:16,992] {settings.py:202} DEBUG - Disposing DB connection pool (PID 1196)
.
----------------------------------------------------------------------
Ran 1 test in 0.001s

OK
[2019-08-28 13:44:18,811] {settings.py:202} DEBUG - Disposing DB connection pool (PID 1204)
.
----------------------------------------------------------------------
Ran 1 test in 0.001s

OK
[2019-08-28 13:44:20,564] {settings.py:202} DEBUG - Disposing DB connection pool (PID 1212)
.
----------------------------------------------------------------------
Ran 1 test in 0.001s

OK
[2019-08-28 13:44:22,328] {settings.py:202} DEBUG - Disposing DB connection pool (PID 1220)
.
----------------------------------------------------------------------
Ran 1 test in 0.002s

OK
[2019-08-28 13:44:24,099] {settings.py:202} DEBUG - Disposing DB connection pool (PID 1228)
.
----------------------------------------------------------------------
Ran 1 test in 0.001s

OK
[2019-08-28 13:44:25,889] {settings.py:202} DEBUG - Disposing DB connection pool (PID 1236)
.
----------------------------------------------------------------------
Ran 1 test in 0.001s

OK
[2019-08-28 13:44:27,766] {settings.py:202} DEBUG - Disposing DB connection pool (PID 1244)
.
----------------------------------------------------------------------
Ran 1 test in 0.002s

OK
[2019-08-28 13:44:29,655] {settings.py:202} DEBUG - Disposing DB connection pool (PID 1252)
.
----------------------------------------------------------------------
Ran 1 test in 0.001s

OK
[2019-08-28 13:44:31,444] {settings.py:202} DEBUG - Disposing DB connection pool (PID 1260)
.
----------------------------------------------------------------------
Ran 1 test in 0.002s

OK
[2019-08-28 13:44:33,298] {settings.py:202} DEBUG - Disposing DB connection pool (PID 1268)
.
----------------------------------------------------------------------
Ran 1 test in 0.002s

OK
[2019-08-28 13:44:35,110] {settings.py:202} DEBUG - Disposing DB connection pool (PID 1276)
.
----------------------------------------------------------------------
Ran 1 test in 0.002s

OK
[2019-08-28 13:44:37,142] {settings.py:202} DEBUG - Disposing DB connection pool (PID 1284)
.
----------------------------------------------------------------------
Ran 1 test in 0.002s

OK
[2019-08-28 13:44:39,097] {settings.py:202} DEBUG - Disposing DB connection pool (PID 1292)
.
----------------------------------------------------------------------
Ran 1 test in 0.001s

OK
[2019-08-28 13:44:41,035] {settings.py:202} DEBUG - Disposing DB connection pool (PID 1300)
.
----------------------------------------------------------------------
Ran 1 test in 0.003s

OK
[2019-08-28 13:44:43,069] {settings.py:202} DEBUG - Disposing DB connection pool (PID 1308)
.
----------------------------------------------------------------------
Ran 1 test in 0.003s

OK
[2019-08-28 13:44:45,005] {settings.py:202} DEBUG - Disposing DB connection pool (PID 1316)
.
----------------------------------------------------------------------
Ran 1 test in 0.001s

OK
[2019-08-28 13:44:46,966] {settings.py:202} DEBUG - Disposing DB connection pool (PID 1324)
.
----------------------------------------------------------------------
Ran 1 test in 0.001s

OK
[2019-08-28 13:44:48,773] {settings.py:202} DEBUG - Disposing DB connection pool (PID 1332)
.
----------------------------------------------------------------------
Ran 1 test in 0.001s

OK
[2019-08-28 13:44:50,606] {settings.py:202} DEBUG - Disposing DB connection pool (PID 1340)
.
----------------------------------------------------------------------
Ran 1 test in 0.001s

OK
[2019-08-28 13:44:52,408] {settings.py:202} DEBUG - Disposing DB connection pool (PID 1348)
.
----------------------------------------------------------------------
Ran 1 test in 0.001s

OK
[2019-08-28 13:44:54,268] {settings.py:202} DEBUG - Disposing DB connection pool (PID 1356)
.
----------------------------------------------------------------------
Ran 1 test in 0.002s

OK
[2019-08-28 13:44:56,129] {settings.py:202} DEBUG - Disposing DB connection pool (PID 1364)
.
----------------------------------------------------------------------
Ran 1 test in 0.001s

OK
[2019-08-28 13:44:58,030] {settings.py:202} DEBUG - Disposing DB connection pool (PID 1372)
.
----------------------------------------------------------------------
Ran 1 test in 0.001s

OK
[2019-08-28 13:44:59,863] {settings.py:202} DEBUG - Disposing DB connection pool (PID 1380)
.
----------------------------------------------------------------------
Ran 1 test in 0.001s

OK
[2019-08-28 13:45:01,697] {settings.py:202} DEBUG - Disposing DB connection pool (PID 1388)
.
----------------------------------------------------------------------
Ran 1 test in 0.002s

OK
[2019-08-28 13:45:03,505] {settings.py:202} DEBUG - Disposing DB connection pool (PID 1396)
.
----------------------------------------------------------------------
Ran 1 test in 0.001s

OK
[2019-08-28 13:45:05,371] {settings.py:202} DEBUG - Disposing DB connection pool (PID 1404)
.
----------------------------------------------------------------------
Ran 1 test in 0.002s

OK
[2019-08-28 13:45:07,246] {settings.py:202} DEBUG - Disposing DB connection pool (PID 1412)
.
----------------------------------------------------------------------
Ran 1 test in 0.002s

OK
[2019-08-28 13:45:09,137] {settings.py:202} DEBUG - Disposing DB connection pool (PID 1420)
.
----------------------------------------------------------------------
Ran 1 test in 0.001s

OK
[2019-08-28 13:45:10,954] {settings.py:202} DEBUG - Disposing DB connection pool (PID 1428)
.
----------------------------------------------------------------------
Ran 1 test in 0.002s

OK
[2019-08-28 13:45:12,804] {settings.py:202} DEBUG - Disposing DB connection pool (PID 1436)
.
----------------------------------------------------------------------
Ran 1 test in 0.001s

OK
[2019-08-28 13:45:14,796] {settings.py:202} DEBUG - Disposing DB connection pool (PID 1444)
.
----------------------------------------------------------------------
Ran 1 test in 0.002s

OK
[2019-08-28 13:45:16,769] {settings.py:202} DEBUG - Disposing DB connection pool (PID 1452)
.
----------------------------------------------------------------------
Ran 1 test in 0.001s

OK
[2019-08-28 13:45:18,648] {settings.py:202} DEBUG - Disposing DB connection pool (PID 1460)
.
----------------------------------------------------------------------
Ran 1 test in 0.002s

OK
[2019-08-28 13:45:20,556] {settings.py:202} DEBUG - Disposing DB connection pool (PID 1468)
.
----------------------------------------------------------------------
Ran 1 test in 0.001s

OK
[2019-08-28 13:45:22,450] {settings.py:202} DEBUG - Disposing DB connection pool (PID 1476)
.
----------------------------------------------------------------------
Ran 1 test in 0.002s

OK
[2019-08-28 13:45:24,364] {settings.py:202} DEBUG - Disposing DB connection pool (PID 1484)
.
----------------------------------------------------------------------
Ran 1 test in 0.001s

OK
[2019-08-28 13:45:26,302] {settings.py:202} DEBUG - Disposing DB connection pool (PID 1492)
.
----------------------------------------------------------------------
Ran 1 test in 0.001s

OK
[2019-08-28 13:45:28,138] {settings.py:202} DEBUG - Disposing DB connection pool (PID 1500)
.
----------------------------------------------------------------------
Ran 1 test in 0.003s

OK
[2019-08-28 13:45:30,418] {settings.py:202} DEBUG - Disposing DB connection pool (PID 1508)
.
----------------------------------------------------------------------
Ran 1 test in 0.002s

OK
[2019-08-28 13:45:32,466] {settings.py:202} DEBUG - Disposing DB connection pool (PID 1516)
.
----------------------------------------------------------------------
Ran 1 test in 0.001s

OK
[2019-08-28 13:45:34,418] {settings.py:202} DEBUG - Disposing DB connection pool (PID 1524)
.
----------------------------------------------------------------------
Ran 1 test in 0.002s

OK
[2019-08-28 13:45:36,287] {settings.py:202} DEBUG - Disposing DB connection pool (PID 1532)
.
----------------------------------------------------------------------
Ran 1 test in 0.001s

OK
[2019-08-28 13:45:38,301] {settings.py:202} DEBUG - Disposing DB connection pool (PID 1540)
.
----------------------------------------------------------------------
Ran 1 test in 0.003s

OK
[2019-08-28 13:45:40,311] {settings.py:202} DEBUG - Disposing DB connection pool (PID 1548)
.
----------------------------------------------------------------------
Ran 1 test in 0.001s

OK
[2019-08-28 13:45:42,291] {settings.py:202} DEBUG - Disposing DB connection pool (PID 1556)
.
----------------------------------------------------------------------
Ran 1 test in 0.001s

OK
[2019-08-28 13:45:44,302] {settings.py:202} DEBUG - Disposing DB connection pool (PID 1564)
.
----------------------------------------------------------------------
Ran 1 test in 0.001s

OK
[2019-08-28 13:45:46,152] {settings.py:202} DEBUG - Disposing DB connection pool (PID 1572)
.
----------------------------------------------------------------------
Ran 1 test in 0.001s

OK
[2019-08-28 13:45:48,024] {settings.py:202} DEBUG - Disposing DB connection pool (PID 1580)
.
----------------------------------------------------------------------
Ran 1 test in 0.002s

OK
[2019-08-28 13:45:49,890] {settings.py:202} DEBUG - Disposing DB connection pool (PID 1588)
.
----------------------------------------------------------------------
Ran 1 test in 0.002s

OK
[2019-08-28 13:45:51,792] {settings.py:202} DEBUG - Disposing DB connection pool (PID 1596)
.
----------------------------------------------------------------------
Ran 1 test in 0.001s

OK
[2019-08-28 13:45:53,743] {settings.py:202} DEBUG - Disposing DB connection pool (PID 1604)
.
----------------------------------------------------------------------
Ran 1 test in 0.002s

OK
[2019-08-28 13:45:55,724] {settings.py:202} DEBUG - Disposing DB connection pool (PID 1612)
.
----------------------------------------------------------------------
Ran 1 test in 0.002s

OK
[2019-08-28 13:45:57,667] {settings.py:202} DEBUG - Disposing DB connection pool (PID 1620)
.
----------------------------------------------------------------------
Ran 1 test in 0.002s

OK
[2019-08-28 13:45:59,718] {settings.py:202} DEBUG - Disposing DB connection pool (PID 1628)
.
----------------------------------------------------------------------
Ran 1 test in 0.002s

OK
[2019-08-28 13:46:01,541] {settings.py:202} DEBUG - Disposing DB connection pool (PID 1636)
.
----------------------------------------------------------------------
Ran 1 test in 0.002s

OK
[2019-08-28 13:46:03,380] {settings.py:202} DEBUG - Disposing DB connection pool (PID 1644)
.
----------------------------------------------------------------------
Ran 1 test in 0.002s

OK
[2019-08-28 13:46:05,240] {settings.py:202} DEBUG - Disposing DB connection pool (PID 1652)
.
----------------------------------------------------------------------
Ran 1 test in 0.001s

OK
[2019-08-28 13:46:07,127] {settings.py:202} DEBUG - Disposing DB connection pool (PID 1660)
.
----------------------------------------------------------------------
Ran 1 test in 0.002s

OK
[2019-08-28 13:46:08,979] {settings.py:202} DEBUG - Disposing DB connection pool (PID 1668)
.
----------------------------------------------------------------------
Ran 1 test in 0.002s

OK
[2019-08-28 13:46:10,792] {settings.py:202} DEBUG - Disposing DB connection pool (PID 1676)
.
----------------------------------------------------------------------
Ran 1 test in 0.001s

OK
[2019-08-28 13:46:12,576] {settings.py:202} DEBUG - Disposing DB connection pool (PID 1684)
.
----------------------------------------------------------------------
Ran 1 test in 0.002s

OK
[2019-08-28 13:46:14,371] {settings.py:202} DEBUG - Disposing DB connection pool (PID 1692)
.
----------------------------------------------------------------------
Ran 1 test in 0.001s

OK
[2019-08-28 13:46:16,144] {settings.py:202} DEBUG - Disposing DB connection pool (PID 1700)
.
----------------------------------------------------------------------
Ran 1 test in 0.001s

OK
[2019-08-28 13:46:18,023] {settings.py:202} DEBUG - Disposing DB connection pool (PID 1708)
.
----------------------------------------------------------------------
Ran 1 test in 0.002s

OK
[2019-08-28 13:46:19,860] {settings.py:202} DEBUG - Disposing DB connection pool (PID 1716)
.
----------------------------------------------------------------------
Ran 1 test in 0.001s

OK
[2019-08-28 13:46:21,707] {settings.py:202} DEBUG - Disposing DB connection pool (PID 1724)
.
----------------------------------------------------------------------
Ran 1 test in 0.001s

OK
[2019-08-28 13:46:23,454] {settings.py:202} DEBUG - Disposing DB connection pool (PID 1732)
.
----------------------------------------------------------------------
Ran 1 test in 0.001s

OK
[2019-08-28 13:46:25,274] {settings.py:202} DEBUG - Disposing DB connection pool (PID 1740)
.
----------------------------------------------------------------------
Ran 1 test in 0.001s

OK
[2019-08-28 13:46:27,059] {settings.py:202} DEBUG - Disposing DB connection pool (PID 1748)
.
----------------------------------------------------------------------
Ran 1 test in 0.001s

OK
[2019-08-28 13:46:28,954] {settings.py:202} DEBUG - Disposing DB connection pool (PID 1756)
.
----------------------------------------------------------------------
Ran 1 test in 0.001s

OK
[2019-08-28 13:46:30,797] {settings.py:202} DEBUG - Disposing DB connection pool (PID 1764)
.
----------------------------------------------------------------------
Ran 1 test in 0.001s

OK
[2019-08-28 13:46:32,729] {settings.py:202} DEBUG - Disposing DB connection pool (PID 1772)
.
----------------------------------------------------------------------
Ran 1 test in 0.003s

OK
[2019-08-28 13:46:34,634] {settings.py:202} DEBUG - Disposing DB connection pool (PID 1780)
.
----------------------------------------------------------------------
Ran 1 test in 0.001s

OK
[2019-08-28 13:46:36,739] {settings.py:202} DEBUG - Disposing DB connection pool (PID 1788)
.
----------------------------------------------------------------------
Ran 1 test in 0.002s

OK
[2019-08-28 13:46:38,731] {settings.py:202} DEBUG - Disposing DB connection pool (PID 1796)
.
----------------------------------------------------------------------
Ran 1 test in 0.001s

OK
[2019-08-28 13:46:40,633] {settings.py:202} DEBUG - Disposing DB connection pool (PID 1804)
.
----------------------------------------------------------------------
Ran 1 test in 0.001s

OK
[2019-08-28 13:46:42,655] {settings.py:202} DEBUG - Disposing DB connection pool (PID 1812)
.
----------------------------------------------------------------------
Ran 1 test in 0.002s

OK
[2019-08-28 13:46:44,608] {settings.py:202} DEBUG - Disposing DB connection pool (PID 1820)
.
----------------------------------------------------------------------
Ran 1 test in 0.001s

OK
[2019-08-28 13:46:46,616] {settings.py:202} DEBUG - Disposing DB connection pool (PID 1828)
.
----------------------------------------------------------------------
Ran 1 test in 0.001s

OK
[2019-08-28 13:46:48,480] {settings.py:202} DEBUG - Disposing DB connection pool (PID 1836)
.
----------------------------------------------------------------------
Ran 1 test in 0.001s

OK
[2019-08-28 13:46:50,363] {settings.py:202} DEBUG - Disposing DB connection pool (PID 1844)
.
----------------------------------------------------------------------
Ran 1 test in 0.001s

OK
[2019-08-28 13:46:52,242] {settings.py:202} DEBUG - Disposing DB connection pool (PID 1852)
.
----------------------------------------------------------------------
Ran 1 test in 0.001s

OK
[2019-08-28 13:46:54,113] {settings.py:202} DEBUG - Disposing DB connection pool (PID 1860)
.
----------------------------------------------------------------------
Ran 1 test in 0.001s

OK
[2019-08-28 13:46:55,987] {settings.py:202} DEBUG - Disposing DB connection pool (PID 1868)
.
----------------------------------------------------------------------
Ran 1 test in 0.002s

OK
[2019-08-28 13:46:57,928] {settings.py:202} DEBUG - Disposing DB connection pool (PID 1876)
.
----------------------------------------------------------------------
Ran 1 test in 0.001s

OK
[2019-08-28 13:46:59,821] {settings.py:202} DEBUG - Disposing DB connection pool (PID 1884)
.
----------------------------------------------------------------------
Ran 1 test in 0.001s

OK
[2019-08-28 13:47:01,675] {settings.py:202} DEBUG - Disposing DB connection pool (PID 1892)
.
----------------------------------------------------------------------
Ran 1 test in 0.002s

OK
[2019-08-28 13:47:03,553] {settings.py:202} DEBUG - Disposing DB connection pool (PID 1900)
.
----------------------------------------------------------------------
Ran 1 test in 0.001s

OK
[2019-08-28 13:47:05,481] {settings.py:202} DEBUG - Disposing DB connection pool (PID 1908)

@mik-laj mik-laj merged commit 382b21e into apache:master Aug 28, 2019
Jerryguo pushed a commit to Jerryguo/airflow that referenced this pull request Sep 2, 2019
@turbaszek turbaszek deleted the fix-gcp-transfer-hook-test branch September 19, 2019 11:53
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
provider:google Google (including GCP) related issues
Projects
None yet
Development

Successfully merging this pull request may close these issues.

3 participants