secret
Last active

Demonstration of I/O hang when using old-style Erlang VM console.

  • Download Gist
aaa-readme.txt
1 2 3 4 5 6 7 8 9
This gist contains 3 parts
 
1. The demo script, written with Expect.
2. Output when the bug is demonstrated: Erlang is started without a pseudo-tty.
3. Output when the bug is not demonstrated: Erlang is started *with* a pseudo-tty.
 
Please see the comments at the top of demo.expect for environment prerequisites.
For example, to disable the SSH authentication agent forwarding so that you are
always asked for a password, undefine the SSH_AUTH_SOCK environment variable.
demo.expect
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 155 156 157 158 159 160 161 162 163 164 165 166 167 168 169 170 171 172 173 174 175 176 177 178 179 180 181 182 183 184 185 186 187 188 189 190 191 192 193 194 195 196 197 198 199 200 201 202 203 204 205 206 207 208 209 210 211 212 213 214 215 216 217 218 219 220 221 222 223 224
#!/usr/bin/expect --
 
## Assumptions:
##
## 1. SSH has been used to log into "hostname" once before: we aren't
## smart enough to deal with SSH host key verification stuff.
##
## 2. This script can successfully use SSH to log into hostname using
## the specified user.
##
## 3. If SSH does not require a password for the specified user on
## hostname, then please break that feature so that the SSH
## password authentication method is required.
##
## 4. We assume that the account's shell prompt will include
## a "$" in it. If that is not a correct assumption, please fix
## the login_prompt procedure below.
##
## 5. This script will kill any other beam.smp processes
## that happen to be running on hostname.
##
## 6. We look at beam.smp processes only.
##
## 7. We assume that the machine has an IPv4 loopback address,
## 127.0.0.1. If it is IPv6 only, this script won't work.
 
## Usage: this-script hostname username password run_erl_path erl_path [yes]
## 6th argument is optional. If present, it should be "yes".
##
## For example:
##
## expect this-script 172.16.72.130 fritchie my-password-here /usr/lib64/riak/erts-5.9.1/bin
 
## Reminder reminder reminder: never use single quotes
## Reminder reminder reminder: never use single quotes
## Reminder reminder reminder: never use single quotes
 
set timeout 10
set erl_prompt {@[^)]+\)\d+> }
 
set hostname [lindex $argv 0]
set username [lindex $argv 1]
set password [lindex $argv 2]
set erts_path [lindex $argv 3]
set use_ssh_minus_t [lindex $argv 4]
 
proc login_prompt {} {
expect -re {\$}
# If a dollar sign does not appear in the prompt, comment out
# the line above, uncomment the line below, then edit the line
# below to include the correct prompt string.
# expect -re {some prompt regexp here}
}
 
proc erlang_prompt {} {
global erl_prompt
 
expect -re $erl_prompt
}
 
proc cmd {cmd} {
send "$cmd\r"
login_prompt
}
 
proc async_cmd {cmd} {
send "$cmd\r"
}
 
proc erlang_cmd {cmd} {
send "$cmd\r"
erlang_prompt
}
 
proc announce {msg} {
puts "\n\n*** [exec date]\n*** $msg"
}
 
proc switch_to {id} {
global spawn_id
 
announce "Switching to session $id"
set spawn_id $id
}
 
# send_user "Password for host $hostname: "
# stty -echo
# expect_user -re "(.*)\n"
# stty echo
# set password $expect_out(1,string)
# puts ""
 
spawn ssh -l $username $hostname
set session1 $spawn_id
expect {password}
send "$password\r"
login_prompt
 
announce "Killing all beam.smp processes"
switch_to $session1
cmd {ps axww | grep beam.smp | grep -v grep | awk '{print $1}' | xargs kill -9 ; sleep 1}
cmd {ps -ef | grep beam.smp | grep -v grep | awk '{print $2}' | xargs kill -9 ; sleep 1}
set tmp_dir /tmp/my-tmp-dir
cmd "rm -rf $tmp_dir ; mkdir -p $tmp_dir ; sleep 1"
 
if {$use_ssh_minus_t == "yes"} {
set ssh_extra_arg "-t"
set ssh_extra_msg "(ALLOCATING PTY via 'ssh -t')"
} else {
set ssh_extra_arg "-a"; # Harmless
set ssh_extra_msg ""
}
 
announce "Starting erl via run_erl $ssh_extra_msg"
#spawn ssh $ssh_extra_arg -l $username $hostname "$erts_path/run_erl -daemon $tmp_dir $tmp_dir \"exec $erts_path/erl -sname foo\""
spawn ssh $ssh_extra_arg -l $username $hostname "$erts_path/run_erl -daemon $tmp_dir $tmp_dir \"exec $erts_path/erl -name foo@127.0.0.1\""
expect {password}
send "$password\r"
expect eof
sleep 2
 
announce "Attach via to_erl, do sanity test"
switch_to $session1
async_cmd "$erts_path/to_erl $tmp_dir"
send "hello_world.\r"
expect {
-re $erl_prompt { announce "Excellent, the sanity test passes" }
timeout { announce "to_erl FAILED. Please try again.\n This script is broken for you if it fails more than twice, sorry!\n If this script runs to completion when 'yes' is *not* the final argument\n but if fails at ths point when 'yes' *is* the final argument, then you\n you are hitting a race condition with run_erl and to_erl that I\n do not understand, sorry. At any rate, you are able to run this script\n to demonstrate the bug successfully when run_erl is started without\n a pseudo-tty.\n" ; exit 4}
}
erlang_cmd "application:start(sasl)."
erlang_cmd "timer:sleep(2000)."
 
announce "2nd login session to $hostname, attach to erl via remsh"
 
spawn ssh -l $username $hostname
set session2 $spawn_id
expect {password}
send "$password\r"
login_prompt
 
switch_to $session2
#async_cmd "$erts_path/erl -sname bar -remsh foo@`uname -n | sed 's/\..*//'`"
async_cmd "$erts_path/erl -name bar@127.0.0.1 -remsh foo@127.0.0.1"
erlang_prompt
erlang_cmd "node()."
 
announce "Log a message via lager, watch for it over on Riak console"
switch_to $session2
### erlang_cmd "error_logger:warning_msg(\"WARNING 1\", \[\])."
erlang_cmd "io:format(user, \"WARNING 1\", \[\])."
 
switch_to $session1
expect {
"WARNING 1" { announce "Found our first warning, excellent!" }
timeout { puts "BUMMER 1!" ; exit 4 }
}
 
announce "Now, to hang the logger to demonstrate the bug.\n Any incomplete term is fine, we'll use an unfinished tuple...."
switch_to $session1
async_cmd "{tuple_item_number_1,"
sleep 1
 
set bug_timeout 15
set timeout $bug_timeout
announce "Now that console is hung, call lager:log().\n Set timeout time to $bug_timeout seconds.\n This function should execute in only a few milliseconds."
 
switch_to $session2
send "\003" ; sleep 1
send "\003" ; sleep 1
login_prompt
cmd "echo do it again"
#async_cmd "$erts_path/erl -sname bar -remsh foo@localhost"
async_cmd "$erts_path/erl -name bar@127.0.0.1 -remsh foo@127.0.0.1"
erlang_prompt
erlang_cmd "{again, node(), nodes()}."
 
async_cmd "{time(), io:format(user, \"WARNING 2\", \[\]), time()}."
expect {
-re $erl_prompt { announce "BUMMER, Found 2nd warning at wrong time, continuing with caution"; sleep 5}
timeout { announce "TIMEOUT! Excellent, the bug has been demonstrated (1)" }
}
 
switch_to $session1
expect {
"WARNING 2" { announce "BUMMER, Found 2nd warning at wrong time\n You used 'ssh -t' to allocate a pseudo-tty and therefore the bug\n doesn't exist here, or there's a problem with this Expect script,\n or you really don't have the problem that I'm trying to demonstrate.\n Goodbye!"; exit 4}
timeout { announce "TIMEOUT! Excellent, the bug has been demonstrated (1b)" }
}
 
announce "When we finish the erlang term over on $session1 ('riak attach' session),\n then the logger will become unblocked."
switch_to $session1
async_cmd "element_number_2}."
expect {
-re $erl_prompt { announce "Excellent, we have 'riak attach' prompt" }
timeout { announce "BUMMER, timeout when not expected (2)"; exit 4}
}
 
announce "Now go to session $session2 and expect the -remsh's prompt."
switch_to $session2
# expect {
# "WARNING 2" { announce "Excellent, I see the 'WARNING 2' log message" }
# timeout { announce "BUMMER, timeout when not expected @ 2nd w"; exit 4}
# }
expect {
-re $erl_prompt { announce "Excellent, we have the 'riak -remsh' prompt" }
timeout { announce "BUMMER, timeout when not expected (3)"; exit 4}
}
 
announce "Time to clean up both sessions"
 
switch_to $session1
async_cmd "\004"
login_prompt
async_cmd "exit\r"
expect eof
 
switch_to $session2
async_cmd "\003" ; sleep 1
async_cmd "\003" ; sleep 1
login_prompt
async_cmd "exit\r"
expect eof
 
announce "Excellent, this successful test is finished."
exit 0
m-bug-demonstrated-output.txt
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 155 156 157 158 159 160 161 162 163 164 165 166 167 168 169 170 171 172 173 174 175 176 177 178 179 180 181 182 183 184 185 186 187 188 189 190 191 192 193 194 195 196 197 198 199 200 201 202 203 204 205 206 207 208 209 210 211 212 213 214 215 216 217 218 219 220 221 222 223 224 225 226 227 228 229 230 231 232 233 234 235 236 237 238 239 240 241 242 243 244 245 246 247 248 249 250 251 252 253 254 255 256 257 258 259 260 261 262 263 264 265 266 267 268 269 270 271 272 273 274 275 276 277 278 279 280 281 282 283 284 285 286 287 288 289 290 291 292 293 294 295 296 297
NOTE: This output was generated by:
csh users:
expect ~/b/notes/2013-04-22.hanging-log-plain.expect 172.16.72.130 fritchie foofoo /usr/lib64/riak/erts-5.9.1/bin | & tee ~/foo2
sh/bash users:
expect ~/b/notes/2013-04-22.hanging-log-plain.expect 172.16.72.130 fritchie foofoo /usr/lib64/riak/erts-5.9.1/bin 2>&1 | tee ~/foo2
 
spawn ssh -l fritchie 172.16.72.130
fritchie@172.16.72.130's password:
Last login: Tue Apr 23 10:07:45 2013 from 172.16.72.1
 
]0;fritchie@localhost:~[fritchie@localhost ~]$
 
*** Tue Apr 23 12:07:59 CDT 2013
*** Killing all beam.smp processes
 
 
*** Tue Apr 23 12:07:59 CDT 2013
*** Switching to session exp7
ps axww | grep beam.smp | grep -v grep | awk '{print $1}
' | xargs kill -9 ; sleep 1
]0;fritchie@localhost:~[fritchie@localhost ~]$ ps -ef | grep beam.smp | grep -v grep | awk '{print $2}'
| xargs kill -9 ; sleep 1
 
 
*** Tue Apr 23 12:08:00 CDT 2013
*** Starting erl via run_erl
spawn ssh -a -l fritchie 172.16.72.130 /usr/local/erlang/R15B03.64-bit/bin/run_erl -daemon /tmp/my-tmp-dir /tmp/my-tmp-dir "exec /usr/local/erlang/R15B03.64-bit/bin/erl -name foo@127.0.0.1"
fritchie@172.16.72.130's password:
 
 
*** Tue Apr 23 12:08:02 CDT 2013
*** Attach via to_erl, do sanity test
 
 
*** Tue Apr 23 12:08:02 CDT 2013
*** Switching to session exp7
rm -rf /tmp/my-tmp-dir ; mkdir -p /tmp/my-tmp-dir ; sleep 1
usage: kill [ -s signal | -p ] [ -a ] pid ...
kill -l [ signal ]
]0;fritchie@localhost:~[fritchie@localhost ~]$ rm -rf /tmp/my-tmp-dir ; mkdir -p /tmp/my-tmp-dir ; slee
p 1
]0;fritchie@localhost:~[fritchie@localhost ~]$ /usr/local/erlang/R15B03.64-bit/bin/to_erl /tmp/my-tmp-d
ir
Attaching to /tmp/my-tmp-dir (^D to exit)
 
^R
 
hello_world.
 
hello_world
 
(foo@127.0.0.1)2>
 
*** Tue Apr 23 12:08:02 CDT 2013
*** Excellent, the sanity test passes
application:start(sasl).
 
ok
 
(foo@127.0.0.1)3>
 
=PROGRESS REPORT==== 23-Apr-2013::10:08:02 ===
 
supervisor: {local,sasl_safe_sup}
 
started: [{pid,<0.44.0>},
 
{name,alarm_handler},
 
{mfargs,{alarm_handler,start_link,[]}},
 
{restart_type,permanent},
 
{shutdown,2000},
 
{child_type,worker}]
 
(foo@127.0.0.1)3>
 
=PROGRESS REPORT==== 23-Apr-2013::10:08:02 ===
 
supervisor: {local,sasl_safe_sup}
 
started: [{pid,<0.45.0>},
 
{name,overload},
 
{mfargs,{overload,start_link,[]}},
 
{restart_type,permanent},
 
{shutdown,2000},
 
{child_type,worker}]
 
(foo@127.0.0.1)3>
 
=PROGRESS REPORT==== 23-Apr-2013::10:08:02 ===
 
supervisor: {local,sasl_sup}
 
started: [{pid,<0.43.0>},
 
{name,sasl_safe_sup},
 
 
*** Tue Apr 23 12:08:02 CDT 2013
*** 2nd login session to 172.16.72.130, attach to erl via remsh
spawn ssh -l fritchie 172.16.72.130
fritchie@172.16.72.130's password:
Last login: Tue Apr 23 10:07:59 2013 from 172.16.72.1
 
]0;fritchie@localhost:~[fritchie@localhost ~]$
 
*** Tue Apr 23 12:08:02 CDT 2013
*** Switching to session exp9
/usr/local/erlang/R15B03.64-bit/bin/erl -name bar@127.0.
0.1 -remsh foo@127.0.0.1
Erlang R15B03 (erts-5.9.3.1) [source] [64-bit] [smp:2:2] [async-threads:0] [hipe] [kernel-poll:false]
 
Eshell V5.9.3.1 (abort with ^G)
(foo@127.0.0.1)1> node().
'foo@127.0.0.1'
(foo@127.0.0.1)2>
 
*** Tue Apr 23 12:08:02 CDT 2013
*** Log a message via lager, watch for it over on Riak console
 
 
*** Tue Apr 23 12:08:02 CDT 2013
*** Switching to session exp9
io:format(user, "WARNING 1", []).
ok
(foo@127.0.0.1)3>
 
*** Tue Apr 23 12:08:02 CDT 2013
*** Switching to session exp7
{mfargs,
 
{supervisor,start_link,
 
[{local,sasl_safe_sup},sasl,safe]}},
 
{restart_type,permanent},
 
{shutdown,infinity},
 
{child_type,supervisor}]
 
(foo@127.0.0.1)3>
 
=PROGRESS REPORT==== 23-Apr-2013::10:08:02 ===
 
supervisor: {local,sasl_sup}
 
started: [{pid,<0.46.0>},
 
{name,release_handler},
 
{mfargs,{release_handler,start_link,[]}},
 
{restart_type,permanent},
 
{shutdown,2000},
 
{child_type,worker}]
 
(foo@127.0.0.1)3>
 
=PROGRESS REPORT==== 23-Apr-2013::10:08:02 ===
 
application: sasl
 
started_at: 'foo@127.0.0.1'
 
(foo@127.0.0.1)3> timer:sleep(2000).
 
WARNING 1
 
