Что это за результат cProfile, говорящий мне, что мне нужно исправить?

Я хотел бы улучшить производительность Python script и использовал cProfile для создания отчета об эффективности:

python -m cProfile -o chrX.prof ./bgchr.py ...args...

Я открыл этот файл chrX.prof с помощью Python pstats и распечатал статистику:

Python 2.7 (r27:82500, Oct  5 2010, 00:24:22) 
[GCC 4.1.2 20080704 (Red Hat 4.1.2-44)] on linux2
Type "help", "copyright", "credits" or "license" for more information.
>>> import pstats
>>> p = pstats.Stats('chrX.prof')
>>> p.sort_stats('name')
>>> p.print_stats()                                                                                                                                                                                                                        
Sun Oct 10 00:37:30 2010    chrX.prof                                                                                                                                                                                                      

         8760583 function calls in 13.780 CPU seconds                                                                                                                                                                                      

   Ordered by: function name                                                                                                                                                                                                               

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)                                                                                                                                                                    
        1    0.000    0.000    0.000    0.000 {_locale.setlocale}                                                                                                                                                                          
        1    1.128    1.128    1.128    1.128 {bz2.decompress}                                                                                                                                                                             
        1    0.002    0.002   13.780   13.780 {execfile}                                                                                                                                                                                   
  1750678    0.300    0.000    0.300    0.000 {len}                                                                                                                                                                                        
       48    0.000    0.000    0.000    0.000 {method 'append' of 'list' objects}                                                                                                                                                          
        1    0.000    0.000    0.000    0.000 {method 'close' of 'file' objects}                                                                                                                                                           
        1    0.000    0.000    0.000    0.000 {method 'disable' of '_lsprof.Profiler' objects}                                                                                                                                             
  1750676    0.496    0.000    0.496    0.000 {method 'join' of 'str' objects}                                                                                                                                                             
        1    0.007    0.007    0.007    0.007 {method 'read' of 'file' objects}                                                                                                                                                            
        1    0.000    0.000    0.000    0.000 {method 'readlines' of 'file' objects}                                                                                                                                                       
        1    0.034    0.034    0.034    0.034 {method 'rstrip' of 'str' objects}                                                                                                                                                           
       23    0.000    0.000    0.000    0.000 {method 'seek' of 'file' objects}                                                                                                                                                            
  1757785    1.230    0.000    1.230    0.000 {method 'split' of 'str' objects}                                                                                                                                                            
        1    0.000    0.000    0.000    0.000 {method 'startswith' of 'str' objects}                                                                                                                                                       
  1750676    0.872    0.000    0.872    0.000 {method 'write' of 'file' objects}                                                                                                                                                           
        1    0.007    0.007   13.778   13.778 ./bgchr:3(<module>)                                                                                                                                                                          
        1    0.000    0.000   13.780   13.780 <string>:1(<module>)                                                                                                                                                                         
        1    0.001    0.001    0.001    0.001 {open}                                                                                                                                                                                       
        1    0.000    0.000    0.000    0.000 {sys.exit}                                                                                                                                                                                   
        1    0.000    0.000    0.000    0.000 ./bgchr:36(checkCommandLineInputs)                                                                                                                                                           
        1    0.000    0.000    0.000    0.000 ./bgchr:27(checkInstallation)                                                                                                                                                                
        1    1.131    1.131   13.701   13.701 ./bgchr:97(extractData)                                                                                                                                                                      
        1    0.003    0.003    0.007    0.007 ./bgchr:55(extractMetadata)                                                                                                                                                                  
        1    0.064    0.064   13.771   13.771 ./bgchr:5(main)                                                                                                                                                                              
  1750677    8.504    0.000   11.196    0.000 ./bgchr:122(parseJarchLine)                                                                                                                                                                  
        1    0.000    0.000    0.000    0.000 ./bgchr:72(parseMetadata)                                                                                                                                                                    
        1    0.000    0.000    0.000    0.000 /home/areynolds/proj/tools/lib/python2.7/locale.py:517(setlocale)

