Skip to content

OpenOLT output error log when add flows #5

@fandy-genew

Description

@fandy-genew

Dear @charlesmcchan @zdw @memerror @LucaPrete @teone

Have a issue need for you help, thanks.

Step1 Start OLT device and register two xgs ONU

Start xgsPON
/a/o object=device sub=connect device_id=0 system_mode=xgs__16_x inni_config={mux=none mode=all_10_g_xfi}

Enable optical module
board/trx/enable pon_ni=1

Register ONU
/a/s object=onu pon_ni=1 onu_id=1 itu={serial_number={vendor_id=47504f4e vendor_specific=20B00039} auto_learning=yes xgpon={ranging_burst_profile=2 data_burst_profile=3 } }

/a/s object=onu pon_ni=1 onu_id=2 itu={serial_number={vendor_id=47504f4e vendor_specific=20B00043} auto_learning=yes xgpon={ranging_burst_profile=2 data_burst_profile=3 } }

Active ONU
/a/o object=pon_interface sub=set_pon_interface_state pon_ni=1 operation=active_working
/api/oper object=onu sub=set_onu_state pon_ni=1 onu_id=1 onu_state=active
/api/oper object=onu sub=set_onu_state pon_ni=1 onu_id=2 onu_state=active

Step2 Create connection Voltha with OLT
voltctl device create -t openolt -H (ip):9191
voltctl device enable (id)

