Create a gist now

Instantly share code, notes, and snippets.

What would you like to do?
Vim system calls when saving a file

Using dtruss on vim's :w

Ever wonder what happens when you save a file in vim? There's quite a lot more happening than open, write, and close. I found this out while working on some code to monitor changed files using the node.js fs.watch API, which abstracts (or obscures) Mac OS X's kqueue API.

To find out exactly what vim is doing when saving a file, we'll use a tool included with DTrace that reports on another process's system calls. We need the process ID of vim, which is already open and editing my file:

$ ps ax | grep vim
15800 s003  R+     0:00.00 vim short/source.html

Then we run dtruss to attach to the running process, elevating our privileges first

$ sudo dtruss -p 15800

Once attached to the running process, dtruss starts printing out system calls invoked by vim. I'm not entirely sure what these first few signify, perhaps they're caused by DTrace attaching, but after waiting a second, the output pauses.

SYSCALL(args)      = return
workq_kernreturn(0x20, 0x0, 0x1)		 = 0 0
kevent(0x5, 0x0, 0x0)		 = 1 0
thread_selfid(0x7FFF74F62278, 0x0, 0xFFFFFFFF)		 = 848013 0
kevent(0x5, 0x10FE8DDB8, 0x1)		 = 1 0
__disable_threadsignal(0x1, 0x0, 0x0)		 = 0 0
thread_selfid(0x10FE0D000, 0x83000, 0x17BB)		 = 848037 0
select(0x1, 0x7FFF50670010, 0x0, 0x7FFF5066FF90, 0x0)		 = 1 0

Wait for user input

Now we're ready to start interacting with vim. With the file already open, and the command mode active, I enter :w. You can see the first call to read fills a buffer with the single-character string ":". Vim then draws the : character to the screen using all sorts of escape sequences to set colors and things.

read(0x0, ":", 0x1000)		 = 1 0
select(0x1, 0x7FFF50670180, 0x0, 0x7FFF50670100, 0x7FFF50670208)		 = 0 0
write(0x1, "\033[?25l\033[58;1H\033[K\033[58;1H:", 0x18)		 = 24 0
ioctl(0x0, 0x80487414, 0x7FFF5066F8E8)		 = 0 0
select(0x1, 0x7FFF5066F790, 0x0, 0x7FFF5066F710, 0x7FFF5066F818)		 = 0 0
write(0x1, "\033[?12l\033[?25h", 0xC)		 = 12 0
select(0x1, 0x7FFF5066F620, 0x0, 0x7FFF5066F5A0, 0x7FFF5066F6A8)		 = 1 0

Now vim waits for more user input by calling select, which eventually signals more input is available from the keyboard. This time it's the letter "w". How exciting! Vim draws the "w" character to the screen and waits for more input.

select(0x1, 0x7FFF5066F620, 0x0, 0x7FFF5066F5A0, 0x0)		 = 1 0
read(0x0, "w", 0x1000)		 = 1 0
select(0x1, 0x7FFF5066F790, 0x0, 0x7FFF5066F710, 0x7FFF5066F818)		 = 0 0
select(0x1, 0x7FFF5066F800, 0x0, 0x7FFF5066F780, 0x7FFF5066F888)		 = 0 0
write(0x1, "w", 0x1)		 = 1 0
select(0x1, 0x7FFF5066F690, 0x0, 0x7FFF5066F610, 0x7FFF5066F718)		 = 0 0
select(0x1, 0x7FFF5066F790, 0x0, 0x7FFF5066F710, 0x7FFF5066F818)		 = 0 0
write(0x1, "\033[?25l\033[?12l\033[?25h", 0x12)		 = 18 0
select(0x1, 0x7FFF5066F620, 0x0, 0x7FFF5066F5A0, 0x7FFF5066F6A8)		 = 1 0
select(0x1, 0x7FFF5066F620, 0x0, 0x7FFF5066F5A0, 0x0)		 = 1 0

