avrdude support broken

[coelner]

as mentioned: With this firmware (U_1-05112018.hex) I can't use avrdude to flash a attiny85. With a usbasp it works well, therefore the attiny seems working and the wiring should be fine. VCC <-> 5V GND <-> GND PB5 <-> CS (RES) PB2 <-> CLK PB1 <-> MISO PB0 <-> MOSI

avrdude -p t85 -c buspirate -P /dev/ttyUSB0 -F

Attempting to initiate BusPirate binary mode...
avrdude: Paged flash write enabled.
avrdude: initialization failed, rc=-2
avrdude: AVR device initialized and ready to accept instructions
avrdude: Device signature = 0x10f553
avrdude: Expected signature for ATtiny85 is 1E 93 0B

****switched MOSI/MISO wire to be really sure*****
avrdude -p t85 -c buspirate -P /dev/ttyUSB0 -F

Attempting to initiate BusPirate binary mode...
avrdude: Paged flash write enabled.
avrdude: initialization failed, rc=-2
avrdude: AVR device initialized and ready to accept instructions
avrdude: Device signature = 0x10251a
avrdude: Expected signature for ATtiny85 is 1E 93 0B

I am aware of this: http://dangerousprototypes.com/docs/Bus_Pirate_AVR_Programming#initialization_failed.2C_rc.3D-2

The wires are working, I used them with the usbasp. I apply 5V from buspirate or directly via PSU. The timing of buspirate should be the lowest as possible.

Any other suggestions?

[coelner]

the same for this version: S_1-05112018.hex.

[USBEprom]

@coelner

I am sorry for the issue you are dealing with. Sadly I have not any chip to test this. Anyway, do you know a revision of the firmware for the Bus Pirate which is surely working for you? What is the avrdude version you are using? I have avrdude-6.3-mingw32, AvrDude GUI v1.0, avrdudessGUI 2.4-6.1 and avrdudess_GUI_2.6-6.3 but I need the chip... What is the hardware revision of your Bus Pirate? Has its bootloader been upgraded to the release v4.5? What is the silicon revision of the PIC welded on the Bus Pirate you own? Thanks!

(http://dangerousprototypes.com/forum/viewtopic.php?f=4&t=9017)

[coelner]

No problem, it is a debug device, sometimes it needs some debug itself ;-)

I don't know the latest working version, but as soon as possible I going to try other versions.

Linux 4.20.2-arch1-1-ARCH #1
avrdude: Version 6.3, compiled on Jan 11 2019 at 08:12:38
Bus Pirate v3.5
Community Firmware v7.1 - goo.gl/gCzQnW [HiZ 1-WIRE UART I2C SPI 2WIRE 3WIRE KEYB LCD PIC DIO] Bootloader v4.5
DEVID:0x0447 REVID:0x3046 (24FJ64GA00 2 B8)

[coelner]

Working: bpv3_fw7.0_opt1_18092016.hex BPv3-firmware-v6.2-r1981.hex Broken: bpv3_fw7.11_opt1_12062018.hex bpv3_fw7.11_opt2_12062018.hex

[USBEprom]

@coelner

Thank you for reporting this. I am on the way to buy some chip for testing. I wonder what is different among the repositories that then some firmware is functioning and some else is not.

[coelner]

cool, very ambitious. Call me if I can support you.

[agatti]

Would it be possible to try out different code versions to see exactly which code change broke the feature? The two post-DangerousPrototypes versions you mention are two years apart, and a lot changed in the meantime.

If you are able to build the firmware yourself, can you try to check out older versions in the git repository to narrow down what broke the code?

[E3V3A]

Could someone pinpoint where in the BP sources the avrdude messages are parsed?

@coelner what does the bitbang option produce? avrdude -p t85 -c buspirate_bb -P /dev/ttyUSB0 -F

@USBEprom Where are BB and "normal" options parsed in the BP fw?

BTW. What exactly is the "normal" (-c buspirate) way?

[coelner]

@E3V3A

user ~ $avrdude -p t85 -c buspirate_bb -P /dev/ttyUSB0 -F
Attempting to initiate BusPirate bitbang binary mode...
BusPirate binmode version: 1
avrdude: AVR device initialized and ready to accept instructions
Reading | ################################################## | 100% 1.53s
avrdude: Device signature = 0x1e930b (probably t85)
avrdude: safemode: Fuses OK (E:FE, H:DD, L:E1)
avrdude done.  Thank you.

@agatti It would take some time

[E3V3A]

So bitbang works, but not normal operation...

[agatti]

@E3V3A as you probably figured out already, the magic seems to be almost entirely on the avrdude side according to both this and this.

The only AVR-specific bit there is in BP's code is here as far as I can remember right away - which I'm not sure it's being invoked at all.

[E3V3A]

which I'm not sure it's being invoked at all

Yeah, all that preprocessor stuff make it look like real spaghetti code. Trying to beautify and accommodate for all incompatible hardware versions in the same files... I can't even be bothered to look at it. Would have been better to use separate branches for the various HW revisions.

