需要帮助调试慢 scons 运行时 [英] Need help debugging slow scons runtime

问题描述

我正在使用 scons 构建两个项目.一个效果很好，而另一个(更复杂的)项目非常令人沮丧.这是我在为第二个项目运行 scons 时看到的:

I am working on two projects using scons to build. One works great, while the other (more complicated) project is very frustrating. Here is what I see when running scons for the second project:

S time scons
scons: Reading SConscript files ...
<<< Generates some code, output seen in console >>>
scons: done reading SConscript files.
scons: Building targets ...
<<< 30+ second delay, with no output >>>
<<< Building occurs, with output, only 2-3 seconds >>>
scons: done building targets.
<<< 15-20 second delay, no output to console >>>

real  0m54.600s
user  0m2.612s
sys   0m9.236s
$

所以它似乎足够快地读取 SConscript 文件，但是当它完成时，有一个巨大的 30+ 秒延迟，它似乎什么都不做.如果我在这里按 Ctrl-C，延迟仍然存在；它不会处理 Ctrl-C 并在延迟结束之前终止运行.同样，在完成所有工作后，还有一个神秘的延迟；此延迟也是不可中断的.

So it seems to read the SConscript files quickly enough, but when it is done, there is a huge 30+ second delay where it seems to be doing nothing at all. If I hit Ctrl-C here, the delay is still there; it won't process the Ctrl-C and terminate the run until the delay elapses. Similarly, there is another mystery delay after it is done with everything; this delay also is not interruptable.

我不知道发生了什么，但是等待 54 秒而应该是大约 4 秒的时间令人沮丧！我一直无法找到一种方法让 scons 告诉我在这些延迟期间它在做什么.有谁知道如何获得有关它在做什么的更多信息?

I do not know what is going on, but it is frustrating to wait 54 seconds for what should be about 4 seconds! I haven't been able to find a way to have scons tell me what it is doing during those delays. Does anyone know how to get more information on what it is doing?

更新:我使用 profile= 选项运行 scons 以获取分析信息，然后打印出一个排序列表；以下是前几项:

Update: I ran scons with the profile= option to get profiling information, then printed out a sorted list; here are the first several items:

2016 年 3 月 13 日星期日 17:46:04 scons.profile.data

Sun Mar 13 17:46:04 2016 scons.profile.data

     1253379 function calls (1208007 primitive calls) in 61.303 seconds

排序方式:内部时间、函数名

Ordered by: internal time, function name

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
       41   32.778    0.799   32.783    0.800 {cPickle.loads}
        1   17.691   17.691   17.691   17.691 {cPickle.dump}
      456    5.337    0.012    5.337    0.012 {method 'read' of 'file' objects}
       24    2.844    0.118    2.844    0.118 {posix.waitpid}
        5    0.245    0.049    0.245    0.049 {built-in method poll}
   . . .
      230    0.016    0.000    0.029    0.000 {cPickle.dumps}

剩余的 1000+ 个条目都小于 0.1 秒 tottime.请注意，前两个条目与两个神秘延迟相匹配！(为了完整起见，我还展示了另一个 cPickle 调用，尽管它非常小.)什么可能导致 cPickle 使用这么多时间?

The remaining 1000+ entries are all less than 0.1 seconds tottime. Note that the first two entries match the two mystery delays! (For completeness, I also show the one other cPickle call, even though it is very small.) What could be causing cPickle to use so much time?

更新 2:我今天再次运行，并得到以下时间:

Update 2: I ran it again today, and got the following timing:

real  1m42.446s
user  0m4.104s
sys   0m11.648s

请注意，这只是编译两个小的 .c 文件！然后，我将 .sconsign.dblite 重命名并再次运行它；当然，它重建了一切，但已经快得多了:

Note that this was just compiling two small .c files! Then, I renamed the .sconsign.dblite and ran it again; of course, it rebuilt everything, but was already much faster:

real  0m34.229s
user  0m28.392s
sys   0m2.932s

好多了！所以现在，我用同样需要编译的两个文件再次运行它，我得到了这个:

Much better! So now, I ran it again with the same two files needing compilation, and I get this:

real  0m3.494s
user  0m2.556s
sys   0m0.460s

现在，那很好！我决定看看.sconsign.dblite和旧版本，发现如下:

Now, that is good! I decided to look at the .sconsign.dblite and the old version, and found the following:

$ ls -la .scons*
-rw-rw-r-- 1 rsg rsg     189513 Mar 14 20:31 .sconsign.dblite
-rw-rw-r-- 1 rsg rsg 1440507770 Mar 14 20:23 .sconsign.dblite.save

相差 7600 倍！！！所以现在，这个问题似乎已经解决了，尽管很高兴知道 .sconsign.dblite 发生了什么，以及如何防止它再次发生.

A factor of 7600 difference!!! So for now, it seems this is resolved, though it would be nice to know what happened to the .sconsign.dblite, and how to prevent it from happening again.

环境:

$ scons --version
SCons by Steven Knight et al.:
    script: v2.1.0.r5357[MODIFIED], 2011/09/09 21:31:03, by bdeegan on ubuntu
    engine: v2.1.0.r5357[MODIFIED], 2011/09/09 21:31:03, by bdeegan on ubuntu
    engine path: ['/usr/lib/scons/SCons']
Copyright (c) 2001, 2002, 2003, 2004, 2005, 2006, 2007, 2008, 2009, 2010, 2011 The SCons Foundation
$ lsb_release -a
No LSB modules are available.
Distributor ID: Ubuntu
Description:    Ubuntu 12.04.5 LTS
Release:        12.04
Codename:       precise
$ python --version
Python 2.7.3

此外，Ubuntu 在虚拟机中运行，在 VirtualBox v5.0.16 下，在一台体面的 Windows 7 机器上运行.

Also, Ubuntu is running in a VM, under VirtualBox v5.0.16 on a decent Windows 7 machine.

推荐答案

由于 unpickling 花费了大量时间，因此 .sconsign 文件可能已损坏或由于某种原因导致数据过多，这可能是明智的重命名它，看看是否能解决您的问题.

Due to the huge amount of time spent unpickling, it's possible the .sconsign file is either corrupted or for some reason exploded with too much data, it may be wise to rename it and see if that resolves your issue.

mv .sconsign.dblite .sconsign.dblist.save

如果是，您可以使用

sconsign .sconsign.dblite.save

这种情况偶尔(实际上很少发生)发生，我们还没有能够为开发人员重现它并修复它.

This occasionally (pretty rarely actually) happens and we've not yet been able to reproduce it for developers and fix it.

这篇关于需要帮助调试慢 scons 运行时的文章就介绍到这了，希望我们推荐的答案对大家有所帮助，也希望大家多多支持IT屋！