Newsbin gets stuck processing one group

[shawn]

I'm having a strange issue with processing one newsgroup, alt.binaries.warez. I downloaded all headers for the newsgroup and now when I try to show headers for that newsgroup Newsbin just sits and spins on that group. It never displays the actual data but continues to use up all of one core (sitting at around 52-53% CPU usage.)

I thought maybe the storage DB was corrupted so I deleted all headers for the group from within Newsbin Pro (6.5 Beta 3) and downloaded headers again. Same problem showed up so I decided to try cutting down the number of headers since NB was sitting around 2GB of memory being used (even though I have 4GB installled and this is Win8 64bit and NBP 64bit) so it seemed like that might be an issue. So I started lowering both the download/display/storage age limits from the 1000 day limit I had originally. First I tried 500 without any luck, so I cut it down to 300 and did the purge/compact process and restarted NBP to get the same problem when I tried to load up the newsgroup.

So I set the limits down to 200 days and did the purge/compact routine on alt.binaries.warez and restarted NBP. When I tried to load up the newsgroup the same thing happened (CPU still sat around 51-52% while memory usage for NBP had dropped to around 1.3GB so it was making a difference in how many headers NBP was processing.) I left NBP working on it overnight thinking it might be an issue with processing spam but NBP still wasn't displaying any headers for that group and was still chewing up the CPU.
No other newsgroup shows this issue.

It doesn't seem to be any sort of hardware issue since I see no errors doing anything else including using NBP for other newsgroups. It doesn't seem to be a disk issue since I've recreated the header DBs, checked the HD and used it for other things without errors. I'm starting to suspect there's something (sort of strange header) that is in this newsgroup that is causing NBP to get lost.

Any suggestions as to how to proceed?

[DThor]

Apart from any potential bug you may have found, check the cache at the middle bottom of the display. If there's a number in brackets, and I'm guessing there is, that's an indication of inserts that still need to be done to the spool before you can get an up to date view. Just the fact you mentioned newsbin gobbling up 2G of memory means you're talking a really large amount of headers. Trying to display them before processing is done can lead to some serious thrashing. I would just open newsbin and let it finish(bracketed number goes away) rather than trying to look at something simultaneously. I'm guessing, but could be wrong, that you're pushing your computer pretty hard, usenet is huge, and I very very rarely come close to eating up that much memory in a session. Doesn't mean you *can't*, but you'll be wanting a serious internal IO pipe for that.

DT

[shawn]

The Cache value shows 186/200, That's before I even try to open any newsgroup. Choosing to open doesn't change that value. I've been letting NBP sit without any newsgroup open and it isn't changing. Even after an hour it is still the same. I'm confused because it sounds like you are suggesting it should be going down on it's own.

[Quade]

Cache X/Y (XXX)

It's the paren number we're curious about. It represents files needing import into the header database.

In the data folder, look in the "Import" folder and see if you see a bunch of files listed.

[shawn]

There is none listed (no parens and no number other than the 186/200. As for the Import directory I'm guessing you mean Newsbin/Import. There are no files listed in that directory.

[pipboy_3000]

I am also experiencing this exact same issue. The blue refresh bar moves across and just stops shy of the end of the row. It does update "New Files" and "Last updated" -it just doesn't show any actual headers. The tab remains blank. E.g. a.b.newgroup:(0).

This issue started after upgrading from 6.50B2 to 6.50B3. I had no problems with 6.50B2.

Cache is [190/200] and my cpu is stuck at 25% using around 3GB+ memory.

[Quade]

Sounds like Newsbin is importing records at the same time you're trying to view them. Same question for you. Number in Parens down at the cache line?

There is none listed (no parens and no number other than the 186/200. As for the Import directory I'm guessing you mean Newsbin/Import. There are no files listed in that directory.

Keep that folder open, then download all headers again and see if any files land in that folder. You should see files with no extensions and then they get renamed with a GZ extension.

[pipboy_3000]

Sounds like Newsbin is importing records at the same time you're trying to view them. Same question for you. Number in Parens down at the cache line?

No number is shown in parenthesis next to the Cache xx/yy.

Keep that folder open, then download all headers again and see if any files land in that folder. You should see files with no extensions and then they get renamed with a GZ extension.

This occurs exactly as you explain it above. File get imported, extension is added and then the file is deleted leaving the folder empty.

[Quade]

It means the records are getting imported properly. I don't really have an answer then. It's working here and seems to be working there.

What's your storage and display age set to?

Do you have any kind of filters set or filter profiles assigned to the group?

[shawn]

I ended up deleting the group and starting over but the same issue is occurring. There are no files in the Import directory and the Cache listing is 186/200 with nothing in parens. Newsbin is chewing away on a single core at 52% CPU usage (dual core system.) Currently I'm at 100 days for download age, 150 days for display age and 150 days for storage age. I don't have any filters enabled currently.

(Only filters I even have defined are to block exe and files with a subject containing German.)

[Quade]

150 days for storage age.

Basically, you're telling Newsbin to throw away 90% of the headers you download. You're downloading them and Newsbin is tossing any headers older than 150 days.

Just for grins, set it to 1700 days. Restart Newsbin and then re-download headers again.

[pipboy_3000]

What's your storage and display age set to?

Display age is 700 days and storage is 900 days.

Do you have any kind of filters set or filter profiles assigned to the group?

No filters or filter profiles.

I tried reinstalling 6.50B2 right over 6.50B3 without deleting any groups or headers and it works perfectly again. I believe that something was introduced in 6.50B3 causing the display headers problem.

[shawn]

Quade, I deleted the headers again, and then downloaded the latest 500,000. Then I tried to display those headers. This is with the download set to 100 days (but I only downloaded the latest 500,000) and the display/storage set to 1000 days (which shouldn't matter since there's probably only a days worth of headers in that 500,000 headers.)

With only 500,000 headers I don't see the problem. I do see NBP spending a minute dealing with insertion of headers since the cache showed 186/200 (1) but once it was done the headers did display.

[Quade]

Got another report similar to yours though. Makes me the think something is up.

[pipboy_3000]

Quade

I just wanted to follow up and let you know the new B4 version is working for me.

Thanks!

[stavros]

hi Quade,

I've just upgraded to 6.50B8 (from 6.42) and I am experiencing very slow header updates, as mentioned by others, above.

I've also noticed that the sequence in which the headers for groups are being imported has changed, so that the groups later in my group list, seem to be being processed before the ones earlier in my group list - I think that this was a planned change (in relnotes - 6.50 Alpha 2 Build 2452).

I think that this import change may be contributing to the problem e.g. for a.b.warez - there were 3 .gz files each > 70MB and the one with the highest message numbers got processed first, then some other groups got processed, then the next lower number range for a.b.warez, then a few other groups then the last of the a.b.warez .gz was processed - this all took over 3 hours to complete - way longer than the usual 10 - 15 mins for me, with 6.42.

For info, the storarge.db3 is 10.8 GB and the storagedata.db3 is 20.2 GB in size.
Storage age is 5000, display age is 7, no groups/headers are being displayed during this process.
Cache 199/200 (356), with the (nnn) decreasing slowly, as the import process continues.

Is it possible, somehow, to revert the header import sequence back to the way it was before - process the headers in the order in which the groups are listed in the group list and the order in which the headers are downloded?

regards
Stavros.

[Quade]

The goal eventually is to feed the group you're currently looking at in the display first. Doesn't seems like you're reporting a performance problem, though you do have a bunch waiting for import, rather you just seem to want to change the order.

I suspect if I implement "feed in the headers for the currently displayed group" first that will solve it.

[stavros]

Thanks Quade, that would help a lot, but there is definately a performance problem here - the header updates continued for more than 12 hours before I stopped the currently running set of updates by shutting down Newsbin.

I moved all of the .gz file that were greater than 3 MB in size to another directory, leaving 181 left to prcoess, then restarted Newsbin. The updates then took another 2 hours to complete, but without getting 'stuck' on a single group for a time significantly longer than any of the others.

However, this entire process has taken the best part of 18 hours to process a set of headers that would normally take no more than about 45 minutes on my setup with 6.42.

I am defragging the hard drive that holds the spool & import directories, just in case the files have reached some threshold level of fragmentation that triggers this processing delay. I'll re-try some of the saved headers after the defrag is completed and see if it happens again.

I checked newsbin64.exe with process explorer while it was in the 'stuck state' processing the large (>70MB) .gz for a.b.warez and saw that it was reaching a constant state of 129MB private bytes and a constant reading of 92MB second for more than 15 mins before before I gave up and stopped monitoring - not sure what this means....

When I restarted newsbin, having moved the larger .gz files out of the import directory, and checked with process explorer, the pattern of private bytes was different (saw tooth, rising to a peak, then dropping) along with a low read/write # bytes, with the occasional peak corresponding with the drop in the saw tooth. I assume that this is how it should be, when things are being processed 'normally'.

Either way, after I re-test 6.50B8 after the defrag, I'll regress back to 6.42 and do a comparison and post an update.

Is there anyting that I should look for to help in diagnosing/isolating what's happening here? Any advice appreciated.

regards
Stavros.

[stavros]

Hi Quade,

It took a while to make space on the hard drive and de-frag...but finally got the a.b.warez storage.db3 in to 2 fragments (10.8GB) and the storagedata.db3 (20.3GB). Of course, I don't know how the data inside the .db3 files is organised.

I re-ran the 6.50B8 update using the same file (alt.binaries.warez-Giganews-1032195535-1033195535.gz) - I left it running for 25 minutes before stopping it. The pattern of I/O and memory usage in process explorer matched what I had seen before I de-fragged the drive. On checking the .db3 files, they had not grown in size or gained more fragments.

I re-installed version 6.42 over the top of 6.50B8. It was my intention to re-run the header load test, but I then realised that the .gz file was in a different format than the .rv4 files that 6.42 used, so I downloaded latest headers for a.b.warez. This caused 10.6 Million headers to be downloaded in 246 .rv4 files, numbered from Giganews-250795990.RV4 to Giganews-252238687.RV4.
DownloadRecords - Total XOVER Size:alt.binaries.warez - 1034279427:1044896812

I monitored the processing of these headers, and left it running until completed. It took 1 hour 20 mins. During the update, the I/O rate rose to 30MB/s for 20 seconds, the rest of the time it stayed, on average, about 8MB/s. CPU remained below 50%. On checking the .db3 files, storage.db3 remained the same size, but storagedata.db3 had grown by about 60MB and to 147 fragments.

I'm not sure what all this really means - but if I interpret the numbers correctly - the 6.50B8 .gz had 1 million header range and did not complete after 25 mins, while the 6.42 had a 10.6 million header range that took 80 minutes to complete, so I'd expect the 6.50B8 to complete in less than 8 minutes.

Anyway, for now, I'm going to stay with 6.42, unless you'd like me to carry out any more tests.

regards
Stavros.

[Quade]

Switching back and forth is likely to cause this. 6.50 uses different indexes than 6.42 so, each time you switch, the DB gets re-indexed. The fact it's not changing sizes suggests it's indexing.

[stavros]

OK, thanks Quade. This was the first time I'd switched back from a more recent release to an earlier one.

Are there any tools available that can verify the integrity of the .db3 files in a newsbin installation? (Especially the group related files - storage.db3, storagedata.db3, range.db3.)

Some of these .db3 files are getting really large, as I try to keep all headers that are downloaded. I'm worried that, at some point, some of these group .db3 files will become corruped somehow, and then my only option will be to re-download the whole of a group all over again - or as many headers as are then available from my news service. I'd rather try to recover from any corruption, if at all possible. Current message base is about 600GB.

regards
Stavros.

[orygun]

Re all the slow- I, too, am experiencing a sudden slowdown in two groups-- large ones, that used to only take 15 or so minutes to process but now these are take two and three-four hours respectfully.

None of my setting have changed for my groups (days kept/download/etc.,) for the last several years.

Currently on the B8. This started a a week or two ago.

Returned previous version, deleted groups, ran for a couple days, same problem.

Back on B8. Up to hour 5 on the big problem group.

Win7-64 pro...