arduino / Arduino

Arduino IDE 1.x
https://www.arduino.cc/en/software
Other
14.16k stars 7.02k forks source link

[1.6.8] Serial Monitor Memory leak with linux #4666

Open NicoHood opened 8 years ago

NicoHood commented 8 years ago

I've been using my Arduino for quite some time and I got a weird error every week or so: Randomly my PC (elementary os, based on ubuntu 14.04 x64) does not recognize any keyboard/mouse inputs anymore. The Mouse is still moving though. I cannot do anything, well sometimes it reacts a very short timespan after waiting minutes.

So I switched to tty1 and tried to debug it. Switching takes about 2~3 minutes to do so. In the log below you can see the CPU errors that occur when switching to tty1 and back to tty7. This CPU errors happen when trying to switch, they are not the main reason it seems.

And the only thing you can see is, that my Arduino suddenly disconnected. (No I did not plug it off). I then switched to tty1, check dmesg, plugged the arduino out and back in (to veryfy the device number) and switched back to tty7 where it fully crashed. Afterwards I saved the log:

Mar  7 23:10:50 linuxpc kernel: [ 1192.959430] usb 3-9: USB disconnect, device number 7
Mar  7 23:11:55 linuxpc kernel: [ 1258.470778] ------------[ cut here ]------------
Mar  7 23:11:55 linuxpc kernel: [ 1258.470817] WARNING: CPU: 7 PID: 1535 at /build/linux-lts-utopic-b0JtBC/linux-lts-utopic-3.16.0/drivers/gpu/drm/i915/intel_display.c:3324 intel_crtc_wait_for_pending_flips+0x171/0x180 [i915]()
Mar  7 23:11:55 linuxpc kernel: [ 1258.470819] Modules linked in: ctr ccm pci_stub vboxpci(OE) vboxnetadp(OE) vboxnetflt(OE) vboxdrv(OE) spidev arc4 dm_multipath scsi_dh wl(POE) intel_rapl x86_pkg_temp_thermal intel_powerclamp kvm_intel kvm iwlmvm uvcvideo videobuf2_vmalloc snd_hda_codec_realtek mac80211 snd_hda_codec_generic snd_hda_codec_hdmi videobuf2_memops videobuf2_core v4l2_common serio_raw videodev joydev media cdc_acm bnep rfcomm iwlwifi snd_hda_intel snd_hda_controller snd_hda_codec btusb bluetooth snd_hwdep 6lowpan_iphc snd_pcm lpc_ich rtsx_pci_ms memstick snd_seq_midi cfg80211 snd_seq_midi_event snd_rawmidi snd_seq snd_seq_device shpchp snd_timer mei_me snd mei binfmt_misc soundcore parport_pc mac_hid fujitsu_laptop ppdev coretemp lp parport btrfs xor raid6_pq dm_crypt hid_generic usbhid hid rtsx_pci_sdmmc i915 crct10dif_pclmul crc32_pclmul aesni_intel aes_x86_64 lrw gf128mul i2c_algo_bit glue_helper ablk_helper drm_kms_helper cryptd e1000e drm psmouse ahci rtsx_pci ptp libahci pps_core video
Mar  7 23:11:55 linuxpc kernel: [ 1258.470866] CPU: 7 PID: 1535 Comm: Xorg Tainted: P           OE 3.16.0-62-generic #83~14.04.1-Ubuntu
Mar  7 23:11:55 linuxpc kernel: [ 1258.470867] Hardware name: FUJITSU LIFEBOOK E744/FJNB26F, BIOS Version 1.20 02/03/2015
Mar  7 23:11:55 linuxpc kernel: [ 1258.470868]  0000000000000009 ffff880405287c10 ffffffff817679cc 0000000000000000
Mar  7 23:11:55 linuxpc kernel: [ 1258.470871]  ffff880405287c48 ffffffff8106dcfd 0000000000000000 ffff880407831000
Mar  7 23:11:55 linuxpc kernel: [ 1258.470873]  ffff880035f98238 ffff880035c4a000 ffff880035c4a000 ffff880405287c58
Mar  7 23:11:55 linuxpc kernel: [ 1258.470876] Call Trace:
Mar  7 23:11:55 linuxpc kernel: [ 1258.470883]  [<ffffffff817679cc>] dump_stack+0x45/0x56
Mar  7 23:11:55 linuxpc kernel: [ 1258.470888]  [<ffffffff8106dcfd>] warn_slowpath_common+0x7d/0xa0
Mar  7 23:11:55 linuxpc kernel: [ 1258.470890]  [<ffffffff8106ddda>] warn_slowpath_null+0x1a/0x20
Mar  7 23:11:55 linuxpc kernel: [ 1258.470906]  [<ffffffffc036f941>] intel_crtc_wait_for_pending_flips+0x171/0x180 [i915]
Mar  7 23:11:55 linuxpc kernel: [ 1258.470911]  [<ffffffff810b4f70>] ? prepare_to_wait_event+0x100/0x100
Mar  7 23:11:55 linuxpc kernel: [ 1258.470925]  [<ffffffffc0372403>] intel_crtc_disable_planes+0x33/0x1c0 [i915]
Mar  7 23:11:55 linuxpc kernel: [ 1258.470929]  [<ffffffff8176dfcb>] ? __ww_mutex_lock+0x1b/0x97
Mar  7 23:11:55 linuxpc kernel: [ 1258.470941]  [<ffffffffc03732f5>] haswell_crtc_disable+0x55/0x2e0 [i915]
Mar  7 23:11:55 linuxpc kernel: [ 1258.470944]  [<ffffffff8176e502>] ? mutex_lock+0x12/0x2f
Mar  7 23:11:55 linuxpc kernel: [ 1258.470957]  [<ffffffffc0373d07>] intel_crtc_update_dpms+0x67/0xa0 [i915]
Mar  7 23:11:55 linuxpc kernel: [ 1258.470970]  [<ffffffffc03781c9>] intel_connector_dpms+0x59/0x70 [i915]
Mar  7 23:11:55 linuxpc kernel: [ 1258.470986]  [<ffffffffc01a9abf>] drm_mode_obj_set_property_ioctl+0x39f/0x3b0 [drm]
Mar  7 23:11:55 linuxpc kernel: [ 1258.470997]  [<ffffffffc01a9b00>] drm_mode_connector_property_set_ioctl+0x30/0x40 [drm]
Mar  7 23:11:55 linuxpc kernel: [ 1258.471006]  [<ffffffffc0198a3c>] drm_ioctl+0x1ec/0x660 [drm]
Mar  7 23:11:55 linuxpc kernel: [ 1258.471009]  [<ffffffff810a6198>] ? __enqueue_entity+0x78/0x80
Mar  7 23:11:55 linuxpc kernel: [ 1258.471013]  [<ffffffff8101da53>] ? __switch_to_xtra+0x143/0x180
Mar  7 23:11:55 linuxpc kernel: [ 1258.471015]  [<ffffffff810a7ec5>] ? set_next_entity+0x95/0xb0
Mar  7 23:11:55 linuxpc kernel: [ 1258.471019]  [<ffffffff811e7310>] do_vfs_ioctl+0x2e0/0x4c0
Mar  7 23:11:55 linuxpc kernel: [ 1258.471022]  [<ffffffff8176bc42>] ? __schedule+0x362/0x7b0
Mar  7 23:11:55 linuxpc kernel: [ 1258.471024]  [<ffffffff811e7571>] SyS_ioctl+0x81/0xa0
Mar  7 23:11:55 linuxpc kernel: [ 1258.471027]  [<ffffffff811e9585>] ? SyS_poll+0x65/0x100
Mar  7 23:11:55 linuxpc kernel: [ 1258.471030]  [<ffffffff817700cd>] system_call_fastpath+0x1a/0x1f
Mar  7 23:11:55 linuxpc kernel: [ 1258.471031] ---[ end trace 0adbc0f52ae9bfc2 ]---
Mar  7 23:13:46 linuxpc kernel: [ 1369.037490] usb 3-9: new full-speed USB device number 10 using xhci_hcd
Mar  7 23:13:46 linuxpc kernel: [ 1369.169551] usb 3-9: New USB device found, idVendor=2341, idProduct=8036
Mar  7 23:13:46 linuxpc kernel: [ 1369.169554] usb 3-9: New USB device strings: Mfr=1, Product=2, SerialNumber=3
Mar  7 23:13:46 linuxpc kernel: [ 1369.169556] usb 3-9: Product: Arduino Leonardo
Mar  7 23:13:46 linuxpc kernel: [ 1369.169558] usb 3-9: Manufacturer: Arduino LLC
Mar  7 23:13:46 linuxpc kernel: [ 1369.169559] usb 3-9: SerialNumber: CD
Mar  7 23:13:46 linuxpc kernel: [ 1369.170240] cdc_acm 3-9:1.0: This device cannot do calls on its own. It is not a modem.
Mar  7 23:13:46 linuxpc kernel: [ 1369.171441] cdc_acm 3-9:1.0: ttyACM0: USB ACM device
Mar  7 23:13:46 linuxpc kernel: [ 1369.172455] input: Arduino LLC Arduino Leonardo as /devices/pci0000:00/0000:00:14.0/usb3/3-9/3-9:1.2/0003:2341:8036.0008/input/input31
Mar  7 23:13:46 linuxpc kernel: [ 1369.172575] hid-generic 0003:2341:8036.0008: input,hidraw5: USB HID v1.01 Mouse [Arduino LLC Arduino Leonardo] on usb-0000:00:14.0-9/input2
Mar  7 23:13:46 linuxpc kernel: [ 1369.173593] input: Arduino LLC Arduino Leonardo as /devices/pci0000:00/0000:00:14.0/usb3/3-9/3-9:1.3/0003:2341:8036.0009/input/input32
Mar  7 23:13:46 linuxpc kernel: [ 1369.173705] hid-generic 0003:2341:8036.0009: input,hidraw6: USB HID v1.01 Keyboard [Arduino LLC Arduino Leonardo] on usb-0000:00:14.0-9/input3
Mar  7 23:14:09 linuxpc kernel: [ 1392.420070] usb 3-9: USB disconnect, device number 10
Mar  7 23:19:16 linuxpc kernel: [ 1699.740604] ------------[ cut here ]------------
Mar  7 23:19:16 linuxpc kernel: [ 1699.740680] WARNING: CPU: 7 PID: 1535 at /build/linux-lts-utopic-b0JtBC/linux-lts-utopic-3.16.0/drivers/gpu/drm/i915/intel_display.c:3324 intel_crtc_wait_for_pending_flips+0x171/0x180 [i915]()
Mar  7 23:19:16 linuxpc kernel: [ 1699.740683] Modules linked in: ctr ccm pci_stub vboxpci(OE) vboxnetadp(OE) vboxnetflt(OE) vboxdrv(OE) spidev arc4 dm_multipath scsi_dh wl(POE) intel_rapl x86_pkg_temp_thermal intel_powerclamp kvm_intel kvm iwlmvm uvcvideo videobuf2_vmalloc snd_hda_codec_realtek mac80211 snd_hda_codec_generic snd_hda_codec_hdmi videobuf2_memops videobuf2_core v4l2_common serio_raw videodev joydev media cdc_acm bnep rfcomm iwlwifi snd_hda_intel snd_hda_controller snd_hda_codec btusb bluetooth snd_hwdep 6lowpan_iphc snd_pcm lpc_ich rtsx_pci_ms memstick snd_seq_midi cfg80211 snd_seq_midi_event snd_rawmidi snd_seq snd_seq_device shpchp snd_timer mei_me snd mei binfmt_misc soundcore parport_pc mac_hid fujitsu_laptop ppdev coretemp lp parport btrfs xor raid6_pq dm_crypt hid_generic usbhid hid rtsx_pci_sdmmc i915 crct10dif_pclmul crc32_pclmul aesni_intel aes_x86_64 lrw gf128mul i2c_algo_bit glue_helper ablk_helper drm_kms_helper cryptd e1000e drm psmouse ahci rtsx_pci ptp libahci pps_core video
Mar  7 23:19:16 linuxpc kernel: [ 1699.740785] CPU: 7 PID: 1535 Comm: Xorg Tainted: P        W  OE 3.16.0-62-generic #83~14.04.1-Ubuntu
Mar  7 23:19:16 linuxpc kernel: [ 1699.740789] Hardware name: FUJITSU LIFEBOOK E744/FJNB26F, BIOS Version 1.20 02/03/2015
Mar  7 23:19:16 linuxpc kernel: [ 1699.740792]  0000000000000009 ffff880405287c00 ffffffff817679cc 0000000000000000
Mar  7 23:19:16 linuxpc kernel: [ 1699.740797]  ffff880405287c38 ffffffff8106dcfd 0000000000000000 ffff880407831000
Mar  7 23:19:16 linuxpc kernel: [ 1699.740802]  ffff880035f98238 ffff880035c4a000 ffff880035c4a368 ffff880405287c48
Mar  7 23:19:16 linuxpc kernel: [ 1699.740808] Call Trace:
Mar  7 23:19:16 linuxpc kernel: [ 1699.740822]  [<ffffffff817679cc>] dump_stack+0x45/0x56
Mar  7 23:19:16 linuxpc kernel: [ 1699.740832]  [<ffffffff8106dcfd>] warn_slowpath_common+0x7d/0xa0
Mar  7 23:19:16 linuxpc kernel: [ 1699.740839]  [<ffffffff8106ddda>] warn_slowpath_null+0x1a/0x20
Mar  7 23:19:16 linuxpc kernel: [ 1699.740875]  [<ffffffffc036f941>] intel_crtc_wait_for_pending_flips+0x171/0x180 [i915]
Mar  7 23:19:16 linuxpc kernel: [ 1699.740885]  [<ffffffff810b4f70>] ? prepare_to_wait_event+0x100/0x100
Mar  7 23:19:16 linuxpc kernel: [ 1699.740921]  [<ffffffffc0379199>] intel_crtc_set_config+0x959/0xdb0 [i915]
Mar  7 23:19:16 linuxpc kernel: [ 1699.740953]  [<ffffffffc01a4511>] drm_mode_set_config_internal+0x61/0xe0 [drm]
Mar  7 23:19:16 linuxpc kernel: [ 1699.740982]  [<ffffffffc01a7f61>] drm_mode_setcrtc+0xe1/0x570 [drm]
Mar  7 23:19:16 linuxpc kernel: [ 1699.741002]  [<ffffffffc0198a3c>] drm_ioctl+0x1ec/0x660 [drm]
Mar  7 23:19:16 linuxpc kernel: [ 1699.741013]  [<ffffffff811e7310>] do_vfs_ioctl+0x2e0/0x4c0
Mar  7 23:19:16 linuxpc kernel: [ 1699.741019]  [<ffffffff811d69a1>] ? __sb_end_write+0x31/0x60
Mar  7 23:19:16 linuxpc kernel: [ 1699.741027]  [<ffffffff811d4522>] ? vfs_write+0x172/0x1f0
Mar  7 23:19:16 linuxpc kernel: [ 1699.741032]  [<ffffffff811e7571>] SyS_ioctl+0x81/0xa0
Mar  7 23:19:16 linuxpc kernel: [ 1699.741040]  [<ffffffff817700cd>] system_call_fastpath+0x1a/0x1f
Mar  7 23:19:16 linuxpc kernel: [ 1699.741044] ---[ end trace 0adbc0f52ae9bfc3 ]---
Mar  7 23:19:16 linuxpc kernel: [ 1699.741051] [drm:intel_pipe_set_base] *ERROR* pipe is still busy with an old pageflip