*** Tue Apr 23 12:08:02 CDT 2013
*** Found our first warning, excellent!
 
 
*** Tue Apr 23 12:08:02 CDT 2013
*** Now, to hang the logger to demonstrate the bug.
Any incomplete term is fine, we'll use an unfinished tuple....
 
 
*** Tue Apr 23 12:08:02 CDT 2013
*** Switching to session exp7
 
 
*** Tue Apr 23 12:08:03 CDT 2013
*** Now that console is hung, call lager:log().
Set timeout time to 15 seconds.
This function should execute in only a few milliseconds.
 
 
*** Tue Apr 23 12:08:03 CDT 2013
*** Switching to session exp9
 
 
BREAK: (a)bort (c)ontinue (p)roc info (i)nfo (l)oaded
 
(v)ersion (k)ill (D)b-tables (d)istribution
 
]0;fritchie@localhost:~[fritchie@localhost ~]$ echo do it again
do it again
]0;fritchie@localhost:~[fritchie@localhost ~]$ /usr/local/erlang/R15B03.64-bit/bin/erl -name bar@127.0.
0.1 -remsh foo@127.0.0.1
Erlang R15B03 (erts-5.9.3.1) [source] [64-bit] [smp:2:2] [async-threads:0] [hipe] [kernel-poll:false]
 
Eshell V5.9.3.1 (abort with ^G)
(foo@127.0.0.1)1> {again, node(), nodes()}.
{again,'foo@127.0.0.1',['bar@127.0.0.1']}
(foo@127.0.0.1)2> {time(), io:format(user, "WARNING 2", []), time()}.
 
 
*** Tue Apr 23 12:08:20 CDT 2013
*** TIMEOUT! Excellent, the bug has been demonstrated (1)
 
 
*** Tue Apr 23 12:08:20 CDT 2013
*** Switching to session exp7
{tuple_item_number_1,
 
ok
 
(foo@127.0.0.1)4>
 
*** Tue Apr 23 12:08:35 CDT 2013
*** TIMEOUT! Excellent, the bug has been demonstrated (1b)
 
 
*** Tue Apr 23 12:08:35 CDT 2013
*** When we finish the erlang term over on exp7 ('riak attach' session),
then the logger will become unblocked.
 
 
*** Tue Apr 23 12:08:35 CDT 2013
*** Switching to session exp7
 
 
*** Tue Apr 23 12:08:35 CDT 2013
*** Excellent, we have 'riak attach' prompt
 
 
*** Tue Apr 23 12:08:35 CDT 2013
*** Now go to session exp9 and expect the -remsh's prompt.
 
 
*** Tue Apr 23 12:08:35 CDT 2013
*** Switching to session exp9
{{10,8,5},ok,{10,8,35}}
(foo@127.0.0.1)3>
 
*** Tue Apr 23 12:08:35 CDT 2013
*** Excellent, we have the 'riak -remsh' prompt
 
 
*** Tue Apr 23 12:08:35 CDT 2013
*** Time to clean up both sessions
 
 
*** Tue Apr 23 12:08:35 CDT 2013
*** Switching to session exp7
element_number_2}.
 
WARNING 2{tuple_item_number_1,element_number_2}
 
(foo@127.0.0.1)5> [Quit]
 
]0;fritchie@localhost:~[fritchie@localhost ~]$ exit
logout
Connection to 172.16.72.130 closed.
 
 
 
*** Tue Apr 23 12:08:35 CDT 2013
*** Switching to session exp9
 
(foo@127.0.0.1)3>
 
BREAK: (a)bort (c)ontinue (p)roc info (i)nfo (l)oaded
 
(v)ersion (k)ill (D)b-tables (d)istribution
 
 
]0;fritchie@localhost:~[fritchie@localhost ~]$ exit
logout
Connection to 172.16.72.130 closed.
 
 
 
*** Tue Apr 23 12:08:37 CDT 2013
*** Excellent, this successful test is finished.
n-no-bug-output.txt
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 155 156 157 158 159 160 161 162 163 164 165 166 167 168 169 170 171 172 173 174 175 176 177 178 179 180 181 182 183 184 185 186 187 188 189 190 191 192 193 194 195 196 197 198 199 200 201 202 203 204 205 206 207 208 209 210 211 212 213 214 215 216 217 218 219 220 221 222 223 224 225 226 227 228 229 230 231 232 233 234 235 236 237
NOTE: This output was generated by:
csh users:
expect ~/b/notes/2013-04-22.hanging-log-plain.expect 172.16.72.130 fritchie foofoo /usr/lib64/riak/erts-5.9.1/bin yes | & tee ~/foo2b
sh/bash users:
expect ~/b/notes/2013-04-22.hanging-log-plain.expect 172.16.72.130 fritchie foofoo /usr/lib64/riak/erts-5.9.1/bin yes 2>&1 | tee ~/foo2b
 
