search

p4lang / tutorials

P4 language tutorials
Apache License 2.0
1.37k stars 892 forks source link

2017_Spring MRI - parsing problem #132

Closed tr1st4 closed 6 years ago

tr1st4 commented 6 years ago

Hello, I've a problem with the mri exercices from the P4D2_2017_Spring repository. When I run my solution (that is exactly the same that the solution provides in the "solution" directory) I'm not able to receive correctly on host 2 (h2): I execute ./receive.py on this host et ./send.py on h1 nothing is shown on h2. 1/ I've edited receive.py to permit udp on any port just like this:


    sniff(filter="udp", iface = iface,
          prn = lambda x: handle_pkt(x))

When I retry here is the output of h2:

[root@localhost build]# ./receive.py
sniffing on h2-eth0
got a packet
###[ Ethernet ]###
  dst       = 00:aa:00:02:00:02
  src       = f2:ed:e6:df:4e:fa
  type      = IPv4
###[ IP ]###
     version   = 4L
     ihl       = 8L
     tos       = 0x0
     len       = 38
     id        = 1
     flags     =
     frag      = 0L
     ttl       = 62
     proto     = udp
     chksum    = 0x63b3
     src       = 10.0.1.10
     dst       = 10.0.2.10
     \options   \
      **|###[ MRI ]###
      |  copy_flag = 1L
      |  optclass  = debug
      |  option    = 31L
      |  length    = 12
      |  count     = 2
      |  swids     = ['80875745', '1244265']
###[ UDP ]###
        sport     = 28724
        dport     = 8297
        len       = 29472
        chksum    = None
###[ Padding ]###
           load      = 'cool'

As you can see all is fine up to the swids reception. So I've suspected a wrong behavior of p4 program (swids missing element for example or something related to the size of the IP header), so I've checked the s1.log and s2.log.