We'd need a huge block diagram of the whole code to understand how stuff is done and when/where it is executed. Reverse engineering the firmware executable with IDA would probably provide better insight how the code is executed and in what order.

[USBEprom]

@E3V3A

@USBEprom Where are BB and "normal" options parsed in the BP fw?

BTW. What exactly is the "normal" (-c buspirate) way?

I am still waiting for the ATTINY chips I ordered on January 18th. However I can not answer you, because I do not know anything about programming, at most I can test firmware and functionality, sorry.

[USBEprom]

Finally I received the chips so I could verify the matter with the firmware U_1-05112018.hex that I released in the forum of dangerousprototypes (http://dangerousprototypes.com/forum/viewtopic.php?f=28&t=8498&start=120#p67834). For my tests I used the program avrdudess_GUI_2.6-6.3_20180920-2 (http://blog.zakkemble.net/avrdudess-a-gui-for-avrdude/) running it on Windows 10 and for me everything works correctly without any problem. Surely it is a kinda too much slow but it is equally sure that it works without showing the problem described by the user named coelner who opened this issue. In detail I used my Bus Pirate Bus v3.6 as an interface to program the flashing of a LED with an ATTINY85 using the GUI for AVRDUDE called avrdudess_GUI_2.6-6.3_20180920-2. In the end from my side everything works for me so I wonder why it does not for the user coelner. I have set up The Bus Pirate (bitbang interface, supports TPI) as a programmer in avrdudess_GUI_2.6-6.3_20180920-2, COM port and its baud rate and simply by pressing the button [Detect] avrdudess_GUI_2.6-6.3_20180920-2 has replied "Detected 1e930b = ATtiny85". Then I programmed the ATTINY85 to flash a LED on its pin number 5 using the hexadecimal compiled with Arduino IDE 1.8.8 improved adding the ATTinyCore-master package and all went well without problems, although in truth rather slowly, but it was to be expected. The test interface I built to connect the ATTINY85 to the Bus Pirate is equipped with an LED on pin number 5 and so I could immediately verify that all was surely working good, beyond the messages shown to me by AVREDS.

@E3V3A From my side by performing -c buspirate_bb -p t85 -P COM3 -b 115200 -F I get:

Attempting to initiate BusPirate bitbang binary mode...

BusPirate binmode version: 1

avrdude.exe: AVR device initialized and ready to accept instructions

Reading | ################################################## | 100% 1.52s

avrdude.exe: Device signature = 0x1e930b (probably t85)

avrdude.exe done. Thank you.

I have also tried without GUI with avrdude-6.3-mingw32 and everything works without problems:

I:\Bus Pirate\avrdude-6.3-mingw32>avrdude -c buspirate_bb -p t85 -P COM3 -b 115200 -F

Attempting to initiate BusPirate bitbang binary mode... BusPirate binmode version: 1 avrdude: AVR device initialized and ready to accept instructions

Reading | ################################################## | 100% 1.54s

avrdude: Device signature = 0x1e930b (probably t85)

avrdude: safemode: Fuses OK (E:FF, H:DF, L:62)

avrdude done. Thank you.

I:\Bus Pirate\avrdude-6.3-mingw32>

[coelner]

It is all the bitbanging mode -c busbirate_bb. Without that it should not work.

[USBEprom]

It is all the bitbanging mode -c busbirate_bb. Without that it should not work.

@ coelner

Ok, but is it sure it should always work both ways? Seems to me it depend on the AVRDUDE implementation because some have it and some do not. So in the end the whole thing it may not on the Bus Pirate side or its firmware, actually, in a good way, the culprit should be AVRDUDE. Is not so?

[Rondom]

Well, if it worked with a previous BusPirate version with buspirate_bb, but not in the latest version (with AVRDUDE unchanged), there is likely a regression on the BusPirate side.

[coelner]

http://dangerousprototypes.com/forum/viewtopic.php?f=28&t=3441&start=60#p63153

Bus Pirate v3.5
Firmware v6.3-beta1 r2151  Bootloader v4.5
DEVID:0x0447 REVID:0x3046 (24FJ64GA002 B8)
19:40 coelner ~/Downloads/BPv3-bootloaderv4xtov45-update-vb_ENG-h $avrdude -p t85 -c buspirate_bb -P /dev/ttyUSB0 -F
Attempting to initiate BusPirate bitbang binary mode...
BusPirate binmode version: 1
avrdude: AVR device initialized and ready to accept instructions
Reading | ################################################## | 100% 1.53s
avrdude: Device signature = 0x1e930b (probably t85)
avrdude: safemode: Fuses OK (E:FE, H:DD, L:E1)

19:40 coelner ~/Downloads/BPv3-bootloaderv4xtov45-update-vb_ENG-h $avrdude -p t85 -c buspirate -P /dev/ttyUSB0 -F
Attempting to initiate BusPirate binary mode...
avrdude: Paged flash write enabled.
avrdude: AVR device initialized and ready to accept instructions
Reading | ################################################## | 100% 0.09s
avrdude: Device signature = 0x1e930b (probably t85)
avrdude: safemode: Fuses OK (E:FE, H:DD, L:E1)

S_1-28102018.hex

HiZ>i
Bus Pirate v3.5
Community Firmware v7.1 - goo.gl/gCzQnW [HiZ 1-WIRE UART I2C SPI 2WIRE 3WIRE KEYB LCD PIC DIO] Bootloader v4.5
DEVID:0x0447 REVID:0x3046 (24FJ64GA00 2 B8)
http://dangerousprototypes.com
19:45 coelner ~/Downloads/BPv3-bootloaderv4xtov45-update-vb_ENG-h $avrdude -p t85 -c buspirate -P /dev/ttyUSB0 -F
Attempting to initiate BusPirate binary mode...
avrdude: Paged flash write enabled.
avrdude: initialization failed, rc=-2
avrdude: AVR device initialized and ready to accept instructions
avrdude: Device signature = 0x10b553
avrdude: Expected signature for ATtiny85 is 1E 93 0B
avrdude: warning: did not get a response to power off command.

19:45 coelner ~/Downloads/BPv3-bootloaderv4xtov45-update-vb_ENG-h $avrdude -p t85 -c buspirate_bb -P /dev/ttyUSB0 -F
Attempting to initiate BusPirate bitbang binary mode...
BusPirate binmode version: 1
avrdude: AVR device initialized and ready to accept instructions
Reading | ################################################## | 100% 1.52s
avrdude: Device signature = 0x1e930b (probably t85)
avrdude: safemode: Fuses OK (E:FE, H:DD, L:E1)

http://dangerousprototypes.com/forum/viewtopic.php?f=28&t=8498#p65290 bpv3_fw7.0_opt0_18092016.hex

buspirate binary mode and bitbang works both.

@USBEprom avrdudess does nothing at all, it is only a gui for avrdude. You can see the command line which is used for avrdude. I have currently not the time to test each commit and compile the firmware and test it.

[USBEprom]

@Rondom

I agree. Based on what I saw with the latest firmwares v7.x the buspirate_bb option works, buspirate does not. My question is different though. I asked if this should always work this way because I know that some versions of AVRDUDE do not allow buspirate_bb syntax, but only buspirate (for instance WinAVR_Portable_V14_1) and some firmwares of the Bus Pirate v3 do not handle bitbang mode, at least not in the same way as the last releases. That is why my question. From my point of view would be great restore both of them although honestly I do not understand the advantage of one over the other syntax, more than anything else I think that since before it worked, if now it does not anymore there must surely be a problem that it would be better to remove. That is.

@coelner

Thanks for your report. I know AVRDUDESS is only a GUI for AVRDUDE and in fact, among other things, the screenshots that I have put not only concern AVRDUDESS GUI, there is also avrdude-6.3-mingw32 (here I am working on Windows, my Linux box is used for MPLAB and compilers and I would rather not have to work on it). When I wrote that, in a good way, the culprit is instead AVRDUDE, I was referring to what I wrote to Rondom, namely that there are versions of AVRDUDE that only allow the syntax buspirate and do not handle the buspirate_bb one, not AVRDUDE itself is the problem. Right now I am testing BPv3-firmware-v6.2-r1981.hex and BPv3-firmware-v6.3-beta1_r2151.hex, but sadly I can do nothing because I have not any skill as software engineer. Anyway in my opinion there is no need to test all the released firmwares, the data already produced may be enough for a software engineer, I think.

[Rondom]

@USBEprom wrote:

I asked if this should always work this way because I know that some versions of AVRDUDE do not allow buspirate_bb syntax, but only buspirate (for instance WinAVR_Portable_V14_1) and some firmwares of the Bus Pirate v3 do not handle bitbang mode, at least not in the same way as the last releases. That is why my question.

I am not really sure what you are trying to say, but I agree with you that it would be nice to fix the underlying issue. So you are saying that some versions of avrdude do not support both modes. Not sure, how exactly they do vary, because I am not familiar with AVR flashing, but from the output below, I would guess that buspirate_bb supports TPI, while buspirate does not. (Disclaimer: I didn't know what TPI is without googling...):

buspirate        = The Bus Pirate
buspirate_bb     = The Bus Pirate (bitbang interface, supports TPI)

@coelner @USBEprom What I can offer is to try to flash an Atmega 328 using BPv4 (I don't have a v3) with the latest version. This is a bit of gamble, because this bug might only occur with an ATTiny or only with BPv3, but if I can reproduce this, we are already one step further.

@USBEprom Are you lacking an avrdude-version that supports buspirate (without the bb)? If no, can you try to reproduce with the command-line that @coelner uses?

[tofurky]

sorry i don't have much to add except i ran into an issue with avrdude on attiny44 tonight, using a git checkout from 2/22/19. 4ba17bfe09465dbaffbfc003915a81a6c029e46a on bp v3.6 to be precise. it mostly works but i am getting bad bytes here and there causing flashes to fail. i haven't bisected but going back to BPv3-frimware-v6.1.hex fixed things 🙄. just reading 256byte eeprom will show some flipped bits about 50% of the time. flashing main program memory was failing 100% of the time due to verification errors (very early in - first 100 bytes or so). i will try to find some time tomorrow to bisect or could test some potential fixes. haven't tested _bb mode yet (and wasn't aware it existed until finding this issue...). anyhow, glad to see it was the buspirate and not my heavily weathered attiny soil sensors :) i was considering swapping chips.

edit: forgot to mention that the old 6.1 firmware was much faster as well.

[coelner]

bpv3_fw7.0_opt0_18092016.hex works both ways with ATMega328p (arduino due board) S_1-05112018.hex works both ways with ATMega328p (arduino due board)

I going to sniff the traffic, maybe someone can use it.

[tofurky]

i bisected and it seems it was broken a long time ago in 47f5c59d9c92ee2ace8bea40b985722f8d71aee5. i will need to double check when i get some more time. here is the log:

matt@aquos:~/devel/buspirate/Bus_Pirate$ git bisect good HEAD 
47f5c59d9c92ee2ace8bea40b985722f8d71aee5 is the first bad commit
commit 47f5c59d9c92ee2ace8bea40b985722f8d71aee5
Author: Alessandro Gatti <a.gatti@frob.it>
Date:   Sun Aug 27 08:20:56 2017 +0800

    Further SPI cleanups.

:040000 040000 455b529e9691e71639dedae208ba82bcff78f377 5f0edec83f3d1be6fb89be7943aa5f3527c0ac3e M  Firmware
matt@aquos:~/devel/buspirate/Bus_Pirate$ git bisect log
git bisect start
# bad: [4ba17bfe09465dbaffbfc003915a81a6c029e46a] Remove unused comments in proc_menu.c.
git bisect bad 4ba17bfe09465dbaffbfc003915a81a6c029e46a
# good: [e1298ba6fe1ebd95213ef2366ee22c162e53c4da] Updated changelog.
git bisect good e1298ba6fe1ebd95213ef2366ee22c162e53c4da
# good: [e1298ba6fe1ebd95213ef2366ee22c162e53c4da] Updated changelog.
git bisect good e1298ba6fe1ebd95213ef2366ee22c162e53c4da
# bad: [f93f7d0250d56051d2ab69d5f4e85c140e426cbe] Merged base_io into base.
git bisect bad f93f7d0250d56051d2ab69d5f4e85c140e426cbe
# bad: [f93f7d0250d56051d2ab69d5f4e85c140e426cbe] Merged base_io into base.
git bisect bad f93f7d0250d56051d2ab69d5f4e85c140e426cbe
# good: [922d9ae148db4b6c5235a07dced5a9d86cb186d5] Merge pull request #56 from andersm/usb-fix
git bisect good 922d9ae148db4b6c5235a07dced5a9d86cb186d5
# bad: [2096dbad9681e697a22dfbe39dacbf4b973f1c4f] Fix compilation error for v3.
git bisect bad 2096dbad9681e697a22dfbe39dacbf4b973f1c4f
# bad: [47f5c59d9c92ee2ace8bea40b985722f8d71aee5] Further SPI cleanups.
git bisect bad 47f5c59d9c92ee2ace8bea40b985722f8d71aee5
# good: [a2dc566b884350791e8ec50630e7d6b0a730bf91] Merge pull request #57 from andersm/usb-fix2
git bisect good a2dc566b884350791e8ec50630e7d6b0a730bf91
# good: [144dfb26e8163002d19ba7d708f98059a8c5756b] Clean up hardware I2C code.
git bisect good 144dfb26e8163002d19ba7d708f98059a8c5756b
# good: [ad8e97e0456e090737d76ece4154b82cdd3d0379] Refactor extended AVR SPI commands.
git bisect good ad8e97e0456e090737d76ece4154b82cdd3d0379
# first bad commit: [47f5c59d9c92ee2ace8bea40b985722f8d71aee5] Further SPI cleanups.
# good: [ad8e97e0456e090737d76ece4154b82cdd3d0379] Refactor extended AVR SPI commands.
git bisect good ad8e97e0456e090737d76ece4154b82cdd3d0379
# first bad commit: [47f5c59d9c92ee2ace8bea40b985722f8d71aee5] Further SPI cleanups.

[agatti]

Does changing

                spi_state.clock_edge =
                         (inByte & 0b0010) ? SPI_TRANSITION_FROM_IDLE_TO_ACTIVE :
                             SPI_TRANSITION_FROM_ACTIVE_TO_IDLE;

to

                spi_state.clock_edge =
                         (inByte & 0b0010) ? SPI_TRANSITION_FROM_ACTIVE_TO_IDLE :
                             SPI_TRANSITION_FROM_IDLE_TO_ACTIVE;

in Firmware/spi.c

fix the issue over there?

[tofurky]

Does changing

                spi_state.clock_edge =
                         (inByte & 0b0010) ? SPI_TRANSITION_FROM_IDLE_TO_ACTIVE :
                             SPI_TRANSITION_FROM_ACTIVE_TO_IDLE;

to

                spi_state.clock_edge =
                         (inByte & 0b0010) ? SPI_TRANSITION_FROM_ACTIVE_TO_IDLE :
                             SPI_TRANSITION_FROM_IDLE_TO_ACTIVE;

in Firmware/spi.c

fix the issue over there?

yes, that fixed it! thanks! i will see if i can find the performance regression as well later tonight (if it still exists with this fixed).

[USBEprom]

Does changing

                spi_state.clock_edge =
                         (inByte & 0b0010) ? SPI_TRANSITION_FROM_IDLE_TO_ACTIVE :
                             SPI_TRANSITION_FROM_ACTIVE_TO_IDLE;

to

                spi_state.clock_edge =
                         (inByte & 0b0010) ? SPI_TRANSITION_FROM_ACTIVE_TO_IDLE :
                             SPI_TRANSITION_FROM_IDLE_TO_ACTIVE;

in Firmware/spi.c

fix the issue over there?

@agatti

Thank you Sir! In the current repository I have patched spi.c as you wrote and I built two test firmware for the Bus Pirate v3:

BP_v3_07032019_patched_OPT1.zip

For what I can verify, AVRDUDE now works with both buspirate_bb and buspirate syntaxes. That is with ATTINY85, sadly I do not have any other chips to do tests.

@tofurky

Thanks for having bisected the source, Sir!

@coelner

Very interesting the fact that with different chips, ATMega328p in your case, the result can change, thanks for sharing the thing, Sir! Also me I would be about to sniff the traffic while programming with AVRDUDE using a logic analyzer, nothing but a simple curiosity.

@Rondom

Thank you for your kind help, Sir. I have several versions of the AVRDUDE program and its reincarnations, some have both buspirate_bb and buspirate syntaxes, some do not, the early versions I guess. I have already reproduced since the beginning what coelner wrote, either from command-line than GUI, and I confirm the whole thing. Sadly I have only ATTINY as chips, nothing else.

[tofurky]

with regards to the performance regression, i wasn't able to bisect it exactly because the compilation failed due to user_serial_read_big_endian_word() being used but undeclared.

after these commits, performance went from < 5s to flash my attiny44, to 10x that - a bit more than 50s. it seems only writes are affected.

so, one of these - the first that compiles is cd6559d53e7ca74033ba0c1f5bad95b7d435bb31, but i have a feeling it was introduced in 8df3c33f701560fe0539a503ae472567bcc30613.

commit cd6559d53e7ca74033ba0c1f5bad95b7d435bb31 (HEAD, refs/bisect/bad)
Author: Alessandro Gatti <a.gatti@frob.it>
Date:   Mon Feb 11 19:19:36 2019 +0100

    Clean up SPI AVR bulk read.

commit 0f2a533d0acd61e594b8911c80182e41e4c70b93 (refs/bisect/skip-0f2a533d0acd61e594b8911c80182e41e4c70b93)
Author: Alessandro Gatti <a.gatti@frob.it>
Date:   Mon Feb 11 19:18:22 2019 +0100

    Update comments in SPI module.

commit 8df3c33f701560fe0539a503ae472567bcc30613 (refs/bisect/skip-8df3c33f701560fe0539a503ae472567bcc30613)
Author: Alessandro Gatti <a.gatti@frob.it>
Date:   Mon Feb 11 19:17:18 2019 +0100

    Add experimental SPI streaming support.

bisect log:

matt@aquos:~/devel/buspirate/Bus_Pirate$ git bisect log
git bisect start
# bad: [1e0b596d504ee652f40d6e8643524a5b4b7ec338] test
git bisect bad 1e0b596d504ee652f40d6e8643524a5b4b7ec338
# good: [47f5c59d9c92ee2ace8bea40b985722f8d71aee5] Further SPI cleanups.
git bisect good 47f5c59d9c92ee2ace8bea40b985722f8d71aee5
# good: [ad67d5aea73b8b7a7da7055760f0bfd9a80e594b] Update changelog.
git bisect good ad67d5aea73b8b7a7da7055760f0bfd9a80e594b
# good: [9081296d0e85d15feeeb915d605eaa97b5892e71] Fix compilation error reported in #113
git bisect good 9081296d0e85d15feeeb915d605eaa97b5892e71
# bad: [019c292801f285602cccf6241680cfe985e1a05d] Add experimental I2C streaming support.
git bisect bad 019c292801f285602cccf6241680cfe985e1a05d
# good: [a76bcc1c65e7077e23d91d95f14a7c5d5678d99b] Add pin type definitions.
git bisect good a76bcc1c65e7077e23d91d95f14a7c5d5678d99b
# bad: [f8d9d78209421269fdc40c07817ef18b89a41fb2] Merge variable declaration and assignment for SPI.
git bisect bad f8d9d78209421269fdc40c07817ef18b89a41fb2
# skip: [0f2a533d0acd61e594b8911c80182e41e4c70b93] Update comments in SPI module.
git bisect skip 0f2a533d0acd61e594b8911c80182e41e4c70b93
# skip: [8df3c33f701560fe0539a503ae472567bcc30613] Add experimental SPI streaming support.
git bisect skip 8df3c33f701560fe0539a503ae472567bcc30613
# skip: [8df3c33f701560fe0539a503ae472567bcc30613] Add experimental SPI streaming support.
git bisect skip 8df3c33f701560fe0539a503ae472567bcc30613
# bad: [cd6559d53e7ca74033ba0c1f5bad95b7d435bb31] Clean up SPI AVR bulk read.
git bisect bad cd6559d53e7ca74033ba0c1f5bad95b7d435bb31
# only skipped commits left to test
# possible first bad commit: [cd6559d53e7ca74033ba0c1f5bad95b7d435bb31] Clean up SPI AVR bulk read.
# possible first bad commit: [0f2a533d0acd61e594b8911c80182e41e4c70b93] Update comments in SPI module.
# possible first bad commit: [8df3c33f701560fe0539a503ae472567bcc30613] Add experimental SPI streaming support.

non-regressed avrdude:

avrdude -c buspirate -P /dev/ttyUSB0 -p attiny44  -U flash:w:main.hex:i

Attempting to initiate BusPirate binary mode...
avrdude: Paged flash write enabled.
avrdude: AVR device initialized and ready to accept instructions

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

avrdude: Device signature = 0x1e9207 (probably t44)
avrdude: NOTE: "flash" memory has been specified, an erase cycle will be performed
         To disable this feature, specify the -D option.
avrdude: erasing chip
avrdude: reading input file "main.hex"
avrdude: writing flash (1618 bytes):

Writing | ################################################## | 100% 3.74s

avrdude: 1618 bytes of flash written
avrdude: verifying flash memory against main.hex:
avrdude: load data flash data from input file main.hex:
avrdude: input file main.hex contains 1618 bytes
avrdude: reading on-chip flash data:

Reading | ################################################## | 100% 2.09s

avrdude: verifying ...
avrdude: 1618 bytes of flash verified

avrdude: safemode: Fuses OK (E:FF, H:D6, L:E2)

avrdude done.  Thank you.

real    0m7.535s
user    0m0.016s
sys 0m0.020s

regressed avrdude:

avrdude -c buspirate -P /dev/ttyUSB0 -p attiny44  -U flash:w:main.hex:i

Attempting to initiate BusPirate binary mode...
avrdude: AVR device initialized and ready to accept instructions

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

avrdude: Device signature = 0x1e9207 (probably t44)
avrdude: NOTE: "flash" memory has been specified, an erase cycle will be performed
         To disable this feature, specify the -D option.
avrdude: erasing chip
avrdude: reading input file "main.hex"
avrdude: writing flash (1618 bytes):

Writing | ################################################## | 100% 52.53s

avrdude: 1618 bytes of flash written
avrdude: verifying flash memory against main.hex:
avrdude: load data flash data from input file main.hex:
avrdude: input file main.hex contains 1618 bytes
avrdude: reading on-chip flash data:

Reading | ################################################## | 100% 2.09s

avrdude: verifying ...
avrdude: 1618 bytes of flash verified

avrdude: safemode: Fuses OK (E:FF, H:D6, L:E2)
avrdude: warning: did not get a response to power off command.

avrdude done.  Thank you.

real    0m56.563s
user    0m0.060s
sys 0m0.100s

to be clear, this patch was applied while bisecting the performance regression:

diff --git a/Firmware/spi.c b/Firmware/spi.c
index 1b2ca65..a70b4bb 100644
--- a/Firmware/spi.c
+++ b/Firmware/spi.c
@@ -928,8 +928,8 @@ void spi_enter_binary_io(void) {
       spi_state.clock_polarity =
           (input_byte & 0b0100) ? SPI_CLOCK_IDLE_HIGH : SPI_CLOCK_IDLE_LOW;
       spi_state.clock_edge = (input_byte & 0b0010)
-                                 ? SPI_TRANSITION_FROM_IDLE_TO_ACTIVE
-                                 : SPI_TRANSITION_FROM_ACTIVE_TO_IDLE;
+                                 ? SPI_TRANSITION_FROM_ACTIVE_TO_IDLE
+                                 : SPI_TRANSITION_FROM_IDLE_TO_ACTIVE;
       spi_state.data_sample_timing = (input_byte & 0b0001)
                                          ? SPI_SAMPLING_ON_DATA_OUTPUT_END
                                          : SPI_SAMPLING_ON_DATA_OUTPUT_MIDDLE;

[agatti]

So, I've taken a look at the offending commits. I'd be surprised if cd6559d is actually slowing things down tenfold, but uart i/o should take a non-trivial amount of time for these sort of operations. 0f2a533 contains no code changes at all and can be safely ignored. 8df3c33 should perform the same set of operations as before, but it is organised differently - the new code is not enabled by default, too.

Unless I've messed up badly in 8df3c33, can you please try with 0f2a533 and 8df3c33 still in and manually revert cd6559d to see if things actually get as fast as before?

[andersm]

There is a possibility that interleaving the user_serial_transmit_character() and spi_write_byte() operations leads to poorer USB utilization, ie. fewer bytes transmitted per packet. This should be visible in a packet capture.

[coelner]

S_1-05112018_attiny85_sniff.zip The ATMega328p sniff follows later--EDIT: S_1-05112018_atmega328p_sniff.zip

My sniffer max rate is 24MHz, I hope it was fast enough. The mapping for the pulseview file. D0 MOSI D1 MISO D2 CLK D3 CS

[agatti]

@andersm SPI streaming is disabled by default, though - if it was left alone then it's either the new uart u32 reading code or I simply messed up when rearranging code for the spi read/write operations I guess.

[USBEprom]

http://dangerousprototypes.com/forum/viewtopic.php?f=28&t=8498&start=120#p68327

[tofurky]

So, I've taken a look at the offending commits. I'd be surprised if cd6559d is actually slowing things down tenfold, but uart i/o should take a non-trivial amount of time for these sort of operations. 0f2a533 contains no code changes at all and can be safely ignored. 8df3c33 should perform the same set of operations as before, but it is organised differently - the new code is not enabled by default, too.

Unless I've messed up badly in 8df3c33, can you please try with 0f2a533 and 8df3c33 still in and manually revert cd6559d to see if things actually get as fast as before?

i'm not quite understanding what you mean by manually revert cd6559d53e7ca74033ba0c1f5bad95b7d435bb31.

i can't move back to a state where user_serial_read_big_endian_word() and user_serial_read_big_endian_long_word() are used but undeclared, so i can't remove those functions.

so, i interpreted your request as to test from tip of current master and reverted like so:

diff --git a/Firmware/spi.c b/Firmware/spi.c
index a70b4bb..532fcc4 100644
--- a/Firmware/spi.c
+++ b/Firmware/spi.c
@@ -1063,8 +1063,20 @@ void handle_extended_avr_command(void) {
     break;

   case BINARY_IO_SPI_AVR_COMMAND_BULK_READ: {
-    uint32_t address = user_serial_read_big_endian_long_word();
-    uint32_t length = user_serial_read_big_endian_long_word();
+    uint32_t address;
+    uint32_t length;
+
+    address = (uint32_t)((((uint32_t)user_serial_read_byte()) << 24) |
+                         (((uint32_t)user_serial_read_byte()) << 16) |
+                         (((uint32_t)user_serial_read_byte()) << 8) |
+                         user_serial_read_byte());
+    length = (uint32_t)((((uint32_t)user_serial_read_byte()) << 24) |
+                        (((uint32_t)user_serial_read_byte()) << 16) |
+                        (((uint32_t)user_serial_read_byte()) << 8) |
+                        user_serial_read_byte());
+
+    /* @todo: avoid (address + length) integer overflow. */
+

     if ((address > 0xFFFF) || (length > 0xFFFF) ||
         ((address + length) > 0xFFFF)) {

that didn't fix it, though. if you had something else in mind let me know, thanks.

edit: fwiw i defined BP_SPI_ENABLE_STREAMING_READ/BP_SPI_ENABLE_STREAMING_WRITE in configuration.h and am still seeing the speed regression.

[agatti]

Yep, that was what I had in mind. It's weird that speed went down like that, since the changes weren't supposed to impact on speed, of all things.

Streaming read/writes were supposed to allow transferring up to 64k per session (since the transfer length is 16 bits) instead of being limited by the buffer size set at compile time - which is definitely less than 64k anyway.

[USBEprom]

@all

For what I can measure it seems to me that the syntaxes buspirate is roughly 17 times faster than the buspirate_bb one.

[agatti]

@tofurky would it be possible to record USB and GPIO traffic similarly to what @coelner did? That would help out in seeing what's the effective SPI CLK frequency and what happens on the bus pirate side between each SPI CLK cycle.

[USBEprom]

@agatti

My logic analyzer manages a different format from that used by @coelner, but I can provide specific data if it is indicated to me exactly what to acquire That said, for what I see to be slowed down is above all writing, reading is faster, although the clock keeps the same values ​​in writing and reading for the buspirate syntaxes and for that buspirate_bb one. With the buspirate syntax the writing and reading clock speed is about ~31kHz, instead with the buspirate_bb syntax the write and read clock speed is about ~64Hz. Despite the speed gap, about ~31kHz versus about ~64Hz, as I have already written the buspirate syntax (clk = ~31kHz) is about 17 times faster than the buspirate_bb one (clk = ~64Hz), which you would not say by doing the ratio between ~31kHz and ~64Hz. Among other things, although the clock gap is the same in reading and writing, performing readings using the buspirate_bb syntax requires a similar time using the buspirate syntax, which is rather weird. Here you go an illustrative screenshot that I took with my logic analyzer:

With the buspirate syntax the duration of each single byte is about ~0.2395ms, instead with the syntax buspirate_bb every single byte takes about ~0.127s, where the ratio between the two values is about ~532.

If I can help you in something else, you just have to tell me, thanks.

[tofurky]

@tofurky would it be possible to record USB and GPIO traffic similarly to what @coelner did? That would help out in seeing what's the effective SPI CLK frequency and what happens on the bus pirate side between each SPI CLK cycle.

yeah, i can get you a pulseview capture of the spi and a usbmon (pcap) of the usb traffic. hopefully both timestamped so you can correlate the two although i've never tried doing so.

[tofurky]

@agatti please see attached pulseview+usbmon pcaps. seems like lots big pauses between writes with the regressed version. i was able to use the SPI decoder to view the bytes that corresponded to the .hex i was flashing, so it seems the captures are good.

thanks!

bp_captures.zip

[andersm]

I don't know if it's relevant, but it seems to me like 8df3c33 introduced one change in behaviour: if the host only wants to write, ie. spi_read_to_uart() is not called, then REPORT_IO_SUCCESS() is also not called.

It should be easy to test if this has any effect. Move lines 985-992 of spi.c to 1045 (below releasing CS), and the old behaviour should be restored. Obviously streaming reads must be disabled.

[tofurky]

I don't know if it's relevant, but it seems to me like 8df3c33 introduced one change in behaviour: if the host only wants to write, ie. spi_read_to_uart() is not called, then REPORT_IO_SUCCESS() is also not called.

It should be easy to test if this has any effect. Move lines 985-992 of spi.c to 1045 (below releasing CS), and the old behaviour should be restored. Obviously streaming reads must be disabled.

adding REPORT_IO_SUCCESS() either unconditionally or adding it to an else at if (bytes_to_read > 0) here didn't make a difference: https://github.com/BusPirate/Bus_Pirate/blob/8df3c33f701560fe0539a503ae472567bcc30613/Firmware/spi.c#L1023-L1025

to:

  if (bytes_to_read > 0) {
    spi_read_to_uart(bytes_to_read);
  }
  else {
      REPORT_IO_SUCCESS();
  }

if you had something else in mind and provide a patch i'd be happy to test it.

[andersm]

I meant something like this:

index 2d79dd3..9b564a7 100644
--- a/Firmware/spi.c
+++ b/Firmware/spi.c
@@ -981,15 +981,6 @@ void spi_read_to_uart(const size_t bytes_to_read) {
   for (uint16_t offset = 0; offset < bytes_to_read; offset++) {
     bus_pirate_configuration.terminal_input[offset] = spi_write_byte(0xFF);
   }
-
-  /* Report success. */
-  REPORT_IO_SUCCESS();
-
-  /* Output read data to the serial port. */
-  for (uint16_t offset = 0; offset < bytes_to_read; offset++) {
-    user_serial_transmit_character(
-        bus_pirate_configuration.terminal_input[offset]);
-  }
 #endif /* BP_SPI_ENABLE_STREAMING_READ */
 }

@@ -1042,6 +1033,15 @@ void spi_read_write_io(const bool engage_cs) {
   if (engage_cs == true) {
     SPICS = HIGH;
   }
+
+  /* Report success. */
+  REPORT_IO_SUCCESS();
+
+  /* Output read data to the serial port. */
+  for (uint16_t offset = 0; offset < bytes_to_read; offset++) {
+    user_serial_transmit_character(
+        bus_pirate_configuration.terminal_input[offset]);
+  }
 }

 #ifdef BP_SPI_ENABLE_AVR_EXTENDED_COMMANDS

At a quick glance, it looked like there were places in the Bus Pirate support code of AVRDUDE where missing success responses could cause repeated host serial port read timeouts without actually failing the operation, but the default read timeout looked to be 100ms, not the 30ms delay shown in the packet traces.

[tofurky]

I meant something like this: ... At a quick glance, it looked like there were places in the Bus Pirate support code of AVRDUDE where missing success responses could cause repeated host serial port read timeouts without actually failing the operation, but the default read timeout looked to be 100ms, not the 30ms delay shown in the packet traces.

the patch didn't seem to make a difference :/

[tofurky]

if someone wanted one of the attiny boards i'm experiencing the issue on to debug, i could mail one to you. they are soil moisture sensors (older version of this: https://www.tindie.com/products/miceuz/i2c-soil-moisture-sensor/). some have corroded at the bottom making them useless for soil measurement but the attiny still works OK. they have a 6 pin avr isp header.

[tofurky]

revisiting this after running into further issues with an atmega32u4.

newer avrdude helpfully outputs this message:

avrdude: Disabling paged flash write. (Need BusPirate firmware >=v5.10.)

looking back at https://github.com/BusPirate/Bus_Pirate/issues/122#issuecomment-470741247, i noticed that the avrdude test with non-regressed firmware output the avrdude: Paged flash write enabled. message, whereas the regressed version did not.

thinking it might have to do with this section of avrdude: https://github.com/manison/avrdude/blob/a87a2c4eefe77ebc522b0a7a4c5ff83c09e3ab3e/buspirate.c#L582-L607

perhaps the lack of paged write explains the performance regression?