Bug 1415090 - gssproxy 0.6 failed to start
Summary: gssproxy 0.6 failed to start
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: Fedora
Classification: Fedora
Component: gssproxy
Version: 25
Hardware: Unspecified
OS: Unspecified
unspecified
urgent
Target Milestone: ---
Assignee: Robbie Harwood
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2017-01-20 08:48 UTC by Lukas Slebodnik
Modified: 2017-01-29 00:20 UTC (History)
3 users (show)

Fixed In Version: gssproxy-0.6.1-2.fc25
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed: 2017-01-29 00:20:47 UTC
Type: Bug


Attachments (Terms of Use)

Description Lukas Slebodnik 2017-01-20 08:48:44 UTC
Description of problem:
The latest upgrade of gssproxy broke start op gssproxy.service

Version-Release number of selected component (if applicable):
sh$ rpm -q  gssproxy krb5-libs
gssproxy-0.6.0-1.fc26.x86_64
krb5-libs-1.15-4.fc26.x86_64

How reproducible:
Deterministic

Steps to Reproduce:
1. systemctl start gssproxy.service
2. systemclt status gssproxy.service

Actual results:
[root@graviton ~]# systemctl start gssproxy
Job for gssproxy.service failed because the control process exited with error code.
See "systemctl status gssproxy.service" and "journalctl -xe" for details.
[root@graviton ~]# systemctl status gssproxy
● gssproxy.service - GSSAPI Proxy Daemon
   Loaded: loaded (/usr/lib/systemd/system/gssproxy.service; disabled; vendor preset: disabled)
   Active: failed (Result: exit-code) since Fri 2017-01-20 09:47:04 CET; 5s ago
  Process: 3588 ExecStart=/usr/sbin/gssproxy -D (code=exited, status=1/FAILURE)

Jan 20 09:47:04 graviton.brq.redhat.com systemd[1]: Starting GSSAPI Proxy Daemon...
Jan 20 09:47:04 graviton.brq.redhat.com gssproxy[3588]: Failed to read krb5 config for service/nfs-server.
Jan 20 09:47:04 graviton.brq.redhat.com gssproxy[3588]: Error reading configuration -1765328203: Unknown error -1765328203
Jan 20 09:47:04 graviton.brq.redhat.com systemd[1]: gssproxy.service: Control process exited, code=exited status=1
Jan 20 09:47:04 graviton.brq.redhat.com systemd[1]: Failed to start GSSAPI Proxy Daemon.
Jan 20 09:47:04 graviton.brq.redhat.com systemd[1]: gssproxy.service: Unit entered failed state.
Jan 20 09:47:04 graviton.brq.redhat.com systemd[1]: gssproxy.service: Failed with result 'exit-code'.


Expected results:
Service start without problems

Additional info:

Comment 1 Lukas Slebodnik 2017-01-20 08:52:46 UTC
Debug output does not help a lot (at least for me). And there are not any AVCs 

sh# systemctl status gssproxy
● gssproxy.service - GSSAPI Proxy Daemon
   Loaded: loaded (/usr/lib/systemd/system/gssproxy.service; disabled; vendor preset: disabled)
  Drop-In: /run/systemd/system/gssproxy.service.d
           └─debug.conf
   Active: failed (Result: exit-code) since Fri 2017-01-20 09:50:17 CET; 3s ago
  Process: 3640 ExecStart=/usr/sbin/gssproxy -D -d (code=exited, status=1/FAILURE)

Jan 20 09:50:17 host.example.com systemd[1]: Starting GSSAPI Proxy Daemon...
Jan 20 09:50:17 host.example.com gssproxy[3640]: Failed to read krb5 config for service/nfs-server.
Jan 20 09:50:17 host.example.com gssproxy[3640]: [2017/01/20 08:50:17]: Debug Enabled (level: 0)
Jan 20 09:50:17 host.example.com gssproxy[3640]: [2017/01/20 08:50:17]: Config file(s) not found! 
Jan 20 09:50:17 host.example.com gssproxy[3640]: Error reading configuration -1765328203: Unknown error -1765328203
Jan 20 09:50:17 host.example.com systemd[1]: gssproxy.service: Control process exited, code=exited status=1
Jan 20 09:50:17 host.example.com systemd[1]: Failed to start GSSAPI Proxy Daemon.
Jan 20 09:50:17 host.example.com systemd[1]: gssproxy.service: Unit entered failed state. 
Jan 20 09:50:17 host.example.com systemd[1]: gssproxy.service: Failed with result 'exit-code'.

