Clone one packet to CPU but get 18 replicated packets

[xbo775]

I want to clone a packet to cpu, but get a lot. There is my p4 code:

action clone_to_cpu(egressSpec_t port) {
    standard_metadata.egress_spec = port;
    hdr.ipv4.ttl = hdr.ipv4.ttl - 1;
    clone3(CloneType.I2E,CPU_MIRROR_SESSION_ID, { standard_metadata.ingress_port });
}

and configure the clone session with P4Runtime :

cse = sh.CloneSessionEntry(1)
cse.add(255,1)
cse.insert()

the logs of bmv2 shows:

P4Runtime Write
election_id {
  low: 1
}
updates {
  type: INSERT
  entity {
    packet_replication_engine_entry {
      clone_session_entry {
        session_id: 1
        replicas {
          egress_port: 255
          instance: 1
        }
      }
    }
  }
}
[06:06:28.084] [bmv2] [D] [thread 17434] mgrp node created for mgid 32769
[06:06:28.084] [bmv2] [D] [thread 17434] node created for rid 1
[06:06:28.084] [bmv2] [D] [thread 17434] node associated with mgid 32769
P4Runtime Read
entities {
  packet_replication_engine_entry {
    clone_session_entry {
      session_id: 1
      replicas {
        egress_port: 255
        instance: 1
      }
    }
  }
}

It seems all right, but when I send a packet, I got 18 replicated packets:

[06:10:15.840] [bmv2] [D] [thread 6088] [341.0] [cxt 0] Processing packet received on port 0
[06:10:15.840] [bmv2] [D] [thread 6088] [341.0] [cxt 0] Parser 'parser': start
[06:10:15.840] [bmv2] [D] [thread 6088] [341.0] [cxt 0] Parser 'parser' entering state 'start'
[06:10:15.840] [bmv2] [D] [thread 6088] [341.0] [cxt 0] Parser state 'start': key is 0000
[06:10:15.840] [bmv2] [T] [thread 6088] [341.0] [cxt 0] Bytes parsed: 0
[06:10:15.840] [bmv2] [D] [thread 6088] [341.0] [cxt 0] Parser 'parser' entering state 'parse_ethernet'
[06:10:15.840] [bmv2] [D] [thread 6088] [341.0] [cxt 0] Extracting header 'ethernet'
[06:10:15.840] [bmv2] [D] [thread 6088] [341.0] [cxt 0] Parser state 'parse_ethernet': key is 0800
[06:10:15.840] [bmv2] [T] [thread 6088] [341.0] [cxt 0] Bytes parsed: 14
[06:10:15.840] [bmv2] [D] [thread 6088] [341.0] [cxt 0] Parser 'parser' entering state 'parse_ipv4'
[06:10:15.840] [bmv2] [D] [thread 6088] [341.0] [cxt 0] Extracting header 'ipv4'
[06:10:15.840] [bmv2] [D] [thread 6088] [341.0] [cxt 0] Parser state 'parse_ipv4' has no switch, going to default next state
[06:10:15.840] [bmv2] [T] [thread 6088] [341.0] [cxt 0] Bytes parsed: 34
[06:10:15.840] [bmv2] [D] [thread 6088] [341.0] [cxt 0] Verifying checksum 'cksum_0': true
[06:10:15.840] [bmv2] [D] [thread 6088] [341.0] [cxt 0] Parser 'parser': end
[06:10:15.840] [bmv2] [D] [thread 6088] [341.0] [cxt 0] Pipeline 'ingress': start
[06:10:15.840] [bmv2] [T] [thread 6088] [341.0] [cxt 0] packet-test.p4(171) Condition "hdr.packet_out.isValid()" (node_2) is false
[06:10:15.840] [bmv2] [T] [thread 6088] [341.0] [cxt 0] packet-test.p4(177) Condition "hdr.ipv4.isValid()" (node_4) is true
[06:10:15.840] [bmv2] [T] [thread 6088] [341.0] [cxt 0] Applying table 'MyIngress.ipv4_exact'
[06:10:15.840] [bmv2] [D] [thread 6088] [341.0] [cxt 0] Looking up key:
* hdr.ipv4.dstAddr    : 0a000002

[06:10:15.840] [bmv2] [D] [thread 6088] [341.0] [cxt 0] Table 'MyIngress.ipv4_exact': hit with handle 2
[06:10:15.840] [bmv2] [D] [thread 6088] [341.0] [cxt 0] Dumping entry 2
Match key:
* hdr.ipv4.dstAddr    : EXACT     0a000002
Action entry: MyIngress.clone_to_cpu - 1,

[06:10:15.840] [bmv2] [D] [thread 6088] [341.0] [cxt 0] Action entry is MyIngress.clone_to_cpu - 1,
[06:10:15.840] [bmv2] [T] [thread 6088] [341.0] [cxt 0] Action MyIngress.clone_to_cpu
[06:10:15.840] [bmv2] [T] [thread 6088] [341.0] [cxt 0] packet-test.p4(135) Primitive standard_metadata.egress_spec = port
[06:10:15.840] [bmv2] [T] [thread 6088] [341.0] [cxt 0] packet-test.p4(136) Primitive hdr.ipv4.ttl = hdr.ipv4.ttl - 1
[06:10:15.840] [bmv2] [T] [thread 6088] [341.0] [cxt 0] packet-test.p4(137) Primitive clone3(CloneType.I2E,1, { standard_metadata.ingress_port })
[06:10:15.840] [bmv2] [D] [thread 6088] [341.0] [cxt 0] Pipeline 'ingress': end
[06:10:15.840] [bmv2] [D] [thread 6088] [341.0] [cxt 0] Cloning packet at ingress
[06:10:15.840] [bmv2] [D] [thread 6088] [341.1] [cxt 0] Parser 'parser': start
[06:10:15.840] [bmv2] [D] [thread 6088] [341.1] [cxt 0] Parser 'parser' entering state 'start'
[06:10:15.840] [bmv2] [D] [thread 6088] [341.1] [cxt 0] Parser state 'start': key is 0000
[06:10:15.840] [bmv2] [T] [thread 6088] [341.1] [cxt 0] Bytes parsed: 0
[06:10:15.840] [bmv2] [D] [thread 6088] [341.1] [cxt 0] Parser 'parser' entering state 'parse_ethernet'
[06:10:15.840] [bmv2] [D] [thread 6088] [341.1] [cxt 0] Extracting header 'ethernet'
[06:10:15.840] [bmv2] [D] [thread 6088] [341.1] [cxt 0] Parser state 'parse_ethernet': key is 0800
[06:10:15.840] [bmv2] [T] [thread 6088] [341.1] [cxt 0] Bytes parsed: 14
[06:10:15.840] [bmv2] [D] [thread 6088] [341.1] [cxt 0] Parser 'parser' entering state 'parse_ipv4'
[06:10:15.840] [bmv2] [D] [thread 6088] [341.1] [cxt 0] Extracting header 'ipv4'
[06:10:15.840] [bmv2] [D] [thread 6088] [341.1] [cxt 0] Parser state 'parse_ipv4' has no switch, going to default next state
[06:10:15.840] [bmv2] [T] [thread 6088] [341.1] [cxt 0] Bytes parsed: 34
[06:10:15.840] [bmv2] [D] [thread 6088] [341.1] [cxt 0] Verifying checksum 'cksum_0': true
[06:10:15.840] [bmv2] [D] [thread 6088] [341.1] [cxt 0] Parser 'parser': end
[06:10:15.840] [bmv2] [D] [thread 6088] [341.0] [cxt 0] Cloning packet to MGID 32769
[06:10:15.840] [bmv2] [D] [thread 6088] number of packets replicated : 18

I receive packet from switch like this:

while True:
        rep = client.get_stream_packet('packet',timeout=2)
        if rep is not None:
            print(time.asctime(time.localtime()),'ingress port is',int.from_bytes(rep.packet.metadata[0].value,'big'))

the ouput shows :

field_id: 1
exact {
  value: "\n\000\000\000"
}

param_id: 1
value: "\000\001"

field_id: 1
exact {
  value: "\n\000\000\001"
}

field_id: 1
exact {
  value: "\n\000\000\002"
}

param_id: 1
value: "\000\001"

clone_session_entry {
  session_id: 1
  replicas {
    egress_port: 255
    instance: 1
  }
}

Wed May 13 06:10:15 2020 ingress port is 0
Wed May 13 06:10:15 2020 ingress port is 0
Wed May 13 06:10:15 2020 ingress port is 0
Wed May 13 06:10:15 2020 ingress port is 0
Wed May 13 06:10:15 2020 ingress port is 0
Wed May 13 06:10:15 2020 ingress port is 0
Wed May 13 06:10:15 2020 ingress port is 0
Wed May 13 06:10:15 2020 ingress port is 0
Wed May 13 06:10:15 2020 ingress port is 0
Wed May 13 06:10:15 2020 ingress port is 0
Wed May 13 06:10:15 2020 ingress port is 0
Wed May 13 06:10:15 2020 ingress port is 0
Wed May 13 06:10:15 2020 ingress port is 0
Wed May 13 06:10:15 2020 ingress port is 0
Wed May 13 06:10:15 2020 ingress port is 0
Wed May 13 06:10:15 2020 ingress port is 0
Wed May 13 06:10:15 2020 ingress port is 0
Wed May 13 06:10:15 2020 ingress port is 0
CRITICAL:root:StreamChannel error, closing stream
CRITICAL:root:P4Runtime RPC error (UNAVAILABLE): Socket closed

I really got 18 same packets, but the number is uncertain, some time 8 or 9.

Why the replicated packets is more than one I need? it's a bug or I used the clone function in a wrong way? I hope you can help me, thanks a lot！

[xbo775]

I reran the simple_switch_grpc and configured it using my p4runtime controller, I got the right result. but everytime after I reran my p4runtime controller, the replicated packets increase one. Obviously，it is due to multiple inserts of clone session entry . However, the sh.CloneSessionEntry(1).read(lambda x: print(x)) shows there is still one replicas.

In issue #667 antoninbas said

clone packet to a set of ports. You need to call clone or clone3 and provide a clone session id. You need to configure that session id with a P4Runtime CloneSessionEntry message. The packet will be cloned to every port you include in the replicas Protobuf field. It can be a single port or several ports. Behind the scenes, bmv2 will implement the P4Runtime message by creating a multicast group, so you will see mentions of multicast groups in the logs, but this is just how bmv2 implements cloning to multiple ports.

so I think if there are multi-replicas in multicast group entry because I inserted clone session entry repeatedly, but result shows there is only one replicas like CloneSessionEntry:

multicast_group_entry {
 multicast_group_id: 32769
 replicas {
   egress_port: 255
   instance: 1
 }
}

the multicast_group_id is found in bmv2's log output:

[07:10:56.975] [bmv2] [D] [thread 19220] mgrp node created for mgid 32769
[07:10:56.975] [bmv2] [D] [thread 19220] node created for rid 1
[07:10:56.975] [bmv2] [D] [thread 19220] node associated with mgid 32769

I am so confused. Is it a bug of bmv2's implementation about Clone/Multicast? Maybe we should avoid repetitive inserts in bmv2 or raise an exception when inserting existent entry .

[antoninbas]

Do you have a script I can run to insert the same clone session id multiple times? Because when I try to do it with the latest version of bmv2 and p4runtime-sh, I get the following error:

P4RuntimeWriteException: Error(s) during Write:
	* At index 0: ALREADY_EXISTS, 'Clone session id already exists'

And the bmv2 logs show:

[11:27:45.300] [bmv2] [E] [thread 58980] [P4Runtime] Clone session id already exists

[antoninbas]

Actually I was able to reproduce this by restarting p4runtime-shell, so I spoke too quickly.

I need to think about it some more, but I assume that your controller does a SetForwardingPipelineConfig RPC on restart? In which case I tend to agree that all forwarding state should be reset, including the multicast engine configuration. I need to think about what is the best way to fix this.

[xbo775]

yes, I can SetForwardingPipelineConfig on restart or restart bmv2 directly , which is my solution for now. but the problem is that all the other configures including tables are reset too, that is not what I want.

Why it raises an error when inserting existent clone session entry at the same p4runtime-shell, but not at another p4runtime-shell? even no replicas found in multicast/clone session entry.

[antoninbas]

There are 2 levels of state:

1. state stored in the P4Runtime server
2. state store in the bmv2 "dataplane"

When you do a SetForwardingPipelineConfig, it clears multicast state for 1, but not for 2. That mismatch is definitely a bug. Match tables' state is reset for both 1 and 2. If you do not do a SetForwardingPipelineConfig, there will be no issue because none of the state will be reset. Which is why my assumption was that you were doing a SetForwardingPipelineConfig on restart in your controller.

Depending on the command-line flags used, p4runtime-shell will perform a SetFowardingPipelineConfig. In particular it is the case when running p4runtime-sh-docker with the --config flag.
If you do the following sequence:

• run p4runtime-sh-docker with --config
• insert a clone session
• kill the shell
• run p4runtime-sh-docker without --config
• insert the same clone session

then you will see an error

If you run the same sequence but with --config for the second run of p4runtime-sh-docker, you will not get an error, but the "dataplane" configuration of multicast will be wrong in bmv2.

[xbo775]

Thank you a lot, I think I have got the point and know the reasons.

In my controller script, I use the config parameter in sh.setup() function without calling sh.SetForwardingPipelineConfig() explicitly, and see P4Runtime SetForwardingPipelineConfig in bmv2's log.

Maybe we'd better clears multicast state for both 1 and 2 when do a SetForwardingPipelineConfig.

[github-actions]

This issue is stale because it has been open 180 days with no activity. Remove stale label or comment, or this will be closed in 180 days