使用 Perl XML::Twig 处理程序处理大文件时内存使用效率低下答案

【问题标题】：Inefficient use of memory processing large file with Perl XML::Twig handlers使用 Perl XML::Twig 处理程序处理大文件时内存使用效率低下
【发布时间】：2018-05-02 12:45:22
【问题描述】：

我偶尔需要从大型 XML 数据库导出中提取数据。文件大小在 600 到 700 MB 之间。经过几天的研究，我得出结论，XML::Twig 是可行的方法，因为它的处理程序允许我逐块处理文件。

我按照示例进行操作，经过几个小时的反复试验，我编写了执行我需要完成的工作的 Perl 代码。代码有效，它提取了我想要的数据并计算了我需要的细节。但是在运行脚本时（处理 620MB 的 XML 大约需要 15 分钟），我在 Activity Monitor 中注意到，到最后，内存使用量迅速增加到不合理的高水平。

我删除了处理我感兴趣的 XML 标记的 Perl 代码，并用一条指令替换它以增加一个变量，只需计算找到了多少 product 元素。内存使用情况相似。首先是正常，然后到最后几个元素，它开始迅速增加并耗尽我所有的一切。

我添加了一些代码来监控时间、处理的项目数以及我的 Perl 进程正在使用多少内存。此代码显示在此处：

#!/usr/bin/perl

use strict;
use utf8;

use XML::Twig;

binmode STDOUT, ":encoding(UTF-8)";
binmode STDERR, ":encoding(UTF-8)";

my $my_processID = $$;
my ($xml_file_name, $second_arg) = @ARGV;
unless (defined($xml_file_name)) { die "Please provide XML filename as 1st argument."; }

my $product_counter = 0;
my @shell_command_output_text;
my $resource_usage_status;
my $reference_timestamp;
my $datetimeNow;

my $t = XML::Twig->new(
    twig_handlers => { 'product' => \&do_what_needs_to_be_done_with_each_product },
    pretty_print  => 'indented'
);

$reference_timestamp = time();

$t->parsefile( $xml_file_name, ErrorContext => 2 );
print "(Parse finished)\n"; 
showstatus();
$t->purge;

print "(Purge finished)\n"; 
showstatus();
print "\nJOB COMPLETE.\n$product_counter items processed.\n";

exit 0;

sub do_what_needs_to_be_done_with_each_product() {
    my( $twig, $product)= @_;

    $product_counter++;

    ## Display status every 5 seconds:
    if ( ( time()-$reference_timestamp ) > 5 ) {
        showstatus();
        $reference_timestamp = time();
    }

    $twig->purge;
} ## end-sub


sub showstatus() {

    @shell_command_output_text = `top -l 1 -pid $my_processID -stats pid,command,cpu,mem`;

    ## I only need the last line of that output.
    $resource_usage_status = $shell_command_output_text[$#shell_command_output_text];
    $datetimeNow = localtime();
    chomp $resource_usage_status;

    print "Res: $resource_usage_status -> item count: $product_counter <- time: $datetimeNow\n";
} ## end-sub

这是我运行上述脚本时屏幕上显示的内容。

keve@deimos:DATA$ ./twigExample.pl product_db_extract.xml 
Res: 3237  perl5.18 0.0  12M+ -> item count: 3086 <- time: Sat Nov 18 23:45:48 2017
Res: 3237  perl5.18 0.0  12M+ -> item count: 6521 <- time: Sat Nov 18 23:45:55 2017
Res: 3237  perl5.18 0.0  12M+ -> item count: 9909 <- time: Sat Nov 18 23:46:02 2017
Res: 3237  perl5.18 0.0  12M+ -> item count: 12751 <- time: Sat Nov 18 23:46:09 2017
Res: 3237  perl5.18 0.0  12M+ -> item count: 15570 <- time: Sat Nov 18 23:46:16 2017
Res: 3237  perl5.18 0.0  12M+ -> item count: 18151 <- time: Sat Nov 18 23:46:23 2017
Res: 3237  perl5.18 0.0  12M+ -> item count: 20828 <- time: Sat Nov 18 23:46:30 2017
Res: 3237  perl5.18 0.0  12M+ -> item count: 23561 <- time: Sat Nov 18 23:46:37 2017
Res: 3237  perl5.18 0.0  12M+ -> item count: 26230 <- time: Sat Nov 18 23:46:44 2017
Res: 3237  perl5.18 0.0  12M+ -> item count: 28861 <- time: Sat Nov 18 23:46:51 2017
Res: 3237  perl5.18 0.0  12M+ -> item count: 31665 <- time: Sat Nov 18 23:46:58 2017
Res: 3237  perl5.18 0.0  13M+ -> item count: 34443 <- time: Sat Nov 18 23:47:05 2017
Res: 3237  perl5.18 0.0  13M+ -> item count: 36952 <- time: Sat Nov 18 23:47:12 2017
Res: 3237  perl5.18 0.0  13M+ -> item count: 39461 <- time: Sat Nov 18 23:47:19 2017
Res: 3237  perl5.18 0.0  13M+ -> item count: 42113 <- time: Sat Nov 18 23:47:26 2017
Res: 3237  perl5.18 0.0  13M+ -> item count: 44794 <- time: Sat Nov 18 23:47:33 2017
Res: 3237  perl5.18 0.0  13M+ -> item count: 47510 <- time: Sat Nov 18 23:47:40 2017
Res: 3237  perl5.18 0.0  15M+ -> item count: 50154 <- time: Sat Nov 18 23:47:47 2017
Res: 3237  perl5.18 0.0  15M+ -> item count: 52869 <- time: Sat Nov 18 23:47:54 2017
Res: 3237  perl5.18 0.0  15M+ -> item count: 55497 <- time: Sat Nov 18 23:48:01 2017
Res: 3237  perl5.18 0.0  15M+ -> item count: 57725 <- time: Sat Nov 18 23:48:08 2017
Res: 3237  perl5.18 0.0  15M+ -> item count: 59754 <- time: Sat Nov 18 23:48:15 2017
Res: 3237  perl5.18 0.0  15M+ -> item count: 61600 <- time: Sat Nov 18 23:48:22 2017
Res: 3237  perl5.18 0.0  15M+ -> item count: 63244 <- time: Sat Nov 18 23:48:29 2017
Res: 3237  perl5.18 0.0  15M+ -> item count: 64801 <- time: Sat Nov 18 23:48:36 2017
Res: 3237  perl5.18 0.0  15M+ -> item count: 66448 <- time: Sat Nov 18 23:48:43 2017
Res: 3237  perl5.18 0.0  15M+ -> item count: 68022 <- time: Sat Nov 18 23:48:50 2017
Res: 3237  perl5.18 0.0  15M+ -> item count: 69561 <- time: Sat Nov 18 23:48:57 2017
Res: 3237  perl5.18 0.0  15M+ -> item count: 71180 <- time: Sat Nov 18 23:49:04 2017
Res: 3237  perl5.18 0.0  15M+ -> item count: 73009 <- time: Sat Nov 18 23:49:11 2017
Res: 3237  perl5.18 0.0  15M+ -> item count: 75259 <- time: Sat Nov 18 23:49:18 2017
Res: 3237  perl5.18 0.0  15M+ -> item count: 77331 <- time: Sat Nov 18 23:49:25 2017
Res: 3237  perl5.18 0.0  15M+ -> item count: 79344 <- time: Sat Nov 18 23:49:32 2017
Res: 3237  perl5.18 0.0  15M+ -> item count: 81389 <- time: Sat Nov 18 23:49:39 2017
Res: 3237  perl5.18 0.0  15M+ -> item count: 83345 <- time: Sat Nov 18 23:49:46 2017
Res: 3237  perl5.18 0.0  15M+ -> item count: 85346 <- time: Sat Nov 18 23:49:53 2017
Res: 3237  perl5.18 0.0  15M+ -> item count: 87350 <- time: Sat Nov 18 23:50:00 2017
Res: 3237  perl5.18 0.0  15M+ -> item count: 89359 <- time: Sat Nov 18 23:50:07 2017
Res: 3237  perl5.18 0.0  15M+ -> item count: 91374 <- time: Sat Nov 18 23:50:14 2017
Res: 3237  perl5.18 0.0  15M+ -> item count: 93451 <- time: Sat Nov 18 23:50:21 2017
Res: 3237  perl5.18 0.0  15M+ -> item count: 95542 <- time: Sat Nov 18 23:50:28 2017
Res: 3237  perl5.18 0.0  15M+ -> item count: 97635 <- time: Sat Nov 18 23:50:35 2017
Res: 3237  perl5.18 0.0  15M+ -> item count: 99764 <- time: Sat Nov 18 23:50:42 2017
Res: 3237  perl5.18 0.0  15M+ -> item count: 101914 <- time: Sat Nov 18 23:50:49 2017
Res: 3237  perl5.18 0.0  15M+ -> item count: 103896 <- time: Sat Nov 18 23:50:56 2017
Res: 3237  perl5.18 0.0  15M+ -> item count: 105982 <- time: Sat Nov 18 23:51:03 2017
Res: 3237  perl5.18 0.0  15M+ -> item count: 108023 <- time: Sat Nov 18 23:51:10 2017
Res: 3237  perl5.18 0.0  15M+ -> item count: 110090 <- time: Sat Nov 18 23:51:17 2017
Res: 3237  perl5.18 0.0  15M+ -> item count: 112033 <- time: Sat Nov 18 23:51:24 2017
Res: 3237  perl5.18 0.0  15M+ -> item count: 114039 <- time: Sat Nov 18 23:51:31 2017
Res: 3237  perl5.18 0.0  15M+ -> item count: 116038 <- time: Sat Nov 18 23:51:38 2017
Res: 3237  perl5.18 0.0  15M+ -> item count: 118031 <- time: Sat Nov 18 23:51:45 2017
(Parse finished)
Res: 3237  perl5.18 0.0  3780M+ -> item count: 119335 <- time: Sat Nov 18 23:54:21 2017
(Purge finished)
Res: 3237  perl5.18 0.0  2634M+ -> item count: 119335 <- time: Sat Nov 18 23:54:27 2017

JOB COMPLETE.
119335 items processed.
keve@deimos:DATA$

请注意打印“解析完成”的 3 分钟间隔。

我预计最后几个产品标签的内存使用率会上升，就像我在活动监视器中看到的一样。但是打印的内存使用量（直到最后一个产品标签）是完全可以接受的 15 MB。这个输出中没有显示棘手的部分：只有缺少的 3 分钟时间和 3780M 表明在最终产品标签之后发生了一些奇怪的事情。

所以我编写了一个 shell 脚本来跟踪最后丢失的 3 分钟内的内存使用情况。这是我在一个单独的窗口中运行的内容，而 perl 脚本正在其自己的窗口中处理 XML。

#!/bin/bash
while true
do
  perlStat=`top -l 1 -pid $1 -stats pid,command,cpu,mem,purg,vsize | grep perl5`
  echo "`date` ::> $perlStat"
  sleep 5
done

这是在 perl 脚本处理 XML 时运行的那个 shell 脚本的输出：

keve@deimos:DATA$ ./monitorTWIGprocess.sh 3237
2017 Nov 18 Szo 23:45:53 CET ::> 3237  perl5.18 0.0  12M+ 0B   N/A  
2017 Nov 18 Szo 23:46:00 CET ::> 3237  perl5.18 0.0  12M+ 0B   N/A  
2017 Nov 18 Szo 23:46:06 CET ::> 3237  perl5.18 0.0  12M+ 0B   N/A  
2017 Nov 18 Szo 23:46:12 CET ::> 3237  perl5.18 0.0  12M+ 0B   N/A  
2017 Nov 18 Szo 23:46:18 CET ::> 3237  perl5.18 0.0  12M+ 0B   N/A  
2017 Nov 18 Szo 23:46:24 CET ::> 3237  perl5.18 0.0  12M+ 0B   N/A  
2017 Nov 18 Szo 23:46:30 CET ::> 3237  perl5.18 0.0  12M+ 0B   N/A  
2017 Nov 18 Szo 23:46:36 CET ::> 3237  perl5.18 0.0  12M+ 0B   N/A  
2017 Nov 18 Szo 23:46:42 CET ::> 3237  perl5.18 0.0  12M+ 0B   N/A  
2017 Nov 18 Szo 23:46:48 CET ::> 3237  perl5.18 0.0  12M+ 0B   N/A  
2017 Nov 18 Szo 23:46:54 CET ::> 3237  perl5.18 0.0  12M+ 0B   N/A  
2017 Nov 18 Szo 23:47:01 CET ::> 3237  perl5.18 0.0  12M+ 0B   N/A  
2017 Nov 18 Szo 23:47:07 CET ::> 3237  perl5.18 0.0  13M+ 0B   N/A  
2017 Nov 18 Szo 23:47:13 CET ::> 3237  perl5.18 0.0  13M+ 0B   N/A  
2017 Nov 18 Szo 23:47:19 CET ::> 3237  perl5.18 0.0  13M+ 0B   N/A  
2017 Nov 18 Szo 23:47:25 CET ::> 3237  perl5.18 0.0  13M+ 0B   N/A  
2017 Nov 18 Szo 23:47:31 CET ::> 3237  perl5.18 0.0  13M+ 0B   N/A  
2017 Nov 18 Szo 23:47:37 CET ::> 3237  perl5.18 0.0  13M+ 0B   N/A  
2017 Nov 18 Szo 23:47:43 CET ::> 3237  perl5.18 0.0  15M+ 0B   N/A  
2017 Nov 18 Szo 23:47:49 CET ::> 3237  perl5.18 0.0  15M+ 0B   N/A  
2017 Nov 18 Szo 23:47:56 CET ::> 3237  perl5.18 0.0  15M+ 0B   N/A  
2017 Nov 18 Szo 23:48:02 CET ::> 3237  perl5.18 0.0  15M+ 0B   N/A  
2017 Nov 18 Szo 23:48:08 CET ::> 3237  perl5.18 0.0  15M+ 0B   N/A  
2017 Nov 18 Szo 23:48:14 CET ::> 3237  perl5.18 0.0  15M+ 0B   N/A  
2017 Nov 18 Szo 23:48:20 CET ::> 3237  perl5.18 0.0  15M+ 0B   N/A  
2017 Nov 18 Szo 23:48:26 CET ::> 3237  perl5.18 0.0  15M+ 0B   N/A  
2017 Nov 18 Szo 23:48:32 CET ::> 3237  perl5.18 0.0  15M+ 0B   N/A  
2017 Nov 18 Szo 23:48:38 CET ::> 3237  perl5.18 0.0  15M+ 0B   N/A  
2017 Nov 18 Szo 23:48:44 CET ::> 3237  perl5.18 0.0  15M+ 0B   N/A  
2017 Nov 18 Szo 23:48:51 CET ::> 3237  perl5.18 0.0  15M+ 0B   N/A  
2017 Nov 18 Szo 23:48:57 CET ::> 3237  perl5.18 0.0  15M+ 0B   N/A  
2017 Nov 18 Szo 23:49:03 CET ::> 3237  perl5.18 0.0  15M+ 0B   N/A  
2017 Nov 18 Szo 23:49:09 CET ::> 3237  perl5.18 0.0  15M+ 0B   N/A  
2017 Nov 18 Szo 23:49:15 CET ::> 3237  perl5.18 0.0  15M+ 0B   N/A  
2017 Nov 18 Szo 23:49:21 CET ::> 3237  perl5.18 0.0  15M+ 0B   N/A  
2017 Nov 18 Szo 23:49:27 CET ::> 3237  perl5.18 0.0  15M+ 0B   N/A  
2017 Nov 18 Szo 23:49:33 CET ::> 3237  perl5.18 0.0  15M+ 0B   N/A  
2017 Nov 18 Szo 23:49:39 CET ::> 3237  perl5.18 0.0  15M+ 0B   N/A  
2017 Nov 18 Szo 23:49:46 CET ::> 3237  perl5.18 0.0  15M+ 0B   N/A  
2017 Nov 18 Szo 23:49:52 CET ::> 3237  perl5.18 0.0  15M+ 0B   N/A  
2017 Nov 18 Szo 23:49:58 CET ::> 3237  perl5.18 0.0  15M+ 0B   N/A  
2017 Nov 18 Szo 23:50:04 CET ::> 3237  perl5.18 0.0  15M+ 0B   N/A  
2017 Nov 18 Szo 23:50:10 CET ::> 3237  perl5.18 0.0  15M+ 0B   N/A  
2017 Nov 18 Szo 23:50:16 CET ::> 3237  perl5.18 0.0  15M+ 0B   N/A  
2017 Nov 18 Szo 23:50:22 CET ::> 3237  perl5.18 0.0  15M+ 0B   N/A  
2017 Nov 18 Szo 23:50:28 CET ::> 3237  perl5.18 0.0  15M+ 0B   N/A  
2017 Nov 18 Szo 23:50:35 CET ::> 3237  perl5.18 0.0  15M+ 0B   N/A  
2017 Nov 18 Szo 23:50:41 CET ::> 3237  perl5.18 0.0  15M+ 0B   N/A  
2017 Nov 18 Szo 23:50:47 CET ::> 3237  perl5.18 0.0  15M+ 0B   N/A  
2017 Nov 18 Szo 23:50:53 CET ::> 3237  perl5.18 0.0  15M+ 0B   N/A  
2017 Nov 18 Szo 23:50:59 CET ::> 3237  perl5.18 0.0  15M+ 0B   N/A  
2017 Nov 18 Szo 23:51:05 CET ::> 3237  perl5.18 0.0  15M+ 0B   N/A  
2017 Nov 18 Szo 23:51:11 CET ::> 3237  perl5.18 0.0  15M+ 0B   N/A  
2017 Nov 18 Szo 23:51:17 CET ::> 3237  perl5.18 0.0  15M+ 0B   N/A  
2017 Nov 18 Szo 23:51:23 CET ::> 3237  perl5.18 0.0  15M+ 0B   N/A  
2017 Nov 18 Szo 23:51:29 CET ::> 3237  perl5.18 0.0  15M+ 0B   N/A  
2017 Nov 18 Szo 23:51:36 CET ::> 3237  perl5.18 0.0  15M+ 0B   N/A  
2017 Nov 18 Szo 23:51:42 CET ::> 3237  perl5.18 0.0  15M+ 0B   N/A  
2017 Nov 18 Szo 23:51:48 CET ::> 3237  perl5.18 0.0  15M+ 0B   N/A  
2017 Nov 18 Szo 23:51:54 CET ::> 3237  perl5.18 0.0  125M+ 0B   N/A  
2017 Nov 18 Szo 23:52:00 CET ::> 3237  perl5.18 0.0  278M+ 0B   N/A  
2017 Nov 18 Szo 23:52:06 CET ::> 3237  perl5.18 0.0  430M+ 0B   N/A  
2017 Nov 18 Szo 23:52:12 CET ::> 3237  perl5.18 0.0  584M+ 0B   N/A  
2017 Nov 18 Szo 23:52:18 CET ::> 3237  perl5.18 0.0  737M+ 0B   N/A  
2017 Nov 18 Szo 23:52:24 CET ::> 3237  perl5.18 0.0  889M+ 0B   N/A  
2017 Nov 18 Szo 23:52:31 CET ::> 3237  perl5.18 0.0  1042M+ 0B   N/A  
2017 Nov 18 Szo 23:52:37 CET ::> 3237  perl5.18 0.0  1195M+ 0B   N/A  
2017 Nov 18 Szo 23:52:43 CET ::> 3237  perl5.18 0.0  1349M+ 0B   N/A  
2017 Nov 18 Szo 23:52:49 CET ::> 3237  perl5.18 0.0  1502M+ 0B   N/A  
2017 Nov 18 Szo 23:52:55 CET ::> 3237  perl5.18 0.0  1656M+ 0B   N/A  
2017 Nov 18 Szo 23:53:01 CET ::> 3237  perl5.18 0.0  1809M+ 0B   N/A  
2017 Nov 18 Szo 23:53:07 CET ::> 3237  perl5.18 0.0  1961M+ 0B   N/A  
2017 Nov 18 Szo 23:53:13 CET ::> 3237  perl5.18 0.0  2114M+ 0B   N/A  
2017 Nov 18 Szo 23:53:19 CET ::> 3237  perl5.18 0.0  2267M+ 0B   N/A  
2017 Nov 18 Szo 23:53:26 CET ::> 3237  perl5.18 0.0  2420M+ 0B   N/A  
2017 Nov 18 Szo 23:53:32 CET ::> 3237  perl5.18 0.0  2573M+ 0B   N/A  
2017 Nov 18 Szo 23:53:38 CET ::> 3237  perl5.18 0.0  2726M+ 0B   N/A  
2017 Nov 18 Szo 23:53:44 CET ::> 3237  perl5.18 0.0  2879M+ 0B   N/A  
2017 Nov 18 Szo 23:53:50 CET ::> 3237  perl5.18 0.0  3032M+ 0B   N/A  
2017 Nov 18 Szo 23:53:56 CET ::> 3237  perl5.18 0.0  3186M+ 0B   N/A  
2017 Nov 18 Szo 23:54:02 CET ::> 3237  perl5.18 0.0  3339M+ 0B   N/A  
2017 Nov 18 Szo 23:54:08 CET ::> 3237  perl5.18 0.0  3492M+ 0B   N/A  
2017 Nov 18 Szo 23:54:15 CET ::> 3237  perl5.18 0.0  3646M+ 0B   N/A  
2017 Nov 18 Szo 23:54:21 CET ::> 3237  perl5.18 0.0  3786M+ 0B   N/A  
2017 Nov 18 Szo 23:54:27 CET ::> 3237  perl5.18 0.0  3502M+ 0B   N/A  
2017 Nov 18 Szo 23:54:33 CET ::> 
^C
keve@deimos:DATA$

请注意在 23:51:54 内存使用量的增加。那是另一个输出中 3 分钟的间隔开始的时候。并且内存使用量从那里迅速上升。

我不明白是什么原因导致在处理最后一个（第 119,335 个）产品标签结束时内存使用量迅速增加。不管它是什么，为什么它要使用这么多内存？ 3.5G而不是15M，那不行。

我是不是做错了什么？

关于如何避免内存使用增加的任何建议？

后来添加，以回应我原来的帖子收到的答案。

补充
切换到 twig_roots。
我通过注释掉处理程序定义并添加其 twig_roots 品种来修改 twig 处理程序块，如下所示：

my $t = XML::Twig->new(
        ##twig_handlers => { 'product' => \&do_what_needs_to_be_done_with_each_product },
        twig_roots => { 'product' => \&do_what_needs_to_be_done_with_each_product },
        twig_print_outside_roots => 0,
        pretty_print => 'indented'
        );

我将$twig->purge(); 指令留在了我的子程序中。

这里是 perl 脚本的输出：

keve@deimos:DATA$ ./twigExample.pl product_db_extract.xml 
Res: 1591  perl5.18 0.0  12M+ -> item count: 2852 <- time: Sun Nov 19 15:20:51 2017
Res: 1591  perl5.18 0.0  12M+ -> item count: 6106 <- time: Sun Nov 19 15:20:58 2017
Res: 1591  perl5.18 0.0  12M+ -> item count: 9341 <- time: Sun Nov 19 15:21:05 2017
Res: 1591  perl5.18 0.0  12M+ -> item count: 12141 <- time: Sun Nov 19 15:21:12 2017
.
.
.
Res: 1591  perl5.18 0.0  15M+ -> item count: 112293 <- time: Sun Nov 19 15:26:41 2017
Res: 1591  perl5.18 0.0  15M+ -> item count: 114255 <- time: Sun Nov 19 15:26:48 2017
Res: 1591  perl5.18 0.0  15M+ -> item count: 116171 <- time: Sun Nov 19 15:26:55 2017
Res: 1591  perl5.18 0.0  15M+ -> item count: 118099 <- time: Sun Nov 19 15:27:02 2017
(Parse finished)
Res: 1591  perl5.18 0.0  15M+ -> item count: 119335 <- time: Sun Nov 19 15:27:56 2017
(Purge finished)
Res: 1591  perl5.18 0.0  15M+ -> item count: 119335 <- time: Sun Nov 19 15:27:57 2017

JOB COMPLETE.
119335 items processed.
keve@deimos:DATA$

这里是监控shell脚本的输出：

keve@deimos:DATA$ ./monitorTWIGprocess.sh 1591
2017 Nov 19 Vas 15:20:57 CET ::> 1591  perl5.18 0.0  12M+ 0B   N/A  
2017 Nov 19 Vas 15:21:03 CET ::> 1591  perl5.18 0.0  12M+ 0B   N/A  
2017 Nov 19 Vas 15:21:09 CET ::> 1591  perl5.18 0.0  12M+ 0B   N/A  
2017 Nov 19 Vas 15:21:16 CET ::> 1591  perl5.18 0.0  12M+ 0B   N/A  
2017 Nov 19 Vas 15:21:22 CET ::> 1591  perl5.18 0.0  12M+ 0B   N/A  
2017 Nov 19 Vas 15:21:28 CET ::> 1591  perl5.18 0.0  12M+ 0B   N/A  
2017 Nov 19 Vas 15:21:34 CET ::> 1591  perl5.18 0.0  12M+ 0B   N/A  
2017 Nov 19 Vas 15:21:40 CET ::> 1591  perl5.18 0.0  12M+ 0B   N/A  
2017 Nov 19 Vas 15:21:46 CET ::> 1591  perl5.18 0.0  12M+ 0B   N/A  
2017 Nov 19 Vas 15:21:52 CET ::> 1591  perl5.18 0.0  12M+ 0B   N/A  
2017 Nov 19 Vas 15:21:58 CET ::> 1591  perl5.18 0.0  12M+ 0B   N/A  
2017 Nov 19 Vas 15:22:04 CET ::> 1591  perl5.18 0.0  12M+ 0B   N/A  
2017 Nov 19 Vas 15:22:10 CET ::> 1591  perl5.18 0.0  12M+ 0B   N/A  
2017 Nov 19 Vas 15:22:16 CET ::> 1591  perl5.18 0.0  13M+ 0B   N/A  
2017 Nov 19 Vas 15:22:22 CET ::> 1591  perl5.18 0.0  13M+ 0B   N/A  
2017 Nov 19 Vas 15:22:28 CET ::> 1591  perl5.18 0.0  13M+ 0B   N/A  
2017 Nov 19 Vas 15:22:35 CET ::> 1591  perl5.18 0.0  13M+ 0B   N/A  
2017 Nov 19 Vas 15:22:41 CET ::> 1591  perl5.18 0.0  13M+ 0B   N/A  
2017 Nov 19 Vas 15:22:47 CET ::> 1591  perl5.18 0.0  13M+ 0B   N/A  
2017 Nov 19 Vas 15:22:53 CET ::> 1591  perl5.18 0.0  15M+ 0B   N/A  
2017 Nov 19 Vas 15:22:59 CET ::> 1591  perl5.18 0.0  15M+ 0B   N/A  
2017 Nov 19 Vas 15:23:05 CET ::> 1591  perl5.18 0.0  15M+ 0B   N/A  
2017 Nov 19 Vas 15:23:11 CET ::> 1591  perl5.18 0.0  15M+ 0B   N/A  
2017 Nov 19 Vas 15:23:17 CET ::> 1591  perl5.18 0.0  15M+ 0B   N/A  
2017 Nov 19 Vas 15:23:23 CET ::> 1591  perl5.18 0.0  15M+ 0B   N/A  
2017 Nov 19 Vas 15:23:29 CET ::> 1591  perl5.18 0.0  15M+ 0B   N/A  
2017 Nov 19 Vas 15:23:35 CET ::> 1591  perl5.18 0.0  15M+ 0B   N/A  
2017 Nov 19 Vas 15:23:41 CET ::> 1591  perl5.18 0.0  15M+ 0B   N/A  
2017 Nov 19 Vas 15:23:47 CET ::> 1591  perl5.18 0.0  15M+ 0B   N/A  
2017 Nov 19 Vas 15:23:54 CET ::> 1591  perl5.18 0.0  15M+ 0B   N/A  
2017 Nov 19 Vas 15:24:00 CET ::> 1591  perl5.18 0.0  15M+ 0B   N/A  
2017 Nov 19 Vas 15:24:06 CET ::> 1591  perl5.18 0.0  15M+ 0B   N/A  
2017 Nov 19 Vas 15:24:12 CET ::> 1591  perl5.18 0.0  15M+ 0B   N/A  
2017 Nov 19 Vas 15:24:18 CET ::> 1591  perl5.18 0.0  15M+ 0B   N/A  
2017 Nov 19 Vas 15:24:24 CET ::> 1591  perl5.18 0.0  15M+ 0B   N/A  
2017 Nov 19 Vas 15:24:30 CET ::> 1591  perl5.18 0.0  15M+ 0B   N/A  
2017 Nov 19 Vas 15:24:36 CET ::> 1591  perl5.18 0.0  15M+ 0B   N/A  
2017 Nov 19 Vas 15:24:42 CET ::> 1591  perl5.18 0.0  15M+ 0B   N/A  
2017 Nov 19 Vas 15:24:48 CET ::> 1591  perl5.18 0.0  15M+ 0B   N/A  
2017 Nov 19 Vas 15:24:54 CET ::> 1591  perl5.18 0.0  15M+ 0B   N/A  
2017 Nov 19 Vas 15:25:00 CET ::> 1591  perl5.18 0.0  15M+ 0B   N/A  
2017 Nov 19 Vas 15:25:06 CET ::> 1591  perl5.18 0.0  15M+ 0B   N/A  
2017 Nov 19 Vas 15:25:13 CET ::> 1591  perl5.18 0.0  15M+ 0B   N/A  
2017 Nov 19 Vas 15:25:19 CET ::> 1591  perl5.18 0.0  15M+ 0B   N/A  
2017 Nov 19 Vas 15:25:25 CET ::> 1591  perl5.18 0.0  15M+ 0B   N/A  
2017 Nov 19 Vas 15:25:31 CET ::> 1591  perl5.18 0.0  15M+ 0B   N/A  
2017 Nov 19 Vas 15:25:37 CET ::> 1591  perl5.18 0.0  15M+ 0B   N/A  
2017 Nov 19 Vas 15:25:43 CET ::> 1591  perl5.18 0.0  15M+ 0B   N/A  
2017 Nov 19 Vas 15:25:49 CET ::> 1591  perl5.18 0.0  15M+ 0B   N/A  
2017 Nov 19 Vas 15:25:55 CET ::> 1591  perl5.18 0.0  15M+ 0B   N/A  
2017 Nov 19 Vas 15:26:01 CET ::> 1591  perl5.18 0.0  15M+ 0B   N/A  
2017 Nov 19 Vas 15:26:07 CET ::> 1591  perl5.18 0.0  15M+ 0B   N/A  
2017 Nov 19 Vas 15:26:13 CET ::> 1591  perl5.18 0.0  15M+ 0B   N/A  
2017 Nov 19 Vas 15:26:19 CET ::> 1591  perl5.18 0.0  15M+ 0B   N/A  
2017 Nov 19 Vas 15:26:26 CET ::> 1591  perl5.18 0.0  15M+ 0B   N/A  
2017 Nov 19 Vas 15:26:32 CET ::> 1591  perl5.18 0.0  15M+ 0B   N/A  
2017 Nov 19 Vas 15:26:38 CET ::> 1591  perl5.18 0.0  15M+ 0B   N/A  
2017 Nov 19 Vas 15:26:44 CET ::> 1591  perl5.18 0.0  15M+ 0B   N/A  
2017 Nov 19 Vas 15:26:50 CET ::> 1591  perl5.18 0.0  15M+ 0B   N/A  
2017 Nov 19 Vas 15:26:56 CET ::> 1591  perl5.18 0.0  15M+ 0B   N/A  
2017 Nov 19 Vas 15:27:02 CET ::> 1591  perl5.18 0.0  15M+ 0B   N/A  
2017 Nov 19 Vas 15:27:08 CET ::> 1591  perl5.18 0.0  15M+ 0B   N/A  
2017 Nov 19 Vas 15:27:14 CET ::> 1591  perl5.18 0.0  15M+ 0B   N/A  
2017 Nov 19 Vas 15:27:20 CET ::> 1591  perl5.18 0.0  15M+ 0B   N/A  
2017 Nov 19 Vas 15:27:26 CET ::> 1591  perl5.18 0.0  15M+ 0B   N/A  
2017 Nov 19 Vas 15:27:32 CET ::> 1591  perl5.18 0.0  15M+ 0B   N/A  
2017 Nov 19 Vas 15:27:38 CET ::> 1591  perl5.18 0.0  15M+ 0B   N/A  
2017 Nov 19 Vas 15:27:44 CET ::> 1591  perl5.18 0.0  15M+ 0B   N/A  
2017 Nov 19 Vas 15:27:51 CET ::> 1591  perl5.18 0.0  15M+ 0B   N/A  
2017 Nov 19 Vas 15:27:57 CET ::> 1591  perl5.18 0.0  15M+ 0B   N/A  
2017 Nov 19 Vas 15:28:03 CET ::> 
^C
keve@deimos:DATA$

好消息是，使用 twig_roots 方法而不是 twig 处理程序可以让我的 perl 代码按我的意愿运行。它通过一个巨大的 XML 文件从每个产品中提取数据（提取的数据不是 XML 格式），同时使用的内存量保持在 20 兆字节以下。太棒了！
坏消息是我仍然无法解释为什么使用处理程序会占用这么多内存，以及为什么在读取最后一个产品后它会这样做。直到最后一个产品，内存使用都非常好。是什么让它在那个时候失控？我将进行更多测试来满足我的好奇心，但这不再与我的 XML 处理 perl 代码开发如何进行的问题相关联。我将 twig_roots 建议标记为已接受的答案，但我也非常感谢另一个答案，因为它同样具有教育意义。

【问题讨论】：

请不要在程序顶部声明所有变量。它们应该在尽可能小的范围内声明，通常在它们第一次定义的地方，就像您使用 my $t = ... 所做的那样
特别是，$datetimeNow 应该在showstatus 中声明为my $datetimeNow = localtime。而且您应该避免使用原型：两个子程序都应该只是 sub showstatus { ... } 等。
我在顶部声明变量的习惯来自于我使用的其他编程语言。在使用 perl 时我会尽量注意这一点。我也会更加小心我的潜艇。
是的，我是这么认为的。大概你是一个C程序员？无论哪种方式，一大块声明实际上只是让编译错误消失的一种方式。我能想到的每一种现代语言都允许你在有限的范围内声明变量，你应该在任何地方使用相同的原则。
mirod 的 答案不是解决方案；他只是在问删除purge 是如何影响行为的。然而，他是XML::Twig 的作者，如果你想解释高内存使用率，那么他是你最好的选择。您应该展示您正在处理的 XML 示例，其中至少包括一些 product 元素。

标签： xml perl xml-twig

【解决方案1】：

您正在构建一个完整的 XML 数据结构，除了 product 元素，只是在最后将其全部丢弃

你没有说你真正想对数据做什么，但如果你提供twig_handlers 那么XML::Twig 期望生成输入数据的过滤/修改版本

如果您根本不想要任何输出 XML，或者您想构建自己的而不是修改输入，那么我建议您改用 twig_roots，就像这样

这是未经测试的代码。我目前正在旅行，离 PC 系统很远，可以用它进行测试

my $t = XML::Twig->new(
    twig_roots               => { product => \&do_what_needs_to_be_done_with_each_product },
    twig_print_outside_roots => 0,
    pretty_print             => 'indented',
);

注意do_what_needs_to_be_done_with_each_product（我希望这不是真正的标识符）在这样工作时不应包含$t->purge

【讨论】：

twig_roots 方式似乎是我需要的方式。我按照您建议的方式修改了 perl 脚本（产品在单引号中，并且在 pretty_print 行后面没有逗号），它完成了我最初期望它做的事情，而内存使用量不超过 15M。当我研究 XML::Twig 文档时，我确实阅读了 twig_roots 部分，但我不明白它的用途。更准确地说，我没有意识到这是我需要的方法。现在我得出结论，twig_roots 做了我认为 twig 处理程序所做的事情。感谢您为我指明正确的方向！
@Keve：我很乐意提供帮助。我同意文档不是最清晰的。三分钟的差距也消失了吗？而且你知道那些引号和逗号是不必要的，对吧？
是的，3 分钟的间隔消失了。我将新结果添加到我的原始帖子中。我对 Mirod 的建议也有结果，但由于字符限制（使我的帖子太长）而无法添加到我的帖子中。不，我不知道引号在那里是微不足道的，或者逗号可能会留在那里。所以这是我今天学到的另一个新东西。 :)
@Keve：这听起来是正确的行为！八分钟够快吗？没有理由在product 周围加上引号，因为“胖逗号”在其左侧隐含地引用了任何“单词字符”（字母数字和下划线）字符串。如果您想要包含空格或标点符号的内容，则需要引号。否则=> 与普通逗号相同。并且 Perl 允许在列表的最后一个元素之后使用逗号，这样您就可以轻松地添加新条目，而无需修改原来的最后一行。

