Problem closing COM port with 1.5.8 (SerialUPDI, Windows)
XFer012 opened this issue · 6 comments
Discussed in #463
Originally posted by XFer012 July 29, 2023
Hello,
after some time (about 1 year) I digged out my AVR128DB28 to do some testing, updated DxCore and... failed to upload a sketch.
OS: Windows 10 64 bit latest updates
IDE: Arduino 1.8.19
DxCore: 1.5.8 (updated from Boards Manager)
Serial-USB cable: CP2104 (works OK with ATTiny3224 and latest megaTinyCore)
Selected programmer: SerialUPDI (tried both "SLOW 57600" and 230400)
Problem:
Sketch uses 1616 bytes (1%) of program storage space. Maximum is 131072 bytes.
Global variables use 157 bytes (0%) of dynamic memory, leaving 16227 bytes for local variables. Maximum is 16384 bytes.
C:\Users\Fernando\AppData\Local\Arduino15\packages\megaTinyCore\tools\python3\3.7.2-post1/python3 -u C:\Users\Fernando\AppData\Local\Arduino15\packages\DxCore\hardware\megaavr\1.5.8/tools/prog.py -t uart -u COM12 -b 57600 -d avr128db28 --fuses 6:0b00001100 7:0x00 8:0x00 -fC:\Temp\arduino-build-files/AVR_New_Sleep_PIT.ino.hex -a write -v
SerialUPDI
UPDI programming for Arduino using a serial adapter
Based on pymcuprog, with significant modifications
By Quentin Bolsee and Spence Konde
Version 1.3.0.2 - Jun 2023
Using serial port COM12 at 57600 baud.
Target: avr128db28
Set fuses: ['6:0b00001100', '7:0x00', '8:0x00']
Action: write
File: C:\Temp\arduino-build-files/AVR_New_Sleep_PIT.ino.hex
pymcuprog.programmer - INFO - Setting up programming session for 'avr128db28'
pymcuprog.deviceinfo.deviceinfo - INFO - Looking for device avr128db28
pymcuprog.serialupdi.physical - INFO - Opening port 'COM12' at '57600' baud
pymcuprog.serialupdi.link - INFO - STCS 08 to 0x03
pymcuprog.serialupdi.link - INFO - STCS 06 to 0x02
pymcuprog.serialupdi.link - INFO - LDCS from 0x00
pymcuprog.serialupdi.link - WARNING - UPDI init failed: Can't read CS register. likely wiring error.
pymcuprog.serialupdi.physical - INFO - Sending double break
pymcuprog.serialupdi.physical - INFO - Double-break sent. Retrying.
pymcuprog.serialupdi.physical - INFO - Opening port 'COM12' at '57600' baud
pymcuprog.serialupdi.link - INFO - STCS 08 to 0x03
pymcuprog.serialupdi.link - INFO - STCS 06 to 0x02
pymcuprog.serialupdi.link - INFO - LDCS from 0x00
pymcuprog.serialupdi.link - INFO - UPDI init OK
pymcuprog.serialupdi.link - INFO - STCS 06 to 0x02
pymcuprog.serialupdi.link - INFO - Setting UPDI clock to 4 MHz
pymcuprog.serialupdi.link - INFO - STCS 03 to 0x09
pymcuprog.serialupdi.physical - INFO - Switching to '57600' baud
pymcuprog.serialupdi.application - WARNING - Cannot read SIB, hard reset...
pymcuprog.serialupdi.physical - INFO - Sending double break
pymcuprog.serialupdi.physical - INFO - Double-break sent. Retrying.
pymcuprog.serialupdi.physical - INFO - Opening port 'COM12' at '57600' baud
pymcuprog.serialupdi.application - INFO - SIB: 'AVR P:2D:1-3M2 (A5.KV00D.0)'
pymcuprog.serialupdi.application - INFO - Device family ID: 'AVR'
pymcuprog.serialupdi.application - INFO - NVM interface: 'P:2'
pymcuprog.serialupdi.application - INFO - Debug interface: 'D:1'
pymcuprog.serialupdi.application - INFO - PDI oscillator: '3M2'
pymcuprog.serialupdi.application - INFO - Extra info: '(A5.KV00D.0)'
pymcuprog.serialupdi.application - INFO - Using 24-bit UPDI
pymcuprog.serialupdi.link - INFO - STCS 08 to 0x03
pymcuprog.serialupdi.link - INFO - STCS 06 to 0x02
pymcuprog.serialupdi.link - INFO - LDCS from 0x00
pymcuprog.serialupdi.link - INFO - UPDI init OK
pymcuprog.serialupdi.link - INFO - LDCS from 0x00
pymcuprog.serialupdi.application - INFO - PDI revision = 0x03
pymcuprog.serialupdi.link - INFO - LDCS from 0x0B
pymcuprog.serialupdi.link - INFO - LDCS from 0x0B
pymcuprog.serialupdi.application - INFO - Entering NVM programming mode
pymcuprog.serialupdi.link - INFO - LDCS from 0x07
pymcuprog.serialupdi.application - INFO - Apply reset
pymcuprog.serialupdi.link - INFO - STCS 59 to 0x08
pymcuprog.serialupdi.application - INFO - Release reset
pymcuprog.serialupdi.link - INFO - STCS 00 to 0x08
pymcuprog.serialupdi.link - INFO - LDCS from 0x0B
pymcuprog.serialupdi.link - INFO - LDCS from 0x0B
pymcuprog.nvm - INFO - No specific initializer for this provider
Pinging device...
pymcuprog.programmer - INFO - Reading device ID...
pymcuprog.serialupdi.application - INFO - SIB: 'AVR P:2D:1-3M2 (A5.KV00D.0)'
pymcuprog.serialupdi.application - INFO - Device family ID: 'AVR'
pymcuprog.serialupdi.application - INFO - NVM interface: 'P:2'
pymcuprog.serialupdi.application - INFO - Debug interface: 'D:1'
pymcuprog.serialupdi.application - INFO - PDI oscillator: '3M2'
pymcuprog.serialupdi.application - INFO - Extra info: '(A5.KV00D.0)'
pymcuprog.serialupdi.application - INFO - Using 24-bit UPDI
pymcuprog.serialupdi.link - INFO - STCS 08 to 0x03
pymcuprog.serialupdi.link - INFO - STCS 06 to 0x02
pymcuprog.serialupdi.link - INFO - LDCS from 0x00
pymcuprog.serialupdi.link - INFO - UPDI init OK
pymcuprog.serialupdi.link - INFO - LDCS from 0x00
pymcuprog.serialupdi.application - INFO - PDI revision = 0x03
pymcuprog.serialupdi.link - INFO - LDCS from 0x0B
pymcuprog.serialupdi.application - INFO - Device ID = '1E970E' rev 'A5'
pymcuprog.nvm - INFO - Device ID: '1E970E'
pymcuprog.nvm - INFO - Device revision: 'A5'
pymcuprog.nvm - INFO - Device serial number: 'b'420501196000080701080119''
Ping response: 1E970E
Setting fuse 0x6=0xc
Writing literal values...
pymcuprog.programmer - INFO - Write...
pymcuprog.programmer - INFO - Writing 1 bytes of data to fuses...
pymcuprog.serialupdi.nvm - INFO - NVM EEPROM erase/write command
pymcuprog.serialupdi.nvm - INFO - Clear NVM command
pymcuprog.programmer - INFO - Write complete.
Verifying literal values...
pymcuprog.programmer - INFO - Reading 1 bytes from fuses...
pymcuprog.programmer - INFO - Verifying...
Action took 0.04s
Setting fuse 0x7=0x0
Writing literal values...
pymcuprog.programmer - INFO - Write...
pymcuprog.programmer - INFO - Writing 1 bytes of data to fuses...
pymcuprog.serialupdi.nvm - INFO - NVM EEPROM erase/write command
pymcuprog.serialupdi.nvm - INFO - Clear NVM command
pymcuprog.programmer - INFO - Write complete.
Verifying literal values...
pymcuprog.programmer - INFO - Reading 1 bytes from fuses...
pymcuprog.programmer - INFO - Verifying...
Action took 0.03s
Setting fuse 0x8=0x0
Writing literal values...
pymcuprog.programmer - INFO - Write...
pymcuprog.programmer - INFO - Writing 1 bytes of data to fuses...
pymcuprog.serialupdi.nvm - INFO - NVM EEPROM erase/write command
pymcuprog.serialupdi.nvm - INFO - Clear NVM command
pymcuprog.programmer - INFO - Write complete.
Verifying literal values...
pymcuprog.programmer - INFO - Reading 1 bytes from fuses...
pymcuprog.programmer - INFO - Verifying...
Action took 0.05s
Finished writing fuses.
Chip/Bulk erase,
Memory type eeprom is conditionally erased (depending upon EESAVE fuse setting)
Memory type flash is always erased
Memory type lockbits is always erased
...
pymcuprog.programmer - INFO - Erase...
pymcuprog.serialupdi.nvm - INFO - Chip erase using NVM CTRL
Traceback (most recent call last):
File "C:\Users\Fernando\AppData\Local\Arduino15\packages\DxCore\hardware\megaavr\1.5.8/tools/prog.py", line 287, in <module>
main()
File "C:\Users\Fernando\AppData\Local\Arduino15\packages\DxCore\hardware\megaavr\1.5.8/tools/prog.py", line 129, in main
return_code = pymcuprog_basic(args, fuses_dict)
File "C:\Users\Fernando\AppData\Local\Arduino15\packages\DxCore\hardware\megaavr\1.5.8/tools/prog.py", line 250, in pymcuprog_basic
offset=0)
File "C:\Users\Fernando\AppData\Local\Arduino15\packages\DxCore\hardware\megaavr\1.5.8/tools/prog.py", line 139, in run_pymcu_action
status = func(backend, *args, args_pymcu)
File "C:\Users\Fernando\AppData\Local\Arduino15\packages\DxCore\hardware\megaavr\1.5.8\tools\libs\pymcuprog\pymcuprog_main.py", line 189, in _action_erase
backend.erase(args.memory, address=None)
File "C:\Users\Fernando\AppData\Local\Arduino15\packages\DxCore\hardware\megaavr\1.5.8\tools\libs\pymcuprog\backend.py", line 436, in erase
self.programmer.erase(memory_name, address)
File "C:\Users\Fernando\AppData\Local\Arduino15\packages\DxCore\hardware\megaavr\1.5.8\tools\libs\pymcuprog\programmer.py", line 150, in erase
self.device_model.erase(memory_info=memory_info, address=address)
File "C:\Users\Fernando\AppData\Local\Arduino15\packages\DxCore\hardware\megaavr\1.5.8\tools\libs\pymcuprog\nvmserialupdi.py", line 103, in erase
self.avr.nvm.chip_erase()
File "C:\Users\Fernando\AppData\Local\Arduino15\packages\DxCore\hardware\megaavr\1.5.8\tools\libs\pymcuprog\serialupdi\nvm.py", line 241, in chip_erase
if not self.wait_flash_ready():
File "C:\Users\Fernando\AppData\Local\Arduino15\packages\DxCore\hardware\megaavr\1.5.8\tools\libs\pymcuprog\serialupdi\nvm.py", line 59, in wait_flash_ready
status = self.readwrite.read_byte(self.device.nvmctrl_address + constants.UPDI_NVMCTRL_STATUS)
File "C:\Users\Fernando\AppData\Local\Arduino15\packages\DxCore\hardware\megaavr\1.5.8\tools\libs\pymcuprog\serialupdi\readwrite.py", line 56, in read_byte
return self.datalink.ld(address)
File "C:\Users\Fernando\AppData\Local\Arduino15\packages\DxCore\hardware\megaavr\1.5.8\tools\libs\pymcuprog\serialupdi\link.py", line 410, in ld
return self.updi_phy.receive(1)[0]
IndexError: bytearray index out of range
pymcuprog.serialupdi.physical - INFO - Closing port 'COM12'
the selected serial port pymcuprog.serialupdi.physical - INFO - Closing port 'COM12'
does not exist or your board is not connected
I re-checked all wiring with my multimeter and everything seems fine; I had the test board stored away in a box and worked like a charm 1 year ago.
I know it could still have failed, maybe I will have to redo the board, but I cannot understand this part:
Pinging device...
pymcuprog.programmer - INFO - Reading device ID...
pymcuprog.serialupdi.application - INFO - SIB: 'AVR P:2D:1-3M2 (A5.KV00D.0)'
pymcuprog.serialupdi.application - INFO - Device family ID: 'AVR'
pymcuprog.serialupdi.application - INFO - NVM interface: 'P:2'
pymcuprog.serialupdi.application - INFO - Debug interface: 'D:1'
pymcuprog.serialupdi.application - INFO - PDI oscillator: '3M2'
pymcuprog.serialupdi.application - INFO - Extra info: '(A5.KV00D.0)'
Doesn't it mean it was able to communicate with the MCU?
Best,
Fernando
WTF I left a long reply here weeks ago!
What jumps out to me about that log is a huge number of random failures. My diagnosis is this: The connection is unreliable, suffering from frequent errors. Look at the signal on a scope, trigger on whichever edge you like, single trigger mode, and during a transfer, start pressing that button to reset the trigger until you capture data. Adjust horizontal scale so you can see 16-24 bits or so on the screen. Repeat the attempt and press the retrigger button repeatedly. You are looking for a snapshot where you can see both devices talking ("how the hell will I know that?!") Simple - they will have different LOW (and possibly slightly different HIGHs) logic levels - a few tenths of a volt difference. Sometimes the waveform will have a different shape. and the waveform will have a different shape. Most often in seemingly correctly made programmers that don't work it's either something stupid like a broken connection (I have had three diodes fail mechanically on these programmers. I now encase them in hotglue or UV resin, or I was doing that until I got my new dual port adapters that have a UPDI mode built in.,
I thought I responded to that, yes it's having some success communicating with the target, but look at all those times the operation failed and it recovered. Wiring issue, possibly due to differences in parameters of the adapter like series resistors (common on CH340, less common elsewhere).
Set digital scope to trigger on either edge and keep pressing the button while uploading. Since log shows two way communication, that's what we expect to see, and keep pressing the button until you get both sides sending data on the same screen. You will know when you can see both sides transmitting, because when each of them drive the line low, they drive it low with drivers of varying strength. Make sure that these voltages on both ends unambiguous to the parts on both sides. The varying values of series resistors added and on serial adapter, make sure the rise time is decent and the shape of the waveform looks reasonable, that kind of thing.
the selected serial port does not exist or your board is not connected
comes from the Arduino IDE, and appears to be the response to any error code returned by an upload tool. You can see how there was text in the middle of it - I'm not quite sure how that mess of a system managed that.
Let's see, first of all I want to retry with a different USB-Serial adapter (I should have a CH340 besides this CP2104).
Then I will try on a different PC.
Testing with a 'scope it's going to be tricky (my scope sits in a different room), I'll see what I can do.
Well, now I am really at a loss.
I had to replace my PC (too slow for upcoming stuff) and now with my new PC (same Windows 10 Pro, same Arduino IDE 1.8.19, newer DxCore 1.5.11) everything works both with the FT232RL-based USB-Serial adapter and the CP210x-based adapter.
Any chance of a UPDI-related fix between 1.5.8 and 1.5.11?
From 1.5.9 changelog:
Bugfixes, several, for SerialUPDI, and improvements in error messages.