2009-02-07 37 views
28

Hôm nay tôi đã suy nghĩ về một dự án Python tôi đã viết về một năm trở lại, nơi tôi sử dụng logging khá rộng rãi. Tôi nhớ phải bình luận ra rất nhiều cuộc gọi đăng nhập trong các tình huống giống như vòng lặp bên trong (mã 90%) vì chi phí (hotshot cho biết đó là một trong những nút cổ chai lớn nhất của tôi).Làm cách nào để loại bỏ các cuộc gọi ghi nhật ký bằng Python mà không nhận xét chúng?

Tôi tự hỏi bây giờ nếu có một số cách hợp pháp để lập trình loại bỏ các cuộc gọi đăng nhập trong các ứng dụng Python mà không cần bình luận và bỏ ghi chú mọi lúc. Tôi nghĩ rằng bạn có thể sử dụng kiểm tra/biên dịch lại hoặc thao tác bytecode để làm một cái gì đó như thế này và chỉ nhắm mục tiêu các đối tượng mã đang gây tắc nghẽn. Bằng cách này, bạn có thể thêm một thao túng như một bước sau biên soạn và sử dụng một tập tin cấu hình tập trung, như vậy:

[Leave ERROR and above] 
my_module.SomeClass.method_with_lots_of_warn_calls 

[Leave WARN and above] 
my_module.SomeOtherClass.method_with_lots_of_info_calls 

[Leave INFO and above] 
my_module.SomeWeirdClass.method_with_lots_of_debug_calls 

Tất nhiên, bạn muốn sử dụng một cách tiết kiệm và có lẽ với granularity mỗi chức năng - chỉ cho các đối tượng mã đã hiển thị logging là một nút cổ chai. Có ai biết bất cứ điều gì như thế này không?

Lưu ý: Có một vài điều khiến việc này trở nên khó thực hiện hơn nhờ tính năng nhập động và ràng buộc trễ. Ví dụ: bất kỳ cuộc gọi nào đến phương thức có tên debug có thể phải được bao bọc bằng if not isinstance(log, Logger). Trong mọi trường hợp, tôi giả sử tất cả các chi tiết nhỏ có thể được khắc phục, hoặc bằng thỏa thuận của một quý ông hoặc một số kiểm tra thời gian chạy. :-)

+0

bạn có sử dụng cùng một logger gốc cấp? tức là, logging.getLogger()? Nếu vậy, bạn cần sửa lỗi đó trước. Nếu không, vui lòng cung cấp một số lệnh gọi getLogger trong các mô-đun đó. –

+0

@ S.Lott: Tôi sử dụng LOG = logging.getLogger (__ name__) trên cơ sở mỗi mô-đun, sau đó gọi LOG.debug (msg) và tương tự. Tôi không thực sự thấy nó có liên quan như thế nào. – cdleary

Trả lời

20

Còn việc sử dụng logging.disable thì sao?

Tôi cũng thấy rằng mình phải sử dụng logging.isEnabledFor nếu thông điệp ghi nhật ký tốn kém.

+0

logging.isEnabledFor có thể hoạt động, vì tôi nghĩ đó là các cuộc gọi vào các phương thức Logger để tìm thời gian. Tôi thích điều này như một giải pháp tiềm năng, mặc dù thực tế nó gây phiền nhiễu để tạo ra điều kiện. Tôi sẽ cố gắng đào lên các cơ sở mã cũ và xem nếu điều này hoạt động. – cdleary

+1

Khi nó quay ra, đây chính là cách 'Logger.debug' được triển khai: http://svn.python.org/view/python/tags/r26/Lib/logging/__init__.py?view=markup – cdleary

+1

Thực ra, tìm kiếm mã 'đăng nhập' hơn nữa, đây có lẽ là tối ưu hóa mà tôi cần. 'getEffectiveLevel' đi qua hệ thống phân cấp logger, trong khi' disable' sẽ loại bỏ sự truyền tải đó. Cảm ơn! – cdleary

2

Là một phím tắt hoàn hảo, cách nhô ra logging trong các mô-đun cụ thể bằng cách sử dụng một cái gì đó như MiniMock?

