Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

firmware transaction timeout issue #263

Closed
sferlix opened this issue Apr 6, 2021 · 3 comments
Closed

firmware transaction timeout issue #263

sferlix opened this issue Apr 6, 2021 · 3 comments

Comments

@sferlix
Copy link

sferlix commented Apr 6, 2021

hello,

I have a raspistill job in crontab, running every 3 minutes to take a picture:

sudo killall raspistill; python3 /home/pi/program/skycamv3.py >/dev/null 2>&1

the python program only defines some raspistill parameters, such as output file name, text annotations and shutter time. Then it invokes raspistill via a shell command

Unfortunately, after several hours, it run in some issue: raspistill stop working.
If I run raspistill from command line, it works "forever", unless I go with ctrl+c.
No error messages from raspistill.
This is running on raspbian lite (no desktop), Raspberry Pi4 model B, 4GB RAM.

Any advise ?
Please find the log below.
Thanks
Frank

Apr  6 06:27:10 raspberrypi CRON[5365]: (CRON) info (No MTA installed, discarding output)
Apr  6 06:30:01 raspberrypi CRON[5388]: (pi) CMD (sudo killall raspistill; python3 /home/pi/program/skycamv3.py >/dev/null 2>&1)
Apr  6 06:30:09 raspberrypi CRON[5387]: (CRON) info (No MTA installed, discarding output)
Apr  6 06:31:50 raspberrypi rngd[349]: stats: bits received from HRNG source: 320064
Apr  6 06:31:50 raspberrypi rngd[349]: stats: bits sent to kernel pool: 273824
Apr  6 06:31:50 raspberrypi rngd[349]: stats: entropy added to kernel pool: 273824
Apr  6 06:31:50 raspberrypi rngd[349]: stats: FIPS 140-2 successes: 16
Apr  6 06:31:50 raspberrypi rngd[349]: stats: FIPS 140-2 failures: 0
Apr  6 06:31:50 raspberrypi rngd[349]: stats: FIPS 140-2(2001-10-10) Monobit: 0
Apr  6 06:31:50 raspberrypi rngd[349]: stats: FIPS 140-2(2001-10-10) Poker: 0
Apr  6 06:31:50 raspberrypi rngd[349]: stats: FIPS 140-2(2001-10-10) Runs: 0
Apr  6 06:31:50 raspberrypi rngd[349]: stats: FIPS 140-2(2001-10-10) Long run: 0
Apr  6 06:31:50 raspberrypi rngd[349]: stats: FIPS 140-2(2001-10-10) Continuous run: 0
Apr  6 06:31:50 raspberrypi rngd[349]: stats: HRNG source speed: (min=231.388; avg=480.014; max=568.860)Kibits/s
Apr  6 06:31:50 raspberrypi rngd[349]: stats: FIPS tests speed: (min=4.809; avg=11.723; max=31.319)Mibits/s
Apr  6 06:31:50 raspberrypi rngd[349]: stats: Lowest ready-buffers level: 2
Apr  6 06:31:50 raspberrypi rngd[349]: stats: Entropy starvations: 0
Apr  6 06:31:50 raspberrypi rngd[349]: stats: Time spent starving for entropy: (min=0; avg=0.000; max=0)us
Apr  6 06:33:01 raspberrypi CRON[5413]: (pi) CMD (sudo killall raspistill; python3 /home/pi/program/skycamv3.py >/dev/null 2>&1)
Apr  6 06:33:10 raspberrypi CRON[5412]: (CRON) info (No MTA installed, discarding output)
Apr  6 06:36:01 raspberrypi CRON[5434]: (pi) CMD (sudo killall raspistill; python3 /home/pi/program/skycamv3.py >/dev/null 2>&1)
Apr  6 06:36:09 raspberrypi kernel: [32666.468514] ------------[ cut here ]------------
Apr  6 06:36:09 raspberrypi kernel: [32666.468555] WARNING: CPU: 3 PID: 5191 at drivers/firmware/raspberrypi.c:64 rpi_firmware_transaction+0xe c/0x128
Apr  6 06:36:09 raspberrypi kernel: [32666.468570] Firmware transaction timeout
Apr  6 06:36:09 raspberrypi kernel: [32666.468584] Modules linked in: cmac bnep hci_uart btbcm bluetooth ecdh_generic ecc 8021q garp stp llc b rcmfmac brcmutil sha256_generic v3d gpu_sched bcm2835_codec(C) cfg80211 vc4 cec raspberrypi_hwmon rfkill drm_kms_helper i2c_bcm2835 v4l2_mem2m em drm bcm2835_v4l2(C) bcm2835_isp(C) bcm2835_mmal_vchiq(C) videobuf2_dma_contig videobuf2_vmalloc videobuf2_memops videobuf2_v4l2 videobuf2_c ommon drm_panel_orientation_quirks snd_soc_core videodev vc_sm_cma(C) snd_compress mc snd_bcm2835(C) snd_pcm_dmaengine snd_pcm snd_timer snd s yscopyarea sysfillrect sysimgblt fb_sys_fops rpivid_mem backlight uio_pdrv_genirq uio nvmem_rmem i2c_dev ip_tables x_tables ipv6
Apr  6 06:36:09 raspberrypi kernel: [32666.469411] CPU: 3 PID: 5191 Comm: kworker/3:1 Tainted: G         C        5.10.17-v7l+ #1403
Apr  6 06:36:09 raspberrypi kernel: [32666.469421] Hardware name: BCM2711
Apr  6 06:36:09 raspberrypi kernel: [32666.469446] Workqueue: events get_values_poll [raspberrypi_hwmon]
Apr  6 06:36:09 raspberrypi kernel: [32666.469464] Backtrace:
Apr  6 06:36:09 raspberrypi kernel: [32666.469496] [] (dump_backtrace) from [] (show_stack+0x20/0x24)
Apr  6 06:36:09 raspberrypi kernel: [32666.469511]  r7:ffffffff r6:00000000 r5:60000013 r4:c12e69fc
Apr  6 06:36:09 raspberrypi kernel: [32666.469531] [] (show_stack) from [] (dump_stack+0xcc/0xf8)
Apr  6 06:36:09 raspberrypi kernel: [32666.469549] [] (dump_stack) from [] (__warn+0xfc/0x114)
Apr  6 06:36:09 raspberrypi kernel: [32666.469565]  r10:dec02008 r9:00000009 r8:c099d5b8 r7:00000040 r6:00000009 r5:c099d5b8
Apr  6 06:36:09 raspberrypi kernel: [32666.469575]  r4:c0e9abc8 r3:c1205094
Apr  6 06:36:09 raspberrypi kernel: [32666.469593] [] (__warn) from [] (warn_slowpath_fmt+0xa4/0xd8)
Apr  6 06:36:09 raspberrypi kernel: [32666.469606]  r7:00000040 r6:c0e9abc8 r5:c1205048 r4:c0e9abe8
Apr  6 06:36:09 raspberrypi kernel: [32666.469626] [] (warn_slowpath_fmt) from [] (rpi_firmware_transaction+0xec/0x128)
Apr  6 06:36:09 raspberrypi kernel: [32666.469640]  r9:c1a544c0 r8:00000010 r7:00000000 r6:ffffff92 r5:c1a544c0 r4:c1205048
Apr  6 06:36:09 raspberrypi kernel: [32666.469658] [] (rpi_firmware_transaction) from [] (rpi_firmware_property_list+0xbc/ 0x170)
Apr  6 06:36:09 raspberrypi kernel: [32666.469671]  r7:c1205048 r6:dec02000 r5:00001000 r4:dec0201c
Apr  6 06:36:09 raspberrypi kernel: [32666.469689] [] (rpi_firmware_property_list) from [] (rpi_firmware_property+0x70/0x1 18)
Apr  6 06:36:09 raspberrypi kernel: [32666.469702]  r10:c37fff8c r9:00030046 r8:00000010 r7:c1a544c0 r6:c4229ed8 r5:00000004
Apr  6 06:36:09 raspberrypi kernel: [32666.469712]  r4:c37fff80
Apr  6 06:36:09 raspberrypi kernel: [32666.469733] [] (rpi_firmware_property) from [] (get_values_poll+0x4c/0x150 [raspber rypi_hwmon])
Apr  6 06:36:09 raspberrypi kernel: [32666.469746]  r10:00000000 r9:00000000 r8:000000c0 r7:eff51900 r6:eff4e640 r5:c1a8454c
Apr  6 06:36:09 raspberrypi kernel: [32666.469757]  r4:c1205048 r3:00000004
Apr  6 06:36:09 raspberrypi kernel: [32666.469777] [] (get_values_poll [raspberrypi_hwmon]) from [] (process_one_work+0x25 0/0x5a0)
Apr  6 06:36:09 raspberrypi kernel: [32666.469787]  r5:c4ce3a00 r4:c1a8454c
Apr  6 06:36:09 raspberrypi kernel: [32666.469805] [] (process_one_work) from [] (worker_thread+0x60/0x5c4)
Apr  6 06:36:09 raspberrypi kernel: [32666.469818]  r10:eff4e640 r9:c1203d00 r8:eff4e658 r7:00000008 r6:eff4e640 r5:c4ce3a14
Apr  6 06:36:09 raspberrypi kernel: [32666.469828]  r4:c4ce3a00
Apr  6 06:36:09 raspberrypi kernel: [32666.469845] [] (worker_thread) from [] (kthread+0x170/0x174)
Apr  6 06:36:09 raspberrypi kernel: [32666.469859]  r10:c4cb3e74 r9:c4ce3a00 r8:c023df68 r7:c4228000 r6:00000000 r5:c37ff340
Apr  6 06:36:09 raspberrypi kernel: [32666.469868]  r4:c4257240
Apr  6 06:36:09 raspberrypi kernel: [32666.469883] [] (kthread) from [] (ret_from_fork+0x14/0x28)
Apr  6 06:36:09 raspberrypi kernel: [32666.469894] Exception stack(0xc4229fb0 to 0xc4229ff8)
Apr  6 06:36:09 raspberrypi kernel: [32666.469906] 9fa0:                                     00000000 00000000 00000000 00000000
Apr  6 06:36:09 raspberrypi kernel: [32666.469920] 9fc0: 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000Apr  6 06:36:09 raspberrypi kernel: [32666.469932] 9fe0: 00000000 00000000 00000000 00000000 00000013 00000000A
pr  6 06:36:09 raspberrypi kernel: [32666.469946]  r10:00000000 r9:00000000 r8:00000000 r7:00000000 r6:00000000 r5:c02458e0Apr  6 06:36:09 raspberrypi kernel: [32666.469956]  r4:c37ff340Apr  6 06:36:09 raspberrypi kernel: [32666.469969] ---[ end trace 40751f1a0de02467 ]---
Apr  6 06:36:09 raspberrypi kernel: [32666.470019] hwmon hwmon1: Failed to get throttled (-110)
Apr  6 06:36:10 raspberrypi kernel: [32667.508542] cpu cpu0: dev_pm_opp_set_rate: failed to find current OPP for freq 4294967186 (-34)
Apr  6 06:36:11 raspberrypi kernel: [32668.548582] raspberrypi-clk soc:firmware:clocks: Failed to change fw-clk-arm frequency: -110Apr  6 06:36:14 raspberrypi kernel: [32671.668691] cpu cpu0: dev_pm_opp_set_rate: failed to find current OPP for freq 4294967186 (-34)
Apr  6 06:36:15 raspberrypi kernel: [32672.708732] raspberrypi-clk soc:firmware:clocks: Failed to change fw-clk-arm frequency: -110
Apr  6 06:38:30 raspberrypi kernel: [32807.273454] INFO: task kworker/3:1:5191 blocked for more than 122 seconds.
Apr  6 06:38:30 raspberrypi kernel: [32807.273476]       Tainted: G        WC        5.10.17-v7l+ #1403
Apr  6 06:38:30 raspberrypi kernel: [32807.273491] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Apr  6 06:38:30 raspberrypi kernel: [32807.273508] task:kworker/3:1     state:D stack:    0 pid: 5191 ppid:     2 flags:0x00000000
Apr  6 06:38:30 raspberrypi kernel: [32807.273561] Workqueue: events get_values_poll [raspberrypi_hwmon]
Apr  6 06:38:30 raspberrypi kernel: [32807.273590] Backtrace:
Apr  6 06:38:30 raspberrypi kernel: [32807.273637] [] (__schedule) from [] (schedule+0x68/0xe4)
Apr  6 06:38:30 raspberrypi kernel: [32807.273661]  r10:dec03008 r9:eff47540 r8:eff47540 r7:c1205048 r6:c4229d8c r5:c3e69f00Apr  6 06:38:30 raspberrypi kernel: [32807.273677]  r4:ffffe000Apr  6 06:38:30 raspberrypi kernel: [32807.273703] [] (schedule) from [] (schedule_timeout+0x1d0/0x384)
Apr  6 06:38:30 raspberrypi kernel: [32807.273721]  r5:c1203d00 r4:0036e418Apr  6 06:38:30 raspberrypi kernel: [32807.273748] [] (schedule_timeout) from [] (wait_for_completion_timeout+0xb8/0x144)
Apr  6 06:38:30 raspberrypi kernel: [32807.273769]  r9:00000002 r8:ffffe000 r7:c197ae90 r6:c1205048 r5:00057e40 r4:

@popcornmix
Copy link
Collaborator

Sounds a bit like raspberrypi/firmware#1552
It may be fixed by latest rpi-update firmware.

@sferlix
Copy link
Author

sferlix commented Apr 6, 2021

thanks ! I have done it.
Let's check :)

@sferlix
Copy link
Author

sferlix commented Apr 13, 2021

Hi,

after few day non-stop, my 2 Raspberry Pi 4 with HQ Camera are not presenting any issue.
Sounds like that was the problem. The fix worked.

Thank you !
francesco

@sferlix sferlix closed this as completed Apr 13, 2021
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

2 participants