Help → POPFile 1.1.3 nntp and Virginmedia's news server
What I have: POPFile v1.1.3 on Ubuntu 12.04, with the nntp module enabled.
I suspect it only works if you are connecting via a Virgin Media line, but their news server does not require authentication:
$ telnet news.virginmedia.com 119 Trying 81.171.92.236... Connected to newsfarm.ams2.highwinds-media.com. Escape character is '^]'. 200 Welcome to Virgin Media help 100 Legal Commands article [<messageid>|number] authinfo type value body [<messageid>|number] date group newsgroup head [<messageid>|number] help last list [active wildmat|active.times|counts wildmat] list [overview.fmt|newsgroups wildmat] listgroup newsgroup mode reader next post stat [<messageid>|number] xhdr field [range] xover [range] xpat field range pattern xfeature useragent <client identifier> quit . list 215 NewsGroups Follow 0 2313358 2313350 y (( lots of newsgroup details deleted! )) zzz.3 3052 22 y . quit 205 Goodbye Connection closed by foreign host.
So I have set the news reader up with
Server: 127.0.0.1
User: news.virginmedia.com:
Password: (none)
However, although it appears to communicate with the news server, nothing is returned. I have tried this with both Thunderbird and XPN news readers.
popfile.log, logging level 2, on attempting to get a list of newsgroups on XPN:
2012/5/5 18:18:17 29310: mq: 227: Parent: postfork() called for pid 30744, reader GLOB(0x9067d70) 2012/5/5 18:18:17 30744: bayes: 811: Attempting to connect to dbi:SQLite:dbname=/var/lib/popfile/popfile.db (1) 2012/5/5 18:18:17 30744: bayes: 912: Using SQLite library version 3.7.9 2012/5/5 18:18:17 30744: bayes: 512: Performing tweak 1 to 1 2012/5/5 18:18:17 30744: nntp: 311: 201 NNTP POPFile (v1.1.3) server ready[0d][0a] 2012/5/5 18:18:17 30744: nntp: 209: Command: --mode reader-- 2012/5/5 18:18:17 30744: nntp: 311: 480 Authorization required for this command[0d][0a] 2012/5/5 18:18:17 30744: nntp: 209: Command: --authinfo user XXXXXX 2012/5/5 18:18:17 30744: nntp: 541: Attempting to connect to POP server at news.virginmedia.com:119 2012/5/5 18:18:17 30744: nntp: 557: Connected to news.virginmedia.com:119 timeout 60 2012/5/5 18:18:17 30744: nntp: 605: Connection returned: 200 Welcome to Virgin Media[0d][0a] 2012/5/5 18:18:17 30744: nntp: 311: 381 password[0d][0a] 2012/5/5 18:18:17 30744: mq: 380: post CMPLT (30744) 2012/5/5 18:18:17 30744: mq: 395: sending post CMPLT (30744) to parent GLOB(0x90a1bf8) 2012/5/5 18:18:17 30744: nntp: 619: NNTP proxy done 2012/5/5 18:18:17 29310: mq: 380: post CMPLT (30744) 2012/5/5 18:18:17 29310: mq: 391: dropping post CMPLT (30744) 2012/5/5 18:18:17 29310: mq: 259: Done with 30744 (0 to go)
.. and with Thunderbird:
2012/5/5 15:05:20 29310: mq: 227: Parent: postfork() called for pid 29324, reader GLOB(0x8bb1aec) 2012/5/5 15:05:20 29324: bayes: 811: Attempting to connect to dbi:SQLite:dbname=/var/lib/popfile/popfile.db (1) 2012/5/5 15:05:20 29324: bayes: 912: Using SQLite library version 3.7.9 2012/5/5 15:05:20 29324: bayes: 512: Performing tweak 1 to 1 2012/5/5 15:05:20 29324: nntp: 311: 201 NNTP POPFile (v1.1.3) server ready[0d][0a] 2012/5/5 15:05:20 29324: nntp: 209: Command: --MODE READER-- 2012/5/5 15:05:20 29324: nntp: 311: 480 Authorization required for this command[0d][0a] 2012/5/5 15:05:20 29324: nntp: 209: Command: --AUTHINFO user XXXXXX 2012/5/5 15:05:20 29324: nntp: 541: Attempting to connect to POP server at news.virginmedia.com:119 2012/5/5 15:05:20 29324: nntp: 557: Connected to news.virginmedia.com:119 timeout 60 2012/5/5 15:05:20 29324: nntp: 605: Connection returned: 200 Welcome to Virgin Media[0d][0a] 2012/5/5 15:05:20 29324: nntp: 311: 381 password[0d][0a] 2012/5/5 15:05:24 29324: nntp: 209: Command: --QUIT-- 2012/5/5 15:05:24 29324: nntp: 311: QUIT[0d][0a] 2012/5/5 15:05:24 29324: nntp: 659: Read slurp data 205 Goodbye[0d][0a] 2012/5/5 15:05:24 29324: nntp: 311: 205 Goodbye[0d][0a] 2012/5/5 15:05:24 29324: mq: 380: post CMPLT (29324) 2012/5/5 15:05:24 29324: mq: 395: sending post CMPLT (29324) to parent GLOB(0x906802c) 2012/5/5 15:05:24 29324: nntp: 619: NNTP proxy done 2012/5/5 15:05:24 29310: mq: 380: post CMPLT (29324) 2012/5/5 15:05:24 29310: mq: 391: dropping post CMPLT (29324) 2012/5/5 15:05:24 29310: mq: 259: Done with 29324 (0 to go)
Any suggestions?
-
Message #1652
Try changing the NNTP separator from the default of : to /
You can do this via the POPFile UI using either the CONFIGURATION page (in NNTP section look for 'NNTP host:port:user separator character' option) or the ADVANCED page (look for the 'nntp_separator' parameter).
After clicking the 'Apply' or 'Update' button shut down POPFile and restart it to make sure it uses the new setting.
Change the newsreader 'User' from news.virginmedia.com: to news.virginmedia.com/
Does this solve the problem (or at least change what appears in the level 2 log)?
Edit: I should have thought a bit longer before I wrote this reply!
brian05/06/12 15:44:55 -
-
Message #1653
Thanks - it changes it in the sense that it no longer connects successfully :)
XPN:
2012/5/6 14:48:35 32360: mq: 227: Parent: postfork() called for pid 32378, reader GLOB(0x94eed04) 2012/5/6 14:48:35 32378: bayes: 811: Attempting to connect to dbi:SQLite:dbname=/var/lib/popfile/popfile.db (1) 2012/5/6 14:48:35 32378: bayes: 912: Using SQLite library version 3.7.9 2012/5/6 14:48:35 32378: bayes: 512: Performing tweak 1 to 1 2012/5/6 14:48:35 32378: nntp: 311: 201 NNTP POPFile (v1.1.3) server ready[0d][0a] 2012/5/6 14:48:35 32378: nntp: 209: Command: --mode reader-- 2012/5/6 14:48:35 32378: nntp: 311: 480 Authorization required for this command[0d][0a] 2012/5/6 14:48:35 32378: nntp: 209: Command: --authinfo user XXXXXX 2012/5/6 14:48:35 32378: nntp: 541: Attempting to connect to POP server at news.virginmedia.com/:119 2012/5/6 14:48:35 32378: nntp: 626: IO::Socket::INET or IO::Socket::SSL gets an error: IO::Socket::INET: Bad hostname 'news.virginmedia.com/' 2012/5/6 14:48:35 32378: nntp: 311: 500 can't connect to news.virginmedia.com/:119[0d][0a] 2012/5/6 14:48:35 32378: mq: 380: post CMPLT (32378) 2012/5/6 14:48:35 32378: mq: 395: sending post CMPLT (32378) to parent GLOB(0x94eecdc) 2012/5/6 14:48:35 32378: nntp: 619: NNTP proxy done 2012/5/6 14:48:35 32360: mq: 380: post CMPLT (32378) 2012/5/6 14:48:35 32360: mq: 391: dropping post CMPLT (32378) 2012/5/6 14:48:35 32360: mq: 259: Done with 32378 (0 to go)
Thunderbird:
2012/5/6 14:58:37 32360: mq: 227: Parent: postfork() called for pid 435, reader GLOB(0x94e8c78) 2012/5/6 14:58:37 435: bayes: 811: Attempting to connect to dbi:SQLite:dbname=/var/lib/popfile/popfile.db (1) 2012/5/6 14:58:37 435: bayes: 912: Using SQLite library version 3.7.9 2012/5/6 14:58:37 435: bayes: 512: Performing tweak 1 to 1 2012/5/6 14:58:37 435: nntp: 311: 201 NNTP POPFile (v1.1.3) server ready[0d][0a] 2012/5/6 14:58:37 435: nntp: 209: Command: --MODE READER-- 2012/5/6 14:58:37 435: nntp: 311: 480 Authorization required for this command[0d][0a] 2012/5/6 14:58:52 435: nntp: 209: Command: --AUTHINFO user XXXXXX 2012/5/6 14:58:52 435: nntp: 541: Attempting to connect to POP server at news.virginmedia.com/:119 2012/5/6 14:58:52 435: nntp: 626: IO::Socket::INET or IO::Socket::SSL gets an error: IO::Socket::INET: Bad hostname 'news.virginmedia.com/' 2012/5/6 14:58:52 435: nntp: 311: 500 can't connect to news.virginmedia.com/:119[0d][0a] 2012/5/6 14:58:52 435: mq: 380: post CMPLT (435) 2012/5/6 14:58:52 435: mq: 395: sending post CMPLT (435) to parent GLOB(0x952150c) 2012/5/6 14:58:52 435: nntp: 619: NNTP proxy done 2012/5/6 14:58:52 32360: mq: 380: post CMPLT (435) 2012/5/6 14:58:52 32360: mq: 391: dropping post CMPLT (435) 2012/5/6 14:58:52 32360: mq: 259: Done with 435 (0 to go)
Just to confirm, popfile.cfg has
nntp_enabled 1 nntp_force_fork 1 nntp_headtoo 0 nntp_local 1 nntp_port 1119 nntp_separator / nntp_socks_port 1080 nntp_socks_server nntp_welcome_string NNTP POPFile (v1.1.3) server ready
I've also tried setting the separator to = and z with a similar lack of success - it tries connecting to news.virginmedia.comz in the latter case, for example.
lovingboth05/06/12 16:14:20 -
-
Message #1654
Sorry about my previous reply; I should have looked a bit longer at the code before I replied. My excuse is that I'm not a Perl programmer.
Go back to using : for the NNTP separator, i.e. undo the changes I suggested in my previous reply (which I have now edited).
The "nntp: 311: 381 password[0d][0a]" entries in the first set of log files are generated by the NNTP proxy when the proxy finds that the modified username does not contain a server username, just the server name (e.g. news.virginmedia.com:)
This "381 password" request is returned to the client and should make it respond with a password which the NNTP proxy ignores (i.e. it does not send the password to the news server). The NNTP proxy then returns a "281 authentication accepted" response to the client.
The first Thunderbird log file shows:
2012/5/5 15:05:20 29324: nntp: 311: 381 password[0d][0a]
2012/5/5 15:05:24 29324: nntp: 209: Command: --QUIT--
2012/5/5 15:05:24 29324: nntp: 311: QUIT[0d][0a]
2012/5/5 15:05:24 29324: nntp: 659: Read slurp data 205 Goodbye[0d][0a]
2012/5/5 15:05:24 29324: nntp: 311: 205 Goodbye[0d][0a]
so it looks to me that when Thunderbird got the "381 password" request it issued a QUIT command. This may be because there was no password defined in Thunderbird for this account.
Try defining a password for this account in Thunderbird (e.g. Password: dummy). Perhaps Thunderbird will accept the "281 authentication accepted" response from the NNTP proxy and actually access the news server now?
brian05/06/12 16:26:14
-
-
