Teensyduino 1.54 Beta #9

Status
Not open for further replies.
The last answer from the link Kurt gave in #13 seems to describe the root cause and how to solve it. See here https://community.nxp.com/t5/i-MX-R...x0-relocation/m-p/981183/highlight/true#M5280. Looks like the change you did to the linker script in the commit I referenced above subtly changed something with the exidx definitions.
...
might be worth a try
As you mentioned it looked like there may be some solution there. The issue is the itcm stuff contains addresses that need to be patched up and there is a jump greater than max of 0x3FFF_FFFF.

It mentions cause is assembler code that creates an unwind table... I assume from your testing that the String class does something here as your previous example compiled without string... So is this sort of implying that some of this library is built to use exceptions, regardless that we specified no exceptions? If so what happens if it is triggered?

Note: I don't use this stuff, so I would probably never run in to it, but???
 
Just in case someone cares here additional info for the GCC9 problem:

If I change the following in the T4 linkerscript (line 72ff)

Code:
.text.csf : {
  FILL(0xFF)
  . = ALIGN(1024);
  KEEP(*(.csf))
} > FLASH

to

Code:
.text.csf : {
   FILL(0xFF)
   . = ALIGN(1024);
   KEEP(*(.csf))
} > [COLOR="#FF0000"][B]DTCM AT>[/B][/COLOR] FLASH

GCC 9 doesn't complain about the relocation problems and the example works. Same if I use ITCM or simply comment the complete section out (+ the reference in line 96)

I have to admit that I have no clue if this makes sense or will break other stuff, it is just a (hopefully useful) observation I made when I compared the working linker script from TD1.53 with the current one.
 
As you mentioned it looked like there may be some solution there. The issue is the itcm stuff contains addresses that need to be patched up and there is a jump greater than max of 0x3FFF_FFFF.

It mentions cause is assembler code that creates an unwind table... I assume from your testing that the String class does something here as your previous example compiled without string... So is this sort of implying that some of this library is built to use exceptions, regardless that we specified no exceptions? If so what happens if it is triggered?

Note: I don't use this stuff, so I would probably never run in to it, but???

Sorry, overlooked your post. I don't think this is related to the standard library since it works perfectly well with TD1.53. And I don't think that the standard library was exchanged between 1.53 and 1.54. See also my last post which indicates that the newly added csf section somehow generates the issue.
 
I'd like to ask everyone to please run this very simple Serial.begin() test program on Teensy 4.0 or 4.1, first with no serial monitor window on your screen. Do all 5 lines appear when you open it a few seconds after uploading? Then please upload again while the serial monitor is still on screen. Do you get all 5 lines when the serial monitor automatically reconnects? And which operating system are you using?

If you comment out Serial.begin(9600), you should get only part of the output, since this doesn't wait for the serial monitor.
...

Paul - Seems you found the sweet spot { 780ms ~= 753ms first/worst case below } for the wait in Serial begin for T_4.1 that takes longer than a T_4.0 ????? QSPI CHIPS are the difference ???
>> Having QSPI chips adds 400 ms to Serial coming online - but only ~50 ms to setup() entry? And T_4.0 into Serial online ~30 ms faster than T_4.1 with no QSPI.

Code below - but Sermon output is using TyCommander to Upload and Serial connected before and after the Upload:

For T_4.1 ( with FLASH and PSRAM )- Serial comes online with DOTS test about the same time it does waiting in Serial.begin::
Code:
first line
.....second line
.....third line
.....fourth line
..................................................last line
in setup @352 : [B][U]serial.begin Done @780[/U][/B] : end setup @2080
Code:
...............................................last line
in setup @352 : [B][U]Serial online dots @753[/U][/B] : end setup @1673

That shows timing after programming to T_4.1 with TyCommander With then without Serial.begin. Then same below for T_4.1 without ANY QSPI chips and then the T_4.0.

T_4.1 no QSPI::
Code:
first line
.....second line
.....third line
.....fourth line
..................................................last line
in setup @300 : [B]serial.begin Done @391[/B] : end setup @1691
Code:
..second line
.....third line
.....fourth line
..................................................last line
in setup @300 : [B]Serial online dots @380[/B] : end setup @1600


T_4.0::
Code:
first line
.....second line
.....third line
.....fourth line
..................................................last line
in setup @300 : [B]serial.begin Done @356[/B] : end setup @1656
Code:
....second line
.....third line
.....fourth line
..................................................last line
in setup @300 : [B]Serial online dots @360[/B] : end setup @1600

Prior code with timing setpoints recorded:
Code:
uint32_t SSS = 0, SBD = 0, SSE = 0, SOD = 0;
void setup() {
	SSS = millis();
	Serial.begin(9600); // JUST comment this line
	SBD = millis();
	digitalWrite(13, LOW);
	Serial.println("first line");
	dots(5);
	Serial.println("second line");
	dots(5);
	Serial.println("third line");
	dots(5);
	Serial.println("fourth line");
	dots(50);
	Serial.println("last line");
	SSE = millis();
}

void dots(int n) {
	for (int i = 0; i < n; i++) {
		[B]if ( 0 == SOD && Serial ) SOD = millis();[/B]
		delay(20);
		Serial.print(".");
	}
}

void loop() {
	if ( 0 != SSS && Serial ) {
		if ( SBD == SOD )
			Serial.printf( "in setup @%lu : serial.begin Done @%lu : end setup @%lu\n", SSS, SBD, SSE );
		else
			Serial.printf( "in setup @%lu : Serial online dots @%lu : end setup @%lu\n", SSS, SOD, SSE );
		SSS = 0;
	}
}
 
Last edited:
...first with no serial monitor window on your screen. Do all 5 lines appear when you open it a few seconds after uploading?

No. If I wait 3 seconds after uploading, I get nothing at all. If I wait less than that, I get various lengths of the tail end depending on how long I wait. If I open the monitor right away after uploading, I get all 5 lines.


Then please upload again while the serial monitor is still on screen. Do you get all 5 lines when the serial monitor automatically reconnects?
Yes.

And which operating system are you using?
Raspbian Stretch on a Pi 3B.
 
A minor oddity with the TeensyLoader in beta9: after the upload completes, the picture disappears.

Before loading
before.png

After loading
after.png

The loader continues to work fine. I don't see this behaviour with the 1.53 loader. This is on a Pi 3B running Raspbian Stretch.
 
Just as a follow to @Silverlock post with the picture disappearing after upload.

Tried it on windows10x64 and after upload picture does not disappear. Pi3b or linux issue?
Capture.PNG
 
It might be curious to pull out one of my RPIs... and try.

Wonder if maybe some form of resource issue, like maybe CPU running at full speed...
 
No. If I wait 3 seconds after uploading, I get nothing at all. If I wait less than that, I get various lengths of the tail end depending on how long I wait. If I open the monitor right away after uploading, I get all 5 lines.
...

Not included in p#29 results was the race turning on Serial 'sometime after upload' ... as @Silverlock and others found that works as expected up to the point of the end of the 'built in wait'.
> in the code extension shown it seemed to demonstrate the best case time when (tycommander) SerMon was online where that wait would not cause delay - but would just a few ms { 4ms to 27 ms } later assure all output was seen.


As far as the other @Silverlock note on the TLoader image display, with Windows that always looked right when it was used.
 
I installed on an RPI4 and installed Arduino 15 and this beta and so far it has worked... Did not run into issues of teensyduino sketch not showing image...
 
I have had the same sort of thing happening with my Linux machine but not quite the same. TD1.54B7-9 and Arduino 1.8.13- 1.8.15. I shows up more effectively with large uploads. If I move the loader dialog box from it's original position to another part of the screen and do another upload the picture in the dialog box will disappear for a split second and then come back just before the progress bar appears. But, the progress bar does not stay with the moved dialog box. I stays at the original position of the dialog box before it was moved.

Here is the verbose output from the loader.

Before dialog box moved:
Code:
15:58:32.127 (ports 5): add child:  subsys=usb, type=usb_interface, location=/sys/devices/pci0000:00/0000:00:1a.7/usb1/1-4/1-4:1.0
15:58:32.127 (ports 5):   parent location=/sys/devices/pci0000:00/0000:00:1a.7/usb1/1-4
15:58:32.127 (ports 5):   model=36 (Teensy 4.0)
15:58:32.127 (ports 5): usb_add: /dev/bus/usb/001/041 (Teensy 4.0) Serial
15:58:32.131 (ports 5): add child:  subsys=usb, type=usb_interface, location=/sys/devices/pci0000:00/0000:00:1a.7/usb1/1-4/1-4:1.1
15:58:32.131 (ports 5):   parent location=/sys/devices/pci0000:00/0000:00:1a.7/usb1/1-4
15:58:32.131 (ports 5): usb_add: /dev/bus/usb/001/041 (Teensy 4.0) Serial
15:58:32.136 (ports 5): unknown action: bind
15:58:32.203 (ports 5): add child:  subsys=tty, type=(null), location=/sys/devices/pci0000:00/0000:00:1a.7/usb1/1-4/1-4:1.0/tty/ttyACM0
15:58:32.203 (ports 5):   parent location=/sys/devices/pci0000:00/0000:00:1a.7/usb1/1-4
15:58:32.203 (ports 5):   devnode=/dev/ttyACM0, subsystem=tty, ifacenum=0
15:58:32.203 (ports 5): usb_add: /dev/ttyACM0 (Teensy 4.0) Serial
15:58:32.209 (ports 5): unknown action: bind
15:58:32.213 (ports 5): unknown action: bind
16:00:16.840 (post_compile 1): Begin, version=1.54-beta9
16:00:16.984 (loader): Teensy Loader 1.54-beta9, begin program
16:00:17.048 (loader): File "DiskIOTesting.ino.hex". 82944 bytes, 4% used
16:00:17.055 (loader): Listening for remote control on port 3149
16:00:17.055 (loader): initialized, showing main window
16:00:17.144 (loader): remote connection 16 opened
16:00:17.144 (post_compile 1): Sending command: comment: Teensyduino 1.54-beta9 - LINUX64 (teensy_post_compile)
16:00:17.144 (loader): remote cmd from 16: "comment: Teensyduino 1.54-beta9 - LINUX64 (teensy_post_compile)"
16:00:17.145 (loader): remote cmd from 16: "status"
16:00:17.151 (post_compile 1): Status: 1, 0, 0, 0, 0, 0, /tmp/arduino_build_731873/, DiskIOTesting.ino.hex
16:00:17.151 (post_compile 1): Sending command: dir:/tmp/arduino_build_908276/
16:00:17.151 (loader): remote cmd from 16: "dir:/tmp/arduino_build_908276/"
16:00:17.151 (post_compile 1): Sending command: file:Blink.pde.hex
16:00:17.152 (loader): remote cmd from 16: "file:Blink.pde.hex"
16:00:17.165 (loader): File "Blink.pde.hex". 17408 bytes, 1% used
16:00:17.174 (loader): remote cmd from 16: "status"
16:00:17.217 (post_compile 1): Status: 1, 0, 0, 0, 0, 0, /tmp/arduino_build_908276/, Blink.pde.hex
16:00:17.217 (post_compile 1): Sending command: auto:on
16:00:17.217 (loader): remote cmd from 16: "auto:on"
16:00:17.217 (post_compile 1): Disconnect
16:00:17.227 (loader): remote connection 16 closed
16:00:17.346 (post_compile 2): Begin, version=1.54-beta9
16:00:17.346 (loader): remote connection 16 opened
16:00:17.347 (post_compile 2): Sending command: comment: Teensyduino 1.54-beta9 - LINUX64 (teensy_post_compile)
16:00:17.348 (loader): remote cmd from 16: "comment: Teensyduino 1.54-beta9 - LINUX64 (teensy_post_compile)"
16:00:17.348 (loader): remote cmd from 16: "status"
16:00:17.348 (post_compile 2): Status: 1, 1, 0, 0, 0, 0, /tmp/arduino_build_908276/, Blink.pde.hex
16:00:17.348 (post_compile 2): Disconnect
16:00:17.358 (post_compile 3): Running teensy_reboot: /home/wwatson/arduino-1.8.15/hardware/teensy/../tools/teensy_reboot
16:00:17.358 (loader): remote connection 16 closed
16:00:17.358 (loader): remote connection 16 opened
16:00:17.359 (loader): remote connection 16 closed
16:00:17.359 (reboot 4): Begin, version=1.54-beta9
16:00:17.359 (reboot 4): location = /sys/devices/pci0000:00/0000:00:1a.7/usb1/1-4
16:00:17.359 (reboot 4): portlabel = /dev/ttyACM0 Serial
16:00:17.359 (reboot 4): portprotocol = Teensy
16:00:17.359 (reboot 4): Only location /sys/devices/pci0000:00/0000:00:1a.7/usb1/1-4 will be tried
16:00:17.379 (loader): remote connection 16 opened
16:00:17.380 (reboot 4): add device: subsys=usb, type=usb_device, location=/sys/devices/pci0000:00/0000:00:1a.7/usb1/1-4
16:00:17.380 (reboot 4):   devnode=/dev/bus/usb/001/041, subsystem=usb, ifacenum=-1
16:00:17.380 (reboot 4): add child:  subsys=usb, type=usb_interface, location=/sys/devices/pci0000:00/0000:00:1a.7/usb1/1-4/1-4:1.0
16:00:17.380 (reboot 4):   parent location=/sys/devices/pci0000:00/0000:00:1a.7/usb1/1-4
16:00:17.380 (reboot 4):   model=36 (Teensy 4.0)
16:00:17.381 (reboot 4): add child:  subsys=tty, type=(null), location=/sys/devices/pci0000:00/0000:00:1a.7/usb1/1-4/1-4:1.0/tty/ttyACM0
16:00:17.381 (reboot 4):   parent location=/sys/devices/pci0000:00/0000:00:1a.7/usb1/1-4
16:00:17.381 (reboot 4):   devnode=/dev/ttyACM0, subsystem=tty, ifacenum=0
16:00:17.381 (reboot 4): add child:  subsys=usb, type=usb_interface, location=/sys/devices/pci0000:00/0000:00:1a.7/usb1/1-4/1-4:1.1
16:00:17.381 (reboot 4):   parent location=/sys/devices/pci0000:00/0000:00:1a.7/usb1/1-4
16:00:17.425 (loader): remote cmd from 16: "show:arduino_attempt_reboot"
16:00:17.425 (loader): got request to show arduino rebooting message
16:00:17.427 (loader): remote cmd from 16: "comment: Teensyduino 1.54-beta9 - LINUX64 (teensy_reboot)"
16:00:17.427 (loader): remote cmd from 16: "status"
16:00:17.428 (loader): remote cmd from 16: "status"
16:00:17.445 (loader): remote connection 16 closed
16:00:17.482 (ports 5): unknown action: unbind
16:00:17.485 (ports 5): del child: location=/sys/devices/pci0000:00/0000:00:1a.7/usb1/1-4/1-4:1.0/tty/ttyACM0
16:00:17.485 (ports 5):   devnode=/dev/bus/usb/001/041, subsystem=usb, ifacenum=-1
16:00:17.485 (ports 5): unknown action: unbind
16:00:17.485 (ports 5): del child: location=/sys/devices/pci0000:00/0000:00:1a.7/usb1/1-4/1-4:1.1
16:00:17.486 (loader): remote connection 16 opened
16:00:17.496 (ports 5): del child: location=/sys/devices/pci0000:00/0000:00:1a.7/usb1/1-4/1-4:1.0
16:00:17.498 (ports 5): unknown action: unbind
16:00:17.501 (ports 5): del device: location=/sys/devices/pci0000:00/0000:00:1a.7/usb1/1-4
16:00:17.956 (ports 5): add device: subsys=usb, type=usb_device, location=/sys/devices/pci0000:00/0000:00:1a.7/usb1/1-4
16:00:17.956 (ports 5):   devnode=/dev/bus/usb/001/042, subsystem=usb, ifacenum=-1
16:00:17.956 (ports 5): usb_add: /dev/bus/usb/001/042 (Teensy 4.0) Bootloader
16:00:17.956 (ports 5): add child:  subsys=usb, type=usb_interface, location=/sys/devices/pci0000:00/0000:00:1a.7/usb1/1-4/1-4:1.0
16:00:17.956 (ports 5):   parent location=/sys/devices/pci0000:00/0000:00:1a.7/usb1/1-4
16:00:17.956 (ports 5): usb_add: /dev/bus/usb/001/042 (Teensy 4.0) Bootloader
16:00:17.958 (ports 5): add child:  subsys=hid, type=(null), location=/sys/devices/pci0000:00/0000:00:1a.7/usb1/1-4/1-4:1.0/0003:16C0:0478.0019
16:00:17.958 (ports 5):   parent location=/sys/devices/pci0000:00/0000:00:1a.7/usb1/1-4
16:00:17.958 (ports 5):   model=36 (Teensy 4.0)
16:00:17.958 (ports 5): usb_add: /dev/bus/usb/001/042 (Teensy 4.0) Bootloader
16:00:17.963 (ports 5): add child:  subsys=hidraw, type=(null), location=/sys/devices/pci0000:00/0000:00:1a.7/usb1/1-4/1-4:1.0/0003:16C0:0478.0019/hidraw/hidraw3
16:00:17.963 (ports 5):   parent location=/sys/devices/pci0000:00/0000:00:1a.7/usb1/1-4
16:00:17.963 (ports 5): usb_add: /dev/bus/usb/001/042 (Teensy 4.0) Bootloader
16:00:17.966 (ports 5): unknown action: bind
16:00:17.968 (ports 5): unknown action: bind
16:00:17.970 (ports 5): unknown action: bind
16:00:18.064 (loader): Device came online, code_size = 2031616
16:00:18.064 (loader): Board is: Teensy 4.0 (IMXRT1062), version 1.05
16:00:18.078 (ports 5): del child: location=/sys/devices/pci0000:00/0000:00:1a.7/usb1/1-4/1-4:1.0/0003:16C0:0478.0019/hidraw/hidraw3
16:00:18.078 (ports 5): unknown action: unbind
16:00:18.078 (ports 5): del child: location=/sys/devices/pci0000:00/0000:00:1a.7/usb1/1-4/1-4:1.0/0003:16C0:0478.0019
16:00:18.079 (ports 5): unknown action: unbind
16:00:18.080 (loader): File "Blink.pde.hex". 17408 bytes, 1% used
16:00:18.086 (loader): set background IMG_ONLINE
16:00:18.100 (loader): File "Blink.pde.hex". 17408 bytes, 1% used
16:00:18.106 (loader): elf appears to be for Teensy 4.0 (IMXRT1062) (2031616 bytes)
16:00:18.106 (loader): elf binary data matches hex file
16:00:18.106 (loader): elf file is for Teensy 4.0 (IMXRT1062)
16:00:18.112 (loader): begin operation
16:00:18.120 (loader): flash, block=0, bs=1024, auto=1
16:00:18.120 (loader):  gauge old value = 0
16:00:18.120 (loader): flash, block=1, bs=1024, auto=1
16:00:18.301 (loader):  gauge old value = 1
16:00:18.302 (loader): flash, block=2, bs=1024, auto=1
16:00:18.472 (loader):  gauge old value = 2
16:00:18.472 (loader): flash, block=3, bs=1024, auto=1
16:00:18.472 (loader):  gauge old value = 3
16:00:18.472 (loader): flash, block=4, bs=1024, auto=1
16:00:18.473 (loader):  gauge old value = 4
16:00:18.474 (loader): flash, block=5, bs=1024, auto=1
16:00:18.474 (loader):  gauge old value = 5
16:00:18.474 (loader): flash, block=6, bs=1024, auto=1
16:00:18.475 (loader):  gauge old value = 6
16:00:18.476 (loader): flash, block=7, bs=1024, auto=1
16:00:18.477 (loader):  gauge old value = 7
16:00:18.477 (loader): flash, block=8, bs=1024, auto=1
16:00:18.478 (loader):  gauge old value = 8
16:00:18.479 (loader): flash, block=9, bs=1024, auto=1
16:00:18.480 (loader):  gauge old value = 9
16:00:18.480 (loader): flash, block=10, bs=1024, auto=1
16:00:18.481 (loader):  gauge old value = 10
16:00:18.482 (loader): flash, block=11, bs=1024, auto=1
16:00:18.483 (loader):  gauge old value = 11
16:00:18.483 (loader): flash, block=12, bs=1024, auto=1
16:00:18.484 (loader):  gauge old value = 12
16:00:18.485 (loader): flash, block=13, bs=1024, auto=1
16:00:18.486 (loader):  gauge old value = 13
16:00:18.486 (loader): flash, block=14, bs=1024, auto=1
16:00:18.487 (loader):  gauge old value = 14
16:00:18.487 (loader): flash, block=15, bs=1024, auto=1
16:00:18.489 (loader):  gauge old value = 15
16:00:18.490 (loader): flash, block=16, bs=1024, auto=1
16:00:18.490 (loader):  gauge old value = 16
16:00:18.517 (loader): sending reboot
16:00:18.517 (loader): begin wait_until_offline
16:00:18.521 (ports 5): unknown action: unbind
16:00:18.523 (ports 5): del child: location=/sys/devices/pci0000:00/0000:00:1a.7/usb1/1-4/1-4:1.0
16:00:18.527 (ports 5): unknown action: unbind
16:00:18.528 (ports 5): del device: location=/sys/devices/pci0000:00/0000:00:1a.7/usb1/1-4
16:00:18.567 (loader): HID/linux: something changed, try reading a descriptor
16:00:18.567 (loader): HID/linux: Device was just disconnected
16:00:18.567 (loader): offline, waited 1
16:00:18.567 (loader): end operation, total time = 0.455 seconds
16:00:18.567 (loader): set background IMG_REBOOT_OK
16:00:18.569 (loader): redraw timer set, image 14 to show for 1200 ms
16:00:19.073 (ports 5): add device: subsys=usb, type=usb_device, location=/sys/devices/pci0000:00/0000:00:1a.7/usb1/1-4
16:00:19.073 (ports 5):   devnode=/dev/bus/usb/001/043, subsystem=usb, ifacenum=-1
16:00:19.073 (ports 5): usb_add: /dev/bus/usb/001/043 (Teensy 4.0) Serial
16:00:19.770 (loader): redraw, image 9
16:00:27.945 (loader): Verbose Info event

