From the documentation & samples provided in the latest release (DO 4.2) I cant setup proper logging of Sql-batches.. If I put in the app.config something like this: <logs> <log name="" provider="Console" events="Info,Debug"> <logs>

I see in the console output only messages from domain building (also sql-batches for creation of db), but not the sql-batches from my application. Any suggestions? Thanks, David


Updated at 12.04.2010 12:39:40

Sorry Dmitri, your solution doesn't help, I still do not get any Sql logging from my application. I use your sample 'Hello world', so you can try it yourself.

David


Updated at 12.04.2010 14:27:41

hmm, I used the this app.config:

<?xml version="1.0" encoding="utf-8" ?>
<configuration>
    <configSections>
        <section name="Xtensive.Core.Diagnostics" type="Xtensive.Core.Diagnostics.Configuration.ConfigurationSection, Xtensive.Core" />
        <section name="Xtensive.Storage" type="Xtensive.Storage.Configuration.Elements.ConfigurationSection, Xtensive.Storage" />
    </configSections>
    <Xtensive.Core.Diagnostics>
        <logs>
            <log name="Storage.Providers.Sql" events="Debug,Info" provider="File" fileName="sqloutput.log"/>
        </logs>
    </Xtensive.Core.Diagnostics>
    <Xtensive.Storage>
        <domains>
            <domain name="Default" upgradeMode="Recreate" connectionUrl="sqlserver://localhost/DO4-Tests" >
                <types>
                    <add assembly="Xtensive.Storage.Samples.HelloWorld" namespace="Xtensive.Storage.Samples.HelloWorld" />
                </types>
            </domain>
        </domains>
    </Xtensive.Storage>
</configuration>

and got this log results:

1.24s/T10     Info Storage.Providers.Sql        Session 'System, #1'. Schema upgrade script:
                                                  ALTER TABLE [dbo].[MyEntity-Others-MyEntity] DROP CONSTRAINT [FK_MyEntity-Others-MyEntity_Master];
                                                  ALTER TABLE [dbo].[MyEntity-Others-MyEntity] DROP CONSTRAINT [FK_MyEntity-Others-MyEntity_Slave];
                                                  DROP TABLE [dbo].[Metadata.Assembly];
                                                  DROP TABLE [dbo].[Metadata.Type];
                                                  DROP TABLE [dbo].[Metadata.Extension];
                                                  DROP TABLE [dbo].[MyEntity];
                                                  DROP TABLE [dbo].[MyEntity-Others-MyEntity];
  1.29s/T10     Info Storage.Providers.Sql        Session 'System, #1'. Schema upgrade script:
                                                  CREATE TABLE [dbo].[Metadata.Assembly] ([Name] nvarchar(1024) NOT NULL,
                                                  [Version] nvarchar(64) DEFAULT NULL,
                                                  CONSTRAINT [PK_Assembly] PRIMARY KEY ([Name]));
                                                  CREATE TABLE [dbo].[Metadata.Type] ([Id] integer NOT NULL,
                                                  [Name] nvarchar(1000) DEFAULT NULL,
                                                  CONSTRAINT [PK_Type] PRIMARY KEY ([Id]));
                                                  CREATE UNIQUE INDEX [Type.IX_Name] ON [dbo].[Metadata.Type] ([Name] ASC);
                                                  CREATE TABLE [dbo].[Metadata.Extension] ([Name] nvarchar(1024) NOT NULL,
                                                  [Text] nvarchar(max) DEFAULT NULL,
                                                  [Data] varbinary(max) DEFAULT NULL,
                                                  CONSTRAINT [PK_Extension] PRIMARY KEY ([Name]));
                                                  CREATE TABLE [dbo].[MyEntity] ([Id] uniqueidentifier NOT NULL,
                                                  [Text] nvarchar(100) DEFAULT NULL,
                                                  [_text] nvarchar(100) DEFAULT NULL,
                                                  CONSTRAINT [PK_MyEntity] PRIMARY KEY ([Id]));
                                                  CREATE TABLE [dbo].[MyEntity-Others-MyEntity] ([Master.Id] uniqueidentifier NOT NULL,
                                                  [Slave.Id] uniqueidentifier NOT NULL,
                                                  CONSTRAINT [PK_MyEntity-Others-MyEntity] PRIMARY KEY ([Master.Id], [Slave.Id]));
                                                  CREATE INDEX [MyEntity-Others-MyEntity.FK_Master] ON [dbo].[MyEntity-Others-MyEntity] ([Master.Id] ASC);
                                                  CREATE INDEX [MyEntity-Others-MyEntity.FK_Slave] ON [dbo].[MyEntity-Others-MyEntity] ([Slave.Id] ASC);
                                                  ALTER TABLE [dbo].[MyEntity-Others-MyEntity] ADD CONSTRAINT [FK_MyEntity-Others-MyEntity_Master] FOREIGN KEY ([Master.Id]) REFERENCES [dbo].[MyEntity] ([Id]);
                                                  ALTER TABLE [dbo].[MyEntity-Others-MyEntity] ADD CONSTRAINT [FK_MyEntity-Others-MyEntity_Slave] FOREIGN KEY ([Slave.Id]) REFERENCES [dbo].[MyEntity] ([Id]);

I downloaded the DataObjects.Net 4.2 install-package and used the samples solution, e.g. the Hello World sample..

Edit: althrough not the same log-output as yours Alexi, I still can get the sql batches with the Sql Profiler, which is ok for now..

thanks anyway,

David


Updated at 13.04.2010 6:33:19

I tried the log4net integration as you suggested. The logging output is almost the same as from integrated, the Hello World sql-queries are still missing. It (integrated or log4net) loggs everything except the application queries, as it would ignore it.. I try to download source files and Samples from your repository so I can double check..

David


Updated at 13.04.2010 11:44:47

I cloned the 'stable' branch from repository. Then built it. Run the HelloWorld sample. Log output is the same without application sql-batches... ok I give up, if it works on your side, propably I am doing something wrong, even if I don't know what.. For now I can live with sql profiler ;)

David

This thread was imported from our support forum. The original discussion may contain more detailed answer. Original topic by david_csharp.

asked Apr 12 '10 at 06:08

Editor's gravatar image

Editor
46156156157

edited Sep 08 '10 at 06:16

Alex%20Yakunin's gravatar image

Alex Yakunin
29714412

Hello David,

Add the following logger to your logging configuration:

<log name="Storage.Providers.Sql" provider="Console" events="Info,Debug">

