search

ibm-research / swifthlm

SwiftHLM - a middleware for using OpenStack Swift with tape and other hight latency media storage backends
Apache License 2.0
14 stars 4 forks source link

HLM log can't be created and some swift related issues #7

Closed tommyJin closed 6 years ago

tommyJin commented 7 years ago

Hi @slavisasarafijanovic @hseipp ,

Today I install a new vm with swift2.5 to figure out what causes the log issue.

Basic info: python: 2.7 swift: 2.5.0(Liberty) swifthlm: 0.2.2 master branch(before 2017/06/20 submit) system: CentOS7

Before config HLM in /etc/swift/proxy-server.conf, it's okay to upload file, get an object and download it.

[root@mercury swift]# curl -v -X PUT -H 'X-Auth-Token: AUTH_tkef8ec68fe33e409e874a06cbd56d3a46' -T /home/mercury/testupload/uploadfile http://localhost:8080/v1/AUTH_test/con3/obj0

  • About to connect() to localhost port 8080 (#0)
  • Trying ::1...
  • Connection refused
  • Trying 127.0.0.1...
  • Connected to localhost (127.0.0.1) port 8080 (#0)

    PUT /v1/AUTH_test/con3/obj0 HTTP/1.1 User-Agent: curl/7.29.0 Host: localhost:8080 Accept: / X-Auth-Token: AUTH_tkef8ec68fe33e409e874a06cbd56d3a46 Content-Length: 16 Expect: 100-continue

    < HTTP/1.1 100 Continue

  • We are completely uploaded and fine < HTTP/1.1 201 Created < Last-Modified: Thu, 13 Jul 2017 07:24:52 GMT < Content-Length: 0 < Etag: c316292b5254ca7622d5e466f3200d71 < Content-Type: text/html; charset=UTF-8 < X-Trans-Id: tx8cc7d86adfa3417596fd6-0059672043 < Date: Thu, 13 Jul 2017 07:24:51 GMT <
  • Connection #0 to host localhost left intact [root@mercury swift]# curl -v -X GET -H 'X-Auth-Token: AUTH_tkef8ec68fe33e409e874a06cbd56d3a46' http://localhost:8080/v1/AUTH_test/con3/obj0
  • About to connect() to localhost port 8080 (#0)
  • Trying ::1...
  • Connection refused
  • Trying 127.0.0.1...
  • Connected to localhost (127.0.0.1) port 8080 (#0)

    GET /v1/AUTH_test/con3/obj0 HTTP/1.1 User-Agent: curl/7.29.0 Host: localhost:8080 Accept: / X-Auth-Token: AUTH_tkef8ec68fe33e409e874a06cbd56d3a46

    < HTTP/1.1 200 OK < Content-Length: 16 < Accept-Ranges: bytes < Last-Modified: Thu, 13 Jul 2017 07:24:52 GMT < Etag: c316292b5254ca7622d5e466f3200d71 < X-Timestamp: 1499930691.40080 < Content-Type: application/octet-stream < X-Trans-Id: txe7bf855d4fe844bdb357d-0059672057 < Date: Thu, 13 Jul 2017 07:25:11 GMT < hello world!!!!

  • Connection #0 to host localhost left intact [root@mercury swift]# curl -v -X GET -o /home/mercury/downloaded/obj0 -H 'X-Auth-Token: AUTH_tkef8ec68fe33e409e874a06cbd56d3a46' http://localhost:8080/v1/AUTH_test/con3/obj0 % Total % Received % Xferd Average Speed Time Time Time Current Dload Upload Total Spent Left Speed 0 0 0 0 0 0 0 0 --:--:-- --:--:-- --:--:-- 0* About to connect() to localhost port 8080 (#0)
  • Trying ::1...
  • Connection refused
  • Trying 127.0.0.1...
  • Connected to localhost (127.0.0.1) port 8080 (#0)

    GET /v1/AUTH_test/con3/obj0 HTTP/1.1 User-Agent: curl/7.29.0 Host: localhost:8080 Accept: / X-Auth-Token: AUTH_tkef8ec68fe33e409e874a06cbd56d3a46

    < HTTP/1.1 200 OK < Content-Length: 16 < Accept-Ranges: bytes < Last-Modified: Thu, 13 Jul 2017 07:24:52 GMT < Etag: c316292b5254ca7622d5e466f3200d71 < X-Timestamp: 1499930691.40080 < Content-Type: application/octet-stream < X-Trans-Id: tx83aad0536ab2402ca6a73-0059672078 < Date: Thu, 13 Jul 2017 07:25:44 GMT < { [data not shown] 100 16 100 16 0 0 78 0 --:--:-- --:--:-- --:--:-- 78

  • Connection #0 to host localhost left intact [root@mercury swift]# cat /home/mercury/downloaded/obj0 hello world!!!!

And then I add the HLM part to the /etc/swift/proxy-server.conf

pipeline = catch_errors gatekeeper healthcheck proxy-logging cache bulk tempurl ratelimit crossdomain container_sync tempauth staticweb container-quotas account-quotas slo dlo versioned_writes proxy-logging proxy-server hlm

[filter:hlm] use = egg:swifthlm#swifthlm

set log_level = INFO

set log_level = DEBUG

change the code in middleware.py(line 527) to my hostname then install

ssh_client.connect(ip_addr, username="mercury")

modify the 'User' value in swifthlm.dispatcher.service

[root@mercury mercury]# cat /etc/systemd/system/swifthlm.dispatcher.service [Unit] Description=SwiftHLM Dispatcher Wants=network-online.target After=network.target network-online.target

[Service] Type=simple User=mercury ExecStart=/usr/bin/python -m swifthlm.dispatcher Restart=on-abort

[Install] WantedBy=multi-user.target

files under /home/mercury/.ssh

[root@mercury .ssh]# ll total 16 -rw-r--r--. 1 mercury mercury 408 Jul 12 14:15 authorized_keys -rw-------. 1 mercury mercury 1679 Jul 12 14:14 id_rsa -rw-r--r--. 1 mercury mercury 408 Jul 12 14:14 id_rsa.pub -rw-r--r--. 1 mercury mercury 172 Jul 10 11:28 known_hosts [root@mercury .ssh]# pwd /home/mercury/.ssh

reload swift and start swifthlm, but hlm.log is not created.

[root@mercury mercury]# systemctl start swifthlm.dispatcher [root@mercury mercury]# systemctl status swifthlm.dispatcher -l ● swifthlm.dispatcher.service - SwiftHLM Dispatcher Loaded: loaded (/etc/systemd/system/swifthlm.dispatcher.service; disabled; vendor preset: disabled) Active: active (running) since Thu 2017-07-13 15:57:21 CST; 1s ago Main PID: 16764 (python) CGroup: /system.slice/swifthlm.dispatcher.service └─16764 /usr/bin/python -m swifthlm.dispatcher

Jul 13 15:57:21 mercury.amethystum systemd[1]: Started SwiftHLM Dispatcher. Jul 13 15:57:21 mercury.amethystum systemd[1]: Starting SwiftHLM Dispatcher... Jul 13 15:57:22 mercury.amethystum hlm-middleware[16764]: 603 [middleware.py: init():245] info: Initialized SwiftHLM Middleware Jul 13 15:57:22 mercury.amethystum hlm-middleware[16764]: 603 [middleware.py: init():246] dbg: Initialized SwiftHLM Middleware Jul 13 15:57:22 mercury.amethystum hlm-dispatcher[16764]: 603 [dispatcher.py: init():101] info: Initialized Dispatcher Jul 13 15:57:22 mercury.amethystum hlm-dispatcher[16764]: 603 [dispatcher.py: init():102] dbg: Initialized Dispatcher Jul 13 15:57:22 mercury.amethystum hlm-dispatcher[16764]: 603 [dispatcher.py: run():166] Polling the requests queue Jul 13 15:57:22 mercury.amethystum swift[16764]: - - 13/Jul/2017/07/57/22 GET /v1/.swifthlm/pending-hlm-requests%3Fformat%3Djson%26marker%3D%26end_marker%3D HTTP/1.0 200 - SwiftHLM%20Middleware - - 2 - txd38477a7fa94436ab370b-00596727e2 - 0.0355 - - 1499932642.603914976 1499932642.639373064 0

I did not config the connector part, so the HLM are supposed to use the dummy_connector and I run get obj command

[root@mercury mercury]# curl -v -X GET -H "X-Auth-Token: AUTH_tkef8ec68fe33e409e874a06cbd56d3a46" http://127.0.0.1:8080/v1/AUTH_test/con3/obj0

  • About to connect() to 127.0.0.1 port 8080 (#0)
  • Trying 127.0.0.1...
  • Connected to 127.0.0.1 (127.0.0.1) port 8080 (#0)

    GET /v1/AUTH_test/con3/obj0 HTTP/1.1 User-Agent: curl/7.29.0 Host: 127.0.0.1:8080 Accept: / X-Auth-Token: AUTH_tkef8ec68fe33e409e874a06cbd56d3a46

    < HTTP/1.1 500 Internal Error < Content-Length: 17 < Content-Type: text/plain < X-Trans-Id: txeb846c43ea094ff6b4078-0059673642 < Date: Thu, 13 Jul 2017 08:58:44 GMT <

  • Connection #0 to host 127.0.0.1 left intact An error occurred[root@mercury mercury]

and the status command

[root@mercury swifthlm]# curl -v -X GET -H 'X-Auth-Token: AUTH_tkef8ec68fe33e409e874a06cbd56d3a46' http://127.0.0.1:8080/hlm/v1/status/AUTH_test/mycontainer/mytestfile

  • About to connect() to 127.0.0.1 port 8080 (#0)
  • Trying 127.0.0.1...
  • Connected to 127.0.0.1 (127.0.0.1) port 8080 (#0)

    GET /hlm/v1/status/AUTH_test/mycontainer/mytestfile HTTP/1.1 User-Agent: curl/7.29.0 Host: 127.0.0.1:8080 Accept: / X-Auth-Token: AUTH_tkef8ec68fe33e409e874a06cbd56d3a46

    < HTTP/1.1 500 Internal Error < Content-Length: 17 < Content-Type: text/plain < X-Trans-Id: tx3ebb06f6e46d45d492bec-0059681f83 < Date: Fri, 14 Jul 2017 01:33:56 GMT <

  • Connection #0 to host 127.0.0.1 left intact An error occurred[root@mercury swifthlm]#

Error occurs in proxy.error log, but no hlm.log so far

Jul 14 09:33:55 mercury proxy-server: STDERR: (23470) accepted ('127.0.0.1', 51613) Jul 14 09:33:56 mercury proxy-server: Error: An error occurred: #012Traceback (most recent call last):#012 File "/home/mercury/jeews/swift-2.5.0/swift/common/middleware/catch_errors.py", line 41, in handle_request#012 resp = self._app_call(env)#012 File "/home/mercury/jeews/swift-2.5.0/swift/common/wsgi.py", line 1033, in _app_call#012 resp = self.app(env, self._start_response)#012 File "/home/mercury/jeews/swift-2.5.0/swift/common/middleware/gatekeeper.py", line 90, in call#012 return self.app(env, gatekeeper_response)#012 File "/home/mercury/jeews/swift-2.5.0/swift/common/middleware/healthcheck.py", line 57, in call#012 return self.app(env, start_response)#012 File "/home/mercury/jeews/swift-2.5.0/swift/common/middleware/proxy_logging.py", line 337, in call#012 iterable = self.app(env, my_start_response)#012 File "/home/mercury/jeews/swift-2.5.0/swift/common/middleware/memcache.py", line 109, in call#012 return self.app(env, start_response)#012 File "/home/mercury/jeews/swift-2.5.0/swift/common/swob.py", line 1418, in _wsgify_self#012 return func(self, Request(env))(env, start_response)#012 File "/home/mercury/jeews/swift-2.5.0/swift/common/middleware/tempurl.py", line 340, in call#012 return self.app(env, start_response)#012 File "/home/mercury/jeews/swift-2.5.0/swift/common/middleware/ratelimit.py", line 301, in call#012 return self.app(env, start_response)#012 File "/home/mercury/jeews/swift-2.5.0/swift/common/middleware/crossdomain.py", line 82, in call#012 return self.app(env, start_response)#012 File "/home/mercury/jeews/swift-2.5.0/swift/common/swob.py", line 1418, in _wsgify_self#012 return func(self, Request(env))(env, start_response)#012 File "/home/mercury/jeews/swift-2.5.0/swift/common/middleware/tempauth.py", line 289, in call#012 return self.app(env, start_response)#012 File "build/bdist.linux-x86_64/egg/swifthlm/middleware.py", line 440, in call#012 self.merge_responses_from_storage_nodes(hlm_req)#012 File "build/bdist.linux-x86_64/egg/swifthlm/middleware.py", line 625, in merge_responses_from_storage_nodes#012 resp_in = (json.loads(self.response_in[ip_addr]))['objects']#012 File "/usr/lib64/python2.7/site-packages/simplejson/init.py", line 488, in loads#012 return _default_decoder.decode(s)#012 File "/usr/lib64/python2.7/site-packages/simplejson/decoder.py", line 370, in decode#012 obj, end = self.raw_decode(s)#012 File "/usr/lib64/python2.7/site-packages/simplejson/decoder.py", line 389, in raw_decode#012 return self.scan_once(s, idx=_w(s, idx).end())#012JSONDecodeError: Expecting value: line 1 column 1 (char 0) (txn: txe6768ac2db7c44c38c3fe-0059681f83) Jul 14 09:33:56 mercury proxy-server: STDERR: 127.0.0.1 - - [14/Jul/2017 01:33:56] "GET /hlm/v1/status/AUTH_test/mycontainer/mytestfile HTTP/1.1" 500 179 0.498426 (txn: txe6768ac2db7c44c38c3fe-0059681f83)

run migrate, status and requests, the error occurs

[root@mercury swifthlm]# curl -v -X POST -H 'X-Auth-Token: AUTH_tkef8ec68fe33e409e874a06cbd56d3a46' http://127.0.0.1:8080/hlm/v1/migrate/AUTH_test/mycontainer/mytestfile

  • About to connect() to 127.0.0.1 port 8080 (#0)
  • Trying 127.0.0.1...
  • Connected to 127.0.0.1 (127.0.0.1) port 8080 (#0)

    POST /hlm/v1/migrate/AUTH_test/mycontainer/mytestfile HTTP/1.1 User-Agent: curl/7.29.0 Host: 127.0.0.1:8080 Accept: / X-Auth-Token: AUTH_tkef8ec68fe33e409e874a06cbd56d3a46

    < HTTP/1.1 200 OK < Content-Length: 26 < Content-Type: text/plain < X-Trans-Id: txd957f90542c44567ba27c-005968200a < Date: Fri, 14 Jul 2017 01:36:10 GMT < Accepted migrate request.

  • Connection #0 to host 127.0.0.1 left intact [root@mercury swifthlm]# curl -v -X GET -H 'X-Auth-Token: AUTH_tkef8ec68fe33e409e874a06cbd56d3a46' http://127.0.0.1:8080/hlm/v1/status/AUTH_test/mycontainer/mytestfile
  • About to connect() to 127.0.0.1 port 8080 (#0)
  • Trying 127.0.0.1...
  • Connected to 127.0.0.1 (127.0.0.1) port 8080 (#0)

    GET /hlm/v1/status/AUTH_test/mycontainer/mytestfile HTTP/1.1 User-Agent: curl/7.29.0 Host: 127.0.0.1:8080 Accept: / X-Auth-Token: AUTH_tkef8ec68fe33e409e874a06cbd56d3a46

    < HTTP/1.1 500 Internal Error < Content-Length: 17 < Content-Type: text/plain < X-Trans-Id: tx7773758cd19d4ad79f295-005968200d < Date: Fri, 14 Jul 2017 01:36:14 GMT <

  • Connection #0 to host 127.0.0.1 left intact An error occurred[root@merurl -v -X GET -H 'X-Auth-Token: AUTH_tkef8ec68fe33e409e874a06cbd56d3a46' http://127.0.0.1:8080/hlm/v1/requests/AUTH_test/mycontainer/mytestfile
  • About to connect() to 127.0.0.1 port 8080 (#0)
  • Trying 127.0.0.1...
  • Connected to 127.0.0.1 (127.0.0.1) port 8080 (#0)

    GET /hlm/v1/requests/AUTH_test/mycontainer/mytestfile HTTP/1.1 User-Agent: curl/7.29.0 Host: 127.0.0.1:8080 Accept: / X-Auth-Token: AUTH_tkef8ec68fe33e409e874a06cbd56d3a46

    < HTTP/1.1 200 OK < Content-Length: 78 < Content-Type: text/plain < X-Trans-Id: tx050e899fb63b4007889e0-0059682012 < Date: Fri, 14 Jul 2017 01:36:18 GMT <

  • Connection #0 to host 127.0.0.1 left intact ["20170714013610.317--migrate--AUTH_test--mycontainer--0--mytestfile--failed"][root@mercury swifthlm]#

and proxy.error log

Jul 14 09:35:45 mercury proxy-server: STDERR: (23470) accepted ('127.0.0.1', 57842) Jul 14 09:35:45 mercury proxy-server: STDERR: 127.0.0.1 - - [14/Jul/2017 01:35:45] "GET /hlm/v1/requests/AUTH_test/mycontainer/mytestfile HTTP/1.1" 200 203 0.125576 (txn: tx2ef360af917846e7bbf47-0059681ff1) Jul 14 09:36:10 mercury proxy-server: STDERR: (23470) accepted ('127.0.0.1', 59256) Jul 14 09:36:10 mercury proxy-server: STDERR: 127.0.0.1 - - [14/Jul/2017 01:36:10] "POST /hlm/v1/migrate/AUTH_test/mycontainer/mytestfile HTTP/1.1" 200 176 0.077675 (txn: txd6071586d2cb4ddaa6a86-005968200a) Jul 14 09:36:13 mercury proxy-server: STDERR: (23470) accepted ('127.0.0.1', 59473) Jul 14 09:36:14 mercury proxy-server: Error: An error occurred: #012Traceback (most recent call last):#012 File "/home/mercury/jeews/swift-2.5.0/swift/common/middleware/catch_errors.py", line 41, in handle_request#012 resp = self._app_call(env)#012 File "/home/mercury/jeews/swift-2.5.0/swift/common/wsgi.py", line 1033, in _app_call#012 resp = self.app(env, self._start_response)#012 File "/home/mercury/jeews/swift-2.5.0/swift/common/middleware/gatekeeper.py", line 90, in call#012 return self.app(env, gatekeeper_response)#012 File "/home/mercury/jeews/swift-2.5.0/swift/common/middleware/healthcheck.py", line 57, in call#012 return self.app(env, start_response)#012 File "/home/mercury/jeews/swift-2.5.0/swift/common/middleware/proxy_logging.py", line 337, in call#012 iterable = self.app(env, my_start_response)#012 File "/home/mercury/jeews/swift-2.5.0/swift/common/middleware/memcache.py", line 109, in call#012 return self.app(env, start_response)#012 File "/home/mercury/jeews/swift-2.5.0/swift/common/swob.py", line 1418, in _wsgify_self#012 return func(self, Request(env))(env, start_response)#012 File "/home/mercury/jeews/swift-2.5.0/swift/common/middleware/tempurl.py", line 340, in call#012 return self.app(env, start_response)#012 File "/home/mercury/jeews/swift-2.5.0/swift/common/middleware/ratelimit.py", line 301, in call#012 return self.app(env, start_response)#012 File "/home/mercury/jeews/swift-2.5.0/swift/common/middleware/crossdomain.py", line 82, in call#012 return self.app(env, start_response)#012 File "/home/mercury/jeews/swift-2.5.0/swift/common/swob.py", line 1418, in _wsgify_self#012 return func(self, Request(env))(env, start_response)#012 File "/home/mercury/jeews/swift-2.5.0/swift/common/middleware/tempauth.py", line 289, in call#012 return self.app(env, start_response)#012 File "build/bdist.linux-x86_64/egg/swifthlm/middleware.py", line 440, in call#012 self.merge_responses_from_storage_nodes(hlm_req)#012 File "build/bdist.linux-x86_64/egg/swifthlm/middleware.py", line 625, in merge_responses_from_storage_nodes#012 resp_in = (json.loads(self.response_in[ip_addr]))['objects']#012 File "/usr/lib64/python2.7/site-packages/simplejson/init.py", line 488, in loads#012 return _default_decoder.decode(s)#012 File "/usr/lib64/python2.7/site-packages/simplejson/decoder.py", line 370, in decode#012 obj, end = self.raw_decode(s)#012 File "/usr/lib64/python2.7/site-packages/simplejson/decoder.py", line 389, in raw_decode#012 return self.scan_once(s, idx=_w(s, idx).end())#012JSONDecodeError: Expecting value: line 1 column 1 (char 0) (txn: txc34018059e4d46398780f-005968200d) Jul 14 09:36:14 mercury proxy-server: STDERR: 127.0.0.1 - - [14/Jul/2017 01:36:14] "GET /hlm/v1/status/AUTH_test/mycontainer/mytestfile HTTP/1.1" 500 179 0.516118 (txn: txc34018059e4d46398780f-005968200d) Jul 14 09:36:18 mercury proxy-server: STDERR: (23470) accepted ('127.0.0.1', 59750) Jul 14 09:36:18 mercury proxy-server: STDERR: 127.0.0.1 - - [14/Jul/2017 01:36:18] "GET /hlm/v1/requests/AUTH_test/mycontainer/mytestfile HTTP/1.1" 200 228 0.085918 (txn: tx3cd476f7088a496c8d4bf-0059682012)

Right now, the list of logs under /var/log/swift

[root@mercury swift]# ll total 10744 -rw-------. 1 root root 890 Jul 12 19:40 expirer.log -rw-------. 1 root adm 30591 Jul 14 09:36 proxy.error -rw-------. 1 root adm 88799 Jul 14 09:36 proxy.log -rw-------. 1 root adm 1107509 Jul 14 09:36 storage1.error -rw-------. 1 root adm 190984 Jul 14 09:36 storage1.log -rw-------. 1 root adm 2071942 Jul 14 09:38 storage2.error -rw-------. 1 root adm 1086750 Jul 14 09:38 storage2.log -rw-------. 1 root adm 2047043 Jul 14 09:38 storage3.error -rw-------. 1 root adm 1154249 Jul 14 09:38 storage3.log -rw-------. 1 root adm 1996357 Jul 14 09:38 storage4.error -rw-------. 1 root adm 1166687 Jul 14 09:38 storage4.log

Would these information help with reproducing the log issue? If you need more settings or config, I am happy to provide if necessary.

Best regards, Tommy

tommyJin commented 7 years ago

Hi there,

When I checked the proxy.log, I find that there are some lines from hlm-middleware a month ago. But after then I did not see any lines about middleware anymore.

BTW, I find that if the name='hlm-middleware' is changed to name='hlm-*dispatcher*' or name='hlm-*handler*' or name='hlm-*connector*'

such as name='hlm-dispatchermiddleware' the log would be written to the hlm.log

Below is the test result and test code.

From hlm.log

Jul 18 10:29:00 localhost hlm-dispatcher: 401 [mytest.py: init():20] testline! Jul 18 10:29:00 localhost hlm-dispatcher: 402 [mytest.py: init():21] 1testline!

Jul 18 10:29:33 localhost hlm-handler: 044 [mytest.py: init():20] testline! Jul 18 10:29:33 localhost hlm-handler: 045 [mytest.py: init():21] 1testline!

Jul 18 10:29:47 localhost hlm-connector: 114 [mytest.py: init():20] testline! Jul 18 10:29:47 localhost hlm-connector: 114 [mytest.py: init():21] 1testline!

Jul 18 10:31:19 localhost hlm-connectormiddleware: 133 [mytest.py: init():20] testline! Jul 18 10:31:19 localhost hlm-connectormiddleware: 134 [mytest.py: init():21] 1testline!

Jul 18 10:32:36 localhost hlm-dispatchermiddleware: 768 [mytest.py: init():20] testline! Jul 18 10:32:36 localhost hlm-dispatchermiddleware: 769 [mytest.py: init():21] 1testline!

Jul 18 10:33:11 localhost hlm-handlermiddleware: 000 [mytest.py: init():20] testline! Jul 18 10:33:11 localhost hlm-handlermiddleware: 001 [mytest.py: init():21] 1testline!

Jul 18 10:33:37 localhost hlm-handlerramdon: 900 [mytest.py: init():20] testline! Jul 18 10:33:37 localhost hlm-handlerramdon: 901 [mytest.py: init():21] 1testline!

Test code

 def __init__(self):
        configFile = r'/etc/swift/proxy-server.conf'
        conf = readconf(configFile)
        # Logging
        self.logger = get_logger(conf, name='hlm-handlerramdon',
                log_route='swifthlm', fmt="%(server)s: %(msecs)03d "
                "[%(filename)s:%(funcName)20s():%(lineno)s] %(message)s")

        self.logger.info('testline!')
        self.logger.info('1testline!')

Regards, Tommy

slavisasarafijanovic commented 7 years ago

Hi Tommy,

1) Regarding failing HLM operations: a) I noticed you added hlm after proxy-server in the pipeline: pipeline = catch_errors gatekeeper healthcheck proxy-logging cache bulk tempurl ratelimit crossdomain container_sync tempauth staticweb container-quotas account-quotas slo dlo versioned_writes proxy-logging hlm proxy-server It should be: pipeline = catch_errors gatekeeper healthcheck proxy-logging cache bulk tempurl ratelimit crossdomain container_sync tempauth staticweb container-quotas account-quotas slo dlo versioned_writes proxy-logging hlm proxy-server

b) mercury is hosthame, you need to put user that is used to run swift. If you are using 'swift all in one' you should put osddev as user in swifthlm.dispatcher.service: 'User=osddev' Also, in middleware.py(line 527):

ssh_client.connect(ip_addr, username="osddev") And ssh should be configured for osddev user.

2) Regarding logging, to investigate that I will try first to recreate your environment. You already provided the main info about the environment you use. Could you additionally provide the info outputed by the following commands: cat /etc/redhat-release uname -a python --version curl -i http://localhost:8080/info

Regards, Slavisa

tommyJin commented 7 years ago

Hi @slavisasarafijanovic ,

Here is the output of the commands:

[root@localhost /]# cat /etc/redhat-release CentOS Linux release 7.2.1511 (Core) [root@localhost /]# uname -a Linux localhost.localdomain 3.10.0-327.el7.x86_64 #1 SMP Thu Nov 19 22:10:57 UTC 2015 x86_64 x86_64 x86_64 GNU/Linux [root@localhost /]# python --version Python 2.7.5 [root@localhost /]# curl -i http://localhost:8080/info HTTP/1.1 200 OK Content-Length: 1285 Content-Type: application/json; charset=UTF-8 X-Trans-Id: tx4cd1fe95dbb34685862ae-00596f29b6 Date: Wed, 19 Jul 2017 09:43:18 GMT

{"bulk_delete": {"max_failed_deletes": 1000, "max_deletes_per_request": 10000}, "versioned_writes": {}, "container_quotas": {}, "crossdomain": {}, "swift": {"max_file_size": 5368709122, "account_listing_limit": 10000, "account_autocreate": false, "max_meta_count": 90, "max_meta_value_length": 256, "container_listing_limit": 10000, "extra_header_count": 0, "max_meta_overall_size": 4096, "version": "2.5.0", "max_meta_name_length": 128, "max_header_size": 8192, "policies": [{"default": true, "name": "gold"}, {"name": "silver"}, {"name": "swiftonfile"}], "max_object_name_length": 1024, "max_account_name_length": 256, "strict_cors_mode": true, "allow_account_management": false, "max_container_name_length": 256}, "tempurl": {"methods": ["GET", "HEAD", "PUT", "POST", "DELETE"]}, "bulk_upload": {"max_failed_extractions": 1000, "max_containers_per_extraction": 10000}, "ratelimit": {"account_ratelimit": 0.0, "max_sleep_time_seconds": 60.0, "container_ratelimits": [], "container_listing_ratelimits": []}, "container_sync": {"realms": {"SAIO": {"clusters": {"SAIO_ENDPOINT": {"current": true}}}}}, "hlm": {}, "slo": {"max_manifest_segments": 1000, "min_segment_size": 1048576, "max_manifest_size": 2097152}, "account_quotas": {}, "staticweb": {}, "tempauth": {"account_acls": true}}[root@localhost /]#

And I change the order of the pipeline, and the order now is pipeline = catch_errors gatekeeper healthcheck proxy-logging cache bulk tempurl ratelimit crossdomain container_sync tempauth staticweb container-quotas account-quotas slo dlo versioned_writes proxy-logging hlm proxy-server

then, I restart swift and swifthlm service, and the 'hlm-middleware' log still can't be written to the hlm.log.

Hope it could help. :)

All the best, Tommy

hseipp commented 7 years ago

@tommyJin please move the hlm entry in the pipeline in front of the second proxy-logging entry, on my test system that is very similar to the one you are using I'm getting appropriate hlm-middleware log entries to /var/log/swift/hlm.log with that setting: pipeline = catch_errors gatekeeper healthcheck proxy-logging cache bulk tempurl ratelimit crossdomain container_sync tempauth staticweb container-quotas account-quotas slo dlo versioned_writes hlm proxy-logging proxy-server

Also please cross-check that you have the appropriate rsyslog configuration:

$ cat /etc/rsyslog.d/00-swifthlmlog.conf
if $programname contains 'hlm-middleware' then /var/log/swift/hlm.log
if $programname contains 'hlm-middleware' and $syslogseverity <= 3 then /var/log/swift/hlm.error
if $programname contains 'hlm-middleware' then ~
if $programname contains 'dispatcher' then /var/log/swift/hlm.log
if $programname contains 'dispatcher' and $syslogseverity <= 3 then /var/log/swift/hlm.error
if $programname contains 'dispatcher' then ~
if $programname contains 'handler' then /var/log/swift/hlm.log
if $programname contains 'handler' and $syslogseverity <= 3 then /var/log/swift/hlm.error
if $programname contains 'handler' then ~
if $programname contains 'connector' then /var/log/swift/hlm.log
if $programname contains 'connector' and $syslogseverity <= 3 then /var/log/swift/hlm.error
if $programname contains 'connector' then ~
tommyJin commented 7 years ago

Hi @hseipp

I've tried the above solution but no luck.

Before I modified the related files, the sequence of the pipeline is pipeline = catch_errors gatekeeper healthcheck proxy-logging cache bulk tempurl ratelimit crossdomain container_sync tempauth staticweb container-quotas account-quotas slo dlo versioned_writes proxy-logging hlm proxy-server and I modified it to pipeline = catch_errors gatekeeper healthcheck proxy-logging cache bulk tempurl ratelimit crossdomain container_sync tempauth staticweb container-quotas account-quotas slo dlo versioned_writes hlm proxy-logging proxy-server

When I checked out the file '/etc/rsyslog.d/00-swifthlmlog.conf', the raw content is if $programname contains 'hlm-middleware' then ~ if $programname contains 'dispatcher' then /var/log/swift/hlm.log if $programname contains 'dispatcher' and $syslogseverity <= 3 then /var/log/swift/hlm.error if $programname contains 'dispatcher' then ~ if $programname contains 'handler' then /var/log/swift/hlm.log if $programname contains 'handler' and $syslogseverity <= 3 then /var/log/swift/hlm.error if $programname contains 'handler' then ~ if $programname contains 'connector' then /var/log/swift/hlm.log if $programname contains 'connector' and $syslogseverity <= 3 then /var/log/swift/hlm.error if $programname contains 'connector' then ~

and I modified it to if $programname contains 'hlm-middleware' then /var/log/swift/hlm.log if $programname contains 'hlm-middleware' and $syslogseverity <= 3 then /var/log/swift/hlm.error if $programname contains 'hlm-middleware' then ~ if $programname contains 'dispatcher' then /var/log/swift/hlm.log if $programname contains 'dispatcher' and $syslogseverity <= 3 then /var/log/swift/hlm.error if $programname contains 'dispatcher' then ~ if $programname contains 'handler' then /var/log/swift/hlm.log if $programname contains 'handler' and $syslogseverity <= 3 then /var/log/swift/hlm.error if $programname contains 'handler' then ~ if $programname contains 'connector' then /var/log/swift/hlm.log if $programname contains 'connector' and $syslogseverity <= 3 then /var/log/swift/hlm.error if $programname contains 'connector' then ~ as you provide and restart swift and swifthlm, and I find no clues in the hlm.log.

Do I need to provide other information to help out the issue?

Best regards, Tommy

hseipp commented 7 years ago

Hi @tommyJin did you issue a systemctl restart rsyslog after modifying the 00-swifthlmlog.conf file? Also, I'm attaching my 00-swifthlmlog.conf as your text above misses carriage returns so I'm not sure if your file is properly formatted. 00-swifthlmlog.conf Note: Github does not let me upload the conf file with the original file name suffix, so you need to rename it after detaching.... Regards, Harald

tommyJin commented 6 years ago

Hi, @hseipp I am able to print out the middleware after updating 00-swifthlmlog stuff, but I can not recreate it on another vm. Anyway, the middleware log shows up. Thanks a lot!

Regards, Tommy