Index: trunk/kernel/kern/rpc.c
===================================================================
--- trunk/kernel/kern/rpc.c	(revision 279)
+++ trunk/kernel/kern/rpc.c	(revision 296)
@@ -99,7 +99,7 @@
                                 uint32_t * ppn )       // out 
 {
-    assert( (cxy != local_cxy) , __FUNCTION__ , "target cluster is not remote\n");
-
-    rpc_dmsg("\n[INFO] %s : enter\n", __FUNCTION__ );
+    rpc_dmsg("\n[INFO] %s : enter at cycle %d\n", __FUNCTION__ , hal_time_stamp() );
+
+    assert( (cxy != local_cxy) , __FUNCTION__ , "target cluster is not remote\n");
 
     // initialise RPC descriptor header 
@@ -118,5 +118,5 @@
     *ppn    = (uint32_t)rpc.args[1];
 
-    rpc_dmsg("\n[INFO] %s : completed\n", __FUNCTION__ );
+    rpc_dmsg("\n[INFO] %s : completed at cycle %d\n", __FUNCTION__ , hal_time_stamp() );
 }
 
@@ -127,4 +127,6 @@
     error_t  error;  // output
     uint32_t ppn;    // output
+
+    rpc_dmsg("\n[INFO] %s : enter at cycle %d\n", __FUNCTION__ , hal_time_stamp() );
 
     // get client cluster identifier and pointer on RPC descriptor
@@ -143,4 +145,6 @@
     hal_remote_sw( XPTR( cxy , &desc->args[0] ) , error );
     hal_remote_sw( XPTR( cxy , &desc->args[1] ) , ppn );
+
+    rpc_dmsg("\n[INFO] %s : completed at cycle %d\n", __FUNCTION__ , hal_time_stamp() );
 }
 
@@ -155,7 +159,7 @@
                                    pid_t     * pid )     // out
 {
-    assert( (cxy != local_cxy) , __FUNCTION__ , "target cluster is not remote\n");
-
-    rpc_dmsg("\n[INFO] %s : enter\n", __FUNCTION__ );
+    rpc_dmsg("\n[INFO] %s : enter at cycle %d\n", __FUNCTION__ , hal_time_stamp() );
+
+    assert( (cxy != local_cxy) , __FUNCTION__ , "target cluster is not remote\n");
 
     // initialise RPC descriptor header 
@@ -174,5 +178,5 @@
     *error  = (error_t)rpc.args[2];     
 
-    rpc_dmsg("\n[INFO] %s : completed\n", __FUNCTION__ );
+    rpc_dmsg("\n[INFO] %s : completed at cycle %d\n", __FUNCTION__ , hal_time_stamp() );
 }
 
@@ -183,4 +187,6 @@
     error_t     error;     // output : error status
     pid_t       pid;       // output : process identifier
+
+    rpc_dmsg("\n[INFO] %s : enter at cycle %d\n", __FUNCTION__ , hal_time_stamp() );
 
     // get client cluster identifier and pointer on RPC descriptor
@@ -198,4 +204,6 @@
     hal_remote_sw( XPTR( client_cxy , &desc->args[0] ) , (uint64_t)error );
     hal_remote_sw( XPTR( client_cxy , &desc->args[1] ) , (uint64_t)pid );
+
+    rpc_dmsg("\n[INFO] %s : completed at cycle %d\n", __FUNCTION__ , hal_time_stamp() );
 }
 
@@ -210,7 +218,7 @@
                               error_t     * error )   // out
 {
-    assert( (cxy != local_cxy) , __FUNCTION__ , "target cluster is not remote\n");
-
-    rpc_dmsg("\n[INFO] %s : enter\n", __FUNCTION__ );
+    rpc_dmsg("\n[INFO] %s : enter at cycle %d\n", __FUNCTION__ , hal_time_stamp() );
+
+    assert( (cxy != local_cxy) , __FUNCTION__ , "target cluster is not remote\n");
 
     // initialise RPC descriptor header 
@@ -228,5 +236,5 @@
     *error  = (error_t)rpc.args[1];     
 
-    rpc_dmsg("\n[INFO] %s : completed\n", __FUNCTION__ );
+    rpc_dmsg("\n[INFO] %s : completed at cycle %d\n", __FUNCTION__ , hal_time_stamp() );
 }
 
@@ -237,4 +245,6 @@
     exec_info_t   info;      // local copy of exec_info structure
     error_t       error;     // local error error status
+
+    rpc_dmsg("\n[INFO] %s : enter at cycle %d\n", __FUNCTION__ , hal_time_stamp() );
 
     // get client cluster identifier and pointer on RPC descriptor
@@ -255,4 +265,6 @@
     // set output argument into client RPC descriptor
     hal_remote_swd( XPTR( client_cxy , &desc->args[1] ) , (uint64_t)error );
+
+    rpc_dmsg("\n[INFO] %s : completed at cycle %d\n", __FUNCTION__ , hal_time_stamp() );
 }
 
@@ -265,9 +277,9 @@
 void rpc_process_kill_client( process_t * process ) 
 {
+    rpc_dmsg("\n[INFO] %s : enter at cycle %d\n", __FUNCTION__ , hal_time_stamp() );
+
     // only reference cluster can send this RPC
     assert( (GET_CXY( process->ref_xp ) == local_cxy) , __FUNCTION__ ,
             "caller must be reference process cluster\n");
-
-    rpc_dmsg("\n[INFO] %s : enter\n", __FUNCTION__ );
 
     // get local process index in reference cluster
@@ -297,5 +309,5 @@
     }
 