【解决方案2】：

在最后一次清除（解析结束后）期间，内存使用量似乎急剧增加。

如果不清除会发生什么？

以下是删除/注释掉$twig->purge(); 行时发生的情况。
处理 XML 的 perl 脚本的输出：

keve@deimos:DATA$ ./twigExample.pl product_db_extract.xml 
Res: 496  perl5.18 0.0  144M+ -> item count: 2905 <- time: Sun Nov 19 13:23:04 2017
Res: 496  perl5.18 0.0  291M+ -> item count: 6341 <- time: Sun Nov 19 13:23:11 2017
Res: 496  perl5.18 0.0  439M+ -> item count: 9777 <- time: Sun Nov 19 13:23:18 2017
Res: 496  perl5.18 0.0  587M+ -> item count: 12641 <- time: Sun Nov 19 13:23:25 2017
Res: 496  perl5.18 0.0  735M+ -> item count: 15528 <- time: Sun Nov 19 13:23:32 2017
Res: 496  perl5.18 0.0  883M+ -> item count: 18137 <- time: Sun Nov 19 13:23:39 2017
Res: 496  perl5.18 0.0  1032M+ -> item count: 20852 <- time: Sun Nov 19 13:23:46 2017
Res: 496  perl5.18 0.0  1179M+ -> item count: 23596 <- time: Sun Nov 19 13:23:53 2017
Res: 496  perl5.18 0.0  1328M+ -> item count: 26297 <- time: Sun Nov 19 13:24:00 2017
Res: 496  perl5.18 0.0  1476M+ -> item count: 28929 <- time: Sun Nov 19 13:24:07 2017
Res: 496  perl5.18 0.0  1624M+ -> item count: 31752 <- time: Sun Nov 19 13:24:14 2017
Res: 496  perl5.18 0.0  1772M+ -> item count: 34536 <- time: Sun Nov 19 13:24:21 2017
Res: 496  perl5.18 0.0  1920M+ -> item count: 37019 <- time: Sun Nov 19 13:24:28 2017
Res: 496  perl5.18 0.0  2068M+ -> item count: 39566 <- time: Sun Nov 19 13:24:35 2017
Res: 496  perl5.18 0.0  2216M+ -> item count: 42246 <- time: Sun Nov 19 13:24:42 2017
Res: 496  perl5.18 0.0  2365M+ -> item count: 44976 <- time: Sun Nov 19 13:24:49 2017
Res: 496  perl5.18 0.0  2513M+ -> item count: 47722 <- time: Sun Nov 19 13:24:56 2017
Res: 496  perl5.18 0.0  2662M+ -> item count: 50389 <- time: Sun Nov 19 13:25:03 2017
Res: 496  perl5.18 0.0  2810M+ -> item count: 53083 <- time: Sun Nov 19 13:25:10 2017
Res: 496  perl5.18 0.0  2958M+ -> item count: 55745 <- time: Sun Nov 19 13:25:17 2017
Res: 496  perl5.18 0.0  3106M+ -> item count: 57955 <- time: Sun Nov 19 13:25:24 2017
Res: 496  perl5.18 0.0  3253M+ -> item count: 59924 <- time: Sun Nov 19 13:25:31 2017
Res: 496  perl5.18 0.0  3402M+ -> item count: 61742 <- time: Sun Nov 19 13:25:38 2017
Res: 496  perl5.18 0.0  3550M+ -> item count: 63373 <- time: Sun Nov 19 13:25:45 2017
Res: 496  perl5.18 0.0  3698M+ -> item count: 64954 <- time: Sun Nov 19 13:25:52 2017
Res: 496  perl5.18 0.0  3845M+ -> item count: 66589 <- time: Sun Nov 19 13:25:59 2017
Res: 496  perl5.18 0.0  3993M+ -> item count: 68165 <- time: Sun Nov 19 13:26:06 2017
Res: 496  perl5.18 0.0  4141M+ -> item count: 69717 <- time: Sun Nov 19 13:26:13 2017
Res: 496  perl5.18 0.0  4289M+ -> item count: 71320 <- time: Sun Nov 19 13:26:20 2017
Res: 496  perl5.18 0.0  4380M+ -> item count: 73202 <- time: Sun Nov 19 13:26:27 2017
Res: 496  perl5.18 0.0  4384M+ -> item count: 75413 <- time: Sun Nov 19 13:26:34 2017
Res: 496  perl5.18 0.0  4280M+ -> item count: 77457 <- time: Sun Nov 19 13:26:41 2017
Res: 496  perl5.18 0.0  4181M+ -> item count: 79444 <- time: Sun Nov 19 13:26:48 2017
Res: 496  perl5.18 0.0  4094M+ -> item count: 81443 <- time: Sun Nov 19 13:26:55 2017
Res: 496  perl5.18 0.0  3939M+ -> item count: 83351 <- time: Sun Nov 19 13:27:02 2017
Res: 496  perl5.18 0.0  3839M+ -> item count: 85322 <- time: Sun Nov 19 13:27:09 2017
Res: 496  perl5.18 0.0  3727M+ -> item count: 87307 <- time: Sun Nov 19 13:27:16 2017
Res: 496  perl5.18 0.0  3629M+ -> item count: 89305 <- time: Sun Nov 19 13:27:23 2017
Res: 496  perl5.18 0.0  3521M+ -> item count: 91275 <- time: Sun Nov 19 13:27:30 2017
Res: 496  perl5.18 0.0  3418M+ -> item count: 93298 <- time: Sun Nov 19 13:27:37 2017
Res: 496  perl5.18 0.0  3299M+ -> item count: 95339 <- time: Sun Nov 19 13:27:44 2017
Res: 496  perl5.18 0.0  3189M+ -> item count: 97398 <- time: Sun Nov 19 13:27:51 2017
Res: 496  perl5.18 0.0  3141M+ -> item count: 99449 <- time: Sun Nov 19 13:27:58 2017
Res: 496  perl5.18 0.0  2977M+ -> item count: 101543 <- time: Sun Nov 19 13:28:05 2017
Res: 496  perl5.18 0.0  2857M+ -> item count: 103519 <- time: Sun Nov 19 13:28:12 2017
Res: 496  perl5.18 0.0  2748M+ -> item count: 105574 <- time: Sun Nov 19 13:28:19 2017
Res: 496  perl5.18 0.0  2643M+ -> item count: 107550 <- time: Sun Nov 19 13:28:26 2017
Res: 496  perl5.18 0.0  2591M+ -> item count: 109574 <- time: Sun Nov 19 13:28:33 2017
Res: 496  perl5.18 0.0  2506M+ -> item count: 111562 <- time: Sun Nov 19 13:28:40 2017
Res: 496  perl5.18 0.0  2389M+ -> item count: 113485 <- time: Sun Nov 19 13:28:47 2017
Res: 496  perl5.18 0.0  2280M+ -> item count: 115455 <- time: Sun Nov 19 13:28:54 2017
Res: 496  perl5.18 0.0  2100M+ -> item count: 117391 <- time: Sun Nov 19 13:29:01 2017
(Parse finished)
Res: 496  perl5.18 0.0  893M+ -> item count: 119335 <- time: Sun Nov 19 13:31:41 2017
(Purge finished)
Res: 496  perl5.18 0.0  5144M+ -> item count: 119335 <- time: Sun Nov 19 13:32:27 2017