Вопрос. Что я могу сделать для операций join, split и write, чтобы уменьшить кажущееся влияние на производительность этого script?

Если это актуально, вот полный исходный код для script:

#!/usr/bin/env python

import sys, os, time, bz2, locale

def main(*args):
    # Constants
    global metadataRequiredFileSize
    metadataRequiredFileSize = 8192
    requiredVersion = (2,5)

    # Prep
    global whichChromosome
    whichChromosome = "all"
    checkInstallation(requiredVersion)
    checkCommandLineInputs()
    extractMetadata()
    parseMetadata()
    if whichChromosome == "--list":
        listMetadata()
        sys.exit(0)

    # Extract
    extractData()   
    return 0

def checkInstallation(rv):
    currentVersion = sys.version_info
    if currentVersion[0] == rv[0] and currentVersion[1] >= rv[1]:
        pass
    else:
        sys.stderr.write( "\n\t[%s] - Error: Your Python interpreter must be %d.%d or greater (within major version %d)\n" % (sys.argv[0], rv[0], rv[1], rv[0]) )
        sys.exit(-1)
    return

def checkCommandLineInputs():
    cmdName = sys.argv[0]
    argvLength = len(sys.argv[1:])
    if (argvLength == 0) or (argvLength > 2):
        sys.stderr.write( "\n\t[%s] - Usage: %s [<chromosome> | --list] <bjarch-file>\n\n" % (cmdName, cmdName) )
        sys.exit(-1)
    else:   
        global inFile
        global whichChromosome
        if argvLength == 1:
            inFile = sys.argv[1]
        elif argvLength == 2:
            whichChromosome = sys.argv[1]
            inFile = sys.argv[2]
        if inFile == "-" or inFile == "--list":
            sys.stderr.write( "\n\t[%s] - Usage: %s [<chromosome> | --list] <bjarch-file>\n\n" % (cmdName, cmdName) )
            sys.exit(-1)
    return

def extractMetadata():
    global metadataList
    global dataHandle
    metadataList = []
    dataHandle = open(inFile, 'rb')
    try:
        for data in dataHandle.readlines(metadataRequiredFileSize):     
            metadataLine = data
            metadataLines = metadataLine.split('\n')
            for line in metadataLines:      
                if line:
                    metadataList.append(line)
    except IOError:
        sys.stderr.write( "\n\t[%s] - Error: Could not extract metadata from %s\n\n" % (sys.argv[0], inFile) )
        sys.exit(-1)
    return

def parseMetadata():
    global metadataList
    global metadata
    metadata = []
    if not metadataList: # equivalent to "if len(metadataList) > 0"
        sys.stderr.write( "\n\t[%s] - Error: No metadata in %s\n\n" % (sys.argv[0], inFile) )
        sys.exit(-1)
    for entryText in metadataList:
        if entryText: # equivalent to "if len(entryText) > 0"
            entry = entryText.split('\t')
            filename = entry[0]
            chromosome = entry[0].split('.')[0]
            size = entry[1]
            entryDict = { 'chromosome':chromosome, 'filename':filename, 'size':size }
            metadata.append(entryDict)
    return

def listMetadata():
    for index in metadata:
        chromosome = index['chromosome']
        filename = index['filename']
        size = long(index['size'])
        sys.stdout.write( "%s\t%s\t%ld" % (chromosome, filename, size) )
    return

def extractData():
    global dataHandle
    global pLength
    global lastEnd
    locale.setlocale(locale.LC_ALL, 'POSIX')
    dataHandle.seek(metadataRequiredFileSize, 0) # move cursor past metadata
    for index in metadata:
        chromosome = index['chromosome']
        size = long(index['size'])
        pLength = 0L
        lastEnd = ""
        if whichChromosome == "all" or whichChromosome == index['chromosome']:
            dataStream = dataHandle.read(size)
            uncompressedData = bz2.decompress(dataStream)
            lines = uncompressedData.rstrip().split('\n')
            for line in lines:
                parseJarchLine(chromosome, line)
            if whichChromosome == chromosome:
                break
        else:
            dataHandle.seek(size, 1) # move cursor past chromosome chunk

    dataHandle.close()
    return

