Foris-controler wakes up dozens of times every second

welinder · July 28, 2019, 11:46pm

My Omnia runs warmer than I would like – 70C. After some googling I realize that this isn’t unusual, but for a mostly idle device is still feels a tad high.

While I was looking around for something to blame I noticed that foris seems to keep the system busy. “ps | grep ‘fo[r]is’” shows 22 processes, 19 of which are “{foris-controlle}”. These processes each wake up about twice a second:

root@jane:/proc/cpu# strace -t -p 2818
Process 2818 attached
19:33:00 clock_gettime(CLOCK_MONOTONIC, {2869, 340227836}) = 0
19:33:00 clock_gettime(CLOCK_MONOTONIC, {2869, 340434687}) = 0
19:33:00 epoll_pwait(16, {}, 10, 239, NULL, 8) = 0
19:33:00 clock_gettime(CLOCK_MONOTONIC, {2869, 580244058}) = 0
19:33:00 rt_sigaction(SIGINT, NULL, {0xb6de4b90, [], SA_RESTORER, 0xb6f25ee4}, 8) = 0
19:33:00 rt_sigaction(SIGTERM, NULL, {0xb6734834, [], SA_RESTORER, 0xb6f25ee4}, 8) = 0
19:33:00 rt_sigaction(SIGTERM, {SIG_DFL, [], SA_RESTORER, 0xb6f25ee4}, NULL, 8) = 0
19:33:00 rt_sigaction(SIGCHLD, NULL, {0xb6734858, [], SA_RESTORER, 0xb6f25ee4}, 8) = 0
19:33:00 rt_sigaction(SIGCHLD, {SIG_DFL, [], SA_RESTORER, 0xb6f25ee4}, NULL, 8) = 0
19:33:00 rt_sigaction(SIGPIPE, NULL, {SIG_IGN, [], SA_RESTORER, 0xb6f25ee4}, 8) = 0
19:33:00 clock_gettime(CLOCK_MONOTONIC, {2869, 582271079}) = 0
19:33:00 rt_sigaction(SIGINT, NULL, {0xb6de4b90, [], SA_RESTORER, 0xb6f25ee4}, 8) = 0
19:33:00 rt_sigaction(SIGTERM, NULL, {SIG_DFL, [], SA_RESTORER, 0xb6f25ee4}, 8) = 0
19:33:00 rt_sigaction(SIGTERM, {0xb6734834, [], SA_RESTORER, 0xb6f25ee4}, NULL, 8) = 0
19:33:00 rt_sigaction(SIGCHLD, NULL, {SIG_DFL, [], SA_RESTORER, 0xb6f25ee4}, 8) = 0
19:33:00 rt_sigaction(SIGCHLD, {0xb6734858, [], SA_RESTORER, 0xb6f25ee4}, NULL, 8) = 0
19:33:00 rt_sigaction(SIGPIPE, NULL, {SIG_IGN, [], SA_RESTORER, 0xb6f25ee4}, 8) = 0
19:33:00 clock_gettime(CLOCK_MONOTONIC, {2869, 584049928}) = 0

That is a lot of wakeups for no apparent reason! And a lot of questionable sigaction calls, btw. What is it that needs 19 processes busy-polling somehting?

mattventura · July 29, 2019, 12:38am

What OS version? I’m seeing this on my Mox with 4.0, but my Omnia with 3.x doesn’t have this problem. On the Mox, the foris-controller processes combined have about 4 hours of CPU time after 1 day of uptime.

welinder · July 29, 2019, 12:56am

It’s a vanilla 3.x

OpenWrt omnia 15.05 r47055 / LuCI d741f93bc5c0d0d8cb7b71a2eec82a7d85ca64e9 branch

anon50890781 · July 29, 2019, 6:10am

On a TOS5.x node (Omnia)

observed with the foris-controller process(s)

:55:43 futex(0x2297e30, FUTEX_WAIT_PRIVATE, 4294967295, {tv_sec=0, tv_nsec=999789247}) = -1 ETIMEDOUT (Operation timed out)
:55:44 futex(0x2297e30, FUTEX_WAKE_PRIVATE, 1) = 0
:55:44 clock_gettime(CLOCK_MONOTONIC, {tv_sec=61301, tv_nsec=729563442}) = 0
:55:44 clock_gettime(CLOCK_REALTIME, {tv_sec=1564379744, tv_nsec=220643775}) = 0
:55:44 clock_gettime(CLOCK_REALTIME, {tv_sec=1564379744, tv_nsec=220885035}) = 0
:55:44 futex(0x22a34c0, FUTEX_WAIT_PRIVATE, 4294967295, {tv_sec=0, tv_nsec=999757965}) = -1 ETIMEDOUT (Operation timed out)
:55:45 futex(0x22a34c0, FUTEX_WAKE_PRIVATE, 1) = 0
:55:45 clock_gettime(CLOCK_MONOTONIC, {tv_sec=61302, tv_nsec=730865084}) = 0
:55:45 clock_gettime(CLOCK_REALTIME, {tv_sec=1564379745, tv_nsec=221947518}) = 0
:55:45 clock_gettime(CLOCK_REALTIME, {tv_sec=1564379745, tv_nsec=222158886}) = 0
:55:45 futex(0x2298660, FUTEX_WAIT_PRIVATE, 4294967295, {tv_sec=0, tv_nsec=999788114}) = -1 ETIMEDOUT (Operation timed out)
:55:46 futex(0x2298660, FUTEX_WAKE_PRIVATE, 1) = 0
:55:46 clock_gettime(CLOCK_MONOTONIC, {tv_sec=61303, tv_nsec=731978826}) = 0
:55:46 clock_gettime(CLOCK_REALTIME, {tv_sec=1564379746, tv_nsec=223067500}) = 0
:55:46 clock_gettime(CLOCK_REALTIME, {tv_sec=1564379746, tv_nsec=223198379}) = 0
:55:46 futex(0x2299b90, FUTEX_WAIT_PRIVATE, 4294967295, {tv_sec=0, tv_nsec=999868621}) = -1 ETIMEDOUT (Operation timed out)
:55:47 futex(0x2299b90, FUTEX_WAKE_PRIVATE, 1) = 0
:55:47 clock_gettime(CLOCK_MONOTONIC, {tv_sec=61304, tv_nsec=733039892}) = 0
:55:47 clock_gettime(CLOCK_REALTIME, {tv_sec=1564379747, tv_nsec=223938163}) = 0
:55:47 clock_gettime(CLOCK_REALTIME, {tv_sec=1564379747, tv_nsec=224062467}) = 0

Not sure sure what condition the futex() call is looking for (and then timing out each time)

The futex() system call provides a method for waiting until a certain
condition becomes true. It is typically used as a blocking construct
in the context of shared-memory synchronization. When using futexes,
the majority of the synchronization operations are performed in user
space. A user-space program employs the futex() system call only
when it is likely that the program has to block for a longer time
until the condition becomes true. Other futex() operations can be
used to wake any processes or threads waiting for a particular
condition.

or why the clock needs to be polled that frequently

The functions clock_gettime() and clock_settime() retrieve and set the time of the specified clock clk_id.

Did not observe the frequent ( which could be due to different TOS version):

rt_sigaction

vcunat · July 29, 2019, 6:52am

I don’t think you’d get much lower temeperature even if you reduced all this activity. (Assuming you get the usual amount on the order of 1% CPU usage.) If you care about the temperature very much, there are multiple threads on the forums that focus on cooling, both active and passive; IIRC these modifications commonly get it 10 degrees lower or more.

anon50890781 · July 29, 2019, 7:57am

I would concur with that opinion, though the (hyper)activity of foris-controller seems somewhat curious.

On the mentioned TOS5.x (Omina) node the temperature reads (looks like within common range)

mv88e6xxx103-mdio-3
Adapter: MDIO adapter
temp1: +62.0°C (crit = +100.0°C)

mv88e6xxx101-mdio-1
Adapter: MDIO adapter
temp1: +62.0°C (crit = +100.0°C)

armada_thermal-virtual-0
Adapter: Virtual device
temp1: +75.6°C

mv88e6xxx104-mdio-4
Adapter: MDIO adapter
temp1: +62.0°C (crit = +100.0°C)

mv88e6xxx102-mdio-2
Adapter: MDIO adapter
temp1: +62.0°C (crit = +100.0°C)

mv88e6xxx100-mdio-0
Adapter: MDIO adapter
temp1: +62.0°C (crit = +100.0°C)

Jirka · July 30, 2019, 3:13pm

isnt foris-controler and foris-ws used just by Foris www interface? If you dont use it I think you could just disable autostart of them…

anon50890781 · July 30, 2019, 3:37pm

That may have some unintended consequences - if not mistaken foris-controler integrates control for lighttpd

Jirka · July 30, 2019, 4:01pm

Ah lighttpd is needed for luci I think, this would be unfortunate