1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
135
136
137
138
139
140
141
142
143
144
145
146
147
148
149
150
151
152
153
154
|
tags {"external:skip"} {
set system_name [string tolower [exec uname -s]]
set backtrace_supported [system_backtrace_supported]
set threads_mngr_supported 0 ;# Do we support printing stack trace from all threads, not just the one that got the signal?
if {$system_name eq {linux}} {
set threads_mngr_supported 1
}
# look for the DEBUG command in the backtrace, used when we triggered
# a stack trace print while we know redis is running that command.
proc check_log_backtrace_for_debug {log_pattern} {
# search for the final line in the stacktraces generation to make sure it was completed.
set pattern "* STACK TRACE DONE *"
set res [wait_for_log_messages 0 \"$pattern\" 0 100 100]
set res [wait_for_log_messages 0 \"$log_pattern\" 0 100 100]
if {$::verbose} { puts $res}
# If the stacktrace is printed more than once, it means redis crashed during crash report generation
assert_equal [count_log_message 0 "STACK TRACE -"] 1
upvar threads_mngr_supported threads_mngr_supported
# the following checks are only done if we support printing stack trace from all threads
if {$threads_mngr_supported} {
assert_equal [count_log_message 0 "setupStacktracePipe failed"] 0
assert_equal [count_log_message 0 "failed to open /proc/"] 0
assert_equal [count_log_message 0 "failed to find SigBlk or/and SigIgn"] 0
# the following are skipped since valgrind is slow and a timeout can happen
if {!$::valgrind} {
assert_equal [count_log_message 0 "wait_threads(): waiting threads timed out"] 0
# make sure redis prints stack trace for all threads. we know 3 threads are idle in bio.c
assert_equal [count_log_message 0 "bioProcessBackgroundJobs"] 3
}
}
set pattern "*debugCommand*"
set res [wait_for_log_messages 0 \"$pattern\" 0 100 100]
if {$::verbose} { puts $res}
}
# used when backtrace_supported == 0
proc check_crash_log {log_pattern} {
set res [wait_for_log_messages 0 \"$log_pattern\" 0 50 100]
if {$::verbose} { puts $res }
}
# test the watchdog and the stack trace report from multiple threads
if {$backtrace_supported} {
set server_path [tmpdir server.log]
start_server [list overrides [list dir $server_path]] {
test "Server is able to generate a stack trace on selected systems" {
r config set watchdog-period 200
r debug sleep 1
check_log_backtrace_for_debug "*WATCHDOG TIMER EXPIRED*"
# make sure redis is still alive
assert_equal "PONG" [r ping]
}
}
}
# Valgrind will complain that the process terminated by a signal, skip it.
if {!$::valgrind} {
if {$backtrace_supported} {
set check_cb check_log_backtrace_for_debug
} else {
set check_cb check_crash_log
}
# test being killed by a SIGABRT from outside
set server_path [tmpdir server1.log]
start_server [list overrides [list dir $server_path crash-memcheck-enabled no]] {
test "Crash report generated on SIGABRT" {
set pid [s process_id]
r deferred 1
r debug sleep 10 ;# so that we see the function in the stack trace
r flush
after 100 ;# wait for redis to get into the sleep
exec kill -SIGABRT $pid
$check_cb "*crashed by signal*"
}
}
# test DEBUG SEGFAULT
set server_path [tmpdir server2.log]
start_server [list overrides [list dir $server_path crash-memcheck-enabled no]] {
test "Crash report generated on DEBUG SEGFAULT" {
catch {r debug segfault}
$check_cb "*crashed by signal*"
}
}
# test DEBUG SIGALRM being non-fatal
set server_path [tmpdir server3.log]
start_server [list overrides [list dir $server_path]] {
test "Stacktraces generated on SIGALRM" {
set pid [s process_id]
r deferred 1
r debug sleep 10 ;# so that we see the function in the stack trace
r flush
after 100 ;# wait for redis to get into the sleep
exec kill -SIGALRM $pid
$check_cb "*Received SIGALRM*"
r read
r deferred 0
# make sure redis is still alive
assert_equal "PONG" [r ping]
}
}
}
# test DEBUG ASSERT
if {$backtrace_supported} {
set server_path [tmpdir server4.log]
# Use exit() instead of abort() upon assertion so Valgrind tests won't fail.
start_server [list overrides [list dir $server_path use-exit-on-panic yes crash-memcheck-enabled no]] {
test "Generate stacktrace on assertion" {
catch {r debug assert}
check_log_backtrace_for_debug "*ASSERTION FAILED*"
}
}
}
# Tests that when `hide-user-data-from-log` is enabled, user information from logs is hidden
if {$backtrace_supported} {
if {!$::valgrind} {
set server_path [tmpdir server5.log]
start_server [list overrides [list dir $server_path crash-memcheck-enabled no]] {
test "Crash report generated on DEBUG SEGFAULT with user data hidden when 'hide-user-data-from-log' is enabled" {
r config set hide-user-data-from-log yes
catch {r debug segfault}
check_log_backtrace_for_debug "*crashed by signal*"
check_log_backtrace_for_debug "*argv*0*: *debug*"
check_log_backtrace_for_debug "*argv*1*: *redacted*"
check_log_backtrace_for_debug "*hide-user-data-from-log is on, skip logging stack content to avoid spilling PII*"
}
}
}
set server_path [tmpdir server6.log]
start_server [list overrides [list dir $server_path use-exit-on-panic yes crash-memcheck-enabled no]] {
test "Generate stacktrace on assertion with user data hidden when 'hide-user-data-from-log' is enabled" {
r config set hide-user-data-from-log yes
catch {r debug assert}
check_log_backtrace_for_debug "*ASSERTION FAILED*"
check_log_backtrace_for_debug "*argv*0* = *debug*"
check_log_backtrace_for_debug "*argv*1* = *redacted*"
}
}
}
}
|