-    rpc_dmsg("\n[INFO] %s : completed\n", __FUNCTION__ );
+    rpc_dmsg("\n[INFO] %s : completed at cycle %d\n", __FUNCTION__ , hal_time_stamp() );
 }  
 
@@ -305,4 +317,6 @@
     pid_t       pid;
     process_t * process;  
+
+    rpc_dmsg("\n[INFO] %s : enter at cycle %d\n", __FUNCTION__ , hal_time_stamp() );
 
     // get client cluster identifier and pointer on RPC descriptor
@@ -325,4 +339,6 @@
         process_kill( process ); 
     }
+
+    rpc_dmsg("\n[INFO] %s : completed at cycle %d\n", __FUNCTION__ , hal_time_stamp() );
 } 
 
@@ -341,7 +357,7 @@
                                     error_t        * error )      // out 
 {
-    assert( (cxy != local_cxy) , __FUNCTION__ , "target cluster is not remote\n");
-
-    rpc_dmsg("\n[INFO] %s : enter\n", __FUNCTION__ );
+    rpc_dmsg("\n[INFO] %s : enter at cycle %d\n", __FUNCTION__ , hal_time_stamp() );
+
+    assert( (cxy != local_cxy) , __FUNCTION__ , "target cluster is not remote\n");
 
     // initialise RPC descriptor header 
@@ -363,5 +379,5 @@
     *error     = (error_t)rpc.args[5];
 
-    rpc_dmsg("\n[INFO] %s : completed\n", __FUNCTION__ );
+    rpc_dmsg("\n[INFO] %s : completed at cycle %d\n", __FUNCTION__ , hal_time_stamp() );
 }
 
@@ -378,4 +394,6 @@
     void           * start_arg;
     error_t          error;
+
+    rpc_dmsg("\n[INFO] %s : enter at cycle %d\n", __FUNCTION__ , hal_time_stamp() );
 
     // get client cluster identifier and pointer on RPC descriptor
@@ -409,4 +427,6 @@
     hal_remote_swd( XPTR( client_cxy , &desc->args[1] ) , (uint64_t)error );
     hal_remote_swd( XPTR( client_cxy , &desc->args[2] ) , (uint64_t)thread_xp );
+
+    rpc_dmsg("\n[INFO] %s : completed at cycle %d\n", __FUNCTION__ , hal_time_stamp() );
 }
 
@@ -423,7 +443,7 @@
                                       error_t * error )      // out
 {
-    assert( (cxy != local_cxy) , __FUNCTION__ , "target cluster is not remote\n");
-
-    rpc_dmsg("\n[INFO] %s : enter\n", __FUNCTION__ );
+    rpc_dmsg("\n[INFO] %s : enter at cycle %d\n", __FUNCTION__ , hal_time_stamp() );
+
+    assert( (cxy != local_cxy) , __FUNCTION__ , "target cluster is not remote\n");
 
     // initialise RPC descriptor header 
@@ -444,5 +464,5 @@
     *error     = (error_t)rpc.args[4];
 
-    rpc_dmsg("\n[INFO] %s : completed\n", __FUNCTION__ );
+    rpc_dmsg("\n[INFO] %s : completed at cycle %d\n", __FUNCTION__ , hal_time_stamp() );
 }
 
@@ -455,4 +475,6 @@
     error_t          error;    
 
+    rpc_dmsg("\n[INFO] %s : enter at cycle %d\n", __FUNCTION__ , hal_time_stamp() );
+
     // get client cluster identifier and pointer on RPC descriptor
     cxy_t        client_cxy  = (cxy_t)GET_CXY( xp );
@@ -474,4 +496,6 @@
     hal_remote_swd( XPTR( client_cxy , &desc->args[1] ) , (uint64_t)error );
     hal_remote_swd( XPTR( client_cxy , &desc->args[2] ) , (uint64_t)thread_xp );
+
+    rpc_dmsg("\n[INFO] %s : completed at cycle %d\n", __FUNCTION__ , hal_time_stamp() );
 }
 
@@ -485,7 +509,7 @@
                              uint32_t    sig_id )    // in
 {
-    assert( (cxy != local_cxy) , __FUNCTION__ , "target cluster is not remote\n");
-
-    rpc_dmsg("\n[INFO] %s : enter\n", __FUNCTION__ );
+    rpc_dmsg("\n[INFO] %s : enter at cycle %d\n", __FUNCTION__ , hal_time_stamp() );
+
+    assert( (cxy != local_cxy) , __FUNCTION__ , "target cluster is not remote\n");
 
     // initialise RPC descriptor header 
@@ -501,5 +525,5 @@
     rpc_send_sync( cxy , &rpc );
 
-    rpc_dmsg("\n[INFO] %s : completed\n", __FUNCTION__ );
+    rpc_dmsg("\n[INFO] %s : completed at cycle %d\n", __FUNCTION__ , hal_time_stamp() );
 }
 
@@ -509,4 +533,6 @@
     process_t  * process;  // local pointer on process descriptor
     uint32_t     sig_id;   // signal index
+
+    rpc_dmsg("\n[INFO] %s : enter at cycle %d\n", __FUNCTION__ , hal_time_stamp() );
 
     // get client cluster identifier and pointer on RPC descriptor
@@ -520,4 +546,6 @@
     // call local kernel function
     signal_rise( process , sig_id );
+
+    rpc_dmsg("\n[INFO] %s : completed at cycle %d\n", __FUNCTION__ , hal_time_stamp() );
 }
 
@@ -539,7 +567,7 @@
                                   error_t      * error )     // out
 {
-    assert( (cxy != local_cxy) , __FUNCTION__ , "target cluster is not remote\n");
-
-    rpc_dmsg("\n[INFO] %s : enter\n", __FUNCTION__ );
+    rpc_dmsg("\n[INFO] %s : enter at cycle %d\n", __FUNCTION__ , hal_time_stamp() );
+
+    assert( (cxy != local_cxy) , __FUNCTION__ , "target cluster is not remote\n");
 
     // initialise RPC descriptor header 
@@ -565,5 +593,5 @@
     *error    = (error_t)rpc.args[9];
 
-    rpc_dmsg("\n[INFO] %s : completed\n", __FUNCTION__ );
+    rpc_dmsg("\n[INFO] %s : completed at cycle %d\n", __FUNCTION__ , hal_time_stamp() );
 }
 
@@ -582,4 +610,6 @@
     error_t          error;
 
+    rpc_dmsg("\n[INFO] %s : enter at cycle %d\n", __FUNCTION__ , hal_time_stamp() );
+
     // get client cluster identifier and pointer on RPC descriptor
     cxy_t        client_cxy  = (cxy_t)GET_CXY( xp );
@@ -610,4 +640,6 @@
     hal_remote_swd( XPTR( client_cxy , &desc->args[8] ) , (uint64_t)inode_xp );
     hal_remote_swd( XPTR( client_cxy , &desc->args[9] ) , (uint64_t)error );
+
+    rpc_dmsg("\n[INFO] %s : completed at cycle %d\n", __FUNCTION__ , hal_time_stamp() );
 }
 
@@ -620,7 +652,7 @@
                                    struct vfs_inode_s * inode )
 {
-    assert( (cxy != local_cxy) , __FUNCTION__ , "target cluster is not remote\n");
-
-    rpc_dmsg("\n[INFO] %s : enter\n", __FUNCTION__ );
+    rpc_dmsg("\n[INFO] %s : enter at cycle %d\n", __FUNCTION__ , hal_time_stamp() );
+
+    assert( (cxy != local_cxy) , __FUNCTION__ , "target cluster is not remote\n");
 
     // initialise RPC descriptor header 
@@ -635,5 +667,5 @@
     rpc_send_sync( cxy , &rpc );
 
-    rpc_dmsg("\n[INFO] %s : completed\n", __FUNCTION__ );
+    rpc_dmsg("\n[INFO] %s : completed at cycle %d\n", __FUNCTION__ , hal_time_stamp() );
 }
 
@@ -642,4 +674,6 @@
 {
     vfs_inode_t * inode;
+
+    rpc_dmsg("\n[INFO] %s : enter at cycle %d\n", __FUNCTION__ , hal_time_stamp() );
 
     // get client cluster identifier and pointer on RPC descriptor
@@ -652,4 +686,6 @@
     // call local kernel function
     vfs_inode_destroy( inode );
+
+    rpc_dmsg("\n[INFO] %s : completed at cycle %d\n", __FUNCTION__ , hal_time_stamp() );
 }
 
@@ -666,7 +702,7 @@
                                    error_t              * error )       // out
 {
-    assert( (cxy != local_cxy) , __FUNCTION__ , "target cluster is not remote\n");
-
-    rpc_dmsg("\n[INFO] %s : enter\n", __FUNCTION__ );
+    rpc_dmsg("\n[INFO] %s : enter at cycle %d\n", __FUNCTION__ , hal_time_stamp() );
+
+    assert( (cxy != local_cxy) , __FUNCTION__ , "target cluster is not remote\n");
 
     // initialise RPC descriptor header 
@@ -687,5 +723,5 @@
     *error     = (error_t)rpc.args[4];
 
-    rpc_dmsg("\n[INFO] %s : completed\n", __FUNCTION__ );
+    rpc_dmsg("\n[INFO] %s : completed at cycle %d\n", __FUNCTION__ , hal_time_stamp() );
 }
 
@@ -701,4 +737,6 @@
     char          name_copy[CONFIG_VFS_MAX_NAME_LENGTH];
 
+    rpc_dmsg("\n[INFO] %s : enter at cycle %d\n", __FUNCTION__ , hal_time_stamp() );
+
     // get client cluster identifier and pointer on RPC descriptor
     cxy_t        client_cxy  = (cxy_t)GET_CXY( xp );
@@ -709,5 +747,5 @@
     name   = (char *)(intptr_t)       hal_remote_lwd( XPTR( client_cxy , &desc->args[1] ) );
     parent = (vfs_inode_t *)(intptr_t)hal_remote_lwd( XPTR( client_cxy , &desc->args[2] ) );
-                       
+
     // makes a local copy of  name
     hal_remote_strcpy( XPTR( local_cxy , name_copy ),
@@ -719,8 +757,9 @@
                                parent,
                                &dentry_xp );
- 
     // set output arguments
     hal_remote_swd( XPTR( client_cxy , &desc->args[3] ) , (uint64_t)dentry_xp );
     hal_remote_swd( XPTR( client_cxy , &desc->args[4] ) , (uint64_t)error );
+
+    rpc_dmsg("\n[INFO] %s : completed at cycle %d\n", __FUNCTION__ , hal_time_stamp() );
 }
 
@@ -728,4 +767,5 @@
 // [13]          Marshaling functions attached to RPC_VFS_DENTRY_DESTROY 
 /////////////////////////////////////////////////////////////////////////////////////////
+
 
 ///////////////////////////////////////////////////////
@@ -733,7 +773,7 @@
                                     vfs_dentry_t * dentry )
 {
-    assert( (cxy != local_cxy) , __FUNCTION__ , "target cluster is not remote\n");
-
-    rpc_dmsg("\n[INFO] %s : enter\n", __FUNCTION__ );
+    rpc_dmsg("\n[INFO] %s : enter at cycle %d\n", __FUNCTION__ , hal_time_stamp() );
+
+    assert( (cxy != local_cxy) , __FUNCTION__ , "target cluster is not remote\n");
 
     // initialise RPC descriptor header 
@@ -748,5 +788,5 @@
     rpc_send_sync( cxy , &rpc );
 
-    rpc_dmsg("\n[INFO] %s : completed\n", __FUNCTION__ );
+    rpc_dmsg("\n[INFO] %s : completed at cycle %d\n", __FUNCTION__ , hal_time_stamp() );
 }
 
@@ -755,4 +795,6 @@
 {
     vfs_dentry_t * dentry;
+
+    rpc_dmsg("\n[INFO] %s : enter at cycle %d\n", __FUNCTION__ , hal_time_stamp() );
 
     // get client cluster identifier and pointer on RPC descriptor
@@ -765,4 +807,6 @@
     // call local kernel function
     vfs_dentry_destroy( dentry );
+
+    rpc_dmsg("\n[INFO] %s : completed at cycle %d\n", __FUNCTION__ , hal_time_stamp() );
 }
 
@@ -779,7 +823,7 @@
                                  error_t              * error )      // out
 {
-    assert( (cxy != local_cxy) , __FUNCTION__ , "target cluster is not remote\n");
-
-    rpc_dmsg("\n[INFO] %s : enter\n", __FUNCTION__ );
+    rpc_dmsg("\n[INFO] %s : enter at cycle %d\n", __FUNCTION__ , hal_time_stamp() );
+
+    assert( (cxy != local_cxy) , __FUNCTION__ , "target cluster is not remote\n");
 
     // initialise RPC descriptor header 
@@ -799,5 +843,5 @@
     *error   = (error_t)rpc.args[3];
 
-    rpc_dmsg("\n[INFO] %s : completed\n", __FUNCTION__ );
+    rpc_dmsg("\n[INFO] %s : completed at cycle %d\n", __FUNCTION__ , hal_time_stamp() );
 }
 
@@ -809,4 +853,6 @@
     xptr_t        file_xp;
     error_t       error;
+
+    rpc_dmsg("\n[INFO] %s : enter at cycle %d\n", __FUNCTION__ , hal_time_stamp() );
 
     // get client cluster identifier and pointer on RPC descriptor
@@ -826,4 +872,6 @@
     hal_remote_swd( XPTR( client_cxy , &desc->args[2] ) , (uint64_t)file_xp );
     hal_remote_swd( XPTR( client_cxy , &desc->args[3] ) , (uint64_t)error );
+
+    rpc_dmsg("\n[INFO] %s : completed at cycle %d\n", __FUNCTION__ , hal_time_stamp() );
 }
 
@@ -836,7 +884,7 @@
                                   vfs_file_t * file )
 {
-    assert( (cxy != local_cxy) , __FUNCTION__ , "target cluster is not remote\n");
-
-    rpc_dmsg("\n[INFO] %s : enter\n", __FUNCTION__ );
+    rpc_dmsg("\n[INFO] %s : enter at cycle %d\n", __FUNCTION__ , hal_time_stamp() );
+
+    assert( (cxy != local_cxy) , __FUNCTION__ , "target cluster is not remote\n");
 
     // initialise RPC descriptor header 
@@ -851,5 +899,5 @@
     rpc_send_sync( cxy , &rpc );
 
-    rpc_dmsg("\n[INFO] %s : completed\n", __FUNCTION__ );
+    rpc_dmsg("\n[INFO] %s : completed at cycle %d\n", __FUNCTION__ , hal_time_stamp() );
 }
 
@@ -858,4 +906,6 @@
 {
     vfs_file_t * file;
+
+    rpc_dmsg("\n[INFO] %s : enter at cycle %d\n", __FUNCTION__ , hal_time_stamp() );
 
     // get client cluster identifier and pointer on RPC descriptor
@@ -868,4 +918,6 @@
     // call local kernel function
     vfs_file_destroy( file );
+
+    rpc_dmsg("\n[INFO] %s : completed at cycle %d\n", __FUNCTION__ , hal_time_stamp() );
 }
 
@@ -881,7 +933,7 @@
                                 error_t     * error )          // out
 {
-    assert( (cxy != local_cxy) , __FUNCTION__ , "target cluster is not remote\n");
-
-    rpc_dmsg("\n[INFO] %s : enter\n", __FUNCTION__ );
+    rpc_dmsg("\n[INFO] %s : enter at cycle %d\n", __FUNCTION__ , hal_time_stamp() );
+
+    assert( (cxy != local_cxy) , __FUNCTION__ , "target cluster is not remote\n");
 
     // initialise RPC descriptor header 
@@ -901,5 +953,5 @@
     *error   = (error_t)rpc.args[3];
 
-    rpc_dmsg("\n[INFO] %s : completed\n", __FUNCTION__ );
+    rpc_dmsg("\n[INFO] %s : completed at cycle %d\n", __FUNCTION__ , hal_time_stamp() );
 }
 
@@ -914,4 +966,6 @@
     char          name_copy[CONFIG_VFS_MAX_NAME_LENGTH];
 
