Re: Lease renewal fails with privsep enabled
Roy Marples
Fri Dec 27 15:22:49 2019
Hi Julian
On 24/12/2019 16:57, Julian Wollrath wrote:
Hi,
I tried out the privilege separation code as of commit 81e7d0aa1a6 on
Debian Sid. There is only IPv4 available. The lease I get from the router via
DHCP has a time of 600, so after five minutes dhcpcd tries to renew the
lease. Unfortunately, it does not work. I enabled PRIVSEP_DEBUG and what
I get in the log is:
PRIVSEP_DEBUG is for debugging the internal IPC that privsep requires.
I would imagine it's really only useful for debugging newly added stuff to privsep.
Dez 24 17:15:44 dhcpcd[51128]: sending commands to master dhcpcd process
Dez 24 17:15:57 dhcpcd[51241]: ps_root_recvmsgcb: IN cmd 13, psp (nil)
Dez 24 17:15:57 dhcpcd[51241]: ps_root_recvmsgcb: IN cmd 11, psp (nil)
Dez 24 17:15:57 dhcpcd[51240]: wlp2s0: connected to Access Point `XXX'
Dez 24 17:15:57 dhcpcd[51241]: ps_root_recvmsgcb: IN cmd 11, psp (nil)
Dez 24 17:15:57 dhcpcd[51240]: DUID XXX
Dez 24 17:15:57 dhcpcd[51240]: wlp2s0: IAID XXX
Dez 24 17:15:57 dhcpcd[51240]: wlp2s0: adding address fe80::XXX
Dez 24 17:15:57 dhcpcd[51241]: ps_root_recvmsgcb: IN cmd 13, psp (nil)
Dez 24 17:15:58 dhcpcd[51240]: wlp2s0: rebinding lease of XXX
Dez 24 17:15:58 dhcpcd[51241]: ps_root_recvmsgcb: IN cmd 45, psp (nil)
Dez 24 17:15:58 dhcpcd[51241]: ps_bpf_cmd: IN cmd 45, psp (nil)
Dez 24 17:15:58 dhcpcd[51241]: ps_root_recvmsgcb: IN cmd 46, psp 0x613000000c80
Dez 24 17:15:58 dhcpcd[51241]: ps_root_recvmsgcb: IN cmd 44, psp (nil)
Dez 24 17:15:58 dhcpcd[51241]: ps_bpf_cmd: IN cmd 44, psp (nil)
Dez 24 17:15:58 dhcpcd[51241]: ps_root_recvmsgcb: IN cmd 4, psp 0x613000000e40
Dez 24 17:15:58 dhcpcd[51240]: wlp2s0: probing address XXX
Dez 24 17:15:58 dhcpcd[51241]: ps_root_recvmsgcb: IN cmd 5, psp 0x613000000c80
Dez 24 17:15:58 dhcpcd[51240]: wlp2s0: soliciting an IPv6 router
Dez 24 17:15:59 dhcpcd[51241]: ps_root_recvmsgcb: IN cmd 43, psp (nil)
Dez 24 17:15:59 dhcpcd[51241]: ps_inet_cmd: IN cmd 43, psp (nil)
Dez 24 17:15:59 dhcpcd[51241]: ps_root_recvmsgcb: IN cmd 5, psp 0x613000000c80
Dez 24 17:16:01 dhcpcd[51241]: ps_root_recvmsgcb: IN cmd 5, psp 0x613000000c80
Dez 24 17:16:03 dhcpcd[51240]: wlp2s0: leased XXX for 600 seconds
Dez 24 17:16:03 dhcpcd[51241]: ps_root_recvmsgcb: IN cmd 84, psp 0x613000000e40
Dez 24 17:16:03 dhcpcd[51241]: ps_root_recvmsgcb: IN cmd 13, psp (nil)
Dez 24 17:16:03 dhcpcd[51240]: wlp2s0: adding route to XXX
Dez 24 17:16:03 dhcpcd[51241]: ps_root_recvmsgcb: IN cmd 13, psp (nil)
Dez 24 17:16:03 dhcpcd[51240]: wlp2s0: adding default route via XXX
Dez 24 17:16:03 dhcpcd[51241]: ps_root_recvmsgcb: IN cmd 13, psp (nil)
Dez 24 17:16:03 dhcpcd[51241]: ps_root_recvmsgcb: IN cmd 5, psp 0x613000000c80
Dez 24 17:16:03 dhcpcd[51241]: ps_root_recvmsgcb: IN cmd 11, psp (nil)
Dez 24 17:16:03 dhcpcd[51240]: forked to background, child pid 51240
Dez 24 17:16:03 dhcpcd[51268]: sending commands to master dhcpcd process
Dez 24 17:16:05 dhcpcd[51241]: ps_root_recvmsgcb: IN cmd 5, psp 0x613000000c80
Dez 24 17:16:11 dhcpcd[51240]: wlp2s0: no IPv6 Routers available
Dez 24 17:21:03 dhcpcd[51241]: ps_root_recvmsgcb: IN cmd 1, psp (nil)
Dez 24 17:21:03 dhcpcd[51241]: ps_inet_cmd: IN cmd 1, psp (nil)
Dez 24 17:21:03 dhcpcd[51241]: ps_root_recvmsg: Invalid argument
Dez 24 17:21:08 dhcpcd[51241]: ps_root_recvmsgcb: IN cmd 1, psp (nil)
Dez 24 17:21:08 dhcpcd[51241]: ps_inet_cmd: IN cmd 1, psp (nil)
Dez 24 17:21:08 dhcpcd[51241]: ps_root_recvmsg: Invalid argument
Dez 24 17:21:16 dhcpcd[51241]: ps_root_recvmsgcb: IN cmd 1, psp (nil)
Dez 24 17:21:16 dhcpcd[51241]: ps_inet_cmd: IN cmd 1, psp (nil)
Dez 24 17:21:16 dhcpcd[51241]: ps_root_recvmsg: Invalid argument
Dez 24 17:21:32 dhcpcd[51241]: ps_root_recvmsgcb: IN cmd 1, psp (nil)
Dez 24 17:21:32 dhcpcd[51241]: ps_inet_cmd: IN cmd 1, psp (nil)
Dez 24 17:21:32 dhcpcd[51241]: ps_root_recvmsg: Invalid argument
Dez 24 17:22:04 dhcpcd[51241]: ps_root_recvmsgcb: IN cmd 1, psp (nil)
Dez 24 17:22:04 dhcpcd[51241]: ps_inet_cmd: IN cmd 1, psp (nil)
Dez 24 17:22:04 dhcpcd[51241]: ps_root_recvmsg: Invalid argument
If I start dhcpcd instead with 'dhcpcd -d -j dhcpcd.log wlp2s0' strangely,
the release renewal works:
You didn't say how you were initially starting dhcpcd above.
Was it `dhcpcd j dhcpcd.log wlp2s0` ?
Dec 24 17:09:54 [48832]: dhcpcd-8.99.0 starting
Dec 24 17:09:54 [48834]: spawned privileged actioneer on PID 48835
Dec 24 17:09:54 [48834]: spawned network proxy on PID 48836
Dec 24 17:09:54 [48834]: ps_sendpsmmsg: 124
Dec 24 17:09:54 [48835]: ps_recvpsmsg: 124
Dec 24 17:09:54 [48835]: ps_root_recvmsgcb: IN cmd 13, psp (nil)
Dec 24 17:09:54 [48835]: ps_root_writeerror: result 0 errno 0
Dec 24 17:09:54 [48834]: ps_sendpsmmsg: 64
Dec 24 17:09:54 [48835]: ps_recvpsmsg: 64
Dec 24 17:09:54 [48835]: ps_root_recvmsgcb: IN cmd 43, psp (nil)
Dec 24 17:09:54 [48835]: ps_inet_cmd: IN cmd 43, psp (nil)
Dec 24 17:09:54 [48834]: wlp2s0: executing `/lib/dhcpcd/dhcpcd-run-hooks' PREINIT
Dec 24 17:09:54 [48834]: ps_root_script: sending script: 29 /lib/dhcpcd/dhcpcd-run-hooks len 286
Dec 24 17:09:54 [48834]: ps_root_script: sending script data: 315
Dec 24 17:09:54 [48834]: ps_sendpsmmsg: 379
Dec 24 17:09:54 [48835]: ps_recvpsmsg: 379
Dec 24 17:09:54 [48835]: ps_root_recvmsgcb: IN cmd 11, psp (nil)
Dec 24 17:09:54 [48835]: ps_root_run_script: IN 315
Dec 24 17:09:54 [48835]: ps_root_run_script: run script: /lib/dhcpcd/dhcpcd-run-hooks
Dec 24 17:09:54 [48837]: spawned listener fe80::XXX on PID 48837
Dec 24 17:09:54 [48835]: ps_root_writeerror: result 0 errno 0
Dec 24 17:09:54 [48834]: wlp2s0: connected to Access Point `XXX'
Dec 24 17:09:54 [48834]: wlp2s0: executing `/lib/dhcpcd/dhcpcd-run-hooks' CARRIER
Dec 24 17:09:54 [48834]: ps_root_script: sending script: 29 /lib/dhcpcd/dhcpcd-run-hooks len 286
Dec 24 17:09:54 [48834]: ps_root_script: sending script data: 315
Dec 24 17:09:54 [48834]: ps_sendpsmmsg: 379
Dec 24 17:09:54 [48835]: ps_recvpsmsg: 379
Dec 24 17:09:54 [48835]: ps_root_recvmsgcb: IN cmd 11, psp (nil)
Dec 24 17:09:54 [48835]: ps_root_run_script: IN 315
Dec 24 17:09:54 [48835]: ps_root_run_script: run script: /lib/dhcpcd/dhcpcd-run-hooks
Dec 24 17:09:54 [48835]: ps_root_writeerror: result 0 errno 0
Dec 24 17:09:54 [48834]: DUID XXX
Dec 24 17:09:54 [48834]: wlp2s0: IAID XXX
Dec 24 17:09:54 [48834]: wlp2s0: delaying IPv6 router solicitation for 0.6 seconds
Dec 24 17:09:54 [48834]: wlp2s0: delaying IPv4 for 0.4 seconds
Dec 24 17:09:54 [48834]: wlp2s0: reading lease `/var/lib/dhcpcd/wlp2s0-Tonimoertlhof.lease'
Dec 24 17:09:54 [48834]: wlp2s0: rebinding lease of XXX
Dec 24 17:09:54 [48834]: ps_sendpsmmsg: 320
Dec 24 17:09:54 [48835]: ps_recvpsmsg: 320
Dec 24 17:09:54 [48834]: ps_sendpsmmsg: 68
Dec 24 17:09:54 [48834]: wlp2s0: ARP announcing XXX (1 of 2), next in 2.0 seconds
Dec 24 17:09:54 [48835]: ps_root_recvmsgcb: IN cmd 45, psp (nil)
Dec 24 17:09:54 [48834]: ps_sendpsmmsg: 92
Dec 24 17:09:54 [48835]: ps_bpf_cmd: IN cmd 45, psp (nil)
Dec 24 17:09:54 [48834]: wlp2s0: sending REQUEST (xid 0xbac51ede), next in 3.5 seconds
Dec 24 17:09:54 [48834]: ps_sendpsmmsg: 320
Dec 24 17:09:54 [48834]: ps_sendpsmmsg: 449
Dec 24 17:09:54 [48835]: wlp2s0: spawned BPF ARP on PID 48840
Dec 24 17:09:54 [48835]: ps_recvpsmsg: 68
Dec 24 17:09:54 [48835]: ps_root_recvmsgcb: IN cmd 46, psp 0x613000000e40
Dec 24 17:09:54 [48835]: ps_sendpsmmsg: 68
Dec 24 17:09:54 [48835]: ps_recvpsmsg: 92
Dec 24 17:09:54 [48835]: ps_root_recvmsgcb: IN cmd 5, psp 0x613000000e40
Dec 24 17:09:54 [48835]: ps_sendpsmmsg: 92
Dec 24 17:09:54 [48835]: ps_recvpsmsg: 320
Dec 24 17:09:54 [48835]: ps_root_recvmsgcb: IN cmd 44, psp (nil)
Dec 24 17:09:54 [48835]: ps_bpf_cmd: IN cmd 44, psp (nil)
Dec 24 17:09:54 [48835]: wlp2s0: spawned BPF BOOTP on PID 48841
Dec 24 17:09:54 [48835]: ps_recvpsmsg: 449
Dec 24 17:09:54 [48835]: ps_root_recvmsgcb: IN cmd 4, psp 0x613000001000
Dec 24 17:09:54 [48835]: ps_sendpsmmsg: 449
Dec 24 16:09:54 [48840]: ps_recvpsmsg: 68
Dec 24 16:09:54 [48840]: ps_recvpsmsg: 92
Dec 24 16:09:54 [48841]: ps_recvpsmsg: 449
Dec 24 16:09:54 [48841]: ps_sendpsmmsg: 394
Dec 24 17:09:54 [48834]: ps_recvpsmsg: 394
Dec 24 17:09:54 [48834]: wlp2s0: acknowledged XXX from XXX
Dec 24 17:09:54 [48834]: wlp2s0: leased XXX for 600 seconds
Dec 24 17:09:54 [48834]: wlp2s0: renew in 300 seconds, rebind in 525 seconds
Dec 24 17:09:54 [48834]: wlp2s0: writing lease `/var/lib/dhcpcd/wlp2s0-XXX.lease'
Dec 24 17:09:54 [48834]: ps_sendpsmmsg: 64
Dec 24 17:09:54 [48835]: ps_recvpsmsg: 64
Dec 24 17:09:54 [48834]: ps_sendpsmmsg: 64
Dec 24 17:09:54 [48835]: ps_root_recvmsgcb: IN cmd 84, psp 0x613000001000
Dec 24 17:09:54 [48834]: wlp2s0: adding IP address XXX broadcast XXX
Dec 24 17:09:54 [48835]: ps_dostop: pid 48841 fd 7
Dec 24 17:09:54 [48834]: ps_sendpsmmsg: 144
Dec 24 17:09:54 [48835]: ps_sendpsmmsg: 64
Dec 24 16:09:54 [48841]: ps_recvpsmsg: 64
Dec 24 16:09:54 [48841]: process 48841 stopping
Dec 24 17:09:54 [48835]: ps_dostop: status 0
Dec 24 17:09:54 [48835]: ps_recvpsmsg: 64
Dec 24 17:09:54 [48835]: ps_root_recvmsgcb: IN cmd 81, psp (nil)
Dec 24 17:09:54 [48835]: ps_recvpsmsg: 144
Dec 24 17:09:54 [48835]: ps_root_recvmsgcb: IN cmd 13, psp (nil)
Dec 24 17:09:54 [48835]: ps_root_writeerror: result 0 errno 0
Dec 24 17:09:54 [48834]: wlp2s0: adding route to XXX
Dec 24 17:09:54 [48834]: wlp2s0: adding default route via XXX
Dec 24 17:09:54 [48834]: wlp2s0: ARP announcing XXX (1 of 2), next in 2.0 seconds
Dec 24 17:09:54 [48834]: ps_sendpsmmsg: 92
Dec 24 17:09:54 [48835]: ps_recvpsmsg: 92
Dec 24 17:09:54 [48835]: ps_root_recvmsgcb: IN cmd 5, psp 0x613000000e40
Dec 24 17:09:54 [48835]: ps_sendpsmmsg: 92
Dec 24 16:09:54 [48840]: ps_recvpsmsg: 92
Dec 24 17:09:54 [48834]: wlp2s0: executing `/lib/dhcpcd/dhcpcd-run-hooks' REBOOT
Dec 24 17:09:54 [48834]: ps_root_script: sending script: 29 /lib/dhcpcd/dhcpcd-run-hooks len 1021
Dec 24 17:09:54 [48834]: ps_root_script: sending script data: 1050
Dec 24 17:09:54 [48834]: ps_sendpsmmsg: 1114
Dec 24 17:09:54 [48835]: ps_recvpsmsg: 1114
Dec 24 17:09:54 [48835]: ps_root_recvmsgcb: IN cmd 11, psp (nil)
Dec 24 17:09:54 [48835]: ps_root_run_script: IN 1050
Dec 24 17:09:54 [48835]: ps_root_run_script: run script: /lib/dhcpcd/dhcpcd-run-hooks
Dec 24 17:09:54 [48835]: ps_root_writeerror: result 0 errno 0
Dec 24 17:09:54 [48834]: forked to background, child pid 48834
Dec 24 17:09:54 [48834]: ps_sendpsmmsg: 64
Dec 24 17:09:54 [48835]: ps_recvpsmsg: 64
Dec 24 17:09:54 [48835]: ps_root_recvmsgcb: IN cmd 41, psp (nil)
Dec 24 17:09:54 [48835]: ps_inet_cmd: IN cmd 41, psp (nil)
Dec 24 17:09:54 [48858]: spawned listener XXX on PID 48858
Dec 24 17:09:54 [48834]: wlp2s0: soliciting an IPv6 router
Dec 24 17:09:54 [48834]: wlp2s0: sending Router Solicitation
Dec 24 17:09:54 [48834]: ps_sendpsmmsg: 148
Dec 24 16:09:54 [48836]: ps_recvpsmsg: 148
Dec 24 17:09:56 [48834]: wlp2s0: ARP announcing XXX (2 of 2)
Dec 24 17:09:56 [48834]: ps_sendpsmmsg: 92
Dec 24 17:09:56 [48835]: ps_recvpsmsg: 92
Dec 24 17:09:56 [48835]: ps_root_recvmsgcb: IN cmd 5, psp 0x613000000e40
Dec 24 17:09:56 [48835]: ps_sendpsmmsg: 92
Dec 24 16:09:56 [48840]: ps_recvpsmsg: 92
Dec 24 17:09:58 [48834]: wlp2s0: sending Router Solicitation
Dec 24 17:09:58 [48834]: ps_sendpsmmsg: 148
Dec 24 16:09:58 [48836]: ps_recvpsmsg: 148
Dec 24 17:10:02 [48834]: wlp2s0: sending Router Solicitation
Dec 24 17:10:02 [48834]: ps_sendpsmmsg: 148
Dec 24 16:10:02 [48836]: ps_recvpsmsg: 148
Dec 24 17:10:06 [48834]: wlp2s0: sending Router Solicitation
Dec 24 17:10:06 [48834]: ps_sendpsmmsg: 148
Dec 24 17:10:06 [48834]: wlp2s0: no IPv6 Routers available
Dec 24 16:10:06 [48836]: ps_recvpsmsg: 148
Dec 24 17:14:54 [48834]: wlp2s0: renewing lease of XXX
Dec 24 17:14:54 [48834]: wlp2s0: sending REQUEST (xid 0xfd780c21), next in 4.6 seconds
Dec 24 17:14:54 [48834]: ps_sendpsmmsg: 431
Dec 24 17:14:54 [48835]: ps_recvpsmsg: 431
Dec 24 17:14:54 [48835]: ps_root_recvmsgcb: IN cmd 1, psp 0x613000001380
Dec 24 17:14:54 [48835]: ps_sendpsmmsg: 431
Dec 24 16:14:54 [48858]: ps_recvpsmsg: 431
Dec 24 16:14:54 [48858]: ps_recvmsg: recv fd 5, 302 bytes
Dec 24 16:14:54 [48858]: ps_recvmsg: send fd 9, 414 bytes
Dec 24 17:14:54 [48834]: ps_recvpsmsg: 414
Dec 24 17:14:54 [48834]: wlp2s0: acknowledged XXX from XXX
Dec 24 17:14:54 [48834]: wlp2s0: leased XXX for 600 seconds
Dec 24 17:14:54 [48834]: wlp2s0: renew in 265 seconds, rebind in 490 seconds
Dec 24 17:14:54 [48834]: wlp2s0: writing lease `/var/lib/dhcpcd/wlp2s0-XXX.lease'
Dec 24 17:14:54 [48834]: wlp2s0: adding IP address XXX broadcast XXX
Dec 24 17:14:54 [48834]: ps_sendpsmmsg: 144
Dec 24 17:14:54 [48835]: ps_recvpsmsg: 144
Dec 24 17:14:54 [48835]: ps_root_recvmsgcb: IN cmd 13, psp (nil)
Dec 24 17:14:54 [48835]: ps_root_writeerror: result 0 errno 0
Dec 24 17:14:54 [48834]: wlp2s0: ARP announcing XXX (1 of 2), next in 2.0 seconds
Dec 24 17:14:54 [48834]: ps_sendpsmmsg: 92
Dec 24 17:14:54 [48835]: ps_recvpsmsg: 92
Dec 24 17:14:54 [48835]: ps_root_recvmsgcb: IN cmd 5, psp 0x613000000e40
Dec 24 17:14:54 [48835]: ps_sendpsmmsg: 92
Dec 24 16:14:54 [48840]: ps_recvpsmsg: 92
Dec 24 17:14:54 [48834]: wlp2s0: executing `/lib/dhcpcd/dhcpcd-run-hooks' RENEW
Dec 24 17:14:54 [48834]: ps_root_script: sending script: 29 /lib/dhcpcd/dhcpcd-run-hooks len 1020
Dec 24 17:14:54 [48834]: ps_root_script: sending script data: 1049
Dec 24 17:14:54 [48834]: ps_sendpsmmsg: 1113
Dec 24 17:14:54 [48835]: ps_recvpsmsg: 1113
Dec 24 17:14:54 [48835]: ps_root_recvmsgcb: IN cmd 11, psp (nil)
Dec 24 17:14:54 [48835]: ps_root_run_script: IN 1049
Dec 24 17:14:54 [48835]: ps_root_run_script: run script: /lib/dhcpcd/dhcpcd-run-hooks
Dec 24 17:14:54 [48835]: ps_root_writeerror: result 0 errno 0
Dec 24 17:14:56 [48834]: wlp2s0: ARP announcing XXX (2 of 2)
Dec 24 17:14:56 [48834]: ps_sendpsmmsg: 92
Dec 24 17:14:56 [48835]: ps_recvpsmsg: 92
Dec 24 17:14:56 [48835]: ps_root_recvmsgcb: IN cmd 5, psp 0x613000000e40
Dec 24 17:14:56 [48835]: ps_sendpsmmsg: 92
Dec 24 16:14:56 [48840]: ps_recvpsmsg: 92
Dec 24 17:15:44 [48834]: received SIGTERM, stopping
Dec 24 17:15:44 [48834]: wlp2s0: removing interface
Dec 24 17:15:44 [48834]: ps_sendpsmmsg: 68
Dec 24 17:15:44 [48834]: ps_sendpsmmsg: 64
Dec 24 17:15:44 [48835]: ps_recvpsmsg: 68
Dec 24 17:15:44 [48835]: ps_root_recvmsgcb: IN cmd 26, psp 0x613000000e40
Dec 24 17:15:44 [48835]: ps_sendpsmmsg: 68
Dec 24 17:15:44 [48834]: wlp2s0: executing `/lib/dhcpcd/dhcpcd-run-hooks' STOPPED
Dec 24 17:15:44 [48834]: ps_root_script: sending script: 29 /lib/dhcpcd/dhcpcd-run-hooks len 287
Dec 24 17:15:44 [48835]: ps_recvpsmsg: 64
Dec 24 17:15:44 [48834]: ps_root_script: sending script data: 316
Dec 24 17:15:44 [48835]: ps_root_recvmsgcb: IN cmd 85, psp 0x613000000e40
Dec 24 16:15:44 [48840]: ps_recvpsmsg: 68
Dec 24 17:15:44 [48834]: ps_sendpsmmsg: 380
Dec 24 17:15:44 [48835]: ps_dostop: pid 48840 fd 6
Dec 24 17:15:44 [48835]: ps_sendpsmmsg: 64
Dec 24 16:15:44 [48840]: ps_recvpsmsg: 64
Dec 24 16:15:44 [48840]: process 48840 stopping
Dec 24 17:15:44 [48835]: ps_dostop: status 0
Dec 24 17:15:44 [48835]: ps_recvpsmsg: 380
Dec 24 17:15:44 [48835]: ps_root_recvmsgcb: IN cmd 11, psp (nil)
Dec 24 17:15:44 [48835]: ps_root_run_script: IN 316
Dec 24 17:15:44 [48835]: ps_root_run_script: run script: /lib/dhcpcd/dhcpcd-run-hooks
Dec 24 17:15:44 [48835]: ps_root_writeerror: result 0 errno 0
Dec 24 17:15:44 [48834]: ps_dostop: pid 48836 fd 11
Dec 24 17:15:44 [48834]: ps_sendpsmmsg: 64
Dec 24 16:15:44 [48836]: ps_recvpsmsg: 64
Dec 24 16:15:44 [48836]: process 48836 stopping
Dec 24 17:15:44 [48834]: ps_dostop: status 0
Dec 24 17:15:44 [48834]: ps_dostop: pid 48835 fd 10
Dec 24 17:15:44 [48834]: ps_sendpsmmsg: 64
Dec 24 17:15:44 [48835]: ps_recvpsmsg: 64
Dec 24 17:15:44 [48835]: process 48835 stopping
Dec 24 17:15:44 [48835]: ps_dostop: pid 48837 fd 5
Dec 24 17:15:44 [48835]: ps_sendpsmmsg: 64
Dec 24 16:15:44 [48837]: ps_recvpsmsg: 64
Dec 24 16:15:44 [48837]: process 48837 stopping
Dec 24 17:15:44 [48835]: ps_dostop: status 0
Dec 24 17:15:44 [48835]: ps_dostop: pid 48858 fd 8
Dec 24 17:15:44 [48835]: ps_sendpsmmsg: 64
Dec 24 16:15:44 [48858]: ps_recvpsmsg: 64
Dec 24 16:15:44 [48858]: process 48858 stopping
Dec 24 17:15:44 [48835]: ps_dostop: status 0
Dec 24 17:15:44 [48834]: ps_dostop: status 0
Dec 24 17:15:44 [48834]: dhcpcd exited
This is quite puzzling to me, since the debug option should not
change anything but just print out some more information, right?
Yes.
There are a handful of places where this is not entirely the case though.
By the way, my timezone is GMT+1 but some of the extra processes seem
to have GMT in there timestamp instead, which seems a bit strange.
Probably because some of the daemons chroot to the users home directory.
As only the dhcpcd master process is supposed to log and this doesn't chroot, it
should be correct without PRIVSEP_DEBUG.
I'll try and look into this over the next few days.
Roy
Archive administrator: postmaster@marples.name