django server 500 error定位

環境信息

python使用的 2.7.6版本

[test@localhost supervisor]$ pip list
ansible (1.9.4)
APScheduler (3.0.3)
click (5.1)
Django (1.6)
ecdsa (0.13)
elasticsearch (1.3.0)
elasticsearch-curator (3.2.3)
futures (3.0.3)
gevent (1.0.2)
greenlet (0.4.9)
gunicorn (19.1.1)
ipython (2.3.1)
Jinja2 (2.8)
MarkupSafe (0.23)
meld3 (1.0.0)
MySQL-python (1.2.5)
paramiko (1.15.3)
pip (1.4.1)
pycrypto (2.6.1)
pyes (0.99.5)
pytz (2015.4)
PyYAML (3.11)
requests (2.6.0)
setuptools (5.8dev)
six (1.9.0)
supervisor (3.1.3)
tzlocal (1.2)
urllib3 (1.10)
wsgiref (0.1.2)

結構以下： Nginx-----Gunicorn----Django | | supervisor

gunicorn使用gevent模式

問題現象

用戶一段時間沒有登錄，在登錄系統後，頁面顯示server 500 error。用戶刷新頁面也沒法解決。

解決過程

彙總信息進行思考

• 測試環境和研發環境沒有此問題，只有生產環境有。
• 若是用戶短期內登錄成功過，則後繼操做正常。

初步懷疑認證系統問題

經過彙總的信息，能夠推論出 生產使用了登錄驗證的SDK，而且長時間無登錄，就會畢現該問題

進行驗證

對gunicorn進行抓包分析

抓包內容以下：

2016-03-01 15:45:25.248883 IP 127.0.0.1.36944 > 127.0.0.1.18500: P 1:474(473) ack 1 win 257
E...;G@.@............PHD..M0....P.......GET /590 HTTP/1.0
Host: pre.diag.ucweb.local
X-Real-IP: 100.84.46.79
X-Forwarded-For: 100.84.46.79
Connection: close
Cache-Control: max-age=0
Accept: text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,*/*;q=0.8
Upgrade-Insecure-Requests: 1
User-Agent: Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/44.0.2403.157 UBrowser/5.5.10106.5 Safari/537.36
Accept-Encoding: gzip, deflate
Accept-Language: zh-CN,zh;q=0.8


2016-03-01 15:45:25.248890 IP 127.0.0.1.18500 > 127.0.0.1.36944: . ack 474 win 265
E..(u.@.@..-........HD.P......O P..     ....
2016-03-01 15:45:25.257441 IP 127.0.0.1.18500 > 127.0.0.1.36944: P 1:174(173) ack 474 win 265
E...u.@.@...........HD.P......O P..     ....HTTP/1.0 500 INTERNAL SERVER ERROR
Server: gunicorn/19.1.1
Date: Tue, 01 Mar 2016 07:45:25 GMT
Connection: close
X-Frame-Options: SAMEORIGIN
Content-Type: text/html


2016-03-01 15:45:25.257455 IP 127.0.0.1.36944 > 127.0.0.1.18500: . ack 174 win 265
E..(;H@.@............PHD..O     ...wP.. ....
2016-03-01 15:45:25.257481 IP 127.0.0.1.18500 > 127.0.0.1.36944: P 174:201(27) ack 474 win 265
E..Cu.@.@...........HD.P...w..O P..     .7..<h1>Server Error (500)</h1>

gunicorn返回了 500的error，可是查看gunicorn沒有發現任何異常。

對django進行抓包分析

這裏再也不使用gunicorn，而是直接使用：python manage.py runserver 0.0.0.0:18500,啓動服務

抓包內容以下：

2016-03-01 15:51:53.590777 IP 127.0.0.1.34323 > 127.0.0.1.18500: P 1:474(473) ack 1 win 257
E....-@.@.............HD.t.L..(.P.......GET /590 HTTP/1.0
Host: pre.diag.ucweb.local
X-Real-IP: 100.84.46.79
X-Forwarded-For: 100.84.46.79
Connection: close
Cache-Control: max-age=0
Accept: text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,*/*;q=0.8
Upgrade-Insecure-Requests: 1
User-Agent: Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/44.0.2403.157 UBrowser/5.5.10106.5 Safari/537.36
Accept-Encoding: gzip, deflate
Accept-Language: zh-CN,zh;q=0.8


2016-03-01 15:51:53.590783 IP 127.0.0.1.18500 > 127.0.0.1.34323: . ack 474 win 265
E..(K.@.@...........HD....(..t.%P..     2...
2016-03-01 15:51:53.715345 IP 127.0.0.1.18500 > 127.0.0.1.34323: P 1:37(36) ack 474 win 265
E..LK.@.@...........HD....(..t.%P..     .@..HTTP/1.0 500 INTERNAL SERVER ERROR

2016-03-01 15:51:53.715357 IP 127.0.0.1.34323 > 127.0.0.1.18500: . ack 37 win 257

這裏能夠看到django返回了500。鎖定django，繼續追查。 結合以前分析到登錄驗證系統的嫌疑。應該是登錄驗證SSD報錯，但是這部分代碼，沒作任何修改，爲什麼這個版本就報錯呢？

登錄驗證SDK添加異常捕獲

分析了好久代碼以爲不多是登錄驗證SDK的問題，但是如何排除呢。 只能修改SDK代碼：添加異常堆棧的輸出 使用 traceback.format_exc() 打印堆棧

分析堆棧

在修改完SDK代碼後，啓動服務：python manage.py runserver 0.0.0.0:18500。 運行後獲得堆棧以下：

Traceback (most recent call last):
  File "/home/project/app/project_pre/sso/sso_v2.py", line 47, in _deco
    return redirect('%s?%s=%s' % (SSO_LOGIN_URL, SSO_REDIRECT_FIELD_NAME, http_referer))
  File "/home/project/local/python/lib/python2.7/site-packages/django/shortcuts/__init__.py", line 78, in redirect
    return redirect_class(resolve_url(to, *args, **kwargs))
  File "/home/project/local/python/lib/python2.7/site-packages/django/shortcuts/__init__.py", line 151, in resolve_url
    return urlresolvers.reverse(to, args=args, kwargs=kwargs)
  File "/home/project/local/python/lib/python2.7/site-packages/django/core/urlresolvers.py", line 480, in reverse
    app_list = resolver.app_dict[ns]
  File "/home/project/local/python/lib/python2.7/site-packages/django/core/urlresolvers.py", line 310, in app_dict
    self._populate()
  File "/home/project/local/python/lib/python2.7/site-packages/django/core/urlresolvers.py", line 285, in _populate
    lookups.appendlist(pattern.callback, (bits, p_pattern, pattern.default_args))
  File "/home/project/local/python/lib/python2.7/site-packages/django/core/urlresolvers.py", line 229, in callback
    self._callback = get_callable(self._callback_str)
  File "/home/project/local/python/lib/python2.7/site-packages/django/utils/functional.py", line 32, in wrapper
    result = func(*args)
  File "/home/project/local/python/lib/python2.7/site-packages/django/core/urlresolvers.py", line 117, in get_callable
    (lookup_view, mod_name))
ViewDoesNotExist: Could not import porject.views.api.get_httpsf_api_status. View does not exist in module project.views.api.

看了工程的urls，的確是有配置，可是對應的model沒有改方法。 原來django在執行redirect時，去檢查urls。若是url對應的方法不存在，就報500異常。可是又不會打印相關信息，而且SDK也沒有捕獲