Changeset 296 for trunk/kernel/kern

Timestamp:

Jul 31, 2017, 1:59:52 PM (7 years ago)

Author:

alain

Message:

Several modifs in the generic scheduler and in the hal_context to
fix the context switch mechanism.

Location:

trunk/kernel/kern

Files:

• chdev.c (modified) (2 diffs)
• cluster.c (modified) (1 diff)
• core.c (modified) (1 diff)
• kernel_init.c (modified) (16 diffs)
• printk.c (modified) (1 diff)
• printk.h (modified) (1 diff)
• rpc.c (modified) (102 diffs)
• rpc.h (modified) (1 diff)
• scheduler.c (modified) (10 diffs)
• scheduler.h (modified) (3 diffs)
• thread.c (modified) (8 diffs)

trunk/kernel/kern/chdev.c

@@ -129 +129 @@
     // client thread goes to blocked state and deschedule
     thread_block( thread_ptr , THREAD_BLOCKED_IO );
-    sched_yield();
+    sched_yield( NULL );
 
 }  // end chdev_register_command()
@@ -162 +162 @@
             // block and deschedule
             thread_block( server , THREAD_BLOCKED_DEV_QUEUE );
-            sched_yield();
+            sched_yield( NULL );
         } 
         else

trunk/kernel/kern/cluster.c

@@ -117 +117 @@
                  __FUNCTION__ , local_cxy , hal_get_cycles() );
 
-    // initialises all cores descriptors
+    // initialises all cores descriptors 
         for( lid = 0 ; lid < cluster->cores_nr; lid++ )
         {

trunk/kernel/kern/core.c

@@ -115 +115 @@
 
         // handle scheduler TODO  improve the scheduling condition ... AG
-        if( (ticks % 10) == 0 ) sched_yield();
+        if( (ticks % 10) == 0 ) sched_yield( NULL );
 
         // update DQDT TODO  This update should depend on the cluster identifier,

trunk/kernel/kern/kernel_init.c

@@ -29 +29 @@
 #include <hal_context.h>
 #include <hal_irqmask.h>
+#include <hal_ppm.h>
 #include <barrier.h>
 #include <remote_barrier.h>
@@ -784 +785 @@
 
     if( (core_lid ==  0) && (local_cxy == 0) ) 
-    kinit_dmsg("\n[INFO] %s exit barrier 0 at cycle %d : TXT0 initialized\n",
-               __FUNCTION__, (uint32_t)hal_time_stamp());
+    kinit_dmsg("\n[INFO] %s : exit barrier 0 : TXT0 initialized / cycle %d\n",
+    __FUNCTION__, hal_time_stamp() );
 
     /////////////////////////////////////////////////////////////////////////////
@@ -822 +823 @@
 
     if( (core_lid ==  0) && (local_cxy == 0) ) 
-    kinit_dmsg("\n[INFO] %s exit barrier 1 at cycle %d : clusters initialised\n",
-               __FUNCTION__, (uint32_t)hal_time_stamp());
+    kinit_dmsg("\n[INFO] %s : exit barrier 1 : clusters initialised / cycle %d\n",
+    __FUNCTION__, hal_time_stamp() );
 
     /////////////////////////////////////////////////////////////////////////////////
     // STEP 2 : all CP0s initialize the process_zero descriptor.
-    //          CP0 in cluster 0 initialises the IOPIC device.
+    //          CP0 in cluster 0 initializes the IOPIC device.
     /////////////////////////////////////////////////////////////////////////////////
 
@@ -847 +848 @@
 
     if( (core_lid ==  0) && (local_cxy == 0) ) 
-    kinit_dmsg("\n[INFO] %s exit barrier 2 at cycle %d : PIC initialised\n",
-               __FUNCTION__, (uint32_t)hal_time_stamp());
+    kinit_dmsg("\n[INFO] %s : exit barrier 2 : PIC initialised / cycle %d\n",
+    __FUNCTION__, hal_time_stamp() );
 
     ////////////////////////////////////////////////////////////////////////////////
-    // STEP 3 : all CP0s complete the distibuted LAPIC initialization.
-    //          all CP0s initialize their internal chdev descriptors
-    //          all CP0s initialize their local external chdev descriptors
+    // STEP 3 : all CP0s initialize the distibuted LAPIC descriptor.
+    //          all CP0s initialize the internal chdev descriptors
+    //          all CP0s initialize the local external chdev descriptors
     ////////////////////////////////////////////////////////////////////////////////
 
@@ -878 +879 @@
 
     if( (core_lid ==  0) && (local_cxy == 0) ) 
-    kinit_dmsg("\n[INFO] %s exit barrier 3 at cycle %d : all chdev initialised\n",
-               __FUNCTION__, (uint32_t)hal_time_stamp());
+    kinit_dmsg("\n[INFO] %s : exit barrier 3 : all chdev initialised / cycle %d\n",
+               __FUNCTION__, hal_time_stamp());
 
     /////////////////////////////////////////////////////////////////////////////////
     // STEP 4 : All cores enable IPI (Inter Procesor Interrupt),
+    //          All cores initialise specific core registers
     //          Alh cores initialize IDLE thread.
     //          Only CP0 in cluster 0 creates the VFS root inode.
@@ -891 +893 @@
     
     // All cores enable the shared IPI channel
-
-// @@@
-    hal_set_ebase( 0x1000 );
-// @@@
-
     dev_pic_enable_ipi();
     hal_enable_irq( &status );
 
+    // All cores initialize specific core registers
+    hal_core_init( info );
+
     kinit_dmsg("\n[INFO] %s : IRQs enabled for core[%x,%d] / SR = %x\n", 
                __FUNCTION__ , local_cxy , core_lid , hal_get_sr() );
 
-    // all cores create the idle thread descriptor
+    // all cores initialize the idle thread descriptor
     error = thread_kernel_init( thread,
                                 THREAD_IDLE,
@@ -915 +915 @@
     }
 
-    // all cores register idle thread in scheduler
+    // all cores unblock idle thread, and register it in scheduler
+    thread_unblock( XPTR( local_cxy , thread ) , THREAD_BLOCKED_GLOBAL );
     core->scheduler.idle = thread;
 
-    // all core activate the idle thread
-    thread_unblock( XPTR( local_cxy , thread ) , THREAD_BLOCKED_GLOBAL );
-
     if( (core_lid ==  0) && (local_cxy == 0) ) 
     {
-        kinit_dmsg("\n[INFO] %s : created idle thread %x at cycle %d\n",
-                   __FUNCTION__ , thread , (uint32_t)hal_time_stamp());
-    }
+        kinit_dmsg("\n[INFO] %s : initialized idle thread %x on core[%x,%d] / cycle %d\n",
+        __FUNCTION__ , thread->trdid , local_cxy, core_lid, (uint32_t)hal_time_stamp());
+    }
+
+    #if CONFIG_KINIT_DEBUG
+    sched_display();
+    #endif
 
     // CPO in cluster 0 creates the VFS root
