search

avrdudes / avrdude

AVRDUDE is a utility to program AVR microcontrollers
GNU General Public License v2.0
696 stars 136 forks source link

Mixing the progress bar with warning messages #1136

Closed mcuee closed 1 year ago

mcuee commented 1 year ago

From here by @stefanrueger https://github.com/avrdudes/avrdude/pull/1125#issuecomment-1280512460

Mixing the progress bar with warning messages is a really hard task: I have added code elsewhere that aborts progress bars on fatal errors, but I have no easy fix for this kind of thing outlined here. Maybe that is one of those things that we need to come back to when there is more time?

I agree this is a low priority.

My simple fix is to add a return after the time. But if that is not accepted, at least adding a space is required.

mcuee commented 1 year ago

Just some reference output from current git main.

Case 1: it is quite okay, but a space would be good to add after the time. But personally I still prefer a return, which may not look as nice but it fits other cases better.

PS C:\work\avr\avrdude_test\avrdude_bin> .\avrdude_git -c usbasp -p t85 -qq -U .\hex2\gemma_v1.hex
PS C:\work\avr\avrdude_test\avrdude_bin> .\avrdude_git -c arduino_gemma -p t85 -U .\hex2\Blink.ino.gemma.hex

avrdude_git: AVR device initialized and ready to accept instructions

Reading | ################################################## | 100% 0.01s

avrdude_git: device signature = 0x1e930b (probably t85)
avrdude_git: Note: flash memory has been specified, an erase cycle will be performed.
             To disable this feature, specify the -D option.
erasing chip
avrdude_git: reading input file .\hex2\Blink.ino.gemma.hex for flash
             with 682 bytes in 1 section within [0, 0x2a9]
             using 11 pages and 22 pad bytes
avrdude_git: writing 682 bytes flash ...

Writing | #####                                              | 9% 0.02savrdude_git: 6 retries during SPI command
Writing | #########                                          | 18% 0.04savrdude_git: 7 retries during SPI command
Writing | ##############                                     | 27% 0.06savrdude_git: 7 retries during SPI command
Writing | ##################                                 | 36% 0.08savrdude_git: 7 retries during SPI command
Writing | #######################                            | 45% 0.10savrdude_git: 6 retries during SPI command
Writing | ###########################                        | 54% 0.12savrdude_git: 6 retries during SPI command
Writing | ################################                   | 63% 0.14savrdude_git: 7 retries during SPI command
Writing | ####################################               | 72% 0.16savrdude_git: 6 retries during SPI command
Writing | #########################################          | 81% 0.18savrdude_git: 7 retries during SPI command
Writing | #############################################      | 90% 0.20savrdude_git: 7 retries during SPI command
Writing | ################################################## | 100% 0.22s

avrdude_git: 682 bytes of flash written
avrdude_git: verifying flash memory against .\hex2\Blink.ino.gemma.hex

Reading | ################################################## | 100% 0.05s

avrdude_git: 682 bytes of flash verified

avrdude_git done.  Thank you.

Adding a return.

Writing | #####                                              | 9% 0.02s
avrdude_git: 6 retries during SPI command
Writing | #########                                          | 18% 0.04s
avrdude_git: 7 retries during SPI command
Writing | ##############                                     | 27% 0.06s
avrdude_git: 7 retries during SPI command
Writing | ##################                                 | 36% 0.08s
avrdude_git: 7 retries during SPI command
Writing | #######################                            | 45% 0.10s
avrdude_git: 6 retries during SPI command
Writing | ###########################                        | 54% 0.12s
avrdude_git: 6 retries during SPI command
Writing | ################################                   | 63% 0.14s
avrdude_git: 7 retries during SPI command
Writing | ####################################               | 72% 0.16s
avrdude_git: 6 retries during SPI command
Writing | #########################################          | 81% 0.18s
avrdude_git: 7 retries during SPI command
Writing | #############################################      | 90% 0.20s
avrdude_git: 7 retries during SPI command
Writing | ################################################## | 100% 0.22s
mcuee commented 1 year ago

Case 2: I think return is better here.

$ ./avrdude -cserialupdi -patmega4808 -e

avrdude: UPDI link initialization OK
avrdude: Device is locked
avrdude: NVM type 0: 16-bit, page oriented write
avrdude: Entering NVM programming mode
avrdude: Timeout waiting for device to unlock
avrdude: Failed to enter NVM programming mode: device is locked
avrdude: AVR device initialized and ready to accept instructions