Ví dụ, nếu my_module.py là:

import logging 
class C(object): 
    def __init__(self, *args, **kw): 
     logging.info("Instantiating") 

Bạn sẽ thay thế việc bạn sử dụng my_module với:

from minimock import Mock 
import my_module 
my_module.logging = Mock('logging') 
c = my_module.C() 

Bạn chỉ muốn có để làm điều này một lần, trước khi nhập khẩu ban đầu của mô-đun.

Bắt hành vi cụ thể ở cấp độ sẽ đủ đơn giản bằng cách chế nhạo các phương thức cụ thể hoặc có logging.getLogger trả về đối tượng giả với một số phương thức bất lực và các phương thức khác ủy quyền cho mô-đun logging thực.

Trong thực tế, bạn có thể muốn thay thế MiniMock bằng một cái gì đó đơn giản và nhanh hơn; ít nhất một cái gì đó mà không in sử dụng để stdout! Tất nhiên, điều này không giải quyết được vấn đề của mô-đun A nhập logging từ mô-đun B (và do đó A cũng nhập độ chi tiết nhật ký của B) ...

Điều này sẽ không bao giờ nhanh bằng cách không chạy báo cáo nhật ký tại tất cả, nhưng nên nhanh hơn nhiều so với việc đi sâu vào tất cả các chiều sâu của mô-đun đăng nhập chỉ để khám phá bản ghi này không được ghi lại sau khi tất cả.

+0

Điều này thực sự nghe có vẻ lành mạnh hơn nhiều so với thao tác bytecode, vì kỹ thuật thao tác bytecode sẽ không nhất thiết phải cổng trên các máy ảo. Vấn đề duy nhất tôi thấy là bạn chỉ có thể tìm ra * phương thức * nào gọi bạn bằng kiểm tra theo dõi stack, cũng sẽ chậm, nếu tôi không nhầm. – cdleary

+0

Ah, ok .. vì vậy tôi đã nghĩ rằng các đối tượng giả sẽ rất câm, không quan tâm (hoặc biết), nơi họ được gọi từ. Bạn sẽ chỉ có độ chi tiết cấu hình theo từng mô-đun, không chỉ cho mỗi chức năng. Việc chọn mô-đun nào của bạn để tiêm các đối tượng giả vào đó là sự linh hoạt duy nhất của bạn mà tôi sợ. –

1

Bạn có thể thử một cái gì đó như thế này:

# Create something that accepts anything 
class Fake(object): 
    def __getattr__(self, key): 
     return self 
    def __call__(self, *args, **kwargs): 
     return True 

# Replace the logging module 
import sys 
sys.modules["logging"] = Fake() 

Đó là bản chất thay thế (hoặc ban đầu điền vào) không gian cho các module đăng nhập với một thể hiện của Fake mà chỉ đơn giản mất trong bất cứ điều gì. Bạn phải chạy mã trên (chỉ một lần!) Trước khi mô-đun đăng nhập được cố gắng sử dụng ở bất cứ đâu.Dưới đây là một thử nghiệm:

import logging 

logging.basicConfig(level=logging.DEBUG, 
        format='%(asctime)s %(levelname)-8s %(message)s', 
        datefmt='%a, %d %b %Y %H:%M:%S', 
        filename='/temp/myapp.log', 
        filemode='w') 
logging.debug('A debug message') 
logging.info('Some information') 
logging.warning('A shot across the bows') 

Với trên, không có gì ở tất cả đã được đăng nhập, như là để được mong đợi.

+0

Vì vậy, bạn không có cách nào để chọn bật hoặc tắt ghi nhật ký cho mỗi mô-đun hoặc theo cấp độ? –

+0

Điều này thậm chí không tăng tốc độ ... – radtek

1

Tôi muốn sử dụng một số trang trí ưa thích khai thác gỗ, hoặc một bó của họ:

def doLogging(logTreshold): 
    def logFunction(aFunc): 
     def innerFunc(*args, **kwargs): 
      if LOGLEVEL >= logTreshold: 
       print ">>Called %s at %s"%(aFunc.__name__, time.strftime("%H:%M:%S")) 
       print ">>Parameters: ", args, kwargs if kwargs else "" 
      try: 
       return aFunc(*args, **kwargs) 
      finally: 
       print ">>%s took %s"%(aFunc.__name__, time.strftime("%H:%M:%S")) 
     return innerFunc 
    return logFunction 

