DRS Initialization In Configuration Manager 2012

DRS Initialization In Configuration Manager 2012

When a site is first installed it establishes an initial synchronization with the sending site so that subsequent data changes are applied to an identical data set as that at the sending site.

By default the first replication group processed is the Replication Configuration group - this group effectively 'bootstraps' the receiving site with the remaining configuration for other replication groups.

The site initializes by sending an 'init' request to the sending site for the desired replication group.

When the sending site receives the 'init' request it uses the bcp application to extract all of the data from the tables that make up the replication group being initialized. At the same time a rowcount of the number of exported rows is also taken and stored in a .rowcount file. This allows the receiving site to ensure it has imported the same number of rows as the sending site exported for import.

The sending site sets the receiving site as a subscriber to the replication group and RCM begins sending any changes to tables in the replication group to the receiving site. The bcp files are replicated to the receiving site via the standard content sender.

Once the bcp files have arrived at the receiving site, RCM on the receiving site is notified of the files in its inbox and begins a cycle of actions for each table in the replication group:

  1.   Any existing data in the destination table that overlaps with the received data from the sending site is deleted from the table.
  2.  BCP is used to import the data from the sending site into the receiving site database.
  3.  After the import has completed the rowcount from the bcp process is compared to the row count in the .rowcount file. Assuming the values match the next table is processed.

Once all the tables have been processed the group status is changed to active and the site begins processing any messages in the queue.

We will also try re-initialization if we see any error on any specific group. When you run replication analyzer it will try auto remediate once and that particular group will be re-initialized.

We can also re-initialize putting a .pub file in RCM.box . The file <replicationgroupname>.pub works fine for Global Data. But for site-data where the CAS is the subscriber you have to add the sitecode to the file name, so it is like <replicationgroupname>-<sitecode>.pub, this is so the CAS knows which primary to re-init from.

Global data eg: configuration data.pub => Drop these on Primary server RCM.BOX

Site Data eg: hardware_inventory_8-PR1.pub => Drop these on CAS server RCM.BOX

 This is all theory, Now what it if it is failing to re-initialize. The question we all have is, where to look and how to track. The remaining part of this document will go through that.

 Always exec spdiagdrs is always a way to know if the replication is active. I will not be going to the details of the output here but will take you through the flow of re-initialization of a particular group.

 Once we find that a particular group is having error in the output of spdiagdrs you will find that the following in the hierarchy information as well

 

This means that there is a Site data replication issue. Also under monitoring you will find the same information with a Link error for site data with Link error

 So now to solve this we will re-initialize the group and track the flow. In this I am taking hardware_inventory_8 as an example. To re-initiate a specific group there are various method the safe method according to me is to put <Groupname>-<SITECODE>.pub in our case eg : hardware_inventory_8-PR1.pub 

 I enable enhanced logging to get more information so that it will be helpful to understand what happened when we see error again and again

HKEY_LOCAL_MACHINE\SOFTWARE\Microsoft\SMS\Components\SMS_REPLICATION_CONFIGURATION_MONITOR ==>Verbose Logging : 2

HKEY_LOCAL_MACHINE\SOFTWARE\Microsoft\SMS\Tracing ==>Sqlenabled : 1

We have two kind of logging in ConfigMgr 2012. For DRS initialization we can use the rcmctrl.log and inside the database vlogs view. For the database I used the following query to get the data out of it while I was performing this action.

 Select * from vLogs where LogTime >GETDATE()-1 and ProcedureName <> 'spDRSSendChangesForGroup' ORDER BY LogTime DESC

 To re-initialize the group put the file in \Microsoft Configuration Manager\inboxes\rcm.box . In some time we will see that vanishing from the box and the RCM will take control.Once the same happens you will see the following in the rcmctrl.log in CAS

 

Processing replication group Hardware_Inventory_8. SMS_REPLICATION_CONFIGURATION_MONITOR 20-10-2012 02:02:24 1820 (0x071C)

Current status is Active. SMS_REPLICATION_CONFIGURATION_MONITOR 20-10-2012 02:02:24 1820 (0x071C)

Requesting initialization for replication group Hardware_Inventory_8. SMS_REPLICATION_CONFIGURATION_MONITOR 20-10-2012 02:02:24 1820 (0x071C)

Checking if initialization request is needed for replication group Hardware_Inventory_8 from site PR1. SMS_REPLICATION_CONFIGURATION_MONITOR 20-10-2012 02:02:27 1820 (0x071C)

 

 

LogLine

LogTime

ComponentName

MachineName

ProcedureName

LogText

429508

02:24.9

Microsoft SQL Server

 Service Broker Activation

spRCMActivation

INFO: Received DRS_SubscriptionInvalid from

 Site CAS for replication group:

 Hardware_Inventory_8 and fulfilling site:

PR1 and requesting site: CAS

429509

02:24.9

Microsoft SQL Server

Service Broker Activation

spRCMActivation

INFO: DRS_SubscriptionInvalid is for full initialization -

 marking required replication group.

429510

02:24.9

Microsoft SQL Server

Service Broker Activation

spRCMActivation

INFO: Finished processing DRS_SubscriptionInvalid from Site

 CAS for replication group: Hardware_Inventory_8

 

Now on the primary server on the rcmctrl.log you will see

 

Processing replication role: DrsReplicationSite, child SMS_REPLICATION_CONFIGURATION_MONITOR 20-10-2012 02:03:03 3364 (0x0D24)

Processing replication group Hardware_Inventory_8. SMS_REPLICATION_CONFIGURATION_MONITOR 20-10-2012 02:03:03 3364 (0x0D24)

Current status is PendingCreation. SMS_REPLICATION_CONFIGURATION_MONITOR 20-10-2012 02:03:03 3364 (0x0D24)

Checking if we need to create an initialization package for replication group Hardware_Inventory_8 for site CAS. SMS_REPLICATION_CONFIGURATION_MONITOR 20-10-2012 02:03:04 3364 (0x0D24)

STATMSG: ID=7802 SEV=I LEV=M SOURCE="SMS Server" COMP="SMS_REPLICATION_CONFIGURATION_MONITOR" SYS=CMLABPRI.CMLAB.COM SITE=PR1 PID=5060 TID=3364 GMTDATE=Sat Oct 20 09:03:04.342 2012 ISTR0="CAS" ISTR1="Hardware_Inventory_8" ISTR2="" ISTR3="" ISTR4="" ISTR5="" ISTR6="" ISTR7="" ISTR8="" ISTR9="" NUMATTRS=0 SMS_REPLICATION_CONFIGURATION_MONITOR 20-10-2012 02:03:04 3364 (0x0D24)

Flushing DRS queue messages coming from CAS for replication group Hardware_Inventory_8. SMS_REPLICATION_CONFIGURATION_MONITOR 20-10-2012 02:03:04 3364 (0x0D24)

Changed the status of ConfigMgrDRSSiteQueue to OFF if it exists. SMS_REPLICATION_CONFIGURATION_MONITOR 20-10-2012 02:03:04 3364 (0x0D24)

Changed the status of ConfigMgrDRSSiteQueue to ON if it exists. SMS_REPLICATION_CONFIGURATION_MONITOR 20-10-2012 02:03:07 3364 (0x0D24)

Files will be copied to directory C:\Program Files\Microsoft Configuration Manager\inboxes\rcm.box\a4ba357d-1cb4-408c-9e89-681686974194. SMS_REPLICATION_CONFIGURATION_MONITOR 20-10-2012 02:03:07 3364 (0x0D24)

Cab File to be sent will be copied to directory C:\Program Files\Microsoft Configuration Manager\inboxes\rcm.box\CabFiles. SMS_REPLICATION_CONFIGURATION_MONITOR 20-10-2012 02:03:07 3364 (0x0D24)

XML CreateTime: 20-10-2012 09:02:31 LastModifyTime: 20-10-2012 09:02:31 SMS_REPLICATION_CONFIGURATION_MONITOR 20-10-2012 02:03:07 3364 (0x0D24)

Creating version file C:\Program Files\Microsoft Configuration Manager\inboxes\rcm.box\a4ba357d-1cb4-408c-9e89-681686974194\781708.version SMS_REPLICATION_CONFIGURATION_MONITOR 20-10-2012 02:03:07 3364 (0x0D24)

Creating trackingGuid file C:\Program Files\Microsoft Configuration Manager\inboxes\rcm.box\a4ba357d-1cb4-408c-9e89-681686974194\d74dc244-a526-4387-86b0-efacf67df680.trackingGuid SMS_REPLICATION_CONFIGURATION_MONITOR 20-10-2012 02:03:07 3364 (0x0D24)

Creating pubName file C:\Program Files\Microsoft Configuration Manager\inboxes\rcm.box\a4ba357d-1cb4-408c-9e89-681686974194\Hardware_Inventory_8-PR1.pubName SMS_REPLICATION_CONFIGURATION_MONITOR 20-10-2012 02:03:07 3364 (0x0D24)

………………………..

……………………….

 Calling BCP out with SELECT BINFILEVERSION00, BINPRODUCTVERSION00, DESCRIPTION00, FILENAME00, FILEPROPERTIESHASH00, FILEPROPERTIESHASHEX00, FILEVERSION00, LOCATION00, PRODUCT00, PRODUCTVERSION00, PUBLISHER00, STARTUPTYPE00, STARTUPVALUE00, MACHINEID, INSTANCEKEY, TIMEKEY, REVISIONID, AGENTID, ROWVERSION~FROM AUTOSTART_SOFTWARE_HIST where (MachineID between 16777216 and 33554431) , C:\Program Files\Microsoft Configuration Manager\inboxes\rcm.box\a4ba357d-1cb4-408c-9e89-681686974194\AUTOSTART_SOFTWARE_HIST.bcp, C:\Program Files\Microsoft Configuration Manager\inboxes\rcm.box\a4ba357d-1cb4-408c-9e89-681686974194\bcpErrors.errors. SMS_REPLICATION_CONFIGURATION_MONITOR 20-10-2012 02:03:07 3364 (0x0D24)

………………………………..

………………………………. 

Successfully created BCP file [C:\Program Files\Microsoft Configuration Manager\inboxes\rcm.box\a4ba357d-1cb4-408c-9e89-681686974194\AUTOSTART_SOFTWARE_DATA.bcp] with rows [6] based on SQL query [SELECT BINFILEVERSION00, BINPRODUCTVERSION00, DESCRIPTION00, FILENAME00, FILEPROPERTIESHASH00, FILEPROPERTIESHASHEX00, FILEVERSION00, LOCATION00, PRODUCT00, PRODUCTVERSION00, PUBLISHER00, STARTUPTYPE00, STARTUPVALUE00, MACHINEID, INSTANCEKEY, TIMEKEY, REVISIONID, AGENTID, ROWVERSION~FROM AUTOSTART_SOFTWARE_DATA where (MachineID between 16777216 and 33554431) ] SMS_REPLICATION_CONFIGURATION_MONITOR 20-10-2012 02:03:07 3364 (0x0D24)

BCP out result is 0. SMS_REPLICATION_CONFIGURATION_MONITOR 20-10-2012 02:03:07 3364 (0x0D24)

Table XML: <TABLE NAME="AUTOSTART_SOFTWARE_HIST"><COLUMN COLUMN_ID="1" NAME="BINFILEVERSION00" TYPENAME="nvarchar" TYPEID="231" MAX_LENGTH="510" IS_NULLABLE="1" HAS_DEFAULTVALUE="0" /><

………………………..

…………………………

                        SMS_REPLICATION_CONFIGURATION_MONITOR 20-10-2012 02:03:07 3364 (0x0D24)

 

This shows the BCP out commands being fired and also you will see the files like shown in the figure below. The Version file ,trackinguid file, Errors file ,pubnamefile and then for each table in the group .bcp file and .row count file.

.

 

In the database on the primary you will see the following .

 

LogLine

LogTime

ComponentName

MachineName

ProcedureName

LogText

7E+16

02:24.9

Microsoft SQL

 Server Service

Broker Activation

 

spRCMActivation

INFO: Received DRS_SubscriptionInvalid  from

Site CAS for replication group:

 Hardware_Inventory_8 and fulfilling site:  PR1

and requesting site: CAS

7E+16

02:24.9

Microsoft SQL

 Server Service

Broker Activation

 

spRCMActivation

INFO: DRS_SubscriptionInvalid is for

full initialization - marking required  replication group.

7E+16

02:24.9

Microsoft SQL

 Server Service

Broker Activation

 

spRCMActivation

INFO: Finished processing  DRS_SubscriptionInvalid

 from Site CAS for replication group:

Hardware_Inventory_8

7E+16

02:31.4

Microsoft

SQL Server Service

Broker Activation

 

spRCMActivation

INFO: Received DRS_InitRequest

from Site CAS for replication group:

 Hardware_Inventory_8

7E+16

03:08.4

SMS_REPLICATION

_CONFIGURATION

_MONITOR

CMLABPRI

SMS_REPLICATION

_CONFIGURATION

_MONITOR

Creating init package for replication  group

Hardware_Inventory_8 for site CAS.

 -- 10/20/2012 02:03:04

7E+16

03:08.4

SMS_REPLICATION

_CONFIGURATION

_MONITOR

CMLABPRI

SMS_REPLICATION_

CONFIGURATION

_MONITOR

INFO: Flushing DRS queue messages  coming

from subscriber CAS for replication  group Hardware_Inventory_8. --  10/20/2012 02:03:04

7E+16

03:08.4

SMS_REPLICATION

_CONFIGURATION

_MONITOR

CMLABPRI

SMS_REPLICATION

_CONFIGURATION

_MONITOR

INFO: Turned off DRS queue

ConfigMgrDRSSiteQueue on publisher

 PR1.   -- 10/20/2012 02:03:04

7E+16

03:08.4

SMS_REPLICATION

_CONFIGURATION

_MONITOR

CMLABPRI

SMS_REPLICATION

_CONFIGURATION

_MONITOR

INFO: Turned on DRS queue

ConfigMgrDRSSiteQueue on publisher PR1

.   -- 10/20/2012 02:03:07

7E+16

03:08.4

SMS_REPLICATION

_CONFIGURATION

_MONITOR

CMLABPRI

SMS_REPLICATION

_CONFIGURATION

_MONITOR

INFO: Init package XML CreateTime:

20-10-2012 09:02:31 LastModifyTime:

 20-10-2012 09:02:31 for replication group Hardware_Inventory_8  for site CAS. 

-- 10/20/2012 02:03:07

7E+16

03:08.5

SMS_

REPLICATION_

CONFIGURATION

_MONITOR

CMLABPRI

SMS_REPLICATION

_CONFIGURATION

_MONITOR

INFO: Created version file for init

 package for replication group

Hardware_Inventory_8 for site CAS.

 -- 10/20/2012 02:03:07

7E+16

03:08.5

SMS_REPLICATION

_CONFIGURATION

_MONITOR

CMLABPRI

SMS_REPLICATION

_CONFIGURATION

_MONITOR

INFO: Created tracking GUID file for

 init package for replication group

 Hardware_Inventory_8 for site CAS. 

-- 10/20/2012 02:03:07

7E+16

03:08.5

SMS_REPLICATION

_CONFIGURATION

_MONITOR

CMLABPRI

SMS_REPLICATION

_CONFIGURATION

_MONITOR

INFO: Created pub file for init

package for replication group

Hardware_Inventory_8 for site CAS.

 -- 10/20/2012 02:03:07

7E+16

03:08.5

SMS_REPLICATION

_CONFIGURATION

_MONITOR

CMLABPRI

SMS_REPLICATION

_CONFIGURATION

_MONITOR

Calling BCP out for table

AUTOSTART_SOFTWARE_DATA. 

-- 10/20/2012 02:03:07

7E+16

03:08.5

SMS_REPLICATION

_CONFIGURATION

_MONITOR

CMLABPRI

SMS_REPLICATION

_CONFIGURATION

_MONITOR

BCP out result for table

 AUTOSTART_SOFTWARE_DATA is 0.

 -- 10/20/2012 02:03:07

7E+16

03:08.5

SMS_REPLICATION

_CONFIGURATION

_MONITOR

CMLABPRI

SMS_REPLICATION

_CONFIGURATION

_MONITOR

Calling BCP out for table  AUTOSTART_SOFTWARE_HIST. -- 10/20/2012  02:03:07

7E+16

03:08.5

SMS_REPLICATION

_CONFIGURATION

_MONITOR

CMLABPRI

SMS_REPLICATION

_CONFIGURATION

_MONITOR

BCP out result for table  AUTOSTART_SOFTWARE_HIST is 0. --  10/20/2012 02:03:07

7E+16

03:08.5

SMS_REPLICATION

_CONFIGURATION

_MONITOR

CMLABPRI

SMS_REPLICATION

_CONFIGURATION

_MONITOR

Calling BCP out for table BROWSER_HELPER_OBJECT_DATA. -- 10/20/2012 02:03:07

7E+16

03:08.6

SMS_REPLICATION

_CONFIGURATION

_MONITOR

CMLABPRI

SMS_REPLICATION

_CONFIGURATION

 

_MONITOR

BCP out result for table  BROWSER_HELPER_OBJECT_DATA is 0. --  10/20/2012 02:03:07

7E+16

03:08.6

SMS_REPLICATION

_CONFIGURATION

_MONITOR

CMLABPRI

SMS_REPLICATION

_CONFIGURATION

_MONITOR

Calling BCP out for table  BROWSER_HELPER_OBJECT_HIST. --  10/20/2012 02:03:07

7E+16

03:08.6

SMS_REPLICATION

_CONFIGURATION

_MONITOR

CMLABPRI

SMS_REPLICATION

_CONFIGURATION_

MONITOR

BCP out result for table  BROWSER_HELPER_OBJECT_HIST is 0. --  10/20/2012 02:03:07

7E+16

03:08.6

SMS_REPLICATION

_CONFIGURATION

_MONITOR

CMLABPRI

SMS_REPLICATION

_CONFIGURATION

_MONITOR

Calling BCP out for table  SW_LICENSING_PRODUCT_DATA. --  10/20/2012 02:03:07

7E+16

03:08.6

SMS_REPLICATION

_CONFIGURATION

_MONITOR

CMLABPRI

SMS_REPLICATION

_CONFIGURATION

_MONITOR

BCP out result for table  SW_LICENSING_PRODUCT_DATA is 0. --  10/20/2012 02:03:07

7E+16

03:08.6

SMS_REPLICATION

_CONFIGURATION

_MONITOR

CMLABPRI

SMS_REPLICATION

_CONFIGURATION

_MONITOR

Calling BCP out for table  SW_LICENSING_PRODUCT_HIST. --  10/20/2012 02:03:07

7E+16

03:08.6

SMS_REPLICATION

_CONFIGURATION

_MONITOR

CMLABPRI

SMS_REPLICATION

_CONFIGURATION

_MONITOR

BCP out result for table  SW_LICENSING_PRODUCT_HIST is 0. --  10/20/2012 02:03:07

7E+16

03:08.6

SMS_REPLICATION

_CONFIGURATION

_MONITOR

CMLABPRI

SMS_REPLICATION

_CONFIGURATION

_MONITOR

Calling BCP out for table  SW_LICENSING_SERVICE_DATA. --  10/20/2012 02:03:07

7E+16

03:08.6

SMS_REPLICATION

_CONFIGURATION

_MONITOR

CMLABPRI

SMS_REPLICATION

_CONFIGURATION

_MONITOR

BCP out result for table SW_LICENSING_SERVICE_DATA  is 0. -- 10/20/2012 02:03:08

7E+16

03:08.7

SMS_REPLICATION

_CONFIGURATION

_MONITOR

CMLABPRI

SMS_REPLICATION

_CONFIGURATION

_MONITOR

Calling BCP out for table  SW_LICENSING_SERVICE_HIST. --  10/20/2012 02:03:08

7E+16

03:08.7

SMS_REPLICATION

_CONFIGURATION

_MONITOR

CMLABPRI

SMS_REPLICATION

_CONFIGURATION

_MONITOR

BCP out result for table  SW_LICENSING_SERVICE_HIST is 0. --  10/20/2012 02:03:08

7E+16

03:08.7

SMS_REPLICATION

_CONFIGURATION

_MONITOR

CMLABPRI

SMS_REPLICATION

_CONFIGURATION

_MONITOR

Calling BCP out for table  USB_DEVICE_DATA. -- 10/20/2012  02:03:08

7E+16

03:08.7

SMS_REPLICATION

_CONFIGURATION

_MONITOR

CMLABPRI

SMS_REPLICATION

_CONFIGURATION

_MONITOR

BCP out result for table  USB_DEVICE_DATA is 0. -- 10/20/2012  02:03:08

7E+16

03:08.7

SMS_REPLICATION

_CONFIGURATION

_MONITOR

CMLABPRI

SMS_REPLICATION

_CONFIGURATION

_MONITOR

Calling BCP out for table  USB_DEVICE_HIST. -- 10/20/2012  02:03:08

7E+16

03:08.7

SMS_REPLICATION

_CONFIGURATION

_MONITOR

CMLABPRI

SMS_REPLICATION

_CONFIGURATION

_MONITOR

BCP out result for table  USB_DEVICE_HIST is 0. -- 10/20/2012  02:03:08

7E+16

03:08.7

SMS_REPLICATION

_CONFIGURATION_

MONITOR

CMLABPRI

SMS_REPLICATION

_CONFIGURATION

_MONITOR

Sending the init package for  replication group Hardware_Inventory_8 to subscriber CAS. -- 10/20/2012 02:03:08

7E+16

03:08.7

SMS_REPLICATION

_CONFIGURATION

_MONITOR

CMLABPRI

SMS_REPLICATION

_CONFIGURATION

_MONITOR

Send result for init package for  replication group Hardware_Inventory_8 to subscriber CAS is 0. -- 10/20/2012 02:03:08

7E+16

03:08.8

SMS_REPLICATION

_CONFIGURATION

_MONITOR

CMLABPRI

SMS_REPLICATION

_CONFIGURATION

_MONITOR

Init package created and sent for  replication group Hardware_Inventory_8 for site CAS. -- 10/20/2012 02:03:08

   
   

Once the BCP out is completed the compression will happen and file will be stored in the CABFiles folder as shown below

 

The rcmctrl.log will have the following

Calling drs_init_send method now with parameters C:\Program Files\Microsoft Configuration Manager\inboxes\rcm.box\a4ba357d-1cb4-408c-9e89-681686974194 and CAS. SMS_REPLICATION_CONFIGURATION_MONITOR 20-10-2012 02:03:08 3364 (0x0D24)

Starting to compress files under folder [C:\Program Files\Microsoft Configuration Manager\inboxes\rcm.box\a4ba357d-1cb4-408c-9e89-681686974194\] to [C:\Program Files\Microsoft Configuration Manager\inboxes\rcm.box\CabFiles\CAS_4C7EB459-2631-455B-93C1-8C08926BAD07.cab] ... SMS_REPLICATION_CONFIGURATION_MONITOR 20-10-2012 02:03:08 3364 (0x0D24)

Deleting all files under folder [C:\Program Files\Microsoft Configuration Manager\inboxes\rcm.box\a4ba357d-1cb4-408c-9e89-681686974194]. SMS_REPLICATION_CONFIGURATION_MONITOR 20-10-2012 02:03:08 3364 (0x0D24)

Created minijob to send compressed copy of DRS INIT BCP Package to site CAS. Tranfer root = C:\Program Files\Microsoft Configuration Manager\inboxes\rcm.box\CabFiles\CAS_4C7EB459-2631-455B-93C1-8C08926BAD07.cab. SMS_REPLICATION_CONFIGURATION_MONITOR 20-10-2012 02:03:08 3364 (0x0D24)

drs_init_send returned 0. SMS_REPLICATION_CONFIGURATION_MONITOR 20-10-2012 02:03:08 3364 (0x0D24)

STATMSG: ID=7803 SEV=I LEV=M SOURCE="SMS Server" COMP="SMS_REPLICATION_CONFIGURATION_MONITOR" SYS=CMLABPRI.CMLAB.COM SITE=PR1 PID=5060 TID=3364 GMTDATE=Sat Oct 20 09:03:08.373 2012 ISTR0="Hardware_Inventory_8" ISTR1="CAS" ISTR2="" ISTR3="" ISTR4="" ISTR5="" ISTR6="" ISTR7="" ISTR8="" ISTR9="" NUMATTRS=0 SMS_REPLICATION_CONFIGURATION_MONITOR 20-10-2012 02:03:08 3364 (0x0D24)

Current status is PackageCreated. SMS_REPLICATION_CONFIGURATION_MONITOR 20-10-2012 02:03:08 3364 (0x0D24)

Found 1 replication roles. SMS_REPLICATION_CONFIGURATION_MONITOR 20-10-2012 02:03:08 3364 (0x0D24)

 

Now once this is done the sender will send the files to the CAS server.

Sender.log

=======

Passed the xmit file test, use the existing connection SMS_LAN_SENDER 20-10-2012 02:03:33 5012 (0x1394)

Package file = C:\Program Files\Microsoft Configuration Manager\inboxes\rcm.box\CabFiles\CAS_4C7EB459-2631-455B-93C1-8C08926BAD07.cab SMS_LAN_SENDER 20-10-2012 02:03:33 5012 (0x1394)

Instruction file = C:\Program Files\Microsoft Configuration Manager\inboxes\schedule.box\tosend\00000085.I59 SMS_LAN_SENDER 20-10-2012 02:03:33 5012 (0x1394)

Checking for remote file \\CMLABCAS.CMLAB.COM\SMS_SITE\1003PPR1.PCK SMS_LAN_SENDER 20-10-2012 02:03:33 5012 (0x1394)

Checking for remote file \\CMLABCAS.CMLAB.COM\SMS_SITE\1003PPR1.SNI SMS_LAN_SENDER 20-10-2012 02:03:33 5012 (0x1394)

Checking for remote file \\CMLABCAS.CMLAB.COM\SMS_SITE\1003PPR1.TMP SMS_LAN_SENDER 20-10-2012 02:03:33 5012 (0x1394)

Attempt to create/open the remote file \\CMLABCAS.CMLAB.COM\SMS_SITE\1003PPR1.PCK SMS_LAN_SENDER 20-10-2012 02:03:33 5012 (0x1394)

Created/opened the remote file \\CMLABCAS.CMLAB.COM\SMS_SITE\1003PPR1.PCK SMS_LAN_SENDER 20-10-2012 02:03:33 5012 (0x1394)

Attempt to create/open the remote file \\CMLABCAS.CMLAB.COM\SMS_SITE\1003PPR1.PCK SMS_LAN_SENDER 20-10-2012 02:03:33 5012 (0x1394)

Created/opened the remote file \\CMLABCAS.CMLAB.COM\SMS_SITE\1003PPR1.PCK SMS_LAN_SENDER 20-10-2012 02:03:33 5012 (0x1394)

Sending Started [C:\Program Files\Microsoft Configuration Manager\inboxes\rcm.box\CabFiles\CAS_4C7EB459-2631-455B-93C1-8C08926BAD07.cab] SMS_LAN_SENDER 20-10-2012 02:03:33 5012 (0x1394)

Attempt to write 1024 bytes to \\CMLABCAS.CMLAB.COM\SMS_SITE\1003PPR1.PCK at position 0 SMS_LAN_SENDER 20-10-2012 02:03:33 5012 (0x1394)

……………………….

……………………….

S.CMLAB.COM\SMS_SITE\1003PPR1.TMP SMS_LAN_SENDER 20-10-2012 02:03:33 5012 (0x1394)

Created/opened the remote file \\CMLABCAS.CMLAB.COM\SMS_SITE\1003PPR1.TMP SMS_LAN_SENDER 20-10-2012 02:03:33 5012 (0x1394)

Sending Started [C:\Program Files\Microsoft Configuration Manager\inboxes\schedule.box\tosend\00000085.I59] SMS_LAN_SENDER 20-10-2012 02:03:33 5012 (0x1394)

Attempt to write 650 bytes to \\CMLABCAS.CMLAB.COM\SMS_SITE\1003PPR1.TMP at position 0 SMS_LAN_SENDER 20-10-2012 02:03:33 5012 (0x1394)

Wrote 650 bytes to \\CMLABCAS.CMLAB.COM\SMS_SITE\1003PPR1.TMP at position 0 SMS_LAN_SENDER 20-10-2012 02:03:33 5012 (0x1394)

Sending completed [C:\Program Files\Microsoft Configuration Manager\inboxes\schedule.box\tosend\00000085.I59] SMS_LAN_SENDER 20-10-2012 02:03:33 5012 (0x1394)

Renaming remote file \\CMLABCAS.CMLAB.COM\SMS_SITE\1003PPR1.TMP to \\CMLABCAS.CMLAB.COM\SMS_SITE\1003PPR1.SNI SMS_LAN_SENDER 20-10-2012 02:03:33 5012 (0x1394)

Rename completed [\\CMLABCAS.CMLAB.COM\SMS_SITE\1003PPR1.TMP] SMS_LAN_SENDER 20-10-2012 02:03:33 5012 (0x1394)

Sending completed successfully SMS_LAN_SENDER 20-10-2012 02:03:33 5012 (0x1394)

COutbox::TakeNextToSend(pszSiteCode) SMS_LAN_SENDER 20-10-2012 02:03:33 5012 (0x1394)

We have 0 active connections SMS_LAN_SENDER 20-10-2012 02:03:38 4784 (0x12B0)

Checking for sending capacity. Used 0 out of 5. SMS_LAN_SENDER 20-10-2012 02:03:38 4784 (0x12B0)

Connecting to C:\Program Files\Microsoft Configuration Manager\inboxes\schedule.box\outboxes\LAN. SMS_LAN_SENDER 20-10-2012 02:03:38 4784 (0x12B0)

COutbox::TakeNextToSend(pszSiteCode) SMS_LAN_SENDER 20-10-2012 02:03:38 4784 (0x12B0)

No (more) send requests found to process. SMS_LAN_SENDER 20-10-2012 02:03:38 4784 (0x12B0)

Waiting for new/rescheduled send requests, Maximum Sleep Time = 60 minutes SMS_LAN_SENDER 20-10-2012 02:03:38 4784 (0x12B0)

 

 

One the database logs you will find the following

LogLine

LogTime

ComponentName

MachineName

ProcedureName

LogText

7.20576E+16

03:08.7

SMS_REPLICATION_

CONFIGURATION_

MONITOR

CMLABPRI

SMS_REPLICATION_

CONFIGURATION_

MONITOR

Sending the init package for replication

group Hardware_Inventory_8 to subscriber

CAS. -- 10/20/2012 02:03:08

7.20576E+16

03:08.7

SMS_REPLICATION_

CONFIGURATION_

MONITOR

CMLABPRI

SMS_REPLICATION_

CONFIGURATION_

MONITOR

Send result for init package

 for replication group Hardware_Inventory_8 t

o subscriber CAS is 0. -- 10/20/2012 02:03:08

7.20576E+16

03:08.8

SMS_REPLICATION_

CONFIGURATION_

MONITOR

CMLABPRI

SMS_REPLICATION_C

ONFIGURATION_

MONITOR

Init package created and sent

 for replication group Hardware_Inventory_8

 for site CAS. -- 10/20/2012 02:03:08

 

 

Now once the CAS receives the files the despooler will start pressing the files inside RCM.box\<GUID> just like it created in Primary. The despooler.log will show you the same

Despoolr.log

=========

Waiting for ready instruction file.... SMS_DESPOOLER 20-10-2012 02:03:38 3972 (0x0F84)

Decompressed C:\Program Files\Microsoft Configuration Manager\inboxes\despoolr.box\receive\ds_fl24a.pkg to C:\Program Files\Microsoft Configuration Manager\inboxes\rcm.box\DBAF3A0C-9FE0-4A93-B771-E2DD3784E755\ SMS_DESPOOLER 20-10-2012 02:03:38 3376 (0x0D30)

Despooler successfully executed one instruction. SMS_DESPOOLER 20-10-2012 02:03:38 3376 (0x0D30)

 

Once it is decompressed the RCM will start processing . It will compare and see the tracking GUID and if publication matches and then will delete the old data BCP in (Bulk copy)the values after verifying with the rowcount files .

RCMctrl.log

===========

Processing replication group Hardware_Inventory_8. SMS_REPLICATION_CONFIGURATION_MONITOR 20-10-2012 02:03:41 1820 (0x071C)

Current status is PackageCreated. SMS_REPLICATION_CONFIGURATION_MONITOR 20-10-2012 02:03:41 1820 (0x071C)

Checking if initialization request is needed for replication group Hardware_Inventory_8 from site PR1. SMS_REPLICATION_CONFIGURATION_MONITOR 20-10-2012 02:03:41 1820 (0x071C)

Checking if there are bcp file to apply for replication group Hardware_Inventory_8 from site PR1. SMS_REPLICATION_CONFIGURATION_MONITOR 20-10-2012 02:03:41 1820 (0x071C)

found a tracking guid, searching through .init files. SMS_REPLICATION_CONFIGURATION_MONITOR 20-10-2012 02:03:41 1820 (0x071C)

Checking bcpDirectory C:\Program Files\Microsoft Configuration Manager\inboxes\rcm.box\DBAF3A0C-9FE0-4A93-B771-E2DD3784E755 SMS_REPLICATION_CONFIGURATION_MONITOR 20-10-2012 02:03:41 1820 (0x071C)

Found files for publication Hardware_Inventory_8-PR1. SMS_REPLICATION_CONFIGURATION_MONITOR 20-10-2012 02:03:41 1820 (0x071C)

Publication names match. Checking vesrion. SMS_REPLICATION_CONFIGURATION_MONITOR 20-10-2012 02:03:41 1820 (0x071C)

Found our tracking guid SMS_REPLICATION_CONFIGURATION_MONITOR 20-10-2012 02:03:41 1820 (0x071C)

Setting deadlock priority level to high. SMS_REPLICATION_CONFIGURATION_MONITOR 20-10-2012 02:03:41 1820 (0x071C)

Initializing to version number 781708. SMS_REPLICATION_CONFIGURATION_MONITOR 20-10-2012 02:03:41 1820 (0x071C)

Publication Hardware_Inventory_8 has ID 30. SMS_REPLICATION_CONFIGURATION_MONITOR 20-10-2012 02:03:41 1820 (0x071C)

Flushing DRS queue messages coming from PR1 for replication group Hardware_Inventory_8. SMS_REPLICATION_CONFIGURATION_MONITOR 20-10-2012 02:03:41 1820 (0x071C)

Executing pre-snapshot stored procedures for group Hardware_Inventory_8. SMS_REPLICATION_CONFIGURATION_MONITOR 20-10-2012 02:03:42 1820 (0x071C)

Pre-snapshot stored procedures for group Hardware_Inventory_8 finished. Applying bcp files. SMS_REPLICATION_CONFIGURATION_MONITOR 20-10-2012 02:03:42 1820 (0x071C)

Removing old data for site table ... [EXEC spSMSTruncatePartitionTable 'AUTOSTART_SOFTWARE_DATA', 1;] SMS_REPLICATION_CONFIGURATION_MONITOR 20-10-2012 02:03:42 1820 (0x071C)

Rowcount from file [C:\Program Files\Microsoft Configuration Manager\inboxes\rcm.box\DBAF3A0C-9FE0-4A93-B771-E2DD3784E755\AUTOSTART_SOFTWARE_DATA.bcp.rowcount] is [6]. SMS_REPLICATION_CONFIGURATION_MONITOR 20-10-2012 02:03:42 1820 (0x071C)

Successfully bulk copied file [C:\Program Files\Microsoft Configuration Manager\inboxes\rcm.box\DBAF3A0C-9FE0-4A93-B771-E2DD3784E755\AUTOSTART_SOFTWARE_DATA.bcp] into table [AUTOSTART_SOFTWARE_DATA] with rows [6]. SMS_REPLICATION_CONFIGURATION_MONITOR 20-10-2012 02:03:43 1820 (0x071C)

Removing old data for site table ... [EXEC spSMSTruncatePartitionTable 'AUTOSTART_SOFTWARE_HIST', 1;] SMS_REPLICATION_CONFIGURATION_MONITOR 20-10-2012 02:03:43 1820 (0x071C)

Rowcount from file [C:\Program Files\Microsoft Configuration Manager\inboxes\rcm.box\DBAF3A0C-9FE0-4A93-B771-E2DD3784E755\AUTOSTART_SOFTWARE_HIST.bcp.rowcount] is [0]. SMS_REPLICATION_CONFIGURATION_MONITOR 20-10-2012 02:03:43 1820 (0x071C)

‘’’’’’’’’’’’’’’’’’’’’’’

‘’’’’’’’’’’’’’’’’’’’’’’

Setting deadlock priority level to normal. SMS_REPLICATION_CONFIGURATION_MONITOR 20-10-2012 02:03:45 1820 (0x071C)

Current status is Active. SMS_REPLICATION_CONFIGURATION_MONITOR 20-10-2012 02:03:45 1820 (0x071C)

--------------

 

In the database logs also you will find this

LogLine

LogTime

ComponentName

MachineName

ProcedureName

LogText

429511

02:31.4

Microsoft SQL Server

 Service Broker Activation

spRCMActivation

INFO: Received DRS_InitRequestReceived

 for replication group: Hardware_Inventory_8

429512

02:32.8

SMS_REPLICATION_

CONFIGURATION_MONITOR

CMLABCAS

SMS_REPLICATION_

CONFIGURATION_MONITOR

INFO: Creating initialization request for

10 articles in replication group

Hardware_Inventory_8

from site PR1. -- 10/20/2012 02:02:27

429513

02:32.8

SMS_REPLICATION_

CONFIGURATION_MONITOR

CMLABCAS

SMS_REPLICATION_

CONFIGURATION_MONITOR

Built the init request XML for replication group

Hardware_Inventory_8 for site PR1. 

-- 10/20/2012 02:02:31

429514

03:08.3

Microsoft SQL Server

Service Broker Activation

spRCMActivation

INFO: Received DRS_InitPackageCreated

for replication group: Hardware_Inventory_8

429516

03:45.0

SMS_REPLICATION_

CONFIGURATION_MONITOR

CMLABCAS

SMS_REPLICATION_

CONFIGURATION_MONITOR

Applying the BCP for replication group

Hardware_Inventory_8 from site PR1.

Tracking guid d74dc244-a526-4387-86b0-efacf67df680. 

-- 10/20/2012 02:03:41

429517

03:45.0

SMS_REPLICATION_

CONFIGURATION_MONITOR

CMLABCAS

SMS_REPLICATION_

CONFIGURATION_MONITOR

BCP version number for replication group

 Hardware_Inventory_8 from site PR1 is 781708. 

-- 10/20/2012 02:03:41

429518

03:45.0

SMS_REPLICATION_

CONFIGURATION_MONITOR

CMLABCAS

SMS_REPLICATION_

CONFIGURATION_MONITOR

Flushing DRS queue messages coming from

site PR1 for replication group

 Hardware_Inventory_8.-- 10/20/2012 02:03:41

429519

03:45.1

SMS_REPLICATION_

CONFIGURATION_MONITOR

CMLABCAS

SMS_REPLICATION_

CONFIGURATION_MONITOR

Executing pre-snapshot stored procedures for

 replication group Hardware_Inventory_8. 

-- 10/20/2012 02:03:42

429520

03:45.1

SMS_REPLICATION_

CONFIGURATION_MONITOR

CMLABCAS

SMS_REPLICATION_

CONFIGURATION_MONITOR

Pre-snapshot stored procedures for replication group

 Hardware_Inventory_8 finished. Applying bcp files. 

-- 10/20/2012 02:03:42

429521

03:45.1

SMS_REPLICATION_

CONFIGURATION_MONITOR

CMLABCAS

SMS_REPLICATION_

CONFIGURATION_MONITOR

Disable foreign keys for replication group

 Hardware_Inventory_8. 

 -- 10/20/2012 02:03:42

429522

03:45.1

SMS_REPLICATION_C

ONFIGURATION_MONITOR

CMLABCAS

SMS_REPLICATION_

CONFIGURATION_MONITOR

Removing old data for site table ..

. [EXEC spSMSTruncatePartitionTable

'AUTOSTART_SOFTWARE_DATA', 1;] 

-- 10/20/2012 02:03:42

429523

03:45.1

SMS_REPLICATION_

CONFIGURATION_MONITOR

CMLABCAS

SMS_REPLICATION_

CONFIGURATION_MONITOR

Removing old data for site table ...

[EXEC spSMSTruncatePartitionTable

 'AUTOSTART_SOFTWARE_HIST', 1;] 

-- 10/20/2012 02:03:43

429524

03:45.1

SMS_REPLICATION_

CONFIGURATION_MONITOR

CMLABCAS

SMS_REPLICATION_

CONFIGURATION_MONITOR

Removing old data for site table ...

 [EXEC spSMSTruncatePartitionTable

'BROWSER_HELPER_OBJECT_DATA', 1;] 

-- 10/20/2012 02:03:43

429525

03:45.1

SMS_REPLICATION_

CONFIGURATION_MONITOR

CMLABCAS

SMS_REPLICATION_

CONFIGURATION_MONITOR

Removing old data for site table ...

 [EXEC spSMSTruncatePartitionTable

'BROWSER_HELPER_OBJECT_HIST', 1;] 

 -- 10/20/2012 02:03:43

429526

03:45.2

SMS_REPLICATION_

CONFIGURATION_MONITOR

CMLABCAS

SMS_REPLICATION_

CONFIGURATION_MONITOR

Removing old data for site table ...

[EXEC spSMSTruncatePartitionTable

'SW_LICENSING_PRODUCT_DATA', 1;] 

-- 10/20/2012 02:03:43

429527

03:45.2

SMS_REPLICATION_

CONFIGURATION_MONITOR

CMLABCAS

SMS_REPLICATION_

CONFIGURATION_MONITOR

Removing old data for site table ...

[EXEC spSMSTruncatePartitionTable '

SW_LICENSING_PRODUCT_HIST', 1;] 

 -- 10/20/2012 02:03:43

429528

03:45.2

SMS_REPLICATION_

CONFIGURATION_MONITOR

CMLABCAS

SMS_REPLICATION_

CONFIGURATION_MONITOR

Removing old data for site table ...

[EXEC spSMSTruncatePartitionTable

 'SW_LICENSING_SERVICE_DATA', 1;] 

-- 10/20/2012 02:03:43

429529

03:45.2

SMS_REPLICATION_

CONFIGURATION_MONITOR

CMLABCAS

SMS_REPLICATION_C

ONFIGURATION_MONITOR

Removing old data for site table .

.. [EXEC spSMSTruncatePartitionTable

 'SW_LICENSING_SERVICE_HIST', 1;] 

-- 10/20/2012 02:03:44

429530

03:45.2

SMS_REPLICATION_

CONFIGURATION_MONITOR

CMLABCAS

SMS_REPLICATION_

CONFIGURATION_MONITOR

Removing old data for site table ..

. [EXEC spSMSTruncatePartitionTable

'USB_DEVICE_DATA', 1;] 

-- 10/20/2012 02:03:44

429531

03:45.2

SMS_REPLICATION_

CONFIGURATION_MONITOR

CMLABCAS

SMS_REPLICATION_

CONFIGURATION_MONITOR

Removing old data for site table ...

 [EXEC spSMSTruncatePartitionTable

'USB_DEVICE_HIST', 1;]

  -- 10/20/2012 02:03:44

429532

03:45.2

SMS_REPLICATION_

CONFIGURATION_MONITOR

CMLABCAS

SMS_REPLICATION_

CONFIGURATION_MONITOR

Applied the BCP files for replication group

Hardware_Inventory_8 from

site PR1. -- 10/20/2012 02:03:44

429533

03:45.2

SMS_REPLICATION_

CONFIGURATION_MONITOR

CMLABCAS

SMS_REPLICATION_

CONFIGURATION_MONITOR

Enable foreign keys for replication group

Hardware_Inventory_8.

  -- 10/20/2012 02:03:44

429534

03:45.3

SMS_REPLICATION_

CONFIGURATION_MONITOR

CMLABCAS

SMS_REPLICATION_

CONFIGURATION_MONITOR

Restore table's identity value for replication group

 Hardware_Inventory_8.

  -- 10/20/2012 02:03:44

429535

03:45.3

SMS_REPLICATION_

CONFIGURATION_MONITOR

CMLABCAS

SMS_REPLICATION_

CONFIGURATION_MONITOR

Executing post-snapshot stored procedures for replication

 group Hardware_Inventory_8. 

-- 10/20/2012 02:03:44

429536

03:45.3

SMS_REPLICATION_

CONFIGURATION_MONITOR

CMLABCAS

SMS_REPLICATION_

CONFIGURATION_MONITOR

Post-snapshot stored procedures for replication group

Hardware_Inventory_8 finished. 

 -- 10/20/2012 02:03:44

429537

03:45.3

SMS_REPLICATION_

CONFIGURATION_MONITOR

CMLABCAS

SMS_REPLICATION_

CONFIGURATION_MONITOR

Finished applying the BCP for replication group

Hardware_Inventory_8 from site PR1. 

 -- 10/20/2012 02:03:45

 

Once the same is completed then on the primary server you will find the replication is finished.

LogLine

LogTime

ComponentName

MachineName

ProcedureName

LogText

7.20576E+16

03:44.8

Microsoft SQL Server

Service Broker Activation

spRCMActivation

INFO: Received DRS_InitFinished from

 Site CAS for replication group:

Hardware_Inventory_8 with Version 135769

 

Once the same happens you will see the link moving from initialization to active in the monitoring phase.

 

Sudheesh Narayanaswamy

Support Escalation Engineer

 Microsoft System Center Support