Reading |                                                    | 0% 0.00savrdude: error reading signature data for part "ATmega4808", rc=-3
avrdude: Received FamilyID: "megaAVR"
avrdude: erasing chip

Reading | ################################################## | 100% 0.02s

avrdude: Device signature = 0x1e9650 (probably m4808)
avrdude: Leaving NVM programming mode

avrdude done.  Thank you.

Adding a return.

Reading |                                                    | 0% 0.00s
avrdude: error reading signature data for part "ATmega4808", rc=-3
avrdude: Received FamilyID: "megaAVR"
avrdude: erasing chip

Reading | ################################################## | 100% 0.02s
mcuee commented 1 year ago

Case 3: I think return is better here. Without adding the return it is a bit messy.

Adding a return.

$ echo "Hello World" | ./avrdude -cjtag2updi -pavr128da32 -Ueeprom:w:-:r

avrdude: AVR device initialized and ready to accept instructions

Reading | ################################################## | 100% 0.03s

avrdude: Device signature = 0x1e9709 (probably avr128da32)
avrdude: reading input file <stdin> for eeprom
avrdude: writing 12 bytes eeprom ...

Writing |                                                    | 0% 0.00s
avrdude: jtagmkII_write_byte(): bad response to write memory command: RSP_ILLEGAL_MCU_STATE
 ***failed;  
Writing | ####                                               | 8% 0.02s
avrdude: jtagmkII_write_byte(): bad response to write memory command: RSP_ILLEGAL_MCU_STATE
 ***failed;  
Writing | ########                                           | 16% 0.02s
avrdude: jtagmkII_write_byte(): bad response to write memory command: RSP_ILLEGAL_MCU_STATE
 ***failed;  
Writing | #############                                      | 25% 0.03s
avrdude: jtagmkII_write_byte(): bad response to write memory command: RSP_ILLEGAL_MCU_STATE
 ***failed;  
Writing | #################                                  | 33% 0.03s
avrdude: jtagmkII_write_byte(): bad response to write memory command: RSP_ILLEGAL_MCU_STATE
 ***failed;  
Writing | #####################                              | 41% 0.04s
avrdude: jtagmkII_write_byte(): bad response to write memory command: RSP_ILLEGAL_MCU_STATE
 ***failed;  
Writing | #########################                          | 50% 0.04s
avrdude: jtagmkII_write_byte(): bad response to write memory command: RSP_ILLEGAL_MCU_STATE
 ***failed;  
Writing | #############################                      | 58% 0.05s
avrdude: jtagmkII_write_byte(): bad response to write memory command: RSP_ILLEGAL_MCU_STATE
 ***failed;  
Writing | #################################                  | 66% 0.06s
avrdude: jtagmkII_write_byte(): bad response to write memory command: RSP_ILLEGAL_MCU_STATE
 ***failed;  
Writing | ######################################             | 75% 0.06s
avrdude: jtagmkII_write_byte(): bad response to write memory command: RSP_ILLEGAL_MCU_STATE
 ***failed;  
Writing | ##########################################         | 83% 0.07s
avrdude: jtagmkII_write_byte(): bad response to write memory command: RSP_ILLEGAL_MCU_STATE
 ***failed;  
Writing | ##############################################     | 91% 0.07s
avrdude: jtagmkII_write_byte(): bad response to write memory command: RSP_ILLEGAL_MCU_STATE
 ***failed;  
Writing | ################################################## | 100% 0.08s

avrdude: 12 bytes of eeprom written
avrdude: verifying eeprom memory against <stdin>

Reading | ################################################## | 100% 0.09s

avrdude: verification error, first mismatch at byte 0x0000
         0xff != 0x48
avrdude: verification error; content mismatch

avrdude done.  Thank you.
stefanrueger commented 1 year ago

Case 1: Adding a space after the time is OK and easy, but adding a return is difficult because it would need to be added before all potential error messages. I also advocate a space before the unit s, as is usual in scientific writing (10 s, not 10s; 12 MHz, not 12MHz; but it remains 12% though).

Case 2: I would suggest to not engage in a progress report for small memories of less than 32 bytes size (fuses, calibration, signature, ...). What is the benefit of a racing progress bar, saying three signature bytes could be read within 0 ms? That can be done relatively easily, I think. Or maybe only show progress bar on -vv for small memories?

Case 3: We should repair jtag2updi ;)

mcuee commented 1 year ago

Case 1: Adding a space after the time is OK and easy, but adding a return is difficult because it would need to be added before all potential error messages. I also advocate a space before the unit s, as is usual in scientific writing (10 s, not 10s; 12 MHz, not 12MHz; but it remains 12% though).

I am okay with your solution.

Case 2: I would suggest to not engage in a progress report for small memories of less than 32 bytes size (fuses, calibration, signature, ...). What is the benefit of a racing progress bar, saying three signature bytes could be read within 0 ms? That can be done relatively easily, I think. Or maybe only show progress bar on -vv for small memories?

I think it is good not to show any progress report for small memories.

Case 3: We should repair jtag2updi ;)

Haha, jtag2updi latest FW is okay. It is just my two boards (official Arduino Nano Every and "Nano Every 4808" clone) do not use the official jtag2updi FW but their own broken FW implementations.

So no problem for Case 3 here. Just the space will do.

stefanrueger commented 1 year ago

I pushed a commit onto PR #1132; you can try out Case 1 and Case 2 there; easy to undo if you (or others) don't like the new look and feel.

mcuee commented 1 year ago

Case 1 looks pretty good now.

PS C:\work\avr\avrdude_test\avrdude_bin> .\avrdude_pr1132v2 -c arduino_gemma -p t85 -D -U .\hex2\Blink.ino.gemma.hex

avrdude_pr1132v2: AVR device initialized and ready to accept instructions
avrdude_pr1132v2: device signature = 0x1e930b (probably t85)
avrdude_pr1132v2: reading input file .\hex2\Blink.ino.gemma.hex for flash
                  with 682 bytes in 1 section within [0, 0x2a9]
                  using 11 pages and 22 pad bytes
avrdude_pr1132v2: writing 682 bytes flash ...

Writing | #####                                              | 9% 0.01 s avrdude_pr1132v2: 5 retries during SPI command
Writing | #########                                          | 18% 0.03 s avrdude_pr1132v2: 6 retries during SPI command
Writing | ##############                                     | 27% 0.05 s avrdude_pr1132v2: 7 retries during SPI command
Writing | ##################                                 | 36% 0.07 s avrdude_pr1132v2: 6 retries during SPI command
Writing | #######################                            | 45% 0.09 s avrdude_pr1132v2: 7 retries during SPI command
Writing | ###########################                        | 54% 0.11 s avrdude_pr1132v2: 6 retries during SPI command
Writing | ################################                   | 63% 0.13 s avrdude_pr1132v2: 6 retries during SPI command
Writing | ####################################               | 72% 0.15 s avrdude_pr1132v2: 7 retries during SPI command
Writing | #########################################          | 81% 0.17 s avrdude_pr1132v2: 6 retries during SPI command
Writing | #############################################      | 90% 0.19 s avrdude_pr1132v2: 7 retries during SPI command
Writing | ################################################## | 100% 0.21 s

avrdude_pr1132v2: 682 bytes of flash written
avrdude_pr1132v2: verifying flash memory against .\hex2\Blink.ino.gemma.hex

Reading | ################################################## | 100% 0.05 s

avrdude_pr1132v2: 682 bytes of flash verified

avrdude_pr1132v2 done.  Thank you.
mcuee commented 1 year ago

Case 2 is also working as expected and much better than git main.

PS C:\work\avr\avrdude_test\avrdude_bin> .\avrdude_git -csnap_updi -patmega4808

             Vtarget                      : 4.74 V
             JTAG clock megaAVR/program   : 1000 kHz
             JTAG clock megaAVR/debug     : 100 kHz
             PDI/UPDI clock Xmega/megaAVR : 100 kHz
avrdude_git: AVR device initialized and ready to accept instructions

Reading |                                                    | 0% 0.00savrdude_git error: device is locked; chip erase required to unlock
avrdude_git error: unable to read byte at address 0x0000
avrdude_git error: read operation failed for memory signature
avrdude_git error: unable to read signature data for part ATmega4808, rc=-3
avrdude_git: received FamilyID: "megaAVR"
            double check chip or use -F to override this check

avrdude_git done.  Thank you.

PS C:\work\avr\avrdude_test\avrdude_bin> .\avrdude_pr1132v2 -csnap_updi -patmega4808

                  Vtarget                      : 4.74 V
                  JTAG clock megaAVR/program   : 1000 kHz
                  JTAG clock megaAVR/debug     : 100 kHz
                  PDI/UPDI clock Xmega/megaAVR : 100 kHz
avrdude_pr1132v2: AVR device initialized and ready to accept instructions
avrdude_pr1132v2 error: device is locked; chip erase required to unlock
avrdude_pr1132v2 error: unable to read byte at address 0x0000
avrdude_pr1132v2 error: read operation failed for memory signature
avrdude_pr1132v2 error: unable to read signature data for part ATmega4808, rc=-3
avrdude_pr1132v2: received FamilyID: "megaAVR"
                 double check chip or use -F to override this check

avrdude_pr1132v2 done.  Thank you.

PS C:\work\avr\avrdude_test\avrdude_bin> .\avrdude_pr1132v2 -csnap_updi -patmega4808 -vv

avrdude_pr1132v2: Version 7.0-20221019 (5eb81a8)
                  Copyright (c) Brian Dean, http://www.bdmicro.com/
                  Copyright (c) Joerg Wunsch

                  System wide configuration file is C:\work\avr\avrdude_test\avrdude_bin\avrdude.conf

                  Using Port                    : usb
                  Using Programmer              : snap_updi
avrdude_pr1132v2: jtag3_open_updi()
avrdude_pr1132v2: HV UPDI support: 1
avrdude_pr1132v2: found CMSIS-DAP compliant device, using EDBG protocol
avrdude_pr1132v2: jtag3_edbg_prepare(): connection status 0x01
avrdude_pr1132v2: sending sign-on command: 0x80 (3 bytes msg)
                  AVR Part                      : ATmega4808
                  RESET disposition             : dedicated
                  RETRY pulse                   : SCK
                  Serial program mode           : yes
                  Parallel program mode         : yes
                  Memory Detail                 :

                                                    Block Poll               Page                       Polled
                    Memory Type Alias    Mode Delay Size  Indx Paged  Size   Size #Pages MinW  MaxW   ReadBack
                    ----------- -------- ---- ----- ----- ---- ------ ------ ---- ------ ----- ----- ---------
                    fuse0       wdtcfg      0     0     0    0 no          1    1      0     0     0 0x00 0x00
                    fuse1       bodcfg      0     0     0    0 no          1    1      0     0     0 0x00 0x00
                    fuse2       osccfg      0     0     0    0 no          1    1      0     0     0 0x00 0x00
                    fuse4       tcd0cfg     0     0     0    0 no          1    1      0     0     0 0x00 0x00
                    fuse5       syscfg0     0     0     0    0 no          1    1      0     0     0 0x00 0x00
                    fuse6       syscfg1     0     0     0    0 no          1    1      0     0     0 0x00 0x00
                    fuse7       append      0     0     0    0 no          1    1      0     0     0 0x00 0x00
                    fuse8       bootend     0     0     0    0 no          1    1      0     0     0 0x00 0x00
                    fuses                   0     0     0    0 no          9   10      0     0     0 0x00 0x00
                    lock                    0     0     0    0 no          1    1      0     0     0 0x00 0x00
                    tempsense               0     0     0    0 no          2    1      0     0     0 0x00 0x00
                    signature               0     0     0    0 no          3    1      0     0     0 0x00 0x00
                    prodsig                 0     0     0    0 no         61   61      0     0     0 0x00 0x00
                    sernum                  0     0     0    0 no         10    1      0     0     0 0x00 0x00
                    osccal16                0     0     0    0 no          2    1      0     0     0 0x00 0x00
                    osccal20                0     0     0    0 no          2    1      0     0     0 0x00 0x00
                    osc16err                0     0     0    0 no          2    1      0     0     0 0x00 0x00
                    osc20err                0     0     0    0 no          2    1      0     0     0 0x00 0x00
                    data                    0     0     0    0 no          0    1      0     0     0 0x00 0x00
                    userrow     usersig     0     0     0    0 no         64   64      0     0     0 0x00 0x00
                    eeprom                  0     0     0    0 no        256   64      0     0     0 0x00 0x00
                    flash                   0     0     0    0 no      49152  128      0     0     0 0x00 0x00

                  Programmer Type : JTAGICE3_UPDI
                  Description     : MPLAB(R) SNAP in UPDI mode
avrdude_pr1132v2: jtag3_getparm()
avrdude_pr1132v2: sending get parameter (scope 0x01, section 0, parm 0) command: 0x84 (9 bytes msg)
avrdude_pr1132v2: sending get info (serial number) command: 0x81 (23 bytes msg)
                  ICE HW version  : 1
                  ICE FW version  : 1.10 (rel. 249)
                  Serial number   :
avrdude_pr1132v2: jtag3_getparm()
avrdude_pr1132v2: sending get parameter (scope 0x01, section 0, parm 1) command: 0x84 (6 bytes msg)
avrdude_pr1132v2: jtag3_setparm()
avrdude_pr1132v2: sending set parameter (scope 0x12, section 0, parm 0) command: 0x80 (3 bytes msg)
avrdude_pr1132v2: jtag3_setparm()
avrdude_pr1132v2: sending set parameter (scope 0x12, section 0, parm 1) command: 0x80 (3 bytes msg)
avrdude_pr1132v2: jtag3_setparm()
avrdude_pr1132v2: sending set parameter (scope 0x12, section 1, parm 0) command: 0x80 (3 bytes msg)
avrdude_pr1132v2: jtag3_getparm()
avrdude_pr1132v2: sending get parameter (scope 0x01, section 1, parm 0) command: 0x84 (6 bytes msg)
                  Vtarget         : 4.74 V
avrdude_pr1132v2: jtag3_getparm()
avrdude_pr1132v2: sending get parameter (scope 0x12, section 1, parm 32) command: 0x84 (6 bytes msg)
                  JTAG clock megaAVR/program   : 1000 kHz
avrdude_pr1132v2: jtag3_getparm()
avrdude_pr1132v2: sending get parameter (scope 0x12, section 1, parm 33) command: 0x84 (6 bytes msg)
                  JTAG clock megaAVR/debug     : 100 kHz
avrdude_pr1132v2: jtag3_getparm()
avrdude_pr1132v2: sending get parameter (scope 0x12, section 1, parm 48) command: 0x84 (6 bytes msg)
avrdude_pr1132v2: jtag3_getparm()
avrdude_pr1132v2: sending get parameter (scope 0x12, section 1, parm 49) command: 0x84 (6 bytes msg)
                  PDI/UPDI clock Xmega/megaAVR : 100 kHz
UPDI SET:
        xd->prog_base_msb=0
        xd->prog_base=0 40
        xd->flash_page_size_msb=0
        xd->flash_page_size=80
        xd->eeprom_page_size=40
        xd->nvmctrl=0 10
        xd->ocd=80 f
        xd->address_mode=0
avrdude_pr1132v2: jtag3_setparm()
avrdude_pr1132v2: sending set parameter (scope 0x12, section 2, parm 0) command: 0x80 (3 bytes msg)
avrdude_pr1132v2: sending AVR sign-on command: 0x84 (8 bytes msg)
avrdude_pr1132v2: partial Family_ID returned: "mega"
avrdude_pr1132v2: AVR device initialized and ready to accept instructions

Reading |                                                    | 0% 0.00 s avrdude_pr1132v2: jtag3_read_byte(.., signature, 0x0, ...)
          mapped to address: 0x1100
avrdude_pr1132v2: sending enter progmode command: 0xa0 (4 bytes msg)
avrdude_pr1132v2 jtag3_command() error: device is locked; chip erase required to unlock
avrdude_pr1132v2 avr_read_mem() error: unable to read byte at address 0x0000
avrdude_pr1132v2 avr_read_mem() error: read operation failed for memory signature
avrdude_pr1132v2 avr_signature() error: unable to read signature data for part ATmega4808, rc=-3
avrdude_pr1132v2: sending read SIB command: 0x84 (20 bytes msg)
avrdude_pr1132v2: System Information Block: megaAVR P:0D:1-3
avrdude_pr1132v2: received FamilyID: "megaAVR"
                 double check chip or use -F to override this check
avrdude_pr1132v2: jtag3_close()
avrdude_pr1132v2: sending AVR sign-off command: 0x80 (3 bytes msg)
avrdude_pr1132v2: sending sign-off command: 0x80 (3 bytes msg)

avrdude_pr1132v2 done.  Thank you.
stefanrueger commented 1 year ago

I just had an idea to freeze the progress bar on the first serious error. This is only now possible since we now know which messages are actually errors. Pushed onto PR #1132 See how you like it.

mcuee commented 1 year ago

I just had an idea to freeze the progress bar on the first serious error. This is only now possible since we now know which messages are actually errors. Pushed onto PR #1132 See how you like it.

PR #1132 works very well. But there are usability issues under macOS due to the use of BSD libedit instead of readline by default under Homebrew. Hopefully @mariusgreuel can help to add some CMake magic to force the use of readline.