How to read DEBUG=1 mode

The binary generated with the build option DEBUG=1 outputs internal operation messages to the VCP on the program port side. The baud rate is 500kbps, and the format is 8N1.

Tip

DEBUG1 binaries are pre-build and are present in the hex folder.

If you observe from the Arduino serial console, you will see the following: First, the boot messages are displayed.

18:39:22.110 -> <RST:IN>
18:39:22.507 -> <RST:OUT>
18:39:22.507 -> <REBOOT>
18:39:22.507 -> <startup>
18:39:22.507 -> F_CPU = 20000000
18:39:22.507 -> _AVR_IOXXX_H_ = ioavr64du32.h
18:39:22.507 -> __AVR_ARCH__ = 102
18:39:22.507 ->  UART=OFF
18:39:22.507 -> <WAITING>

If the application port is not connected, it will stop here. It will flash the LED and wait for a USB connection.

If you connect the application port to macos, you will get the following result.

18:39:28.505 -> RQ=13:0008:00:05:0004:0000:0000
18:39:28.505 ->  USB0_ADDR=4
18:39:28.505 -> RQ=13:0008:80:06:0100:0000:0008
18:39:28.505 ->  VID:PID=03EB:2177
18:39:28.505 -> RQ=13:0008:80:06:0100:0000:0012
18:39:28.505 ->  VID:PID=03EB:2177
18:39:28.505 -> RQ=13:0008:80:06:0302:0409:0002
18:39:28.505 -> RQ=13:0008:80:06:0302:0409:0046
18:39:28.505 -> RQ=13:0008:80:06:0301:0409:0002
18:39:28.505 -> RQ=13:0008:80:06:0301:0409:0034
18:39:28.543 -> RQ=13:0008:80:06:0303:0409:0002
18:39:28.543 -> RQ=13:0008:80:06:0303:0409:0016
18:39:28.543 -> RQ=13:0008:80:06:0200:0000:0009
18:39:28.543 -> RQ=13:0008:80:06:0200:0000:006B
18:39:28.543 -> RQ=13:0008:00:09:0001:0000:0000
18:39:28.543 -> <SC:01>
18:39:28.543 -> RQ=13:0008:81:06:2200:0000:0023

RQ= is a dump of a USB setup request packet. From the left, it shows the USB controller endpoint status, the setup packet length, and the contents of the first 8 bytes. For example, 00:05:0004:0000:0000 means to set USB address 0x0004 in the SET_ADDR request. For example, 80:06:0100:0000:0008 is a GET_DESCRIPTOR request that says "I want 8 bytes at offset 0 in the Device Descriptor." This sequence of steps is called USB enumeration.

If all goes well, the SET_CONFIGURATION request will be sent as 00:09:0001:0000:0000, which indicates that USB Interface#1 is now active on the host PC side.

Interface#1 is the VCP defined in the Device Descriptor. The device's internal state will be <SC:01>, which indicates that USB communication is now available. The LED display will change to a heartbeat.

---

Then open the VCP in the console, for 9600,8N1 it looks like this:

19:12:34.423 -> RQ=13:0008:21:22:0003:0001:0000
19:12:34.423 ->  SLS=03
19:12:34.423 -> <RST:IN>
19:12:34.533 -> <RST:OUT>
19:12:34.533 -> RQ=53:0008:21:20:0000:0001:0007
19:12:34.533 ->  UART=OFF
19:12:34.533 ->  BAUD=0000208D:C8
19:12:34.533 ->  UART=VCP
19:12:34.533 ->  SLE=80:25:00:00:00:00:08
19:12:34.533 -> RQ=13:0008:21:20:0000:0001:0007
19:12:34.533 ->  SLE=80:25:00:00:00:00:08
19:12:34.533 -> RQ=13:0008:21:20:0000:0001:0007
19:12:34.533 ->  SLE=80:25:00:00:00:00:08
19:12:34.533 -> RQ=13:0008:21:20:0000:0001:0007
19:12:34.569 ->  SLE=80:25:00:00:00:00:08

SLS=03 (SET_LINE_STATE) was requested, so DTR and RTS on the device are set. UPDI4AVR toggles the TRST signal when DTR is enabled, resetting the device. Also, SLE=80:25:00:00:00:00:08 (SET_LINE_ENCODING:0x00002580==9600bps) was requested, so the VCP device UART is initialized with these parameters. The host must respond honestly, as it repeatedly checks with GLE= (GET_LINE_ENCODING) to see if this is reflected correctly.

Tip

DEBUG=1 doesn't show VCP traffic, too much information.

19:12:36.172 -> RQ=13:0008:21:23:0000:0001:0000
19:12:36.172 ->  SB=0000
19:12:36.172 -> RQ=13:0008:21:22:0000:0001:0000
19:12:36.206 ->  SLS=00

Conversely, closing the serial console will generate SB= (SET_SEND_BREAK:0==OFF) and SLS=00 (SET_LINE_STATE:DTR=OFF,RTS=OFF) requests, which UPDI4AVR doesn't actually do anything with, as they may or may not be present depending on the host application implementation, but opening a VCP port will always result in SLE= and new communication parameters will be passed.

---

What kind of display will you get with UPDI programming? Try running the following command:

avrdude -cpickit4_updi -pavr64du28 -U fuse7:w:0:m

The result is a quick summary of the JTAG3 payload:

The scope number and command number are all the same, but the next two bytes have different meanings depending on the command number: they could be a subcommand, a memory type, a configuration memory index, or just padding.

19:33:53.364 -> SCOPE=01,C=10,S=00,L=96
19:33:53.364 ->  GEN_SIGN_ON
19:33:53.364 -> SCOPE=01,C=02,S=00,L=01
19:33:53.364 ->  GEN_GET_PARAM=00:01:02
19:33:53.364 ->  VESRION=01:20
19:33:53.364 -> SCOPE=12,C=01,S=00,L=00
19:33:53.364 ->  AVR_SET_PARAM=00:00:01:05
19:33:53.364 ->  ARCH=05
19:33:53.364 -> SCOPE=12,C=01,S=00,L=01
19:33:53.364 ->  AVR_SET_PARAM=00:01:01:01
19:33:53.364 ->  SESS_PURPOSE=01
19:33:53.364 -> SCOPE=12,C=01,S=01,L=00
19:33:53.364 ->  AVR_SET_PARAM=01:00:01:08
19:33:53.364 ->  CONNECTION=08
19:33:53.364 -> SCOPE=12,C=01,S=02,L=00
19:33:53.364 ->  AVR_SET_PARAM=02:00:30:00
19:33:53.364 ->  DEVICEDESC=30
19:33:53.364 ->  HVTYPE=02
19:33:53.364 -> SCOPE=12,C=10,S=00,L=00
19:33:53.364 ->  UPDI_SIGN_ON=EXT:00
19:33:53.364 ->  UART=OFF
19:33:53.402 ->  UART=UPDI
19:33:53.402 ->  BAUD=0164:C8
19:33:53.402 -> <STAT:A2> SIB=AVR     P:4D:1-3M2 (A3.KV00S.0)
19:33:53.402 ->  <NVM:34>
19:33:53.402 -> SCOPE=12,C=21,S=D3,L=00
19:33:53.440 ->  UPDI_READ=D3:000000:0020
19:33:53.440 -> SCOPE=12,C=15,S=41,L=56
19:33:53.440 ->  UPDI_ENTER_PROG
19:33:53.440 ->  PROG_KEY
19:33:53.440 ->  KEY=10
19:33:53.440 ->  PROGSTART=08
19:33:53.440 -> SCOPE=12,C=21,S=20,L=01
19:33:53.440 ->  UPDI_READ=20:000F01:0001
19:33:53.440 -> SCOPE=12,C=21,S=B4,L=80
19:33:53.440 ->  UPDI_READ=B4:001080:0003
19:33:53.473 -> SCOPE=12,C=23,S=B2,L=57
19:33:53.473 ->  UPDI_WRITE=B2:001057:0001
19:33:53.473 -> SCOPE=12,C=21,S=B2,L=57
19:33:53.473 ->  UPDI_READ=B2:001057:0001
19:33:53.473 -> SCOPE=12,C=16,S=00,L=00
19:33:53.473 ->  UPDI_LEAVE_PROG
19:33:53.473 -> SCOPE=12,C=11,S=00,L=00
19:33:53.473 ->  UPDI_SIGN_OFF
19:33:53.508 ->  <RST:1>
19:33:53.508 ->  UART=OFF
19:33:53.508 ->  BAUD=0000208D:C8
19:33:53.508 ->  UART=VCP
19:33:53.545 -> SCOPE=01,C=11,S=00,L=00
19:33:53.545 ->  GEN_SIGN_OFF

UPDI_SIGN_ON will be executed a maximum of two times after stopping VCP and modifying UART for UPDI communication, if the first time is not successful, a second time will be attempted for HV control.

UPDI_ENTER_PROG checks if memory rewrite is possible. For locked devices, the LSB of the PROGSTART status is set and only chip erase and USERROW writes are allowed from then on.

Finally, the device is reset with UPDI_SIGN_OFF, VCP communication is resumed, and GEN_SIGN_OFF exits JTAG3 payload mode.

Tip

Because TPI communications use the STK600-XPRG protocol for the payload, everything appears completely different except for the scope number.

More detailed information is available in DEBUG=2 or 3 modes. DEBUG=0 normally doesn't show anything but boot messages.