What is a system call?
$ cat a.html b.html c.html | wc
cat: c.html: No such file or directory
111 250 5787
┌───┐ ┌──┐
TTY → 0│cat│1 → 0│wc│1→ TTY
└───┘ └──┘
2 2
↓ ↓
TTY TTY
$ cat a.html b.html c.html 2>err | wc >out
$ cat err
cat: c.html: No such file or directory
$ cat out
111 250 5787
┌───┐ ┌──┐
TTY → 0│cat│1 → 0│wc│1→ “./out”
└───┘ └──┘
2 2
↓ ↓
“./err” TTY
$ ... | strace python script.py 2>trace.txt | ...
$ ... | strace -o trace.txt python script.py | ...
/bin/true
$ grep root /etc/passwd
root:x:0:0:root:/root:/bin/bash
$ echo $?
0
$ grep hamlet /etc/passwd
$ echo $?
1
$ if grep -q root /etc/passwd; \
then echo found; else echo nope; fi
found
$ if grep -q hamlet /etc/passwd; \
then echo found; else echo nope; fi
nope
# Copyright (c) 1984 AT&T
# All Rights Reserved
# THIS IS UNPUBLISHED PROPRIETARY SOURCE CODE OF AT&T
# The copyright notice above does not evidence any
# actual or intended publication of such source code.
#ident "@(#)cmd/true.sh 50.1"
# Copyright (c) 1984 AT&T
# All Rights Reserved
# THIS IS UNPUBLISHED PROPRIETARY SOURCE CODE OF AT&T
# The copyright notice above does not evidence any
# actual or intended publication of such source code.
#ident "@(#)cmd/true.sh 50.1"
# Copyright (c) 1984 AT&T
# All Rights Reserved
# THIS IS UNPUBLISHED PROPRIETARY SOURCE CODE OF AT&T
# The copyright notice above does not evidence any
# actual or intended publication of such source code.
#ident "@(#)cmd/true.sh 50.1"
$ file /bin/true
/bin/true: ELF 32-bit LSB executable...
$ strace -o trace.txt /bin/true
execve("/bin/true", ["true"], [/* 71 vars */]) = 0
brk(0) = 0x8385000
access("/etc/ld.so.nohwcap", F_OK) = -1 ENOENT (No such file or directory)
mmap2(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb777d000
access("/etc/ld.so.preload", R_OK) = -1 ENOENT (No such file or directory)
open("/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3
fstat64(3, {st_mode=S_IFREG|0644, st_size=95435, ...}) = 0
mmap2(NULL, 95435, PROT_READ, MAP_PRIVATE, 3, 0) = 0xb7765000
close(3) = 0
access("/etc/ld.so.nohwcap", F_OK) = -1 ENOENT (No such file or directory)
open("/lib/i386-linux-gnu/libc.so.6", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\1\1\1\0\0\0\0\0"..., 512) = 512
fstat64(3, {st_mode=S_IFREG|0755, st_size=1758972, ...}) = 0
mmap2(NULL, 1763964, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0xb75b6000
mmap2(0xb775f000, 12288, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x1a9000) = 0xb775f000
mmap2(0xb7762000, 10876, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xb7762000
close(3) = 0
mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb75b5000
set_thread_area({entry_number:-1 -> 6, base_addr:0xb75b5940,
limit:1048575, seg_32bit:1, contents:0, read_exec_only:0,
limit_in_pages:1, seg_not_present:0, useable:1}) = 0
mprotect(0xb775f000, 8192, PROT_READ) = 0
mprotect(0x804d000, 4096, PROT_READ) = 0
mprotect(0xb77a0000, 4096, PROT_READ) = 0
munmap(0xb7765000, 95435) = 0
exit_group(0) = ?
+++ exited with 0 +++
execve("/bin/true", ["true"], [/* 71 vars */]) = 0
brk(0) = 0x8385000
access("/etc/ld.so.nohwcap", F_OK)
= -1 ENOENT (No such file or directory)
mmap2(NULL, 8192, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb777d000
access("/etc/ld.so.preload", R_OK)
= -1 ENOENT (No such file or directory)
open("/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3
fstat64(3, {..., st_size=95435, ...}) = 0
mmap2(NULL, 95435, PROT_READ, MAP_PRIVATE, 3, 0)
= 0xb7765000
close(3) = 0
open("/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3
access("/etc/ld.so.nohwcap", F_OK) = -1 ENOENT
open("/lib/i386-linux-gnu/libc.so.6",
O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\1\1\1\0\0\0\0\0"..., 512) = 512
fstat64(3, {..., st_size=1758972, ...}) = 0
mmap2(NULL, 1763964, PROT_READ|PROT_EXEC,
MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0xb75b6000
mmap2(0xb775f000, 12288, PROT_READ|PROT_WRITE,
MAP_PRIVATE|..., 3, 0x1a9000) = 0xb775f000
mmap2(0xb7762000, 10876, PROT_READ|PROT_WRITE,
MAP_PRIVATE|..., -1, 0) = 0xb7762000
close(3) = 0
mmap2(NULL, 4096, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_ANONYMOUS, -1,
0) = 0xb75b5000
set_thread_area({entry_number:-1 -> 6,
base_addr:0xb75b5940, limit:1048575,
seg_32bit:1, contents:0, read_exec_only:0,
limit_in_pages:1, seg_not_present:0,
useable:1}) = 0
mprotect(0xb775f000, 8192, PROT_READ) = 0
mprotect(0x804d000, 4096, PROT_READ) = 0
mprotect(0xb77a0000, 4096, PROT_READ) = 0
munmap(0xb7765000, 95435) = 0
exit_group(0) = ?
+++ exited with 0 +++
execve("/bin/true", ["true"], [/* 71 vars */]) = 0
brk(0) = 0x8385000
access("/etc/ld.so.nohwcap", F_OK) = -1 ENOENT (No such file or directory)
mmap2(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb777d000
access("/etc/ld.so.preload", R_OK) = -1 ENOENT (No such file or directory)
open("/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3
fstat64(3, {st_mode=S_IFREG|0644, st_size=95435, ...}) = 0
mmap2(NULL, 95435, PROT_READ, MAP_PRIVATE, 3, 0) = 0xb7765000
close(3) = 0
access("/etc/ld.so.nohwcap", F_OK) = -1 ENOENT (No such file or directory)
open("/lib/i386-linux-gnu/libc.so.6", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\1\1\1\0\0\0\0\0"..., 512) = 512
fstat64(3, {st_mode=S_IFREG|0755, st_size=1758972, ...}) = 0
mmap2(NULL, 1763964, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0xb75b6000
mmap2(0xb775f000, 12288, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x1a9000) = 0xb775f000
mmap2(0xb7762000, 10876, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xb7762000
close(3) = 0
mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb75b5000
set_thread_area({entry_number:-1 -> 6, base_addr:0xb75b5940,
limit:1048575, seg_32bit:1, contents:0, read_exec_only:0,
limit_in_pages:1, seg_not_present:0, useable:1}) = 0
mprotect(0xb775f000, 8192, PROT_READ) = 0
mprotect(0x804d000, 4096, PROT_READ) = 0
mprotect(0xb77a0000, 4096, PROT_READ) = 0
munmap(0xb7765000, 95435) = 0
exit_group(0) = ?
+++ exited with 0 +++
— strace(2)
$ strace -o trace.txt python3.4 -c ''
↓
507 lines
execve("/usr/bin/python3.4",
["python3.4", "-c", ""], [/* 71 vars */])
brk(0)
access("/etc/ld.so.nohwcap", F_OK)
mmap2(NULL, 8192, …)
access("/etc/ld.so.preload", R_OK)
open("/etc/ld.so.cache", …) = 3
fstat64(3, {…, st_size=95435, …})
mmap2(NULL, 95435, …)
close(3)
⋮
7 times:
⋮
access("/etc/ld.so.nohwcap", F_OK)
open("/lib/i386-linux-gnu/libpthread.so.0", …)
read(3, "\177ELF\1\1\1\0"…, 512)
fstat64(3, {…, st_size=130518, …})
mmap2(NULL, 111276, …)
mmap2(0xb776e000, 8192, …)
mmap2(0xb7770000, 4780, …)
close(3)
⋮
$ which python3.4
/usr/bin/python3.4
$ ldd /usr/bin/python3.4
linux-gate.so.1 => ...
libpthread.so.0 => ...
libc.so.6 => ...
libdl.so.2 => ...
libutil.so.1 => ...
libexpat.so.1 => ...
libz.so.1 => ...
libm.so.6 => ...
/lib/ld-linux.so.2 (0xb77da000)
After further memory-map shenanigans:
open("/dev/urandom",
O_RDONLY|O_LARGEFILE|O_CLOEXEC) = 3
fcntl64(3, F_GETFD) = 0x1 (flags FD_CLOEXEC)
read(3, "…", 24) = 24
close(3)
Then the Python runtime gets serious:
stat64("/home/brandon/bin/python3.4", …) = -1
stat64("/home/brandon/usr/bin/python3.4", …) = -1
stat64("/usr/local/sbin/python3.4", …) = -1
stat64("/usr/local/bin/python3.4", …) = -1
stat64("/usr/sbin/python3.4", …) = -1
stat64("/usr/bin/python3.4",
{…, st_size=3802224, …}) = 0
readlink("/usr/bin/python3.4", …, 4096) = -1
the result is stored as sys.executable
Python checks for a few config files
open("/usr/bin/pyvenv.cfg", …) = -1 ENOENT
open("/usr/pyvenv.cfg", …) = -1 ENOENT
stat64("/usr/bin/Modules/Setup", …) = -1 ENOENT
stat64("/usr/bin/lib/python3.4/os.py", …) = -1
stat64("/usr/bin/lib/python3.4/os.pyc", …) = -1
stat64("/usr/lib/python3.4/os.py",
{…, st_size=33618, …}) = 0
Finally, import can start its work
stat64("/usr/lib/python3.4/encodings"
"/__init__.cpython-34m-i386-linux-gnu.so",
…) = -1
stat64(…"/__init__.cpython-34m.so", …) = -1
stat64(…"/__init__.abi3.so", …) = -1
stat64(…"/__init__.so", …) = -1
stat64(…"/__init__.py", …) = 0
stat64(…"/__init__.py", …) = 0
open(…"/__pycache__/__init__.cpython-34.pyc", …) = 3
How many filenames does Python try?
m directories × n extensions
System Python:
$ python3.4 -c 'import sys, pprint;\
pprint.pprint(sys.path)'
['',
'/usr/lib/python3.4',
'/usr/lib/python3.4/plat-i386-linux-gnu',
'/usr/lib/python3.4/lib-dynload',
'/usr/local/lib/python3.4/dist-packages',
'/usr/lib/python3/dist-packages']
Python in a virtualenv:
$ bin/python3.4 -c 'import sys,pprint;\
pprint.pprint(sys.path)'
['',
'…venv/lib/python3.4',
'…venv/lib/python3.4/plat-i386-linux-gnu',
'…venv/lib/python3.4/lib-dynload',
'/usr/lib/python3.4',
'/usr/lib/python3.4/plat-i386-linux-gnu',
'/home/brandon/p/lib/python3.4/site-packages',
'/usr/lib/python3/dist-packages',
'/usr/local/lib/python3.4/dist-packages']
After easy_install of some eggs:
$ easy_install zc.recipe.egg
⋮
$ bin/python3.4 -c 'import sys,pprint;\
pprint.pprint(sys.path)'
['',
'…venv/…/site-packages/zc.recipe.egg-2.0.1-py3.4.egg',
'…venv/…/site-packages/zc.buildout-2.2.1-py3.4.egg',
'…venv/lib/python3.4',
'…venv/lib/python3.4/plat-i386-linux-gnu',
'…venv/lib/python3.4/lib-dynload',
'/usr/lib/python3.4',
'/usr/lib/python3.4/plat-i386-linux-gnu',
'/home/brandon/v/lib/python3.4/site-packages',
'/usr/lib/python3/dist-packages',
'/usr/local/lib/python3.4/dist-packages']
$ grokenv/bin/easy_install grok
⋮
$ grokenv/bin/python2.7 -c \
'import sys; print(len(sys.path))'
183
strace -c ...
Counts system calls
strace -e open,stat64 ...
Filter system calls
$ strace -c -e open,stat64 \
/usr/bin/python2.7 -c 'import popen2'
% time seconds usecs/call calls errors syscall
------ ----------- ----------- --------- --------- -------
70.11 0.000258 1 276 206 open
29.89 0.000110 1 102 66 stat64
------ ----------- ----------- --------- --------- -------
100.00 0.000368 378 272 total
$ strace -c -e open,stat64 \
venv/bin/python2.7 -c 'import popen2'
% time seconds usecs/call calls errors syscall
------ ----------- ----------- --------- --------- -------
72.73 0.000947 3 292 237 open
27.27 0.000355 2 222 117 stat64
------ ----------- ----------- --------- --------- -------
100.00 0.001302 514 354 total
$ strace -c -e open,stat64 \
grokenv/bin/python2.7 -c 'import popen2'
% time seconds usecs/call calls errors syscall
------ ----------- ----------- --------- --------- -------
72.42 0.013402 3 4290 4232 open
27.58 0.005104 4 1417 879 stat64
------ ----------- ----------- --------- --------- -------
100.00 0.018506 5707 5111 total
$ time -p /usr/bin/python2.7 -c 'import popen2'
real 0.03
user 0.03
sys 0.00
$ time -p grokenv/bin/python2.7 -c 'import popen2'
real 0.13
user 0.05
sys 0.07
Note
import popen2
O(n²)
$ strace -c -e open,stat64 \
grokenv/bin/python2.7 -c 'import grok'
% time seconds usecs/call calls errors syscall
------ ----------- ----------- --------- --------- -------
79.56 0.163195 3 59704 58917 open
20.44 0.041926 3 13773 11972 stat64
------ ----------- ----------- --------- --------- -------
100.00 0.205121 73477 70889 total
…/site-packages/Django-1.3-py2.7.egg/django/…
…/site-packages/Django-1.5-py2.7.egg/django/…
…/site-packages/Django-1.6-py2.7.egg/django/…
…/venv/python2.7/site-packages/django/…
$ strace -c -e open,stat64 \
/usr/bin/python2.7 -c 'import email'
% time seconds usecs/call calls errors syscall
⋮
100.00 0.000000 384 275 total
$ strace -c -e open,stat64 \
/usr/bin/python3.4 -c 'import email'
% time seconds usecs/call calls errors syscall
⋮
100.00 0.000000 148 24 total
import example
import example
import example
import ssl
import os
os.mkdir("d")
⋮
mkdir("d", 0777)
⋮
import socket
s = socket.socket()
⋮
socket(PF_INET, SOCK_STREAM, IPPROTO_IP) = 3
⋮
import os
os.write(1, "hello\n")
⋮
write(1, "hello\n", 6) = 6
⋮
import os
os.listdir("/")
⋮
openat(AT_FDCWD, "/", ...) = 3
getdents64(3, /* 27 entries */, 32768) = 720
getdents64(3, /* 0 entries */, 32768) = 0
close(3) = 0
⋮
import socket
socket.getaddrinfo("google.com", "www")
open("/etc/resolv.conf", O_RDONLY|O_CLOEXEC) = 3
⋮
(20 more system calls)
⋮
open("/etc/gai.conf", O_RDONLY|O_CLOEXEC) = 3
⋮
(18 more system calls)
⋮
socket(PF_INET, SOCK_DGRAM|…, IPPROTO_IP) = 3
connect(3, {sa_family=AF_INET, sin_port=htons(53),
sin_addr=inet_addr("127.0.1.1")}, 16) = 0
⋮
(35 more system calls)
Manual section 2 vs 3
$ man mkdir
Whoops! Section 1 is shell commands:
MKDIR(1) User Commands MKDIR(1)
NAME
mkdir - make directories
SYNOPSIS
mkdir [OPTION]... DIRECTORY...
DESCRIPTION
Create the DIRECTORY(ies), if
they do not already exist.
$ man -s 2,3 mkdir
or, if you already have a guess:
$ man 2 mkdir # system call: simple
$ man 3 getaddrinfo # libc function: compound
import sys, time
print "Hello",
sys.stdout.write("world.")
time.sleep(100)
os.write()
print "a",
print "b",
print "c"
⋮
write(1, "a b c\n", 6)
⋮
import sys
print "a",
sys.stdout.flush()
print "b"
⋮
write(1, "a", 1)
write(1, " b\n", 3)
⋮
$ python -u ...
$ export PYTHONUNBUFFERED=True
or even
sys.stdout = os.fdopen(sys.stdout.fileno(), 'w', 0)
After newline, when writing to terminal:
for i in range(10000):
print 'Number',
print i
⋮
write(1, "Number 0\n", 9)
write(1, "Number 1\n", 9)
write(1, "Number 2\n", 9)
⋮
write(1, "Number 9999\n", 12)
⋮
Every block, when writing to file:
for i in range(10000):
print 'Number',
print i
⋮
write(1, "Number 0\nNumber 1\nNumber 2\n"..., 4096)
write(1, "er 382\nNumber 383\nNumber 384"..., 4096)
write(1, "54\nNumber 755\nNumber 756\nNu"..., 4096)
⋮
write(1, "mber 9991\nNumber 9992\nNumber"..., 106)
⋮
import sys
sys.stdout.isatty()
import os
os.isatty(1)
ioctl(1,
SNDCTL_TMR_TIMEBASE
or SNDRV_TIMER_IOCTL_NEXT_DEVICE
or TCGETS,
{B38400 opost isig icanon echo...}) = 0
import threading
threading.Thread().start()
⋮
clone(child_stack=0xb70f6424,
flags=CLONE_VM|CLONE_FS|CLONE_FILES
|CLONE_SIGHAND|CLONE_THREAD|CLONE_SYSVSEM
|CLONE_SETTLS|CLONE_PARENT_SETTID
|CLONE_CHILD_CLEARTID, ...) = 13496
⋮
import os
os.spawnvp(os.P_WAIT, "ls", ["ls"])
⋮
clone(child_stack=0, flags=CLONE_CHILD_CLEARTID
|CLONE_CHILD_SETTID|SIGCHLD, ...) = 13703
⋮
And then what?
import os
os.spawnvp(os.P_WAIT, "ls", ["ls"])
⋮
13742 clone(child_stack=0, flags=CLONE_CHILD_CLEARTID
|CLONE_CHILD_SETTID|SIGCHLD, ...) = 13743
⋮
13743 execve("/bin/ls", ["ls"], [/* 70 vars */]) = 0
13743 brk(0) = 0x90b4000
13743 access("/etc/ld.so.nohwcap", F_OK) = -1 ENOENT
⋮
import os
os.system("ls")
⋮
1915 clone(child_stack=0, flags=CLONE_CHILD_CLEARTID
|CLONE_CHILD_SETTID|SIGCHLD, ...) = 1916
1915 wait4(-1, <unfinished ...>
1916 execve("/bin/ls", ["ls"], [/* 79 vars */]) = 0
1916 brk(0) = 0x90b4000
1916 access("/etc/ld.so.nohwcap", F_OK) = -1 ENOENT
⋮
1916 +++ exited with 0 +++
1915 <... waitpid resumed>
[{WIFEXITED(s)… == 0}], 0, NULL) = 1916
⋮
call()
check_call()
check_output()
Popen()
⋮
write(3, "\27\3\3\0`\342\243\357\314\ndk"..., 101)
read(3, "\27\3\3\4\343", 5)
read(3, "\0\0\0\0\0\0\0\1\262/\264\254\0"..., 1251)
⋮
ssl_test.py
import urllib
urllib.urlopen('https://www.google.com/').read()
ltrace.conf
int SSL_write(void, string, uint)
$ ltrace -F ltrace.conf -s 9999 \
-l 'libssl*' -o ltrace.txt \
python2.7 -c ssl_test.py
_ssl.i386-linux-gnu.so->SSL_write(
"GET / HTTP/1.0\r\nHost: www.google.com\r\n"
"User-Agent: Python-urllib/1.17\r\n\r\n",
72) = 72
@brandon_rhodes