Tất cả bạn cần là để khai báo LogLevel liên tục trong mỗi module (hoặc chỉ toàn cầu và chỉ cần nhập nó trong tất cả các mô-đun) và sau đó bạn có thể sử dụng nó như thế này:

@doLogging(2.5) 
def myPreciousFunction(one, two, three=4): 
    print "I'm doing some fancy computations :-)" 
    return 

Và nếu LogLevel là không ít hơn 2,5 bạn sẽ nhận được kết quả như thế này:

>>Called myPreciousFunction at 18:49:13 
>>Parameters: (1, 2) 
I'm doing some fancy computations :-) 
>>myPreciousFunction took 18:49:13 

Như bạn có thể thấy, một số công việc là cần thiết để xử lý tốt hơn các kwarg, vì vậy các giá trị mặc định sẽ được in nếu chúng có mặt, nhưng đó là một câu hỏi khác.

Bạn có lẽ nên sử dụng một số logger mô-đun thay vì nguyên print báo cáo, nhưng tôi muốn tập trung vào ý tưởng trang trí và tránh đưa ra những mã quá dài.

Dù sao - với trình trang trí như vậy, bạn sẽ nhận được nhật ký cấp chức năng, nhiều cấp nhật ký tùy ý, dễ áp ​​dụng cho chức năng mới và để tắt ghi nhật ký bạn chỉ cần đặt LOGLEVEL. Và bạn có thể xác định các luồng/tệp đầu ra khác nhau cho mỗi hàm nếu bạn muốn. Bạn có thể viết doLogging là:

def doLogging(logThreshold, outStream=sys.stdout): 
     ..... 
     print >>outStream, ">>Called %s at %s" etc. 

Và sử dụng tệp nhật ký được xác định trên cơ sở mỗi chức năng.

+0

Tôi đăng nhập từ * bên trong * phương thức sử dụng mô-đun 'đăng nhập '- cách tiếp cận của bạn chỉ có thể ghi lại những thứ có thể nhìn thấy bên ngoài (args, kwargs, return value, và execute time). – cdleary

+0

Bạn đã viết về việc sử dụng ghi nhật ký trên mức độ chi tiết của mỗi hàm và ví dụ mã giả của bạn cũng gợi ý một cái gì đó như thế này. Cách tiếp cận của tôi có thể được mở rộng - bạn có thể thêm thông số từ khóa bổ sung vào chức năng của mình. Và tham số bổ sung đó sẽ là một đối tượng logger hoặc giả, được cung cấp bởi decorator :-) – Abgan

+0

Không phải là một giải pháp lý tưởng, tôi đồng ý, nhưng - trang trí có khả năng mở rộng cao phải không? – Abgan

1

Đây cũng là vấn đề trong dự án của tôi - việc ghi nhật ký kết thúc trên báo cáo profiler khá nhất quán.