Yep, got it, ":w". Finally, vim reads the result of me pressing [return] on the keyboard.

read(0x0, "\r", 0x1000)		 = 1 0
select(0x1, 0x7FFF5066F790, 0x0, 0x7FFF5066F710, 0x7FFF5066F818)		 = 0 0
write(0x1, "\r", 0x1)		 = 1 0

Begin saving

Having received the whole command, it's parsed and the code to output the buffer contents to a file is dispatched. We can see vim getting metadata in the stat64 call, then checking write permissions with access.

stat64("/Users/kputnam/wd/resume/short/source.html", 0x7FFF5066F6C0, 0x7FFF506702E0)		 = 0 0
access("/Users/kputnam/wd/resume/short/source.html", 0x2, 0x0)		 = 0 0

Notably, the Mac OS X man page for access states,

Access() is a potential security hole and should never be used.

Next we see vim setting the current working directory to ".". Yes, "." is the symbol that means the current working directory. So this just tells the current working directory, "Be yourself, current working directory."

open(".", 0x0, 0x0)		 = 6 0
fchdir(0x6, 0x0, 0x0)		 = 0 0

Then vim traverses to the subdirectory "short", relative to the current working directory. Again we see some calls that appear redundant, like two calls to change the current working directory to "short".

chdir("short", 0x7FE96B417065, 0x0)		 = 0 0
open_nocancel(".", 0x0, 0x1)		 = 7 0
fstat64(0x7, 0x7FFF5066EBF0, 0x0)		 = 0 0
fcntl_nocancel(0x7, 0x32, 0x7FE96D803200)		 = 0 0
close_nocancel(0x7)		 = 0 0
stat64("/Users/kputnam/wd/resume/short", 0x7FFF5066EB60, 0x0)		 = 0 0
fchdir(0x6, 0x7FFF5066EB60, 0x0)		 = 0 0
close(0x6)		 = 0 0

Inform the user

Now vim prints the filename to the terminal, to indicate to the user that it's beginning to write the file contents to disk. Then another few calls to test the file status.

select(0x1, 0x7FFF5066F1B0, 0x0, 0x7FFF5066F130, 0x7FFF5066F238)		 = 0 0
write(0x1, "\033[?25l\"short/source.html\"", 0x19)		 = 25 0
stat64("short/source.html", 0x7FFF5066F970, 0x7FE96D807C00)		 = 0 0
access("short/source.html", 0x2, 0x0)		 = 0 0
lstat64("short/source.html", 0x7FFF5066F7E0, 0x98880)		 = 0 0

This next part seems highly strange. Apparently vim creates a new file called "short/4913", sets the ownership of it, closes it, and then deletes the file.

lstat64("short/4913", 0x7FFF5066F7E0, 0x4)		 = -1 Err#2
open("short/4913", 0xB01, 0x81A4)		 = 6 0
fchown(0x6, 0x14000001F5, 0x14)		 = 0 0
stat64("short/4913", 0x7FFF5066F7E0, 0x0)		 = 0 0
close(0x6)		 = 0 0
unlink("short/4913", 0x7FFF5066F7E0, 0x0)		 = 0 0

Having completed that inexplicable task, vim now checks for the presence of a backup named "source.html~", twice for good measure, and despite learning that the file doesn't exist, tells the OS to remove it.

stat64("short/source.html~", 0x7FFF5066F330, 0x98880)		 = -1 Err#2
stat64("short/source.html", 0x7FFF5066EEF0, 0x7FFFFFFF)		 = 0 0
stat64("short/source.html~", 0x7FFF5066EE60, 0x0)		 = -1 Err#2
unlink("short/source.html~", 0x1, 0xFFFFFFFFFFFFFFFF)		 = -1 Err#2

Write the contents

Now vim renames the original, unmodified file, to "source.html~", and then creates a new, empty file in its place. The contents of the editor buffer are written to this new file.

