Stdout console clogging => 300ms blocked

[Willaert, Bernard]

System details:
Freescale MPC8347 at 200MHz
Kernel 2.6.18

Problem:
When we log debug output via the serial console on a multithreaded
application, the console throughput may get clogged and then we
experience a >300ms deadlock.

Quick and dirty test program: threadtest.c:
//----------------------------------------------------------------------
-------------------------
#include <pthread.h>
#include <stdio.h>
#include <sys/time.h>

#define THREAD_DELAY 1000

void* thread_1(void* unused)
{
	while (1)
	{
		usleep(THREAD_DELAY);
		fprintf(stdout," <----- thread 1\n");
	}
	return NULL;
}

void* thread_2(void* unused)
{
	static long ts_old;
	long ts;
	struct timeval tv;

	while (1)
	{
		usleep(THREAD_DELAY);
		fprintf(stdout," <----- thread 2\n");

		gettimeofday (&tv, NULL);
		ts = (tv.tv_sec * 1000L) + (tv.tv_usec / 1000L);
		if ((ts - ts_old) > 100)
		{
			fprintf(stdout, "!!!!!!!!!!! thread2 interval
timeout = %d ms\n",(int)(ts - ts_old));
		}
		ts_old = ts;
	}
	return NULL;			

}



int main()
{
	pthread_t pthread_id_1, pthread_id_2;
	
	pthread_create(&pthread_id_1,NULL,&thread_1,NULL);
	pthread_create(&pthread_id_2,NULL,&thread_2,NULL);
	while (1)
	{
	}
	return 0;

}

//----------------------------------------------------------------------
-------------------------

Build command on our platform: 
powerpc-linux-uclibc-gcc threadtest.c  -lpthread -o threadtest
Execute: ./threadtest > /dev/console &

Uboot settings for the serial console:
consoledev=ttyS0
baudrate=115200
stdin=serial
stdout=serial
stderr=serial
boot_go=setenv bootargs console=$consoledev,$baudrate $args_rtc
$args_mtd $args_nfs $args_debug;bootm $addr_kernel $addr_root $addr_dtb


Expected output [snippet] on the console:
.... /\ ........
 <----- thread 1
 <----- thread 2
 <----- thread 1
 <----- thread 2
 <----- thread 1
 <----- thread 2
 <----- thread 1
 <----- thread 2
 <----- thread 1
 <----- thread 2
 <----- thread 1
.... /\ ........

Real output on the console:

.... /\ ........
 <----- thread 1
 <----- thread 2
 <----- thread 1
 <----- thread 2
 <----- thread 1
 <----- thread 2
!!!!!!!!!!! thread2 interval timeout = 335 ms
 <----- thread 1
 <----- thread 2
 <----- thread 1
 <----- thread 2
 <----- thread 1
.... /\ ........ 

This timeout shows up around every second and has always about the same
value of 335 ms.
Can somebody reproduce this behaviour ( the console speed and/or thread
interval may have to be tweaked to clog the serial output) ?
Thank you in advance for your help.
Bernard




-----------------------------------------------------------
Bernard Willaert
Software Development Engineer Modality OEM Solutions
BARCO Medical Imaging Division
President Kennedypark 35 - B-8500 KORTRIJK - BELGIUM
Tel.  +32 56 233 439  Fax +32 56 233 457
www.barco.com/medical
mailto:bernard.willaert at barco.com





DISCLAIMER:
Unless indicated otherwise, the information contained in this message is privileged and confidential, and is intended only for the use of the addressee(s) named above and others who have been specifically authorized to receive it. If you are not the intended recipient, you are hereby notified that any dissemination, distribution or copying of this message and/or attachments is strictly prohibited. The company accepts no liability for any damage caused by any virus transmitted by this email. Furthermore, the company does not warrant a proper and complete transmission of this information, nor does it accept liability for any delays. If you have received this message in error, please contact the sender and delete the message. Thank you.
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.ozlabs.org/pipermail/linuxppc-dev/attachments/20071002/6cd4fb90/attachment.htm>