diff mbox

[U-Boot,3/7] Add timing information to printf's for use with bootgraph.pl

Message ID 1314829261-13996-4-git-send-email-amurray@theiet.org
State Superseded
Headers show

Commit Message

Andrew Murray Aug. 31, 2011, 10:20 p.m. UTC
From: Andrew Murray <amurray@mpcdata.com>

This patch adds timings information to printfs.

Signed-off-by: Andrew Murray <amurray@theiet.org>
---
 common/console.c |   12 +++++++++++-
 1 files changed, 11 insertions(+), 1 deletions(-)

Comments

Mike Frysinger Aug. 31, 2011, 10:47 p.m. UTC | #1
On Wednesday, August 31, 2011 18:20:57 Andrew Murray wrote:
>  	va_list args;
>  	uint i;
>  	char printbuffer[CONFIG_SYS_PBSIZE];
> +	char *buf = printbuffer;
> 
>  	va_start(args, fmt);
> 
> +#if defined(CONFIG_BOOT_TRACE)
> +	unsigned long long ticks = get_ticks();
> +	int secs = ticks / get_tbclk();
> +	int msec = ((ticks * 1000000) / get_tbclk()) - (secs * 1000000);
> +
> +	i += sprintf(buf, "[%5lu.%06lu] ", secs, msec);
> +	buf += i;
> +#endif
> +
>  	/* For this to work, printbuffer must be larger than
>  	 * anything we ever want to print.
>  	 */
> -	i = vsprintf(printbuffer, fmt, args);
> +	i += vsprintf(buf, fmt, args);
>  	va_end(args);

NAK for a few reasons:
 - i dont see how this could possibly compile warning free
 - you never initialize "i", only added to it
 - you call va_start() inbetween variable decls
-mike
Andrew Murray Aug. 31, 2011, 11:30 p.m. UTC | #2
On 31 August 2011 23:47, Mike Frysinger <vapier@gentoo.org> wrote:
> On Wednesday, August 31, 2011 18:20:57 Andrew Murray wrote:
>>       va_list args;
>>       uint i;
>>       char printbuffer[CONFIG_SYS_PBSIZE];
>> +     char *buf = printbuffer;
>>
>>       va_start(args, fmt);
>>
>> +#if defined(CONFIG_BOOT_TRACE)
>> +     unsigned long long ticks = get_ticks();
>> +     int secs = ticks / get_tbclk();
>> +     int msec = ((ticks * 1000000) / get_tbclk()) - (secs * 1000000);
>> +
>> +     i += sprintf(buf, "[%5lu.%06lu] ", secs, msec);
>> +     buf += i;
>> +#endif
>> +
>>       /* For this to work, printbuffer must be larger than
>>        * anything we ever want to print.
>>        */
>> -     i = vsprintf(printbuffer, fmt, args);
>> +     i += vsprintf(buf, fmt, args);
>>       va_end(args);
>
> NAK for a few reasons:
>  - i dont see how this could possibly compile warning free
>  - you never initialize "i", only added to it
>  - you call va_start() inbetween variable decls
> -mike
>

Yes this does look dreadful - I'll update the patch pending outcome of
thread with Simon Glass and existing work in this area.

Andrew Murray
Graeme Russ Aug. 31, 2011, 11:38 p.m. UTC | #3
Hi Mike, Andrew,

On Thu, Sep 1, 2011 at 8:47 AM, Mike Frysinger <vapier@gentoo.org> wrote:
> On Wednesday, August 31, 2011 18:20:57 Andrew Murray wrote:
>>       va_list args;
>>       uint i;
>>       char printbuffer[CONFIG_SYS_PBSIZE];
>> +     char *buf = printbuffer;
>>
>>       va_start(args, fmt);
>>
>> +#if defined(CONFIG_BOOT_TRACE)
>> +     unsigned long long ticks = get_ticks();
>> +     int secs = ticks / get_tbclk();
>> +     int msec = ((ticks * 1000000) / get_tbclk()) - (secs * 1000000);
>> +
>> +     i += sprintf(buf, "[%5lu.%06lu] ", secs, msec);
>> +     buf += i;
>> +#endif
>> +
>>       /* For this to work, printbuffer must be larger than
>>        * anything we ever want to print.
>>        */
>> -     i = vsprintf(printbuffer, fmt, args);
>> +     i += vsprintf(buf, fmt, args);
>>       va_end(args);
>
> NAK for a few reasons:
>  - i dont see how this could possibly compile warning free
>  - you never initialize "i", only added to it
>  - you call va_start() inbetween variable decls

And correct me if I'm wrong, but EVERY printf() will get the timing info
tacked on - Even the ones without \n which are intermediate prints in
larger messages which is going to lead to very ugly outputs

I think instead we should look at another 'printf() with timestamp'
function which can be used on an as-needed basis

Regards,

Graeme
Andrew Murray Aug. 31, 2011, 11:42 p.m. UTC | #4
On 1 September 2011 00:38, Graeme Russ <graeme.russ@gmail.com> wrote:
> Hi Mike, Andrew,
>
> On Thu, Sep 1, 2011 at 8:47 AM, Mike Frysinger <vapier@gentoo.org> wrote:
>> On Wednesday, August 31, 2011 18:20:57 Andrew Murray wrote:
>>>       va_list args;
>>>       uint i;
>>>       char printbuffer[CONFIG_SYS_PBSIZE];
>>> +     char *buf = printbuffer;
>>>
>>>       va_start(args, fmt);
>>>
>>> +#if defined(CONFIG_BOOT_TRACE)
>>> +     unsigned long long ticks = get_ticks();
>>> +     int secs = ticks / get_tbclk();
>>> +     int msec = ((ticks * 1000000) / get_tbclk()) - (secs * 1000000);
>>> +
>>> +     i += sprintf(buf, "[%5lu.%06lu] ", secs, msec);
>>> +     buf += i;
>>> +#endif
>>> +
>>>       /* For this to work, printbuffer must be larger than
>>>        * anything we ever want to print.
>>>        */
>>> -     i = vsprintf(printbuffer, fmt, args);
>>> +     i += vsprintf(buf, fmt, args);
>>>       va_end(args);
>>
>> NAK for a few reasons:
>>  - i dont see how this could possibly compile warning free
>>  - you never initialize "i", only added to it
>>  - you call va_start() inbetween variable decls
>
> And correct me if I'm wrong, but EVERY printf() will get the timing info
> tacked on - Even the ones without \n which are intermediate prints in
> larger messages which is going to lead to very ugly outputs
>
> I think instead we should look at another 'printf() with timestamp'
> function which can be used on an as-needed basis

Yes that's exactly the case ... e.g.

[    3.122000] initcall 0x9ff864cc returned
[    3.126000] calling  0x9ff78174
[    3.129000] ## Booting kernel from Legacy Image at 82000000 ...
[    3.135000]    Image Name:   Angstrom/2.6.32/beagleboard
[    3.141000]    Image Type:   [    3.143000] ARM Linux Kernel Image
(uncompressed)
[    3.148000]    Data Size:    [    3.151000] 3194192 Bytes = [
3.154000] 3[    3.155000]
MiB

It's certainty ugly. A dedicated printf seems very sensible.

Andrew Murray
Wolfgang Denk Sept. 7, 2011, 9:10 p.m. UTC | #5
Dear Mike Frysinger,

In message <201108311847.16042.vapier@gentoo.org> you wrote:
>
> NAK for a few reasons:
>  - i dont see how this could possibly compile warning free
>  - you never initialize "i", only added to it
>  - you call va_start() inbetween variable decls

Could you _please_ accustom yourself to updating the status in
patchwork to "changes requested"  when sending revierw comments like
here?


I think I asked this a couple of times before...

Best regards,

Wolfgang Denk
Mike Frysinger Sept. 9, 2011, 12:50 a.m. UTC | #6
On Wednesday, September 07, 2011 17:10:03 Wolfgang Denk wrote:
> Mike Frysinger wrote:
> > NAK for a few reasons:
> >  - i dont see how this could possibly compile warning free
> >  - you never initialize "i", only added to it
> >  - you call va_start() inbetween variable decls
> 
> Could you _please_ accustom yourself to updating the status in
> patchwork to "changes requested"  when sending revierw comments like
> here?

be nice if patchwork itself would key off a tag we could use in our e-mails 
and auto set the status ...
-mike
Wolfgang Denk Sept. 9, 2011, 7 a.m. UTC | #7
Dear Mike Frysinger,

In message <201109082050.51313.vapier@gentoo.org> you wrote:
>
> > Could you _please_ accustom yourself to updating the status in
> > patchwork to "changes requested"  when sending revierw comments like
> > here?
>
> be nice if patchwork itself would key off a tag we could use in our e-mails
> and auto set the status ...

Patchwork offers sufficient features to do this; you just have to use
the right tools.

For example, I am using exmh as MUA; this is MH based (well, actuallny
nmh these days) and has the nice feature that each message is a
separate file, so I can easily run any standard tools on a specific
message.  I have added a custom button to exmh which will run the
command

	pw_update 'Changes Requested' $file

with $file holding the file name of the current message.

Script pw_update looks about like this:

---------------------------------------------------------
#!/bin/bash -e

# pwparser.py reads from stdin
hash=$(/home/wd/bin/pwparser.py --hash) <$2
pwclient update -s $1 -h $hash
---------------------------------------------------------

(pwparser.py coming from git/patchwork/apps/patchwork/parser.py)

Feel free to adapt to your favorite MUA...

Best regards,

Wolfgang Denk
diff mbox

Patch

diff --git a/common/console.c b/common/console.c
index 8c650e0..33de3fa 100644
--- a/common/console.c
+++ b/common/console.c
@@ -370,13 +370,23 @@  int printf(const char *fmt, ...)
 	va_list args;
 	uint i;
 	char printbuffer[CONFIG_SYS_PBSIZE];
+	char *buf = printbuffer;
 
 	va_start(args, fmt);
 
+#if defined(CONFIG_BOOT_TRACE)
+	unsigned long long ticks = get_ticks();
+	int secs = ticks / get_tbclk();
+	int msec = ((ticks * 1000000) / get_tbclk()) - (secs * 1000000);
+
+	i += sprintf(buf, "[%5lu.%06lu] ", secs, msec);
+	buf += i;
+#endif
+
 	/* For this to work, printbuffer must be larger than
 	 * anything we ever want to print.
 	 */
-	i = vsprintf(printbuffer, fmt, args);
+	i += vsprintf(buf, fmt, args);
 	va_end(args);
 
 	/* Print the string */