[Bug 206579] Re: Bluetooth CUPS backend takes very long time on device discovery
Till Kamppeter
till.kamppeter at gmail.com
Wed Mar 26 09:09:59 GMT 2008
Now I have done
strace /usr/lib/cups/backend/bluetooth
and got the output shown below. The strace output came together in a few
seconds (< 30 sec) and then it was simply hanging at the "poll(" in the
end of the shown output. So in the middle of that poll the backend was
hanging indefinitely. The "<unfinished ...>" was added when I have
killed the backend with Ctrl + C after several minutes (~10 min).
Till
-------------------------
execve("/usr/lib/cups/backend/bluetooth", ["/usr/lib/cups/backend/bluetooth"], [/* 20 vars */]) = 0
brk(0) = 0x60b000
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f5acbfeb000
access("/etc/ld.so.nohwcap", F_OK) = -1 ENOENT (No such file or directory)
mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f5acbfe9000
access("/etc/ld.so.preload", R_OK) = -1 ENOENT (No such file or directory)
open("/etc/ld.so.cache", O_RDONLY) = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=115877, ...}) = 0
mmap(NULL, 115877, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f5acbfcc000
close(3) = 0
access("/etc/ld.so.nohwcap", F_OK) = -1 ENOENT (No such file or directory)
open("/usr/lib/libdbus-1.so.3", O_RDONLY) = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0pd\0\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0644, st_size=248432, ...}) = 0
mmap(NULL, 2344488, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f5acbb92000
mprotect(0x7f5acbbcd000, 2097152, PROT_NONE) = 0
mmap(0x7f5acbdcd000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x3b000) = 0x7f5acbdcd000
close(3) = 0
access("/etc/ld.so.nohwcap", F_OK) = -1 ENOENT (No such file or directory)
open("/usr/lib/libglib-2.0.so.0", O_RDONLY) = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\240M\1\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0644, st_size=775416, ...}) = 0
mmap(NULL, 2872584, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f5acb8d4000
mprotect(0x7f5acb990000, 2097152, PROT_NONE) = 0
mmap(0x7f5acbb90000, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0xbc000) = 0x7f5acbb90000
mmap(0x7f5acbb91000, 1288, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7f5acbb91000
close(3) = 0
access("/etc/ld.so.nohwcap", F_OK) = -1 ENOENT (No such file or directory)
open("/usr/lib/libbluetooth.so.2", O_RDONLY) = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0Pn\0\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0644, st_size=99800, ...}) = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f5acbfcb000
mmap(NULL, 2195064, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f5acb6bc000
mprotect(0x7f5acb6d2000, 2097152, PROT_NONE) = 0
mmap(0x7f5acb8d2000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x16000) = 0x7f5acb8d2000
close(3) = 0
access("/etc/ld.so.nohwcap", F_OK) = -1 ENOENT (No such file or directory)
open("/lib/libc.so.6", O_RDONLY) = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\340\342"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0755, st_size=1436976, ...}) = 0
mmap(NULL, 3543640, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f5acb35a000
mprotect(0x7f5acb4b2000, 2097152, PROT_NONE) = 0
mmap(0x7f5acb6b2000, 20480, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x158000) = 0x7f5acb6b2000
mmap(0x7f5acb6b7000, 16984, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7f5acb6b7000
close(3) = 0
access("/etc/ld.so.nohwcap", F_OK) = -1 ENOENT (No such file or directory)
open("/usr/lib/libpcre.so.3", O_RDONLY) = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\240\23\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0644, st_size=154200, ...}) = 0
mmap(NULL, 2249472, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f5acb134000
mprotect(0x7f5acb159000, 2097152, PROT_NONE) = 0
mmap(0x7f5acb359000, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x25000) = 0x7f5acb359000
close(3) = 0
access("/etc/ld.so.nohwcap", F_OK) = -1 ENOENT (No such file or directory)
open("/lib/libselinux.so.1", O_RDONLY) = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\240Q\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0644, st_size=109368, ...}) = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f5acbfca000
mmap(NULL, 2209176, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f5acaf18000
mprotect(0x7f5acaf31000, 2097152, PROT_NONE) = 0
mmap(0x7f5acb131000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x19000) = 0x7f5acb131000
mmap(0x7f5acb133000, 1432, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7f5acb133000
close(3) = 0
access("/etc/ld.so.nohwcap", F_OK) = -1 ENOENT (No such file or directory)
open("/lib/libdl.so.2", O_RDONLY) = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0 \16\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0644, st_size=14624, ...}) = 0
mmap(NULL, 2109728, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f5acad14000
mprotect(0x7f5acad16000, 2097152, PROT_NONE) = 0
mmap(0x7f5acaf16000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x2000) = 0x7f5acaf16000
close(3) = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f5acbfc9000
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f5acbfc8000
arch_prctl(ARCH_SET_FS, 0x7f5acbfc8780) = 0
mprotect(0x7f5acb6b2000, 12288, PROT_READ) = 0
munmap(0x7f5acbfcc000, 115877) = 0
brk(0) = 0x60b000
brk(0x62c000) = 0x62c000
open("/etc/selinux/config", O_RDONLY) = -1 ENOENT (No such file or directory)
statfs("/selinux", 0x7fffd3fec5e0) = -1 ENOENT (No such file or directory)
open("/proc/mounts", O_RDONLY) = 3
fstat(3, {st_mode=S_IFREG|0444, st_size=0, ...}) = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f5acbfe8000
read(3, "rootfs / rootfs rw 0 0\nnone /sys"..., 1024) = 1024
read(3, "efault_permissions,allow_other 0"..., 1024) = 312
read(3, "", 1024) = 0
close(3) = 0
munmap(0x7f5acbfe8000, 4096) = 0
rt_sigaction(SIGPIPE, {SIG_IGN}, {SIG_DFL}, 8) = 0
socket(PF_FILE, SOCK_STREAM, 0) = 3
connect(3, {sa_family=AF_FILE, path="/var/run/dbus/system_bus_socket"}, 33) = 0
fcntl(3, F_GETFL) = 0x2 (flags O_RDWR)
fcntl(3, F_SETFL, O_RDWR|O_NONBLOCK) = 0
fcntl(3, F_GETFD) = 0
fcntl(3, F_SETFD, FD_CLOEXEC) = 0
geteuid() = 1000
rt_sigaction(SIGPIPE, {SIG_IGN}, {SIG_IGN}, 8) = 0
poll([{fd=3, events=POLLOUT, revents=POLLOUT}], 1, 0) = 1
write(3, "\0", 1) = 1
write(3, "AUTH EXTERNAL 31303030\r\n", 24) = 24
poll([{fd=3, events=POLLIN, revents=POLLIN}], 1, -1) = 1
read(3, "OK 5bc05bca70d9025efa048d5347e96"..., 2048) = 37
poll([{fd=3, events=POLLOUT, revents=POLLOUT}], 1, -1) = 1
write(3, "BEGIN\r\n", 7) = 7
poll([{fd=3, events=POLLIN|POLLOUT, revents=POLLOUT}], 1, -1) = 1
writev(3, [{"l\1\0\1\0\0\0\0\1\0\0\0n\0\0\0\1\1o\0\25\0\0\0/org/fre"..., 128}, {"", 0}], 2) = 128
poll([{fd=3, events=POLLIN, revents=POLLIN}], 1, 25000) = 1
read(3, "l\2\1\1\f\0\0\0\1\0\0\0=\0\0\0\6\1s\0\7\0\0\0:1.7325\0"..., 2048) = 264
read(3, 0x60d1b0, 2048) = -1 EAGAIN (Resource temporarily unavailable)
fstat(3, {st_mode=S_IFSOCK|0777, st_size=0, ...}) = 0
fcntl(3, F_GETFL) = 0x802 (flags O_RDWR|O_NONBLOCK)
writev(3, [{"l\1\0\1\16\0\0\0\2\0\0\0\177\0\0\0\1\1o\0\25\0\0\0/org"..., 144}, {"\t\0\0\0org.bluez\0", 14}], 2) = 158
poll([{fd=3, events=POLLIN, revents=POLLIN}], 1, 25000) = 1
read(3, "l\2\1\1\4\0\0\0\3\0\0\0=\0\0\0\6\1s\0\7\0\0\0:1.7325\0"..., 2048) = 84
read(3, 0x60d1b0, 2048) = -1 EAGAIN (Resource temporarily unavailable)
writev(3, [{"l\1\0\1\0\0\0\0\3\0\0\0g\0\0\0\1\1o\0\n\0\0\0/org/blu"..., 120}, {"", 0}], 2) = 120
poll([{fd=3, events=POLLIN, revents=POLLIN}], 1, 25000) = 1
read(3, "l\2\1\1\24\0\0\0\"\0\0\0.\0\0\0\6\1s\0\7\0\0\0:1.7325\0"..., 2048) = 84
read(3, 0x60d1b0, 2048) = -1 EAGAIN (Resource temporarily unavailable)
writev(3, [{"l\1\0\1Z\0\0\0\4\0\0\0\177\0\0\0\1\1o\0\25\0\0\0/org/f"..., 144}, {"U\0\0\0type=\'signal\',interface=\'org"..., 90}], 2) = 234
poll([{fd=3, events=POLLIN, revents=POLLIN}], 1, 25000) = 1
read(3, "l\2\1\1\0\0\0\0\4\0\0\0005\0\0\0\6\1s\0\7\0\0\0:1.7325"..., 2048) = 72
read(3, 0x60d1b0, 2048) = -1 EAGAIN (Resource temporarily unavailable)
writev(3, [{"l\1\0\1\0\0\0\0\5\0\0\0|\0\0\0\1\1o\0\17\0\0\0/org/blu"..., 144}, {"", 0}], 2) = 144
poll([{fd=3, events=POLLIN}], 1, 0) = 0
writev(3, [{"l\1\0\1\0\0\0\0\6\0\0\0j\0\0\0\1\1o\0\17\0\0\0/org/blu"..., 128}, {"", 0}], 2) = 128
poll([{fd=3, events=POLLIN, revents=POLLIN}], 1, 25000) = 1
read(3, "l\2\1\1\0\0\0\0$\0\0\0&\0\0\0\6\1s\0\7\0\0\0:1.7325\0"..., 2048) = 56
read(3, 0x60d1b0, 2048) = -1 EAGAIN (Resource temporarily unavailable)
poll([{fd=3, events=POLLIN, revents=POLLIN}], 1, 24993) = 1
read(3, "l\2\1\1b\0\0\0%\0\0\0.\0\0\0\6\1s\0\7\0\0\0:1.7325\0"..., 2048) = 282
read(3, 0x60d1b0, 2048) = -1 EAGAIN (Resource temporarily unavailable)
writev(3, [{"l\1\0\1\26\0\0\0\7\0\0\0w\0\0\0\1\1o\0\17\0\0\0/org/bl"..., 136}, {"\21\0\0\00000:02:76:01:75:BA\0", 22}], 2) = 158
poll([{fd=3, events=POLLIN, revents=POLLIN}], 1, 25000) = 1
read(3, "l\2\1\1\r\0\0\0\'\0\0\0.\0\0\0\6\1s\0\7\0\0\0:1.7325\0"..., 2048) = 77
read(3, 0x60d1b0, 2048) = -1 EAGAIN (Resource temporarily unavailable)
writev(3, [{"l\1\0\1\26\0\0\0\10\0\0\0w\0\0\0\1\1o\0\17\0\0\0/org/b"..., 136}, {"\21\0\0\00000:04:61:82:97:9C\0", 22}], 2) = 158
poll([{fd=3, events=POLLIN, revents=POLLIN}], 1, 25000) = 1
read(3, "l\2\1\1\r\0\0\0(\0\0\0.\0\0\0\6\1s\0\7\0\0\0:1.7325\0"..., 2048) = 77
read(3, 0x60d1b0, 2048) = -1 EAGAIN (Resource temporarily unavailable)
writev(3, [{"l\1\0\1\26\0\0\0\t\0\0\0w\0\0\0\1\1o\0\17\0\0\0/org/bl"..., 136}, {"\21\0\0\00000:04:61:82:0B:10\0", 22}], 2) = 158
poll([{fd=3, events=POLLIN, revents=POLLIN}], 1, 25000) = 1
read(3, "l\2\1\1\f\0\0\0)\0\0\0.\0\0\0\6\1s\0\7\0\0\0:1.7325\0"..., 2048) = 76
read(3, 0x60d1b0, 2048) = -1 EAGAIN (Resource temporarily unavailable)
writev(3, [{"l\1\0\1\26\0\0\0\n\0\0\0o\0\0\0\1\1o\0\17\0\0\0/org/bl"..., 128}, {"\21\0\0\00000:04:61:82:0B:10\0", 22}], 2) = 150
poll([{fd=3, events=POLLIN, revents=POLLIN}], 1, 25000) = 1
read(3, "l\2\1\1\33\0\0\0*\0\0\0.\0\0\0\6\1s\0\7\0\0\0:1.7325\0"..., 2048) = 91
read(3, 0x60d1b0, 2048) = -1 EAGAIN (Resource temporarily unavailable)
writev(3, [{"l\1\0\1A\0\0\0\v\0\0\0x\0\0\0\1\1o\0\17\0\0\0/org/blu"..., 136}, {"\21\0\0\00000:04:61:82:0B:10\0\0\0$\0\0\0000000"..., 65}], 2) = 201
poll([{fd=3, events=POLLIN, revents=POLLIN}], 1, 25000) = 1
read(3, "l\4\1\1\0\0\0\0+\0\0\0f\0\0\0\1\1o\0\17\0\0\0/org/blu"..., 2048) = 120
read(3, 0x60d1b0, 2048) = -1 EAGAIN (Resource temporarily unavailable)
poll([{fd=3, events=POLLIN, revents=POLLIN}], 1, 24987) = 1
read(3, "l\3\1\1\21\0\0\0-\0\0\0^\0\0\0\6\1s\0\7\0\0\0:1.7325\0"..., 2048) = 129
read(3, 0x60d1b0, 2048) = -1 EAGAIN (Resource temporarily unavailable)
writev(3, [{"l\1\0\1\26\0\0\0\f\0\0\0w\0\0\0\1\1o\0\17\0\0\0/org/bl"..., 136}, {"\21\0\0\00000:17:83:88:09:03\0", 22}], 2) = 158
poll([{fd=3, events=POLLIN, revents=POLLIN}], 1, 25000) = 1
read(3, "l\2\1\1\20\0\0\0.\0\0\0.\0\0\0\6\1s\0\7\0\0\0:1.7325\0"..., 2048) = 80
read(3, 0x60d1b0, 2048) = -1 EAGAIN (Resource temporarily unavailable)
poll( <unfinished ...>
--
Bluetooth CUPS backend takes very long time on device discovery
https://bugs.launchpad.net/bugs/206579
You received this bug notification because you are a member of
Bluetooth, which is subscribed to bluez-utils in ubuntu.
More information about the Ubuntu-bluetooth
mailing list