2016-12-19 12:13:26

by Martin Steigerwald

[permalink] [raw]
Subject: [REGRESSION] Two issues that prevent process accounting (taskstats) from working correctly

Hello Ingo, Peter, Nicolas, Andrew, Balbir, Shailabh, Jay, Gerlof and Marc,

starting from a Debian bug report of mine, Gerlof Langeveld, developer of
system and process monitor atop¹, found two issues with process accounting.

[1] http://atoptool.nl/


I did some guess work on who might be the maintainer for this, but please feel
free to add further Cc´s as you see fit. Or ask for removal for Cc if you are
not working on this anymore.

Gerlof found two issues which I also reported to the kernel bug tracker. I
copy and paste the summaries that Gerlof prepared:


1) Sometimes process accounting does not work at all.

The acct() system call (to activate process accounting) return value 0,
which means that process accounting is activated successfully.
However, no process accounting records are written whatsoever. This
situation can be reproduced with the program 'acctdemo.c'
that you can find as attachment. When this program gives the message
"found a process accounting record!", the situation is okay
and process accounting works fine to the file '/tmp/mypacct'. When the
message 'No process accounting record yet....' is repeatedly given,
process accounting does not work and will not work at all. It might be
that you have to start this program several times before you get
this situation (preferably start/finish lots of processes in the mean time).
This problem is probably caused by a new mechanism introduced in the
kernel code (..../linux/kernel/acct.c) that is called 'slow accounting'
and has to be solved in the kernel code.

I experience this problem on Debian8 with a 4.8 kernel and on CentOS7
with a 4.8 kernel.

I reported this as:

Bug 190271 - process accounting sometimes does not work
https://bugzilla.kernel.org/show_bug.cgi?id=190271



2) When using the NETLINK inface, the command TASKSTATS_CMD_GET
consequently returns -EINVAL.

The code that is used by the atopacctd daemon is based on the demo code
'getdelays.c' that can be found in the kernel source code tree
(..../linux/Documentation/accounting/getdelays.c). Also this 'getdelays'
program does not work any more (also -EINVAL on the same call)
with the newer kernels. I really spent a lot of time on this issue to
get the code running (there are many places in the kernel code where
-EINVAL for this call can be given), but I did not succeed. It is really
an incompatibility introduced by the kernel code.
It would be nice if the kernel maintainers provide a working version of
the getdelays program in the kernel source tree.

I only experience this problem on Debian8 with a 4.8 kernel (virtual
machine with 4 cores).
On CentOS7 with a 4.8 kernel it works fine (physical machine with 4 cores).

I will anyhow adapt atopacctd for this issue that it detects and logs
the -EINVAL and terminates.
The current version of atopacctd keeps running which is not useful at all.


I reported this as:

Bug 190711 - Process accounting: Using the NETLINK inface, the command
TASKSTATS_CMD_GET returns -EINVAL

https://bugzilla.kernel.org/show_bug.cgi?id=190711


Marc Haber, maintainer of atop package, Gerlof Langeveld, developer of atop
and I are currently discussing workarounds with atop and/or systemd service
fail for the time till upstream kernels with this issues fixed are shipped by
distributions. Still it would be nice to remove those work-arounds and have
the kernel work correctly again at some time in the future.

Thanks,
--
Martin Steigerwald | Trainer

teamix GmbH
Südwestpark 43
90449 Nürnberg

Tel.: +49 911 30999 55 | Fax: +49 911 30999 99
mail: [email protected] | web: http://www.teamix.de | blog: http://blog.teamix.de

Amtsgericht Nürnberg, HRB 18320 | Geschäftsführer: Oliver Kügow, Richard Müller

teamix Support Hotline: +49 911 30999-112

*** Bitte liken Sie uns auf Facebook: facebook.com/teamix ***


Attachments:
acctdemo.c (764.00 B)

2016-12-19 13:19:34

by Peter Zijlstra

[permalink] [raw]
Subject: Re: [REGRESSION] Two issues that prevent process accounting (taskstats) from working correctly

On Mon, Dec 19, 2016 at 01:06:00PM +0100, Martin Steigerwald wrote:
> Hello Ingo, Peter, Nicolas, Andrew, Balbir, Shailabh, Jay, Gerlof and Marc,
>
> starting from a Debian bug report of mine, Gerlof Langeveld, developer of
> system and process monitor atop¹, found two issues with process accounting.
>

While $subject says regression the rest of the email completely fails to
mentions if this ever worked, and if so, against what version.

2016-12-19 13:56:26

by Martin Steigerwald

[permalink] [raw]
Subject: Re: [REGRESSION] Two issues that prevent process accounting (taskstats) from working correctly

Am Montag, 19. Dezember 2016, 14:19:11 CET schrieb Peter Zijlstra:
> On Mon, Dec 19, 2016 at 01:06:00PM +0100, Martin Steigerwald wrote:
> > Hello Ingo, Peter, Nicolas, Andrew, Balbir, Shailabh, Jay, Gerlof and
> > Marc,
> >
> > starting from a Debian bug report of mine, Gerlof Langeveld, developer of
> > system and process monitor atop¹, found two issues with process
> > accounting.
>
> While $subject says regression the rest of the email completely fails to
> mentions if this ever worked, and if so, against what version.

Sorry for not mentioning it here. With kernel 3.16 process accounting worked
nicely. We do not have any data on the exact kernel version where it started
to fail. I do see these issues since quite a while, but I was never sure
whether it was an issue in atop or the kernel and I do not recall on what
exact combination of atop + kernel version it failed to work.

As an additional notice: The mail addresses of Balbir and Shailabh which I got
from source code annotations of taskstats.c and getdelays.c do not work
anymore.

--
Martin

2016-12-19 14:02:20

by Peter Zijlstra

[permalink] [raw]
Subject: Re: [REGRESSION] Two issues that prevent process accounting (taskstats) from working correctly

On Mon, Dec 19, 2016 at 02:50:25PM +0100, Martin Steigerwald wrote:
> Am Montag, 19. Dezember 2016, 14:19:11 CET schrieb Peter Zijlstra:
> > On Mon, Dec 19, 2016 at 01:06:00PM +0100, Martin Steigerwald wrote:
> > > Hello Ingo, Peter, Nicolas, Andrew, Balbir, Shailabh, Jay, Gerlof and
> > > Marc,
> > >
> > > starting from a Debian bug report of mine, Gerlof Langeveld, developer of
> > > system and process monitor atop¹, found two issues with process
> > > accounting.
> >
> > While $subject says regression the rest of the email completely fails to
> > mentions if this ever worked, and if so, against what version.
>
> Sorry for not mentioning it here. With kernel 3.16 process accounting worked
> nicely. We do not have any data on the exact kernel version where it started
> to fail. I do see these issues since quite a while, but I was never sure
> whether it was an issue in atop or the kernel and I do not recall on what
> exact combination of atop + kernel version it failed to work.
>
> As an additional notice: The mail addresses of Balbir and Shailabh which I got
> from source code annotations of taskstats.c and getdelays.c do not work
> anymore.

Right, Balbir is back with IBM and working on Linux again, but under a
different email address (and on a different continent). I've amended
his address and bounced him the initial email.

2016-12-19 17:26:06

by Peter Zijlstra

[permalink] [raw]
Subject: Re: [REGRESSION] Two issues that prevent process accounting (taskstats) from working correctly


On Mon, Dec 19, 2016 at 01:06:00PM +0100, Martin Steigerwald wrote:
>
> 2) When using the NETLINK inface, the command TASKSTATS_CMD_GET
> consequently returns -EINVAL.
>
> The code that is used by the atopacctd daemon is based on the demo code
> 'getdelays.c' that can be found in the kernel source code tree
> (..../linux/Documentation/accounting/getdelays.c). Also this 'getdelays'
> program does not work any more (also -EINVAL on the same call)
> with the newer kernels. I really spent a lot of time on this issue to
> get the code running (there are many places in the kernel code where
> -EINVAL for this call can be given), but I did not succeed. It is really
> an incompatibility introduced by the kernel code.
> It would be nice if the kernel maintainers provide a working version of
> the getdelays program in the kernel source tree.
>
> I only experience this problem on Debian8 with a 4.8 kernel (virtual
> machine with 4 cores).
> On CentOS7 with a 4.8 kernel it works fine (physical machine with 4 cores).
>
> I will anyhow adapt atopacctd for this issue that it detects and logs
> the -EINVAL and terminates.
> The current version of atopacctd keeps running which is not useful at all.
>
>
> I reported this as:
>
> Bug 190711 - Process accounting: Using the NETLINK inface, the command
> TASKSTATS_CMD_GET returns -EINVAL
>
> https://bugzilla.kernel.org/show_bug.cgi?id=190711


Ben Hutchings reports:

"It looks like the taskstats bug was introduced by 513e3d2d11c9 as that
means cpumask_parse() may not initialise as many bits as
cpumask_subset() compares"



2017-03-08 11:23:43

by Richard Genoud

[permalink] [raw]
Subject: Re: [REGRESSION] Two issues that prevent process accounting (taskstats) from working correctly

Cc += Al Viro

2017-02-12 16:44 GMT+01:00 Dmitry Romanov <[email protected]>:
> On Mon, Dec 19, 2016 at 01:06:00PM +0100, Martin Steigerwald wrote:
>>
>> 1) Sometimes process accounting does not work at all.
>>
>> The acct() system call (to activate process accounting) return value 0,
>> which means that process accounting is activated successfully.
>> However, no process accounting records are written whatsoever. This
>> situation can be reproduced with the program 'acctdemo.c'
>> that you can find as attachment. When this program gives the message
>> "found a process accounting record!", the situation is okay
>> and process accounting works fine to the file '/tmp/mypacct'. When the
>> message 'No process accounting record yet....' is repeatedly given,
>> process accounting does not work and will not work at all. It might be
>> that you have to start this program several times before you get
>> this situation (preferably start/finish lots of processes in the mean time).
>> This problem is probably caused by a new mechanism introduced in the
>> kernel code (..../linux/kernel/acct.c) that is called 'slow accounting'
>> and has to be solved in the kernel code.
>>
>> I experience this problem on Debian8 with a 4.8 kernel and on CentOS7
>> with a 4.8 kernel.
>
> I reported same problem on bugzilla as:
>
> Bug 180841 - Process accounting sometimes do not append records for terminated
> processes
> https://bugzilla.kernel.org/show_bug.cgi?id=180841
>
> I think I found cause of this problem and can suggest patch which correct this
> problem.
>
> Problem arise in such situation:
>
> Problem arise if between process accounting activation with call acct(...) and
> first termination of process pass not less than one jiffy. (Note, acct() return
> successfully, with zero.) In such situation records for terminated processes
> do nod append to accounting file, until process accounting is restarted.
>
> I wrote test program test.c for illustration described problem for kernel
> version 3.17-rc1 and later. This program create empty file for accounting,
> call system call acct() with this file, sleep for not less than one jiffy,
> create new process and exit this process. Then, program test size of accounting
> file. If size of file remain zero, it seems problem and program display message
> "Accounting file size = 0, process accounting did not add record to accounting
> file!".
> On my system problem reproduce almost always by this test.c.
>
> ----------
> test.c
> ----------
> #include <stdio.h>
> #include <unistd.h>
> #include <sys/types.h>
> #include <sys/stat.h>
> #include <fcntl.h>
> #include <stdlib.h>
>
> /* Accounting file name : */
> #define ACCTFILENAME "/var/log/pacct"
>
> int main()
> {
> int fd;
> int pid;
> struct stat sb;
>
> /* Turn off accounting */
> if ( acct(NULL) < 0 ) {
> perror("Process accounting off");
> return -1;
> }
>
> /* Create empty accounting file */
> fd = creat(ACCTFILENAME, S_IRUSR | S_IWUSR);
> if ( fd == -1 ) {
> perror("Accounting file creation");
> return -1;
> }
> if ( close(fd) == -1) {
> perror("Accounting file closing");
> return -1;
> }
>
> /* Switch accounting on */
> if ( acct(ACCTFILENAME) < 0 ) {
> perror("Process accounting on");
> return -1;
> }
>
> /* Delay must be at least 1 jiffy.
> For reproducing bug, some process exit must not happen during first jiffy.
> If HZ >= 100, need delay minimum 10 ms. */
> usleep(10000);
>
> /* Create and exit child process. The record for this process must be append
> by activated process accounting. */
> pid = fork();
> if (pid < 0) {
> perror("Child process creating");
> return -1;
> }
> /* Exit child process */
> if (pid == 0) {
> exit(0);
> }
> /* Wait for child process termination */
> wait(NULL);
>
> /* Get size of accounting file. */
> if ( stat(ACCTFILENAME, &sb) == -1 ) {
> perror("Getting accounting file status");
> return -1;
> }
>
> if ( sb.st_size == 0 ) {
> printf("Accounting file size = 0, process accounting did not add record to accounting file!\n");
> }
> else {
> printf("Accounting file size > 0, expected behaviour.\n");
> }
>
> /* Turn off accounting and remove accounting file*/
> if ( acct(NULL) < 0 ) {
> perror("Process accounting off");
> return -1;
> }
> if ( remove(ACCTFILENAME) == -1 ) {
> perror("Removing accounting file");
> return -1;
> }
>
> return 0;
>
> }
> ----------
>
> I suppose that this problem may be solve in kernel versions 3.17-rc1 and
> later by following patch:
>
> Signed-off-by: Dmitry Romanov <[email protected]>
> ---
> kernel/acct.c | 2 +-
> 1 file changed, 1 insertion(+), 1 deletion(-)
>
> diff --git a/kernel/acct.c b/kernel/acct.c
> index 74963d1..37f1dc6 100644
> --- a/kernel/acct.c
> +++ b/kernel/acct.c
> @@ -99,7 +99,7 @@ static int check_free_space(struct bsd_acct_struct *acct)
> {
> struct kstatfs sbuf;
>
> - if (time_is_before_jiffies(acct->needcheck))
> + if (time_is_after_jiffies(acct->needcheck))
> goto out;
>
> /* May block */
> --
> 1.9.1
>
> Line "if (time_is_before_jiffies(acct->needcheck))" use for check whether the
> time for check free space. It seems function "time_is_after_jiffies" need here.
>
> ----------
> In kernel versions 3.3-rc1 - 3.16 activation of process accounting implemented
> differently, so delay between call acct(filename) and first process termination
> do not produce problem, and program test.c do not detect problem. But, it seems,
> using function time_is_before_jiffies is not right similarly.
> Another problem arise, if during work of process accounting happen that current
> jiffies is greater than acct->needcheck (for example, if between two consecutive
> process terminations happen interval greater than ACCT_TIMEOUT seconds).
> Then in lines:
>
> if (!file || time_is_before_jiffies(acct->needcheck))
> goto out;
>
> always will branch with "goto" and acct->needcheck will not change. So free
> space will not check more, until process accounting is restarted.
> Note, that in version 3.17-rc1 and later this problem is also present.
>
> Therefore I suppose that this problem for kernel version 3.3-rc1 - 3.16 may be
> solve by following patch:
>
> Signed-off-by: Dmitry Romanov <[email protected]>
> ---
> kernel/acct.c | 2 +-
> 1 file changed, 1 insertion(+), 1 deletion(-)
>
> diff --git a/kernel/acct.c b/kernel/acct.c
> index 808a86f..591bdcd 100644
> --- a/kernel/acct.c
> +++ b/kernel/acct.c
> @@ -107,7 +107,7 @@ static int check_free_space(struct bsd_acct_struct *acct, struct file *file)
>
> spin_lock(&acct_lock);
> res = acct->active;
> - if (!file || time_is_before_jiffies(acct->needcheck))
> + if (!file || time_is_after_jiffies(acct->needcheck))
> goto out;
> spin_unlock(&acct_lock);
>
> --
> 1.9.1
>
>
> In kernel 3.2 another method used for define time to check
> free space (by timer). So I did not find in this version such problem.
>
> Dmitry

Playing with bootchart, I also had some problems with BSD process
acounting V3 on v4.11-rc1.
The file kernel_pacct created by bootchartd was always empty.

After a git bisect, the culprit was :
commit 795a2f22a8ea ("acct() should honour the limits from the very beginning")

If I revert this commit, the accounting starts working again

test platform: ARM at91sam9g35
test software : busybox bootchartd

Richard.