Export (0) Print
Expand All

How to: Trace the Synchronization Process

This topic shows how to use the tracing infrastructure and tracing class in Sync Framework. The examples in this topic focus on the following Sync Framework types and events:

For information about how to run sample code, see "Example Applications in the How to Topics" in Programming Common Client and Server Synchronization Tasks.

Understanding Tracing in Synchronization Services

Tracing involves recording application operations, data, and metadata, and providing this information to a listener. A listener frequently writes trace information to a file, but could also handle the information in other ways. Sync Framework includes tracing for the client and server synchronization providers. In distributed applications, tracing can be very important because it enables you to troubleshoot issues that might otherwise be difficult to discover.

Tracing in Sync Framework is composed of the following components:

  • A tracing infrastructure that is based on the .NET Framework implementation of tracing, specifically the TraceListener class. The most important operations of the client and server providers are traced, and key metadata is provided to one or more listeners.

  • The SyncTracer object. This enables you to determine which level of tracing is enabled and to write messages to the trace output based on application events.

In addition to the tracing components that Sync Framework provides, troubleshooting typically involves other tools, such as a debugger or SQL Server Profiler. For example, trace output could include information about a SQL Server database, and then you would use SQL Server Profiler to obtain more detail about database activity that was generated by the server synchronization provider.

Using the Tracing Infrastructure

By default, tracing is not enabled for Sync Framework applications. To configure a trace listener, edit the app.config file for your application. For more information about this file, see the Visual Studio documentation. In this file, you can add a listener, set its type and related parameters, remove a listener, or clear all the listeners that were previously set by the application. For more information, see the .NET Framework documentation about tracing. The configuration file should resemble the following example.

<configuration>
  <system.diagnostics>
    <switches>
      <!--  0-off, 1-error, 2-warn, 3-info, 4-verbose. -->
      <add name="SyncTracer" value="3" />
    </switches>

    <trace autoflush="true">
      <listeners>
        <add name="TestListener" type="System.Diagnostics.TextWriterTraceListener" initializeData="c:\TraceSample.txt"/>
      </listeners>
    </trace>
  </system.diagnostics>
</configuration>

The following XML nodes are included in the example code:

  • A listener of type System.Diagnostics.TextWriterTraceListener (TextWriterTraceListener), with the path to: c:\TraceSample.txt.

  • A switch called SyncTracer. This has a value of 3. The following table shows all the values and how they relate to trace output.

    Switch value Tracing level Output

    0

    off

    No messages to trace listeners.

    1

    error

    Only error messages to trace listeners.

    2

    warning

    Error and warning messages to trace listeners.

    3

    info

    Informational, warning, and error messages to trace listeners.

    4

    verbose

    All messages to trace listeners.

    Tracing does have some overhead. Therefore, you should balance tracing against the performance requirements of your application. In most cases, info and verbose settings are only appropriate during application development and troubleshooting.

The following configuration file shows an example for devices.

<configuration>

   <traceSettings>

     <add key ="FileLocation" value="TraceSample.txt"/>

     <add key ="LogLevel" value="4"/>

   </traceSettings>

</configuration>

The file should be named trace.config.txt and should be placed in the application directory on the device. If you include the file in a Visual Studio solution, it can be deployed with the application.

The following file segment is from a trace that was configured by using a SyncTracer value of 3. Each line begins with the kind of output. In this case, all the output is INFO. If an error occurred, the relevant lines would begin with ERROR.

INFO, MyApp.vshost, 10, 03/20/2008 17:43:03:027, Connecting to server using string: Data Source=localhost;Initial Catalog=SyncSamplesDb;Integrated Security=True

INFO, MyApp.vshost, 10, 03/20/2008 17:43:03:027, ----- Server Enumerating Changes to Client for Group "Customer" -----

INFO, MyApp.vshost, 10, 03/20/2008 17:43:03:027, Client Id: bc5610f6-bf9c-4ccd-8599-839e54e953e2

INFO, MyApp.vshost, 10, 03/20/2008 17:43:03:027, Mapped Originator Id: 0

INFO, MyApp.vshost, 10, 03/20/2008 17:43:03:042,

INFO, MyApp.vshost, 10, 03/20/2008 17:43:03:042, ----- Enumerating Inserts for Table Customer -----

INFO, MyApp.vshost, 10, 03/20/2008 17:43:03:058, Changes Enumerated: 5

INFO, MyApp.vshost, 10, 03/20/2008 17:43:03:058, --- End Enumerating Inserts for Table Customer ---

Using the SyncTracer Object

The SyncTracer object enables you to write application-specific tracing data to the trace file. This can provide contextual information about what an application is doing at a specific time. This object enables you to perform the following tasks:

  • Determine which level of tracing is enabled, by using the following methods:

  • Write messages to the trace output based on application events, by using the following methods, and other overloads for each method:

    For example, to output an informational message, you can use the following code:

    SyncTracer.Info("Informational message")

    If the Info level is enabled, the message is written to the output; otherwise, it is ignored.

    More complex messages can be formed also, such as the following. The numbers that are specified set the level of indentation in the output file.

    SyncTracer.Verbose("Processing table t1")

    SyncTracer.Verbose(1, "Applying Deletes")

    SyncTracer.Verbose(2, "{0} rows deleted", numDeleted)

    SyncTracer.Verbose(1, "Applying Inserts")

    SyncTracer.Verbose(2, "{0} rows inserted", numInserted)

    The output is as follows:

    Processing table t1

    Applying Deletes

    7 Rows Deleted

    Applying Inserts

    9 Rows inserted

The following code example writes information to the console about which tracing levels are enabled. The configuration file specifies a value of 3 for the SyncTracer switch. This corresponds to Info. Therefore, Error, Warning, and Info return True, and Verbose returns False.

Console.WriteLine("** Tracing Levels Enabled for this Application **");
Console.WriteLine("Error: " + SyncTracer.IsErrorEnabled().ToString());
Console.WriteLine("Warning: " + SyncTracer.IsWarningEnabled().ToString());
Console.WriteLine("Info: " + SyncTracer.IsInfoEnabled().ToString());
Console.WriteLine("Verbose: " + SyncTracer.IsVerboseEnabled().ToString());

The following code example shows how to write formatted warning messages about data conflicts to the trace output. For more information about conflicts, see How to: Handle Data Conflicts and Errors. Verbose tracing includes information about conflicts. In this application, verbose tracing is disabled, and the application flags conflicts with a warning instead.

if (SyncTracer.IsVerboseEnabled() == false && e.Conflict.ConflictType != ConflictType.ErrorsOccurred)
{
    DataTable conflictingServerChange = e.Conflict.ServerChange;
    DataTable conflictingClientChange = e.Conflict.ClientChange;
    int serverColumnCount = conflictingServerChange.Columns.Count;
    int clientColumnCount = conflictingClientChange.Columns.Count;
    StringBuilder clientRowAsString = new StringBuilder();
    StringBuilder serverRowAsString = new StringBuilder();

    for (int i = 0; i < clientColumnCount; i++)
    {
        clientRowAsString.Append(conflictingClientChange.Rows[0][i] + " | ");
    }

    for (int i = 0; i < serverColumnCount; i++)
    {
        serverRowAsString.Append(conflictingServerChange.Rows[0][i] + " | ");
    }

    SyncTracer.Warning(1, "CONFLICT DETECTED FOR CLIENT {0}", e.Session.ClientId);
    SyncTracer.Warning(2, "** Client change **");
    SyncTracer.Warning(2, clientRowAsString.ToString());
    SyncTracer.Warning(2, "** Server change **");
    SyncTracer.Warning(2, serverRowAsString.ToString());
}

Checking which levels of tracing are enabled can help you avoid potentially costly processing. In the example code, the application avoids additional processing if verbose tracing is already enabled. Conversely, the application might generate output only when a certain tracing level is enabled.

Security Considerations for Tracing

Trace files can include information about server and client computers, application data, and logins. (Passwords are not written to the trace file.) If verbose tracing is enabled, each changed row from the database is written to the trace file. Help protect the trace file by using the appropriate access control lists.

Complete Code Example

The following complete code example includes the code examples that are described earlier in this topic and additional code to perform synchronization. Before you run the application, perform the following steps:

  1. Create a project in Visual Studio.

  2. Add references to the Sync Framework DLLs and the Utility class that is available in Utility Class for Database Provider How-to Topics.

  3. Create a configuration file and copy the XML code from the example shown earlier in this topic.

Be aware of the two calls to methods in the Utility class:

  • util.MakeFailingChangesOnClient() This makes a change at the client that fails when it is applied at the server. The constraint violation and related application exception are automatically written to the trace file as warnings.

  • util.MakeConflictingChangesOnClientAndServer() This makes changes at the client and server that conflict when they are synchronized. The conflicts are written to the trace file in the SampleServerSyncProvider_ApplyChangeFailed event handler.

After you run the application, open the trace output file to see: the messages that are written automatically; and the conflict warnings, which are the result of application code.

using System;
using System.IO;
using System.Text;
using System.Data;
using System.Data.SqlClient;
using System.Data.SqlServerCe;
using Microsoft.Synchronization;
using Microsoft.Synchronization.Data;
using Microsoft.Synchronization.Data.Server;
using Microsoft.Synchronization.Data.SqlServerCe;

namespace Microsoft.Samples.Synchronization
{
    class Program
    {
        static void Main(string[] args)
        {

            //The SampleStats class handles information from the SyncStatistics
            //object that the Synchronize method returns.
            SampleStats sampleStats = new SampleStats();

            //Delete and re-create the database. The client synchronization
            //provider also enables you to create the client database 
            //if it does not exist.
            Utility.SetPassword_SqlCeClientSync();
            Utility.DeleteAndRecreateCompactDatabase(Utility.ConnStr_SqlCeClientSync, true);

            //Write to the console which tracing levels are enabled. The app.config
            //file specifies a value of 3 for the SyncTracer switch, which corresponds
            //to Info. Therefore, Error, Warning, and Info return True, and Verbose
            //returns False.
            Console.WriteLine("");
            Console.WriteLine("** Tracing Levels Enabled for this Application **");
            Console.WriteLine("Error: " + SyncTracer.IsErrorEnabled().ToString());
            Console.WriteLine("Warning: " + SyncTracer.IsWarningEnabled().ToString());
            Console.WriteLine("Info: " + SyncTracer.IsInfoEnabled().ToString());
            Console.WriteLine("Verbose: " + SyncTracer.IsVerboseEnabled().ToString());

            //Initial synchronization. Instantiate the SyncAgent
            //and call Synchronize.
            SampleSyncAgent sampleSyncAgent = new SampleSyncAgent();
            SyncStatistics syncStatistics = sampleSyncAgent.Synchronize();
            sampleStats.DisplayStats(syncStatistics, "initial");

            //Make a change at the client that fails when it is
            //applied at the server. The constraint violation
            //is automatically written to the trace file as a warning.
            Utility.MakeFailingChangeOnClient();

            //Make changes at the client and server that conflict
            //when they are synchronized. The conflicts are written
            //to the trace file in the SampleServerSyncProvider_ApplyChangeFailed
            //event handler.
            Utility.MakeConflictingChangesOnClientAndServer();

            //Subsequent synchronization.
            syncStatistics = sampleSyncAgent.Synchronize();
            sampleStats.DisplayStats(syncStatistics, "subsequent");

            //Return server data back to its original state.
            Utility.CleanUpServer();

            //Exit.
            Console.Write("\nPress Enter to close the window.");
            Console.ReadLine();
        }
    }

    //Create a class that is derived from 
    //Microsoft.Synchronization.SyncAgent.
    public class SampleSyncAgent : SyncAgent
    {
        public SampleSyncAgent()
        {
            //Instantiate a client synchronization provider and specify it
            //as the local provider for this synchronization agent.
            this.LocalProvider = new SampleClientSyncProvider();

            //Instantiate a server synchronization provider and specify it
            //as the remote provider for this synchronization agent.
            this.RemoteProvider = new SampleServerSyncProvider();

            //Add the Customer table: specify a synchronization direction of
            //DownloadOnly.
            SyncTable customerSyncTable = new SyncTable("Customer");
            customerSyncTable.CreationOption = TableCreationOption.DropExistingOrCreateNewTable;
            customerSyncTable.SyncDirection = SyncDirection.Bidirectional;
            this.Configuration.SyncTables.Add(customerSyncTable);
        }
    }

    //Create a class that is derived from 
    //Microsoft.Synchronization.Server.DbServerSyncProvider.
    public class SampleServerSyncProvider : DbServerSyncProvider
    {
        public SampleServerSyncProvider()
        {
            //Create a connection to the sample server database.
            Utility util = new Utility();
            SqlConnection serverConn = new SqlConnection(Utility.ConnStr_DbServerSync);
            this.Connection = serverConn;

            //Create a command to retrieve a new anchor value from
            //the server. In this case, we use a timestamp value
            //that is retrieved and stored in the client database.
            //During each synchronization, the new anchor value and
            //the last anchor value from the previous synchronization
            //are used: the set of changes between these upper and
            //lower bounds is synchronized.
            //
            //SyncSession.SyncNewReceivedAnchor is a string constant; 
            //you could also use @sync_new_received_anchor directly in 
            //your queries.
            SqlCommand selectNewAnchorCommand = new SqlCommand();
            string newAnchorVariable = "@" + SyncSession.SyncNewReceivedAnchor;
            selectNewAnchorCommand.CommandText = "SELECT " + newAnchorVariable + " = min_active_rowversion() - 1";
            selectNewAnchorCommand.Parameters.Add(newAnchorVariable, SqlDbType.Timestamp);
            selectNewAnchorCommand.Parameters[newAnchorVariable].Direction = ParameterDirection.Output;
            selectNewAnchorCommand.Connection = serverConn;
            this.SelectNewAnchorCommand = selectNewAnchorCommand;


            //Create a SyncAdapter for the Customer table by using 
            //the SqlSyncAdapterBuilder:
            //  * Specify the base table and tombstone table names.
            //  * Specify the columns that are used to track when
            //    and where changes are made.
            //  * Specify bidirectional synchronization.
            //  * Call ToSyncAdapter to create the SyncAdapter.
            //  * Specify a name for the SyncAdapter that matches the
            //    the name specified for the corresponding SyncTable.
            //    Do not include the schema names (Sales in this case).

            SqlSyncAdapterBuilder customerBuilder = new SqlSyncAdapterBuilder(serverConn);

            customerBuilder.TableName = "Sales.Customer";
            customerBuilder.TombstoneTableName = customerBuilder.TableName + "_Tombstone";
            customerBuilder.SyncDirection = SyncDirection.Bidirectional;
            customerBuilder.CreationTrackingColumn = "InsertTimestamp";
            customerBuilder.UpdateTrackingColumn = "UpdateTimestamp";
            customerBuilder.DeletionTrackingColumn = "DeleteTimestamp";
            customerBuilder.CreationOriginatorIdColumn = "InsertId";
            customerBuilder.UpdateOriginatorIdColumn = "UpdateId";
            customerBuilder.DeletionOriginatorIdColumn = "DeleteId";

            SyncAdapter customerSyncAdapter = customerBuilder.ToSyncAdapter();
            customerSyncAdapter.TableName = "Customer";
            this.SyncAdapters.Add(customerSyncAdapter);

            //Handle the ApplyChangeFailed event. This allows us to write  
            //information to the trace file about any conflicts that occur.
            this.ApplyChangeFailed += new EventHandler<ApplyChangeFailedEventArgs>(SampleServerSyncProvider_ApplyChangeFailed);
        }

        private void SampleServerSyncProvider_ApplyChangeFailed(object sender, ApplyChangeFailedEventArgs e)
        {
            //Verbose tracing includes information about conflicts. In this application,
            //Verbose tracing is disabled, and we have decided to flag conflicts with a 
            //warning.
            //Check if Verbose tracing is enabled and if the conflict is an error.
            //If the conflict is not an error, we write a warning to the trace file
            //with information about the conflict.
            if (SyncTracer.IsVerboseEnabled() == false && e.Conflict.ConflictType != ConflictType.ErrorsOccurred)
            {
                DataTable conflictingServerChange = e.Conflict.ServerChange;
                DataTable conflictingClientChange = e.Conflict.ClientChange;
                int serverColumnCount = conflictingServerChange.Columns.Count;
                int clientColumnCount = conflictingClientChange.Columns.Count;
                StringBuilder clientRowAsString = new StringBuilder();
                StringBuilder serverRowAsString = new StringBuilder();

                for (int i = 0; i < clientColumnCount; i++)
                {
                    clientRowAsString.Append(conflictingClientChange.Rows[0][i] + " | ");
                }

                for (int i = 0; i < serverColumnCount; i++)
                {
                    serverRowAsString.Append(conflictingServerChange.Rows[0][i] + " | ");
                }

                SyncTracer.Warning(1, "CONFLICT DETECTED FOR CLIENT {0}", e.Session.ClientId);
                SyncTracer.Warning(2, "** Client change **");
                SyncTracer.Warning(2, clientRowAsString.ToString());
                SyncTracer.Warning(2, "** Server change **");
                SyncTracer.Warning(2, serverRowAsString.ToString());
            }
        }
    }

    //Create a class that is derived from 
    //Microsoft.Synchronization.Data.SqlServerCe.SqlCeClientSyncProvider.
    //You can just instantiate the provider directly and associate it
    //with the SyncAgent, but you could use this class to handle client 
    //provider events and other client-side processing.
    public class SampleClientSyncProvider : SqlCeClientSyncProvider
    {

        public SampleClientSyncProvider()
        {
            //Specify a connection string for the sample client database.
            Utility util = new Utility();
            this.ConnectionString = Utility.ConnStr_SqlCeClientSync;
            
            this.SchemaCreated += new EventHandler<SchemaCreatedEventArgs>(SampleClientSyncProvider_SchemaCreated);            
        }

        private void SampleClientSyncProvider_SchemaCreated(object sender, SchemaCreatedEventArgs e)
        {
            string tableName = e.Table.TableName;
            Utility util = new Utility();

            //Call ALTER TABLE on the client. This must be done
            //over the same connection and within the same
            //transaction that Sync Framework uses
            //to create the schema on the client.
            Utility.MakeSchemaChangesOnClient(e.Connection, e.Transaction, "Customer");

        }
    }

    //Handle the statistics that are returned by the SyncAgent.
    public class SampleStats
    {
        public void DisplayStats(SyncStatistics syncStatistics, string syncType)
        {
            Console.WriteLine(String.Empty);
            if (syncType == "initial")
            {
                Console.WriteLine("****** Initial Synchronization ******");
            }
            else if (syncType == "subsequent")
            {
                Console.WriteLine("***** Subsequent Synchronization ****");
            }

            Console.WriteLine("Start Time: " + syncStatistics.SyncStartTime);
            Console.WriteLine("Total Changes Downloaded: " + syncStatistics.TotalChangesDownloaded);
            Console.WriteLine("Total Changes Uploaded: " + syncStatistics.TotalChangesUploaded);
            Console.WriteLine("Complete Time: " + syncStatistics.SyncCompleteTime);
            Console.WriteLine(String.Empty);

        }
    }
}

See Also

Show:
© 2014 Microsoft