Enhance timer system to avoid double deregister

The bug reported was because the dbmon service audit timer was
overwritten accidentally, therefore no audit was performed so the
dbmon service was not actually being audit.

Major change is to enhance timer system to use global unique timer
id (not reused) to ensure timer is not double deregistered by 2
different mechanisms (disarm/deregister).
Change the timer id to 64 bit integer to ensure id never overflow.

Above change eliminates the double deregistering a timer issue which
could accidentally deregister a new timer that reuses the same id.

Also some cleaning to get rid of cases that could double deregister
timer (although it is no longer harmful as above mentioned change is
in place)

Change-Id: I2603870d2eb2749d78456e406095ae543353963f
Closes-Bug: 1837724
Signed-off-by: Bin Qian <bin.qian@windriver.com>
This commit is contained in:
Bin Qian 2019-08-07 14:00:11 -04:00
parent 72b6de9607
commit 3034fef823
11 changed files with 88 additions and 41 deletions

View File

@ -136,11 +136,12 @@ static bool sm_service_audit_timeout( SmTimerIdT timer_id, int64_t user_data )
return( false );
}
// timer to be disarmed after exit
service->action_timer_id = SM_TIMER_ID_INVALID;
if(( SM_SERVICE_ACTION_AUDIT_ENABLED != service->action_running )&&
( SM_SERVICE_ACTION_AUDIT_DISABLED != service->action_running ))
{
// timer will be deregistered after exit
service->action_timer_id = SM_TIMER_ID_INVALID;
DPRINTFE( "Service (%s) not running audit-enabled or audit-disabled "
"action.", service->name );
return( false );
@ -183,8 +184,6 @@ static bool sm_service_audit_timeout( SmTimerIdT timer_id, int64_t user_data )
}
service->action_running = SM_SERVICE_ACTION_NONE;
service->action_timer_id = SM_TIMER_ID_INVALID;
error = service_audit_result_handler( service, action_running,
action_result, service_state,
service_status, service_condition,
@ -436,6 +435,9 @@ static SmErrorT sm_service_audit_abort( SmServiceT* service )
return( error );
}
service->action_running = SM_SERVICE_ACTION_NONE;
service->action_pid = -1;
if( SM_TIMER_ID_INVALID != service->action_timer_id )
{
error = sm_timer_deregister( service->action_timer_id );
@ -449,8 +451,6 @@ static SmErrorT sm_service_audit_abort( SmServiceT* service )
}
}
service->action_running = SM_SERVICE_ACTION_NONE;
service->action_pid = -1;
service->action_timer_id = SM_TIMER_ID_INVALID;
service->action_attempts = 0;

View File