Step3 Config FLOW by ONOS
3.1xgpon technologyprofile 64 key in etcd file
{
"name": "64QueueHybridProfileMapforvoip",
"profile_type": "XPON",
"version": 1,
"num_gem_ports": 1,
"instance_control": {
"onu": "multi-instance",
"uni": "single-instance",
"max_gem_payload_size": "auto"
},
"us_scheduler": {
"additional_bw": "AdditionalBW_Auto",
"direction": "UPSTREAM",
"priority": 5,
"weight": 0,
"q_sched_policy": "StrictPriority"
},
"ds_scheduler": {
"additional_bw": "AdditionalBW_Auto",
"direction": "DOWNSTREAM",
"priority": 5,
"weight": 0,
"q_sched_policy": "StrictPriority"
},
"upstream_gem_port_attribute_list": [
{
"pbit_map": "0b00100000",
"aes_encryption": "True",
"scheduling_policy": "StrictPriority",
"priority_q": 5,
"weight": 0,
"discard_policy": "TailDrop",
"max_q_size": "auto",
"discard_config": {
"max_threshold": 0,
"min_threshold": 0,
"max_probability": 0
}
}
],
"downstream_gem_port_attribute_list": [
{
"pbit_map": "0b00100000",
"aes_encryption": "True",
"scheduling_policy": "StrictPriority",
"priority_q": 5,
"weight": 0,
"discard_policy": "TailDrop",
"max_q_size": "auto",
"discard_config": {
"min_threshold": 0,
"max_threshold": 0,
"max_probability": 0
}
}
]
}
3.2 network-cfg file
{ "devices": {},
"apps": {
"org.opencord.dhcpl2relay": {
"dhcpl2relay": {
"useOltUplinkForServerPktInOut": false
}
},
"org.opencord.kafka": {
"kafka": {
"bootstrapServers": "127.0.0.1:9092"
}
},
"org.opencord.aaa": {
"AAA": {
"radiusIp": "127.0.0.1",
"radiusServerPort": "1812",
"radiusSecret": "SECRET",
"nasIp": "127.0.0.1",
"radiusConnectionType": "socket"
}
},
"org.opencord.sadis": {
"sadis": {
"integration": {
"cache": {
"enabled": true,
"maxsize": 50,
"ttl": "PT1m"
}
},
"entries": [
{
"id": "BBSIM_OLT_1",
"uplinkPort": 1048576,
"hardwareIdentifier": "02:10:18:01:b4:70",
"ipAddress": "192.168.3.9",
"nasId": "ATLEDGEVOLT1"
},
{
"id": "BBSIM_OLT_10",
"uplinkPort": 1048576,
"hardwareIdentifier": "0a:0a:0a:0a:0a:0a",
"ipAddress": "127.0.0.1",
"nasId": "ATLEDGEVOLT1"
},
{
"id": "GPON20b00043-1",
"nasPortId": "PON 1/1/3/1:4.1.1",
"circuitId": "PON 1/1/3/1:4.1.1-CID",
"remoteId": "ATLEDGEVOLT1-RID",
"uniTagList": [
{
"ponCTag": 20,
"ponSTag": 1024,
"technologyProfileId": 64,
"downstreamBandwidthProfile": "Silver_Download",
"upstreamBandwidthProfile": "Silver_Upload",
"isDhcpRequired": false
}
]
},
{
"id": "GPON20b00043-2",
"nasPortId": "PON 1/1/3/1:4.1.1",
"circuitId": "PON 1/1/3/1:4.1.1-CID",
"remoteId": "ATLEDGEVOLT1-RID",
"uniTagList": [
{
"ponCTag": 21,
"ponSTag": 1025,
"technologyProfileId": 64,
"downstreamBandwidthProfile": "Silver_Download",
"upstreamBandwidthProfile": "Silver_Upload",
"isDhcpRequired": false
}
]
},
{
"id": "GPON20b00039-1",
"nasPortId": "PON 1/1/3/1:4.1.1",
"circuitId": "PON 1/1/3/1:4.1.1-CID",
"remoteId": "ATLEDGEVOLT1-RID",
"uniTagList": [
{
"ponCTag": 10,
"ponSTag": 1026,
"technologyProfileId": 64,
"downstreamBandwidthProfile": "Silver_Download",
"upstreamBandwidthProfile": "Silver_Upload",
"isDhcpRequired": false
}
]
},
{
"id": "GPON20b00039-2",
"nasPortId": "PON 1/1/3/1:4.1.1",
"circuitId": "PON 1/1/3/1:4.1.1-CID",
"remoteId": "ATLEDGEVOLT1-RID",
"uniTagList": [
{
"ponCTag": 10,
"ponSTag": 1027,
"technologyProfileId": 64,
"downstreamBandwidthProfile": "Silver_Download",
"upstreamBandwidthProfile": "Silver_Upload",
"isDhcpRequired": false
}
]
},
{
"id": "BBSM000a0001-1",
"nasPortId": "PON 1/1/3/1:10.1.1",
"circuitId": "PON 1/1/3/1:10.1.1-CID",
"remoteId": "ATLEDGEVOLT1-RID",
"uniTagList": [
{
"ponCTag": 100,
"ponSTag": 101,
"technologyProfileId": 64,
"downstreamBandwidthProfile": "Silver_Download",
"upstreamBandwidthProfile": "Silver_Upload",
"isDhcpRequired": false
}
]
},
{
"id": "BBSM000a0001-2",
"nasPortId": "PON 1/1/3/1:11.1.1",
"circuitId": "PON 1/1/3/1:11.1.1-CID",
"remoteId": "ATLEDGEVOLT1-RID",
"uniTagList": [
{
"ponCTag": 200,
"ponSTag": 201,
"technologyProfileId": 65,
"downstreamBandwidthProfile": "Gold_Download",
"upstreamBandwidthProfile": "Gold_Upload",
"isDhcpRequired": false
}
]
}
]
},
"bandwidthprofile": {
"integration": {
"cache": {
"enabled": true,
"maxsize": 40,
"ttl": "PT1m"
}
},
"entries": [
{
"id": "Default",
"gir": 0,
"cbs": 1000,
"cir": 0,
"pbs": 2000,
"pir": 12500
},
{
"id": "Bronze_Upload",
"gir": 5000,
"cbs": 1000,
"cir": 10000,
"pbs": 2000,
"pir": 200000
},
{
"id": "Bronze_Download",
"gir": 5000,
"cbs": 1000,
"cir": 10000,
"pbs": 2000,
"pir": 200000
},
{
"id": "Silver_Upload",
"gir": 30000,
"cbs": 0,
"cir": 0,
"pbs": 0,
"pir": 0
},
{
"id": "Silver_Download",
"gir": 30000,
"cbs": 0,
"cir": 0,
"pbs": 0,
"pir": 0
},
{
"id": "Gold_Upload",
"gir": 0,
"cbs": 1000,
"cir": 0,
"pbs": 1000,
"pir": 50000
},
{
"id": "Gold_Download",
"gir": 0,
"cbs": 1000,
"cir": 0,
"pbs": 1000,
"pir": 50000
}
]
}
}
}
}
3.3 view ports
karaf@root > ports
id=of:000002101801b470, available=true, local-status=connected 32s ago, role=MASTER, type=SWITCH, mfr=VOLTHA Project, hw=open_pon, sw=open_pon, serial=BBSIM_OLT_1, chassis=2101801b470, driver=voltha, channelId=10.32.0.8:38684, managementAddress=10.32.0.8, protocol=OF_13
port=4112, state=enabled, type=fiber, speed=1 , adminState=enabled, portMac=08:00:01:00:10:10, portName=GPON20b00043-1
port=4113, state=disabled, type=fiber, speed=1 , adminState=enabled, portMac=08:00:01:00:10:11, portName=GPON20b00043-2
port=4128, state=enabled, type=fiber, speed=1 , adminState=enabled, portMac=08:00:01:00:10:20, portName=GPON20b00039-1
port=4129, state=disabled, type=fiber, speed=1 , adminState=enabled, portMac=08:00:01:00:10:21, portName=GPON20b00039-2
port=1048576, state=enabled, type=fiber, speed=0 , adminState=enabled, portMac=02:10:18:01:b4:70, portName=nni-1048576
3.4 Add flows
karaf@root > volt-add-subscriber-access of:000002101801b470 4128
karaf@root > flows
deviceId=of:000002101801b470, flowRuleCount=7
id=b20000530248f4, state=ADDED, bytes=0, packets=0, duration=0, liveType=UNKNOWN, priority=10000, tableId=0, appId=org.opencord.olt, selector=[IN_PORT:4112, ETH_TYPE:eapol], treatment=DefaultTrafficTreatment{immediate=[OUTPUT:CONTROLLER, VLAN_PUSH:vlan, VLAN_ID:4091], deferred=[], transition=None, meter=[METER:1], cleared=false, StatTrigger=null, metadata=METADATA:ffb004100000000/0}
id=b20000d2ebb078, state=ADDED, bytes=0, packets=0, duration=0, liveType=UNKNOWN, priority=10000, tableId=0, appId=org.opencord.olt, selector=[IN_PORT:1048576, ETH_TYPE:lldp], treatment=DefaultTrafficTreatment{immediate=[OUTPUT:CONTROLLER], deferred=[], transition=None, meter=[], cleared=false, StatTrigger=null, metadata=null}
id=b20000f98e8d01, state=ADDED, bytes=0, packets=0, duration=0, liveType=UNKNOWN, priority=10000, tableId=0, appId=org.opencord.olt, selector=[IN_PORT:4128, ETH_TYPE:eapol], treatment=DefaultTrafficTreatment{immediate=[OUTPUT:CONTROLLER, VLAN_PUSH:vlan, VLAN_ID:10], deferred=[], transition=None, meter=[METER:2], cleared=false, StatTrigger=null, metadata=METADATA:a004100000002/0}
id=b20000025e6ddf, state=ADDED, bytes=0, packets=0, duration=0, liveType=UNKNOWN, priority=1000, tableId=0, appId=org.opencord.olt, selector=[IN_PORT:1048576, METADATA:a, VLAN_VID:1026], treatment=DefaultTrafficTreatment{immediate=[VLAN_POP], deferred=[], transition=TABLE:1, meter=[METER:3], cleared=false, StatTrigger=null, metadata=METADATA:a004100001020/0}
id=b20000de13fecb, state=ADDED, bytes=0, packets=0, duration=0, liveType=UNKNOWN, priority=1000, tableId=0, appId=org.opencord.olt, selector=[IN_PORT:4128, VLAN_VID:0], treatment=DefaultTrafficTreatment{immediate=[VLAN_ID:10], deferred=[], transition=TABLE:1, meter=[METER:2], cleared=false, StatTrigger=null, metadata=METADATA:a004100100000/0}
id=b200000374c4e2, state=ADDED, bytes=0, packets=0, duration=0, liveType=UNKNOWN, priority=1000, tableId=1, appId=org.opencord.olt, selector=[IN_PORT:4128, VLAN_VID:10], treatment=DefaultTrafficTreatment{immediate=[VLAN_PUSH:vlan, VLAN_ID:1026, OUTPUT:1048576], deferred=[], transition=None, meter=[METER:2], cleared=false, StatTrigger=null, metadata=METADATA:4100000000/0}
id=b20000c398857e, state=ADDED, bytes=0, packets=0, duration=0, liveType=UNKNOWN, priority=1000, tableId=1, appId=org.opencord.olt, selector=[IN_PORT:1048576, METADATA:1020, VLAN_VID:10], treatment=DefaultTrafficTreatment{immediate=[VLAN_ID:0, OUTPUT:4128], deferred=[], transition=None, meter=[METER:3], cleared=false, StatTrigger=null, metadata=METADATA:4100000000/0}

Step4 After Config Flows, Openolt Output Error log
[20210913_15:20:22_312]#BCM.0> call---> CreateTrafficSchedulers[3223646: I OPENOLT ] core_api_handler.cc 2444| Creating alloc_id 257 with pir = 3744000 bytes/sec, cir = 0 bytes/sec, gir = 3744000 bytes/sec, additional_bw = 2.
[20210913_15:20:22_327]#[3223646: E OPENOLT ] core_api_handler.cc 2462| Maximum bandwidth must be greater than Guaranteed bandwidth for additional bandwidth eligibility of type Best Effort
[20210913_15:20:22_329]#[3223646: E OPENOLT ] core_api_handler.cc 2586| Failed to create scheduler, err = Error in parameters
[20210913_15:20:22_330]#
[20210913_15:20:22_373]#[3223649: I OPENOLT ] core_utils.cc 532| Qos-type for subscriber connected to pon_intf_id 1, onu_id 1 and uni_id 0 is FIXED_QUEUE
[20210913_15:20:22_373]#[3223649: I OPENOLT ] core_api_handler.cc 2786| creating upstream queue. access_intf_id = 1, onu_id = 1, uni_id = 0 gemport_id = 257, tech_profile_id = 64
[20210913_15:20:22_373]#[3223649: I OPENOLT ] core_api_handler.cc 2817| queue assigned queue_id = 0
[20210913_15:20:22_374]#call---> CreateTrafficQueues[3223649: E OPENOLT ] core_api_handler.cc 2826| Failed to create subscriber tm queue, direction = upstream, queue_id 0, sched_id 1020, tm_q_set_id 32768, intf_id 1, onu_id 1, uni_id 0, tech_profile_id 64, err = Error in parameters
[20210913_15:20:22_375]#[3223649: E OPENOLT ] core_api_handler.cc 2905| Failed to create queue, err = Error in parameters
[20210913_15:20:22_375]#
[20210913_15:20:22_375]#call---> FlowAdd
[20210913_15:20:22_375]#[3223654: I OPENOLT ] core_api_handler.cc 1602| received flow add. voltha_flow_id=6664920330952084293, symmetric_voltha_flow_id=0, replication=0
[20210913_15:20:22_376]#[3223654: I OPENOLT ] core_api_handler.cc 1676| not a symmetric flow and replication is not needed
[20210913_15:20:22_376]#[3223654: I OPENOLT ] core_api_handler.cc 1780| flow add received for flow_id=3, flow_type=upstream
[20210913_15:20:22_376]#[3223654: I OPENOLT ] core_utils.cc 519| Qos-type for subscriber connected to pon_intf_id 1, onu_id 1 and uni_id 0 is FIXED_QUEUE
[20210913_15:20:22_376]#[3223654: E OPENOLT ] core_api_handler.cc 2110| --------> Flow add failed (flow_id 3) err: -9 <--------
[20210913_15:20:22_376]#[3223654: E OPENOLT ] core_api_handler.cc 2110| intf_id 1, onu_id 1, uni_id 0, port_no 4112, cookie 50102548878412882
[20210913_15:20:22_376]#[3223654: E OPENOLT ] core_api_handler.cc 2110| flow_type upstream, queue_id 0, sched_id 1020
[20210913_15:20:22_377]#[3223654: E OPENOLT ] core_api_handler.cc 2110| Ingress(intfd_type PON, intf_id 1), Egress(intf_type NNI, intf_id 0)
[20210913_15:20:22_377]#[3223654: E OPENOLT ] core_api_handler.cc 2110| classifier(o_vid 20, o_pbits 0, i_vid 0, i_pbits 0, ether type 0x0)
[20210913_15:20:22_377]#[3223654: E OPENOLT ] core_api_handler.cc 2110| classifier(ip_proto 0x0, gemport_id 257, src_port 0, dst_port 0, pkt_tag_type SINGLE_TAG)
[20210913_15:20:22_378]#[3223654: E OPENOLT ] core_api_handler.cc 2110| action(cmds_bitmask ADD_OUTER_TAG|, o_vid 1024, o_pbits 0, i_vid 0, i_pbits 0)
[20210913_15:20:22_378]#
[20210913_15:20:22_378]#[3223658: I OPENOLT ] core_api_handler.cc 2399| applying traffic shaping in DL cir=0, pir=30000, burst=0
[20210913_15:20:22_378]#call---> CreateTrafficSchedulers
[20210913_15:20:22_378]#[3223658: E OPENOLT ] core_api_handler.cc 2412| Failed to create downstream subscriber scheduler, id 0, intf_id 1, onu_id 1, uni_id 0, port_no 4112, err = Entry doesn't exist
[20210913_15:20:22_378]#[3223658: E OPENOLT ] core_api_handler.cc 2586| Failed to create scheduler, err = Entry doesn't exist
[20210913_15:20:22_378]#[3223660: I OPENOLT ] core_utils.cc 519| Qos-type for subscriber connected to pon_intf_id 1, onu_id 1 and uni_id 0 is FIXED_QUEUE
[20210913_15:20:22_379]#[3223660: I OPENOLT ] core_api_handler.cc 2786| creating downstream queue. access_intf_id = 1, onu_id = 1, uni_id = 0 gemport_id = 257, tech_profile_id = 64
[20210913_15:20:22_379]#call---> CreateTrafficQueues[3223660: I OPENOLT ] core_api_handler.cc 2817| queue assigned queue_id = 0
[20210913_15:20:22_379]#[3223660: E OPENOLT ] core_api_handler.cc 2826| Failed to create subscriber tm queue, direction = downstream, queue_id 0, sched_id 0, tm_q_set_id 32768, intf_id 1, onu_id 1, uni_id 0, tech_profile_id 64, err = Error in parameters
[20210913_15:20:22_379]#[3223660: E OPENOLT ] core_api_handler.cc 2905| Failed to create queue, err = Error in parameters
[20210913_15:20:22_379]#
[20210913_15:20:22_379]#call---> OmciMsgOut
[20210913_15:20:22_380]#call---> FlowAdd
[20210913_15:20:22_380]#[3223662: I OPENOLT ] core_api_handler.cc 1602| received flow add. voltha_flow_id=7853868489580710419, symmetric_voltha_flow_id=0, replication=0
[20210913_15:20:22_380]#[3223662: I OPENOLT ] core_api_handler.cc 1676| not a symmetric flow and replication is not needed
[20210913_15:20:22_380]#[3223662: I OPENOLT ] core_api_handler.cc 1780| flow add received for flow_id=3, flow_type=downstream
[20210913_15:20:22_380]#[3223662: I OPENOLT ] core_utils.cc 519| Qos-type for subscriber connected to pon_intf_id 1, onu_id 1 and uni_id 0 is FIXED_QUEUE
[20210913_15:20:22_380]#[3223663: E OPENOLT ] core_api_handler.cc 2110| --------> Flow add failed (flow_id 3) err: -6 <--------
[20210913_15:20:22_381]#[3223663: E OPENOLT ] core_api_handler.cc 2110| intf_id 1, onu_id 1, uni_id 0, port_no 4112, cookie 50102548670742975
[20210913_15:20:22_381]#[3223663: E OPENOLT ] core_api_handler.cc 2110| flow_type downstream, queue_id 0, sched_id 0
[20210913_15:20:22_381]#[3223663: E OPENOLT ] core_api_handler.cc 2110| Ingress(intfd_type NNI, intf_id 0), Egress(intf_type PON, intf_id 1)
[20210913_15:20:22_381]#[3223663: E OPENOLT ] core_api_handler.cc 2110| classifier(o_vid 1024, o_pbits 0, i_vid 20, i_pbits 0, ether type 0x0)
[20210913_15:20:22_381]#[3223663: E OPENOLT ] core_api_handler.cc 2110| classifier(ip_proto 0x0, gemport_id 257, src_port 0, dst_port 0, pkt_tag_type DOUBLE_TAG)
[20210913_15:20:22_382]#[3223663: E OPENOLT ] core_api_handler.cc 2110| action(cmds_bitmask REMOVE_OUTER_TAG|, o_vid 0, o_pbits 0, i_vid 0, i_pbits 0)
[20210913_15:20:22_382]#
[20210913_15:20:22_382]#call---> FlowAdd
[20210913_15:20:22_382]#[3223666: I OPENOLT ] core_api_handler.cc 1602| received flow add. voltha_flow_id=812894631930657282, symmetric_voltha_flow_id=0, replication=0
[20210913_15:20:22_382]#[3223666: I OPENOLT ] core_api_handler.cc 1676| not a symmetric flow and replication is not needed
[20210913_15:20:22_382]#[3223666: I OPENOLT ] core_api_handler.cc 1780| flow add received for flow_id=3, flow_type=upstream
[20210913_15:20:22_382]#[3223666: I OPENOLT ] core_utils.cc 1261| --------> ACL add ok (acl_id 2) err: 0 <--------
[20210913_15:20:22_392]#[3223666: I OPENOLT ] core_utils.cc 1261| action_type trap_to_host
[20210913_15:20:22_402]#[3223666: I OPENOLT ] core_utils.cc 1261| classifier(ether type 34958), ip_proto -1, src_port -1, dst_port -1
[20210913_15:20:22_402]#[3223666: I OPENOLT ] core_utils.cc 1415| acl add success for flow_id=3 with acl_id=2
[20210913_15:20:22_402]#[3223666: I OPENOLT ] core_utils.cc 1166| update acl interface received for intf_id = 1, intf_type = pon, acl_id = 2, acl_cmd = add
[20210913_15:20:22_402]#[3223667: E OPENOLT ] core_utils.cc 1192| update acl interface fail for intf_id = 1, intf_type = pon, acl_id = 2, acl_cmd = add
[20210913_15:20:22_403]#[3223667: E OPENOLT ] core_utils.cc 1428| failed to update acl interfaces intf_id=1, intf_type=pon, acl_id=2OmciIndication:obj_type 14 subgroup 19

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions