OrchardCMS / Orchard

Orchard is a free, open source, community-focused Content Management System built on the ASP.NET MVC platform.
https://orchardproject.net
BSD 3-Clause "New" or "Revised" License
2.37k stars 1.12k forks source link

Error using Azure Table Storage in 1.9-int - OData 5.6.2 vs 5.6.3 #5187

Closed dcinzona closed 9 years ago

dcinzona commented 9 years ago

We are storing some data in Azure Table Storage and when we try to execute CreateIfNotExists, we get the following error:

Could not load file or assembly 'Microsoft.Data.OData, Version=5.6.2.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35' or one of its dependencies

We are using the Azure library files in the lib folder ( Azure Storage 4.3.0.0 and Microsoft.Data.OData 5.6.3). It seems as though there's a hard reference to OData 5.6.2.0 somewhere? I've looked and can't seem to find it...

Any ideas (or could this be a bug in the Azure SDK)?

dcinzona commented 9 years ago

I've also posted an issue on Microsofts Azure SDK repo: https://github.com/Azure/azure-storage-net/issues/125

We have a web app running on Orchard CMS that communicates with Azure. Running the app locally, in IIS or within visual studio produces the error. Also, deploying to Azure produces the error as well. We have Microsoft OData version 5.6.3 installed and Orchard uses that same version.

We are using OData version 5.6.3 and we are getting the error below. I have verified that the DLL is in the bin directory and web.config

Any idea why/if there is a hard reference to 5.6.2? The Nuget package states it can use >= 5.6.2

Our config:

      <dependentAssembly>
        <assemblyIdentity name="Microsoft.WindowsAzure.Storage" publicKeyToken="31bf3856ad364e35" culture="neutral" />
        <bindingRedirect oldVersion="0.0.0.0-4.3.0.0" newVersion="4.3.0.0" />
      </dependentAssembly>
      <dependentAssembly>
        <assemblyIdentity name="Newtonsoft.Json" publicKeyToken="30ad4fe6b2a6aeed" culture="neutral" />
        <bindingRedirect oldVersion="0.0.0.0-6.0.0.0" newVersion="6.0.0.0" />
      </dependentAssembly>
      <dependentAssembly>
        <assemblyIdentity name="Microsoft.Data.Edm" publicKeyToken="31bf3856ad364e35" culture="neutral" />
        <bindingRedirect oldVersion="0.0.0.0-5.6.3.0" newVersion="5.6.3.0" />
      </dependentAssembly>
      <dependentAssembly>
        <assemblyIdentity name="Microsoft.Data.Services.Client" publicKeyToken="31bf3856ad364e35" culture="neutral" />
        <bindingRedirect oldVersion="0.0.0.0-5.6.3.0" newVersion="5.6.3.0" />
      </dependentAssembly>
      <dependentAssembly>
        <assemblyIdentity name="Microsoft.Data.OData" publicKeyToken="31bf3856ad364e35" culture="neutral" />
        <bindingRedirect oldVersion="0.0.0.0-5.6.3.0" newVersion="5.6.3.0" />
      </dependentAssembly>
Microsoft.WindowsAzure.Storage.StorageException: Could not load file or assembly
'Microsoft.Data.OData, Version=5.6.2.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35' 
or one of its dependencies. The located assembly's manifest definition does not match the assembly
reference. (Exception from HRESULT: 0x80131040) ---> 
System.IO.FileLoadException: Could not load file or assembly 'Microsoft.Data.OData, Version=5.6.2.0,
Culture=neutral, PublicKeyToken=31bf3856ad364e35' or one of its dependencies. 
The located assembly's manifest definition does not match the assembly reference. 
(Exception from HRESULT: 0x80131040) 
at Microsoft.WindowsAzure.Storage.Table.Protocol.TableOperationHttpWebRequestFactory.BuildRequestForTableOperation(Uri uri, UriQueryBuilder builder, IBufferManager bufferManager, Nullable`1 timeout, TableOperation operation, Boolean useVersionHeader, OperationContext ctx, TablePayloadFormat payloadFormat, String accountName)
at Microsoft.WindowsAzure.Storage.Table.TableOperation.<>c__DisplayClass18.<RetrieveImpl>b__15(Uri uri, UriQueryBuilder builder, Nullable`1 timeout, Boolean useVersionHeader, OperationContext ctx)
at Microsoft.WindowsAzure.Storage.Core.Executor.Executor.ProcessStartOfRequest[T](ExecutionState`1 executionState, String startLogMessage)
at Microsoft.WindowsAzure.Storage.Core.Executor.Executor.ExecuteSync[T](RESTCommand`1 cmd, IRetryPolicy policy, OperationContext operationContext)
--- End of inner exception stack trace ---
at Microsoft.WindowsAzure.Storage.Core.Executor.Executor.ExecuteSync[T](RESTCommand`1 cmd, IRetryPolicy policy, OperationContext operationContext)
at Microsoft.WindowsAzure.Storage.Table.CloudTable.Exists(Boolean primaryOnly, TableRequestOptions requestOptions, OperationContext operationContext)
at Microsoft.WindowsAzure.Storage.Table.CloudTable.CreateIfNotExists(TableRequestOptions requestOptions, OperationContext operationContext)
DaRosenberg commented 9 years ago

Truly perplexing - looks like your assembly binding redirect just doesn't take!

The only time I've ever seen that happening is when running code in the RoleEntry.OnStart() method in an Azure web role (cloud service) because this code is executed using a different process which has its own App.config. Could this be the case by any chance? But then again, you say it repros locally in IIS Express as well, so that shouldn't be it.

You should enable fusion logging at this point and examine the log. This will tell you exactly how it's determining which version to load, and where it is trying to find that version of the assembly.

dcinzona commented 9 years ago

Agreed Daniel, it's weird. I've tested this on a local IIS deployment (on my dev machine) and on Azure Websites. The issue persists on both. When I'm back in the office on Monday, I'll test again with fusion logging enabled. It has me baffled. I'll report back here with my findings. Thanks!

dcinzona commented 9 years ago

Pulled this from the fuslogvw tool:

For Microsoft.Data.OData 5.6.2.0:

*** Assembly Binder Log Entry  (5/1/2015 @ 3:20:21 PM) ***

The operation failed.
Bind result: hr = 0x80131040. No description available.

Assembly manager loaded from:  C:\Windows\Microsoft.NET\Framework64\v4.0.30319\clr.dll
Running under executable  c:\windows\system32\inetsrv\w3wp.exe
--- A detailed error log follows. 

=== Pre-bind state information ===
LOG: DisplayName = Microsoft.Data.OData, Version=5.6.2.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35
 (Fully-specified)
LOG: Appbase = file:///C:/WWW/orchard 1.9-int/
LOG: Initial PrivatePath = C:\WWW\orchard 1.9-int\bin
LOG: Dynamic Base = C:\Windows\Microsoft.NET\Framework64\v4.0.30319\Temporary ASP.NET Files\root\aa2320a0
LOG: Cache Base = C:\Windows\Microsoft.NET\Framework64\v4.0.30319\Temporary ASP.NET Files\root\aa2320a0
LOG: AppName = 6d3135d0
Calling assembly : Microsoft.WindowsAzure.Storage, Version=4.3.0.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35.
===
LOG: This bind starts in default load context.
LOG: Using application configuration file: C:\WWW\orchard 1.9-int\web.config
LOG: Using host configuration file: C:\Windows\Microsoft.NET\Framework64\v4.0.30319\aspnet.config
LOG: Using machine configuration file from C:\Windows\Microsoft.NET\Framework64\v4.0.30319\config\machine.config.
LOG: Post-policy reference: Microsoft.Data.OData, Version=5.6.2.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35
LOG: GAC Lookup was unsuccessful.
LOG: Attempting download of new URL file:///C:/Windows/Microsoft.NET/Framework64/v4.0.30319/Temporary ASP.NET Files/root/aa2320a0/6d3135d0/Microsoft.Data.OData.DLL.
LOG: Attempting download of new URL file:///C:/Windows/Microsoft.NET/Framework64/v4.0.30319/Temporary ASP.NET Files/root/aa2320a0/6d3135d0/Microsoft.Data.OData/Microsoft.Data.OData.DLL.
LOG: Attempting download of new URL file:///C:/WWW/orchard 1.9-int/bin/Microsoft.Data.OData.DLL.
LOG: Attempting download of new URL file:///C:/WWW/orchard 1.9-int/bin/Microsoft.Data.OData/Microsoft.Data.OData.DLL.
LOG: Attempting download of new URL file:///C:/WWW/orchard 1.9-int/App_Data/Dependencies/Microsoft.Data.OData.DLL.
LOG: Assembly download was successful. Attempting setup of file: C:\WWW\orchard 1.9-int\App_Data\Dependencies\Microsoft.Data.OData.dll
LOG: Entering run-from-source setup phase.
LOG: Assembly Name is: Microsoft.Data.OData, Version=5.6.3.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35
WRN: Comparing the assembly name resulted in the mismatch: Build Number
ERR: The assembly reference did not match the assembly definition found.
ERR: Run-from-source setup phase failed with hr = 0x80131040.
ERR: Failed to complete setup of assembly (hr = 0x80131040). Probing terminated.

*** Assembly Binder Log Entry  (5/1/2015 @ 3:20:21 PM) ***

The operation failed.
Bind result: hr = 0x80131040. No description available.

Assembly manager loaded from:  C:\Windows\Microsoft.NET\Framework64\v4.0.30319\clr.dll
Running under executable  c:\windows\system32\inetsrv\w3wp.exe
--- A detailed error log follows. 

=== Pre-bind state information ===
LOG: DisplayName = Microsoft.Data.OData, Version=5.6.2.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35
 (Fully-specified)
LOG: Appbase = file:///C:/WWW/orchard 1.9-int/
LOG: Initial PrivatePath = C:\WWW\orchard 1.9-int\bin
LOG: Dynamic Base = C:\Windows\Microsoft.NET\Framework64\v4.0.30319\Temporary ASP.NET Files\root\aa2320a0
LOG: Cache Base = C:\Windows\Microsoft.NET\Framework64\v4.0.30319\Temporary ASP.NET Files\root\aa2320a0
LOG: AppName = 6d3135d0
Calling assembly : Microsoft.WindowsAzure.Storage, Version=4.3.0.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35.
===
LOG: This bind starts in default load context.
LOG: Using application configuration file: C:\WWW\orchard 1.9-int\web.config
LOG: Using host configuration file: C:\Windows\Microsoft.NET\Framework64\v4.0.30319\aspnet.config
LOG: Using machine configuration file from C:\Windows\Microsoft.NET\Framework64\v4.0.30319\config\machine.config.
LOG: Post-policy reference: Microsoft.Data.OData, Version=5.6.2.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35
LOG: GAC Lookup was unsuccessful.
LOG: Attempting download of new URL file:///C:/Windows/Microsoft.NET/Framework64/v4.0.30319/Temporary ASP.NET Files/root/aa2320a0/6d3135d0/Microsoft.Data.OData.DLL.
LOG: Attempting download of new URL file:///C:/Windows/Microsoft.NET/Framework64/v4.0.30319/Temporary ASP.NET Files/root/aa2320a0/6d3135d0/Microsoft.Data.OData/Microsoft.Data.OData.DLL.
LOG: Attempting download of new URL file:///C:/WWW/orchard 1.9-int/bin/Microsoft.Data.OData.DLL.
LOG: Attempting download of new URL file:///C:/WWW/orchard 1.9-int/bin/Microsoft.Data.OData/Microsoft.Data.OData.DLL.
LOG: Attempting download of new URL file:///C:/WWW/orchard 1.9-int/App_Data/Dependencies/Microsoft.Data.OData.DLL.
LOG: Assembly download was successful. Attempting setup of file: C:\WWW\orchard 1.9-int\App_Data\Dependencies\Microsoft.Data.OData.dll
LOG: Entering run-from-source setup phase.
LOG: Assembly Name is: Microsoft.Data.OData, Version=5.6.3.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35
WRN: Comparing the assembly name resulted in the mismatch: Build Number
ERR: The assembly reference did not match the assembly definition found.
ERR: Run-from-source setup phase failed with hr = 0x80131040.
ERR: Failed to complete setup of assembly (hr = 0x80131040). Probing terminated.

For 5.6.3.0 - which is successful:

*** Assembly Binder Log Entry  (5/1/2015 @ 3:20:03 PM) ***

The operation was successful.
Bind result: hr = 0x0. The operation completed successfully.

Assembly manager loaded from:  C:\Windows\Microsoft.NET\Framework64\v4.0.30319\clr.dll
Running under executable  c:\windows\system32\inetsrv\w3wp.exe
--- A detailed error log follows. 

=== Pre-bind state information ===
LOG: DisplayName = Microsoft.Data.OData
 (Partial)
WRN: Partial binding information was supplied for an assembly:
WRN: Assembly Name: Microsoft.Data.OData | Domain ID: 2
WRN: A partial bind occurs when only part of the assembly display name is provided.
WRN: This might result in the binder loading an incorrect assembly.
WRN: It is recommended to provide a fully specified textual identity for the assembly,
WRN: that consists of the simple name, version, culture, and public key token.
WRN: See whitepaper http://go.microsoft.com/fwlink/?LinkId=109270 for more information and common solutions to this issue.
LOG: Appbase = file:///C:/WWW/orchard 1.9-int/
LOG: Initial PrivatePath = C:\WWW\orchard 1.9-int\bin
LOG: Dynamic Base = C:\Windows\Microsoft.NET\Framework64\v4.0.30319\Temporary ASP.NET Files\root\aa2320a0
LOG: Cache Base = C:\Windows\Microsoft.NET\Framework64\v4.0.30319\Temporary ASP.NET Files\root\aa2320a0
LOG: AppName = 6d3135d0
Calling assembly : Orchard.Framework, Version=1.9.0.0, Culture=neutral, PublicKeyToken=null.
===
LOG: This bind starts in default load context.
LOG: Using application configuration file: C:\WWW\orchard 1.9-int\web.config
LOG: Using host configuration file: C:\Windows\Microsoft.NET\Framework64\v4.0.30319\aspnet.config
LOG: Using machine configuration file from C:\Windows\Microsoft.NET\Framework64\v4.0.30319\config\machine.config.
LOG: Policy not being applied to reference at this time (private, custom, partial, or location-based assembly bind).
LOG: Attempting download of new URL file:///C:/Windows/Microsoft.NET/Framework64/v4.0.30319/Temporary ASP.NET Files/root/aa2320a0/6d3135d0/Microsoft.Data.OData.DLL.
LOG: Attempting download of new URL file:///C:/Windows/Microsoft.NET/Framework64/v4.0.30319/Temporary ASP.NET Files/root/aa2320a0/6d3135d0/Microsoft.Data.OData/Microsoft.Data.OData.DLL.
LOG: Attempting download of new URL file:///C:/WWW/orchard 1.9-int/bin/Microsoft.Data.OData.DLL.
LOG: Attempting download of new URL file:///C:/WWW/orchard 1.9-int/bin/Microsoft.Data.OData/Microsoft.Data.OData.DLL.
LOG: Attempting download of new URL file:///C:/WWW/orchard 1.9-int/App_Data/Dependencies/Microsoft.Data.OData.DLL.
LOG: Assembly download was successful. Attempting setup of file: C:\WWW\orchard 1.9-int\App_Data\Dependencies\Microsoft.Data.OData.dll
LOG: Entering run-from-source setup phase.
LOG: Assembly Name is: Microsoft.Data.OData, Version=5.6.3.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35
LOG: A partially-specified assembly bind succeeded from the application directory. Need to re-apply policy.
LOG: Using application configuration file: C:\WWW\orchard 1.9-int\web.config
LOG: Using host configuration file: C:\Windows\Microsoft.NET\Framework64\v4.0.30319\aspnet.config
LOG: Using machine configuration file from C:\Windows\Microsoft.NET\Framework64\v4.0.30319\config\machine.config.
LOG: Post-policy reference: Microsoft.Data.OData, Version=5.6.3.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35
LOG: GAC Lookup was unsuccessful.
LOG: Binding succeeds. Returns assembly from C:\WWW\orchard 1.9-int\App_Data\Dependencies\Microsoft.Data.OData.dll.
LOG: Assembly is loaded in default load context.

*** Assembly Binder Log Entry  (5/1/2015 @ 3:20:03 PM) ***

The operation was successful.
Bind result: hr = 0x0. The operation completed successfully.

Assembly manager loaded from:  C:\Windows\Microsoft.NET\Framework64\v4.0.30319\clr.dll
Running under executable  c:\windows\system32\inetsrv\w3wp.exe
--- A detailed error log follows. 

=== Pre-bind state information ===
LOG: DisplayName = Microsoft.Data.OData
 (Partial)
WRN: Partial binding information was supplied for an assembly:
WRN: Assembly Name: Microsoft.Data.OData | Domain ID: 2
WRN: A partial bind occurs when only part of the assembly display name is provided.
WRN: This might result in the binder loading an incorrect assembly.
WRN: It is recommended to provide a fully specified textual identity for the assembly,
WRN: that consists of the simple name, version, culture, and public key token.
WRN: See whitepaper http://go.microsoft.com/fwlink/?LinkId=109270 for more information and common solutions to this issue.
LOG: Appbase = file:///C:/WWW/orchard 1.9-int/
LOG: Initial PrivatePath = C:\WWW\orchard 1.9-int\bin
LOG: Dynamic Base = C:\Windows\Microsoft.NET\Framework64\v4.0.30319\Temporary ASP.NET Files\root\aa2320a0
LOG: Cache Base = C:\Windows\Microsoft.NET\Framework64\v4.0.30319\Temporary ASP.NET Files\root\aa2320a0
LOG: AppName = 6d3135d0
Calling assembly : Orchard.Framework, Version=1.9.0.0, Culture=neutral, PublicKeyToken=null.
===
LOG: This bind starts in default load context.
LOG: Using application configuration file: C:\WWW\orchard 1.9-int\web.config
LOG: Using host configuration file: C:\Windows\Microsoft.NET\Framework64\v4.0.30319\aspnet.config
LOG: Using machine configuration file from C:\Windows\Microsoft.NET\Framework64\v4.0.30319\config\machine.config.
LOG: Policy not being applied to reference at this time (private, custom, partial, or location-based assembly bind).
LOG: Attempting download of new URL file:///C:/Windows/Microsoft.NET/Framework64/v4.0.30319/Temporary ASP.NET Files/root/aa2320a0/6d3135d0/Microsoft.Data.OData.DLL.
LOG: Attempting download of new URL file:///C:/Windows/Microsoft.NET/Framework64/v4.0.30319/Temporary ASP.NET Files/root/aa2320a0/6d3135d0/Microsoft.Data.OData/Microsoft.Data.OData.DLL.
LOG: Attempting download of new URL file:///C:/WWW/orchard 1.9-int/bin/Microsoft.Data.OData.DLL.
LOG: Attempting download of new URL file:///C:/WWW/orchard 1.9-int/bin/Microsoft.Data.OData/Microsoft.Data.OData.DLL.
LOG: Attempting download of new URL file:///C:/WWW/orchard 1.9-int/App_Data/Dependencies/Microsoft.Data.OData.DLL.
LOG: Assembly download was successful. Attempting setup of file: C:\WWW\orchard 1.9-int\App_Data\Dependencies\Microsoft.Data.OData.dll
LOG: Entering run-from-source setup phase.
LOG: Assembly Name is: Microsoft.Data.OData, Version=5.6.3.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35
LOG: A partially-specified assembly bind succeeded from the application directory. Need to re-apply policy.
LOG: Using application configuration file: C:\WWW\orchard 1.9-int\web.config
LOG: Using host configuration file: C:\Windows\Microsoft.NET\Framework64\v4.0.30319\aspnet.config
LOG: Using machine configuration file from C:\Windows\Microsoft.NET\Framework64\v4.0.30319\config\machine.config.
LOG: Post-policy reference: Microsoft.Data.OData, Version=5.6.3.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35
LOG: GAC Lookup was unsuccessful.
LOG: Binding succeeds. Returns assembly from C:\WWW\orchard 1.9-int\App_Data\Dependencies\Microsoft.Data.OData.dll.
LOG: Assembly is loaded in default load context.
dcinzona commented 9 years ago

I think I have it working... the web.config in Orchard.Web did not have assembly binding for OData 5.6.3. It's in the module web.config, but that isn't used so, I guess, it defaulted to 5.6.2? I will do some more testing, including a clean install, but you may want to consider adding it into the default Orchard Web.config so that others don't experience this issue.

      <dependentAssembly>
        <assemblyIdentity name="Microsoft.Data.Edm" publicKeyToken="31bf3856ad364e35" culture="neutral" />
        <bindingRedirect oldVersion="0.0.0.0-5.6.3.0" newVersion="5.6.3.0" />
      </dependentAssembly>
      <dependentAssembly>
        <assemblyIdentity name="Microsoft.Data.Services.Client" publicKeyToken="31bf3856ad364e35" culture="neutral" />
        <bindingRedirect oldVersion="0.0.0.0-5.6.3.0" newVersion="5.6.3.0" />
      </dependentAssembly>
      <dependentAssembly>
        <assemblyIdentity name="Microsoft.Data.OData" publicKeyToken="31bf3856ad364e35" culture="neutral" />
        <bindingRedirect oldVersion="0.0.0.0-5.6.3.0" newVersion="5.6.3.0" />
      </dependentAssembly>
DaRosenberg commented 9 years ago

Just pushed fix to 1.9-int. (Forgot to tag the commit with this work item, sorry.)

When Sipke and I updated to Azure SDK 2.5 we added this redirect to Orchard.Azure.Web but apparently forgot to add it to Orchard.Web. I assumed it was in Orchard.Web, that's why I suggested you try Fusion logging.

But yeah, the Web.config files in modules/themes have no effect, except for:

  1. Visual Studio editing experience (IntelliSense etc)
  2. Files that are actually served by IIS directly from the module folder (such as JS and CSS assets)

For anything else, the only Web.config file that is relevant is the one in the hosting assembly, i.e. Orchard.Web or Orchard.Azure.Web.

dcinzona commented 9 years ago

Excellent, yes, fusion logging definitely helped out. Thanks for getting that in 1.9-int!