Hi Patrick,
As per my original post, the infopath form connects to a .NET web service and that does the database calls. The Sharepoint site and the webservice(running under Default Web Service - port 8888) are both on the SP2010dev server, the database is on the SQL server. Sharepoint is 2010, web service was recompiled with VS2010, 3.5 framwork. The service account on this SP site is Agency\SP001, AppPool runs as the same user and I've verified it is part of the Administrator group on the server.
In the old environment, the Sharepoint (SP2007) site and web service (running under Default Web Service - port 90) are on the OldSharepoint server (it was renamed from Sharepoint), and the web service(running under default web site) connects to the database on the SQL server. The AppPool for this site runs as user Agency\SPPortal who is part of the Administrator group.
I've uploaded the web service for you to see what I'm working with. Nothing out of the ordinary here. I also included the .udcx files from the old SP 2007 site which I used as a guide when generating the new .udcx files.
The infopath form works in filler. If I put the web service in debug mode and connect the infopath form in sharepoint to this it works fine. It's only when I connect the sharepoint infopath form to the web service running under the default web site that it gets this error. I've tried modifying the .udcx file replacing localhost:8888 with sp2010dev:8888 and get the same error. I even tried connecting to the web service which is still running on the OldSharepoint server by using oldsharepoint:90 and it generates the same error.
Once again, the error does not happen on the 1st call to the web service/database, but after the dropdown list is loaded, the user selects an item from the ddl and the web service returns the data and populates the form with that data. So it makes to successfull calls to the web service before the error occurs. I've looked at the SP logs, the windows logs and the Microsft/Sharepoint Product/Shared/Operational log. They all say the same thing:
Exception occurred during request processing. (User: AGENCY\spfarm, Form Name: Capital Replacement Reserve Contributions Tracking, IP: , Request: http://sp2010dev/PM/_layouts/FormServer.aspx?XsnLocation=http://sp2010dev/PM/CapitalReplacementRCT/Forms/template.xsn&SaveLocation=http://sp2010dev/PM/CapitalReplacementRCT&ClientInstalled=true&Source=http://sp2010dev/PM/CapitalReplacementRCT/Forms/AllItems.aspx&DefaultItemOpen=1, Form ID: urn:schemas-microsoft-com:office:infopath:Capital-Replacement-Reserve-Contributions-Tracking:-dataFormSolution, Type: KeyNotFoundException, Exception Message: The given key was not present in the dictionary.)
The only other thing I can find is this message:
Watson bucket parameters: SharePoint Server 2010, ULSException14, 41b7c39f "infopath forms services", 0e00178d "14.0.6029.0", c180aef3 "mscorlib", 0200c627 "2.0.50727.0", 4e1539fa "thu jul 07 00:45:46 2011", 000000dd "000000dd", 00000005 "00000005", 0560164b "keynotfoundexception", 38676563 "8gec" 6997ccd6-eb92-42fd-8e49-5b9fd7113582
At the same time I find this in the Windows Application log in the event viewer:
Login failed for user 'AGENCY\sp001'. Reason: Failed to open the explicitly specified database. [CLIENT: <local machine>]
I've looked at the permissions on the SP site, in IIS and even the c:/Temp folder.
I Turned on Verbose logging and this is what now comes out in the log:
08/01/2013 12:13:26.68 w3wp.exe (0x1B64) 0x0E4C SharePoint Foundation Logging Correlation Data xmnv Medium Name=Request (POST:http://sp2010dev:80/PM/_layouts/Postback.FormServer.aspx) e64280d1-ff24-41ee-8a6e-506197624e51
08/01/2013 12:13:26.69 w3wp.exe (0x1B64) 0x0E4C InfoPath Forms Services Runtime 42cp Verbose Request: Posting back to the Postback Page (XmlHttp). e64280d1-ff24-41ee-8a6e-506197624e51
08/01/2013 12:13:26.69 w3wp.exe (0x1B64) 0x0E4C InfoPath Forms Services Runtime 8z3p Verbose Calling GlobalStorage.SetItem with index GlobalPageObjectsRendered value type Boolean. e64280d1-ff24-41ee-8a6e-506197624e51
08/01/2013 12:13:26.69 w3wp.exe (0x1B64) 0x0E4C InfoPath Forms Services Runtime wdqk Verbose GlobalStorage.Enter: New context - FormControl Total contexts - 1 e64280d1-ff24-41ee-8a6e-506197624e51
08/01/2013 12:13:26.69 w3wp.exe (0x1B64) 0x0E4C InfoPath Forms Services Runtime 8z3p Verbose Calling GlobalStorage.SetItem with index IsConversionInProgress value type Boolean. e64280d1-ff24-41ee-8a6e-506197624e51
08/01/2013 12:13:26.69 w3wp.exe (0x1B64) 0x0E4C InfoPath Forms Services Runtime 8z3p Verbose Calling GlobalStorage.SetItem with index SiteAndWebCache value type SiteAndWebCache. e64280d1-ff24-41ee-8a6e-506197624e51
08/01/2013 12:13:26.69 w3wp.exe (0x1B64) 0x0E4C InfoPath Forms Services Runtime 8z3p Verbose Calling GlobalStorage.SetItem with index CultureData value type RequestCultureData. e64280d1-ff24-41ee-8a6e-506197624e51
08/01/2013 12:13:26.69 w3wp.exe (0x1B64) 0x0E4C InfoPath Forms Services Runtime 8z3p Verbose Calling GlobalStorage.SetItem with index TimeZoneId value type UInt16. e64280d1-ff24-41ee-8a6e-506197624e51
08/01/2013 12:13:26.71 w3wp.exe (0x1B64) 0x0E4C InfoPath Forms Services Runtime 8z3p Verbose Calling GlobalStorage.SetItem with index EditingSessionId value type String. e64280d1-ff24-41ee-8a6e-506197624e51
08/01/2013 12:13:26.71 w3wp.exe (0x1B64) 0x0E4C InfoPath Forms Services Runtime 8ykj Verbose Creating document with editingSessionId: 5b6cdf9c229b41ab8945f1c86a1eae88_32c6df23cfa4489198117ad31426df2a e64280d1-ff24-41ee-8a6e-506197624e51
08/01/2013 12:13:26.72 w3wp.exe (0x1B64) 0x0E4C InfoPath Forms Services Runtime c1jb Verbose DataObject.Deserialize.Load for XML name: finished in:00:00:00.0003626. e64280d1-ff24-41ee-8a6e-506197624e51
08/01/2013 12:13:26.73 w3wp.exe (0x1B64) 0x0E4C InfoPath Forms Services Runtime c1jb Verbose DataObject.Deserialize.Load for XML name:GetCoopListDS finished in:00:00:00.0143708. e64280d1-ff24-41ee-8a6e-506197624e51
08/01/2013 12:13:26.74 w3wp.exe (0x1B64) 0x0E4C InfoPath Forms Services Administration 82fk Warning Exception occurred during request processing. (User: AGENCY\spfarm, Form Name: Capital Replacement Reserve Contributions Tracking, IP: , Request: http://sp2010dev/PM/_layouts/FormServer.aspx?XsnLocation=http://sp2010dev/PM/CapitalReplacementRCT/Forms/template.xsn&SaveLocation=http://sp2010dev/PM/CapitalReplacementRCT&ClientInstalled=true&Source=http://sp2010dev/PM/CapitalReplacementRCT/Forms/AllItems.aspx&DefaultItemOpen=1, Form ID: urn:schemas-microsoft-com:office:infopath:Capital-Replacement-Reserve-Contributions-Tracking:-dataFormSolution, Type: KeyNotFoundException, Exception Message: The given key was not present in the dictionary.) e64280d1-ff24-41ee-8a6e-506197624e51
08/01/2013 12:13:26.74 w3wp.exe (0x1B64) 0x0E4C InfoPath Forms Services Runtime 8z3p Verbose Calling GlobalStorage.SetItem with index LastExceptionLogged value type KeyNotFoundException. e64280d1-ff24-41ee-8a6e-506197624e51
08/01/2013 12:13:26.74 w3wp.exe (0x1B64) 0x0E4C InfoPath Forms Services Runtime wdqk Verbose GlobalStorage.Enter: New context - {F888E1A1-20CA-470d-A2F4-498A9ECD1C67} Total contexts - 2 e64280d1-ff24-41ee-8a6e-506197624e51
08/01/2013 12:13:26.74 w3wp.exe (0x1B64) 0x0E4C InfoPath Forms Services Runtime wdqm Verbose GlobalStorage.Leave: Old context - {F888E1A1-20CA-470d-A2F4-498A9ECD1C67} Total contexts after Leave - 1 e64280d1-ff24-41ee-8a6e-506197624e51
08/01/2013 12:13:26.95 w3wp.exe (0x1B64) 0x0E4C InfoPath Forms Services Runtime 3pcy Verbose Unhandled exception in FormServer: The given key was not present in the dictionary.. Type: System.Collections.Generic.KeyNotFoundException. StackTrace: at System.ThrowHelper.ThrowKeyNotFoundException() at System.Collections.Generic.Dictionary`2.get_Item(TKey key) at Microsoft.Office.InfoPath.Server.DocumentLifetime.ErrorBoard.ConvertTokensToNodesInErrorsCollection() at Microsoft.Office.InfoPath.Server.DocumentLifetime.Document.LoadFromSessionInternal(Byte[] serializedSessionState, Byte[] serializedVersionState, Solution solution, StateOriginType stateOrigin) at Microsoft.Office.InfoPath.Server.DocumentLifetime.Document.LoadFromSession(HttpContext context, SPSite contextSite, EventLogStart eventLogStart, Solution solution) at Microsoft.Office.InfoPath.Server.Controls.... e64280d1-ff24-41ee-8a6e-506197624e51
08/01/2013 12:13:26.95* w3wp.exe (0x1B64) 0x0E4C InfoPath Forms Services Runtime 3pcy Verbose ...PostbackPage.ProcessIndividual(HttpContext context, String eventLogText, Boolean firstEventLog) e64280d1-ff24-41ee-8a6e-506197624e51
08/01/2013 12:13:26.96 w3wp.exe (0x1B64) 0x0E4C InfoPath Forms Services Runtime 8gec Exception Unhandled exception when rendering form System.Collections.Generic.KeyNotFoundException: The given key was not present in the dictionary. at System.ThrowHelper.ThrowKeyNotFoundException() at System.Collections.Generic.Dictionary`2.get_Item(TKey key) at Microsoft.Office.InfoPath.Server.DocumentLifetime.ErrorBoard.ConvertTokensToNodesInErrorsCollection() at Microsoft.Office.InfoPath.Server.DocumentLifetime.Document.LoadFromSessionInternal(Byte[] serializedSessionState, Byte[] serializedVersionState, Solution solution, StateOriginType stateOrigin) at Microsoft.Office.InfoPath.Server.DocumentLifetime.Document.LoadFromSession(HttpContext context, SPSite contextSite, EventLogStart eventLogStart, Solution solution) at Microsoft.Office.InfoPath.Server.Controls.PostbackPage.... e64280d1-ff24-41ee-8a6e-506197624e51
08/01/2013 12:13:26.96* w3wp.exe (0x1B64) 0x0E4C InfoPath Forms Services Runtime 8gec Exception ...ProcessIndividual(HttpContext context, String eventLogText, Boolean firstEventLog) e64280d1-ff24-41ee-8a6e-506197624e51
08/01/2013 12:13:26.96 w3wp.exe (0x1B64) 0x0E4C SharePoint Server Unified Logging Service c91s Monitorable Watson bucket parameters: SharePoint Server 2010, ULSException14, 41b7c39f "infopath forms services", 0e00178d "14.0.6029.0", c180aef3 "mscorlib", 0200c627 "2.0.50727.0", 4e1539fa "thu jul 07 00:45:46 2011", 000000dd "000000dd", 00000005 "00000005", 0560164b "keynotfoundexception", 38676563 "8gec" e64280d1-ff24-41ee-8a6e-506197624e51
08/01/2013 12:13:26.96 w3wp.exe (0x1B64) 0x0E4C InfoPath Forms Services Runtime - State Service 0000 Verbose Abandoning session state for 5b6cdf9c229b41ab8945f1c86a1eae88_32c6df23cfa4489198117ad31426df2a. e64280d1-ff24-41ee-8a6e-506197624e51
08/01/2013 12:13:27.00 w3wp.exe (0x1B64) 0x0E4C InfoPath Forms Services Runtime wdqk Verbose GlobalStorage.Enter: New context - {F888E1A1-20CA-470d-A2F4-498A9ECD1C67} Total contexts - 2 e64280d1-ff24-41ee-8a6e-506197624e51
08/01/2013 12:13:27.00 w3wp.exe (0x1B64) 0x0E4C InfoPath Forms Services Runtime wdqm Verbose GlobalStorage.Leave: Old context - {F888E1A1-20CA-470d-A2F4-498A9ECD1C67} Total contexts after Leave - 1 e64280d1-ff24-41ee-8a6e-506197624e51
08/01/2013 12:13:27.00 w3wp.exe (0x1B64) 0x0E4C InfoPath Forms Services Runtime 7nek Verbose Disposing all cached sites. e64280d1-ff24-41ee-8a6e-506197624e51
08/01/2013 12:13:27.00 w3wp.exe (0x1B64) 0x0E4C InfoPath Forms Services Runtime 8z3q Verbose Calling GlobalStorage.RemoveAll! e64280d1-ff24-41ee-8a6e-506197624e51