+    rpc_dmsg("\n[INFO] %s : enter at cycle %d\n", __FUNCTION__ , hal_time_stamp() );
+
     // get client cluster identifier and pointer on RPC descriptor
     cxy_t        client_cxy  = (cxy_t)GET_CXY( xp );
@@ -932,4 +986,6 @@
     // set output argument
     hal_remote_swd( XPTR( client_cxy , &desc->args[3] ) , (uint64_t)error );
+
+    rpc_dmsg("\n[INFO] %s : completed at cycle %d\n", __FUNCTION__ , hal_time_stamp() );
 }
 
@@ -943,7 +999,7 @@
                                      error_t     * error )     // out
 {
-    assert( (cxy != local_cxy) , __FUNCTION__ , "target cluster is not remote\n");
-
-    rpc_dmsg("\n[INFO] %s : enter\n", __FUNCTION__ );
+    rpc_dmsg("\n[INFO] %s : enter at cycle %d\n", __FUNCTION__ , hal_time_stamp() );
+
+    assert( (cxy != local_cxy) , __FUNCTION__ , "target cluster is not remote\n");
 
     // initialise RPC descriptor header 
@@ -961,5 +1017,5 @@
     *error   = (error_t)rpc.args[1];
 
-    rpc_dmsg("\n[INFO] %s : completed\n", __FUNCTION__ );
+    rpc_dmsg("\n[INFO] %s : completed at cycle %d\n", __FUNCTION__ , hal_time_stamp() );
 }
 
@@ -970,4 +1026,6 @@
     vfs_inode_t * inode;
 
+    rpc_dmsg("\n[INFO] %s : enter at cycle %d\n", __FUNCTION__ , hal_time_stamp() );
+
     // get client cluster identifier and pointer on RPC descriptor
     cxy_t        client_cxy  = (cxy_t)GET_CXY( xp );
@@ -982,4 +1040,6 @@
     // set output argument
     hal_remote_swd( XPTR( client_cxy , &desc->args[3] ) , (uint64_t)error );
+
+    rpc_dmsg("\n[INFO] %s : completed at cycle %d\n", __FUNCTION__ , hal_time_stamp() );
 }
 
@@ -996,7 +1056,7 @@
                                    error_t  * error )    // out
 {
-    assert( (cxy != local_cxy) , __FUNCTION__ , "target cluster is not remote\n");
-
-    rpc_dmsg("\n[INFO] %s : enter\n", __FUNCTION__ );
+    rpc_dmsg("\n[INFO] %s : enter at cycle %d\n", __FUNCTION__ , hal_time_stamp() );
+
+    assert( (cxy != local_cxy) , __FUNCTION__ , "target cluster is not remote\n");
 
     // initialise RPC descriptor header 
@@ -1017,5 +1077,5 @@
     *error   = (error_t)rpc.args[4];
 
-    rpc_dmsg("\n[INFO] %s : completed\n", __FUNCTION__ );
+    rpc_dmsg("\n[INFO] %s : completed at cycle %d\n", __FUNCTION__ , hal_time_stamp() );
 }
 
@@ -1029,4 +1089,6 @@
     error_t       error;
 
+    rpc_dmsg("\n[INFO] %s : enter at cycle %d\n", __FUNCTION__ , hal_time_stamp() );
+
     // get client cluster identifier and pointer on RPC descriptor
     cxy_t        client_cxy  = (cxy_t)GET_CXY( xp );
@@ -1044,4 +1106,6 @@
     hal_remote_swd( XPTR( client_cxy , &desc->args[3] ) , (uint64_t)cluster );
     hal_remote_swd( XPTR( client_cxy , &desc->args[4] ) , (uint64_t)error );
+
+    rpc_dmsg("\n[INFO] %s : completed at cycle %d\n", __FUNCTION__ , hal_time_stamp() );
 }
 
@@ -1056,7 +1120,7 @@
                                   xptr_t    * vseg_xp )    // out
 {
-    assert( (cxy != local_cxy) , __FUNCTION__ , "target cluster is not remote\n");
-
-    rpc_dmsg("\n[INFO] %s : enter\n", __FUNCTION__ );
+    rpc_dmsg("\n[INFO] %s : enter at cycle %d\n", __FUNCTION__ , hal_time_stamp() );
+
+    assert( (cxy != local_cxy) , __FUNCTION__ , "target cluster is not remote\n");
 
     // initialise RPC descriptor header 
@@ -1075,5 +1139,5 @@
     *vseg_xp = rpc.args[2];
 
-    rpc_dmsg("\n[INFO] %s : completed\n", __FUNCTION__ );
+    rpc_dmsg("\n[INFO] %s : completed at cycle %d\n", __FUNCTION__ , hal_time_stamp() );
 }
 
@@ -1085,4 +1149,6 @@
     vseg_t      * vseg_ptr;
     xptr_t        vseg_xp;
+
+    rpc_dmsg("\n[INFO] %s : enter at cycle %d\n", __FUNCTION__ , hal_time_stamp() );
 
     // get client cluster identifier and pointer on RPC descriptor
@@ -1101,4 +1167,6 @@
     else                   vseg_xp = XPTR( local_cxy , vseg_ptr );
     hal_remote_swd( XPTR( client_cxy , &desc->args[2] ) , (uint64_t)vseg_xp );
+
+    rpc_dmsg("\n[INFO] %s : completed at cycle %d\n", __FUNCTION__ , hal_time_stamp() );
 }
 
@@ -1116,7 +1184,7 @@
                              error_t   * error )   // out 
 {
-    assert( (cxy != local_cxy) , __FUNCTION__ , "target cluster is not remote\n");
-
-    rpc_dmsg("\n[INFO] %s : enter\n", __FUNCTION__ );
+    rpc_dmsg("\n[INFO] %s : enter at cycle %d\n", __FUNCTION__ , hal_time_stamp() );
+
+    assert( (cxy != local_cxy) , __FUNCTION__ , "target cluster is not remote\n");
 
     // initialise RPC descriptor header 
@@ -1137,5 +1205,5 @@
     *error = (error_t)rpc.args[4];
 
-    rpc_dmsg("\n[INFO] %s : completed\n", __FUNCTION__ );
+    rpc_dmsg("\n[INFO] %s : completed at cycle %d\n", __FUNCTION__ , hal_time_stamp() );
 }
 
@@ -1148,4 +1216,6 @@
     ppn_t         ppn;
     error_t       error;
+
+    rpc_dmsg("\n[INFO] %s : enter at cycle %d\n", __FUNCTION__ , hal_time_stamp() );
 
     // get client cluster identifier and pointer on RPC descriptor
@@ -1164,4 +1234,6 @@
     hal_remote_swd( XPTR( client_cxy , &desc->args[3] ) , (uint64_t)ppn );
     hal_remote_swd( XPTR( client_cxy , &desc->args[4] ) , (uint64_t)error );
+
+    rpc_dmsg("\n[INFO] %s : completed at cycle %d\n", __FUNCTION__ , hal_time_stamp() );
 }
 
@@ -1175,7 +1247,7 @@
                            xptr_t *   buf_xp )     // out
 {
-    assert( (cxy != local_cxy) , __FUNCTION__ , "target cluster is not remote\n");
-
-    rpc_dmsg("\n[INFO] %s : enter\n", __FUNCTION__ );
+    rpc_dmsg("\n[INFO] %s : enter at cycle %d\n", __FUNCTION__ , hal_time_stamp() );
+
+    assert( (cxy != local_cxy) , __FUNCTION__ , "target cluster is not remote\n");
 
     // initialise RPC descriptor header 
@@ -1193,5 +1265,5 @@
     *buf_xp = (xptr_t)rpc.args[1];
 
-    rpc_dmsg("\n[INFO] %s : completed\n", __FUNCTION__ );
+    rpc_dmsg("\n[INFO] %s : completed at cycle %d\n", __FUNCTION__ , hal_time_stamp() );
 }
 
@@ -1199,4 +1271,6 @@
 void rpc_kcm_alloc_server( xptr_t xp )
 {
+    rpc_dmsg("\n[INFO] %s : enter at cycle %d\n", __FUNCTION__ , hal_time_stamp() );
+
     // get client cluster identifier and pointer on RPC descriptor
     cxy_t        client_cxy  = (cxy_t)GET_CXY( xp );
@@ -1215,4 +1289,6 @@
     xptr_t buf_xp = XPTR( local_cxy , buf_ptr );
     hal_remote_swd( XPTR( client_cxy , &desc->args[1] ) , (uint64_t)buf_xp );
+
+    rpc_dmsg("\n[INFO] %s : completed at cycle %d\n", __FUNCTION__ , hal_time_stamp() );
 }   
 
@@ -1226,7 +1302,7 @@
                           uint32_t   kmem_type )   // in
 {
-    assert( (cxy != local_cxy) , __FUNCTION__ , "target cluster is not remote\n");
-
-    rpc_dmsg("\n[INFO] %s : enter\n", __FUNCTION__ );
+    rpc_dmsg("\n[INFO] %s : enter at cycle %d\n", __FUNCTION__ , hal_time_stamp() );
+
+    assert( (cxy != local_cxy) , __FUNCTION__ , "target cluster is not remote\n");
 
     // initialise RPC descriptor header 
@@ -1242,5 +1318,5 @@
     rpc_send_sync( cxy , &rpc );
 
-    rpc_dmsg("\n[INFO] %s : completed\n", __FUNCTION__ );
+    rpc_dmsg("\n[INFO] %s : completed at cycle %d\n", __FUNCTION__ , hal_time_stamp() );
 }
 
@@ -1248,4 +1324,6 @@
 void rpc_kcm_free_server( xptr_t xp )
 {
+    rpc_dmsg("\n[INFO] %s : enter at cycle %d\n", __FUNCTION__ , hal_time_stamp() );
+
     // get client cluster identifier and pointer on RPC descriptor
     cxy_t        client_cxy  = (cxy_t)GET_CXY( xp );
@@ -1261,4 +1339,6 @@
     req.ptr  = buf;
     kmem_free( &req );
+
+    rpc_dmsg("\n[INFO] %s : completed at cycle %d\n", __FUNCTION__ , hal_time_stamp() );
 }   
 
@@ -1277,7 +1357,7 @@
                                     error_t  * error )        // out
 {
-    assert( (cxy != local_cxy) , __FUNCTION__ , "target cluster is not remote\n");
-
-    rpc_dmsg("\n[INFO] %s : enter\n", __FUNCTION__ );
+    rpc_dmsg("\n[INFO] %s : enter at cycle %d\n", __FUNCTION__ , hal_time_stamp() );
+
+    assert( (cxy != local_cxy) , __FUNCTION__ , "target cluster is not remote\n");
 
     // initialise RPC descriptor header 
@@ -1300,5 +1380,5 @@
     *error     = (error_t)rpc.args[6];
 
-    rpc_dmsg("\n[INFO] %s : completed\n", __FUNCTION__ );
+    rpc_dmsg("\n[INFO] %s : completed at cycle %d\n", __FUNCTION__ , hal_time_stamp() );
 }
 
