[Buildbot-devel] `make clean' is too slow on buildbot

Sat Apr 24 00:08:11 UTC 2010

On Fri, Apr 23, 2010 at 03:45:59PM -0700, Dustin J. Mitchell wrote:
> On Fri, Apr 23, 2010 at 2:04 PM, Weongyo Jeong <weongyo.jeong at gmail.com> wrote:
> > It looks make(1) command consumes 100% CPU with calling brk(2) system
> > calls and it takes about 250MB ~ 300MB memory! ??Normally `gmake' worked
> > without consuming so many memory but on buildbot it consumes so many
> > memory and spends most of time to call brk(2). ??After calling brk(2) it
> > seems the process becomes a normal as it did.
> >
> > It looks there are some issues combining GNU make and buildbot. ??Any
> > ideas why it comes out on buildbot specially?
> 
> Earlier you said that this happens with any command, not just make.
> 
> Try it with /bin/true to see what happens.

I think my report wasn't correct slightly that it looks the slowness is
happen on `make' command specially because elapsedTime value for strace
is enough short.

It'd better for me to look into Makefile first.  I can't understand
still why it's caused but it looks it needs more tests

The results are as follows:

- log -----------------------------------------------------------------

2010-04-23 16:33:34-0700 [Broker,client] ShellCommand._startCommand
2010-04-23 16:33:34-0700 [Broker,client]  strace /bin/true
2010-04-23 16:33:34-0700 [Broker,client]   in dir /home/buildbot/slave/project/build (timeout 1200 secs)
2010-04-23 16:33:34-0700 [Broker,client]   watching logfiles {}
2010-04-23 16:33:34-0700 [Broker,client]   argv: ['strace', '/bin/true']
2010-04-23 16:33:34-0700 [Broker,client]  environment: {'LC_CTYPE': 'en_US.UTF-8', 'LESSOPEN': '|/usr/bin/lesspipe.sh %s', 'SSH_CLIENT': 'xx.xx.x55.161 54074 22', 'CVS_RSH': 'ssh', 'LOGNAME': 'deploy', 'USER': 'deploy', 'INPUTRC': '/etc/inputrc', 'HOME': '/root', 'PATH': '/usr/kerberos/sbin:/usr/kerberos/bin:/usr/local/bin:/bin:/usr/bin:/home/deploy/bin:/usr/local/bin', 'LANG': 'en_US.UTF-8', 'TERM': 'xterm', 'SHELL': '/bin/bash', 'SHLVL': '3', 'G_BROKEN_FILENAMES': '1', 'HISTSIZE': '1000', '_': '/usr/bin/buildbot', 'PROJECT_PREFIX': '/home/buildbot/apps', 'SSH_CONNECTION': 'xx.xx.x55.161 54074 xx.xx.x51.20 22', 'SSH_TTY': '/dev/pts/13', 'HOSTNAME': 'eng', 'PWD': '/home/buildbot/slave/project/build', 'MAIL': '/var/spool/mail/deploy', 'LS_COLORS': 'no=00:fi=00:di=00;34:ln=00;36:pi=40;33:so=00;35:bd=40;33;01:cd=40;33;01:or=01;05;37;41:mi=01;05;37;41:ex=00;32:*.cmd=00;32:*.exe=00;32:*.com=00;32:*.btm=00;32:*.bat=00;32:*.sh=00;32:*.csh=00;32:*.tar=00;31:*.tgz=00;31:*.arj=00;31:*.taz=00;31:*.lzh=00;31:*.zip=00;31:*.z=00;31:*.Z=00;31:*.gz=00;31:*.bz2=00;31:*.bz=00;31:*.tz=00;31:*.rpm=00;31:*.cpio=00;31:*.jpg=00;35:*.gif=00;35:*.bmp=00;35:*.xbm=00;35:*.xpm=00;35:*.png=00;35:*.tif=00;35:'}
2010-04-23 16:33:34-0700 [Broker,client]   closing stdin
2010-04-23 16:33:34-0700 [Broker,client]   using PTY: False
2010-04-23 16:33:34-0700 [-] command finished with signal None, exit code 0, elapsedTime: 0.013934
2010-04-23 16:33:34-0700 [-] SlaveBuilder.commandComplete <buildbot.slave.commands.SlaveShellCommand instance at 0x2ada5213aa28>

- strace -------------------------------------------------------------

strace /bin/true
 in dir /home/buildbot/slave/project/build (timeout 1200 secs)
 watching logfiles {}
 argv: ['strace', '/bin/true']
 environment:
  CVS_RSH=ssh
  G_BROKEN_FILENAMES=1
  HISTSIZE=1000
  HOME=/root
  HOSTNAME=eng
  PROJECT_PREFIX=/home/buildbot/apps
  INPUTRC=/etc/inputrc
  LANG=en_US.UTF-8
  LC_CTYPE=en_US.UTF-8
  LESSOPEN=|/usr/bin/lesspipe.sh %s
  LOGNAME=deploy
  LS_COLORS=no=00:fi=00:di=00;34:ln=00;36:pi=40;33:so=00;35:bd=40;33;01:cd=40;33;01:or=01;05;37;41:mi=01;05;37;41:ex=00;32:*.cmd=00;32:*.exe=00;32:*.com=00;32:*.btm=00;32:*.bat=00;32:*.sh=00;32:*.csh=00;32:*.tar=00;31:*.tgz=00;31:*.arj=00;31:*.taz=00;31:*.lzh=00;31:*.zip=00;31:*.z=00;31:*.Z=00;31:*.gz=00;31:*.bz2=00;31:*.bz=00;31:*.tz=00;31:*.rpm=00;31:*.cpio=00;31:*.jpg=00;35:*.gif=00;35:*.bmp=00;35:*.xbm=00;35:*.xpm=00;35:*.png=00;35:*.tif=00;35:
  MAIL=/var/spool/mail/deploy
  PATH=/usr/kerberos/sbin:/usr/kerberos/bin:/usr/local/bin:/bin:/usr/bin:/home/deploy/bin:/usr/local/bin
  PWD=/home/buildbot/slave/project/build
  SHELL=/bin/bash
  SHLVL=3
  SSH_CLIENT=xx.xx.x55.161 54074 22
  SSH_CONNECTION=xx.xx.x55.161 54074 xx.xx.x51.20 22
  SSH_TTY=/dev/pts/13
  TERM=xterm
  USER=deploy
  _=/usr/bin/buildbot
 closing stdin
 using PTY: False
execve("/bin/true", ["/bin/true"], [/* 23 vars */]) = 0
brk(0)                                  = 0x39f1000
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0)
= 0x2ad89373b000
uname({sys="Linux", node="eng", ...}) = 0
access("/etc/ld.so.preload", R_OK)      = -1 ENOENT (No such file or
directory)
open("/etc/ld.so.cache", O_RDONLY)      = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=38277, ...}) = 0
mmap(NULL, 38277, PROT_READ, MAP_PRIVATE, 3, 0) = 0x2ad89373c000
close(3)                                = 0
open("/lib64/libc.so.6", O_RDONLY)      = 3
read(3,
"\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0p\332!\2111\0\0\0"...,
832) = 832
fstat(3, {st_mode=S_IFREG|0755, st_size=1713160, ...}) = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0)
= 0x2ad893746000
mmap(0x3189200000, 3494168, PROT_READ|PROT_EXEC,
MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x3189200000
mprotect(0x318934c000, 2097152, PROT_NONE) = 0
mmap(0x318954c000, 20480, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x14c000) = 0x318954c000
mmap(0x3189551000, 16664, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x3189551000
close(3)                                = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0)
= 0x2ad893747000
arch_prctl(ARCH_SET_FS, 0x2ad893747250) = 0
mprotect(0x318954c000, 16384, PROT_READ) = 0
mprotect(0x318901b000, 4096, PROT_READ) = 0
munmap(0x2ad89373c000, 38277)           = 0
brk(0)                                  = 0x39f1000
brk(0x3a12000)                          = 0x3a12000
open("/usr/lib/locale/locale-archive", O_RDONLY) = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=56462720, ...}) = 0
mmap(NULL, 56462720, PROT_READ, MAP_PRIVATE, 3, 0) = 0x2ad893748000
close(3)                                = 0
close(1)                                = 0
exit_group(0)                           = ?
program finished with exit code 0
elapsedTime=0.013934

regards,
Weongyo Jeong