(Sorry for the long output but it's to give you a full picture).

s1.log

[16:34:52.064] [bmv2] [D] [thread 13466] [115.0] [cxt 0] Processing packet received on port 1
[16:34:52.064] [bmv2] [D] [thread 13466] [115.0] [cxt 0] Parser 'parser': start
[16:34:52.064] [bmv2] [D] [thread 13466] [115.0] [cxt 0] Parser 'parser' entering state 'start'
[16:34:52.064] [bmv2] [D] [thread 13466] [115.0] [cxt 0] Extracting header 'ethernet'
[16:34:52.064] [bmv2] [D] [thread 13466] [115.0] [cxt 0] Parser state 'start': key is 0800
[16:34:52.064] [bmv2] [T] [thread 13466] [115.0] [cxt 0] Bytes parsed: 14
[16:34:52.064] [bmv2] [D] [thread 13466] [115.0] [cxt 0] Parser 'parser' entering state 'parse_ipv4'
[16:34:52.064] [bmv2] [D] [thread 13466] [115.0] [cxt 0] Extracting header 'ipv4'
[16:34:52.064] [bmv2] [D] [thread 13466] [115.0] [cxt 0] Parser set: setting field 'scalars.tmp' from expression, new value is 1
[16:34:52.064] [bmv2] [D] [thread 13466] [115.0] [cxt 0] Parser state 'parse_ipv4': key is 05
[16:34:52.064] [bmv2] [T] [thread 13466] [115.0] [cxt 0] Bytes parsed: 34
[16:34:52.064] [bmv2] [D] [thread 13466] [115.0] [cxt 0] Parser 'parser': end
[16:34:52.064] [bmv2] [D] [thread 13466] [115.0] [cxt 0] Pipeline 'ingress': start
[16:34:52.064] [bmv2] [T] [thread 13466] [115.0] [cxt 0] mri-implementation.p4(260) Condition "hdr.ipv4.isValid()" (node_2) is true
[16:34:52.064] [bmv2] [T] [thread 13466] [115.0] [cxt 0] Applying table 'ingress.ipv4_lpm'
[16:34:52.064] [bmv2] [D] [thread 13466] [115.0] [cxt 0] Looking up key:
* hdr.ipv4.dstAddr    : 0a00020a

[16:34:52.064] [bmv2] [D] [thread 13466] [115.0] [cxt 0] Table 'ingress.ipv4_lpm': hit with handle 1
[16:34:52.064] [bmv2] [D] [thread 13466] [115.0] [cxt 0] Dumping entry 1
Match key:
* hdr.ipv4.dstAddr    : LPM       0a00020a/32
Action entry: ingress.ipv4_forward - f2ede6df4efa,2,

[16:34:52.064] [bmv2] [D] [thread 13466] [115.0] [cxt 0] Action entry is ingress.ipv4_forward - f2ede6df4efa,2,
[16:34:52.064] [bmv2] [T] [thread 13466] [115.0] [cxt 0] Action ingress.ipv4_forward
[16:34:52.064] [bmv2] [T] [thread 13466] [115.0] [cxt 0] mri-implementation.p4(229) Primitive standard_metadata.egress_spec = port
[16:34:52.064] [bmv2] [T] [thread 13466] [115.0] [cxt 0] mri-implementation.p4(230) Primitive hdr.ethernet.srcAddr = hdr.ethernet.dstAddr
[16:34:52.064] [bmv2] [T] [thread 13466] [115.0] [cxt 0] mri-implementation.p4(231) Primitive hdr.ethernet.dstAddr = dstAddr
[16:34:52.064] [bmv2] [T] [thread 13466] [115.0] [cxt 0] mri-implementation.p4(232) Primitive hdr.ipv4.ttl = hdr.ipv4.ttl - 1
[16:34:52.064] [bmv2] [T] [thread 13466] [115.0] [cxt 0] mri-implementation.p4(262) Condition "!hdr.mri.isValid()" (node_4) is true
[16:34:52.064] [bmv2] [T] [thread 13466] [115.0] [cxt 0] Applying table 'tbl_add_mri_option'
[16:34:52.064] [bmv2] [D] [thread 13466] [115.0] [cxt 0] Looking up key:

[16:34:52.064] [bmv2] [D] [thread 13466] [115.0] [cxt 0] Table 'tbl_add_mri_option': miss
[16:34:52.064] [bmv2] [D] [thread 13466] [115.0] [cxt 0] Action entry is ingress.add_mri_option -
[16:34:52.064] [bmv2] [T] [thread 13466] [115.0] [cxt 0] Action ingress.add_mri_option
[16:34:52.064] [bmv2] [T] [thread 13466] [115.0] [cxt 0] mri-implementation.p4(188) Primitive hdr.ipv4_option.setValid()
[16:34:52.064] [bmv2] [T] [thread 13466] [115.0] [cxt 0] mri-implementation.p4(189) Primitive hdr.ipv4_option.copyFlag = 1
[16:34:52.064] [bmv2] [T] [thread 13466] [115.0] [cxt 0] mri-implementation.p4(190) Primitive hdr.ipv4_option.optClass = 2
[16:34:52.064] [bmv2] [T] [thread 13466] [115.0] [cxt 0] mri-implementation.p4(7) Primitive 31; ...
[16:34:52.064] [bmv2] [T] [thread 13466] [115.0] [cxt 0] mri-implementation.p4(192) Primitive hdr.ipv4_option.optionLength = 4
[16:34:52.064] [bmv2] [T] [thread 13466] [115.0] [cxt 0] mri-implementation.p4(193) Primitive hdr.mri.setValid()
[16:34:52.064] [bmv2] [T] [thread 13466] [115.0] [cxt 0] mri-implementation.p4(194) Primitive hdr.mri.count = 0
[16:34:52.064] [bmv2] [T] [thread 13466] [115.0] [cxt 0] mri-implementation.p4(195) Primitive hdr.ipv4.ihl = hdr.ipv4.ihl + 1
[16:34:52.064] [bmv2] [T] [thread 13466] [115.0] [cxt 0] Applying table 'ingress.swid'
[16:34:52.064] [bmv2] [D] [thread 13466] [115.0] [cxt 0] Looking up key:

[16:34:52.064] [bmv2] [D] [thread 13466] [115.0] [cxt 0] Table 'ingress.swid': miss
[16:34:52.064] [bmv2] [D] [thread 13466] [115.0] [cxt 0] Action entry is ingress.add_swid - 1,
[16:34:52.064] [bmv2] [T] [thread 13466] [115.0] [cxt 0] Action ingress.add_swid
[16:34:52.064] [bmv2] [T] [thread 13466] [115.0] [cxt 0] mri-implementation.p4(212) Primitive hdr.mri.count = hdr.mri.count + 1
[16:34:52.064] [bmv2] [T] [thread 13466] [115.0] [cxt 0] mri-implementation.p4(213) Primitive hdr.swids.push_front(1)
[16:34:52.064] [bmv2] [T] [thread 13466] [115.0] [cxt 0] mri-implementation.p4(214) Primitive hdr.swids[0].swid = id
[16:34:52.064] [bmv2] [T] [thread 13466] [115.0] [cxt 0] mri-implementation.p4(215) Primitive hdr.ipv4.ihl = hdr.ipv4.ihl + 1
[16:34:52.064] [bmv2] [T] [thread 13466] [115.0] [cxt 0] mri-implementation.p4(216) Primitive hdr.ipv4_option.optionLength = hdr.ipv4_option.optionLength + 4
[16:34:52.064] [bmv2] [D] [thread 13466] [115.0] [cxt 0] Pipeline 'ingress': end
[16:34:52.064] [bmv2] [D] [thread 13466] [115.0] [cxt 0] Egress port is 2
[16:34:52.064] [bmv2] [D] [thread 13469] [115.0] [cxt 0] Pipeline 'egress': start
[16:34:52.064] [bmv2] [D] [thread 13469] [115.0] [cxt 0] Pipeline 'egress': end
[16:34:52.064] [bmv2] [D] [thread 13469] [115.0] [cxt 0] Deparser 'deparser': start
[16:34:52.064] [bmv2] [D] [thread 13469] [115.0] [cxt 0] Deparsing header 'ethernet'
[16:34:52.064] [bmv2] [D] [thread 13469] [115.0] [cxt 0] Deparsing header 'ipv4'
[16:34:52.064] [bmv2] [D] [thread 13469] [115.0] [cxt 0] Deparsing header 'ipv4_option'
[16:34:52.064] [bmv2] [D] [thread 13469] [115.0] [cxt 0] Deparsing header 'mri'
 ---> ???? Missing deparsing of swids here!!!!
[16:34:52.064] [bmv2] [D] [thread 13469] [115.0] [cxt 0] Deparser 'deparser': end
[16:34:52.064] [bmv2] [D] [thread 13471] [115.0] [cxt 0] Transmitting packet of size 56 out of port 2

s2.log

[16:34:52.064] [bmv2] [D] [thread 13479] [106.0] [cxt 0] Processing packet received on port 2
[16:34:52.064] [bmv2] [D] [thread 13479] [106.0] [cxt 0] Parser 'parser': start
[16:34:52.064] [bmv2] [D] [thread 13479] [106.0] [cxt 0] Parser 'parser' entering state 'start'
[16:34:52.064] [bmv2] [D] [thread 13479] [106.0] [cxt 0] Extracting header 'ethernet'
[16:34:52.064] [bmv2] [D] [thread 13479] [106.0] [cxt 0] Parser state 'start': key is 0800
[16:34:52.064] [bmv2] [T] [thread 13479] [106.0] [cxt 0] Bytes parsed: 14
[16:34:52.065] [bmv2] [D] [thread 13479] [106.0] [cxt 0] Parser 'parser' entering state 'parse_ipv4'
[16:34:52.065] [bmv2] [D] [thread 13479] [106.0] [cxt 0] Extracting header 'ipv4'
[16:34:52.065] [bmv2] [D] [thread 13479] [106.0] [cxt 0] Parser set: setting field 'scalars.tmp' from expression, new value is 1
[16:34:52.065] [bmv2] [D] [thread 13479] [106.0] [cxt 0] Parser state 'parse_ipv4': key is 07
[16:34:52.065] [bmv2] [T] [thread 13479] [106.0] [cxt 0] Bytes parsed: 34
[16:34:52.065] [bmv2] [D] [thread 13479] [106.0] [cxt 0] Parser 'parser' entering state 'parse_ipv4_option'
[16:34:52.065] [bmv2] [D] [thread 13479] [106.0] [cxt 0] Extracting header 'ipv4_option'
[16:34:52.065] [bmv2] [D] [thread 13479] [106.0] [cxt 0] Parser state 'parse_ipv4_option': key is 1f
[16:34:52.065] [bmv2] [T] [thread 13479] [106.0] [cxt 0] Bytes parsed: 36
[16:34:52.065] [bmv2] [D] [thread 13479] [106.0] [cxt 0] Parser 'parser' entering state 'parse_mri'
[16:34:52.065] [bmv2] [D] [thread 13479] [106.0] [cxt 0] Extracting header 'mri'
[16:34:52.065] [bmv2] [D] [thread 13479] [106.0] [cxt 0] Parser set: setting field 'userMetadata.parser_metadata.remaining' from field 'mri.count' (1)
[16:34:52.065] [bmv2] [D] [thread 13479] [106.0] [cxt 0] Parser state 'parse_mri': key is 0001
[16:34:52.065] [bmv2] [T] [thread 13479] [106.0] [cxt 0] Bytes parsed: 38
[16:34:52.065] [bmv2] [D] [thread 13479] [106.0] [cxt 0] Parser 'parser' entering state 'parse_swid'
[16:34:52.065] [bmv2] [D] [thread 13479] [106.0] [cxt 0] Extracting to header stack 0, next header is 6
[16:34:52.065] [bmv2] [D] [thread 13479] [106.0] [cxt 0] Parser set: setting field 'userMetadata.parser_metadata.remaining' from expression, new value is 0
[16:34:52.065] [bmv2] [D] [thread 13479] [106.0] [cxt 0] Parser state 'parse_swid': key is 0000
[16:34:52.065] [bmv2] [T] [thread 13479] [106.0] [cxt 0] Bytes parsed: 42
[16:34:52.065] [bmv2] [D] [thread 13479] [106.0] [cxt 0] Parser 'parser': end
[16:34:52.065] [bmv2] [D] [thread 13479] [106.0] [cxt 0] Pipeline 'ingress': start
[16:34:52.065] [bmv2] [T] [thread 13479] [106.0] [cxt 0] mri-implementation.p4(260) Condition "hdr.ipv4.isValid()" (node_2) is true
[16:34:52.065] [bmv2] [T] [thread 13479] [106.0] [cxt 0] Applying table 'ingress.ipv4_lpm'
[16:34:52.065] [bmv2] [D] [thread 13479] [106.0] [cxt 0] Looking up key:
* hdr.ipv4.dstAddr    : 0a00020a

[16:34:52.065] [bmv2] [D] [thread 13479] [106.0] [cxt 0] Table 'ingress.ipv4_lpm': hit with handle 0
[16:34:52.065] [bmv2] [D] [thread 13479] [106.0] [cxt 0] Dumping entry 0
Match key:
* hdr.ipv4.dstAddr    : LPM       0a00020a/32
Action entry: ingress.ipv4_forward - aa00020002,1,

[16:34:52.065] [bmv2] [D] [thread 13479] [106.0] [cxt 0] Action entry is ingress.ipv4_forward - aa00020002,1,
[16:34:52.065] [bmv2] [T] [thread 13479] [106.0] [cxt 0] Action ingress.ipv4_forward
[16:34:52.065] [bmv2] [T] [thread 13479] [106.0] [cxt 0] mri-implementation.p4(229) Primitive standard_metadata.egress_spec = port
[16:34:52.065] [bmv2] [T] [thread 13479] [106.0] [cxt 0] mri-implementation.p4(230) Primitive hdr.ethernet.srcAddr = hdr.ethernet.dstAddr
[16:34:52.065] [bmv2] [T] [thread 13479] [106.0] [cxt 0] mri-implementation.p4(231) Primitive hdr.ethernet.dstAddr = dstAddr
[16:34:52.065] [bmv2] [T] [thread 13479] [106.0] [cxt 0] mri-implementation.p4(232) Primitive hdr.ipv4.ttl = hdr.ipv4.ttl - 1
[16:34:52.065] [bmv2] [T] [thread 13479] [106.0] [cxt 0] mri-implementation.p4(262) Condition "!hdr.mri.isValid()" (node_4) is false
[16:34:52.065] [bmv2] [T] [thread 13479] [106.0] [cxt 0] Applying table 'ingress.swid'
[16:34:52.065] [bmv2] [D] [thread 13479] [106.0] [cxt 0] Looking up key:

[16:34:52.065] [bmv2] [D] [thread 13479] [106.0] [cxt 0] Table 'ingress.swid': miss
[16:34:52.065] [bmv2] [D] [thread 13479] [106.0] [cxt 0] Action entry is ingress.add_swid - 2,
[16:34:52.065] [bmv2] [T] [thread 13479] [106.0] [cxt 0] Action ingress.add_swid
[16:34:52.065] [bmv2] [T] [thread 13479] [106.0] [cxt 0] mri-implementation.p4(212) Primitive hdr.mri.count = hdr.mri.count + 1
[16:34:52.065] [bmv2] [T] [thread 13479] [106.0] [cxt 0] mri-implementation.p4(213) Primitive hdr.swids.push_front(1)
[16:34:52.065] [bmv2] [T] [thread 13479] [106.0] [cxt 0] mri-implementation.p4(214) Primitive hdr.swids[0].swid = id
[16:34:52.065] [bmv2] [T] [thread 13479] [106.0] [cxt 0] mri-implementation.p4(215) Primitive hdr.ipv4.ihl = hdr.ipv4.ihl + 1
[16:34:52.065] [bmv2] [T] [thread 13479] [106.0] [cxt 0] mri-implementation.p4(216) Primitive hdr.ipv4_option.optionLength = hdr.ipv4_option.optionLength + 4
[16:34:52.065] [bmv2] [D] [thread 13479] [106.0] [cxt 0] Pipeline 'ingress': end
[16:34:52.065] [bmv2] [D] [thread 13479] [106.0] [cxt 0] Egress port is 1
[16:34:52.065] [bmv2] [D] [thread 13481] [106.0] [cxt 0] Pipeline 'egress': start
[16:34:52.065] [bmv2] [D] [thread 13481] [106.0] [cxt 0] Pipeline 'egress': end
[16:34:52.065] [bmv2] [D] [thread 13481] [106.0] [cxt 0] Deparser 'deparser': start
[16:34:52.065] [bmv2] [D] [thread 13481] [106.0] [cxt 0] Deparsing header 'ethernet'
[16:34:52.065] [bmv2] [D] [thread 13481] [106.0] [cxt 0] Deparsing header 'ipv4'
[16:34:52.065] [bmv2] [D] [thread 13481] [106.0] [cxt 0] Deparsing header 'ipv4_option'
[16:34:52.065] [bmv2] [D] [thread 13481] [106.0] [cxt 0] Deparsing header 'mri'
 [16:34:52.065] [bmv2] [D] [thread 13481] [106.0] [cxt 0] Deparsing header 'swids[1]' <-- here the swids is deparsed as expected in the p4 mri.
[16:34:52.065] [bmv2] [D] [thread 13481] [106.0] [cxt 0] Deparser 'deparser': end
[16:34:52.065] [bmv2] [D] [thread 13484] [106.0] [cxt 0] Transmitting packet of size 56 out of port 1

So I suspect a problem with deparsing on s1 because of the step in bold ...However, in the code the deparsing Implementation is as follow:


control DeparserImpl(packet_out packet, in headers hdr) {
    apply {
        packet.emit(hdr.ethernet);
        packet.emit(hdr.ipv4);
        packet.emit(hdr.ipv4_option);
        packet.emit(hdr.mri);
        packet.emit(hdr.swids);                 
    }
}

Anyone was confronted to the same problem before ? Or Someone has an idea ?

Thanks in advance!

antoninbas commented 6 years ago

You are using a recent version of bmv2 with an old(er) tutorial. Starting with version 1.11, bmv2 conforms with the P4_16 specification and no longer marks headers added to a stack with push_front as valid: https://p4.org/p4-spec/docs/P4-16-v1.0.0-spec.html#sec-expr-hs.

I updated all existing mri.p4 solutions with a call to setValid (right after the call to push_front). This call will have no effect for older versions of bmv2, but will make the solution work for versions >= 1.11. Please take a look at this patch and tell us if it works for you: https://github.com/p4lang/tutorials/pull/133

tr1st4 commented 6 years ago

Sorry for the delay, I confirm your diagnostic is right. Thank you!

jnfoster commented 6 years ago

Have you tried this with the latest version of the tutorial?

https://github.com/p4lang/tutorials/tree/master/P4D2_2018_East

On Sat, Apr 14, 2018 at 1:52 PM, tr1st4 notifications@github.com wrote:

Hello, I've a problem with the mri exercices from the P4D2_2017_Spring repository. When I run my solution (that is exactly the same that the solution provides in the "solution" directory) I'm not able to receive correctly on host 2 (h2): I execute ./receive.py on this host et ./send.py on h1 nothing is shown on h2. 1/ I've edited receive.py to permit udp on any port just like this:

sniff(filter="udp", iface = iface,
      prn = lambda x: handle_pkt(x))

When I retry here is the output of h2:

[root@localhost build]# ./receive.py sniffing on h2-eth0 got a packet

[ Ethernet ]

dst = 00:aa:00:02:00:02 src = f2:ed:e6:df:4e:fa type = IPv4

[ IP ]

 version   = 4L
 ihl       = 8L
 tos       = 0x0
 len       = 38
 id        = 1
 flags     =
 frag      = 0L
 ttl       = 62
 proto     = udp
 chksum    = 0x63b3
 src       = 10.0.1.10
 dst       = 10.0.2.10
 \options   \
  **|###[ MRI ]###
  |  copy_flag = 1L
  |  optclass  = debug
  |  option    = 31L
  |  length    = 12
  |  count     = 2**
  |  swids     = ['80875745', '1244265']

[ UDP ]

    sport     = 28724
    dport     = 8297
    len       = 29472
    chksum    = None

[ Padding ]

       load      = 'cool'

As you can see all is fine up to the swids reception. So I've suspected a wrong behavior of p4 program (swids missing element for example or something related to the size of the IP header), so I've checked the s1.log and s2.log.

(Sorry for the long output but it's to give you a full picture).

s1.log

[16:34:52.064] [bmv2] [D] [thread 13466] [115.0] [cxt 0] Processing packet received on port 1 [16:34:52.064] [bmv2] [D] [thread 13466] [115.0] [cxt 0] Parser 'parser': start [16:34:52.064] [bmv2] [D] [thread 13466] [115.0] [cxt 0] Parser 'parser' entering state 'start' [16:34:52.064] [bmv2] [D] [thread 13466] [115.0] [cxt 0] Extracting header 'ethernet' [16:34:52.064] [bmv2] [D] [thread 13466] [115.0] [cxt 0] Parser state 'start': key is 0800 [16:34:52.064] [bmv2] [T] [thread 13466] [115.0] [cxt 0] Bytes parsed: 14 [16:34:52.064] [bmv2] [D] [thread 13466] [115.0] [cxt 0] Parser 'parser' entering state 'parse_ipv4' [16:34:52.064] [bmv2] [D] [thread 13466] [115.0] [cxt 0] Extracting header 'ipv4' [16:34:52.064] [bmv2] [D] [thread 13466] [115.0] [cxt 0] Parser set: setting field 'scalars.tmp' from expression, new value is 1 [16:34:52.064] [bmv2] [D] [thread 13466] [115.0] [cxt 0] Parser state 'parse_ipv4': key is 05 [16:34:52.064] [bmv2] [T] [thread 13466] [115.0] [cxt 0] Bytes parsed: 34 [16:34:52.064] [bmv2] [D] [thread 13466] [115.0] [cxt 0] Parser 'parser': end [16:34:52.064] [bmv2] [D] [thread 13466] [115.0] [cxt 0] Pipeline 'ingress': start [16:34:52.064] [bmv2] [T] [thread 13466] [115.0] [cxt 0] mri-implementation.p4(260) Condition "hdr.ipv4.isValid()" (node_2) is true [16:34:52.064] [bmv2] [T] [thread 13466] [115.0] [cxt 0] Applying table 'ingress.ipv4_lpm' [16:34:52.064] [bmv2] [D] [thread 13466] [115.0] [cxt 0] Looking up key:

  • hdr.ipv4.dstAddr : 0a00020a

[16:34:52.064] [bmv2] [D] [thread 13466] [115.0] [cxt 0] Table 'ingress.ipv4_lpm': hit with handle 1 [16:34:52.064] [bmv2] [D] [thread 13466] [115.0] [cxt 0] Dumping entry 1 Match key:

  • hdr.ipv4.dstAddr : LPM 0a00020a/32 Action entry: ingress.ipv4_forward - f2ede6df4efa,2,

[16:34:52.064] [bmv2] [D] [thread 13466] [115.0] [cxt 0] Action entry is ingress.ipv4_forward - f2ede6df4efa,2, [16:34:52.064] [bmv2] [T] [thread 13466] [115.0] [cxt 0] Action ingress.ipv4_forward [16:34:52.064] [bmv2] [T] [thread 13466] [115.0] [cxt 0] mri-implementation.p4(229) Primitive standard_metadata.egress_spec = port [16:34:52.064] [bmv2] [T] [thread 13466] [115.0] [cxt 0] mri-implementation.p4(230) Primitive hdr.ethernet.srcAddr = hdr.ethernet.dstAddr [16:34:52.064] [bmv2] [T] [thread 13466] [115.0] [cxt 0] mri-implementation.p4(231) Primitive hdr.ethernet.dstAddr = dstAddr [16:34:52.064] [bmv2] [T] [thread 13466] [115.0] [cxt 0] mri-implementation.p4(232) Primitive hdr.ipv4.ttl = hdr.ipv4.ttl - 1 [16:34:52.064] [bmv2] [T] [thread 13466] [115.0] [cxt 0] mri-implementation.p4(262) Condition "!hdr.mri.isValid()" (node_4) is true [16:34:52.064] [bmv2] [T] [thread 13466] [115.0] [cxt 0] Applying table 'tbl_add_mri_option' [16:34:52.064] [bmv2] [D] [thread 13466] [115.0] [cxt 0] Looking up key:

[16:34:52.064] [bmv2] [D] [thread 13466] [115.0] [cxt 0] Table 'tbl_add_mri_option': miss [16:34:52.064] [bmv2] [D] [thread 13466] [115.0] [cxt 0] Action entry is ingress.add_mri_option - [16:34:52.064] [bmv2] [T] [thread 13466] [115.0] [cxt 0] Action ingress.add_mri_option [16:34:52.064] [bmv2] [T] [thread 13466] [115.0] [cxt 0] mri-implementation.p4(188) Primitive hdr.ipv4_option.setValid() [16:34:52.064] [bmv2] [T] [thread 13466] [115.0] [cxt 0] mri-implementation.p4(189) Primitive hdr.ipv4_option.copyFlag = 1 [16:34:52.064] [bmv2] [T] [thread 13466] [115.0] [cxt 0] mri-implementation.p4(190) Primitive hdr.ipv4_option.optClass = 2 [16:34:52.064] [bmv2] [T] [thread 13466] [115.0] [cxt 0] mri-implementation.p4(7) Primitive 31; ... [16:34:52.064] [bmv2] [T] [thread 13466] [115.0] [cxt 0] mri-implementation.p4(192) Primitive hdr.ipv4_option.optionLength = 4 [16:34:52.064] [bmv2] [T] [thread 13466] [115.0] [cxt 0] mri-implementation.p4(193) Primitive hdr.mri.setValid() [16:34:52.064] [bmv2] [T] [thread 13466] [115.0] [cxt 0] mri-implementation.p4(194) Primitive hdr.mri.count = 0 [16:34:52.064] [bmv2] [T] [thread 13466] [115.0] [cxt 0] mri-implementation.p4(195) Primitive hdr.ipv4.ihl = hdr.ipv4.ihl + 1 [16:34:52.064] [bmv2] [T] [thread 13466] [115.0] [cxt 0] Applying table 'ingress.swid' [16:34:52.064] [bmv2] [D] [thread 13466] [115.0] [cxt 0] Looking up key:

[16:34:52.064] [bmv2] [D] [thread 13466] [115.0] [cxt 0] Table 'ingress.swid': miss [16:34:52.064] [bmv2] [D] [thread 13466] [115.0] [cxt 0] Action entry is ingress.add_swid - 1, [16:34:52.064] [bmv2] [T] [thread 13466] [115.0] [cxt 0] Action ingress.add_swidœ [16:34:52.064] [bmv2] [T] [thread 13466] [115.0] [cxt 0] mri-implementation.p4(212) Primitive hdr.mri.count = hdr.mri.count + 1 [16:34:52.064] [bmv2] [T] [thread 13466] [115.0] [cxt 0] mri-implementation.p4(213) Primitive hdr.swids.push_front(1) [16:34:52.064] [bmv2] [T] [thread 13466] [115.0] [cxt 0] mri-implementation.p4(214) Primitive hdr.swids[0].swid = id [16:34:52.064] [bmv2] [T] [thread 13466] [115.0] [cxt 0] mri-implementation.p4(215) Primitive hdr.ipv4.ihl = hdr.ipv4.ihl + 1 [16:34:52.064] [bmv2] [T] [thread 13466] [115.0] [cxt 0] mri-implementation.p4(216) Primitive hdr.ipv4_option.optionLength = hdr.ipv4_option.optionLength + 4 [16:34:52.064] [bmv2] [D] [thread 13466] [115.0] [cxt 0] Pipeline 'ingress': end [16:34:52.064] [bmv2] [D] [thread 13466] [115.0] [cxt 0] Egress port is 2 [16:34:52.064] [bmv2] [D] [thread 13469] [115.0] [cxt 0] Pipeline 'egress': start [16:34:52.064] [bmv2] [D] [thread 13469] [115.0] [cxt 0] Pipeline 'egress': end [16:34:52.064] [bmv2] [D] [thread 13469] [115.0] [cxt 0] Deparser 'deparser': start [16:34:52.064] [bmv2] [D] [thread 13469] [115.0] [cxt 0] Deparsing header 'ethernet' [16:34:52.064] [bmv2] [D] [thread 13469] [115.0] [cxt 0] Deparsing header 'ipv4' [16:34:52.064] [bmv2] [D] [thread 13469] [115.0] [cxt 0] Deparsing header 'ipv4_option' [16:34:52.064] [bmv2] [D] [thread 13469] [115.0] [cxt 0] Deparsing header 'mri' #### ---> ???? Missing deparsing of swids here!!!! [16:34:52.064] [bmv2] [D] [thread 13469] [115.0] [cxt 0] Deparser 'deparser': end [16:34:52.064] [bmv2] [D] [thread 13471] [115.0] [cxt 0] Transmitting packet of size 56 out of port 2

s2.log

[16:34:52.064] [bmv2] [D] [thread 13479] [106.0] [cxt 0] Processing packet received on port 2 [16:34:52.064] [bmv2] [D] [thread 13479] [106.0] [cxt 0] Parser 'parser': start [16:34:52.064] [bmv2] [D] [thread 13479] [106.0] [cxt 0] Parser 'parser' entering state 'start' [16:34:52.064] [bmv2] [D] [thread 13479] [106.0] [cxt 0] Extracting header 'ethernet' [16:34:52.064] [bmv2] [D] [thread 13479] [106.0] [cxt 0] Parser state 'start': key is 0800 [16:34:52.064] [bmv2] [T] [thread 13479] [106.0] [cxt 0] Bytes parsed: 14 [16:34:52.065] [bmv2] [D] [thread 13479] [106.0] [cxt 0] Parser 'parser' entering state 'parse_ipv4' [16:34:52.065] [bmv2] [D] [thread 13479] [106.0] [cxt 0] Extracting header 'ipv4' [16:34:52.065] [bmv2] [D] [thread 13479] [106.0] [cxt 0] Parser set: setting field 'scalars.tmp' from expression, new value is 1 [16:34:52.065] [bmv2] [D] [thread 13479] [106.0] [cxt 0] Parser state 'parse_ipv4': key is 07 [16:34:52.065] [bmv2] [T] [thread 13479] [106.0] [cxt 0] Bytes parsed: 34 [16:34:52.065] [bmv2] [D] [thread 13479] [106.0] [cxt 0] Parser 'parser' entering state 'parse_ipv4_option' [16:34:52.065] [bmv2] [D] [thread 13479] [106.0] [cxt 0] Extracting header 'ipv4_option' [16:34:52.065] [bmv2] [D] [thread 13479] [106.0] [cxt 0] Parser state 'parse_ipv4_option': key is 1f [16:34:52.065] [bmv2] [T] [thread 13479] [106.0] [cxt 0] Bytes parsed: 36 [16:34:52.065] [bmv2] [D] [thread 13479] [106.0] [cxt 0] Parser 'parser' entering state 'parse_mri' [16:34:52.065] [bmv2] [D] [thread 13479] [106.0] [cxt 0] Extracting header 'mri' [16:34:52.065] [bmv2] [D] [thread 13479] [106.0] [cxt 0] Parser set: setting field 'userMetadata.parser_metadata.remaining' from field 'mri.count' (1) [16:34:52.065] [bmv2] [D] [thread 13479] [106.0] [cxt 0] Parser state 'parse_mri': key is 0001 [16:34:52.065] [bmv2] [T] [thread 13479] [106.0] [cxt 0] Bytes parsed: 38 [16:34:52.065] [bmv2] [D] [thread 13479] [106.0] [cxt 0] Parser 'parser' entering state 'parse_swid' [16:34:52.065] [bmv2] [D] [thread 13479] [106.0] [cxt 0] Extracting to header stack 0, next header is 6 [16:34:52.065] [bmv2] [D] [thread 13479] [106.0] [cxt 0] Parser set: setting field 'userMetadata.parser_metadata.remaining' from expression, new value is 0 [16:34:52.065] [bmv2] [D] [thread 13479] [106.0] [cxt 0] Parser state 'parse_swid': key is 0000 [16:34:52.065] [bmv2] [T] [thread 13479] [106.0] [cxt 0] Bytes parsed: 42 [16:34:52.065] [bmv2] [D] [thread 13479] [106.0] [cxt 0] Parser 'parser': end [16:34:52.065] [bmv2] [D] [thread 13479] [106.0] [cxt 0] Pipeline 'ingress': start [16:34:52.065] [bmv2] [T] [thread 13479] [106.0] [cxt 0] mri-implementation.p4(260) Condition "hdr.ipv4.isValid()" (node_2) is true [16:34:52.065] [bmv2] [T] [thread 13479] [106.0] [cxt 0] Applying table 'ingress.ipv4_lpm' [16:34:52.065] [bmv2] [D] [thread 13479] [106.0] [cxt 0] Looking up key:

  • hdr.ipv4.dstAddr : 0a00020a

[16:34:52.065] [bmv2] [D] [thread 13479] [106.0] [cxt 0] Table 'ingress.ipv4_lpm': hit with handle 0 [16:34:52.065] [bmv2] [D] [thread 13479] [106.0] [cxt 0] Dumping entry 0 Match key:

  • hdr.ipv4.dstAddr : LPM 0a00020a/32 Action entry: ingress.ipv4_forward - aa00020002,1,

[16:34:52.065] [bmv2] [D] [thread 13479] [106.0] [cxt 0] Action entry is ingress.ipv4_forward - aa00020002,1, [16:34:52.065] [bmv2] [T] [thread 13479] [106.0] [cxt 0] Action ingress.ipv4_forward [16:34:52.065] [bmv2] [T] [thread 13479] [106.0] [cxt 0] mri-implementation.p4(229) Primitive standard_metadata.egress_spec = port [16:34:52.065] [bmv2] [T] [thread 13479] [106.0] [cxt 0] mri-implementation.p4(230) Primitive hdr.ethernet.srcAddr = hdr.ethernet.dstAddr [16:34:52.065] [bmv2] [T] [thread 13479] [106.0] [cxt 0] mri-implementation.p4(231) Primitive hdr.ethernet.dstAddr = dstAddr [16:34:52.065] [bmv2] [T] [thread 13479] [106.0] [cxt 0] mri-implementation.p4(232) Primitive hdr.ipv4.ttl = hdr.ipv4.ttl - 1 [16:34:52.065] [bmv2] [T] [thread 13479] [106.0] [cxt 0] mri-implementation.p4(262) Condition "!hdr.mri.isValid()" (node_4) is false [16:34:52.065] [bmv2] [T] [thread 13479] [106.0] [cxt 0] Applying table 'ingress.swid' [16:34:52.065] [bmv2] [D] [thread 13479] [106.0] [cxt 0] Looking up key:

[16:34:52.065] [bmv2] [D] [thread 13479] [106.0] [cxt 0] Table 'ingress.swid': miss [16:34:52.065] [bmv2] [D] [thread 13479] [106.0] [cxt 0] Action entry is ingress.add_swid - 2, [16:34:52.065] [bmv2] [T] [thread 13479] [106.0] [cxt 0] Action ingress.add_swid [16:34:52.065] [bmv2] [T] [thread 13479] [106.0] [cxt 0] mri-implementation.p4(212) Primitive hdr.mri.count = hdr.mri.count + 1 [16:34:52.065] [bmv2] [T] [thread 13479] [106.0] [cxt 0] mri-implementation.p4(213) Primitive hdr.swids.push_front(1) [16:34:52.065] [bmv2] [T] [thread 13479] [106.0] [cxt 0] mri-implementation.p4(214) Primitive hdr.swids[0].swid = id [16:34:52.065] [bmv2] [T] [thread 13479] [106.0] [cxt 0] mri-implementation.p4(215) Primitive hdr.ipv4.ihl = hdr.ipv4.ihl + 1 [16:34:52.065] [bmv2] [T] [thread 13479] [106.0] [cxt 0] mri-implementation.p4(216) Primitive hdr.ipv4_option.optionLength = hdr.ipv4_option.optionLength + 4 [16:34:52.065] [bmv2] [D] [thread 13479] [106.0] [cxt 0] Pipeline 'ingress': end [16:34:52.065] [bmv2] [D] [thread 13479] [106.0] [cxt 0] Egress port is 1 [16:34:52.065] [bmv2] [D] [thread 13481] [106.0] [cxt 0] Pipeline 'egress': start [16:34:52.065] [bmv2] [D] [thread 13481] [106.0] [cxt 0] Pipeline 'egress': end [16:34:52.065] [bmv2] [D] [thread 13481] [106.0] [cxt 0] Deparser 'deparser': start [16:34:52.065] [bmv2] [D] [thread 13481] [106.0] [cxt 0] Deparsing header 'ethernet' [16:34:52.065] [bmv2] [D] [thread 13481] [106.0] [cxt 0] Deparsing header 'ipv4' [16:34:52.065] [bmv2] [D] [thread 13481] [106.0] [cxt 0] Deparsing header 'ipv4_option' [16:34:52.065] [bmv2] [D] [thread 13481] [106.0] [cxt 0] Deparsing header 'mri' #### [16:34:52.065] [bmv2] [D] [thread 13481] [106.0] [cxt 0] Deparsing header 'swids[1]' [16:34:52.065] [bmv2] [D] [thread 13481] [106.0] [cxt 0] Deparser 'deparser': end [16:34:52.065] [bmv2] [D] [thread 13484] [106.0] [cxt 0] Transmitting packet of size 56 out of port 1

So I suspect a problem with deparsing on s1 because of the step in bold ... Anyone was confronted to the same problem before ? Or Someone has an idea ?

Thanks in advance!

— You are receiving this because you are subscribed to this thread. Reply to this email directly, view it on GitHub https://github.com/p4lang/tutorials/issues/132, or mute the thread https://github.com/notifications/unsubscribe-auth/ABwi0hMlyHDpxK4cyutTUZeVVmEvcHSbks5tojdhgaJpZM4TVKTc .

jafingerhut commented 6 years ago

The latest version of the tutorial P4D2_2018_East had the same code with a wrong assumption about the P4_16 behavior of push_front(), and Antonin's commit fixed that version as well as the older ones, in case someone tries running the older demo code with the latest behavioral-model.