def parseJarchLine(chromosome, line):
    global pLength
    global lastEnd
    elements = line.split('\t')
    if len(elements) > 1:
        if lastEnd:
            start = long(lastEnd) + long(elements[0])
            lastEnd = long(start + pLength)
            sys.stdout.write("%s\t%ld\t%ld\t%s\n" % (chromosome, start, lastEnd, '\t'.join(elements[1:])))
        else:
            lastEnd = long(elements[0]) + long(pLength)
            sys.stdout.write("%s\t%ld\t%ld\t%s\n" % (chromosome, long(elements[0]), lastEnd, '\t'.join(elements[1:])))
    else:
        if elements[0].startswith('p'):
            pLength = long(elements[0][1:])
        else:
            start = long(long(lastEnd) + long(elements[0]))
            lastEnd = long(start + pLength)
            sys.stdout.write("%s\t%ld\t%ld\n" % (chromosome, start, lastEnd))               
    return

if __name__ == '__main__':
    sys.exit(main(*sys.argv))

ИЗМЕНИТЬ

Если я комментирую оператор sys.stdout.write в первом условном выражении parseJarchLine(), то мое время выполнения идет от 10,2 с до 4,8 секунд:

# with first conditional "sys.stdout.write" enabled
$ time ./bgchr chrX test.bjarch > /dev/null
real    0m10.186s                                                                                                                                                                                        
user    0m9.917s                                                                                                                                                                                         
sys 0m0.160s  

# after first conditional "sys.stdout.write" is commented out                                                                                                                                                                                           
$ time ./bgchr chrX test.bjarch > /dev/null
real    0m4.808s                                                                                                                                                                                         
user    0m4.561s                                                                                                                                                                                         
sys 0m0.156s

Является ли запись на stdout действительно такой дорогой в Python?

Ответ 1

ncalls имеет значение только в той степени, в которой сравнение чисел с другими значениями, такими как количество символов/полей/строк в файле, может иметь большие аномалии; tottime и cumtime - это действительно важно. cumtime - время, затрачиваемое на функцию/метод, включая время, затрачиваемое на функции/методы, которые он вызывает; tottime - это время, потраченное на функцию/метод, исключая время, потраченное на функции/методы, которые он вызывает.

Мне полезно сортировать статистику по tottime и снова на cumtime, а не на name.

bgchar определенно относится к выполнению script и не имеет значения, поскольку он занимает 8,9 секунды из 13,5; что 8,9 секунды не включают время в функции/методы, которые он вызывает! Внимательно прочитайте, что @Lie Ryan говорит о том, как модулировать ваши функции script и выполнять его рекомендации. Точно также говорит @jonesy.

string упоминается, потому что вы import string и используете его только в одном месте: string.find(elements[0], 'p'). В другой строке на выходе вы заметите, что string.find вызывается только один раз, поэтому в этом запуске этого script это не проблема с производительностью. ОДНАКО: Вы используете методы str везде. В настоящее время функции string устаревают и реализуются путем вызова соответствующего метода str. Лучше написать elements[0].find('p') == 0 для точного, но более быстрого эквивалента, и, возможно, захотите использовать elements[0].startswith('p'), который сохранит читателей, задающихся вопросом, действительно ли это == 0 == -1.

Четыре метода, упомянутые @Bernd Petersohn, занимают всего 3,7 секунды из общего времени выполнения 13,541 секунды. Прежде чем слишком беспокоиться об этом, модулируйте свои функции script в функции, снова запустите cProfile и отсортируйте статистику по tottime.

Обновление после вопроса с измененным script:

"" Вопрос: Что я могу сделать для операций объединения, разделения и записи, чтобы уменьшить кажущееся влияние на производительность этого script?"

А? Эти 3 вместе занимают 2,6 секунды из общего числа 13,8. Функция parseJarchLine занимает 8,5 секунды (что не включает время, затраченное функциями/методами, которые он вызывает. assert(8.5 > 2.6)

Бернд уже указал вам на то, что вы могли бы подумать над этим. Вы совершенно бесполезно раскалываете линию полностью, чтобы снова присоединяться к ней, когда записываете ее. Вам нужно проверить только первый элемент. Вместо elements = line.split('\t') do elements = line.split('\t', 1) и замените '\t'.join(elements[1:]) на elements[1].

Теперь давайте погрузиться в тело parseJarchLine. Количество применений в источнике и способ использования встроенной функции long поразительны. Также поражает тот факт, что long не упоминается в выводе cProfile.

Зачем вам нужно long вообще? Файлы более 2 Гб? Хорошо, тогда вам нужно учитывать, что, поскольку переполнение Python 2.2, int вызывает продвижение до long вместо повышения исключения. Вы можете воспользоваться более быстрым выполнением арифметики int. Вам также необходимо учитывать, что выполнение long(x), когда x уже очевидно, что long является пустой тратой ресурсов.

Вот функция parseJarchLine с изменениями удаления отходов, отмеченными [1], и изменениями изменения в int, отмеченными [2]. Хорошая идея: внести изменения в небольшие шаги, повторить проверку, перепрофилировать.

def parseJarchLine(chromosome, line):
    global pLength
    global lastEnd
    elements = line.split('\t')
    if len(elements) > 1:
        if lastEnd != "":
            start = long(lastEnd) + long(elements[0])
            # [1] start = lastEnd + long(elements[0])
            # [2] start = lastEnd + int(elements[0])
            lastEnd = long(start + pLength)
            # [1] lastEnd = start + pLength
            sys.stdout.write("%s\t%ld\t%ld\t%s\n" % (chromosome, start, lastEnd, '\t'.join(elements[1:])))
        else:
            lastEnd = long(elements[0]) + long(pLength)
            # [1] lastEnd = long(elements[0]) + pLength
            # [2] lastEnd = int(elements[0]) + pLength
            sys.stdout.write("%s\t%ld\t%ld\t%s\n" % (chromosome, long(elements[0]), lastEnd, '\t'.join(elements[1:])))
    else:
        if elements[0].startswith('p'):
            pLength = long(elements[0][1:])
            # [2] pLength = int(elements[0][1:])
        else:
            start = long(long(lastEnd) + long(elements[0]))
            # [1] start = lastEnd + long(elements[0])
            # [2] start = lastEnd + int(elements[0])
            lastEnd = long(start + pLength)
            # [1] lastEnd = start + pLength
            sys.stdout.write("%s\t%ld\t%ld\n" % (chromosome, start, lastEnd))               
    return

Обновить после вопроса о sys.stdout.write

Если выражение, которое вы закомментировали, было похоже на оригинальное:

sys.stdout.write("%s\t%ld\t%ld\t%s\n" % (chromosome, start, lastEnd, '\t'.join(elements[1:])))

Тогда ваш вопрос... интересный. Попробуйте следующее:

payload = "%s\t%ld\t%ld\t%s\n" % (chromosome, start, lastEnd, '\t'.join(elements[1:]))
sys.stdout.write(payload)

Теперь закомментируйте инструкцию sys.stdout.write...

Кстати, кто-то упомянул в комментарии о том, чтобы разбить это на несколько писем... считали ли вы это? Сколько байтов в среднем по элементам [1:]? В хромосоме?

=== смена темы: меня беспокоит, что вы инициализируете lastEnd до "", а не ноль, и что никто не прокомментировал это. В любом случае, вы должны это исправить, что позволяет довольно радикально упростить и добавить в предложения других:

def parseJarchLine(chromosome, line):
    global pLength
    global lastEnd
    elements = line.split('\t', 1)
    if elements[0][0] == 'p':
        pLength = int(elements[0][1:])
        return
    start = lastEnd + int(elements[0])
    lastEnd = start + pLength
    sys.stdout.write("%s\t%ld\t%ld" % (chromosome, start, lastEnd))
    if elements[1:]:
        sys.stdout.write(elements[1])
    sys.stdout.write(\n)

Теперь меня так же беспокоят две глобальные переменные lastEnd и pLength - функция parseJarchLine теперь настолько мала, что ее можно складывать обратно в тело своего единственного вызывающего, extractData, что экономит две глобальные переменные и вызовы функций gazillion. Вы также можете сохранить gazillion lookups sys.stdout.write, поместив write = sys.stdout.write вверх по фронту extractData и используя это вместо этого.

BTW, тесты script для Python 2.5 или лучше; вы пробовали профилировать на 2.5 и 2.6?

Ответ 2

Этот вывод будет более полезен, если ваш код будет более модульным, как заявил Ли Райан. Тем не менее, пару вещей, которые вы можете выбрать из вывода и просто глядя на исходный код:

Вы делаете много сравнений, которые на самом деле не нужны в Python. Например, вместо:

if len(entryText) > 0:

Вы можете просто написать:

if entryText:

Пустой список вычисляет False в Python. То же самое верно для пустой строки, которую вы также проверяете в своем коде, и ее изменение также сделает код более коротким и читаемым, поэтому вместо этого:

   for line in metadataLines:      
        if line == '':
            break
        else:
            metadataList.append(line)

Вы можете просто сделать:

for line in metadataLines:
    if line:
       metadataList.append(line)

Есть несколько других проблем с этим кодом с точки зрения как организации, так и производительности. Например, вы назначаете переменные несколько раз одной и той же вещи, а не просто создаете экземпляр объекта один раз и выполняете все обращения к объекту, например. Это уменьшит количество назначений, а также количество глобальных переменных. Я не хочу звучать слишком критично, но этот код, похоже, не написан с учетом производительности.

Ответ 3

Записи, релевантные для возможной оптимизации, - это те, которые имеют высокие значения для ncalls и tottime. bgchr:4(<module>) и <string>:1(<module>), вероятно, относятся к исполнению вашего тела модуля и здесь не актуальны.

Очевидно, что ваша проблема с производительностью связана с обработкой строк. Возможно, это должно быть уменьшено. Горячие точки: split, join и sys.stdout.write. bz2.decompress также представляется дорогостоящим.

Я предлагаю вам попробовать следующее:

Ваши основные данные, по-видимому, состоят из значений CSV, разделенных табуляцией. Попробуйте, если CSV-считыватель работает лучше.
sys.stdout - строка буферизируется и сбрасывается каждый раз при написании новой строки. Рассмотрите возможность записи в файл с большим размером буфера.
Вместо того, чтобы соединяться с элементами перед их записью, последовательно их записывайте в выходной файл. Вы также можете рассмотреть возможность использования CSV-записи.
Вместо того, чтобы сразу распаковывать данные в одну строку, используйте объект BZ2File и передайте его в считыватель CSV.

Кажется, что тело цикла, которое на самом деле распаковывает данные, вызывается только один раз. Возможно, вы найдете способ избежать вызова dataHandle.read(size), который создает огромную строку, которая затем распаковывается, и непосредственно работать с файлом.

Добавление: BZ2File, вероятно, не применим в вашем случае, потому что для этого требуется аргумент имени файла. Что вам нужно, это что-то вроде просмотра файлового объекта со встроенным пределом чтения, сопоставимого с ZipExtFile, но с использованием BZ2Decompressor для декомпрессии.

Мой главный смысл в том, что ваш код должен быть изменен для выполнения более итеративной обработки ваших данных, вместо того, чтобы разрывать его в целом и снова расщеплять его.