* Emacs hangs with concurrent TLS connections
@ 2010-11-28 14:20 Lars Magne Ingebrigtsen
2010-12-10 19:24 ` Ted Zlatanov
0 siblings, 1 reply; 5+ messages in thread
From: Lars Magne Ingebrigtsen @ 2010-11-28 14:20 UTC (permalink / raw)
To: ding; +Cc: emacs-devel
This can be rather tricky to reproduce, but I seem to be able to
reproduce it kinda reliably with the following.
Don't eval it -- it might hang your Emacs completely. Start a new one
and try it there:
(progn
(require 'gnutls)
(url-retrieve "https://www.google.no" #'ignore)
(url-retrieve "https://www.google.no" #'ignore))
If it doesn't hang your Emacs, try some other URLs, and more of them.
Emacs becomes completely unresponsive, and the only thing that can be
done is to kill Emacs.
I get an infinite loop like this:
select(11, [3 4 6 8 9], [], NULL, {0, 19533}) = 1 (in [9], left {0, 19531})
getrusage(RUSAGE_SELF, {ru_utime={6, 424401}, ru_stime={1, 744109}, ...}) = 0
times({tms_utime=642, tms_stime=174, tms_cutime=0, tms_cstime=0}) = 1846926770
getrusage(RUSAGE_SELF, {ru_utime={6, 424401}, ru_stime={1, 744109}, ...}) = 0
times({tms_utime=642, tms_stime=174, tms_cutime=0, tms_cstime=0}) = 1846926770
read(3, 0xda6174, 4096) = -1 EAGAIN (Resource temporarily unavailable)
poll([{fd=4, events=POLLIN}, {fd=3, events=POLLIN}], 2, 0) = 0 (Timeout)
select(11, [3 4 6 8 9], [], NULL, {0, 19388}) = 1 (in [9], left {0, 19386})
where fd 3 is
lrwx------ 1 larsi larsi 64 Nov 28 15:14 3 -> socket:[5510547]
which is
emacs 20504 larsi 3u IPv4 5510547 0t0 TCP localhost.localdomain:57459->localhost.localdomain:6010 (ESTABLISHED)
which is the ssh-tunnelled X connection.
So something is up when trying to initialise two gnutls connections at
the same time. Or something. A race condition? Some state shared that
shouldn't be shared? I don't know.
--
(domestic pets only, the antidote for overdose, milk.)
larsi@gnus.org * Lars Magne Ingebrigtsen
^ permalink raw reply [flat|nested] 5+ messages in thread
* Re: Emacs hangs with concurrent TLS connections
2010-11-28 14:20 Emacs hangs with concurrent TLS connections Lars Magne Ingebrigtsen
@ 2010-12-10 19:24 ` Ted Zlatanov
2010-12-13 3:36 ` Lars Magne Ingebrigtsen
0 siblings, 1 reply; 5+ messages in thread
From: Ted Zlatanov @ 2010-12-10 19:24 UTC (permalink / raw)
To: ding; +Cc: emacs-devel
On Sun, 28 Nov 2010 15:20:50 +0100 Lars Magne Ingebrigtsen <larsi@gnus.org> wrote:
LMI> This can be rather tricky to reproduce, but I seem to be able to
LMI> reproduce it kinda reliably with the following.
LMI> Don't eval it -- it might hang your Emacs completely. Start a new one
LMI> and try it there:
LMI> (progn
LMI> (require 'gnutls)
LMI> (url-retrieve "https://www.google.no" #'ignore)
LMI> (url-retrieve "https://www.google.no" #'ignore))
LMI> If it doesn't hang your Emacs, try some other URLs, and more of them.
LMI> Emacs becomes completely unresponsive, and the only thing that can be
LMI> done is to kill Emacs.
LMI> I get an infinite loop like this:
LMI> select(11, [3 4 6 8 9], [], NULL, {0, 19533}) = 1 (in [9], left {0, 19531})
LMI> getrusage(RUSAGE_SELF, {ru_utime={6, 424401}, ru_stime={1, 744109}, ...}) = 0
LMI> times({tms_utime=642, tms_stime=174, tms_cutime=0, tms_cstime=0}) = 1846926770
LMI> getrusage(RUSAGE_SELF, {ru_utime={6, 424401}, ru_stime={1, 744109}, ...}) = 0
LMI> times({tms_utime=642, tms_stime=174, tms_cutime=0, tms_cstime=0}) = 1846926770
LMI> read(3, 0xda6174, 4096) = -1 EAGAIN (Resource temporarily unavailable)
LMI> poll([{fd=4, events=POLLIN}, {fd=3, events=POLLIN}], 2, 0) = 0 (Timeout)
LMI> select(11, [3 4 6 8 9], [], NULL, {0, 19388}) = 1 (in [9], left {0, 19386})
LMI> where fd 3 is
LMI> lrwx------ 1 larsi larsi 64 Nov 28 15:14 3 -> socket:[5510547]
LMI> which is
LMI> emacs 20504 larsi 3u IPv4 5510547 0t0 TCP localhost.localdomain:57459->localhost.localdomain:6010 (ESTABLISHED)
LMI> which is the ssh-tunnelled X connection.
LMI> So something is up when trying to initialise two gnutls connections at
LMI> the same time. Or something. A race condition? Some state shared that
LMI> shouldn't be shared? I don't know.
Have you looked at a verbose log with gnutls-log-level set high?
Ted
^ permalink raw reply [flat|nested] 5+ messages in thread
* Re: Emacs hangs with concurrent TLS connections
2010-12-10 19:24 ` Ted Zlatanov
@ 2010-12-13 3:36 ` Lars Magne Ingebrigtsen
2011-02-25 22:24 ` Ted Zlatanov
0 siblings, 1 reply; 5+ messages in thread
From: Lars Magne Ingebrigtsen @ 2010-12-13 3:36 UTC (permalink / raw)
To: ding; +Cc: emacs-devel
Ted Zlatanov <tzz@lifelogs.com> writes:
> Have you looked at a verbose log with gnutls-log-level set high?
Good idea.
It starts off normal with all the tls chatter, and then it ends up
here...
gnutls.c: [9] INT: CLIENT WRITE KEY [16]: 6cecebb7aa1e56ee74f24771b39f996a
gnutls.c: [9] INT: SERVER WRITE KEY [16]: 70c92720b41a6e281485e907d8a439c9
gnutls.c: [3] HSK[0x1848300]: Cipher Suite: RSA_ARCFOUR_SHA1
gnutls.c: [3] HSK[0x1848300]: Initializing internal [write] cipher sessions
gnutls.c: [6] BUF[HSK]: Peeked 0 bytes of Data
gnutls.c: [6] BUF[HSK]: Emptied buffer
gnutls.c: [3] HSK[0x1848300]: FINISHED was send [16 bytes]
gnutls.c: [6] BUF[HSK]: Peeked 0 bytes of Data
gnutls.c: [6] BUF[HSK]: Emptied buffer
gnutls.c: [4] REC[0x1848300]: Sending Packet[0] Handshake(22) with length: 16
gnutls.c: [7] WRITE: Will write 41 bytes to 0x8.
gnutls.c: [7] WRITE: wrote 41 bytes to 0x8. Left 0 bytes. Total 41 bytes.
gnutls.c: [7] 0000 - 16 03 01 00 24 50 ca 9f d8 2c d4 34 33 15 cb 33
gnutls.c: [7] 0001 - d7 8a de 9c ab 5c 72 0c 5b b2 4b 5b 74 ce d1 47
gnutls.c: [7] 0002 - 1b f9 db 44 d1 57 9d 9c 21
gnutls.c: [4] REC[0x1848300]: Sent Packet[1] Handshake(22) with length: 41
gnutls.c: [7] READ: -1 returned from 0x8, errno=11 gerrno=0
gnutls.c: [2] ASSERT: gnutls_buffers.c:322
gnutls.c: [2] ASSERT: gnutls_handshake.c:2525
gnutls.c: [7] READ: Got 5 bytes from 0x9
gnutls.c: [7] READ: read 5 bytes from 0x9
gnutls.c: [7] 0000 - 48 54 54 50 2f
gnutls.c: [7] RB: Have 0 bytes into buffer. Adding 5 bytes.
gnutls.c: [7] RB: Requested 5 bytes
gnutls.c: [2] ASSERT: gnutls_record.c:507
I think everything up to here is normal. And then things go wonky:
gnutls.c: [4] REC[0x1841540]: Expected Packet[0] Handshake(22) with length: 1
gnutls.c: [4] REC[0x1841540]: Received Packet[0] Unknown Packet(72) with length: 20527
gnutls.c: [4] REC[0x1841540]: FATAL ERROR: Received packet with length: 20527
gnutls.c: [2] ASSERT: gnutls_record.c:960
gnutls.c: [2] ASSERT: gnutls_buffers.c:1032
gnutls.c: [2] ASSERT: gnutls_handshake.c:1045
gnutls.c: [2] ASSERT: gnutls_handshake.c:2364
gnutls.c: [6] BUF[HSK]: Cleared Data from buffer
gnutls.c: [2] ASSERT: gnutls_record.c:879
gnutls.c: [2] ASSERT: gnutls_buffers.c:1032
gnutls.c: [2] ASSERT: gnutls_handshake.c:1045
gnutls.c: [2] ASSERT: gnutls_handshake.c:2364
gnutls.c: [6] BUF[HSK]: Cleared Data from buffer
gnutls.c: [2] ASSERT: gnutls_record.c:879
gnutls.c: [2] ASSERT: gnutls_buffers.c:1032
gnutls.c: [2] ASSERT: gnutls_handshake.c:1045
gnutls.c: [2] ASSERT: gnutls_handshake.c:2364
and here it just loops forever.
Is the wrong socket being asked to handle the TLS data or something?
Hm... I don't really know how to proceed to debug this, but it's 100%
reproducible for me, so if you have any suggestions, I can test it out
easily enough.
--
(domestic pets only, the antidote for overdose, milk.)
larsi@gnus.org * Lars Magne Ingebrigtsen
^ permalink raw reply [flat|nested] 5+ messages in thread
* Re: Emacs hangs with concurrent TLS connections
2010-12-13 3:36 ` Lars Magne Ingebrigtsen
@ 2011-02-25 22:24 ` Ted Zlatanov
2011-03-05 11:45 ` Lars Magne Ingebrigtsen
0 siblings, 1 reply; 5+ messages in thread
From: Ted Zlatanov @ 2011-02-25 22:24 UTC (permalink / raw)
To: emacs-devel; +Cc: ding
On Mon, 13 Dec 2010 04:36:18 +0100 Lars Magne Ingebrigtsen <larsi@gnus.org> wrote:
LMI> Ted Zlatanov <tzz@lifelogs.com> writes:
>> Have you looked at a verbose log with gnutls-log-level set high?
LMI> Good idea.
LMI> It starts off normal with all the tls chatter, and then it ends up
LMI> here...
LMI> gnutls.c: [9] INT: CLIENT WRITE KEY [16]: 6cecebb7aa1e56ee74f24771b39f996a
LMI> gnutls.c: [9] INT: SERVER WRITE KEY [16]: 70c92720b41a6e281485e907d8a439c9
LMI> gnutls.c: [3] HSK[0x1848300]: Cipher Suite: RSA_ARCFOUR_SHA1
LMI> gnutls.c: [3] HSK[0x1848300]: Initializing internal [write] cipher sessions
LMI> gnutls.c: [6] BUF[HSK]: Peeked 0 bytes of Data
LMI> gnutls.c: [6] BUF[HSK]: Emptied buffer
LMI> gnutls.c: [3] HSK[0x1848300]: FINISHED was send [16 bytes]
LMI> gnutls.c: [6] BUF[HSK]: Peeked 0 bytes of Data
LMI> gnutls.c: [6] BUF[HSK]: Emptied buffer
LMI> gnutls.c: [4] REC[0x1848300]: Sending Packet[0] Handshake(22) with length: 16
LMI> gnutls.c: [7] WRITE: Will write 41 bytes to 0x8.
LMI> gnutls.c: [7] WRITE: wrote 41 bytes to 0x8. Left 0 bytes. Total 41 bytes.
LMI> gnutls.c: [7] 0000 - 16 03 01 00 24 50 ca 9f d8 2c d4 34 33 15 cb 33
LMI> gnutls.c: [7] 0001 - d7 8a de 9c ab 5c 72 0c 5b b2 4b 5b 74 ce d1 47
LMI> gnutls.c: [7] 0002 - 1b f9 db 44 d1 57 9d 9c 21
LMI> gnutls.c: [4] REC[0x1848300]: Sent Packet[1] Handshake(22) with length: 41
LMI> gnutls.c: [7] READ: -1 returned from 0x8, errno=11 gerrno=0
LMI> gnutls.c: [2] ASSERT: gnutls_buffers.c:322
LMI> gnutls.c: [2] ASSERT: gnutls_handshake.c:2525
LMI> gnutls.c: [7] READ: Got 5 bytes from 0x9
LMI> gnutls.c: [7] READ: read 5 bytes from 0x9
LMI> gnutls.c: [7] 0000 - 48 54 54 50 2f
LMI> gnutls.c: [7] RB: Have 0 bytes into buffer. Adding 5 bytes.
LMI> gnutls.c: [7] RB: Requested 5 bytes
LMI> gnutls.c: [2] ASSERT: gnutls_record.c:507
LMI> I think everything up to here is normal. And then things go wonky:
LMI> gnutls.c: [4] REC[0x1841540]: Expected Packet[0] Handshake(22) with length: 1
LMI> gnutls.c: [4] REC[0x1841540]: Received Packet[0] Unknown Packet(72) with length: 20527
LMI> gnutls.c: [4] REC[0x1841540]: FATAL ERROR: Received packet with length: 20527
LMI> gnutls.c: [2] ASSERT: gnutls_record.c:960
LMI> gnutls.c: [2] ASSERT: gnutls_buffers.c:1032
LMI> gnutls.c: [2] ASSERT: gnutls_handshake.c:1045
LMI> gnutls.c: [2] ASSERT: gnutls_handshake.c:2364
LMI> gnutls.c: [6] BUF[HSK]: Cleared Data from buffer
LMI> gnutls.c: [2] ASSERT: gnutls_record.c:879
LMI> gnutls.c: [2] ASSERT: gnutls_buffers.c:1032
LMI> gnutls.c: [2] ASSERT: gnutls_handshake.c:1045
LMI> gnutls.c: [2] ASSERT: gnutls_handshake.c:2364
LMI> gnutls.c: [6] BUF[HSK]: Cleared Data from buffer
LMI> gnutls.c: [2] ASSERT: gnutls_record.c:879
LMI> gnutls.c: [2] ASSERT: gnutls_buffers.c:1032
LMI> gnutls.c: [2] ASSERT: gnutls_handshake.c:1045
LMI> gnutls.c: [2] ASSERT: gnutls_handshake.c:2364
LMI> and here it just loops forever.
LMI> Is the wrong socket being asked to handle the TLS data or something?
LMI> Hm... I don't really know how to proceed to debug this, but it's 100%
LMI> reproducible for me, so if you have any suggestions, I can test it out
LMI> easily enough.
Is this still happening? I plan to hit GnuTLS support after we've
battled it out with auth-source.
Ted
^ permalink raw reply [flat|nested] 5+ messages in thread
end of thread, other threads:[~2011-03-05 11:45 UTC | newest]
Thread overview: 5+ messages (download: mbox.gz follow: Atom feed
-- links below jump to the message on this page --
2010-11-28 14:20 Emacs hangs with concurrent TLS connections Lars Magne Ingebrigtsen
2010-12-10 19:24 ` Ted Zlatanov
2010-12-13 3:36 ` Lars Magne Ingebrigtsen
2011-02-25 22:24 ` Ted Zlatanov
2011-03-05 11:45 ` Lars Magne Ingebrigtsen
Code repositories for project(s) associated with this external index
https://git.savannah.gnu.org/cgit/emacs.git
https://git.savannah.gnu.org/cgit/emacs/org-mode.git
This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.