JOB COMPLETE.
119335 items processed.
keve@deimos:DATA$

监控perl脚本内存使用情况的shell脚本输出：

keve@deimos:DATA$ ./monitorTWIGprocess.sh 496
2017 Nov 19 Vas 13:23:11 CET ::> 496  perl5.18 0.0  291M+ 0B   N/A  
2017 Nov 19 Vas 13:23:17 CET ::> 496  perl5.18 0.0  434M+ 0B   N/A  
2017 Nov 19 Vas 13:23:23 CET ::> 496  perl5.18 0.0  559M+ 0B   N/A  
2017 Nov 19 Vas 13:23:30 CET ::> 496  perl5.18 0.0  684M+ 0B   N/A  
2017 Nov 19 Vas 13:23:36 CET ::> 496  perl5.18 0.0  810M+ 0B   N/A  
2017 Nov 19 Vas 13:23:42 CET ::> 496  perl5.18 0.0  936M+ 0B   N/A  
2017 Nov 19 Vas 13:23:48 CET ::> 496  perl5.18 0.0  1061M+ 0B   N/A  
2017 Nov 19 Vas 13:23:54 CET ::> 496  perl5.18 0.0  1185M+ 0B   N/A  
2017 Nov 19 Vas 13:24:00 CET ::> 496  perl5.18 0.0  1328M+ 0B   N/A  
2017 Nov 19 Vas 13:24:06 CET ::> 496  perl5.18 0.0  1463M+ 0B   N/A  
2017 Nov 19 Vas 13:24:12 CET ::> 496  perl5.18 0.0  1589M+ 0B   N/A  
2017 Nov 19 Vas 13:24:18 CET ::> 496  perl5.18 0.0  1715M+ 0B   N/A  
2017 Nov 19 Vas 13:24:24 CET ::> 496  perl5.18 0.0  1840M+ 0B   N/A  
2017 Nov 19 Vas 13:24:30 CET ::> 496  perl5.18 0.0  1964M+ 0B   N/A  
2017 Nov 19 Vas 13:24:36 CET ::> 496  perl5.18 0.0  2090M+ 0B   N/A  
2017 Nov 19 Vas 13:24:43 CET ::> 496  perl5.18 0.0  2216M+ 0B   N/A  
2017 Nov 19 Vas 13:24:49 CET ::> 496  perl5.18 0.0  2365M+ 0B   N/A  
2017 Nov 19 Vas 13:24:55 CET ::> 496  perl5.18 0.0  2494M+ 0B   N/A  
2017 Nov 19 Vas 13:25:01 CET ::> 496  perl5.18 0.0  2620M+ 0B   N/A  
2017 Nov 19 Vas 13:25:07 CET ::> 496  perl5.18 0.0  2745M+ 0B   N/A  
2017 Nov 19 Vas 13:25:13 CET ::> 496  perl5.18 0.0  2870M+ 0B   N/A  
2017 Nov 19 Vas 13:25:19 CET ::> 496  perl5.18 0.0  2996M+ 0B   N/A  
2017 Nov 19 Vas 13:25:25 CET ::> 496  perl5.18 0.0  3121M+ 0B   N/A  
2017 Nov 19 Vas 13:25:31 CET ::> 496  perl5.18 0.0  3253M+ 0B   N/A  
2017 Nov 19 Vas 13:25:37 CET ::> 496  perl5.18 0.0  3399M+ 0B   N/A  
2017 Nov 19 Vas 13:25:43 CET ::> 496  perl5.18 0.0  3524M+ 0B   N/A  
2017 Nov 19 Vas 13:25:50 CET ::> 496  perl5.18 0.0  3649M+ 0B   N/A  
2017 Nov 19 Vas 13:25:56 CET ::> 496  perl5.18 0.0  3774M+ 0B   N/A  
2017 Nov 19 Vas 13:26:02 CET ::> 496  perl5.18 0.0  3899M+ 0B   N/A  
2017 Nov 19 Vas 13:26:08 CET ::> 496  perl5.18 0.0  4024M+ 0B   N/A  
2017 Nov 19 Vas 13:26:14 CET ::> 496  perl5.18 0.0  4149M+ 0B   N/A  
2017 Nov 19 Vas 13:26:20 CET ::> 496  perl5.18 0.0  4289M+ 0B   N/A  
2017 Nov 19 Vas 13:26:26 CET ::> 496  perl5.18 0.0  4370M+ 0B   N/A  
2017 Nov 19 Vas 13:26:32 CET ::> 496  perl5.18 0.0  4409M+ 0B   N/A  
2017 Nov 19 Vas 13:26:38 CET ::> 496  perl5.18 0.0  4319M+ 0B   N/A  
2017 Nov 19 Vas 13:26:44 CET ::> 496  perl5.18 0.0  4231M+ 0B   N/A  
2017 Nov 19 Vas 13:26:51 CET ::> 496  perl5.18 0.0  4152M+ 0B   N/A  
2017 Nov 19 Vas 13:26:57 CET ::> 496  perl5.18 0.0  4079M+ 0B   N/A  
2017 Nov 19 Vas 13:27:03 CET ::> 496  perl5.18 0.0  3934M+ 0B   N/A  
2017 Nov 19 Vas 13:27:09 CET ::> 496  perl5.18 0.0  3839M+ 0B   N/A  
2017 Nov 19 Vas 13:27:15 CET ::> 496  perl5.18 0.0  3741M+ 0B   N/A  
2017 Nov 19 Vas 13:27:21 CET ::> 496  perl5.18 0.0  3654M+ 0B   N/A  
2017 Nov 19 Vas 13:27:27 CET ::> 496  perl5.18 0.0  3566M+ 0B   N/A  
2017 Nov 19 Vas 13:27:33 CET ::> 496  perl5.18 0.0  3473M+ 0B   N/A  
2017 Nov 19 Vas 13:27:39 CET ::> 496  perl5.18 0.0  3377M+ 0B   N/A  
2017 Nov 19 Vas 13:27:45 CET ::> 496  perl5.18 0.0  3286M+ 0B   N/A  
2017 Nov 19 Vas 13:27:51 CET ::> 496  perl5.18 0.0  3189M+ 0B   N/A  
2017 Nov 19 Vas 13:27:58 CET ::> 496  perl5.18 0.0  3141M+ 0B   N/A  
2017 Nov 19 Vas 13:28:04 CET ::> 496  perl5.18 0.0  2987M+ 0B   N/A  
2017 Nov 19 Vas 13:28:10 CET ::> 496  perl5.18 0.0  2881M+ 0B   N/A  
2017 Nov 19 Vas 13:28:16 CET ::> 496  perl5.18 0.0  2796M+ 0B   N/A  
2017 Nov 19 Vas 13:28:22 CET ::> 496  perl5.18 0.0  2707M+ 0B   N/A  
2017 Nov 19 Vas 13:28:28 CET ::> 496  perl5.18 0.0  2615M+ 0B   N/A  
2017 Nov 19 Vas 13:28:34 CET ::> 496  perl5.18 0.0  2597M+ 0B   N/A  
2017 Nov 19 Vas 13:28:40 CET ::> 496  perl5.18 0.0  2499M+ 0B   N/A  
2017 Nov 19 Vas 13:28:46 CET ::> 496  perl5.18 0.0  2395M+ 0B   N/A  
2017 Nov 19 Vas 13:28:53 CET ::> 496  perl5.18 0.0  2310M+ 0B   N/A  
2017 Nov 19 Vas 13:28:59 CET ::> 496  perl5.18 0.0  2208M+ 0B   N/A  
2017 Nov 19 Vas 13:29:05 CET ::> 496  perl5.18 0.0  2052M+ 0B   N/A  
2017 Nov 19 Vas 13:29:11 CET ::> 496  perl5.18 0.0  1943M+ 0B   N/A  
2017 Nov 19 Vas 13:29:17 CET ::> 496  perl5.18 0.0  1832M+ 0B   N/A  
2017 Nov 19 Vas 13:29:23 CET ::> 496  perl5.18 0.0  1761M+ 0B   N/A  
2017 Nov 19 Vas 13:29:29 CET ::> 496  perl5.18 0.0  1669M+ 0B   N/A  
2017 Nov 19 Vas 13:29:35 CET ::> 496  perl5.18 0.0  1563M+ 0B   N/A  
2017 Nov 19 Vas 13:29:41 CET ::> 496  perl5.18 0.0  1452M+ 0B   N/A  
2017 Nov 19 Vas 13:29:47 CET ::> 496  perl5.18 0.0  1340M+ 0B   N/A  
2017 Nov 19 Vas 13:29:54 CET ::> 496  perl5.18 0.0  1275M+ 0B   N/A  
2017 Nov 19 Vas 13:30:00 CET ::> 496  perl5.18 0.0  1231M+ 0B   N/A  
2017 Nov 19 Vas 13:30:06 CET ::> 496  perl5.18 0.0  1142M+ 0B   N/A  
2017 Nov 19 Vas 13:30:12 CET ::> 496  perl5.18 0.0  1082M+ 0B   N/A  
2017 Nov 19 Vas 13:30:18 CET ::> 496  perl5.18 0.0  1042M+ 0B   N/A  
2017 Nov 19 Vas 13:30:24 CET ::> 496  perl5.18 0.0  1000M+ 0B   N/A  
2017 Nov 19 Vas 13:30:30 CET ::> 496  perl5.18 0.0  958M+ 0B   N/A  
2017 Nov 19 Vas 13:30:36 CET ::> 496  perl5.18 0.0  977M+ 0B   N/A  
2017 Nov 19 Vas 13:30:42 CET ::> 496  perl5.18 0.0  941M+ 0B   N/A  
2017 Nov 19 Vas 13:30:48 CET ::> 496  perl5.18 0.0  924M+ 0B   N/A  
2017 Nov 19 Vas 13:30:55 CET ::> 496  perl5.18 0.0  956M+ 0B   N/A  
2017 Nov 19 Vas 13:31:01 CET ::> 496  perl5.18 0.0  895M+ 0B   N/A  
2017 Nov 19 Vas 13:31:07 CET ::> 496  perl5.18 0.0  911M+ 0B   N/A  
2017 Nov 19 Vas 13:31:13 CET ::> 496  perl5.18 0.0  895M+ 0B   N/A  
2017 Nov 19 Vas 13:31:19 CET ::> 496  perl5.18 0.0  876M+ 0B   N/A  
2017 Nov 19 Vas 13:31:25 CET ::> 496  perl5.18 0.0  825M+ 0B   N/A  
2017 Nov 19 Vas 13:31:31 CET ::> 496  perl5.18 0.0  812M+ 0B   N/A  
2017 Nov 19 Vas 13:31:37 CET ::> 496  perl5.18 0.0  812M+ 0B   N/A  
2017 Nov 19 Vas 13:31:43 CET ::> 496  perl5.18 0.0  987M+ 0B   N/A  
2017 Nov 19 Vas 13:31:49 CET ::> 496  perl5.18 0.0  2058M+ 0B   N/A  
2017 Nov 19 Vas 13:31:56 CET ::> 496  perl5.18 0.0  2947M+ 0B   N/A  
2017 Nov 19 Vas 13:32:02 CET ::> 496  perl5.18 0.0  3178M+ 0B   N/A  
2017 Nov 19 Vas 13:32:08 CET ::> 496  perl5.18 0.0  3301M+ 0B   N/A  
2017 Nov 19 Vas 13:32:14 CET ::> 496  perl5.18 0.0  3429M+ 0B   N/A  
2017 Nov 19 Vas 13:32:20 CET ::> 496  perl5.18 0.0  4247M+ 0B   N/A  
2017 Nov 19 Vas 13:32:26 CET ::> 496  perl5.18 0.0  4674M+ 0B   N/A  
2017 Nov 19 Vas 13:32:32 CET ::> 496  perl5.18 0.0  5362M+ 0B   N/A  
2017 Nov 19 Vas 13:32:38 CET ::> 
^C
keve@deimos:DATA$

