[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

[leafnode-list] SIGPIPE Issues



I'm running 1.9.20.rc7, and have set debugemode = 1.

I have not received any "Broken Pipe" messages with this version, but
fetchnews still terminates abnormally, particularly on long runs, and
still fails to update /var/spool/news/leaf.node/SERVERNAME with the
correct numbers when that happens.  Here is what it said...

[root@{WORSTATION} news]# fetchnews -nvv
1.9.20.rc7: verbosity level is 2
Don't automatically unsubscribe unread newsgroups.
Trying to connect to {SERVERNAME}:2000 ... connected.
Getting new newsgroups from {SERVERNAME}
Read server info from /var/spool/news/leaf.node/{SERVERNAME}
{GROUP 1}: considering articles 23631-30565
Disconnected from {SERVERNAME}
[root@{WORKSTATION} news]# 

Certain information has been edited due to internal paranoia ploicy, edits
are contained within curly-braces.

The log (news.debug) says...

Mar 19 02:35:23 shire fetchnews[26161]: 1.9.20.rc7: verbosity level is 2
Mar 19 02:35:23 shire fetchnews[26161]: config: debugmode is 1
Mar 19 02:35:26 shire fetchnews[26161]: Last LIST ACTIVE done 73562 seconds ago: NEWGROUPS
Mar 19 02:35:26 shire fetchnews[26161]: connected to {SERVER IP}: 200
Mar 19 02:35:26 shire fetchnews[26161]: >MODE READER^M
Mar 19 02:35:26 shire fetchnews[26161]: >NEWGROUPS 020318 233500 GMT^M
Mar 19 02:35:28 shire fetchnews[26161]: >XGTITLE alt.binaries.nospam.hipcrime^M
Mar 19 02:35:28 shire fetchnews[26161]: >XGTITLE alt.binaries.pictures.erotica.spam.hipcrime^M
Mar 19 02:35:29 shire fetchnews[26161]: >XGTITLE alt.binaries.sounds.mp3.nospam.hipcrime^M
Mar 19 02:35:29 shire fetchnews[26161]: >XGTITLE alt.creative^M
Mar 19 02:35:30 shire fetchnews[26161]: >XGTITLE alt.bestjobsua.minnesota.jobs^M
Mar 19 02:35:30 shire fetchnews[26161]: >XGTITLE cn.sci.polymers^M
Mar 19 02:35:31 shire fetchnews[26161]: >XGTITLE alt.binaries.multimedia.erotica.gay^M
Mar 19 02:35:31 shire fetchnews[26161]: >XGTITLE alt.binaries.multimedia.erotica.gay.d.moderated^M
Mar 19 02:35:32 shire fetchnews[26161]: >XGTITLE pn.take5.archive^M
Mar 19 02:35:32 shire fetchnews[26161]: >XGTITLE fr.misc.enfants.bebes^M
Mar 19 02:35:32 shire fetchnews[26161]: >XGTITLE fr.rec.beaute-mode^M
Mar 19 02:35:33 shire fetchnews[26161]: >XGTITLE async^M
Mar 19 02:35:33 shire fetchnews[26161]: Read server info from /var/spool/news/leaf.node/{SERVERNAME}
Mar 19 02:35:33 shire fetchnews[26161]: >GROUP {GROUP 1}^M
Mar 19 02:35:33 shire fetchnews[26161]: >XOVER 23631-30565^M
Mar 19 02:37:50 shire fetchnews[26161]: {GROUP 1} 23631: reply 500 No server having article is reachable
Mar 19 02:38:35 shire fetchnews[26161]: {GROUP 1} 23632: reply 500 No server having article is reachable

This goes on for a while, since the server we are connecting to is a sort
of a caching server (NewsPlex) and it's overview is a little behind.  The
actual acticles have expired on the downstream servers.  This is made
worse beacuse some or all of these articles have already been fetched and
expired by leafnode (fetchnews and texpire, respectively) Eventually we
see...

Mar 19 02:53:57 shire fetchnews[26161]: {GROUP 1} 23996: reply 500 No server having article is reachable
Mar 19 02:53:57 shire fetchnews[26161]: {GROUP 1} 23997: reply 500 No server having article is reachable
Mar 19 02:53:58 shire fetchnews[26161]: {GROUP 1} 24025: reply 500 No server having article is reachable
Mar 19 02:53:58 shire fetchnews[26161]: {GROUP 1} 24104: reply 500 No server having article is reachable
Mar 19 02:54:44 shire fetchnews[26161]: >BODY 24226^M
Mar 19 02:54:47 shire fetchnews[26161]: >HEAD 24227^M
Mar 19 02:54:47 shire fetchnews[26161]: >BODY 24227^M
Mar 19 02:54:50 shire fetchnews[26161]: >HEAD 24228^M
Mar 19 02:54:50 shire fetchnews[26161]: >BODY 24228^M

Now we are fecthing real articles.  Not sure, however, if we have seen 
them before.  Finally, when it terminates...


Mar 19 03:47:56 shire fetchnews[26161]: >HEAD 27556^M
Mar 19 03:47:56 shire fetchnews[26161]: >BODY 27556^M
Mar 19 03:48:02 shire fetchnews[26161]: >HEAD 27557^M
Mar 19 03:48:03 shire fetchnews[26161]: >BODY 27557^M
Mar 19 03:58:08 shire fetchnews[26161]: >GROUP {GROUP 2}^M
Mar 19 03:58:08 shire fetchnews[26161]: >GROUP {GROUP 3}^M
Mar 19 03:58:08 shire fetchnews[26161]: >GROUP {GROUP 4}^M
Mar 19 03:58:08 shire fetchnews[26161]: >GROUP {GROUP 5}^M
Mar 19 03:58:08 shire fetchnews[26161]: >GROUP {GROUP 6}^M
Mar 19 03:58:08 shire fetchnews[26161]: >GROUP {GROUP 7}^M
Mar 19 03:58:08 shire fetchnews[26161]: >GROUP {GROUP 8}^M
Mar 19 03:58:09 shire fetchnews[26161]: >GROUP {GROUP 9}^M
Mar 19 03:58:09 shire fetchnews[26161]: >QUIT^M
Mar 19 03:58:11 shire fetchnews[27012]: Process forked.
Mar 19 03:58:12 shire fetchnews[27012]: reading XOVER info from /var/spool/news/{GROUP 1}/91928
Mar 19 03:58:12 shire fetchnews[27012]: reading XOVER info from /var/spool/news/{GROUP 1}/91929
Mar 19 03:58:12 shire fetchnews[27012]: reading XOVER info from /var/spool/news/{GROUP 1}/91930
Mar 19 03:58:13 shire fetchnews[27012]: reading XOVER info from /var/spool/news/{GROUP 1}/91931


Three things to point out.  

First, fetchnews should have fetched a lot more articles in {GROUP 1}.

Second, it's likely Groups 2 thru 9 really had no articles.  I had just
subscribed to them, and NewsPlex needs a few minutes to explore the
downstream servers before any actual articles are present.  I am running
fetchnews as we speak, and this time it's picking up articles in all the 
groups, and it appears to have to completeed {GROUP 1} successfully.

I'd wait for it to finish, but I have to get to work, and I want to post 
this SOMETIME before the final release.

Third is just a minor logging issue.  I am connecting to {SERVERNAME} port 
2000, but the log reported it as port 200.

Finally, is there something I should be doing which will give you more
information about this?

Thanks,
Michael O'Quinn



-- 
leafnode-list@xxxxxxxxxxxxxxxxxxxxxxxxxxxx -- mailing list for leafnode
To unsubscribe, send mail with "unsubscribe" in the subject to the list