After dialog box moved:
Code:
15:58:32.127 (ports 5): add child:  subsys=usb, type=usb_interface, location=/sys/devices/pci0000:00/0000:00:1a.7/usb1/1-4/1-4:1.0
15:58:32.127 (ports 5):   parent location=/sys/devices/pci0000:00/0000:00:1a.7/usb1/1-4
15:58:32.127 (ports 5):   model=36 (Teensy 4.0)
15:58:32.127 (ports 5): usb_add: /dev/bus/usb/001/041 (Teensy 4.0) Serial
15:58:32.131 (ports 5): add child:  subsys=usb, type=usb_interface, location=/sys/devices/pci0000:00/0000:00:1a.7/usb1/1-4/1-4:1.1
15:58:32.131 (ports 5):   parent location=/sys/devices/pci0000:00/0000:00:1a.7/usb1/1-4
15:58:32.131 (ports 5): usb_add: /dev/bus/usb/001/041 (Teensy 4.0) Serial
15:58:32.136 (ports 5): unknown action: bind
15:58:32.203 (ports 5): add child:  subsys=tty, type=(null), location=/sys/devices/pci0000:00/0000:00:1a.7/usb1/1-4/1-4:1.0/tty/ttyACM0
15:58:32.203 (ports 5):   parent location=/sys/devices/pci0000:00/0000:00:1a.7/usb1/1-4
15:58:32.203 (ports 5):   devnode=/dev/ttyACM0, subsystem=tty, ifacenum=0
15:58:32.203 (ports 5): usb_add: /dev/ttyACM0 (Teensy 4.0) Serial
15:58:32.209 (ports 5): unknown action: bind
15:58:32.213 (ports 5): unknown action: bind
16:00:16.840 (post_compile 1): Begin, version=1.54-beta9
16:00:16.984 (loader): Teensy Loader 1.54-beta9, begin program
16:00:17.048 (loader): File "DiskIOTesting.ino.hex". 82944 bytes, 4% used
16:00:17.055 (loader): Listening for remote control on port 3149
16:00:17.055 (loader): initialized, showing main window
16:00:17.144 (loader): remote connection 16 opened
16:00:17.144 (post_compile 1): Sending command: comment: Teensyduino 1.54-beta9 - LINUX64 (teensy_post_compile)
16:00:17.144 (loader): remote cmd from 16: "comment: Teensyduino 1.54-beta9 - LINUX64 (teensy_post_compile)"
16:00:17.145 (loader): remote cmd from 16: "status"
16:00:17.151 (post_compile 1): Status: 1, 0, 0, 0, 0, 0, /tmp/arduino_build_731873/, DiskIOTesting.ino.hex
16:00:17.151 (post_compile 1): Sending command: dir:/tmp/arduino_build_908276/
16:00:17.151 (loader): remote cmd from 16: "dir:/tmp/arduino_build_908276/"
16:00:17.151 (post_compile 1): Sending command: file:Blink.pde.hex
16:00:17.152 (loader): remote cmd from 16: "file:Blink.pde.hex"
16:00:17.165 (loader): File "Blink.pde.hex". 17408 bytes, 1% used
16:00:17.174 (loader): remote cmd from 16: "status"
16:00:17.217 (post_compile 1): Status: 1, 0, 0, 0, 0, 0, /tmp/arduino_build_908276/, Blink.pde.hex
16:00:17.217 (post_compile 1): Sending command: auto:on
16:00:17.217 (loader): remote cmd from 16: "auto:on"
16:00:17.217 (post_compile 1): Disconnect
16:00:17.227 (loader): remote connection 16 closed
16:00:17.346 (post_compile 2): Begin, version=1.54-beta9
16:00:17.346 (loader): remote connection 16 opened
16:00:17.347 (post_compile 2): Sending command: comment: Teensyduino 1.54-beta9 - LINUX64 (teensy_post_compile)
16:00:17.348 (loader): remote cmd from 16: "comment: Teensyduino 1.54-beta9 - LINUX64 (teensy_post_compile)"
16:00:17.348 (loader): remote cmd from 16: "status"
16:00:17.348 (post_compile 2): Status: 1, 1, 0, 0, 0, 0, /tmp/arduino_build_908276/, Blink.pde.hex
16:00:17.348 (post_compile 2): Disconnect
16:00:17.358 (post_compile 3): Running teensy_reboot: /home/wwatson/arduino-1.8.15/hardware/teensy/../tools/teensy_reboot
16:00:17.358 (loader): remote connection 16 closed
16:00:17.358 (loader): remote connection 16 opened
16:00:17.359 (loader): remote connection 16 closed
16:00:17.359 (reboot 4): Begin, version=1.54-beta9
16:00:17.359 (reboot 4): location = /sys/devices/pci0000:00/0000:00:1a.7/usb1/1-4
16:00:17.359 (reboot 4): portlabel = /dev/ttyACM0 Serial
16:00:17.359 (reboot 4): portprotocol = Teensy
16:00:17.359 (reboot 4): Only location /sys/devices/pci0000:00/0000:00:1a.7/usb1/1-4 will be tried
16:00:17.379 (loader): remote connection 16 opened
16:00:17.380 (reboot 4): add device: subsys=usb, type=usb_device, location=/sys/devices/pci0000:00/0000:00:1a.7/usb1/1-4
16:00:17.380 (reboot 4):   devnode=/dev/bus/usb/001/041, subsystem=usb, ifacenum=-1
16:00:17.380 (reboot 4): add child:  subsys=usb, type=usb_interface, location=/sys/devices/pci0000:00/0000:00:1a.7/usb1/1-4/1-4:1.0
16:00:17.380 (reboot 4):   parent location=/sys/devices/pci0000:00/0000:00:1a.7/usb1/1-4
16:00:17.380 (reboot 4):   model=36 (Teensy 4.0)
16:00:17.381 (reboot 4): add child:  subsys=tty, type=(null), location=/sys/devices/pci0000:00/0000:00:1a.7/usb1/1-4/1-4:1.0/tty/ttyACM0
16:00:17.381 (reboot 4):   parent location=/sys/devices/pci0000:00/0000:00:1a.7/usb1/1-4
16:00:17.381 (reboot 4):   devnode=/dev/ttyACM0, subsystem=tty, ifacenum=0
16:00:17.381 (reboot 4): add child:  subsys=usb, type=usb_interface, location=/sys/devices/pci0000:00/0000:00:1a.7/usb1/1-4/1-4:1.1
16:00:17.381 (reboot 4):   parent location=/sys/devices/pci0000:00/0000:00:1a.7/usb1/1-4
16:00:17.425 (loader): remote cmd from 16: "show:arduino_attempt_reboot"
16:00:17.425 (loader): got request to show arduino rebooting message
16:00:17.427 (loader): remote cmd from 16: "comment: Teensyduino 1.54-beta9 - LINUX64 (teensy_reboot)"
16:00:17.427 (loader): remote cmd from 16: "status"
16:00:17.428 (loader): remote cmd from 16: "status"
16:00:17.445 (loader): remote connection 16 closed
16:00:17.482 (ports 5): unknown action: unbind
16:00:17.485 (ports 5): del child: location=/sys/devices/pci0000:00/0000:00:1a.7/usb1/1-4/1-4:1.0/tty/ttyACM0
16:00:17.485 (ports 5):   devnode=/dev/bus/usb/001/041, subsystem=usb, ifacenum=-1
16:00:17.485 (ports 5): unknown action: unbind
16:00:17.485 (ports 5): del child: location=/sys/devices/pci0000:00/0000:00:1a.7/usb1/1-4/1-4:1.1
16:00:17.486 (loader): remote connection 16 opened
16:00:17.496 (ports 5): del child: location=/sys/devices/pci0000:00/0000:00:1a.7/usb1/1-4/1-4:1.0
16:00:17.498 (ports 5): unknown action: unbind
16:00:17.501 (ports 5): del device: location=/sys/devices/pci0000:00/0000:00:1a.7/usb1/1-4
16:00:17.956 (ports 5): add device: subsys=usb, type=usb_device, location=/sys/devices/pci0000:00/0000:00:1a.7/usb1/1-4
16:00:17.956 (ports 5):   devnode=/dev/bus/usb/001/042, subsystem=usb, ifacenum=-1
16:00:17.956 (ports 5): usb_add: /dev/bus/usb/001/042 (Teensy 4.0) Bootloader
16:00:17.956 (ports 5): add child:  subsys=usb, type=usb_interface, location=/sys/devices/pci0000:00/0000:00:1a.7/usb1/1-4/1-4:1.0
16:00:17.956 (ports 5):   parent location=/sys/devices/pci0000:00/0000:00:1a.7/usb1/1-4
16:00:17.956 (ports 5): usb_add: /dev/bus/usb/001/042 (Teensy 4.0) Bootloader
16:00:17.958 (ports 5): add child:  subsys=hid, type=(null), location=/sys/devices/pci0000:00/0000:00:1a.7/usb1/1-4/1-4:1.0/0003:16C0:0478.0019
16:00:17.958 (ports 5):   parent location=/sys/devices/pci0000:00/0000:00:1a.7/usb1/1-4
16:00:17.958 (ports 5):   model=36 (Teensy 4.0)
16:00:17.958 (ports 5): usb_add: /dev/bus/usb/001/042 (Teensy 4.0) Bootloader
16:00:17.963 (ports 5): add child:  subsys=hidraw, type=(null), location=/sys/devices/pci0000:00/0000:00:1a.7/usb1/1-4/1-4:1.0/0003:16C0:0478.0019/hidraw/hidraw3
16:00:17.963 (ports 5):   parent location=/sys/devices/pci0000:00/0000:00:1a.7/usb1/1-4
16:00:17.963 (ports 5): usb_add: /dev/bus/usb/001/042 (Teensy 4.0) Bootloader
16:00:17.966 (ports 5): unknown action: bind
16:00:17.968 (ports 5): unknown action: bind
16:00:17.970 (ports 5): unknown action: bind
16:00:18.064 (loader): Device came online, code_size = 2031616
16:00:18.064 (loader): Board is: Teensy 4.0 (IMXRT1062), version 1.05
16:00:18.078 (ports 5): del child: location=/sys/devices/pci0000:00/0000:00:1a.7/usb1/1-4/1-4:1.0/0003:16C0:0478.0019/hidraw/hidraw3
16:00:18.078 (ports 5): unknown action: unbind
16:00:18.078 (ports 5): del child: location=/sys/devices/pci0000:00/0000:00:1a.7/usb1/1-4/1-4:1.0/0003:16C0:0478.0019
16:00:18.079 (ports 5): unknown action: unbind
16:00:18.080 (loader): File "Blink.pde.hex". 17408 bytes, 1% used
16:00:18.086 (loader): set background IMG_ONLINE
16:00:18.100 (loader): File "Blink.pde.hex". 17408 bytes, 1% used
16:00:18.106 (loader): elf appears to be for Teensy 4.0 (IMXRT1062) (2031616 bytes)
16:00:18.106 (loader): elf binary data matches hex file
16:00:18.106 (loader): elf file is for Teensy 4.0 (IMXRT1062)
16:00:18.112 (loader): begin operation
16:00:18.120 (loader): flash, block=0, bs=1024, auto=1
16:00:18.120 (loader):  gauge old value = 0
16:00:18.120 (loader): flash, block=1, bs=1024, auto=1
16:00:18.301 (loader):  gauge old value = 1
16:00:18.302 (loader): flash, block=2, bs=1024, auto=1
16:00:18.472 (loader):  gauge old value = 2
16:00:18.472 (loader): flash, block=3, bs=1024, auto=1
16:00:18.472 (loader):  gauge old value = 3
16:00:18.472 (loader): flash, block=4, bs=1024, auto=1
16:00:18.473 (loader):  gauge old value = 4
16:00:18.474 (loader): flash, block=5, bs=1024, auto=1
16:00:18.474 (loader):  gauge old value = 5
16:00:18.474 (loader): flash, block=6, bs=1024, auto=1
16:00:18.475 (loader):  gauge old value = 6
16:00:18.476 (loader): flash, block=7, bs=1024, auto=1
16:00:18.477 (loader):  gauge old value = 7
16:00:18.477 (loader): flash, block=8, bs=1024, auto=1
16:00:18.478 (loader):  gauge old value = 8
16:00:18.479 (loader): flash, block=9, bs=1024, auto=1
16:00:18.480 (loader):  gauge old value = 9
16:00:18.480 (loader): flash, block=10, bs=1024, auto=1
16:00:18.481 (loader):  gauge old value = 10
16:00:18.482 (loader): flash, block=11, bs=1024, auto=1
16:00:18.483 (loader):  gauge old value = 11
16:00:18.483 (loader): flash, block=12, bs=1024, auto=1
16:00:18.484 (loader):  gauge old value = 12
16:00:18.485 (loader): flash, block=13, bs=1024, auto=1
16:00:18.486 (loader):  gauge old value = 13
16:00:18.486 (loader): flash, block=14, bs=1024, auto=1
16:00:18.487 (loader):  gauge old value = 14
16:00:18.487 (loader): flash, block=15, bs=1024, auto=1
16:00:18.489 (loader):  gauge old value = 15
16:00:18.490 (loader): flash, block=16, bs=1024, auto=1
16:00:18.490 (loader):  gauge old value = 16
16:00:18.517 (loader): sending reboot
16:00:18.517 (loader): begin wait_until_offline
16:00:18.521 (ports 5): unknown action: unbind
16:00:18.523 (ports 5): del child: location=/sys/devices/pci0000:00/0000:00:1a.7/usb1/1-4/1-4:1.0
16:00:18.527 (ports 5): unknown action: unbind
16:00:18.528 (ports 5): del device: location=/sys/devices/pci0000:00/0000:00:1a.7/usb1/1-4
16:00:18.567 (loader): HID/linux: something changed, try reading a descriptor
16:00:18.567 (loader): HID/linux: Device was just disconnected
16:00:18.567 (loader): offline, waited 1
16:00:18.567 (loader): end operation, total time = 0.455 seconds
16:00:18.567 (loader): set background IMG_REBOOT_OK
16:00:18.569 (loader): redraw timer set, image 14 to show for 1200 ms
16:00:19.073 (ports 5): add device: subsys=usb, type=usb_device, location=/sys/devices/pci0000:00/0000:00:1a.7/usb1/1-4
16:00:19.073 (ports 5):   devnode=/dev/bus/usb/001/043, subsystem=usb, ifacenum=-1
16:00:19.073 (ports 5): usb_add: /dev/bus/usb/001/043 (Teensy 4.0) Serial
16:00:19.077 (ports 5): add child:  subsys=usb, type=usb_interface, location=/sys/devices/pci0000:00/0000:00:1a.7/usb1/1-4/1-4:1.0
16:00:19.077 (ports 5):   parent location=/sys/devices/pci0000:00/0000:00:1a.7/usb1/1-4
16:00:19.077 (ports 5):   model=36 (Teensy 4.0)
16:00:19.077 (ports 5): usb_add: /dev/bus/usb/001/043 (Teensy 4.0) Serial
16:00:19.078 (ports 5): add child:  subsys=usb, type=usb_interface, location=/sys/devices/pci0000:00/0000:00:1a.7/usb1/1-4/1-4:1.1
16:00:19.078 (ports 5):   parent location=/sys/devices/pci0000:00/0000:00:1a.7/usb1/1-4
16:00:19.078 (ports 5): usb_add: /dev/bus/usb/001/043 (Teensy 4.0) Serial
16:00:19.082 (ports 5): unknown action: bind
16:00:19.141 (ports 5): add child:  subsys=tty, type=(null), location=/sys/devices/pci0000:00/0000:00:1a.7/usb1/1-4/1-4:1.0/tty/ttyACM0
16:00:19.141 (ports 5):   parent location=/sys/devices/pci0000:00/0000:00:1a.7/usb1/1-4
16:00:19.141 (ports 5):   devnode=/dev/ttyACM0, subsystem=tty, ifacenum=0
16:00:19.141 (ports 5): usb_add: /dev/ttyACM0 (Teensy 4.0) Serial
16:00:19.148 (ports 5): unknown action: bind
16:00:19.150 (ports 5): unknown action: bind
16:00:19.770 (loader): redraw, image 9
16:00:27.945 (loader): Verbose Info event
16:03:01.399 (post_compile 6): Begin, version=1.54-beta9
16:03:01.399 (loader): remote connection 18 opened
16:03:01.402 (post_compile 6): Sending command: comment: Teensyduino 1.54-beta9 - LINUX64 (teensy_post_compile)
16:03:01.402 (loader): remote cmd from 18: "comment: Teensyduino 1.54-beta9 - LINUX64 (teensy_post_compile)"
16:03:01.403 (loader): remote cmd from 18: "status"
16:03:01.403 (loader): file changed
16:03:01.419 (loader): File "Blink.pde.hex". 17408 bytes, 1% used
16:03:01.425 (post_compile 6): Status: 1, 1, 0, 1, 0, 0, /tmp/arduino_build_908276/, Blink.pde.hex
16:03:01.425 (post_compile 6): Disconnect
16:03:01.436 (loader): remote connection 18 closed
16:03:01.548 (post_compile 7): Begin, version=1.54-beta9
16:03:01.548 (loader): remote connection 18 opened
16:03:01.548 (post_compile 7): Sending command: comment: Teensyduino 1.54-beta9 - LINUX64 (teensy_post_compile)
16:03:01.548 (loader): remote cmd from 18: "comment: Teensyduino 1.54-beta9 - LINUX64 (teensy_post_compile)"
16:03:01.548 (loader): remote cmd from 18: "status"
16:03:01.549 (post_compile 7): Status: 1, 1, 0, 1, 0, 0, /tmp/arduino_build_908276/, Blink.pde.hex
16:03:01.549 (post_compile 7): Disconnect
16:03:01.559 (post_compile 8): Running teensy_reboot: /home/wwatson/arduino-1.8.15/hardware/teensy/../tools/teensy_reboot
16:03:01.559 (loader): remote connection 18 closed
16:03:01.559 (loader): remote connection 18 opened
16:03:01.559 (loader): remote connection 18 closed
16:03:01.560 (reboot 9): Begin, version=1.54-beta9
16:03:01.560 (reboot 9): location = /sys/devices/pci0000:00/0000:00:1a.7/usb1/1-4
16:03:01.560 (reboot 9): portlabel = /dev/ttyACM0 Serial
16:03:01.560 (reboot 9): Only location /sys/devices/pci0000:00/0000:00:1a.7/usb1/1-4 will be tried
16:03:01.560 (reboot 9): portprotocol = Teensy
16:03:01.581 (loader): remote connection 18 opened
16:03:01.583 (reboot 9): add device: subsys=usb, type=usb_device, location=/sys/devices/pci0000:00/0000:00:1a.7/usb1/1-4
16:03:01.583 (reboot 9):   devnode=/dev/bus/usb/001/043, subsystem=usb, ifacenum=-1
16:03:01.583 (reboot 9): add child:  subsys=usb, type=usb_interface, location=/sys/devices/pci0000:00/0000:00:1a.7/usb1/1-4/1-4:1.0
16:03:01.583 (reboot 9):   parent location=/sys/devices/pci0000:00/0000:00:1a.7/usb1/1-4
16:03:01.583 (reboot 9):   model=36 (Teensy 4.0)
16:03:01.584 (reboot 9): add child:  subsys=tty, type=(null), location=/sys/devices/pci0000:00/0000:00:1a.7/usb1/1-4/1-4:1.0/tty/ttyACM0
16:03:01.584 (reboot 9):   parent location=/sys/devices/pci0000:00/0000:00:1a.7/usb1/1-4
16:03:01.584 (reboot 9):   devnode=/dev/ttyACM0, subsystem=tty, ifacenum=0
16:03:01.584 (reboot 9): add child:  subsys=usb, type=usb_interface, location=/sys/devices/pci0000:00/0000:00:1a.7/usb1/1-4/1-4:1.1
16:03:01.584 (reboot 9):   parent location=/sys/devices/pci0000:00/0000:00:1a.7/usb1/1-4
16:03:01.625 (loader): remote cmd from 18: "show:arduino_attempt_reboot"
16:03:01.625 (loader): got request to show arduino rebooting message
16:03:01.627 (loader): remote cmd from 18: "comment: Teensyduino 1.54-beta9 - LINUX64 (teensy_reboot)"
16:03:01.627 (loader): remote cmd from 18: "status"
16:03:01.628 (loader): remote cmd from 18: "status"
16:03:01.657 (loader): remote connection 18 closed
16:03:01.704 (ports 5): del child: location=/sys/devices/pci0000:00/0000:00:1a.7/usb1/1-4/1-4:1.0/tty/ttyACM0
16:03:01.704 (ports 5):   devnode=/dev/bus/usb/001/043, subsystem=usb, ifacenum=-1
16:03:01.704 (ports 5): unknown action: unbind
16:03:01.704 (ports 5): del child: location=/sys/devices/pci0000:00/0000:00:1a.7/usb1/1-4/1-4:1.1
16:03:01.706 (ports 5): unknown action: unbind
16:03:01.717 (ports 5): del child: location=/sys/devices/pci0000:00/0000:00:1a.7/usb1/1-4/1-4:1.0
16:03:01.718 (ports 5): unknown action: unbind
16:03:01.720 (ports 5): del device: location=/sys/devices/pci0000:00/0000:00:1a.7/usb1/1-4
16:03:02.145 (ports 5): add device: subsys=usb, type=usb_device, location=/sys/devices/pci0000:00/0000:00:1a.7/usb1/1-4
16:03:02.145 (ports 5):   devnode=/dev/bus/usb/001/044, subsystem=usb, ifacenum=-1
16:03:02.145 (ports 5): usb_add: /dev/bus/usb/001/044 (Teensy 4.0) Bootloader
16:03:02.152 (ports 5): add child:  subsys=usb, type=usb_interface, location=/sys/devices/pci0000:00/0000:00:1a.7/usb1/1-4/1-4:1.0
16:03:02.152 (ports 5):   parent location=/sys/devices/pci0000:00/0000:00:1a.7/usb1/1-4
16:03:02.152 (ports 5): usb_add: /dev/bus/usb/001/044 (Teensy 4.0) Bootloader
16:03:02.154 (ports 5): add child:  subsys=hid, type=(null), location=/sys/devices/pci0000:00/0000:00:1a.7/usb1/1-4/1-4:1.0/0003:16C0:0478.001A
16:03:02.154 (ports 5):   parent location=/sys/devices/pci0000:00/0000:00:1a.7/usb1/1-4
16:03:02.154 (ports 5):   model=36 (Teensy 4.0)
16:03:02.154 (ports 5): usb_add: /dev/bus/usb/001/044 (Teensy 4.0) Bootloader
16:03:02.180 (ports 5): add child:  subsys=hidraw, type=(null), location=/sys/devices/pci0000:00/0000:00:1a.7/usb1/1-4/1-4:1.0/0003:16C0:0478.001A/hidraw/hidraw3
16:03:02.180 (ports 5):   parent location=/sys/devices/pci0000:00/0000:00:1a.7/usb1/1-4
16:03:02.181 (ports 5): usb_add: /dev/bus/usb/001/044 (Teensy 4.0) Bootloader
16:03:02.181 (ports 5): unknown action: bind
16:03:02.181 (ports 5): unknown action: bind
16:03:02.181 (ports 5): unknown action: bind
16:03:02.286 (loader): Device came online, code_size = 2031616
16:03:02.286 (loader): Board is: Teensy 4.0 (IMXRT1062), version 1.05
16:03:02.292 (ports 5): del child: location=/sys/devices/pci0000:00/0000:00:1a.7/usb1/1-4/1-4:1.0/0003:16C0:0478.001A/hidraw/hidraw3
16:03:02.293 (ports 5): unknown action: unbind
16:03:02.293 (ports 5): del child: location=/sys/devices/pci0000:00/0000:00:1a.7/usb1/1-4/1-4:1.0/0003:16C0:0478.001A
16:03:02.293 (ports 5): unknown action: unbind
16:03:02.303 (loader): File "Blink.pde.hex". 17408 bytes, 1% used
16:03:02.309 (loader): set background IMG_ONLINE
16:03:02.323 (loader): File "Blink.pde.hex". 17408 bytes, 1% used
16:03:02.329 (loader): elf appears to be for Teensy 4.0 (IMXRT1062) (2031616 bytes)
16:03:02.330 (loader): elf binary data matches hex file
16:03:02.330 (loader): elf file is for Teensy 4.0 (IMXRT1062)
16:03:02.335 (loader): begin operation
16:03:02.344 (loader): flash, block=0, bs=1024, auto=1
16:03:02.344 (loader):  gauge old value = 0
16:03:02.344 (loader): flash, block=1, bs=1024, auto=1
16:03:02.521 (loader):  gauge old value = 1
16:03:02.523 (loader): flash, block=2, bs=1024, auto=1
16:03:02.523 (loader):  gauge old value = 2
16:03:02.523 (loader): flash, block=3, bs=1024, auto=1
16:03:02.524 (loader):  gauge old value = 3
16:03:02.524 (loader): flash, block=4, bs=1024, auto=1
16:03:02.524 (loader):  gauge old value = 4
16:03:02.525 (loader): flash, block=5, bs=1024, auto=1
16:03:02.525 (loader):  gauge old value = 5
16:03:02.525 (loader): flash, block=6, bs=1024, auto=1
16:03:02.526 (loader):  gauge old value = 6
16:03:02.527 (loader): flash, block=7, bs=1024, auto=1
16:03:02.528 (loader):  gauge old value = 7
16:03:02.529 (loader): flash, block=8, bs=1024, auto=1
16:03:02.530 (loader):  gauge old value = 8
16:03:02.530 (loader): flash, block=9, bs=1024, auto=1
16:03:02.531 (loader):  gauge old value = 9
16:03:02.531 (loader): flash, block=10, bs=1024, auto=1
16:03:02.533 (loader):  gauge old value = 10
16:03:02.533 (loader): flash, block=11, bs=1024, auto=1
16:03:02.534 (loader):  gauge old value = 11
16:03:02.534 (loader): flash, block=12, bs=1024, auto=1
16:03:02.536 (loader):  gauge old value = 12
16:03:02.536 (loader): flash, block=13, bs=1024, auto=1
16:03:02.537 (loader):  gauge old value = 13
16:03:02.537 (loader): flash, block=14, bs=1024, auto=1
16:03:02.538 (loader):  gauge old value = 14
16:03:02.539 (loader): flash, block=15, bs=1024, auto=1
16:03:02.540 (loader):  gauge old value = 15
16:03:02.540 (loader): flash, block=16, bs=1024, auto=1
16:03:02.541 (loader):  gauge old value = 16
16:03:02.563 (loader): sending reboot
16:03:02.564 (loader): begin wait_until_offline
16:03:02.568 (ports 5): unknown action: unbind
16:03:02.570 (ports 5): del child: location=/sys/devices/pci0000:00/0000:00:1a.7/usb1/1-4/1-4:1.0
16:03:02.575 (ports 5): unknown action: unbind
16:03:02.577 (ports 5): del device: location=/sys/devices/pci0000:00/0000:00:1a.7/usb1/1-4
16:03:02.614 (loader): HID/linux: something changed, try reading a descriptor
16:03:02.614 (loader): HID/linux: Device was just disconnected
16:03:02.614 (loader): offline, waited 1
16:03:02.614 (loader): end operation, total time = 0.279 seconds
16:03:02.614 (loader): set background IMG_REBOOT_OK
16:03:02.616 (loader): redraw timer set, image 14 to show for 1200 ms
16:03:03.115 (ports 5): add device: subsys=usb, type=usb_device, location=/sys/devices/pci0000:00/0000:00:1a.7/usb1/1-4
16:03:03.115 (ports 5):   devnode=/dev/bus/usb/001/045, subsystem=usb, ifacenum=-1
16:03:03.115 (ports 5): usb_add: /dev/bus/usb/001/045 (Teensy 4.0) Serial
16:03:03.816 (loader): redraw, image 9
16:03:09.817 (loader): Verbose Info event