内存使用量不断增加并不令我感到惊讶。但输出仍然显示出一些意想不到的结果。我不明白为什么内存分配会在 13:26:57 停止，为什么它从那时开始释放内存，直到它下降到 987M，而脚本实际上正在读取和处理越来越多的产品标签。还有，为什么当代码最终到达$t->purge();这一行时，内存使用率又回升了？

注意：我还测试了修改为$twig->purge() unless ($product_counter > 119334); 的行的脚本，它不会清除最后一个（第119335 个）产品，但仍会清除它之前的所有其他产品。我故意不发布该输出，因为它与我的原始输出几乎相同。

【讨论】：

当显示“解析完成”文本时，内存使用量已经增加（3780M 而不是 15M）。那是在调用最后的 Purge 之前。这表明内存使用的增加发生在最后一个产品元素的清除时/周围。我修改了 perl 脚本，首先注释掉了清除指令，然后还尝试仅跳过最后一个产品的清除。
Mirod，我也使用您的建议生成了输出，但我无法在此处发布，因为它使我的帖子太长了。
虽然我不能再用更多输出来扩展我的原始帖子，但似乎我可以编辑你的答案并在那里添加输出。
在最后一个product 元素之后是否还有更多数据？这可以解释代码的行为：使用twig_handlers，树是为元素之后的数据构建的，twig_root 不是。如果是这种情况，并且如果您可以确定您何时超过了最后一个 product，您可以使用对 finish 的调用（完成解析而不检查是否找到 product）或 finish_now（甚至更快）它只是杀死了解析器，）