I am using th latest nightly IDE (selfcompiled via git). I also worked on the USB core as you remember, but I have no clue what is happening here. I also cannot post my sketch, it is quite complex. Also I think this was not the problem, since it only presses USB HID keys when I do so with my remote. I also did not use the Serial port, so the device was in idle. It happen with and without usb hub, with different cables.

Also I cannot debug this further because it happens so few times. But I remember that my Arduino sketch crashed somehow, since it did not react to my IR remote anymore. No HID was working and no leds (ir remote can trigger leds). But the watchdog also did not restart the MCU. So I guess the usb core hangs at some function in idle mode. Any Ideas?

facchinm commented 8 years ago

Hi Nico, the stacktrace looks somehow related with Intel display drivers (as you can see from the timestamps, USB events seems uncorrelated with the kernel oops). Is your sketch doing something graphic-related?

NicoHood commented 8 years ago

My sketch controls HID and reads the serial. The time difference is probably because the error occured (Arduino disconnected), then I noticed it some minutes afterwards and switched to tty1 (where then the error was triggered). Next time i could just turn off the pc and see what the log then says. But the error happens very few times.

NicoHood commented 8 years ago

Good for you, bad for me:

My PC crashed again. (and i instantly tunred it off, no switching to tty1) The kernel message sais absolutely nothing. I have no idea how to debug this. its not causes by any usb device it seems. But when the bug occurs the usb devices will give errors, and the display also. I developed an usb bootloader though, but this should not crash my pc, i've been doing this quite some time now.

