swauth-prep returns 500 Server Error

Asked by Stefan Thorvardarson

Hi

I'm testing the 1.3 development version of swift on a few servers I have for testing. I have read the SAIO and the "Instructions for a Multiple Server Swift Installation" pages in detail and have already installed a SAIO in a virtual machine a few weeks ago and that worked fine but now I am installing the software again in a bigger setup. I downloaded the software from the trunk last Friday. In my new multi-server setup, it seems that all of the services start up normally but when I try to execute swauth-prep to prepare the user database, I get an error like this:

$ swauth-prep -K secretkey
Auth subsystem prep failed: 500 Server Error

I have not been able to identify the problem.

The swift storage logs contain the following:

==> storage1.log <==
Apr 3 14:19:32 blazer1 object-server 192.168.51.1 - - [03/Apr/2011:14:19:32 +0000] "PUT /6/67951/AUTH_.auth" 400 33 "-" "tx8b685c8d-0d47-4c25-8337-fe1d1faea66a" "-" 0.0006

A similar log is on 2 other storage servers that the proxy contacted.

The proxy logs show:

==> proxy.log <==
Apr 3 14:19:32 blazer1 proxy-server - - 03/Apr/2011/14/19/32 PUT /v1/AUTH_.auth HTTP/1.0 400 - Swauth - - - - tx8b685c8d-0d47-4c25-8337-fe1d1faea66a - 0.0029

==> proxy.error <==
Apr 3 14:19:32 blazer1 proxy-server STDOUT: EXCEPTION IN handle: Traceback (most recent call last):#012 File "/home/stefanth/swift/trunk/swift/common/middleware/swauth.py", line 321, in handle#012 return self.handle_request(req)(env, start_response)#012 File "/home/stefanth/swift/trunk/swift/common/middleware/swauth.py", line 384, in handle_request#012 req.response = handler(req)#012 File "/home/stefanth/swift/trunk/swift/common/middleware/swauth.py", line 403, in handle_prep#012 (path, resp.status))#012Exception: Could not create the main auth account: /v1/AUTH_.auth 400 Bad Request#012: {'SCRIPT_NAME': '/auth/v2', 'webob.adhoc_attrs': {'start_time': 1301840372.753715, 'bytes_transferred': '-', 'client_disconnect': False}, 'REQUEST_METHOD': 'POST', 'PATH_INFO': '/.prep', 'SERVER_PROTOCOL': 'HTTP/1.0', 'eventlet.posthooks': [(<bound method Swauth.posthooklogger of <swift.common.middleware.swauth.Swauth object at 0x8ebcfec>>, (<Request at 0x8ec622c POST http://127.0.0.1:8080/auth/v2/.prep>,), {})], 'SERVER_NAME': '127.0.0.1', 'REMOTE_ADDR': '127.0.0.1', 'eventlet.input': <eventlet.wsgi.Input object at 0x8ec8a6c>, 'HTTP_X_AUTH_ADMIN_KEY': 'secretkey', 'wsgi.url_scheme': 'http', 'SERVER_PORT': '8080', 'HTTP_X_AUTH_ADMIN_USER': '.super_admin', 'HTTP_X_CF_TRANS_ID': 'tx8b685c8d-0d47-4c25-8337-fe1d1faea66a', 'wsgi.input': <eventlet.wsgi.Input object at 0x8ec8a6c>, 'HTTP_HOST': '127.0.0.1:8080', 'swift.cache': <swift.common.memcached.MemcacheRing object at 0x8ebd2ec>, 'wsgi.multithread': True, 'wsgi.version': (1, 0), 'GATEWAY_INTERFACE': 'CGI/1.1', 'wsgi.run_once': False, 'wsgi.errors': <swift.common.utils.LoggerFileObject object at 0x8e512ec>, 'wsgi.multiprocess': False, 'CONTENT_TYPE': None, 'HTTP_ACCEPT_ENCODING': 'identity'}

