Converting Unix timestamps

Sometimes, we need to convert Unix timestamps (seconds since January 1st, 1970) to human-readable dates. For example, we might transform 1539561600 to 2018-10-15 00:00 UTC.

There are multiple online services that do this, I like unixtimestamp.com.

Every now and then we need to batch-convert timestamps. The date command shipped on Linux distributions does this nicely:

date "+%c" --date=@1539561600

I recently ran into a similar problem when logfiles contained Unix timestamps instead of human-readable dates. Using date seemed a bit clumsy here. Fortunately, Superuser.com had a nice solution involving Vim. The following sequence converts the timestamp under the cursor and records a macro q to facilitate future conversions:

qq                             " start recording
"mciw                          " put time in register m and replace it…
<C-r>=strftime("%c", @m)<CR>   " …with localized datetime
<Esc>                          " exit insert mode
q                              " stop recording

Quick and convenient — and easily incorporated into a macro to convert timestamps across the entire file.

Debugging riddle of the day

One of our services failed to start on a test system (Ubuntu 12.04 on amd64). The stdout/stderr log streams contained only the string “Permission denied” – less than helpful. strace showed that the service tried to create a file under /run, which it doesn't have write permissions to. This caused the it to bail out:

open("/run/some_service", O_RDWR|O_CREAT|O_NOFOLLOW|O_CLOEXEC, 0644) = -1
    EACCES (Permission denied)

Grepping the source code and configuration files for /run didn't turn up anything that could explain this open() call. Debugging with gdb gave further hints:

Breakpoint 2, 0x00007ffff73e3ea0 in open64 () from /lib/x86_64-linux-gnu/libc.so.6
(gdb) bt
#0  0x00007ffff73e3ea0 in open64 () from /lib/x86_64-linux-gnu/libc.so.6
#1  0x00007ffff7bd69bf in shm_open () from /lib/x86_64-linux-gnu/librt.so.1
#2  0x0000000000400948 in daemonize () at service.cpp:93
#3  0x00000000004009ac in main () at main.cpp:24
(gdb) p (char*)$rdi
$1 = 0x7fffffffe550 "/run/some_service"
(gdb) frame 2
#2  0x0000000000400948 in daemonize () at service.cpp:93
9           int fd = shm_open(fname.c_str(), O_RDWR | O_CREAT, 0644);
(gdb) p fname
$2 = {...., _M_p = 0x602028 "/some_service"}}

The open("/run/some_service", ...) was caused by an shm_open("/some_service", ...).

This code is working on other machines, why does it fail on this particular one? Can you figure it out? Bonus points if you can explain why it is trying to access /run and not some other directory. You might find the shm_open() man page and source code helpful.

I'll be waiting for you.

The solution is pretty evident after examining the Linux version of shm_open(). By default, it tries to create shared memory files under /dev/shm. If that doesn't exist, it will pick the first tmpfs mount point from /proc/mounts.

In Ubuntu 12.04, /dev/shm is a symlink to /run/shm. On this machine the symlink was missing, which caused shm_open() to go hunting for a tmpfs filesystem, and /run happened to be the first one in /proc/mounts.

Re-creating the symlink solved the problem. Why it was missing in the first place is still unclear. In the aftermath, we're also improving the error messages in this part of the code to make such issues easier to diagnose.

dh_virtualenv and long package names (FileNotFound error)

Interesting tidbit about Linux:

A maximum line length of 127 characters is allowed for the first line in a #! executable shell script.

Should be enough, right? Wrong.

Well, not if you are using dh_virtualenv with long package names, anyway:

Installing pip...
  Error [Errno 2] No such file or directory while executing command /tmp/lo...me/bin/easy_install /usr/share/python-virtualenv/pip-1.1.tar.gz
...Installing pip...done.
Traceback (most recent call last):
  File "/usr/bin/virtualenv", line 3, in <module>
virtualenv.main()
  File "/usr/lib/python2.7/dist-packages/virtualenv.py", line 938, in main
never_download=options.never_download)
  File "/usr/lib/python2.7/dist-packages/virtualenv.py", line 1054, in create_environment
install_pip(py_executable, search_dirs=search_dirs, never_download=never_download)
  File "/usr/lib/python2.7/dist-packages/virtualenv.py", line 643, in install_pip
filter_stdout=_filter_setup)
  File "/usr/lib/python2.7/dist-packages/virtualenv.py", line 976, in call_subprocess
cwd=cwd, env=env)
  File "/usr/lib/python2.7/subprocess.py", line 679, in __init__
errread, errwrite)
  File "/usr/lib/python2.7/subprocess.py", line 1249, in _execute_child
raise child_exception
OSError: [Errno 2] No such file or directory
Traceback (most recent call last):
  File "/usr/bin/dh_virtualenv", line 106, in <module>
sys.exit(main() or 0)
  File "/usr/bin/dh_virtualenv", line 83, in main
deploy.create_virtualenv()
  File "/usr/lib/python2.7/dist-packages/dh_virtualenv/deployment.py", line 112, in create_virtualenv
subprocess.check_call(virtualenv)
  File "/usr/lib/python2.7/subprocess.py", line 511, in check_call
raise CalledProcessError(retcode, cmd)
subprocess.CalledProcessError: Command '['virtualenv', '--system-site-packages', '--setuptools', 'debian/long-package-name/usr/share/python/long-package-name']' returned non-zero exit status 1
make: *** [binary-arch] Error 1
dpkg-buildpackage: error: fakeroot debian/rules binary gave error exit status 2

dh_virtualenv is used to create Debian packages that include Python virtualenvs. It is one of the better ways of packaging Python software, especially if there are Python dependencies that are not available in Debian or Ubuntu. When building a .deb package, it creates a virtualenv in a location such as:

/<build-directory>/debian/<packagename>/usr/share/python/<packagename>

This virtualenv has several tools under its bin/ directory, and they all have the absolute path of the virtualenv's Python interpreter hard-coded in their #! shebang line:

#!/<build-directory>/debian/<packagename>/usr/share/python/<packagename>/bin/python

Given that <build-directory> often contains the package name as well, it's easy to overflow the 128 byte limit of the #! shebang line. In my case, with a ~30 character package name, the path length grew to 160 characters!

Consequently, the kernel couldn't find the Python executable anymore, and running any of the tools from the bin/ directory gave an ENOENT (file not found) error. This is what happened when virtualenv tried to install pip during the initial setup. The root cause of this error is not immediately obvious, to say the least.

To check whether this affects you, check the line length of any script with wc:

head -n 1 /path/to/virtualenv/bin/easy_install | wc -c

If that's larger than 128, it's probably the cause of the problem.

The fix is to change the package name and/or the build location to something shorter. The alternative would be to patch the Linux kernel, which – depending on your preferences – sounds either fun or really unpleasant. Suit yourself!

Behold the power of perf-tools

perf-tools is a collection of scripts for system-wide tracing on Linux. It's really, really cool. It's what the perf command should have included from day one, but didn't.

It is packaged in Debian and Ubuntu, but those versions miss some key features. As perf-tools consists of shell scripts (no compilation necessary), I recommend using the GitHub version directly:

git clone https://github.com/brendangregg/perf-tools.git

Two tools that are included are execsnoop and opensnoop, which trace new program executions and open() calls across the whole system.

$ sudo ./execsnoop
TIME        PID   PPID ARGS
21:12:56  22898  15674 ls --color=auto -la
21:12:56  22899  15674 git rev-parse --is-inside-work-tree
21:12:56  22900  15674 git rev-parse --git-dir
...

$ sudo ./opensnoop
Tracing open()s. Ctrl-C to end.
COMM             PID      FD FILE
opensnoop        22924   0x3 /etc/ld.so.cache
gawk             22924   0x3 /usr/lib/locale/locale-archive
top              15555   0x8 /proc/1/stat
...

Maybe the most interesting tool is uprobe. It's magic: it traces function calls in arbitrary user-space programs. With debugging symbols available, it can trace practically every function in a program. Without them, it can trace exported functions or arbitrary code locations (specified by raw address). It can also trace library code, e.g. libc). Having these possibilities on a production system without any prior setup is staggering.

$ sudo user/uprobe -F -l /tmp/a.out | grep quicksort
_Z9quicksortN9__gnu_cxx17__normal_iteratorIPiSt6vectorIiSaIiEEEES5_
$ sudo user/uprobe -F p:/tmp/a.out:_Z9quicksortN9__gnu_cxx17__normal_iteratorIPiSt6vectorIiSaIiEEEES5_
Tracing uprobe _Z9quicksort[snip] (p:_Z9quicksort[snip] /tmp/a.out:0x8ba). Ctrl-C to end.
   a.out-23171 [000] d... 1860355.891238: _Z9quicksort[snip]: (0x80488ba)
   a.out-23171 [000] d... 1860355.891353: _Z9quicksort[snip]: (0x80488ba)
   ...

(To demangle the C++ function names, use the c++filt tool.)

perf-tools really shows the power of the Linux perf/ftrace infrastructure, and make it usable for the broad masses. There are several other tools that analyze latency and cache hit rates, trace kernel functions, and much more. To finally have such functionality in Linux is fabulous!

published February 10, 2016
tags linux

Running strace for multiple processes

Just a quick note about strace, the ancient Linux system-call tracing tool.

It can trace multiple processes at once: simply start it with multiple -p arguments (the numbers give the processes' PIDs):

sudo strace -p 2916 -p 2929 -p 2930 -p 2931 -p 2932 -o /tmp/strace.log

This is great for tracing daemons which use separate worker processes, for example Apache with mpm-prefork.

published February 09, 2016
tags linux