rearranging the verbose output of avrdude

[macsimski]

Hi all,

I want to start a discussion about a better format of the avrdude log format. It might that I am missing a simple solution to the parsing problems i have with the avrdude log format. my current problems are:

1. avrdude always ends with: Avrdude done. Thank you. regardless if there were errors or not. I think that a difference wound be handy to see at a glance if programming succeeded or not. now i have to view the whole log to see that.
2. I think it would be more clear if there was a visual space between te separate steps avrdude performs:
   now its:

avrdude: AVR device initialized and ready to accept instructions

Reading | ################################################## | 100% 0.00s

avrdude: Device signature = 0x1e940b (probably m168p)
avrdude: erasing chip
avrdude: reading input file "0xfc"
avrdude: writing efuse (1 bytes):

Writing | ################################################## | 100% 0.09s

avrdude: 1 bytes of efuse written
avrdude: verifying efuse memory against 0xfc:
avrdude: load data efuse data from input file 0xfc:
avrdude: input file 0xfc contains 1 bytes
avrdude: reading on-chip efuse data:

Reading | ################################################## | 100% 0.00s

avrdude: verifying ...
avrdude: 1 bytes of efuse verified
avrdude: reading input file "0xd5"
avrdude: writing hfuse (1 bytes):

Writing | ################################################## | 100% 0.09s

avrdude: 1 bytes of hfuse written
avrdude: verifying hfuse memory against 0xd5:
avrdude: load data hfuse data from input file 0xd5:
avrdude: input file 0xd5 contains 1 bytes
avrdude: reading on-chip hfuse data:

Reading | ################################################## | 100% 0.00s

avrdude: verifying ...
avrdude: 1 bytes of hfuse verified
avrdude: reading input file "0xe2"
avrdude: writing lfuse (1 bytes):

Writing | ################################################## | 100% 0.09s

avrdude: 1 bytes of lfuse written
avrdude: verifying lfuse memory against 0xe2:
avrdude: load data lfuse data from input file 0xe2:
avrdude: input file 0xe2 contains 1 bytes
avrdude: reading on-chip lfuse data:

Reading | ################################################## | 100% 0.00s

avrdude: verifying ...
avrdude: 1 bytes of lfuse verified

avrdude: safemode: Fuses OK (E:FC, H:D5, L:E2)

avrdude done.  Thank you.`

using 55 lines

Here my suggestion with visual spaces per item done:

avrdude: AVR device initialized and ready to accept instructions

Reading Device Signature
Reading | ################################################## | 100% 0.00s
avrdude: Device signature = 0x1e940b (probably m168p)

avrdude: erasing chip
Done

avrdude: reading input file "0xfc"
avrdude: writing efuse (1 bytes):
Writing | ################################################## | 100% 0.09s
avrdude: 1 bytes of efuse written
avrdude: verifying efuse memory against 0xfc:
avrdude: load data efuse data from input file 0xfc:
avrdude: input file 0xfc contains 1 bytes
avrdude: reading on-chip efuse data:
Reading | ################################################## | 100% 0.00s
avrdude: verifying ...
avrdude: 1 bytes of efuse verified

avrdude: reading input file "0xd5"
avrdude: writing hfuse (1 bytes):
Writing | ################################################## | 100% 0.09s
avrdude: 1 bytes of hfuse written
avrdude: verifying hfuse memory against 0xd5:
avrdude: load data hfuse data from input file 0xd5:
avrdude: input file 0xd5 contains 1 bytes
avrdude: reading on-chip hfuse data:
Reading | ################################################## | 100% 0.00s
avrdude: verifying ...
avrdude: 1 bytes of hfuse verified

avrdude: reading input file "0xe2"
avrdude: writing lfuse (1 bytes):
Writing | ################################################## | 100% 0.09s
avrdude: 1 bytes of lfuse written
avrdude: verifying lfuse memory against 0xe2:
avrdude: load data lfuse data from input file 0xe2:
avrdude: input file 0xe2 contains 1 bytes
avrdude: reading on-chip lfuse data:
Reading | ################################################## | 100% 0.00s
avrdude: verifying ...
avrdude: 1 bytes of lfuse verified

avrdude: safemode: Fuses OK (E:FC, H:D5, L:E2)

avrdude done.  Thank you.

taking 5 lines less.

maybe even including the original command (-Uefuse:w:0xfc:m) at the starting of the item.

This not only makes reading the logs easier, but alsohelps parsing the output in a script.

what are your ideas?

[mcuee]

I think it would be more clear if there was a visual space between te separate steps avrdude performs:

How do you define the steps here?

[macsimski]

like every step is a program-and-verify thing. so if for example you state on the command line to check a fuse, that's a step, of if you want to program a hex file, or set the high fuses, or the low fuses or erase the chip. now the spaces only separate the progress bars. that is superfluous as if it takes a short time, its over before you know, if it takes long, its the last line written on screen. but if things go wrong, it is quite difficult to find out what step of the program failed.

[stefanrueger]

see at a glance if programming succeeded or not

AVRDUDE exits with a non-zero value when things went wrong, and with 0 when it thinks all went well. Try adding && echo OK or || echo Trouble to the shell command line. My favourite programming quells many of the (for me) unnecessary comments:

$ avrdude -qqc urclock -U blink.hex && echo OK
OK

$ avrdude -qqc urclock -U trouble.hex && echo OK
avrdude OS error: file trouble.hex is not readable: No such file or directory

$ avrdude -qqc urclock -U blank.hex && echo OK
avrdude error: input would overwrite the reset vector bricking the bootloader
        using -F will try to patch the input but this may not be what is needed

Only when things go wrong (not seeing OK and/or error messages) do I investigate with fewer -q and more -v.

spaces only separate the progress bars. that is superfluous

Correct. Git mainline already has removed the empty lines. Try the newest to see how you like that.

succeeded or not. now i have to view the whole log to see that

Usually AVRDUDE stops when something goes wrong and usually AVRDUDE is quite good in saying what went wrong. So if the twelfth of your seventeen -U steps goes wrong it says so and stops. That means errors should appear near the end.

I realise you may want more explicit reassurance than you would get with -qq, but try various -q and -v combos and/or the && echo OK trick to see if you find something that you like.

[stefanrueger]

difficult to find out what step of the program failed

PR #1373 implements option -T cmd that, like -U, could be considered a step of programming the part. That PR experiments with the idea of giving each -T and -U processing its own paragraph headed by avrdude: processing [-T cmd | -U memory operation]. @macsimski give it a try and see what you think.

[stefanrueger]

By and large this idea has been implemented, hence closing the discussion.

[macsimski]

Thank you! I have not been able to test it yet, but it looks promising.

keep up the good work!