rename("short/source.html", "short/source.html~")		 = 0 0
open("short/source.html", 0x601, 0x1A4)		 = 6 0
write(0x6, "<!DOCTYPE html PUBLIC \"-//W3C//DTD XHTML 1.0 Strict//EN\"\n...", 0x2000)		 = 8192 0
write(0x6, "S)</a>.</p>\n\n        <span class=\"date_duration\">\n     ...", 0x2000)		 = 8192 0
write(0x6, "gration with <a\n            href=\"https://github.com/kputn...", 0x2000)		 = 8192 0
write(0x6, "ols</span>\n        <span class=\"hidden\">\n          <span...", 0x1A25)		 = 6693 0
fsync(0x6, 0x7FE96D805C00, 0x0)		 = 0 0
stat64("short/source.html", 0x7FFF5066F588, 0x0)		 = 0 0
stat64("short/source.html", 0x7FFF5066F328, 0x0)		 = 0 0
close(0x6)		 = 0 0

We can see from the return values of the write calls that vim writes 8192 bytes each time. Then it waits for the OS to confirm the contents were flushed to disk by calling fsync.

Inform the user

Lastly, vim indicates in the UI that the file has been written, and removes the backup file.

chmod(0x7FE96B417060, 0x81A4, 0x0)		 = 0 0
write(0x1, " 747L, 31269C written", 0x15)		 = 21 0
stat64("/Users/kputnam/wd/resume/short/source.html", 0x7FFF5066F290, 0x0)		 = 0 0
unlink("short/source.html~", 0x7FE96B44B4A0, 0x10F6F44F8)		 = 0 0

Verify HTML syntax

Once the file's been written, some plugin (probably syntastic) is invoked to check the syntax of the newly written file. But first vim asks the OS to do a bunch of seemingly useless tasks.

Stand in the place where you are:

open(".", 0x0, 0x0)		 = 6 0
fchdir(0x6, 0x0, 0x0)		 = 0 0

Now face West:

chdir("short", 0x7FE96B417065, 0x0)		 = 0 0
open_nocancel(".", 0x0, 0x1)		 = 7 0
fstat64(0x7, 0x7FFF5066EBF0, 0x0)		 = 0 0
fcntl_nocancel(0x7, 0x32, 0x7FE96C00B600)		 = 0 0
close_nocancel(0x7)		 = 0 0

Think about direction. Wonder why you haven't before.

stat64("/Users/kputnam/wd/resume/short", 0x7FFF5066EB60, 0x0)		 = 0 0
fchdir(0x6, 0x7FFF5066EB60, 0x0)		 = 0 0
close(0x6)		 = 0 0
stat64("short/source.html", 0x7FFF5066BF38, 0x10)		 = 0 0

Open it! No, close it!

open("short/source.html", 0x4, 0x0)		 = 6 0
close(0x6)		 = 0 0

Delete a non-existent file whose name is incomprehensible.

unlink("/var/folders/n2/b4nj1yhx7fbc3dcvqgt_93nr0000gn/T/vEtkV5J/7", 0x7FFF5066A29B, 0x0)		 = -1 Err#2

Invoke Tidy HTML

Next vim forks a child process to execute Tidy HTML, which will check that the changes I saved were well-formed HTML.

write(0x1, "\033[?12l\033[?25h", 0xC)		 = 12 0
ioctl(0x0, 0x80487414, 0x7FFF5066A028)		 = 0 0
fork()		 = 13834 0

Then vim compulsively waits for its child to die.

