Date: Thu, 11 Apr 2019 16:39:26 +0200 From: Konstantin Schukraft <konstantin@schukraft.org> To: Jan Bramkamp <crest@rlwinm.de> Cc: freebsd-ports@freebsd.org Subject: Re: python 3 subprocess performance Message-ID: <20190411143926.5rg4jskmodt4shhi@laparbeit> In-Reply-To: <8f3f8413-60f2-bb03-a6b4-4f6364cdc3df@rlwinm.de> References: <20190411161649.1b740d21@vm2.home.zagrebin.ru> <8f3f8413-60f2-bb03-a6b4-4f6364cdc3df@rlwinm.de>
next in thread | previous in thread | raw e-mail | index | archive | help
--kwzmq4cyo2whxe62
Content-Type: text/plain; charset=utf-8; format=flowed
Content-Disposition: inline
>Please run python under truss -f. Does it try to close(2) all possible
>file descriptors? Does the runtime decrease if fdescfs is mounted at
>/dev/fd?
truss -f -p 17407
17407: read(5,0x1265d2e9120,50000) = 0 (0x0)
17407: close(5) = 0 (0x0)
17407: lseek(3,0x0,SEEK_CUR) ERR#29 'Illegal seek'
17407: fstat(3,{ mode=p--------- ,inode=1610971,size=0,blksize=4096 }) = 0 (0x0)
17407: read(3,"FreeBSD midgard 12.0-STABLE-HBSD"...,8192) = 88 (0x58)
17407: read(3,0x1265ceda078,8104) = 0 (0x0)
17407: close(3) = 0 (0x0)
17407: wait4(1948,{ EXITED,val=0 },0x0,0x0) = 1948 (0x79c)
17407: write(1,"63\n",3) = 3 (0x3)
17407: pipe2(0x63857dad22e8,O_CLOEXEC) = 0 (0x0)
17407: fstat(3,{ mode=p--------- ,inode=1610975,size=0,blksize=4096 }) = 0 (0x0)
17407: ioctl(3,TIOCGETA,0x63857dad21a0) ERR#25 'Inappropriate ioctl for device'
17407: lseek(3,0x0,SEEK_CUR) ERR#29 'Illegal seek'
17407: pipe2(0x63857dad21e8,O_CLOEXEC) = 0 (0x0)
17407: sigprocmask(SIG_BLOCK,{ SIGHUP|SIGINT|SIGQUIT|SIGILL|SIGTRAP|SIGABRT|SIGEMT|SIGFPE|SIGKILL|SIGBUS|SIGSEGV|SIGSYS|SIGPIPE|SIGALRM|SIGTERM|SIGURG|SIGSTOP|SIGTSTP|SIGCONT|SIGCHLD|SIGTTIN|SIGTTOU|SIGIO|SIGXCPU|SIGXFSZ|SIGVTALRM|SIGPROF|
SIGWINCH|SIGINFO|SIGUSR1|SIGUSR2 },{ }) = 0 (0x0)
97164: <new process>
17407: fork() = 97164 (0x17b8c)
97164: thr_self(0x1265c7e9000) = 0 (0x0)
17407: sigprocmask(SIG_SETMASK,{ },0x0) = 0 (0x0)
97164: sigprocmask(SIG_SETMASK,{ },0x0) = 0 (0x0)
97164: close(3) = 0 (0x0)
97164: close(5) = 0 (0x0)
17407: close(6) = 0 (0x0)
97164: dup2(4,1) = 1 (0x1)
17407: close(4) = 0 (0x0)
97164: dup2(4,2) = 2 (0x2)
97164: sigprocmask(SIG_SETMASK,{ SIGHUP|SIGINT|SIGQUIT|SIGILL|SIGTRAP|SIGABRT|SIGEMT|SIGFPE|SIGKILL|SIGBUS|SIGSEGV|SIGSYS|SIGPIPE|SIGALRM|SIGTERM|SIGURG|SIGSTOP|SIGTSTP|SIGCONT|SIGCHLD|SIGTTIN|SIGTTOU|SIGIO|SIGXCPU|SIGXFSZ|SIGVTALRM|SIGPRO
F|SIGWINCH|SIGINFO|SIGUSR1|SIGUSR2 },{ }) = 0 (0x0)
97164: sigaction(SIGPIPE,{ SIG_DFL 0x0 ss_t },{ SIG_IGN 0x0 ss_t }) = 0 (0x0)
97164: sigprocmask(SIG_SETMASK,{ },0x0) = 0 (0x0)
97164: sigprocmask(SIG_SETMASK,{ SIGHUP|SIGINT|SIGQUIT|SIGILL|SIGTRAP|SIGABRT|SIGEMT|SIGFPE|SIGKILL|SIGBUS|SIGSEGV|SIGSYS|SIGPIPE|SIGALRM|SIGTERM|SIGURG|SIGSTOP|SIGTSTP|SIGCONT|SIGCHLD|SIGTTIN|SIGTTOU|SIGIO|SIGXCPU|SIGXFSZ|SIGVTALRM|SIGPRO
F|SIGWINCH|SIGINFO|SIGUSR1|SIGUSR2 },{ }) = 0 (0x0)
97164: sigaction(SIGXFSZ,{ SIG_DFL 0x0 ss_t },{ SIG_IGN 0x0 ss_t }) = 0 (0x0)
97164: sigprocmask(SIG_SETMASK,{ },0x0) = 0 (0x0)
97164: fstatat(AT_FDCWD,"/dev",{ mode=dr-xr-xr-x ,inode=2,size=512,blksize=4096 },0x0) = 0 (0x0)
97164: fstatat(AT_FDCWD,"/dev/fd",{ mode=dr-xr-xr-x ,inode=135,size=512,blksize=4096 },0x0) = 0 (0x0)
97164: getrlimit(RLIMIT_NOFILE,{ cur=940563,max=940563 }) = 0 (0x0)
97164: close(3) ERR#9 'Bad file descriptor'
97164: close(4) = 0 (0x0)
97164: close(5) ERR#9 'Bad file descriptor'
97164: close(7) ERR#9 'Bad file descriptor'
97164: close(8) ERR#9 'Bad file descriptor'
97164: close(9) ERR#9 'Bad file descriptor'
The last error repeats several 10000 times.
Mounting fdescfs does indeed speed python3 up to python2 levels.
>On 11.04.19 15:16, Alexander Zagrebin wrote:
>> Hi!
>>
>> I've noticed the subprocess performance issue with python 3.
>> For example, this simple script takes just 0,15 second to complete
>> with python 2.7, but more than 5 sec with python 3.6:
>>
>> import subprocess
>>
>> for i in range(100):
>> p = subprocess.Popen(['uname', '-a'], stdout=subprocess.PIPE, stderr=subprocess.STDOUT)
>> (stdoutdata, stderrdata) = p.communicate()
>>
>> Profiling with the cProfile shows, that this excessive 5 seconds was
>> wasted in the "{built-in method posix.read}"
>>
>> Could anybody confirm this issue?
>>
>_______________________________________________
>freebsd-ports@freebsd.org mailing list
>https://lists.freebsd.org/mailman/listinfo/freebsd-ports
>To unsubscribe, send any mail to "freebsd-ports-unsubscribe@freebsd.org"
--kwzmq4cyo2whxe62
Content-Type: application/pgp-signature; name="signature.asc"
-----BEGIN PGP SIGNATURE-----
iHUEARYIAB0WIQT5hlD1gMfKZVmJgKBt4hVX4L8dwAUCXK9RnQAKCRBt4hVX4L8d
wLjEAP9HSu9LxFw4msWVmXaTnL4oPCY2d2Q8vr47cNcgJVSYugD+JL32jVO+NPqw
2px/iCIvt0kUdOImWUXMu7G8koaNLQE=
=rJ5k
-----END PGP SIGNATURE-----
--kwzmq4cyo2whxe62--
Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?20190411143926.5rg4jskmodt4shhi>