I killed one of the object-servers and started it manually with strace to see what syscalls it was calling. Here is an strace of what the object-server is doing when it gets the command from the proxy:
[pid 5772] accept(4, {sa_family=AF_INET, sin_port=htons(57662), sin_addr=inet_addr("192.168.51.1")}, [16]) = 6
[pid 5772] fcntl64(6, F_GETFL) = 0x2 (flags O_RDWR)
[pid 5772] fcntl64(6, F_SETFL, O_RDWR|O_NONBLOCK) = 0
[pid 5772] fcntl64(6, F_GETFL) = 0x802 (flags O_RDWR|O_NONBLOCK)
[pid 5772] fcntl64(6, F_SETFL, O_RDWR|O_NONBLOCK) = 0
[pid 5772] gettimeofday({1301843137, 731960}, NULL) = 0
[pid 5772] accept(4, 0xff99bae4, [16]) = -1 EAGAIN (Resource temporarily unavailable)
[pid 5772] gettimeofday({1301843137, 732082}, NULL) = 0
[pid 5772] fcntl64(6, F_GETFL) = 0x802 (flags O_RDWR|O_NONBLOCK)
[pid 5772] fcntl64(6, F_SETFL, O_RDWR|O_NONBLOCK) = 0
[pid 5772] fcntl64(6, F_GETFL) = 0x802 (flags O_RDWR|O_NONBLOCK)
[pid 5772] fcntl64(6, F_SETFL, O_RDWR|O_NONBLOCK) = 0
[pid 5772] fcntl64(6, F_GETFL) = 0x802 (flags O_RDWR|O_NONBLOCK)
[pid 5772] fcntl64(6, F_SETFL, O_RDWR|O_NONBLOCK) = 0
[pid 5772] fcntl64(6, F_GETFL) = 0x802 (flags O_RDWR|O_NONBLOCK)
[pid 5772] fcntl64(6, F_SETFL, O_RDWR|O_NONBLOCK) = 0
[pid 5772] recv(6, "PUT /6/67951/AUTH_.auth HTTP/1.1"..., 8192, 0) = 174
[pid 5772] getsockname(6, {sa_family=AF_INET, sin_port=htons(6010), sin_addr=inet_addr("192.168.51.1")}, [16]) = 0
[pid 5772] gettimeofday({1301843137, 732614}, NULL) = 0
[pid 5772] gettimeofday({1301843137, 732649}, NULL) = 0
[pid 5772] gettimeofday({1301843137, 733231}, NULL) = 0
[pid 5772] gettimeofday({1301843137, 733262}, NULL) = 0
[pid 5772] stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=1141, ...}) = 0
[pid 5772] gettimeofday({1301843137, 733499}, NULL) = 0
[pid 5772] send(5, "<150>object-server 192.168.51.1 "..., 154, 0) = 154
[pid 5772] gettimeofday({1301843137, 733857}, NULL) = 0
[pid 5772] send(6, "HTTP/1.1 400 Bad Request\r\nConten"..., 159, 0) = 159
[pid 5772] gettimeofday({1301843137, 734117}, NULL) = 0
[pid 5772] gettimeofday({1301843137, 734187}, NULL) = 0
[pid 5772] stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=1141, ...}) = 0
[pid 5772] recv(6, "", 8192, 0) = 0
[pid 5772] shutdown(6, 2 /* send and receive */) = 0
[pid 5772] close(6) = 0
[pid 5772] poll([{fd=4, events=POLLIN|POLLPRI|POLLERR|POLLHUP}], 1, 60000

I'm running the latest Debian on the servers. It seems that the object-server is rejecting the request immediately. The config for the object-server is here:

[DEFAULT]
devices = /srv/swift_1
mount_check = false
bind_ip = 192.168.51.1
bind_port = 6010
user = swift
log_facility = LOG_LOCAL2

[pipeline:main]
pipeline = object-server

[app:object-server]
use = egg:swift#object

[object-replicator]

[object-updater]

[object-auditor]

The devices under /srv/swift_1/ are named simply "1", "2" and up to "6". What could be the reason for the 400 error from the object-servers?

[ Edits below]
I have a very similar issue, which differs only in the path being accessed.

Apr 26 16:48:39 d00-0c-29-14-30-92 proxy-server STDOUT: EXCEPTION IN handle: Traceback (most recent call last):#012 Fil
e "/usr/lib/pymodules/python2.6/swift/common/middleware/swauth.py", line 321, in handle#012 return self.handle_reques
t(req)(env, start_response)#012 File "/usr/lib/pymodules/python2.6/swift/common/middleware/swauth.py", line 384, in han
dle_request#012 req.response = handler(req)#012 File "/usr/lib/pymodules/python2.6/swift/common/middleware/swauth.py", line 404, in handle_prep#012 (path, resp.body))#012Exception: Could not create the main auth account: /v1/AUTH_.auth Invalid path: /sdb1/40466/AUTH_.auth

(note the /sdb1 path)
All 3 servers (container, account and object) are running on the same nodes. disks are mounted on /srv/node/sdb1. I verified that the ports in the ring file are correct
account ring output
The minimum number of hours before a partition can be reassigned is 1
Devices: id zone ip address port name weight partitions balance meta
             4 1 192.168.124.130 6000 sdb1 100.00 131072 0.00
             5 1 192.168.124.132 6000 sdb1 100.00 131072 0.00

Any pointers?

Question information

Language:
English Edit question
Status:
Solved
For:
OpenStack Object Storage (swift) Edit question
Assignee:
No assignee Edit question
Solved by:
gholt
Solved:
Last query:
Last reply:
Revision history for this message
Best gholt (gholt) said :
#1

This seems like a ring creation issue. It seems that the proxy server is trying to talk to the object servers while trying to create an account when it should be talking to the account servers.

Try running
swift-ring-builder /etc/swift/account.builder
and double-check all the ip:port are correct for the account servers.

Revision history for this message
Stefan Thorvardarson (stefanth) said :
#2

Thanks gholt, that solved my question.

Revision history for this message
Andrea Turli (andrea-turli-d) said :
#3

Unfortunately even if my ring seems ok

$ swift-ring-builder /etc/swift/account.builder
/etc/swift/account.builder, build version 5
262144 partitions, 3 replicas, 5 zones, 5 devices, 0.00 balance
The minimum number of hours before a partition can be reassigned is 1
Devices: id zone ip address port name weight partitions balance meta
             0 3 192.168.125.49 6002 sdb1 99.00 157286 -0.00
             1 1 192.168.125.50 6002 sdb1 99.00 157286 -0.00
             2 4 192.168.125.51 6002 sdb1 99.00 157287 0.00
             3 2 192.168.125.52 6002 sdb1 99.00 157286 -0.00
             4 0 192.168.125.53 6002 sdb1 99.00 157287 0.00

and this is the error I can see on /var/log/syslog
Jul 20 11:39:35 d00-0c-29-d1-3f-5e proxy-server STDOUT: EXCEPTION IN handle: Traceback (most recent call last):#012 File "/usr/lib/pymodules/python2.6/swift/common/middleware/swauth.py", line 321, in handle#012 return self.handle_request(req)(env, start_response)#012 File "/usr/lib/pymodules/python2.6/swift/common/middleware/swauth.py", line 384, in handle_request#012 req.response = handler(req)#012 File "/usr/lib/pymodules/python2.6/swift/common/middleware/swauth.py", line 403, in handle_prep#012 (path, resp.status))#012Exception: Could not create the main auth account: /v1/AUTH_.auth 405 Method Not Allowed#012: {'SCRIPT_NAME': '/auth/v2', 'webob.adhoc_attrs': {'start_time': 1311179975.6493311, 'bytes_transferred': '-', 'client_disconnect': False}, 'REQUEST_METHOD': 'POST', 'PATH_INFO': '/.prep', 'SERVER_PROTOCOL': 'HTTP/1.0', 'eventlet.posthooks': [(<bound method Swauth.posthooklogger of <swift.common.middleware.swauth.Swauth object at 0x1387990>>, (<Request at 0x1621b10 POST https://127.0.0.1:8080/auth/v2/.prep>,), {})], 'SERVER_NAME': '127.0.0.1', 'REMOTE_ADDR': '127.0.0.1', 'eventlet.input': <eventlet.wsgi.Input object at 0x1613ad0>, 'HTTP_X_AUTH_ADMIN_KEY': 'swauth', 'wsgi.url_scheme': 'https', 'SERVER_PORT': '8080', 'HTTP_X_AUTH_ADMIN_USER': '.super_admin', 'HTTP_X_CF_TRANS_ID': 'tx0f246b47-e417-4d48-9b2f-3f0dd71c3aed', 'wsgi.input': <eventlet.wsgi.Input object at 0x1613ad0>, 'HTTP_HOST': '127.0.0.1:8080', 'swift.cache': <swift.common.memcached.MemcacheRing object at 0x139e310>, 'HTTPS': 'on', 'wsgi.multithread': True, 'wsgi.version': (1, 0), 'GATEWAY_INTERFACE': 'CGI/1.1', 'wsgi.run_once': False, 'wsgi.errors': <swift.common.utils.LoggerFileObject object at 0x132f410>, 'wsgi.multiprocess': False, 'CONTENT_TYPE': None, 'HTTP_ACCEPT_ENCODING': 'identity'}

Any hint?

thanks,
Andrea

Revision history for this message
Hugo Kou (tonytkdk) said :
#4

Need help

Swift 1.4.4
Swauth from https://github.com/gholt/swauth

I found that "Exception: Could not create the main auth account: /v1/AUTH_.auth 405 Method Not Allowed" in proxy.erro

details as below :

While execute "swauth-prep -K tony1020 -A https://10.103.0.67:443/auth"

========proxy.log=========
Oct 21 13:54:06 swift proxy-server - - 21/Oct/2011/05/54/06 PUT /v1/AUTH_.auth HTTP/1.0 405 - Swauth - - - - - - 0.0003

========proxy.error==========
Oct 21 13:54:10 swift proxy-server STDOUT: EXCEPTION IN handle: Traceback (most recent call last):#012 File "/usr/local/lib/python2.7/dist-packages/swauth-1.0.3.dev-py2.7.egg/swauth/middleware.py", line 415, in handle#012 return self.handle_request(req)(env, start_response)#012 File "/usr/local/lib/python2.7/dist-packages/swauth-1.0.3.dev-py2.7.egg/swauth/middleware.py", line 482, in handle_request#012 req.response = handler(req)#012 File "/usr/local/lib/python2.7/dist-packages/swauth-1.0.3.dev-py2.7.egg/swauth/middleware.py", line 512, in handle_prep#012 (path, resp.status))#012Exception: Could not create the main auth account: /v1/AUTH_.auth 405 Method Not Allowed#012: {'SCRIPT_NAME': '/auth/v2', 'webob.adhoc_attrs': {'start_time': 1319176450.567375, 'bytes_transferred': '-', 'client_disconnect': False}, 'REQUEST_METHOD': 'POST', 'PATH_INFO': '/.prep', 'SERVER_PROTOCOL': 'HTTP/1.0', 'eventlet.posthooks': [(<bound method Swauth.posthooklogger of <swauth.middleware.Swauth object at 0x1851650>>, (<Request at 0x1addf90 POST https://10.103.0.67/auth/v2/.prep>,), {})], 'SERVER_NAME': '10.103.0.67', 'REMOTE_ADDR': '10.103.0.67', 'HTTP_X_TRANS_ID': 'tx4f0338fe542a4765ace049b35d705dbb', 'eventlet.input': <eventlet.wsgi.Input object at 0x1abd0d0>, 'HTTP_X_AUTH_ADMIN_KEY': 'tony1020', 'wsgi.url_scheme': 'https', 'SERVER_PORT': '443', 'HTTP_X_AUTH_ADMIN_USER': '.super_admin', 'HTTP_X_CF_TRANS_ID': 'tx69c78908-3b4b-4112-b7e4-e0ba1f128a94', 'wsgi.input': <eventlet.wsgi.Input object at 0x1abd0d0>, 'HTTP_HOST': '10.103.0.67', 'swift.cache': <swift.common.memcached.MemcacheRing object at 0x1aa7f90>, 'HTTPS': 'on', 'wsgi.multithread': True, 'wsgi.version': (1, 0), 'GATEWAY_INTERFACE': 'CGI/1.1', 'wsgi.run_once': False, 'wsgi.errors': <swift.common.utils.LoggerFileObject object at 0x1522910>, 'wsgi.multiprocess': False, 'CONTENT_TYPE': None, 'HTTP_ACCEPT_ENCODING': 'identity'}

==================================================

!No any log in other servers!

=====proxy-server.conf=======

[DEFAULT]
bind_port = 443
user = root
log_facility = LOG_LOCAL1
cert_file = /etc/swift/server.crt
key_file = /etc/swift/server.key

[pipeline:main]
pipeline = catch_errors cache swauth proxy-server

[app:proxy-server]
use = egg:swift#proxy
#allow_account_management = true
account_autocreate = true

[filter:swauth]
use = egg:swauth#swauth
super_admin_key = tony1020

[filter:keystone]
use = egg:keystone#tokenauth
auth_protocol = http
auth_host = 192.168.1.105
auth_port = 35357
admin_token = 999888777666
delay_auth_decision = 0
service_protocol = http
service_host = 192.168.1.105
service_port = 8100
service_pass = dTpw

[filter:cache]
use = egg:swift#memcache
set log_name = cache

[filter:catch_errors]
use = egg:swift#catch_errors

===============================

Revision history for this message
Qi Weining (qi-weining) said :
#5

My swauth is run ok. But after I add 3 devices, I does not run.

swift@cloud1:~$ swauth-prep -K swauthkey1qaz
Auth subsystem prep failed: 500 Server Error
swift@cloud1:~$ swift-ring-builder /etc/swift/account.builder
/etc/swift/account.builder, build version 10
262144 partitions, 3.000000 replicas, 1 regions, 3 zones, 6 devices, 400.00 balance
The minimum number of hours before a partition can be reassigned is 1
Devices: id region zone ip address port name weight partitions balance meta
             0 1 1 192.168.1.3 6012 sdb1 100.00 262144 400.00
             1 1 2 192.168.1.4 6012 sdb1 100.00 262144 400.00
             2 1 3 192.168.1.5 6012 sdb1 100.00 262144 400.00
             3 1 1 192.168.1.3 6012 sdc1 400.00 0-100.00
             4 1 2 192.168.1.4 6012 sdc1 400.00 0-100.00
             5 1 3 192.168.1.5 6012 sdc1 400.00 0-100.00
swift@cloud1:~$ swauth-prep -K swauthkey1qaz
Auth subsystem prep failed: 500 Server Error

Revision history for this message
Qi Weining (qi-weining) said :
#6

gholt (gholt) said right.

After I added new device, I "scp *.ring.gz" to other nodes. And I copy object.ring.gz to account.ring.gz.

It is a silly error.