Forum Discussion

Ralfeus's avatar
Ralfeus
Level 4
15 years ago

Can't open archived item in OWA

Hi everybody
I have a problem with opening archived items in OWA.
I have EV 2007 SP 2007 SP3 working with Exchange 2007 SP2. The infrastructure is separated to two large locations. SEV servers are in one site and Exchange server I have problem with is at another one.
When I try to open archived message in Outlook everything works fine. There is some time delay while downloading item from SEV server but it's ok.
When I open same item in OWA new window is opened and item is trying to be opened. It takes about 1 minute. Then only shortcut content is opened and notification showing the item is not available

When I click on the notification new window is opened with warning about redirection to another server (SEV one).

When I confirm the archived item is directly from SEV server. 
I turned logging on at Client Access server and found following information:
4/20/2010 2:31:05 PM [2736,105] EV Extensions DLL version: 8.0.3.0
4/20/2010 2:31:05 PM [2736,105] [RequestProcessor::StartImpersonation] Impersonating logged on user
4/20/2010 2:31:05 PM [2736,105] [EVContext::Initialise] EVContext intialised at 4/20/2010 2:30:55 PM
4/20/2010 2:31:05 PM [2736,105] [EVContext::Initialise] Hidden settings loaded at 4/20/2010 2:30:55 PM
4/20/2010 2:31:05 PM [2736,105] [EVContext::IsValidBrowser] Returning: True
4/20/2010 2:31:05 PM [2736,105] [RequestProcessor::ProcessItem] started
4/20/2010 2:31:05 PM [2736,105] [RequestProcessor::ProcessItem] Processing EV item
4/20/2010 2:31:05 PM [2736,105] [RequestProcessor::ProcessOWAItemAction] started
4/20/2010 2:31:05 PM [2736,105] [RequestProcessor::ProcessOWAItemAction] Opening archived item
4/20/2010 2:31:05 PM [2736,105] [Id::EwsId] Converting OwaId to EwsId
4/20/2010 2:31:05 PM [2736,105] [MailboxBase::MailboxBase] Connecting to Exchange Web Services using: https://caserver/ews/exchange.asmx
4/20/2010 2:31:05 PM [2736,105] [ConvertId::DoConvertId] Converting ID using web services
4/20/2010 2:31:05 PM [2736,105] [Id::EwsId] Converted OwaId to Mailbox EwsId: AAMkAGI3OTQ3ZjgzLTYzOWItNGFmNC04YTRhLTRhZjFiNWZkMWI2YQBGAAAAAACYthawHp9aSYbEzalSIedLBwCao/L01jnwQabrxpuQTC26AAAFKTLKAACucCMs/ieoSq5U11lCQNDkAAB3oMUVAAA=
4/20/2010 2:31:05 PM [2736,105] [MailboxBase::MailboxBase] Connecting to Exchange Web Services using: https://caserver/ews/exchange.asmx
4/20/2010 2:31:05 PM [2736,105] [MailboxItem::LoadProperties] Loading properties for: AAMkAGI3OTQ3ZjgzLTYzOWItNGFmNC04YTRhLTRhZjFiNWZkMWI2YQBGAAAAAACYthawHp9aSYbEzalSIedLBwCao/L01jnwQabrxpuQTC26AAAFKTLKAACucCMs/ieoSq5U11lCQNDkAAB3oMUVAAA=
4/20/2010 2:31:05 PM [2736,105] [MailboxItem::LoadProperties] Loaded item properties: 
4/20/2010 2:31:05 PM [2736,105] [MailboxItem::LoadProperties]   Id: AAMkAGI3OTQ3ZjgzLTYzOWItNGFmNC04YTRhLTRhZjFiNWZkMWI2YQBGAAAAAACYthawHp9aSYbEzalSIedLBwCao/L01jnwQabrxpuQTC26AAAFKTLKAACucCMs/ieoSq5U11lCQNDkAAB3oMUVAAA=
4/20/2010 2:31:05 PM [2736,105] [MailboxItem::LoadProperties]   Change Key: CQAAABYAAACucCMs/ieoSq5U11lCQNDkAAB3qfUc
4/20/2010 2:31:05 PM [2736,105] [MailboxItem::LoadProperties]   Message Class: IPM.Note.EnterpriseVault.Shortcut
4/20/2010 2:31:05 PM [2736,105] [MailboxItem::LoadProperties]   Size: 1060
4/20/2010 2:31:05 PM [2736,105] [MailboxItem::LoadProperties]   Parent Folder Id: AAMkAGI3OTQ3ZjgzLTYzOWItNGFmNC04YTRhLTRhZjFiNWZkMWI2YQAuAAAAAACYthawHp9aSYbEzalSIedLAQCao/L01jnwQabrxpuQTC26AAAFKTLKAAA=
4/20/2010 2:31:05 PM [2736,105] [MailboxItem::LoadProperties]   Archive Id: 10FFF4E6AF59F3E4CA631CBF3864A8B201110000EVAPAC
4/20/2010 2:31:05 PM [2736,105] [MailboxItem::LoadProperties]   Saveset Id: 685000000000000~201004080940330000~0~715FD12C79A244ABB11131285886CA9
4/20/2010 2:31:05 PM [2736,105] [MailboxItem::LoadProperties]   Original Message Class: IPM.Note
4/20/2010 2:31:05 PM [2736,105] [MailboxItem::LoadProperties]   Original Content Class: urn:content-classes:message
4/20/2010 2:31:05 PM [2736,105] [MailboxItem::LoadProperties]   Original Size: 105312
4/20/2010 2:31:05 PM [2736,105] [MailboxItem::LoadProperties]   View Item Ref Count: 
4/20/2010 2:31:05 PM [2736,105] [MailboxItem::LoadProperties]   Content Class: urn:kvsplc-com:cc:vault:shortcut
4/20/2010 2:31:05 PM [2736,105] [MailboxItem::LoadProperties]   Archived Date: 4/15/2010 2:58:54 AM
4/20/2010 2:31:05 PM [2736,105] [MailboxItem::LoadProperties]   Restored Date: 
4/20/2010 2:31:05 PM [2736,105] [MailboxItem::LoadProperties]   Post Processed Date: 
4/20/2010 2:31:05 PM [2736,105] [MailboxItem::LoadProperties]   Last modified time: 4/15/2010 2:59:03 AM
4/20/2010 2:31:05 PM [2736,105] [MailboxItem::LoadProperties]   PR_URL_NAME: /Inbox/Announcement for the Leaving.EML
4/20/2010 2:31:05 PM [2736,105] [MailboxItem::LoadProperties]   PR_ICON_INDEX: 
4/20/2010 2:31:05 PM [2736,105] [MailboxItem::LoadProperties]   Original Icon Index: -1
4/20/2010 2:31:05 PM [2736,105] [Id::OwaId] Returning cached OwaId: RgAAAACYthawHp9aSYbEzalSIedLBwCao/L01jnwQabrxpuQTC26AAAFKTLKAACucCMs/ieoSq5U11lCQNDkAAB3oMUVAAAJ
4/20/2010 2:31:05 PM [2736,105] [MailboxBase::MailboxBase] Connecting to Exchange Web Services using: https://caserver/ews/exchange.asmx
4/20/2010 2:31:05 PM [2736,105] [MailboxFolder::LoadProperties] Folder name: Deleted Items
4/20/2010 2:31:05 PM [2736,105] [MailboxFolder::LoadProperties] Folder path: /Deleted Items
4/20/2010 2:31:05 PM [2736,105] [MailboxFolder::LoadProperties] Non-Deletable: False
4/20/2010 2:31:05 PM [2736,105] [WebDAVRequest::Send] Request url: http://MBSERVER/exchange/test@intra.local/Deleted Items/10FFF4E6AF59F3E4CA631CBF3864A8B201110000EVAPAC!685000000000000.201004080940330000.0.715FD12C79A244ABB11131285886CA9.EML
4/20/2010 2:31:05 PM [2736,105] [WebDAVRequest::Send] Request method: PROPFIND
4/20/2010 2:31:05 PM [2736,105] [WebDAVRequest::Send] Request timeout (milliseconds): 300000
4/20/2010 2:31:05 PM [2736,105] [WebDAVRequest::Send] Adding FBA cookies
4/20/2010 2:31:05 PM [2736,105] [WebDAVRequest::Send] Adding Depth header: 0
4/20/2010 2:31:05 PM [2736,105] [WebDAVRequest::Send] Request body: <?xml version="1.0"?><d:propfind xmlns:d="DAV:" ><d:prop><mapi:x0FFF0102 xmlns:mapi="http://schemas.microsoft.com/mapi/proptag/" /><exch:outlookmessageclass xmlns:exch="http://schemas.microsoft.com/exchange/" /></d:prop></d:propfind>
4/20/2010 2:31:06 PM [2736,105] [WebDAVRequest::Send] Exception sending WebDAV request: System.Net.WebException: The remote server returned an error: (404) Not Found.
   at System.Net.HttpWebRequest.GetResponse()
   at Symantec.EnterpriseVault.Owa.ExchangeStoreAccess.WebDAVRequest.Send()
