[Fli4l_dev] Chrony geh?==?utf-8?Q?t mit dhcp Ciruits nicht on?==?utf-8?Q?line

dark06 at gmx.de dark06 at gmx.de
Mo Nov 12 17:18:41 CET 2018


Hallo Christoph,

Auszug aus dem Syslog für Facilitiy "daemon" 

Nov 12 13:38:48 router daemon.notice mini_httpd[18594]:
mini_httpd/1.29-fli4l 23May2018 starting on router, port 80
Nov 12 13:38:49 router daemon.info chronyd[19626]: chronyd version 3.3
starting (+CMDMON +NTP +REFCLOCK +RTC -PRIVDROP -SCFILTER -SIGND
+ASYNCDNS +SECHASH +IPV6 -DEBUG)
Nov 12 13:38:49 router daemon.err chronyd[19626]: Wrong permissions on
/var/run/chrony
Nov 12 13:38:49 router daemon.warn chronyd[19626]: Disabled command
socket /var/run/chrony/chronyd.sock
Nov 12 13:38:49 router daemon.info chronyd[19626]: Frequency 0.000 +/-
1000000.000 ppm read from /var/lib/persistent/chrony/chrony.drift
Nov 12 13:39:03 router local2.notice circd[3255]:
handle_start_daemon_circuit_message(55#27545:start_daemon_circuit_message):
id=circ1 daemon=dhcpcd daemon_args='-B' '-e' 'circ_id=circ1' '-c'
'/etc/dhcpcd.sh' '-G' '-L' '-b' '--noipv6' '-o'
'classless_static_routes,ms_classless_static_routes,domain_name,domain_name_servers'
'eth3' cleanup_func=
Nov 12 13:39:03 router local2.notice circd[3255]:
circd_daemon_wrapper[circ1]: started child circ1:d
Nov 12 13:39:03 router daemon.warn syslog[28557]: read_config: fopen
`/etc/dhcpcd.conf': No such file or directory
Nov 12 13:39:03 router daemon.warn syslog[28557]: read_config: fopen
`/etc/dhcpcd.conf': No such file or directory
Nov 12 13:39:03 router daemon.info dhcp-client: DHCP event 'PREINIT'
Nov 12 13:39:03 router daemon.info dhcp-client:     sleeping 0 seconds
Nov 12 13:39:03 router daemon.info dhcp-client: DHCP event 'NOCARRIER'
Nov 12 13:39:04 router daemon.info syslog[28557]: eth3: waiting for
carrier
Nov 12 13:39:06 router daemon.info syslog[28557]: eth3: carrier
acquired
Nov 12 13:39:06 router daemon.warn syslog[28557]: read_config: fopen
`/etc/dhcpcd.conf': No such file or directory
Nov 12 13:39:06 router daemon.info dhcp-client: DHCP event 'CARRIER'
Nov 12 13:39:06 router daemon.info dhcp-client:     ignoring dhcp event
'CARRIER'
Nov 12 13:39:08 router daemon.info syslog[28557]: eth3: soliciting a
DHCP lease
Nov 12 13:39:09 router daemon.info syslog[28557]: eth3: offered
100.65.XX.XX from 100.68.0.1
Nov 12 13:39:09 router daemon.info syslog[28557]: eth3: probing address
100.65.XX.XX/17
Nov 12 13:39:14 router daemon.info syslog[28557]: eth3: leased
100.65.XX.XX for 3600 seconds
Nov 12 13:39:14 router daemon.info syslog[28557]: eth3: adding route to
100.65.0.0/17
Nov 12 13:39:15 router daemon.info dhcp-client: DHCP event 'BOUND'
Nov 12 13:39:15 router daemon.debug dhcp-client:
new_broadcast_address='100.65.127.255'
Nov 12 13:39:15 router daemon.debug dhcp-client:
new_dhcp_lease_time='3600'
Nov 12 13:39:15 router daemon.debug dhcp-client:
new_dhcp_message_type='5'
Nov 12 13:39:15 router daemon.debug dhcp-client:
new_dhcp_server_identifier='100.68.0.1'
Nov 12 13:39:15 router daemon.debug dhcp-client:
new_domain_name_servers='185.22.44.50 185.22.45.50'
Nov 12 13:39:15 router daemon.debug dhcp-client:
new_ip_address='100.65.XX.XX'
Nov 12 13:39:15 router daemon.debug dhcp-client:
new_network_number='100.65.0.0'
Nov 12 13:39:15 router daemon.debug dhcp-client:
new_routers='100.65.0.1'
Nov 12 13:39:15 router daemon.debug dhcp-client: new_subnet_cidr='17'
Nov 12 13:39:15 router daemon.debug dhcp-client:
new_subnet_mask='255.255.128.0'
Nov 12 13:39:15 router daemon.notice dhcp-client: Event: up, local:
'100.65.XX.XX/17', remote: '100.65.0.1'
Nov 12 13:39:16 router daemon.info chronyd[19626]: chronyd exiting
Nov 12 13:39:16 router daemon.info chronyd[31968]: chronyd version 3.3
starting (+CMDMON +NTP +REFCLOCK +RTC -PRIVDROP -SCFILTER -SIGND
+ASYNCDNS +SECHASH +IPV6 -DEBUG)
Nov 12 13:39:16 router daemon.err chronyd[31968]: Wrong permissions on
/var/run/chrony
Nov 12 13:39:16 router daemon.warn chronyd[31968]: Disabled command
socket /var/run/chrony/chronyd.sock
Nov 12 13:39:16 router daemon.info chronyd[31968]: Frequency 0.000 +/-
1000000.000 ppm read from /var/lib/persistent/chrony/chrony.drift
Nov 12 13:39:18 router daemon.info acpid: starting up with netlink and
the input layer
Nov 12 13:39:18 router daemon.info acpid: 1 rule loaded
Nov 12 13:39:18 router daemon.info acpid: waiting for events: event
logging is on
Nov 12 13:39:21 router daemon.info chronyd[31968]: System's initial
offset : 14.223825 seconds slow of true (slew)
Nov 12 13:39:23 router local2.notice circd[3255]:
handle_start_daemon_circuit_message(79#2252:start_daemon_circuit_message):
id=circ2 daemon=dibbler-client daemon_args='run' '-w'
'/var/lib/dibbler/circ2' cleanup_func=dhcp_circuit_cleanup
Nov 12 13:39:23 router local2.notice circd[3255]:
circd_daemon_wrapper[circ2]: started child circ2:d
Nov 12 13:39:23 router daemon.debug Dibbler-circ2[4446]: Prefix
delegation option (with scope) found.
Nov 12 13:39:23 router daemon.debug Dibbler-circ2[4446]: PD: Adding
single prefix.
Nov 12 13:39:23 router daemon.debug Dibbler-circ2[4446]: Parsing
/var/lib/dibbler/circ2/client.conf done, result=0(success)
Nov 12 13:39:23 router daemon.debug Dibbler-circ2[4446]: 1 interface(s)
specified in /var/lib/dibbler/circ2/client.conf
Nov 12 13:39:23 router daemon.info Dibbler-circ2[4446]: Interface eth3/5
configuration has been loaded.
Nov 12 13:39:23 router daemon.notice Dibbler-circ2[4446]: Unable to open
DUID file (client-duid), generating new DUID.
Nov 12 13:39:23 router daemon.debug Dibbler-circ2[4446]: DUID creation:
Interface tun0/7 skipped: MAC length is 0, but at least 6 is required.
Nov 12 13:39:23 router daemon.debug Dibbler-circ2[4446]: DUID creation:
Interface dummy0/6 skipped: Interface is down.
Nov 12 13:39:23 router daemon.notice Dibbler-circ2[4446]: DUID creation:
Generating 14-bytes long link-local+time (duid-llt) DUID.
Nov 12 13:39:23 router daemon.notice Dibbler-circ2[4446]: DUID creation:
generated using eth3/5 interface.
Nov 12 13:39:23 router daemon.info Dibbler-circ2[4446]: My DUID is
00:01:00:01:23:7c:30:fb:00:e0:XX:XX:XX:XX.
Nov 12 13:39:23 router daemon.info Dibbler-circ2[4446]: Loading old
address database (client-AddrMgr.xml), using built-in routines.
Nov 12 13:39:23 router daemon.warn Dibbler-circ2[4446]: Unable to open
client-AddrMgr.xml.
Nov 12 13:39:23 router daemon.debug Dibbler-circ2[4446]: Bind reuse
enabled (multiple instances allowed).
Nov 12 13:39:23 router daemon.notice Dibbler-circ2[4446]: Creating
control (::) socket on the lo/1 interface.
Nov 12 13:39:23 router daemon.notice Dibbler-circ2[4446]: Creating
socket (addr=fe80::2e0:XXXX:XXXX:9383) on eth3/5 interface.
Nov 12 13:39:23 router daemon.debug Dibbler-circ2[4446]: Initialising
link-state detection for interfaces: eth3/5 
Nov 12 13:39:23 router daemon.notice Dibbler-circ2[4446]: CONFIRM
support compiled in.
Nov 12 13:39:23 router daemon.info Dibbler-circ2[4446]: Creating SOLICIT
message with 0 IA(s), no TA and 1 PD(s) on eth3/5 interface.
Nov 12 13:39:23 router daemon.debug Dibbler-circ2[4446]: Sending
SOLICIT(opts:1 25 8 ) on eth3/5 to multicast.
Nov 12 13:39:23 router daemon.debug Dibbler-circ2[4446]: Sleeping for 1
second(s).
Nov 12 13:39:23 router daemon.debug Dibbler-circ2[4446]: Received 85
bytes on interface eth3/5 (socket=6, addr=fe80::ff:fe00:17).
Nov 12 13:39:23 router daemon.info Dibbler-circ2[4446]: Received
ADVERTISE on eth3/5,trans-id=0x9787ab, 3 opts: 25 1 2
Nov 12 13:39:23 router daemon.debug Dibbler-circ2[4446]: Script
execution skipped for ADVERTISE response to SOLICIT. No action needed
for this message type.
Nov 12 13:39:23 router daemon.debug Dibbler-circ2[4446]: Sleeping for 1
second(s).
Nov 12 13:39:24 router daemon.info Dibbler-circ2[4446]: Processing msg
(SOLICIT,transID=0x9787ab,opts: 1 25 8)
Nov 12 13:39:24 router daemon.info Dibbler-circ2[4446]: Creating
REQUEST. Backup server list contains 1 server(s).
Nov 12 13:39:24 router daemon.debug Dibbler-circ2[4446]: Advertise from
Server ID=00:01:00:01:1d:9c:43:c4:00:50:XX:XX:XX:XX, no preference
option, assumed 0.[using this]
Nov 12 13:39:24 router daemon.debug Dibbler-circ2[4446]: Sending
REQUEST(opts:1 25 2 8 ) on eth3/5 to multicast.
Nov 12 13:39:24 router daemon.debug Dibbler-circ2[4446]: Sleeping for 1
second(s).
Nov 12 13:39:24 router daemon.debug Dibbler-circ2[4446]: Received 85
bytes on interface eth3/5 (socket=6, addr=fe80::ff:fe00:17).
Nov 12 13:39:24 router daemon.info Dibbler-circ2[4446]: Received REPLY
on eth3/5,trans-id=0x63f52b, 3 opts: 25 1 2
Nov 12 13:39:24 router daemon.notice Dibbler-circ2[4446]: Server set T1
and T2 to 0. Choosing default (50%, 70% * prefered-lifetime): T1=1125,
T2=1575
Nov 12 13:39:24 router daemon.debug Dibbler-circ2[4446]: PD: Adding
2a00:6020:XXXX:XXXX:: prefix to PD (iaid=1) to addrDB.
Nov 12 13:39:24 router daemon.notice Dibbler-circ2[4446]: PD: Adding
prefix 2a00:6020:XXXX:XXXX::/56 to all interfaces (prefix will be split
to /64 prefixes if necessary).
Nov 12 13:39:24 router daemon.debug Dibbler-circ2[4446]: PD: Interface
tun0/7 has MAC address length 0 (6 or more required), ignoring.
Nov 12 13:39:24 router daemon.debug Dibbler-circ2[4446]: PD: Interface
dummy0/6 is down, ignoring.
Nov 12 13:39:24 router daemon.debug Dibbler-circ2[4446]: PD: Interface
eth3/5 is the interface, where prefix has been obtained, skipping.
Nov 12 13:39:24 router daemon.debug Dibbler-circ2[4446]: PD: Interface
eth2/4 is down, ignoring.
Nov 12 13:39:24 router daemon.debug Dibbler-circ2[4446]: PD: Interface
eth1/3 is down, ignoring.
Nov 12 13:39:24 router daemon.debug Dibbler-circ2[4446]: PD: Interface
eth0/2 is suitable for PD.
Nov 12 13:39:24 router daemon.debug Dibbler-circ2[4446]: PD: Interface
lo/1 is not multicast capable, ignoring.
Nov 12 13:39:24 router daemon.info Dibbler-circ2[4446]: PD: Using 1
suitable interface(s):eth0 
Nov 12 13:39:24 router daemon.notice Dibbler-circ2[4446]: PD: Adding
prefix 2a00:6020:XXXX:XXXX::/56 on the eth0/2 interface.
Nov 12 13:39:24 router daemon.debug Dibbler-circ2[4446]: RENEW(IA_PD)
will be sent (T1) after 1125, REBIND (T2) after 1575 seconds.
Nov 12 13:39:24 router daemon.debug Dibbler-circ2[4446]: About to
execute /var/lib/dibbler/circ2/dibbler-notify-circ2.sh script, 15
variables.
Nov 12 13:39:24 router daemon.debug Dibbler-circ2[4446]: Script
execution complete, return code=0
Nov 12 13:39:24 router daemon.debug Dibbler-circ2[4446]: Sleeping for
1124 second(s).
Nov 12 13:39:27 router daemon.info radvd[10970]: version 2.17 started
Nov 12 13:58:08 router daemon.info Dibbler-circ2[4446]: Generating RENEW
for 0 IA(s) and 1 PD(s). 
Nov 12 13:58:08 router daemon.debug Dibbler-circ2[4446]: Sending
RENEW(opts:1 2 25 8 ) on eth3/5 to multicast.
Nov 12 13:58:08 router daemon.debug Dibbler-circ2[4446]: Sleeping for 10
second(s).
Nov 12 13:58:08 router daemon.debug Dibbler-circ2[4446]: Received 85
bytes on interface eth3/5 (socket=6, addr=fe80::ff:fe00:17).
Nov 12 13:58:08 router daemon.info Dibbler-circ2[4446]: Received REPLY
on eth3/5,trans-id=0x70bb0c, 3 opts: 25 1 2
Nov 12 13:58:08 router daemon.notice Dibbler-circ2[4446]: Server set T1
and T2 to 0. Choosing default (50%, 70% * prefered-lifetime): T1=1125,
T2=1575
Nov 12 13:58:08 router daemon.notice Dibbler-circ2[4446]: PD: Updating
prefix 2a00:6020:XXXX:XXXX::/56 to all interfaces (prefix will be split
to /64 prefixes if necessary).
Nov 12 13:58:08 router daemon.debug Dibbler-circ2[4446]: PD: Interface
tun0/7 has MAC address length 0 (6 or more required), ignoring.
Nov 12 13:58:08 router daemon.debug Dibbler-circ2[4446]: PD: Interface
dummy0/6 is down, ignoring.
Nov 12 13:58:08 router daemon.debug Dibbler-circ2[4446]: PD: Interface
eth3/5 is the interface, where prefix has been obtained, skipping.
Nov 12 13:58:08 router daemon.debug Dibbler-circ2[4446]: PD: Interface
eth2/4 is down, ignoring.
Nov 12 13:58:08 router daemon.debug Dibbler-circ2[4446]: PD: Interface
eth1/3 is down, ignoring.
Nov 12 13:58:08 router daemon.debug Dibbler-circ2[4446]: PD: Interface
eth0/2 is suitable for PD.
Nov 12 13:58:08 router daemon.debug Dibbler-circ2[4446]: PD: Interface
lo/1 is not multicast capable, ignoring.
Nov 12 13:58:08 router daemon.info Dibbler-circ2[4446]: PD: Using 1
suitable interface(s):eth0 
Nov 12 13:58:08 router daemon.notice Dibbler-circ2[4446]: PD: Updating
prefix 2a00:6020:XXXX:XXXX::/56 on the eth0/2 interface.
Nov 12 13:58:08 router daemon.debug Dibbler-circ2[4446]: RENEW(IA_PD)
will be sent (T1) after 1125, REBIND (T2) after 1575 seconds.
Nov 12 13:58:08 router daemon.debug Dibbler-circ2[4446]: About to
execute /var/lib/dibbler/circ2/dibbler-notify-circ2.sh script, 21
variables.
Nov 12 13:58:08 router daemon.debug Dibbler-circ2[4446]: Script
execution complete, return code=0
Nov 12 13:58:08 router daemon.debug Dibbler-circ2[4446]: Sleeping for
1125 second(s).
Nov 12 13:58:10 router daemon.info radvd[10973]: attempting to reread
config file
Nov 12 13:58:10 router daemon.info radvd[10973]: resuming normal
operation


Auszug aus dem Syslog für Facilitiy "local2"
Nov 12 13:38:34 router local2.notice circd[3255]: entering message loop
Nov 12 13:38:38 router local2.notice circd[3255]:
handle_create_circuit_message(31#174:create_circuit_message): type=dhcp
Nov 12 13:38:38 router local2.notice circd[3255]:
circd_start_queue[circ1]: started child circ1:q
Nov 12 13:38:38 router local2.notice circd[3255]: circd_change_state:
circuit circ1 changes state from inactive to active
Nov 12 13:38:38 router local2.notice circd[3255]:
handle_create_circuit_message(31#174:create_circuit_message): ACK,
id=circ1
Nov 12 13:38:39 router local2.notice circd[3255]:
handle_create_circuit_message(34#174:create_circuit_message): type=dhcp
Nov 12 13:38:39 router local2.notice circd[3255]:
circd_start_queue[circ2]: started child circ2:q
Nov 12 13:38:39 router local2.notice circd[3255]: circd_change_state:
circuit circ2 changes state from inactive to active
Nov 12 13:38:39 router local2.notice circd[3255]:
handle_create_circuit_message(34#174:create_circuit_message): ACK,
id=circ2
Nov 12 13:38:40 router local2.notice circd[3255]:
handle_create_circuit_message(37#174:create_circuit_message): type=dhcp
Nov 12 13:38:40 router local2.notice circd[3255]:
circd_start_queue[circ3]: started child circ3:q
Nov 12 13:38:40 router local2.notice circd[3255]: circd_change_state:
circuit circ3 changes state from inactive to active
Nov 12 13:38:40 router local2.notice circd[3255]:
handle_create_circuit_message(37#174:create_circuit_message): ACK,
id=circ3
Nov 12 13:38:40 router local2.notice circd[3255]:
handle_create_circuit_message(40#174:create_circuit_message): type=dhcp
Nov 12 13:38:41 router local2.notice circd[3255]:
circd_start_queue[circ4]: started child circ4:q
Nov 12 13:38:41 router local2.notice circd[3255]: circd_change_state:
circuit circ4 changes state from inactive to active
Nov 12 13:38:41 router local2.notice circd[3255]:
handle_create_circuit_message(40#174:create_circuit_message): ACK,
id=circ4
Nov 12 13:38:48 router local2.notice circd[3255]:
circd_circuit_postprocessing: adding reverse dependency internet-v4 -->
circ2
Nov 12 13:38:48 router local2.notice circd[3255]:
circd_circuit_postprocessing: adding reverse dependency internet-v4p -->
circ4
Nov 12 13:39:01 router local2.notice circd[3255]:
handle_set_global_dialmode_message(48#26205:set_global_dialmode_message):
mode=auto
Nov 12 13:39:01 router local2.notice circd[3255]:
handle_set_global_dialmode_message(48#26205:set_global_dialmode_message):
effective dial mode changed for circuit circ1 from off to auto
Nov 12 13:39:01 router local2.notice circd[3255]:
circd_circuit_autodialup: dialling up circ1
Nov 12 13:39:01 router local2.notice circd[3255]: circd_change_state:
circuit circ1 changes state from active to ready
Nov 12 13:39:02 router local2.notice circd[3255]:
handle_set_global_dialmode_message(48#26205:set_global_dialmode_message):
effective dial mode changed for circuit circ2 from off to auto
Nov 12 13:39:02 router local2.notice circ1:q[10715]:
handle_dialup_circuit_queue_message(53#circd:dialup_circuit_queue_message)
Nov 12 13:39:02 router local2.notice dhcp-dhcpcd-circuit-ctrl.sh[27545]:
circ1: starting dhcpcd
Nov 12 13:39:02 router local2.notice circ1:q[10715]:
dhcp-dhcpcd-circuit-ctrl.sh[27545]: circ1: starting dhcpcd
Nov 12 13:39:02 router local2.notice circd[3255]:
handle_set_global_dialmode_message(48#26205:set_global_dialmode_message):
effective dial mode changed for circuit circ3 from off to manual
Nov 12 13:39:02 router local2.notice circd[3255]:
handle_set_global_dialmode_message(48#26205:set_global_dialmode_message):
effective dial mode changed for circuit circ4 from off to auto
Nov 12 13:39:03 router local2.notice circd[3255]:
handle_start_daemon_circuit_message(55#27545:start_daemon_circuit_message):
id=circ1 daemon=dhcpcd daemon_args='-B' '-e' 'circ_id=circ1' '-c'
'/etc/dhcpcd.sh' '-G' '-L' '-b' '--noipv6' '-o'
'classless_static_routes,ms_classless_static_routes,domain_name,domain_name_servers'
'eth3' cleanup_func=
Nov 12 13:39:03 router local2.notice circd[3255]:
circd_daemon_wrapper[circ1]: started child circ1:d
Nov 12 13:39:03 router local2.notice circ1:d[28543]: starting dhcpcd -B
-e circ_id=circ1 -c /etc/dhcpcd.sh -G -L -b --noipv6 -o
classless_static_routes,ms_classless_static_routes,domain_name,domain_name_servers
eth3...
Nov 12 13:39:03 router local2.notice circ1:d[28543]: read_config: fopen
`/etc/dhcpcd.conf': No such file or directory
Nov 12 13:39:03 router local2.notice circ1:d[28543]: waiting for dhcpcd
with PID 28557
Nov 12 13:39:03 router local2.notice circ1:d[28543]: read_config: fopen
`/etc/dhcpcd.conf': No such file or directory
Nov 12 13:39:04 router local2.notice circ1:d[28543]: eth3: waiting for
carrier
Nov 12 13:39:04 router local2.notice circd[3255]:
handle_dialup_control_circuit_event(56#circ1:q:dialup_control_circuit_event):
id=circ1 status_code=0
Nov 12 13:39:06 router local2.notice circ1:d[28543]: eth3: carrier
acquired
Nov 12 13:39:06 router local2.notice circ1:d[28543]: read_config: fopen
`/etc/dhcpcd.conf': No such file or directory
Nov 12 13:39:08 router local2.notice circ1:d[28543]: eth3: soliciting a
DHCP lease
Nov 12 13:39:09 router local2.notice circ1:d[28543]: eth3: offered
100.65.XX.XX from 100.68.0.1
Nov 12 13:39:09 router local2.notice circ1:d[28543]: eth3: probing
address 100.65.XX.XX/17
Nov 12 13:39:14 router local2.notice circ1:d[28543]: eth3: leased
100.65.XX.XX for 3600 seconds
Nov 12 13:39:14 router local2.notice circ1:d[28543]: eth3: adding route
to 100.65.0.0/17
Nov 12 13:39:15 router local2.notice addr-up[29316]: circ1[eth3]: IPv4
address 100.65.XX.XX/17 has appeared
Nov 12 13:39:15 router local2.notice ip-up[29278]: executing ip-up
scripts for circ1[eth3]
Nov 12 13:39:15 router local2.notice ip-up[29278]: circuit circ1[eth3]
comes up
Nov 12 13:39:15 router local2.notice ip-up[29278]: circ1: local IPv4
address: 100.65.XX.XX/17
Nov 12 13:39:15 router local2.notice ip-up[29278]: circ1: remote IPv4
address: 100.65.0.1
Nov 12 13:39:15 router local2.notice addr-up[29316]: executing
/etc/ppp/addr-up300.logip
Nov 12 13:39:16 router local2.notice ip-up[29278]: executing
/etc/ppp/ip-up050.conntrack
Nov 12 13:39:16 router local2.notice ip-up[29278]: conntrack v1.4.4
(conntrack-tools): 205 flow entries have been deleted.
Nov 12 13:39:16 router local2.notice ip-up[29278]: executing
/etc/ppp/ip-up200.dhcp
Nov 12 13:39:16 router local2.notice ip-up[29278]: executing
/etc/ppp/ip-up200.dns
Nov 12 13:39:16 router local2.notice ip-up[29278]: using nameserver
185.22.44.50
Nov 12 13:39:16 router local2.notice ip-up[29278]: using nameserver
185.22.45.50
Nov 12 13:39:16 router local2.notice ip-up[29278]: executing
/etc/ppp/ip-up500.chrony
Nov 12 13:39:16 router local2.notice ip-up[29278]: restarting chronyd 
Nov 12 13:39:16 router local2.notice ip-up[29278]: now restart chronyd
with '-s -r' as options
Nov 12 13:39:16 router local2.notice circd[3255]:
handle_up_l3prot_circuit_event(69#29278:up_l3prot_circuit_event):
id=circ1 l3prot=ipv4
Nov 12 13:39:16 router local2.notice circd[3255]: circd_change_state:
circuit circ1 changes state from ready to online
Nov 12 13:39:17 router local2.notice circd[3255]:
circd_circuit_autodialup: dialling up circ2
Nov 12 13:39:17 router local2.notice circd[3255]: circd_change_state:
circuit circ2 changes state from active to ready
Nov 12 13:39:17 router local2.notice circ2:q[11477]:
handle_dialup_circuit_queue_message(73#circd:dialup_circuit_queue_message)
Nov 12 13:39:23 router local2.notice circ2:q[11477]: Soliciting ff02::2
(ff02::2) on eth3...
Nov 12 13:39:23 router local2.notice circ2:q[11477]: Timed out.
Nov 12 13:39:23 router local2.notice circ2:q[11477]: Timed out.
Nov 12 13:39:23 router local2.notice circ2:q[11477]: Timed out.
Nov 12 13:39:23 router local2.notice circ2:q[11477]: No response.
Nov 12 13:39:23 router local2.notice circd[3255]:
handle_start_daemon_circuit_message(79#2252:start_daemon_circuit_message):
id=circ2 daemon=dibbler-client daemon_args='run' '-w'
'/var/lib/dibbler/circ2' cleanup_func=dhcp_circuit_cleanup
Nov 12 13:39:23 router local2.notice ip-up[29278]: executing
/etc/ppp/ip-up800.openvpn
Nov 12 13:39:23 router local2.notice ip-up[29278]: >HOLD:Waiting for
hold release:0
Nov 12 13:39:23 router local2.notice ip-up[29278]: SUCCESS: hold flag
set to OFF
Nov 12 13:39:23 router local2.notice ip-up[29278]: >HOLD:Waiting for
hold release:0
Nov 12 13:39:23 router local2.notice ip-up[29278]: SUCCESS: hold release
succeeded
Nov 12 13:39:23 router local2.notice circd[3255]:
circd_daemon_wrapper[circ2]: started child circ2:d
Nov 12 13:39:23 router local2.notice circ2:d[4404]: starting
dibbler-client run -w /var/lib/dibbler/circ2...
Nov 12 13:39:23 router local2.notice circ2:d[4404]: | Dibbler - a
portable DHCPv6, version 1.0.1 (CLIENT, Linux port)
Nov 12 13:39:23 router local2.notice circ2:d[4404]: | Authors : Tomasz
Mrugalski<thomson(at)klub.com.pl>,Marek Senderski<msend(at)o2.pl>
Nov 12 13:39:23 router local2.notice circ2:d[4404]: | Licence : GNU GPL
v2 only. Developed at Gdansk University of Technology.
Nov 12 13:39:23 router local2.notice circ2:d[4404]: | Homepage:
http://klub.com.pl/dhcpv6/
Nov 12 13:39:23 router local2.notice circ2:d[4404]: 2018.11.12 13:39:23
Client Notice    My pid (4446) is stored in
/var/lib/dibbler/circ2/client.pid
Nov 12 13:39:23 router local2.notice circ2:d[4404]: 2018.11.12 13:39:23
Client Notice    Detected iface tun0/7, MAC=.
Nov 12 13:39:23 router local2.notice circ2:d[4404]: 2018.11.12 13:39:23
Client Notice    Detected iface dummy0/6, MAC=1a:4b:3c:39:82:13.
Nov 12 13:39:23 router local2.notice circ2:d[4404]: 2018.11.12 13:39:23
Client Notice    Detected iface eth3/5, MAC=00:e0:XX:XX:XX:83.
Nov 12 13:39:23 router local2.notice circ2:d[4404]: 2018.11.12 13:39:23
Client Notice    Detected iface eth2/4, MAC=00:e0:XX:XX:XX:82.
Nov 12 13:39:23 router local2.notice circ2:d[4404]: 2018.11.12 13:39:23
Client Notice    Detected iface eth1/3, MAC=00:e0:XX:XX:XX:81.
Nov 12 13:39:23 router local2.notice circ2:d[4404]: 2018.11.12 13:39:23
Client Notice    Detected iface eth0/2, MAC=00:e0:XX:XX:XX:80.
Nov 12 13:39:23 router local2.notice circ2:d[4404]: 2018.11.12 13:39:23
Client Notice    Detected iface lo/1, MAC=00:00:00:00:00:00.
Nov 12 13:39:23 router local2.notice circ2:d[4404]: 2018.11.12 13:39:23
Client Notice    Parsing /var/lib/dibbler/circ2/client.conf config
file...
Nov 12 13:39:23 router local2.notice circ2:d[4404]: Prefix delegation
option (with scope) found.
Nov 12 13:39:23 router local2.notice circ2:d[4404]: PD: Adding single
prefix.
Nov 12 13:39:23 router local2.notice circ2:d[4404]: Parsing
/var/lib/dibbler/circ2/client.conf done, result=0(success)
Nov 12 13:39:23 router local2.notice circ2:d[4404]: 1 interface(s)
specified in /var/lib/dibbler/circ2/client.conf
Nov 12 13:39:23 router local2.notice circ2:d[4404]: Interface eth3/5
configuration has been loaded.
Nov 12 13:39:23 router local2.notice circ2:d[4404]: Unable to open DUID
file (client-duid), generating new DUID.
Nov 12 13:39:23 router local2.notice circ2:d[4404]: DUID creation:
Interface tun0/7 skipped: MAC length is 0, but at least 6 is required.
Nov 12 13:39:23 router local2.notice circ2:d[4404]: DUID creation:
Interface dummy0/6 skipped: Interface is down.
Nov 12 13:39:23 router local2.notice circ2:d[4404]: DUID creation:
Generating 14-bytes long link-local+time (duid-llt) DUID.
Nov 12 13:39:23 router local2.notice circ2:d[4404]: DUID creation:
generated using eth3/5 interface.
Nov 12 13:39:23 router local2.notice circ2:d[4404]: My DUID is
00:01:00:01:23:7c:30:fb:00:e0:XX:XX:XX:83.
Nov 12 13:39:23 router local2.notice circ2:d[4404]: Loading old address
database (client-AddrMgr.xml), using built-in routines.
Nov 12 13:39:23 router local2.notice circ2:d[4404]: Unable to open
client-AddrMgr.xml.
Nov 12 13:39:23 router local2.notice circ2:d[4404]: Bind reuse enabled
(multiple instances allowed).
Nov 12 13:39:23 router local2.notice circ2:d[4404]: Creating control
(::) socket on the lo/1 interface.
Nov 12 13:39:23 router local2.notice circ2:d[4404]: Creating socket
(addr=fe80::2e0:67ff:fe0b:9383) on eth3/5 interface.
Nov 12 13:39:23 router local2.notice circ2:d[4404]: Initialising
link-state detection for interfaces: eth3/5 
Nov 12 13:39:23 router local2.notice circ2:d[4404]: CONFIRM support
compiled in.
Nov 12 13:39:23 router local2.notice circ2:d[4404]: Creating SOLICIT
message with 0 IA(s), no TA and 1 PD(s) on eth3/5 interface.
Nov 12 13:39:23 router local2.notice circ2:d[4404]: Sending
SOLICIT(opts:1 25 8 ) on eth3/5 to multicast.
Nov 12 13:39:23 router local2.notice circ2:d[4404]: Sleeping for 1
second(s).
Nov 12 13:39:23 router local2.notice circ2:d[4404]: Received 85 bytes on
interface eth3/5 (socket=6, addr=fe80::XX:XXXX:XX).
Nov 12 13:39:23 router local2.notice circ2:d[4404]: Received ADVERTISE
on eth3/5,trans-id=0x9787ab, 3 opts: 25 1 2
Nov 12 13:39:23 router local2.notice circ2:d[4404]: Script execution
skipped for ADVERTISE response to SOLICIT. No action needed for this
message type.
Nov 12 13:39:23 router local2.notice circ2:d[4404]: Sleeping for 1
second(s).
Nov 12 13:39:23 router local2.notice circ2:d[4404]: waiting for
dibbler-client with PID 4446
Nov 12 13:39:24 router local2.notice ip-up[29278]: SUCCESS: signal
SIGUSR1 thrown
Nov 12 13:39:24 router local2.notice ip-up[29278]: >HOLD:Waiting for
hold release:0
Nov 12 13:39:24 router local2.notice ip-up[29278]: SUCCESS: hold flag
set to OFF
Nov 12 13:39:24 router local2.notice ip-up[29278]: >HOLD:Waiting for
hold release:0
Nov 12 13:39:24 router local2.notice ip-up[29278]: SUCCESS: hold release
succeeded
Nov 12 13:39:24 router local2.notice ip-up[29278]: SUCCESS: signal
SIGUSR1 thrown
Nov 12 13:39:24 router local2.notice ip-up[29278]: >HOLD:Waiting for
hold release:0
Nov 12 13:39:24 router local2.notice ip-up[29278]: SUCCESS: hold flag
set to OFF
Nov 12 13:39:24 router local2.notice ip-up[29278]: >HOLD:Waiting for
hold release:0
Nov 12 13:39:24 router local2.notice ip-up[29278]: SUCCESS: hold release
succeeded
Nov 12 13:39:24 router local2.notice circ2:d[4404]: Processing msg
(SOLICIT,transID=0x9787ab,opts: 1 25 8)
Nov 12 13:39:24 router local2.notice circ2:d[4404]: Creating REQUEST.
Backup server list contains 1 server(s).
Nov 12 13:39:24 router local2.notice circ2:d[4404]: Advertise from
Server ID=00:01:00:01:1d:9c:43:c4:00:XX:XX:XX:XX:XX, no preference
option, assumed 0.[using this]
Nov 12 13:39:24 router local2.notice circ2:d[4404]: Sending
REQUEST(opts:1 25 2 8 ) on eth3/5 to multicast.
Nov 12 13:39:24 router local2.notice circ2:d[4404]: Sleeping for 1
second(s).
Nov 12 13:39:24 router local2.notice circd[3255]:
handle_dialup_control_circuit_event(80#circ2:q:dialup_control_circuit_event):
id=circ2 status_code=0
Nov 12 13:39:24 router local2.notice circ2:d[4404]: Received 85 bytes on
interface eth3/5 (socket=6, addr=fe80::XX:XXXX:XX).
Nov 12 13:39:24 router local2.notice circ2:d[4404]: Received REPLY on
eth3/5,trans-id=0x63f52b, 3 opts: 25 1 2
Nov 12 13:39:24 router local2.notice circ2:d[4404]: Server set T1 and T2
to 0. Choosing default (50%, 70% * prefered-lifetime): T1=1125, T2=1575
Nov 12 13:39:24 router local2.notice circ2:d[4404]: PD: Adding
2a00:6020:XXXX:XXXX:: prefix to PD (iaid=1) to addrDB.
Nov 12 13:39:24 router local2.notice circ2:d[4404]: PD: Adding prefix
2a00:6020:XXXX:XXXX::/56 to all interfaces (prefix will be split to /64
prefixes if necessary).
Nov 12 13:39:24 router local2.notice circ2:d[4404]: PD: Interface tun0/7
has MAC address length 0 (6 or more required), ignoring.
Nov 12 13:39:24 router local2.notice circ2:d[4404]: PD: Interface
dummy0/6 is down, ignoring.
Nov 12 13:39:24 router local2.notice circ2:d[4404]: PD: Interface eth3/5
is the interface, where prefix has been obtained, skipping.
Nov 12 13:39:24 router local2.notice circ2:d[4404]: PD: Interface eth2/4
is down, ignoring.
Nov 12 13:39:24 router local2.notice circ2:d[4404]: PD: Interface eth1/3
is down, ignoring.
Nov 12 13:39:24 router local2.notice circ2:d[4404]: PD: Interface eth0/2
is suitable for PD.
Nov 12 13:39:24 router local2.notice circ2:d[4404]: PD: Interface lo/1
is not multicast capable, ignoring.
Nov 12 13:39:24 router local2.notice circ2:d[4404]: PD: Using 1 suitable
interface(s):eth0 
Nov 12 13:39:24 router local2.notice circ2:d[4404]: PD: Adding prefix
2a00:6020:XXXX:XXXX::/56 on the eth0/2 interface.
Nov 12 13:39:24 router local2.notice circ2:d[4404]: RENEW(IA_PD) will be
sent (T1) after 1125, REBIND (T2) after 1575 seconds.
Nov 12 13:39:24 router local2.notice circ2:d[4404]: About to execute
/var/lib/dibbler/circ2/dibbler-notify-circ2.sh script, 15 variables.
Nov 12 13:39:24 router local2.notice circ2:d[4404]: Script execution
complete, return code=0
Nov 12 13:39:24 router local2.notice circ2:d[4404]: Sleeping for 1124
second(s).
Nov 12 13:39:24 router local2.notice prefixv6-up[6443]: circ2[eth3]:
IPv6 prefix 2a00:6020:XXXX:XXXX::/56 has appeared
Nov 12 13:39:25 router local2.notice ip-up[29278]: SUCCESS: signal
SIGUSR1 thrown
Nov 12 13:39:25 router local2.notice ip-up[29278]: executing
/etc/ppp/ip-up900.user
Nov 12 13:39:25 router local2.notice ip-up[29278]: executing
/etc/ppp-once/ip-up001.ppp-onceflag
Nov 12 13:39:25 router local2.notice ip-up[29278]: finished ip-up
scripts for circ1[eth3] (rc=0)
Nov 12 13:39:25 router local2.notice prefixv6-up[6443]: executing
/etc/ppp/prefixv6-up030.nets
Nov 12 13:39:25 router local2.notice prefixv6-up[6443]: setting up IPv6
networks...
Nov 12 13:39:25 router local2.notice circd[3255]:
handle_up_l3prot_circuit_event(89#6498:up_l3prot_circuit_event):
id=circ2 l3prot=ipv6
Nov 12 13:39:25 router local2.notice prefixv6-up[6443]:   
ipv6-interface-setup.sh: IPV6_NET_1: advertising prefix
2a00:6020:XXXX:XXXX::/64 on eth0 for 3599/2249 seconds
Nov 12 13:39:25 router local2.notice prefixv6-up[6443]:   
ipv6-interface-setup.sh: IPV6_NET_1: address 2a00:6020:XXXX:XXXX::1/64
added to eth0 for 3599/2249 seconds
Nov 12 13:39:25 router local2.notice circd[3255]: circd_change_state:
circuit circ2 changes state from ready to online
Nov 12 13:39:27 router local2.notice prefixv6-up[6443]: executing
/etc/ppp/prefixv6-up050.circuits-net
Nov 12 13:39:28 router local2.notice prefixv6-up[6443]: executing
/etc/ppp/prefixv6-up300.logip
Nov 12 13:39:28 router local2.notice ip-up[29278]: chronyd is now
'online'
Nov 12 13:58:08 router local2.notice circ2:d[4404]: Generating RENEW for
0 IA(s) and 1 PD(s). 
Nov 12 13:58:08 router local2.notice circ2:d[4404]: Sending RENEW(opts:1
2 25 8 ) on eth3/5 to multicast.
Nov 12 13:58:08 router local2.notice circ2:d[4404]: Sleeping for 10
second(s).
Nov 12 13:58:08 router local2.notice circ2:d[4404]: Received 85 bytes on
interface eth3/5 (socket=6, addr=fe80::XX:XXXX:XX).
Nov 12 13:58:08 router local2.notice circ2:d[4404]: Received REPLY on
eth3/5,trans-id=0x70bb0c, 3 opts: 25 1 2
Nov 12 13:58:08 router local2.notice circ2:d[4404]: Server set T1 and T2
to 0. Choosing default (50%, 70% * prefered-lifetime): T1=1125, T2=1575
Nov 12 13:58:08 router local2.notice circ2:d[4404]: PD: Updating prefix
2a00:6020:XXXX:XXXX::/56 to all interfaces (prefix will be split to /64
prefixes if necessary).
Nov 12 13:58:08 router local2.notice circ2:d[4404]: PD: Interface tun0/7
has MAC address length 0 (6 or more required), ignoring.
Nov 12 13:58:08 router local2.notice circ2:d[4404]: PD: Interface
dummy0/6 is down, ignoring.
Nov 12 13:58:08 router local2.notice circ2:d[4404]: PD: Interface eth3/5
is the interface, where prefix has been obtained, skipping.
Nov 12 13:58:08 router local2.notice circ2:d[4404]: PD: Interface eth2/4
is down, ignoring.
Nov 12 13:58:08 router local2.notice circ2:d[4404]: PD: Interface eth1/3
is down, ignoring.
Nov 12 13:58:08 router local2.notice circ2:d[4404]: PD: Interface eth0/2
is suitable for PD.
Nov 12 13:58:08 router local2.notice circ2:d[4404]: PD: Interface lo/1
is not multicast capable, ignoring.
Nov 12 13:58:08 router local2.notice circ2:d[4404]: PD: Using 1 suitable
interface(s):eth0 
Nov 12 13:58:08 router local2.notice circ2:d[4404]: PD: Updating prefix
2a00:6020:XXXX:XXXX::/56 on the eth0/2 interface.
Nov 12 13:58:08 router local2.notice circ2:d[4404]: RENEW(IA_PD) will be
sent (T1) after 1125, REBIND (T2) after 1575 seconds.
Nov 12 13:58:08 router local2.notice circ2:d[4404]: About to execute
/var/lib/dibbler/circ2/dibbler-notify-circ2.sh script, 21 variables.
Nov 12 13:58:08 router local2.notice circ2:d[4404]: Script execution
complete, return code=0
Nov 12 13:58:08 router local2.notice circ2:d[4404]: Sleeping for 1125
second(s).
Nov 12 13:58:09 router local2.notice prefixv6-up[16701]: circ2[eth3]:
IPv6 prefix 2a00:6020:XXXX:XXXX::/56 has been renewed
Nov 12 13:58:09 router local2.notice prefixv6-up[16701]: executing
/etc/ppp/prefixv6-up030.nets
Nov 12 13:58:09 router local2.notice prefixv6-up[16701]: setting up IPv6
networks...
Nov 12 13:58:09 router local2.notice prefixv6-up[16701]:   
ipv6-interface-setup.sh: IPV6_NET_1: advertising prefix
2a00:6020:XXXX:XXXX::/64 on eth0 for 3600/2250 seconds
Nov 12 13:58:09 router local2.notice prefixv6-up[16701]:   
ipv6-interface-setup.sh: IPV6_NET_1: address 2a00:6020:XXXX:XXXX::1/64
added to eth0 for 3600/2250 seconds
Nov 12 13:58:11 router local2.notice prefixv6-up[16701]: executing
/etc/ppp/prefixv6-up050.circuits-net
Nov 12 13:58:11 router local2.notice prefixv6-up[16701]: executing
/etc/ppp/prefixv6-up300.logip


Interesant sind die 3 ersten  Einträge 
Nov 12 13:38:49 router daemon.info chronyd[19626]: chronyd version 3.3
starting (+CMDMON +NTP +REFCLOCK +RTC -PRIVDROP -SCFILTER -SIGND
+ASYNCDNS +SECHASH +IPV6 -DEBUG)
Nov 12 13:38:49 router daemon.err chronyd[19626]: Wrong permissions on
/var/run/chrony
Nov 12 13:38:49 router daemon.warn chronyd[19626]: Disabled command
socket /var/run/chrony/chronyd.sock

Hier sind die zugehörigen Rechte
router 4.0.0-r54331-testing # ls -ldh /var/run/chrony/
drwxr-xr-x    2 root     root         100 Nov 12 14:40 /var/run/chrony/

router 4.0.0-r54331-testing # ls -lh /var/run/chrony
-rw-r--r--    1 root     root        1.3K Nov 12 13:39 measurements.log
-rw-r--r--    1 root     root         702 Nov 12 13:39 statistics.log
-rw-r--r--    1 root     root        1.0K Nov 12 13:39 tracking.log

Zur Info: Daten für Openvpn aus den Protokollen gelöscht und die IP
und Macadressen angepasst.

Neben dem Berechtigungsproblem, könnten die folgenden Situatioen
auftreten?
Die chrony sources werden per ipv6 aufgelöst, aber chrony wird nur neu
gestartet nachdem der ipv4 circuit online ist. Dadurch könen die IPV6
Adressen nicht erreicht werden und somit sind sie offline? 

Viele Grüße

Frank


Mehr Informationen über die Mailingliste Fli4l_dev