gdb prints long values watching a variable set with rand()

Question

I'm using a gdb script to watch the changes of a variable using awatch:

#!/bin/bash

# Compile
gcc -Wall -pedantic -g -o demo demo.c

# Exit on compile error
if [ $? -ne 0 ]; then
    exit
fi

# Overwrite the contents of trace.gdb with a title
echo "# Watch var" > trace.gdb

# Don't stop each time there is a pagination
echo "set pagination off" >> trace.gdb

# Set a breakpoint in order to read the var address
echo "break main" >> trace.gdb

# Run the debugger
echo "run" >> trace.gdb

# Set watchpoint
echo "awatch var" >> trace.gdb

# Don't stop on each watchpoint (just show the trace)
echo "commands" >> trace.gdb
echo "continue" >> trace.gdb
echo "end" >> trace.gdb

# Start monitoring
echo "continue" >> trace.gdb

# Exit the debugger
echo "quit" >> trace.gdb

# Run the generated script
gdb -quiet -command=trace.gdb demo

The program:

/* demo.c */
#include <stdio.h>

int main(void)
{
    int var = 0;

    for (int i = 0; i < 5; i++)
    {
        var++;
    }
    printf("%d\n", var);
    return 0;
}

The ouptut seems correct:

Hardware access (read/write) watchpoint 2: var

Value = 0
main () at demo.c:7
7       for (int i = 0; i < 5; i++)

Hardware access (read/write) watchpoint 2: var

Old value = 0
New value = 1
main () at demo.c:7
7       for (int i = 0; i < 5; i++)

Hardware access (read/write) watchpoint 2: var

Old value = 1
New value = 2
main () at demo.c:7
7       for (int i = 0; i < 5; i++)

Hardware access (read/write) watchpoint 2: var

Old value = 2
New value = 3
main () at demo.c:7
7       for (int i = 0; i < 5; i++)

Hardware access (read/write) watchpoint 2: var

Old value = 3
New value = 4
main () at demo.c:7
7       for (int i = 0; i < 5; i++)

Hardware access (read/write) watchpoint 2: var

Old value = 4
New value = 5
main () at demo.c:7
7       for (int i = 0; i < 5; i++)

Hardware access (read/write) watchpoint 2: var

Value = 5
0x0000555555555176 in main () at demo.c:11
11      printf("%d\n", var);
5

But if I switch to this code using rand():

#include <stdio.h>
#include <stdlib.h>
#include <time.h>

int main(void)
{
    int var = 0;

    srand((unsigned)time(NULL));
    for (int i = 0; i < 10; i++)
    {
        var = rand() % 10;
    }
    printf("%d\n", var);
    return 0;
}

and run the same script, gdb starts printing wrong values:

Breakpoint 1, main () at demo.c:6
6   {
Hardware access (read/write) watchpoint 2: var

Hardware access (read/write) watchpoint 2: var

Value = 0
main () at demo.c:9
9       srand((unsigned)time(NULL));

Hardware access (read/write) watchpoint 2: var

Old value = 0
New value = 32015002
0x00005555555551f8 in main () at demo.c:12
12          var = rand() % 10;

Hardware access (read/write) watchpoint 2: var

Value = 32015002
0x00005555555551fb in main () at demo.c:12
12          var = rand() % 10;

Hardware access (read/write) watchpoint 2: var

Old value = 32015002
New value = 7
main () at demo.c:10
10      for (int i = 0; i < 5; i++)

Hardware access (read/write) watchpoint 2: var

Old value = 7
New value = 84992124
0x00005555555551f8 in main () at demo.c:12
12          var = rand() % 10;

Hardware access (read/write) watchpoint 2: var

Value = 84992124
0x00005555555551fb in main () at demo.c:12
12          var = rand() % 10;

Hardware access (read/write) watchpoint 2: var

Old value = 84992124
New value = 6
main () at demo.c:10
10      for (int i = 0; i < 5; i++)

Hardware access (read/write) watchpoint 2: var

Old value = 6
New value = 55442740
0x00005555555551f8 in main () at demo.c:12
12          var = rand() % 10;

Hardware access (read/write) watchpoint 2: var

Value = 55442740
0x00005555555551fb in main () at demo.c:12
12          var = rand() % 10;

Hardware access (read/write) watchpoint 2: var

Old value = 55442740
New value = 0
main () at demo.c:10
10      for (int i = 0; i < 5; i++)

Hardware access (read/write) watchpoint 2: var

Old value = 0
New value = 208731384
0x00005555555551f8 in main () at demo.c:12
12          var = rand() % 10;

Hardware access (read/write) watchpoint 2: var

Value = 208731384
0x00005555555551fb in main () at demo.c:12
12          var = rand() % 10;

Hardware access (read/write) watchpoint 2: var

Old value = 208731384
New value = 3
main () at demo.c:10
10      for (int i = 0; i < 5; i++)

Hardware access (read/write) watchpoint 2: var

Old value = 3
New value = 114916873
0x00005555555551f8 in main () at demo.c:12
12          var = rand() % 10;

Hardware access (read/write) watchpoint 2: var

Value = 114916873
0x00005555555551fb in main () at demo.c:12
12          var = rand() % 10;

Hardware access (read/write) watchpoint 2: var

Old value = 114916873
New value = 9
main () at demo.c:10
10      for (int i = 0; i < 5; i++)

Hardware access (read/write) watchpoint 2: var

Value = 9
0x0000555555555216 in main () at demo.c:14
14      printf("%d\n", var);
9

I have read this post: gdb prints wrong values when modifying arguments and compiled with -fvar-tracking but it doesn't help.

Why this behaviour with rand()?

`Why this behaviour with rand()?` Inspect the assembly code. Could be that compiler optimized the `% 10` operation after the loop. @edit No, the values make sense. First variable is assgned to result of `rand()` `Value = 208731384` then `% 10` is calculated `Old value = 208731384 New value = 3`. Compiler effectively does `var = rand(); var %= 10`. — KamilCuk, Dec 01 '20 at 12:37
... or a variety of other optimization-related effects. Chances are good that if you compile with `-O0` then the unexpected behavior will disappear. All manner of seeming weirdness shows up when you debug optimized code. — John Bollinger, Dec 01 '20 at 12:39
@KamilCuk this makes a lot of sense, using `int r = rand() % 10; var = r;` the ouput is correct, this is the assembly code: https://ideone.com/qYOAEe , but I'm not good reading assembly :( thanks a lot for your help! — David Ranieri, Dec 01 '20 at 12:42
@KamilCuk, I think I can confirm your point: including `` and declaring `var` as `atomic_int var = 0;` using `var = rand() % 10;` the output is also correct, feel free to post your comment as an answer and I will accept it. — David Ranieri, Dec 01 '20 at 12:51

score 1 · Accepted Answer · answered Dec 01 '20 at 13:01

Unoptimized gcc assembly can be strange:

        jmp     .L2
.L3:
        call    rand
        movl    %eax, %edx
        movslq  %edx, %rax
        imulq   $1717986919, %rax, %rax
        shrq    $32, %rax
        sarl    $2, %eax
        movl    %edx, %ecx
        sarl    $31, %ecx
        subl    %ecx, %eax
        movl    %eax, -4(%rbp)
        movl    -4(%rbp), %ecx
        movl    %ecx, %eax
        sall    $2, %eax
        addl    %ecx, %eax
        addl    %eax, %eax
        subl    %eax, %edx
        movl    %edx, -4(%rbp)
        addl    $1, -8(%rbp)
.L2:
        cmpl    $9, -8(%rbp)
        jle     .L3

And it seems you are warching -4(%rbp). So there is movl %eax, -4(%rbp) where a "big number" is put there, then a read in movl -4(%rbp), %ecx and then movl %edx, -4(%rbp) where the result of % 10 is put there. So you are seeing some number from middle of calculations. Ie. one loop corresponds to:

New value = 32015002
0x00005555555551f8 in main () at demo.c:12
12          var = rand() % 10;

Hardware access (read/write) watchpoint 2: var

Value = 32015002
0x00005555555551fb in main () at demo.c:12
12          var = rand() % 10;

Hardware access (read/write) watchpoint 2: var

Old value = 32015002
New value = 7
main () at demo.c:10
10      for (int i = 0; i < 5; i++)

Hardware access (read/write) watchpoint 2: var

gdb prints long values watching a variable set with rand()

1 Answers1