Index failure

[mickelingon]

Hi

I'm going tp post a case here that I can't figure out.
I've already opened a case with Symantec but not much help from there, so I'm asking your advice.

It's a EV 8 SP4 running on Win 2008 R2
It's regarding filearchiving.

We tested an archive at the start of the setup and it worked fine.
I've been doing installations in big EV environments for three years but haven't seen such a problem that you could not correct with a rebuild.

I've tried update, repair and rebuild, and it works for a couple of hours and then failes again, not being able to conduct searches.
Antivirus is excluded from scanning indexes.

The logs in the eventvwr are:
Event ID 7235

A low level indexing operation has failed

Error: Filter error [AV:24]

Index Id: 171245972904B7D41B7D886071B8C8FCB1110000evserver1/Volume:4 (U7000)

 Event ID 7187
 

 

Could not add Indexable Item and Per-user data to Index: Unspecified error [0x80004005]

Internal reference: 171245972904B7D41B7D886071B8C8FCB1110000evserver1/Volume:4 (U7000)

Additional Info: AltaVista error

 Event ID7235
 

A low level indexing operation has failed

Error: Filter error [AV:24]

Index Id: 171245972904B7D41B7D886071B8C8FCB1110000evserver1/Volume:4 (U7000)

   Eve nt  ID7180
 

     

Could not access indexable item: Not enough storage is available to complete this operation. [0x8007000e]

Internal reference: PFS/ce

Event ID 7284
 

Failed to add item to the index due to failure loading the item's index metadata.

Reason: Could not access indexable item: Internal reference: [0xc0041c0c]

Index Id: 171245972904B7D41B7D886071B8C8FCB1110000evserver1/Volume:4 (U7000)

Saveset Id: 201007249994166~200601181419480000~Z~B1588AAE93EF68D2B24A4470093C4871

Internal reference: II load

Event ID 7313
 

Failed to commit Index updates to disk.

Reason: Not enough storage is available to complete this operation. [0x8007000e]

Index Id: 171245972904B7D41B7D886071B8C8FCB1110000evserver1/Volume:4 (U7000)

Index Path: G:\Index\index3\171245972904B7D41B7D886071B8C8FCB1110000evserver1

Available Disk Space: 2036749372 KB(2036749372 KB)

Number of Items added: 7329

Number of Items deleted: 0

Number of Items updated: 0

Number of new words: 500010

Additional Info: Makestable

Vers:-1 Mem Load:1311211 (Max:1310720) KB

There are enough space for both archive and idexes, so that can't be the problem.
We have 1.8 TB for indexes left and are using medium indexing level. The share we are archiving is 2TB only running for 3 hours every night so there wont be much to index

I also get these logs in the index location:
AVTrace log:

Tue Sep 07 10:31:57.612 2010 (thread:4660) backtrace: backtrace starts:
Tue Sep 07 10:31:57.612 2010 (thread:4660) backtrace: ..\indexlib\emalloc.c:27: (errno:12:Not enough space) (result:0x00000800) realloc
Tue Sep 07 10:31:57.612 2010 (thread:4660) backtrace: ..\indexlib\index.c:1968: (errno:12:Not enough space) (result:0x00000800)
Tue Sep 07 10:31:57.612 2010 (thread:4660) backtrace: ..\indexlib\index.c:3732: (errno:12:Not enough space) (result:0x00000800)
Tue Sep 07 10:31:57.627 2010 (thread:4660) backtrace: ..\indexlib\index.c:3785: (errno:12:Not enough space) (result:0x00000800)
Tue Sep 07 10:31:57.627 2010 (thread:4660) backtrace: ..\api\avs_open.c:661: (errno:12:Not enough space) (result:0x00000800) starting catch block
Tue Sep 07 10:31:57.627 2010 (thread:4660) backtrace: ..\api\avs_open.c:668: (errno:12:Not enough space) (result:0x00000800) no specific catch clause caught
Tue Sep 07 10:31:57.627 2010 (thread:4660) backtrace: backtrace completed.
Tue Sep 07 10:31:57.627 2010 (thread:4660) avs_makestable: error: can't allocate memory
Tue Sep 07 10:31:57.627 2010 (thread:4660) avs_getindexversion: locked out
Tue Sep 07 10:31:57.627 2010 (thread:4660) avs_getmaxloc: locked out
Tue Sep 07 10:31:57.659 2010 (thread:4660) avs_getindexversion: locked out
Tue Sep 07 10:31:57.659 2010 (thread:4660) avs_startdoc: locked out
Tue Sep 07 10:31:57.659 2010 (thread:4660) avs_getindexversion: locked out
Tue Sep 07 10:31:57.659 2010 (thread:4660) avs_getindexversion: locked out
Tue Sep 07 10:31:57.659 2010 (thread:4660) avs_startdoc: locked out
Tue Sep 07 10:31:57.659 2010 (thread:4660) avs_getindexversion: locked out
Tue Sep 07 10:31:57.768 2010 (thread:4660) avs_getindexversion: locked out
Tue Sep 07 10:31:57.768 2010 (thread:4660) avs_close: locked out
Tue Sep 07 10:31:57.768 2010 (thread:4660) avs_release_valtypes: locked out

IndexMissing log:

171245972904B7D41B7D886071B8C8FCB1110000evserver1/Volume:4
815175,201007250074931~200906250845140000~Z~A148F525B49B25B2620548C37A8A10A1,-1
813880,201007249994166~200601181419480000~Z~B1588AAE93EF68D2B24A4470093C4871,-1
815175,201007250074931~200906250845140000~Z~A148F525B49B25B2620548C37A8A10A1,-1
813880,201007249994166~200601181419480000~Z~B1588AAE93EF68D2B24A4470093C4871,-1
815175,201007250074931~200906250845140000~Z~A148F525B49B25B2620548C37A8A10A1,-1
813880,201007249994166~200601181419480000~Z~B1588AAE93EF68D2B24A4470093C4871,-1
815175,201007250074931~200906250845140000~Z~A148F525B49B25B2620548C37A8A10A1,-1
813880,201007249994166~200601181419480000~Z~B1588AAE93EF68D2B24A4470093C4871,-1
815175,201007250074931~200906250845140000~Z~A148F525B49B25B2620548C37A8A10A1,-1
813880,201007249994166~200601181419480000~Z~B1588AAE93EF68D2B24A4470093C4871,-1
815175,201007250074931~200906250845140000~Z~A148F525B49B25B2620548C37A8A10A1,-1
813880,201007249994166~200601181419480000~Z~B1588AAE93EF68D2B24A4470093C4871,-1
815175,201007250074931~200906250845140000~Z~A148F525B49B25B2620548C37A8A10A1,-1
813880,201007249994166~200601181419480000~Z~B1588AAE93EF68D2B24A4470093C4871,-1
815175,201007250074931~200906250845140000~Z~A148F525B49B25B2620548C37A8A10A1,-1
813880,201007249994166~200601181419480000~Z~B1588AAE93EF68D2B24A4470093C4871,-1
815175,201007250074931~200906250845140000~Z~A148F525B49B25B2620548C37A8A10A1,-1
813880,201007249994166~200601181419480000~Z~B1588AAE93EF68D2B24A4470093C4871,-1
815175,201007250074931~200906250845140000~Z~A148F525B49B25B2620548C37A8A10A1,-1
813880,201007249994166~200601181419480000~Z~B1588AAE93EF68D2B24A4470093C4871,-1
815175,201007250074931~200906250845140000~Z~A148F525B49B25B2620548C37A8A10A1,-1
813880,201007249994166~200601181419480000~Z~B1588AAE93EF68D2B24A4470093C4871,-1
815175,201007250074931~200906250845140000~Z~A148F525B49B25B2620548C37A8A10A1,-1
813880,201007249994166~200601181419480000~Z~B1588AAE93EF68D2B24A4470093C4871,-1
815175,201007250074931~200906250845140000~Z~A148F525B49B25B2620548C37A8A10A1,-1
813880,201007249994166~200601181419480000~Z~B1588AAE93EF68D2B24A4470093C4871,-1
815175,201007250074931~200906250845140000~Z~A148F525B49B25B2620548C37A8A10A1,-1
813880,201007249994166~200601181419480000~Z~B1588AAE93EF68D2B24A4470093C4871,-1

IndexCheck log:

Indexcheck executing 'Exist' check, running with ignorewarnings set, and checking for avtrace.log modified in the last 3 days
Start time: 2010-09-06 13:02:35
  Running with ignorewarnings set
Indexcheck executing 'Exist' check, running with ignorewarnings set, and checking for avtrace.log modified in the last 3 days
  Processing index folder g:\index\index3\12981B75F45D4CE4894736615A407B7C01110000evserver1
  Checking file existence...
  Completed OK. 91 lines
Indexcheck executing 'Exist' check, running with ignorewarnings set, and checking for avtrace.log modified in the last 3 days
  Processing index folder g:\index\index3\171245972904B7D41B7D886071B8C8FCB1110000evserver1
  Checking file existence...
  Completed OK. 94 lines
  WARNING! avtrace.log in g:\index\index3\171245972904B7D41B7D886071B8C8FCB1110000evserver1 has been modified in the last 3 day(s)
Indexcheck executing 'Exist' check, running with ignorewarnings set, and checking for avtrace.log modified in the last 3 days
  Processing index folder g:\index\index3\172D308048AAD87459B5C81CBCC37CC161110000evserver1
  Checking file existence...
  Completed OK. 91 lines
Indexcheck executing 'Exist' check, running with ignorewarnings set, and checking for avtrace.log modified in the last 3 days
  Processing index folder g:\index\index3\1B9E2D828F633E041A9FFD14525C8AC111110000evserver1
  Checking file existence...
  Completed OK. 91 lines
Indexcheck executing 'Exist' check, running with ignorewarnings set, and checking for avtrace.log modified in the last 3 days
  Processing index folder g:\index\index3\1E2136FC09DC04843BF8D917B8BD726961110000evserver1
  Checking file existence...
  Completed OK. 91 lines
Indexcheck executing 'Exist' check, running with ignorewarnings set, and checking for avtrace.log modified in the last 3 days
  Processing index folder g:\index\index3\1F48D51D006315B44B32ABF24E650CF151110000evserver1
  Checking file existence...
  Completed OK. 91 lines
Indexcheck executing 'Exist' check, running with ignorewarnings set, and checking for avtrace.log modified in the last 3 days
  Processing index folder g:\index\index8\1D23AB3F1EFF611488FD8329C9B1AFC551110000evserver1
  Checking file existence...
  Completed OK. 91 lines
  Finished. Checked 7 index(es), 0 with errors, 1 with warnings
End time: 2010-09-06 13:02:38
Duration: 0 minute(s) 2 second(s)

Any suggestions

Kind regards

Mike

[GertjanA]

Hi Mike,

I've seen these errors on mail-archiving also. Don't get thrown off by the 'not enough storage' looking at the file system, it seems to be a memory issue. Once we made sure all the vaultservers had 4 GB RAM, and a pagefile of at elast 4Gb, the errors went away. I still see the issue on 1 archives-index. My best option is to export the archive, delete the archive, import the archive (thus rebuilding the index...)
What also might be an issue is disk-latency. We had one server giving latency of high 2, finally proved that it was a raid misconfiguration....

I'm curious to what you find further.

[JesusWept3]

yup not enough storage space is always memory

[mickelingon]

Hi

We have increased the memory on the file archiving server to 8 GB but still the same problem. Any other thoughts.
Still no help from Symantec, last thing we did was setting a reg key, but it didn't help.

Mike

[Mohawk_Marvin]

are the indexes being replicated? Anything else going on with the index drive itself?

[AndrewB]

what storage device are you using for your indexes?

[JesusWept3]

it isn't a problem with the indexes itself, its the fact that the Indexable Item itself is just freakin massive and will overload how much space is allocated to the indexing servers themselves

the best thing you could do is stop as much in EV as you can , lower the indexing servers down to something ridiculous like 5 and then try and repair the index to have it try the item again.

Because Indexing by default launches up to i think 24 threads each with an allocated amount of space to perform its indexing actions, the more servers means less resources and when a large complex item comes in it can fail to index it

in this circumstance you have an item that most likely changed from its native format to html.

take the following example with something that is text

"         " <--- 8 spaces

HTML rendering turns 8 spaces into html space's which is

&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;

thats a lot more data than the 8 spaces held, you get that type of thing occuring over and over and what can start off as say a 20k text file turns in to a 4mb rendering


So lets really look at what the errors are telling us, first clue is the following:

Reason: Could not access indexable item: Internal reference: [0xc0041c0c]
.......
Internal reference: II load


Then later we see this
Vers:-1 Mem Load:1311211 (Max:1310720) KB

and then finally this:

Tue Sep 07 10:31:57.612 2010 (thread:4660) backtrace: ..\indexlib\emalloc.c:27: (errno:12:Not enough space) (result:0x00000800) realloc


If you look at where it says Mem Load it showing that the maximum allocated size is 1310720kb (1280MB or 1.25GB) but its already gone 400k over the maximum allocated size.

[AndrewB]

kudos for the excellent explanation

[Michael_Bilsbor]

Hi,

It is not just size that's the problem, as you can see it's the indexing engine itself(alta vista) which is complaining.  What you sometimes have (especially with File data) is 'weird' data which when index can overwhelm one of the files used by Alta Vista.  So when you get multiples of these items in memory and then written to disk that's when Alta Vista can get overwhelmed.  So for example the file is really 'data' and perhaps has thousands and thousands of words beginning with the letter 'A'

As a test you can set AVSNumWordsToWrite to say 50000(take a look at TN's before doing this) and it's quite possible EV will get past the item ok.  You need to set it back afterwards.

Mike

[JesusWept3 · Accepted solution]

I think it'd be helpful to know what troubleshooting steps support have performed thus far and what those registry keys they had you set were, and Mike is spot on as i forgot to take FSA in to account, but have seen numerous times where decreasing the numwordstowrite can have a dramatic impact.

typically though you wouldwant to reset it afterwards unless its a truly prominent problem that keeps occuring, however the default for NumWordsToWrite is 2,000,000 and where 50,000 could help the problem, you will introduce a level of much higher activity on the disk

So for instance, by default the indexing engine will commit what it has in memory to the indexes either every 15 minutes or every 2 million words.

In some circumstances you can reach 2 million words in 4 minutes, so based on that you could be writing to the disk every 30 seconds or perhaps even less

[rodriscoll]

  Watch your virtual bytes in perfmon they can be very high with alta vista may want to enlarge pagefile don't be shy make it large.  You can try this below on the collection just change the path to what you need. This will not harm the collection it is just regular maintaince.

avs_sample -i d:\collections\indexc20 -c compact

[rodriscoll]

I should mention collection has to be offline when you run that but it will just now allow you to run it if the collection is running.

[mickelingon]

Hi

We tried the NumWordsToWrite to 50,000 but no luck. Still getting the errors.
Then Sym. support had me set a value for Index Poison Pill and rebuild the index but no luck.

I wonder if I should just delete the index and reindex the volume? Or will I get in the same mess again?

I'm curious about JesusWepts explainasion about the "If you look at where it says Mem Load it showing that the maximum allocated size is 1310720kb (1280MB or 1.25GB) but its already gone 400k over the maximum allocated size. " How can I target this?

In other words, what actions should I take now.

Mike

[rodriscoll]

1.25 gig is about the max for a single 32 bit process before it crashes.

[mickelingon]

Okej, but can you do something about it? I understand the problem, but is there a solution?

Mike