[alsa-devel] BugReport: Dice works partially [Broken]
Stanislav Sergiienko
pythonpowerd at gmail.com
Sun Aug 16 00:13:51 CEST 2015
Hi, I did all you asked exactly step by step, and after that, even
more. Linux kernel == 4.1.4
This was printed by dmesg when I plugged card after reboot:
...
[ 53.654603] cfg80211: Calling CRDA to update world regulatory domain
[ 56.802735] cfg80211: Exceeded CRDA call max attempts. Not calling CRDA
[ 163.474535] firewire_core 0000:0a:00.0: phy config: new root=ffc1,
gap_count=5
[ 165.633183] firewire_core 0000:0a:00.0: created device fw1: GUID
000166040900328d, S400
[ 165.635721] firewire_core 0000:0a:00.0: phy config: new root=ffc1,
gap_count=5
[ 165.979725] firewire_core 0000:0a:00.0: giving up on node ffc0:
reading config rom failed: timeout
[ 167.640492] firewire_core 0000:0a:00.0: BM lock failed (timeout),
making local node (ffc0) root
[ 167.640496] firewire_core 0000:0a:00.0: phy config: new root=ffc0,
gap_count=5
This after modprobe (kde played notification sound on this command):
cat /proc/asound/DesktopKonnekt6/dice
sections:
global: offset 10, size 90
tx: offset 100, size 142
rx: offset 242, size 282
ext_sync: offset 524, size 4
unused2: offset 0, size 0
global:
owner: ffc1:000100000000
notification: 00000040
nick name: DesktopKonnekt6
clock select: internal 48000
enable: 0
status: locked 48000
ext status: 00000000
sample rate: 48000
version: 1.0.4.0
clock caps: 44100 48000 88200 96000 176400 192000 arx1 arx2 internal
clock source names:
Unused\Unused\Unused\Unused\Unused\Unused\Unused\Unused\Unused\Unused\Unused\Unused\INTERNAL\\
tx 0:
iso channel: -1
audio channels: 6
midi ports: 0
speed: S400
names: ch 1\ch 2\ - \ - \ - \ - \\
ac3 caps: 00000000
ac3 enable: 00000000
rx 0:
iso channel: -1
sequence start: 0
audio channels: 6
midi ports: 0
names: main out 1\main out 2\phones out 1\phones out 2\ - \ - \\
ac3 caps: 00000000
ac3 enable: 00000000
ext status:
clock source: internal
locked: 1
rate: 48000
adat user data: 0
aplay -v ./test.wav
Playing WAVE './test.wav' : Signed 16 bit Little Endian, Rate 44100 Hz, Stereo
Plug PCM: Route conversion PCM (sformat=S16_LE)
Transformation table:
0 <- 0
1 <- 1
2 <- none
3 <- none
4 <- none
5 <- none
Its setup is:
stream : PLAYBACK
access : RW_INTERLEAVED
format : S16_LE
subformat : STD
channels : 2
rate : 44100
exact rate : 44100 (44100/1)
msbits : 16
buffer_size : 8192
period_size : 1536
period_time : 34829
tstamp_mode : NONE
tstamp_type : MONOTONIC
period_step : 1
avail_min : 1536
period_event : 0
start_threshold : 8192
stop_threshold : 8192
silence_threshold: 0
silence_size : 0
boundary : 4611686018427387904
Slave: Hardware PCM card 0 'DesktopKonnekt6' device 0 subdevice 0
Its setup is:
stream : PLAYBACK
access : MMAP_INTERLEAVED
format : S16_LE
subformat : STD
channels : 6
rate : 44100
exact rate : 44100 (44100/1)
msbits : 16
buffer_size : 8192
period_size : 1536
period_time : 34829
tstamp_mode : NONE
tstamp_type : MONOTONIC
period_step : 1
avail_min : 1536
period_event : 0
start_threshold : 8192
stop_threshold : 8192
silence_threshold: 0
silence_size : 0
boundary : 4611686018427387904
appl_ptr : 0
hw_ptr : 0
^CAborted by signal Прерывание...
aplay: pcm_write:1939: write error: Прерван системный вызов
aplay freezes randomly and prints NO ERRORS. Same with pulseaudio, i
tried even pulseaudio -v --log-level=4 (huge output) but no errors
when playing stopped.
I have try to set various sample size format and clock rate, same results.
After that I even use python lib
https://github.com/larsimmisch/pyalsaaudio/ to debug tiny program that
plays .wav. I tried to see where exactly was error, and found that no
errors is occured, program always blocked here:
...
while data:
y = device.write(data) # blocked here
print('WRITTEN=', y)
...
That's why there is no errors in any programs.
Then I remember about strace:
strace -i -v -T -y -yy aplay ./test.wav
[00007f2b604db18d] poll([{fd=4</dev/snd/pcmC0D0p>,
events=POLLOUT|POLLERR|POLLNVAL}], 1, 4294967295) = 1 ([{fd=4,
revents=POLLOUT}]) <0.033380>
[00007f2b604dc797] ioctl(4</dev/snd/pcmC0D0p>, SNDRV_PCM_IOCTL_HWSYNC,
0x7f2b60a13cf0) = 0 <0.000056>
[00007f2b607aefad] read(3</home/stas/test.wav>,
"N\0\0\0024\0\31\2\306\0^\2\36\1~\2\301\0\350\1\330\0\331\1\277\0d\1$\1{\1"...,
6144) = 6144 <0.000067>
[00007f2b604dc797] ioctl(4</dev/snd/pcmC0D0p>, SNDRV_PCM_IOCTL_HWSYNC,
0x7f2b60a13cf0) = 0 <0.000058>
[00007f2b604db18d] poll([{fd=4</dev/snd/pcmC0D0p>,
events=POLLOUT|POLLERR|POLLNVAL}], 1, 4294967295) = 1 ([{fd=4,
revents=POLLOUT}]) <0.035439>
[00007f2b604dc797] ioctl(4</dev/snd/pcmC0D0p>, SNDRV_PCM_IOCTL_HWSYNC,
0x7f2b60a13cf0) = 0 <0.000030>
[00007f2b607aefad] read(3</home/stas/test.wav>,
"\267\373\225\372\225\373Q\372U\373\342\371,\373\273\371\276\372?\371\340\3729\371\23\372\230\370\326\372F\371"...,
6144) = 6144 <0.000051>
[00007f2b604dc797] ioctl(4</dev/snd/pcmC0D0p>, SNDRV_PCM_IOCTL_HWSYNC,
0x7f2b60a13cf0) = 0 <0.000066>
[00007f2b604db18d] poll([{fd=4</dev/snd/pcmC0D0p>,
events=POLLOUT|POLLERR|POLLNVAL}], 1, 4294967295) = 1 ([{fd=4,
revents=POLLOUT}]) <0.033301>
[00007f2b604dc797] ioctl(4</dev/snd/pcmC0D0p>, SNDRV_PCM_IOCTL_HWSYNC,
0x7f2b60a13cf0) = 0 <0.000079>
[00007f2b607aefad] read(3</home/stas/test.wav>,
"_\1\313\377_\2\230\0\36\6\212\4\270\7\234\6\360\6f\0061\6o\5\362\2q\2t\0\3\0"...,
6144) = 6144 <0.000107>
[00007f2b604dc797] ioctl(4</dev/snd/pcmC0D0p>, SNDRV_PCM_IOCTL_HWSYNC,
0x7f2b60a13cf0) = 0 <0.000080>
[00007f2b604db18d] poll([{fd=4</dev/snd/pcmC0D0p>,
events=POLLOUT|POLLERR|POLLNVAL}], 1, 4294967295) = 1 ([{fd=4,
revents=POLLOUT}]) <0.033154>
[00007f2b604dc797] ioctl(4</dev/snd/pcmC0D0p>, SNDRV_PCM_IOCTL_HWSYNC,
0x7f2b60a13cf0) = 0 <0.000093>
[00007f2b607aefad] read(3</home/stas/test.wav>,
"\354\1W\5-\1\266\4t\377\1\3Y\376\330\1E\376\267\1\222\376\350\1<\377u\2\251\377\364\2"...,
6144) = 6144 <0.000081>
[00007f2b604dc797] ioctl(4</dev/snd/pcmC0D0p>, SNDRV_PCM_IOCTL_HWSYNC,
0x7f2b60a13cf0) = 0 <0.000033>
[00007f2b604db18d] poll([{fd=4</dev/snd/pcmC0D0p>,
events=POLLOUT|POLLERR|POLLNVAL}], 1, 4294967295) = 1 ([{fd=4,
revents=POLLOUT}]) <0.035188>
[00007f2b604dc797] ioctl(4</dev/snd/pcmC0D0p>, SNDRV_PCM_IOCTL_HWSYNC,
0x7f2b60a13cf0) = 0 <0.000087>
[00007f2b607aefad] read(3</home/stas/test.wav>,
"\306\350\353\346>\351I\347>\351\25\347\325\350\370\346v\346\372\344\317\343\205\342(\343O\342V\343\220\342"...,
6144) = 6144 <0.000090>
[00007f2b604dc797] ioctl(4</dev/snd/pcmC0D0p>, SNDRV_PCM_IOCTL_HWSYNC,
0x7f2b60a13cf0) = 0 <0.000089>
[00007f2b604db18d] poll([{fd=4</dev/snd/pcmC0D0p>,
events=POLLOUT|POLLERR|POLLNVAL}], 1, 4294967295) = 1 ([{fd=4,
revents=POLLOUT}]) <0.034704>
[00007f2b604dc797] ioctl(4</dev/snd/pcmC0D0p>, SNDRV_PCM_IOCTL_HWSYNC,
0x7f2b60a13cf0) = 0 <0.000083>
[00007f2b607aefad] read(3</home/stas/test.wav>,
"E\27\330\26>\32\320\31a\32F\31e\31\372\27\336\30t\27x\31\254\27\352\31\372\27\17\32)\30"...,
6144) = 6144 <0.000085>
[00007f2b604dc797] ioctl(4</dev/snd/pcmC0D0p>, SNDRV_PCM_IOCTL_HWSYNC,
0x7f2b60a13cf0) = 0 <0.000049>
[00007f2b604db18d] poll([{fd=4</dev/snd/pcmC0D0p>,
events=POLLOUT|POLLERR|POLLNVAL}], 1, 4294967295 #
sound stops play here and program blocks
Same aplay but through pulseaudio:
[00007f3f7fa56fad] read(3<pipe:[76277]>, 0x7ffda627a910, 10) = -1
EAGAIN (Resource temporarily unavailable)
[00007f3f7fa51f07] futex(0x1fd17d0, FUTEX_UNLOCK_PI_PRIVATE, 0) = 0
[00007f3f7fa56fad] read(8</home/stas/test.wav>,
"i\10\200\7D\4\317\0023\4w\2\346\5/\4\307\6\373\4\177\6\344\4l\4\371\2\241\375\227\374"...,
22048) = 22048
[00007f3f7f78318d] poll([{fd=3<pipe:[76277]>,
events=POLLIN|POLLERR|POLLNVAL}], 1, 4294967295) = 1 ([{fd=3,
revents=POLLIN}])
[00007f3f7fa56f4d] write(6<pipe:[76278]>, "W", 1) = 1
[00007f3f7fa56fad] read(3<pipe:[76277]>, "x", 10) = 1
[00007f3f7fa56fad] read(3<pipe:[76277]>, 0x7ffda627a910, 10) = -1
EAGAIN (Resource temporarily unavailable)
[00007f3f7fa51f07] futex(0x1fd17d0, FUTEX_UNLOCK_PI_PRIVATE, 0) = 0
[00007f3f7fa56fad] read(8</home/stas/test.wav>,
"g\350_\350\260\350y\350\273\350\215\350\350\350\221\350\365\350\22\350\357\350\375\347\353\350\330\350\v\351\307\351"...,
22048) = 22048
[00007f3f7f78318d] poll([{fd=3<pipe:[76277]>,
events=POLLIN|POLLERR|POLLNVAL}], 1, 4294967295) = 1 ([{fd=3,
revents=POLLIN}])
[00007f3f7fa56f4d] write(6<pipe:[76278]>, "W", 1) = 1
[00007f3f7fa56fad] read(3<pipe:[76277]>, "x", 10) = 1
[00007f3f7fa56fad] read(3<pipe:[76277]>, 0x7ffda627a910, 10) = -1
EAGAIN (Resource temporarily unavailable)
[00007f3f7fa51f07] futex(0x1fd17d0, FUTEX_UNLOCK_PI_PRIVATE, 0) = 0
[00007f3f7fa56fad] read(8</home/stas/test.wav>,
"\36\355\"\355Z\355_\355\212\355\232\355\277\355\345\355\33\356P\356\273\356\341\356\264\357\326\357\337\360\363\360"...,
22048) = 22048
[00007f3f7f78318d] poll([{fd=3<pipe:[76277]>,
events=POLLIN|POLLERR|POLLNVAL}], 1, 4294967295
After my tests with aplay:
cat /proc/asound/DesktopKonnekt6/dice
sections:
global: offset 10, size 90
tx: offset 100, size 142
rx: offset 242, size 282
ext_sync: offset 524, size 4
unused2: offset 0, size 0
global:
owner: ffc1:000100000000
notification: 00000040
nick name: DesktopKonnekt6
clock select: internal 44100
enable: 0
status: locked 44100
ext status: 00000000
sample rate: 44100
version: 1.0.4.0
clock caps: 44100 48000 88200 96000 176400 192000 arx1 arx2 internal
clock source names:
Unused\Unused\Unused\Unused\Unused\Unused\Unused\Unused\Unused\Unused\Unused\Unused\INTERNAL\\
tx 0:
iso channel: -1
audio channels: 6
midi ports: 0
speed: S400
names: ch 1\ch 2\ - \ - \ - \ - \\
ac3 caps: 00000000
ac3 enable: 00000000
rx 0:
iso channel: -1
sequence start: 0
audio channels: 6
midi ports: 0
names: main out 1\main out 2\phones out 1\phones out 2\ - \ - \\
ac3 caps: 00000000
ac3 enable: 00000000
ext status:
clock source: internal
locked: 1
rate: 44100
adat user data: 0
I noticed that when sound is playing "ext status: 00000040". When
sound stops and program freezes then it sets to 00000000 again, even
if program still works (freezed).
Hope this helps to solve the problem.
2015-05-11 4:42 GMT+03:00 Takashi Sakamoto <o-takashi at sakamocchi.jp>:
> Hi,
>
> To reveal what causes this issue, please post following test and the
> outputs. The test consists of 8 steps.
>
> 0. Plug-out your DesktopKonnect6.
>
> 1. To prevent snd_dice from auto-loading, add an entry to configuration
> file. See:
> https://wiki.archlinux.org/index.php/Kernel_modules#Blacklisting
>
> Perhaps:
> $ cat /etc/modprobe.d/blacklist.conf
> ...
> blacklist snd_dice
> ...
>
> 2. Reboot your system and confirm that snd_dice is not auto-loaded.
>
> $ lsmod | grep snd_dice
> (nothing)
>
> 3. Plug-in your DesktopKonnect6.
>
> 4. Wait one minute without do things
> (I expect several bus reset occurs in IEEE 1394 bus then the bus becomes
> calm.)
>
> 5. Load snd_dice and check it
> $ modprobe snd_dice
> $ lsmod | grep snd_dice
> snd_dice (you may see.)
>
> 6. Dump module information
> $ cat /proc/asound/DesktopKonnekt6/dice
> ...(outputs)...
>
> 7. Try your playback test.
>
> 8. get logs from pulseaudio via journalctl or the other tools.
>
>
> Regards
>
> Takashi Sakamoto
>
>
> On May 11 2015 07:10, Stanislav Sergiienko wrote:
>>>
>>> Any error messages in the system log?
>>
>>
>> The problem is that i couldn't find any significant errors. All i was
>> able to gather is:
>>
>> journalctl:
>> апр 13 13:47:56 ArchLinux pulseaudio[2115]: [pulseaudio] pid.c: Daemon
>> already running.
>> апр 13 13:48:03 ArchLinux pulseaudio[2098]: [alsa-sink-DICE]
>> alsa-sink.c: ALSA woke us up to write new data to the device, but
>> there was actually nothing to write!
>> апр 13 13:48:03 ArchLinux pulseaudio[2098]: [alsa-sink-DICE]
>> alsa-sink.c: Most likely this is a bug in the ALSA driver 'snd_dice'.
>> Please report this issue to the ALSA developers.
>> апр 13 13:48:03 ArchLinux pulseaudio[2098]: [alsa-sink-DICE]
>> alsa-sink.c: We were woken up with POLLOUT set -- however a subsequent
>> snd_pcm_avail() returned 0 or another value < min_avail.
>>
>> Sometimes see this:
>> май 03 17:30:27 ArchLinux pulseaudio[657]: [alsa-sink-DICE]
>> alsa-sink.c: Resume failed, couldn't restore original sample settings.
>>
>> Sometimes after play failed i see in sysnotification area:
>> "DesktopKonnect6 don't work, 'Default' will be used"
>>
>> In dmesg i see no errors.
>>
>>> What exactly happens when it cannot play sound?
>>
>>
>> No errors. It's just don't play anything. For example, for video,
>> various players handle it differently - some are just play video
>> without any sound, some can't play video at all(stops play on first
>> frame).
>>
>>> What exactly happens when it "breaks"?
>>
>>
>> Almost nothing, sometimes i can hear that music breaks with some kind
>> of "click-sound", like someone pulled the wire from my loudspeakers.
>> But this sound is barely noticeable.
>> If i try to play file again i hear some kind of "initialization
>> sound", like when device open on PC boot.
>> It's hard to describe it in my English :)
>>
>> If you send me info about how to gather more detailed logs, i try do this.
>> P.S. Sorry for long time to answer.
More information about the Alsa-devel
mailing list