What were you trying to do that didn't work?

synce4l client can't get locekd when receiving QL 0x0

Please provide the package NVR for which bug is seen:

[root@dell-per740-83 topo]# rpm -q synce4l

synce4l-1.0.0-1.el9.x86_64

[root@dell-per740-83 topo]# uname -r

5.14.0-453.el9.x86_64

[root@dell-per740-83 topo]# ethtool -i ens1f0

driver: ice

version: 5.14.0-453.el9.x86_64

firmware-version: 4.01 0x800135e7 1.3256.0

expansion-rom-version:

bus-info: 0000:3b:00.0

supports-statistics: yes

supports-test: yes

supports-eeprom-access: yes

supports-register-dump: yes

supports-priv-flags: yes

[root@dell-per740-83 topo]# lspci -s 0000:3b:00.0 -nn

3b:00.0 Ethernet controller [0200]: Intel Corporation Ethernet Controller E810-C for SFP [8086:1593] (rev 02)

How reproducible:

always

Steps to reproduce

1. start synce4l on server side using following cfg file:

```

[global]

logging_level              7

use_syslog                 0

verbose                    1

message_tag                [synce4l]

 

[<synce1>]

network_option             2

extended_tlv               1

recover_time               60

clock_id 5799633565437511660

module_name                ice

 

[ens3f0]

tx_heartbeat_msec          1000

rx_heartbeat_msec          10

allowed_qls                0xE

allowed_ext_qls            0x40

 

[\{GNSS}]

board_label                GNSS-1PPS

input_QL                   0x0

input_ext_QL               0xFF

```

 

2. start synce4l on client side using following cfg file:

```

[global]

logging_level              7

use_syslog                 0

verbose                    1

message_tag                [synce4l]

 

[<synce1>]

network_option             2

extended_tlv               0

recover_time               60

clock_id 5799633565436792966

module_name                ice

 

[ens1f0]

tx_heartbeat_msec          1000

rx_heartbeat_msec          500

allowed_qls                0x0

allowed_ext_qls            0xFF,0x20

```

 

The client side can't get locked with following log:

synce4l[3250.924]: [synce4l] created synce1

synce4l[3250.924]: [synce4l] device init synce1 addr 0x562f1e478780

synce4l[3250.924]: [synce4l] created num_devices: 1

synce4l[3250.924]: [synce4l] config item synce1.extended_tlv is 0 (0x0)

synce4l[3250.924]: [synce4l] config item synce1.network_option is 2 (0x2)

synce4l[3250.924]: [synce4l] config item synce1.recover_time is 60 (0x3c)

synce4l[3250.924]: [synce4l] config item synce1.eec_get_state_cmd is '(null)'

synce4l[3250.924]: [synce4l] config item synce1.eec_holdover_value is '(null)'

synce4l[3250.924]: [synce4l] config item synce1.eec_locked_ho_value is '(null)'

synce4l[3250.924]: [synce4l] config item synce1.eec_locked_value is '(null)'

synce4l[3250.924]: [synce4l] config item synce1.eec_freerun_value is '(null)'

synce4l[3250.924]: [synce4l] config item synce1.eec_invalid_value is '(null)'

synce4l[3250.924]: [synce4l] config item synce1.module_name is 'ice'

synce4l[3250.924]: [synce4l] config item synce1.clock_id is 5799633565436792966 (0x507c6fffff4ad086)

synce4l[3250.924]: [synce4l] config item synce1.dnu_prio is 15 (0xf)

synce4l[3250.924]: [synce4l] dpll mon for synce1 new state: 1

synce4l[3250.924]: [synce4l] monitor socket created

synce4l[3250.924]: [synce4l] dev socket created for synce1 device

synce4l[3250.924]: [synce4l] dpll mon for synce1 new state: 2

synce4l[3250.924]: [synce4l] synce_dev_ctrl_init: using dpll subsystem

synce4l[3250.924]: [synce4l] dpll_mon thread started state:2

synce4l[3250.933]: [synce4l] clock_source ens1f0 added on device synce1 addr 0x562f1e47a660

synce4l[3250.933]: [synce4l] pin_create 0x562f1e47a700

synce4l[3250.939]: [synce4l] adding valid pin:0x562f1e47a700 pin_id:0 for pin board_label:N/A panel_label:N/A package_label:N/A type:3 ifname:ens1f0 v:1 r:0

synce4l[3250.945]: [synce4l] config item ens1f0.tx_heartbeat_msec is 1000 (0x3e8)

synce4l[3250.945]: [synce4l] tx thread started on port ens1f0

synce4l[3250.945]: [synce4l] THREAD_STARTED

synce4l[3250.945]: [synce4l] config item ens1f0.rx_heartbeat_msec is 500 (0x1f4)

synce4l[3250.945]: [synce4l] config item ens1f0.allowed_qls is '0x0'

synce4l[3250.945]: [synce4l] config item ens1f0.allowed_ext_qls is '0xFF,0x20'

synce4l[3250.945]: [synce4l] rx thread started on port ens1f0

synce4l[3250.965]: [synce4l] THREAD_STARTED

synce4l[3250.965]: [synce4l] inited clock_source ens1f0 on device synce1

synce4l[3250.965]: [synce4l] act on EEC_HOLDOVER for ens1f0

synce4l[3250.965]: [synce4l] inited num_clock_sources 1 (1 ports) for synce1

synce4l[3250.965]: [synce4l] device inited synce1

synce4l[3250.965]: [synce4l] DEVICE_ID_GET request sent dpll id: 5799633565436792966 ice, ret:48

synce4l[3250.965]: [synce4l] dpll_id:0 received on synce1

synce4l[3250.965]: [synce4l] dpll mon for synce1 new state: 3

synce4l[3250.965]: [synce4l] dpll get dev id requested

synce4l[3250.965]: [synce4l] waiting for RUNNING on dpll mon for 'synce1'

synce4l[3250.965]: [synce4l] running num_devices 1 configured 1

synce4l[3250.965]: [synce4l] dpll mon for synce1 new state: 4

synce4l[3250.965]: [synce4l] DEVICE_GET request sent dpll_id:0, ret:28

synce4l[3250.965]: [synce4l] dpll_id:0 received on synce1

synce4l[3250.965]: [synce4l] mode:2 received on synce1

synce4l[3250.965]: [synce4l] lock status:3 received on synce1

synce4l[3250.965]: [synce4l] dpll mon for synce1 new state: 5

synce4l[3250.965]: [synce4l] dpll get dev requested

synce4l[3250.965]: [synce4l] dpll for 'synce1' not running

synce4l[3250.965]: [synce4l] waiting for dev synce1 to appear on dpll subsystem

synce4l[3251.445]: [synce4l] QL=0xd found on ens1f0

synce4l[3251.445]: [synce4l] Received not allowed QL: 0xd, discarding

synce4l[3251.945]: [synce4l] tx_rebuild_tlv: attached new TLV, QL=0xf on ens1f0

synce4l[3251.985]: [synce4l] pin assigned id:0x562f1e47a700 pin_id:13 for pin board_label:N/A panel_label:N/A package_label:N/A type:3 ifname:ens1f0 v:1 r:0

synce4l[3251.985]: [synce4l] RT link dump requested

synce4l[3252.445]: [synce4l] QL=0xd found on ens1f0

synce4l[3252.445]: [synce4l] Received not allowed QL: 0xd, discarding

synce4l[3252.523]: [synce4l] PIN_GET dump request sent ret:20

synce4l[3252.523]: [synce4l] pin_create 0x562f1e47cb80

synce4l[3252.523]: [synce4l] new pin state 3 for pin_id:0

synce4l[3252.523]: [synce4l] new pin prio 15 for pin_id:0

synce4l[3252.523]: [synce4l] pin_create 0x562f1e47cd10

synce4l[3252.523]: [synce4l] new pin state 3 for pin_id:1

synce4l[3252.523]: [synce4l] new pin prio 15 for pin_id:1

synce4l[3252.523]: [synce4l] pin_create 0x562f1e47ce60

synce4l[3252.523]: [synce4l] new pin state 1 for pin_id:2

synce4l[3252.523]: [synce4l] pin_create 0x562f1e47cfb0

synce4l[3252.523]: [synce4l] new pin state 3 for pin_id:3

synce4l[3252.523]: [synce4l] pin_create 0x562f1e47d130

synce4l[3252.523]: [synce4l] new pin state 3 for pin_id:4

synce4l[3252.523]: [synce4l] new pin prio 15 for pin_id:4

synce4l[3252.523]: [synce4l] pin_create 0x562f1e47d2c0

synce4l[3252.523]: [synce4l] new pin state 3 for pin_id:5

synce4l[3252.523]: [synce4l] new pin prio 15 for pin_id:5

synce4l[3252.523]: [synce4l] pin_create 0x562f1e47d430

synce4l[3252.523]: [synce4l] new pin state 3 for pin_id:6

synce4l[3252.523]: [synce4l] new pin prio 15 for pin_id:6

synce4l[3252.523]: [synce4l] pin_create 0x562f1e47d590

synce4l[3252.523]: [synce4l] new pin state 1 for pin_id:7

synce4l[3252.523]: [synce4l] pin_create 0x562f1e47d6f0

synce4l[3252.523]: [synce4l] new pin state 1 for pin_id:8

synce4l[3252.523]: [synce4l] pin_create 0x562f1e47d760

synce4l[3252.523]: [synce4l] new pin state 1 for pin_id:9

synce4l[3252.523]: [synce4l] pin_create 0x562f1e47d880

synce4l[3252.523]: [synce4l] new pin state 1 for pin_id:10

synce4l[3252.523]: [synce4l] pin_create 0x562f1e47d9c0

synce4l[3252.523]: [synce4l] new pin state 1 for pin_id:11

synce4l[3252.523]: [synce4l] pin_create 0x562f1e47db00

synce4l[3252.523]: [synce4l] new pin state 1 for pin_id:12

synce4l[3252.628]: [synce4l] PIN_SET request sent state:3, pin:2 dpll:0 ret: 48

synce4l[3252.628]: [synce4l] new pin state 1 for pin_id:13 on parent_id:2

synce4l[3252.628]: [synce4l] new pin state 1 for pin_id:13 on parent_id:3

synce4l[3252.628]: [synce4l] pin_create 0x562f1e47dd00

synce4l[3252.628]: [synce4l] new pin state 2 for pin_id:14 on parent_id:2

synce4l[3252.628]: [synce4l] new pin state 2 for pin_id:14 on parent_id:3

synce4l[3252.628]: [synce4l] pin_create 0x562f1e47de30

synce4l[3252.628]: [synce4l] new pin state 2 for pin_id:15 on parent_id:2

synce4l[3252.628]: [synce4l] new pin state 2 for pin_id:15 on parent_id:3

synce4l[3252.628]: [synce4l] pin_create 0x562f1e47df60

synce4l[3252.628]: [synce4l] new pin state 2 for pin_id:16 on parent_id:2

synce4l[3252.628]: [synce4l] new pin state 2 for pin_id:16 on parent_id:3

synce4l[3252.628]: [synce4l] dpll pin dump requested

synce4l[3252.628]: [synce4l] dpll mon for synce1 new state: 6

synce4l[3252.628]: [synce4l] dpll for 'synce1' not running

synce4l[3252.628]: [synce4l] waiting for dev synce1 to appear on dpll subsystem

synce4l[3253.445]: [synce4l] QL=0xd found on ens1f0

synce4l[3253.445]: [synce4l] Received not allowed QL: 0xd, discarding

synce4l[3253.649]: [synce4l] dpll mon for synce1 new state: 7

synce4l[3253.649]: [synce4l] dpll for 'synce1' not running

synce4l[3253.649]: [synce4l] waiting for dev synce1 to appear on dpll subsystem

synce4l[3254.445]: [synce4l] QL=0xd found on ens1f0

synce4l[3254.445]: [synce4l] Received not allowed QL: 0xd, discarding

synce4l[3254.695]: [synce4l] PIN_SET request sent state:2, pin:13 parent:2 ret:48

synce4l[3254.760]: [synce4l] PIN_SET request sent prio:15, pin:2 dpll:0 ret: 48

synce4l[3254.832]: [synce4l] PIN_SET request sent state:3, pin:2 dpll:0 ret: 48

synce4l[3254.832]: [synce4l] new pin state 2 for pin_id:13 on parent_id:2

synce4l[3254.852]: [synce4l] new pin prio 15 for pin_id:2

synce4l[3254.875]: [synce4l] PIN_SET request sent state:2, pin:13 parent:3 ret:48

synce4l[3254.914]: [synce4l] PIN_SET request sent prio:15, pin:3 dpll:0 ret: 48

synce4l[3255.034]: [synce4l] PIN_SET request sent state:3, pin:2 dpll:0 ret: 48

synce4l[3255.034]: [synce4l] new pin state 2 for pin_id:13 on parent_id:3

synce4l[3255.054]: [synce4l] new pin prio 15 for pin_id:3

synce4l[3255.086]: [synce4l] PIN_SET request sent prio:15, pin:0 dpll:0 ret: 48

synce4l[3255.114]: [synce4l] dpll_id:0 received on synce1

synce4l[3255.114]: [synce4l] mode:2 received on synce1

synce4l[3255.114]: [synce4l] lock status:4 received on synce1

synce4l[3255.134]: [synce4l] new pin state 3 for pin_id:2

synce4l[3255.177]: [synce4l] PIN_SET request sent prio:15, pin:1 dpll:0 ret: 48

synce4l[3255.215]: [synce4l] PIN_SET request sent prio:15, pin:2 dpll:0 ret: 48

synce4l[3255.272]: [synce4l] PIN_SET request sent prio:15, pin:3 dpll:0 ret: 48

synce4l[3255.323]: [synce4l] PIN_SET request sent prio:15, pin:4 dpll:0 ret: 48

synce4l[3255.377]: [synce4l] PIN_SET request sent prio:15, pin:5 dpll:0 ret: 48

synce4l[3255.417]: [synce4l] PIN_SET request sent prio:15, pin:6 dpll:0 ret: 48

synce4l[3255.417]: [synce4l] dpll mon for synce1 new state: 8

synce4l[3255.417]: [synce4l] dpll for 'synce1' not running

synce4l[3255.417]: [synce4l] waiting for dev synce1 to appear on dpll subsystem

synce4l[3255.445]: [synce4l] QL=0xd found on ens1f0

synce4l[3255.445]: [synce4l] Received not allowed QL: 0xd, discarding

synce4l[3256.438]: [synce4l] dpll mon for synce1 new state: 9

synce4l[3256.438]: [synce4l] dpll device for synce1 - init successful

synce4l[3256.438]: [synce4l] not valid source: ens1f0

synce4l[3256.438]: [synce4l] both left and right are invalid

synce4l[3256.438]: [synce4l] no valid source found

synce4l[3256.446]: [synce4l] QL=0xd found on ens1f0

 

Expected results

Actual results