@@ -991 +993 @@
 
     if( (core_lid ==  0) && (local_cxy == 0) ) 
-    kinit_dmsg("\n[INFO] %s exit barrier 4 at cycle %d : VFS OK in cluster 0\n",
-               __FUNCTION__, (uint32_t)hal_time_stamp());
+    kinit_dmsg("\n[INFO] %s : exit barrier 4 : VFS_root = %l in cluster 0 / cycle %d\n",
+               __FUNCTION__, vfs_root_inode_xp , hal_time_stamp());
 
     /////////////////////////////////////////////////////////////////////////////////
@@ -1010 +1012 @@
             fatfs_ctx_t * fatfs_ctx = fatfs_ctx_alloc();
 
-            assert( (fatfs_ctx != NULL) , __FUNCTION__ ,
-                    "cannot create FATFS context\n" );
+            assert( (fatfs_ctx != NULL) , __FUNCTION__ , "cannot create FATFS context\n" );
 
             // get local pointer on VFS context for FATFS
@@ -1031 +1032 @@
 
         // get extended pointer on VFS root inode from cluster 0
-        vfs_root_inode_xp = hal_remote_lwd( XPTR( 0 , process_zero.vfs_root_xp ) );
+        vfs_root_inode_xp = hal_remote_lwd( XPTR( 0 , &process_zero.vfs_root_xp ) );
 
         // update local process_zero descriptor
@@ -1044 +1045 @@
     /////////////////////////////////////////////////////////////////////////////////
 
-//    if( (core_lid ==  0) && (local_cxy == 0) ) 
-    kinit_dmsg("\n[INFO] %s exit barrier 5 at cycle %d : VFS OK in all clusters\n",
-               __FUNCTION__, (uint32_t)hal_time_stamp());
-
+    if( (core_lid ==  0) && (local_cxy == io_cxy) ) 
+    kinit_dmsg("\n[INFO] %s : exit barrier 5 : VFS_root = %l in cluster IO / cycle %d\n",
+    __FUNCTION__, vfs_root_inode_xp , hal_time_stamp() );
 
     /////////////////////////////////////////////////////////////////////////////////
