Tag: bugs

Posted on

Office Web Apps – Word Viewing Service Error

All of a sudden, we started having issues with our Office Web Apps install for a set of users.  No reason, no changes, just some users can't use OWA to VIEW files (they can however edit the files in the browser).  The service account for the application pool and the word viewing app pool both have dbo on the content database in question.

Here's the errors:

User:

Word Web App cannot open this document for viewing because of an unexpected error.  To view this document, open it in Microsoft Word.

WFE:

 05/23/2012 07:56:55.17  w3wp.exe (0x32CC)                        0x310C Office Web Apps                Office Viewing Architecture    dg2s Medium   RequestDispatcher: response received for document F4813f0a0691d4d61a109e9ab86a17815m4d776f4fd83844328210cf1c84e667cbm06ebaf2e1684459c9c00819543a2a08em from http://servername:32843/69c32f311e164e8184803a179b32d194/Conversion.svc. d3e88a2a-977b-48df-a70a-4765c4ff1ac9
05/23/2012 07:56:55.19  w3wp.exe (0x32CC)                        0x310C Office Web Apps                Office Viewing Architecture    b4vn Medium   Conversion response received: CantFindSourceDocument d3e88a2a-977b-48df-a70a-4765c4ff1ac9
05/23/2012 07:56:55.19  w3wp.exe (0x32CC)                        0x310C Office Web Apps                Office Viewing Architecture    b4vi Verbose  DocumentInfoCache.RemoveDocumentInfo: docId=d=F4813f0a0691d4d61a109e9ab86a17815m4d776f4fd83844328210cf1c84e667cbm06ebaf2e1684459c9c00819543a2a08em&z=06EBAF2E-1684-459C-9C00-819543A2A08E1, outputFormat=_v00000000-0000-0000-0000-000000000202 d3e88a2a-977b-48df-a70a-4765c4ff1ac9
05/23/2012 07:56:55.19  w3wp.exe (0x32CC)                        0x310C Office Web Apps                Office Viewing Architecture    vjza Medium   Librarian.OnConversionResponseReceived(F4813f0a0691d4d61a109e9ab86a17815m4d776f4fd83844328210cf1c84e667cbm06ebaf2e1684459c9c00819543a2a08em, Png, docdata.xml) – Response=CantFindSourceDocument, Data=NO d3e88a2a-977b-48df-a70a-4765c4ff1ac9
05/23/2012 07:56:55.20  w3wp.exe (0x32CC)                        0x310C Office Web Apps                Office Viewing Architecture    vjzo Medium   Librarian.SetCompleted(F4813f0a0691d4d61a109e9ab86a17815m4d776f4fd83844328210cf1c84e667cbm06ebaf2e1684459c9c00819543a2a08em, Png, docdata.xml) – status = ConversionError d3e88a2a-977b-48df-a70a-4765c4ff1ac9

APP:

05/23/2012 07:56:55.57  w3wp.exe (0x1330)                        0x0B6C Office Web Apps                Office Viewing Architecture    bv6l Medium   DownloadManager: Starting download for document F4813f0a0691d4d61a109e9ab86a17815m4d776f4fd83844328210cf1c84e667cbm06ebaf2e1684459c9c00819543a2a08em. d3e88a2a-977b-48df-a70a-4765c4ff1ac9
05/23/2012 07:56:55.57  w3wp.exe (0x1330)                        0x0B6C Office Web Apps                Office Performance Tracing     dcw3 Verbose  PerfCounterAverageTimer started: WssStorageReadTime d3e88a2a-977b-48df-a70a-4765c4ff1ac9
05/23/2012 07:56:55.57  w3wp.exe (0x1330)                        0x0B6C SharePoint Foundation          General                        6t8j Verbose  Site lookup by id found the typical site /training. d3e88a2a-977b-48df-a70a-4765c4ff1ac9
05/23/2012 07:56:55.57  w3wp.exe (0x1330)                        0x0B6C SharePoint Foundation          General                        8kh7 High     Cannot complete this action.  Please try again. d3e88a2a-977b-48df-a70a-4765c4ff1ac9
05/23/2012 07:56:55.58  w3wp.exe (0x1330)                        0x0B6C SharePoint Foundation          General                        8kh7 High     Stack trace: onetutil.dll: (unresolved symbol, module offset=00000000000A2551) at 0x000007FEF0142551 onetutil.dll: (unresolved symbol, module offset=00000000000A3711) at 0x000007FEF0143711 owssvr.dll: (unresolved symbol, module offset=0000000000009212) at 0x000007FEF0399212 owssvr.dll: (unresolved symbol, module offset=0000000000044378) at 0x000007FEF03D4378 mscorwks.dll: (unresolved symbol, module offset=00000000002CB6D7) at 0x000007FEF9BFB6D7 Microsoft.SharePoint.Library.ni.dll: (unresolved symbol, module offset=00000000000E5128) at 0x000007FEF2D85128 Microsoft.SharePoint.ni.dll: (unresolved symbol, module offset=0000000001AB43D0) at 0x000007FEE0AA43D0 Microsoft.SharePoint.ni.dll: (unresolved symbol, module offset=0000000001AA811D) at 0x000007FEE0A9811D Microsoft.SharePoint.ni.dll: (unre… d3e88a2a-977b-48df-a70a-4765c4ff1ac9
05/23/2012 07:56:55.58* w3wp.exe (0x1330)                        0x0B6C SharePoint Foundation          General                        8kh7 High     …solved symbol, module offset=0000000001AADC71) at 0x000007FEE0A9DC71 Microsoft.SharePoint.ni.dll: (unresolved symbol, module offset=0000000001AA2A25) at 0x000007FEE0A92A25 Microsoft.SharePoint.ni.dll: (unresolved symbol, module offset=0000000001AA4717) at 0x000007FEE0A94717 Microsoft.SharePoint.ni.dll: (unresolved symbol, module offset=0000000001AA46A2) at 0x000007FEE0A946A2  d3e88a2a-977b-48df-a70a-4765c4ff1ac9
05/23/2012 07:56:55.58  w3wp.exe (0x1330)            &nbs
p;           0x0B6C Office Web Apps                Office Viewing Architecture    ekp1 Medium   No SPFile found for Id 06ebaf2e-1684-459c-9c00-819543a2a08e d3e88a2a-977b-48df-a70a-4765c4ff1ac9
05/23/2012 07:56:55.58  w3wp.exe (0x1330)                        0x0B6C Office Web Apps                Office Viewing Architecture    ekp3 Medium   SharepointReaderAsync: No SPFile provided d3e88a2a-977b-48df-a70a-4765c4ff1ac9
05/23/2012 07:56:55.58  w3wp.exe (0x1330)                        0x0B6C Office Web Apps                Office Performance Tracing     a495 Verbose  PerfCounterAverageTimer stopped: WssStorageReadTime, elapsed time = 20 milliseconds d3e88a2a-977b-48df-a70a-4765c4ff1ac9
05/23/2012 07:56:55.58  w3wp.exe (0x1330)                        0x0B6C Office Web Apps                Office Viewing Architecture    bv6p Unexpected Exception thrown downloading file C:WindowsTEMPwaccache69c32f31-1e16-4e81-8480-3a179b32d194domainuserca171873-6de3-4dd4-abef-09d23996d26coutput.docx: System.ArgumentException: SharepointReaderAsync: no SPFile     at Microsoft.Office.Web.Environment.Sharepoint.SharepointReaderAsync.End()     at Microsoft.Office.Web.Conversion.Framework.DownloadManager.OnFileReadComplete(IAsyncResult ar) d3e88a2a-977b-48df-a70a-4765c4ff1ac9
05/23/2012 07:56:55.58  w3wp.exe (0x1330)                        0x0B6C Office Web Apps                Office Viewing Architecture    fvj9 Unexpected DownloadManager: Download FAILED for document F4813f0a0691d4d61a109e9ab86a17815m4d776f4fd83844328210cf1c84e667cbm06ebaf2e1684459c9c00819543a2a08em; Time spent: 24ms. d3e88a2a-977b-48df-a70a-4765c4ff1ac9

The only possible hints lie in the users access (this says it is request view and edit access but the user doesn't have it):

05/23/2012 07:56:54.20  w3wp.exe (0x32CC)                        0x2B94 SharePoint Foundation          General                        ewn8 Verbose  OriginalPermissionMask check failed. asking for 0x00000005, have 0xB008431041 9806faaf-ad37-406f-9164-5705a9aca938

You'll also find several errors about configuration settings missing for the Word Viewing settings:

05/23/2012 07:56:54.30  w3wp.exe (0x32CC)                        0x2B94 Office Web Apps                Office Web Apps Configuration  bbw9 Verbose  Trying to get setting C2ROFFERENABLED 9806faaf-ad37-406f-9164-5705a9aca938
05/23/2012 07:56:54.30  w3wp.exe (0x32CC)                        0x2B94 Office Web Apps                Office Web Apps Configuration  bbx0 Verbose  Tried to obtain setting C2ROFFERENABLED but it does not exist in the list of known settings for this environment. 9806faaf-ad37-406f-9164-5705a9aca938
05/23/2012 07:56:54.30  w3wp.exe (0x32CC)                        0x2B94 Office Web Apps                Office Web Apps Configuration  bbw9 Verbose  Trying to get setting WLSIAOFFERENABLED 9806faaf-ad37-406f-9164-5705a9aca938
05/23/2012 07:56:54.30  w3wp.exe (0x32CC)                        0x2B94 Office Web Apps                Office Web Apps Configuration  bbx0 Verbose  Tried to obtain setting WLSIAOFFERENABLED but it does not exist in the list of known settings for this environment. 9806faaf-ad37-406f-9164-5705a9aca938
05/23/2012 07:56:54.31  w3wp.exe (0x32CC)                        0x2B94 Office Web Apps                Office Web Apps Configuration  bbw9 Verbose  Trying to get setting USEPARENTHELPFUNCTION 9806faaf-ad37-406f-9164-5705a9aca938
05/23/2012 07:56:54.31  w3wp.exe (0x32CC)                        0x2B94 Office Web Apps                Office Web Apps Configuration  bbx0 Verbose  Tried to obtain setting USEPARENTHELPFUNCTION but it does not exist in the list of known settings for this environment. 9806faaf-ad37-406f-9164-5705a9aca938
05/23/2012 07:56:54.31  w3wp.exe (0x32CC)                        0x2B94 Office Web Apps                Office Web Apps Configuration  bbw9 Verbose  Trying to get setting SHOWFEEDBACKLINK 9806faaf-ad37-406f-9164-5705a9aca938
05/23/2012 07:56:54.31  w3wp.exe (0x32CC)                        0x2B94 Office Web Apps                Office Web Apps Configuration  bbx0 Verbose  Tried to obtain setting SHOWFEEDBACKLINK but it does not exist in the list of known settings for this environment. 9806faaf-ad37-406f-9164-5705a9aca938
05/23/2012 07:56:54.33  w3wp.exe (0x32CC)                        0x2B94 Office Web Apps                Office Web Apps Configuration  bbw9 Verbose  Trying to get setting HIDETITLE 9806faaf-ad37-406f-9164-5705a9aca938
05/23/2012 07:56:54.33  w3wp.exe (0x32CC)                        0x2B94 Office Web Apps     
           Office Web Apps Configuration  bbx0 Verbose  Tried to obtain setting HIDETITLE but it does not exist in the list of known settings for this environment. 9806faaf-ad37-406f-9164-5705a9aca938
05/23/2012 07:56:54.33  w3wp.exe (0x32CC)                        0x2B94 Office Web Apps                Office Web Apps Configuration  bbw9 Verbose  Trying to get setting MACOFFICETRIALOFFERENABLED 9806faaf-ad37-406f-9164-5705a9aca938
05/23/2012 07:56:54.33  w3wp.exe (0x32CC)                        0x2B94 Office Web Apps                Office Web Apps Configuration  bbx0 Verbose  Tried to obtain setting MACOFFICETRIALOFFERENABLED but it does not exist in the list of known settings for this environment. 9806faaf-ad37-406f-9164-5705a9aca938
05/23/2012 07:56:54.33  w3wp.exe (0x32CC)                        0x2B94 Office Web Apps                Office Web Apps Configuration  bbw9 Verbose  Trying to get setting TRIMOICBUTTONSIFUNAVAILABLE 9806faaf-ad37-406f-9164-5705a9aca938
05/23/2012 07:56:54.33  w3wp.exe (0x32CC)                        0x2B94 Office Web Apps                Office Web Apps Configuration  bbx0 Verbose  Tried to obtain setting TRIMOICBUTTONSIFUNAVAILABLE but it does not exist in the list of known settings for this environment. 9806faaf-ad37-406f-9164-5705a9aca938
05/23/2012 07:56:54.33  w3wp.exe (0x32CC)                        0x2B94 Office Web Apps                Office Web Apps Configuration  bbw9 Verbose  Trying to get setting WORDWEBAPPSHORTRESOURCENAME 9806faaf-ad37-406f-9164-5705a9aca938
05/23/2012 07:56:54.33  w3wp.exe (0x32CC)                        0x2B94 Office Web Apps                Office Web Apps Configuration  bbw9 Verbose  Trying to get setting WORDWEBAPPFULLRESOURCENAME 9806faaf-ad37-406f-9164-5705a9aca938

What have I done so far?  Here's the things I have tried: 

  1. I created a new Word Viewing Service and set it as the default service application.  Had the user retry…the documents still didn't display in OWA and I still get all the wonderful OWA settings are missing messages (so the messages can be ignored) – NO GO
  2. I gave the user contribute access, had them re-try…still didn't display in OWA, but at least a new button showed up on the error that lets them "Open in Word" (realized this happens after the second attempt to open the file) – NO GO
  3. Last ditch effort, added the app pool for the OWA conversion service to the local WSS_ADMIN_WPG…NO GO.
  4. Made the user a site collection admin – NO GO  

Weird that it only applies to a small set of users.  It shouldn't matter that they just have View Only rights to the file, it should open in OWA…again editing works just fine…

Sooo…how did I fix this?  I went to the handy SQL Profiler tool and watched the SQL traffic.  I re-run all the queries and looked at all the results sets that were returned.  I opened the OWA dlls in Reflecter and explored every method call.  I found the "no SPFile" returned set of code, everything looks file, but, it is the hint that I was looking for.  Stepping back, one should ask…why is the file not being returned?  It is there, but…it isn't?  In looking at the result sets, I found something interesting.  Once upon a time, users had enabled the DocumentID feature of sharepoint.  This assigned document ids to some of the documents.  They also are using this tool called "CopyPaste".  When copying a record from one site collection to another, the document ID values were being replicated to the new location and metadata of the files.  When OWA makes the call to get the file, it is going through the SharePoint APIs and in this case, the document ID is wrong and the site that used to hold the file is gone (or in some cases not accessible by the user because we removed their permissions)!  Document IDs suck and this is just another reason to use my SharePoint Durable Urls tool (http://www.sharepointdurableurls.com). That means…if you hit the document id link for the file, you get simple html that says "File Not Found".  BINGO!  Now…how to remove the DocumentID residual?  Here's what I did:

foreach($li in $list.items)
{
$docid = $li["Document ID"]

if ($docid)
{
"Found doc id in " + $li["Name"]
"ID is: $docid"

$li.file.checkout()
$li["Document ID"] = ""
$li.update()
$li.file.checkin("Removed Document ID")
}
}

Yet another case of the code making one call (View is using the DocumentID redirect) in one instance and another in another instance (Editing does not use the DocumentID redirect).  Very annoying.

Enjoy!
Chris

Follow me on twitter: @givenscj

Check out the previous blog post:
https://blogs.architectingconnectedsystems.com/blogs/cjg/archive/2012/05/18/Announcing-_2D00_-ACS-Rebate-and-Charity-Event.aspx

Posted on

ATTENTION: Database Leak in SharePoint 2010!!!

I have been doing a massive Oracle Portal migration, 3000+ pages of content, with a targeted subset of that in my dev envrionment at just over 3GB of content.  I noticed the other day that my development content database kept getting bigger and bigger.  Running a "dbcc checkdb" pointed me to the largest tables.  After clearing the Audit logs, EventLogs and everything else I could think of, then shrinking the database files, the databse size was still WAY bigger than what it was supposed to be (it should be 35GB, but it is currently 72GB).  The dbcc command pointed to the AllDocStreams table as the source of the problem.  I thought it possible the new web recycle bin may be the culprit, so I set out to find the root cause and prove to the community that "Redmond, we have a problem"

My first test was to create a web and then delete it over and over again.  That didn't change the row sizes in the database.  Next test was to do the same thing, only add a document to the doc library.  That didn't cause any leaks.  The last step was to enable versioning and to upload a document a few times, then delete the webs…VIOLA!  Found the leak!  Want to try this on your own…here is the PowerShell that proves that we have a big issue here:

function CheckRows($table, $conn)
{
$sql = "select count(*) as count from $table";
$cmd = new-object system.data.sqlclient.sqlcommand($sql, $conn)

$reader = $cmd.executereader()

while($reader.read())
{
$line = $reader["count"].tostring()
}

$reader.close()

"$table has " + $line + " rows"
}

function ReportRowCounts($cdb)
{

$connString = $cdb.LegacyDatabaseConnectionString

$conn = new-object system.data.sqlclient.sqlconnection
$conn.connectionstring = $connstring
$conn.open()

CheckRows "AllDocs" $conn
CheckRows "AllDocStreams" $conn
CheckRows "AllDocVersions" $conn

$conn.close()

}

function UploadFile($web)
{

$list = $web.lists["Shared Documents"]
$list.EnableModeration = $true
$list.EnableMinorVersions = $true
$list.contenttypesenabled = $true
$list.update()

$spFolder = $list.rootfolder
$spFileCollection = $spFolder.Files
$file = get-item "c:scriptsexport.zip"
$spfile = $spFileCollection.Add($file.name,$file.OpenRead(),$true)
$spfile.checkout()
$spfile.checkin("checkin")
$spfile.approve("approved")

}

$cdb = get-spcontentdatabase "WSS_Content_Contoso"
$web = get-spweb http://www.contoso.com

ReportRowCounts($cdb)

#create a site
$subweb = $web.webs.add("Test1", "Test1", "", 1033, "STS#0", $false, $false);

ReportRowCounts($cdb)

$subweb.delete()

ReportRowCounts($cdb)

$subweb = $web.webs.add("Test1", "Test1", "", 1033, "STS#0", $false, $false);
UploadFile $subweb
UploadFile $subweb
UploadFile $subweb
UploadFile $subweb
UploadFile $subweb

ReportRowCounts($cdb)

$subweb.delete()

ReportRowCounts($cdb)

You will see the AllDocStreams table continues to get larger and larger.  This is the table that has your BLOBS!  The worst table to have a database leak!  From a high level, what does this mean?  It means if you turn on versioning, and say upload a 1Gb file and then make 5 changes to it, you will have 5GB of storage used in your database.  If you then delete the web, you will lose file pointers in the database and that 5GB will remain in the database forever and never get cleaned up.  Now, how likely is it that you are creating and deleting webs in production?  Not too many people will have a fancy process setup like this, but in Development and QA, you will.  I can't afford to keep restorting a "clean" copy of my development databases everytime it gets too big.

NOTE:  This bug shows up in all builds after SP1 (the web recycle build), my environment is the latest release build of 14.6112.5000.

Here's how to determine if you are having a problem and how BIG it is:

$global:count = 0
$global:size = 0

function CheckDatabase($cdb)
{
$connString = $cdb.LegacyDatabaseConnectionString
$conn = new-object system.data.sqlclient.sqlconnection
$conn.connectionstring = $connstring
$conn.open()

$sql = "select count(*) as count, sum(datalength(content)) as size from alldocstreams where id not in (select id from alldocs)";
$cmd = new-object system.data.sqlclient.sqlcommand($sql, $conn)
$reader = $cmd.executereader()

while($reader.read())
{
$count = [double]::parse($reader["count"].tostring())
$size = [double]::parse($reader["size"].tostring())

}

$reader.close()
$conn.close()

$global:Count += $count
$global:size += $size

}

$cdbs = get-spcontentdatabase

foreach ($cdb in $cdbs)
{
CheckDatabase $cdb
}

"Orphaned rows: " + $global:count
"Orphaned rows size: " + $global:size + " bytes"

Microsoft…you need to get us a cumulative updatehot fix RIGHT NOW.

UPDATE:  AUGUST 2012 Cumulative Update fixes this bug:
http://technet.microsoft.com/en-us/sharepoint/ff800847.aspx

Not one to say enjoy too, but at least I know what is going on now and so do you!
Chris

Follow me on twitter: @givenscj

Check out the previous blog post:
https://blogs.architectingconnectedsystems.com/blogs/cjg/archive/2012/04/20/Project-Server-PSI-WCF-bug-_2D00_-WSEC_5F00_CAT_5F00_UID-and-WSEC_5F00_GRP_5F00_UID.aspx