__semwait_signal(0x60F, 0x0, 0x1)		 = -1 Err#60
wait4(0x360A, 0x7FFF5066A1AC, 0x1)		 = 0 0
__semwait_signal(0x60F, 0x0, 0x1)		 = -1 Err#60
wait4(0x360A, 0x7FFF5066A1AC, 0x1)		 = 0 0
__semwait_signal(0x60F, 0x0, 0x1)		 = -1 Err#60
wait4(0x360A, 0x7FFF5066A1AC, 0x1)		 = 0 0
__semwait_signal(0x60F, 0x0, 0x1)		 = -1 Err#60
wait4(0x360A, 0x7FFF5066A1AC, 0x1)		 = 0 0
__semwait_signal(0x60F, 0x0, 0x1)		 = -1 Err#60
wait4(0x360A, 0x7FFF5066A1AC, 0x1)		 = 0 0
__semwait_signal(0x60F, 0x0, 0x1)		 = -1 Err#60
wait4(0x360A, 0x7FFF5066A1AC, 0x1)		 = 0 0
__semwait_signal(0x60F, 0x0, 0x1)		 = -1 Err#60
wait4(0x360A, 0x7FFF5066A1AC, 0x1)		 = 0 0
...

Someone now installs signal handlers for several UNIX signals, like SIGKILL, SIGHUP, etc. I'm not sure if these are calls from the child process or why the parent (vim) would reinitialize the signal handlers at this ponit. These all point to the same address, except for the last one on signal 0x2 which is SIGINT.

sigaction(0x1, 0x7FFF5066A048, 0x0)		 = 0 0
sigaction(0x3, 0x7FFF5066A048, 0x0)		 = 0 0
sigaction(0x4, 0x7FFF5066A048, 0x0)		 = 0 0
sigaction(0x5, 0x7FFF5066A048, 0x0)		 = 0 0
sigaction(0x6, 0x7FFF5066A048, 0x0)		 = 0 0
sigaction(0x7, 0x7FFF5066A048, 0x0)		 = 0 0
sigaction(0x8, 0x7FFF5066A048, 0x0)		 = 0 0
sigaction(0xA, 0x7FFF5066A048, 0x0)		 = 0 0
sigaction(0xB, 0x7FFF5066A048, 0x0)		 = 0 0
sigaction(0xC, 0x7FFF5066A048, 0x0)		 = 0 0
sigaction(0xF, 0x7FFF5066A048, 0x0)		 = 0 0
sigaction(0x1B, 0x7FFF5066A048, 0x0)		 = 0 0
sigaction(0x18, 0x7FFF5066A048, 0x0)		 = 0 0
sigaction(0x19, 0x7FFF5066A048, 0x0)		 = 0 0
sigaction(0x1E, 0x7FFF5066A048, 0x0)		 = 0 0
sigaction(0x1F, 0x7FFF5066A048, 0x0)		 = 0 0
sigprocmask(0x0, 0x0, 0x7FFF5066A08C)		 = 0x0 0
sigaction(0x2, 0x7FFF5066A018, 0x7FFF5066A040)		 = 0 0

More compulsive checking. Hurry up, are you dead yet?

wait4(0x360A, 0x7FFF5066A1AC, 0x1)		 = 0 0
__semwait_signal(0x60F, 0x0, 0x1)		 = -1 Err#60
wait4(0x360A, 0x7FFF5066A1AC, 0x1)		 = 0 0
__semwait_signal(0x60F, 0x0, 0x1)		 = -1 Err#60
wait4(0x360A, 0x7FFF5066A1AC, 0x1)		 = 0 0
__semwait_signal(0x60F, 0x0, 0x1)		 = -1 Err#60
wait4(0x360A, 0x7FFF5066A1AC, 0x1)		 = 0 0
__semwait_signal(0x60F, 0x0, 0x1)		 = -1 Err#60
...

Signal handlers still being installed, this time replacing some of the handlers we just installed, with an address 16 bytes from the previous handler.