@ -119,15 +119,16 @@ static bool sm_service_disable_timeout( SmTimerIdT timer_id, int64_t user_data )
service = sm_service_table_read_by_id( id );
if( NULL == service )
{
// This means a bug elsewhere
DPRINTFE( "Failed to read service, error=%s.",
sm_error_str(SM_NOT_FOUND) );
return( false );
}
// timer to be disarmed after exit
service->action_timer_id = SM_TIMER_ID_INVALID;
if( SM_SERVICE_ACTION_DISABLE != service->action_running )
{
// timer will be deregistered after exit
service->action_timer_id = SM_TIMER_ID_INVALID;
DPRINTFE( "Service (%s) not running action (%s).", service->name,
sm_service_action_str( service->action_running ) );
return( false );
@ -171,7 +172,6 @@ static bool sm_service_disable_timeout( SmTimerIdT timer_id, int64_t user_data )
service->action_running = SM_SERVICE_ACTION_NONE;
service->action_pid = -1;
service->action_timer_id = SM_TIMER_ID_INVALID;
error = service_disable_result_handler( service, action_running,
action_result, service_state,

View File

@ -33,7 +33,7 @@ static bool sm_service_disabled_state_audit_timer( SmTimerIdT timer_id,
{
DPRINTFE( "Failed to read service %d, error=%s.",
id, sm_error_str(SM_NOT_FOUND) );
return( false );
return( true );
}
error = sm_service_fsm_event_handler( service->name,

View File

@ -204,6 +204,9 @@ static bool sm_service_enable_timeout( SmTimerIdT timer_id, int64_t user_data )
return( false );
}
// timer to be disarmed after exit
service->action_timer_id = SM_TIMER_ID_INVALID;
sm_service_enable_throttle_uncheck();
if( SM_SERVICE_ACTION_ENABLE != service->action_running )
@ -251,7 +254,6 @@ static bool sm_service_enable_timeout( SmTimerIdT timer_id, int64_t user_data )
service->action_running = SM_SERVICE_ACTION_NONE;
service->action_pid = -1;
service->action_timer_id = SM_TIMER_ID_INVALID;
error = service_enable_result_handler( service, action_running,
action_result, service_state,

View File

@ -33,7 +33,7 @@ static bool sm_service_enabled_active_state_audit_timer( SmTimerIdT timer_id,
{
DPRINTFE( "Failed to read service %d, error=%s.",
id, sm_error_str(SM_NOT_FOUND) );
return( false );
return( true );
}
error = sm_service_fsm_event_handler( service->name,

View File

@ -62,6 +62,9 @@ static bool sm_service_enabled_go_active_state_timeout_timer(
return( false );
}
// timer to be disarmed after exit
service->action_state_timer_id = SM_TIMER_ID_INVALID;
error = sm_service_fsm_event_handler( service->name,
SM_SERVICE_EVENT_GO_ACTIVE_TIMEOUT,
NULL, "overall go-active timeout" );
@ -69,12 +72,12 @@ static bool sm_service_enabled_go_active_state_timeout_timer(
{
DPRINTFE( "Failed to signal overall go-active timeout to service "
"(%s), error=%s.", service->name, sm_error_str( error ) );
return( true );
return( false );
}
DPRINTFI( "Service (%s) go-active overall timeout.", service->name );
return( true );
return( false );
}
// ****************************************************************************

View File

@ -33,6 +33,9 @@ static bool sm_service_enabled_go_standby_state_timeout_timer(
return( false );
}
// timer to be disarmed after exit
service->action_state_timer_id = SM_TIMER_ID_INVALID;
error = sm_service_fsm_event_handler( service->name,
SM_SERVICE_EVENT_GO_STANDBY_TIMEOUT,
NULL, "overall go-standby timeout" );
@ -40,12 +43,12 @@ static bool sm_service_enabled_go_standby_state_timeout_timer(
{
DPRINTFE( "Failed to signal overall go-standby timeout to service "
"(%s), error=%s.", service->name, sm_error_str( error ) );
return( true );
return( false );
}
DPRINTFI( "Service (%s) go-standby overall timeout.", service->name );
return( true );
return( false );
}
// ****************************************************************************

View File

@ -164,6 +164,8 @@ static bool sm_service_heartbeat_timer( SmTimerIdT timer_id, int64_t user_data )
if( SM_SERVICE_HEARTBEAT_STATE_STARTED != service_heartbeat.state )
{
// timer to be disarmed after exit
service_heartbeat.heartbeat_timer_id = SM_TIMER_ID_INVALID;
DPRINTFI( "Service (%s) heartbeat in the stopped state.",
service_heartbeat.name );
return( false );

View File

@ -50,6 +50,7 @@ typedef struct
int64_t user_data;
SmTimeT last_fired;
uint32_t total_fired;
char debug_info[200];
} SmTimerEntryT;
typedef struct
@ -67,6 +68,8 @@ typedef struct
SmTimerEntryT timers[SM_MAX_TIMERS];
} SmTimerThreadInfoT;
static SmTimerIdT _next_timer_id = 1;
static pthread_mutex_t _mutex = PTHREAD_MUTEX_INITIALIZER;
static SmTimerThreadInfoT _threads[SM_THREADS_MAX];
@ -94,8 +97,9 @@ static SmTimerThreadInfoT* sm_timer_find_thread_info( void )
// ****************************************************************************
// Timer - Register
// ================
SmErrorT sm_timer_register( const char name[], unsigned int ms,
SmTimerCallbackT callback, int64_t user_data, SmTimerIdT* timer_id )
SmErrorT _sm_timer_register( const char name[], unsigned int ms,
SmTimerCallbackT callback, int64_t user_data, SmTimerIdT* timer_id,
const char* func, const char* file, int line )
{
SmTimerEntryT* timer_entry;
SmTimerThreadInfoT* thread_info;
@ -123,7 +127,7 @@ SmErrorT sm_timer_register( const char name[], unsigned int ms,
timer_entry->timer_instance = ++thread_info->timer_instance;
snprintf( timer_entry->timer_name, sizeof(timer_entry->timer_name),
"%s", name );
timer_entry->timer_id = timer_i;
timer_entry->timer_id = __sync_fetch_and_add(&_next_timer_id, 1);
timer_entry->ms_interval = ms;
sm_time_get( &timer_entry->arm_timestamp );
timer_entry->callback = callback;
@ -140,9 +144,12 @@ SmErrorT sm_timer_register( const char name[], unsigned int ms,
abort();
}
*timer_id = timer_i;
*timer_id = timer_entry->timer_id;
DPRINTFD( "Created timer (name=%s, id=%i).", timer_entry->timer_name,
snprintf(timer_entry->debug_info, sizeof(timer_entry->debug_info),
"timer %li, %s, %s %i", *timer_id, func, file, line);
DPRINTFD( "Created timer (name=%s, id=%li).", timer_entry->timer_name,
timer_entry->timer_id );
return( SM_OKAY );
@ -152,13 +159,13 @@ SmErrorT sm_timer_register( const char name[], unsigned int ms,
// ****************************************************************************
// Timer - Deregister
// ==================
SmErrorT sm_timer_deregister( SmTimerIdT timer_id )
SmErrorT _sm_timer_deregister( SmTimerIdT timer_id,
const char* func, const char* file, int line )
{
SmTimerEntryT* timer_entry = NULL;
SmTimerThreadInfoT* thread_info;
if(( SM_TIMER_ID_INVALID == timer_id )||
( SM_MAX_TIMERS <= timer_id ))
if(( SM_TIMER_ID_INVALID == timer_id ) )
{
return( SM_OKAY );
}
@ -170,14 +177,35 @@ SmErrorT sm_timer_deregister( SmTimerIdT timer_id )
return( SM_FAILED );
}
timer_entry = &(thread_info->timers[timer_id]);
timer_entry->inuse = 0;
timer_entry->timer_instance = 0;
timer_entry->user_data = 0;
unsigned int timer_i;
bool found = false;
for( timer_i=0; SM_MAX_TIMERS > timer_i; ++timer_i )
{
timer_entry = &(thread_info->timers[timer_i]);
DPRINTFD( "Cancelled timer (name=%s, id=%i).", timer_entry->timer_name,
timer_entry->timer_id );
if( SM_TIMER_ENTRY_INUSE == timer_entry->inuse
&& timer_entry->timer_id == timer_id)
{
found = true;
break;
}
}
if(found)
{
timer_entry->inuse = 0;
timer_entry->timer_instance = 0;
timer_entry->user_data = 0;
timer_id = 0;
DPRINTFD( "Cancelled timer (name=%s, id=%li).", timer_entry->timer_name,
timer_entry->timer_id );
}
else
{
DPRINTFI("WARN: Timer %li is not in used (already disarmed?)", timer_id);
DPRINTFI("WARN: Attempted to deregister by %s %s:%i", func, file, line);
}
return( SM_OKAY );
}
// ****************************************************************************
@ -346,13 +374,13 @@ static void sm_timer_dispatch( int selobj, int64_t user_data )
if( rearm )
{
sm_time_get( &timer_entry->arm_timestamp );
DPRINTFD( "Timer (%i) rearmed.", timer_entry->timer_id );
DPRINTFD( "Timer (%li) rearmed.", timer_entry->timer_id );
} else {
timer_entry->inuse = 0;
DPRINTFD( "Timer (%i) removed.", timer_entry->timer_id );
DPRINTFD( "Timer (%li) removed.", timer_entry->timer_id );
}
} else {
DPRINTFD( "Timer (%i) instance changed since callback, "
DPRINTFD( "Timer (%li) instance changed since callback, "
"rearm=%d.", timer_entry->timer_id, (int) rearm );
}
@ -468,6 +496,7 @@ void sm_timer_dump_data( FILE* log )
char buffer[24];
fprintf( log, "--------------------------------------------------------------------\n" );
fprintf( log, "Next timer id %li\n", _next_timer_id );
int thread_i;
for( thread_i=0; SM_THREADS_MAX > thread_i; ++thread_i )
{
@ -487,13 +516,13 @@ void sm_timer_dump_data( FILE* log )
if( SM_TIMER_ENTRY_INUSE == timer_entry->inuse )
{
fprintf( log, " timer (name=%s, id=%i)\n", timer_entry->timer_name,
fprintf( log, " timer (name=%s, id=%li)\n", timer_entry->timer_name,
timer_entry->timer_id );
fprintf( log, " instance..........%" PRIu64 "\n", timer_entry->timer_instance );
fprintf( log, " ms_interval.......%i\n", timer_entry->ms_interval );
fprintf( log, " user_data.........%" PRIi64 "\n", timer_entry->user_data );
sm_time_format_monotonic_time(&timer_entry->arm_timestamp, buffer, sizeof(buffer));
fprintf( log, " timer created at .%s\n", buffer );
fprintf( log, " last armed at .%s\n", buffer );
sm_time_format_realtime(&timer_entry->last_fired, buffer, sizeof(buffer));
fprintf( log, " last fired at ....%s\n", buffer );
fprintf( log, " total fired ......%d\n", timer_entry->total_fired );

View File

@ -20,23 +20,31 @@ extern "C" {
#define SM_TIMER_ID_INVALID -1
typedef int SmTimerIdT;
typedef int64_t SmTimerIdT;
typedef bool (*SmTimerCallbackT) (SmTimerIdT timer_id, int64_t user_data );
// ****************************************************************************
// Timer - Register
// ================
extern SmErrorT sm_timer_register( const char name[], unsigned int ms,
SmTimerCallbackT callback, int64_t user_data, SmTimerIdT* timer_id );
extern SmErrorT _sm_timer_register( const char name[], unsigned int ms,
SmTimerCallbackT callback, int64_t user_data, SmTimerIdT* timer_id,
const char* func, const char* file, int line);
// ****************************************************************************
// ****************************************************************************
// Timer - Deregister
// ==================
extern SmErrorT sm_timer_deregister( SmTimerIdT timer_id );
extern SmErrorT _sm_timer_deregister( SmTimerIdT timer_id,
const char* func, const char* file, int line );
// ****************************************************************************
#define sm_timer_register( name, ms, callback, user_data, timer_id) \
_sm_timer_register( name, ms, callback, user_data, timer_id, __FUNCTION__, __FILE__, __LINE__ )
#define sm_timer_deregister( timer_id ) \
_sm_timer_deregister( timer_id, __FUNCTION__, __FILE__, __LINE__ )
// ****************************************************************************
// Timer - Scheduling On Time
// ==========================

View File

@ -284,7 +284,7 @@ SmErrorT sm_db_service_heartbeat_insert( SmDbHandleT* sm_db_handle,
snprintf( sql, sizeof(sql), "INSERT INTO %s ( %s, "
"%s, %s, %s, %s, %s, %s, %s, %s, %s, %s, %s, %s, %s, %s, %s ) "
"VALUES ('%s', '%s', '%s', '%s', '%i', '%s', '%i', '%s', "
"'%i', '%i', '%i', '%i', '%s', '%i', %i', '%i' );",
"'%i', '%i', '%i', '%i', '%s', '%i', %li', '%i' );",
SM_SERVICE_HEARTBEAT_TABLE_NAME,
SM_SERVICE_HEARTBEAT_TABLE_COLUMN_PROVISIONED,
SM_SERVICE_HEARTBEAT_TABLE_COLUMN_NAME,
@ -433,7 +433,7 @@ SmErrorT sm_db_service_heartbeat_update( SmDbHandleT* sm_db_handle,
record->missed );
}
len += snprintf( sql+len, sizeof(sql)-len, "%s = '%i', ",
len += snprintf( sql+len, sizeof(sql)-len, "%s = '%li', ",
SM_SERVICE_HEARTBEAT_TABLE_COLUMN_HEARTBEAT_TIMER_ID,
record->heartbeat_timer_id );