Re: Posting to one specific nntp server hangs emacs/gnus

[Tassilo Horn <tassilo@member.fsf.org>]

On Tuesday 06 July 2010 14:05:11 Adam Sjøgren wrote:

Hi Adam,

> > What might be the culprit?  How can I debug that any further?
> 
> I find that a nice way to debug such conversations is ngrep -
> something like:
> 
>  $ sudo ngrep -Wbyline port nntp
> 
> and then trying to post; makes it easy to see what is going on over
> the wire.

Hey, what a cool tool!

Ok, that's the output when sending a posting:

--8<---------------cut here---------------start------------->8---
####
T 141.26.67.142:50445 -> 141.26.64.5:563 [AP]
...........L3Czn..!..t.....G..*..G'..R.......@.g.3.E.k.9.....@.2.D.j.8.....f.........<./.A.=.5...
...............<................news.uni-koblenz.de......#.......
..........
##
T 141.26.64.5:563 -> 141.26.67.142:50445 [A]
....J...F..L3CzS.....v......J.....Mj.ff.... ...zg.....6Tt.M..u.....\n..v ..].3.....R...N..K..f0..b0..J........=d.0...*.H........0..1.0...U....DE1907..U.
.0Regionales Hochschulrechenzentrum Kaiserslautern1.0...U....RHRK-CA - G021 0...*.H........ca@rhrk.uni-kl.de0...071023122007Z..121021122007Z0..1.0...U....DE1.0...U....Rheinland-Pfalz1.0...U....Koblenz1$0"..U.
..Universitaet Koblenz-Landau1301..U...*Gemeinsames Hochschulrechenzentrum Koblenz1.0...U....news.uni-koblenz.de0.."0...*.H.............0..
...........V.......\..Y.v~\.........C-......`O.Q..h...e(.9........3..G.1...T...../.M..........V{P5...MB.....n:.[........]..8W.......h($..N..`g.53..~.5..Pc.&8F......ZI...{.*...dr..:.~......"B.;L..!...#.......J......s..C.\.*R..2;....}...N{\*....J.. 6.F...
....K.o.........0...0...U....0.0...U........0...U.%..0
..+.......0...U........N...&....`...!A.-.0...U.#..0.../...c\..o.....'.o...0...U....0...admin@uni-koblenz.de0}..U...v0t08.6.4.2http://cdp1.pca.dfn.de/rhrk-ca/pub/crl/g_cacrl.crl08.6.4.2http://cdp2.pca.dfn.de/rhrk-ca/pub/crl/g_cacrl.crl0....+..........0..0B..+.....0..6http://cdp1.pca.dfn.de/rhrk-ca/pub/cacert/g_cacert.crt0B..+.....0..6http://cdp2.pca.dfn.de/rhrk-ca/pub/cacert/g_cacert.crt0...*.H.............rE&sk'xmP..Lm..rJ....1.....\AJ..Qu....[.V....A.....s..@>p'...@}........y.Z...S.7..h=.j...D.N.W..d^Y......W..,Z.2..
.[....Z./...O..........{....A..1....[..S=.b`..O.8c....$..0....f..'..-..N..4...Z+..5.f6.%........I.g'.`I. ..%.F.O.
#
T 141.26.64.5:563 -> 141.26.67.142:50445 [A]
.-n....G~.@.Rk.F.S.J...b,......0...0..........
.C50...*.H........0Z1.0...U....DE1.0...U.
.
DFN-Verein1.0...U....DFN-PKI1$0"..U....DFN-Verein PCA Global - G010...070314095134Z..190313000000Z0..1.0...U....DE1907..U.
.0Regionales Hochschulrechenzentrum Kaiserslautern1.0...U....RHRK-CA - G021 0...*.H........ca@rhrk.uni-kl.de0.."0...*.H.............0..
......@C.........t........$#...)Q....Ke.k...Fn..,v\iw........n..Q.g.....eR..s..=.Ev......VCw.ap..A:..iSat^a3>.f6ku{W8...o$.....>SI..6.8.M#.I....r..{.....DCUI....U.......kS....H.K....\.W........Y/....~...nu:{...6."s..O,..!^......o"]$..J{..R...?..5..,Ax4.KIB...E..........0...0...U.......0....0...U........0...U....../...c\..o.....'.o...0...U.#..0...I....=...D{.)..
p>.d0...U....0...ca@rhrk.uni-kl.de0....U.....0~0=.;.9.7http://cdp1.pca.dfn.de/global-root-ca/pub/crl/cacrl.crl0=.;.9.7http://cdp2.pca.dfn.de/global-root-ca/pub/crl/cacrl.crl0....+..........0..0G..+.....0..;http://cdp1.pca.dfn.de/global-root-ca/pub/cacert/cacert.crt0G..+.....0..;http://cdp2.pca.dfn.de/global-root-ca/pub/cacert/cacert.crt0...*.H...............j..\.\J1....NF.)Y.4....L..f+uW..f...:vx."...N."....D{.V!...e.wZ.......qO.h..5.FQ...I.r]..`!..W.\@.N2XU$E/.,..j.....&_...
=....Ab..|j..B.Y...[.oAd.9V.B.I.]H....._.....3..W....J.....8\\kW.......i...h...V.T.1...l..9.-SrZ.....L......K....$.U.@].9z..KF\P.x..O..%0..!0............0...*.H........0q1.0...U....DE1.0...U.
..Deutsche Telekom AG1.0...U....T-TeleSec Trust Center1#0!..U
#
T 141.26.64.5:563 -> 141.26.67.142:50445 [AP]
....Deutsche Telekom Root CA 20...061219102900Z..190630235900Z0Z1.0...U....DE1.0...U.
.
DFN-Verein1.0...U....DFN-PKI1$0"..U....DFN-Verein PCA Global - G010.."0...*.H.............0..
........g......T..P5=b.nL....[."t. .4....1........R.(#..t..^[..x.x...(59{-.E....z|.J......\+1.{...$C..8.jh....Ox.....v...&....t.....k.....0O.....b....'0..e`M...#*.5X'.v.q......5.}o3..........]Ak....L..Q...........VVC....=..'0.IT...4.qu.l.....!.'.>.99Hj.................0..0p..U...i0g0e.c.a._http://pki.telesec.de/cgi-bin/service/af_DownloadARL.crl?-crl_format=X_509&-issuer=DT_ROOT_CA_20...U......I....=...D{.)..
p>.d0...U.#..0...1.y...S....z-.l
.+.30...U...........0...U.......0.......0...*.H.............;.Zw.H.......Z...(...Y..p.(.....,..].1..+t......g.9.y;....kx.3~;_&'uSe.3c..s...#I!Pu#......=?3.w ......)@.?s2X..k...l.?..fdV$N..?25.[....rYO....t.V...\...G.S.p..M.i.(.....^..X......Z.h.(>...X...,7W.g.#h.c...k\.KV..@.4...l...
..3r.o..T,.Q...0.Cr.2...Ic........0...0..........&0...*.H........0q1.0...U....DE1.0...U.
..Deutsche Telekom AG1.0...U....T-TeleSec Trust Center1#0!..U....Deutsche Telekom Root CA 20...990709121100Z..190709235900Z0q1.0...U....DE1.0...U.
..Deutsche Telekom AG1.0...U....T-TeleSec Trust Cen
####
T 141.26.64.5:563 -> 141.26.67.142:50445 [AP]
ter1#0!..U....Deutsche Telekom Root CA 20.."0...*.H.............0..
........5..).....<..9o5]J...a..I.od..`f..@".....x..h...M\:....B@.....Yj.......+%'.i#G...,z.....~4|..<.Y.....2<+.P..........2..HV[j...XX.I_rA<....]..........j-R4.:.\uQ...1..q.2.T.D...U.........I.S...L..Xy..j.B.....h....a.va..|.>...P...
......:}....4..[..j....nJ.......B0@0...U......1.y...S....z-.l
.+.30...U....0.......0...U...........0...*.H..............dY.9d.)...Z...W..$.tw.`.g........|n..=...n.)..z.;T.9.G~.....1Y1.....,.b6U."..U..H.d...6.DxZZ#:W..z0O..jLK+....>....{....r<....Y..E..;..9..2..!a..1!.4../5J.....7!.Yc....1S.T..py...w'u/........6....e..cZ.F...7.A..#....h.Dc.Z..5Y..p...#W..
m.9c(..........VdW..............XNI.. .....6k3l8.E..|...|[-....#.C..[....U..]8.4.|.WC...l.3!,.*.<..)@...|..
r.......)z........
P..F..=f.]A..|..K".&...^.U./x........,1.k.n..e.o!.$.S.I...<.S....o0.rJ@..v[.j..Ke..//.2....%k..8ZAf2.+.ob..rK...0f......ri.[.".!.....9J...(l8S.~..>~.s.HY.Y.).2.+........S@C.1u.|...%(.x
.F.........i...z.........n...1. .lF
...;..q.
?;.y.....c..J=.}..=...>.....$
x#.o...Rx...._.^..<....)..
}.....v.;..j.._yj3.....%./j.(.1]...(..Vs...l.g....D..}#6.........o...||..R....wN...?.q....9......g..j...'N.uV.+.D.F].ggM.........#eI...........
##
T 141.26.67.142:50445 -> 141.26.64.5:563 [AP]
.........................LIP6...^......~-..t......*...B..../...b.....v.........yU.).......+=.dQP..=..>.U.u...R.t....r..c...Z@V(q..X6.}...*.
##
T 141.26.67.142:50445 -> 141.26.64.5:563 [AP]
......
##
T 141.26.67.142:50445 -> 141.26.64.5:563 [AP]
....P...n;..AztZ.u}.*.Z....-Wh#DH}.(......T.$.............b....%w.&...]^\.6....T.)..h
##
T 141.26.64.5:563 -> 141.26.67.142:50445 [AP]
..........0..P..QX .u.E...k...@.7gw`d.~2<..........n9.n..b.
##
T 141.26.64.5:563 -> 141.26.67.142:50445 [AP]
....p......O...>.5#..&..F..I.z...c....K...q..Or......W.K[.>/.F..8...RV..#......Y.U....C^F&....g.b.R.a.1.C...m....R..N
##
T 141.26.67.142:50445 -> 141.26.64.5:563 [AP]
....0...9...1.TdM,........wW........h...dv.}..9.W...n
#
T 141.26.64.5:563 -> 141.26.67.142:50445 [AP]
....p...pT.Mk..I.R.g.g
O...........+ .V.e.b..`F........\.d.......E*...{6..5GH......7...3N..m.GNMV..'b.....:....;A.K*.
#
T 141.26.67.142:50445 -> 141.26.64.5:563 [AP]
....0........6..WE.'.
.4........... K.0....).@.....Y.
#
T 141.26.64.5:563 -> 141.26.67.142:50445 [AP]
....0...._.L.....%..".....n%F....7....:..Mp........!e
#
T 141.26.67.142:50445 -> 141.26.64.5:563 [AP]
......G.|..o.V..^.-/...F']..j...z3f.p.e0..e0......{.3...je.n...W...pi......a.....I.v...&..._.sE.......D_.[...Z:.Vk\;.o..b...<.aB...g!.95f.WD?..N.........w...IY.....~e|(..;@.H..b.l..F.+...|...[)..=.....z
e?M....k...xt....b.sd........K9..../...^8..e..M=!%k..`.........~.2.J~...."
#
T 141.26.64.5:563 -> 141.26.67.142:50445 [AP]
.... S.*`......DG....../%i..8.}M....Y
#
T 141.26.67.142:50445 -> 141.26.64.5:563 [AP]
.......j....wdhB.........w.G..............Ba....q.....M 6!...-..._....J..,M..01H.....$....CN....D.'<.+...n.?@i9..*..*......ghcC..s.. .?..R....aw..bk&
#
T 141.26.64.5:563 -> 141.26.67.142:50445 [AP]
....`.h~.....b..1...4....q$.$..>F......a.u..f....E..t.^.......m.........7*..Q..zC.G...n..7`...l.8.h..
#
T 141.26.67.142:50445 -> 141.26.64.5:563 [AP]
....P.Gn...U=0...N..'x....F......z...?...).^Yd+.=/._+..5.....FV..+.<.yc.n.Srf={...:.............[]6..Iav.a.."x.>?Z\S+p....&........%.w*I.....TP...M.'0.p'...TO.../.. ......].oc...%...q..I..s.[u..[......4=...................=......j..6.CK..`G.sB....s...9..R......>d.....r.H%.j....-...Z......E.7...."\"....$*'......y..~A.....Q.M.P.....&V'T.....Gn.......m..4M.........t......vPm...o..|iAZ...[...c.+..I...\T.....@sw..D....'...^r......l.~C\..uu.*7....Y%........W............o...&..{..u..\.....N.L..\..|.t..&....Iq.m*........~.<.t...s3lB.....Z_8.\Ngm&. yA..=l]Db.'#.X&.},P..D.W.?...D..Y...H..d....S...;....3]........3B.....$......$....U..F[..{.......O.%.H....D.E%[..N.*c.c.Ft.E2}.d.D.....H.d.u....,..y"P...>2~..Q......P...E........^..g...,..rO.s..;.....=mP.m.........C2.5|..9.O....t.......)..R[...?*.2B.'..E...Z....GM,3..sZ..q....5...z ).f.x.....f.}!...%u.%.u*
# ***HERE IT HANGS, THE FOLLOWING IS AFTER A C-g.***
T 141.26.67.142:50445 -> 141.26.64.5:563 [AP]
....`S.Q.<4 ...k1V.UJb.Vo.yB1....]~.K..,R.....q...'_.....}.XD]....AU.....D[...X...VIL..r`.......}Z..C
##
T 141.26.64.5:563 -> 141.26.67.142:50445 [AP]
....POZT....x&.[+k.C..^.U..d..Zi....}....
.....7..u.#.....a.../ '...E.>."Vp..,.......
#
T 141.26.64.5:563 -> 141.26.67.142:50445 [AFP]
.... .X/I.........r...p............M..... .),?....`G...b..p...._..x. ..!W~
###
--8<---------------cut here---------------end--------------->8---

As you can see, you can see nothing, because I use a TLS stream.

--8<---------------cut here---------------start------------->8---
(add-to-list 'gnus-secondary-select-methods
             '(nntp "Uni"
                    (nntp-address "news.uni-koblenz.de")
                    (nntp-open-connection-function nntp-open-tls-stream)
                    (nntp-port-number 563)))
--8<---------------cut here---------------end--------------->8---

Have a look at the line

# ***HERE IT HANGS, THE FOLLOWING IS AFTER A C-g.***

in the output above.  Then you can see what happens before and after I
hit C-g.

When I don't use TLS, the sending works flawlessly without a hang, and I
get this output:

--8<---------------cut here---------------start------------->8---
#
T 141.26.67.142:53478 -> 141.26.64.5:119 [AP]
POST.

#
T 141.26.64.5:119 -> 141.26.67.142:53478 [AP]
340 Ok, recommended ID <i0vfhd$i3p$1@cache.uni-koblenz.de>.

##
T 141.26.67.142:53478 -> 141.26.64.5:119 [AP]
From: Tassilo Horn <horn@uni-koblenz.de>.
Newsgroups: infko.test.
Subject: Und wieder ein Test.
Date: Tue, 06 Jul 2010 16:45:00 +0200.
Message-ID: <87hbkc3c0j.fsf@thinkpad.tsdh.de>.
User-Agent: Gnus/5.13 (Gnus v5.13) Emacs/24.0.50 (gnu/linux).
Cancel-Lock: sha1:WSCCWT+aSTjDhnvZKGfZiCa6ikQ=.
MIME-Version: 1.0.
Content-Type: text/plain; charset=utf-8.
Content-Transfer-Encoding: 8bit.
.
foo bar.
-- .
Dipl.-Inform. Tassilo Horn                   | Room:  B015.
University of Koblenz-Landau, Campus Koblenz | Phone: +49 (261) 287-2745.
Institute for Software Technology            | Mail: horn@uni-koblenz.de.
Universit..tsstr. 1, 56070 Koblenz, Germany   |.
..

#
T 141.26.64.5:119 -> 141.26.67.142:53478 [AP]
240 Article posted <87hbkc3c0j.fsf@thinkpad.tsdh.de>.

#
--8<---------------cut here---------------end--------------->8---

In that case, the select method definition is:

--8<---------------cut here---------------start------------->8---
(add-to-list 'gnus-secondary-select-methods
             '(nntp "Uni"
                    (nntp-address "news.uni-koblenz.de")))
--8<---------------cut here---------------end--------------->8---

So it seems to be a TLS issue.  Do you see what's wrong?  I have to
admit that except knowing that this only happens with a TLS stream, I
cannot see what's wrong.

I can only say that some weeks ago, it just worked fine, and I didn't
change my gnus setup.

Does anyone use NNTP over a TLS stream and check if that hang can be
reproduced with other servers?

Bye,
Tassilo