Forum Rule: Always post complete source code & details to reproduce any issue!
Page 1 of 2 1 2 LastLast
Results 1 to 25 of 41

Thread: Loader crashes, Monitor closed, Linux

  1. #1
    Senior Member
    Join Date
    Dec 2016
    Posts
    138

    Loader crashes, Monitor closed, Linux

    The system is 64-bit Linux, Ubuntu 18.04, lots of memory, etc.

    1-Turn on PC
    2-Plug in T3.6 with Audio adapter, nothing else
    3-Open Serial Monitor
    4-Load simple INO
    Code:
    /* TestLoader.ino  Bob Larkin 3 July 2020
     */
    
    void setup(void) {
      Serial.begin(9600);
      delay(1000);
      Serial.println("Test Loader");
    }
    
    void loop() {
    }
    5-This works fine, over and over. But wait,
    6-Close Serial Monitor
    7-Load same little program. All seems OK
    8-Load it again and error message shows on IDE:
    Code:
    Arduino: 1.8.12 (Linux), TD: 1.52, Board: "Teensy 3.6, Serial, 180 MHz, Faster, US English"
    
    Sketch uses 14016 bytes (1%) of program storage space. Maximum is 1048576 bytes.
    Global variables use 4948 bytes (1%) of dynamic memory, leaving 257196 bytes for local variables. Maximum is 262144 bytes.
    /home/bob/arduino-1.8.12/hardware/teensy/../tools/teensy_post_compile -file=TestLoader.ino -path=/tmp/arduino_build_61261 -tools=/home/bob/arduino-1.8.12/hardware/teensy/../tools -board=TEENSY36 -reboot -port=/sys/devices/pci0000:00/0000:00:14.0/usb3/3-10 -portlabel=/dev/bus/usb/003/013 Bootloader -portprotocol=Teensy 
    An error occurred while uploading the sketch
    The Loader Verbose:
    Code:
    10:05:51.297 (ports 5): add child:  subsys=usb, type=usb_interface, location=/sys/devices/pci0000:00/0000:00:14.0/usb3/3-10/3-10:1.0
    10:05:51.297 (ports 5):   parent location=/sys/devices/pci0000:00/0000:00:14.0/usb3/3-10
    10:05:51.297 (ports 5):   model=34 (Teensy 3.6)
    10:05:51.297 (ports 5): usb_add: /dev/bus/usb/003/014 (Teensy 3.6) Serial
    10:05:51.297 (ports 5): add child:  subsys=usb, type=usb_interface, location=/sys/devices/pci0000:00/0000:00:14.0/usb3/3-10/3-10:1.1
    10:05:51.297 (ports 5):   parent location=/sys/devices/pci0000:00/0000:00:14.0/usb3/3-10
    10:05:51.297 (ports 5): usb_add: /dev/bus/usb/003/014 (Teensy 3.6) Serial
    10:05:51.299 (ports 5): add child:  subsys=tty, type=(null), location=/sys/devices/pci0000:00/0000:00:14.0/usb3/3-10/3-10:1.0/tty/ttyACM0
    10:05:51.299 (ports 5):   parent location=/sys/devices/pci0000:00/0000:00:14.0/usb3/3-10
    10:05:51.299 (ports 5):   devnode=/dev/ttyACM0, subsystem=tty, ifacenum=0
    10:05:51.299 (ports 5): usb_add: /dev/ttyACM0 (Teensy 3.6) Serial
    10:05:51.299 (ports 5): unknown action: bind
    10:05:51.300 (ports 5): unknown action: bind
    10:05:51.302 (ports 5): unknown action: bind
    10:06:11.429 (post_compile 26): Begin, version=1.52
    10:06:11.429 (loader): remote connection 8 opened
    10:06:11.430 (post_compile 26): Sending command: comment: Teensyduino 1.52 - LINUX64 (teensy_post_compile)
    10:06:11.430 (loader): remote cmd from 8: "comment: Teensyduino 1.52 - LINUX64 (teensy_post_compile)"
    10:06:11.431 (loader): remote cmd from 8: "status"
    10:06:11.431 (loader): file changed
    10:06:11.439 (loader): File "TestLoader.ino.hex". 14020 bytes, 1% used
    10:06:11.531 (post_compile 26): Status: 1, 1, 0, 5, 0, 0, /tmp/arduino_build_61261/, TestLoader.ino.hex
    10:06:11.531 (post_compile 26): Disconnect
    10:06:11.547 (post_compile 27): Begin, version=1.52
    10:06:11.562 (loader): remote connection 10 opened
    10:06:11.562 (post_compile 27): Sending command: comment: Teensyduino 1.52 - LINUX64 (teensy_post_compile)
    10:06:11.573 (loader): remote cmd from 10: "comment: Teensyduino 1.52 - LINUX64 (teensy_post_compile)"
    10:06:11.573 (loader): remote connection 8 closed
    10:06:11.574 (loader): remote cmd from 10: "status"
    10:06:11.659 (post_compile 27): Status: 1, 1, 0, 5, 0, 0, /tmp/arduino_build_61261/, TestLoader.ino.hex
    10:06:11.659 (post_compile 27): Disconnect
    10:06:11.669 (post_compile 28): Running teensy_reboot: /home/bob/arduino-1.8.12/hardware/teensy/../tools/teensy_reboot
    10:06:11.669 (loader): remote connection 10 closed
    10:06:11.670 (loader): remote connection 8 opened
    10:06:11.671 (reboot 29): Begin, version=1.52
    10:06:11.671 (reboot 29): location = /sys/devices/pci0000:00/0000:00:14.0/usb3/3-10
    10:06:11.671 (reboot 29): portlabel = /dev/bus/usb/003/013 Bootloader
    10:06:11.671 (reboot 29): portprotocol = Teensy
    10:06:11.671 (reboot 29): Only location /sys/devices/pci0000:00/0000:00:14.0/usb3/3-10 will be tried
    10:06:11.680 (loader): remote connection 8 closed
    10:06:11.682 (loader): remote connection 8 opened
    10:06:11.683 (reboot 29): add device: subsys=usb, type=usb_device, location=/sys/devices/pci0000:00/0000:00:14.0/usb3/3-10
    10:06:11.683 (reboot 29):   devnode=/dev/bus/usb/003/014, subsystem=usb, ifacenum=-1
    10:06:11.683 (reboot 29): add child:  subsys=usb, type=usb_interface, location=/sys/devices/pci0000:00/0000:00:14.0/usb3/3-10/3-10:1.0
    10:06:11.683 (reboot 29):   parent location=/sys/devices/pci0000:00/0000:00:14.0/usb3/3-10
    10:06:11.683 (reboot 29):   model=34 (Teensy 3.6)
    10:06:11.683 (reboot 29): add child:  subsys=tty, type=(null), location=/sys/devices/pci0000:00/0000:00:14.0/usb3/3-10/3-10:1.0/tty/ttyACM0
    10:06:11.683 (reboot 29):   parent location=/sys/devices/pci0000:00/0000:00:14.0/usb3/3-10
    10:06:11.683 (reboot 29):   devnode=/dev/ttyACM0, subsystem=tty, ifacenum=0
    10:06:11.683 (reboot 29): add child:  subsys=usb, type=usb_interface, location=/sys/devices/pci0000:00/0000:00:14.0/usb3/3-10/3-10:1.1
    10:06:11.683 (reboot 29):   parent location=/sys/devices/pci0000:00/0000:00:14.0/usb3/3-10
    10:06:11.731 (loader): remote cmd from 8: "show:arduino_attempt_reboot"
    10:06:11.731 (loader): got request to show arduino rebooting message
    10:06:11.734 (loader): remote cmd from 8: "comment: Teensyduino 1.52 - LINUX64 (teensy_reboot)"
    10:06:11.734 (loader): remote cmd from 8: "status"
    10:06:17.021 (ports 5): del child: location=/sys/devices/pci0000:00/0000:00:14.0/usb3/3-10/3-10:1.0/tty/ttyACM0
    10:06:17.021 (ports 5):   devnode=/dev/bus/usb/003/014, subsystem=usb, ifacenum=-1
    10:06:17.022 (ports 5): unknown action: unbind
    10:06:17.025 (ports 5): unknown action: unbind
    10:06:17.025 (ports 5): del child: location=/sys/devices/pci0000:00/0000:00:14.0/usb3/3-10/3-10:1.1
    10:06:17.026 (ports 5): del child: location=/sys/devices/pci0000:00/0000:00:14.0/usb3/3-10/3-10:1.0
    10:06:17.026 (ports 5): unknown action: unbind
    10:06:17.027 (ports 5): del device: location=/sys/devices/pci0000:00/0000:00:14.0/usb3/3-10
    10:06:17.077 (loader): remote cmd from 8: "status"
    10:06:17.137 (loader): remote connection 8 closed
    10:06:17.442 (ports 5): add device: subsys=usb, type=usb_device, location=/sys/devices/pci0000:00/0000:00:14.0/usb3/3-10
    10:06:17.442 (ports 5):   devnode=/dev/bus/usb/003/015, subsystem=usb, ifacenum=-1
    10:06:17.442 (ports 5): usb_add: /dev/bus/usb/003/015 (Teensy 3.6) Bootloader
    10:06:17.444 (ports 5): add child:  subsys=usb, type=usb_interface, location=/sys/devices/pci0000:00/0000:00:14.0/usb3/3-10/3-10:1.0
    10:06:17.444 (ports 5):   parent location=/sys/devices/pci0000:00/0000:00:14.0/usb3/3-10
    10:06:17.444 (ports 5): usb_add: /dev/bus/usb/003/015 (Teensy 3.6) Bootloader
    10:06:17.446 (ports 5): add child:  subsys=hid, type=(null), location=/sys/devices/pci0000:00/0000:00:14.0/usb3/3-10/3-10:1.0/0003:16C0:0478.000B
    10:06:17.446 (ports 5):   parent location=/sys/devices/pci0000:00/0000:00:14.0/usb3/3-10
    10:06:17.446 (ports 5):   model=34 (Teensy 3.6)
    10:06:17.446 (ports 5): usb_add: /dev/bus/usb/003/015 (Teensy 3.6) Bootloader
    10:06:17.448 (ports 5): add child:  subsys=hidraw, type=(null), location=/sys/devices/pci0000:00/0000:00:14.0/usb3/3-10/3-10:1.0/0003:16C0:0478.000B/hidraw/hidraw3
    10:06:17.448 (ports 5):   parent location=/sys/devices/pci0000:00/0000:00:14.0/usb3/3-10
    10:06:17.448 (ports 5): usb_add: /dev/bus/usb/003/015 (Teensy 3.6) Bootloader
    10:06:17.449 (ports 5): unknown action: bind
    10:06:17.451 (ports 5): unknown action: bind
    10:06:17.452 (ports 5): unknown action: bind
    10:06:17.566 (loader): Device came online, code_size = 1048576
    10:06:17.566 (loader): Board is: Teensy 3.6 (MK66FX1M0), version 1.03
    10:06:17.567 (ports 5): del child: location=/sys/devices/pci0000:00/0000:00:14.0/usb3/3-10/3-10:1.0/0003:16C0:0478.000B/hidraw/hidraw3
    10:06:17.567 (ports 5): unknown action: unbind
    10:06:17.568 (ports 5): del child: location=/sys/devices/pci0000:00/0000:00:14.0/usb3/3-10/3-10:1.0/0003:16C0:0478.000B
    10:06:17.568 (ports 5): unknown action: unbind
    10:06:17.573 (loader): File "TestLoader.ino.hex". 14020 bytes, 1% used
    10:06:17.576 (loader): set background IMG_ONLINE
    10:06:17.584 (loader): File "TestLoader.ino.hex". 14020 bytes, 1% used
    10:06:17.588 (loader): elf appears to be for Teensy 3.6 (MK66FX1M0) (1048576 bytes)
    10:06:17.588 (loader): elf binary data matches hex file
    10:06:17.588 (loader): elf file is for Teensy 3.6 (MK66FX1M0)
    10:06:17.591 (loader): begin operation
    10:06:17.596 (loader): flash, block=0, bs=1024, auto=1
    10:06:17.597 (loader):  gauge old value = 0
    10:06:17.598 (loader): flash, block=1, bs=1024, auto=1
    10:06:17.599 (loader):  gauge old value = 1
    10:06:17.612 (loader): flash, block=2, bs=1024, auto=1
    10:06:17.613 (loader):  gauge old value = 2
    10:06:17.614 (loader): flash, block=3, bs=1024, auto=1
    10:06:17.888 (loader):  gauge old value = 3
    10:06:17.890 (loader): flash, block=4, bs=1024, auto=1
    10:06:17.891 (loader):  gauge old value = 4
    10:06:17.893 (loader): flash, block=5, bs=1024, auto=1
    10:06:17.909 (loader):  gauge old value = 5
    10:06:17.911 (loader): flash, block=6, bs=1024, auto=1
    10:06:17.912 (loader):  gauge old value = 6
    10:06:17.914 (loader): flash, block=7, bs=1024, auto=1
    10:06:17.915 (loader):  gauge old value = 7
    10:06:17.917 (loader): flash, block=8, bs=1024, auto=1
    10:06:17.933 (loader):  gauge old value = 8
    10:06:17.935 (loader): flash, block=9, bs=1024, auto=1
    10:06:17.936 (loader):  gauge old value = 9
    10:06:17.937 (loader): flash, block=10, bs=1024, auto=1
    10:06:17.939 (loader):  gauge old value = 10
    10:06:17.940 (loader): flash, block=11, bs=1024, auto=1
    10:06:17.956 (loader):  gauge old value = 11
    10:06:17.958 (loader): flash, block=12, bs=1024, auto=1
    10:06:17.959 (loader):  gauge old value = 12
    10:06:17.961 (loader): flash, block=13, bs=1024, auto=1
    10:06:17.962 (loader):  gauge old value = 13
    10:06:17.965 (loader): sending reboot
    10:06:17.981 (loader): begin wait_until_offline
    10:06:18.050 (ports 5): unknown action: unbind
    10:06:18.051 (ports 5): del child: location=/sys/devices/pci0000:00/0000:00:14.0/usb3/3-10/3-10:1.0
    10:06:18.051 (ports 5): unknown action: unbind
    10:06:18.052 (ports 5): del device: location=/sys/devices/pci0000:00/0000:00:14.0/usb3/3-10
    10:06:18.081 (loader): HID/linux: something changed, try reading a descriptor
    10:06:18.081 (loader): HID/linux: Device was just disconnected
    10:06:18.081 (loader): offline, waited 2
    10:06:18.082 (loader): end operation, total time = 0.490 seconds
    10:06:18.082 (loader): set background IMG_REBOOT_OK
    10:06:18.083 (loader): redraw timer set, image 14 to show for 1200 ms
    10:06:18.506 (ports 5): add device: subsys=usb, type=usb_device, location=/sys/devices/pci0000:00/0000:00:14.0/usb3/3-10
    10:06:18.506 (ports 5):   devnode=/dev/bus/usb/003/016, subsystem=usb, ifacenum=-1
    10:06:18.506 (ports 5): usb_add: /dev/bus/usb/003/016 (Teensy 3.6) Serial
    10:06:19.283 (loader): redraw, image 9
    9-Any attempt to Load again results in a non-responsive Loader. Other indications are that portions of Linux has also been corrupted. The solution becomes a Linux reboot (sometimes needs multiple)

    This has been causing problems for some while, but they seemed "random". This now seems to isolate the issue to Loading without the Serial Monitor being open. I can now work around the issue by always having the Monitor open,or so it seems at this point.

    Can anyone duplicate this problem?
    Bob

  2. #2
    Senior Member+ manitou's Avatar
    Join Date
    Jan 2013
    Posts
    2,588
    sketch seems to work OK for me on ubuntu 18.04 (64-bit) with 1.8.12 and 1.53-beta2. i did see one fail to upload, but next upload was OK. nothing fatal
    Code:
    Opening Teensy Loader...
    Sketch uses 12016 bytes (1%) of program storage space. Maximum is 1048576 bytes.
    Global variables use 4196 bytes (1%) of dynamic memory, leaving 257948 bytes for local variables. Maximum is 262144 bytes.
    Sketch uses 12016 bytes (1%) of program storage space. Maximum is 1048576 bytes.
    Global variables use 4196 bytes (1%) of dynamic memory, leaving 257948 bytes for local variables. Maximum is 262144 bytes.
    Sketch uses 12016 bytes (1%) of program storage space. Maximum is 1048576 bytes.
    Global variables use 4196 bytes (1%) of dynamic memory, leaving 257948 bytes for local variables. Maximum is 262144 bytes.
    Sketch uses 12016 bytes (1%) of program storage space. Maximum is 1048576 bytes.
    Global variables use 4196 bytes (1%) of dynamic memory, leaving 257948 bytes for local variables. Maximum is 262144 bytes.
    An error occurred while uploading the sketch
    Sketch uses 12016 bytes (1%) of program storage space. Maximum is 1048576 bytes.
    Global variables use 4196 bytes (1%) of dynamic memory, leaving 257948 bytes for local variables. Maximum is 262144 bytes.
    Sketch uses 12016 bytes (1%) of program storage space. Maximum is 1048576 bytes.
    Global variables use 4196 bytes (1%) of dynamic memory, leaving 257948 bytes for local variables. Maximum is 262144 bytes.
    Sketch uses 12016 bytes (1%) of program storage space. Maximum is 1048576 bytes.
    Global variables use 4196 bytes (1%) of dynamic memory, leaving 257948 bytes for local variables. Maximum is 262144 bytes.
    Sketch uses 12016 bytes (1%) of program storage space. Maximum is 1048576 bytes.
    Global variables use 4196 bytes (1%) of dynamic memory, leaving 257948 bytes for local variables. Maximum is 262144 bytes.
    Sketch uses 12016 bytes (1%) of program storage space. Maximum is 1048576 bytes.
    Global variables use 4196 bytes (1%) of dynamic memory, leaving 257948 bytes for local variables. Maximum is 262144 bytes.
    do you have the latest udev rules ? https://www.pjrc.com/teensy/49-teensy.rules

    you could try while(!Serial) after Serial.begin

  3. #3
    Senior Member
    Join Date
    Dec 2016
    Posts
    138
    Thanks for the ideas.

    udev rule is per that link.

    I tried !Serial, as
    Code:
    /* TestLoader.ino  Bob Larkin 3 July 2020
     */
    
    void setup(void) {
      Serial.begin(9600);
      while(!Serial) ;
      Serial.println("Test Loader");
    }
    
    void loop() {
    }
    but no change, the problem is still there.

    Did you have the Serial Monitor closed? That turns it on and off for me. "Monitor on" is apparently no problem, but I'm never quite sure as I have seen so many variations of this over the last few weeks, and I was not thinking it related to the Serial Monitor.

    Bob

  4. #4
    Senior Member+ manitou's Avatar
    Join Date
    Jan 2013
    Posts
    2,588
    Quote Originally Posted by Bob Larkin View Post
    Thanks for the ideas.

    udev rule is per that link.



    Did you have the Serial Monitor closed? That turns it on and off for me. "Monitor on" is apparently no problem, but I'm never quite sure as I have seen so many variations of this over the last few weeks, and I was not thinking it related to the Serial Monitor.

    Bob
    yep, i tested with Serial Monitor open and closed as per your directions in post #1. maybe upgrade to teensyduino 1.53?

    with IDE, loader, and serial monitor closed, do a ps uax | grep teen to see if you happen to have any rogue teensy tasks running?

  5. #5
    Senior Member PaulStoffregen's Avatar
    Join Date
    Nov 2012
    Posts
    22,757
    There is a bug on Linux which causes "An error occurred while uploading the sketch" to be mistakenly printed, but then the upload happens successfully a second or two later. Or simply trying again works. It's on my list of low-priority bugs to fix.

    I use Ubuntu 18.04 as my primary desktop system. So far I've not seen Teensy Loader crash.

    Here's a few idea to hopefully collect more info about what's going wrong.

    1: Try running "tail -f /var/log/syslog" in a terminal, so you can see the Kernel's messages about USB device removal and detection. If Arduino and/or Teensy Loader aren't seeing your board, this can tell you with certainty whether it really is connected, at least as far as the Linux Kernel knows.

    2: In Arduino's Tools > Ports you should see Teensy twice, under "Teensy ports" and "Serial Ports". If you select the Teensy Ports device, all serial monitor communication is by native helper programs which communicate with the Java runtime via stdin/stdout/stderr. If you select the device in "Serial Ports", helpers are still used to communicate with Teensy Loader, but all communication done by the Serial Monitor is through Java libraries. Maybe this makes a difference, or maybe not?

    3: Quit Arduino, so it doesn't overwrite your changes. Then edit the file ".arduino15/preferences.txt". At the end, add "discovery.debug=true". When you run Arduino again, this will cause the it to print lots of info as it watches for USB devices to come and go.

    I have no idea what's going wrong on your system. I don't even have a clear picture of what you're really experiencing on your screen. But hopefully these 3 things can help you collect more info. I'd really like to understand what's happening, and if there is a bug in Teensy Loader or any other software, I definitely want to fix it. But first I need just know what's really happening and develop an understanding of why.

  6. #6
    Senior Member
    Join Date
    Dec 2016
    Posts
    138
    Thanks much, Paul. Here are the results of your experiments. But first, a couple of notes. The problem went away for many tries, yesterday. I brought it back by running this same sketch on a T4.0 (selecting proper device and serial port at each point). It has not gone away again after perhaps 20 tries, each necessarily including a full reboot of Linux. For each reboot, Linux required a hardware power off and sometimes two restarts. After each "Sketch/Load" in the IDE, I would eventually get a Crash Dialog Box, the one that asks if you want to submit a dump.

    Fortunately, Geany, the Terminal and the Arduino IDE continue to operate properly, afterthe Load attempt, so data can be gotten.

    Also, sometimes the crash is on the first Load and sometimes on the second!

    I have USB2 and USB3 that produce the same result. That suggests that USB hardware and low-level drivers are probably OK.

    Responding to your experiments: 1-running tail...syslog. Here is the output with my notes being pretty obvious:

    Code:
    Bob Note: Connect T3.6 to USB port,  syslog:
    
    Jul  5 09:30:22 bob-desktop kernel: [  309.304237] usb 3-10: new full-speed USB device number 4 using xhci_hcd
    Jul  5 09:30:22 bob-desktop kernel: [  309.452986] usb 3-10: New USB device found, idVendor=16c0, idProduct=0483
    Jul  5 09:30:22 bob-desktop kernel: [  309.452987] usb 3-10: New USB device strings: Mfr=1, Product=2, SerialNumber=3
    Jul  5 09:30:22 bob-desktop kernel: [  309.452988] usb 3-10: Product: USB Serial
    Jul  5 09:30:22 bob-desktop kernel: [  309.452990] usb 3-10: Manufacturer: Teensyduino
    Jul  5 09:30:22 bob-desktop kernel: [  309.452990] usb 3-10: SerialNumber: 3052850
    Jul  5 09:30:22 bob-desktop kernel: [  309.460241] cdc_acm 3-10:1.0: ttyACM0: USB ACM device
    Jul  5 09:30:22 bob-desktop kernel: [  309.460379] usbcore: registered new interface driver cdc_acm
    Jul  5 09:30:22 bob-desktop kernel: [  309.460380] cdc_acm: USB Abstract Control Model driver for USB modems and ISDN adapters
    Jul  5 09:30:22 bob-desktop upowerd[984]: unhandled action 'bind' on /sys/devices/pci0000:00/0000:00:14.0/usb3/3-10
    Jul  5 09:30:22 bob-desktop upowerd[984]: unhandled action 'bind' on /sys/devices/pci0000:00/0000:00:14.0/usb3/3-10/3-10:1.1
    Jul  5 09:30:22 bob-desktop upowerd[984]: unhandled action 'bind' on /sys/devices/pci0000:00/0000:00:14.0/usb3/3-10/3-10:1.0
    Jul  5 09:30:24 bob-desktop ModemManager[642]: <info>  [device /sys/devices/pci0000:00/0000:00:14.0/usb3/3-10] creating modem with plugin 'Generic' and '1' ports
    Jul  5 09:30:24 bob-desktop ModemManager[642]: <warn>  Couldn't create modem for device '/sys/devices/pci0000:00/0000:00:14.0/usb3/3-10': Failed to find primary AT port
    
    Bob Note: omit 2 lines here of cron activity with wifi
    
    Bob Note: Do Sketch/Upload,  syslog:
    
    Jul  5 09:35:52 bob-desktop kernel: [  639.237630] usb 3-10: USB disconnect, device number 4
    Jul  5 09:35:52 bob-desktop kernel: [  639.764548] ------------[ cut here ]------------
    Jul  5 09:35:52 bob-desktop kernel: [  639.764551] URB ffff9da213c90000 submitted while active
    Jul  5 09:35:52 bob-desktop kernel: [  639.764567] WARNING: CPU: 3 PID: 2066 at /build/linux-UhTchP/linux-4.15.0/drivers/usb/core/urb.c:364 usb_submit_urb+0x442/0x5b0
    Jul  5 09:35:52 bob-desktop kernel: [  639.764567] Modules linked in: cdc_acm usblp snd_hda_codec_hdmi intel_rapl x86_pkg_temp_thermal intel_powerclamp coretemp kvm_intel kvm irqbypass crct10dif_pclmul crc32_pclmul ghash_clmulni_intel pcbc mxm_wmi aesni_intel i915 88x2bu(OE) aes_x86_64 crypto_simd joydev drm_kms_helper glue_helper cryptd snd_hda_codec_realtek input_leds drm snd_hda_codec_generic intel_cstate i2c_algo_bit intel_rapl_perf fb_sys_fops cfg80211 snd_soc_rt5640 syscopyarea snd_hda_intel sysfillrect mei_me snd_hda_codec snd_soc_rl6231 mei lpc_ich sysimgblt snd_soc_core snd_hda_core snd_hwdep shpchp snd_compress ac97_bus snd_pcm_dmaengine snd_pcm snd_timer snd soundcore mac_hid intel_smartconnect wmi acpi_pad video sch_fq_codel parport_pc ppdev lp parport ip_tables x_tables autofs4 uas usb_storage hid_logitech_hidpp hid_logitech_dj
    Jul  5 09:35:52 bob-desktop kernel: [  639.764591]  hid_generic usbhid hid e1000e ahci ptp r8169 libahci mii pps_core
    Jul  5 09:35:52 bob-desktop kernel: [  639.764596] CPU: 3 PID: 2066 Comm: kworker/3:0 Tainted: G        W  OE    4.15.0-108-generic #109-Ubuntu
    Jul  5 09:35:52 bob-desktop kernel: [  639.764597] Hardware name: To Be Filled By O.E.M. To Be Filled By O.E.M./Z97 Extreme6, BIOS P1.40 09/15/2014
    Jul  5 09:35:52 bob-desktop kernel: [  639.764601] Workqueue: events acm_softint [cdc_acm]
    Jul  5 09:35:52 bob-desktop kernel: [  639.764605] RIP: 0010:usb_submit_urb+0x442/0x5b0
    Jul  5 09:35:52 bob-desktop kernel: [  639.764605] RSP: 0018:ffffb5e08598fdd8 EFLAGS: 00010282
    Jul  5 09:35:52 bob-desktop kernel: [  639.764607] RAX: 0000000000000000 RBX: ffff9da213c90000 RCX: 0000000000000006
    Jul  5 09:35:52 bob-desktop kernel: [  639.764608] RDX: 0000000000000007 RSI: 0000000000000082 RDI: ffff9da26fad6490
    Jul  5 09:35:52 bob-desktop kernel: [  639.764608] RBP: ffffb5e08598fe18 R08: 0000000000000404 R09: 0000000000000004
    Jul  5 09:35:52 bob-desktop kernel: [  639.764609] R10: 0000000000000000 R11: 0000000000000001 R12: 0000000000000008
    Jul  5 09:35:52 bob-desktop kernel: [  639.764610] R13: 0000000001400000 R14: ffff9da25a87f020 R15: 0000000000000000
    Jul  5 09:35:52 bob-desktop kernel: [  639.764611] FS:  0000000000000000(0000) GS:ffff9da26fac0000(0000) knlGS:0000000000000000
    Jul  5 09:35:52 bob-desktop kernel: [  639.764612] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
    Jul  5 09:35:52 bob-desktop kernel: [  639.764613] CR2: 00007f9d11600250 CR3: 0000000345e0a001 CR4: 00000000001606e0
    Jul  5 09:35:52 bob-desktop kernel: [  639.764614] Call Trace:
    Jul  5 09:35:52 bob-desktop kernel: [  639.764619]  ? __switch_to_asm+0x41/0x70
    Jul  5 09:35:52 bob-desktop kernel: [  639.764621]  ? __switch_to_asm+0x35/0x70
    Jul  5 09:35:52 bob-desktop kernel: [  639.764624]  acm_submit_read_urb+0x42/0x90 [cdc_acm]
    Jul  5 09:35:52 bob-desktop kernel: [  639.764626]  acm_softint+0x6b/0xe0 [cdc_acm]
    Jul  5 09:35:52 bob-desktop kernel: [  639.764630]  process_one_work+0x1de/0x420
    Jul  5 09:35:52 bob-desktop kernel: [  639.764632]  worker_thread+0x32/0x410
    Jul  5 09:35:52 bob-desktop kernel: [  639.764634]  kthread+0x121/0x140
    Jul  5 09:35:52 bob-desktop kernel: [  639.764635]  ? process_one_work+0x420/0x420
    Jul  5 09:35:52 bob-desktop kernel: [  639.764637]  ? kthread_create_worker_on_cpu+0x70/0x70
    Jul  5 09:35:52 bob-desktop kernel: [  639.764639]  ret_from_fork+0x35/0x40
    Jul  5 09:35:52 bob-desktop kernel: [  639.764640] Code: 83 f1 01 45 89 c8 41 81 c0 a4 03 00 00 e9 1b fe ff ff 48 89 fe 48 c7 c7 60 fc 76 99 89 45 d0 c6 05 03 26 ed 00 01 e8 9e 01 95 ff <0f> 0b 8b 45 d0 e9 00 fc ff ff 66 83 79 06 00 0f 84 10 ff ff ff 
    Jul  5 09:35:52 bob-desktop kernel: [  639.764655] ---[ end trace e3350ea79f55d69c ]---
    Jul  5 09:35:52 bob-desktop kernel: [  639.764658] ���Z�������Z���� T: urb 8 failed submission with -16
    Jul  5 09:35:52 bob-desktop kernel: [  639.764661] ���Z�������Z���� T: urb 10 failed submission with -16
    Jul  5 09:35:52 bob-desktop kernel: [  639.764663] ���Z�������Z���� T: urb 12 failed submission with -22
    Jul  5 09:35:52 bob-desktop kernel: [  639.764664] ���Z�������Z���� T: urb 13 failed submission with -22
    Jul  5 09:35:52 bob-desktop kernel: [  639.764668] BUG: unable to handle kernel paging request at 0000000414843238
    Jul  5 09:35:52 bob-desktop kernel: [  639.764672] IP: usb_submit_urb+0xe/0x5b0
    Jul  5 09:35:52 bob-desktop kernel: [  639.764673] PGD 0 P4D 0 
    Jul  5 09:35:52 bob-desktop kernel: [  639.764675] Oops: 0000 [#1] SMP PTI
    Jul  5 09:35:52 bob-desktop kernel: [  639.764677] Modules linked in: cdc_acm usblp snd_hda_codec_hdmi intel_rapl x86_pkg_temp_thermal intel_powerclamp coretemp kvm_intel kvm irqbypass crct10dif_pclmul crc32_pclmul ghash_clmulni_intel pcbc mxm_wmi aesni_intel i915 88x2bu(OE) aes_x86_64 crypto_simd joydev drm_kms_helper glue_helper cryptd snd_hda_codec_realtek input_leds drm snd_hda_codec_generic intel_cstate i2c_algo_bit intel_rapl_perf fb_sys_fops cfg80211 snd_soc_rt5640 syscopyarea snd_hda_intel sysfillrect mei_me snd_hda_codec snd_soc_rl6231 mei lpc_ich sysimgblt snd_soc_core snd_hda_core snd_hwdep shpchp snd_compress ac97_bus snd_pcm_dmaengine snd_pcm snd_timer snd soundcore mac_hid intel_smartconnect wmi acpi_pad video sch_fq_codel parport_pc ppdev lp parport ip_tables x_tables autofs4 uas usb_storage hid_logitech_hidpp hid_logitech_dj
    Jul  5 09:35:52 bob-desktop kernel: [  639.764692]  hid_generic usbhid hid e1000e ahci ptp r8169 libahci mii pps_core
    Jul  5 09:35:52 bob-desktop kernel: [  639.764696] CPU: 3 PID: 2066 Comm: kworker/3:0 Tainted: G        W  OE    4.15.0-108-generic #109-Ubuntu
    Jul  5 09:35:52 bob-desktop kernel: [  639.764697] Hardware name: To Be Filled By O.E.M. To Be Filled By O.E.M./Z97 Extreme6, BIOS P1.40 09/15/2014
    Jul  5 09:35:52 bob-desktop kernel: [  639.764700] Workqueue: events acm_softint [cdc_acm]
    Jul  5 09:35:52 bob-desktop kernel: [  639.764703] RIP: 0010:usb_submit_urb+0xe/0x5b0
    Jul  5 09:35:52 bob-desktop kernel: [  639.764704] RSP: 0018:ffffb5e08598fe20 EFLAGS: 00010202
    Jul  5 09:35:52 bob-desktop kernel: [  639.764705] RAX: 00000000ffffffea RBX: ffff9da25a87f020 RCX: 0000000000000006
    Jul  5 09:35:52 bob-desktop kernel: [  639.764707] RDX: 0000000001400000 RSI: 0000000001400000 RDI: 0000000414843180
    Jul  5 09:35:52 bob-desktop kernel: [  639.764708] RBP: ffffb5e08598fe48 R08: 0000000000000425 R09: 0000000000000004
    Jul  5 09:35:52 bob-desktop kernel: [  639.764709] R10: 0000000000000000 R11: ffffffff99f6080d R12: 000000000000000e
    Jul  5 09:35:52 bob-desktop kernel: [  639.764710] R13: 000000000000000e R14: ffff9da25a87f020 R15: 0000000000000000
    Jul  5 09:35:52 bob-desktop kernel: [  639.764712] FS:  0000000000000000(0000) GS:ffff9da26fac0000(0000) knlGS:0000000000000000
    Jul  5 09:35:52 bob-desktop kernel: [  639.764713] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
    Jul  5 09:35:52 bob-desktop kernel: [  639.764714] CR2: 0000000414843238 CR3: 0000000345e0a001 CR4: 00000000001606e0
    Jul  5 09:35:52 bob-desktop kernel: [  639.764715] Call Trace:
    Jul  5 09:35:52 bob-desktop kernel: [  639.764717]  ? acm_submit_read_urb+0x42/0x90 [cdc_acm]
    Jul  5 09:35:52 bob-desktop kernel: [  639.764720]  acm_softint+0x6b/0xe0 [cdc_acm]
    Jul  5 09:35:52 bob-desktop kernel: [  639.764722]  process_one_work+0x1de/0x420
    Jul  5 09:35:52 bob-desktop kernel: [  639.764725]  worker_thread+0x32/0x410
    Jul  5 09:35:52 bob-desktop kernel: [  639.764727]  kthread+0x121/0x140
    Jul  5 09:35:52 bob-desktop kernel: [  639.764729]  ? process_one_work+0x420/0x420
    Jul  5 09:35:52 bob-desktop kernel: [  639.764730]  ? kthread_create_worker_on_cpu+0x70/0x70
    Jul  5 09:35:52 bob-desktop kernel: [  639.764733]  ret_from_fork+0x35/0x40
    Jul  5 09:35:52 bob-desktop kernel: [  639.764735] Code: f3 c3 48 83 c7 10 31 c9 ba 01 00 00 00 be 03 00 00 00 e8 a6 76 99 ff 5d c3 0f 1f 40 00 0f 1f 44 00 00 48 85 ff 0f 84 98 05 00 00 <48> 83 bf b8 00 00 00 00 0f 84 8a 05 00 00 55 48 89 e5 41 57 41 
    Jul  5 09:35:52 bob-desktop kernel: [  639.764751] RIP: usb_submit_urb+0xe/0x5b0 RSP: ffffb5e08598fe20
    Jul  5 09:35:52 bob-desktop kernel: [  639.764752] CR2: 0000000414843238
    Jul  5 09:35:52 bob-desktop kernel: [  639.764754] ---[ end trace e3350ea79f55d69d ]---
    Jul  5 09:36:23 bob-desktop kernel: [  670.459850] cdc_acm 3-10:1.0: failed to set dtr/rts
    Jul  5 09:36:23 bob-desktop kernel: [  670.459878] ------------[ cut here ]------------
    Jul  5 09:36:23 bob-desktop kernel: [  670.459893] WARNING: CPU: 3 PID: 0 at /build/linux-UhTchP/linux-4.15.0/kernel/workqueue.c:1446 __queue_work+0x36c/0x420
    Jul  5 09:36:23 bob-desktop kernel: [  670.459895] Modules linked in: cdc_acm usblp snd_hda_codec_hdmi intel_rapl x86_pkg_temp_thermal intel_powerclamp coretemp kvm_intel kvm irqbypass crct10dif_pclmul crc32_pclmul ghash_clmulni_intel pcbc mxm_wmi aesni_intel i915 88x2bu(OE) aes_x86_64 crypto_simd joydev drm_kms_helper glue_helper cryptd snd_hda_codec_realtek input_leds drm snd_hda_codec_generic intel_cstate i2c_algo_bit intel_rapl_perf fb_sys_fops cfg80211 snd_soc_rt5640 syscopyarea snd_hda_intel sysfillrect mei_me snd_hda_codec snd_soc_rl6231 mei lpc_ich sysimgblt snd_soc_core snd_hda_core snd_hwdep shpchp snd_compress ac97_bus snd_pcm_dmaengine snd_pcm snd_timer snd soundcore mac_hid intel_smartconnect wmi acpi_pad video sch_fq_codel parport_pc ppdev lp parport ip_tables x_tables autofs4 uas usb_storage hid_logitech_hidpp hid_logitech_dj
    Jul  5 09:36:23 bob-desktop kernel: [  670.459933]  hid_generic usbhid hid e1000e ahci ptp r8169 libahci mii pps_core
    Jul  5 09:36:23 bob-desktop kernel: [  670.459941] CPU: 3 PID: 0 Comm: swapper/3 Tainted: G      D W  OE    4.15.0-108-generic #109-Ubuntu
    Jul  5 09:36:23 bob-desktop kernel: [  670.459943] Hardware name: To Be Filled By O.E.M. To Be Filled By O.E.M./Z97 Extreme6, BIOS P1.40 09/15/2014
    Jul  5 09:36:23 bob-desktop kernel: [  670.459947] RIP: 0010:__queue_work+0x36c/0x420
    Jul  5 09:36:23 bob-desktop kernel: [  670.459949] RSP: 0018:ffff9da26fac3ca0 EFLAGS: 00010086
    Jul  5 09:36:23 bob-desktop kernel: [  670.459951] RAX: 0000000000000024 RBX: 0000000000000003 RCX: 0000000000000006
    Jul  5 09:36:23 bob-desktop kernel: [  670.459953] RDX: 0000000000000000 RSI: 00000000000000f6 RDI: ffff9da26fad6490
    Jul  5 09:36:23 bob-desktop kernel: [  670.459955] RBP: ffff9da26fac3cd8 R08: 0000000000000447 R09: 000000000000000f
    Jul  5 09:36:23 bob-desktop kernel: [  670.459957] R10: 0000000000000040 R11: ffffffff99f6080d R12: ffff9da25f418c00
    Jul  5 09:36:23 bob-desktop kernel: [  670.459959] R13: 0000000000002000 R14: ffff9da25a87f790 R15: ffff9da26fae6500
    Jul  5 09:36:23 bob-desktop kernel: [  670.459962] FS:  0000000000000000(0000) GS:ffff9da26fac0000(0000) knlGS:0000000000000000
    Jul  5 09:36:23 bob-desktop kernel: [  670.459964] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
    Jul  5 09:36:23 bob-desktop kernel: [  670.459966] CR2: 00007fd49cbdb180 CR3: 0000000345e0a005 CR4: 00000000001606e0
    Jul  5 09:36:23 bob-desktop kernel: [  670.459968] Call Trace:
    Jul  5 09:36:23 bob-desktop kernel: [  670.459970]  <IRQ>
    Jul  5 09:36:23 bob-desktop kernel: [  670.459977]  queue_work_on+0x38/0x40
    Jul  5 09:36:23 bob-desktop kernel: [  670.459983]  acm_write_bulk+0x70/0x80 [cdc_acm]
    Jul  5 09:36:23 bob-desktop kernel: [  670.459989]  __usb_hcd_giveback_urb+0xa4/0x140
    Jul  5 09:36:23 bob-desktop kernel: [  670.459993]  usb_hcd_giveback_urb+0xb8/0xe0
    Jul  5 09:36:23 bob-desktop kernel: [  670.459997]  xhci_giveback_urb_in_irq.isra.40+0x84/0xf0
    Jul  5 09:36:23 bob-desktop kernel: [  670.460001]  handle_cmd_completion+0x99f/0x1050
    Jul  5 09:36:23 bob-desktop kernel: [  670.460006]  xhci_irq+0x349/0x460
    Jul  5 09:36:23 bob-desktop kernel: [  670.460011]  ? lapic_next_deadline+0x26/0x30
    Jul  5 09:36:23 bob-desktop kernel: [  670.460014]  xhci_msi_irq+0x11/0x20
    Jul  5 09:36:23 bob-desktop kernel: [  670.460020]  __handle_irq_event_percpu+0x44/0x1a0
    Jul  5 09:36:23 bob-desktop kernel: [  670.460024]  handle_irq_event_percpu+0x32/0x80
    Jul  5 09:36:23 bob-desktop kernel: [  670.460028]  handle_irq_event+0x3b/0x60
    Jul  5 09:36:23 bob-desktop kernel: [  670.460032]  handle_edge_irq+0x83/0x1a0
    Jul  5 09:36:23 bob-desktop kernel: [  670.460036]  handle_irq+0x20/0x30
    Jul  5 09:36:23 bob-desktop kernel: [  670.460040]  do_IRQ+0x50/0xe0
    Jul  5 09:36:23 bob-desktop kernel: [  670.460045]  common_interrupt+0x8c/0x8c
    Jul  5 09:36:23 bob-desktop kernel: [  670.460047]  </IRQ>
    Jul  5 09:36:23 bob-desktop kernel: [  670.460053] RIP: 0010:cpuidle_enter_state+0xa7/0x2f0
    Jul  5 09:36:23 bob-desktop kernel: [  670.460055] RSP: 0018:ffffb5e081927e68 EFLAGS: 00000246 ORIG_RAX: ffffffffffffffdc
    Jul  5 09:36:23 bob-desktop kernel: [  670.460059] RAX: ffff9da26fae1840 RBX: 0000009c1a85b11f RCX: 000000000000001f
    Jul  5 09:36:23 bob-desktop kernel: [  670.460062] RDX: 0000009c1a85b11f RSI: fffffffb09f8202c RDI: 0000000000000000
    Jul  5 09:36:23 bob-desktop kernel: [  670.460065] RBP: ffffb5e081927ea8 R08: 0000000000000004 R09: 0000000000021080
    Jul  5 09:36:23 bob-desktop kernel: [  670.460069] R10: ffffb5e081927e38 R11: 00000243a80c8b08 R12: ffff9da26faeba00
    Jul  5 09:36:23 bob-desktop kernel: [  670.460071] R13: 0000000000000005 R14: ffffffff99b733f8 R15: 0000000000000000
    Jul  5 09:36:23 bob-desktop kernel: [  670.460079]  ? cpuidle_enter_state+0x97/0x2f0
    Jul  5 09:36:23 bob-desktop kernel: [  670.460084]  cpuidle_enter+0x17/0x20
    Jul  5 09:36:23 bob-desktop kernel: [  670.460091]  call_cpuidle+0x23/0x40
    Jul  5 09:36:23 bob-desktop kernel: [  670.460096]  do_idle+0x18c/0x1f0
    Jul  5 09:36:23 bob-desktop kernel: [  670.460101]  cpu_startup_entry+0x73/0x80
    Jul  5 09:36:23 bob-desktop kernel: [  670.460106]  start_secondary+0x1ab/0x200
    Jul  5 09:36:23 bob-desktop kernel: [  670.460112]  secondary_startup_64+0xa5/0xb0
    Jul  5 09:36:23 bob-desktop kernel: [  670.460115] Code: 24 20 74 14 e8 76 90 00 00 48 85 c0 74 0a 48 8b 40 20 4c 3b 60 08 74 31 0f 0b e9 f7 fd ff ff 48 c7 c7 78 4a 6b 99 e8 a4 92 04 00 <0f> 0b 49 8b 3f c6 07 00 0f 1f 40 00 e9 da fd ff ff 41 83 cc 02 
    Jul  5 09:36:23 bob-desktop kernel: [  670.460141] ---[ end trace e3350ea79f55d69e ]---
    Jul  5 09:36:23 bob-desktop kernel: [  670.460233] BUG: unable to handle kernel paging request at ffff9da25b513554
    Jul  5 09:36:23 bob-desktop kernel: [  670.460245] IP: usb_kill_urb+0x3a/0xc0
    Jul  5 09:36:23 bob-desktop kernel: [  670.460251] PGD 346595067 P4D 346595067 PUD 346599067 PMD 41b445063 PTE 800000041b513061
    Jul  5 09:36:23 bob-desktop kernel: [  670.460257] Oops: 0003 [#2] SMP PTI
    Jul  5 09:36:23 bob-desktop kernel: [  670.460260] Modules linked in: cdc_acm usblp snd_hda_codec_hdmi intel_rapl x86_pkg_temp_thermal intel_powerclamp coretemp kvm_intel kvm irqbypass crct10dif_pclmul crc32_pclmul ghash_clmulni_intel pcbc mxm_wmi aesni_intel i915 88x2bu(OE) aes_x86_64 crypto_simd joydev drm_kms_helper glue_helper cryptd snd_hda_codec_realtek input_leds drm snd_hda_codec_generic intel_cstate i2c_algo_bit intel_rapl_perf fb_sys_fops cfg80211 snd_soc_rt5640 syscopyarea snd_hda_intel sysfillrect mei_me snd_hda_codec snd_soc_rl6231 mei lpc_ich sysimgblt snd_soc_core snd_hda_core snd_hwdep shpchp snd_compress ac97_bus snd_pcm_dmaengine snd_pcm snd_timer snd soundcore mac_hid intel_smartconnect wmi acpi_pad video sch_fq_codel parport_pc ppdev lp parport ip_tables x_tables autofs4 uas usb_storage hid_logitech_hidpp hid_logitech_dj
    Jul  5 09:36:23 bob-desktop kernel: [  670.460286]  hid_generic usbhid hid e1000e ahci ptp r8169 libahci mii pps_core
    Jul  5 09:36:23 bob-desktop kernel: [  670.460293] CPU: 3 PID: 2063 Comm: teensy_reboot Tainted: G      D W  OE    4.15.0-108-generic #109-Ubuntu
    Jul  5 09:36:23 bob-desktop kernel: [  670.460295] Hardware name: To Be Filled By O.E.M. To Be Filled By O.E.M./Z97 Extreme6, BIOS P1.40 09/15/2014
    Jul  5 09:36:23 bob-desktop kernel: [  670.460299] RIP: 0010:usb_kill_urb+0x3a/0xc0
    Jul  5 09:36:23 bob-desktop kernel: [  670.460301] RSP: 0018:ffffb5e0859e7d38 EFLAGS: 00010206
    Jul  5 09:36:23 bob-desktop kernel: [  670.460303] RAX: 0000000000000000 RBX: ffff9da25b513540 RCX: ffffffff99bd2598
    Jul  5 09:36:23 bob-desktop kernel: [  670.460305] RDX: 0000000000000001 RSI: 0000000000000286 RDI: ffff9da25b513540
    Jul  5 09:36:23 bob-desktop kernel: [  670.460307] RBP: ffffb5e0859e7d78 R08: 0000000000000000 R09: 00000000000006da
    Jul  5 09:36:23 bob-desktop kernel: [  670.460309] R10: 0000000000000000 R11: 00000243a81fc3fc R12: ffff9da25a87f440
    Jul  5 09:36:23 bob-desktop kernel: [  670.460310] R13: ffff9da25a87f000 R14: ffff9da25d72fb20 R15: ffff9da213acf0c0
    Jul  5 09:36:23 bob-desktop kernel: [  670.460313] FS:  00007f807d769b80(0000) GS:ffff9da26fac0000(0000) knlGS:0000000000000000
    Jul  5 09:36:23 bob-desktop kernel: [  670.460315] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
    Jul  5 09:36:23 bob-desktop kernel: [  670.460317] CR2: ffff9da25b513554 CR3: 00000003b106e006 CR4: 00000000001606e0
    Jul  5 09:36:23 bob-desktop kernel: [  670.460318] Call Trace:
    Jul  5 09:36:23 bob-desktop kernel: [  670.460323]  ? wait_woken+0x80/0x80
    Jul  5 09:36:23 bob-desktop kernel: [  670.460328]  acm_kill_urbs+0x59/0x70 [cdc_acm]
    Jul  5 09:36:23 bob-desktop kernel: [  670.460332]  acm_port_shutdown+0x84/0x90 [cdc_acm]
    Jul  5 09:36:23 bob-desktop kernel: [  670.460337]  tty_port_shutdown+0x80/0x90
    Jul  5 09:36:23 bob-desktop kernel: [  670.460341]  tty_port_close+0x3d/0x70
    Jul  5 09:36:23 bob-desktop kernel: [  670.460345]  acm_tty_close+0x22/0x30 [cdc_acm]
    Jul  5 09:36:23 bob-desktop kernel: [  670.460348]  tty_release+0x124/0x600
    Jul  5 09:36:23 bob-desktop kernel: [  670.460354]  __fput+0xea/0x220
    Jul  5 09:36:23 bob-desktop kernel: [  670.460358]  ____fput+0xe/0x10
    Jul  5 09:36:23 bob-desktop kernel: [  670.460363]  task_work_run+0x9d/0xc0
    Jul  5 09:36:23 bob-desktop kernel: [  670.460367]  exit_to_usermode_loop+0xc0/0xd0
    Jul  5 09:36:23 bob-desktop kernel: [  670.460375]  do_syscall_64+0x121/0x130
    Jul  5 09:36:23 bob-desktop kernel: [  670.460383]  entry_SYSCALL_64_after_hwframe+0x3d/0xa2
    Jul  5 09:36:23 bob-desktop kernel: [  670.460390] RIP: 0033:0x7f807d07e8d4
    Jul  5 09:36:23 bob-desktop kernel: [  670.460395] RSP: 002b:00007fffc2684cd8 EFLAGS: 00000246 ORIG_RAX: 0000000000000003
    Jul  5 09:36:23 bob-desktop kernel: [  670.460404] RAX: 0000000000000000 RBX: 0000000000000000 RCX: 00007f807d07e8d4
    Jul  5 09:36:23 bob-desktop kernel: [  670.460411] RDX: 0000000000000000 RSI: 0000000000005401 RDI: 0000000000000004
    Jul  5 09:36:23 bob-desktop kernel: [  670.460418] RBP: 0000000000000000 R08: ffffffffffffff70 R09: 00007fffc2684c7c
    Jul  5 09:36:23 bob-desktop kernel: [  670.460425] R10: 0000000000000006 R11: 0000000000000246 R12: 0000000000000005
    Jul  5 09:36:23 bob-desktop kernel: [  670.460432] R13: 0000000000000005 R14: 0000000000000000 R15: 0000000000000000
    Jul  5 09:36:23 bob-desktop kernel: [  670.460440] Code: 48 83 ec 30 65 48 8b 04 25 28 00 00 00 48 89 45 e8 31 c0 e8 c9 ce 27 00 48 85 db 74 2f 48 83 7b 48 00 74 28 48 83 7b 50 00 74 21 <f0> ff 43 14 be fe ff ff ff 48 89 df e8 c5 ea ff ff e8 a0 ce 27 
    Jul  5 09:36:23 bob-desktop kernel: [  670.460487] RIP: usb_kill_urb+0x3a/0xc0 RSP: ffffb5e0859e7d38
    Jul  5 09:36:23 bob-desktop kernel: [  670.460493] CR2: ffff9da25b513554
    Jul  5 09:36:23 bob-desktop kernel: [  670.460498] ---[ end trace e3350ea79f55d69f ]---
    
    Bob note: At this point Loader window is dead
    At this point Loader window is dead and after a few seconds, a Linux "Crash" box appears (the one that asks if we want to report system error). The Crash Report from /var/crash:

    Code:
    ProblemType: KernelOops
    Annotation: Your system might become unstable now and might need to be restarted.
    Date: Sun Jul  5 09:36:39 2020
    Failure: oops
    OopsText:
     BUG: unable to handle kernel paging request at ffff9da25b513554
     IP: usb_kill_urb+0x3a/0xc0
     PGD 346595067 P4D 346595067 PUD 346599067 PMD 41b445063 PTE 800000041b513061
     Oops: 0003 [#2] SMP PTI
     Modules linked in: cdc_acm usblp snd_hda_codec_hdmi intel_rapl x86_pkg_temp_thermal intel_powerclamp coretemp kvm_intel kvm irqbypass crct10dif_pclmul crc32_pclmul ghash_clmulni_intel pcbc mxm_wmi aesni_intel i915 88x2bu(OE) aes_x86_64 crypto_simd joydev drm_kms_helper glue_helper cryptd snd_hda_codec_realtek input_leds drm snd_hda_codec_generic intel_cstate i2c_algo_bit intel_rapl_perf fb_sys_fops cfg80211 snd_soc_rt5640 syscopyarea snd_hda_intel sysfillrect mei_me snd_hda_codec snd_soc_rl6231 mei lpc_ich sysimgblt snd_soc_core snd_hda_core snd_hwdep shpchp snd_compress ac97_bus snd_pcm_dmaengine snd_pcm snd_timer snd soundcore mac_hid intel_smartconnect wmi acpi_pad video sch_fq_codel parport_pc ppdev lp parport ip_tables x_tables autofs4 uas usb_storage hid_logitech_hidpp hid_logitech_dj
      hid_generic usbhid hid e1000e ahci ptp r8169 libahci mii pps_core
     CPU: 3 PID: 2063 Comm: teensy_reboot Tainted: G      D W  OE    4.15.0-108-generic #109-Ubuntu
     Hardware name: To Be Filled By O.E.M. To Be Filled By O.E.M./Z97 Extreme6, BIOS P1.40 09/15/2014
     RIP: 0010:usb_kill_urb+0x3a/0xc0
     RSP: 0018:ffffb5e0859e7d38 EFLAGS: 00010206
     RAX: 0000000000000000 RBX: ffff9da25b513540 RCX: ffffffff99bd2598
     RDX: 0000000000000001 RSI: 0000000000000286 RDI: ffff9da25b513540
     RBP: ffffb5e0859e7d78 R08: 0000000000000000 R09: 00000000000006da
     R10: 0000000000000000 R11: 00000243a81fc3fc R12: ffff9da25a87f440
     R13: ffff9da25a87f000 R14: ffff9da25d72fb20 R15: ffff9da213acf0c0
     FS:  00007f807d769b80(0000) GS:ffff9da26fac0000(0000) knlGS:0000000000000000
     CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
     CR2: ffff9da25b513554 CR3: 00000003b106e006 CR4: 00000000001606e0
     Call Trace:
      ? wait_woken+0x80/0x80
      acm_kill_urbs+0x59/0x70 [cdc_acm]
      acm_port_shutdown+0x84/0x90 [cdc_acm]
      tty_port_shutdown+0x80/0x90
      tty_port_close+0x3d/0x70
      acm_tty_close+0x22/0x30 [cdc_acm]
      tty_release+0x124/0x600
      __fput+0xea/0x220
      ____fput+0xe/0x10
      task_work_run+0x9d/0xc0
      exit_to_usermode_loop+0xc0/0xd0
      do_syscall_64+0x121/0x130
      entry_SYSCALL_64_after_hwframe+0x3d/0xa2
     RIP: 0033:0x7f807d07e8d4
     RSP: 002b:00007fffc2684cd8 EFLAGS: 00000246 ORIG_RAX: 0000000000000003
     RAX: 0000000000000000 RBX: 0000000000000000 RCX: 00007f807d07e8d4
     RDX: 0000000000000000 RSI: 0000000000005401 RDI: 0000000000000004
     RBP: 0000000000000000 R08: ffffffffffffff70 R09: 00007fffc2684c7c
     R10: 0000000000000006 R11: 0000000000000246 R12: 0000000000000005
     R13: 0000000000000005 R14: 0000000000000000 R15: 0000000000000000
     Code: 48 83 ec 30 65 48 8b 04 25 28 00 00 00 48 89 45 e8 31 c0 e8 c9 ce 27 00 48 85 db 74 2f 48 83 7b 48 00 74 28 48 83 7b 50 00 74 21 <f0> ff 43 14 be fe ff ff ff 48 89 df e8 c5 ea ff ff e8 a0 ce 27 
     RIP: usb_kill_urb+0x3a/0xc0 RSP: ffffb5e0859e7d38
     CR2: ffff9da25b513554
     ---[ end trace e3350ea79f55d69f ]---
     
    Package: linux-image-4.15.0-108-generic 4.15.0-108.109
    SourcePackage: linux
    Tags: kernel-oops
    Uname: Linux 4.15.0-108-generic x86_64
    For 2-Serial Ports /dev/ttyACM0 (Teensy) or /dev/ttyACM0 (Teensy) gave the same response.

    For 3-discovery.debug=true, the IDE response was
    Code:
    Arduino: 1.8.12 (Linux), TD: 1.52, Board: "Teensy 3.6, Serial, 180 MHz, Faster, US English"
    
    Opening Teensy Loader...
    Sketch uses 14056 bytes (1%) of program storage space. Maximum is 1048576 bytes.
    Global variables use 4948 bytes (1%) of dynamic memory, leaving 257196 bytes for local variables. Maximum is 262144 bytes.
    /home/bob/arduino-1.8.12/hardware/teensy/../tools/teensy_post_compile -file=TestLoader.ino -path=/tmp/arduino_build_580551 -tools=/home/bob/arduino-1.8.12/hardware/teensy/../tools -board=TEENSY36 -reboot -port=/sys/devices/pci0000:00/0000:00:14.0/usb3/3-10 -portlabel=/dev/ttyACM0 Serial -portprotocol=Teensy 
    An error occurred while uploading the sketch
    And again Loader crashed and is non-responsive.

    I hope this is helpful in seeing a direction to head. Bob

  7. #7
    Senior Member
    Join Date
    Dec 2016
    Posts
    138
    Correction, in item 2, it should be or /dev/ttyACM0 Serial (Teensy3.6)

  8. #8
    Senior Member
    Join Date
    Dec 2016
    Posts
    138
    Another update. The error messages with "discovery.debug=true" are as shown in #6, above, when the loader crashes. For reference, when the loader does not crash there is something to see:
    Code:
    Arduino: 1.8.12 (Linux), TD: 1.52, Board: "Teensy 3.6, Serial, 180 MHz, Faster, US English"
    
    Opening Teensy Loader...
    Sketch uses 14056 bytes (1%) of program storage space. Maximum is 1048576 bytes.
    Global variables use 4948 bytes (1%) of dynamic memory, leaving 257196 bytes for local variables. Maximum is 262144 bytes.
    /home/bob/arduino-1.8.12/hardware/teensy/../tools/teensy_post_compile -file=TestLoader.ino -path=/tmp/arduino_build_842652 -tools=/home/bob/arduino-1.8.12/hardware/teensy/../tools -board=TEENSY36 -reboot -port=/sys/devices/pci0000:00/0000:00:14.0/usb3/3-10 -portlabel=/dev/ttyACM0 Serial -portprotocol=Teensy 
    An error occurred while uploading the sketch
    teensy: Received json: {"eventType":"add","port":{"address":"/sys/devices/pci0000:00/0000:00:14.0/usb3/3-10","protocol":"Teensy","protocolLabel":"Teensy Ports","boardName":"Teensy 3.6","label":"/dev/bus/usb/003/005 Bootloader","identificationPrefs":{},"prefs":{"vendorId":"16C0","productId":"0478","serialNumber":"0"},"online":"true"}}
    teensy: Received json: {"eventType":"add","port":{"address":"/sys/devices/pci0000:00/0000:00:14.0/usb3/3-10","protocol":"Teensy","protocolLabel":"Teensy Ports","boardName":"Teensy 3.6","label":"/dev/bus/usb/003/005 Bootloader","identificationPrefs":{},"prefs":{"vendorId":"16C0","productId":"0478","serialNumber":"0"},"online":"true"}}
    teensy: Received json: {"eventType":"add","port":{"address":"/sys/devices/pci0000:00/0000:00:14.0/usb3/3-10","protocol":"Teensy","protocolLabel":"Teensy Ports","boardName":"Teensy 3.6","label":"/dev/bus/usb/003/005 Bootloader","identificationPrefs":{},"prefs":{"vendorId":"16C0","productId":"0478","serialNumber":"0"},"online":"true"}}
    teensy: Received json: {"eventType":"add","port":{"address":"/sys/devices/pci0000:00/0000:00:14.0/usb3/3-10","protocol":"Teensy","protocolLabel":"Teensy Ports","boardName":"Teensy 3.6","label":"/dev/bus/usb/003/005 Bootloader","identificationPrefs":{},"prefs":{"vendorId":"16C0","productId":"0478","serialNumber":"0"},"online":"true"}}
    teensy: Received json: {"eventType":"add","port":{"address":"/sys/devices/pci0000:00/0000:00:14.0/usb3/3-10","protocol":"Teensy","protocolLabel":"Teensy Ports","boardName":"Teensy 3.6","label":"/dev/bus/usb/003/006 Serial","identificationPrefs":{},"prefs":{"vendorId":"16C0","productId":"0483","serialNumber":"0"},"online":"true"}}
    teensy: Received json: {"eventType":"add","port":{"address":"/sys/devices/pci0000:00/0000:00:14.0/usb3/3-10","protocol":"Teensy","protocolLabel":"Teensy Ports","boardName":"Teensy 3.6","label":"/dev/bus/usb/003/006 Serial","identificationPrefs":{},"prefs":{"vendorId":"16C0","productId":"0483","serialNumber":"0"},"online":"true"}}
    teensy: Received json: {"eventType":"add","port":{"address":"/sys/devices/pci0000:00/0000:00:14.0/usb3/3-10","protocol":"Teensy","protocolLabel":"Teensy Ports","boardName":"Teensy 3.6","label":"/dev/bus/usb/003/006 Serial","identificationPrefs":{},"prefs":{"vendorId":"16C0","productId":"0483","serialNumber":"0"},"online":"true"}}
    teensy: Received json: {"eventType":"add","port":{"address":"/sys/devices/pci0000:00/0000:00:14.0/usb3/3-10","protocol":"Teensy","protocolLabel":"Teensy Ports","boardName":"Teensy 3.6","label":"/dev/ttyACM0 Serial","identificationPrefs":{},"prefs":{"vendorId":"16C0","productId":"0483","serialNumber":"0"},"online":"true"}}
    Also, the fact that the crashes can sometimes cease and only be brought back by loading T4.0 says that I have NOT isolated a fully repeatable condition to create the bug. I am pursuing that now, but it is slow going with lots of PC reboots. More when I am sure. Bob

  9. #9
    Member
    Join Date
    Apr 2020
    Location
    Germany, NRW
    Posts
    86
    If you ask me, looking at the kernel oops, this might be a bug in the cdc_acm driver, any chance that you update the kernel and try again?

    There might be a 5.x kernel available on 18.04, i think

  10. #10
    Senior Member
    Join Date
    Dec 2016
    Posts
    138
    OK, here is an INO that has consistently created the crash of the Loader and of Linux, listed above. Creating this problem, for me, only needs the Teensy3.6. It is the previous INO with a small amount of Teensy Audio:
    Code:
    #include <Audio.h>
    
    AudioSynthWaveformSine sine1;
    AudioOutputI2S         i2sOut;
    AudioConnection        patchCord1(sine1, 0, i2sOut, 0);
    AudioConnection        patchCord2(sine1, 0, i2sOut, 1);
    AudioControlSGTL5000   sgtl5000_1;
    
    void setup(void) {
      Serial.begin(1);   delay(1000);
      Serial.println("Teensy Audio, Test Loader"); 
     
      AudioMemory(10);
      sgtl5000_1.enable();
      sine1.frequency(300.0);
      sine1.amplitude(0.005f);
    } 
    
    void loop() {
    }
    The sequence I have been using
    1-Reboot Linux 2+ times
    2-Plug in T3.6 to US
    3-Open the Arduino IDE with the INO above.
    4-Check Tools: Teensy 3.6 and /dev/ttyACM0 Serial(Teensy 3.6)
    5-Sketch/Upload many time to confirm consistent good loads, It is always good at this point.
    6-Close Serial Monitor window.
    7-Sketch/Upload 2 to 4 times to cause the Teensy Loader to lock up and for Linux to "crash report" and refuse to "Shut Down" or "Reboot"

    That has been consistent for 5 full 1-to-7 sequences, so I believe it will continue! The number of tries in step 7 is not always the same for some reason. This difficulty seems to be sensitive to the INO content, somehow, and as near as I can tell always requires the Monitor window to be closed. The latter provides a work-around. Strange bug. Even stranger if I'm the only one that gets it...

    Also, I have never seen any Linux crash behavior from other programs, as I recollect. If any, it wold have been an isolated incident. I have been with Ubuntu 18.04 for a couple of years.

    Thanks, Bob

  11. #11
    Member
    Join Date
    Apr 2020
    Location
    Germany, NRW
    Posts
    86
    If the other programs don't use the AMA driver they will not crash if there is a race condition or bug in this driver. If you google for kernel oops cdc_ama you find some issues, so upgrading to a kernel > 4.15 might help if it is not a big issue for you.

    My opinion is, a user level program should not be able to cause a kernel oops, if it does likely the driver is to blame.

  12. #12
    Senior Member+ manitou's Avatar
    Join Date
    Jan 2013
    Posts
    2,588
    it looks like you are running ModemManager. try getting rid of that. sudo apt-get purge modemmanager

  13. #13
    Senior Member
    Join Date
    Dec 2016
    Posts
    138
    Thanks much, I needed things to try. I first deleted modemmanager. No change that I could see, in loading.

    Then after a full backup, I updated to kernel 5.3 with no obvious issues. No change that I could see in loading.

    So, I am still seeing the results for steps 1 to 7 of post #10 above. It seems to be 100% repeatable as described.

    More tomorrow.

  14. #14
    Senior Member
    Join Date
    Dec 2016
    Posts
    138
    It would appear that this crashing issue relates to the timing of constructors for at least the AudioOutputI2S (possibly others). Here is the observation. Steps 1 to 7 of post #10 are consistent and repeatable for me. BUT, if I make one change to the AudioOutputI2S class, namely adding delays on either side of begin():
    Code:
    	AudioOutputI2S(void) : AudioStream(2, inputQueueArray) //  WAS { begin(); }
    	{
    	  uint32_t xx = 0;
    	  for(uint32_t ii=0; ii<10000; ii++) 
    	    xx = xx + ii;
    	  begin();
    	  for(uint32_t ii=0; ii<10000; ii++) 
    	    xx = xx + ii;
    	}
    the problem seems to go away. As least in several tries it did not appear. I did not try to minimize the cure---maybe one small delay would do it.

    I discovered this while building a different, but similar class. It showed the same cure.

    I need to test this more, but I am going to be away tomorrow and wanted to toss this out while it is fresh. Does any of this make sense? Thoughts?

    Bob

  15. #15
    Senior Member PaulStoffregen's Avatar
    Join Date
    Nov 2012
    Posts
    22,757
    Wow, you don't see a Kernel Opps very often in these modern times of Linux! This is extremely unusual. We hear all sorts of problems with Linux which almost always turn out to be udev rules or permissions or other misconfiguration or buggy ModemManager, but pretty much never a kernel-level crash.

    Something is going horribly wrong on your PC. It might be USB hardware. It might be a corrupted kernel module. Just to be clear, nothing Teensy does should ever be able to cause a Kernel opps. We never install any kernel modules. By following the normal way of installation, absolutely everything we install runs without root permission, using only the drivers that come with the Linux kernel. The udev rules are the only part installed with root permission, and it's just a text file that tells udev how to handle Teensy and (hopefully) get ModemManager to not interfere.

    I know you're interested focusing on Teensy here, and for pretty much any other problem I would agree. But a kernel opps means something is very wrong with either your PC hardware or its Linux installation. That's where you should focus your attention, rather than the specific code on the Teensy side which triggers this crash.

    With that in mind, I have 2 quick suggestions of things to try...

    1: Add a USB hub between your PC and Teensy. A hub will change 2 things. First, detection of USB connect and disconnect is handled by the hub rather than the USB controller in your PC. Second, for 12 MBit USB devices like Teensy 3.6, your PC actually communicates at 480 Mbit using split transactions to the transaction translator inside the hub, which in turn communicates with Teensy at 12 Mbit. If the hub solves this problem, odds are strong your PC's USB controller (or its kernel driver) has a serious problem.

    2: In Arduino, change Tools > USB Type to any of the non-Serial options. RawHID is a probably a good choice. Your kernel log seems to suggest the crash may be happening within the cdc_acm driver. Using RawHID will avoid all use of that driver. If the hub makes no difference but this solves everything, odds are strong your cdc_acm driver module file is corrupted. Or maybe you've discovered a kernel bug, but that seems pretty unlikely for such a well established and widely used driver.

    Just to clearly repeat, we pretty much never hear reports of kernel crashes on Linux. Whatever is going so horribly wrong on your machine is absolutely not normal. We do hear lots of Linux issues involving config & ModemManager, but almost never this.

    (however, a few years ago Apple shipped a buggy driver and we did hear lots of reports of MacOS kernel crashes around the El Capitan era)

  16. #16
    Senior Member
    Join Date
    Dec 2016
    Posts
    138
    Thanks Paul. Your "big picture" thinking was right on.

    When I inserted a x4 USB 2.0 hub, the crashes went away. This is not just for the test INO, but a two of others that had been problems. Also, it held true for T4.0 which had been every bit as much an issue. I will get back to Teensy programming and report back if I see anything else. For now, the message to anyone else seeing Loader crashes under Linux, try a USB expander hub!

    Background:
    First, I found from lsusb that whether I used a blue USB 3 socket or a USB 2.0 socket, the driver was always xhci_hcd/14p at the internal hub level and cdc_acm at the device level. lspci shows the hardware controller is always "USB controller: Intel Corporation 9 Series Chipset Family USB xHCI Controller". This holds for T3.6 and T4.0, but with the different speeds indicated.

    Second, several days ago, post #13, I installed kernel 5.3 replacing 4.15. This should have cleared corrupted kernel drivers, if any.

    Third, Paul, your comment, "If the hub solves this problem, odds are strong your PC's USB controller (or its kernel driver) has a serious problem." is concerning. Wouldn't the kernel update make driver issues unlikely? I have not seen other issues with the USB. Internet search on the Intel chip set does not suggest any issues, not surprisingly.

    For reference, here is the relevant portion of lsusb -t for no hub, T3.6:
    Code:
    /:  Bus 03.Port 1: Dev 1, Class=root_hub, Driver=xhci_hcd/14p, 480M
        |__ Port 9: Dev 2, If 0, Class=Hub, Driver=hub/4p, 480M
            |__ Port 2: Dev 4, If 0, Class=Human Interface Device, Driver=usbhid, 12M
            |__ Port 2: Dev 4, If 1, Class=Human Interface Device, Driver=usbhid, 12M
            |__ Port 2: Dev 4, If 2, Class=Human Interface Device, Driver=usbhid, 12M
        |__ Port 10: Dev 10, If 0, Class=Communications, Driver=cdc_acm, 12M    <<<<<<<<<<<<<<<
        |__ Port 10: Dev 10, If 1, Class=CDC Data, Driver=cdc_acm, 12M         <<<<<<<<<<<<<<
    and with the hub, T3.6:
    Code:
    /:  Bus 03.Port 1: Dev 1, Class=root_hub, Driver=xhci_hcd/14p, 480M
        |__ Port 9: Dev 2, If 0, Class=Hub, Driver=hub/4p, 480M
            |__ Port 2: Dev 4, If 0, Class=Human Interface Device, Driver=usbhid, 12M
            |__ Port 2: Dev 4, If 1, Class=Human Interface Device, Driver=usbhid, 12M
            |__ Port 2: Dev 4, If 2, Class=Human Interface Device, Driver=usbhid, 12M
        |__ Port 10: Dev 11, If 0, Class=Hub, Driver=hub/4p, 480M
            |__ Port 1: Dev 12, If 1, Class=CDC Data, Driver=cdc_acm, 12M     <<<<<<<<<<<<<<<
            |__ Port 1: Dev 12, If 0, Class=Communications, Driver=cdc_acm, 12M  <<<<<<<<<<<<
    and with the hub for T4.0:
    Code:
    /:  Bus 03.Port 1: Dev 1, Class=root_hub, Driver=xhci_hcd/14p, 480M
        |__ Port 9: Dev 2, If 0, Class=Hub, Driver=hub/4p, 480M
            |__ Port 2: Dev 4, If 0, Class=Human Interface Device, Driver=usbhid, 12M
            |__ Port 2: Dev 4, If 1, Class=Human Interface Device, Driver=usbhid, 12M
            |__ Port 2: Dev 4, If 2, Class=Human Interface Device, Driver=usbhid, 12M
        |__ Port 10: Dev 11, If 0, Class=Hub, Driver=hub/4p, 480M
            |__ Port 1: Dev 47, If 1, Class=CDC Data, Driver=cdc_acm, 480M      <<<<<<<<<<
            |__ Port 1: Dev 47, If 0, Class=Communications, Driver=cdc_acm, 480M   <<<<<<<<<

  17. #17
    Member
    Join Date
    Apr 2020
    Location
    Germany, NRW
    Posts
    86
    Good to hear that the issues are solved now.

  18. #18
    Senior Member
    Join Date
    Dec 2016
    Posts
    138
    The celebration was fun! But brief :-(

    When I went back to playing with a getting the OutputI2S class working with F32 and Teensy 4.0, and made more code changes, the crash problem came back. The code works, but only with some added delays on the constructor. There is no point in showing details until I work it down to a minimal complexity that still retains the crash. This testing was with the 4x hub in the USB path. One observation, relative to Paul's experiments, is that I moved the Tools/USB Type to "Raw HID" and after a bit of playing got Serial Port communications, "/dev/hidraw4RawHID (Teensy 4.0)" and the crash was still there. Bob

  19. #19
    Senior Member PaulStoffregen's Avatar
    Join Date
    Nov 2012
    Posts
    22,757
    I use Linux for nearly all Teensy development. While Frank and others have made some very substantial contributions, I've uploaded the audio library many thousands of times while developing most of its code over the years, all from Ubuntu 14, 16, 18. I've never experienced a Linux kernel opps while developing the audio library. I also developed all the USB device stack code, on Teensy 2, 3/LC and 4 - where I have uploaded very wrong USB implementations over and over (in the earliest versions using non-USB ways since I wrote all the USB code from scratch). I've done so many USB things wrong in the course of developing Teensy's core lib. Years ago I did encounter bugs in the Linux drivers requiring a reboot (it's very rare), but never a kernel opps.

    We also don't generally get reports of Linux kernel problems from the thousands of people who've used this forum. And indeed we have heard from many Linux users, so it's not a case of everyone using Windows & Macintosh. Problems from not installing the udev rules or having buggy ModemManager interfere have come up over and over. But not Linux kernel opps.

    My point is a Linux kernel opps is a very serious problem which we just don't see here. It's unique to you. I'm pretty sure something is very wrong on your machine.

  20. #20
    Senior Member
    Join Date
    Dec 2016
    Posts
    138
    Thanks, Paul. I am continuing to pursue an explanation for what I am seeing and when the data is totally solid, I will report back. I don't mean to add noise here :-) Bob

  21. #21
    Senior Member
    Join Date
    Dec 2016
    Posts
    138
    Quote Originally Posted by Bob Larkin View Post
    .... when the data is totally solid, I will report back. I don't mean to add noise here :-)
    OK, I've been able to narrow down a specific set of conditions that is consistent for me in creating the problem. And have also been able to isolate the area in the loading/booting process where things seem to go wrong.

    First, I am able to duplicate the problem on two different sets of USB hardware in my regular PC, and more importantly, could duplicate this on an old 32-bit Ubuntu 18.04 PC.

    My problems with Teensy 3.6 were the result of first breaking something in Linux by running Teensy 4.0 and later having the problem with 3.6. At this point, I never see it on Teensy 3.6 after cold booting the PC,

    I have only been able to create the problem with one specific Class, and it is NOT from the Teensy library. It is a floating point audio I2S output class, made by taking the Teensy I16 output_i2s.h and .cpp and gluing on the OpenAudio F32 read of a data block, followed by conversion to I16 integer. The obvious thing to say at this point is that there is a bug in my code. But, it compiles and links without error, but of course it may not run without error. The details of the experiment are at https://github.com/boblark/TestLoadT The difference between good and bad is the timing of the I2S, interrupt and DMA startup. The bad timing is the same as used by Teensy output_i2s.

    I have piles of data, and would be happy to share any, but probably more useful now is to show the Loader verbose output when faiiling:
    Code:
    09:48:00.405 (loader): remote connection 8 closed
    09:48:01.353 (loader): file changed
    09:48:01.362 (loader): File "TL_TestOutput_float.ino.hex". 29308 bytes, 1% used
    09:48:01.378 (post_compile 12): Begin, version=1.53
    09:48:01.411 (loader): remote connection 8 opened
    09:48:01.411 (post_compile 12): Sending command: comment: Teensyduino 1.53 - LINUX64 (teensy_post_compile)
    09:48:01.412 (loader): remote cmd from 8: "comment: Teensyduino 1.53 - LINUX64 (teensy_post_compile)"
    09:48:01.412 (loader): remote cmd from 8: "status"
    09:48:01.457 (post_compile 12): Status: 1, 1, 0, 2, 0, 0, /tmp/arduino_build_728953/, TL_TestOutput_float.ino.hex
    09:48:01.457 (post_compile 12): Disconnect
    09:48:01.467 (loader): remote connection 8 closed
    09:48:01.473 (post_compile 13): Begin, version=1.53
    09:48:01.473 (loader): remote connection 8 opened
    09:48:01.473 (post_compile 13): Sending command: comment: Teensyduino 1.53 - LINUX64 (teensy_post_compile)
    09:48:01.473 (loader): remote cmd from 8: "comment: Teensyduino 1.53 - LINUX64 (teensy_post_compile)"
    09:48:01.473 (loader): remote cmd from 8: "status"
    09:48:01.520 (post_compile 13): Status: 1, 1, 0, 2, 0, 0, /tmp/arduino_build_728953/, TL_TestOutput_float.ino.hex
    09:48:01.520 (post_compile 13): Disconnect
    09:48:01.530 (post_compile 14): Running teensy_reboot: /home/bob/arduino-1.8.13/hardware/teensy/../tools/teensy_reboot
    09:48:01.531 (loader): remote connection 8 closed
    09:48:01.531 (loader): remote connection 8 opened
    09:48:01.531 (loader): remote connection 8 closed
    09:48:01.531 (reboot 15): Begin, version=1.53
    09:48:01.531 (reboot 15): location = /sys/devices/pci0000:00/0000:00:1c.6/0000:09:00.0/usb5/5-1
    09:48:01.531 (reboot 15): portlabel = /dev/bus/usb/005/031 Bootloader
    09:48:01.531 (reboot 15): portprotocol = Teensy
    09:48:01.531 (reboot 15): Only location /sys/devices/pci0000:00/0000:00:1c.6/0000:09:00.0/usb5/5-1 will be tried
    09:48:01.542 (loader): remote connection 8 opened
    09:48:01.545 (reboot 15): add device: subsys=usb, type=usb_device, location=/sys/devices/pci0000:00/0000:00:1c.6/0000:09:00.0/usb5/5-1
    09:48:01.545 (reboot 15):   devnode=/dev/bus/usb/005/032, subsystem=usb, ifacenum=-1
    09:48:01.545 (reboot 15): add child:  subsys=usb, type=usb_interface, location=/sys/devices/pci0000:00/0000:00:1c.6/0000:09:00.0/usb5/5-1/5-1:1.0
    09:48:01.545 (reboot 15):   parent location=/sys/devices/pci0000:00/0000:00:1c.6/0000:09:00.0/usb5/5-1
    09:48:01.545 (reboot 15):   model=36 (Teensy 4.0)
    09:48:01.545 (reboot 15): add child:  subsys=tty, type=(null), location=/sys/devices/pci0000:00/0000:00:1c.6/0000:09:00.0/usb5/5-1/5-1:1.0/tty/ttyACM0
    09:48:01.545 (reboot 15):   parent location=/sys/devices/pci0000:00/0000:00:1c.6/0000:09:00.0/usb5/5-1
    09:48:01.545 (reboot 15):   devnode=/dev/ttyACM0, subsystem=tty, ifacenum=0
    09:48:01.545 (reboot 15): add child:  subsys=usb, type=usb_interface, location=/sys/devices/pci0000:00/0000:00:1c.6/0000:09:00.0/usb5/5-1/5-1:1.1
    09:48:01.545 (reboot 15):   parent location=/sys/devices/pci0000:00/0000:00:1c.6/0000:09:00.0/usb5/5-1
    09:48:01.552 (reboot 15): found Teensy Loader, version 1.53
    09:48:01.552 (reboot 15): Sending command: show:arduino_attempt_reboot
    09:48:01.587 (loader): remote cmd from 8: "show:arduino_attempt_reboot"
    09:48:01.587 (loader): got request to show arduino rebooting message
    09:48:01.589 (reboot 15): Sending command: comment: Teensyduino 1.53 - LINUX64 (teensy_reboot)
    09:48:01.590 (loader): remote cmd from 8: "comment: Teensyduino 1.53 - LINUX64 (teensy_reboot)"
    09:48:01.590 (loader): remote cmd from 8: "status"
    09:48:01.637 (reboot 15): Status: 1, 1, 0, 2, 0, 0, /tmp/arduino_build_728953/, TL_TestOutput_float.ino.hex
    09:48:01.637 (reboot 15): do_reset (serial) /dev/ttyACM0
    09:48:01.663 (ports 5): del child: location=/sys/devices/pci0000:00/0000:00:1c.6/0000:09:00.0/usb5/5-1/5-1:1.0/tty/ttyACM0
    09:48:01.663 (ports 5):   devnode=/dev/bus/usb/005/032, subsystem=usb, ifacenum=-1
    09:48:01.663 (ports 5): unknown action: unbind
    09:48:01.663 (ports 5): unknown action: unbind
    09:48:01.664 (ports 5): del child: location=/sys/devices/pci0000:00/0000:00:1c.6/0000:09:00.0/usb5/5-1/5-1:1.1
    09:48:01.664 (ports 5): del child: location=/sys/devices/pci0000:00/0000:00:1c.6/0000:09:00.0/usb5/5-1/5-1:1.0
    09:48:01.665 (ports 5): unknown action: unbind
    09:48:01.665 (ports 5): del device: location=/sys/devices/pci0000:00/0000:00:1c.6/0000:09:00.0/usb5/5-1
    09:48:01.681 (loader): remote cmd from 8: "status"
    09:48:01.724 (reboot 15): Status: 1, 1, 0, 2, 0, 0, /tmp/arduino_build_728953/, TL_TestOutput_float.ino.hex
    09:48:01.724 (reboot 15): status read, retry 0
    09:48:01.824 (loader): remote cmd from 8: "status"
    09:48:01.872 (reboot 15): Status: 1, 1, 0, 2, 0, 0, /tmp/arduino_build_728953/, TL_TestOutput_float.ino.hex
    09:48:01.872 (reboot 15): status read, retry 1
    09:48:01.972 (loader): remote cmd from 8: "status"
    09:48:02.021 (reboot 15): Status: 1, 1, 0, 2, 0, 0, /tmp/arduino_build_728953/, TL_TestOutput_float.ino.hex
    09:48:02.021 (reboot 15): status read, retry 2
    09:48:02.121 (loader): remote cmd from 8: "status"
    09:48:02.171 (reboot 15): Status: 1, 1, 0, 2, 0, 0, /tmp/arduino_build_728953/, TL_TestOutput_float.ino.hex
    09:48:02.171 (reboot 15): status read, retry 3
    09:48:02.271 (loader): remote cmd from 8: "status"
    09:48:02.296 (ports 5): add device: subsys=usb, type=usb_device, location=/sys/devices/pci0000:00/0000:00:1c.6/0000:09:00.0/usb5/5-1
    09:48:02.296 (ports 5):   devnode=/dev/bus/usb/005/033, subsystem=usb, ifacenum=-1
    09:48:02.296 (ports 5): usb_add: /dev/bus/usb/005/033 (Teensy 4.0) Bootloader
    09:48:02.297 (ports 5): add child:  subsys=usb, type=usb_interface, location=/sys/devices/pci0000:00/0000:00:1c.6/0000:09:00.0/usb5/5-1/5-1:1.0
    09:48:02.297 (ports 5):   parent location=/sys/devices/pci0000:00/0000:00:1c.6/0000:09:00.0/usb5/5-1
    09:48:02.297 (ports 5): usb_add: /dev/bus/usb/005/033 (Teensy 4.0) Bootloader
    09:48:02.298 (ports 5): add child:  subsys=hid, type=(null), location=/sys/devices/pci0000:00/0000:00:1c.6/0000:09:00.0/usb5/5-1/5-1:1.0/0003:16C0:0478.0013
    09:48:02.298 (ports 5):   parent location=/sys/devices/pci0000:00/0000:00:1c.6/0000:09:00.0/usb5/5-1
    09:48:02.298 (ports 5):   model=36 (Teensy 4.0)
    09:48:02.298 (ports 5): usb_add: /dev/bus/usb/005/033 (Teensy 4.0) Bootloader
    09:48:02.299 (ports 5): add child:  subsys=hidraw, type=(null), location=/sys/devices/pci0000:00/0000:00:1c.6/0000:09:00.0/usb5/5-1/5-1:1.0/0003:16C0:0478.0013/hidraw/hidraw3
    09:48:02.299 (ports 5):   parent location=/sys/devices/pci0000:00/0000:00:1c.6/0000:09:00.0/usb5/5-1
    09:48:02.299 (ports 5): usb_add: /dev/bus/usb/005/033 (Teensy 4.0) Bootloader
    09:48:02.300 (ports 5): unknown action: bind
    09:48:02.300 (ports 5): unknown action: bind
    09:48:02.301 (ports 5): unknown action: bind
    09:48:02.325 (reboot 15): Status: 1, 1, 0, 2, 0, 0, /tmp/arduino_build_728953/, TL_TestOutput_float.ino.hex
    09:48:02.325 (reboot 15): status read, retry 4
    09:48:02.470 (loader): Device came online, code_size = 2031616
    09:48:02.470 (loader): Board is: Teensy 4.0 (IMXRT1062), version 1.05
    09:48:02.471 (ports 5): del child: location=/sys/devices/pci0000:00/0000:00:1c.6/0000:09:00.0/usb5/5-1/5-1:1.0/0003:16C0:0478.0013/hidraw/hidraw3
    09:48:02.471 (ports 5): unknown action: unbind
    09:48:02.472 (ports 5): del child: location=/sys/devices/pci0000:00/0000:00:1c.6/0000:09:00.0/usb5/5-1/5-1:1.0/0003:16C0:0478.0013
    09:48:02.472 (ports 5): unknown action: unbind
    09:48:02.478 (loader): File "TL_TestOutput_float.ino.hex". 29308 bytes, 1% used
    09:48:02.481 (loader): set background IMG_ONLINE
    09:48:02.491 (loader): File "TL_TestOutput_float.ino.hex". 29308 bytes, 1% used
    09:48:02.495 (loader): elf appears to be for Teensy 4.0 (IMXRT1062) (2031616 bytes)
    09:48:02.495 (loader): elf binary data matches hex file
    09:48:02.495 (loader): elf file is for Teensy 4.0 (IMXRT1062)
    09:48:02.498 (loader): begin operation
    09:48:02.502 (loader): remote cmd from 8: "status"
    09:48:02.502 (reboot 15): Status: 1, 1, 1, 3, 0, 1, /tmp/arduino_build_728953/, TL_TestOutput_float.ino.hex
    09:48:02.502 (loader): flash, block=0, bs=1024, auto=1
    09:48:02.502 (loader):  gauge old value = 0
    09:48:02.503 (loader): flash, block=1, bs=1024, auto=1
    09:48:02.723 (loader):  gauge old value = 1
    09:48:02.724 (loader): remote cmd from 8: "status"
    09:48:02.724 (reboot 15): Status: 1, 1, 1, 3, 0, 1, /tmp/arduino_build_728953/, TL_TestOutput_float.ino.hex
    09:48:02.724 (loader): flash, block=2, bs=1024, auto=1
    09:48:02.724 (loader):  gauge old value = 2
    09:48:02.725 (loader): flash, block=3, bs=1024, auto=1
    09:48:02.725 (loader):  gauge old value = 3
    09:48:02.726 (loader): flash, block=4, bs=1024, auto=1
    09:48:02.726 (loader):  gauge old value = 4
    09:48:02.729 (loader): flash, block=5, bs=1024, auto=1
    09:48:02.730 (loader):  gauge old value = 5
    09:48:02.731 (loader): flash, block=6, bs=1024, auto=1
    09:48:02.731 (loader):  gauge old value = 6
    09:48:02.732 (loader): flash, block=7, bs=1024, auto=1
    09:48:02.733 (loader):  gauge old value = 7
    09:48:02.734 (loader): flash, block=8, bs=1024, auto=1
    09:48:02.735 (loader):  gauge old value = 8
    09:48:02.735 (loader): flash, block=9, bs=1024, auto=1
    09:48:02.736 (loader):  gauge old value = 9
    09:48:02.737 (loader): flash, block=10, bs=1024, auto=1
    09:48:02.738 (loader):  gauge old value = 10
    09:48:02.739 (loader): flash, block=11, bs=1024, auto=1
    09:48:02.740 (loader):  gauge old value = 11
    09:48:02.740 (loader): flash, block=12, bs=1024, auto=1
    09:48:02.741 (loader):  gauge old value = 12
    09:48:02.742 (loader): flash, block=13, bs=1024, auto=1
    09:48:02.743 (loader):  gauge old value = 13
    09:48:02.743 (loader): flash, block=14, bs=1024, auto=1
    09:48:02.744 (loader):  gauge old value = 14
    09:48:02.745 (loader): flash, block=15, bs=1024, auto=1
    09:48:02.746 (loader):  gauge old value = 15
    09:48:02.747 (loader): flash, block=16, bs=1024, auto=1
    09:48:02.748 (loader):  gauge old value = 16
    09:48:02.748 (loader): flash, block=17, bs=1024, auto=1
    09:48:02.749 (loader):  gauge old value = 17
    09:48:02.750 (loader): flash, block=18, bs=1024, auto=1
    09:48:02.751 (loader):  gauge old value = 18
    09:48:02.752 (loader): flash, block=19, bs=1024, auto=1
    09:48:02.753 (loader):  gauge old value = 19
    09:48:02.753 (loader): flash, block=20, bs=1024, auto=1
    09:48:02.754 (loader):  gauge old value = 20
    09:48:02.755 (loader): flash, block=21, bs=1024, auto=1
    09:48:02.756 (loader):  gauge old value = 21
    09:48:02.756 (loader): flash, block=22, bs=1024, auto=1
    09:48:02.758 (loader):  gauge old value = 22
    09:48:02.758 (loader): flash, block=23, bs=1024, auto=1
    09:48:02.759 (loader):  gauge old value = 23
    09:48:02.760 (loader): flash, block=24, bs=1024, auto=1
    09:48:02.761 (loader):  gauge old value = 24
    09:48:02.761 (loader): flash, block=25, bs=1024, auto=1
    09:48:02.762 (loader):  gauge old value = 25
    09:48:02.763 (loader): flash, block=26, bs=1024, auto=1
    09:48:02.764 (loader):  gauge old value = 26
    09:48:02.765 (loader): flash, block=27, bs=1024, auto=1
    09:48:02.766 (loader):  gauge old value = 27
    09:48:02.766 (loader): flash, block=28, bs=1024, auto=1
    09:48:02.767 (loader):  gauge old value = 28
    09:48:02.769 (loader): sending reboot
    09:48:02.770 (loader): begin wait_until_offline
    09:48:02.773 (ports 5): unknown action: unbind
    09:48:02.773 (ports 5): del child: location=/sys/devices/pci0000:00/0000:00:1c.6/0000:09:00.0/usb5/5-1/5-1:1.0
    09:48:02.774 (ports 5): unknown action: unbind
    09:48:02.775 (ports 5): del device: location=/sys/devices/pci0000:00/0000:00:1c.6/0000:09:00.0/usb5/5-1
    09:48:02.820 (loader): HID/linux: something changed, try reading a descriptor
    09:48:02.820 (loader): HID/linux: Device was just disconnected
    09:48:02.820 (loader): offline, waited 1
    09:48:02.820 (loader): end operation, total time = 0.322 seconds
    09:48:02.820 (loader): set background IMG_REBOOT_OK
    09:48:02.823 (loader): redraw timer set, image 14 to show for 1200 ms
    09:48:02.824 (loader): remote cmd from 8: "status"
    09:48:02.870 (reboot 15): Status: 1, 1, 0, 3, 0, 0, /tmp/arduino_build_728953/, TL_TestOutput_float.ino.hex
    09:48:02.870 (reboot 15): status read, retry 5
    09:48:02.870 (reboot 15): Success
    09:48:02.870 (reboot 15): Disconnect
    09:48:02.880 (loader): remote connection 8 closed
    09:48:02.884 (serialmon 16): Begin, version=1.53
    09:48:02.884 (serialmon 16): listening for location: /sys/devices/pci0000:00/0000:00:1c.6/0000:09:00.0/usb5/5-1
    09:48:02.895 (loader): remote connection 8 opened
    09:48:03.576 (ports 5): purge, name=/dev/bus/usb/005/033 (Teensy 4.0) Bootloader, loc=/sys/devices/pci0000:00/0000:00:1c.6/0000:09:00.0/usb5/5-1, age=0.801
    09:48:03.897 (loader): remote connection 8 closed
    09:48:04.025 (loader): redraw, image 9
    09:49:05.541 (ports 5): add device: subsys=usb, type=usb_device, location=/sys/devices/pci0000:00/0000:00:1c.6/0000:09:00.0/usb5/5-1
    09:49:05.541 (ports 5):   devnode=/dev/bus/usb/005/038, subsystem=usb, ifacenum=-1
    09:49:05.541 (ports 5): usb_add: /dev/bus/usb/005/038 (Teensy) Bootloader
    09:49:05.542 (ports 5): add child:  subsys=usb, type=usb_interface, location=/sys/devices/pci0000:00/0000:00:1c.6/0000:09:00.0/usb5/5-1/5-1:1.0
    09:49:05.542 (ports 5):   parent location=/sys/devices/pci0000:00/0000:00:1c.6/0000:09:00.0/usb5/5-1
    09:49:05.542 (ports 5): usb_add: /dev/bus/usb/005/038 (Teensy) Bootloader
    09:49:05.544 (ports 5): add child:  subsys=hid, type=(null), location=/sys/devices/pci0000:00/0000:00:1c.6/0000:09:00.0/usb5/5-1/5-1:1.0/0003:16C0:0478.0014
    09:49:05.544 (ports 5):   parent location=/sys/devices/pci0000:00/0000:00:1c.6/0000:09:00.0/usb5/5-1
    09:49:05.544 (ports 5):   model=36 (Teensy 4.0)
    09:49:05.544 (ports 5): usb_add: /dev/bus/usb/005/038 (Teensy 4.0) Bootloader
    09:49:05.545 (ports 5): add child:  subsys=hidraw, type=(null), location=/sys/devices/pci0000:00/0000:00:1c.6/0000:09:00.0/usb5/5-1/5-1:1.0/0003:16C0:0478.0014/hidraw/hidraw3
    09:49:05.545 (ports 5):   parent location=/sys/devices/pci0000:00/0000:00:1c.6/0000:09:00.0/usb5/5-1
    09:49:05.545 (ports 5): usb_add: /dev/bus/usb/005/038 (Teensy 4.0) Bootloader
    09:49:05.546 (ports 5): unknown action: bind
    09:49:05.547 (ports 5): unknown action: bind
    09:49:05.548 (ports 5): unknown action: bind
    09:49:05.708 (loader): Device came online, code_size = 2031616
    09:49:05.708 (loader): Board is: Teensy 4.0 (IMXRT1062), version 1.05
    09:49:05.709 (ports 5): del child: location=/sys/devices/pci0000:00/0000:00:1c.6/0000:09:00.0/usb5/5-1/5-1:1.0/0003:16C0:0478.0014/hidraw/hidraw3
    09:49:05.710 (ports 5): unknown action: unbind
    09:49:05.711 (ports 5): del child: location=/sys/devices/pci0000:00/0000:00:1c.6/0000:09:00.0/usb5/5-1/5-1:1.0/0003:16C0:0478.0014
    09:49:05.711 (ports 5): unknown action: unbind
    09:49:05.717 (loader): File "TL_TestOutput_float.ino.hex". 29308 bytes, 1% used
    09:49:05.720 (loader): set background IMG_ONLINE
    09:49:05.730 (loader): File "TL_TestOutput_float.ino.hex". 29308 bytes, 1% used
    09:49:05.733 (loader): elf appears to be for Teensy 4.0 (IMXRT1062) (2031616 bytes)
    09:49:05.733 (loader): elf binary data matches hex file
    09:49:05.733 (loader): elf file is for Teensy 4.0 (IMXRT1062)
    09:49:05.737 (loader): begin operation
    09:49:05.739 (loader): flash, block=0, bs=1024, auto=1
    09:49:05.739 (loader):  gauge old value = 0
    09:49:05.740 (loader): flash, block=1, bs=1024, auto=1
    09:49:05.958 (loader):  gauge old value = 1
    09:49:05.959 (loader): flash, block=2, bs=1024, auto=1
    09:49:05.960 (loader):  gauge old value = 2
    09:49:05.960 (loader): flash, block=3, bs=1024, auto=1
    09:49:05.960 (loader):  gauge old value = 3
    09:49:05.961 (loader): flash, block=4, bs=1024, auto=1
    09:49:05.961 (loader):  gauge old value = 4
    09:49:05.966 (loader): flash, block=5, bs=1024, auto=1
    09:49:05.966 (loader):  gauge old value = 5
    09:49:05.968 (loader): flash, block=6, bs=1024, auto=1
    09:49:05.968 (loader):  gauge old value = 6
    09:49:05.970 (loader): flash, block=7, bs=1024, auto=1
    09:49:05.970 (loader):  gauge old value = 7
    09:49:05.972 (loader): flash, block=8, bs=1024, auto=1
    09:49:05.972 (loader):  gauge old value = 8
    09:49:05.973 (loader): flash, block=9, bs=1024, auto=1
    09:49:05.974 (loader):  gauge old value = 9
    09:49:05.975 (loader): flash, block=10, bs=1024, auto=1
    09:49:05.975 (loader):  gauge old value = 10
    09:49:05.976 (loader): flash, block=11, bs=1024, auto=1
    09:49:05.977 (loader):  gauge old value = 11
    09:49:05.977 (loader): flash, block=12, bs=1024, auto=1
    09:49:05.978 (loader):  gauge old value = 12
    09:49:05.979 (loader): flash, block=13, bs=1024, auto=1
    09:49:05.980 (loader):  gauge old value = 13
    09:49:05.981 (loader): flash, block=14, bs=1024, auto=1
    09:49:05.982 (loader):  gauge old value = 14
    09:49:05.982 (loader): flash, block=15, bs=1024, auto=1
    09:49:05.983 (loader):  gauge old value = 15
    09:49:05.984 (loader): flash, block=16, bs=1024, auto=1
    09:49:05.985 (loader):  gauge old value = 16
    09:49:05.985 (loader): flash, block=17, bs=1024, auto=1
    09:49:05.987 (loader):  gauge old value = 17
    09:49:05.987 (loader): flash, block=18, bs=1024, auto=1
    09:49:05.988 (loader):  gauge old value = 18
    09:49:05.989 (loader): flash, block=19, bs=1024, auto=1
    09:49:05.990 (loader):  gauge old value = 19
    09:49:05.990 (loader): flash, block=20, bs=1024, auto=1
    09:49:05.992 (loader):  gauge old value = 20
    09:49:05.992 (loader): flash, block=21, bs=1024, auto=1
    09:49:05.993 (loader):  gauge old value = 21
    09:49:05.994 (loader): flash, block=22, bs=1024, auto=1
    09:49:05.995 (loader):  gauge old value = 22
    09:49:05.995 (loader): flash, block=23, bs=1024, auto=1
    09:49:05.996 (loader):  gauge old value = 23
    09:49:05.997 (loader): flash, block=24, bs=1024, auto=1
    09:49:05.998 (loader):  gauge old value = 24
    09:49:05.999 (loader): flash, block=25, bs=1024, auto=1
    09:49:06.000 (loader):  gauge old value = 25
    09:49:06.000 (loader): flash, block=26, bs=1024, auto=1
    09:49:06.001 (loader):  gauge old value = 26
    09:49:06.002 (loader): flash, block=27, bs=1024, auto=1
    09:49:06.003 (loader):  gauge old value = 27
    09:49:06.003 (loader): flash, block=28, bs=1024, auto=1
    09:49:06.005 (loader):  gauge old value = 28
    09:49:06.006 (loader): sending reboot
    09:49:06.007 (loader): begin wait_until_offline
    09:49:06.010 (ports 5): unknown action: unbind
    09:49:06.010 (ports 5): del child: location=/sys/devices/pci0000:00/0000:00:1c.6/0000:09:00.0/usb5/5-1/5-1:1.0
    09:49:06.011 (ports 5): unknown action: unbind
    09:49:06.012 (ports 5): del device: location=/sys/devices/pci0000:00/0000:00:1c.6/0000:09:00.0/usb5/5-1
    09:49:06.057 (loader): HID/linux: something changed, try reading a descriptor
    09:49:06.057 (loader): HID/linux: Device was just disconnected
    09:49:06.057 (loader): offline, waited 1
    09:49:06.057 (loader): end operation, total time = 0.320 seconds
    09:49:06.057 (loader): set background IMG_REBOOT_OK
    09:49:06.060 (loader): redraw timer set, image 14 to show for 1200 ms    *** Continued below ***
    
    **********EXAMPLE OF GOOD LOAD/REBOOT AT THIS POINT, JUST AFTER DATA TRANSFER:   ************
    09:41:36.879 (ports 5): add device: subsys=usb, type=usb_device, location=/sys/devices/pci0000:00/0000:00:1c.6/0000:09:00.0/usb5/5-1
    09:41:36.879 (ports 5):   devnode=/dev/bus/usb/005/030, subsystem=usb, ifacenum=-1
    09:41:36.879 (ports 5): usb_add: /dev/bus/usb/005/030 (Teensy 4.0) Serial
    09:41:36.882 (ports 5): add child:  subsys=usb, type=usb_interface, location=/sys/devices/pci0000:00/0000:00:1c.6/0000:09:00.0/usb5/5-1/5-1:1.0
    09:41:36.882 (ports 5):   parent location=/sys/devices/pci0000:00/0000:00:1c.6/0000:09:00.0/usb5/5-1
    09:41:36.882 (ports 5):   model=36 (Teensy 4.0)
    09:41:36.882 (ports 5): usb_add: /dev/bus/usb/005/030 (Teensy 4.0) Serial
    09:41:36.883 (ports 5): add child:  subsys=usb, type=usb_interface, location=/sys/devices/pci0000:00/0000:00:1c.6/0000:09:00.0/usb5/5-1/5-1:1.1
    09:41:36.883 (ports 5):   parent location=/sys/devices/pci0000:00/0000:00:1c.6/0000:09:00.0/usb5/5-1
    09:41:36.883 (ports 5): usb_add: /dev/bus/usb/005/030 (Teensy 4.0) Serial
    09:41:36.883 (ports 5): unknown action: bind
    09:41:36.885 (ports 5): add child:  subsys=tty, type=(null), location=/sys/devices/pci0000:00/0000:00:1c.6/0000:09:00.0/usb5/5-1/5-1:1.0/tty/ttyACM0
    09:41:36.885 (ports 5):   parent location=/sys/devices/pci0000:00/0000:00:1c.6/0000:09:00.0/usb5/5-1
    09:41:36.885 (ports 5):   devnode=/dev/ttyACM0, subsystem=tty, ifacenum=0
    09:41:36.885 (ports 5): usb_add: /dev/ttyACM0 (Teensy 4.0) Serial
    09:41:36.886 (ports 5): unknown action: bind
    09:41:36.887 (ports 5): unknown action: bind
    09:41:37.422 (loader): redraw, image 9
    *************************************************** END OF GOOD LOAD/REBOOT EXAMPLE *****************************************
    
    ************ Back to Loader output for Bad Load/Reboot:     ********
    09:49:06.448 (serialmon 17): Begin, version=1.53
    09:49:06.448 (serialmon 17): listening for location: /sys/devices/pci0000:00/0000:00:1c.6/0000:09:00.0/usb5/5-1
    09:49:06.501 (loader): remote connection 8 opened
    09:49:06.813 (ports 5): purge, name=/dev/bus/usb/005/038 (Teensy 4.0) Bootloader, loc=/sys/devices/pci0000:00/0000:00:1c.6/0000:09:00.0/usb5/5-1, age=0.801
    09:49:07.261 (loader): redraw, image 9
    09:49:07.446 (loader): remote connection 8 closed
    09:49:53.790 (loader): Verbose Info event
    Can somebody tell me if the Loader entry
    "09:49:06.006 (loader): sending reboot"
    resulted in a reboot, and therefore the running of my Teensy code with the possibility of overwriting something? That "overwrite" might stop the Teensy from doing USB serial? Or is there something else happening that can be deduced? I'm overwhelmed!!

    For further reference, here is the Linux /var/log/syslog for the same time period
    Code:
    Jul 29 09:48:01 bob-desktop kernel: [ 4964.779055] usb 5-1: USB disconnect, device number 32
    Jul 29 09:48:01 bob-desktop upowerd[1065]: unhandled action 'unbind' on /sys/devices/pci0000:00/0000:00:1c.6/0000:09:00.0/usb5/5-1/5-1:1.1
    Jul 29 09:48:01 bob-desktop upowerd[1065]: unhandled action 'unbind' on /sys/devices/pci0000:00/0000:00:1c.6/0000:09:00.0/usb5/5-1/5-1:1.0
    Jul 29 09:48:01 bob-desktop upowerd[1065]: unhandled action 'unbind' on /sys/devices/pci0000:00/0000:00:1c.6/0000:09:00.0/usb5/5-1
    Jul 29 09:48:01 bob-desktop kernel: [ 4964.996708] debugfs: Directory '02' with parent 'devices' already present!
    Jul 29 09:48:02 bob-desktop kernel: [ 4965.192564] usb 5-1: new high-speed USB device number 33 using xhci_hcd
    Jul 29 09:48:02 bob-desktop kernel: [ 4965.408779] usb 5-1: New USB device found, idVendor=16c0, idProduct=0478, bcdDevice= 1.05
    Jul 29 09:48:02 bob-desktop kernel: [ 4965.408780] usb 5-1: New USB device strings: Mfr=0, Product=0, SerialNumber=1
    Jul 29 09:48:02 bob-desktop kernel: [ 4965.408781] usb 5-1: SerialNumber: 00097D96
    Jul 29 09:48:02 bob-desktop kernel: [ 4965.412514] hid-generic 0003:16C0:0478.0013: hidraw3: USB HID v1.11 Device [HID 16c0:0478] on usb-0000:09:00.0-1/input0
    Jul 29 09:48:02 bob-desktop upowerd[1065]: unhandled action 'bind' on /sys/devices/pci0000:00/0000:00:1c.6/0000:09:00.0/usb5/5-1/5-1:1.0/0003:16C0:0478.0013
    Jul 29 09:48:02 bob-desktop upowerd[1065]: unhandled action 'bind' on /sys/devices/pci0000:00/0000:00:1c.6/0000:09:00.0/usb5/5-1/5-1:1.0
    Jul 29 09:48:02 bob-desktop upowerd[1065]: unhandled action 'bind' on /sys/devices/pci0000:00/0000:00:1c.6/0000:09:00.0/usb5/5-1
    Jul 29 09:48:02 bob-desktop upowerd[1065]: unhandled action 'unbind' on /sys/devices/pci0000:00/0000:00:1c.6/0000:09:00.0/usb5/5-1/5-1:1.0/0003:16C0:0478.0013
    Jul 29 09:48:02 bob-desktop upowerd[1065]: unhandled action 'unbind' on /sys/devices/pci0000:00/0000:00:1c.6/0000:09:00.0/usb5/5-1/5-1:1.0
    Jul 29 09:48:02 bob-desktop upowerd[1065]: unhandled action 'unbind' on /sys/devices/pci0000:00/0000:00:1c.6/0000:09:00.0/usb5/5-1/5-1:1.0
    Jul 29 09:48:02 bob-desktop upowerd[1065]: unhandled action 'unbind' on /sys/devices/pci0000:00/0000:00:1c.6/0000:09:00.0/usb5/5-1
    Jul 29 09:48:02 bob-desktop kernel: [ 4965.888834] usb 5-1: USB disconnect, device number 33
    Jul 29 09:48:03 bob-desktop kernel: [ 4966.140724] debugfs: Directory '02' with parent 'devices' already present!
    Jul 29 09:48:03 bob-desktop kernel: [ 4966.340577] usb 5-1: new high-speed USB device number 34 using xhci_hcd
    Jul 29 09:48:08 bob-desktop kernel: [ 4971.676676] usb 5-1: device descriptor read/64, error -110
    Jul 29 09:48:24 bob-desktop kernel: [ 4987.292782] usb 5-1: device descriptor read/64, error -110
    Jul 29 09:48:24 bob-desktop kernel: [ 4987.401220] debugfs: Directory '02' with parent 'devices' already present!
    Jul 29 09:48:24 bob-desktop kernel: [ 4987.596694] usb 5-1: new high-speed USB device number 35 using xhci_hcd
    Jul 29 09:48:29 bob-desktop kernel: [ 4992.924786] usb 5-1: device descriptor read/64, error -110
    Jul 29 09:48:45 bob-desktop kernel: [ 5008.540880] usb 5-1: device descriptor read/64, error -110
    Jul 29 09:48:45 bob-desktop kernel: [ 5008.648809] usb usb5-port1: attempt power cycle
    Jul 29 09:48:45 bob-desktop kernel: [ 5008.964980] debugfs: Directory '02' with parent 'devices' already present!
    Jul 29 09:48:46 bob-desktop kernel: [ 5009.368810] usb 5-1: new high-speed USB device number 36 using xhci_hcd
    Jul 29 09:48:54 bob-desktop kernel: [ 5017.562110] usb 5-1: Device not responding to setup address.
    Jul 29 09:48:54 bob-desktop kernel: [ 5017.562545] debugfs: Directory '02' with parent 'devices' already present!
    Jul 29 09:49:02 bob-desktop kernel: [ 5025.962072] usb 5-1: Device not responding to setup address.
    Jul 29 09:49:02 bob-desktop kernel: [ 5025.962481] debugfs: Directory '02' with parent 'devices' already present!
    Jul 29 09:49:03 bob-desktop kernel: [ 5026.168911] usb 5-1: device not accepting address 36, error -71
    Jul 29 09:49:03 bob-desktop kernel: [ 5026.169373] debugfs: Directory '02' with parent 'devices' already present!
    Jul 29 09:49:03 bob-desktop kernel: [ 5026.364908] usb 5-1: new high-speed USB device number 37 using xhci_hcd
    Jul 29 09:49:04 bob-desktop kernel: [ 5027.680771] usb 5-1: Device not responding to setup address.
    Jul 29 09:49:04 bob-desktop kernel: [ 5027.681213] debugfs: Directory '02' with parent 'devices' already present!
    Jul 29 09:49:04 bob-desktop kernel: [ 5027.889104] usb 5-1: Device not responding to setup address.
    Jul 29 09:49:04 bob-desktop kernel: [ 5027.889542] debugfs: Directory '02' with parent 'devices' already present!
    Jul 29 09:49:04 bob-desktop kernel: [ 5028.096921] usb 5-1: device not accepting address 37, error -71
    Jul 29 09:49:04 bob-desktop kernel: [ 5028.096946] usb usb5-port1: unable to enumerate USB device
    Jul 29 09:49:05 bob-desktop kernel: [ 5028.241143] debugfs: Directory '02' with parent 'devices' already present!
    Jul 29 09:49:05 bob-desktop kernel: [ 5028.436924] usb 5-1: new high-speed USB device number 38 using xhci_hcd
    Jul 29 09:49:05 bob-desktop kernel: [ 5028.653302] usb 5-1: New USB device found, idVendor=16c0, idProduct=0478, bcdDevice= 1.05
    Jul 29 09:49:05 bob-desktop kernel: [ 5028.653304] usb 5-1: New USB device strings: Mfr=0, Product=0, SerialNumber=1
    Jul 29 09:49:05 bob-desktop kernel: [ 5028.653305] usb 5-1: SerialNumber: 00097D96
    Jul 29 09:49:05 bob-desktop kernel: [ 5028.657170] hid-generic 0003:16C0:0478.0014: hidraw3: USB HID v1.11 Device [HID 16c0:0478] on usb-0000:09:00.0-1/input0
    Jul 29 09:49:05 bob-desktop upowerd[1065]: unhandled action 'bind' on /sys/devices/pci0000:00/0000:00:1c.6/0000:09:00.0/usb5/5-1/5-1:1.0/0003:16C0:0478.0014
    Jul 29 09:49:05 bob-desktop upowerd[1065]: unhandled action 'bind' on /sys/devices/pci0000:00/0000:00:1c.6/0000:09:00.0/usb5/5-1/5-1:1.0
    Jul 29 09:49:05 bob-desktop upowerd[1065]: unhandled action 'bind' on /sys/devices/pci0000:00/0000:00:1c.6/0000:09:00.0/usb5/5-1
    Jul 29 09:49:05 bob-desktop upowerd[1065]: unhandled action 'unbind' on /sys/devices/pci0000:00/0000:00:1c.6/0000:09:00.0/usb5/5-1/5-1:1.0/0003:16C0:0478.0014
    Jul 29 09:49:05 bob-desktop upowerd[1065]: unhandled action 'unbind' on /sys/devices/pci0000:00/0000:00:1c.6/0000:09:00.0/usb5/5-1/5-1:1.0
    Jul 29 09:49:06 bob-desktop kernel: [ 5029.126341] usb 5-1: USB disconnect, device number 38
    Jul 29 09:49:06 bob-desktop upowerd[1065]: unhandled action 'unbind' on /sys/devices/pci0000:00/0000:00:1c.6/0000:09:00.0/usb5/5-1/5-1:1.0
    Jul 29 09:49:06 bob-desktop upowerd[1065]: unhandled action 'unbind' on /sys/devices/pci0000:00/0000:00:1c.6/0000:09:00.0/usb5/5-1
    Jul 29 09:49:06 bob-desktop kernel: [ 5029.377100] debugfs: Directory '02' with parent 'devices' already present!
    Jul 29 09:49:06 bob-desktop kernel: [ 5029.572907] usb 5-1: new high-speed USB device number 39 using xhci_hcd
    Jul 29 09:49:11 bob-desktop kernel: [ 5034.909049] usb 5-1: device descriptor read/64, error -110
    Jul 29 09:49:27 bob-desktop kernel: [ 5050.525200] usb 5-1: device descriptor read/64, error -110
    Jul 29 09:49:27 bob-desktop kernel: [ 5050.633645] debugfs: Directory '02' with parent 'devices' already present!
    Jul 29 09:49:27 bob-desktop kernel: [ 5050.829101] usb 5-1: new high-speed USB device number 40 using xhci_hcd
    Jul 29 09:49:33 bob-desktop kernel: [ 5056.157202] usb 5-1: device descriptor read/64, error -110
    Jul 29 09:49:48 bob-desktop kernel: [ 5071.773375] usb 5-1: device descriptor read/64, error -110
    Jul 29 09:49:48 bob-desktop kernel: [ 5071.881317] usb usb5-port1: attempt power cycle
    Jul 29 09:49:49 bob-desktop kernel: [ 5072.197545] debugfs: Directory '02' with parent 'devices' already present!
    Jul 29 09:49:49 bob-desktop kernel: [ 5072.601272] usb 5-1: new high-speed USB device number 41 using xhci_hcd
    Jul 29 09:49:57 bob-desktop kernel: [ 5080.794585] usb 5-1: Device not responding to setup address.
    Jul 29 09:49:57 bob-desktop kernel: [ 5080.795010] debugfs: Directory '02' with parent 'devices' already present!
    Jul 29 09:50:06 bob-desktop kernel: [ 5089.194549] usb 5-1: Device not responding to setup address.
    Jul 29 09:50:06 bob-desktop kernel: [ 5089.194985] debugfs: Directory '02' with parent 'devices' already present!
    Jul 29 09:50:06 bob-desktop kernel: [ 5089.401421] usb 5-1: device not accepting address 41, error -71
    Jul 29 09:50:06 bob-desktop kernel: [ 5089.401916] debugfs: Directory '02' with parent 'devices' already present!
    Jul 29 09:50:06 bob-desktop kernel: [ 5089.597430] usb 5-1: new high-speed USB device number 42 using xhci_hcd
    Jul 29 09:50:14 bob-desktop kernel: [ 5097.790659] usb 5-1: Device not responding to setup address.
    Jul 29 09:50:14 bob-desktop kernel: [ 5097.791079] debugfs: Directory '02' with parent 'devices' already present!
    Jul 29 09:50:23 bob-desktop kernel: [ 5106.190757] usb 5-1: Device not responding to setup address.
    Jul 29 09:50:23 bob-desktop kernel: [ 5106.191204] debugfs: Directory '02' with parent 'devices' already present!
    Jul 29 09:50:23 bob-desktop kernel: [ 5106.397584] usb 5-1: device not accepting address 42, error -71
    Jul 29 09:50:23 bob-desktop kernel: [ 5106.397609] usb usb5-port1: unable to enumerate USB device
    One other clue, is that there have been Linux error messages, at times, that have suggested the Linux Oops of previous posts in this thread was related to a process taking over a CPU for some number of seconds. I am no longer getting Oops messages, but Linux is showing serious problems with very messy shutdowns and reboots, only after the Load/Boot problem.

    Sorry I can't seem to make this simple.

    Bob

  22. #22
    Senior Member PaulStoffregen's Avatar
    Join Date
    Nov 2012
    Posts
    22,757
    Wow, maybe this is a previously unknown & elusive bug?!

    Can I talk you into sharing the compiled .elf and .hex files for both the Teensy 4.0 and Teensy 3.6? That will let me try it here on Ubuntu 18 using the exact same data.

    You'll probably need to put all 4 into a zip file to attach them to a message here on the forum. If using the Quick Reply editor, click "Go Advanced" to get to the full editor which lets you attach a zip file.

  23. #23
    Senior Member
    Join Date
    Feb 2015
    Location
    Finland
    Posts
    216
    To me, it looks like an actual Linux kernel bug, that occurs when an USB URB is canceled (because the device reset or vanishes).

    There is a relatively recent possibly related bug report on the linux-usb mailing list.

    However, an even more recent thread points out in my opinion, the underlying cause of this particular crash/oops! a race condition in this exact situation that would produce pretty much exactly this kind of oops, if there was a reliable pattern to reproduce the timing.

    In my opinion, Teensy just happens to hit that window when programming it, on some hardware.

    It might be useful to post an email to the linux-usb mailing list (info) with a crash dump (preferably on different machines, if you can duplicate it), asking if this is a related issue. (I believe it is, because it fits the pattern. But I am not a paid kernel developer, and I could be quite wrong.)

  24. #24
    Senior Member
    Join Date
    Dec 2016
    Posts
    138
    Here are 2 .hex and 2 .elf for T3.6 andT4.0, both sets with the begin() function in the constructor problematic spot. The code is unchanged, only the selection of a Teensy target is changed. The file names start with TL36 or TL40 to keep them straight.
    Good luck!
    Attached Files Attached Files

  25. #25
    Senior Member PaulStoffregen's Avatar
    Join Date
    Nov 2012
    Posts
    22,757
    Thanks. I've put this on my high priority issue list. Hope to look into it this weekend.

Posting Permissions

  • You may not post new threads
  • You may not post replies
  • You may not post attachments
  • You may not edit your posts
  •