The ISR code is not of much interest, but I can post it. I can also show most of the call chain:
This is the ISR (the call to the callback function is done in the 3rd party library function nrf_modem_application_irq_handler() which I don’t have source code for but I can configure the name/pointer of the callback function):
void EGU1_IRQHandler( void )
{
nrf_modem_application_irq_handler();
BaseType_t higher_priority_task_woken = pdFALSE;
vTaskNotifyGiveFromISR( modem_obj.sleeping_task.handle, &higher_priority_task_woken );
portYIELD_FROM_ISR( higher_priority_task_woken );
}
This is the callback which is called by the ISR:
void ModemNotificationCb( const char * notification )
{
uint32_t i;
int32_t parameters[ 5 ];
char *result;
for ( i = 0; i < sizeof( modem_response ) / sizeof( char * ); i++ )
{
result = stristr( notification, modem_response[ i ] );
if ( result != NULL )
{
break;
}
}
if ( result != NULL )
{
switch ( i )
{
case 0: // CESQ: RSRP, RSRP Threshold, RSRQ, RSRQ Threshold
result = stristr( notification, ":" ) + 1;
sscanf( result, "%d, %d, %d, %d",
¶meters[ 0 ],
¶meters[ 1 ],
¶meters[ 2 ],
¶meters[ 3 ] );
Log.DebugPrint( "RSRP: %d dBm\tRSRP Threshold: %d\tRSRQ: %d dBm\tRSRQ Threshold: %d",
parameters[ 0 ] - 141,
parameters[ 1 ],
( parameters[ 2 ] - 40 ) / 2,
parameters[ 3 ] );
break;
case 1: // CSCON: a,b,c
result = stristr( notification, ":" ) + 1;
sscanf( result, "%d", ¶meters[ 0 ] );
Log.DebugPrint( "%s", parameters[ 0 ] == 1 ? "Connected" : "Idle" );
break;
case 2: // CEREG: a,"b","c",d,,,"e","f"
result = stristr( notification, ":" ) + 1;
sscanf( result, "%d", ¶meters[ 0 ] );
Log.DebugPrint( "%s", parameters[ 0 ] == 1 || parameters[ 0 ] == 5 ? "Registered" : "Not registered" );
if ( ( parameters[ 0 ] == 1 ) || ( parameters[ 0 ] == 5 ) )
{
Log.InfoPrint( "Modem is registered on %s network", parameters[ 0 ] == 1 ? "home" : "roaming" );
modem_obj.is_registered = true;
}
else
{
Log.InfoPrint( "Modem is unregistered" );
modem_obj.is_registered = false;
}
break;
case 3: // XOPNAME: "a","b","c"
break;
}
}
}
This is the last function in a chain for functions of the logger before the queue send to the log task (note the comment that points out the if statement that checks the context):
void log_LevelPrint( log_level_t log_level, const char *fmt, va_list args )
{
log_qmessage_t log_msg;
BaseType_t high_priority_task = pdFALSE;
vsnprintf( log_msg.data, LONG_MSG_MAX - 1, fmt, args );
log_msg.ticks = xTaskGetTickCount();
log_msg.log_level = log_level;
log_msg.handle = xTaskGetCurrentTaskHandle();
/* Use correct context to send to log queue */
if ( ( SCB->ICSR & SCB_ICSR_VECTACTIVE_Msk ) != 0 ) // In interrupt context
{
xQueueSendFromISR( app.GetLogHandle(), &log_msg, &high_priority_task );
/* Now the buffer is empty we can switch context if necessary. */
if ( high_priority_task )
{
portYIELD_FROM_ISR( high_priority_task );
}
}
else // In normal context
{
if ( xQueueSend( app.GetLogHandle(), &log_msg, pdMS_TO_TICKS( 100 ) ) != pdPASS )
{
/* Message failed to send */
}
}
}
Finally, the log task itself:
void log_Thread( void *parameter_ptr )
{
uint32_t i;
log_qmessage_t msg;
TickType_t msg_time = pdTICKS_TO_MS( xTaskGetTickCount() );
char time_buf[128];
twdt.Configure( TWDT_TIMEOUT );
#ifdef INIT_LOG_LEVEL
log_obj.log_level = INIT_LOG_LEVEL;
#else
log_obj.log_level = loglevel_info;
#endif
log_obj.task_list.type = logtask_all;
log_GetTimestamp( msg_time, time_buf );
printf( "[%-12s] <%s>: %s\r\n",
pcTaskGetName( xTaskGetCurrentTaskHandle() ), // Task name
time_buf, // Timestamp
"Log task started" ); // Message
for( ; ; )
{
twdt.Update();
/* Wait for the maximum period for data to become available on the queue.
* The period will be indefinite if INCLUDE_vTaskSuspend is set to 1 in
* FreeRTOSConfig.h.
*/
if( xQueueReceive( app.GetLogHandle(), &msg, pdMS_TO_TICKS( TWDT_TIMEOUT / 2 ) ) == pdPASS )
{
switch ( msg.log_level )
{
case loglevel_force:
printf( "%s", msg.data );
break;
case loglevel_task:
log_obj.task_list.type = msg.task_list.type;
for ( i = 0; i < LOG_MAX_LIST; i++ )
{
log_obj.task_list.handle[ i ] = msg.task_list.handle[ i ];
}
break;
default:
/* xLogMessage now contains the received data. */
msg_time = pdTICKS_TO_MS( msg.ticks );
if ( log_Show( msg ) )
{
log_GetTimestamp( msg_time, time_buf );
printf( "[%-12s] <%s>: %s\r\n",
pcTaskGetName( msg.handle ), // Task name
time_buf, // Timestamp
msg.data ); // Message
}
break;
}
}
}
}
The callback is no longer causing asserts which fixes the original problem. However, now when an unprivileged task in normal context calls the logger, I get a hard fault. Configuring the unprivileged task as privileged seems to solve this problem. Now, the problem is not as severe, but this means that every task that needs to print will have to be privileged. That is not good.