Any ideas appreciated, however it is not an arduino bug as i first though.

NicoHood commented 8 years ago

I have to reopen this issue, as I had this error again yesterday.

The bug was caused by the IDE, I am pretty sure. I developed for a very long time and the Serial was used a lot. I do not know if this is a linux driver, java or arduino issue, but is has to be one of those.

I will test again and check my ram usage carefully. It might still be a java crash, as it also has some internal memory management I guess. Maybe one who know the code better can give a statement about that.

The last sketch I used printed a single char ('s') aka Serial.println("s"); very fast (every 1~10ms).

NicoHood commented 8 years ago

Yes I am right with my assumption. It takes quite a long time to fill the ram (thatswhy it happened very few times), but it does fill up. I started with 3gb of ram usage and now i got 4gb. The IDE now uses 1.3gb of ram at the moment, increasing slow, but increasing.

I think no screenshots are required that you believe me.

I think one of the problems with the new IDE is the feature, that the serial monitor can stay open, even after uploading. Thatswhy the ram is not freed. On top of that the ram is also not freed if the serial monitor is closed! I have not tested if it continues to fill. The ram is only freed when you close the last IDE window.

And that causes the freeze and the VERY slow PC. Because it started to swap and therefor it was not fully unfunctional but extremely slow. This should be fixed for sure. Luckly I have 16gb and do not notice this bug that fast. Others don't, especially for the ARM builds.

Test sketch:

void setup() {
  // put your setup code here, to run once:
Serial.begin(115200);
}

void loop() {
  // put your main code here, to run repeatedly:
Serial.println("t");
}
NicoHood commented 8 years ago

I've updated the title. I have not tested this issue again with the latest version, not on any other OS. I assume it still got not fixed yet.