@@ -1314,4 +1394,6 @@
     error_t    error;
 
+    rpc_dmsg("\n[INFO] %s : enter at cycle %d\n", __FUNCTION__ , hal_time_stamp() );
+
     // get client cluster identifier and pointer on RPC descriptor
     cxy_t        client_cxy  = (cxy_t)GET_CXY( xp );
@@ -1336,4 +1418,6 @@
     // set output argument to client RPC descriptor
     hal_remote_swd( XPTR( client_cxy , &desc->args[6] ) , (uint64_t)error );
+
+    rpc_dmsg("\n[INFO] %s : completed at cycle %d\n", __FUNCTION__ , hal_time_stamp() );
 }
 
@@ -1353,6 +1437,6 @@
     thread_t * this = CURRENT_THREAD;
 
-    rpc_dmsg("\n[INFO] %s : enter / client_cxy = %x / server_cxy = %x\n",
-             __FUNCTION__ , local_cxy , server_cxy );
+    rpc_dmsg("\n[INFO] %s : enter / client_cxy = %x / server_cxy = %x / cycle %d\n",
+    __FUNCTION__ , local_cxy , server_cxy , hal_time_stamp() );
 
     // allocate and initialise an extended pointer on the RPC descriptor
@@ -1374,16 +1458,13 @@
         {
             printk("\n[WARNING] %s : cluster %x cannot post RPC to cluster %x\n",
-                   __FUNCTION__ , local_cxy , server_cxy );
-
-            if( thread_can_yield() ) sched_yield();
-        }
-        else
-        {
+            __FUNCTION__ , local_cxy , server_cxy );
+
+            if( thread_can_yield() ) sched_yield( NULL );
         }
     }
     while( error );
  
-    rpc_dmsg("\n[INFO] %s : RPC registered / client_cxy = %x / server_cxy = %x\n",
-             __FUNCTION__ , local_cxy , server_cxy , first );
+    rpc_dmsg("\n[INFO] %s : RPC %l registered / server_cxy = %x / cycle %d\n",
+    __FUNCTION__ , desc_xp , server_cxy , hal_time_stamp() );
 	
     // send IPI to remote CP0, if this is the first RPC in remote FIFO,
@@ -1399,5 +1480,5 @@
 
 		    rpc_dmsg("\n[INFO] %s : IPI sent / client_cxy = %x / server_cxy = %x\n",
-                     __FUNCTION__, local_cxy , server_cxy );
+            __FUNCTION__, local_cxy , server_cxy );
         }
 	}
@@ -1416,6 +1497,6 @@
 	if( this->type == THREAD_RPC ) hal_restore_irq( sr_save );
 
-    rpc_dmsg("\n[INFO] %s : completed / client_cxy = %x / server_cxy = %x\n",
-             __FUNCTION__ , local_cxy , server_cxy );
+    rpc_dmsg("\n[INFO] %s : completed / client_cxy = %x / server_cxy = %x / cycle %d\n",
+    __FUNCTION__ , local_cxy , server_cxy , hal_time_stamp() );
 
 }  // end rpc_send_sync()
@@ -1447,20 +1528,18 @@
 	error_t        error;
       
-	this = CURRENT_THREAD; 
-    core = this->core;   
-
-
+	this  = CURRENT_THREAD; 
+    core  = this->core;   
+	count = 0;
+
+    rpc_dmsg("\n[INFO] %s : enter / thread %x on core[%x,%d] / fifo = %x / cycle %d\n",
+    __FUNCTION__, this->trdid, local_cxy, core->lid , hal_time_stamp() );
+ 
     // handle up to CONFIG_RPC_PENDING_MAX requests before exit
-	count = 0;
 	do
     {
-	    error = local_fifo_get_item( &rpc_fifo->fifo, 
-                                     (uint64_t *)&xp );
+	    error = local_fifo_get_item( &rpc_fifo->fifo, (uint64_t *)&xp );
 
 		if ( error == 0 )  // One RPC request successfully extracted from RPC_FIFO
         {
-            rpc_dmsg("\n[INFO] %s : RPC_THREAD %x on core %x in cluster %x handles RPC %d\n",
-				     __FUNCTION__ , this->trdid , core->lid , local_cxy , count );
-
             // get client cluster identifier and pointer on RPC descriptor
             client_cxy = (cxy_t)GET_CXY( xp );
@@ -1468,5 +1547,8 @@
 
             // get rpc index from RPC descriptor
-	        index     = hal_remote_lw( XPTR( client_cxy , &desc->index ) );
+	        index = hal_remote_lw( XPTR( client_cxy , &desc->index ) );
+
+            rpc_dmsg("\n[INFO] %s : thread %x on core [%x,%d] / index = %d / &rpc = %x\n",
+		     __FUNCTION__ , this->trdid , core->lid , local_cxy , index , rpc_server[index] );
 
             // call the relevant server function
@@ -1533,11 +1615,13 @@
     if( found )                    // activate this idle RPC thread      
     {
+        // unblock it
         thread->blocked = 0;
 
-        rpc_dmsg("\n[INFO] %s : activate RPC thread %x on core %x in cluster %x at cycle %d\n", 
-		          __FUNCTION__ , thread , core->gid , local_cxy , hal_get_cycles() );
+        rpc_dmsg("\n[INFO] %s : activate RPC thread %x on core [%x,%d] / cycle %d\n", 
+		          __FUNCTION__ , thread , core->gid , local_cxy , hal_time_stamp() );
     }
     else                           // create a new RPC thread
     {
+        // create new thread
         error = thread_kernel_create( &thread,
                                       THREAD_RPC, 
@@ -1553,9 +1637,12 @@
         }
 
-        rpc_dmsg("\n[INFO] %s : create RPC thread %x on core %x in cluster %x at cycle %d\n", 
-		          __FUNCTION__ , thread , core->gid , local_cxy , hal_get_cycles() );
+        // unblock new thread
+        thread->blocked = 0;
 
         // update core descriptor counter  
 	    hal_atomic_add( &LOCAL_CLUSTER->rpc_threads , 1 );
+
+        rpc_dmsg("\n[INFO] %s : create RPC thread %x on core [%x,%d] / cycle %d\n", 
+		          __FUNCTION__ , thread->trdid, local_cxy, core->lid, hal_time_stamp() );
     }
 
@@ -1563,6 +1650,6 @@
     rpc_fifo->owner = thread->trdid;
 
-    // current thread deschedules / RPC thread start execution 
-	sched_switch_to( thread );
+    // current thread switch to RPC thread  
+	sched_yield( thread );
 
     // restore IRQs for the calling thread 
@@ -1581,7 +1668,13 @@
     error_t      error;
 
+    rpc_dmsg("\n[INFO] %s : enter in cluster %x\n",
+             __FUNCTION__ , local_cxy );
+
     // calling thread does nothing if light lock already taken or FIFO empty  
 	if( (rpc_fifo->owner != 0) || (local_fifo_is_empty( &rpc_fifo->fifo )) )
     {
+        rpc_dmsg("\n[INFO] %s : exit but do nothing in cluster %x\n",
+                 __FUNCTION__ , local_cxy );
+
         return false;
     }
@@ -1601,8 +1694,14 @@
         }
 
+        rpc_dmsg("\n[INFO] %s : exit after activating an RPC thread in cluster %x\n",
+                 __FUNCTION__ , local_cxy );
+
         return true;
     }
     else  // light lock taken by another thread
     {
+        rpc_dmsg("\n[INFO] %s : exit but do nothing in cluster %x\n",
+                 __FUNCTION__ , local_cxy );
+
         return false;
     }
@@ -1613,5 +1712,5 @@
 void rpc_thread_func()
 {
-    // makes the calling thread not preemptable
+    // makes the RPC thread not preemptable
 	hal_disable_irq( NULL );
   
@@ -1619,6 +1718,6 @@
 	rpc_fifo_t * rpc_fifo = &LOCAL_CLUSTER->rpc_fifo;
 
-    rpc_dmsg("\n[INFO] RPC thread %x created on core %d in cluster %x at cycle %d\n",
-             this->trdid , this->core->lid , local_cxy , hal_get_cycles() );
+    rpc_dmsg("\n[INFO] %s : enter / thread %x on core[%x,%d] / cycle %d\n",
+             __FUNCTION__, this->trdid, local_cxy, this->core->lid, hal_time_stamp() );
 
     // this infinite loop is not preemptable
@@ -1629,6 +1728,6 @@
         if( this->trdid != rpc_fifo->owner )
         {
-            printk("\n[PANIC] in %s : RPC_THREAD %x not owner of RPC_FIFO in cluster %x\n",
-                   __FUNCTION__ , this->trdid , local_cxy );
+            printk("\n[PANIC] in %s : thread %x on core[%x,%d] not owner of RPC_FIFO\n",
+            __FUNCTION__, this->trdid, local_cxy, this->core->lid );
             hal_core_sleep();
         }
@@ -1644,6 +1743,6 @@
 		if( LOCAL_CLUSTER->rpc_threads >= CONFIG_RPC_THREADS_MAX ) 
 		{
-            rpc_dmsg("\n[INFO] RPC thread %x suicide on core %d in cluster %x at cycle %d\n", 
-		             this->trdid , this->core->lid , local_cxy , hal_get_cycles() );
+            rpc_dmsg("\n[INFO] thread %x on core[%x,%d] suicide / cycle %d\n", 
+		    __FUNCTION__, this->trdid, local_cxy, this->core->lid, hal_time_stamp() );
 
             // update core descriptor counter
@@ -1655,12 +1754,12 @@
         else
         {
-            rpc_dmsg("\n[INFO] RPC thread %x blocks on core %d in cluster %x at cycle %d\n", 
-			         this->trdid , this->core->lid , local_cxy , hal_get_cycles() ); 
-
-		     thread_block( this , THREAD_BLOCKED_IDLE );
-             sched_yield();
-
-		     rpc_dmsg("\n[INFO] RPC thread %x wake up on core %d in cluster %x at cycle %d\n", 
-	    	          this->trdid , this->core->lid , local_cxy , hal_get_cycles() );
+            rpc_dmsg("\n[INFO] %s : thread %x on core[%x,%d] blocks / cycle %d\n", 
+			__FUNCTION__, this->trdid, local_cxy, this->core->lid, hal_time_stamp() ); 
+
+		    thread_block( this , THREAD_BLOCKED_IDLE );
+            sched_yield( NULL );
+
+		    rpc_dmsg("\n[INFO] RPC thread %x wake up on core[%x,%d] / cycle %d\n", 
+	        __FUNCTION__, this->trdid, local_cxy, this->core->lid, hal_time_stamp() );
         }
 	} // end while
