Problem with version released 18’Th of Feb

May 11, 2009 at 11:26 AM

Hi

First of all; thanks for all the efforts making development of custom crawlers a bit easier!

I’m new to the concept so you have to excuse my question if it’s kind of stupid. Anyway; we need to develop a custom crawler and before digging into the development part of it I need to verify that the example you have provided does work.

All versions prior to 18’Th of February 2009 works well, but the one released the 18’Th (and later ones) doesn’t.

I have included the complete content of the mssdmn.exe log in this message. We’re running MOSS 2007 (x64) on Windows 2003.

Any idea what might go wrong? The GetChunck logic seems to be updated a bit, so it might be in this area the error occurs? The crawler log says “The filtering process has been terminated”, and I have included the interesting part of the SP logs below.

Any help or advice would be very much appreciated.

Regards
Mats

[Extract from SharePoint Logs begin]

05/11/2009 12:29:25.87  w3wp.exe (0x038C)                        0x0C5C Search Server Common           MS Search Administration       8wn6 Information A full crawl was started on 'Test' by CORPNET\sysmoss. 
05/11/2009 12:29:26.95  mssdmn.exe (0x0B80)                      0x12CC ULS Logging                    Unified Logging Service        8wsv High     ULS Init Completed (mssdmn.exe, Microsoft.Office.Server.Native.dll) 
05/11/2009 12:29:27.46  mssdmn.exe (0x0B80)                      0x12CC SharePoint Portal Server       Business Data                  0 Medium   CBdcProtocolHandler::Init() 
05/11/2009 12:29:27.46  mssdmn.exe (0x0B80)                      0x12CC SharePoint Portal Server       Business Data                  0 Medium   CBdcProtocolHandler::Init()
05/11/2009 12:29:29.35  mssearch.exe (0x0478)                    0x0EC0 Search Server Common           GatherSvc                      0 Monitorable TraceHealthStatus application 'ed33f012-4bdf-40c6-9e72-9ed79d295fb6': Everything appears OK - File:d:\office\source\search\search\gather\gthrsvc\gthrapp.cxx Line:5552 
05/11/2009 12:29:30.14  mssdmn.exe (0x0B80)                      0x0924 Search Server Common           Exceptions                     0 Monitorable Exception caught at  - File:d:\office\source\search\common\pkmutild\memthrow.cxx Line:108 
05/11/2009 12:29:30.14  mssdmn.exe (0x0B80)                      0x0924 Search Server Common           Common                         0 Assert   d:\office\source\search\common\pkmutild\memthrow.cxx(110) 
05/11/2009 12:29:30.14  mssdmn.exe (0x0B80)                      0x0924 Search Server Common           Exceptions                     0 Monitorable <Exception><HR>0xc0000005</HR><eip>000000003003E90B</eip><module>d:\office\source\search\common\pkmutild\memthrow.cxx</module><line>124</line></Exception> 
05/11/2009 12:29:30.17  mssdmn.exe (0x0B80)                      0x12CC Search Server Common           PHSts                          0 Monitorable ***** V3 Cache statistics: committed=32595968, UserCatalogCaches=0 - File:d:\office\source\search\search\gather\protocols\sts3\sts3util.hxx Line:171 
05/11/2009 12:29:30.17  mssdmn.exe (0x0B80)                      0x12CC Search Server Common           PHSts                          0 Monitorable ***** V3 Cache statistics: servers=0, serverhit=0, servermiss 0 - File:d:\office\source\search\search\gather\protocols\sts3\sts3util.hxx Line:172 
05/11/2009 12:29:30.17  mssdmn.exe (0x0B80)                      0x12CC Search Server Common           PHSts                          0 Monitorable ***** V3 Cache statistics: sites=0, sitehit=0, sitemiss 0 - File:d:\office\source\search\search\gather\protocols\sts3\sts3util.hxx Line:173 
05/11/2009 12:29:30.17  mssdmn.exe (0x0B80)                      0x12CC Search Server Common           PHSts                          0 Monitorable ***** V3 Cache statistics: webs=0, webhit 0, webmiss 0 - File:d:\office\source\search\search\gather\protocols\sts3\sts3util.hxx Line:174 
05/11/2009 12:29:30.17  mssdmn.exe (0x0B80)                      0x12CC Search Server Common           PHSts                          0 Monitorable ***** V3 Cache statistics: lists=0, listhit 0, listmiss 0 - File:d:\office\source\search\search\gather\protocols\sts3\sts3util.hxx Line:175 
05/11/2009 12:29:30.17  mssdmn.exe (0x0B80)                      0x12CC Search Server Common           PHSts                          0 Monitorable ***************** Remove V2 cache - File:d:\office\source\search\search\gather\protocols\sts2\sts2util.cxx Line:80 
05/11/2009 12:29:30.17  mssdmn.exe (0x0B80)                      0x12CC Search Server Common           PHSts                          0 Monitorable ***** V2 Cache statistics: committed=32595968, UserCatalogCaches=0 - File:d:\office\source\search\search\gather\protocols\sts2\sts2util.hxx Line:153 
05/11/2009 12:29:30.17  mssdmn.exe (0x0B80)                      0x12CC Search Server Common           PHSts                          0 Monitorable ***** V2 Cache statistics: servers=0, serverhit=0, servermiss 0 - File:d:\office\source\search\search\gather\protocols\sts2\sts2util.hxx Line:154 
05/11/2009 12:29:30.17  mssdmn.exe (0x0B80)                      0x12CC Search Server Common           PHSts                          0 Monitorable ***** V2 Cache statistics: sites=0, sitehit=0, sitemiss 0 - File:d:\office\source\search\search\gather\protocols\sts2\sts2util.hxx Line:155 
05/11/2009 12:29:30.17  mssdmn.exe (0x0B80)                      0x12CC Search Server Common           PHSts                          0 Monitorable ***** V2 Cache statistics: webs=0, webhit 0, webmiss 0 - File:d:\office\source\search\search\gather\protocols\sts2\sts2util.hxx Line:156 
05/11/2009 12:29:30.17  mssdmn.exe (0x0B80)                      0x12CC Search Server Common           PHSts                          0 Monitorable ***** V2 Cache statistics: lists=0, listhit 0, listmiss 0 - File:d:\office\source\search\search\gather\protocols\sts2\sts2util.hxx Line:157 
05/11/2009 12:29:30.18  mssdmn.exe (0x0B80)                      0x12CC ULS Logging                    Unified Logging Service        8wsw High     Now terminating ULS (mssdmn.exe, Microsoft.Office.Server.Native.dll) 
05/11/2009 12:29:30.31  mssdmn.exe (0x0E84)                      0x02BC ULS Logging                    Unified Logging Service        8wsv High     ULS Init Completed (mssdmn.exe, Microsoft.Office.Server.Native.dll) 
[Extract from SharePoint Logs end]


[mssdmn.exe log begin]

5/11/2009 12:29:29 PM, 002944-000001, Verbose: MOSSPH.ProtocolHandler::Init enter
5/11/2009 12:29:29 PM, 002944-000001, Info: Initializing protocol handler. Agent: Mozilla/4.0 (compatible; MSIE 4.01; Windows NT; MS Search 5.0 Robot)
5/11/2009 12:29:29 PM, 002944-000001, Verbose: MOSSPH.ProtocolHandler::Init leave, duration: 00:00:00.1718926
5/11/2009 12:29:29 PM, 002944-000003, Verbose: MOSSPH.ProtocolHandler::CreateAccessor enter (mossph://lkpoidevtest7 [0000000000000000])
5/11/2009 12:29:29 PM, 002944-000003, Info: Creating ContentEnumerator
5/11/2009 12:29:29 PM, 002944-000003, Verbose: MOSSPH.ContentEnumerator::Init enter (mossph://lkpoidevtest7)
5/11/2009 12:29:29 PM, 002944-000003, Verbose: Opening XML file: C:\Program Files\Microsoft Office Servers\12.0\bin\lkpoidevtest7.xml
5/11/2009 12:29:30 PM, 002944-000003, Verbose: MOSSPH.ContentEnumerator::Init leave, duration: 00:00:00.5625576
5/11/2009 12:29:30 PM, 002944-000003, Verbose: Last modified: 1/1/2000 12:00:00 AM (328262246429316066)
5/11/2009 12:29:30 PM, 002944-000003, Verbose: MOSSPH.Accessor::Init enter
5/11/2009 12:29:30 PM, 002944-000003, Info: Accessor::Init(mossph://lkpoidevtest7/)
5/11/2009 12:29:30 PM, 002944-000003, Verbose: MOSSPH.Accessor::Init leave, duration: 00:00:00, data: 0
5/11/2009 12:29:30 PM, 002944-000003, Verbose: MOSSPH.ProtocolHandler::CreateAccessor leave, duration: 00:00:00.5938108, data: 0
5/11/2009 12:29:30 PM, 002944-000003, Verbose: MOSSPH.Accessor::GetDocFormat enter
5/11/2009 12:29:30 PM, 002944-000003, Verbose: MOSSPH.Accessor::GetDocFormat leave, data: E_NOTIMPL
5/11/2009 12:29:30 PM, 002944-000003, Verbose: MOSSPH.Accessor::GetCLSID enter
5/11/2009 12:29:30 PM, 002944-000003, Verbose: MOSSPH.Accessor::GetCLSID leave, data: E_NOTIMPL
5/11/2009 12:29:30 PM, 002944-000003, Verbose: MOSSPH.Accessor::GetCLSID enter
5/11/2009 12:29:30 PM, 002944-000003, Verbose: MOSSPH.Accessor::GetCLSID leave, data: E_NOTIMPL
5/11/2009 12:29:30 PM, 002944-000003, Verbose: MOSSPH.Accessor::GetHost called
5/11/2009 12:29:30 PM, 002944-000003, Verbose: MOSSPH.Accessor::IsDirectory called (True)
5/11/2009 12:29:30 PM, 002944-000003, Verbose: MOSSPH.Accessor::GetSize enter
5/11/2009 12:29:30 PM, 002944-000003, Verbose: MOSSPH.Accessor::GetSize leave
5/11/2009 12:29:30 PM, 002944-000003, Verbose: MOSSPH.Accessor::GetLastModified enter
5/11/2009 12:29:30 PM, 002944-000003, Verbose: mossph://lkpoidevtest7/, content date: 1/1/2000 12:00:00 AM
5/11/2009 12:29:30 PM, 002944-000003, Verbose: MOSSPH.Accessor::GetLastModified leave
5/11/2009 12:29:30 PM, 002944-000003, Verbose: MOSSPH.Accessor::GetRedirectedURL called
5/11/2009 12:29:30 PM, 002944-000003, Verbose: MOSSPH.Accessor::BindToStream enter
5/11/2009 12:29:30 PM, 002944-000003, Verbose: MOSSPH.Accessor::BindToStream leave, data: E_NOTIMPL
5/11/2009 12:29:30 PM, 002944-000003, Verbose: MOSSPH.Accessor::GetFileName called
5/11/2009 12:29:30 PM, 002944-000003, Verbose: MOSSPH.Accessor::GetSecurityProvider called
5/11/2009 12:29:30 PM, 002944-000003, Verbose: MOSSPH.Accessor::GetSecurityDescriptor enter
5/11/2009 12:29:30 PM, 002944-000003, Verbose: MOSSPH.ContentEnumerator::SecurityDescriptor-create enter
5/11/2009 12:29:30 PM, 002944-000003, Verbose: MOSSPH.ContentEnumerator::SecurityDescriptor-create leave, duration: 00:00:00, data: Length: (null)
5/11/2009 12:29:30 PM, 002944-000003, Verbose: MOSSPH.Accessor::GetSecurityDescriptor leave, data: E_NOTIMPL
5/11/2009 12:29:30 PM, 002944-000003, Verbose: MOSSPH.Accessor::BindToFilter called
5/11/2009 12:29:30 PM, 002944-000003, Verbose: MOSSPH.Accessor::Init enter
5/11/2009 12:29:30 PM, 002944-000003, Verbose: MOSSPH.Accessor::Init leave
5/11/2009 12:29:30 PM, 002944-000003, Verbose: MOSSPH.Accessor::GetChunk enter
5/11/2009 12:29:30 PM, 002944-000003, Verbose: Adding DIRLINK_WITH_TIME chunk: mossph://lkpoidevtest7/container1 (328262246429316066)
5/11/2009 12:29:30 PM, 002944-000003, Verbose: MOSSPH.Accessor::GetChunk leave, data: S_OK
5/11/2009 12:29:30 PM, 002944-000003, Verbose: MOSSPH.Accessor::GetValue enter
5/11/2009 12:29:30 PM, 002944-000003, Verbose: MOSSPH.Accessor::GetValue leave, data: S_OK
5/11/2009 12:29:30 PM, 002944-000003, Verbose: MOSSPH.ProtocolHandler::CloseAccessor enter
5/11/2009 12:29:30 PM, 002944-000003, Info: Closing Accessor: mossph://lkpoidevtest7/
5/11/2009 12:29:30 PM, 002944-000003, Verbose: MOSSPH.Accessor::Close enter
5/11/2009 12:29:30 PM, 002944-000003, Info: ContentEnumerator terminated
5/11/2009 12:29:30 PM, 002944-000003, Verbose: MOSSPH.Accessor::Close leave
5/11/2009 12:29:30 PM, 002944-000003, Verbose: MOSSPH.ProtocolHandler::CloseAccessor leave
5/11/2009 12:29:30 PM, 002944-000001, Verbose: MOSSPH.ProtocolHandler::ShutDown called

[mssdmn.exe log end]

 

May 12, 2009 at 6:30 AM

A quick update;

By reverting the method GetChunk to a version prior to the 18'th of feb it now works. Don't have time to investigate it any further right now...

May 25, 2009 at 9:21 AM
Edited May 25, 2009 at 9:23 AM

I've been digging into this for a couple of days now and have located the problem.

It gives an error on containers when the GetValue returns a DIRLINK_WITH_TIME. When I change the code to DIRLINK everyhing works like a charm.

So this goes wrong:

PropSpec.guidPropSet = PROPSET_GATHERER.GUID;
PropSpec.psProperty = new PROPSPEC();
PropSpec.psProperty.ulKind = PSKIND.PROPID;
PropSpec.psProperty.data.propid = (uint)PROPSET_GATHERER.PID.DIRLINK_WITH_TIME;

PROPVARIANT_URL_VECTOR uv = new PROPVARIANT_URL_VECTOR();
uv.Url = new PROPVARIANT();
uv.Url.vt = (VARTYPE)VarEnum.VT_LPWSTR;
uv.Url.union = new PROPVARIANT_UNION();
uv.Url.union.pwszVal = Marshal.StringToCoTaskMemUni((string)url);
uv.LastModified = new PROPVARIANT();
uv.LastModified.vt = (VARTYPE)VarEnum.VT_FILETIME;
uv.LastModified.union = new PROPVARIANT_UNION();
uv.LastModified.union.filetime = COMInterop.DateTimeToFileTime(lastModified);

PropVariant = new PROPVARIANT();
PropVariant.vt = (VARTYPE)(VarEnum.VT_VECTOR | VarEnum.VT_VARIANT);
PropVariant.union = new PROPVARIANT_UNION();
PropVariant.union.capropvar = new CAPROPVARIANT();
PropVariant.union.capropvar.cElems = 2;
PropVariant.union.capropvar.pElems = Marshal.AllocCoTaskMem(Marshal.SizeOf(uv));
Marshal.StructureToPtr(uv, PropVariant.union.capropvar.pElems, false);

But this goes right:

PropSpec.guidPropSet = PROPSET_GATHERER.GUID;
PropSpec.psProperty = new PROPSPEC();
PropSpec.psProperty.ulKind = PSKIND.PROPID;
PropSpec.psProperty.data.propid = (uint)PROPSET_GATHERER.PID.DIRLINK;

PropVariant = new PROPVARIANT();
PropVariant.vt = (VARTYPE)VarEnum.VT_LPWSTR;
PropVariant.union = new PROPVARIANT_UNION();
PropVariant.union.pwszVal = Marshal.StringToCoTaskMemUni((string)url);

I'm now trying to test the same code on x86.

 

May 25, 2009 at 10:15 AM

I can now confirm that the DIRLINK_WITH_TIME works on x86 but fails on x64.

Somehow the structure is of a different size in memory then the service is expecting, I think I'll have to check on every int, lon, etc.

Anybody with suggestions, please provide :)

May 25, 2009 at 1:21 PM
Edited May 25, 2009 at 2:28 PM

OK, I think I got it, if you change the following:

[StructLayout(LayoutKind.Sequential, Pack=1)]

above the struct:

public struct CAPROPVARIANT
{
    public ULONG cElems;
    public IntPtr pElems; // Pointer to a single PROPVARIANT or an array of PROPVARIANT structures.
}

To:

[StructLayout(LayoutKind.Sequential, Pack=0)]
The pointer size will be 4 on x86 and 8 on x64. I changed all Pack=1 into Pack=0 and seems to work. Time for a patch :)

Uploaded the IUrlAccessor as patch

May 27, 2009 at 10:08 PM

Thanks! Will try...

Best regards
Mats

Jun 29, 2009 at 3:44 PM

Hi,

Sorry for the late update. Just wanted to mention that the new code works well.

Thank you
Mats

Aug 12, 2009 at 3:33 PM

Just wanted to chime in that this fixed the issues I was having on x64.  Nice work Mats!

Thanks,

Patrick