(Apr 12 '10 at 06:08) Dmitri Maximov Dmitri%20Maximov's gravatar image

One Answer:

Dmitri Maximov (Xtensive) wrote:

David, try using the following app.config:

<?xml version="1.0" encoding="utf-8" ?>
<configuration>
  <configSections>
    <section name="Xtensive.Core.Diagnostics" type="Xtensive.Core.Diagnostics.Configuration.ConfigurationSection, Xtensive.Core" />
    <section name="Xtensive.Storage" type="Xtensive.Storage.Configuration.Elements.ConfigurationSection, Xtensive.Storage" />
  </configSections>
  <Xtensive.Core.Diagnostics>
    <logs>
      <log name="Storage.Providers.Sql" events="Info,Debug" provider="Console"/>
    </logs>
  </Xtensive.Core.Diagnostics>
  <Xtensive.Storage>
    <domains>
      <domain name="Default" upgradeMode="Recreate" connectionUrl="sqlserver://localhost/DO40-Tests" >
        <types>
          <add assembly="Xtensive.Storage.Samples.HelloWorld" namespace="Xtensive.Storage.Samples.HelloWorld" />
        </types>
      </domain>
    </domains>
  </Xtensive.Storage>
</configuration>

Alex (Xtensive) wrote:

I just tested exactly this App.config with HelloWorld sample and got the following output:

1,47s/T1     Debug Storage.Providers.Sql      Session 'System, #1'. Creating connection 'sqlserver://localhost/DO40-Tests'.
  1,48s/T1     Debug Storage.Providers.Sql      Session 'System, #1'. Opening connection 'sqlserver://localhost/DO40-Tests'.
  1,48s/T1     Debug Storage.Providers.Sql      Session 'System, #1'. Beginning transaction @ RepeatableRead.
  2,12s/T1      Info Storage.Providers.Sql        Session 'System, #1'. Schema upgrade script:
                                                  DROP TABLE [dbo].[Int32-Generator];
                                                  DROP TABLE [dbo].[Metadata.Assembly];
                                                  DROP TABLE [dbo].[Metadata.Type];
                                                  DROP TABLE [dbo].[Metadata.Extension];
                                                  DROP TABLE [dbo].[MyEntity];
  2,12s/T1     Debug Storage.Providers.Sql        Session 'n/a'. SQL batch: 
                                                  DROP TABLE [dbo].[Int32-Generator];
                                                  DROP TABLE [dbo].[Metadata.Assembly];
                                                  DROP TABLE [dbo].[Metadata.Type];
                                                  DROP TABLE [dbo].[Metadata.Extension];
                                                  DROP TABLE [dbo].[MyEntity];
  2,22s/T1      Info Storage.Providers.Sql        Session 'System, #1'. Schema upgrade script:
                                                  CREATE TABLE [dbo].[Metadata.Assembly] ([Name] nvarchar(1024) NOT NULL,
                                                  [Version] nvarchar(64) DEFAULT NULL,
                                                  CONSTRAINT [PK_Assembly] PRIMARY KEY ([Name]));
                                                  CREATE TABLE [dbo].[Metadata.Type] ([Id] integer NOT NULL,
                                                  [Name] nvarchar(1000) DEFAULT NULL,
                                                  CONSTRAINT [PK_Type] PRIMARY KEY ([Id]));
                                                  CREATE UNIQUE INDEX [Type.IX_Name] ON [dbo].[Metadata.Type] ([Name] ASC);
                                                  CREATE TABLE [dbo].[Metadata.Extension] ([Name] nvarchar(1024) NOT NULL,
                                                  [Text] nvarchar(max) DEFAULT NULL,
                                                  [Data] varbinary(max) DEFAULT NULL,
                                                  CONSTRAINT [PK_Extension] PRIMARY KEY ([Name]));
                                                  CREATE TABLE [dbo].[MyEntity] ([Id] integer NOT NULL,
                                                  [Text] nvarchar(100) DEFAULT NULL,
                                                  CONSTRAINT [PK_MyEntity] PRIMARY KEY ([Id]));
                                                  CREATE TABLE [dbo].[Int32-Generator] ([ID] integer IDENTITY (128, 128) NOT NULL,
                                                  CONSTRAINT [PK_Int32-Generator] PRIMARY KEY ([ID]));
  2,22s/T1     Debug Storage.Providers.Sql        Session 'n/a'. SQL batch: 
                                                  CREATE TABLE [dbo].[Metadata.Assembly] ([Name] nvarchar(1024) NOT NULL,
                                                  [Version] nvarchar(64) DEFAULT NULL,
                                                  CONSTRAINT [PK_Assembly] PRIMARY KEY ([Name]));
                                                  CREATE TABLE [dbo].[Metadata.Type] ([Id] integer NOT NULL,
                                                  [Name] nvarchar(1000) DEFAULT NULL,
                                                  CONSTRAINT [PK_Type] PRIMARY KEY ([Id]));
                                                  CREATE UNIQUE INDEX [Type.IX_Name] ON [dbo].[Metadata.Type] ([Name] ASC);
                                                  CREATE TABLE [dbo].[Metadata.Extension] ([Name] nvarchar(1024) NOT NULL,
                                                  [Text] nvarchar(max) DEFAULT NULL,
                                                  [Data] varbinary(max) DEFAULT NULL,
                                                  CONSTRAINT [PK_Extension] PRIMARY KEY ([Name]));
                                                  CREATE TABLE [dbo].[MyEntity] ([Id] integer NOT NULL,
                                                  [Text] nvarchar(100) DEFAULT NULL,
                                                  CONSTRAINT [PK_MyEntity] PRIMARY KEY ([Id]));
                                                  CREATE TABLE [dbo].[Int32-Generator] ([ID] integer IDENTITY (128, 128) NOT NULL,
                                                  CONSTRAINT [PK_Int32-Generator] PRIMARY KEY ([ID]));
  2,73s/T1     Debug Storage.Providers.Sql      Session 'System, #1'. SQL batch: 
                                                SELECT [a].[Name], 2 AS [TypeId], [a].[Version] FROM [dbo].[Metadata.Assembly] [a];
  2,95s/T1     Debug Storage.Providers.Sql      Session 'System, #1'. SQL batch: 
                                                INSERT INTO [dbo].[Metadata.Assembly] ([Name], [Version]) VALUES (@p1_0, @p1_1);
                                                INSERT INTO [dbo].[Metadata.Assembly] ([Name], [Version]) VALUES (@p2_0, @p2_1);
                                                SELECT [a].[Id], 1 AS [TypeId], [a].[Name] FROM [dbo].[Metadata.Type] [a]; [p1_0='Xtensive.Storage';p1_1='1.0.0.0';p2_0='Xtensive.Storage.Samples.HelloWorld';p2_1='1.0.0.0']
  2,97s/T1     Debug Storage.Providers.Sql      Session 'System, #1'. SQL batch: 
                                                SELECT [a].[Id], 1 AS [TypeId], [a].[Name] FROM [dbo].[Metadata.Type] [a];
  3,24s/T1     Debug Storage.Providers.Sql      Session 'System, #1'. SQL batch: 
                                                INSERT INTO [dbo].[Metadata.Type] ([Id], [Name]) VALUES (@p1_0, @p1_1);
                                                INSERT INTO [dbo].[Metadata.Type] ([Id], [Name]) VALUES (@p2_0, @p2_1);
                                                INSERT INTO [dbo].[Metadata.Type] ([Id], [Name]) VALUES (@p3_0, @p3_1);
                                                INSERT INTO [dbo].[Metadata.Type] ([Id], [Name]) VALUES (@p4_0, @p4_1);
                                                SELECT TOP 2 [a].[Name], 3 AS [TypeId], [a].[Text], [a].[Data] FROM [dbo].[Metadata.Extension] [a] WHERE ([a].[Name] = 'Xtensive.Storage.Model') ORDER BY [a].[Name] ASC; [p1_0='2';p1_1='Xtensive.Storage.Metadata.Assembly';p2_0='1';p2_1='Xtensive.Storage.Metadata.Type';p3_0='3';p3_1='Xtensive.Storage.Metadata.Extension';p4_0='101';p4_1='Xtensive.Storage.Samples.HelloWorld.Model.MyEntity']
  3,79s/T1     Debug Storage.Providers.Sql      Session 'System, #1'. SQL batch: 
                                                INSERT INTO [dbo].[Metadata.Extension] ([Name], [Text], [Data]) VALUES (@p1_0, @p1_1, @p1_2); [p1_0='Xtensive.Storage.Model';p1_1='<?xml version="1.0" encoding="utf-16"?>
                                                <DomainModel xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xmlns:xsd="http://www.w3.org/2001/XMLSchema">
                                                  <Types>
                                                    <Type>
                                                      <Name>Structure</Name>
                                                      <MappingName>Structure</MappingName>
                                                      <UnderlyingType>Xtensive.Storage.Structure</UnderlyingType>
                                                      <TypeId>102</TypeId>
                                                      <Fields />
                                                      <Associations />
                                                      <IsStructure>true</IsStructure>
                                                    </Type>
                                                    <Type>
                                                      <Name>Assembly</Name>
                                                      <MappingName>Metadata.Assembly</MappingName>
                                                      <UnderlyingType>Xtensive.Storage.Metadata.Assembly</UnderlyingType>
                                                      <TypeId>2</TypeId>
                                                      <HierarchyRoot>ConcreteTable</HierarchyRoot>
                                                      <Fields>
                                                        <Field>
                                                          <Name>Name</Name>
                                                          <MappingName>Name</MappingName>
                                                          <PropertyName>Name</PropertyName>
                                                          <OriginalName>Name</OriginalName>
                                                          <ValueType>System.String</ValueType>
                                                          <Fields />
                                                          <Length>1024</Length>
                                                          <IsPrimaryKey>true</IsPrimaryKey>
                                                          <IsPrimitive>true</IsPrimitive>
                                                        </Field>
                                                        <Field>
                                                          <Name>TypeId</Name>
                                                          <MappingName>TypeId</MappingName>
                                                          <PropertyName>TypeId</PropertyName>
                                                          <OriginalName>TypeId</OriginalName>
                                                          <ValueType>System.Int32</ValueType>
                                                          <Fields />
                                                          <IsSystem>true</IsSystem>
                                                          <IsTypeId>true</IsTypeId>
                                                          <IsPrimitive>true</IsPrimitive>
                                                        </Field>
                                                        <Field>
                                                          <Name>Version</Name>
                                                          <MappingName>Version</MappingName>
                                                          <PropertyName>Version</PropertyName>
                                                          <OriginalName>Version</OriginalName>
                                                          <ValueType>System.String</ValueType>
                                                          <Fields />
                                                          <Length>64</Length>
                                                          <IsPrimitive>true</IsPrimitive>
                                                          <IsNullable>true</IsNullable>
                                                        </Field>
                                                      </Fields>
                                                      <Associations />
                                                      <IsEntity>true</IsEntity>
                                                      <IsSystem>true</IsSystem>
                                                    </Type>
                                                    <Type>
                                                      <Name>Type</Name>
                                                      <MappingName>Metadata.Type</MappingName>
                                                      <UnderlyingType>Xtensive.Storage.Metadata.Type</UnderlyingType>
                                                      <TypeId>1</TypeId>
                                                      <HierarchyRoot>ConcreteTable</HierarchyRoot>
                                                      <Fields>
                                                        <Field>
                                                          <Name>Id</Name>
                                                          <MappingName>Id</MappingName>
                                                          <PropertyName>Id</PropertyName>
                                                          <OriginalName>Id</OriginalName>
                                                          <ValueType>System.Int32</ValueType>
                                                          <Fields />
                                                          <IsPrimaryKey>true</IsPrimaryKey>
                                                          <IsPrimitive>true</IsPrimitive>
                                                        </Field>
                                                        <Field>
                                                          <Name>TypeId</Name>
                                                          <MappingName>TypeId</MappingName>
                                                          <PropertyName>TypeId</PropertyName>
                                                          <OriginalName>TypeId</OriginalName>
                                                          <ValueType>System.Int32</ValueType>
                                                          <Fields />
                                                          <IsSystem>true</IsSystem>
                                                          <IsTypeId>true</IsTypeId>
                                                          <IsPrimitive>true</IsPrimitive>
                                                        </Field>
                                                        <Field>
                                                          <Name>Name</Name>
                                                          <MappingName>Name</MappingName>
                                                          <PropertyName>Name</PropertyName>
                                                          <OriginalName>Name</OriginalName>
                                                          <ValueType>System.String</ValueType>
                                                          <Fields />
                                                          <Length>1000</Length>
                                                          <IsPrimitive>true</IsPrimitive>
                                                          <IsNullable>true</IsNullable>
                                                        </Field>
                                                      </Fields>
                                                      <Associations />
                                                      <IsEntity>true</IsEntity>
                                                      <IsSystem>true</IsSystem>
                                                    </Type>
                                                    <Type>
                                                      <Name>Extension</Name>
                                                      <MappingName>Metadata.Extension</MappingName>
                                                      <UnderlyingType>Xtensive.Storage.Metadata.Extension</UnderlyingType>
                                                      <TypeId>3</TypeId>
                                                      <HierarchyRoot>ConcreteTable</HierarchyRoot>
                                                      <Fields>
                                                        <Field>
                                                          <Name>Name</Name>
                                                          <MappingName>Name</MappingName>
                                                          <PropertyName>Name</PropertyName>
                                                          <OriginalName>Name</OriginalName>
                                                          <ValueType>System.String</ValueType>
                                                          <Fields />
                                                          <Length>1024</Length>
                                                          <IsPrimaryKey>true</IsPrimaryKey>
                                                          <IsPrimitive>true</IsPrimitive>
                                                        </Field>
                                                        <Field>
                                                          <Name>TypeId</Name>
                                                          <MappingName>TypeId</MappingName>
                                                          <PropertyName>TypeId</PropertyName>
                                                          <OriginalName>TypeId</OriginalName>
                                                          <ValueType>System.Int32</ValueType>
                                                          <Fields />
                                                          <IsSystem>true</IsSystem>
                                                          <IsTypeId>true</IsTypeId>
                                                          <IsPrimitive>true</IsPrimitive>
                                                        </Field>
                                                        <Field>
                                                          <Name>Text</Name>
                                                          <MappingName>Text</MappingName>
                                                          <PropertyName>Text</PropertyName>
                                                          <OriginalName>Text</OriginalName>
                                                          <ValueType>System.String</ValueType>
                                                          <Fields />
                                                          <Length>2147483647</Length>
                                                          <IsPrimitive>true</IsPrimitive>
                                                          <IsNullable>true</IsNullable>
                                                        </Field>
                                                        <Field>
                                                          <Name>Data</Name>
                                                          <MappingName>Data</MappingName>
                                                          <PropertyName>Data</PropertyName>
                                                          <OriginalName>Data</OriginalName>
                                                          <ValueType>System.Byte[]</ValueType>
                                                          <Fields />
                                                          <Length>2147483647</Length>
                                                          <IsPrimitive>true</IsPrimitive>
                                                          <IsNullable>true</IsNullable>
                                                        </Field>
                                                      </Fields>
                                                      <Associations />
                                                      <IsEntity>true</IsEntity>
                                                      <IsSystem>true</IsSystem>
                                                    </Type>
                                                    <Type>
                                                      <Name>MyEntity</Name>
                                                      <MappingName>MyEntity</MappingName>
                                                      <UnderlyingType>Xtensive.Storage.Samples.HelloWorld.Model.MyEntity</UnderlyingType>
                                                      <TypeId>101</TypeId>
                                                      <HierarchyRoot>ConcreteTable</HierarchyRoot>
                                                      <Fields>
                                                        <Field>
                                                          <Name>Id</Name>
                                                          <MappingName>Id</MappingName>
                                                          <PropertyName>Id</PropertyName>
                                                          <OriginalName>Id</OriginalName>
                                                          <ValueType>System.Int32</ValueType>
                                                          <Fields />
                                                          <IsPrimaryKey>true</IsPrimaryKey>
                                                          <IsPrimitive>true</IsPrimitive>
                                                        </Field>
                                                        <Field>
                                                          <Name>TypeId</Name>
                                                          <MappingName>TypeId</MappingName>
                                                          <PropertyName>TypeId</PropertyName>
                                                          <OriginalName>TypeId</OriginalName>
                                                          <ValueType>System.Int32</ValueType>
                                                          <Fields />
                                                          <IsSystem>true</IsSystem>
                                                          <IsTypeId>true</IsTypeId>
                                                          <IsPrimitive>true</IsPrimitive>
                                                        </Field>
                                                        <Field>
                                                          <Name>Text</Name>
                                                          <MappingName>Text</MappingName>
                                                          <PropertyName>Text</PropertyName>
                                                          <OriginalName>Text</OriginalName>
                                                          <ValueType>System.String</ValueType>
                                                          <Fields />
                                                          <Length>100</Length>
                                                          <IsPrimitive>true</IsPrimitive>
                                                          <IsNullable>true</IsNullable>
                                                        </Field>
                                                      </Fields>
                                                      <Associations />
                                                      <IsEntity>true</IsEntity>
                                                    </Type>
                                                  </Types>
                                                </DomainModel>';p1_2='']
  3,95s/T1     Debug Storage.Providers.Sql      Session 'System, #1'. Commit transaction.
  3,97s/T1     Debug Storage.Providers.Sql      Session 'System, #1'. Closing connection 'sqlserver://localhost/DO40-Tests'.
  3,98s/T1     Debug Storage.Providers.Sql    Session 'Default, #2'. Creating connection 'sqlserver://localhost/DO40-Tests'.
  3,98s/T1     Debug Storage.Providers.Sql    Session 'Default, #2'. Opening connection 'sqlserver://localhost/DO40-Tests'.
  3,98s/T1     Debug Storage.Providers.Sql    Session 'Default, #2'. Beginning transaction @ RepeatableRead.
  4,02s/T1     Debug Storage.Providers.Sql    Session 'KeyGenerator, #3'. Creating connection 'sqlserver://localhost/DO40-Tests'.
  4,02s/T1     Debug Storage.Providers.Sql    Session 'KeyGenerator, #3'. Opening connection 'sqlserver://localhost/DO40-Tests'.
  4,02s/T1     Debug Storage.Providers.Sql    Session 'KeyGenerator, #3'. Beginning transaction @ RepeatableRead.
  4,02s/T1     Debug Storage.Providers.Sql    Session 'KeyGenerator, #3'. SQL batch: 
                                              INSERT INTO [dbo].[Int32-Generator] DEFAULT VALUES;
                                              SELECT SCOPE_IDENTITY();
  4,04s/T1     Debug Storage.Providers.Sql    Session 'KeyGenerator, #3'. Rollback transaction.
  4,04s/T1     Debug Storage.Providers.Sql    Session 'KeyGenerator, #3'. Closing connection 'sqlserver://localhost/DO40-Tests'.
  4,04s/T1     Debug Storage.Providers.Sql    Session 'Default, #2'. SQL batch: 
                                              INSERT INTO [dbo].[MyEntity] ([Id], [Text]) VALUES (@p1_0, @p1_1); [p1_0='1';p1_1='Hello World!']
  4,05s/T1     Debug Storage.Providers.Sql    Session 'Default, #2'. Commit transaction.
  4,05s/T1     Debug Storage.Providers.Sql    Session 'Default, #2'. Closing connection 'sqlserver://localhost/DO40-Tests'.
  4,05s/T1     Debug Storage.Providers.Sql    Session 'Default, #4'. Creating connection 'sqlserver://localhost/DO40-Tests'.
  4,05s/T1     Debug Storage.Providers.Sql    Session 'Default, #4'. Opening connection 'sqlserver://localhost/DO40-Tests'.
  4,05s/T1     Debug Storage.Providers.Sql    Session 'Default, #4'. Beginning transaction @ RepeatableRead.
  4,06s/T1     Debug Storage.Providers.Sql    Session 'Default, #4'. SQL batch: 
                                              SELECT [a].[Id], 101 AS [TypeId], [a].[Text] FROM [dbo].[MyEntity] [a];
Hello World!
  4,08s/T1     Debug Storage.Providers.Sql    Session 'Default, #4'. Commit transaction.
  4,08s/T1     Debug Storage.Providers.Sql    Session 'Default, #4'. Closing connection 'sqlserver://localhost/DO40-Tests'.

So everything works as expected. Have you tried exactly the same?


Alex (Xtensive) wrote:

Tested the same with all log scopes & events enabled (<log name="" events="All" provider="Console"/>):

0,11s/T1      Info Core.Diagnostics         Core.Diagnostics log initialized.
  0,11s/T1      Info Core.Diagnostics         Storage.Building log initialized.
  0,11s/T1      Info Storage.Building         Building Domain: started.
  0,12s/T1      Info Storage.Building           Creating Domain: started.
  0,13s/T1      Info Core.Diagnostics             Storage log initialized.
  0,16s/T1      Info Storage.Building           Creating Domain: completed.

... The part is removed, since PhpBB considers original message too large.

  1,52s/T1      Info Storage.Building           Building Model: completed.
  1,52s/T1      Info Storage.Building           Building Key generators: started.
  1,57s/T1      Info Storage.Building           Building Key generators: completed.
  1,57s/T1     Debug Storage                    Opening session 'Name = System, UserName = <null>, Options = Default, CacheType = LruWeak, CacheSize = 16384, DefaultIsolationLevel = RepeatableRead'.
  1,64s/T1     Debug Storage                    Session 'System, #1'. Opening transaction.
  1,74s/T1     Debug Storage.Providers.Sql      Session 'System, #1'. Creating connection 'sqlserver://localhost/DO40-Tests'.
  1,74s/T1     Debug Storage.Providers.Sql      Session 'System, #1'. Opening connection 'sqlserver://localhost/DO40-Tests'.
  1,75s/T1     Debug Storage.Providers.Sql      Session 'System, #1'. Beginning transaction @ RepeatableRead.
  1,75s/T1     Debug Storage                    Session 'System, #1'. Opened transaction.
  1,75s/T1      Info Storage.Building           Synchronizing schema in Recreate mode.: started.
  1,97s/T1      Info Storage.Building             Target schema:
  1,97s/T1      Info Core.Diagnostics             Modelling log initialized.
  1,98s/T1      Info Modelling                    StorageInfo "./"
  1,98s/T1      Info Modelling                      +Tables (4):
  1,98s/T1      Info Modelling                        TableInfo "./Tables/Metadata.Assembly"
  1,98s/T1      Info Modelling                          +Columns (2):
  1,98s/T1      Info Modelling                            ColumnInfo "./Tables/Metadata.Assembly/Columns/Name"
  2,08s/T1      Info Modelling                              +Type = Type: String, Length: 1024 (TypeInfo)
  2,08s/T1      Info Modelling                            ColumnInfo "./Tables/Metadata.Assembly/Columns/Version"
  2,08s/T1      Info Modelling                              +Type = Type: String?, Length: 64 (TypeInfo)
  2,08s/T1      Info Modelling                          +PrimaryIndex:
  2,18s/T1      Info Modelling                            PrimaryIndexInfo "./Tables/Metadata.Assembly/PrimaryIndex (PK_Assembly)"
  2,20s/T1      Info Modelling                              +IsUnique = True (Boolean)
  2,20s/T1      Info Modelling                              +KeyColumns (1):
  2,20s/T1      Info Modelling                                0: KeyColumnRef "./Tables/Metadata.Assembly/PrimaryIndex/KeyColumns/0"
  2,20s/T1      Info Modelling                                  +Direction = Positive (Direction)
  2,20s/T1      Info Modelling                                  +Value = ./Tables/Metadata.Assembly/Columns/Name (ColumnInfo)
  2,20s/T1      Info Modelling                              +ValueColumns (1):
  2,20s/T1      Info Modelling                                ValueColumnRef "./Tables/Metadata.Assembly/PrimaryIndex/ValueColumns/0"
  2,20s/T1      Info Modelling                                  +Value = ./Tables/Metadata.Assembly/Columns/Version (ColumnInfo)
  2,20s/T1      Info Modelling                              +IsPrimary = True (Boolean)
  2,20s/T1      Info Modelling                          +SecondaryIndexes:
  2,20s/T1      Info Modelling                            None
  2,20s/T1      Info Modelling                          +ForeignKeys:
  2,20s/T1      Info Modelling                            None
  2,20s/T1      Info Modelling                          +FullTextIndexes:
  2,20s/T1      Info Modelling                            None
  2,20s/T1      Info Modelling                        TableInfo "./Tables/Metadata.Type"
  2,20s/T1      Info Modelling                          +Columns (2):
  2,20s/T1      Info Modelling                            ColumnInfo "./Tables/Metadata.Type/Columns/Id"
  2,20s/T1      Info Modelling                              +Type = Type: Int32, Length: null (TypeInfo)
  2,20s/T1      Info Modelling                              +DefaultValue = 0 (Int32)
  2,20s/T1      Info Modelling                            ColumnInfo "./Tables/Metadata.Type/Columns/Name"
  2,20s/T1      Info Modelling                              +Type = Type: String?, Length: 1000 (TypeInfo)
  2,20s/T1      Info Modelling                          +PrimaryIndex:
  2,20s/T1      Info Modelling                            PrimaryIndexInfo "./Tables/Metadata.Type/PrimaryIndex (PK_Type)"
  2,21s/T1      Info Modelling                              +IsUnique = True (Boolean)
  2,21s/T1      Info Modelling                              +KeyColumns (1):
  2,21s/T1      Info Modelling                                0: KeyColumnRef "./Tables/Metadata.Type/PrimaryIndex/KeyColumns/0"
  2,21s/T1      Info Modelling                                  +Direction = Positive (Direction)
  2,21s/T1      Info Modelling                                  +Value = ./Tables/Metadata.Type/Columns/Id (ColumnInfo)
  2,21s/T1      Info Modelling                              +ValueColumns (1):
  2,21s/T1      Info Modelling                                ValueColumnRef "./Tables/Metadata.Type/PrimaryIndex/ValueColumns/0"
  2,21s/T1      Info Modelling                                  +Value = ./Tables/Metadata.Type/Columns/Name (ColumnInfo)
  2,21s/T1      Info Modelling                              +IsPrimary = True (Boolean)
  2,21s/T1      Info Modelling                          +SecondaryIndexes (1):
  2,21s/T1      Info Modelling                            SecondaryIndexInfo "./Tables/Metadata.Type/SecondaryIndexes/Type.IX_Name"
  2,22s/T1      Info Modelling                              +IsUnique = True (Boolean)
  2,22s/T1      Info Modelling                              +KeyColumns (1):
  2,22s/T1      Info Modelling                                0: KeyColumnRef "./Tables/Metadata.Type/SecondaryIndexes/Type.IX_Name/KeyColumns/0"
  2,22s/T1      Info Modelling                                  +Direction = Positive (Direction)
  2,22s/T1      Info Modelling                                  +Value = ./Tables/Metadata.Type/Columns/Name (ColumnInfo)
  2,22s/T1      Info Modelling                              +PrimaryKeyColumns (1):
  2,22s/T1      Info Modelling                                0: PrimaryKeyColumnRef "./Tables/Metadata.Type/SecondaryIndexes/Type.IX_Name/PrimaryKeyColumns/0"
  2,22s/T1      Info Modelling                                  +Direction = Positive (Direction)
  2,22s/T1      Info Modelling                                  +Value = ./Tables/Metadata.Type/Columns/Id (ColumnInfo)
  2,22s/T1      Info Modelling                              +IncludedColumns:
  2,22s/T1      Info Modelling                                None
  2,22s/T1      Info Modelling                          +ForeignKeys:
  2,22s/T1      Info Modelling                            None
  2,22s/T1      Info Modelling                          +FullTextIndexes:
  2,22s/T1      Info Modelling                            None
  2,22s/T1      Info Modelling                        TableInfo "./Tables/Metadata.Extension"
  2,22s/T1      Info Modelling                          +Columns (3):
  2,22s/T1      Info Modelling                            ColumnInfo "./Tables/Metadata.Extension/Columns/Name"
  2,22s/T1      Info Modelling                              +Type = Type: String, Length: 1024 (TypeInfo)
  2,22s/T1      Info Modelling                            ColumnInfo "./Tables/Metadata.Extension/Columns/Text"
  2,22s/T1      Info Modelling                              +Type = Type: String?, Length: null (TypeInfo)
  2,22s/T1      Info Modelling                            ColumnInfo "./Tables/Metadata.Extension/Columns/Data"
  2,22s/T1      Info Modelling                              +Type = Type: Byte[]?, Length: null (TypeInfo)
  2,22s/T1      Info Modelling                          +PrimaryIndex:
  2,22s/T1      Info Modelling                            PrimaryIndexInfo "./Tables/Metadata.Extension/PrimaryIndex (PK_Extension)"
  2,22s/T1      Info Modelling                              +IsUnique = True (Boolean)
  2,22s/T1      Info Modelling                              +KeyColumns (1):
  2,22s/T1      Info Modelling                                0: KeyColumnRef "./Tables/Metadata.Extension/PrimaryIndex/KeyColumns/0"
  2,22s/T1      Info Modelling                                  +Direction = Positive (Direction)
  2,22s/T1      Info Modelling                                  +Value = ./Tables/Metadata.Extension/Columns/Name (ColumnInfo)
  2,22s/T1      Info Modelling                              +ValueColumns (2):
  2,22s/T1      Info Modelling                                ValueColumnRef "./Tables/Metadata.Extension/PrimaryIndex/ValueColumns/0"
  2,22s/T1      Info Modelling                                  +Value = ./Tables/Metadata.Extension/Columns/Text (ColumnInfo)
  2,22s/T1      Info Modelling                                ValueColumnRef "./Tables/Metadata.Extension/PrimaryIndex/ValueColumns/1"
  2,22s/T1      Info Modelling                                  +Value = ./Tables/Metadata.Extension/Columns/Data (ColumnInfo)
  2,22s/T1      Info Modelling                              +IsPrimary = True (Boolean)
  2,22s/T1      Info Modelling                          +SecondaryIndexes:
  2,22s/T1      Info Modelling                            None
  2,22s/T1      Info Modelling                          +ForeignKeys:
  2,22s/T1      Info Modelling                            None
  2,22s/T1      Info Modelling                          +FullTextIndexes:
  2,22s/T1      Info Modelling                            None
  2,22s/T1      Info Modelling                        TableInfo "./Tables/MyEntity"
  2,22s/T1      Info Modelling                          +Columns (2):
  2,22s/T1      Info Modelling                            ColumnInfo "./Tables/MyEntity/Columns/Id"
  2,22s/T1      Info Modelling                              +Type = Type: Int32, Length: null (TypeInfo)
  2,22s/T1      Info Modelling                              +DefaultValue = 0 (Int32)
  2,22s/T1      Info Modelling                            ColumnInfo "./Tables/MyEntity/Columns/Text"
  2,22s/T1      Info Modelling                              +Type = Type: String?, Length: 100 (TypeInfo)
  2,22s/T1      Info Modelling                          +PrimaryIndex:
  2,22s/T1      Info Modelling                            PrimaryIndexInfo "./Tables/MyEntity/PrimaryIndex (PK_MyEntity)"
  2,22s/T1      Info Modelling                              +IsUnique = True (Boolean)
  2,22s/T1      Info Modelling                              +KeyColumns (1):
  2,22s/T1      Info Modelling                                0: KeyColumnRef "./Tables/MyEntity/PrimaryIndex/KeyColumns/0"
  2,22s/T1      Info Modelling                                  +Direction = Positive (Direction)
  2,22s/T1      Info Modelling                                  +Value = ./Tables/MyEntity/Columns/Id (ColumnInfo)
  2,22s/T1      Info Modelling                              +ValueColumns (1):
  2,22s/T1      Info Modelling                                ValueColumnRef "./Tables/MyEntity/PrimaryIndex/ValueColumns/0"
  2,22s/T1      Info Modelling                                  +Value = ./Tables/MyEntity/Columns/Text (ColumnInfo)
  2,22s/T1      Info Modelling                              +IsPrimary = True (Boolean)
  2,22s/T1      Info Modelling                          +SecondaryIndexes:
  2,22s/T1      Info Modelling                            None
  2,22s/T1      Info Modelling                          +ForeignKeys:
  2,22s/T1      Info Modelling                            None
  2,22s/T1      Info Modelling                          +FullTextIndexes:
  2,22s/T1      Info Modelling                            None
  2,22s/T1      Info Modelling                      +Sequences (1):
  2,22s/T1      Info Modelling                        SequenceInfo "./Sequences/Int32-Generator"
  2,22s/T1      Info Modelling                          +Seed = 128 (Int64)
  2,22s/T1      Info Modelling                          +Increment = 128 (Int64)
  2,22s/T1      Info Modelling                          +Type = Type: Int32, Length: null (TypeInfo)
  2,42s/T1      Info Storage.Building             Extracted schema:

... The part is removed, since PhpBB considers original message too large.

  2,51s/T1      Info Modelling                    Base comparison complete.
  2,63s/T1      Info Modelling                    Stage Prepare complete.
  2,63s/T1      Info Modelling                    Stage TemporaryRename complete.
  2,64s/T1      Info Modelling                    Base comparison complete.
  2,64s/T1      Info Modelling                    Stage Upgrade complete.
  2,64s/T1      Info Modelling                    Stage DataManipulate complete.
  2,64s/T1      Info Modelling                    Stage Cleanup complete.
  2,64s/T1      Info Modelling                    Base comparison complete.
  2,69s/T1      Info Storage.Building             Clearing comparison result:

... The part is removed, since PhpBB considers original message too large.

  2,77s/T1      Info Modelling                    Base comparison complete.
  2,79s/T1      Info Storage.Building             Comparison result:
                                                  Status: TargetIsSuperset, Can upgrade safely
                                                  Hints:

                                                  Difference:
                                                    "./" != "./" (NodeDifference): Unknown
                                                      +Tables: "./Tables (0)" != "./Tables (4)" (NodeCollectionDifference): 4 change(s)
                                                        "" != "./Tables/Metadata.Assembly" (NodeDifference): Created
                                                          +Columns: "" != "./Tables/Metadata.Assembly/Columns (2)" (NodeCollectionDifference): 2 change(s)
                                                            "" != "./Tables/Metadata.Assembly/Columns/Name" (NodeDifference): Created
                                                              +Type: "" != "Type: String, Length: 1024" (ValueDifference): values differ
                                                            "" != "./Tables/Metadata.Assembly/Columns/Version" (NodeDifference): Created
                                                              +Type: "" != "Type: String?, Length: 64" (ValueDifference): values differ
                                                          +PrimaryIndex: "" != "./Tables/Metadata.Assembly/PrimaryIndex (PK_Assembly)" (NodeDifference): Created
                                                            +IsUnique: "False" != "True" (ValueDifference): values differ
                                                            +KeyColumns: "" != "./Tables/Metadata.Assembly/PrimaryIndex/KeyColumns (1)" (NodeCollectionDifference): 1 change(s)
                                                              "" != "./Tables/Metadata.Assembly/PrimaryIndex/KeyColumns/0" (NodeDifference): Created
                                                                +Direction: "None" != "Positive" (ValueDifference): values differ
                                                                +Value: "" != "./Tables/Metadata.Assembly/Columns/Name" (ValueDifference): values differ
                                                        "" != "./Tables/Metadata.Type" (NodeDifference): Created
                                                          +Columns: "" != "./Tables/Metadata.Type/Columns (2)" (NodeCollectionDifference): 2 change(s)
                                                            "" != "./Tables/Metadata.Type/Columns/Id" (NodeDifference): Created
                                                              +Type: "" != "Type: Int32, Length: null" (ValueDifference): values differ
                                                            "" != "./Tables/Metadata.Type/Columns/Name" (NodeDifference): Created
                                                              +Type: "" != "Type: String?, Length: 1000" (ValueDifference): values differ
                                                          +PrimaryIndex: "" != "./Tables/Metadata.Type/PrimaryIndex (PK_Type)" (NodeDifference): Created
                                                            +IsUnique: "False" != "True" (ValueDifference): values differ
                                                            +KeyColumns: "" != "./Tables/Metadata.Type/PrimaryIndex/KeyColumns (1)" (NodeCollectionDifference): 1 change(s)
                                                              "" != "./Tables/Metadata.Type/PrimaryIndex/KeyColumns/0" (NodeDifference): Created
                                                                +Direction: "None" != "Positive" (ValueDifference): values differ
                                                                +Value: "" != "./Tables/Metadata.Type/Columns/Id" (ValueDifference): values differ
                                                          +SecondaryIndexes: "" != "./Tables/Metadata.Type/SecondaryIndexes (1)" (NodeCollectionDifference): 1 change(s)
                                                            "" != "./Tables/Metadata.Type/SecondaryIndexes/Type.IX_Name" (NodeDifference): Created
                                                              +IsUnique: "False" != "True" (ValueDifference): values differ
                                                              +KeyColumns: "" != "./Tables/Metadata.Type/SecondaryIndexes/Type.IX_Name/KeyColumns (1)" (NodeCollectionDifference): 1 change(s)
                                                                "" != "./Tables/Metadata.Type/SecondaryIndexes/Type.IX_Name/KeyColumns/0" (NodeDifference): Created
                                                                  +Direction: "None" != "Positive" (ValueDifference): values differ
                                                                  +Value: "" != "./Tables/Metadata.Type/Columns/Name" (ValueDifference): values differ
                                                              +PrimaryKeyColumns: "" != "./Tables/Metadata.Type/SecondaryIndexes/Type.IX_Name/PrimaryKeyColumns (1)" (NodeCollectionDifference): 1 change(s)
                                                                "" != "./Tables/Metadata.Type/SecondaryIndexes/Type.IX_Name/PrimaryKeyColumns/0" (NodeDifference): Created
                                                                  +Direction: "None" != "Positive" (ValueDifference): values differ
                                                                  +Value: "" != "./Tables/Metadata.Type/Columns/Id" (ValueDifference): values differ
                                                        "" != "./Tables/Metadata.Extension" (NodeDifference): Created
                                                          +Columns: "" != "./Tables/Metadata.Extension/Columns (3)" (NodeCollectionDifference): 3 change(s)
                                                            "" != "./Tables/Metadata.Extension/Columns/Name" (NodeDifference): Created
                                                              +Type: "" != "Type: String, Length: 1024" (ValueDifference): values differ
                                                            "" != "./Tables/Metadata.Extension/Columns/Text" (NodeDifference): Created
                                                              +Type: "" != "Type: String?, Length: null" (ValueDifference): values differ
                                                            "" != "./Tables/Metadata.Extension/Columns/Data" (NodeDifference): Created
                                                              +Type: "" != "Type: Byte[]?, Length: null" (ValueDifference): values differ
                                                          +PrimaryIndex: "" != "./Tables/Metadata.Extension/PrimaryIndex (PK_Extension)" (NodeDifference): Created
                                                            +IsUnique: "False" != "True" (ValueDifference): values differ
                                                            +KeyColumns: "" != "./Tables/Metadata.Extension/PrimaryIndex/KeyColumns (1)" (NodeCollectionDifference): 1 change(s)
                                                              "" != "./Tables/Metadata.Extension/PrimaryIndex/KeyColumns/0" (NodeDifference): Created
                                                                +Direction: "None" != "Positive" (ValueDifference): values differ
                                                                +Value: "" != "./Tables/Metadata.Extension/Columns/Name" (ValueDifference): values differ
                                                        "" != "./Tables/MyEntity" (NodeDifference): Created
                                                          +Columns: "" != "./Tables/MyEntity/Columns (2)" (NodeCollectionDifference): 2 change(s)
                                                            "" != "./Tables/MyEntity/Columns/Id" (NodeDifference): Created
                                                              +Type: "" != "Type: Int32, Length: null" (ValueDifference): values differ
                                                            "" != "./Tables/MyEntity/Columns/Text" (NodeDifference): Created
                                                              +Type: "" != "Type: String?, Length: 100" (ValueDifference): values differ
                                                          +PrimaryIndex: "" != "./Tables/MyEntity/PrimaryIndex (PK_MyEntity)" (NodeDifference): Created
                                                            +IsUnique: "False" != "True" (ValueDifference): values differ
                                                            +KeyColumns: "" != "./Tables/MyEntity/PrimaryIndex/KeyColumns (1)" (NodeCollectionDifference): 1 change(s)
                                                              "" != "./Tables/MyEntity/PrimaryIndex/KeyColumns/0" (NodeDifference): Created
                                                                +Direction: "None" != "Positive" (ValueDifference): values differ
                                                                +Value: "" != "./Tables/MyEntity/Columns/Id" (ValueDifference): values differ
                                                      +Sequences: "./Sequences (0)" != "./Sequences (1)" (NodeCollectionDifference): 1 change(s)
                                                        "" != "./Sequences/Int32-Generator" (NodeDifference): Created
                                                          +Increment: "0" != "128" (ValueDifference): values differ
                                                  Actions:
                                                    GroupingNode, Comment=Prepare
                                                    GroupingNode, Comment=TemporaryRename
                                                    GroupingNode, Comment=Upgrade
                                                      GroupingNode, Comment=.
                                                        GroupingNode, Comment=Tables[]
                                                          GroupingNode, Comment=Metadata.Assembly
                                                            CreateNode, Path=, Type=TableInfo, Name=Metadata.Assembly, Index=0
                                                            GroupingNode, Comment=Columns[]
                                                              GroupingNode, Comment=Name
                                                                CreateNode, Path=Tables/Metadata.Assembly, Type=ColumnInfo, Name=Name, Index=0
                                                                PropertyChange, Path=Tables/Metadata.Assembly/Columns/Name, Type=Type: String, Length: 1024
                                                              GroupingNode, Comment=Version
                                                                CreateNode, Path=Tables/Metadata.Assembly, Type=ColumnInfo, Name=Version, Index=1
                                                                PropertyChange, Path=Tables/Metadata.Assembly/Columns/Version, Type=Type: String?, Length: 64
                                                            GroupingNode, Comment=PK_Assembly
                                                              CreateNode, Path=Tables/Metadata.Assembly, Type=PrimaryIndexInfo, Name=PK_Assembly
                                                              PropertyChange, Path=Tables/Metadata.Assembly/PrimaryIndex, IsUnique=True
                                                              GroupingNode, Comment=KeyColumns[]
                                                                GroupingNode, Comment=0
                                                                  CreateNode, Path=Tables/Metadata.Assembly/PrimaryIndex, Type=KeyColumnRef, Name=0, Index=0
                                                                  PropertyChange, Path=Tables/Metadata.Assembly/PrimaryIndex/KeyColumns/0, Value=Tables/Metadata.Assembly/Columns/Name, Direction=Positive
                                                          GroupingNode, Comment=Metadata.Type
                                                            CreateNode, Path=, Type=TableInfo, Name=Metadata.Type, Index=1
                                                            GroupingNode, Comment=Columns[]
                                                              GroupingNode, Comment=Id
                                                                CreateNode, Path=Tables/Metadata.Type, Type=ColumnInfo, Name=Id, Index=0
                                                                PropertyChange, Path=Tables/Metadata.Type/Columns/Id, Type=Type: Int32, Length: null
                                                              GroupingNode, Comment=Name
                                                                CreateNode, Path=Tables/Metadata.Type, Type=ColumnInfo, Name=Name, Index=1
                                                                PropertyChange, Path=Tables/Metadata.Type/Columns/Name, Type=Type: String?, Length: 1000
                                                            GroupingNode, Comment=PK_Type
                                                              CreateNode, Path=Tables/Metadata.Type, Type=PrimaryIndexInfo, Name=PK_Type
                                                              PropertyChange, Path=Tables/Metadata.Type/PrimaryIndex, IsUnique=True
                                                              GroupingNode, Comment=KeyColumns[]
                                                                GroupingNode, Comment=0
                                                                  CreateNode, Path=Tables/Metadata.Type/PrimaryIndex, Type=KeyColumnRef, Name=0, Index=0
                                                                  PropertyChange, Path=Tables/Metadata.Type/PrimaryIndex/KeyColumns/0, Value=Tables/Metadata.Type/Columns/Id, Direction=Positive
                                                            GroupingNode, Comment=SecondaryIndexes[]
                                                              GroupingNode, Comment=Type.IX_Name
                                                                CreateNode, Path=Tables/Metadata.Type, Type=SecondaryIndexInfo, Name=Type.IX_Name, Index=0
                                                                PropertyChange, Path=Tables/Metadata.Type/SecondaryIndexes/Type.IX_Name, IsUnique=True
                                                                GroupingNode, Comment=KeyColumns[]
                                                                  GroupingNode, Comment=0
                                                                    CreateNode, Path=Tables/Metadata.Type/SecondaryIndexes/Type.IX_Name, Type=KeyColumnRef, Name=0, Index=0
                                                                    PropertyChange, Path=Tables/Metadata.Type/SecondaryIndexes/Type.IX_Name/KeyColumns/0, Value=Tables/Metadata.Type/Columns/Name, Direction=Positive
                                                                GroupingNode, Comment=PrimaryKeyColumns[]
                                                                  GroupingNode, Comment=0
                                                                    CreateNode, Path=Tables/Metadata.Type/SecondaryIndexes/Type.IX_Name, Type=PrimaryKeyColumnRef, Name=0, Index=0
                                                                    PropertyChange, Path=Tables/Metadata.Type/SecondaryIndexes/Type.IX_Name/PrimaryKeyColumns/0, Value=Tables/Metadata.Type/Columns/Id, Direction=Positive
                                                          GroupingNode, Comment=Metadata.Extension
                                                            CreateNode, Path=, Type=TableInfo, Name=Metadata.Extension, Index=2
                                                            GroupingNode, Comment=Columns[]
                                                              GroupingNode, Comment=Name
                                                                CreateNode, Path=Tables/Metadata.Extension, Type=ColumnInfo, Name=Name, Index=0
                                                                PropertyChange, Path=Tables/Metadata.Extension/Columns/Name, Type=Type: String, Length: 1024
                                                              GroupingNode, Comment=Text
                                                                CreateNode, Path=Tables/Metadata.Extension, Type=ColumnInfo, Name=Text, Index=1
                                                                PropertyChange, Path=Tables/Metadata.Extension/Columns/Text, Type=Type: String?, Length: null
                                                              GroupingNode, Comment=Data
                                                                CreateNode, Path=Tables/Metadata.Extension, Type=ColumnInfo, Name=Data, Index=2
                                                                PropertyChange, Path=Tables/Metadata.Extension/Columns/Data, Type=Type: Byte[]?, Length: null
                                                            GroupingNode, Comment=PK_Extension
                                                              CreateNode, Path=Tables/Metadata.Extension, Type=PrimaryIndexInfo, Name=PK_Extension
                                                              PropertyChange, Path=Tables/Metadata.Extension/PrimaryIndex, IsUnique=True
                                                              GroupingNode, Comment=KeyColumns[]
                                                                GroupingNode, Comment=0
                                                                  CreateNode, Path=Tables/Metadata.Extension/PrimaryIndex, Type=KeyColumnRef, Name=0, Index=0
                                                                  PropertyChange, Path=Tables/Metadata.Extension/PrimaryIndex/KeyColumns/0, Value=Tables/Metadata.Extension/Columns/Name, Direction=Positive
                                                          GroupingNode, Comment=MyEntity
                                                            CreateNode, Path=, Type=TableInfo, Name=MyEntity, Index=3
                                                            GroupingNode, Comment=Columns[]
                                                              GroupingNode, Comment=Id
                                                                CreateNode, Path=Tables/MyEntity, Type=ColumnInfo, Name=Id, Index=0
                                                                PropertyChange, Path=Tables/MyEntity/Columns/Id, Type=Type: Int32, Length: null
                                                              GroupingNode, Comment=Text
                                                                CreateNode, Path=Tables/MyEntity, Type=ColumnInfo, Name=Text, Index=1
                                                                PropertyChange, Path=Tables/MyEntity/Columns/Text, Type=Type: String?, Length: 100
                                                            GroupingNode, Comment=PK_MyEntity
                                                              CreateNode, Path=Tables/MyEntity, Type=PrimaryIndexInfo, Name=PK_MyEntity
                                                              PropertyChange, Path=Tables/MyEntity/PrimaryIndex, IsUnique=True
                                                              GroupingNode, Comment=KeyColumns[]
                                                                GroupingNode, Comment=0
                                                                  CreateNode, Path=Tables/MyEntity/PrimaryIndex, Type=KeyColumnRef, Name=0, Index=0
                                                                  PropertyChange, Path=Tables/MyEntity/PrimaryIndex/KeyColumns/0, Value=Tables/MyEntity/Columns/Id, Direction=Positive
                                                        GroupingNode, Comment=Sequences[]
                                                          GroupingNode, Comment=Int32-Generator
                                                            CreateNode, Path=, Type=SequenceInfo, Name=Int32-Generator, Index=0
                                                            PropertyChange, Path=Sequences/Int32-Generator, Increment=128
                                                    GroupingNode, Comment=DataManipulate
                                                    GroupingNode, Comment=Cleanup

  2,84s/T1      Info Storage.Providers.Sql        Session 'System, #1'. Schema upgrade script:
                                                  CREATE TABLE [dbo].[Metadata.Assembly] ([Name] nvarchar(1024) NOT NULL,
                                                  [Version] nvarchar(64) DEFAULT NULL,
                                                  CONSTRAINT [PK_Assembly] PRIMARY KEY ([Name]));
                                                  CREATE TABLE [dbo].[Metadata.Type] ([Id] integer NOT NULL,
                                                  [Name] nvarchar(1000) DEFAULT NULL,
                                                  CONSTRAINT [PK_Type] PRIMARY KEY ([Id]));
                                                  CREATE UNIQUE INDEX [Type.IX_Name] ON [dbo].[Metadata.Type] ([Name] ASC);
                                                  CREATE TABLE [dbo].[Metadata.Extension] ([Name] nvarchar(1024) NOT NULL,
                                                  [Text] nvarchar(max) DEFAULT NULL,
                                                  [Data] varbinary(max) DEFAULT NULL,
                                                  CONSTRAINT [PK_Extension] PRIMARY KEY ([Name]));
                                                  CREATE TABLE [dbo].[MyEntity] ([Id] integer NOT NULL,
                                                  [Text] nvarchar(100) DEFAULT NULL,
                                                  CONSTRAINT [PK_MyEntity] PRIMARY KEY ([Id]));
                                                  CREATE TABLE [dbo].[Int32-Generator] ([ID] integer IDENTITY (128, 128) NOT NULL,
                                                  CONSTRAINT [PK_Int32-Generator] PRIMARY KEY ([ID]));
  2,84s/T1     Debug Storage.Providers.Sql        Session 'n/a'. SQL batch: 
                                                  CREATE TABLE [dbo].[Metadata.Assembly] ([Name] nvarchar(1024) NOT NULL,
                                                  [Version] nvarchar(64) DEFAULT NULL,
                                                  CONSTRAINT [PK_Assembly] PRIMARY KEY ([Name]));
                                                  CREATE TABLE [dbo].[Metadata.Type] ([Id] integer NOT NULL,
                                                  [Name] nvarchar(1000) DEFAULT NULL,
                                                  CONSTRAINT [PK_Type] PRIMARY KEY ([Id]));
                                                  CREATE UNIQUE INDEX [Type.IX_Name] ON [dbo].[Metadata.Type] ([Name] ASC);
                                                  CREATE TABLE [dbo].[Metadata.Extension] ([Name] nvarchar(1024) NOT NULL,
                                                  [Text] nvarchar(max) DEFAULT NULL,
                                                  [Data] varbinary(max) DEFAULT NULL,
                                                  CONSTRAINT [PK_Extension] PRIMARY KEY ([Name]));
                                                  CREATE TABLE [dbo].[MyEntity] ([Id] integer NOT NULL,
                                                  [Text] nvarchar(100) DEFAULT NULL,
                                                  CONSTRAINT [PK_MyEntity] PRIMARY KEY ([Id]));
                                                  CREATE TABLE [dbo].[Int32-Generator] ([ID] integer IDENTITY (128, 128) NOT NULL,
                                                  CONSTRAINT [PK_Int32-Generator] PRIMARY KEY ([ID]));
  2,85s/T1      Info Storage.Building           Synchronizing schema in Recreate mode.: completed.
  2,88s/T1      Info Storage.Building           Building Type-related information cache: started.
  2,89s/T1      Info Storage.Building           Building Type-related information cache: completed.
  3,36s/T1     Debug Storage.Providers.Sql      Session 'System, #1'. SQL batch: 
                                                SELECT [a].[Name], 2 AS [TypeId], [a].[Version] FROM [dbo].[Metadata.Assembly] [a];
  3,43s/T1     Debug Storage                    Session 'System, #1'. Caching: Key = 'Assembly, (Xtensive.Storage)', Tuple = (Xtensive.Storage, 2, null), State = New.
  3,44s/T1     Debug Storage                    Session 'System, #1'. Materializing Assembly: Key = 'Assembly, (Xtensive.Storage)'.
  3,57s/T1     Debug Storage                    Session 'System, #1'. Setting value: Key = 'Assembly, (Xtensive.Storage)', Field = 'Version (FieldInfo)'.
  3,57s/T1     Debug Storage                    Session 'System, #1'. Getting value: Key = 'Assembly, (Xtensive.Storage)', Field = 'Version (FieldInfo)'.
  3,58s/T1      Info Core.Diagnostics           Storage.Upgrade log initialized.
  3,59s/T1     Debug Storage                    Session 'System, #1'. Getting value: Key = 'Assembly, (Xtensive.Storage)', Field = 'Name (FieldInfo)'.
  3,59s/T1     Debug Storage                    Session 'System, #1'. Getting value: Key = 'Assembly, (Xtensive.Storage)', Field = 'Version (FieldInfo)'.
  3,59s/T1      Info Storage.Upgrade            Metadata.Assembly created: 'Xtensive.Storage (Version=1.0.0.0)'.
  3,59s/T1     Debug Storage                    Session 'System, #1'. Caching: Key = 'Assembly, (Xtensive.Storage.Samples.HelloWorld)', Tuple = (Xtensive.Storage.Samples.HelloWorld, 2, null), State = New.
  3,59s/T1     Debug Storage                    Session 'System, #1'. Materializing Assembly: Key = 'Assembly, (Xtensive.Storage.Samples.HelloWorld)'.
  3,59s/T1     Debug Storage                    Session 'System, #1'. Setting value: Key = 'Assembly, (Xtensive.Storage.Samples.HelloWorld)', Field = 'Version (FieldInfo)'.
  3,59s/T1     Debug Storage                    Session 'System, #1'. Getting value: Key = 'Assembly, (Xtensive.Storage.Samples.HelloWorld)', Field = 'Version (FieldInfo)'.
  3,59s/T1     Debug Storage                    Session 'System, #1'. Getting value: Key = 'Assembly, (Xtensive.Storage.Samples.HelloWorld)', Field = 'Name (FieldInfo)'.
  3,59s/T1     Debug Storage                    Session 'System, #1'. Getting value: Key = 'Assembly, (Xtensive.Storage.Samples.HelloWorld)', Field = 'Version (FieldInfo)'.
  3,59s/T1      Info Storage.Upgrade            Metadata.Assembly created: 'Xtensive.Storage.Samples.HelloWorld (Version=1.0.0.0)'.
  3,62s/T1     Debug Storage                    Session 'System, #1'. Persisting (reason 'Query').
  3,70s/T1     Debug Storage                    Session 'System, #1'. Persist completed.
  3,71s/T1     Debug Storage.Providers.Sql      Session 'System, #1'. SQL batch: 
                                                INSERT INTO [dbo].[Metadata.Assembly] ([Name], [Version]) VALUES (@p1_0, @p1_1);
                                                INSERT INTO [dbo].[Metadata.Assembly] ([Name], [Version]) VALUES (@p2_0, @p2_1);
                                                SELECT [a].[Id], 1 AS [TypeId], [a].[Name] FROM [dbo].[Metadata.Type] [a]; [p1_0='Xtensive.Storage';p1_1='1.0.0.0';p2_0='Xtensive.Storage.Samples.HelloWorld';p2_1='1.0.0.0']
  3,73s/T1     Debug Storage.Providers.Sql      Session 'System, #1'. SQL batch: 
                                                SELECT [a].[Id], 1 AS [TypeId], [a].[Name] FROM [dbo].[Metadata.Type] [a];
  3,74s/T1     Debug Storage                    Session 'System, #1'. Caching: Key = 'Type, (2)', Tuple = (2, 1, null), State = New.
  3,74s/T1     Debug Storage                    Session 'System, #1'. Materializing Type: Key = 'Type, (2)'.
  3,74s/T1     Debug Storage                    Session 'System, #1'. Setting value: Key = 'Type, (2)', Field = 'Name (FieldInfo)'.
  3,74s/T1     Debug Storage                    Session 'System, #1'. Getting value: Key = 'Type, (2)', Field = 'Name (FieldInfo)'.
  3,74s/T1      Info Core.Diagnostics           Core.Comparison log initialized.
  3,74s/T1      Warn Core.Comparison            Can't find Comparer ('IAdvancedComparer<IValidationAware>') for type 'IValidationAware'.
  3,75s/T1      Warn Core.Comparison            Can't find Comparer ('IAdvancedComparer<IValidationAware>') for type 'IValidationAware'.
  3,75s/T1      Warn Core.Comparison            Can't find Comparer ('IAdvancedComparer<Action<IValidationAware>>') for type 'Action<IValidationAware>'.
  3,75s/T1      Warn Core.Comparison            Can't find Comparer ('IAdvancedComparer<Action<IValidationAware>>') for type 'Action<IValidationAware>'.
  3,76s/T1     Debug Storage                    Session 'System, #1'. Caching: Key = 'Type, (1)', Tuple = (1, 1, null), State = New.
  3,76s/T1     Debug Storage                    Session 'System, #1'. Materializing Type: Key = 'Type, (1)'.
  3,76s/T1     Debug Storage                    Session 'System, #1'. Setting value: Key = 'Type, (1)', Field = 'Name (FieldInfo)'.
  3,76s/T1     Debug Storage                    Session 'System, #1'. Getting value: Key = 'Type, (1)', Field = 'Name (FieldInfo)'.
  3,76s/T1     Debug Storage                    Session 'System, #1'. Caching: Key = 'Type, (3)', Tuple = (3, 1, null), State = New.
  3,76s/T1     Debug Storage                    Session 'System, #1'. Materializing Type: Key = 'Type, (3)'.
  3,76s/T1     Debug Storage                    Session 'System, #1'. Setting value: Key = 'Type, (3)', Field = 'Name (FieldInfo)'.
  3,76s/T1     Debug Storage                    Session 'System, #1'. Getting value: Key = 'Type, (3)', Field = 'Name (FieldInfo)'.
  3,76s/T1     Debug Storage                    Session 'System, #1'. Caching: Key = 'Type, (101)', Tuple = (101, 1, null), State = New.
  3,76s/T1     Debug Storage                    Session 'System, #1'. Materializing Type: Key = 'Type, (101)'.
  3,76s/T1     Debug Storage                    Session 'System, #1'. Setting value: Key = 'Type, (101)', Field = 'Name (FieldInfo)'.
  3,76s/T1     Debug Storage                    Session 'System, #1'. Getting value: Key = 'Type, (101)', Field = 'Name (FieldInfo)'.
  3,92s/T1     Debug Storage                    Session 'System, #1'. Persisting (reason 'Query').
  3,92s/T1     Debug Storage                    Session 'System, #1'. Persist completed.
  4,11s/T1     Debug Storage.Providers.Sql      Session 'System, #1'. SQL batch: 
                                                INSERT INTO [dbo].[Metadata.Type] ([Id], [Name]) VALUES (@p1_0, @p1_1);
                                                INSERT INTO [dbo].[Metadata.Type] ([Id], [Name]) VALUES (@p2_0, @p2_1);
                                                INSERT INTO [dbo].[Metadata.Type] ([Id], [Name]) VALUES (@p3_0, @p3_1);
                                                INSERT INTO [dbo].[Metadata.Type] ([Id], [Name]) VALUES (@p4_0, @p4_1);
                                                SELECT TOP 2 [a].[Name], 3 AS [TypeId], [a].[Text], [a].[Data] FROM [dbo].[Metadata.Extension] [a] WHERE ([a].[Name] = 'Xtensive.Storage.Model') ORDER BY [a].[Name] ASC; [p1_0='2';p1_1='Xtensive.Storage.Metadata.Assembly';p2_0='1';p2_1='Xtensive.Storage.Metadata.Type';p3_0='3';p3_1='Xtensive.Storage.Metadata.Extension';p4_0='101';p4_1='Xtensive.Storage.Samples.HelloWorld.Model.MyEntity']
  4,12s/T1     Debug Storage                    Session 'System, #1'. Caching: Key = 'Extension, (Xtensive.Storage.Model)', Tuple = (Xtensive.Storage.Model, 3, null, null), State = New.
  4,12s/T1     Debug Storage                    Session 'System, #1'. Materializing Extension: Key = 'Extension, (Xtensive.Storage.Model)'.
  4,32s/T1     Debug Storage                    Session 'System, #1'. Setting value: Key = 'Extension, (Xtensive.Storage.Model)', Field = 'Text (FieldInfo)'.
  4,32s/T1     Debug Storage                    Session 'System, #1'. Getting value: Key = 'Extension, (Xtensive.Storage.Model)', Field = 'Text (FieldInfo)'.
  4,33s/T1     Debug Storage                    Session 'System, #1'. Committing transaction.
  4,33s/T1     Debug Storage                    Session 'System, #1'. Persisting (reason 'Commit').
  4,33s/T1     Debug Storage.Providers.Sql      Session 'System, #1'. SQL batch: 
                                                INSERT INTO [dbo].[Metadata.Extension] ([Name], [Text], [Data]) VALUES (@p1_0, @p1_1, @p1_2); [p1_0='Xtensive.Storage.Model';p1_1='<?xml version="1.0" encoding="utf-16"?>
                                                <DomainModel xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xmlns:xsd="http://www.w3.org/2001/XMLSchema">
                                                  <Types>

... The part is removed, since PhpBB considers original message too large.

                                                  </Types>
                                                </DomainModel>';p1_2='']
  4,33s/T1     Debug Storage                    Session 'System, #1'. Persist completed.
  4,33s/T1     Debug Storage.Providers.Sql      Session 'System, #1'. Commit transaction.
  4,34s/T1     Debug Storage                    Session 'System, #1'. Committed transaction.
  4,34s/T1     Debug Storage                    Session 'System, #1'. Disposing.
  4,34s/T1     Debug Storage.Providers.Sql      Session 'System, #1'. Closing connection 'sqlserver://localhost/DO40-Tests'.
  4,34s/T1      Info Storage.Building         Building Domain: completed.
  4,34s/T1     Debug Storage                  Opening session 'Name = Default, UserName = <null>, Options = Default, CacheType = LruWeak, CacheSize = 16384, DefaultIsolationLevel = RepeatableRead'.
  4,34s/T1     Debug Storage                  Session 'Default, #2'. Opening transaction.
  4,34s/T1     Debug Storage.Providers.Sql    Session 'Default, #2'. Creating connection 'sqlserver://localhost/DO40-Tests'.
  4,34s/T1     Debug Storage.Providers.Sql    Session 'Default, #2'. Opening connection 'sqlserver://localhost/DO40-Tests'.
  4,34s/T1     Debug Storage.Providers.Sql    Session 'Default, #2'. Beginning transaction @ RepeatableRead.
  4,34s/T1     Debug Storage                  Session 'Default, #2'. Opened transaction.
  4,39s/T1     Debug Storage                  Opening session 'Name = KeyGenerator, UserName = <null>, Options = Default, CacheType = LruWeak, CacheSize = 16384, DefaultIsolationLevel = RepeatableRead'.
  4,39s/T1     Debug Storage                  Session 'KeyGenerator, #3'. Opening transaction.
  4,39s/T1     Debug Storage.Providers.Sql    Session 'KeyGenerator, #3'. Creating connection 'sqlserver://localhost/DO40-Tests'.
  4,39s/T1     Debug Storage.Providers.Sql    Session 'KeyGenerator, #3'. Opening connection 'sqlserver://localhost/DO40-Tests'.
  4,39s/T1     Debug Storage.Providers.Sql    Session 'KeyGenerator, #3'. Beginning transaction @ RepeatableRead.
  4,39s/T1     Debug Storage                  Session 'KeyGenerator, #3'. Opened transaction.
  4,39s/T1     Debug Storage.Providers.Sql    Session 'KeyGenerator, #3'. SQL batch: 
                                              INSERT INTO [dbo].[Int32-Generator] DEFAULT VALUES;
                                              SELECT SCOPE_IDENTITY();
  4,40s/T1     Debug Storage                  Session 'KeyGenerator, #3'. Rolling back transaction.
  4,40s/T1     Debug Storage.Providers.Sql    Session 'KeyGenerator, #3'. Rollback transaction.
  4,40s/T1     Debug Storage                  Session 'KeyGenerator, #3'. Rolled back transaction.
  4,40s/T1     Debug Storage                  Session 'KeyGenerator, #3'. Disposing.
  4,40s/T1     Debug Storage.Providers.Sql    Session 'KeyGenerator, #3'. Closing connection 'sqlserver://localhost/DO40-Tests'.
  4,40s/T1     Debug Storage                  Session 'Default, #2'. Caching: Key = 'MyEntity, (1)', Tuple = (1, 101, null), State = New.
  4,40s/T1     Debug Storage                  Session 'Default, #2'. Materializing MyEntity: Key = 'MyEntity, (1)'.
  4,40s/T1     Debug Storage                  Session 'Default, #2'. Setting value: Key = 'MyEntity, (1)', Field = 'Text (FieldInfo)'.
  4,40s/T1     Debug Storage                  Session 'Default, #2'. Getting value: Key = 'MyEntity, (1)', Field = 'Text (FieldInfo)'.
  4,40s/T1     Debug Storage                  Session 'Default, #2'. Committing transaction.
  4,40s/T1     Debug Storage                  Session 'Default, #2'. Persisting (reason 'Commit').
  4,40s/T1     Debug Storage.Providers.Sql    Session 'Default, #2'. SQL batch: 
                                              INSERT INTO [dbo].[MyEntity] ([Id], [Text]) VALUES (@p1_0, @p1_1); [p1_0='1';p1_1='Hello World!']
  4,40s/T1     Debug Storage                  Session 'Default, #2'. Persist completed.
  4,40s/T1     Debug Storage.Providers.Sql    Session 'Default, #2'. Commit transaction.
  4,41s/T1     Debug Storage                  Session 'Default, #2'. Committed transaction.
  4,41s/T1     Debug Storage                  Session 'Default, #2'. Disposing.
  4,41s/T1     Debug Storage.Providers.Sql    Session 'Default, #2'. Closing connection 'sqlserver://localhost/DO40-Tests'.
  4,41s/T1     Debug Storage                  Opening session 'Name = Default, UserName = <null>, Options = Default, CacheType = LruWeak, CacheSize = 16384, DefaultIsolationLevel = RepeatableRead'.
  4,41s/T1     Debug Storage                  Session 'Default, #4'. Opening transaction.
  4,41s/T1     Debug Storage.Providers.Sql    Session 'Default, #4'. Creating connection 'sqlserver://localhost/DO40-Tests'.
  4,41s/T1     Debug Storage.Providers.Sql    Session 'Default, #4'. Opening connection 'sqlserver://localhost/DO40-Tests'.
  4,41s/T1     Debug Storage.Providers.Sql    Session 'Default, #4'. Beginning transaction @ RepeatableRead.
  4,41s/T1     Debug Storage                  Session 'Default, #4'. Opened transaction.
  4,42s/T1     Debug Storage.Providers.Sql    Session 'Default, #4'. SQL batch: 
                                              SELECT [a].[Id], 101 AS [TypeId], [a].[Text] FROM [dbo].[MyEntity] [a];
  4,43s/T1     Debug Storage                  Session 'Default, #4'. Caching: Key = 'MyEntity, (1)', Tuple = (1, 101, Hello World!), State = Synchronized.
  4,44s/T1     Debug Storage                  Session 'Default, #4'. Materializing MyEntity: Key = 'MyEntity, (1)'.
  4,44s/T1     Debug Storage                  Session 'Default, #4'. Getting value: Key = 'MyEntity, (1)', Field = 'Text (FieldInfo)'.
Hello World!
  4,44s/T1     Debug Storage                  Session 'Default, #4'. Committing transaction.
  4,44s/T1     Debug Storage.Providers.Sql    Session 'Default, #4'. Commit transaction.
  4,44s/T1     Debug Storage                  Session 'Default, #4'. Committed transaction.
  4,44s/T1     Debug Storage                  Session 'Default, #4'. Disposing.
  4,44s/T1     Debug Storage.Providers.Sql    Session 'Default, #4'. Closing connection 'sqlserver://localhost/DO40-Tests'.

Much more stuff, but "SQL batch" lines are still there.


Alex (Xtensive) wrote:

Not days, but weeks (likely, a week or two). Migration to PostSharp 2.0 is already mostly finished (mostly = everything already compiles, tests for Core pass, but there are issues with tests for Storage). Migration to .NET 4 is mainly a set of renames + conditional compilation constructs.


Alex (Xtensive) wrote:

Ok, I just committed configuration for option two :)

DO4 supports switching log provider via its IoC framework. So you can forward all the logging to log4net: 1) Copy log4net.dll from {DO4}\Lib and Xtensive.Adapters.log4net.dll from {DO4}\Bin\Latest to bin folder of your application (or simply reference them). 2) Use setting from this App.config for HelloWorld sample: http://goo.gl/uGDp

Expected result: logging messages are written to Application.log file.


Alex (Xtensive) wrote:

Btw, there is no "v4.2.0" branch now (it is closed). See:

So you need to checkout "stable" branch.

Currently there are 3 branches:

  • stable: the one you need

  • default: development branch, don't use it

  • PostSharp: a branch from development branch, don't use it.

Current changes propagation rule: stable -> default -> PostSharp. When PostSharp will be closed, it will be merged back into stable. default will be merged into stable on next release.

answered Apr 12 '10 at 13:17

Editor's gravatar image

Editor
46156156157

david_csharp wrote: It seems that you tried everything in your 'Postsharp' branch, can you try it also in the '4.2.0' branch? Because that is what I tried it on..

(Apr 12 '10 at 13:17) Editor Editor's gravatar image

No, I'm 100% sure I use "stable" branch...

(Apr 12 '10 at 13:17) Alex Yakunin Alex%20Yakunin's gravatar image

Btw, if you downloaded the latest DO4 build, there is no need to update from repository. I know there are no any changes related to logging during last week.

(Apr 12 '10 at 13:17) Alex Yakunin Alex%20Yakunin's gravatar image

Sorry, that's really really strange. If someone else will confirm the issue, it will be easier to fix it.

What's the OS you're using?

(Apr 12 '10 at 13:17) Alex Yakunin Alex%20Yakunin's gravatar image

david_csharp wrote: windows 7

(Apr 12 '10 at 13:17) Editor Editor's gravatar image

32 or 64 bit?

(Apr 12 '10 at 13:17) Alex Yakunin Alex%20Yakunin's gravatar image

david_csharp wrote: sorry, Win7 x86

(Apr 12 '10 at 13:17) Editor Editor's gravatar image

App.config I used previously: http://goo.gl/id0W

Logs everything to console using integrated logging provider.

(Apr 12 '10 at 13:17) Alex Yakunin Alex%20Yakunin's gravatar image

david_csharp wrote: well the log output from file is the same as of console, so file flushing isn't the issue..

Can I ask what is the progress of migration to .Net40 & VS2010? Is it a matter of days/weeks/months to upgrade to Postsharp2.0? David

(Apr 12 '10 at 13:17) Editor Editor's gravatar image

Could you send me the complete log output? Or is the published one was complete?

(Apr 12 '10 at 13:17) Alex Yakunin Alex%20Yakunin's gravatar image

david_csharp wrote: The used app.config and the log-output is complete, nothing was cut or changed.

David

(Apr 12 '10 at 13:17) Editor Editor's gravatar image

david_csharp wrote: nope, the result is the same e.g. no logging output of Sql-batches..

David

(Apr 12 '10 at 13:17) Editor Editor's gravatar image

David, any chance you are running on memory instead of SQL Server? Check your connection string, plz

(Apr 12 '10 at 13:17) Dmitri Maximov Dmitri%20Maximov's gravatar image

Hmm, I suspect the issue is related to file buffer flushing. We'll check this.

(Apr 12 '10 at 13:17) Alex Yakunin Alex%20Yakunin's gravatar image

Any word on this? I'm experiencing the same issue (and answered by mistake, instead of commenting)

(Sep 01 '10 at 16:12) ScottyH ScottyH's gravatar image

So far we discovered nothing. I'll look this up once more tomorrow (sorry, it's almost 4am here).

(Sep 01 '10 at 17:31) Alex Yakunin Alex%20Yakunin's gravatar image

Thanks. I appreciate this.

I'm currently evaluating DO.net for a large project. It's on the short list, and this fix would go a long way to convincing me.

(Sep 02 '10 at 10:36) ScottyH ScottyH's gravatar image

We've added one more stream.Flush() to FileLog code today - likely, we really had a bug there. We were flushing the TextWriter, but FileStream (to which it writes) wasn't flushed.

Now the issue must be fixed. The updated DO4 will be available a bit later today.

Btw, the issue was related to FileLog only.

(Sep 06 '10 at 19:12) Alex Yakunin Alex%20Yakunin's gravatar image
Your answer
Please start posting your answer anonymously - your answer will be saved within the current session and published after you log in or create a new account. Please try to give a substantial answer, for discussions, please use comments and please do remember to vote (after you log in)!
toggle preview

powered by OSQA