[scponly] Intermittently working sftp
Whit Blauvelt
whit at transpect.com
Mon Jun 15 12:56:12 EDT 2009
On Mon, Jun 15, 2009 at 08:17:25AM -0700, Kaleb Pederson wrote:
> That's an odd situation. The only thing that might help diagnose the
> problem is if you can grab a log of system calls with strace. The logs may
> help uncover something different in the way the system calls are
> happening.
Thanks Kaleb. It does tell something. The pipe to the log is breaking. But
why? Here's an excerpt from a session where it breaks:
---
execve("/usr/local/sbin/scponlyc", ["scponlyc", "-c", "/usr/lib/openssh/sftp-server"], [/* 10 vars */]) = 0
brk(0) = 0x91fe000
fcntl64(0, F_GETFD) = 0
fcntl64(1, F_GETFD) = 0
fcntl64(2, F_GETFD) = 0
access("/etc/suid-debug", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/ld.so.nohwcap", F_OK) = -1 ENOENT (No such file or directory)
mmap2(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb80cd000
access("/etc/ld.so.preload", R_OK) = -1 ENOENT (No such file or directory)
open("/etc/ld.so.cache", O_RDONLY) = 3
fstat64(3, {st_mode=S_IFREG|0644, st_size=50742, ...}) = 0
mmap2(NULL, 50742, PROT_READ, MAP_PRIVATE, 3, 0) = 0xb80c0000
close(3) = 0
access("/etc/ld.so.nohwcap", F_OK) = -1 ENOENT (No such file or directory)
open("/lib/tls/i686/cmov/libc.so.6", O_RDONLY) = 3
read(3, "\177ELF\1\1\1\0\0\0\0\0\0\0\0\0\3\0\3\0\1\0\0\0\340g\1"..., 512) = 512
fstat64(3, {st_mode=S_IFREG|0755, st_size=1425800, ...}) = 0
mmap2(NULL, 1431152, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0xb7f62000
mmap2(0xb80ba000, 12288, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x158) = 0xb80ba000
mmap2(0xb80bd000, 9840, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xb80bd000
close(3) = 0
mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb7f61000
set_thread_area({entry_number:-1 -> 6, base_addr:0xb7f616b0, limit:1048575, seg_32bit:1, contents:0, read_exec_only:0, limit_in_pages:1, seg_not_prese
mprotect(0xb80ba000, 8192, PROT_READ) = 0
mprotect(0x804b000, 4096, PROT_READ) = 0
mprotect(0xb80ea000, 4096, PROT_READ) = 0
munmap(0xb80c0000, 50742) = 0
brk(0) = 0x91fe000
brk(0x921f000) = 0x921f000
open("/usr/local/etc/scponly/debuglevel", O_RDONLY) = 3
fstat64(3, {st_mode=S_IFREG|0644, st_size=2, ...}) = 0
mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb80cc000
read(3, "2\n", 4096) = 2
close(3) = 0
munmap(0xb80cc000, 4096) = 0
socket(PF_FILE, SOCK_DGRAM, 0) = 3
fcntl64(3, F_SETFD, FD_CLOEXEC) = 0
connect(3, {sa_family=AF_FILE, path="/dev/log"}, 110) = 0
time(NULL) = 1245083828
open("/etc/localtime", O_RDONLY) = 4
fstat64(4, {st_mode=S_IFREG|0644, st_size=3519, ...}) = 0
fstat64(4, {st_mode=S_IFREG|0644, st_size=3519, ...}) = 0
mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb80cc000
read(4, "TZif2\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\4\0\0\0\4\0\0"..., 4096) = 3519
_llseek(4, -24, [3495], SEEK_CUR) = 0
read(4, "\nEST5EDT,M3.2.0,M11.1.0\n", 4096) = 24
close(4) = 0
munmap(0xb80cc000, 4096) = 0
stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=3519, ...}) = 0
getpid() = 8018
writev(2, [{"scponly[8018]: chrooted binary i"..., 54}, {"\n", 1}], 2) = -1 EPIPE (Broken pipe)
--- SIGPIPE (Broken pipe) @ 0 (0) ---
---
And here's one that works where the pipe doesn't break:
---
execve("/usr/local/sbin/scponlyc", ["scponlyc", "-c", "/usr/lib/openssh/sftp-server"], [/* 10 vars */]) = 0
brk(0) = 0x90b6000
fcntl64(0, F_GETFD) = 0
fcntl64(1, F_GETFD) = 0
fcntl64(2, F_GETFD) = 0
access("/etc/suid-debug", F_OK) = -1 ENOENT (No such file or directory)
access("/etc/ld.so.nohwcap", F_OK) = -1 ENOENT (No such file or directory)
mmap2(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb7fb1000
access("/etc/ld.so.preload", R_OK) = -1 ENOENT (No such file or directory)
open("/etc/ld.so.cache", O_RDONLY) = 3
fstat64(3, {st_mode=S_IFREG|0644, st_size=50742, ...}) = 0
mmap2(NULL, 50742, PROT_READ, MAP_PRIVATE, 3, 0) = 0xb7fa4000
close(3) = 0
access("/etc/ld.so.nohwcap", F_OK) = -1 ENOENT (No such file or directory)
open("/lib/tls/i686/cmov/libc.so.6", O_RDONLY) = 3
read(3, "\177ELF\1\1\1\0\0\0\0\0\0\0\0\0\3\0\3\0\1\0\0\0\340g\1"..., 512) = 512
fstat64(3, {st_mode=S_IFREG|0755, st_size=1425800, ...}) = 0
mmap2(NULL, 1431152, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0xb7e46000
mmap2(0xb7f9e000, 12288, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x158) = 0xb7f9e000
mmap2(0xb7fa1000, 9840, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xb7fa1000
close(3) = 0
mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb7e45000
set_thread_area({entry_number:-1 -> 6, base_addr:0xb7e456b0, limit:1048575, seg_32bit:1, contents:0, read_exec_only:0, limit_in_pages:1, seg_not_prese
mprotect(0xb7f9e000, 8192, PROT_READ) = 0
mprotect(0x804b000, 4096, PROT_READ) = 0
mprotect(0xb7fce000, 4096, PROT_READ) = 0
munmap(0xb7fa4000, 50742) = 0
brk(0) = 0x90b6000
brk(0x90d7000) = 0x90d7000
open("/usr/local/etc/scponly/debuglevel", O_RDONLY) = 3
fstat64(3, {st_mode=S_IFREG|0644, st_size=2, ...}) = 0
mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb7fb0000
read(3, "2\n", 4096) = 2
close(3) = 0
munmap(0xb7fb0000, 4096) = 0
socket(PF_FILE, SOCK_DGRAM, 0) = 3
fcntl64(3, F_SETFD, FD_CLOEXEC) = 0
connect(3, {sa_family=AF_FILE, path="/dev/log"}, 110) = 0
time(NULL) = 1245084219
open("/etc/localtime", O_RDONLY) = 4
fstat64(4, {st_mode=S_IFREG|0644, st_size=3519, ...}) = 0
fstat64(4, {st_mode=S_IFREG|0644, st_size=3519, ...}) = 0
mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb7fb0000
read(4, "TZif2\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\4\0\0\0\4\0\0"..., 4096) = 3519
_llseek(4, -24, [3495], SEEK_CUR) = 0
read(4, "\nEST5EDT,M3.2.0,M11.1.0\n", 4096) = 24
close(4) = 0
munmap(0xb7fb0000, 4096) = 0
stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=3519, ...}) = 0
getpid() = 8569
writev(2, [{"scponly[8569]: chrooted binary i"..., 54}, {"\n", 1}], 2) = 55
send(3, "<86>Jun 15 12:43:39 scponly[8569"..., 74, MSG_NOSIGNAL) = 74
time(NULL) = 1245084219
stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=3519, ...}) = 0
writev(2, [{"scponly[8569]: 3 arguments in to"..., 36}, {"\n", 1}], 2) = 37
send(3, "<87>Jun 15 12:43:39 scponly[8569"..., 56, MSG_NOSIGNAL) = 56
time(NULL) = 1245084219
... [and onward]
---
I'm not picking up on any critical difference before the breakaga. So why
would the pipe often (not always) break?
Whit
More information about the scponly
mailing list