Noticed there was a few 'unknown action: bind' and 'unknown action: unbind' involved.

I am running Ubuntu 18.04.1 with the Mate Desktop 1.20.1.
 
A minor oddity with the TeensyLoader in beta9: after the upload completes, the picture disappears.
.....
The loader continues to work fine. I don't see this behaviour with the 1.53 loader. This is on a Pi 3B running Raspbian Stretch.

The main change was linking with GTK3 libraries.

Version 1.53 links to GTK2. The switch to using GTK3 comes mostly from Ubuntu 20.04.2 (released in February 2021) shipping broken GTK2 which takes 30 seconds for programs to start up (not just Teensy Loader).
 
But, the progress bar does not stay with the moved dialog box.

At least this part is expected behavior. The progress bar is created as its own dialog box.

Creating the progress bar as part of the original window would be better... but also a lot of work that's probably never going to happen. Oo many other much more important things are needed from limited dev time.


Noticed there was a few 'unknown action: bind' and 'unknown action: unbind' involved.

Those are unrelated to the GUI. They're from the USB port detection. Apparently udev is sending other types of event notices we don't use. This can be safely ignored.
 
Creating the progress bar as part of the original window would be better... but also a lot of work that's probably never going to happen. Oo many other much more important things are needed from limited dev time.

Yeah, this for me this is only cosmetic. It still programs the Teensy:) Need to upgrade my Linux. I know you are extremely busy but thought I would bring it up if it helps.
 
Not sure what I can do about the blank window bug. Maybe we could (usually needlessly) redraw a couple extra times?

As wwatson says, it's only cosmetic; the loader still works afterwards. But if you're looking at where to insert a redraw or two, here's some more data points:

  • The picture disappears at the same time as the "Reboot OK" dialog box disappears.
  • If the loader window is minimized and then restored, the picture reappears.
  • If another window is brought in front of the loader window, and then the loader window is brought back to the front, the picture reappears.
  • If another window comes in front of part of the loader window, and then the loader windows is brought back in front, the portion of the picture that was behind the window reappears.
  • Pressing the button on the Teensy makes the background image appear.
  • The tooltips (Open HEX File, Program, Reboot, Automatic Mode) erase the part of the background image they overlay. Most of the time. It seems to depend on which way the cursor leaves the tooltip. Leaving vertically usually erases part of the background image; leaving horizontally (i.e. to another tooltip) usually doesn't.
 
I'd like to ask everyone to please run this very simple Serial.begin() test program on Teensy 4.0 or 4.1, first with no serial monitor window on your screen. Do all 5 lines appear when you open it a few seconds after uploading?
No, also interestingly copying for this reply a select all misses the last character but all text except the return is actually in copy buffer:
Image 5-20-21 at 9.50 AM.jpg

Code:
first line
...

Then please upload again while the serial monitor is still on screen. Do you get all 5 lines when the serial monitor automatically reconnects?
yes
And which operating system are you using?
macOS 10.15.7
The big question is whether these fixed delays, 0.7 seconds if the PC hasn't sent the configure device command or 2.0 second if it has, give a good serial monitor experience with all operating systems across a variety of computers of different speeds and amounts of installed software?
My projects tend to use built on displays where I want instant action, but debugging on the terminal so I have extensively used:
Code:
  while(!Serial && millis()<2000) //wait for lesser of Serial or 2 seconds.  Use 500 if not expecting debugging but it misses stuff
    ;
As the comment says, 500 is more tolerable but 2000 is required to get everything, so your numbers seem like a good choice.

I have to mention that this issue led me to a probably not smart procedure of pulling the usb plug with the monitor window still on and then reinserting so the teensy will restart with all the printout. I am convinced that this practice done enough times leads to an eventual random crash of the whole mac. It's random and dangerous to reproduce so I haven't submitted it as a short easily reproduced code example. Teensy monitor shows up in the crash log.
 
I'd like to ask everyone to please run this very simple Serial.begin() test program on Teensy 4.0 or 4.1, first with no serial monitor window on your screen.
Do all 5 lines appear when you open it a few seconds after uploading?

No.
I get this (with the usb-hub built into my dell screen; Windows 10)
Code:
first line
... (<-yes 3 dots)
All between "first line" and the "..." is missing, also the rest of the "..." line.

Then please upload again while the serial monitor is still on screen. Do you get all 5 lines when the serial monitor automatically reconnects?

Yes.
 
Having a new issue with 1.8.15 w beta9 on Teensy 4.0. Seems like all programs that use SD.h cause the serial monitor to go away along with Teensy freeze. Tried about 5 examples that run on 1.8.13 beta 7. These are the builtin examples modified for my hardware pins so I'm not posting. (yet)
 
I edited the test slightly to be able to see which of the dots(5) calls are printed:
Code:
void setup() {
  Serial.begin(9600);
  Serial.println("first line");
  dots(5);
  Serial.println("second line");
  dots(5);
  Serial.println("third line");
  dots(5);
  Serial.println("fourth line");
  dots(50);
  Serial.println("last line");
}

[COLOR=#00ff00]int l = 0;[/COLOR]
void dots(int n) {
  [COLOR=#00ff00]Serial.print(++l);[/COLOR]
  for (int i=0; i < n; i++) {
    delay(20);
    Serial.print(".");
  }
}

void loop() {
}

Output:
Code:
first line
1...
So it s the first dots call. Interesting: It prints a character more. There is no delay() call befor the print of "1". The # of characters printed is (including CRLF) 16.
 
Got closer to finding issue at #45. Was not SD.h but narrowed down to a function flexRamInfo2() that I got from somewhere.

Code:
#if defined(ARDUINO_TEENSY40)
  static const unsigned DTCM_START = 0x20000000UL;
  static const unsigned OCRAM_START = 0x20200000UL;
  static const unsigned OCRAM_SIZE = 512;
  static const unsigned FLASH_SIZE = 1984;
#elif defined(ARDUINO_TEENSY41)
  static const unsigned DTCM_START = 0x20000000UL;
  static const unsigned OCRAM_START = 0x20200000UL;
  static const unsigned OCRAM_SIZE = 512;
  static const unsigned FLASH_SIZE = 7936;
#if TEENSYDUINO>151  
  extern "C" uint8_t external_psram_size; 
#endif  
#endif

unsigned long maxstack(void) {
  extern unsigned long _ebss;
  extern unsigned long _estack;
  uint32_t e = (uintptr_t)&_ebss;
  uint32_t * p = (uint32_t*)e + 32;
  while (*p == 0) p++;
  return (unsigned) &_estack - (unsigned) p;
}

#if defined(__IMXRT1052__) || defined(__IMXRT1062__)
FLASHMEM
void flexRamInfo2(void) { // credit to FrankB and KurtE and defragster
  //extern unsigned long _stext;
  extern unsigned long _etext;
  extern unsigned long _sdata;
  extern unsigned long _ebss;
  extern unsigned long _flashimagelen;
  extern unsigned long _heap_start;
  extern unsigned long _estack;
  extern unsigned long _itcm_block_count;

  int itcm = (unsigned long)&_itcm_block_count;
  int dtcm = 0;
  int ocram = 0;
  uint32_t gpr17 = IOMUXC_GPR_GPR17;

  char __attribute__((unused)) dispstr[17] = {0};
  dispstr[16] = 0;

  for (int i = 15; i >= 0; i--) {
    switch ((gpr17 >> (i * 2)) & 0b11) {
      default: dispstr[15 - i] = '.'; break;
      case 0b01: dispstr[15 - i] = 'O'; ocram++; break;
      case 0b10: dispstr[15 - i] = 'D'; dtcm++; break;
      case 0b11: dispstr[15 - i] = 'I'; break;
    }
  }

  const char* fmtstr = "%-6s%7d %5.02f%% of %4dkB (%7d Bytes free) %s\n";
 
  Serial.printf(fmtstr, "FLASH:",
                (unsigned)&_flashimagelen,
                (double)((unsigned)&_flashimagelen) / (FLASH_SIZE * 1024) * 100,
                FLASH_SIZE,
                FLASH_SIZE * 1024 - ((unsigned)&_flashimagelen), "FLASHMEM, PROGMEM");
  
  unsigned long szITCM = itcm>0?(unsigned long)&_etext:0;
  Serial.printf(fmtstr, "ITCM:",
                szITCM,
                (double)(itcm>0?(((double)szITCM / (itcm * 32768) * 100)):0),
                itcm * 32,
                itcm * 32768 - szITCM, "(RAM1) FASTRUN");

  void* hTop = malloc(8);// current position of heap.
  unsigned heapTop = (unsigned) hTop;
  free(hTop);
  unsigned freeheap = (OCRAM_START + (OCRAM_SIZE * 1024)) - heapTop;
#if defined(ARDUINO_TEENSY41) && TEENSYDUINO>151
  if (external_psram_size > 0) {
  Serial.printf("PSRAM: %d MB\n", external_psram_size);
  } else {
  Serial.printf("PSRAM: none\n", external_psram_size);
  }   
#endif
  Serial.printf("OCRAM:\n  %7d Bytes (%d kB)\n", OCRAM_SIZE * 1024, OCRAM_SIZE);
  Serial.printf("- %7d Bytes (%d kB) DMAMEM\n", ((unsigned)&_heap_start - OCRAM_START), ((unsigned)&_heap_start - OCRAM_START) / 1024);
  Serial.printf("- %7d Bytes (%d kB) Heap\n", (heapTop - (unsigned)&_heap_start ), (heapTop - (unsigned)&_heap_start ) / 1024);
  Serial.printf("  %7d Bytes heap free (%d kB), %d Bytes OCRAM in use (%d kB).\n",
                freeheap, freeheap / 1024,
                heapTop - OCRAM_START, (heapTop - OCRAM_START) / 1024);

  unsigned _dtcm = (unsigned)&_estack - DTCM_START; //or, one could use dtcm * 32768 here.
  //unsigned stackinuse = (unsigned) &_estack -  (unsigned) __builtin_frame_address(0);
  unsigned stackinuse = maxstack();
  unsigned varsinuse = (unsigned)&_ebss - (unsigned)&_sdata;
  //unsigned freemem = _dtcm - stackinuse - varsinuse;
  Serial.printf("DTCM:\n  %7d Bytes (%d kB)\n", _dtcm, _dtcm / 1024);
  Serial.printf("- %7d Bytes (%d kB) global variables\n", varsinuse, varsinuse / 1024);
  Serial.printf("- %7d Bytes (%d kB) max. stack so far\n", stackinuse, stackinuse / 1024);
  Serial.println("=========");
  Serial.printf("  %7d Bytes free (%d kB), %d Bytes in use (%d kB).\n",
                _dtcm - (varsinuse + stackinuse), (_dtcm - (varsinuse + stackinuse)) / 1024,
                varsinuse + stackinuse, (varsinuse + stackinuse) / 1024
               );
}
#endif


void setup() {
  while(!Serial)
    ;
  flexRamInfo2();
}

void loop() {

}

Compiles with no issues on either version.
On a brand new T4, no connections, on desk:
on 1.8.13 with beta7 it runs fine.
on 1.8.15 with beta9 it takes the serial port offline and removes from the available ports although the terminal window remains open. Requires a button press to program again.

If I quickly hit the terminal window button after the Teensy's button the terminal window will open with title "[offline] (Teensy)". Pressing the button again the title will say something like "HID=0:0478.ff9c.24 Bootloader" before returning to "[offline] (Teensy)"

Runs fine on T4.1 with either. Neither Teensy has additional chips or stuff soldered on.
 
Last edited:
Issue with printf and flush on serial transfer

Noticed an issue with Serialx.printf vs Serialx.println and flush()function. Seems like printf followed by flush() doesn't actually wait sometimes. Characters are not lost there is just a delay before they can be read. If I wait >75us on a Teensy 3.2 they all come through.

Code:
void loop() {
  uint8_t ch;
  
  Serial.println("Ser #2 Sends: ID 0 1");
  
  Serial1.clear();
  //Serial2.printf("ID 0 1\n");   // this doesn't work
  Serial2.println("ID 0 1");       // this works
  Serial2.flush();
  
  while (Serial1.available()) {
    ch = Serial1.read();
    Serial.print(char(ch));
  }
  
  delay(1000);
}

Tested with Win 7 machine. Arduino 1.8.13 TeensyDuino 1.54Beta9

BUT interestingly this DOES work with printf()
Code:
Serial2.printf("ID 0 1 0123456789ABCDEF\n");
all characters come through. Strange. Baud rate doesn't matter.
 
Noticed an issue with Serialx.printf vs Serialx.println and flush()function. Seems like printf followed by flush() doesn't actually wait sometimes. Characters are not lost there is just a delay before they can be read. If I wait >75us on a Teensy 3.2 they all come through.
...
Tested with Win 7 machine. Arduino 1.8.13 TeensyDuino 1.54Beta9

BUT interestingly this DOES work with printf()
Code:
Serial2.printf("ID 0 1 0123456789ABCDEF\n");
all characters come through. Strange. Baud rate doesn't matter.

Assuming: Serial2 and Serial1 crossed Rx<>Tx to each other on same Teensy?
Not sure how that measures delay time?

Perhaps something like this? {code typed in browser - not tested here}:
Code:
void loop() {
  uint8_t ch;
[B]elapsedMicros foo;
uint32_t bar;[/B]

  Serial.println("First .println() Ser #2 Sends: ID 0 1");
  Serial1.clear();
  Serial2.println("ID 0 1");       // this works
  Serial2.flush();

[B]
foo=0;
  while (!Serial1.available());
bar= foo;
    Serial.printf( "micros before first char %lu :: .println() Ser2>Ser1" , bar );
[/B]  
  while (Serial1.available()) {
    ch = Serial1.read();
    Serial.print(char(ch));
  }
  delay(500);

  Serial.println("Second .printf() Ser #2 Sends: ID 0 1");
  Serial1.clear();
  Serial2.printf("ID 0 1\n");   // this doesn't work
  Serial2.flush();

[B]foo=0;
  while (!Serial1.available());
bar= foo;
    Serial.printf( "micros before first char %lu :: .printf()  Ser2>Ser1" , bar );
[/B]  
  while (Serial1.available()) {
    ch = Serial1.read();
    Serial.print(char(ch));
  }
  delay(1000);

}
 
Actually it may be the other way around...

That is Serial.print/write/printf.. Simply put the stuff into a software output queue, and then interrupt happens and one or more bytes are transferred to the uarts transfer queue. If I remember correctly Serial1 and Serial2 on T3.2 have a FIFO queue the other has double buffer.

Now the code has been with flush to simply wait until all of the data has been sent including one last interrupt for transfer complete will it return...

So the more interesting thing is how long after the last byte is sent, is it before the interrupt happens to remove the byte(s) from the hardware FIFO and put it into the software queue.
Some of this may depend on how many bytes that have been sent and are already in the queue. Again it has been awhile since I looked at the T3.x FIFO setup and how a settable watermark works with it. That is if the queue can hold lets say 8 items, such the processor force an interrupt every time a byte is received, or only after there are so many items in the queue (RX Watermark). And then how long to wait after you receive a byte and have not received anything else to force it...
 
Status
Not open for further replies.
Back
Top