Bug #16129
HTTPConnectionPool(host='mira101.front.sepia.ceph.com', port=8000): Max retries exceeded with url: /metadata/incremental
% Done:
0%
Source:
other
Tags:
Backport:
Regression:
No
Severity:
3 - minor
Reviewed:
Affected Versions:
ceph-qa-suite:
Pull request ID:
Crash signature (v1):
Crash signature (v2):
Description
when testing with civetweb, the radosgw-agent sometimes fails to connect to a client at port 8000, from the logs
both clients do appear to be started
2016-05-26T11:45:09.622 INFO:tasks.util.rgw:master_zone=r0z0 2016-05-26T11:45:09.623 DEBUG:tasks.radosgw_admin:radosgw-admin: realm 'realm0' 2016-05-26T11:45:09.624 INFO:tasks.util.rgw:rgwadmin: client.0 : ['user', 'info', '--uid', 'foo'] 2016-05-26T11:45:09.624 INFO:tasks.util.rgw:rgwadmin: cmd=['adjust-ulimits', 'ceph-coverage', '/home/ubuntu/cephtest/archive/coverage', 'radosgw-admin', '--log-to-stderr', '--format', 'json', '-n', 'client.0', 'user', 'info', '--uid', 'foo'] 2016-05-26T11:45:09.625 INFO:teuthology.orchestra.run.mira101:Running: 'adjust-ulimits ceph-coverage /home/ubuntu/cephtest/archive/coverage radosgw-admin --log-to-stderr --format json -n client.0 user info --uid foo' 2016-05-26T11:45:09.737 INFO:tasks.radosgw_agent.ubuntu@mira101.front.sepia.ceph.com.8000.syncdaemon.mira101.stderr:2016-05-26 18:45:09,723 12988 [radosgw_agent][INFO ] __ __ __ ___ ___ 2016-05-26T11:45:09.737 INFO:tasks.radosgw_agent.ubuntu@mira101.front.sepia.ceph.com.8000.syncdaemon.mira101.stderr:2016-05-26 18:45:09,724 12988 [radosgw_agent][INFO ] /__` \ / |\ | / ` /\ / _` |__ |\ | | 2016-05-26T11:45:09.737 INFO:tasks.radosgw_agent.ubuntu@mira101.front.sepia.ceph.com.8000.syncdaemon.mira101.stderr:2016-05-26 18:45:09,724 12988 [radosgw_agent][INFO ] .__/ | | \| \__, /~~\ \__> |___ | \| | 2016-05-26T11:45:09.738 INFO:tasks.radosgw_agent.ubuntu@mira101.front.sepia.ceph.com.8000.syncdaemon.mira101.stderr:2016-05-26 18:45:09,724 12988 [radosgw_agent][INFO ] v1.2.5 2016-05-26T11:45:09.738 INFO:tasks.radosgw_agent.ubuntu@mira101.front.sepia.ceph.com.8000.syncdaemon.mira101.stderr:2016-05-26 18:45:09,724 12988 [radosgw_agent][INFO ] agent options: 2016-05-26T11:45:09.738 INFO:tasks.radosgw_agent.ubuntu@mira101.front.sepia.ceph.com.8000.syncdaemon.mira101.stderr:2016-05-26 18:45:09,725 12988 [radosgw_agent][INFO ] args: 2016-05-26T11:45:09.738 INFO:tasks.radosgw_agent.ubuntu@mira101.front.sepia.ceph.com.8000.syncdaemon.mira101.stderr:2016-05-26 18:45:09,725 12988 [radosgw_agent][INFO ] conf : None 2016-05-26T11:45:09.739 INFO:tasks.radosgw_agent.ubuntu@mira101.front.sepia.ceph.com.8000.syncdaemon.mira101.stderr:2016-05-26 18:45:09,725 12988 [radosgw_agent][INFO ] dest_access_key : **************** 2016-05-26T11:45:09.742 INFO:tasks.radosgw_agent.ubuntu@mira101.front.sepia.ceph.com.8000.syncdaemon.mira101.stderr:2016-05-26 18:45:09,725 12988 [radosgw_agent][INFO ] dest_secret_key : **************** 2016-05-26T11:45:09.743 INFO:tasks.radosgw_agent.ubuntu@mira101.front.sepia.ceph.com.8000.syncdaemon.mira101.stderr:2016-05-26 18:45:09,726 12988 [radosgw_agent][INFO ] destination : http://mira062.front.sepia.ceph.com:7281 2016-05-26T11:45:09.743 INFO:tasks.radosgw_agent.ubuntu@mira101.front.sepia.ceph.com.8000.syncdaemon.mira101.stderr:2016-05-26 18:45:09,726 12988 [radosgw_agent][INFO ] incremental_sync_delay : 30 2016-05-26T11:45:09.743 INFO:tasks.radosgw_agent.ubuntu@mira101.front.sepia.ceph.com.8000.syncdaemon.mira101.stderr:2016-05-26 18:45:09,726 12988 [radosgw_agent][INFO ] lock_timeout : 60 2016-05-26T11:45:09.743 INFO:tasks.radosgw_agent.ubuntu@mira101.front.sepia.ceph.com.8000.syncdaemon.mira101.stderr:2016-05-26 18:45:09,726 12988 [radosgw_agent][INFO ] log_file : /home/ubuntu/cephtest/archive/rgw_sync_agent.client.0.log 2016-05-26T11:45:09.743 INFO:tasks.radosgw_agent.ubuntu@mira101.front.sepia.ceph.com.8000.syncdaemon.mira101.stderr:2016-05-26 18:45:09,727 12988 [radosgw_agent][INFO ] log_lock_time : 20 2016-05-26T11:45:09.744 INFO:tasks.radosgw_agent.ubuntu@mira101.front.sepia.ceph.com.8000.syncdaemon.mira101.stderr:2016-05-26 18:45:09,727 12988 [radosgw_agent][INFO ] max_entries : 10 2016-05-26T11:45:09.744 INFO:tasks.radosgw_agent.ubuntu@mira101.front.sepia.ceph.com.8000.syncdaemon.mira101.stderr:2016-05-26 18:45:09,727 12988 [radosgw_agent][INFO ] metadata_only : False 2016-05-26T11:45:09.744 INFO:tasks.radosgw_agent.ubuntu@mira101.front.sepia.ceph.com.8000.syncdaemon.mira101.stderr:2016-05-26 18:45:09,727 12988 [radosgw_agent][INFO ] num_workers : 1 2016-05-26T11:45:09.744 INFO:tasks.radosgw_agent.ubuntu@mira101.front.sepia.ceph.com.8000.syncdaemon.mira101.stderr:2016-05-26 18:45:09,728 12988 [radosgw_agent][INFO ] object_sync_timeout : 30 2016-05-26T11:45:09.744 INFO:tasks.radosgw_agent.ubuntu@mira101.front.sepia.ceph.com.8000.syncdaemon.mira101.stderr:2016-05-26 18:45:09,728 12988 [radosgw_agent][INFO ] prepare_error_delay : 10 2016-05-26T11:45:09.745 INFO:tasks.radosgw_agent.ubuntu@mira101.front.sepia.ceph.com.8000.syncdaemon.mira101.stderr:2016-05-26 18:45:09,728 12988 [radosgw_agent][INFO ] quiet : False 2016-05-26T11:45:09.745 INFO:tasks.radosgw_agent.ubuntu@mira101.front.sepia.ceph.com.8000.syncdaemon.mira101.stderr:2016-05-26 18:45:09,728 12988 [radosgw_agent][INFO ] rgw_data_log_window : 30 2016-05-26T11:45:09.745 INFO:tasks.radosgw_agent.ubuntu@mira101.front.sepia.ceph.com.8000.syncdaemon.mira101.stderr:2016-05-26 18:45:09,729 12988 [radosgw_agent][INFO ] source : http://mira101.front.sepia.ceph.com:7280 2016-05-26T11:45:09.745 INFO:tasks.radosgw_agent.ubuntu@mira101.front.sepia.ceph.com.8000.syncdaemon.mira101.stderr:2016-05-26 18:45:09,729 12988 [radosgw_agent][INFO ] src_access_key : **************** 2016-05-26T11:45:09.745 INFO:tasks.radosgw_agent.ubuntu@mira101.front.sepia.ceph.com.8000.syncdaemon.mira101.stderr:2016-05-26 18:45:09,729 12988 [radosgw_agent][INFO ] src_secret_key : **************** 2016-05-26T11:45:09.746 INFO:tasks.radosgw_agent.ubuntu@mira101.front.sepia.ceph.com.8000.syncdaemon.mira101.stderr:2016-05-26 18:45:09,729 12988 [radosgw_agent][INFO ] src_zone : None 2016-05-26T11:45:09.746 INFO:tasks.radosgw_agent.ubuntu@mira101.front.sepia.ceph.com.8000.syncdaemon.mira101.stderr:2016-05-26 18:45:09,730 12988 [radosgw_agent][INFO ] sync_scope : incremental 2016-05-26T11:45:09.746 INFO:tasks.radosgw_agent.ubuntu@mira101.front.sepia.ceph.com.8000.syncdaemon.mira101.stderr:2016-05-26 18:45:09,730 12988 [radosgw_agent][INFO ] test_server_host : 0.0.0.0 2016-05-26T11:45:09.746 INFO:tasks.radosgw_agent.ubuntu@mira101.front.sepia.ceph.com.8000.syncdaemon.mira101.stderr:2016-05-26 18:45:09,730 12988 [radosgw_agent][INFO ] test_server_port : 8000 2016-05-26T11:45:09.746 INFO:tasks.radosgw_agent.ubuntu@mira101.front.sepia.ceph.com.8000.syncdaemon.mira101.stderr:2016-05-26 18:45:09,730 12988 [radosgw_agent][INFO ] verbose : True 2016-05-26T11:45:09.747 INFO:tasks.radosgw_agent.ubuntu@mira101.front.sepia.ceph.com.8000.syncdaemon.mira101.stderr:2016-05-26 18:45:09,731 12988 [radosgw_agent][INFO ] versioned : False 2016-05-26T11:45:09.747 INFO:tasks.radosgw_agent.ubuntu@mira101.front.sepia.ceph.com.8000.syncdaemon.mira101.stderr:2016-05-26 18:45:09,731 12988 [radosgw_agent.client][INFO ] creating connection to endpoint: http://mira062.front.sepia.ceph.com:7281 2016-05-26T11:45:10.063 INFO:tasks.util.rgw:rgwadmin: client.0 : ['user', 'create', '--uid', 'foo', '--display-name', 'Foo', '--email', 'foo@foo.com', '--access-key', '9te6NH5mcdcq0Tc5i8i1', '--secret', 'Ny4IOauQoL18Gp2zM7lC1vLmoawgqcYP/YGcWfXu', '--max-buckets', '4'] 2016-05-26T11:45:10.063 INFO:tasks.util.rgw:rgwadmin: cmd=['adjust-ulimits', 'ceph-coverage', '/home/ubuntu/cephtest/archive/coverage', 'radosgw-admin', '--log-to-stderr', '--format', 'json', '-n', 'client.0', 'user', 'create', '--uid', 'foo', '--display-name', 'Foo', '--email', 'foo@foo.com', '--access-key', '9te6NH5mcdcq0Tc5i8i1', '--secret', 'Ny4IOauQoL18Gp2zM7lC1vLmoawgqcYP/YGcWfXu', '--max-buckets', '4'] 2016-05-26T11:45:10.063 INFO:teuthology.orchestra.run.mira101:Running: 'adjust-ulimits ceph-coverage /home/ubuntu/cephtest/archive/coverage radosgw-admin --log-to-stderr --format json -n client.0 user create --uid foo --display-name Foo --email foo@foo.com --access-key 9te6NH5mcdcq0Tc5i8i1 --secret Ny4IOauQoL18Gp2zM7lC1vLmoawgqcYP/YGcWfXu --max-buckets 4' 2016-05-26T11:45:12.094 INFO:tasks.util.rgw: json result: {u'auid': 0, u'display_name': u'Foo', u'keys': [{u'access_key': u'9te6NH5mcdcq0Tc5i8i1', u'secret_key': u'Ny4IOauQoL18Gp2zM7lC1vLmoawgqcYP/YGcWfXu', u'user': u'foo'}], u'default_placement': u'', u'temp_url_keys': [], u'caps': [], u'max_buckets': 4, u'swift_keys': [], u'user_quota': {u'max_objects': -1, u'enabled': False, u'max_size_kb': -1}, u'placement_tags': [], u'suspended': 0, u'op_mask': u'read, write, delete', u'user_id': u'foo', u'email': u'foo@foo.com', u'subusers': [], u'bucket_quota': {u'max_objects': -1, u'enabled': False, u'max_size_kb': -1}} 2016-05-26T11:45:12.094 INFO:tasks.util.rgw:rgwadmin: client.0 : ['user', 'create', '--uid', 'fud', '--display-name', 'Fud', '--email', 'foo@foo.com'] 2016-05-26T11:45:12.095 INFO:tasks.util.rgw:rgwadmin: cmd=['adjust-ulimits', 'ceph-coverage', '/home/ubuntu/cephtest/archive/coverage', 'radosgw-admin', '--log-to-stderr', '--format', 'json', '-n', 'client.0', 'user', 'create', '--uid', 'fud', '--display-name', 'Fud', '--email', 'foo@foo.com'] 2016-05-26T11:45:12.095 INFO:teuthology.orchestra.run.mira101:Running: 'adjust-ulimits ceph-coverage /home/ubuntu/cephtest/archive/coverage radosgw-admin --log-to-stderr --format json -n client.0 user create --uid fud --display-name Fud --email foo@foo.com' 2016-05-26T11:45:12.510 INFO:tasks.util.rgw:rgwadmin: client.0 : ['user', 'info', '--uid', 'foo'] 2016-05-26T11:45:12.510 INFO:tasks.util.rgw:rgwadmin: cmd=['adjust-ulimits', 'ceph-coverage', '/home/ubuntu/cephtest/archive/coverage', 'radosgw-admin', '--log-to-stderr', '--format', 'json', '-n', 'client.0', 'user', 'info', '--uid', 'foo'] 2016-05-26T11:45:12.510 INFO:teuthology.orchestra.run.mira101:Running: 'adjust-ulimits ceph-coverage /home/ubuntu/cephtest/archive/coverage radosgw-admin --log-to-stderr --format json -n client.0 user info --uid foo' 2016-05-26T11:45:12.931 INFO:tasks.util.rgw: json result: {u'auid': 0, u'display_name': u'Foo', u'keys': [{u'access_key': u'9te6NH5mcdcq0Tc5i8i1', u'secret_key': u'Ny4IOauQoL18Gp2zM7lC1vLmoawgqcYP/YGcWfXu', u'user': u'foo'}], u'default_placement': u'', u'temp_url_keys': [], u'caps': [], u'max_buckets': 4, u'swift_keys': [], u'user_quota': {u'max_objects': -1, u'enabled': False, u'max_size_kb': -1}, u'placement_tags': [], u'suspended': 0, u'op_mask': u'read, write, delete', u'user_id': u'foo', u'email': u'foo@foo.com', u'subusers': [], u'bucket_quota': {u'max_objects': -1, u'enabled': False, u'max_size_kb': -1}} 2016-05-26T11:45:12.932 DEBUG:tasks.util.rgw:doing a sync via mira101.front.sepia.ceph.com 2016-05-26T11:45:12.932 INFO:tasks.util.rgw:sync agent mira101.front.sepia.ceph.com:8000 2016-05-26T11:45:12.939 ERROR:teuthology.run_tasks:Saw exception from tasks. Traceback (most recent call last): File "/home/teuthworker/src/teuthology_master/teuthology/run_tasks.py", line 66, in run_tasks manager = run_one_task(taskname, ctx=ctx, config=config) File "/home/teuthworker/src/teuthology_master/teuthology/run_tasks.py", line 45, in run_one_task return fn(**kwargs) File "/var/lib/teuthworker/src/ceph-qa-suite_wip-rgw-fix-longpath/tasks/radosgw_admin.py", line 172, in task rgw_utils.radosgw_agent_sync_all(ctx) File "/var/lib/teuthworker/src/ceph-qa-suite_wip-rgw-fix-longpath/tasks/util/rgw.py", line 155, in radosgw_agent_sync_all radosgw_agent_sync_metadata(ctx, sync_host, sync_port, full) File "/var/lib/teuthworker/src/ceph-qa-suite_wip-rgw-fix-longpath/tasks/util/rgw.py", line 147, in radosgw_agent_sync_metadata return requests.post('http://{addr}:{port}/metadata/{method}'.format(addr = agent_host, port = agent_port, method = method)) File "/home/teuthworker/src/teuthology_master/virtualenv/local/lib/python2.7/site-packages/requests/api.py", line 111, in post return request('post', url, data=data, json=json, **kwargs) File "/home/teuthworker/src/teuthology_master/virtualenv/local/lib/python2.7/site-packages/requests/api.py", line 57, in request return session.request(method=method, url=url, **kwargs) File "/home/teuthworker/src/teuthology_master/virtualenv/local/lib/python2.7/site-packages/requests/sessions.py", line 475, in request resp = self.send(prep, **send_kwargs) File "/home/teuthworker/src/teuthology_master/virtualenv/local/lib/python2.7/site-packages/requests/sessions.py", line 585, in send r = adapter.send(request, **kwargs) File "/home/teuthworker/src/teuthology_master/virtualenv/local/lib/python2.7/site-packages/requests/adapters.py", line 467, in send raise ConnectionError(e, request=request) ConnectionError: HTTPConnectionPool(host='mira101.front.sepia.ceph.com', port=8000): Max retries exceeded with url: /metadata/incremental (Caused by NewConnectionError('<requests.packages.urllib3.connection.HTTPConnection object at 0x7fa8c32a4c90>: Failed to establish a new connection: [Errno 111] Connection refused',))
History
#1 Updated by Casey Bodley almost 8 years ago
I took a look at the logs. I see client.0 on mira101 is running on civetweb port 7280, and client.1 on mira062 is on port 7281. It's the sync agent running on mira101:8000. The sync agent log doesn't give us much to go on though: http://qa-proxy.ceph.com/teuthology/vasu-2016-05-26_10:52:16-rgw:singleton-master---basic-mira/217337/remote/mira101/rgw_sync_agent.client.0.log
#2 Updated by Orit Wasserman almost 8 years ago
It maybe a timing issue , we can add a sleep before running the radosgw-admin task for example:
https://github.com/ceph/ceph-qa-suite/tree/wip-16129
#3 Updated by Orit Wasserman almost 8 years ago
- Assignee set to Orit Wasserman
#4 Updated by Orit Wasserman over 7 years ago
- Status changed from New to Fix Under Review
- Assignee changed from Orit Wasserman to Casey Bodley
#5 Updated by Casey Bodley about 7 years ago
- Status changed from Fix Under Review to Resolved