Strictly speaking CIFS pre-population is not a latency optimization feature but a data store warming feature. The feature overcomes the initial cold data transfer of new files read from a remote CIFS share by going through the remote CIFS share during the night and performing the initial cold transfer. As a result the next morning the data store is warm for the contents of the new files from the remote CIFS share and the users immediately experience the full optimization.
The configuration of the CIFS pre-population requires name of the remote CIFS share, the username and the password to access the remote CIFS share. All files and directories on that remote CIFS share should be readable by that user.
The optimization service on the client-side Steelhead appliance needs to see the naked SYN of the CIFS session. The TCP SYN packet will leave the primary interface and should go arrive on the LAN interface where it will be processed as a normal TCP session to be optimized and go through the in-path rules.
When modifying the CIFS pre-population share from the CLI, the share
needs to be entered like a Windows path with backslashes. Because
the backslash has a different meaning on the CLI, it is required
to escape the backslashes. This is the way to escape the name for
the share
\\192.168.1.1\admin\prepop
is
\\\\192.168.1.1\\admin\\prepop
.
The CIFS pre-population process consists of three steps: The registration of the CIFS share, the initial syncing and the periodical syncing.
During the registration the CIFS pre-population process will connect to the remote server, login and map the share.
Figure 8.11. Successful registration of the CIFS pre-population session
CSH rcud[5555]: [rcud/req/.NOTICE] - {- -} Received action: /rbt/rcu/action/share_config CSH rcud[5555]: [rcud/main/.INFO] - {- -} Adding share: Share : \\192.168.1.1\admin\prepo \ p Server name : 192.168.1.1 Server path : \\192.168.1.1\admin\prepop Server port : 0 S \ hare Mode : 3 Sync freq : 604800 CSH rcud[5555]: [rcud/main/.INFO] - {- -} Share parameters verified locally. Reply to mgmt \ d CSH rcud[5555]: [rcud/main/.INFO] - {- -} succ=0, msg=Share registration in progress ... CSH rcud[5555]: [policy_manager.INFO] - {- -} @ [126]: Saved policies CSH rcud[5555]: [rcud/main/.INFO] - {- -} For Share : \\192.168.1.1\admin\prepop CSH mgmtd[3544]: [mgmtd.NOTICE]: Share registration in progress ... CSH webasd[6087]: [web.INFO]: web: Received return code 0, return message 'Share registrat \ ion in progress ...\n' from gclSession pygs_handle_any_response CSH rcud[5555]: [rcud/share/.INFO] - {- -} Share \\192.168.1.1\admin\prepop Enter dispatch \ _cmd(): cmd=REGISTER_SHARE CSH rcud[5555]: [rcud/share/.NOTICE] - {- -} dispatch_cmd() START CMD : REGISTER_SHARE Sha \ re : \\192.168.1.1\admin\prepop CSH sport[2946]: [splice/client.INFO] 14 {10.0.1.5:47055 192.168.1.1:139} init client 10.0 \ .1.5:47055 server 192.168.1.1:139 cfe 10.0.1.6:7801 sfe 192.168.1.6:7800 client connec \ ted: yes CSH sport[2946]: [splice/client.INFO] 14 {10.0.1.5:47055 192.168.1.1:139} Start flowing, l \ port 40281, rport 7800, OPOL_NORMAL, NAGLE_NEVER, PREOPT_NONE, LATOPT_AUTO, TRANSPORT_ \ ID_NONE, TPTOPT_NONE(0x0), TRPY_NONE CSH rcud[5555]: [cifsclient.INFO] - {- -} @ [320]: Connected to server 192.168.1.1 CSH webasd[6087]: [web.INFO]: web: User admin viewing setupPrepop page. CSH sport[2946]: [cifs_neg.INFO] 14 {- -} Dialect[0] = PC NETWORK PROGRAM 1.0 CSH sport[2946]: [cifs_neg.INFO] 14 {- -} Dialect[1] = MICROSOFT NETWORKS 1.03 CSH sport[2946]: [cifs_neg.INFO] 14 {- -} Dialect[2] = MICROSOFT NETWORKS 3.0 CSH sport[2946]: [cifs_neg.INFO] 14 {- -} Dialect[3] = LANMAN1.0 CSH sport[2946]: [cifs_neg.INFO] 14 {- -} Dialect[4] = LM1.2X002 CSH sport[2946]: [cifs_neg.INFO] 14 {- -} Dialect[5] = DOS LANMAN2.1 CSH sport[2946]: [cifs_neg.INFO] 14 {- -} Dialect[6] = NT LANMAN 1.0 CSH sport[2946]: [cifs_neg.INFO] 14 {- -} Dialect[7] = NT LM 0.12 CSH sport[2946]: [cifs_neg.INFO] 14 {- -} Dialect[8] = Samba CSH sport[2946]: [cifs_neg.INFO] 14 {- -} Dialect[9] = RCU SMB 1 CSH sport[2946]: [cifs_neg.INFO] 14 {- -} rcu dialect index = 9 CSH sport[2946]: [cifs_neg.INFO] 14 {- -} Dialect in response before: 6 CSH sport[2946]: [cifs_neg.INFO] 14 {- -} Dialect in response after: 9 CSH sport[2946]: [smbmux_cfe/scons.INFO] 14 {10.0.1.5:47055 192.168.1.1:139} Creating pars \ er type: SMB_PARSER CSH sport[2946]: [smbmux_cfe.INFO] 14 {10.0.1.5:47055 192.168.1.1:139} Creating client-sid \ e SMB parser CSH sport[2946]: [smbcfe.INFO] 14 {- -} RTT time: sec:0, usec:305000 CSH sport[2946]: [smbcfe.INFO] 14 {- -} MAX metadata cache time: 2.000000 sec, data cache \ time 20.000000 sec CSH sport[2946]: [smbcfe.INFO] 14 {- -} Idle FOI timeouts : 15250 No oplock timeout : 7625 \ CSH sport[2946]: [smbcfe.INFO] 14 {10.0.1.5:47055 192.168.1.1:139} Client Native OS Versio \ n: bytes: 52 69 4f 53 RiOS CSH sport[2946]: [smbcfe.INFO] 14 {10.0.1.5:47055 192.168.1.1:139} Client Native LAN Manag \ er: bytes 52 42 54 2d 43 69 66 73 43 6c 69 65 6e 74 RBT-Cifs Client CSH rcud[5555]: [rcud/share/.INFO] - {- -} Status string : Registration in progress... CSH sport[2946]: [smbcfe.INFO] 14 {10.0.1.5:47055 192.168.1.1:139} Client Native OS Versio \ n: bytes: 52 69 4f 53 RiOS CSH sport[2946]: [smbcfe.INFO] 14 {10.0.1.5:47055 192.168.1.1:139} Client Native LAN Manag \ er: bytes 52 42 54 2d 43 69 66 73 43 6c 69 65 6e 74 RBT-Cifs Client CSH sport[2946]: [smbcfe.INFO] 14 {10.0.1.5:47055 192.168.1.1:139} Server Native OS Versio \ n: unix: Unix CSH sport[2946]: [smbcfe.INFO] 14 {10.0.1.5:47055 192.168.1.1:139} Server Native LAN Manag \ er: Samba: Samba CSH sport[2946]: [smbsign_cfe.INFO] 14 {10.0.1.5:47055 192.168.1.1:139} Shutting down sign \ ing blade for this connection. Reason - Signing feature disabled on SFE. CSH rcud[5555]: [rcud/share/.INFO] - {- -} Status string : Registration in progress... CSH sport[2946]: [smbcfe/ccons.INFO] 14 {10.0.1.5:47055 192.168.1.1:139} SMBConsumer::eof( \ ) this=0x52d2b30, qlen=0 CSH rcud[5555]: [rcud/share/.NOTICE] - {- -} Completed successfully CMD : REGISTER_SHARE \ Share : \\192.168.1.1\admin\prepop CSH sport[2946]: [smbcfe/scons.INFO] 14 {10.0.1.5:47055 192.168.1.1:139} SMBConsumer::eof( \ ) this=0x52d2c08, qlen=0 CSH sport[2946]: [splice/client.INFO] 14 {10.0.1.5:47055 192.168.1.1:139} fini client 10.0 \ .1.5:47055 server 192.168.1.1:139 cfe 10.0.1.6:40281 sfe 192.168.1.6:7800 app CIFS CSH rcud[5555]: [rcud/share/.INFO] - {- -} Status string : Share Registered
It shows up as a normal CIFS session on TCP port 139 or 445 and it
should complete with a successful completion:
Completed successfully CMD : REGISTER_SHARE Share : \\192.168.1.1\admin\prepop
.
The host portion of the remote share can be entered by IP addresses or by hostname, for example \\192.168.1.1\admin or \\share.example.com\admin.
If the hostname cannot be resolved, the logs show the error
Host not found (authoritative)
:
Figure 8.12. Registration failed due to an unknown hostname
CSH mgmtd[3544]: [mgmtd.NOTICE]: Share registration in progress ... CSH webasd[6087]: [web.INFO]: web: Received return code 0, return message 'Share registrat \ ion in progress ...\n' from gclSession pygs_handle_any_response CSH rcud[5555]: [rcud/share/.INFO] - {- -} Share \\foo.example.com\test Enter dispatch_cmd \ (): cmd=REGISTER_SHARE CSH rcud[5555]: [rcud/share/.NOTICE] - {- -} dispatch_cmd() START CMD : REGISTER_SHARE Sha \ re : \\foo.example.com\test CSH webasd[6087]: [web.INFO]: web: User admin viewing setupPrepop page. CSH rcud[5555]: [cifsclient.NOTICE] - {- -} @ [233]: Host not found (authoritative) CSH rcud[5555]: [rcud/client/.NOTICE] - {- -} kerberos authentication on port 139 Failed, \ trying NTLMSSP... CSH rcud[5555]: [cifsclient.NOTICE] - {- -} @ [233]: Host not found (authoritative) CSH rcud[5555]: [rcud/client/.NOTICE] - {- -} Logon to port: 139 Failed: CSH rcud[5555]: [rcud/client/.NOTICE] - {- -} Retrying alternate CIFS port... CSH rcud[5555]: [rcud/share/.INFO] - {- -} Status string : Registration in progress... CSH rcud[5555]: [cifsclient.NOTICE] - {- -} @ [233]: Host not found (authoritative) CSH rcud[5555]: [rcud/client/.NOTICE] - {- -} kerberos authentication on port 445 Failed, \ trying NTLMSSP... CSH rcud[5555]: [rcud/share/.INFO] - {- -} Status string : Registration in progress... CSH rcud[5555]: [cifsclient.NOTICE] - {- -} @ [233]: Host not found (authoritative) CSH rcud[5555]: [rcud/client/.NOTICE] - {- -} Network error. Success, error no : 0 => erro \ r_info.h:235 CSH rcud[5555]: [rcud/client/.WARN] - {- -} run_rbcp_cmd_v3 : Connecting to server failed. \ Server : foo.example.com Share : \\foo.example.com\test CSH rcud[5555]: [rcud/share/.NOTICE] - {- -} record_start_to_status_file(): Received unkno \ wn command: 0 CSH rcud[5555]: [rcud/share/.NOTICE] - {- -} got unknown cmd:0 CSH rcud[5555]: [rcud/share/.NOTICE] - {- -} Completed with Error CMD : REGISTER_SHARE S \ hare : \\foo.example.com\test CSH rcud[5555]: [rcud/share/.INFO] - {- -} Status string : Share has error
If the host doesn't exist or doesn't respond, the logs show the error:
Network error. Connection reset by peer, error no : 104
:
Figure 8.13. Registration failed due to an non-responding remote server
CSH rcud[5555]: [rcud/share/.INFO] - {- -} Status string : Registration in progress... CSH last message repeated 2 times CSH sport[2946]: [segstore/peertable.INFO] - {- -} Attempting to write stat table to offse \ t 1. Num pages: 9 CSH sport[2946]: [segstore/peertable.INFO] - {- -} Write stat table complete, error 0 CSH kernel: [intercept.WARN] Detected SYN retransmits for a PFSv3 connection. Potential r \ easons include the remote host or network being down, probe filtering, and asymmetric \ routing. CSH rcud[5555]: [rcud/share/.INFO] - {- -} Status string : Registration in progress... CSH kernel: [intercept.WARN] Detected SYN retransmits for a PFSv3 connection. Potential r \ easons include the remote host or network being down, probe filtering, and asymmetric \ routing. CSH rcud[5555]: [rcud/share/.INFO] - {- -} Status string : Registration in progress... CSH last message repeated 3 times CSH rcud[5555]: [cifsclient.INFO] - {- -} @ [320]: Connected to server 192.168.1.2 CSH rcud[5555]: [cifsclient.NOTICE] - {- -} @ [53]: Send failed CSH rcud[5555]: [rcud/client/.NOTICE] - {- -} Logon to port: 139 Failed: CSH rcud[5555]: [rcud/client/.NOTICE] - {- -} Retrying alternate CIFS port... CSH rcud[5555]: [rcud/share/.INFO] - {- -} Status string : Registration in progress... CSH kernel: [intercept.WARN] Detected SYN retransmits for a PFSv3 connection. Potential r \ easons include the remote host or network being down, probe filtering, and asymmetric \ routing. CSH rcud[5555]: [rcud/share/.INFO] - {- -} Status string : Registration in progress... CSH kernel: [intercept.WARN] Detected SYN retransmits for a PFSv3 connection. Potential r \ easons include the remote host or network being down, probe filtering, and asymmetric \ routing. CSH rcud[5555]: [rcud/share/.INFO] - {- -} Status string : Registration in progress... CSH last message repeated 4 times CSH rcud[5555]: [cifsclient.INFO] - {- -} @ [320]: Connected to server 192.168.1.2 CSH rcud[5555]: [cifsclient.NOTICE] - {- -} @ [53]: Send failed CSH rcud[5555]: [rcud/client/.NOTICE] - {- -} Network error. Connection reset by peer, err \ or no : 104 CSH rcud[5555]: [rcud/client/.WARN] - {- -} run_rbcp_cmd_v3 : Connecting to server failed. \ Server : 192.168.1.2 Share : \\192.168.1.2\admin\prepop CSH rcud[5555]: [rcud/share/.NOTICE] - {- -} record_start_to_status_file(): Received unkno \ wn command: 0 CSH rcud[5555]: [rcud/share/.NOTICE] - {- -} got unknown cmd:0 CSH rcud[5555]: [rcud/share/.NOTICE] - {- -} Completed with Error CMD : REGISTER_SHARE S \ hare : \\192.168.1.2\admin\prepop CSH rcud[5555]: [rcud/share/.INFO] - {- -} Status string : Share has error
If the username or password provided is incorrect, the logs will show
Session setup failed. Status code : NT_STATUS_LOGON_FAILURE
:
Figure 8.14. Registration failed due to a login failure
CSH rcud[5555]: [rcud/client/.NOTICE] - {- -} Session setup failed. Status code : NT_STATU \ S_LOGON_FAILURE => ntlm_session_impl.cc:131 CSH rcud[5555]: [rcud/client/.WARN] - {- -} run_rbcp_cmd_v3 : Connecting to server failed. \ Server : 192.168.1.1 Share : \\192.168.1.1\prepop CSH rcud[5555]: [rcud/share/.NOTICE] - {- -} Completed with Error CMD : REGISTER_SHARE S \ hare : \\192.168.1.1\prepop CSH rcud[5555]: [rcud/share/.INFO] - {- -} Status string : Share has error
If the path on the remote server does not exist, the logs will show
Failed to map share, because network path is unavailable
:
Figure 8.15. Registration failed due to a login failure
CSH rcud[5555]: [rcud/share/.INFO] - {- -} Status string : Registration in progress... CSH rcud[5555]: [rcud/client/.NOTICE] - {- -} Could not connect to share \\192.168.1.1\pre \ pop. Tree connect failed. Status code : Failed to map share, because network path is u \ navailable => tree_connect_impl.cc:90 CSH rcud[5555]: [rcud/client/.WARN] - {- -} run_rbcp_cmd_v3 : Connecting to server failed. \ Server : 192.168.1.1 Share : \\192.168.1.1\prepop CSH rcud[5555]: [rcud/share/.NOTICE] - {- -} record_start_to_status_file(): Received unkno \ wn command: 0 CSH rcud[5555]: [rcud/share/.NOTICE] - {- -} got unknown cmd:0 CSH rcud[5555]: [rcud/share/.NOTICE] - {- -} Completed with Error CMD : REGISTER_SHARE S \ hare : \\192.168.1.1\prepop CSH rcud[5555]: [rcud/share/.INFO] - {- -} Status string : Share has error
When the registration has completed successfully, the syncing needs
to be enabled. From the CLI this can be done with the command
prepop share modify remote-path <share> syncing true
.
In this example, the remote share has two files in it: \foo.doc and \bar\bar.pdf.
Figure 8.16. A successful sync
CSH rcud[5555]: [crawler.INFO] - {- -} Get initial copy started at Fri 2014-Jan-03 21:29:0 \ 1 CSH rcud[5555]: [cifsfs.INFO] - {- -} @ [199]: Base cifs sync directory = '\prepop' CSH sport[2946]: [smbcfe/file.INFO] 17 {10.0.1.5:47717 192.168.1.1:139} process_trans2_fin \ dfirst_response() has search attr : 23 CSH sport[2946]: [smbcfe/file.INFO] 17 {10.0.1.5:47717 192.168.1.1:139} process_trans2_fin \ dfirst_response() has search attr : 23 CSH rcud[5555]: [sync_file.INFO] - {- -} @ [207]: Syncing file \foo.doc CSH last message repeated 4 times CSH rcud[5555]: [rcud/share/.INFO] - {- -} Status string : Get initial copy in progress s \ ince Fri Jan 3 21:28:59 2014 CSH rcud[5555]: [sync_file.INFO] - {- -} @ [207]: Syncing file \foo.doc CSH rcud[5555]: [sync_file.INFO] - {- -} @ [207]: Syncing file \bar\bar.pdf CSH last message repeated 4 times CSH rcud[5555]: [rcud/req/.NOTICE] - {- -} Received action: /rbt/rcu/action/share_config CSH rcud[5555]: [rcud/share/.NOTICE] - {- -} Syncing changed for Share : \\192.168.1.1\ad \ min\prepop Old syncing : 1 New syncing: 0 CSH rcud[5555]: [rcud/main/.INFO] - {- -} succ=0, msg=Share modify succeeded CSH mgmtd[3544]: [mgmtd.NOTICE]: Share modify succeeded CSH rcud[5555]: [sync_file.INFO] - {- -} @ [207]: Syncing file \bar\bar.pdf CSH rcud[5555]: [rcud/share/.INFO] - {- -} Status string : Get initial copy in progress s \ ince Fri Jan 3 21:28:59 2014 CSH rcud[5555]: [rcud/share/.INFO] - {- -} Status string : Get initial copy in progress s \ ince Fri Jan 3 21:28:59 2014 CSH rcud[5555]: [sync_file.INFO] - {- -} @ [207]: Syncing file \bar\bar.pdf CSH rcud[5555]: [crawler/sync_lists.INFO] - {- -} @ [194]: Synced file : \foo.doc CSH rcud[5555]: [crawler/sync_lists.INFO] - {- -} @ [194]: Synced file : \bar\bar.pdf CSH sport[2946]: [smbcfe/file.NOTICE] 17 {10.0.1.5:47717 192.168.1.1:139} File::add_trans \ 2_findnext_data() last entries dont match : \ CSH rcud[5555]: [crawler.INFO] - {- -} Get initial copy completed successfully at Fri 2014 \ -Jan-03 21:29:14 CSH rcud[5555]: [crawler.INFO] - {- -} Received 2 files, 0 objects have error. (34125972 b \ ytes were received in 13.7194 seconds at 19.8993 Mbps) CSH sport[2946]: [smbcfe/ccons.INFO] 17 {10.0.1.5:47717 192.168.1.1:139} SMBConsumer::eof( \ ) this=0x52f0130, qlen=0 CSH rcud[5555]: [rcud/share/.NOTICE] - {- -} Completed successfully CMD : GET_INITIAL_COP \ Y Share : \\192.168.1.1\admin\prepop CSH sport[2946]: [smbcfe/scons.INFO] 17 {10.0.1.5:47717 192.168.1.1:139} SMBConsumer::eof( \ ) this=0x52f0208, qlen=0 CSH sport[2946]: [splice/client.INFO] 17 {10.0.1.5:47717 192.168.1.1:139} fini client 10.0 \ .1.5:47717 server 192.168.1.1:139 cfe 10.0.1.6:40284 sfe 192.168.1.6:7800 app CIFS CSH rcud[5555]: [rcud/share/.INFO] - {- -} Status string : Share idle
The Initial Copy log file shows it as:
Figure 8.17. Log file of the Initial Copy
Get initial copy started at Fri 2014-Jan-03 21:29:01 Synced file : \foo.doc Synced file : \bar\bar.pdf Get initial copy completed successfully at Fri 2014-Jan-03 21:29:14 Received 2 files, 0 objects have error. (34125972 bytes were received in 13.7194 seconds a \ t 19.8993 Mbps)
In previous RiOS versions, if the client-side Steelhead appliance did not see the CIFS pre-population session, the CIFS pre-population process would warn about this and abort.
With the new implementation this doesn't happen anymore. The best
way to check is to initiate a manual sync and confirm that the TCP
session is optimized. This can be done with the command
prepop share manual-sync remote-path <path>
Figure 8.18. Manually starting a CIFS pre-population sync
CSH (config) # prepop share manual-sync remote-path \\\\192.168.1.1\\admin\\prepop Share manual sync in progress...
This can be caused by:
The cable of the primary interface is attached to the WAN router instead of to the LAN switch. If this is on design, consider connecting the auxiliary interface to the LAN switch and a routing statement to force traffic to the CIFS servers to go via the gateway on the auxiliary interface.
In case of a parallel cluster, the traffic from the LAN switch does not go via this Steelhead appliance. The way around this could be to configure the data store synchronization and to enable the CIFS pre-population on the Steelhead appliance through which the naked SYN normally goes.
In-path rules on the Steelhead appliance prevent optimization from this traffic. The way around this would be to allow optimization from the Steelhead appliance primary interface to the CIFS servers.
When the CIFS pre-population process cannot read a certain file or directory, it will mark it as failed.
In this example, the file bar\bar.pdf is not readable by the specified user.
Figure 8.19. Unable to read some of the files
CSH rcud[5555]: [crawler.INFO] - {- -} Get initial copy started at Fri 2014-Jan-03 21:23:5 \ 7 CSH rcud[5555]: [cifsfs.INFO] - {- -} @ [199]: Base cifs sync directory = '\prepop' CSH sport[2946]: [smbcfe/file.INFO] 16 {10.0.1.5:47574 192.168.1.1:139} process_trans2_fin \ dfirst_response() has search attr : 23 CSH sport[2946]: [smbcfe/file.INFO] 16 {10.0.1.5:47574 192.168.1.1:139} process_trans2_fin \ dfirst_response() has search attr : 23 CSH rcud[5555]: [sync_obj.ERR] - {- -} @ [59]: Nt Create AndX failed. Status code : NT_ST \ ATUS_ACCESS_DENIED => nt_create_andx_impl.cc:94. For \bar\bar.pdf CSH rcud[5555]: [sync_file.INFO] - {- -} @ [207]: Syncing file \foo.doc CSH rcud[5555]: [rcud/share/.INFO] - {- -} Status string : Get initial copy in progress s \ ince Fri Jan 3 21:23:55 2014 CSH rcud[5555]: [sync_file.INFO] - {- -} @ [207]: Syncing file \foo.doc CSH rcud[5555]: [rcud/share/.INFO] - {- -} Status string : Get initial copy in progress s \ ince Fri Jan 3 21:23:55 2014 CSH rcud[5555]: [sync_file.INFO] - {- -} @ [207]: Syncing file \foo.doc CSH rcud[5555]: [sync_file.INFO] - {- -} @ [207]: Syncing file \foo.doc CSH rcud[5555]: [sync_file.INFO] - {- -} @ [207]: Syncing file \bar\bar.pdf CSH rcud[5555]: [crawler/sync_lists.INFO] - {- -} @ [194]: Synced file : \foo.doc CSH rcud[5555]: [crawler/sync_lists.INFO] - {- -} @ [194]: Synced file : \bar\bar.pdf CSH rcud[5555]: [rcud/client/.ERR] - {- -} Sync error. CSH rcud[5555]: [rcud/client/.ERR] - {- -} Failed to sync share \\192.168.1.1\admin. CSH rcud[5555]: [crawler.INFO] - {- -} Get initial copy completed with error. CSH rcud[5555]: [crawler.INFO] - {- -} Received 1 files, 1 objects have error. (17062986 b \ ytes were received in 11.5794 seconds at 11.7885 Mbps) CSH sport[2946]: [smbcfe.INFO] 16 {10.0.1.5:47574 192.168.1.1:139} clearing pending req: \ uid: 0x64 tid: 0x1 pid: 0x15b3 mid: 0x11f omid: 0x11f smid: 0x11f cmd: close subcmd: 0 \ infolvl: 0 fid: 0x1cb5 status: 1 len 45 time: 1388744649.518695 sec CSH sport[2946]: [smbcfe/ccons.INFO] 16 {10.0.1.5:47574 192.168.1.1:139} SMBConsumer::eof( \ ) this=0x52f1530, qlen=0 CSH rcud[5555]: [rcud/share/.NOTICE] - {- -} Completed with Error CMD : GET_INITIAL_COPY \ Share : \\192.168.1.1\admin\prepop
The Initial Copy log shows:
Figure 8.20. Initial copy failed due to reading errors
Get initial copy started at Fri 2014-Jan-03 21:23:57 Synced file : \foo.doc Error in syncing file \bar\bar.pdf Get initial copy completed with error. Received 1 files, 1 objects have error. (17062986 bytes were received in 11.5794 seconds a \ t 11.7885 Mbps)
To prevent the failure of one or two files which couldn't be synchronized to be seen as a full failure of the Initial Sync, a failure ignore percentage can be configured:
Figure 8.21. CIFS pre-population failure settings
CSH (config) # show prepop settings Maximum Mpx Count Percentage: 40 Ignore Percentage: 0 CSH (config) # prepop settings ignore-pct 10 Processed RCU configuration command. CSH (config) # show prepop settings Maximum Mpx Count Percentage: 40 Ignore Percentage: 10
Now up to 10% of the files to be synced can fail and the initial sync is still considered to be successful.
After the initial syncing, the periodical syncing checks for new files and updated files.
Figure 8.22. No new files found during the periodical sync
CSH rcud[5555]: [crawler.INFO] - {- -} Sync started at Fri 2014-Jan-03 21:33:15 CSH rcud[5555]: [cifsfs.INFO] - {- -} @ [199]: Base cifs sync directory = '\prepop' CSH sport[2946]: [smbcfe/file.INFO] 19 {10.0.1.5:47840 192.168.1.1:139} process_trans2_fin \ dfirst_response() has search attr : 23 CSH sport[2946]: [smbcfe/file.INFO] 19 {10.0.1.5:47840 192.168.1.1:139} process_trans2_fin \ dfirst_response() has search attr : 23 CSH sport[2946]: [smbcfe/file.NOTICE] 19 {10.0.1.5:47840 192.168.1.1:139} File::add_trans \ 2_findnext_data() last entries dont match : \ CSH rcud[5555]: [crawler.INFO] - {- -} Sync completed successfully at Fri 2014-Jan-03 21:3 \ 3:16 CSH rcud[5555]: [crawler.INFO] - {- -} Received 0 files, 0 objects have error. (0 bytes we \ re received in 1.26024 seconds at 0 Mbps) CSH sport[2946]: [smbcfe/ccons.INFO] 19 {10.0.1.5:47840 192.168.1.1:139} SMBConsumer::eof( \ ) this=0x5494530, qlen=0 CSH rcud[5555]: [rcud/share/.NOTICE] - {- -} Completed successfully CMD : START_SYNC Shar \ e : \\192.168.1.1\admin\prepop CSH sport[2946]: [smbcfe/scons.INFO] 19 {10.0.1.5:47840 192.168.1.1:139} SMBConsumer::eof( \ ) this=0x5494608, qlen=0 CSH sport[2946]: [splice/client.INFO] 19 {10.0.1.5:47840 192.168.1.1:139} fini client 10.0 \ .1.5:47840 server 192.168.1.1:139 cfe 10.0.1.6:40286 sfe 192.168.1.6:7800 app CIFS CSH rcud[5555]: [rcud/share/.INFO] - {- -} Status string : Share idle
The Last Sync log files show as:
Figure 8.23. The Last Sync log files shows no new files found
Sync started at Fri 2014-Jan-03 21:33:15 Sync completed successfully at Fri 2014-Jan-03 21:33:16 Received 0 files, 0 objects have error. (0 bytes were received in 1.26024 seconds at 0 Mbp \ s)
If the timestamp of a remote file has changed or a new file has been detected, it will be transferred:
Figure 8.24. New files found during the periodical sync
CSH rcud[5555]: [crawler.INFO] - {- -} Sync started at Fri 2014-Jan-03 21:34:15 CSH rcud[5555]: [cifsfs.INFO] - {- -} @ [199]: Base cifs sync directory = '\prepop' CSH sport[2946]: [smbcfe/file.INFO] 20 {10.0.1.5:47863 192.168.1.1:139} process_trans2_fin \ dfirst_response() has search attr : 23 CSH last message repeated 2 times CSH rcud[5555]: [sync_file.INFO] - {- -} @ [207]: Syncing file \quux\quux.mbox CSH rcud[5555]: [sync_file.INFO] - {- -} @ [207]: Syncing file \quux\quux.mbox CSH rcud[5555]: [rcud/share/.INFO] - {- -} Status string : START_SYNC in progress since F \ ri Jan 3 21:34:12 2014 CSH rcud[5555]: [sync_file.INFO] - {- -} @ [207]: Syncing file \quux\quux.mbox CSH last message repeated 3 times CSH rcud[5555]: [crawler/sync_lists.INFO] - {- -} @ [194]: Synced file : \quux\quux.mbox CSH sport[2946]: [smbcfe/file.NOTICE] 20 {10.0.1.5:47863 192.168.1.1:139} File::add_trans \ 2_findnext_data() last entries dont match : \ CSH rcud[5555]: [crawler.INFO] - {- -} Sync completed successfully at Fri 2014-Jan-03 21:3 \ 4:23 CSH rcud[5555]: [crawler.INFO] - {- -} Received 1 files, 0 objects have error. (17062986 b \ ytes were received in 7.97558 seconds at 17.1152 Mbps)
The Last Sync log files show as:
Figure 8.25. The Last Sync log files shows new or updated files found
Sync started at Fri 2014-Jan-03 21:34:15 Synced file : \quux\quux.mbox Sync completed successfully at Fri 2014-Jan-03 21:34:23 Received 1 files, 0 objects have error. (17062986 bytes were received in 7.97558 seconds a \ t 17.1152 Mbps)
The status of the CIFS pre-population process can be determined with
the command
show prepop stats shares
:
Figure 8.26. Status of the pre-population shares during syncing and when the share is idle
CSH # show prepop stats shares +============================= | Prepopulation name: '\\192.168.1.1\admin\prepop' | | ----- Statistics ----- | Receiving : NONE | Files Received : 1 | Directories Received : 0 | Bytes Received : 17062986 CSH # show prepop stats shares +============================= | Prepopulation name: '\\192.168.1.1\admin\prepop' | | ----- Statistics ----- | No action in progress