Comment 2 Lukas Slebodnik 2017-01-20 08:55:24 UTC
strace is a little bit more helpful

stat("/etc/krb5.conf", {st_mode=S_IFREG|0644, st_size=1037, ...}) = 0
open("/etc/krb5.conf", O_RDONLY)        = 3
fcntl(3, F_SETFD, FD_CLOEXEC)           = 0
fstat(3, {st_mode=S_IFREG|0644, st_size=1037, ...}) = 0
read(3, "# To opt out of the system crypt"..., 4096) = 1037
open("/etc/krb5.conf.d/", O_RDONLY|O_NONBLOCK|O_DIRECTORY|O_CLOEXEC) = 4
fstat(4, {st_mode=S_IFDIR|0755, st_size=106, ...}) = 0
getdents(4, /* 5 entries */, 32768)     = 176
open("/etc/krb5.conf.d//crypto-policies", O_RDONLY) = 5
fstat(5, {st_mode=S_IFREG|0644, st_size=125, ...}) = 0
read(5, "permitted_enctypes = aes256-cts-"..., 4096) = 125
read(5, "", 4096)                       = 0
close(5)                                = 0
open("/etc/krb5.conf.d//fedoraproject_org", O_RDONLY) = 5
fstat(5, {st_mode=S_IFREG|0644, st_size=181, ...}) = 0
read(5, "[realms]\n FEDORAPROJECT.ORG = {\n"..., 4096) = 181
read(5, "", 4096)                       = 0
close(5)                                = 0
open("/etc/krb5.conf.d//stg_fedoraproject_org", O_RDONLY) = 5
fstat(5, {st_mode=S_IFREG|0644, st_size=205, ...}) = 0
read(5, "[realms]\n STG.FEDORAPROJECT.ORG "..., 4096) = 205
read(5, "", 4096)                       = 0
close(5)                                = 0
getdents(4, /* 0 entries */, 32768)     = 0
close(4)                                = 0
read(3, "", 4096)                       = 0
close(3)                                = 0
getpid()                                = 3687
open("/etc/krb5.keytab", O_RDONLY)      = -1 ENOENT (No such file or directory)
open("/etc/localtime", O_RDONLY|O_CLOEXEC) = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=2272, ...}) = 0
fstat(3, {st_mode=S_IFREG|0644, st_size=2272, ...}) = 0
read(3, "TZif2\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\7\0\0\0\7\0\0\0\0"..., 4096) = 2272
lseek(3, -1449, SEEK_CUR)               = 823
read(3, "TZif2\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\10\0\0\0\10\0\0\0\0"..., 4096) = 1449
close(3)                                = 0
socket(AF_UNIX, SOCK_DGRAM|SOCK_CLOEXEC, 0) = 3
connect(3, {sa_family=AF_UNIX, sun_path="/dev/log"}, 110) = 0
sendto(3, "<11>Jan 20 09:53:36 gssproxy: Fa"..., 81, MSG_NOSIGNAL, NULL, 0) = 81
sendto(3, "<11>Jan 20 09:53:36 gssproxy: Er"..., 96, MSG_NOSIGNAL, NULL, 0) = 96
write(2, "[2017/01/20 08:53:36]: ", 23) = 23
write(2, "Debug Enabled (level: 0)\n", 25) = 25
write(2, "[2017/01/20 08:53:36]: ", 23) = 23
write(2, "Config file(s) not found!\n", 26) = 26

Comment 3 Lukas Slebodnik 2017-01-20 11:46:25 UTC
The same bug is even without fedora specific configure files.

stat("/etc/krb5.conf", {st_mode=S_IFREG|0644, st_size=677, ...}) = 0
open("/etc/krb5.conf", O_RDONLY)        = 3
fcntl(3, F_SETFD, FD_CLOEXEC)           = 0
fstat(3, {st_mode=S_IFREG|0644, st_size=677, ...}) = 0
read(3, "# To opt out of the system crypt"..., 4096) = 677
open("/etc/krb5.conf.d/", O_RDONLY|O_NONBLOCK|O_DIRECTORY|O_CLOEXEC) = 4
fstat(4, {st_mode=S_IFDIR|0755, st_size=29, ...}) = 0
getdents(4, /* 3 entries */, 32768)     = 88
open("/etc/krb5.conf.d//crypto-policies", O_RDONLY) = 5
fstat(5, {st_mode=S_IFREG|0644, st_size=125, ...}) = 0
read(5, "permitted_enctypes = aes256-cts-"..., 4096) = 125
read(5, "", 4096)                       = 0
close(5)                                = 0
getdents(4, /* 0 entries */, 32768)     = 0
close(4)                                = 0
read(3, "", 4096)                       = 0
close(3)                                = 0
gettimeofday({tv_sec=1484912736, tv_usec=354387}, NULL) = 0
open("/etc/krb5.keytab", O_RDONLY)      = -1 ENOENT (No such file or directory)
open("/etc/localtime", O_RDONLY|O_CLOEXEC) = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=2272, ...}) = 0
fstat(3, {st_mode=S_IFREG|0644, st_size=2272, ...}) = 0
read(3, "TZif2\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\7\0\0\0\7\0\0\0\0"..., 4096) = 2272
lseek(3, -1449, SEEK_CUR)               = 823
read(3, "TZif2\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\10\0\0\0\10\0\0\0\0"..., 4096) = 1449
close(3)                                = 0
socket(AF_UNIX, SOCK_DGRAM|SOCK_CLOEXEC, 0) = 3
connect(3, {sa_family=AF_UNIX, sun_path="/dev/log"}, 110) = 0
sendto(3, "<11>Jan 20 12:45:36 gssproxy: Fa"..., 81, MSG_NOSIGNAL, NULL, 0) = 81
sendto(3, "<11>Jan 20 12:45:36 gssproxy: Er"..., 96, MSG_NOSIGNAL, NULL, 0) = 96
write(2, "[2017/01/20 11:45:36]: ", 23) = 23
write(2, "Debug Enabled (level: 0)\n", 25) = 25
write(2, "[2017/01/20 11:45:36]: ", 23) = 23
write(2, "Config file(s) not found!\n", 26) = 26

Comment 4 Fedora Update System 2017-01-20 22:54:29 UTC
gssproxy-0.6.1-1.fc25 has been submitted as an update to Fedora 25. https://bodhi.fedoraproject.org/updates/FEDORA-2017-bdfba1e58c

Comment 5 Fedora Update System 2017-01-21 22:25:59 UTC
gssproxy-0.6.1-1.fc25 has been pushed to the Fedora 25 testing repository. If problems still persist, please make note of it in this bug report.
See https://fedoraproject.org/wiki/QA:Updates_Testing for
instructions on how to install test updates.
You can provide feedback for this update here: https://bodhi.fedoraproject.org/updates/FEDORA-2017-bdfba1e58c

Comment 6 Fedora Update System 2017-01-23 22:22:17 UTC
gssproxy-0.6.1-2.fc25 has been submitted as an update to Fedora 25. https://bodhi.fedoraproject.org/updates/FEDORA-2017-4c47de4898

Comment 7 Fedora Update System 2017-01-28 19:19:12 UTC
gssproxy-0.6.1-2.fc25 has been pushed to the Fedora 25 testing repository. If problems still persist, please make note of it in this bug report.
See https://fedoraproject.org/wiki/QA:Updates_Testing for
instructions on how to install test updates.
You can provide feedback for this update here: https://bodhi.fedoraproject.org/updates/FEDORA-2017-4c47de4898

Comment 8 Fedora Update System 2017-01-29 00:20:47 UTC
gssproxy-0.6.1-2.fc25 has been pushed to the Fedora 25 stable repository. If problems still persist, please make note of it in this bug report.


Note You need to log in before you can comment on or make changes to this bug.