* sound: -EPERM on first mplayer invocation
@ 2009-08-02 21:36 Denys Vlasenko
2009-08-03 6:55 ` Takashi Iwai
0 siblings, 1 reply; 9+ messages in thread
From: Denys Vlasenko @ 2009-08-02 21:36 UTC (permalink / raw)
To: Takashi Iwai; +Cc: linux-kernel
Hi,
For a long time I observe the following nuisance:
when I run mplayer for the very first time after boot,
I can't adjust the volume. mplayer spews this to stderr:
alsa-control: error setting left channel, Operation not permitted
This happens even if I login as root and run mplayer as root.
I tracked it down to snd_ctl_elem_write in sound/core/control.c
static int snd_ctl_elem_write(struct snd_card *card, struct snd_ctl_file *file,
struct snd_ctl_elem_value *control)
{
struct snd_kcontrol *kctl;
struct snd_kcontrol_volatile *vd;
unsigned int index_offset;
int result;
down_read(&card->controls_rwsem);
kctl = snd_ctl_find_id(card, &control->id);
if (kctl == NULL) {
result = -ENOENT;
} else {
index_offset = snd_ctl_get_ioff(kctl, &control->id);
vd = &kctl->vd[index_offset];
if (!(vd->access & SNDRV_CTL_ELEM_ACCESS_WRITE) ||
kctl->put == NULL ||
(file && vd->owner && vd->owner != file)) {
printk("EPERM:\n");
printk("vd->access & SNDRV_CTL_ELEM_ACCESS_WRITE:%x\n", vd->access & SNDRV_CTL_ELEM_ACCESS_WRITE);
printk("kctl->put:%p\n", kctl->put);
printk("file:%p vd->owner:%p\n", file, vd->owner);
result = -EPERM;
} else {
The above printk triggers and prints:
EPERM:
vd->access & SNDRV_CTL_ELEM_ACCESS_WRITE:2
kctl->put:ffffffffa009e8de
file:ffff88007c56a5c0 vd->owner:ffff88007bc34740
Thus, vd->owner != file.
As I said, it only happens on very first run of mplayer,
and it isn't a recent change, I think I saw it at least
for one year with different kernels.
Takashi, any idea what might be happening here?
How can I help you more with tracking it down?
--
vda
^ permalink raw reply [flat|nested] 9+ messages in thread
* Re: sound: -EPERM on first mplayer invocation
2009-08-02 21:36 sound: -EPERM on first mplayer invocation Denys Vlasenko
@ 2009-08-03 6:55 ` Takashi Iwai
2009-08-04 9:01 ` Denys Vlasenko
0 siblings, 1 reply; 9+ messages in thread
From: Takashi Iwai @ 2009-08-03 6:55 UTC (permalink / raw)
To: Denys Vlasenko; +Cc: linux-kernel
At Sun, 2 Aug 2009 23:36:48 +0200,
Denys Vlasenko wrote:
>
> Hi,
>
> For a long time I observe the following nuisance:
> when I run mplayer for the very first time after boot,
> I can't adjust the volume. mplayer spews this to stderr:
>
> alsa-control: error setting left channel, Operation not permitted
>
> This happens even if I login as root and run mplayer as root.
>
> I tracked it down to snd_ctl_elem_write in sound/core/control.c
>
> static int snd_ctl_elem_write(struct snd_card *card, struct snd_ctl_file *file,
> struct snd_ctl_elem_value *control)
> {
> struct snd_kcontrol *kctl;
> struct snd_kcontrol_volatile *vd;
> unsigned int index_offset;
> int result;
>
> down_read(&card->controls_rwsem);
> kctl = snd_ctl_find_id(card, &control->id);
> if (kctl == NULL) {
> result = -ENOENT;
> } else {
> index_offset = snd_ctl_get_ioff(kctl, &control->id);
> vd = &kctl->vd[index_offset];
> if (!(vd->access & SNDRV_CTL_ELEM_ACCESS_WRITE) ||
> kctl->put == NULL ||
> (file && vd->owner && vd->owner != file)) {
> printk("EPERM:\n");
> printk("vd->access & SNDRV_CTL_ELEM_ACCESS_WRITE:%x\n", vd->access & SNDRV_CTL_ELEM_ACCESS_WRITE);
> printk("kctl->put:%p\n", kctl->put);
> printk("file:%p vd->owner:%p\n", file, vd->owner);
> result = -EPERM;
> } else {
>
> The above printk triggers and prints:
>
> EPERM:
> vd->access & SNDRV_CTL_ELEM_ACCESS_WRITE:2
> kctl->put:ffffffffa009e8de
> file:ffff88007c56a5c0 vd->owner:ffff88007bc34740
>
> Thus, vd->owner != file.
>
> As I said, it only happens on very first run of mplayer,
> and it isn't a recent change, I think I saw it at least
> for one year with different kernels.
>
> Takashi, any idea what might be happening here?
> How can I help you more with tracking it down?
This implies that another process (e.g. a sound daemon like PA)
already opened the device and locked this specific control element.
If so, this is no bug but the right behavior.
Check "fuser /dev/snd/controlC*".
Takashi
^ permalink raw reply [flat|nested] 9+ messages in thread
* Re: sound: -EPERM on first mplayer invocation
2009-08-03 6:55 ` Takashi Iwai
@ 2009-08-04 9:01 ` Denys Vlasenko
2009-08-04 9:16 ` Takashi Iwai
0 siblings, 1 reply; 9+ messages in thread
From: Denys Vlasenko @ 2009-08-04 9:01 UTC (permalink / raw)
To: Takashi Iwai; +Cc: linux-kernel
On Monday 03 August 2009 08:55, Takashi Iwai wrote:
> Denys Vlasenko wrote:
> > Hi,
> >
> > For a long time I observe the following nuisance:
> > when I run mplayer for the very first time after boot,
> > I can't adjust the volume. mplayer spews this to stderr:
> >
> > alsa-control: error setting left channel, Operation not permitted
> >
> > This happens even if I login as root and run mplayer as root.
> >
> > I tracked it down to snd_ctl_elem_write in sound/core/control.c
> >
...
> >
> > Thus, vd->owner != file.
> >
> > As I said, it only happens on very first run of mplayer,
> > and it isn't a recent change, I think I saw it at least
> > for one year with different kernels.
> >
> > Takashi, any idea what might be happening here?
> > How can I help you more with tracking it down?
>
> This implies that another process (e.g. a sound daemon like PA)
> already opened the device and locked this specific control element.
> If so, this is no bug but the right behavior.
> Check "fuser /dev/snd/controlC*".
Nothing uses them:
shadow:~# lsof -nP | grep '/dev/.*control'
shadow:~# fuser /dev/snd/controlC*
shadow:~#
I tried running bare X with only xterm and mplayer,
and I see the same symptoms when I try to adjust volume:
...
[Mixer] No hardware mixing, inserting volume filter.
[libaf] Adding filter volume
[dummy] Was reinitialized: 48000Hz/2ch/s16le
alsa-control: error setting left channel, Operation not permitted0 78%
alsa-control: error setting left channel, Operation not permitted0 77%
alsa-control: error setting left channel, Operation not permitted0 76%
alsa-control: error setting left channel, Operation not permitted0 75%
...
Here is the list of processes just before I started mplayer.
AFAICS, no sound daemons:
PID USER TIME COMMAND
1 root 0:00 /bin/sh /init
2 root 0:00 [kthreadd]
3 root 0:00 [migration/0]
4 root 0:00 [ksoftirqd/0]
5 root 0:00 [watchdog/0]
6 root 0:00 [events/0]
7 root 0:00 [khelper]
13 root 0:00 [async/mgr]
184 root 0:00 [kblockd/0]
186 root 0:00 [kacpid]
187 root 0:00 [kacpi_notify]
188 root 0:00 [kacpi_hotplug]
284 root 0:00 [ata/0]
285 root 0:00 [ata_aux]
289 root 0:00 [ksuspend_usbd]
293 root 0:00 [khubd]
296 root 0:00 [kseriod]
298 root 0:00 [kgameportd]
356 root 0:00 [khungtaskd]
357 root 0:00 [pdflush]
358 root 0:00 [pdflush]
359 root 0:00 [kswapd0]
360 root 0:00 [aio/0]
361 root 0:00 [nfsiod]
362 root 0:00 [crypto/0]
551 root 0:00 [scsi_eh_0]
553 root 0:00 [scsi_eh_1]
555 root 0:00 [scsi_eh_2]
557 root 0:00 [scsi_eh_3]
612 root 0:00 [bnx2x]
670 root 0:00 [mlx4]
688 root 0:00 [netxen]
691 root 0:00 [sfc_refill/0]
692 root 0:00 [sfc_reset]
709 root 0:00 [kpsmoused]
715 root 0:00 [rpciod/0]
765 root 0:00 [kjournald]
783 root 0:00 udevd
800 root 0:00 [reiserfs/0]
807 1 0:00 rpc.portmap
866 root 0:00 runsvdir -P /var/service _____________________________________________
867 root 0:00 sleep 32000
868 root 0:00 runsv fw
869 root 0:00 runsv gpm
870 root 0:00 runsv ntp
871 root 0:00 runsv top
872 root 0:00 runsv klog
873 logger 0:00 svlogd -tt /var/log/service/ntp
876 root 0:00 gpm -D -2 -m /dev/psaux -t ps2
880 root 0:00 top
884 root 0:00 runsv once
885 root 0:00 runsv tftp
903 root 0:00 runsv sshd
904 root 0:00 runsv vpnc
905 root 0:00 runsv ora_db_test1st
906 root 0:00 runsv dhcp_if
911 logger 0:00 svlogd -tt /var/log/service/klog
913 root 0:00 socklog ucspi
932 root 0:00 runsv httpd
933 root 0:00 runsv httpd_ssl
934 root 0:00 runsv vsftp
935 root 0:00 runsv proxy-2222-to-22
948 root 0:00 runsv ftpd_bbox
949 root 0:00 runsv ora_listener
950 root 0:00 runsv nfs_v3
951 root 0:00 runsv nmeter
952 root 0:00 runsv getty_gay
953 root 0:00 runsv telnetd_bbox
954 root 0:00 runsv clock_server
955 root 0:00 runsv getty_tty1
966 time 0:00 taiclockd
975 root 0:00 runsv getty_tty2
976 root 0:00 runsv getty_tty3
977 root 0:00 nmeter %t %c x %x p%p f %f b %b m %m if%[nif]
994 logger 0:00 svlogd -tt /var/log/service/dhcp_if
996 root 0:00 ./udhcpc -vv --hostname=null --foreground --interface=if --pidfile=/.local/var/service/dhcp_if/udhcpc.pid --script=/.local/var/service/dhcp_if/dhcp_handler
1004 logger 0:00 svlogd -tt /var/log/service/ora_db_test1st
1007 logger 0:00 svlogd -tt /var/log/service/tftp
1009 root 0:00 udpsvd -v -c 10 -l localhost 0 69 tftpd /pub/tftp
1011 root 0:00 -bash
1022 root 0:00 runsv getty_tty4
1024 root 0:00 runsv getty_tty5
1025 logger 0:00 svlogd -tt /var/log/service/vsftp
1028 logger 0:00 svlogd -tt /var/log/service/httpd
1035 root 0:00 runsv getty_tty6
1036 root 0:00 runsv getty_tty7
1037 root 0:00 runsv getty_tty8
1038 root 0:00 runsv httpd_bbox
1039 root 0:00 runsv syslog
1040 root 0:00 runsv tidy_tmp
1041 root 0:00 runsv dnscache_int
1042 root 0:00 runsv automount
1043 root 0:00 runsv crond_bbox
1044 root 0:00 runsv dhcpd_if
1045 root 0:00 runsv inetd_bbox
1046 root 0:00 runsv dhcp_if_pinger
1047 logger 0:00 svlogd -tt /var/log/service/sshd
1049 logger 0:00 svlogd -tt /var/log/service/httpd_ssl
1051 logger 0:00 svlogd -tt /var/log/service/vpnc
1053 root 0:00 tcpserver -v -R -H -l 0 -c 40 0.0.0.0 80 setuidgid root httpd -f /.local/var/service/httpd/httpd.conf
1055 root 0:00 getty 38400 /dev/tty3 linux
1059 root 0:00 getty 38400 /dev/tty8 linux
1061 logger 0:00 svlogd -tt /var/log/service/inetd_bbox
1075 root 0:00 tcpserver -v -R -H -l 0 -c 40 0.0.0.0 443 stunnel -f -p ../host.pem -l setuidgid -- setuidgid root httpd -f /.local/var/service/httpd_ssl/httpd.conf
1077 root 0:00 tcpsvd -vE -l 0 -c 40 0 22 /usr/bin/sshd -i -D -e -p22 -u0
1090 logger 0:00 svlogd -tt /var/log/service/automount
1092 root 0:00 automount -f -s -v --timeout 15 /.local/mnt/auto program /.local/var/service/automount/mapper.sh
1103 root 0:00 getty 38400 /dev/tty5 linux
1110 logger 0:00 svlogd -tt /var/log/service/telnetd_bbox
1112 logger 0:00 svlogd /var/log/service/syslog
1113 logger 0:00 svlogd -tt /var/log/service/tidy_tmp
1122 root 0:00 sleep 1260
1127 root 0:00 getty 38400 /dev/tty7 linux
1157 logger 0:00 svlogd -tt /var/log/service/httpd_bbox
1159 root 0:00 tcpserver -v -R -H -l 0 -c 40 0.0.0.0 81 setuidgid root ./busybox httpd -vvv -i -h /.1/video
1166 root 0:00 getty 38400 /dev/tty6 linux
1171 logger 0:00 svlogd -tt /var/log/service/dnscache_int
1173 logger 0:00 svlogd -tt /var/log/service/crond_bbox
1179 root 0:00 crond -f -d7
1190 root 0:00 syslogd -m 0 -n -S -s 99 -b 9 -O /.local/var/service/syslog/syslog
1200 root 0:00 getty 38400 /dev/tty4 linux
1205 logger 0:00 svlogd -tt /var/log/service/ora_listener
1225 logger 0:00 svlogd -tt /var/log/service/proxy-2222-to-22
1229 logger 0:00 svlogd -tt /var/log/service/dhcpd_if
1234 logger 0:00 svlogd -tt /var/log/service/ftpd_bbox
1236 root 0:00 tcpsvd -vE -l 0 -c 40 0.0.0.0 21 setuidgid root ./busybox ftpd -vv -t10 /.1/video
1733 root 0:00 [hd-audio0]
1741 dns 0:00 dnscache
2292 root 0:00 xinit
2293 root 0:00 X :0
2297 root 0:00 xterm -geometry +1+1 -n login
2298 root 0:00 bash
2302 root 0:00 ps -A
When I exit mplayer and start it again, it works.
What can I try next?
--
vda
^ permalink raw reply [flat|nested] 9+ messages in thread
* Re: sound: -EPERM on first mplayer invocation
2009-08-04 9:01 ` Denys Vlasenko
@ 2009-08-04 9:16 ` Takashi Iwai
2009-08-05 2:32 ` Denys Vlasenko
0 siblings, 1 reply; 9+ messages in thread
From: Takashi Iwai @ 2009-08-04 9:16 UTC (permalink / raw)
To: Denys Vlasenko; +Cc: linux-kernel
At Tue, 4 Aug 2009 11:01:43 +0200,
Denys Vlasenko wrote:
>
> On Monday 03 August 2009 08:55, Takashi Iwai wrote:
> > Denys Vlasenko wrote:
> > > Hi,
> > >
> > > For a long time I observe the following nuisance:
> > > when I run mplayer for the very first time after boot,
> > > I can't adjust the volume. mplayer spews this to stderr:
> > >
> > > alsa-control: error setting left channel, Operation not permitted
> > >
> > > This happens even if I login as root and run mplayer as root.
> > >
> > > I tracked it down to snd_ctl_elem_write in sound/core/control.c
> > >
> ...
> > >
> > > Thus, vd->owner != file.
> > >
> > > As I said, it only happens on very first run of mplayer,
> > > and it isn't a recent change, I think I saw it at least
> > > for one year with different kernels.
> > >
> > > Takashi, any idea what might be happening here?
> > > How can I help you more with tracking it down?
> >
> > This implies that another process (e.g. a sound daemon like PA)
> > already opened the device and locked this specific control element.
> > If so, this is no bug but the right behavior.
> > Check "fuser /dev/snd/controlC*".
>
> Nothing uses them:
>
> shadow:~# lsof -nP | grep '/dev/.*control'
> shadow:~# fuser /dev/snd/controlC*
> shadow:~#
>
> I tried running bare X with only xterm and mplayer,
Hm, but according to your debug session, the vd->owner is set
to a different value, right? Check vd->owner_pid in the error path.
It'll show the pid blocking that control element.
Takashi
^ permalink raw reply [flat|nested] 9+ messages in thread
* Re: sound: -EPERM on first mplayer invocation
2009-08-04 9:16 ` Takashi Iwai
@ 2009-08-05 2:32 ` Denys Vlasenko
2009-08-05 5:37 ` Takashi Iwai
0 siblings, 1 reply; 9+ messages in thread
From: Denys Vlasenko @ 2009-08-05 2:32 UTC (permalink / raw)
To: Takashi Iwai; +Cc: linux-kernel
On Tuesday 04 August 2009 11:16, Takashi Iwai wrote:
> > > > For a long time I observe the following nuisance:
> > > > when I run mplayer for the very first time after boot,
> > > > I can't adjust the volume. mplayer spews this to stderr:
> > > >
> > > > alsa-control: error setting left channel, Operation not permitted
> > > >
> > > > This happens even if I login as root and run mplayer as root.
> > > >
> > > > I tracked it down to snd_ctl_elem_write in sound/core/control.c
> > > >
> > ...
> > > >
> > > > Thus, vd->owner != file.
> > > >
> > > > As I said, it only happens on very first run of mplayer,
> > > > and it isn't a recent change, I think I saw it at least
> > > > for one year with different kernels.
> > > >
> > > > Takashi, any idea what might be happening here?
> > > > How can I help you more with tracking it down?
> > >
> > > This implies that another process (e.g. a sound daemon like PA)
> > > already opened the device and locked this specific control element.
> > > If so, this is no bug but the right behavior.
> > > Check "fuser /dev/snd/controlC*".
> >
> > Nothing uses them:
> >
> > shadow:~# lsof -nP | grep '/dev/.*control'
> > shadow:~# fuser /dev/snd/controlC*
> > shadow:~#
> >
> > I tried running bare X with only xterm and mplayer,
>
> Hm, but according to your debug session, the vd->owner is set
> to a different value, right? Check vd->owner_pid in the error path.
> It'll show the pid blocking that control element.
I modified 2.6.31-rc2 source as follows:
static int snd_ctl_elem_write(struct snd_card *card, struct snd_ctl_file *file,
struct snd_ctl_elem_value *control)
{
struct snd_kcontrol *kctl;
struct snd_kcontrol_volatile *vd;
unsigned int index_offset;
int result;
down_read(&card->controls_rwsem);
kctl = snd_ctl_find_id(card, &control->id);
if (kctl == NULL) {
result = -ENOENT;
} else {
index_offset = snd_ctl_get_ioff(kctl, &control->id);
vd = &kctl->vd[index_offset];
if (file && vd->owner)
printk("file:%p vd->owner:%p\n", file, vd->owner);
if (!(vd->access & SNDRV_CTL_ELEM_ACCESS_WRITE) ||
kctl->put == NULL ||
(file && vd->owner && vd->owner != file)) {
if (file && vd->owner)
printk("vd->owner_pid:%d vd->owner->pid:%d file->pid:%d\n", vd->owner_pid, vd->owner->pid, file->pid);
result = -EPERM;
} else {
...
and when I start mplayer, I see this:
dmesg:
file:ffff8800798af940 vd->owner:ffff8800798af940
file:ffff8800798af940 vd->owner:ffff8800798af940
I assume it's some sort of initialization, no EPERM here.
Then I press "lower the volume" key (keypad "/")
in mplayer window, twice:
dmesg:
file:ffff8800798af8c0 vd->owner:ffff8800798af940
vd->owner_pid:0 vd->owner->pid:2067 file->pid:2067
file:ffff8800798af740 vd->owner:ffff8800798af940
vd->owner_pid:0 vd->owner->pid:2067 file->pid:2067
mplayer:
alsa-control: error setting left channel, Operation not permitted
The pid is mplayer's pid:
# ps -A | grep mpl
2067 root 0:01 mplayer The_league_of_extraordinary_gentlemen.avi
2081 root 0:00 grep mpl
It has one thread, btw, no funky multithreading stuff:
# ls -l /proc/2067/task
dr-xr-xr-x 4 root root 0 Aug 5 04:28 2067
--
vda
^ permalink raw reply [flat|nested] 9+ messages in thread
* Re: sound: -EPERM on first mplayer invocation
2009-08-05 2:32 ` Denys Vlasenko
@ 2009-08-05 5:37 ` Takashi Iwai
2009-08-05 5:41 ` Takashi Iwai
0 siblings, 1 reply; 9+ messages in thread
From: Takashi Iwai @ 2009-08-05 5:37 UTC (permalink / raw)
To: Denys Vlasenko; +Cc: linux-kernel
At Wed, 5 Aug 2009 04:32:34 +0200,
Denys Vlasenko wrote:
>
> On Tuesday 04 August 2009 11:16, Takashi Iwai wrote:
> > > > > For a long time I observe the following nuisance:
> > > > > when I run mplayer for the very first time after boot,
> > > > > I can't adjust the volume. mplayer spews this to stderr:
> > > > >
> > > > > alsa-control: error setting left channel, Operation not permitted
> > > > >
> > > > > This happens even if I login as root and run mplayer as root.
> > > > >
> > > > > I tracked it down to snd_ctl_elem_write in sound/core/control.c
> > > > >
> > > ...
> > > > >
> > > > > Thus, vd->owner != file.
> > > > >
> > > > > As I said, it only happens on very first run of mplayer,
> > > > > and it isn't a recent change, I think I saw it at least
> > > > > for one year with different kernels.
> > > > >
> > > > > Takashi, any idea what might be happening here?
> > > > > How can I help you more with tracking it down?
> > > >
> > > > This implies that another process (e.g. a sound daemon like PA)
> > > > already opened the device and locked this specific control element.
> > > > If so, this is no bug but the right behavior.
> > > > Check "fuser /dev/snd/controlC*".
> > >
> > > Nothing uses them:
> > >
> > > shadow:~# lsof -nP | grep '/dev/.*control'
> > > shadow:~# fuser /dev/snd/controlC*
> > > shadow:~#
> > >
> > > I tried running bare X with only xterm and mplayer,
> >
> > Hm, but according to your debug session, the vd->owner is set
> > to a different value, right? Check vd->owner_pid in the error path.
> > It'll show the pid blocking that control element.
>
> I modified 2.6.31-rc2 source as follows:
>
> static int snd_ctl_elem_write(struct snd_card *card, struct snd_ctl_file *file,
> struct snd_ctl_elem_value *control)
> {
> struct snd_kcontrol *kctl;
> struct snd_kcontrol_volatile *vd;
> unsigned int index_offset;
> int result;
>
> down_read(&card->controls_rwsem);
> kctl = snd_ctl_find_id(card, &control->id);
> if (kctl == NULL) {
> result = -ENOENT;
> } else {
> index_offset = snd_ctl_get_ioff(kctl, &control->id);
> vd = &kctl->vd[index_offset];
> if (file && vd->owner)
> printk("file:%p vd->owner:%p\n", file, vd->owner);
> if (!(vd->access & SNDRV_CTL_ELEM_ACCESS_WRITE) ||
> kctl->put == NULL ||
> (file && vd->owner && vd->owner != file)) {
> if (file && vd->owner)
> printk("vd->owner_pid:%d vd->owner->pid:%d file->pid:%d\n", vd->owner_pid, vd->owner->pid, file->pid);
> result = -EPERM;
> } else {
> ...
>
> and when I start mplayer, I see this:
>
> dmesg:
> file:ffff8800798af940 vd->owner:ffff8800798af940
> file:ffff8800798af940 vd->owner:ffff8800798af940
>
> I assume it's some sort of initialization, no EPERM here.
> Then I press "lower the volume" key (keypad "/")
> in mplayer window, twice:
>
> dmesg:
> file:ffff8800798af8c0 vd->owner:ffff8800798af940
> vd->owner_pid:0 vd->owner->pid:2067 file->pid:2067
> file:ffff8800798af740 vd->owner:ffff8800798af940
> vd->owner_pid:0 vd->owner->pid:2067 file->pid:2067
The file instances are different. It implies that mplayer opens the
device at each time but doesn't close.
It sounds like a bug in mplayer to me.
Takashi
^ permalink raw reply [flat|nested] 9+ messages in thread
* Re: sound: -EPERM on first mplayer invocation
2009-08-05 5:37 ` Takashi Iwai
@ 2009-08-05 5:41 ` Takashi Iwai
2009-08-05 8:50 ` Clemens Ladisch
2009-08-05 22:00 ` Denys Vlasenko
0 siblings, 2 replies; 9+ messages in thread
From: Takashi Iwai @ 2009-08-05 5:41 UTC (permalink / raw)
To: Denys Vlasenko; +Cc: linux-kernel
At Wed, 05 Aug 2009 07:37:30 +0200,
I wrote:
>
> At Wed, 5 Aug 2009 04:32:34 +0200,
> Denys Vlasenko wrote:
> >
> > On Tuesday 04 August 2009 11:16, Takashi Iwai wrote:
> > > > > > For a long time I observe the following nuisance:
> > > > > > when I run mplayer for the very first time after boot,
> > > > > > I can't adjust the volume. mplayer spews this to stderr:
> > > > > >
> > > > > > alsa-control: error setting left channel, Operation not permitted
> > > > > >
> > > > > > This happens even if I login as root and run mplayer as root.
> > > > > >
> > > > > > I tracked it down to snd_ctl_elem_write in sound/core/control.c
> > > > > >
> > > > ...
> > > > > >
> > > > > > Thus, vd->owner != file.
> > > > > >
> > > > > > As I said, it only happens on very first run of mplayer,
> > > > > > and it isn't a recent change, I think I saw it at least
> > > > > > for one year with different kernels.
> > > > > >
> > > > > > Takashi, any idea what might be happening here?
> > > > > > How can I help you more with tracking it down?
> > > > >
> > > > > This implies that another process (e.g. a sound daemon like PA)
> > > > > already opened the device and locked this specific control element.
> > > > > If so, this is no bug but the right behavior.
> > > > > Check "fuser /dev/snd/controlC*".
> > > >
> > > > Nothing uses them:
> > > >
> > > > shadow:~# lsof -nP | grep '/dev/.*control'
> > > > shadow:~# fuser /dev/snd/controlC*
> > > > shadow:~#
> > > >
> > > > I tried running bare X with only xterm and mplayer,
> > >
> > > Hm, but according to your debug session, the vd->owner is set
> > > to a different value, right? Check vd->owner_pid in the error path.
> > > It'll show the pid blocking that control element.
> >
> > I modified 2.6.31-rc2 source as follows:
> >
> > static int snd_ctl_elem_write(struct snd_card *card, struct snd_ctl_file *file,
> > struct snd_ctl_elem_value *control)
> > {
> > struct snd_kcontrol *kctl;
> > struct snd_kcontrol_volatile *vd;
> > unsigned int index_offset;
> > int result;
> >
> > down_read(&card->controls_rwsem);
> > kctl = snd_ctl_find_id(card, &control->id);
> > if (kctl == NULL) {
> > result = -ENOENT;
> > } else {
> > index_offset = snd_ctl_get_ioff(kctl, &control->id);
> > vd = &kctl->vd[index_offset];
> > if (file && vd->owner)
> > printk("file:%p vd->owner:%p\n", file, vd->owner);
> > if (!(vd->access & SNDRV_CTL_ELEM_ACCESS_WRITE) ||
> > kctl->put == NULL ||
> > (file && vd->owner && vd->owner != file)) {
> > if (file && vd->owner)
> > printk("vd->owner_pid:%d vd->owner->pid:%d file->pid:%d\n", vd->owner_pid, vd->owner->pid, file->pid);
> > result = -EPERM;
> > } else {
> > ...
> >
> > and when I start mplayer, I see this:
> >
> > dmesg:
> > file:ffff8800798af940 vd->owner:ffff8800798af940
> > file:ffff8800798af940 vd->owner:ffff8800798af940
> >
> > I assume it's some sort of initialization, no EPERM here.
> > Then I press "lower the volume" key (keypad "/")
> > in mplayer window, twice:
> >
> > dmesg:
> > file:ffff8800798af8c0 vd->owner:ffff8800798af940
> > vd->owner_pid:0 vd->owner->pid:2067 file->pid:2067
> > file:ffff8800798af740 vd->owner:ffff8800798af940
> > vd->owner_pid:0 vd->owner->pid:2067 file->pid:2067
>
> The file instances are different. It implies that mplayer opens the
> device at each time but doesn't close.
> It sounds like a bug in mplayer to me.
... or the first control handle keeps opened and blocks it.
A question is how is your PCM configuration and which control element
is locked? The latter can be seen by adding a printk of kctl->id.name.
Takashi
^ permalink raw reply [flat|nested] 9+ messages in thread
* Re: sound: -EPERM on first mplayer invocation
2009-08-05 5:41 ` Takashi Iwai
@ 2009-08-05 8:50 ` Clemens Ladisch
2009-08-05 22:00 ` Denys Vlasenko
1 sibling, 0 replies; 9+ messages in thread
From: Clemens Ladisch @ 2009-08-05 8:50 UTC (permalink / raw)
To: Takashi Iwai; +Cc: Denys Vlasenko, linux-kernel
Takashi Iwai wrote:
> I wrote:
> > The file instances are different. It implies that mplayer opens the
> > device at each time but doesn't close.
> > It sounds like a bug in mplayer to me.
>
> ... or the first control handle keeps opened and blocks it.
mplayer indeed leaks the mixer handle. This happens if setting the
volume fails, i.e., _after_ this message:
> > > > > > > alsa-control: error setting left channel, Operation not permitted
Best regards,
Clemens
^ permalink raw reply [flat|nested] 9+ messages in thread
* Re: sound: -EPERM on first mplayer invocation
2009-08-05 5:41 ` Takashi Iwai
2009-08-05 8:50 ` Clemens Ladisch
@ 2009-08-05 22:00 ` Denys Vlasenko
1 sibling, 0 replies; 9+ messages in thread
From: Denys Vlasenko @ 2009-08-05 22:00 UTC (permalink / raw)
To: Takashi Iwai, mplayer-users; +Cc: linux-kernel
[Added mplayer-users@mplayerhq.hu to To:]
On Wednesday 05 August 2009 07:41, Takashi Iwai wrote:
> At Wed, 05 Aug 2009 07:37:30 +0200,
> > > I modified 2.6.31-rc2 source as follows:
> > >
> > > static int snd_ctl_elem_write(struct snd_card *card, struct snd_ctl_file *file,
> > > struct snd_ctl_elem_value *control)
> > > {
> > > struct snd_kcontrol *kctl;
> > > struct snd_kcontrol_volatile *vd;
> > > unsigned int index_offset;
> > > int result;
> > >
> > > down_read(&card->controls_rwsem);
> > > kctl = snd_ctl_find_id(card, &control->id);
> > > if (kctl == NULL) {
> > > result = -ENOENT;
> > > } else {
> > > index_offset = snd_ctl_get_ioff(kctl, &control->id);
> > > vd = &kctl->vd[index_offset];
> > > if (file && vd->owner)
> > > printk("file:%p vd->owner:%p\n", file, vd->owner);
> > > if (!(vd->access & SNDRV_CTL_ELEM_ACCESS_WRITE) ||
> > > kctl->put == NULL ||
> > > (file && vd->owner && vd->owner != file)) {
> > > if (file && vd->owner)
> > > printk("vd->owner_pid:%d vd->owner->pid:%d file->pid:%d\n", vd->owner_pid, vd->owner->pid, file->pid);
> > > result = -EPERM;
> > > } else {
> > > ...
> > >
> > > and when I start mplayer, I see this:
> > >
> > > dmesg:
> > > file:ffff8800798af940 vd->owner:ffff8800798af940
> > > file:ffff8800798af940 vd->owner:ffff8800798af940
> > >
> > > I assume it's some sort of initialization, no EPERM here.
> > > Then I press "lower the volume" key (keypad "/")
> > > in mplayer window, twice:
> > >
> > > dmesg:
> > > file:ffff8800798af8c0 vd->owner:ffff8800798af940
> > > vd->owner_pid:0 vd->owner->pid:2067 file->pid:2067
> > > file:ffff8800798af740 vd->owner:ffff8800798af940
> > > vd->owner_pid:0 vd->owner->pid:2067 file->pid:2067
> >
> > The file instances are different. It implies that mplayer opens the
> > device at each time but doesn't close.
> > It sounds like a bug in mplayer to me.
>
> ... or the first control handle keeps opened and blocks it.
> A question is how is your PCM configuration and which control element
> is locked? The latter can be seen by adding a printk of kctl->id.name.
I see this in dmesg:
file:ffff88007d28e7c0 vd->owner:ffff88007d28e7c0 kctl->id.name:'PCM Playback Volume'
file:ffff88007d28e7c0 vd->owner:ffff88007d28e7c0 kctl->id.name:'PCM Playback Volume'
file:ffff88007d28e740 vd->owner:ffff88007d28e7c0 kctl->id.name:'PCM Playback Volume'
vd->owner_pid:0 vd->owner->pid:2086 file->pid:2086
file:ffff88007d28e5c0 vd->owner:ffff88007d28e7c0 kctl->id.name:'PCM Playback Volume'
vd->owner_pid:0 vd->owner->pid:2086 file->pid:2086
I straced mplayer. I pressed "lower the volume" key
twice within about 3 seconds, then exited mplayer.
I see this in strace (filtered using
"grep -e open -e close -e error -e /dev/ STRACE_LOG"):
...
23:38:19.825798 open("/dev/snd/controlC0", O_RDONLY) = 6
23:38:19.825951 close(6) = 0
23:38:19.826325 open("/dev/snd/controlC0", O_RDONLY) = 6
23:38:19.826445 close(6) = 0
23:38:19.826543 open("/dev/snd/controlC0", O_RDWR) = 6
23:38:19.826870 close(6) = 0
...
23:38:19.844860 open("/dev/snd/controlC0", O_RDONLY) = 6
23:38:19.844973 close(6) = 0
23:38:19.845282 open("/dev/snd/controlC0", O_RDONLY) = 6
23:38:19.845390 close(6) = 0
23:38:19.845500 open("/dev/snd/controlC0", O_RDWR) = 6
23:38:19.845797 close(6) = 0
23:38:19.855205 open("/dev/snd/controlC0", O_RDONLY) = 6
23:38:19.855338 close(6) = 0
23:38:19.855647 open("/dev/snd/controlC0", O_RDONLY) = 6
23:38:19.855755 close(6) = 0
23:38:19.855848 open("/dev/snd/controlC0", O_RDWR) = 6
23:38:19.856145 close(6) = 0
23:38:19.856323 open("/dev/snd/controlC0", O_RDONLY) = 6
23:38:19.856440 close(6) = 0
23:38:19.856762 open("/dev/snd/controlC0", O_RDONLY) = 6
23:38:19.856870 close(6) = 0
23:38:19.856964 open("/dev/snd/controlC0", O_RDWR) = 6
23:38:19.857257 close(6) = 0
23:38:19.857442 open("/dev/snd/controlC0", O_RDONLY) = 6
23:38:19.857549 close(6) = 0
23:38:19.857836 open("/dev/snd/controlC0", O_RDONLY) = 6
23:38:19.857943 close(6) = 0
23:38:19.858038 open("/dev/snd/controlC0", O_RDWR) = 6
23:38:19.858329 close(6) = 0
...
23:38:19.874866 open("/dev/snd/controlC0", O_RDONLY) = 6
23:38:19.874977 close(6) = 0
23:38:19.876461 open("/dev/snd/controlC0", O_RDONLY) = 6
23:38:19.876574 close(6) = 0
23:38:19.876675 open("/dev/snd/controlC0", O_RDWR) = 6
23:38:19.876977 open("/dev/snd/pcmC0D0p", O_RDWR|O_NONBLOCK) = 7
23:38:19.877202 close(6) = 0
23:38:19.891060 open("/dev/snd/controlC0", O_RDONLY) = 6
23:38:19.891177 close(6) = 0
23:38:19.891278 open("/dev/snd/timer", O_RDONLY|O_NONBLOCK) = 6
23:38:19.891781 open("/proc/cpuinfo", O_RDONLY) = 8
23:38:19.892409 close(8) = 0
23:38:19.892727 open("/dev/snd/controlC0", O_RDONLY) = 8
23:38:19.892834 close(8) = 0
23:38:19.893166 open("/dev/snd/controlC0", O_RDONLY) = 8
23:38:19.893274 close(8) = 0
23:38:19.893369 open("/dev/snd/controlC0", O_RDWR) = 8
23:38:19.894819 write(1, "alsa-init: pcm opend in blocking"..., 38) = 38
...
...
Here I press "lower the volume" key:
23:38:28.343401 open("/dev/snd/controlC0", O_RDONLY) = 9
23:38:28.343530 close(9) = 0
23:38:28.343630 open("/dev/snd/controlC0", O_RDWR) = 9
23:38:28.354506 close(9) = 0
23:38:28.354908 open("/dev/snd/controlC0", O_RDONLY) = 9
23:38:28.355024 close(9) = 0
23:38:28.355119 open("/dev/snd/controlC0", O_RDWR) = 9
23:38:28.365707 write(2, "alsa-control: error setting left"..., 66) = 66
23:38:28.367310 open("/dev/snd/controlC0", O_RDONLY) = 10
23:38:28.367427 close(10) = 0
23:38:28.367539 open("/dev/snd/controlC0", O_RDWR) = 10
23:38:28.381267 close(10) = 0
And again:
23:38:31.503361 open("/dev/snd/controlC0", O_RDONLY) = 10
23:38:31.503489 close(10) = 0
23:38:31.503589 open("/dev/snd/controlC0", O_RDWR) = 10
23:38:31.514280 close(10) = 0
23:38:31.514690 open("/dev/snd/controlC0", O_RDONLY) = 10
23:38:31.514805 close(10) = 0
23:38:31.514899 open("/dev/snd/controlC0", O_RDWR) = 10
23:38:31.525305 write(2, "alsa-control: error setting left"..., 66) = 66
23:38:31.526167 open("/dev/snd/controlC0", O_RDONLY) = 11
23:38:31.526283 close(11) = 0
23:38:31.526382 open("/dev/snd/controlC0", O_RDWR) = 11
23:38:31.539630 close(11) = 0
I press ESC:
23:38:34.385307 close(3) = 0
23:38:34.403561 close(6) = 0
23:38:34.403883 close(7) = 0
23:38:34.404767 close(8) = 0
23:38:34.404921 write(1, "alsa-uninit: pcm closed\n", 24) = 24
23:38:34.405961 close(5) = 0
Obviously, mplayer forgets to close fds opened to /dev/snd/controlC0:
first, fd 8; it opens a new one (fd 9) and gets error out of it.
Then, after 1st error, it similarly does not close or reuse fd 9
but opens fd 10.
For mplayer folks: my ~/.mplayer/config is:
msglevel=all=6
ao=alsa
monitoraspect=5:4
And command line is just:
mplayer The_league_of_extraordinary_gentlemen.avi
For completeness, here is unabridged strace from the moment
I press "\" for the 1st time until -EPERM is seen:
23:38:28.342959 read(0, "/", 256) = 1
23:38:28.343136 stat64("/usr/app/alsa-lib-1.0.17a/share/alsa/alsa.conf", {st_mode=S_IFREG|0644, st_size=9008, ...}) = 0
23:38:28.343401 open("/dev/snd/controlC0", O_RDONLY) = 9
23:38:28.343530 close(9) = 0
23:38:28.343630 open("/dev/snd/controlC0", O_RDWR) = 9
23:38:28.343736 ioctl(9, USBDEVFS_CONTROL, 0xffd31984) = 0
23:38:28.343846 fcntl64(9, F_GETFL) = 0x2 (flags O_RDWR)
23:38:28.343984 fcntl64(9, F_SETFL, O_RDWR|O_NONBLOCK) = 0
23:38:28.344112 ioctl(9, USBDEVFS_RELEASEINTERFACE, 0xffd31a00) = 0
23:38:28.344214 ioctl(9, USBDEVFS_RELEASEINTERFACE, 0xffd31a00) = 0
23:38:28.344461 ioctl(9, USBDEVFS_CONNECTINFO, 0xffd31760) = 0
23:38:28.344606 ioctl(9, USBDEVFS_IOCTL, 0xffd31330) = 0
23:38:28.344713 ioctl(9, USBDEVFS_CONNECTINFO, 0xffd31760) = 0
23:38:28.344819 ioctl(9, USBDEVFS_IOCTL, 0xffd31320) = 0
23:38:28.344916 ioctl(9, USBDEVFS_IOCTL, 0xffd31330) = 0
23:38:28.345013 ioctl(9, USBDEVFS_CONNECTINFO, 0xffd31760) = 0
23:38:28.345127 ioctl(9, USBDEVFS_IOCTL, 0xffd31330) = 0
23:38:28.345226 ioctl(9, USBDEVFS_CONNECTINFO, 0xffd31760) = 0
23:38:28.345326 ioctl(9, USBDEVFS_IOCTL, 0xffd31320) = 0
23:38:28.345425 ioctl(9, USBDEVFS_CONNECTINFO, 0xffd31760) = 0
23:38:28.345535 ioctl(9, USBDEVFS_IOCTL, 0xffd31320) = 0
23:38:28.345633 ioctl(9, USBDEVFS_IOCTL, 0xffd31320) = 0
23:38:28.345730 ioctl(9, USBDEVFS_CONNECTINFO, 0xffd31760) = 0
23:38:28.345830 ioctl(9, USBDEVFS_IOCTL, 0xffd31330) = 0
23:38:28.345928 ioctl(9, USBDEVFS_CONNECTINFO, 0xffd31760) = 0
23:38:28.346026 ioctl(9, USBDEVFS_IOCTL, 0xffd31320) = 0
23:38:28.346123 ioctl(9, USBDEVFS_IOCTL, 0xffd31330) = 0
23:38:28.346220 ioctl(9, USBDEVFS_CONNECTINFO, 0xffd31760) = 0
23:38:28.346319 ioctl(9, USBDEVFS_IOCTL, 0xffd31330) = 0
23:38:28.346417 ioctl(9, USBDEVFS_CONNECTINFO, 0xffd31760) = 0
23:38:28.346524 ioctl(9, USBDEVFS_IOCTL, 0xffd31320) = 0
23:38:28.346620 ioctl(9, USBDEVFS_IOCTL, 0xffd31330) = 0
23:38:28.346717 ioctl(9, USBDEVFS_CONNECTINFO, 0xffd31760) = 0
23:38:28.346816 ioctl(9, USBDEVFS_IOCTL, 0xffd31330) = 0
23:38:28.346914 ioctl(9, USBDEVFS_CONNECTINFO, 0xffd31760) = 0
23:38:28.347012 ioctl(9, USBDEVFS_IOCTL, 0xffd31320) = 0
23:38:28.347108 ioctl(9, USBDEVFS_IOCTL, 0xffd31330) = 0
23:38:28.347205 ioctl(9, USBDEVFS_CONNECTINFO, 0xffd31760) = 0
23:38:28.347304 ioctl(9, USBDEVFS_IOCTL, 0xffd31330) = 0
23:38:28.347402 ioctl(9, USBDEVFS_CONNECTINFO, 0xffd31760) = 0
23:38:28.347508 ioctl(9, USBDEVFS_IOCTL, 0xffd31320) = 0
23:38:28.347604 ioctl(9, USBDEVFS_IOCTL, 0xffd31330) = 0
23:38:28.347701 ioctl(9, USBDEVFS_CONNECTINFO, 0xffd31760) = 0
23:38:28.347800 ioctl(9, USBDEVFS_IOCTL, 0xffd31330) = 0
23:38:28.347898 ioctl(9, USBDEVFS_CONNECTINFO, 0xffd31760) = 0
23:38:28.347996 ioctl(9, USBDEVFS_IOCTL, 0xffd31320) = 0
23:38:28.348092 ioctl(9, USBDEVFS_IOCTL, 0xffd31330) = 0
23:38:28.348188 ioctl(9, USBDEVFS_CONNECTINFO, 0xffd31760) = 0
23:38:28.348288 ioctl(9, USBDEVFS_IOCTL, 0xffd31330) = 0
23:38:28.348387 ioctl(9, USBDEVFS_CONNECTINFO, 0xffd31760) = 0
23:38:28.348493 ioctl(9, USBDEVFS_IOCTL, 0xffd31320) = 0
23:38:28.348590 ioctl(9, USBDEVFS_IOCTL, 0xffd31330) = 0
23:38:28.348687 ioctl(9, USBDEVFS_CONNECTINFO, 0xffd31760) = 0
23:38:28.348787 ioctl(9, USBDEVFS_IOCTL, 0xffd31330) = 0
23:38:28.348885 ioctl(9, USBDEVFS_CONNECTINFO, 0xffd31760) = 0
23:38:28.348982 ioctl(9, USBDEVFS_IOCTL, 0xffd31320) = 0
23:38:28.349079 ioctl(9, USBDEVFS_IOCTL, 0xffd31330) = 0
23:38:28.349176 ioctl(9, USBDEVFS_CONNECTINFO, 0xffd31760) = 0
23:38:28.349277 ioctl(9, USBDEVFS_IOCTL, 0xffd31320) = 0
23:38:28.349373 ioctl(9, USBDEVFS_IOCTL, 0xffd31320) = 0
23:38:28.349479 ioctl(9, USBDEVFS_CONNECTINFO, 0xffd31760) = 0
23:38:28.349579 ioctl(9, USBDEVFS_IOCTL, 0xffd31330) = 0
23:38:28.349677 ioctl(9, USBDEVFS_CONNECTINFO, 0xffd31760) = 0
23:38:28.349775 ioctl(9, USBDEVFS_IOCTL, 0xffd31320) = 0
23:38:28.349872 ioctl(9, USBDEVFS_IOCTL, 0xffd31330) = 0
23:38:28.349969 ioctl(9, USBDEVFS_CONNECTINFO, 0xffd31760) = 0
23:38:28.350069 ioctl(9, USBDEVFS_IOCTL, 0xffd31330) = 0
23:38:28.350169 ioctl(9, USBDEVFS_CONNECTINFO, 0xffd31760) = 0
23:38:28.350269 ioctl(9, USBDEVFS_IOCTL, 0xffd31330) = 0
23:38:28.350368 ioctl(9, USBDEVFS_CONNECTINFO, 0xffd31760) = 0
23:38:28.350475 ioctl(9, USBDEVFS_IOCTL, 0xffd31320) = 0
23:38:28.350573 ioctl(9, USBDEVFS_IOCTL, 0xffd31330) = 0
23:38:28.350670 ioctl(9, USBDEVFS_CONNECTINFO, 0xffd31760) = 0
23:38:28.350769 ioctl(9, USBDEVFS_IOCTL, 0xffd31320) = 0
23:38:28.350866 ioctl(9, USBDEVFS_IOCTL, 0xffd31330) = 0
23:38:28.350990 ioctl(9, USBDEVFS_CONNECTINFO, 0xffd31760) = 0
23:38:28.351091 ioctl(9, USBDEVFS_IOCTL, 0xffd31330) = 0
23:38:28.351190 ioctl(9, USBDEVFS_CONNECTINFO, 0xffd31760) = 0
23:38:28.351286 ioctl(9, USBDEVFS_CONNECTINFO, 0xffd31760) = 0
23:38:28.351381 ioctl(9, USBDEVFS_CONNECTINFO, 0xffd31760) = 0
23:38:28.351486 ioctl(9, USBDEVFS_CONNECTINFO, 0xffd31760) = 0
23:38:28.351586 ioctl(9, USBDEVFS_IOCTL, 0xffd31330) = 0
23:38:28.351685 ioctl(9, USBDEVFS_CONNECTINFO, 0xffd31760) = 0
23:38:28.351780 ioctl(9, USBDEVFS_CONNECTINFO, 0xffd31760) = 0
23:38:28.351878 ioctl(9, USBDEVFS_IOCTL, 0xffd31330) = 0
23:38:28.351975 ioctl(9, USBDEVFS_IOCTL, 0xffd31330) = 0
23:38:28.352072 ioctl(9, USBDEVFS_CONNECTINFO, 0xffd31760) = 0
23:38:28.352173 ioctl(9, USBDEVFS_IOCTL, 0xffd31330) = 0
23:38:28.352271 ioctl(9, USBDEVFS_CONNECTINFO, 0xffd31760) = 0
23:38:28.352369 ioctl(9, USBDEVFS_IOCTL, 0xffd31320) = 0
23:38:28.353085 ioctl(9, USBDEVFS_IOCTL, 0xffd31330) = 0
23:38:28.353208 ioctl(9, USBDEVFS_CONNECTINFO, 0xffd31760) = 0
23:38:28.353330 ioctl(9, USBDEVFS_IOCTL, 0xffd31330) = 0
23:38:28.353450 ioctl(9, USBDEVFS_CONNECTINFO, 0xffd31760) = 0
23:38:28.353554 ioctl(9, USBDEVFS_IOCTL, 0xffd31330) = 0
23:38:28.353653 ioctl(9, USBDEVFS_CONNECTINFO, 0xffd31760) = 0
23:38:28.353754 ioctl(9, USBDEVFS_IOCTL, 0xffd31330) = 0
23:38:28.353852 ioctl(9, USBDEVFS_CONNECTINFO, 0xffd31760) = 0
23:38:28.353953 ioctl(9, USBDEVFS_IOCTL, 0xffd31330) = 0
23:38:28.354052 ioctl(9, USBDEVFS_CONNECTINFO, 0xffd31760) = 0
23:38:28.354151 ioctl(9, USBDEVFS_IOCTL, 0xffd31320) = 0
23:38:28.354248 ioctl(9, USBDEVFS_IOCTL, 0xffd31330) = 0
23:38:28.354348 ioctl(9, USBDEVFS_DISCONNECT, 0xffd319e8) = 0
23:38:28.354506 close(9) = 0
23:38:28.354639 stat64("/usr/app/alsa-lib-1.0.17a/share/alsa/alsa.conf", {st_mode=S_IFREG|0644, st_size=9008, ...}) = 0
23:38:28.354908 open("/dev/snd/controlC0", O_RDONLY) = 9
23:38:28.355024 close(9) = 0
23:38:28.355119 open("/dev/snd/controlC0", O_RDWR) = 9
23:38:28.355226 ioctl(9, USBDEVFS_CONTROL, 0xffd31924) = 0
23:38:28.355321 fcntl64(9, F_GETFL) = 0x2 (flags O_RDWR)
23:38:28.355415 fcntl64(9, F_SETFL, O_RDWR|O_NONBLOCK) = 0
23:38:28.355519 ioctl(9, USBDEVFS_RELEASEINTERFACE, 0xffd319a0) = 0
23:38:28.355620 ioctl(9, USBDEVFS_RELEASEINTERFACE, 0xffd319a0) = 0
23:38:28.355811 ioctl(9, USBDEVFS_CONNECTINFO, 0xffd31700) = 0
23:38:28.355913 ioctl(9, USBDEVFS_IOCTL, 0xffd312d0) = 0
23:38:28.356013 ioctl(9, USBDEVFS_CONNECTINFO, 0xffd31700) = 0
23:38:28.356111 ioctl(9, USBDEVFS_IOCTL, 0xffd312c0) = 0
23:38:28.356208 ioctl(9, USBDEVFS_IOCTL, 0xffd312d0) = 0
23:38:28.356304 ioctl(9, USBDEVFS_CONNECTINFO, 0xffd31700) = 0
23:38:28.356404 ioctl(9, USBDEVFS_IOCTL, 0xffd312d0) = 0
23:38:28.356511 ioctl(9, USBDEVFS_CONNECTINFO, 0xffd31700) = 0
23:38:28.356610 ioctl(9, USBDEVFS_IOCTL, 0xffd312c0) = 0
23:38:28.356709 ioctl(9, USBDEVFS_CONNECTINFO, 0xffd31700) = 0
23:38:28.356809 ioctl(9, USBDEVFS_IOCTL, 0xffd312c0) = 0
23:38:28.356906 ioctl(9, USBDEVFS_IOCTL, 0xffd312c0) = 0
23:38:28.357003 ioctl(9, USBDEVFS_CONNECTINFO, 0xffd31700) = 0
23:38:28.357104 ioctl(9, USBDEVFS_IOCTL, 0xffd312d0) = 0
23:38:28.357203 ioctl(9, USBDEVFS_CONNECTINFO, 0xffd31700) = 0
23:38:28.357301 ioctl(9, USBDEVFS_IOCTL, 0xffd312c0) = 0
23:38:28.357398 ioctl(9, USBDEVFS_IOCTL, 0xffd312d0) = 0
23:38:28.357504 ioctl(9, USBDEVFS_CONNECTINFO, 0xffd31700) = 0
23:38:28.357604 ioctl(9, USBDEVFS_IOCTL, 0xffd312d0) = 0
23:38:28.357702 ioctl(9, USBDEVFS_CONNECTINFO, 0xffd31700) = 0
23:38:28.357800 ioctl(9, USBDEVFS_IOCTL, 0xffd312c0) = 0
23:38:28.357897 ioctl(9, USBDEVFS_IOCTL, 0xffd312d0) = 0
23:38:28.357993 ioctl(9, USBDEVFS_CONNECTINFO, 0xffd31700) = 0
23:38:28.358093 ioctl(9, USBDEVFS_IOCTL, 0xffd312d0) = 0
23:38:28.358191 ioctl(9, USBDEVFS_CONNECTINFO, 0xffd31700) = 0
23:38:28.358289 ioctl(9, USBDEVFS_IOCTL, 0xffd312c0) = 0
23:38:28.358385 ioctl(9, USBDEVFS_IOCTL, 0xffd312d0) = 0
23:38:28.358490 ioctl(9, USBDEVFS_CONNECTINFO, 0xffd31700) = 0
23:38:28.358590 ioctl(9, USBDEVFS_IOCTL, 0xffd312d0) = 0
23:38:28.358689 ioctl(9, USBDEVFS_CONNECTINFO, 0xffd31700) = 0
23:38:28.358824 ioctl(9, USBDEVFS_IOCTL, 0xffd312c0) = 0
23:38:28.358921 ioctl(9, USBDEVFS_IOCTL, 0xffd312d0) = 0
23:38:28.359018 ioctl(9, USBDEVFS_CONNECTINFO, 0xffd31700) = 0
23:38:28.359117 ioctl(9, USBDEVFS_IOCTL, 0xffd312d0) = 0
23:38:28.359215 ioctl(9, USBDEVFS_CONNECTINFO, 0xffd31700) = 0
23:38:28.359313 ioctl(9, USBDEVFS_IOCTL, 0xffd312c0) = 0
23:38:28.359410 ioctl(9, USBDEVFS_IOCTL, 0xffd312d0) = 0
23:38:28.359515 ioctl(9, USBDEVFS_CONNECTINFO, 0xffd31700) = 0
23:38:28.359631 ioctl(9, USBDEVFS_IOCTL, 0xffd312d0) = 0
23:38:28.359730 ioctl(9, USBDEVFS_CONNECTINFO, 0xffd31700) = 0
23:38:28.359827 ioctl(9, USBDEVFS_IOCTL, 0xffd312c0) = 0
23:38:28.359924 ioctl(9, USBDEVFS_IOCTL, 0xffd312d0) = 0
23:38:28.360021 ioctl(9, USBDEVFS_CONNECTINFO, 0xffd31700) = 0
23:38:28.360121 ioctl(9, USBDEVFS_IOCTL, 0xffd312d0) = 0
23:38:28.360220 ioctl(9, USBDEVFS_CONNECTINFO, 0xffd31700) = 0
23:38:28.360317 ioctl(9, USBDEVFS_IOCTL, 0xffd312c0) = 0
23:38:28.360414 ioctl(9, USBDEVFS_IOCTL, 0xffd312d0) = 0
23:38:28.360521 ioctl(9, USBDEVFS_CONNECTINFO, 0xffd31700) = 0
23:38:28.360622 ioctl(9, USBDEVFS_IOCTL, 0xffd312c0) = 0
23:38:28.360719 ioctl(9, USBDEVFS_IOCTL, 0xffd312c0) = 0
23:38:28.360816 ioctl(9, USBDEVFS_CONNECTINFO, 0xffd31700) = 0
23:38:28.360916 ioctl(9, USBDEVFS_IOCTL, 0xffd312d0) = 0
23:38:28.361014 ioctl(9, USBDEVFS_CONNECTINFO, 0xffd31700) = 0
23:38:28.361112 ioctl(9, USBDEVFS_IOCTL, 0xffd312c0) = 0
23:38:28.361209 ioctl(9, USBDEVFS_IOCTL, 0xffd312d0) = 0
23:38:28.361307 ioctl(9, USBDEVFS_CONNECTINFO, 0xffd31700) = 0
23:38:28.361407 ioctl(9, USBDEVFS_IOCTL, 0xffd312d0) = 0
23:38:28.361515 ioctl(9, USBDEVFS_CONNECTINFO, 0xffd31700) = 0
23:38:28.361616 ioctl(9, USBDEVFS_IOCTL, 0xffd312d0) = 0
23:38:28.361715 ioctl(9, USBDEVFS_CONNECTINFO, 0xffd31700) = 0
23:38:28.361814 ioctl(9, USBDEVFS_IOCTL, 0xffd312c0) = 0
23:38:28.361971 ioctl(9, USBDEVFS_IOCTL, 0xffd312d0) = 0
23:38:28.362069 ioctl(9, USBDEVFS_CONNECTINFO, 0xffd31700) = 0
23:38:28.362169 ioctl(9, USBDEVFS_IOCTL, 0xffd312c0) = 0
23:38:28.362266 ioctl(9, USBDEVFS_IOCTL, 0xffd312d0) = 0
23:38:28.362363 ioctl(9, USBDEVFS_CONNECTINFO, 0xffd31700) = 0
23:38:28.362473 ioctl(9, USBDEVFS_IOCTL, 0xffd312d0) = 0
23:38:28.362572 ioctl(9, USBDEVFS_CONNECTINFO, 0xffd31700) = 0
23:38:28.362668 ioctl(9, USBDEVFS_CONNECTINFO, 0xffd31700) = 0
23:38:28.362914 ioctl(9, USBDEVFS_CONNECTINFO, 0xffd31700) = 0
23:38:28.363010 ioctl(9, USBDEVFS_CONNECTINFO, 0xffd31700) = 0
23:38:28.363112 ioctl(9, USBDEVFS_IOCTL, 0xffd312d0) = 0
23:38:28.363211 ioctl(9, USBDEVFS_CONNECTINFO, 0xffd31700) = 0
23:38:28.363307 ioctl(9, USBDEVFS_CONNECTINFO, 0xffd31700) = 0
23:38:28.363405 ioctl(9, USBDEVFS_IOCTL, 0xffd312d0) = 0
23:38:28.363511 ioctl(9, USBDEVFS_IOCTL, 0xffd312d0) = 0
23:38:28.363608 ioctl(9, USBDEVFS_CONNECTINFO, 0xffd31700) = 0
23:38:28.363744 ioctl(9, USBDEVFS_IOCTL, 0xffd312d0) = 0
23:38:28.363844 ioctl(9, USBDEVFS_CONNECTINFO, 0xffd31700) = 0
23:38:28.363943 ioctl(9, USBDEVFS_IOCTL, 0xffd312c0) = 0
23:38:28.364040 ioctl(9, USBDEVFS_IOCTL, 0xffd312d0) = 0
23:38:28.364138 ioctl(9, USBDEVFS_CONNECTINFO, 0xffd31700) = 0
23:38:28.364242 ioctl(9, USBDEVFS_IOCTL, 0xffd312d0) = 0
23:38:28.364342 ioctl(9, USBDEVFS_CONNECTINFO, 0xffd31700) = 0
23:38:28.364453 ioctl(9, USBDEVFS_IOCTL, 0xffd312d0) = 0
23:38:28.364552 ioctl(9, USBDEVFS_CONNECTINFO, 0xffd31700) = 0
23:38:28.364652 ioctl(9, USBDEVFS_IOCTL, 0xffd312d0) = 0
23:38:28.364750 ioctl(9, USBDEVFS_CONNECTINFO, 0xffd31700) = 0
23:38:28.364850 ioctl(9, USBDEVFS_IOCTL, 0xffd312d0) = 0
23:38:28.364948 ioctl(9, USBDEVFS_CONNECTINFO, 0xffd31700) = 0
23:38:28.365046 ioctl(9, USBDEVFS_IOCTL, 0xffd312c0) = 0
23:38:28.365143 ioctl(9, USBDEVFS_IOCTL, 0xffd312d0) = 0
23:38:28.365238 ioctl(9, USBDEVFS_DISCONNECT, 0xffd31988) = 0
23:38:28.365343 ioctl(9, USBDEVFS_IOCTL, 0xffd316b0) = 0
23:38:28.365456 ioctl(9, USBDEVFS_HUB_PORTINFO, 0xffd316b0) = -1 EPERM (Operation not permitted)
23:38:28.365565 ioctl(9, USBDEVFS_IOCTL, 0xffd315b0) = 0
23:38:28.365707 write(2, "alsa-control: error setting left"..., 66) = 66
--
vda
^ permalink raw reply [flat|nested] 9+ messages in thread
end of thread, other threads:[~2009-08-05 21:59 UTC | newest]
Thread overview: 9+ messages (download: mbox.gz follow: Atom feed
-- links below jump to the message on this page --
2009-08-02 21:36 sound: -EPERM on first mplayer invocation Denys Vlasenko
2009-08-03 6:55 ` Takashi Iwai
2009-08-04 9:01 ` Denys Vlasenko
2009-08-04 9:16 ` Takashi Iwai
2009-08-05 2:32 ` Denys Vlasenko
2009-08-05 5:37 ` Takashi Iwai
2009-08-05 5:41 ` Takashi Iwai
2009-08-05 8:50 ` Clemens Ladisch
2009-08-05 22:00 ` Denys Vlasenko
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox