[dm-crypt] The weird bug again: semid XXXXXX: semop failed for cookie 0xdeadbeef: incorrect semaphore state

[dm-crypt] The weird bug again: semid XXXXXX: semop failed for cookie 0xdeadbeef: incorrect semaphore state

[Thomas Bächler]

[-- Attachment #1: Type: text/plain, Size: 739 bytes --]

I am getting reports of this error again:

semid 491524: semop failed for cookie 0xd4dc159: incorrect semaphore state
Failed to set a proper state for notification semaphore identified by
cookie value 223199577 (0xd4dc159) to initialize waiting for incoming
notifications.

This issue is so weird that I don't know where to start. Apparently,
this problem appears whenever chromium is running, and disappears when
you quit chromium. I'm confused about this. Very confused.

I cannot see any connection here, but it has been confirmed by several
users of different distributions (several Arch users, at least one
Slackware user).

For details, please read: https://bugs.archlinux.org/task/24614

I hope anyone can help.


[-- Attachment #2: OpenPGP digital signature --]
[-- Type: application/pgp-signature, Size: 262 bytes --]

Re: [dm-crypt] The weird bug again: semid XXXXXX: semop failed for cookie 0xdeadbeef: incorrect semaphore state

[Milan Broz]

On 08/16/2011 10:45 PM, Thomas Bächler wrote:
> I am getting reports of this error again:
> 
> semid 491524: semop failed for cookie 0xd4dc159: incorrect semaphore state
> Failed to set a proper state for notification semaphore identified by
> cookie value 223199577 (0xd4dc159) to initialize waiting for incoming
> notifications.
> 
> This issue is so weird that I don't know where to start. Apparently,
> this problem appears whenever chromium is running, and disappears when
> you quit chromium. I'm confused about this. Very confused.

I know that this bug is still there. I think that the problem is:

- kernel, in response to devmapper library request, send uevent with cookie
- kernel reports failure (despite uevent was sent), I guess it is
some memory allocation error later
- libdevmapper takes error path, destroying semaphore, which was already
destroyed in udev rules

So my guess is that connection with chromium just it perhaps allocates most
of system memory and some allocation in kernel perhaps fail then.

The final state should be correct, so you can (I hope) ignore that error
for now.

It is not a cryptsetup bug but I would like to fix it anyway,
the problem is the bug appears and disappears quite randomly.

Does anyone see this bug in some other libdevmapper user?
(lvm, multipath, kpartx, ... ?)

(Another possibility is that you have broken udev rules and
"dmsetup udevcomplete" is called twice there, but I do not think it
the issue.)

Milan

Re: [dm-crypt] The weird bug again: semid XXXXXX: semop failed for cookie 0xdeadbeef: incorrect semaphore state

[Thomas Bächler]

[-- Attachment #1: Type: text/plain, Size: 1964 bytes --]

Am 16.08.2011 23:44, schrieb Milan Broz:
> On 08/16/2011 10:45 PM, Thomas Bächler wrote:
>> I am getting reports of this error again:
>>
>> semid 491524: semop failed for cookie 0xd4dc159: incorrect semaphore state
>> Failed to set a proper state for notification semaphore identified by
>> cookie value 223199577 (0xd4dc159) to initialize waiting for incoming
>> notifications.
>>
>> This issue is so weird that I don't know where to start. Apparently,
>> this problem appears whenever chromium is running, and disappears when
>> you quit chromium. I'm confused about this. Very confused.
> 
> I know that this bug is still there. I think that the problem is:
> 
> - kernel, in response to devmapper library request, send uevent with cookie
> - kernel reports failure (despite uevent was sent), I guess it is
> some memory allocation error later
> - libdevmapper takes error path, destroying semaphore, which was already
> destroyed in udev rules
> 
> So my guess is that connection with chromium just it perhaps allocates most
> of system memory and some allocation in kernel perhaps fail then.

Then this would probably be reproducible with other programs, too. So
far, the connection has been only made with chromium. I would love to
find another test case though.

> The final state should be correct, so you can (I hope) ignore that error
> for now.

Don't the LUKS commands abort after this error? (Don't remember).

> It is not a cryptsetup bug but I would like to fix it anyway,
> the problem is the bug appears and disappears quite randomly.
> 
> Does anyone see this bug in some other libdevmapper user?
> (lvm, multipath, kpartx, ... ?)

I have only seen this with cryptsetup so far.

> (Another possibility is that you have broken udev rules and
> "dmsetup udevcomplete" is called twice there, but I do not think it
> the issue.)

Udev rules are all taken directly from upstream udev and device-mapper.


[-- Attachment #2: OpenPGP digital signature --]
[-- Type: application/pgp-signature, Size: 262 bytes --]

Re: [dm-crypt] The weird bug again: semid XXXXXX: semop failed for cookie 0xdeadbeef: incorrect semaphore state

[Alexander Koch]

> Does anyone see this bug in some other libdevmapper user?
> (lvm, multipath, kpartx, ... ?)

I see it when creating or resizing lvm volumes. The creation fails, so I
cant't just ignore the message there :)

Closing chromium avoids the issue.


Greetings

Alex

Re: [dm-crypt] The weird bug again: semid XXXXXX: semop failed for cookie 0xdeadbeef: incorrect semaphore state

[Milan Broz]

On 08/16/2011 11:55 PM, Thomas Bächler wrote:
> Am 16.08.2011 23:44, schrieb Milan Broz:
>> On 08/16/2011 10:45 PM, Thomas Bächler wrote:
>>> I am getting reports of this error again:
>>>
>>> semid 491524: semop failed for cookie 0xd4dc159: incorrect semaphore state
>>> Failed to set a proper state for notification semaphore identified by
>>> cookie value 223199577 (0xd4dc159) to initialize waiting for incoming
>>> notifications.
>>>
>>> This issue is so weird that I don't know where to start. Apparently,
>>> this problem appears whenever chromium is running, and disappears when
>>> you quit chromium. I'm confused about this. Very confused.
>>
>> I know that this bug is still there. I think that the problem is:
>>
>> - kernel, in response to devmapper library request, send uevent with cookie
>> - kernel reports failure (despite uevent was sent), I guess it is
>> some memory allocation error later
>> - libdevmapper takes error path, destroying semaphore, which was already
>> destroyed in udev rules
>>
>> So my guess is that connection with chromium just it perhaps allocates most
>> of system memory and some allocation in kernel perhaps fail then.
> 
> Then this would probably be reproducible with other programs, too. So
> far, the connection has been only made with chromium. I would love to
> find another test case though.

Well, this is the most strange report so far. If more people can reproduce it,
there must be a connection. Isn't chromium using system semaphores intensively?
(I have no idea.)

What says "ipcs -s" (with and without chromium running)?

Will increasing number of system semaphores help (first number)?
sysctl -a |grep sem

Can you try to increase it to 1000 for example
sysctl -w kernel.sem=1000


> 
>> The final state should be correct, so you can (I hope) ignore that error
>> for now.
> 
> Don't the LUKS commands abort after this error? (Don't remember).

It should not.

Milan

Re: [dm-crypt] The weird bug again: semid XXXXXX: semop failed for cookie 0xdeadbeef: incorrect semaphore state

[Yves-Alexis Perez]

On mer., 2011-08-17 at 13:22 +0200, Alexander Koch wrote:
>   [alex@thor ~]$ sudo vgchange -an ArchiveGroup
>     0 logical volume(s) in volume group "ArchiveGroup" now active
>     semid 557056: semop failed for cookie 0xd4d88de: incorrect semaphore
> state
>     Failed to set a proper state for notification semaphore identified
> by cookie value 223185118 (0xd4d88de) to initialize waiting for incoming
> notifications. 

vchange is only LVM, not dm-crypt, is it? So might not be related at all
to dm-crypt or cryptsetup?

For chromium, it might be that the default sandboxing (setuid one) uses
PID and network namespaces. Not sure why it'd mess with semaphores, but
maybe there's something to look at there.

Regards,
-- 
Yves-Alexis

Re: [dm-crypt] The weird bug again: semid XXXXXX: semop failed for cookie 0xdeadbeef: incorrect semaphore state

[Milan Broz]

On 08/17/2011 12:43 PM, Yves-Alexis Perez wrote:
> On mer., 2011-08-17 at 13:22 +0200, Alexander Koch wrote:
>>   [alex@thor ~]$ sudo vgchange -an ArchiveGroup
>>     0 logical volume(s) in volume group "ArchiveGroup" now active
>>     semid 557056: semop failed for cookie 0xd4d88de: incorrect semaphore
>> state
>>     Failed to set a proper state for notification semaphore identified
>> by cookie value 223185118 (0xd4d88de) to initialize waiting for incoming
>> notifications. 
> 
> vchange is only LVM, not dm-crypt, is it? So might not be related at all
> to dm-crypt or cryptsetup?

Thet problem is in libdevampper library (which is common for cryptsetup and lvm).
(cryptsetup itself does not use semaphores at all)

Just to verify that udev handling is correct, can you paste output of
grep dmsetup /lib/udev/rules.d/* ? 

> For chromium, it might be that the default sandboxing (setuid one) uses
> PID and network namespaces. Not sure why it'd mess with semaphores, but
> maybe there's something to look at there.

Hm. Is there some page describing what it is doing?
(Of course on my system it works with chromium running without problem...)


Milan

Re: [dm-crypt] The weird bug again: semid XXXXXX: semop failed for cookie 0xdeadbeef: incorrect semaphore state

[Alexander Koch]

> What says "ipcs -s" (with and without chromium running)?
I get an empty list, no matter if chromium is running or not:

  [alex@thor ~]$ LC_ALL=C ipcs -s

  ------ Semaphore Arrays --------
  key        semid      owner      perms      nsems


> Will increasing number of system semaphores help (first number)?
> sysctl -a |grep sem
Default was 250, increasing to 1000 had no effect:

  [alex@thor ~]$ sudo vgchange -an ArchiveGroup
    0 logical volume(s) in volume group "ArchiveGroup" now active
    semid 557056: semop failed for cookie 0xd4d88de: incorrect semaphore
state
    Failed to set a proper state for notification semaphore identified
by cookie value 223185118 (0xd4d88de) to initialize waiting for incoming
notifications.


Besides, I got this message in the logs, don't know if this could be
related:

chromium-sandbo (2120): /proc/2118/oom_adj is deprecated, please use
/proc/2118/oom_score_adj instead.


Greetings

Alex

Re: [dm-crypt] The weird bug again: semid XXXXXX: semop failed for cookie 0xdeadbeef: incorrect semaphore state

[Milan Broz]

On 08/17/2011 12:48 PM, Milan Broz wrote:
>> For chromium, it might be that the default sandboxing (setuid one) uses
>> PID and network namespaces. Not sure why it'd mess with semaphores, but
>> maybe there's something to look at there.

It is apparently related to sandboxing, namely to using namespaces
(You need kernel support for it to reproduce. See about:sandbox in chromium.)

I would really like to know what crazy is chromium doing to global
system.

Despite I like the idea of sandboxing I have to ask
why it is part of "browser" and not some separate package.
What's next? Bundled kernel? :)

Also installing setuid /usr/lib64/chromium/chromium-sandbox ...
Not even man page for it. Sigh...

Milan

Re: [dm-crypt] The weird bug again: semid XXXXXX: semop failed for cookie 0xdeadbeef: incorrect semaphore state

[Yves-Alexis Perez]

On mer., 2011-08-17 at 13:30 +0200, Milan Broz wrote:
> On 08/17/2011 12:48 PM, Milan Broz wrote:
> >> For chromium, it might be that the default sandboxing (setuid one)
> uses
> >> PID and network namespaces. Not sure why it'd mess with semaphores,
> but
> >> maybe there's something to look at there.
> 
> It is apparently related to sandboxing, namely to using namespaces
> (You need kernel support for it to reproduce. See about:sandbox in
> chromium.)
> 
> I would really like to know what crazy is chromium doing to global
> system.
> 
> Despite I like the idea of sandboxing I have to ask
> why it is part of "browser" and not some separate package.
> What's next? Bundled kernel? :)

Because each tab is sandboxed. There's a seccomp sandbox available too.


> 
> Also installing setuid /usr/lib64/chromium/chromium-sandbox ...
> Not even man page for it. Sigh... 

See http://code.google.com/p/chromium/wiki/LinuxSandboxing
-- 
Yves-Alexis

Re: [dm-crypt] The weird bug again: semid XXXXXX: semop failed for cookie 0xdeadbeef: incorrect semaphore state

[Milan Broz]

On 08/17/2011 02:17 PM, Yves-Alexis Perez wrote:
>> I would really like to know what crazy is chromium doing to global
>> system.
>>
>> Despite I like the idea of sandboxing I have to ask
>> why it is part of "browser" and not some separate package.
>> What's next? Bundled kernel? :)
> 
> Because each tab is sandboxed. There's a seccomp sandbox available too.

It doesn't mean it should install trillion of bundled libraries.
(Not that other browsers are much bettter...)


Whatever, the bug is neither in chromium nor in cryptsetup and libdevmapper
but kernel.

Sandoxing uses clone with CLONE_NEWNET (use own net namespace) and after
that call some udev event in kernel reports failure (netlink send fails).

I will report that upstream because this is quite unexpected result, easily
reproducible with simple clone() and dmsetup.

(DM is here victim because it is one of the rare users of kobject_uevent_env()
which checks return value, others quietly ignore this failure:-)

Milan

Re: [dm-crypt] The weird bug again: semid XXXXXX: semop failed for cookie 0xdeadbeef: incorrect semaphore state

[Thomas Bächler]

[-- Attachment #1: Type: text/plain, Size: 294 bytes --]

Am 18.08.2011 10:56, schrieb Milan Broz:
> I will report that upstream because this is quite unexpected result, easily
> reproducible with simple clone() and dmsetup.

Can you describe the test you are doing in more detail (or give me a few
shell commands or a C program to reproduce)?


[-- Attachment #2: OpenPGP digital signature --]
[-- Type: application/pgp-signature, Size: 262 bytes --]

Re: [dm-crypt] The weird bug again: semid XXXXXX: semop failed for cookie 0xdeadbeef: incorrect semaphore state

[Milan Broz]

On 08/18/2011 11:56 AM, Thomas Bächler wrote:
> Am 18.08.2011 10:56, schrieb Milan Broz:
>> I will report that upstream because this is quite unexpected result, easily
>> reproducible with simple clone() and dmsetup.
> 
> Can you describe the test you are doing in more detail (or give me a few
> shell commands or a C program to reproduce)?

https://lkml.org/lkml/2011/8/18/112

Run

dmsetup create aaa --table "0 100 zero" -vvvv
dmsetup remove aaa -vvvv

(it should work)

Then run e.g. such program in parallel:
(uevent fails and dmsetup receive "uevent not sent" taking
wrong error path)

#include <stdio.h>
#include <stdlib.h>
#include <unistd.h>
#include <sched.h>
#include <sys/types.h>
#include <sys/wait.h>

#define STACK_MIN 4096

int clone_start(void* x)
{
        printf("child running...\n");
        sleep(30);

        return 0;
}

int main (int argc, char *argv[])
{
        char stack[STACK_MIN];
        int waitpid_status;
        int clone_flags = SIGCHLD | CLONE_NEWNET;

        pid_t pid = clone(clone_start, stack + STACK_MIN, clone_flags, (void *) argv);
        if (pid == -1) {
                printf("clone()\n");
                exit(1);
        }

        printf("waiting for pid: %d ...\n", (int) pid);
        pid = waitpid(pid, &waitpid_status, 0);
        if (pid < 0) {
                printf("waitpid()\n");
                exit(1);
        }

        return 0;
}

Re: [dm-crypt] The weird bug again: semid XXXXXX: semop failed for cookie 0xdeadbeef: incorrect semaphore state

[Yves-Alexis Perez]

[-- Attachment #1: Type: text/plain, Size: 599 bytes --]

On jeu., 2011-08-18 at 10:56 +0200, Milan Broz wrote:
> >> Despite I like the idea of sandboxing I have to ask
> >> why it is part of "browser" and not some separate package.
> >> What's next? Bundled kernel? :)
> > 
> > Because each tab is sandboxed. There's a seccomp sandbox available too.
> 
> It doesn't mean it should install trillion of bundled libraries.
> (Not that other browsers are much bettter...) 

Though that's quite unrelated. But they intend to provide a seccomp
sandbox library at one point, see
http://code.google.com/p/seccompsandbox/

Regards,
-- 
Yves-Alexis

[-- Attachment #2: This is a digitally signed message part --]
[-- Type: application/pgp-signature, Size: 836 bytes --]

Re: [dm-crypt] The weird bug again: semid XXXXXX: semop failed for cookie 0xdeadbeef: incorrect semaphore state

[Thomas Bächler]

[-- Attachment #1: Type: text/plain, Size: 633 bytes --]

Am 18.08.2011 12:25, schrieb Milan Broz:
> On 08/18/2011 11:56 AM, Thomas Bächler wrote:
>> Am 18.08.2011 10:56, schrieb Milan Broz:
>>> I will report that upstream because this is quite unexpected result, easily
>>> reproducible with simple clone() and dmsetup.
>>
>> Can you describe the test you are doing in more detail (or give me a few
>> shell commands or a C program to reproduce)?
> 
> https://lkml.org/lkml/2011/8/18/112

And nobody seems to care. Maybe some subsystem maintainer/list would be
more responsive than just LKML? I don't know which one though. Maybe one
should also CC the udev people on this.


[-- Attachment #2: OpenPGP digital signature --]
[-- Type: application/pgp-signature, Size: 262 bytes --]

Re: [dm-crypt] The weird bug again: semid XXXXXX: semop failed for cookie 0xdeadbeef: incorrect semaphore state

[Thomas Bächler]

[-- Attachment #1: Type: text/plain, Size: 792 bytes --]

Am 22.08.2011 13:51, schrieb Thomas Bächler:
> Am 18.08.2011 12:25, schrieb Milan Broz:
>> On 08/18/2011 11:56 AM, Thomas Bächler wrote:
>>> Am 18.08.2011 10:56, schrieb Milan Broz:
>>>> I will report that upstream because this is quite unexpected result, easily
>>>> reproducible with simple clone() and dmsetup.
>>>
>>> Can you describe the test you are doing in more detail (or give me a few
>>> shell commands or a C program to reproduce)?
>>
>> https://lkml.org/lkml/2011/8/18/112
> 
> And nobody seems to care. Maybe some subsystem maintainer/list would be
> more responsive than just LKML? I don't know which one though. Maybe one
> should also CC the udev people on this.

NVM, I just realized there are replies to this, but the LKML link above
doesn't show them.


[-- Attachment #2: OpenPGP digital signature --]
[-- Type: application/pgp-signature, Size: 262 bytes --]

Re: [dm-crypt] The weird bug again: semid XXXXXX: semop failed for cookie 0xdeadbeef: incorrect semaphore state

[Milan Broz]

On 08/23/2011 12:01 PM, Thomas Bächler wrote:
> NVM, I just realized there are replies to this, but the LKML link above
> doesn't show them.

My simple patch was just committed to driver's git, so it will appear shortly
in linux-next. There is cc to stable so I think it will appear in stable
update later.

If anyone want to try it:
https://lkml.org/lkml/2011/8/22/155

Thanks,
Milan

Re: [dm-crypt] The weird bug again: semid XXXXXX: semop failed for cookie 0xdeadbeef: incorrect semaphore state

[Thomas Bächler]

[-- Attachment #1: Type: text/plain, Size: 572 bytes --]

Am 23.08.2011 13:51, schrieb Milan Broz:
> On 08/23/2011 12:01 PM, Thomas Bächler wrote:
>> NVM, I just realized there are replies to this, but the LKML link above
>> doesn't show them.
> 
> My simple patch was just committed to driver's git, so it will appear shortly
> in linux-next. There is cc to stable so I think it will appear in stable
> update later.
> 
> If anyone want to try it:
> https://lkml.org/lkml/2011/8/22/155
> 
> Thanks,
> Milan

I finally have confirmation that this patch helps:
https://bugs.archlinux.org/task/24614#comment83007


[-- Attachment #2: OpenPGP digital signature --]
[-- Type: application/pgp-signature, Size: 262 bytes --]

Re: [dm-crypt] The weird bug again: semid XXXXXX: semop failed for cookie 0xdeadbeef: incorrect semaphore state

[Sebastian Steinhuber]

Am 23.08.2011 13:51, schrieb Milan Broz:
> My simple patch was just committed to driver's git, so it will appear shortly
> in linux-next. There is cc to stable so I think it will appear in stable
> update later.
> 
> If anyone want to try it:
> https://lkml.org/lkml/2011/8/22/155
> 
> Thanks,
> Milan

Hi!
It seems that the patch was committed to 2.6.32 and 2.6.33 for now,
according to LKML.
However, I reproduced the behavior with chromium and google-chrome.
Maybe the patch was not commited to mainline:

"semid 688130: semop failed for cookie 0xd4d5abf: incorrect semaphore state
Failed to set a proper state for notification semaphore identified by
cookie value 223173311 (0xd4d5abf) to initialize waiting for incoming
notifications."

I'm running debian unstable with a customized vanilla kernel 3.0.7 with
vserver patch, cryptsetup 1.3.0, udev 172, chromium 14.0, google-chrome
15.0.

Best,
Sebastian

Re: [dm-crypt] The weird bug again: semid XXXXXX: semop failed for cookie 0xdeadbeef: incorrect semaphore state

[Milan Broz]

On 11/03/2011 04:32 PM, Sebastian Steinhuber wrote:
> It seems that the patch was committed to 2.6.32 and 2.6.33 for now,
> according to LKML.
> However, I reproduced the behavior with chromium and google-chrome.
> Maybe the patch was not commited to mainline:

It is in mainline and it is in queue for 3.0.9 and 3.1.1 now.

Milan