Python慢​​读性能问题

在更早的线程之后，我把问题归结为它的基本原理，在从Perl脚本迁移到Python脚本的过程中，发现了一个巨大的性能问题。 在Ubuntu服务器上运行这个。

注意：这不是一个X对Y线程，我需要从根本上知道，如果这是如何，或者如果我做一些愚蠢的事情。

我创build了我的testing数据，50,000个10kb的文件（这反映了我正在处理的平均文件大小）：

mkdir 1 cd 1 for i in {1..50000}; do dd if=/dev/zero of=$i.xml bs=1 count=10000; done cd .. cp -r 1 2 

创build我的2脚本尽可能简单：

Perl的

 foreach my $file (<$ARGV[0]/*.xml>){ my $fh; open($fh, "< $file"); my $contents = do { local $/; <$fh> }; close($fh); } 

python

 import glob, sys for file in glob.iglob(sys.argv[1] + '/*.xml'): with open(file) as x: f = x.read() 

然后清理caching并运行我的两个slurp脚本，在每次运行之间，我再次使用以下命令清理caching：

 sync; sudo sh -c 'echo 3 > /proc/sys/vm/drop_caches' 

然后进行监视，以确保每次从磁盘读取所有内容：

 sudo iotop -a -u me 

我在一台配有RAID 10磁盘的物理机器上，以及一台全新的虚拟机上设置了虚拟机在RAID 1固态硬盘上的configuration，刚刚包含了来自虚拟机的testing运行，因为物理服务器快得多。

 $ time python readFiles.py 1 real 5m2.493s user 0m1.783s sys 0m5.013s $ time perl readFiles.pl 2 real 0m13.059s user 0m1.690s sys 0m2.471s $ time perl readFiles.pl 2 real 0m13.313s user 0m1.670s sys 0m2.579s $ time python readFiles.py 1 real 4m43.378s user 0m1.772s sys 0m4.731s 

当运行Perl时，我注意到iotop的磁盘读数大约是45 M / s，IOWAIT大约是70％，运行Python DISK READ时是2M / s，IOWAIT是97％。 我不知道该从哪儿走，把他们煮得尽可能简单。

在相关的情况下

 $ python Python 2.7.6 (default, Mar 22 2014, 22:59:56) [GCC 4.8.2] on linux2 $ perl -v This is perl 5, version 18, subversion 2 (v5.18.2) built for x86_64-linux-gnu-thread-multi 

根据要求提供其他信息

我运行strace并抓取文件1000.xml的信息，但似乎都做同样的事情：

Perl的

 $strace -f -T -o trace.perl.1 perl readFiles.pl 2 32303 open("2/1000.xml", O_RDONLY) = 3 <0.000020> 32303 ioctl(3, SNDCTL_TMR_TIMEBASE or SNDRV_TIMER_IOCTL_NEXT_DEVICE or TCGETS, 0x7fff7f6f7b90) = -1 ENOTTY (Inappropriate ioctl for device) <0.000016> 32303 lseek(3, 0, SEEK_CUR) = 0 <0.000016> 32303 fstat(3, {st_mode=S_IFREG|0664, st_size=10000, ...}) = 0 <0.000016> 32303 fcntl(3, F_SETFD, FD_CLOEXEC) = 0 <0.000017> 32303 fstat(3, {st_mode=S_IFREG|0664, st_size=10000, ...}) = 0 <0.000030> 32303 read(3, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 8192) = 8192 <0.005323> 32303 read(3, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 8192) = 1808 <0.000022> 32303 read(3, "", 8192) = 0 <0.000019> 32303 close(3) = 0 <0.000017> 

python

 $strace -f -T -o trace.python.1 python readFiles.py 1 32313 open("1/1000.xml", O_RDONLY) = 3 <0.000021> 32313 fstat(3, {st_mode=S_IFREG|0664, st_size=10000, ...}) = 0 <0.000017> 32313 fstat(3, {st_mode=S_IFREG|0664, st_size=10000, ...}) = 0 <0.000019> 32313 lseek(3, 0, SEEK_CUR) = 0 <0.000018> 32313 fstat(3, {st_mode=S_IFREG|0664, st_size=10000, ...}) = 0 <0.000018> 32313 mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fa18820a000 <0.000019> 32313 lseek(3, 0, SEEK_CUR) = 0 <0.000018> 32313 read(3, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 8192) = 8192 <0.006795> 32313 read(3, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 4096) = 1808 <0.000031> 32313 read(3, "", 4096) = 0 <0.000018> 32313 close(3) = 0 <0.000027> 32313 munmap(0x7fa18820a000, 4096) = 0 <0.000022> 

我注意到的一个区别是，不知道它是否相关，是Perl在它开始打开它们之前似乎对所有文件运行这个，而python不：

 32303 lstat("2/1000.xml", {st_mode=S_IFREG|0664, st_size=10000, ...}) = 0 <0.000022> 

也运行strace -c（刚刚接过几个电话）：

Perl的

 $ time strace -f -c perl readFiles.pl 2 % time seconds usecs/call calls errors syscall ------ ----------- ----------- --------- --------- ---------------- 44.07 3.501471 23 150018 read 12.54 0.996490 10 100011 fstat 9.47 0.752552 15 50000 lstat 7.99 0.634904 13 50016 open 6.89 0.547016 11 50017 close 6.19 0.491944 10 50008 50005 ioctl 6.12 0.486208 10 50014 3 lseek 6.10 0.484374 10 50001 fcntl real 0m37.829s user 0m6.373s sys 0m25.042s 

python

 $ time strace -f -c python readFiles.py 1 % time seconds usecs/call calls errors syscall ------ ----------- ----------- --------- --------- ---------------- 42.97 4.186173 28 150104 read 15.58 1.518304 10 150103 fstat 10.51 1.023681 20 50242 174 open 10.12 0.986350 10 100003 lseek 7.69 0.749387 15 50047 munmap 6.85 0.667576 13 50071 close 5.90 0.574888 11 50073 mmap real 5m5.237s user 0m7.278s sys 0m30.736s 

用-T开启了一些strace输出的parsing，并计算了每个文件的第一个8192字节读数，很明显这就是时间的推移，下面是50000次读取文件所花费的总时间，平均每次读取的时间。

 300.247128000002 (0.00600446220302379) - Python 11.6845620000003 (0.000233681892724297) - Perl 

不知道这是否有帮助！

更新2在Python中更新的代码，以使用os.open和os.read，只是做了第一个4096字节的单个读取（这将工作对我来说，因为我想要的信息是在文件的顶部），也消除了所有其他的电话strace的：

 18346 open("1/1000.xml", O_RDONLY) = 3 <0.000026> 18346 read(3, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 4096) = 4096 <0.007206> 18346 close(3) = 0 <0.000024> $ time strace -f -c python readFiles.py 1 % time seconds usecs/call calls errors syscall ------ ----------- ----------- --------- --------- ---------------- 55.39 2.388932 48 50104 read 22.86 0.986096 20 50242 174 open 20.72 0.893579 18 50071 close real 4m48.751s user 0m3.078s sys 0m12.360s Total Time (avg read call) 282.28626 (0.00564290374812595) 

仍然没有更好的…接下来，我要在Azure上创build一个虚拟机，并尝试另一个例子！

更新3 – 道歉这个大小！

在3个设置中使用（@JFSebastian）脚本获得一些有趣的结果，为了简洁，在开始时剥离了输出，并且还删除了从caching运行得超快的所有testing，如下所示：

 0.23user 0.26system 0:00.50elapsed 99%CPU (0avgtext+0avgdata 9140maxresident)k 0inputs+0outputs (0major+2479minor)pagefaults 0swaps 

Azure A2标准虚拟机（2核3.5GB RAM磁盘未知但速度慢）

 $ uname -a Linux servername 3.13.0-35-generic #62-Ubuntu SMP Fri Aug 15 01:58:42 UTC 2014 x86_64 x86_64 x86_64 GNU/Linux $ python Python 2.7.6 (default, Mar 22 2014, 22:59:56) [GCC 4.8.2] on linux2 $ perl -v This is perl 5, version 18, subversion 2 (v5.18.2) built for x86_64-linux-gnu-thread-multi (with 41 registered patches, see perl -V for more detail) + /usr/bin/time perl slurp.pl 1 1.81user 2.95system 3:11.28elapsed 2%CPU (0avgtext+0avgdata 9144maxresident)k 1233840inputs+0outputs (20major+2461minor)pagefaults 0swaps + clearcache + sync + sudo sh -c 'echo 3 > /proc/sys/vm/drop_caches' + /usr/bin/time python slurp.py 1 1.56user 3.76system 3:06.05elapsed 2%CPU (0avgtext+0avgdata 8024maxresident)k 1232232inputs+0outputs (14major+52273minor)pagefaults 0swaps + /usr/bin/time perl slurp.pl 2 1.90user 3.11system 6:02.17elapsed 1%CPU (0avgtext+0avgdata 9144maxresident)k 1233776inputs+0outputs (16major+2465minor)pagefaults 0swaps 

可比较的第一次slurp结果，不知道在第二次Perl浆果发生了什么？

我的VMWare Linux VM（2核8GB RAM磁盘RAID1 SSD）

 $ uname -a Linux servername 3.13.0-32-generic #57-Ubuntu SMP Tue Jul 15 03:51:08 UTC 2014 x86_64 x86_64 x86_64 GNU/Linux $ python Python 2.7.6 (default, Mar 22 2014, 22:59:56) [GCC 4.8.2] on linux2 $ perl -v This is perl 5, version 18, subversion 2 (v5.18.2) built for x86_64-linux-gnu-thread-multi (with 41 registered patches, see perl -V for more detail) + /usr/bin/time perl slurp.pl 1 1.66user 2.55system 0:13.28elapsed 31%CPU (0avgtext+0avgdata 9136maxresident)k 1233152inputs+0outputs (20major+2460minor)pagefaults 0swaps + clearcache + sync + sudo sh -c 'echo 3 > /proc/sys/vm/drop_caches' + /usr/bin/time python slurp.py 1 2.10user 4.67system 4:45.65elapsed 2%CPU (0avgtext+0avgdata 8012maxresident)k 1232056inputs+0outputs (14major+52269minor)pagefaults 0swaps + /usr/bin/time perl slurp.pl 2 2.13user 4.11system 5:01.40elapsed 2%CPU (0avgtext+0avgdata 9140maxresident)k 1233264inputs+0outputs (16major+2463minor)pagefaults 0swaps 

这一次，和以前一样，Perl在第一个stream水线上运行得更快，但是不确定第二个Perlstream水线上发生了什么，虽然之前没有看到这种行为。 然后再度量measure.sh，结果是一样的给予或花费几秒钟。 然后，我做了任何普通人都会做的事情，并更新内核以匹配Azure机器3.13.0-35-generic，并再次运行measure.sh，对结果没有影响。

出于好奇，我换了1和2参数在measure.sh和一些奇怪的事情发生..Perl减慢，Python加快！

 + /usr/bin/time perl slurp.pl 2 1.78user 3.46system 4:43.90elapsed 1%CPU (0avgtext+0avgdata 9140maxresident)k 1234952inputs+0outputs (21major+2458minor)pagefaults 0swaps + clearcache + sync + sudo sh -c 'echo 3 > /proc/sys/vm/drop_caches' + /usr/bin/time python slurp.py 2 1.19user 3.09system 0:10.67elapsed 40%CPU (0avgtext+0avgdata 8012maxresident)k 1233632inputs+0outputs (14major+52269minor)pagefaults 0swaps + /usr/bin/time perl slurp.pl 1 1.36user 2.32system 0:13.40elapsed 27%CPU (0avgtext+0avgdata 9136maxresident)k 1232032inputs+0outputs (17major+2465minor)pagefaults 0swaps 

这更使我更困惑:-(

物理服务器（32核心132 GB RAM磁盘RAID10 SAS）

 $ uname -a Linux servername 3.5.0-23-generic #35~precise1-Ubuntu SMP Fri Jan 25 17:13:26 UTC 2013 x86_64 x86_64 x86_64 GNU/Linux $ python Python 2.7.3 (default, Aug 1 2012, 05:14:39) [GCC 4.6.3] on linux2 $ perl -v This is perl 5, version 14, subversion 2 (v5.14.2) built for x86_64-linux-gnu-thread-multi (with 55 registered patches, see perl -V for more detail) + /usr/bin/time perl slurp.pl 1 2.22user 2.60system 0:15.78elapsed 30%CPU (0avgtext+0avgdata 43728maxresident)k 1233264inputs+0outputs (15major+2984minor)pagefaults 0swaps + clearcache + sync + sudo sh -c 'echo 3 > /proc/sys/vm/drop_caches' + /usr/bin/time python slurp.py 1 2.51user 4.79system 1:58.53elapsed 6%CPU (0avgtext+0avgdata 34256maxresident)k 1234752inputs+0outputs (16major+52385minor)pagefaults 0swaps + /usr/bin/time perl slurp.pl 2 2.17user 2.95system 0:06.96elapsed 73%CPU (0avgtext+0avgdata 43744maxresident)k 1232008inputs+0outputs (14major+2987minor)pagefaults 0swaps 

这里Perl似乎每次都赢。

困惑

鉴于我的本地虚拟机的怪异，当我交换目录，这是我最控制的机器我将尝试所有可能的选项运行python与perl使用1或2作为数据目录的二进制方法和尝试多次运行它们的一致性，但它会需要一段时间，我会有点疯狂，所以可能需要先rest！ 我只想要一致性:-(

更新4 – 一致性

（下面是在ubuntu-14.04.1-server VM上运行，Kernel是3.13.0-35-generic＃62-Ubuntu）

我想我已经find了一些一致性，在数据目录上运行Python / Perl slurp的所有可能的testing方法1/2我发现以下内容：

• Python创build的文件总是很慢（即由dd创build）
• Python总是快速复制文件（即由cp -r创build）
• Perl在创build的文件上总是很快（即由dd创build）
• Perl复制文件总是很慢（即由cp -r创build）

所以我看着操作系统级别的复制，看起来像Ubuntu上'cp'的行为方式与Python相同，即原始文件速度慢，复制文件速度快。

这就是我运行的结果，我在有单个SATA HD和RAID10系统的机器上做了几次，结果如下：

 $ mkdir 1 $ cd 1 $ for i in {1..50000}; do dd if=/dev/urandom of=$i.xml bs=1K count=10; done $ cd .. $ cp -r 1 2 $ sync; sudo sh -c 'echo 3 > /proc/sys/vm/drop_caches' $ time strace -f -c -o trace.copy2c cp -r 2 2copy real 0m28.624s user 0m1.429s sys 0m27.558s $ sync; sudo sh -c 'echo 3 > /proc/sys/vm/drop_caches' $ time strace -f -c -o trace.copy1c cp -r 1 1copy real 5m21.166s user 0m1.348s sys 0m30.717s 

跟踪结果显示在哪里花费时间

 $ head trace.copy1c trace.copy2c ==> trace.copy1c <== % time seconds usecs/call calls errors syscall ------ ----------- ----------- --------- --------- ---------------- 60.09 2.541250 25 100008 read 12.22 0.516799 10 50000 write 9.62 0.406904 4 100009 open 5.59 0.236274 2 100013 close 4.80 0.203114 4 50004 1 lstat 4.71 0.199211 2 100009 fstat 2.19 0.092662 2 50000 fadvise64 0.72 0.030418 608 50 getdents ==> trace.copy2c <== % time seconds usecs/call calls errors syscall ------ ----------- ----------- --------- --------- ---------------- 47.86 0.802376 8 100008 read 13.55 0.227108 5 50000 write 13.02 0.218312 2 100009 open 7.36 0.123364 1 100013 close 6.83 0.114589 1 100009 fstat 6.31 0.105742 2 50004 1 lstat 3.38 0.056634 1 50000 fadvise64 1.62 0.027191 544 50 getdents 

所以看起来复制副本比复制原始文件要快得多，我目前的猜测是，当复制文件在磁盘上alignment的时候比在最初创build时更好，使得它们更有效率的读取？

有趣的是，'rsyn'和'cp'似乎在速度上以相反的方式工作，很像Perl和Python！

 $ rm -rf 1copy 2copy; sync; sudo sh -c 'echo 3 > /proc/sys/vm/drop_caches'; echo "Rsync 1"; /usr/bin/time rsync -a 1 1copy; sync; sudo sh -c 'echo 3 > /proc/sys/vm/drop_caches'; echo "Rsync 2"; /usr/bin/time rsync -a 2 2copy Rsync 1 3.62user 3.76system 0:13.00elapsed 56%CPU (0avgtext+0avgdata 5072maxresident)k 1230600inputs+1200000outputs (13major+2684minor)pagefaults 0swaps Rsync 2 4.87user 6.52system 5:06.24elapsed 3%CPU (0avgtext+0avgdata 5076maxresident)k 1231832inputs+1200000outputs (13major+2689minor)pagefaults 0swaps $ rm -rf 1copy 2copy; sync; sudo sh -c 'echo 3 > /proc/sys/vm/drop_caches'; echo "Copy 1"; /usr/bin/time cp -r 1 1copy; sync; sudo sh -c 'echo 3 > /proc/sys/vm/drop_caches'; echo "Copy 2"; /usr/bin/time cp -r 2 2copy Copy 1 0.48user 6.42system 5:05.30elapsed 2%CPU (0avgtext+0avgdata 1212maxresident)k 1229432inputs+1200000outputs (6major+415minor)pagefaults 0swaps Copy 2 0.33user 4.17system 0:11.13elapsed 40%CPU (0avgtext+0avgdata 1212maxresident)k 1230416inputs+1200000outputs (6major+414minor)pagefaults 0swaps 

Answer 1

我只关注你的一个例子，因为其余的东西应该是类比的：

我认为，在这种情况下可能很重要的是“预先读取”（或者与此相关的另一种技术）function：

考虑这样的例子：

我已经创build了1000个XML文件在“1”目录（名称1.xml到1000.xml），就像你用dd命令做的那样，然后我复制了原始目录1到目录2

 $ mkdir 1 $ cd 1 $ for i in {1..1000}; do dd if=/dev/urandom of=$i.xml bs=1K count=10; done $ cd .. $ cp -r 1 2 $ sync; sudo sh -c 'echo 3 > /proc/sys/vm/drop_caches' $ time strace -f -c -o trace.copy2c cp -r 2 2copy $ sync; sudo sh -c 'echo 3 > /proc/sys/vm/drop_caches' $ time strace -f -c -o trace.copy1c cp -r 1 1copy 

在接下来的步骤中，我debugging了cp命令（通过strace）来发现数据被复制的顺序：

所以cp按以下顺序执行（仅前4个文件，因为我看到从原始目录中读取的第二个文件比从复制目录中读取第二个文件更耗时）

100.xml 150.xml 58.xml 64.xml … *在我的例子

现在，看一下这些文件使用的文件系统块（debugfs output – ext3 fs）：

原始目录：

 BLOCKS: (0-9):63038-63047 100.xml (0-9):64091-64100 150.xml (0-9):57926-57935 58.xml (0-9):60959-60968 64.xml .... Copied directory: BLOCKS: (0-9):65791-65800 100.xml (0-9):65801-65810 150.xml (0-9):65811-65820 58.xml (0-9):65821-65830 64.xml 

….

正如你所看到的，在“复制目录”中，这个块是相邻的，所以这意味着在读取第一个文件100.xml时，“预读”技术（控制器或系统设置）可以提高性能。

dd按照1.xml到1000.xml的顺序创build文件，但cp命令以另一种顺序（100.xml，150.xml，58.xml，64.xml）复制它。 所以当你执行：

 cp -r 1 1copy 

复制这个目录到另一个，你复制的文件块是不相邻的，所以阅读这些文件需要更多的时间。

当你拷贝由cp命令复制的dir时（所以文件不是由dd命令创build的），那么文件是相邻的，所以创build：

 cp -r 2 2copy 

副本的副本更快。

总结：为了testingpython / perl的性能，你应该使用相同的dir（或者cp命令复制的两个dir），而且你可以使用O_DIRECT选项来读取绕过所有内核缓冲区并直接从磁盘读取数据。

请记住，不同types的内核，系统，磁盘控制器，系统设置，fs等可能会有不同的结果。

加法：

  [debugfs] [root@dhcppc3 test]# debugfs /dev/sda1 debugfs 1.39 (29-May-2006) debugfs: cd test debugfs: stat test.xml Inode: 24102 Type: regular Mode: 0644 Flags: 0x0 Generation: 3385884179 User: 0 Group: 0 Size: 4 File ACL: 0 Directory ACL: 0 Links: 1 Blockcount: 2 Fragment: Address: 0 Number: 0 Size: 0 ctime: 0x543274bf -- Mon Oct 6 06:53:51 2014 atime: 0x543274be -- Mon Oct 6 06:53:50 2014 mtime: 0x543274bf -- Mon Oct 6 06:53:51 2014 BLOCKS: (0):29935 TOTAL: 1 debugfs: