Configuring Profiling for Operations

To check the amount of time it took to complete each operation (from the time of submission), enable profiling for client RPC and file system operations. To enable profiling for:

  • Client RPC, run the following command:
    fcdebug -s <shmid> -m ClntProfileRpc -1 DEBUG
    TIP
    For more information, see fcdebug.
    Enabling profiling for the client RPC will allow you to determine, for each RPC, the amount of time it took to receive a response after submitting the request.
  • file system operations, run the following command:
    maprcli trace setlevel -module FSProfile -level debug
    TIP
    For more information, see maprcli.
    Enabling profiling for file system operations will allow you to determine the amount of time it took file system to process each operation.

By default, profiling is disabled for both client RPC and file system operations. Once enabled, the log for:

  • Client RPC should look similar to the following:
    2016-06-16 10:58:04,6404 DEBUG ClntProfileRpc
    fs/client/fileclient/cc/client.cc:3483 Thread: 32188 Profile: CltRpcDone:
    server 10.10.100.196:5692 took 1 msec error 0 FID 2125.34.262486  Getattr
              
    2016-06-16 11:13:55,7480 DEBUG ClntProfileRpc
    fs/client/fileclient/cc/client.cc:3202 Thread: 32161 Profile: CltRpcDone:
    server 10.10.100.196:5692 took 1 msec error 0 FID 2125.16.2  PathWalkPlus path
    abc
  • file system should look similar to the following:
    2016-06-19 15:51:05,0231 DEBUG FSProfile unlink.cc:2456 OP unlink: localTm 34
    elapsedTm 34 client 10.10.100.196 err 0 PFID: 1.32.131398 name
    unreachableFSIdTable itype Regular
              
    2016-06-19 15:51:11,0249 DEBUG FSProfile writev3.cc:1296 OP Write: localTm 13
    elapsedTm 13 client 10.10.100.196 err 0 FID: 2121.532.2364014 off 29234 count
    1424
              
    2016-06-19 15:51:08,1184 DEBUG FSProfile readdir.cc:505 OP ReadDir: elapsedTm
    28 client 10.10.100.196 err 0 FID: 2121.16.2 Isplus true

For example, to check the time it took for a read RPC, run the following command:

# cat /opt/mapr/logs/ffs.log* | grep -nrui "CltRpcDone" | grep -nrui "read" | less
1009:1014:2016-06-16 11:21:51,8203 DEBUG ClntProfileRpc
fs/client/fileclient/cc/client.cc:4900 Thread: 32151 Profile: CltRpcDone:
server10.10.100.196:5660 took 0 msec for Proc Read error 0 FID 2182.32.131232
off 7143424 len 131072 name 2125.34.262486