決算分析システムでは、EDGAR XBRLを読み込むのに lxml.etree を使用しているのですが、いろいろなXMLを読み込んでいくうちに、「メモリの割り当てに失敗しました」という旨のメッセージが出ていたことに気づきました。
困ったことに、いったんこのエラーが出ると、それ以降の etree.fromstring() がほとんど失敗するようになっていたんですね。単発のエラーではなく、問題のある状態が継続している感じでした。
一応、何らかのエラーが出たときは、XMLパーサーのエラー回復オプション (recover=True)を追加して再解析を試みるようにしていたのですが、このエラーに限っては特に効果がなく、最終的にPythonプログラムを再起動することで復帰しました。
それで原因を調べていたのですが、どうやらある種のファイルを何度か読み込んでいるうちに、lxml.etree に問題が起こるようだ、というところまで分かってきたので、そのメモを紹介します。
エラーメッセージと発生タイミング
まず、エラーメッセージの全体です。（ファイルパスは削っています）
065346 065346_vsys-20130930.xml
Traceback (most recent call last):
File "***\test_lxml_etree.py", line 49, in proc
root = etree.fromstring(f.read())
File "src\lxml\etree.pyx", line 3213, in lxml.etree.fromstring
File "src\lxml\parser.pxi", line 1877, in lxml.etree._parseMemoryDocument
File "src\lxml\parser.pxi", line 1765, in lxml.etree._parseDoc
File "src\lxml\parser.pxi", line 1127, in lxml.etree._BaseParser._parseDoc
File "src\lxml\parser.pxi", line 601, in lxml.etree._ParserContext._handleParseResultDoc
File "src\lxml\parser.pxi", line 711, in lxml.etree._handleParseResult
File "src\lxml\parser.pxi", line 640, in lxml.etree._raiseParseError
File "<string>", line 2608
lxml.etree.XMLSyntaxError: Memory allocation failed, line 2608, column 132000000 から始まって、065346 番目の「065346_vsys-20130930.xml」でエラーが発生しました。「なるほど。それじゃあ、このファイルが問題なのかな？」と、これだけを読み込んでみたのですが、それは問題なく解析できたんですね。
どうやら、簡単には発生しないようだと。実際、EDINET XBRLでは長時間連続で解析できていた実績がありました。このエラーに気づいてから、改めてエディネットXBRLを連続で再解析してみたのですが、上手く動いてくれました。
それで、エドガーXBRLに連番を付けながら現象発生のタイミングを探っていたのですが、ようやく進展がありました。ファイルを読み込んでいく順番が同じなら、ピタリ同じファイルのところでエラーになる、というところまで分かりました。この検証が上の連番にある通り、時間的にとても大変でした。
エドガーXBRLを６万ファイル以上読み込んで、ようやくエラーが発生するんですね。１回の検証に２時間から４時間かかっていました。メモリの消費量ですが、特に増加していってる様子はなかったです。
それで、おそらくはこの６万ファイルの中に、良くないファイルがあったのではないかと想像しているのですが、どうなんでしょうかね。ひとつひとつのXMLを読み込んでみても問題が起こらないところが少々厄介です。
エディネットXBRLとエドガーXBRLですね、なにが違うのか？
エディネットでは上場企業３７００社の有報に関して、etree.fromstring() が失敗するファイルは１つか２つだったと記憶していますが、エドガーでも似たような割合でしたし、ちょっとわからないですね。
とりあえず、エドガーに関しては、数万ファイル読み込んだらプログラムを終了する感じで回避しています。
以下、検証のために書いたコードの全体とログファイルの一部です。
検証コード
ひとつのフォルダに集めたXBRLとXSDを、ソートしてから読み込んでいくだけのコードです。肝心なファイルリストですが、数が膨大で載せられないので、割愛しています。
"""test_lxml_etree"""
import os
import datetime
import traceback
import logging
import pdb
from lxml import etree
def main():
"""メイン関数"""
lg = get_logger(__name__, r'(ログファイルのパス)')
data_dir = r'(EDGARのXBRLとXSDを入れたフォルダ)'
t1 = datetime.datetime.now()
lg.debug(t1)
proc(data_dir, lg)
lg.debug('# end\n経過時間 %d days %02d:%02d:%02d\n'
% get_time_tuple(datetime.datetime.now() - t1))
shutdown_logging_system(lg)
return
def proc(data_dir, lg):
"""XBRLとXSDのXMLを読み込む"""
# エラーカウンタ
n_err = 0
# ファイル名をソート
filenames = sorted(os.listdir(data_dir), reverse=False)
lg.debug('filenames: %d' % len(filenames))
# 読み込む
for (n, filename) in enumerate(filenames):
lg.debug('%06d %s' % (n, filename))
try:
# ファイルパス生成
file = os.path.join(data_dir, filename)
# ファイルを開いて解析
with open(file, 'rb') as f:
root = None
root = etree.fromstring(f.read())
# raise etree.XMLSyntaxError(0,0,0,0,0)
except etree.XMLSyntaxError:
# エラー内容を表示
lg.debug(datetime.datetime.now())
lg.debug(traceback.format_exc())
n_err += 1
if n_err >= 10:
# デバッガ起動
pdb.set_trace()
return
def get_time_tuple(delta):
"""timedeltaから (days, hours, minutes, seconds) のタプルを取得"""
(hours, r) = divmod(delta.seconds, 3600)
(minutes, seconds) = divmod(r, 60)
return (delta.days, hours, minutes, seconds)
def get_logger(
logger_name, log_file, s_fmt='%(message)s', f_fmt='%(message)s',
):
"""ロガーを取得"""
# ロガー作成
logger = logging.getLogger(logger_name)
logger.setLevel(logging.DEBUG)
# ストリームハンドラ作成
stream_handler = logging.StreamHandler()
stream_handler.setLevel(logging.DEBUG)
stream_handler.setFormatter(logging.Formatter(s_fmt))
# ロガーに追加
logger.addHandler(stream_handler)
# ファイルハンドラ作成
file_handler = logging.FileHandler(
log_file, mode='a', encoding='utf-8')
file_handler.setLevel(logging.DEBUG)
file_handler.setFormatter(logging.Formatter(f_fmt))
# ロガーに追加
logger.addHandler(file_handler)
return logger
def remove_logger_handlers(logger):
"""ロガーに追加したハンドラーをすべてremoveする"""
# リストの要素番号が変わらないように後ろからremoveしていく。
for handle in logger.handlers[::-1]:
logger.removeHandler(handle)
if type(handle) == logging.FileHandler:
print('Removed %s %s' % (
str(type(handle)),
os.path.basename(handle.baseFilename),
))
else:
print('Removed %s' % str(type(handle)))
return
def shutdown_logging_system(logger):
"""ロガーをシャットダウンする"""
# すべてのハンドラーをremoveする
remove_logger_handlers(logger)
# ロガーをシャットダウンする
logging.shutdown()
return
if __name__ == '__main__':
main()
ログファイルの一部
開始直後とエラー発生時のところのログです。ここでは 065346 番目でエラーが発生していますが、いったんプログラムを終了して、少し戻った 065000 番目からスタートすると、これが問題なく進んでいくんですね。なかなか難しいところです。
2018-08-12 12:24:46.631815
filenames: 65768
000000 000000_nick-20110630.xml
000001 000001_nick-20110630.xsd
000002 000002_nick-20110930.xml
000003 000003_nick-20110930.xsd
000004 000004_nick-20111231.xml
000005 000005_nick-20111231.xsd
(中略)
065341 065341_vsys-20121231.xsd
065342 065342_vsys-20130331.xml
065343 065343_vsys-20130331.xsd
065344 065344_vsys-20130630.xml
065345 065345_vsys-20130630.xsd
065346 065346_vsys-20130930.xml
2018-08-12 15:49:51.747812
Traceback (most recent call last):
File "***\test_lxml_etree.py", line 49, in proc
root = etree.fromstring(f.read())
File "src\lxml\etree.pyx", line 3213, in lxml.etree.fromstring
File "src\lxml\parser.pxi", line 1877, in lxml.etree._parseMemoryDocument
File "src\lxml\parser.pxi", line 1765, in lxml.etree._parseDoc
File "src\lxml\parser.pxi", line 1127, in lxml.etree._BaseParser._parseDoc
File "src\lxml\parser.pxi", line 601, in lxml.etree._ParserContext._handleParseResultDoc
File "src\lxml\parser.pxi", line 711, in lxml.etree._handleParseResult
File "src\lxml\parser.pxi", line 640, in lxml.etree._raiseParseError
File "<string>", line 2608
lxml.etree.XMLSyntaxError: Memory allocation failed, line 2608, column 132
065347 065347_vsys-20130930.xsd
065348 065348_vsys-20131231.xml
2018-08-12 15:49:51.896831
Traceback (most recent call last):
File "***\test_lxml_etree.py", line 49, in proc
root = etree.fromstring(f.read())
File "src\lxml\etree.pyx", line 3213, in lxml.etree.fromstring
File "src\lxml\parser.pxi", line 1877, in lxml.etree._parseMemoryDocument
File "src\lxml\parser.pxi", line 1765, in lxml.etree._parseDoc
File "src\lxml\parser.pxi", line 1127, in lxml.etree._BaseParser._parseDoc
File "src\lxml\parser.pxi", line 601, in lxml.etree._ParserContext._handleParseResultDoc
File "src\lxml\parser.pxi", line 711, in lxml.etree._handleParseResult
File "src\lxml\parser.pxi", line 640, in lxml.etree._raiseParseError
File "<string>", line 539
lxml.etree.XMLSyntaxError: Memory allocation failed, line 539, column 64
065349 065349_vsys-20131231.xsd
065350 065350_vsys-20140331.xml
2018-08-12 15:49:52.045350
Traceback (most recent call last):
File "***\test_lxml_etree.py", line 49, in proc
root = etree.fromstring(f.read())
File "src\lxml\etree.pyx", line 3213, in lxml.etree.fromstring
File "src\lxml\parser.pxi", line 1877, in lxml.etree._parseMemoryDocument
File "src\lxml\parser.pxi", line 1765, in lxml.etree._parseDoc
File "src\lxml\parser.pxi", line 1127, in lxml.etree._BaseParser._parseDoc
File "src\lxml\parser.pxi", line 601, in lxml.etree._ParserContext._handleParseResultDoc
File "src\lxml\parser.pxi", line 711, in lxml.etree._handleParseResult
File "src\lxml\parser.pxi", line 640, in lxml.etree._raiseParseError
File "<string>", line 5
lxml.etree.XMLSyntaxError: xmlns:vsys: Empty XML namespace is not allowed, line 5, column 471
065351 065351_vsys-20140331.xsd
2018-08-12 15:49:52.072854
Traceback (most recent call last):
File "***\test_lxml_etree.py", line 49, in proc
root = etree.fromstring(f.read())
File "src\lxml\etree.pyx", line 3213, in lxml.etree.fromstring
File "src\lxml\parser.pxi", line 1877, in lxml.etree._parseMemoryDocument
File "src\lxml\parser.pxi", line 1765, in lxml.etree._parseDoc
File "src\lxml\parser.pxi", line 1127, in lxml.etree._BaseParser._parseDoc
File "src\lxml\parser.pxi", line 601, in lxml.etree._ParserContext._handleParseResultDoc
File "src\lxml\parser.pxi", line 711, in lxml.etree._handleParseResult
File "src\lxml\parser.pxi", line 640, in lxml.etree._raiseParseError
File "<string>", line 5
lxml.etree.XMLSyntaxError: xmlns:vsys: Empty XML namespace is not allowed, line 5, column 358バージョン情報
- Windows 7 (64 bit)
- Python 3.5.2 (64 bit)
- lxml 4.2.4
- libxml 2.9.5
- libxslt 1.1.30
回避方法が見つかりました
以下の記事で紹介しています。
