tao Posted April 23, 2017 Share Posted April 23, 2017 I have an orange pi one running armbian 5.25 with a 2.4" ili9341 TF LCD initialized with "modprobe fbtft_device custom name=fb_ili9341 gpios=reset:198,dc:199 speed=16000000 rotate=90 busnum=0". Most of the time, after running a pygame program for about 25 minutes I get the error below. Then, often about 10 minutes after the error message the program freezes. ALSA lib pcm.c:7843:(snd_pcm_recover) underrun occurred I've seen the same thing happen with several programs. The program below usually creates the error. Running the same program on raspbian generates no errors so I don't think it's the code itself, but something in the environment. Spoiler #TEST PYGAME PROGRAM import pygame, os os.putenv('SDL_VIDEODRIVER','fbcon') os.putenv('SDL_FBDEV','/dev/fb8') pygame.init() pygame.mouse.set_visible(False) clock = pygame.time.Clock() rect_change_x = rect_change_y = 5 rect_x = rect_y = 50 size = [320, 240] screen = pygame.display.set_mode(size) while 1: for event in pygame.event.get(): if event.type == pygame.QUIT: done = True screen.fill((0,0,0)) pygame.draw.rect(screen, (255,255,255), [rect_x, rect_y, 10, 10]) rect_x += rect_change_x rect_y += rect_change_y if rect_y > 240 or rect_y < 0: rect_change_y = rect_change_y * -1 if rect_x > 320 or rect_x < 0: rect_change_x = rect_change_x * -1 clock.tick(60) pygame.display.flip() pygame.quit() Here's dmesg info from the fb modprobe to just after the program freezes Spoiler [ 34.357584] fbtft_device: SPI devices registered: [ 34.357623] fbtft_device: spidev spi0.0 33000kHz 8 bits mode=0x00 [ 34.357644] fbtft_device: 'fb' Platform devices registered: [ 34.357772] fbtft_device: Deleting spi0.0 [ 34.358537] fbtft_device: GPIOS used by 'fb_ili9341': [ 34.358562] fbtft_device: 'reset' = GPIO198 [ 34.358579] fbtft_device: 'dc' = GPIO199 [ 34.358595] fbtft_device: SPI devices registered: [ 34.358618] fbtft_device: fb_ili9341 spi0.0 16000kHz 8 bits mode=0x00 [ 34.688784] graphics fb8: fb_ili9341 frame buffer, 320x240, 150 KiB video memory, 16 KiB buffer memory, fps=20, spi0.0 at 16 MHz [ 46.507506] vmouse_input_dev_open [ 960.460119] INFO: task kworker/u:0:5 blocked for more than 120 seconds. [ 960.460149] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [ 960.460171] kworker/u:0 D c061e084 0 5 2 0x00000000 [ 960.460253] [<c061e084>] (__schedule+0x574/0x7fc) from [<c061e39c>] (schedule+0x90/0x94) [ 960.460299] [<c061e39c>] (schedule+0x90/0x94) from [<c061c2dc>] (schedule_timeout+0x2c/0x2bc) [ 960.460346] [<c061c2dc>] (schedule_timeout+0x2c/0x2bc) from [<c061d878>] (wait_for_common+0x120/0x168) [ 960.460393] [<c061d878>] (wait_for_common+0x120/0x168) from [<c061d8e0>] (wait_for_completion+0x20/0x24) [ 960.460443] [<c061d8e0>] (wait_for_completion+0x20/0x24) from [<c03e39dc>] (sunxi_spi_work+0x748/0x88c) [ 960.460495] [<c03e39dc>] (sunxi_spi_work+0x748/0x88c) from [<c00445a0>] (process_one_work+0x248/0x404) [ 960.460543] [<c00445a0>] (process_one_work+0x248/0x404) from [<c00459d8>] (worker_thread+0x1b4/0x2d0) [ 960.460592] [<c00459d8>] (worker_thread+0x1b4/0x2d0) from [<c0049cf0>] (kthread+0x94/0xa0) [ 960.460641] [<c0049cf0>] (kthread+0x94/0xa0) from [<c000f1b0>] (kernel_thread_exit+0x0/0x8) [ 960.460680] INFO: task kworker/3:1:27 blocked for more than 120 seconds. [ 960.460700] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [ 960.460722] kworker/3:1 D c061e084 0 27 2 0x00000000 [ 960.460778] [<c061e084>] (__schedule+0x574/0x7fc) from [<c061e39c>] (schedule+0x90/0x94) [ 960.460822] [<c061e39c>] (schedule+0x90/0x94) from [<c061c2dc>] (schedule_timeout+0x2c/0x2bc) [ 960.460866] [<c061c2dc>] (schedule_timeout+0x2c/0x2bc) from [<c061d878>] (wait_for_common+0x120/0x168) [ 960.460913] [<c061d878>] (wait_for_common+0x120/0x168) from [<c061d8e0>] (wait_for_completion+0x20/0x24) [ 960.460959] [<c061d8e0>] (wait_for_completion+0x20/0x24) from [<c03e0854>] (spi_sync+0x84/0xa0) [ 960.461032] [<c03e0854>] (spi_sync+0x84/0xa0) from [<bf12134c>] (fbtft_write_spi+0xf0/0x104 [fbtft]) [ 960.461166] [<bf12134c>] (fbtft_write_spi+0xf0/0x104 [fbtft]) from [<bf121208>] (fbtft_write_vmem16_bus8+0x11c/0x138 [fbtft]) [ 960.461248] [<bf121208>] (fbtft_write_vmem16_bus8+0x11c/0x138 [fbtft]) from [<bf11e918>] (fbtft_update_display+0x150/0x2fc [fbtft]) [ 960.461324] [<bf11e918>] (fbtft_update_display+0x150/0x2fc [fbtft]) from [<bf11e2a8>] (fbtft_deferred_io+0x110/0x11c [fbtft]) [ 960.461388] [<bf11e2a8>] (fbtft_deferred_io+0x110/0x11c [fbtft]) from [<c0382b98>] (fb_deferred_io_work+0x84/0xcc) [ 960.461438] [<c0382b98>] (fb_deferred_io_work+0x84/0xcc) from [<c00445a0>] (process_one_work+0x248/0x404) [ 960.461483] [<c00445a0>] (process_one_work+0x248/0x404) from [<c00459d8>] (worker_thread+0x1b4/0x2d0) [ 960.461529] [<c00459d8>] (worker_thread+0x1b4/0x2d0) from [<c0049cf0>] (kthread+0x94/0xa0) [ 960.461575] [<c0049cf0>] (kthread+0x94/0xa0) from [<c000f1b0>] (kernel_thread_exit+0x0/0x8) [ 960.461632] INFO: task python:840 blocked for more than 120 seconds. [ 960.461652] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [ 960.461674] python D c061e084 0 840 831 0x00000000 [ 960.461732] [<c061e084>] (__schedule+0x574/0x7fc) from [<c061e39c>] (schedule+0x90/0x94) [ 960.461777] [<c061e39c>] (schedule+0x90/0x94) from [<c061e78c>] (schedule_preempt_disabled+0x30/0x40) [ 960.461824] [<c061e78c>] (schedule_preempt_disabled+0x30/0x40) from [<c061cf70>] (__mutex_lock_slowpath+0x160/0x1a8) [ 960.461872] [<c061cf70>] (__mutex_lock_slowpath+0x160/0x1a8) from [<c061d01c>] (mutex_lock+0x64/0x7c) [ 960.461917] [<c061d01c>] (mutex_lock+0x64/0x7c) from [<c0382a84>] (fb_deferred_io_mkwrite+0x2c/0xbc) [ 960.461963] [<c0382a84>] (fb_deferred_io_mkwrite+0x2c/0xbc) from [<c00ff630>] (do_wp_page+0x224/0x7a4) [ 960.462008] [<c00ff630>] (do_wp_page+0x224/0x7a4) from [<c0101210>] (handle_pte_fault+0x7b0/0x838) [ 960.462052] [<c0101210>] (handle_pte_fault+0x7b0/0x838) from [<c0101390>] (handle_mm_fault+0xf8/0x134) [ 960.462096] [<c0101390>] (handle_mm_fault+0xf8/0x134) from [<c001b180>] (do_page_fault+0x11c/0x344) [ 960.462140] [<c001b180>] (do_page_fault+0x11c/0x344) from [<c00083a8>] (do_DataAbort+0x44/0xa8) [ 960.462184] [<c00083a8>] (do_DataAbort+0x44/0xa8) from [<c000dcd8>] (__dabt_usr+0x38/0x40) [ 960.462211] Exception stack(0xd4a3dfb0 to 0xd4a3dff8) [ 960.462238] dfa0: b45ba000 016b16c8 00000280 00000000 [ 960.462275] dfc0: 000000f0 016b16a8 b45ba280 00000280 ffffffc0 00000280 be876854 00000000 [ 960.462309] dfe0: b45ba000 be876774 b6a1e52f b6d89398 80000010 ffffffff [ 1080.460137] INFO: task kworker/u:0:5 blocked for more than 120 seconds. [ 1080.460166] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [ 1080.460190] kworker/u:0 D c061e084 0 5 2 0x00000000 [ 1080.460272] [<c061e084>] (__schedule+0x574/0x7fc) from [<c061e39c>] (schedule+0x90/0x94) [ 1080.460318] [<c061e39c>] (schedule+0x90/0x94) from [<c061c2dc>] (schedule_timeout+0x2c/0x2bc) [ 1080.460365] [<c061c2dc>] (schedule_timeout+0x2c/0x2bc) from [<c061d878>] (wait_for_common+0x120/0x168) [ 1080.460413] [<c061d878>] (wait_for_common+0x120/0x168) from [<c061d8e0>] (wait_for_completion+0x20/0x24) [ 1080.460463] [<c061d8e0>] (wait_for_completion+0x20/0x24) from [<c03e39dc>] (sunxi_spi_work+0x748/0x88c) [ 1080.460514] [<c03e39dc>] (sunxi_spi_work+0x748/0x88c) from [<c00445a0>] (process_one_work+0x248/0x404) [ 1080.460562] [<c00445a0>] (process_one_work+0x248/0x404) from [<c00459d8>] (worker_thread+0x1b4/0x2d0) [ 1080.460610] [<c00459d8>] (worker_thread+0x1b4/0x2d0) from [<c0049cf0>] (kthread+0x94/0xa0) [ 1080.460659] [<c0049cf0>] (kthread+0x94/0xa0) from [<c000f1b0>] (kernel_thread_exit+0x0/0x8) [ 1080.460698] INFO: task kworker/3:1:27 blocked for more than 120 seconds. [ 1080.460718] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [ 1080.460739] kworker/3:1 D c061e084 0 27 2 0x00000000 [ 1080.460796] [<c061e084>] (__schedule+0x574/0x7fc) from [<c061e39c>] (schedule+0x90/0x94) [ 1080.460840] [<c061e39c>] (schedule+0x90/0x94) from [<c061c2dc>] (schedule_timeout+0x2c/0x2bc) [ 1080.460885] [<c061c2dc>] (schedule_timeout+0x2c/0x2bc) from [<c061d878>] (wait_for_common+0x120/0x168) [ 1080.460931] [<c061d878>] (wait_for_common+0x120/0x168) from [<c061d8e0>] (wait_for_completion+0x20/0x24) [ 1080.460977] [<c061d8e0>] (wait_for_completion+0x20/0x24) from [<c03e0854>] (spi_sync+0x84/0xa0) [ 1080.461050] [<c03e0854>] (spi_sync+0x84/0xa0) from [<bf12134c>] (fbtft_write_spi+0xf0/0x104 [fbtft]) [ 1080.461136] [<bf12134c>] (fbtft_write_spi+0xf0/0x104 [fbtft]) from [<bf121208>] (fbtft_write_vmem16_bus8+0x11c/0x138 [fbtft]) [ 1080.461216] [<bf121208>] (fbtft_write_vmem16_bus8+0x11c/0x138 [fbtft]) from [<bf11e918>] (fbtft_update_display+0x150/0x2fc [fbtft]) [ 1080.461292] [<bf11e918>] (fbtft_update_display+0x150/0x2fc [fbtft]) from [<bf11e2a8>] (fbtft_deferred_io+0x110/0x11c [fbtft]) [ 1080.461357] [<bf11e2a8>] (fbtft_deferred_io+0x110/0x11c [fbtft]) from [<c0382b98>] (fb_deferred_io_work+0x84/0xcc) [ 1080.461406] [<c0382b98>] (fb_deferred_io_work+0x84/0xcc) from [<c00445a0>] (process_one_work+0x248/0x404) [ 1080.461452] [<c00445a0>] (process_one_work+0x248/0x404) from [<c00459d8>] (worker_thread+0x1b4/0x2d0) [ 1080.461498] [<c00459d8>] (worker_thread+0x1b4/0x2d0) from [<c0049cf0>] (kthread+0x94/0xa0) [ 1080.461544] [<c0049cf0>] (kthread+0x94/0xa0) from [<c000f1b0>] (kernel_thread_exit+0x0/0x8) [ 1080.461601] INFO: task python:840 blocked for more than 120 seconds. [ 1080.461620] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [ 1080.461642] python D c061e084 0 840 831 0x00000000 [ 1080.461699] [<c061e084>] (__schedule+0x574/0x7fc) from [<c061e39c>] (schedule+0x90/0x94) [ 1080.461744] [<c061e39c>] (schedule+0x90/0x94) from [<c061e78c>] (schedule_preempt_disabled+0x30/0x40) [ 1080.461792] [<c061e78c>] (schedule_preempt_disabled+0x30/0x40) from [<c061cf70>] (__mutex_lock_slowpath+0x160/0x1a8) [ 1080.461840] [<c061cf70>] (__mutex_lock_slowpath+0x160/0x1a8) from [<c061d01c>] (mutex_lock+0x64/0x7c) [ 1080.461884] [<c061d01c>] (mutex_lock+0x64/0x7c) from [<c0382a84>] (fb_deferred_io_mkwrite+0x2c/0xbc) [ 1080.461930] [<c0382a84>] (fb_deferred_io_mkwrite+0x2c/0xbc) from [<c00ff630>] (do_wp_page+0x224/0x7a4) [ 1080.461977] [<c00ff630>] (do_wp_page+0x224/0x7a4) from [<c0101210>] (handle_pte_fault+0x7b0/0x838) [ 1080.462021] [<c0101210>] (handle_pte_fault+0x7b0/0x838) from [<c0101390>] (handle_mm_fault+0xf8/0x134) [ 1080.462065] [<c0101390>] (handle_mm_fault+0xf8/0x134) from [<c001b180>] (do_page_fault+0x11c/0x344) [ 1080.462109] [<c001b180>] (do_page_fault+0x11c/0x344) from [<c00083a8>] (do_DataAbort+0x44/0xa8) [ 1080.462152] [<c00083a8>] (do_DataAbort+0x44/0xa8) from [<c000dcd8>] (__dabt_usr+0x38/0x40) [ 1080.462179] Exception stack(0xd4a3dfb0 to 0xd4a3dff8) [ 1080.462206] dfa0: b45ba000 016b16c8 00000280 00000000 [ 1080.462243] dfc0: 000000f0 016b16a8 b45ba280 00000280 ffffffc0 00000280 be876854 00000000 [ 1080.462278] dfe0: b45ba000 be876774 b6a1e52f b6d89398 80000010 ffffffff [ 1200.460115] INFO: task kworker/u:0:5 blocked for more than 120 seconds. [ 1200.460144] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [ 1200.460167] kworker/u:0 D c061e084 0 5 2 0x00000000 [ 1200.460248] [<c061e084>] (__schedule+0x574/0x7fc) from [<c061e39c>] (schedule+0x90/0x94) [ 1200.460294] [<c061e39c>] (schedule+0x90/0x94) from [<c061c2dc>] (schedule_timeout+0x2c/0x2bc) [ 1200.460340] [<c061c2dc>] (schedule_timeout+0x2c/0x2bc) from [<c061d878>] (wait_for_common+0x120/0x168) [ 1200.460388] [<c061d878>] (wait_for_common+0x120/0x168) from [<c061d8e0>] (wait_for_completion+0x20/0x24) [ 1200.460439] [<c061d8e0>] (wait_for_completion+0x20/0x24) from [<c03e39dc>] (sunxi_spi_work+0x748/0x88c) [ 1200.460490] [<c03e39dc>] (sunxi_spi_work+0x748/0x88c) from [<c00445a0>] (process_one_work+0x248/0x404) [ 1200.460538] [<c00445a0>] (process_one_work+0x248/0x404) from [<c00459d8>] (worker_thread+0x1b4/0x2d0) [ 1200.460586] [<c00459d8>] (worker_thread+0x1b4/0x2d0) from [<c0049cf0>] (kthread+0x94/0xa0) [ 1200.460636] [<c0049cf0>] (kthread+0x94/0xa0) from [<c000f1b0>] (kernel_thread_exit+0x0/0x8) [ 1200.460673] INFO: task kworker/3:1:27 blocked for more than 120 seconds. [ 1200.460693] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [ 1200.460715] kworker/3:1 D c061e084 0 27 2 0x00000000 [ 1200.460771] [<c061e084>] (__schedule+0x574/0x7fc) from [<c061e39c>] (schedule+0x90/0x94) [ 1200.460851] [<c061e39c>] (schedule+0x90/0x94) from [<c061c2dc>] (schedule_timeout+0x2c/0x2bc) [ 1200.460898] [<c061c2dc>] (schedule_timeout+0x2c/0x2bc) from [<c061d878>] (wait_for_common+0x120/0x168) [ 1200.460944] [<c061d878>] (wait_for_common+0x120/0x168) from [<c061d8e0>] (wait_for_completion+0x20/0x24) [ 1200.460991] [<c061d8e0>] (wait_for_completion+0x20/0x24) from [<c03e0854>] (spi_sync+0x84/0xa0) [ 1200.461062] [<c03e0854>] (spi_sync+0x84/0xa0) from [<bf12134c>] (fbtft_write_spi+0xf0/0x104 [fbtft]) [ 1200.461148] [<bf12134c>] (fbtft_write_spi+0xf0/0x104 [fbtft]) from [<bf121208>] (fbtft_write_vmem16_bus8+0x11c/0x138 [fbtft]) [ 1200.461228] [<bf121208>] (fbtft_write_vmem16_bus8+0x11c/0x138 [fbtft]) from [<bf11e918>] (fbtft_update_display+0x150/0x2fc [fbtft]) [ 1200.461304] [<bf11e918>] (fbtft_update_display+0x150/0x2fc [fbtft]) from [<bf11e2a8>] (fbtft_deferred_io+0x110/0x11c [fbtft]) [ 1200.461368] [<bf11e2a8>] (fbtft_deferred_io+0x110/0x11c [fbtft]) from [<c0382b98>] (fb_deferred_io_work+0x84/0xcc) [ 1200.461417] [<c0382b98>] (fb_deferred_io_work+0x84/0xcc) from [<c00445a0>] (process_one_work+0x248/0x404) [ 1200.461462] [<c00445a0>] (process_one_work+0x248/0x404) from [<c00459d8>] (worker_thread+0x1b4/0x2d0) [ 1200.461508] [<c00459d8>] (worker_thread+0x1b4/0x2d0) from [<c0049cf0>] (kthread+0x94/0xa0) [ 1200.461554] [<c0049cf0>] (kthread+0x94/0xa0) from [<c000f1b0>] (kernel_thread_exit+0x0/0x8) [ 1200.461611] INFO: task python:840 blocked for more than 120 seconds. [ 1200.461631] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [ 1200.461653] python D c061e084 0 840 831 0x00000000 [ 1200.461710] [<c061e084>] (__schedule+0x574/0x7fc) from [<c061e39c>] (schedule+0x90/0x94) [ 1200.461755] [<c061e39c>] (schedule+0x90/0x94) from [<c061e78c>] (schedule_preempt_disabled+0x30/0x40) [ 1200.461803] [<c061e78c>] (schedule_preempt_disabled+0x30/0x40) from [<c061cf70>] (__mutex_lock_slowpath+0x160/0x1a8) [ 1200.461851] [<c061cf70>] (__mutex_lock_slowpath+0x160/0x1a8) from [<c061d01c>] (mutex_lock+0x64/0x7c) [ 1200.461895] [<c061d01c>] (mutex_lock+0x64/0x7c) from [<c0382a84>] (fb_deferred_io_mkwrite+0x2c/0xbc) [ 1200.461941] [<c0382a84>] (fb_deferred_io_mkwrite+0x2c/0xbc) from [<c00ff630>] (do_wp_page+0x224/0x7a4) [ 1200.461988] [<c00ff630>] (do_wp_page+0x224/0x7a4) from [<c0101210>] (handle_pte_fault+0x7b0/0x838) [ 1200.462032] [<c0101210>] (handle_pte_fault+0x7b0/0x838) from [<c0101390>] (handle_mm_fault+0xf8/0x134) [ 1200.462075] [<c0101390>] (handle_mm_fault+0xf8/0x134) from [<c001b180>] (do_page_fault+0x11c/0x344) [ 1200.462119] [<c001b180>] (do_page_fault+0x11c/0x344) from [<c00083a8>] (do_DataAbort+0x44/0xa8) [ 1200.462163] [<c00083a8>] (do_DataAbort+0x44/0xa8) from [<c000dcd8>] (__dabt_usr+0x38/0x40) [ 1200.462189] Exception stack(0xd4a3dfb0 to 0xd4a3dff8) [ 1200.462216] dfa0: b45ba000 016b16c8 00000280 00000000 [ 1200.462254] dfc0: 000000f0 016b16a8 b45ba280 00000280 ffffffc0 00000280 be876854 00000000 [ 1200.462288] dfe0: b45ba000 be876774 b6a1e52f b6d89398 80000010 ffffffff Link to comment Share on other sites More sharing options...
tao Posted April 24, 2017 Author Share Posted April 24, 2017 echo 0 > /proc/sys/kernel/hung_task_timeout_secs reduces the number of log messages, but the program still hangs. Not sure pygame is generating an ALSA error. Link to comment Share on other sites More sharing options...
tao Posted April 26, 2017 Author Share Posted April 26, 2017 I might have misrepresented the problem by naming the message printed on the console (ALSA). I suspect the problem might be related to fbftft. Looking at issues such as https://github.com/notro/fbtft/issues/413 If that's the case, it may be hard to fix running with the legacy kernel. Link to comment Share on other sites More sharing options...
Recommended Posts