ioctl(0x0, 0x80487414, 0x7FFF5066A028)		 = 0 0
sigprocmask(0x0, 0x0, 0x7FFF5066A07C)		 = 0x0 0
sigaction(0x1C, 0x7FFF5066A008, 0x7FFF5066A030)		 = 0 0
sigprocmask(0x0, 0x0, 0x7FFF5066A07C)		 = 0x0 0
sigaction(0x12, 0x7FFF5066A008, 0x7FFF5066A030)		 = 0 0
sigprocmask(0x0, 0x0, 0x7FFF5066A07C)		 = 0x0 0
sigaction(0x13, 0x7FFF5066A008, 0x7FFF5066A030)		 = 0 0
sigprocmask(0x0, 0x0, 0x7FFF5066A07C)		 = 0x0 0
sigaction(0xD, 0x7FFF5066A008, 0x7FFF5066A030)		 = 0 0
sigprocmask(0x0, 0x0, 0x7FFF5066A07C)		 = 0x0 0
sigaction(0x2, 0x7FFF5066A008, 0x7FFF5066A030)		 = 0 0
sigprocmask(0x0, 0x0, 0x7FFF5066A07C)		 = 0x0 0
sigaction(0xE, 0x7FFF5066A008, 0x7FFF5066A030)		 = 0 0
sigaction(0x1, 0x7FFF5066A038, 0x0)		 = 0 0
sigaction(0x3, 0x7FFF5066A038, 0x0)		 = 0 0
sigaction(0x4, 0x7FFF5066A038, 0x0)		 = 0 0
sigaction(0x5, 0x7FFF5066A038, 0x0)		 = 0 0
sigaction(0x6, 0x7FFF5066A038, 0x0)		 = 0 0
sigaction(0x7, 0x7FFF5066A038, 0x0)		 = 0 0
sigaction(0x8, 0x7FFF5066A038, 0x0)		 = 0 0
sigaction(0xA, 0x7FFF5066A038, 0x0)		 = 0 0
sigaction(0xB, 0x7FFF5066A038, 0x0)		 = 0 0
sigaction(0xC, 0x7FFF5066A038, 0x0)		 = 0 0
sigaction(0xF, 0x7FFF5066A038, 0x0)		 = 0 0
sigaction(0x1B, 0x7FFF5066A038, 0x0)		 = 0 0
sigaction(0x18, 0x7FFF5066A038, 0x0)		 = 0 0
sigaction(0x19, 0x7FFF5066A038, 0x0)		 = 0 0
sigaction(0x1E, 0x7FFF5066A038, 0x0)		 = 0 0
sigaction(0x1F, 0x7FFF5066A038, 0x0)		 = 0 0
ioctl(0x1, 0x4004667A, 0x7FFF5066A264)		 = 0 0
ioctl(0x1, 0x40087468, 0x7FFF5066A288)		 = 0 0

Conspicuously absent from these signal handlers is SIGCHLD (0x14), which is invoked by the OS when a child process terminates. Perhaps what's going on is the handlers are setup one way just after spawning the child, then wait4 returns indicating the child died, then the handlers are all restored to their original settings.

Valid HTML

Now vim reads the output of the child process, which was stored in /var/folders, a descriptively named folder.

open_nocancel("/var/folders/n2/b4nj1yhx7fbc3dcvqgt_93nr0000gn/T/vEtkV5J/7", 0x0, 0x1B6)		 = 6 0
fstat64(0x6, 0x7FFF50669FD8, 0x7FFF5066A09C)		 = 0 0
read_nocancel(0x6, "No warnings or errors were found.\n\n\nTo learn more about HTML Tidy see http://tidy.sourceforge.net\nPlease send bug reports to html-tidy@w3.org\nHTML and CSS specifications are available from http://www.w3.org/\nLobby your company to join W3C, see http://www.w", 0x1000)		 = 273 0
read_nocancel(0x6, "", 0x1000)		 = 0 0
close_nocancel(0x6)		 = 0 0
unlink("/var/folders/n2/b4nj1yhx7fbc3dcvqgt_93nr0000gn/T/vEtkV5J/7", 0x10F6F91CA, 0x10F7649F0)		 = 0 0

Refresh the screen

Next all kinds of escape codes are written to the terminal, probably to position the cursor, and write color-coded, syntax-highlighted HTML to the screen.

select(0x1, 0x7FFF50669700, 0x0, 0x7FFF50669680, 0x7FFF50669788)		 = 0 0
select(0x1, 0x7FFF50669B90, 0x0, 0x7FFF50669B10, 0x7FFF50669C18)		 = 0 0
select(0x1, 0x7FFF50669B90, 0x0, 0x7FFF50669B10, 0x7FFF50669C18)		 = 0 0
...

write(0x1, "\033[27m\033[m\033[38;5;244m\033[48;5;234m\033[H\033[2J\033[?25l...", 0x7F1)		 = 2033 0
__semwait_signal(0x60F, 0x0, 0x1)		 = -1 Err#60
wait4(0x360A, 0x7FFF5066A1AC, 0x1)		 = 0 0
write(0x1, "m</a>\r\n\033[38;5;239m\033[48;5;235m 54 \033[m\033[38;5;244m\03...", 0x151)		 = 337 0
select(0x1, 0x7FFF5066B830, 0x0, 0x7FFF5066B7B0, 0x7FFF5066B8B8)		 = 0 0
select(0x1, 0x7FFF5066E290, 0x0, 0x7FFF5066E210, 0x7FFF5066E318)		 = 0 0

Then vim tells the OS to check again that the current directory still exists, and that the directory containing our file still exists, etc, in case it changed in the intervening microseconds since we last checked. You never know.

open(".", 0x0, 0x0)		 = 6 0
fchdir(0x6, 0x0, 0x0)		 = 0 0
chdir("short", 0x7FE96CB574A5, 0x0)		 = 0 0
open_nocancel(".", 0x0, 0x1)		 = 7 0
fstat64(0x7, 0x7FFF5066C330, 0x0)		 = 0 0
fcntl_nocancel(0x7, 0x32, 0x7FE96D800000)		 = 0 0
close_nocancel(0x7)		 = 0 0
stat64("/Users/kputnam/wd/resume/short", 0x7FFF5066C2A0, 0x0)		 = 0 0
fchdir(0x6, 0x7FFF5066C2A0, 0x0)		 = 0 0
close(0x6)		 = 0 0

Maybe execute ctags

Next, vim looks in my $PATH for ctags, probably to rebuild the a ctags index (if I had ctags configured).

stat64("/Users/kputnam/wd/resume/short/source.html", 0x7FFF5066C968, 0x10FC76408)		 = 0 0
stat64("/Users/kputnam/.rvm/gems/ruby-2.0.0-p195/bin/ctags", 0x7FFF5066CE68, 0x6)		 = -1 Err#2
stat64("/Users/kputnam/.rvm/gems/ruby-2.0.0-p195@global/bin/ctags", 0x7FFF5066CE68, 0x6)		 = -1 Err#2
stat64("/Users/kputnam/.rvm/rubies/ruby-2.0.0-p195/bin/ctags", 0x7FFF5066CE68, 0x6)		 = -1 Err#2
stat64("/Users/kputnam/.rvm/bin/ctags", 0x7FFF5066CE68, 0x6)		 = -1 Err#2
stat64("/usr/local/share/npm/bin/ctags", 0x7FFF5066CE68, 0x6)		 = -1 Err#2
stat64("/usr/local/sbin/ctags", 0x7FFF5066CE68, 0x6)		 = -1 Err#2
stat64("/usr/local/bin/ctags", 0x7FFF5066CE68, 0x6)		 = -1 Err#2
stat64("/Users/kputnam/.cabal/bin/ctags", 0x7FFF5066CE68, 0x6)		 = -1 Err#2
stat64("/Users/kputnam/bin/ctags", 0x7FFF5066CE68, 0x6)		 = -1 Err#2
stat64("/usr/bin/ctags", 0x7FFF5066CE68, 0x6)		 = 0 0
access("/usr/bin/ctags", 0x1, 0x0)		 = 0 0

Conclusion

That's pretty much it. Part of the status bar is written to the screen again, and a few lines of the file are redrawn. The revelant parts which actually deal with the filesystem are:

  1. Move the original file out of the way, to source.html~.
  2. Write the buffer contents to a new file, source.html
  3. Remove the source.html~ backup file after flushing output
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment