X-Auth-Token changed itself

Asked by HU Zhong

i wrote a script to write large number of files into my cluster system, and this morning i found in log that the auth-server came up to a problem, and the write operation cannot be executed. the log looks like this:

Nov 17 09:45:42 swift1 auth-server validate_token('AUTH_tkeea74a86c13244a49327dc7de941e7f0', _, _) = False [0.00]
Nov 17 09:45:42 swift1 auth-server 127.0.0.1 - - [17/Nov/2010:01:45:42 +0000] "GET /token/AUTH_tkeea74a86c13244a49327dc7de941e7f0 HTTP/1.0" 404 - "-" "-" - - - - - - - - - "-" "127.0.0.1" "-" 0.0006

it seems that the x-auth-token has failed to be validated. so i check the file which had saved the x-auth-token before.
root@swift1:~# cat token
AUTH_tkeea74a86c13244a49327dc7de941e7f0

the token saved in the file was used in my request(write operation) to the cluster. so the one in log is the same as that in the file.
it seems the x-auth-token is not valid, so i fetched the x-auth-token again like below.
root@swift1:~# ./swift_create_token test tester testing <my-auth-server>:<port>

swift_create_token is a script like this:
#!/bin/bash

if [ $# -ne 4 ]
then
    echo "Usage:"
    echo " swift_create_token <account> <user> <password> <auth-server-ip:port>"
    exit 1
fi

curl -k -v -H "X-Storage-User: $1:$2" -H "X-Storage-Pass: $3" "https://$4/v1.0" > token_tmp 2>&1
grep X-Auth-Token token_tmp | awk -F ": " '{print $2}' > token
grep X-Storage-Url token_tmp | awk -F ": " '{print $2}' > url

amazingly, i found that the x-auth-token has changed to something below!
root@swift1:~# cat token
AUTH_tk48ae64f7d7cf45cb93960bfeaaf14d32

I used the new x-auth token above in my request and the write operation was OK eventually.
I wonder how can the x-auth-token had been changed?

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
HU Zhong (hz02ruc) said :
#1

here is the log in proxy & auth server(proxy and auth are in one machine) when the error happend ( 22:03:05 )
----------------------------------------------------------------------------------------------------------
Nov 16 22:03:15 swift1 proxy-server - <my-proxy-ip> 16/Nov/2010/14/03/15 PUT /v1/AUTH_f8848316cedb483aa734098b1b1290ab/new_5k_dir_0/5k_file_196494 HTTP/1.0 201 - curl/7.15.1%20%28x86_64-suse-linux%29%20libcurl/7.15.1%20OpenSSL/0.9.8a%20zlib/1.2.3%20libidn/0.6.0 test%3Atester%2CAUTH_tkeea74a86c13244a49327dc7de941e7f0 5120 - - tx8d361a08-a1ee-4ea8-acf5-54b4f05096ab - 0.0771
Nov 16 22:03:15 swift1 proxy-server - <my-proxy-ip> 16/Nov/2010/14/03/15 PUT /v1/AUTH_f8848316cedb483aa734098b1b1290ab/new_5k_dir_0/5k_file_196495 HTTP/1.0 201 - curl/7.15.1%20%28x86_64-suse-linux%29%20libcurl/7.15.1%20OpenSSL/0.9.8a%20zlib/1.2.3%20libidn/0.6.0 test%3Atester%2CAUTH_tkeea74a86c13244a49327dc7de941e7f0 5120 - - tx4d620ec8-33ec-475c-9e5a-947d879776d6 - 0.0965
Nov 16 22:03:15 swift1 auth-server validate_token('AUTH_tkeea74a86c13244a49327dc7de941e7f0', _, _) = False [0.09]
Nov 16 22:03:15 swift1 auth-server 127.0.0.1 - - [16/Nov/2010:14:03:15 +0000] "GET /token/AUTH_tkeea74a86c13244a49327dc7de941e7f0 HTTP/1.0" 404 - "-" "-" - - - - - - - - - "-" "127.0.0.1" "-" 0.0931
Nov 16 22:03:15 swift1 auth-server validate_token('AUTH_tkeea74a86c13244a49327dc7de941e7f0', _, _) = False [0.00]
Nov 16 22:03:15 swift1 auth-server 127.0.0.1 - - [16/Nov/2010:14:03:15 +0000] "GET /token/AUTH_tkeea74a86c13244a49327dc7de941e7f0 HTTP/1.0" 404 - "-" "-" - - - - - - - - - "-" "127.0.0.1" "-" 0.0005
Nov 16 22:03:15 swift1 auth-server validate_token('AUTH_tkeea74a86c13244a49327dc7de941e7f0', _, _) = False [0.00]
Nov 16 22:03:15 swift1 auth-server 127.0.0.1 - - [16/Nov/2010:14:03:15 +0000] "GET /token/AUTH_tkeea74a86c13244a49327dc7de941e7f0 HTTP/1.0" 404 - "-" "-" - - - - - - - - - "-" "127.0.0.1" "-" 0.0006
----------------------------------------------------------------------------------------------------------

the write operation stopped at that time. below is the log in one of my storage node.
----------------------------------------------------------------------------------------------------------
Nov 16 22:02:48 swift5 object-server 192.168.13.13 - - [16/Nov/2010:14:02:48 +0000] "PUT /sdb1/4022/AUTH_f8848316cedb483aa734098b1b1290ab/new_5k_dir_0/5k_file_196492" 201 - "-" "tx5e08e01e-0232-4dcb-a1c0-fe0f93548397" "curl/7.15.1 (x86_64-suse-linux) libcurl/7.15.1 OpenSSL/0.9.8a zlib/1.2.3 libidn/0.6.0" 0.1107
Nov 16 22:02:48 swift5 object-server 192.168.13.13 - - [16/Nov/2010:14:02:48 +0000] "PUT /sdc1/2735/AUTH_f8848316cedb483aa734098b1b1290ab/new_5k_dir_0/5k_file_196493" 201 - "-" "txe364e6c0-dcfd-4c4c-b79e-b48e859c40a1" "curl/7.15.1 (x86_64-suse-linux) libcurl/7.15.1 OpenSSL/0.9.8a zlib/1.2.3 libidn/0.6.0" 0.0410
Nov 16 22:02:48 swift5 container-server 192.168.13.16 - - [16/Nov/2010:14:02:48 +0000] "PUT /sdd1/641/AUTH_f8848316cedb483aa734098b1b1290ab/new_5k_dir_0/5k_file_196493" 201 - "txe364e6c0-dcfd-4c4c-b79e-b48e859c40a1" "-" "-" 0.0007
Nov 16 22:02:48 swift5 object-server 192.168.13.13 - - [16/Nov/2010:14:02:48 +0000] "PUT /sdd1/74/AUTH_f8848316cedb483aa734098b1b1290ab/new_5k_dir_0/5k_file_196494" 201 - "-" "tx8d361a08-a1ee-4ea8-acf5-54b4f05096ab" "curl/7.15.1 (x86_64-suse-linux) libcurl/7.15.1 OpenSSL/0.9.8a zlib/1.2.3 libidn/0.6.0" 0.0524
Nov 16 22:02:48 swift5 container-server 192.168.13.16 - - [16/Nov/2010:14:02:48 +0000] "PUT /sdd1/641/AUTH_f8848316cedb483aa734098b1b1290ab/new_5k_dir_0/5k_file_196494" 201 - "tx8d361a08-a1ee-4ea8-acf5-54b4f05096ab" "-" "-" 0.0006
Nov 16 22:02:48 swift5 object-server 192.168.13.13 - - [16/Nov/2010:14:02:48 +0000] "PUT /sdd1/4066/AUTH_f8848316cedb483aa734098b1b1290ab/new_5k_dir_0/5k_file_196495" 201 - "-" "tx4d620ec8-33ec-475c-9e5a-947d879776d6" "curl/7.15.1 (x86_64-suse-linux) libcurl/7.15.1 OpenSSL/0.9.8a zlib/1.2.3 libidn/0.6.0" 0.0373
Nov 16 22:02:48 swift5 object-replicator 4096/4096 (100.00%) partitions replicated in 27.67 seconds (148.00/sec, 0s remaining)
Nov 16 22:02:48 swift5 object-replicator 579494 suffixes checked - 0.02% hashed, 0.00% synced
Nov 16 22:02:48 swift5 object-replicator Partition times: max 0.1804s, min 0.0048s, med 0.0059s
Nov 16 22:02:48 swift5 object-replicator Object replication complete. (0.46 minutes)
Nov 16 22:02:48 swift5 container-server 192.168.13.12 - - [16/Nov/2010:14:02:48 +0000] "PUT /sdd1/641/AUTH_f8848316cedb483aa734098b1b1290ab/new_5k_dir_0/5k_file_196495" 201 - "tx4d620ec8-33ec-475c-9e5a-947d879776d6" "-" "-" 0.0006
Nov 16 22:03:06 swift5 account-replicator Beginning replication run
Nov 16 22:03:06 swift5 account-replicator Replication run OVER
Nov 16 22:03:06 swift5 account-replicator Attempted to replicate 1 dbs in 0.02702 seconds (37.00397/s)
Nov 16 22:03:06 swift5 account-replicator Removed 0 dbs

Revision history for this message
Best gholt (gholt) said :
#2

Tokens are only good for 24 hours by default. If you use an old token, the proxy should give you a 401 Unauthorized, at which point you should reauthenticate with the the auth server to obtain a fresh token for the next 24 hours.

The included client.py's Connection class does this reauthing, for example.

Revision history for this message
HU Zhong (hz02ruc) said :
#3

Thanks gholt, that solved my question.