Tôi đã sử dụng mô-đun _ast trước trong một ngã ba PyFlakes (http://github.com/kevinw/pyflakes) ... và chắc chắn có thể làm những gì bạn đề xuất trong câu hỏi của bạn - để kiểm tra và tiêm bảo vệ trước cuộc gọi đến phương pháp ghi nhật ký (với bạn đã biết trước rằng bạn phải thực hiện kiểm tra kiểu thời gian chạy). Xem http://pyside.blogspot.com/2008/03/ast-compilation-from-python.html để biết ví dụ đơn giản.

Chỉnh sửa: Tôi vừa nhận thấy MetaPython trên nguồn cấp dữ liệu planetpython.org của tôi - trường hợp sử dụng ví dụ là xóa báo cáo nhật ký tại thời điểm nhập.

Có lẽ giải pháp tốt nhất sẽ là một ai đó để reimplement đăng nhập như một module C, nhưng tôi sẽ không là người đầu tiên nhảy tại một ... cơ hội như vậy: p

5

Tôi cũng thấy khẳng định sử dụng theo cách này.

assert logging.warn('disable me with the -O option') is None 

(Tôi đoán cảnh báo đó sẽ không trả về giá trị nào.nếu không, bạn sẽ nhận được một AssertionError

Nhưng thực sự đó chỉ là một cách hài hước để làm điều này:

if __debug__: logging.warn('disable me with the -O option') 

Khi bạn chạy một kịch bản với điều đó dòng trong nó với các tùy chọn -O, dòng sẽ được xóa khỏi mã .pyo được tối ưu hóa. Nếu, thay vào đó, bạn có biến riêng của mình, như sau, bạn sẽ có điều kiện luôn được thực thi (bất kể giá trị biến là gì), mặc dù điều kiện nên thực thi nhanh hơn hàm gọi:

my_debug = True 
... 
if my_debug: logging.warn('disable me by setting my_debug = False') 

vì vậy nếu hiểu biết của tôi về gỡ lỗi là chính xác, có vẻ như đây là cách hay để loại bỏ các cuộc gọi ghi nhật ký không cần thiết. Flipside là nó cũng vô hiệu hóa tất cả các xác nhận của bạn, do đó, nó là một vấn đề nếu bạn cần các xác nhận.

+0

Vâng, đặt một khẳng định ở phía trước của mỗi cuộc gọi là cách quá xấu xí. Đặt một 'if my_debug' trước tất cả mọi thứ là tương tự như không mong muốn và không thích hợp - tôi đã hy vọng cho một cái gì đó để dải/sửa đổi chúng tự động. :-(Ngoài ra, luôn luôn sử dụng 'là None' để so sánh rõ ràng với Không. :-) – cdleary

0

Tôi thích giải pháp 'if __debug_' ngoại trừ việc đưa nó vào trước mỗi cuộc gọi là một chút mất tập trung và xấu xí. Tôi đã có cùng một vấn đề này và vượt qua nó bằng cách viết một kịch bản tự động phân tích cú pháp các tệp nguồn của bạn và thay thế các câu lệnh ghi nhật ký bằng các câu lệnh pass (và nhận xét các bản sao của các câu lệnh khai thác). Nó cũng có thể hoàn tác chuyển đổi này.

Tôi sử dụng nó khi triển khai mã mới vào môi trường sản xuất khi có nhiều câu lệnh ghi nhật ký mà tôi không cần trong cài đặt sản xuất và chúng ảnh hưởng đến hiệu suất.

Bạn có thể tìm thấy kịch bản ở đây: http://dound.com/2010/02/python-logging-performance/

1

:-) Chúng tôi sử dụng để gọi đó là một tiền xử lý và mặc dù tiền xử lý C có một số những capablities, các "vua của ngọn đồi" là tiền xử lý cho IBM mainframe PL /TÔI. Nó cung cấp hỗ trợ ngôn ngữ mở rộng trong bộ tiền xử lý (các bài tập đầy đủ, điều kiện, vòng lặp, vv) và có thể viết "chương trình đã viết chương trình" chỉ bằng PP PL/I.

Tôi đã viết nhiều ứng dụng với chương trình phức tạp và theo dõi dữ liệu (chúng tôi không có trình gỡ rối phong nha cho quy trình back-end tại thời điểm đó) để sử dụng trong quá trình phát triển và thử nghiệm, khi được biên dịch với "cờ thời gian chạy" chỉ đơn giản là tước tất cả mã truy tìm ra một cách sạch sẽ mà không có bất kỳ tác động hiệu suất nào.

Tôi nghĩ ý tưởng trang trí là một ý tưởng hay. Bạn có thể viết một trang trí để bọc các chức năng cần đăng nhập. Sau đó, để phân phối thời gian chạy, trình trang trí được biến thành "no-op" để loại bỏ các câu lệnh gỡ lỗi.

Jon R

5

Sử dụng pypreprocessor

nào cũng có thể được tìm thấy trên PYPI (Python Package Index) và được lấy bằng pip.

Dưới đây là một cách sử dụng ví dụ cơ bản:

from pypreprocessor import pypreprocessor 

pypreprocessor.parse() 

#define nologging 

#ifdef nologging 
...logging code you'd usually comment out manually... 
#endif 

Về cơ bản, tiền xử lý ý kiến ​​ra mã theo cách bạn đã làm nó bằng tay trước. Nó chỉ làm điều đó một cách có điều kiện tùy thuộc vào những gì bạn xác định.

Bạn cũng có thể xóa tất cả chỉ thị tiền xử lý và nhận xét mã khỏi mã được xử lý bằng cách thêm 'pypreprocessor.removeMeta = True' giữa các câu lệnh nhập và phân tích cú pháp().

Đầu ra bytecode (.pyc) sẽ chứa đầu ra được tối ưu hóa.

SideNote: pypreprocessor tương thích với python2x và python3k.

Tuyên bố từ chối trách nhiệm: Tôi là tác giả của bộ xử lý pypreprocessor.

+0

Tôi thường không phải là một fan hâm mộ tuyệt vời của các chỉ thị tiền xử lý. Tôi đã đến rìa của khoảng trống trên phương pháp đó, trở lại khi không có Unix đã làm những điều khá giống như bất kỳ Unix khác, và nó đã không được đẹp. OTOH, thật tuyệt vời khi tính năng này có thể được thêm vào như một mô-đun bên ngoài. Và trong một số trường hợp ... nó có thể chỉ là những gì bạn cần. –

+0

@ Jonathan Tôi không phải là tôi nhưng có một số trường hợp thích hợp, nơi nó có thể cắt giảm đáng kể về bảo trì. Ban đầu tôi tạo ra nó vì vậy tôi có thể chạy cả mã py2x và py3x trong cùng một tệp (phát triển song song cho nhiều phiên bản) nhưng lexer làm mất hiệu lực mã trước khi bộ tiền xử lý có thể chạy. Đối với những trường hợp như vậy, nó sẽ hoạt động hoàn hảo. Về cơ bản nó chỉ tự mở, đọc mã, nhận xét các nhánh mã không cần thiết và chạy đầu ra đã sửa đổi. Khá hacky nhưng nó hoạt động đáng ngạc nhiên cũng đặc biệt là kể từ khi bạn có thể lưu mã sau xử lý như một tập tin quá. –

+0

Gói mã của tôi trong khối '#define nologging' cho tôi' NameError: tên toàn cục 'logging' không được định nghĩa' – radtek

1

Tôi đang thực hiện một dự án hiện đang sử dụng ghi nhật ký rộng rãi cho thử nghiệm logic và thời gian thực hiện cho API phân tích dữ liệu bằng cách sử dụng thư viện Pandas.

Tôi đã tìm thấy chuỗi này có mối quan tâm tương tự - ví dụ: chi phí trên các câu lệnh logging.debug là gì ngay cả khi mức logging.basicConfig được đặt thành level = logging.WARNING

Tôi đã phải viết kịch bản sau để nhận xét hoặc bỏ ghi nhật ký gỡ lỗi trước khi triển khai:

import os 
import fileinput 

comment = True 

# exclude files or directories matching string 
fil_dir_exclude = ["__","_archive",".pyc"] 

if comment : 
    ## Variables to comment 
    source_str = 'logging.debug' 
    replace_str = '#logging.debug' 
else : 
    ## Variables to uncomment 
    source_str = '#logging.debug' 
    replace_str = 'logging.debug' 

# walk through directories 
for root, dirs, files in os.walk('root/directory') : 
    # where files exist 
    if files: 
     # for each file 
     for file_single in files : 
      # build full file name 
      file_name = os.path.join(root,file_single) 
      # exclude files with matching string 
      if not any(exclude_str in file_name for exclude_str in fil_dir_exclude) : 
       # replace string in line 
       for line in fileinput.input(file_name, inplace=True): 
        print "%s" % (line.replace(source_str, replace_str)), 

đây là một đệ quy tập tin mà không bao gồm các tập tin dựa trên một danh sách các tiêu chuẩn và thực hiện một tại chỗ thay thế cho dựa trên một câu trả lời tìm thấy ở đây: Search and replace a line in a file in Python

Các vấn đề liên quan