Project

General

Profile

Bug #16129

HTTPConnectionPool(host='mira101.front.sepia.ceph.com', port=8000): Max retries exceeded with url: /metadata/incremental

Added by Vasu Kulkarni almost 8 years ago. Updated about 7 years ago.

Status:
Resolved
Priority:
Normal
Assignee:
Target version:
-
% 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

logs: http://qa-proxy.ceph.com/teuthology/vasu-2016-05-26_10:52:16-rgw:singleton-master---basic-mira/217337/teuthology.log


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

Also available in: Atom PDF