@@ -1072 +1072 @@
     }    
 
-printk("\n@@@ %s : cluster %x reach barrier 6\n", __FUNCTION__ , local_cxy );
-
     /////////////////////////////////////////////////////////////////////////////////
     if( core_lid == 0 ) remote_barrier( XPTR( io_cxy , &global_barrier ), 
@@ -1080 +1078 @@
     /////////////////////////////////////////////////////////////////////////////////
 
-//    if( (core_lid ==  0) && (local_cxy == 0) ) 
-    kinit_dmsg("\n[INFO] %s exit barrier 6 at cycle %d : DEVFS OK in cluster IO\n",
-               __FUNCTION__, (uint32_t)hal_time_stamp());
+    if( (core_lid ==  0) && (local_cxy == io_cxy) ) 
+    kinit_dmsg("\n[INFO] %s : exit barrier 6 : dev_root = %l in cluster IO / cycle %d\n",
+    __FUNCTION__, devfs_dev_inode_xp , hal_time_stamp() );
 
     /////////////////////////////////////////////////////////////////////////////////
@@ -1118 +1116 @@
 
     if( (core_lid ==  0) && (local_cxy == 0) ) 
-    kinit_dmsg("\n[INFO] %s exit barrier 7 at cycle %d : DEVFS OK in all clusters\n",
-               __FUNCTION__, (uint32_t)hal_time_stamp());
+    kinit_dmsg("\n[INFO] %s : exit barrier 7 : dev_root = %l in cluster 0 / cycle %d\n",
+    __FUNCTION__, devfs_dev_inode_xp , hal_time_stamp() );
 
     #if CONFIG_KINIT_DEBUG
@@ -1141 +1139 @@
 
     if( (core_lid ==  0) && (local_cxy == 0) ) 
-    kinit_dmsg("\n[INFO] %s exit barrier 8 at cycle %d : process init created\n", 
-               __FUNCTION__ , (uint32_t)hal_time_stamp() );
+    kinit_dmsg("\n[INFO] %s : exit barrier 8 : process init created / cycle %d\n", 
+    __FUNCTION__ , hal_time_stamp() );
 
     /////////////////////////////////////////////////////////////////////////////////
@@ -1198 +1196 @@
     dev_pic_enable_timer( CONFIG_SCHED_TICK_PERIOD );
 
-    if( (core_lid ==  0) && (local_cxy == io_cxy) ) 
-    thread_dmsg("\n[INFO] %s complete kernel init in cluster 0 at cycle %d\n"
-                __FUNCTION__ , (uint32_t)hal_time_stamp() )
-
     // each core jump to idle thread
     thread_idle_func();

trunk/kernel/kern/printk.c

@@ -401 +401 @@
 }
 
+////////////////////////////////////////
+void nolock_printk( char * format , ...)
+{
+    va_list       args;
+
+    // call kernel_printf on TXT0, in busy waiting mode
+    va_start( args , format );
+    kernel_printf( 0 , 1 , format , &args );
+    va_end( args );
+}
+
 ///////////////////////////////////////////
 inline void assert( bool_t       condition,

trunk/kernel/kern/printk.h

@@ -67 +67 @@
  * This function displays a formated string on the kernel terminal TXT0,
  * using a busy waiting policy: It calls directly the relevant TXT driver, 
- * after taking the lock for exclusive access to the TXT0 terminal.
+ * after taking the TXT0 lock.
  **********************************************************************************
  * @ format     : formated string.
  *********************************************************************************/
 void printk( char* format, ... );
+
+/**********************************************************************************
+ * This function displays a formated string on the kernel terminal TXT0,
+ * using a busy waiting policy: It calls directly the relevant TXT driver, 
+ * without taking the TXT0 lock.
+ **********************************************************************************
+ * @ format     : formated string.
+ *********************************************************************************/
+void nolock_printk( char* format, ... );
 
 /**********************************************************************************

trunk/kernel/kern/rpc.c

@@ -99 +99 @@
                                 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 +118 @@
     *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 +127 @@
     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 +145 @@
     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 +159 @@
                                    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 +178 @@
     *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 +187 @@
     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 +204 @@
     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 +218 @@
                               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 +236 @@
     *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 +245 @@
     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 +265 @@
     // 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 +277 @@
 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 +309 @@
     }
 
-    rpc_dmsg("\n[INFO] %s : completed\n", __FUNCTION__ );
+    rpc_dmsg("\n[INFO] %s : completed at cycle %d\n", __FUNCTION__ , hal_time_stamp() );
 }  
 
@@ -305 +317 @@
     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 +339 @@
         process_kill( process ); 
     }
+
+    rpc_dmsg("\n[INFO] %s : completed at cycle %d\n", __FUNCTION__ , hal_time_stamp() );
 } 
 
@@ -341 +357 @@
                                     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 +379 @@
     *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 +394 @@
     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 +427 @@
     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 +443 @@
                                       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 +464 @@
     *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 +475 @@
     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 +496 @@
     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 +509 @@
                              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 +525 @@
     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 +533 @@
     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 +546 @@
     // call local kernel function
     signal_rise( process , sig_id );
+
+    rpc_dmsg("\n[INFO] %s : completed at cycle %d\n", __FUNCTION__ , hal_time_stamp() );
 }
 
@@ -539 +567 @@
                                   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 +593 @@
     *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 +610 @@
     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 +640 @@
     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 +652 @@
                                    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 +667 @@
     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 +674 @@
 {
     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 +686 @@
     // call local kernel function
     vfs_inode_destroy( inode );
+
+    rpc_dmsg("\n[INFO] %s : completed at cycle %d\n", __FUNCTION__ , hal_time_stamp() );
 }
 
@@ -666 +702 @@
                                    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 +723 @@
     *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 +737 @@
     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 +747 @@
     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 +757 @@
                                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 +767 @@
 // [13]          Marshaling functions attached to RPC_VFS_DENTRY_DESTROY 
 /////////////////////////////////////////////////////////////////////////////////////////
+
 
 ///////////////////////////////////////////////////////
@@ -733 +773 @@
                                     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 +788 @@
     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 +795 @@
 {
     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 +807 @@
     // call local kernel function
     vfs_dentry_destroy( dentry );
+
+    rpc_dmsg("\n[INFO] %s : completed at cycle %d\n", __FUNCTION__ , hal_time_stamp() );
 }
 
@@ -779 +823 @@
                                  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 +843 @@
     *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 +853 @@
     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 +872 @@
     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 +884 @@
                                   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 +899 @@
     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 +906 @@
 {
     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 +918 @@
     // call local kernel function
     vfs_file_destroy( file );
+
+    rpc_dmsg("\n[INFO] %s : completed at cycle %d\n", __FUNCTION__ , hal_time_stamp() );
 }
 
@@ -881 +933 @@
                                 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 +953 @@
     *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 +966 @@
     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 +986 @@
     // 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 +999 @@
                                      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 +1017 @@
     *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 +1026 @@
     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 +1040 @@
     // 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 +1056 @@
                                    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 +1077 @@
     *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 +1089 @@
     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 +1106 @@
     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 +1120 @@
                                   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 +1139 @@
     *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 +1149 @@
     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 +1167 @@
     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 +1184 @@
                              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 +1205 @@
     *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 +1216 @@
     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 +1234 @@
     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 +1247 @@
                            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 +1265 @@
     *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 +1271 @@
 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 +1289 @@
     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 +1302 @@
                           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 +1318 @@
     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 +1324 @@
 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 +1339 @@
     req.ptr  = buf;
     kmem_free( &req );
+
+    rpc_dmsg("\n[INFO] %s : completed at cycle %d\n", __FUNCTION__ , hal_time_stamp() );
 }   
 
@@ -1277 +1357 @@
                                     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 +1380 @@
     *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 +1394 @@
     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 +1418 @@
     // 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 +1437 @@
     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 +1458 @@
         {
             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 +1480 @@
 
                     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 +1497 @@
         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 +1528 @@
         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 +1547 @@
 
             // 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 +1615 @@
     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 +1637 @@
         }
 
-        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 +1650 @@
     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 +1668 @@
     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 +1694 @@
         }
 
+        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 +1712 @@
 void rpc_thread_func()
 {
-    // makes the calling thread not preemptable
+    // makes the RPC thread not preemptable
         hal_disable_irq( NULL );
   
@@ -1619 +1718 @@
         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 +1728 @@
         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 +1743 @@
                 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 +1754 @@
         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

trunk/kernel/kern/rpc.h

@@ -157 +157 @@
 /***********************************************************************************
  * This function is the entry point for RPC handling on the server side.
- * It can be executed by any thread running (in kernel mode) on any core.
+ * It is executed by a core receiving an IPI.
  * It checks the RPC fifo, try to take the light-lock and activates (or creates)
  * an RPC thread in case of success.

trunk/kernel/kern/scheduler.c

@@ -30 +30 @@
 #include <core.h>
 #include <thread.h>
+#include <chdev.h>
 #include <scheduler.h>
+
+///////////////////////////////////////////////////////////////////////////////////////////
+// Extern global variables
+///////////////////////////////////////////////////////////////////////////////////////////
+
+extern chdev_directory_t    chdev_dir;            // allocated in kernel_init.c file
 
 
@@ -144 +151 @@
 thread_t * sched_select( core_t * core )
 {
-    thread_t * thread;
+    thread_t    * thread;
 
     scheduler_t * sched = &core->scheduler;
+
+    sched_dmsg("\n[INFO] %s : enter core[%x,%d] / cycle %d\n",
+    __FUNCTION__ , local_cxy , core->lid , hal_time_stamp() );
 
     // take lock protecting sheduler lists
@@ -154 +164 @@
     list_entry_t * last;
 
-    // first : scan the kernel threads list,
-    // only if this list is not empty 
+    // first : scan the kernel threads list if not empty 
     if( list_is_empty( &sched->k_root ) == false )
     {
@@ -171 +180 @@
             thread = LIST_ELEMENT( current , thread_t , sched_list );
 
-            // return thread if runnable
-            if( thread->blocked == 0 ) 
+            // return thread if not idle_thread and runnable 
+            if( (thread->type != THREAD_IDLE) && (thread->blocked == 0) ) 
             {
                 // release lock 
                 spinlock_unlock( &sched->lock );
+
+                sched_dmsg("\n[INFO] %s : exit core[%x,%d] / k_thread = %x / cycle %d\n",
+                __FUNCTION__ , local_cxy , core->lid , thread->trdid , hal_time_stamp() );
+
                 return thread;
             }
@@ -182 +195 @@
     }
 
-    // second : scan the user threads list,
-    // only if this list is not empty 
+    // second : scan the user threads list if not empty 
     if( list_is_empty( &sched->u_root ) == false )
     {
@@ -204 +216 @@
                 // release lock 
                 spinlock_unlock( &sched->lock );
+
+                sched_dmsg("\n[INFO] %s : exit core[%x,%d] / u_thread = %x / cycle %d\n",
+                __FUNCTION__ , local_cxy , core->lid , thread->trdid , hal_time_stamp() );
                 return thread;
             }
@@ -213 +228 @@
     spinlock_unlock( &sched->lock );
 
+    sched_dmsg("\n[INFO] %s : exit core[%x,%d] / idle = %x / cycle %d\n",
+    __FUNCTION__ , local_cxy , core->lid , sched->idle->trdid , hal_time_stamp() );
+
     // third : return idle thread if no runnable thread
     return sched->idle;
 
-}  // end sched_elect()
+}  // end sched_select()
 
 //////////////////////////////////////////
@@ -223 +241 @@
     list_entry_t * iter;
     thread_t     * thread;
-
     scheduler_t  * sched = &core->scheduler;
+
+    sched_dmsg("\n[INFO] %s : enter / thread %x on core[%x,%d]\n",
+    __FUNCTION__, CURRENT_THREAD->trdid , local_cxy , core->lid );
 
     // take lock protecting threads lists
@@ -246 +266 @@
     spinlock_unlock( &sched->lock );
 
+    sched_dmsg("\n[INFO] %s : exit / thread %x on core[%x,%d]\n",
+    __FUNCTION__, CURRENT_THREAD->trdid , local_cxy , core->lid );
+
 } // end sched_handle_signals()
 
-//////////////////
-void sched_yield()
+///////////////////////////////////
+void sched_yield( thread_t * next )
 {
     reg_t         sr_save;
-    thread_t    * next;
 
     thread_t    * current = CURRENT_THREAD;
@@ -258 +280 @@
     scheduler_t * sched   = &core->scheduler;
 
-    if( thread_can_yield() == false )
-    {
-        printk("\n[PANIC] in %s : thread %x for process %x on core_gid %x"
-               " has not released all locks at cycle %d\n",
-               __FUNCTION__, current->trdid, current->process->pid, 
-               local_cxy , core->lid , hal_get_cycles() );
-        hal_core_sleep();
-    }
-
-    // desactivate IRQs
-    hal_disable_irq( &sr_save );
+    sched_dmsg("\n[INFO] %s : thread %x on core[%x,%d] enter / cycle %d\n",
+    __FUNCTION__, current->trdid, local_cxy, core->lid, hal_time_stamp() );
+
+    // check calling thread released all locks
+    assert( (thread_can_yield() == true), __FUNCTION__, "locks not released\n");
 
     // first loop on all threads to handle pending signals
     sched_handle_signals( core );
 
-    // second loop on threads to select next thread
-    next = sched_select( core );
-
-    // check stack overflow for selected thread
-    if( next->signature != THREAD_SIGNATURE )
-    {
-        printk("\n[PANIC] in %s : detected stack overflow for thread %x of process %x"
-               " on core [%x][%d]\n",
-               __FUNCTION__, next->trdid, next->process->pid, local_cxy , core->lid );
-        hal_core_sleep();
-        }
-        
-        sched_dmsg("\n[INFO] %s on core %d in cluster %x / old thread = %x / new thread = %x\n",
-               __FUNCTION__, core->lid, local_cxy, current->trdid, next->trdid );
-
-    // switch contexts and update scheduler state if new thread
-        if( next != current )  
-        {
-        hal_cpu_context_save( current );
-        hal_cpu_context_restore( next );
-
+    // second loop on threads to select next thread if required
+    if( next == NULL ) next = sched_select( core );
+
+    // check next thread attached to same core as the calling thread
+    assert( (next->core == current->core), __FUNCTION__ , "next core != current core\n");
+
+    // check next thread not blocked
+    assert( (next->blocked == 0), __FUNCTION__ , "next thread is blocked\n");
+
+    // switch contexts and update scheduler state if next != current
+        if( next != current )
+    {
+        sched_dmsg("\n[INFO] %s : trd %x (%s) on core[%x,%d] => trd %x (%s) / cycle %d\n",
+        __FUNCTION__, current->trdid, thread_type_str(current->type), local_cxy, core->lid, 
+        next->trdid, thread_type_str(next->type), hal_time_stamp() );
+
+        // calling thread desactivate IRQs
+        hal_disable_irq( &sr_save );
+
+        // update scheduler 
         if( current->type == THREAD_USER ) sched->u_last = &current->sched_list;
         else                               sched->k_last = &current->sched_list;
-
         sched->current = next;
-        }
-
-    // restore IRQs
-    hal_restore_irq( sr_save );
-
-        if( current->type != THREAD_USER ) return;
-
-        if( next == core->fpu_owner ) hal_fpu_enable();
-        else                          hal_fpu_disable();
-
+
+        // handle FPU
+            if( next->type == THREAD_USER ) return;
+        {
+                if( next == core->fpu_owner )  hal_fpu_enable();
+                else                           hal_fpu_disable();
+        }
+
+        // switch contexts 
+        hal_cpu_context_save( current->cpu_context );
+        hal_cpu_context_restore( next->cpu_context );
+
+        // restore IRQs when calling thread resume
+        hal_restore_irq( sr_save );
+
+        sched_dmsg("\n[INFO] %s : thread %x on core[%x,%d] / cycle %d\n",
+        __FUNCTION__, current->trdid, local_cxy, core->lid, hal_time_stamp() );
+    }
+    else
+    {
+        sched_dmsg("\n[INFO] %s : thread %x on core[%x,%d] continue / cycle %d\n",
+        __FUNCTION__, current->trdid, local_cxy, core->lid, hal_time_stamp() );
+    }
 }  // end sched_yield()
 
-//////////////////////////////////////
-void sched_switch_to( thread_t * new )
-{
-    reg_t         sr_save;
-
-    thread_t    * current = CURRENT_THREAD;
-    core_t      * core    = current->core;
-    process_t   * process = current->process;
-
-    // check calling thread released all locks
-    if( thread_can_yield() == false )
-    {
-        printk("\n[PANIC] in %s : thread %x for process %x on core %d in cluster %x"
-               " has not released all locks\n",
-               __FUNCTION__, current->trdid, process->pid, core->lid, local_cxy );
-        hal_core_sleep();
-    }
-
-    // check new thread attached to same core as the calling thread
-    if( new->core != current->core )
-    {
-        printk("\n[PANIC] in %s : new thread %x is attached to core %d"
-               " different from core %d of current thread\n",
-               __FUNCTION__, new->trdid, new->core->lid, core->lid , current->trdid );
-        hal_core_sleep();
-    }
-
-    // check new thread not blocked
-    if( new->blocked == 0 )
-    {
-        printk("\n[PANIC] in %s for thread %x of process %x on core %d in cluster %x"
-               " : new thread %x is blocked\n",
-               __FUNCTION__, current->trdid, process->pid , core->lid, local_cxy , new->trdid );
-        hal_core_sleep();
-    }
-
-    // check stack overflow for new thread
-    if( new->signature != THREAD_SIGNATURE )
-    {
-        printk("\n[PANIC] in %s : stack overflow for new thread %x of process %x"
-               " on core %d in cluster %x\n",
-               __FUNCTION__, new->trdid, process->pid , core->lid , local_cxy );
-        hal_core_sleep();
-        }
-
-    // desactivate IRQs
-    hal_disable_irq( &sr_save );
-
-    // loop on all threads to handle pending signals
-    sched_handle_signals( core );
-
-    // check stack overflow for new thread
-    if( new->signature != THREAD_SIGNATURE )
-    {
-        printk("PANIC %s detected stack overflow for thread %x of process %x"
-               " on core %d in cluster %x\n",
-               __FUNCTION__, new->trdid, new->process->pid, core->lid, local_cxy);
-        hal_core_sleep();
-        }
-        
-        sched_dmsg("INFO : %s on core %d in cluster %x / old thread = %x / new thread = %x\n",
-               __FUNCTION__, core->lid, local_cxy, current->trdid, new->trdid );
-
-    // switch contexts if new thread
-    hal_cpu_context_save( current );
-    hal_cpu_context_restore( new );
-
-    // restore IRQs
-    hal_restore_irq( sr_save );
-
-        if( current->type != THREAD_USER ) return;
-
-        if( current == core->fpu_owner )  hal_fpu_enable();
-        else                              hal_fpu_disable();
-
-}  // end sched_switch_to()
-
+////////////////////
+void sched_display()
+{
+    list_entry_t * iter;
+    thread_t     * thread;
+    uint32_t       save_sr;
+
+    thread_t     * current = CURRENT_THREAD;
+    core_t       * core    = current->core;
+    scheduler_t  * sched   = &core->scheduler;
+    
+    // get pointers on TXT0 chdev
+    xptr_t    txt0_xp  = chdev_dir.txt[0];
+    cxy_t     txt0_cxy = GET_CXY( txt0_xp );
+    chdev_t * txt0_ptr = GET_PTR( txt0_xp );
+
+    // get extended pointer on remote TXT0 chdev lock
+    xptr_t  lock_xp = XPTR( txt0_cxy , &txt0_ptr->wait_lock );
+
+    // get TXT0 lock in busy waiting mode
+    remote_spinlock_lock_busy( lock_xp , &save_sr );
+
+    nolock_printk("\n********** scheduler state for core[%x,%d] **********************\n"
+           "kernel_threads = %d / user_threads = %d / current = %x\n",
+            local_cxy , core->lid, 
+            sched->k_threads_nr, sched->u_threads_nr, sched->current->trdid );
+
+    // display kernel threads
+    LIST_FOREACH( &sched->k_root , iter )
+    {
+        thread = LIST_ELEMENT( iter , thread_t , sched_list );
+        nolock_printk(" - type = %s / trdid = %x / pid = %x / func = %x / blocked_vect = %x\n",
+        thread_type_str( thread->type ), thread->trdid, thread->process->pid,
+        thread->entry_func, thread->blocked );
+    }
+
+    // display user threads
+    LIST_FOREACH( &sched->u_root , iter )
+    {
+        thread = LIST_ELEMENT( iter , thread_t , sched_list );
+        nolock_printk(" - type = %s / trdid = %x / pid = %x / func = %x / blocked_vect = %x\n",
+        thread_type_str( thread->type ), thread->trdid, thread->process->pid,
+        thread->entry_func, thread->blocked );
+    }
+
+    // release TXT0 lock
+    remote_spinlock_unlock_busy( lock_xp , save_sr );
+
+}  // end sched_display()
+

trunk/kernel/kern/scheduler.h

@@ -36 +36 @@
 /*********************************************************************************************
  * This structure define the scheduler associated to a given core.
- * WARNING : the idle thread is executed when there is no runable thread in the list 
- * of attached threads, but is NOT part of the list of attached threads.
  ********************************************************************************************/
 
@@ -78 +76 @@
  * This function handles pending signals for all registered threads, and tries to make 
  * a context switch for the core running the calling thread.
- * - If there is a runable thread (other than the current thread or the idle thread),
- *   the calling thread is descheduled, but its state is not modified.
+ * - If the <next> argument is not NULL, this next thread starts execution.
+ * - If <next> is NULL, it calls the sched_select() function. If there is a runable thread
+ *   (other than current thread or idle thread), this selected thread starts execution.
  * - If there is no other runable thread, the calling thread continues execution.
  * - If there is no runable thread, the idle thread is executed.
+ *********************************************************************************************
+ * @ next  : local pointer on next thread to run / call sched_select() if NULL.
  ********************************************************************************************/
-void sched_yield();
-
-/********************************************************************************************* 
- * This function handles pending signals for all registered threads, and make 
- * a context switch to the thread defined by the <thread> argument.
- * If the selected thread is not attached to the same core as the calling thread,
- * or is blocked, it causes a kernel panic.
- *********************************************************************************************
- * @ new   : local pointer on the thread to run.
- ********************************************************************************************/
-void sched_switch_to( struct thread_s * new );
+void sched_yield( struct thread_s * next );
 
 /*********************************************************************************************
@@ -130 +121 @@
 
 /********************************************************************************************* 
- * This function scan the list of kernel threads to find an idle (blocked) RPC thread.
- *********************************************************************************************
- * @ core    : local pointer on the core descriptor.
- * @ returns pointer on RPC thread descriptor / returns NULL if no idle RPC thread.
+ * This function display the internal state of the calling core scheduler.
  ********************************************************************************************/
-struct thread_s * sched_get_rpc_thead( struct core_s * core );
-
+void sched_display();
 
 

trunk/kernel/kern/thread.c

@@ -54 +54 @@
 char * thread_type_str( uint32_t type )
 {
-    if     ( type == THREAD_USER   ) return "USER";
+    if     ( type == THREAD_USER   ) return "USR";
     else if( type == THREAD_RPC    ) return "RPC";
     else if( type == THREAD_DEV    ) return "DEV";
-    else if( type == THREAD_KERNEL ) return "KERNEL";
-    else if( type == THREAD_IDLE   ) return "IDLE";
+    else if( type == THREAD_KERNEL ) return "KER";
+    else if( type == THREAD_IDLE   ) return "IDL";
     else                             return "undefined";
 }
@@ -199 +199 @@
 
         return 0;
-}
+
+} // end thread_init()
 
 /////////////////////////////////////////////////////////
@@ -309 +310 @@
     *new_thread = thread;
         return 0;
-}
+
+}  // end thread_user_create()
 
 //////////////////////////////////////////////
@@ -395 +397 @@
     *new_thread = thread;
         return 0;
-}
+
+}  // end thread_user_fork()
 
 /////////////////////////////////////////////////////////
@@ -407 +410 @@
         thread_t     * thread;       // pointer on new thread descriptor
 
-    thread_dmsg("\n[INFO] %s : enters for type %s in cluster %x\n",
-                __FUNCTION__ , thread_type_str( type ) , local_cxy );
+    thread_dmsg("\n[INFO] %s : enter / for type %s on core[%x,%d] / cycle %d\n",
+    __FUNCTION__ , thread_type_str( type ) , local_cxy , core_lid , hal_time_stamp() );
 
     assert( ( (type == THREAD_KERNEL) || (type == THREAD_RPC) ||
@@ -440 +443 @@
         hal_cpu_context_create( thread );
 
-    thread_dmsg("\n[INFO] %s : exit in cluster %x / trdid = %x / core_lid = %d\n",
-                 __FUNCTION__ , local_cxy , thread->trdid , core_lid );
+    thread_dmsg("\n[INFO] %s : exit / trdid = %x / type = %s / core = [%x,%d] / cycle %d\n",
+    __FUNCTION__ , thread->trdid , thread_type_str(type) , 
+    local_cxy , core_lid , hal_time_stamp() );
 
     *new_thread = thread;
         return 0;
-}
+
+} // end thread_kernel_create()
 
 ///////////////////////////////////////////////////
@@ -685 +690 @@
 
     // deschedule
-    sched_yield();
+    sched_yield( NULL );
     return 0;
 }
@@ -741 +746 @@
 
         // force scheduling
-        sched_yield();
+        sched_yield( NULL );
    }
 }