4/20/2010 2:31:06 PM [2736,105] [EVServerRequest::CreateRequest] Sending request to: http://SEVAPAC/EVAnon/restoreo2k.asp?vaultid=10FFF4E6AF59F3E4CA631CBF3864A8B201110000EVAPAC&savesetid=685000000000000~201004080940330000~0~715FD12C79A244ABB11131285886CA9&mbx=test@intra.local&server=MBSERVER&restorelocation=3&foldername=Deleted Items
4/20/2010 2:31:06 PM [2736,105] [EVServerRequest::CreateRequest] Request timeout (milliseconds): 300000
4/20/2010 2:31:06 PM [2736,105] [EVServerRequest::AddHeader] Set header: EV-OWA-2007-Extensions-Version=8.0.3.0
4/20/2010 2:31:06 PM [2736,105] [EVServerRequest::CreateRequest] Making request for user: EXI\mykhaylo.khodorev
4/20/2010 2:31:06 PM [2736,105] [EVServerRequest::AddHeader] Set header: X-EVOWA-User-Encoded=4500580049005C006D0079006B006800610079006C006F002E006B0068006F0064006F00720065007600
4/20/2010 2:31:54 PM [2736,105] [EVServerRequest::LogResponseHeaders] Response received from EV server:
4/20/2010 2:31:54 PM [2736,105] [EVServerRequest::LogResponseHeaders]   Status: 201 Basket Restoring
4/20/2010 2:31:54 PM [2736,105] [EVServerRequest::LogResponseHeaders]   Headers: 
4/20/2010 2:31:54 PM [2736,105] [EVServerRequest::LogResponseHeaders]     Content-Length: 0
4/20/2010 2:31:54 PM [2736,105] [EVServerRequest::LogResponseHeaders]     Cache-Control: private
4/20/2010 2:31:54 PM [2736,105] [EVServerRequest::LogResponseHeaders]     Content-Type: text/html
4/20/2010 2:31:54 PM [2736,105] [EVServerRequest::LogResponseHeaders]     Date: Tue, 20 Apr 2010 12:31:53 GMT
4/20/2010 2:31:54 PM [2736,105] [EVServerRequest::LogResponseHeaders]     Set-Cookie: ASPSESSIONIDACTRSDST=EKDCKPFCHMOOIIMNLABFKPBJ; path=/
4/20/2010 2:31:54 PM [2736,105] [EVServerRequest::LogResponseHeaders]     Server: Microsoft-IIS/6.0
4/20/2010 2:31:54 PM [2736,105] [EVServerRequest::LogResponseHeaders]     X-Powered-By: ASP.NET
4/20/2010 2:31:54 PM [2736,105] [RestoreRequest::Send] Item is being restored
4/20/2010 2:31:54 PM [2736,105] [RequestProcessor::RestoreAndActOnItem] Item is being restored
4/20/2010 2:31:54 PM [2736,105] [RequestProcessor::RestoreAndActOnItem] RestoreWaitMaxIterations: 30
4/20/2010 2:31:54 PM [2736,105] [RequestProcessor::RestoreAndActOnItem] RestoreWaitSleepTime: 2000
4/20/2010 2:31:54 PM [2736,105] [WebDAVRequest::Send] Request url: http://MBSERVER/exchange/test@intra.local/Deleted Items/10FFF4E6AF59F3E4CA631CBF3864A8B201110000EVAPAC!685000000000000.201004080940330000.0.715FD12C79A244ABB11131285886CA9.EML
4/20/2010 2:31:54 PM [2736,105] [WebDAVRequest::Send] Request method: PROPFIND
4/20/2010 2:31:54 PM [2736,105] [WebDAVRequest::Send] Request timeout (milliseconds): 300000
4/20/2010 2:31:54 PM [2736,105] [WebDAVRequest::Send] Adding FBA cookies
4/20/2010 2:31:54 PM [2736,105] [WebDAVRequest::Send] Adding Depth header: 0
4/20/2010 2:31:54 PM [2736,105] [WebDAVRequest::Send] Request body: <?xml version="1.0"?><d:propfind xmlns:d="DAV:" ><d:prop><mapi:x0FFF0102 xmlns:mapi="http://schemas.microsoft.com/mapi/proptag/" /><exch:outlookmessageclass xmlns:exch="http://schemas.microsoft.com/exchange/" /></d:prop></d:propfind>
4/20/2010 2:31:54 PM [2736,105] [WebDAVRequest::Send] Exception sending WebDAV request: System.Net.WebException: The remote server returned an error: (404) Not Found.
   at System.Net.HttpWebRequest.GetResponse()
   at Symantec.EnterpriseVault.Owa.ExchangeStoreAccess.WebDAVRequest.Send()
4/20/2010 2:31:56 PM [2736,105] [WebDAVRequest::Send] Request url: http://MBSERVER/exchange/test@intra.local/Deleted Items/10FFF4E6AF59F3E4CA631CBF3864A8B201110000EVAPAC!685000000000000.201004080940330000.0.715FD12C79A244ABB11131285886CA9.EML
4/20/2010 2:31:56 PM [2736,105] [WebDAVRequest::Send] Request method: PROPFIND
4/20/2010 2:31:56 PM [2736,105] [WebDAVRequest::Send] Request timeout (milliseconds): 300000
4/20/2010 2:31:56 PM [2736,105] [WebDAVRequest::Send] Adding FBA cookies
4/20/2010 2:31:56 PM [2736,105] [WebDAVRequest::Send] Adding Depth header: 0
4/20/2010 2:31:56 PM [2736,105] [WebDAVRequest::Send] Request body: <?xml version="1.0"?><d:propfind xmlns:d="DAV:" ><d:prop><mapi:x0FFF0102 xmlns:mapi="http://schemas.microsoft.com/mapi/proptag/" /><exch:outlookmessageclass xmlns:exch="http://schemas.microsoft.com/exchange/" /></d:prop></d:propfind>
4/20/2010 2:31:56 PM [2736,105] [WebDAVRequest::Send] Exception sending WebDAV request: System.Net.WebException: The remote server returned an error: (404) Not Found.
   at System.Net.HttpWebRequest.GetResponse()
   at Symantec.EnterpriseVault.Owa.ExchangeStoreAccess.WebDAVRequest.Send()


I'm confused about this point:


4/20/2010 2:31:05 PM [2736,105] [MailboxFolder::LoadProperties] Folder name: Deleted Items
4/20/2010 2:31:05 PM [2736,105] [MailboxFolder::LoadProperties] Folder path: /Deleted Items

 The message is not in Deleted Items. It's in Inbox. Moreover it shows:
[MailboxItem::LoadProperties]   PR_URL_NAME: /Inbox/Announcement for the Leaving.EML

what is correct. So I don't understand where Deleted Items were taken from. 
Any help is appreciated.
Enterprise Vault
Information Governance
MS Exchange
Troubleshooting
  • Rob_Wilcox1's avatar
    Rob_Wilcox1
    Level 6
    15 years ago
    I think you might not be telling us everything ....

    <snip>
    I have EV 2007 SP 2007 SP3
    </snip>

    But in your log I see :

    <snip>
    4/20/2010 2:31:05 PM [2736,105] EV Extensions DLL version: 8.0.3.0
    </snip>

    So at least you have EV 8 SP 3 extensions.

    Did you make any changes to your web.config file on the CAS server?

    The reason I ask is that your Request Timeout is set to 300 seconds, rather than the default of 30 seconds..  so it would be good to know if there are any other changes in the web.config.

    The Deleted Items part...  The way that OWA 2003 and OWA 2007 extensions work is that they know that the item you've double clicked on is an archived item... so in the background they restore the item to the Deleted Items folder (don't worry, it's restored as a hidden message so you can't see it) and then they display it.

    Whilst the item is restoring (if it takes a while) it is fairly normal to see repeated entries showing (404) Not Found.

    Can I ask that you attach your full OWA log, and web.config to the original post..  That might shed some light on things.  In addition, you ran the owauser.wsf script on the EV Server, and all those sorts of things (to give the CAS IP address access rights to the EVAnon virtual directory on the EV server)..  Just trying to gather what steps you've been through so far.

    Hope that helps,




  • Rob_Wilcox1's avatar
    Rob_Wilcox1
    Level 6
    15 years ago
    That's fine to use different extensions to your EV Server version (don't quote me too much on that though laugh)

    From your log file :

    4/20/2010 2:31:06 PM [2736,105] [EVServerRequest::CreateRequest] Sending request to: http://SEVAPAC2/EVAnon/restoreo2k.asp?vaultid=10FFF4E6AF59F3E4CA631CBF3864A8B201110000EVAPAC&savesetid=685000000000000~201004080940330000~0~715FD12C79A244ABB11131285886CA9&mbx=test@intra.local&server=MBSERVER&restorelocation=3&foldername=Deleted Items
     
    4/20/2010 2:32:54 PM [2736,105] [RequestProcessor::RestoreAndActOnItem] Item not restored
     
    That's 1 minute 48 elapsed
     
    4/20/2010 2:31:54 PM [2736,105] [RequestProcessor::RestoreAndActOnItem] Item is being restored
    4/20/2010 2:31:54 PM [2736,105] [RequestProcessor::RestoreAndActOnItem] RestoreWaitMaxIterations: 30
    4/20/2010 2:31:54 PM [2736,105] [RequestProcessor::RestoreAndActOnItem] RestoreWaitSleepTime: 2000
    These are the default
     
    We then see this every 2 seconds :
     
     
    4/20/2010 2:31:54 PM [2736,105] [WebDAVRequest::Send] Request url: http://MBSERVER/exchange/test@intra.local/Deleted Items/10FFF4E6AF59F3E4CA631CBF3864A8B201110000EVAPAC!685000000000000.201004080940330000.0.715FD12C79A244ABB11131285886CA9.EML
    4/20/2010 2:31:54 PM [2736,105] [WebDAVRequest::Send] Request method: PROPFIND
    4/20/2010 2:31:54 PM [2736,105] [WebDAVRequest::Send] Request timeout (milliseconds): 300000
    4/20/2010 2:31:54 PM [2736,105] [WebDAVRequest::Send] Adding FBA cookies
    4/20/2010 2:31:54 PM [2736,105] [WebDAVRequest::Send] Adding Depth header: 0
    4/20/2010 2:31:54 PM [2736,105] [WebDAVRequest::Send] Request body: <?xml version="1.0"?><d:propfind xmlns:d="DAV:" ><d:prop><mapi:x0FFF0102 xmlns:mapi="http://schemas.microsoft.com/mapi/proptag/" /><exch:outlookmessageclass xmlns:exch="http://schemas.microsoft.com/exchange/" /></d:prop></d:propfind>
    4/20/2010 2:31:54 PM [2736,105] [WebDAVRequest::Send] Exception sending WebDAV request: System.Net.WebException: The remote server returned an error: (404) Not Found.
       at System.Net.HttpWebRequest.GetResponse()
       at Symantec.EnterpriseVault.Owa.ExchangeStoreAccess.WebDAVRequest.Send()
     
    I see that ALOT of times.
     
    The last one is at 
     
    4/20/2010 2:32:54 PM [2736,105] [RequestProcessor::RestoreAndActOnItem] Item not restored
     
    That's more like it... That's 30 times 2 seconds (2000 milliseconds) = 60 seconds
     
    So ...
     
    If it "takes a while to open" when using Outlook, how long is that?  We could change either :-
     
    RestoreWaitMaxIterations to 60
     
    or perhaps better we could change
     
    RestoreWaitSleepTime to 4000
     
    From : http://support.veritas.com/docs/304386
     
    When attempting to open an Item through OWA the original message must be restored from the Enterprise Vault Server, this key sets the number of times to check if an archived item has been restored (default 30):
    <add key="EnterpriseVault_RestoreWaitMaxIterations" value="30"/>
     
    The time to wait (milliseconds) between the previously mentioned checks for the restoration of the item (default 2000):
    <add key="EnterpriseVault_RestoreWaitSleepTime" value="2000"/>
     
    This one is doing something different to what you might think, I think :
     
    This determines the number of milliseconds the EV OWA extensions will wait until the http (or https) request times out (default 30000):
    <add key="EnterpriseVault_HttpWebRequestTimeout" value="30000"/>
     
    I think that's just a timeout for the initial HTTP request/response pairings... not the overall run time.

    So, if it takes a couple of minutes (sometimes) to retrieve an item in OWA... then I'd go for setting RestoreWaitSleepTime to 4000 or even 6000, this will give you :

    120 seconds (versus the current 60) 
    180 seconds

    respectively, before the timeout occurs.

    Hope that helps,
     
  • Ralfeus's avatar
    Ralfeus
    Level 4
    15 years ago
    Thank you for advise. It changed the behavior but not in better way :-)
    Now when I try to open archived item from OWA it takes a little longer than before and then I get an HTTP 500 status code. Details of the error are following:

    Request
    Url: https://caserver:443/owa/forms/premium/ReadMessage.aspx?ae=Item&a=Open&t=IPM.Note.EnterpriseVault.Shortcut&id=RgAAAACYthawHp9aSYbEzalSIedLBwCao%2fL01jnwQabrxpuQTC26AAAFKTLKAACucCMs%2fieoSq5U11lCQNDkAAB3oMUlAAAJ
    User host address: 192.168.1.176
    User: test
    EX Address: /o=INTRA/ou=Exchange Administrative Group (FYDIBOHF23SPDLT)/cn=Recipients/cn=test
    SMTP Address: test@intra.local
    OWA version: 8.2.234.1
    Mailbox server: mbserver.intra.local
     
    Exception
    Exception type: System.Web.HttpException
    Exception message: Request timed out.
     
    Call stack
     

    No callstack available




    The SEV OWA log is attached. 

    When I try to open the URL, mentioned in the log file at SEV server (http://SEVAPAC2/EVAnon/restoreo2k.asp?vaultid=10FFF4E6AF59F3E4CA631CBF3864A8B201110000EVAPAC&savesetid=230000000000000~201004090059070000~0~4C3E334D54B544C8B838262839F23CB&mbx=test@intra.local&server=MBSERVER&restorelocation=3&foldername=Deleted Items) I get an error 500 immediately.
    I checked Application log of the SEV server the the time of request - no errors, no warnings, nothing related to this request...

  • Rob_Wilcox1's avatar
    Rob_Wilcox1
    Level 6
    15 years ago
    hmm so I don't see an internal server error (500) in the OWA log that you added .. unless I missed it.

    Have a look on the EV server in the IIS logs at the time of your test..  Is the 500 logged there?  Is there anything else nearby ?

    Whilst there check the IIS settings on the EVanon virtual directory, it should be restricted access to a number of IP addresses.  Are the IP addresses of the CAS in there?

    When you did the seperate test to launch :

    (http://SEVAPAC2/EVAnon/restoreo2k.asp?vaultid=10FF... Items

    Where did you do that from?  The CAS or a workstation ?
  • Ralfeus's avatar
    Ralfeus
    Level 4
    15 years ago
    The error is quoted one. There was no 500 error at SEV server so I guess the error was generated by CAS server. Regarding this item I have found only one record in SEV IIS log. The status of request was 201.

    EVAnon VD indeed is restricted only CAS IP address. 

    I tried to open the URL from CAS server. From any other server it returns error 403 as expected.
  • Ralfeus's avatar
    Ralfeus
    Level 4
    15 years ago
    I tried to open URL http://SEVAPAC2/EVAnon. I've got same HTTP 500 error. Then I tried to run custom script (http://SEVAPAC2/EVAnon/test.asp). Again HTTP 500.
    But when I tried to open http://SEVAPAC2/EnterpriseVault/test.asp (EVAnon and EnterpriseVault refer to same catalog but with different authentication methods) it was opened.
    Also I have noticed archiving and restoring works fine in OWA. In log file I've found HTTP requests for archiving and restoring. Both actions refer to http://SEVAPAC2/EVAnon/clientaction.asp. The result is HTTP 200.