Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

libcups attempted to connect to daemon endlessly if there's no daemon running #4870

Closed
xuzhen opened this issue Aug 22, 2016 · 30 comments
Closed

libcups attempted to connect to daemon endlessly if there's no daemon running #4870

xuzhen opened this issue Aug 22, 2016 · 30 comments
Assignees
@michaelrsweet
Labels
priority-high
Milestone
CUPS 2.2.x Updates

Comments

@xuzhen
Copy link

xuzhen commented Aug 22, 2016 •
edited
Loading

CUPS 2.2rc1
Ubuntu 16.10

use the sample code from document:

#include <stdio.h>
#include <cups/cups.h>

int main(void)
{
  int i;
  cups_dest_t *dests, *dest;
  int num_dests = cupsGetDests(&dests);

  for (i = num_dests, dest = dests; i > 0; i --, dest ++)
  {
    if (dest->instance)
      printf("%s/%s\n", dest->name, dest->instance);
    else
      puts(dest->name);
  }

  return (0);
}

the strace output:

execve("./simple", ["./simple"], [/* 59 vars */]) = 0
brk(NULL)                               = 0x56002ba53000
access("/etc/ld.so.nohwcap", F_OK)      = -1 ENOENT (No such file or directory)
mmap(NULL, 12288, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fcb8c523000
access("/etc/ld.so.preload", R_OK)      = -1 ENOENT (No such file or directory)
open("/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=121385, ...}) = 0
mmap(NULL, 121385, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7fcb8c505000
close(3)                                = 0
access("/etc/ld.so.nohwcap", F_OK)      = -1 ENOENT (No such file or directory)
open("/usr/lib/x86_64-linux-gnu/libcups.so.2", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\0\267\1\0\0\0\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0644, st_size=542672, ...}) = 0
mmap(NULL, 2638408, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7fcb8c07d000
mprotect(0x7fcb8c0fa000, 2093056, PROT_NONE) = 0
mmap(0x7fcb8c2f9000, 36864, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x7c000) = 0x7fcb8c2f9000
close(3)                                = 0
access("/etc/ld.so.nohwcap", F_OK)      = -1 ENOENT (No such file or directory)
open("/lib/x86_64-linux-gnu/libc.so.6", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\3\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\20\5\2\0\0\0\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0755, st_size=1856752, ...}) = 0
mmap(NULL, 3959200, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7fcb8bcb6000
mprotect(0x7fcb8be73000, 2097152, PROT_NONE) = 0
mmap(0x7fcb8c073000, 24576, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x1bd000) = 0x7fcb8c073000
mmap(0x7fcb8c079000, 14752, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7fcb8c079000
close(3)                                = 0
access("/etc/ld.so.nohwcap", F_OK)      = -1 ENOENT (No such file or directory)
open("/usr/lib/x86_64-linux-gnu/libgssapi_krb5.so.2", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\20\265\0\0\0\0\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0644, st_size=301376, ...}) = 0
mmap(NULL, 2396960, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7fcb8ba6c000
mprotect(0x7fcb8bab3000, 2097152, PROT_NONE) = 0
mmap(0x7fcb8bcb3000, 12288, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x47000) = 0x7fcb8bcb3000
close(3)                                = 0
access("/etc/ld.so.nohwcap", F_OK)      = -1 ENOENT (No such file or directory)
open("/usr/lib/x86_64-linux-gnu/libgnutls.so.30", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\200f\2\0\0\0\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0644, st_size=1412736, ...}) = 0
mmap(NULL, 3513152, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7fcb8b712000
mprotect(0x7fcb8b85e000, 2097152, PROT_NONE) = 0
mmap(0x7fcb8ba5e000, 53248, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x14c000) = 0x7fcb8ba5e000
mmap(0x7fcb8ba6b000, 2880, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7fcb8ba6b000
close(3)                                = 0
access("/etc/ld.so.nohwcap", F_OK)      = -1 ENOENT (No such file or directory)
open("/usr/lib/x86_64-linux-gnu/libavahi-common.so.3", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0@/\0\0\0\0\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0644, st_size=47952, ...}) = 0
mmap(NULL, 2143216, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7fcb8b506000
mprotect(0x7fcb8b511000, 2093056, PROT_NONE) = 0
mmap(0x7fcb8b710000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0xa000) = 0x7fcb8b710000
close(3)                                = 0
access("/etc/ld.so.nohwcap", F_OK)      = -1 ENOENT (No such file or directory)
open("/usr/lib/x86_64-linux-gnu/libavahi-client.so.3", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\2206\0\0\0\0\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0644, st_size=68512, ...}) = 0
mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fcb8c503000
mmap(NULL, 2163576, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7fcb8b2f5000
mprotect(0x7fcb8b305000, 2093056, PROT_NONE) = 0
mmap(0x7fcb8b504000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0xf000) = 0x7fcb8b504000
close(3)                                = 0
access("/etc/ld.so.nohwcap", F_OK)      = -1 ENOENT (No such file or directory)
open("/lib/x86_64-linux-gnu/libpthread.so.0", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\340`\0\0\0\0\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0755, st_size=142456, ...}) = 0
mmap(NULL, 2217000, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7fcb8b0d7000
mprotect(0x7fcb8b0ef000, 2097152, PROT_NONE) = 0
mmap(0x7fcb8b2ef000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x18000) = 0x7fcb8b2ef000
mmap(0x7fcb8b2f1000, 13352, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7fcb8b2f1000
close(3)                                = 0
access("/etc/ld.so.nohwcap", F_OK)      = -1 ENOENT (No such file or directory)
open("/lib/x86_64-linux-gnu/libz.so.1", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\260\35\0\0\0\0\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0644, st_size=104864, ...}) = 0
mmap(NULL, 2199848, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7fcb8aebd000
mprotect(0x7fcb8aed6000, 2093056, PROT_NONE) = 0
mmap(0x7fcb8b0d5000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x18000) = 0x7fcb8b0d5000
close(3)                                = 0
access("/etc/ld.so.nohwcap", F_OK)      = -1 ENOENT (No such file or directory)
open("/lib/x86_64-linux-gnu/libm.so.6", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\3\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\20W\0\0\0\0\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0644, st_size=1088952, ...}) = 0
mmap(NULL, 3178744, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7fcb8abb4000
mprotect(0x7fcb8acbc000, 2093056, PROT_NONE) = 0
mmap(0x7fcb8aebb000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x107000) = 0x7fcb8aebb000
close(3)                                = 0
access("/etc/ld.so.nohwcap", F_OK)      = -1 ENOENT (No such file or directory)
open("/usr/lib/x86_64-linux-gnu/libkrb5.so.3", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\240\24\2\0\0\0\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0644, st_size=864584, ...}) = 0
mmap(NULL, 2960384, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7fcb8a8e1000
mprotect(0x7fcb8a9a5000, 2093056, PROT_NONE) = 0
mmap(0x7fcb8aba4000, 65536, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0xc3000) = 0x7fcb8aba4000
close(3)                                = 0
access("/etc/ld.so.nohwcap", F_OK)      = -1 ENOENT (No such file or directory)
open("/usr/lib/x86_64-linux-gnu/libk5crypto.so.3", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0P>\0\0\0\0\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0644, st_size=186824, ...}) = 0
mmap(NULL, 2285656, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7fcb8a6b2000
mprotect(0x7fcb8a6de000, 2093056, PROT_NONE) = 0
mmap(0x7fcb8a8dd000, 12288, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x2b000) = 0x7fcb8a8dd000
mmap(0x7fcb8a8e0000, 88, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7fcb8a8e0000
close(3)                                = 0
access("/etc/ld.so.nohwcap", F_OK)      = -1 ENOENT (No such file or directory)
open("/lib/x86_64-linux-gnu/libcom_err.so.2", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0@\23\0\0\0\0\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0644, st_size=14248, ...}) = 0
mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fcb8c501000
mmap(NULL, 2109608, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7fcb8a4ae000
mprotect(0x7fcb8a4b1000, 2093056, PROT_NONE) = 0
mmap(0x7fcb8a6b0000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x2000) = 0x7fcb8a6b0000
close(3)                                = 0
access("/etc/ld.so.nohwcap", F_OK)      = -1 ENOENT (No such file or directory)
open("/usr/lib/x86_64-linux-gnu/libkrb5support.so.0", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\320&\0\0\0\0\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0644, st_size=43664, ...}) = 0
mmap(NULL, 2139080, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7fcb8a2a3000
mprotect(0x7fcb8a2ad000, 2093056, PROT_NONE) = 0
mmap(0x7fcb8a4ac000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x9000) = 0x7fcb8a4ac000
close(3)                                = 0
access("/etc/ld.so.nohwcap", F_OK)      = -1 ENOENT (No such file or directory)
open("/usr/lib/x86_64-linux-gnu/libp11-kit.so.0", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\260\21\1\0\0\0\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0644, st_size=407592, ...}) = 0
mmap(NULL, 2503856, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7fcb8a03f000
mprotect(0x7fcb8a098000, 2093056, PROT_NONE) = 0
mmap(0x7fcb8a297000, 49152, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x58000) = 0x7fcb8a297000
close(3)                                = 0
access("/etc/ld.so.nohwcap", F_OK)      = -1 ENOENT (No such file or directory)
open("/lib/x86_64-linux-gnu/libidn.so.11", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\320*\0\0\0\0\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0644, st_size=206872, ...}) = 0
mmap(NULL, 2302000, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7fcb89e0c000
mprotect(0x7fcb89e3d000, 2097152, PROT_NONE) = 0
mmap(0x7fcb8a03d000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x31000) = 0x7fcb8a03d000
close(3)                                = 0
access("/etc/ld.so.nohwcap", F_OK)      = -1 ENOENT (No such file or directory)
open("/usr/lib/x86_64-linux-gnu/libtasn1.so.6", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\300(\0\0\0\0\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0644, st_size=75776, ...}) = 0
mmap(NULL, 2171624, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7fcb89bf9000
mprotect(0x7fcb89c0a000, 2097152, PROT_NONE) = 0
mmap(0x7fcb89e0a000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x11000) = 0x7fcb89e0a000
close(3)                                = 0
access("/etc/ld.so.nohwcap", F_OK)      = -1 ENOENT (No such file or directory)
open("/usr/lib/x86_64-linux-gnu/libnettle.so.6", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0`~\0\0\0\0\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0644, st_size=219336, ...}) = 0
mmap(NULL, 2314384, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7fcb899c3000
mprotect(0x7fcb899f7000, 2093056, PROT_NONE) = 0
mmap(0x7fcb89bf6000, 12288, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x33000) = 0x7fcb89bf6000
close(3)                                = 0
access("/etc/ld.so.nohwcap", F_OK)      = -1 ENOENT (No such file or directory)
open("/usr/lib/x86_64-linux-gnu/libhogweed.so.4", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\220e\0\0\0\0\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0644, st_size=207632, ...}) = 0
mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fcb8c4ff000
mmap(NULL, 2302648, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7fcb89790000
mprotect(0x7fcb897c2000, 2093056, PROT_NONE) = 0
mmap(0x7fcb899c1000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x31000) = 0x7fcb899c1000
close(3)                                = 0
access("/etc/ld.so.nohwcap", F_OK)      = -1 ENOENT (No such file or directory)
open("/usr/lib/x86_64-linux-gnu/libgmp.so.10", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\300\223\0\0\0\0\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0644, st_size=522664, ...}) = 0
mmap(NULL, 2617792, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7fcb89510000
mprotect(0x7fcb8958f000, 2093056, PROT_NONE) = 0
mmap(0x7fcb8978e000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x7e000) = 0x7fcb8978e000
close(3)                                = 0
access("/etc/ld.so.nohwcap", F_OK)      = -1 ENOENT (No such file or directory)
open("/lib/x86_64-linux-gnu/libdbus-1.so.3", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0`\244\0\0\0\0\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0644, st_size=309392, ...}) = 0
mmap(NULL, 2405040, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7fcb892c4000
mprotect(0x7fcb8930e000, 2097152, PROT_NONE) = 0
mmap(0x7fcb8950e000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x4a000) = 0x7fcb8950e000
close(3)                                = 0
access("/etc/ld.so.nohwcap", F_OK)      = -1 ENOENT (No such file or directory)
open("/lib/x86_64-linux-gnu/libdl.so.2", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\200\r\0\0\0\0\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0644, st_size=14608, ...}) = 0
mmap(NULL, 2109680, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7fcb890c0000
mprotect(0x7fcb890c3000, 2093056, PROT_NONE) = 0
mmap(0x7fcb892c2000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x2000) = 0x7fcb892c2000
close(3)                                = 0
access("/etc/ld.so.nohwcap", F_OK)      = -1 ENOENT (No such file or directory)
open("/lib/x86_64-linux-gnu/libkeyutils.so.1", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\300\22\0\0\0\0\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0644, st_size=14256, ...}) = 0
mmap(NULL, 2109456, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7fcb88ebc000
mprotect(0x7fcb88ebf000, 2093056, PROT_NONE) = 0
mmap(0x7fcb890be000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x2000) = 0x7fcb890be000
close(3)                                = 0
access("/etc/ld.so.nohwcap", F_OK)      = -1 ENOENT (No such file or directory)
open("/lib/x86_64-linux-gnu/libresolv.so.2", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0p9\0\0\0\0\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0644, st_size=101200, ...}) = 0
mmap(NULL, 2206280, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7fcb88ca1000
mprotect(0x7fcb88cb8000, 2097152, PROT_NONE) = 0
mmap(0x7fcb88eb8000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x17000) = 0x7fcb88eb8000
mmap(0x7fcb88eba000, 6728, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7fcb88eba000
close(3)                                = 0
mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fcb8c4fd000
access("/etc/ld.so.nohwcap", F_OK)      = -1 ENOENT (No such file or directory)
open("/usr/lib/x86_64-linux-gnu/libffi.so.6", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\360\27\0\0\0\0\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0644, st_size=31104, ...}) = 0
mmap(NULL, 2127368, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7fcb88a99000
mprotect(0x7fcb88aa0000, 2093056, PROT_NONE) = 0
mmap(0x7fcb88c9f000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x6000) = 0x7fcb88c9f000
close(3)                                = 0
access("/etc/ld.so.nohwcap", F_OK)      = -1 ENOENT (No such file or directory)
open("/lib/x86_64-linux-gnu/libsystemd.so.0", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\0\0\0\0\0\0\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0644, st_size=544864, ...}) = 0
mmap(NULL, 549105, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7fcb8c476000
mprotect(0x7fcb8c4f7000, 4096, PROT_NONE) = 0
mmap(0x7fcb8c4f8000, 16384, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x81000) = 0x7fcb8c4f8000
mmap(0x7fcb8c4fc000, 241, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7fcb8c4fc000
close(3)                                = 0
access("/etc/ld.so.nohwcap", F_OK)      = -1 ENOENT (No such file or directory)
open("/lib/x86_64-linux-gnu/libselinux.so.1", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\200_\0\0\0\0\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0644, st_size=146672, ...}) = 0
mmap(NULL, 2250560, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7fcb88873000
mprotect(0x7fcb88896000, 2093056, PROT_NONE) = 0
mmap(0x7fcb88a95000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x22000) = 0x7fcb88a95000
mmap(0x7fcb88a97000, 5952, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7fcb88a97000
close(3)                                = 0
access("/etc/ld.so.nohwcap", F_OK)      = -1 ENOENT (No such file or directory)
open("/lib/x86_64-linux-gnu/librt.so.1", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\340 \0\0\0\0\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0644, st_size=31712, ...}) = 0
mmap(NULL, 2128832, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7fcb8866b000
mprotect(0x7fcb88672000, 2093056, PROT_NONE) = 0
mmap(0x7fcb88871000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x6000) = 0x7fcb88871000
close(3)                                = 0
access("/etc/ld.so.nohwcap", F_OK)      = -1 ENOENT (No such file or directory)
open("/lib/x86_64-linux-gnu/liblzma.so.5", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\220 \0\0\0\0\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0644, st_size=141552, ...}) = 0
mmap(NULL, 2236536, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7fcb88448000
mprotect(0x7fcb8846a000, 2093056, PROT_NONE) = 0
mmap(0x7fcb88669000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x21000) = 0x7fcb88669000
close(3)                                = 0
access("/etc/ld.so.nohwcap", F_OK)      = -1 ENOENT (No such file or directory)
open("/lib/x86_64-linux-gnu/libgcrypt.so.20", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\0\253\0\0\0\0\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0644, st_size=1107992, ...}) = 0
mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fcb8c474000
mmap(NULL, 3204256, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7fcb88139000
mprotect(0x7fcb88240000, 2093056, PROT_NONE) = 0
mmap(0x7fcb8843f000, 36864, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x106000) = 0x7fcb8843f000
close(3)                                = 0
access("/etc/ld.so.nohwcap", F_OK)      = -1 ENOENT (No such file or directory)
open("/lib/x86_64-linux-gnu/libpcre.so.3", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\20\25\0\0\0\0\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0644, st_size=464824, ...}) = 0
mmap(NULL, 2560264, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7fcb87ec7000
mprotect(0x7fcb87f38000, 2093056, PROT_NONE) = 0
mmap(0x7fcb88137000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x70000) = 0x7fcb88137000
close(3)                                = 0
access("/etc/ld.so.nohwcap", F_OK)      = -1 ENOENT (No such file or directory)
open("/lib/x86_64-linux-gnu/libgpg-error.so.0", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\320(\0\0\0\0\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0644, st_size=80496, ...}) = 0
mmap(NULL, 2175544, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7fcb87cb3000
mprotect(0x7fcb87cc5000, 2097152, PROT_NONE) = 0
mmap(0x7fcb87ec5000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x12000) = 0x7fcb87ec5000
close(3)                                = 0
mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fcb8c472000
mmap(NULL, 12288, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fcb8c46f000
arch_prctl(ARCH_SET_FS, 0x7fcb8c46f880) = 0
mprotect(0x7fcb8c073000, 16384, PROT_READ) = 0
mprotect(0x7fcb87ec5000, 4096, PROT_READ) = 0
mprotect(0x7fcb8b2ef000, 4096, PROT_READ) = 0
mprotect(0x7fcb88137000, 4096, PROT_READ) = 0
mprotect(0x7fcb8843f000, 8192, PROT_READ) = 0
mprotect(0x7fcb892c2000, 4096, PROT_READ) = 0
mprotect(0x7fcb88669000, 4096, PROT_READ) = 0
mprotect(0x7fcb88871000, 4096, PROT_READ) = 0
mprotect(0x7fcb88a95000, 4096, PROT_READ) = 0
mprotect(0x7fcb8c4f8000, 12288, PROT_READ) = 0
mprotect(0x7fcb88c9f000, 4096, PROT_READ) = 0
mprotect(0x7fcb88eb8000, 4096, PROT_READ) = 0
mprotect(0x7fcb890be000, 4096, PROT_READ) = 0
mprotect(0x7fcb8950e000, 4096, PROT_READ) = 0
mprotect(0x7fcb8978e000, 4096, PROT_READ) = 0
mprotect(0x7fcb89bf6000, 8192, PROT_READ) = 0
mprotect(0x7fcb899c1000, 4096, PROT_READ) = 0
mprotect(0x7fcb89e0a000, 4096, PROT_READ) = 0
mprotect(0x7fcb8a03d000, 4096, PROT_READ) = 0
mprotect(0x7fcb8a297000, 40960, PROT_READ) = 0
mprotect(0x7fcb8a4ac000, 4096, PROT_READ) = 0
mprotect(0x7fcb8a6b0000, 4096, PROT_READ) = 0
mprotect(0x7fcb8a8dd000, 8192, PROT_READ) = 0
mprotect(0x7fcb8aba4000, 57344, PROT_READ) = 0
mprotect(0x7fcb8aebb000, 4096, PROT_READ) = 0
mprotect(0x7fcb8b0d5000, 4096, PROT_READ) = 0
mprotect(0x7fcb8b710000, 4096, PROT_READ) = 0
mprotect(0x7fcb8b504000, 4096, PROT_READ) = 0
mprotect(0x7fcb8ba5e000, 49152, PROT_READ) = 0
mprotect(0x7fcb8bcb3000, 4096, PROT_READ) = 0
mprotect(0x7fcb8c2f9000, 32768, PROT_READ) = 0
mprotect(0x56002b9f1000, 4096, PROT_READ) = 0
mprotect(0x7fcb8c526000, 4096, PROT_READ) = 0
munmap(0x7fcb8c505000, 121385)          = 0
set_tid_address(0x7fcb8c46fb50)         = 10817
set_robust_list(0x7fcb8c46fb60, 24)     = 0
rt_sigaction(SIGRTMIN, {0x7fcb8b0dcb80, [], SA_RESTORER|SA_SIGINFO, 0x7fcb8b0e8670}, NULL, 8) = 0
rt_sigaction(SIGRT_1, {0x7fcb8b0dcc10, [], SA_RESTORER|SA_RESTART|SA_SIGINFO, 0x7fcb8b0e8670}, NULL, 8) = 0
rt_sigprocmask(SIG_UNBLOCK, [RTMIN RT_1], NULL, 8) = 0
getrlimit(RLIMIT_STACK, {rlim_cur=8192*1024, rlim_max=RLIM64_INFINITY}) = 0
brk(NULL)                               = 0x56002ba53000
brk(0x56002ba74000)                     = 0x56002ba74000
statfs("/sys/fs/selinux", 0x7ffc3c6df060) = -1 ENOENT (No such file or directory)
statfs("/selinux", 0x7ffc3c6df060)      = -1 ENOENT (No such file or directory)
open("/proc/filesystems", O_RDONLY)     = 3
fstat(3, {st_mode=S_IFREG|0444, st_size=0, ...}) = 0
read(3, "nodev\tsysfs\nnodev\trootfs\nnodev\tr"..., 1024) = 265
read(3, "", 1024)                       = 0
close(3)                                = 0
access("/etc/selinux/config", F_OK)     = -1 ENOENT (No such file or directory)
futex(0x7fcb8a2a2460, FUTEX_WAKE_PRIVATE, 2147483647) = 0
open("/dev/urandom", O_RDONLY)          = 3
fcntl(3, F_GETFD)                       = 0
fcntl(3, F_SETFD, FD_CLOEXEC)           = 0
fstat(3, {st_mode=S_IFCHR|0666, st_rdev=makedev(1, 9), ...}) = 0
clock_gettime(CLOCK_REALTIME, {1471868463, 448273608}) = 0
getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 2000}, ru_stime={0, 2000}, ...}) = 0
read(3, "\322\334\31'\353\232\343b \366No\201_\307\357\203X\313\362\351~!'\330I\273<UH\20\252", 32) = 32
read(3, "\323\352\367\255\376r\3114\334\37080\201\31\331\16\177o\366D+\216\255@p\17\27\365\\\310zx", 32) = 32
read(3, "mk\377\3475\362\213E", 8)      = 8
stat("/etc/gnutls/default-priorities", 0x7ffc3c6df090) = -1 ENOENT (No such file or directory)
futex(0x7fcb8c301088, FUTEX_WAKE_PRIVATE, 2147483647) = 0
geteuid()                               = 1000
getuid()                                = 1000
getegid()                               = 1000
getgid()                                = 1000
open("/etc/cups/client.conf", O_RDONLY) = -1 ENOENT (No such file or directory)
geteuid()                               = 1000
getuid()                                = 1000
getegid()                               = 1000
getgid()                                = 1000
open("/home/xxx/.cups/client.conf", O_RDONLY) = -1 ENOENT (No such file or directory)
access("/var/run/cups/cups.sock", R_OK) = -1 ENOENT (No such file or directory)
socket(AF_LOCAL, SOCK_STREAM|SOCK_CLOEXEC|SOCK_NONBLOCK, 0) = 4
connect(4, {sa_family=AF_LOCAL, sun_path="/var/run/nscd/socket"}, 110) = -1 ENOENT (No such file or directory)
close(4)                                = 0
socket(AF_LOCAL, SOCK_STREAM|SOCK_CLOEXEC|SOCK_NONBLOCK, 0) = 4
connect(4, {sa_family=AF_LOCAL, sun_path="/var/run/nscd/socket"}, 110) = -1 ENOENT (No such file or directory)
close(4)                                = 0
open("/etc/nsswitch.conf", O_RDONLY|O_CLOEXEC) = 4
fstat(4, {st_mode=S_IFREG|0644, st_size=491, ...}) = 0
read(4, "# /etc/nsswitch.conf\n#\n# Example"..., 4096) = 491
read(4, "", 4096)                       = 0
close(4)                                = 0
open("/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 4
fstat(4, {st_mode=S_IFREG|0644, st_size=121385, ...}) = 0
mmap(NULL, 121385, PROT_READ, MAP_PRIVATE, 4, 0) = 0x7fcb8c505000
close(4)                                = 0
access("/etc/ld.so.nohwcap", F_OK)      = -1 ENOENT (No such file or directory)
open("/lib/x86_64-linux-gnu/libnss_compat.so.2", O_RDONLY|O_CLOEXEC) = 4
read(4, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\260\22\0\0\0\0\0\0"..., 832) = 832
fstat(4, {st_mode=S_IFREG|0644, st_size=35688, ...}) = 0
mmap(NULL, 2131040, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 4, 0) = 0x7fcb87aaa000
mprotect(0x7fcb87ab2000, 2093056, PROT_NONE) = 0
mmap(0x7fcb87cb1000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 4, 0x7000) = 0x7fcb87cb1000
close(4)                                = 0
access("/etc/ld.so.nohwcap", F_OK)      = -1 ENOENT (No such file or directory)
open("/lib/x86_64-linux-gnu/libnsl.so.1", O_RDONLY|O_CLOEXEC) = 4
read(4, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\320?\0\0\0\0\0\0"..., 832) = 832
fstat(4, {st_mode=S_IFREG|0644, st_size=93128, ...}) = 0
mmap(NULL, 2198104, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 4, 0) = 0x7fcb87891000
mprotect(0x7fcb878a7000, 2093056, PROT_NONE) = 0
mmap(0x7fcb87aa6000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 4, 0x15000) = 0x7fcb87aa6000
mmap(0x7fcb87aa8000, 6744, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7fcb87aa8000
close(4)                                = 0
mprotect(0x7fcb87aa6000, 4096, PROT_READ) = 0
mprotect(0x7fcb87cb1000, 4096, PROT_READ) = 0
munmap(0x7fcb8c505000, 121385)          = 0
open("/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 4
fstat(4, {st_mode=S_IFREG|0644, st_size=121385, ...}) = 0
mmap(NULL, 121385, PROT_READ, MAP_PRIVATE, 4, 0) = 0x7fcb8c505000
close(4)                                = 0
access("/etc/ld.so.nohwcap", F_OK)      = -1 ENOENT (No such file or directory)
open("/lib/x86_64-linux-gnu/libnss_nis.so.2", O_RDONLY|O_CLOEXEC) = 4
read(4, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\340 \0\0\0\0\0\0"..., 832) = 832
fstat(4, {st_mode=S_IFREG|0644, st_size=47656, ...}) = 0
mmap(NULL, 2143656, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 4, 0) = 0x7fcb87685000
mprotect(0x7fcb87690000, 2093056, PROT_NONE) = 0
mmap(0x7fcb8788f000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 4, 0xa000) = 0x7fcb8788f000
close(4)                                = 0
access("/etc/ld.so.nohwcap", F_OK)      = -1 ENOENT (No such file or directory)
open("/lib/x86_64-linux-gnu/libnss_files.so.2", O_RDONLY|O_CLOEXEC) = 4
read(4, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\320!\0\0\0\0\0\0"..., 832) = 832
fstat(4, {st_mode=S_IFREG|0644, st_size=47608, ...}) = 0
mmap(NULL, 2168600, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 4, 0) = 0x7fcb87473000
mprotect(0x7fcb8747e000, 2093056, PROT_NONE) = 0
mmap(0x7fcb8767d000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 4, 0xa000) = 0x7fcb8767d000
mmap(0x7fcb8767f000, 22296, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7fcb8767f000
close(4)                                = 0
mprotect(0x7fcb8767d000, 4096, PROT_READ) = 0
mprotect(0x7fcb8788f000, 4096, PROT_READ) = 0
munmap(0x7fcb8c505000, 121385)          = 0
open("/etc/passwd", O_RDONLY|O_CLOEXEC) = 4
lseek(4, 0, SEEK_CUR)                   = 0
fstat(4, {st_mode=S_IFREG|0644, st_size=2040, ...}) = 0
mmap(NULL, 2040, PROT_READ, MAP_SHARED, 4, 0) = 0x7fcb8c522000
lseek(4, 2040, SEEK_SET)                = 2040
munmap(0x7fcb8c522000, 2040)            = 0
close(4)                                = 0
getuid()                                = 1000
brk(0x56002ba95000)                     = 0x56002ba95000
rt_sigaction(SIGPIPE, {SIG_IGN, [], SA_RESTORER, 0x7fcb8bceb860}, NULL, 8) = 0
fstat(3, {st_mode=S_IFCHR|0666, st_rdev=makedev(1, 9), ...}) = 0
socket(AF_INET6, SOCK_STREAM, IPPROTO_IP) = 4
setsockopt(4, SOL_SOCKET, SO_REUSEADDR, [1], 4) = 0
setsockopt(4, SOL_SOCKET, SO_REUSEPORT, [1], 4) = 0
setsockopt(4, SOL_TCP, TCP_NODELAY, [1], 4) = 0
fcntl(4, F_SETFD, FD_CLOEXEC)           = 0
fcntl(4, F_GETFL)                       = 0x2 (flags O_RDWR)
fcntl(4, F_SETFL, O_RDWR|O_NONBLOCK)    = 0
connect(4, {sa_family=AF_INET6, sin6_port=htons(631), inet_pton(AF_INET6, "::1", &sin6_addr), sin6_flowinfo=0, sin6_scope_id=0}, 28) = -1 EINPROGRESS (Operation now in progress)
fcntl(4, F_SETFL, O_RDWR)               = 0
poll([{fd=4, events=POLLIN|POLLOUT}], 1, 100) = 1 ([{fd=4, revents=POLLIN|POLLOUT|POLLERR|POLLHUP}])
uname({sysname="Linux", nodename="ubuntu", ...}) = 0
sendto(4, "POST / HTTP/1.1\r\nContent-Length:"..., 169, 0, NULL, 0) = -1 ECONNREFUSED (Connection refused)
sendto(4, "POST / HTTP/1.1\r\nContent-Length:"..., 169, 0, NULL, 0) = -1 EPIPE (Broken pipe)
--- SIGPIPE {si_signo=SIGPIPE, si_code=SI_USER, si_pid=10817, si_uid=1000} ---
sendto(4, "POST / HTTP/1.1\r\nContent-Length:"..., 169, 0, NULL, 0) = -1 EPIPE (Broken pipe)
--- SIGPIPE {si_signo=SIGPIPE, si_code=SI_USER, si_pid=10817, si_uid=1000} ---
close(4)                                = 0
socket(AF_INET6, SOCK_STREAM, IPPROTO_IP) = 4
setsockopt(4, SOL_SOCKET, SO_REUSEADDR, [1], 4) = 0
setsockopt(4, SOL_SOCKET, SO_REUSEPORT, [1], 4) = 0
setsockopt(4, SOL_TCP, TCP_NODELAY, [1], 4) = 0
fcntl(4, F_SETFD, FD_CLOEXEC)           = 0
fcntl(4, F_GETFL)                       = 0x2 (flags O_RDWR)
fcntl(4, F_SETFL, O_RDWR|O_NONBLOCK)    = 0
connect(4, {sa_family=AF_INET6, sin6_port=htons(631), inet_pton(AF_INET6, "::1", &sin6_addr), sin6_flowinfo=0, sin6_scope_id=0}, 28) = -1 EINPROGRESS (Operation now in progress)
fcntl(4, F_SETFL, O_RDWR)               = 0
poll([{fd=4, events=POLLIN|POLLOUT}], 1, 100) = 1 ([{fd=4, revents=POLLIN|POLLOUT|POLLERR|POLLHUP}])
sendto(4, "POST / HTTP/1.1\r\nContent-Length:"..., 169, 0, NULL, 0) = -1 ECONNREFUSED (Connection refused)
sendto(4, "POST / HTTP/1.1\r\nContent-Length:"..., 169, 0, NULL, 0) = -1 EPIPE (Broken pipe)
--- SIGPIPE {si_signo=SIGPIPE, si_code=SI_USER, si_pid=10817, si_uid=1000} ---
sendto(4, "POST / HTTP/1.1\r\nContent-Length:"..., 169, 0, NULL, 0) = -1 EPIPE (Broken pipe)
--- SIGPIPE {si_signo=SIGPIPE, si_code=SI_USER, si_pid=10817, si_uid=1000} ---
close(4)                                = 0
socket(AF_INET6, SOCK_STREAM, IPPROTO_IP) = 4
setsockopt(4, SOL_SOCKET, SO_REUSEADDR, [1], 4) = 0
setsockopt(4, SOL_SOCKET, SO_REUSEPORT, [1], 4) = 0
setsockopt(4, SOL_TCP, TCP_NODELAY, [1], 4) = 0
fcntl(4, F_SETFD, FD_CLOEXEC)           = 0
fcntl(4, F_GETFL)                       = 0x2 (flags O_RDWR)
fcntl(4, F_SETFL, O_RDWR|O_NONBLOCK)    = 0
connect(4, {sa_family=AF_INET6, sin6_port=htons(631), inet_pton(AF_INET6, "::1", &sin6_addr), sin6_flowinfo=0, sin6_scope_id=0}, 28) = -1 EINPROGRESS (Operation now in progress)
fcntl(4, F_SETFL, O_RDWR)               = 0
poll([{fd=4, events=POLLIN|POLLOUT}], 1, 100) = 1 ([{fd=4, revents=POLLIN|POLLOUT|POLLERR|POLLHUP}])
sendto(4, "POST / HTTP/1.1\r\nContent-Length:"..., 169, 0, NULL, 0) = -1 ECONNREFUSED (Connection refused)
sendto(4, "POST / HTTP/1.1\r\nContent-Length:"..., 169, 0, NULL, 0) = -1 EPIPE (Broken pipe)
--- SIGPIPE {si_signo=SIGPIPE, si_code=SI_USER, si_pid=10817, si_uid=1000} ---
sendto(4, "POST / HTTP/1.1\r\nContent-Length:"..., 169, 0, NULL, 0) = -1 EPIPE (Broken pipe)
--- SIGPIPE {si_signo=SIGPIPE, si_code=SI_USER, si_pid=10817, si_uid=1000} ---
close(4)                                = 0
socket(AF_INET6, SOCK_STREAM, IPPROTO_IP) = 4
setsockopt(4, SOL_SOCKET, SO_REUSEADDR, [1], 4) = 0
setsockopt(4, SOL_SOCKET, SO_REUSEPORT, [1], 4) = 0
setsockopt(4, SOL_TCP, TCP_NODELAY, [1], 4) = 0
fcntl(4, F_SETFD, FD_CLOEXEC)           = 0
fcntl(4, F_GETFL)                       = 0x2 (flags O_RDWR)
fcntl(4, F_SETFL, O_RDWR|O_NONBLOCK)    = 0
connect(4, {sa_family=AF_INET6, sin6_port=htons(631), inet_pton(AF_INET6, "::1", &sin6_addr), sin6_flowinfo=0, sin6_scope_id=0}, 28) = -1 EINPROGRESS (Operation now in progress)
fcntl(4, F_SETFL, O_RDWR)               = 0
poll([{fd=4, events=POLLIN|POLLOUT}], 1, 100) = 1 ([{fd=4, revents=POLLIN|POLLOUT|POLLERR|POLLHUP}])
sendto(4, "POST / HTTP/1.1\r\nContent-Length:"..., 169, 0, NULL, 0) = -1 ECONNREFUSED (Connection refused)
sendto(4, "POST / HTTP/1.1\r\nContent-Length:"..., 169, 0, NULL, 0) = -1 EPIPE (Broken pipe)
--- SIGPIPE {si_signo=SIGPIPE, si_code=SI_USER, si_pid=10817, si_uid=1000} ---
sendto(4, "POST / HTTP/1.1\r\nContent-Length:"..., 169, 0, NULL, 0) = -1 EPIPE (Broken pipe)
--- SIGPIPE {si_signo=SIGPIPE, si_code=SI_USER, si_pid=10817, si_uid=1000} ---
close(4)                                = 0
socket(AF_INET6, SOCK_STREAM, IPPROTO_IP) = 4
setsockopt(4, SOL_SOCKET, SO_REUSEADDR, [1], 4) = 0
setsockopt(4, SOL_SOCKET, SO_REUSEPORT, [1], 4) = 0
setsockopt(4, SOL_TCP, TCP_NODELAY, [1], 4) = 0
fcntl(4, F_SETFD, FD_CLOEXEC)           = 0
fcntl(4, F_GETFL)                       = 0x2 (flags O_RDWR)
fcntl(4, F_SETFL, O_RDWR|O_NONBLOCK)    = 0
connect(4, {sa_family=AF_INET6, sin6_port=htons(631), inet_pton(AF_INET6, "::1", &sin6_addr), sin6_flowinfo=0, sin6_scope_id=0}, 28) = -1 EINPROGRESS (Operation now in progress)
fcntl(4, F_SETFL, O_RDWR)               = 0
poll([{fd=4, events=POLLIN|POLLOUT}], 1, 100) = 1 ([{fd=4, revents=POLLIN|POLLOUT|POLLERR|POLLHUP}])
sendto(4, "POST / HTTP/1.1\r\nContent-Length:"..., 169, 0, NULL, 0) = -1 ECONNREFUSED (Connection refused)
sendto(4, "POST / HTTP/1.1\r\nContent-Length:"..., 169, 0, NULL, 0) = -1 EPIPE (Broken pipe)
--- SIGPIPE {si_signo=SIGPIPE, si_code=SI_USER, si_pid=10817, si_uid=1000} ---
sendto(4, "POST / HTTP/1.1\r\nContent-Length:"..., 169, 0, NULL, 0) = -1 EPIPE (Broken pipe)
--- SIGPIPE {si_signo=SIGPIPE, si_code=SI_USER, si_pid=10817, si_uid=1000} ---
close(4)                                = 0
socket(AF_INET6, SOCK_STREAM, IPPROTO_IP) = 4
setsockopt(4, SOL_SOCKET, SO_REUSEADDR, [1], 4) = 0
setsockopt(4, SOL_SOCKET, SO_REUSEPORT, [1], 4) = 0
setsockopt(4, SOL_TCP, TCP_NODELAY, [1], 4) = 0
fcntl(4, F_SETFD, FD_CLOEXEC)           = 0
fcntl(4, F_GETFL)                       = 0x2 (flags O_RDWR)
fcntl(4, F_SETFL, O_RDWR|O_NONBLOCK)    = 0
connect(4, {sa_family=AF_INET6, sin6_port=htons(631), inet_pton(AF_INET6, "::1", &sin6_addr), sin6_flowinfo=0, sin6_scope_id=0}, 28) = -1 EINPROGRESS (Operation now in progress)
fcntl(4, F_SETFL, O_RDWR)               = 0
poll([{fd=4, events=POLLIN|POLLOUT}], 1, 100) = 1 ([{fd=4, revents=POLLIN|POLLOUT|POLLERR|POLLHUP}])
sendto(4, "POST / HTTP/1.1\r\nContent-Length:"..., 169, 0, NULL, 0) = -1 ECONNREFUSED (Connection refused)
sendto(4, "POST / HTTP/1.1\r\nContent-Length:"..., 169, 0, NULL, 0) = -1 EPIPE (Broken pipe)
--- SIGPIPE {si_signo=SIGPIPE, si_code=SI_USER, si_pid=10817, si_uid=1000} ---
sendto(4, "POST / HTTP/1.1\r\nContent-Length:"..., 169, 0, NULL, 0) = -1 EPIPE (Broken pipe)
--- SIGPIPE {si_signo=SIGPIPE, si_code=SI_USER, si_pid=10817, si_uid=1000} ---
close(4)                                = 0
socket(AF_INET6, SOCK_STREAM, IPPROTO_IP) = 4
setsockopt(4, SOL_SOCKET, SO_REUSEADDR, [1], 4) = 0
setsockopt(4, SOL_SOCKET, SO_REUSEPORT, [1], 4) = 0
setsockopt(4, SOL_TCP, TCP_NODELAY, [1], 4) = 0
fcntl(4, F_SETFD, FD_CLOEXEC)           = 0
fcntl(4, F_GETFL)                       = 0x2 (flags O_RDWR)
fcntl(4, F_SETFL, O_RDWR|O_NONBLOCK)    = 0
connect(4, {sa_family=AF_INET6, sin6_port=htons(631), inet_pton(AF_INET6, "::1", &sin6_addr), sin6_flowinfo=0, sin6_scope_id=0}, 28) = -1 EINPROGRESS (Operation now in progress)
fcntl(4, F_SETFL, O_RDWR)               = 0
poll([{fd=4, events=POLLIN|POLLOUT}], 1, 100) = 1 ([{fd=4, revents=POLLIN|POLLOUT|POLLERR|POLLHUP}])
sendto(4, "POST / HTTP/1.1\r\nContent-Length:"..., 169, 0, NULL, 0) = -1 ECONNREFUSED (Connection refused)
sendto(4, "POST / HTTP/1.1\r\nContent-Length:"..., 169, 0, NULL, 0) = -1 EPIPE (Broken pipe)
--- SIGPIPE {si_signo=SIGPIPE, si_code=SI_USER, si_pid=10817, si_uid=1000} ---
sendto(4, "POST / HTTP/1.1\r\nContent-Length:"..., 169, 0, NULL, 0) = -1 EPIPE (Broken pipe)
--- SIGPIPE {si_signo=SIGPIPE, si_code=SI_USER, si_pid=10817, si_uid=1000} ---
close(4)                                = 0
socket(AF_INET6, SOCK_STREAM, IPPROTO_IP) = 4
setsockopt(4, SOL_SOCKET, SO_REUSEADDR, [1], 4) = 0
setsockopt(4, SOL_SOCKET, SO_REUSEPORT, [1], 4) = 0
setsockopt(4, SOL_TCP, TCP_NODELAY, [1], 4) = 0
fcntl(4, F_SETFD, FD_CLOEXEC)           = 0
fcntl(4, F_GETFL)                       = 0x2 (flags O_RDWR)
fcntl(4, F_SETFL, O_RDWR|O_NONBLOCK)    = 0
connect(4, {sa_family=AF_INET6, sin6_port=htons(631), inet_pton(AF_INET6, "::1", &sin6_addr), sin6_flowinfo=0, sin6_scope_id=0}, 28strace: Process 10817 detached
 <detached ...>
@Sworddragon
Copy link

Based on the Wine report this should be the same as #4867. As I'm using only the libraries and not the CUPS service this could explain why Wine hangs.

@michaelrsweet
Copy link
Collaborator

Investigating, but I don't think we changed anything here that would cause infinite retries... :/

@michaelrsweet michaelrsweet added this to the 2.2 milestone Aug 23, 2016
@michaelrsweet michaelrsweet self-assigned this Aug 23, 2016
@michaelrsweet
Copy link
Collaborator

Testing on macOS shows we get the (expected) 30 second timeout and no retries.

This might be Linux-specific...

@michaelrsweet
Copy link
Collaborator

Yes, something is up with asynchronous connections on Linux...

michaelrsweet added a commit that referenced this issue Aug 25, 2016
@michaelrsweet
http*Connect did not work on Linux when cupsd was not running (Issue #…
4c3f8a9 
…4870)
@michaelrsweet
Copy link
Collaborator

[master 4c3f8a9] http*Connect did not work on Linux when cupsd was not running (Issue #4870)

@xuzhen
Copy link
Author

xuzhen commented Aug 26, 2016 •
edited
Loading

It seems the fix is incomplete. Compiled the sample programe with the latest cups source code. It still attempted to connect continually, and sent data into socket file descriptor -1

socket(AF_INET6, SOCK_STREAM, IPPROTO_IP) = 4
setsockopt(4, SOL_SOCKET, SO_REUSEADDR, [1], 4) = 0
setsockopt(4, SOL_SOCKET, SO_REUSEPORT, [1], 4) = 0
setsockopt(4, SOL_TCP, TCP_NODELAY, [1], 4) = 0
fcntl(4, F_SETFD, FD_CLOEXEC)           = 0
fcntl(4, F_GETFL)                       = 0x2 (flags O_RDWR)
fcntl(4, F_SETFL, O_RDWR|O_NONBLOCK)    = 0
connect(4, {sa_family=AF_INET6, sin6_port=htons(631), inet_pton(AF_INET6, "::1", &sin6_addr), sin6_flowinfo=0, sin6_scope_id=0}, 28) = -1 EINPROGRESS (Operation now in progress)
fcntl(4, F_SETFL, O_RDWR)               = 0
poll([{fd=4, events=POLLIN|POLLOUT}], 1, 100) = 1 ([{fd=4, revents=POLLIN|POLLOUT|POLLERR|POLLHUP}])
close(4)                                = 0
uname({sysname="Linux", nodename="ubuntu", ...}) = 0
socket(AF_INET6, SOCK_STREAM, IPPROTO_IP) = 4
setsockopt(4, SOL_SOCKET, SO_REUSEADDR, [1], 4) = 0
setsockopt(4, SOL_SOCKET, SO_REUSEPORT, [1], 4) = 0
setsockopt(4, SOL_TCP, TCP_NODELAY, [1], 4) = 0
fcntl(4, F_SETFD, FD_CLOEXEC)           = 0
fcntl(4, F_GETFL)                       = 0x2 (flags O_RDWR)
fcntl(4, F_SETFL, O_RDWR|O_NONBLOCK)    = 0
connect(4, {sa_family=AF_INET6, sin6_port=htons(631), inet_pton(AF_INET6, "::1", &sin6_addr), sin6_flowinfo=0, sin6_scope_id=0}, 28) = -1 EINPROGRESS (Operation now in progress)
fcntl(4, F_SETFL, O_RDWR)               = 0
poll([{fd=4, events=POLLIN|POLLOUT}], 1, 100) = 1 ([{fd=4, revents=POLLIN|POLLOUT|POLLERR|POLLHUP}])
close(4)                                = 0
sendto(-1, "POST / HTTP/1.1\r\nContent-Length:"..., 168, 0, NULL, 0) = -1 EBADF (Bad file descriptor)
sendto(-1, "POST / HTTP/1.1\r\nContent-Length:"..., 168, 0, NULL, 0) = -1 EBADF (Bad file descriptor)
socket(AF_INET6, SOCK_STREAM, IPPROTO_IP) = 4
setsockopt(4, SOL_SOCKET, SO_REUSEADDR, [1], 4) = 0
setsockopt(4, SOL_SOCKET, SO_REUSEPORT, [1], 4) = 0
setsockopt(4, SOL_TCP, TCP_NODELAY, [1], 4) = 0
fcntl(4, F_SETFD, FD_CLOEXEC)           = 0
fcntl(4, F_GETFL)                       = 0x2 (flags O_RDWR)
fcntl(4, F_SETFL, O_RDWR|O_NONBLOCK)    = 0
connect(4, {sa_family=AF_INET6, sin6_port=htons(631), inet_pton(AF_INET6, "::1", &sin6_addr), sin6_flowinfo=0, sin6_scope_id=0}, 28) = -1 EINPROGRESS (Operation now in progress)
fcntl(4, F_SETFL, O_RDWR)               = 0
poll([{fd=4, events=POLLIN|POLLOUT}], 1, 100) = 1 ([{fd=4, revents=POLLIN|POLLOUT|POLLERR|POLLHUP}])
close(4)                                = 0
socket(AF_INET6, SOCK_STREAM, IPPROTO_IP) = 4
setsockopt(4, SOL_SOCKET, SO_REUSEADDR, [1], 4) = 0
setsockopt(4, SOL_SOCKET, SO_REUSEPORT, [1], 4) = 0
setsockopt(4, SOL_TCP, TCP_NODELAY, [1], 4) = 0
fcntl(4, F_SETFD, FD_CLOEXEC)           = 0
fcntl(4, F_GETFL)                       = 0x2 (flags O_RDWR)
fcntl(4, F_SETFL, O_RDWR|O_NONBLOCK)    = 0
connect(4, {sa_family=AF_INET6, sin6_port=htons(631), inet_pton(AF_INET6, "::1", &sin6_addr), sin6_flowinfo=0, sin6_scope_id=0}, 28) = -1 EINPROGRESS (Operation now in progress)
fcntl(4, F_SETFL, O_RDWR)               = 0
poll([{fd=4, events=POLLIN|POLLOUT}], 1, 100) = 1 ([{fd=4, revents=POLLIN|POLLOUT|POLLERR|POLLHUP}])
close(4)                                = 0
sendto(-1, "POST / HTTP/1.1\r\nContent-Length:"..., 168, 0, NULL, 0) = -1 EBADF (Bad file descriptor)
sendto(-1, "POST / HTTP/1.1\r\nContent-Length:"..., 168, 0, NULL, 0) = -1 EBADF (Bad file descriptor)
socket(AF_INET6, SOCK_STREAM, IPPROTO_IP) = 4
setsockopt(4, SOL_SOCKET, SO_REUSEADDR, [1], 4) = 0
setsockopt(4, SOL_SOCKET, SO_REUSEPORT, [1], 4) = 0
setsockopt(4, SOL_TCP, TCP_NODELAY, [1], 4) = 0
fcntl(4, F_SETFD, FD_CLOEXEC)           = 0
fcntl(4, F_GETFL)                       = 0x2 (flags O_RDWR)
fcntl(4, F_SETFL, O_RDWR|O_NONBLOCKstrace: Process 4527 detached
 <detached ...>

@michaelrsweet
Copy link
Collaborator

What happens if you run the "testcups" unit test program in the "cups" directory?

In my Ubuntu VM the testcups program (which does a cupsGetDests call) exits immediately with an error.

@xuzhen
Copy link
Author

xuzhen commented Aug 27, 2016 •
edited
Loading

I ran the testcups program, and it still went into that endless loop on both ubuntu 16.04 and 16.10 without cups-daemon package installed.
If cups-daemon is not removed in your VM, you should run sudo systemctl stop cups.socket cups.service to stop the daemon and its socket listener. Otherwise systemd will revive cupsd automatically when any program connects to /var/run/cups/cups.sock

@zdohnal
Copy link
Contributor

zdohnal commented Sep 8, 2016

Hi,
I debugged that "testcups" unit test program on Fedora with cups.service, cups.path and cups.socket stopped and I found out following information. Program doesn't run in infinite loop, but it keeps sending requests for 30s and ends with error after that. Program never gets into sections where you applied patch, because nfds is 0 (so program doesn't get into 'for' loops on l.271 and l.304 in http-addrlist.c) and result of poll on l.277 is 0 (so it doesn't get into if statement on l.302 in http-addrlist.c). Errno is set ECONNREFUSED (111). I created patch, which makes "testcups" ends immediately:
http://paste.fedoraproject.org/423885/47334039/
, but it fails when I run 'make check'.

@zdohnal
Copy link
Contributor

zdohnal commented Sep 8, 2016

But now, when I changed only condition on line 302 (without application of your patch or any other changes) in http-addrlist.c to:

if(result >= 0)

testcups failed immediately and even 'make check' ran almost without fails (only one fail happened, but it was test, which was failing even before my change). Is it correct?

@michaelrsweet
Copy link
Collaborator

In this case, "result" contains the number of file descriptors that connected. Since none have connected, returning an address with no connection is the wrong behavior.

@michaelrsweet michaelrsweet reopened this Sep 9, 2016
@michaelrsweet
Copy link
Collaborator

OK, I think I've found the "problem". The connection loop did not break out early if all of the addresses failed before the timeout. Thus, cupsGetDests (and other API functions) would take 30 seconds to timeout before continuing.

[master e8916f4] Allow http*Connect to return early if all addresses fail (Issue #4870)

michaelrsweet added a commit that referenced this issue Sep 9, 2016
@michaelrsweet
Allow http*Connect to return early if all addresses fail (Issue #4870)
e8916f4
@bluetech
Copy link

bluetech commented Sep 18, 2016 •
edited
Loading

Hi @michaelrsweet,

It looks like this issue is still present in the released version 2.2.0. Here are bug reports from Arch Linux:

For myself: after upgrading to libcups 2.2.0 the "gnome-settings-daemon" started to show 100% CPU usage. Attaching with gdb showed an infinite loop in libcups around the "http*" functions (I don't have cupsd running). Downgrading to libcups 2.1.4 resolved this issue.

@michaelrsweet
Copy link
Collaborator

I need to see a backtrace from gdb or ltrace output so we can see what is happening.

@bluetech
Copy link

Here is a looping backtrace, by attaching gdb to the gnome-settings-daemon process:

#0  0x00007ff4e143d40d in connect () from /usr/lib/libpthread.so.0
#1  0x00007ff4b63fea77 in httpAddrConnect2 () from /usr/lib/libcups.so.2
#2  0x00007ff4b63fd3be in httpReconnect2 () from /usr/lib/libcups.so.2
#3  0x00007ff4b642293f in cupsSendRequest () from /usr/lib/libcups.so.2
#4  0x00007ff4b6422d54 in cupsDoIORequest () from /usr/lib/libcups.so.2
#5  0x00007ff4b63ef49b in _cupsGetDests () from /usr/lib/libcups.so.2
#6  0x00007ff4b63f063f in cupsGetDests2 () from /usr/lib/libcups.so.2
#7  0x00007ff4b6653ccd in ?? () from /usr/lib/gnome-settings-daemon-3.0/libprint-notifications.so
#8  0x00007ff4e1693d1a in g_main_context_dispatch () from /usr/lib/libglib-2.0.so.0
#9  0x00007ff4e16940d0 in ?? () from /usr/lib/libglib-2.0.so.0
#10 0x00007ff4e16943f2 in g_main_loop_run () from /usr/lib/libglib-2.0.so.0
#11 0x00007ff4e2429a65 in gtk_main () from /usr/lib/libgtk-3.so.0
#12 0x0000000000403780 in main ()

@genodeftest
Copy link

Same issue reported on downstream RedHat (Fedora) Bugzilla: https://bugzilla.redhat.com/show_bug.cgi?id=1366775

From this report:
Steps to reproduce:

  1. disable cups.service
  2. disable cups socket
  3. run any application that is using cups-libs to communicate with cups service, e.g. gnome-settings-daemon or gnome-control-center.

I'm seeing the same backtrace, here are a few more details:

#0  0x00007fdcad19d8ed in connect () at ../sysdeps/unix/syscall-template.S:84
No locals.
#1  0x00007fdc80db3db7 in httpAddrConnect2 (addrlist=0x55703f160180, sock=sock@entry=0x55703f160870, msec=msec@entry=30000, 
    cancel=cancel@entry=0x0) at http-addrlist.c:197
        val = 1
        flags = 2
        remaining = 30000
        i = <optimized out>
        nfds = 0
        fds = {22, 0 <repeats 99 times>}
        result = <optimized out>
        addrs = {0x55703f160180, 0x0 <repeats 48 times>, 0x3, 0x0, 0x7ffcde4d0ea0, 0x7ffcde4d0e90, 0x7fdc80def54a, 0x7ffcde4d1018, 
          0x0, 0x7fdcad1840c0 <_IO_strn_jumps>, 0x7fdcace151b1 <_IO_vfprintf_internal+1937>, 0x0, 0x277, 0x7ffcde4d09f8, 0xa, 
          0x7ffcde4d0a20, 0x64, 0x0, 0x100000010, 0x7ffcde4d09d0, 0x7ffc00000010, 0x7ffcde4d09e0, 0x7ffcde4d09a0, 0x0, 
          0x7fdcad19d6a9 <close+57>, 0x0, 0x7fdc80db2cef <httpAddrClose+31>, 0x55703f15f9b9, 0x834b195aa1f4d500, 0x0, 
          0x7fdc80db3c56 <httpAddrConnect2+550>, 0xff, 0x1, 0x55703f160870, 0x7530, 0x0, 0x7ffcde4d0a1c, 0x55703f15f9b9, 0x13f15f9fa, 
          0x557000000016, 0x55703f15f9b9, 0x55703f15fab8, 0x0, 0x0, 0x0, 0x0, 0x0, 0x400000000, 0x0, 0x0, 0x3, 0x0, 0x7ffcde4d1020}
        pfds = {{fd = -565374960, events = 32764, revents = 0}, {fd = -2132903428, events = 32732, revents = 0}, {fd = -565374568, 
            events = 32764, revents = 0}, {fd = 0, events = 0, revents = 0}, {fd = -1390919488, events = 32732, revents = 0}, {
            fd = -1394519631, events = 32732, revents = 0}, {fd = 0, events = 0, revents = 0}, {fd = 724, events = 0, revents = 0}, {
            fd = -565376136, events = 32764, revents = 0}, {fd = 10, events = 0, revents = 0}, {fd = -565376096, events = 32764, 
            revents = 0}, {fd = 100, events = 0, revents = 0}, {fd = 0, events = 0, revents = 0}, {fd = 0, events = 1, revents = 0}, {
            fd = -565375019, events = 32764, revents = 0}, {fd = 0, events = 0, revents = 0}, {fd = -1, events = -1, revents = -1}, {
            fd = 0, events = 0, revents = 0}, {fd = 0, events = 0, revents = 0}, {fd = 1058400288, events = 21872, revents = 0}, {
            fd = 0, events = 32764, revents = 0}, {fd = 3, events = 0, revents = 0}, {fd = -565376016, events = 32764, revents = 0}, {
            fd = 0, events = 0, revents = 0}, {fd = 3432, events = 0, revents = 0}, {fd = 3, events = 0, revents = 0}, {
            fd = -2132903428, events = 32732, revents = 0}, {fd = 0, events = 115, revents = 0}, {fd = -565375920, events = 32764, 
            revents = 0}, {fd = -2132903424, events = 32732, revents = 0}, {fd = 0, events = 0, revents = 0}, {fd = 0, events = 0, 
            revents = 0}, {fd = 0, events = 0, revents = 0}, {fd = 0, events = 0, revents = 0}, {fd = 1058406784, events = 21872, 
            revents = 0}, {fd = -565375920, events = 32764, revents = 0}, {fd = 1058406784, events = 21872, revents = 0}, {fd = 40, 
            events = 48, revents = 0}, {fd = -565374352, events = 32764, revents = 0}, {fd = -565374544, events = 32764, 
            revents = 0}, {fd = 0, events = 0, revents = 0}, {fd = 0, events = 0, revents = 0}, {fd = 0, events = 0, revents = 0}, {
            fd = 0, events = 0, revents = 0}, {fd = 0, events = 0, revents = 0}, {fd = 0, events = 0, revents = 0}, {fd = 0, 
            events = 0, revents = 0}, {fd = 0, events = 0, revents = 0}, {fd = 0, events = 0, revents = 0}, {fd = -2133142876, 
            events = 32732, revents = 0}, {fd = 0, events = 0, revents = 0}, {fd = -1577790208, events = 6490, revents = -31925}, {
            fd = 0, events = 0, revents = 0}, {fd = -2132923645, events = 32732, revents = 0}, {fd = -565375790, events = 32764, 
            revents = 0}, {fd = -565375660, events = 32764, revents = 0}, {fd = 1970170188, events = 120, revents = 0}, {fd = 0, 
            events = 0, revents = 0}, {fd = 0, events = 0, revents = 0}, {fd = 0, events = 0, revents = 0}, {fd = 0, events = 0, 
            revents = 0}, {fd = 0, events = 0, revents = 0}, {fd = 0, events = 0, revents = 0}, {fd = 0, events = 0, revents = 0}, {
            fd = 1936220928, events = 28276, revents = 11618}, {fd = 51, events = 0, revents = 0}, {fd = 0, events = 0, revents = 0}, 
          {fd = 0, events = 0, revents = 0}, {fd = 0, events = 0, revents = 0}, {fd = 0, events = 0, revents = 0}, {fd = 0, 
            events = 0, revents = 0}, {fd = 0, events = 0, revents = 0}, {fd = 775159808, events = 11832, revents = 11568}, {
            fd = 1668427312, events = 11830, revents = 26983}, {fd = 825110644, events = 26158, revents = 12899}, {fd = 947400245, 
            events = 24374, revents = 13366}, {fd = 0, events = 0, revents = 0}, {fd = 0, events = 0, revents = 0}, {fd = 0, 
            events = 0, revents = 0}, {fd = 0, events = 0, revents = 0}, {fd = 587202560, events = 8241, revents = 19795}, {
            fd = 1867325520, events = 8302, revents = 25939}, {fd = 842080368, events = 12576, revents = 14905}, {fd = 893007409, 
            events = 8244, revents = 21589}, {fd = 808591427, events = 13873, revents = 0}, {fd = 0, events = 0, revents = 0}, {
            fd = 0, events = 0, revents = 0}, {fd = 0, events = 0, revents = 0}, {fd = 0, events = 14456, revents = 24374}, {
            fd = -1577790208, events = 6490, revents = -31925}, {fd = 0, events = 0, revents = 0}, {fd = 0, events = 0, revents = 0}, 
          {fd = 22, events = 0, revents = 0}, {fd = -1390814509, events = 32732, revents = 0}, {fd = 0, events = 0, revents = 0}, {
            fd = -1, events = -1, revents = -1}, {fd = 1058408560, events = 21872, revents = 0}, {fd = -565375552, events = 32764, 
            revents = 0}, {fd = 0, events = 0, revents = 0}, {fd = -2132904361, events = 32732, revents = 0}}
#2  0x00007fdc80db2302 in httpReconnect2 (http=http@entry=0x55703f160870, msec=msec@entry=30000, cancel=cancel@entry=0x0)
    at http.c:2413
        addr = <optimized out>
#3  0x00007fdc80db1dff in http_send (http=http@entry=0x55703f160870, request=request@entry=HTTP_STATE_POST, 
    uri=uri@entry=0x7fdc80de7657 "/") at http.c:4330
        i = <optimized out>
        buf = "/", '\000' <repeats 36 times>, "\066\063\061\000\000\000\000\000\000\000\000\240\016M\336\374\177\000\000\240\016M\336\374\177\000\000\000\021M\336\374\177\000\000J\365ހ\334\177\000\000\030\020M\336\374\177\000\000\001\000\000\000\000\000\000\000\376\000\000\000\000\000\000\000\006\350\355\254\334\177\000\000\001\200\255\373\000\000\000\000\000\021M\336\374\177\000\000\000\021M\336\374\177\000\000\000\021M\336\374\177\000\000\026\000\000\000\005\000\035\000\003\021M\336\374\177\000\000\026\000\000\000\005\000\035\000\000\021M\336\374\177\000\000\376\021M\336\374\177", '\000' <repeats 26 times>...
        value = <optimized out>
        codes = {0x0, 0x7fdc80de81b8 "OPTIONS", 0x7fdc80de81cb "GET", 0x0, 0x7fdc80de81ee "HEAD", 0x7fdc80de81fe "POST", 0x0, 0x0, 
          0x7fdc80de8238 "PUT", 0x0, 0x7fdc80de825b "DELETE", 0x7fdc80de826d "TRACE", 0x7fdc80de7ba5 "CLOSE", 0x0, 0x0}
#4  0x00007fdc80db26d5 in httpPost (http=http@entry=0x55703f160870, uri=uri@entry=0x7fdc80de7657 "/") at http.c:1878
No locals.
#5  0x00007fdc80dda1c5 in cupsSendRequest (http=http@entry=0x55703f160870, request=request@entry=0x55703f15cfa0, 
    resource=resource@entry=0x7fdc80de7657 "/", length=length@entry=724) at request.c:712
        status = HTTP_STATUS_NONE
        got_status = <optimized out>
        state = <optimized out>
        expect = HTTP_STATUS_CONTINUE
#6  0x00007fdc80dda744 in cupsDoIORequest (http=0x55703f160870, http@entry=0x0, request=request@entry=0x55703f15cfa0, 
    resource=resource@entry=0x7fdc80de7657 "/", infile=infile@entry=-1, outfile=outfile@entry=-1) at request.c:211
        response = 0x0
        length = 724
        status = <optimized out>
        fileinfo = {st_dev = 0, st_ino = 0, st_nlink = 0, st_mode = 0, st_uid = 0, st_gid = 0, __pad0 = 0, st_rdev = 0, st_size = 0, 
          st_blksize = 0, st_blocks = 0, st_atim = {tv_sec = 0, tv_nsec = 0}, st_mtim = {tv_sec = 0, tv_nsec = 0}, st_ctim = {
            tv_sec = 0, tv_nsec = 0}, __glibc_reserved = {0, 0, 0}}
        bytes = <optimized out>
        buffer = '\000' <repeats 12640 times>...
#7  0x00007fdc80ddab16 in cupsDoRequest (http=http@entry=0x0, request=request@entry=0x55703f15cfa0, 
    resource=resource@entry=0x7fdc80de7657 "/") at request.c:301
No locals.
#8  0x00007fdc80da2dbb in _cupsGetDests (http=http@entry=0x0, op=op@entry=IPP_OP_CUPS_GET_PRINTERS, name=name@entry=0x0, 
    dests=dests@entry=0x55703f03c910, type=type@entry=0, mask=mask@entry=134217728) at dest.c:1633
        num_dests = 0
        dest = <optimized out>
        request = 0x55703f15cfa0
        response = <optimized out>
        attr = <optimized out>
        printer_name = <optimized out>
        uri = "[\000\000\000n", '\000' <repeats 19 times>, "w\000\000\000|", '\000' <repeats 11 times>, "\060x\020?pU\000\000@\224\n?pU\000\000\200h\020?pU\000\000\200x\020?pU\000\000\335(A\255\334\177\000\000\002\000\000\000\000\000\000\000Z5>\255\334\177\000\000\000\000\000\000\000\000\000\000\241\064>\255\334\177\000\000\220\200\020?pU\000\000\331\345S\260\334\177\000\000\300\224M\336\374\177\000\000\364ET\260\334\177\000\000 \227\r?pU\000\000\300\230\r?pU\000\000\b\000\000\000\000\000\000\000\300\224M\336\374\177\000\000 \000\000\000\b\000\000\000\025\000\001\000\376\312\355\376\006\000\000\000\377\377\377\377"...
        num_options = <optimized out>
        options = 0x0
        optname = "\000\000\000\000\000\000\000\000\035k6\260\334\177\000\000\000\000\000\000\000\000\000\000\364\374\066\260\002", '\000' <repeats 11 times>, "w\036B\203\334\177\000\000\000\000\000\000\000\000\000\000\035k6\260\334\177\000\000\000\000\000\000\000\000\000\000\364\374\066\260\002", '\000' <repeats 11 times>, "l\036B\203\334\177\000\000\000\000\000\000\000\000\000\000\035k6\260\334\177\000\000\000\000\000\000\000\000\000\000{)\215|\002", '\000' <repeats 11 times>, "\035k6\260\334\177\000\000\000\000\000\000\000\000\000\000\364\374\066\260\002", '\000' <repeats 11 times>, "p)\215|\334\177\000\000\000\000\000\000\000\000\000\000\035k6\260\334\177\000\000\000\000\000\000\000\000\000\000"...
        value = "\230\000\000\000\000\000\000\000\t\000\000\000\000\000\000\000\230IX\260\334\177\000\000\340\235M\336\374\177\000\000\245\204\233\254\334\177\000\000\203\315\066\260\334\177\000\000\000\000\001\000\001\000\001\000\230IX\260\334\177\000\000@\243M\336\374\177\000\000S\320\066\260\334\177\000\000\001\000\000\000\000\000\000\000\230IX\260\334\177\000\000\000\000\000\000\000\000\000\000\223\215\210\004\315vl\347`]:\255\334\177\000\000N\304\066\260\334\177\000\000\001\000\000\000\000\000\000\000\210\317U\260\334\177\000\000`\234M\336\374\177\000\000\223\215\210\004\315vl\347\270\r\001\203\334\177\000\000N\304\066\260\334\177\000\000\001\000\000\000\000\000\000\000\320\304U\260\334\177\000\000\220\234M\336\374\177\000\000"...
        ptr = <optimized out>
        pattrs = {0x7fdc80de67c1 "auth-info-required", 0x7fdc80de6762 "device-uri", 0x7fdc80de5fa1 "job-sheets-default", 
          0x7fdc80de67d4 "marker-change-time", 0x7fdc80de67e7 "marker-colors", 0x7fdc80de67f5 "marker-high-levels", 
          0x7fdc80de6808 "marker-levels", 0x7fdc80de6816 "marker-low-levels", 0x7fdc80de6828 "marker-message", 
          0x7fdc80de6837 "marker-names", 0x7fdc80de6844 "marker-types", 0x7fdc80de6851 "printer-commands", 
          0x7fdc80de6938 "printer-defaults", 0x7fdc80de66e1 "printer-info", 0x7fdc80de688e "printer-is-accepting-jobs", 
          0x7fdc80de6862 "printer-is-shared", 0x7fdc80de6642 "printer-location", 0x7fdc80de66ee "printer-make-and-model", 
          0x7fdc80de6970 "printer-mandatory-job-attributes", 0x7fdc80de6716 "printer-name", 0x7fdc80de674b "printer-state", 
          0x7fdc80de6874 "printer-state-change-time", 0x7fdc80deb9d0 "printer-state-reasons", 0x7fdc80de6682 "printer-type", 
          0x7fdc80de6735 "printer-uri-supported"}
#9  0x00007fdc80da403f in cupsGetDests2 (http=http@entry=0x0, dests=dests@entry=0x55703f03c910) at dest.c:1855
        num_dests = <optimized out>
        dest = <optimized out>
        home = <optimized out>
        filename = "h\r\000\000\000\000\000\000@8\344\254\334\177\000\000Ѕ\020?pU\000\000\300C\030\255\334\177\000\000\n", '\000' <repeats 11 times>, "\001\000\000\000\377\003\000\000\000\000\000\000\302J\344\254\334\177\000\000O\254M\336\374\177\000\000Ѕ\020?pU", '\000' <repeats 19 times>, "\004\000\000\000\000\000\000\300\201\020?pU\000\000Ѕ\020?pU\000\000\034\323\344\254\334\177\000\000с\020?pU\000\000\277\205\020?pU\000\000\000\004\000\000\000\000\000\000Ѕ\020?pU\000\000\000\000\000\000\000\000\000\000\300C\030\255\334\177\000\000\000\004\000\000\000\000\000\000\300\201\020?pU\000\000Ѕ\020?pU\000\000\034\323\344\254\334\177"...
        defprinter = <optimized out>
        name = "f\000\000\000\000\000\000\000\032\336\344\254\334\177\000\000H\000\000\000\000\000\000\000(", '\000' <repeats 15 times>, "d\000\000\000\000\000\000\000\360\316\025?pU\000\000`\201\020?pU\000\000\340z\030\255\334\177\000\000Ё\020?pU\000\000Q\000\000\000\000\000\000\000P\a\000\000\000\000\000\000!\000\000\000\000\000\000\000\332\304\344\254\334\177\000\000\335\000\000\000\000\000\000\000\260A\002?pU\000\000\300A\002?pU\000\000O\000\000\000\000\000\000\000O\000\000\000\000\000\000\000\340z\030\255\334\177\000\000p\000\000\000\000\000\000\000F\326\344\254\334\177\000\000p\201\020?pU\000\000@\000\000\000\000\000\000\000@\000\000\000\000\000\000\000\340"...
        instance = <optimized out>
        user_default = <optimized out>
        num_reals = <optimized out>
        reals = <optimized out>
        cg = 0x55703f15e800
#10 0x00007fdc80da42d2 in cupsGetDests (dests=dests@entry=0x55703f03c910) at dest.c:1802
No locals.
#11 0x00007fdc8100ca55 in gsd_print_notifications_manager_start_idle (data=data@entry=0x55703f03c960)
    at gsd-print-notifications-manager.c:1362
        manager = 0x55703f03c960
        __func__ = "gsd_print_notifications_manager_start_idle"
#12 0x00007fdcad3f1987 in g_idle_dispatch (source=0x55703f044190, 
    callback=0x7fdc8100c980 <gsd_print_notifications_manager_start_idle>, user_data=0x55703f03c960) at gmain.c:5543
        again = <optimized out>
#13 0x00007fdcad3f4f22 in g_main_dispatch (context=0x55703ed05b00) at gmain.c:3201
        dispatch = 0x7fdcad3f1970 <g_idle_dispatch>
        prev_source = 0x0
        was_in_call = 0
        user_data = 0x55703f03c960
        callback = 0x7fdc8100c980 <gsd_print_notifications_manager_start_idle>
        cb_funcs = 0x7fdcad6bb280 <g_source_callback_funcs>
        cb_data = 0x55703f044200
        need_destroy = <optimized out>
        source = 0x55703f044190
        current = 0x55703ecd3520
        i = 6
#14 g_main_context_dispatch (context=context@entry=0x55703ed05b00) at gmain.c:3854
No locals.
#15 0x00007fdcad3f52a0 in g_main_context_iterate (context=0x55703ed05b00, block=block@entry=1, dispatch=dispatch@entry=1, 
    self=<optimized out>) at gmain.c:3927
        max_priority = 200
        timeout = 0
        some_ready = 1
        nfds = 6
        allocated_nfds = 6
        fds = <optimized out>
#16 0x00007fdcad3f55c2 in g_main_loop_run (loop=0x55703ef9d1b0) at gmain.c:4123
        __func__ = "g_main_loop_run"
#17 0x00007fdcaefd9fe5 in gtk_main () at gtkmain.c:1295
        loop = 0x55703ef9d1b0
#18 0x000055703d63866b in main (argc=<optimized out>, argv=<optimized out>) at main.c:434
        __func__ = "main"

@michaelrsweet michaelrsweet reopened this Sep 19, 2016
@michaelrsweet
Copy link
Collaborator

Reopening for now; with the changes in the released 2.2.0 I was unable to get this behavior in my Ubuntu and Fedora VMs, but I will re-test and try to duplicate.

@xuzhen
Copy link
Author

xuzhen commented Sep 19, 2016 •
edited
Loading

I think this bug is cause by this return: https://github.com/apple/cups/blob/master/cups/http-addrlist.c#L329

When cupsd is not running, nfds=1, fds[0].revents=POLLIN|POLLOUT|POLLERR|POLLHUP, the for loop will not assign value to neither *sock nor addrlist.

But addrlist is not NULL because it has been assigned here https://github.com/apple/cups/blob/master/cups/http-addrlist.c#L239. The caller of httpAddrConnect2() will think the connection has been established.

Add addrlist = NULL; before the for loop fix this issue on my system

@zdohnal
Copy link
Contributor

zdohnal commented Sep 20, 2016

Xuzhen's patch worked for me.

@xuzhen
Copy link
Author

xuzhen commented Sep 20, 2016

@michaelrsweet I found that If /var/run/cups/cups.sock already exists, connect() in httpAddrConnect2() tried to connect to it and failed with ECONNREFUSED, then everything worked as expected. But if /var/run/cups/cups.sock not exists, connect() tried to connect to localhost and failed with EINPROGRESS, then this bug appeared. Maybe this is the reason why this bug cannot be reproducedin your VMs

@zdohnal
Copy link
Contributor

zdohnal commented Sep 20, 2016

@michaelrsweet I think the first issue, what Xu Zhen talks about, is solved by your previous patch ('Allow http*Connect to return early if all addresses fail'). To reproduce this, I needed to stop cups.service, cups.path and cups.socket. But to reproduce issue, which Xu Zhen's patch fixed, I needed to disable all these services in addition to stopping them.

@xuzhen
Copy link
Author

xuzhen commented Sep 20, 2016

@zdohnal Yes, /var/run/cups/cups.sock was created by cups.socket unit at startup. Just stop the unit will not delete it.

@michaelrsweet
Copy link
Collaborator

@xuzhen Your fix breaks printers/services that have more than one address. Which is basically always the case these days...

@michaelrsweet
Copy link
Collaborator

OK, the poll/select that detects an error with any of the previous sockets will (incorrectly) return the next address in the list rather than continuing until all connections have failed.

@michaelrsweet
Copy link
Collaborator

[master 0ca77b3] Handle partial failures when connecting (Issue #4866)

Please let me know if the latest changes do not solve your issues...

@michaelrsweet
Copy link
Collaborator

(and of course I messed up the commit message...)

@michaelrsweet michaelrsweet mentioned this issue Sep 20, 2016
Closed
michaelrsweet added a commit that referenced this issue Sep 20, 2016
@michaelrsweet
Use self-signed certificates over CA-signed ones (Issue #4870)
7b98e44
@xuzhen
Copy link
Author

xuzhen commented Sep 21, 2016

It worked for me

@zdohnal
Copy link
Contributor

zdohnal commented Sep 22, 2016

Worked for me.

@michaelrsweet
Copy link
Collaborator

Good, let's call this fixed then. 2.2.1 release will be released soon with this fix...

@michaelrsweet
Copy link
Collaborator

(soon being in a week or so)

frugalware-repo pushed a commit to frugalware/frugalware-current that referenced this issue Sep 29, 2016
@abucodonosor
cups-2.2.0-3-x86_64
4d4ef30 
* added patch for apple/cups#4870
@michaelrsweet michaelrsweet mentioned this issue Nov 11, 2016
Closed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@michaelrsweet michaelrsweet

Labels
priority-high
Projects
None yet
Milestone
CUPS 2.2.x Updates
Development

No branches or pull requests
6 participants
@Sworddragon @xuzhen @michaelrsweet @genodeftest @bluetech @zdohnal