spawn ssh -l fritchie 172.16.72.130
fritchie@172.16.72.130's password:
Last login: Tue Apr 23 10:06:37 2013 from 172.16.72.1
 
]0;fritchie@localhost:~[fritchie@localhost ~]$
 
*** Tue Apr 23 12:07:40 CDT 2013
*** Killing all beam.smp processes
 
 
*** Tue Apr 23 12:07:40 CDT 2013
*** Switching to session exp7
ps axww | grep beam.smp | grep -v grep | awk '{print $1}
' | xargs kill -9 ; sleep 1
]0;fritchie@localhost:~[fritchie@localhost ~]$ ps -ef | grep beam.smp | grep -v grep | awk '{print $
 
*** Tue Apr 23 12:07:41 CDT 2013
*** Starting erl via run_erl (ALLOCATING PTY via 'ssh -t')
spawn ssh -t -l fritchie 172.16.72.130 /usr/local/erlang/R15B03.64-bit/bin/run_erl -daemon /tmp/my-tmp-dir /tmp/my-tmp-dir "exec /usr/local/erlang/R15B03.64-bit/bin/erl -name foo@127.0.0.1"
fritchie@172.16.72.130's password:
Connection to 172.16.72.130 closed.
 
 
 
*** Tue Apr 23 12:07:43 CDT 2013
*** Attach via to_erl, do sanity test
 
 
*** Tue Apr 23 12:07:43 CDT 2013
*** Switching to session exp7
2}'
| xargs kill -9 ; sleep 1
usage: kill [ -s signal | -p ] [ -a ] pid ...
kill -l [ signal ]
]0;fritchie@localhost:~[fritchie@localhost ~]$ rm -rf /tmp/my-tmp-dir ; mkdir -p /tmp/my-tmp-dir ; slee
p 1
]0;fritchie@localhost:~[fritchie@localhost ~]$ /usr/local/erlang/R15B03.64-bit/bin/to_erl /tmp/my-tmp-d
ir
Attaching to /tmp/my-tmp-dir (^D to exit)
 
hello_world.
 
hello_world
 
(foo@127.0.0.1)2>
 
*** Tue Apr 23 12:07:43 CDT 2013
*** Excellent, the sanity test passes
application:start(sasl).
 
ok
 
(foo@127.0.0.1)3>
 
=PROGRESS REPORT==== 23-Apr-2013::10:07:43 ===
 
supervisor: {local,sasl_safe_sup}
 
started: [{pid,<0.45.0>},
 
{name,alarm_handler},
 
{mfargs,{alarm_handler,start_link,[]}},
 
{restart_type,permanent},
 
{shutdown,2000},
 
{child_type,worker}]
 
 
 
=PROGRESS REPORT==== 23-Apr-2013::10:07:43 ===
 
supervisor: {local,sasl_safe_sup}
 
started: [{pid,<0.46.0>},
 
{name,overload},
 
{mfargs,{overload,start_link,[]}},
 
{restart_type,permanent},
 
{shutdown,2000},
 
{child_type,worker}]
 
 
 
=PROGRESS REPORT==== 23-Apr-2013::10:07:43 ===
 
supervisor: {local,sasl_sup}
 
started: [{pid,<0.44.0>},
 
{name,sasl_safe_sup},
 
{mfargs,
 
{supervisor,start_link,
 
[{local,sasl_safe_sup},sasl,safe]}},
 
{restart_type,permanent},
 
{shutdown,infinity},
 
{child_type,supervisor}]
 
 
 
=PROGRESS REPORT==== 23-Apr-2013::10:07:43 ===
 
supervisor: {local,sasl_sup}
 
started: [{pid,<0.47.0>},
 
{name,release_handler},
 
{mfargs,{release_handler,start_link,[]}},
 
{restart_type,permanent},
 
{shutdown,2000},
 
{child_type,worker}]
 
 
 
=PROGRESS REPORT==== 23-Apr-2013::10:07:43 ===
 
application: sasl
 
started_at: 'foo@127.0.0.1'
 
timer:sleep(2000).
 
ok
 
(foo@127.0.0.1)4>
 
*** Tue Apr 23 12:07:45 CDT 2013
*** 2nd login session to 172.16.72.130, attach to erl via remsh
spawn ssh -l fritchie 172.16.72.130
fritchie@172.16.72.130's password:
Last login: Tue Apr 23 10:07:41 2013 from 172.16.72.1
 
]0;fritchie@localhost:~[fritchie@localhost ~]$
 
*** Tue Apr 23 12:07:45 CDT 2013
*** Switching to session exp9
/usr/local/erlang/R15B03.64-bit/bin/erl -name bar@127.0.
0.1 -remsh foo@127.0.0.1
Erlang R15B03 (erts-5.9.3.1) [source] [64-bit] [smp:2:2] [async-threads:0] [hipe] [kernel-poll:false]
 
Eshell V5.9.3.1 (abort with ^G)
(foo@127.0.0.1)1> node().
'foo@127.0.0.1'
(foo@127.0.0.1)2>
 
*** Tue Apr 23 12:07:45 CDT 2013
*** Log a message via lager, watch for it over on Riak console
 
 
*** Tue Apr 23 12:07:45 CDT 2013
*** Switching to session exp9
io:format(user, "WARNING 1", []).
ok
(foo@127.0.0.1)3>
 
*** Tue Apr 23 12:07:45 CDT 2013
*** Switching to session exp7
WARNING 1
 
*** Tue Apr 23 12:07:45 CDT 2013
*** Found our first warning, excellent!
 
 
*** Tue Apr 23 12:07:45 CDT 2013
*** Now, to hang the logger to demonstrate the bug.
Any incomplete term is fine, we'll use an unfinished tuple....
 
 
*** Tue Apr 23 12:07:45 CDT 2013
*** Switching to session exp7
 
 
*** Tue Apr 23 12:07:46 CDT 2013
*** Now that console is hung, call lager:log().
Set timeout time to 15 seconds.
This function should execute in only a few milliseconds.
 
 
*** Tue Apr 23 12:07:46 CDT 2013
*** Switching to session exp9
 
 
BREAK: (a)bort (c)ontinue (p)roc info (i)nfo (l)oaded
 
(v)ersion (k)ill (D)b-tables (d)istribution
 
]0;fritchie@localhost:~[fritchie@localhost ~]$ echo do it again
do it again
]0;fritchie@localhost:~[fritchie@localhost ~]$ /usr/local/erlang/R15B03.64-bit/bin/erl -name bar@127.0.
0.1 -remsh foo@127.0.0.1
Erlang R15B03 (erts-5.9.3.1) [source] [64-bit] [smp:2:2] [async-threads:0] [hipe] [kernel-poll:false]
 
Eshell V5.9.3.1 (abort with ^G)
(foo@127.0.0.1)1> {again, node(), nodes()}.
{again,'foo@127.0.0.1',['bar@127.0.0.1']}
(foo@127.0.0.1)2> {time(), io:format(user, "WARNING 2", []), time()}.
{{10,7,48},ok,{10,7,48}}
(foo@127.0.0.1)3>
 
*** Tue Apr 23 12:07:48 CDT 2013
*** BUMMER, Found 2nd warning at wrong time, continuing with caution
 
 
*** Tue Apr 23 12:07:53 CDT 2013
*** Switching to session exp7
{tuple_item_number_1,
 
(foo@127.0.0.1)4> WARNING 2
 
*** Tue Apr 23 12:07:53 CDT 2013
*** BUMMER, Found 2nd warning at wrong time
You used 'ssh -t' to allocate a pseudo-tty and therefore the bug
doesn't exist here, or there's a problem with this Expect script,
or you really don't have the problem that I'm trying to demonstrate.
Goodbye!

Please sign in to comment on this gist.

Something went wrong with that request. Please try again.