Can you debug it? — Signal Handler with unexpected behavior

This is the first edition of “Can you debug it?”, where we test your mettle with weird, small pieces of code which don’t work as they are supposed to. The goal of this series is twofold: In this “age of AI” (are you all also tired of hearing that sentence?) I think it is becoming more important to debug code than to write it. These small pieces of buggy code will sharpen that skill for you. The second goal is for me to share some of my dumb mistakes: every one of these articles will be a bug I encountered myself: No fake simulated scenarios: I don’t have time to make those.

I will add an image before the solution, so you have a chance to think about it without spoilers.

The code

#include <signal.h>
#include <stdio.h>
#include <unistd.h>

void horribly_slow_handler() {
  for (int i = 0; i < 3; i++) {
    printf("Handler secs: %d\n", i);
    sleep(1);
  }
}

int main() {
  char dumb_buffer[100];
  struct sigaction act = {0};
  act.sa_handler = horribly_slow_handler;
  act.sa_flags = SA_RESTART | SA_NODEFER;
  sigaction(SIGINT, &act, NULL);
  int bytes_read = read(0, &dumb_buffer, 100);
  printf("Bytes read %d\n", bytes_read);
  perror("Status: ");
}

You can (and should) compile it with:

gcc -std=c99 -D_XOPEN_SOURCE=600 simplified_error.c

where simplified_error.c is the name of the program.

This code will not work on a Windows terminal, you will need WSL. I think it should work on a Mac, but I am not certain. On Linux you will be golden.

The code changes the behavior of SIGINT, which can be sent to a process by pressing Control + C in the terminal where it is running. Instead of stopping the process, it will count up to three.

In case you need a refresher on how signal handlers work:

Source: The Linux Programming Interface. (Go and buy that book, it is worth it)

[sigaction](https://man7.org/linux/man-pages/man2/sigaction.2.html) is the Linux function to change the default signal handler. You pass a struct to it, which contains the function to the handler, and some flags. Although I left you a link at the beginning of this paragraph, you should not need it: man sigaction will give you the same output. You can search inside the output with the / symbol.

Let’s check the meaning of those two flags:

SA_RESTART
              Provide behavior compatible with BSD signal semantics by
              making certain system calls restartable across signals.
              This flag is meaningful only when establishing a signal
              handler.  See signal(7) for a discussion of system call
              restarting.

That is kernel-dev-speak for “Kernel operations like read and write will start from the beginning again after your signal handler finishes running”. Going back to the graph: instead of continuing at the next instruction, it remains on the interrupted syscall.

The second flag is described as follows:

SA_NODEFER
              Do not add the signal to the thread's signal mask while the
              handler is executing, unless the signal is specified in
              act.sa_mask.  Consequently, a further instance of the
              signal may be delivered to the thread while it is executing
              the handler.  This flag is meaningful only when
              establishing a signal handler.

              SA_NOMASK is an obsolete, nonstandard synonym for this
              flag.

Once again, translating from kernel-dev-speak: Your signal handler will run although you are inside the same signal handler: you will just go one level deeper in the stack and run the function again.

Let’s now see how this program behaves.

Normal behavior

(I write potatoes here and press Enter)

potatoes
Bytes read 9
Status: : Success

One SIGINT behavior

^CHandler secs: 0
Handler secs: 1
Handler secs: 2
potatoes
Bytes read 9
Status: : Success

Pay attention to the Control+C at the beginning of the text: The handler gets triggered, the seconds count up, then I type the text and press Enter.

SIGINT while we are inside the handler

^CHandler secs: 0
Handler secs: 1
^CHandler secs: 0
Handler secs: 1
Handler secs: 2
Handler secs: 2
stew                             
Bytes read 5
Status: : Interrupted system call

Here lies the mystery: The handler gets triggered (first ^C), it starts counting up, then we trigger the handler again, it starts counting up from 0 again. When it finishes counting up to two, we leave that stack frame, going one up, and we continue where we left. That is the effect of SA_NODEFER.

What was unexpected for me is “Status: Interrupted system call”. According to SA_RESTART, we should have no error. Instead, the syscall should be restarted.

Anyway, here is where I leave you for now: Think a bit, and continue reading when you think you see the problem.

Thinking penguin — GPT’s Image Generator

The Hint

If you actually tried this and have no idea, follow this link, and go to the chapter: “Interruption of system calls and library functions by signal handlers”

The solution

First of all: The syscall is not failing: The output only makes it look like it does. read returns -1 on failure. The following modification (checking for a -1) fixes it.

printf("Bytes read %d\n", bytes_read);
if (bytes_read == -1) {
    perror("Status: ");
}

After this change, this is the output

^CHandler secs: 0
Handler secs: 1
^CHandler secs: 0
Handler secs: 1
Handler secs: 2
Handler secs: 2
rabbit
Bytes read 7

The Lesson

Do not call perror without actually checking whether there is an error.

The Mystery

What is the error? Yes, we should not call perror without checking. But also, perror is not likely to print an error about an interrupted syscall if there is none. At the same time, this program should not complain about interrupted syscalls, because the SA_RESTART flag should make it tolerate such interruptions.

In the solution section, we realized that the read syscall is not actually failing. However, the error tells us that a syscall is indeed failing. The question is then, which other syscalls do we have here, which could be failing?

To discover that, you can use the strace command. If you don’t have it by default, it should be in the repositories of your distro of choice.

There are few more eye-opening experiences in Software Engineering than your first strace call. Seeing the crazy amount of syscalls happening for even the most basic command is astounding: In my laptop, ls on an empty directory results in 112 syscalls.

Getting strace to work in our current scenario is not very straightforward. Pressing Control+C on a program running under strace will stop strace itself. Therefore, I use two terminals. One runs the program, the other I use with the kill -s SIGINT <pid>

read(0, 0x7ffe3e9e4c60, 100)            = ? ERESTARTSYS (To be restarted if SA_RESTART is set)
--- SIGINT {si_signo=SIGINT, si_code=SI_USER, si_pid=619205, si_uid=1000} ---
fstat(1, {st_mode=S_IFCHR|0600, st_rdev=makedev(0x88, 0x2), ...}) = 0
brk(NULL)                               = 0x56378d7aa000
brk(0x56378d7cb000)                     = 0x56378d7cb000
write(1, “Handler secs: 0\n”, 16Handler secs: 0
) = 16
clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=1, tv_nsec=0}, 0x7ffe3e9e3e30) = 0
write(1, “Handler secs: 1\n”, 16Handler secs: 1
) = 16
clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=1, tv_nsec=0}, {tv_sec=0, tv_nsec=217528274}) = ? 
  ERESTART_RESTARTBLOCK (Interrupted by signal)
 — — SIGINT {si_signo=SIGINT, si_code=SI_USER, si_pid=619205, si_uid=1000} — -
write(1, “Handler secs: 0\n”, 16Handler secs: 0
) = 16
clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=1, tv_nsec=0}, 0x7ffe3e9e30b0) = 0
write(1, “Handler secs: 1\n”, 16Handler secs: 1
) = 16
clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=1, tv_nsec=0}, 0x7ffe3e9e30b0) = 0
write(1, “Handler secs: 2\n”, 16Handler secs: 2
) = 16
...

Out of all of the output, I extracted the important part. We can see on the first line, the read syscall. We see that it says it will be restarted if SA_RESTART is set. The SIGINT comes afterwards.

The next three lines are also interesting, although unrelated to our problem. The fstat checks whether the file descriptor 1, standard output, can be written to. The first brk call finds the heap position and the second expands the heap. Those who have read “Malloc is not Magic” will not be surprised by this behavior.

Afterwards, we see the write calls and clock_nanosleep.And there we can see the ERESTART_RESTARTBLOCK and SIGINT. Our second SIGINT is not interrupting the original read . Instead, it interrupts clock_nanosleep . I was slightly confused: Although I had suspected that sleep was the problematic syscall, the following content of the signal(7) manpage had laid those worries to rest:

The sleep(3) function is also never restarted if interrupted by a
       handler, but gives a success return: the number of seconds
       remaining to sleep.

According to this, sleep should return successfully, even if interrupted. Seeing the output of strace told me that sleep was calling instead to clock_nanosleep. A quick man 3 sleep , which gives us the Standard Library Manual, confirmed this:

VERSIONS
       On Linux, sleep() is implemented via nanosleep(2).  See the nanosleep(2) man page for a
       discussion of the clock used.

But wait: we were seeing no nanosleep, but instead clock_nanosleep. Checking the manual of clock_nanosleep, we get the following output:

clock_nanosleep(2)
System Calls Manual

NAME
       clock_nanosleep - high-resolution sleep with specifiable clock
...

If the call is interrupted by a signal handler, clock_nanosleep() fails with the error EINTR.

Part of the mystery is solved: clock_nanosleep will actually fail. But why is clock_nanosleep appearing, when the sleep manpage tells us sleep is implemented via nanosleep?

No need to wonder or ponder. In Linux, we just wander: We wander through the source code. To get the source code of any apt package, you can run apt source <package> . In this case we run apt source libc

sleep.c:

unsigned int
__sleep (unsigned int seconds)
{
  int save_errno = errno;

  const unsigned int max
    = (unsigned int) (((unsigned long int) (~((time_t) 0))) >> 1);
  struct timespec ts = { 0, 0 };
  do
    {
      if (sizeof (ts.tv_sec) <= sizeof (seconds))
        {
          /* Since SECONDS is unsigned assigning the value to .tv_sec can
             overflow it.  In this case we have to wait in steps.  */
          ts.tv_sec += MIN (seconds, max);
          seconds -= (unsigned int) ts.tv_sec;
        }
      else
        {
          ts.tv_sec = (time_t) seconds;
          seconds = 0;
        }

      if (__nanosleep (&ts, &ts) < 0)
        /* We were interrupted.
           Return the number of (whole) seconds we have not yet slept.  */
        return seconds + ts.tv_sec;
    }
  while (seconds > 0);

  __set_errno (save_errno);

  return 0;
}

The manual page is right! sleep.c is implemented through nanosleep. What the manual page did not tell us is that nanosleep is implemented through clock_nanosleep:

nanosleep.c:

int
__nanosleep (const struct timespec *requested_time,
      struct timespec *remaining)
{
  int ret = __clock_nanosleep (CLOCK_REALTIME, 0, requested_time, remaining);
  if (ret != 0)
    {
      __set_errno (ret);
      return -1;
    }
  return 0;
}

All our questions are now solved: We were interrupting sleep, which deep in its implementation actually calls clock_nanosleep, which will generate an error when interrupted even if the flag SA_RESTART is used. clock_nanosleep is setting the error with __set_errno, which is not cleared on sleep when interrupted. That is the error we see, being picked up by perror.

A rule you should know

If you got all the way here, you are interested in signal handlers. I will let you know an extra secret: I made a second mistake on that piece of code. According to the rules for signal handlers, stdio.h functions should not be used inside them. Everything inside a signal handler must be either atomic or reentrant. stdio functions are neither. As we saw before, they operate on the heap, and if another stdio.h operation was interrupted with this signal handler, the printf in the handler could wrangle the data of the interrupted call. Even worse, it holds internal locks which could block the program or crash it during a handler’s execution.

For more info on this topic and an official list of safe functions, check man signal-safety

Some thoughts

The beauty about our profession is that more often than not, all problems are understandable. You just need to be willing to dig deep and to carry a good shovel. In this case, strace, the man pages and apt source are an excavator. I cannot recommend strace enough: You can see exactly what is happening during execution regarding the interactions of your software and the OS.

I hope you had fun while guessing the solution. I will see you the next time I have a weird problem that deserves such an article. Have a good one!

Alejandro

(Note: This post is my first paid Medium Post: the goal is to see if I can get enough money out of it to pay an artist to actually make cool images instead of using AI. We should be paying artists and not autogenerating art, which was stolen from humans only to give billions to a few big companies. If all goes well, I will replace the image used with something human-made)