behavioral-model icon indicating copy to clipboard operation
behavioral-model copied to clipboard

Metadada(deq_timedelta, ingress_global_timestamp, egress_global_timestamp) are always ZERO.

Open leandrocalmeida opened this issue 4 years ago • 6 comments

Hello everyone,

I am doing some tests to evaluate INT in P4. I am extending the MRI code available in tutorials.

Part...

    hdr.swtraces[0].enq_qdepth = (enq_qdepth_t)standard_metadata.enq_qdepth;
    hdr.swtraces[0].deq_qdepth = (deq_qdepth_t)standard_metadata.deq_qdepth;
    hdr.swtraces[0].enq_timestamp = (enq_timestamp_t)standard_metadata.enq_timestamp;
    hdr.swtraces[0].deq_timedelta = (deq_timedelta_t)standard_metadata.deq_timedelta;
    hdr.swtraces[0].ingress_global_timestamp = (ingress_global_timestamp_t)standard_metadata.ingress_global_timestamp;
    hdr.swtraces[0].egress_global_timestamp = (egress_global_timestamp_t)standard_metadata.egress_global_timestamp;

I am generating traffic with IPERF to initiate congestion on the device., but when I run, the numbers of these metadata (deq_timedelta, ingress_global_timestamp, egress_global_timestamp) are always ZERO.

Logs....

  |   |  enq_timestamp= 851116001
  |   |  deq_timedelta= 0
  |   |  ingress_global_timestamp= 0
  |   |  egress_global_timestamp= 0
  |   |  enq_qdepth= 511
  |   |  deq_qdepth= 511

Buffer.p4i.zip

leandrocalmeida avatar Aug 26 '20 14:08 leandrocalmeida

I am not able to reproduce. I changed your program a bit to call the log_msg extern and log the values of these fields, and the values looked correct (non-zero).

If you are not using the latest version of the p4c compiler, I encourage you to upgrade it. Similar issues were reported in the past so I believe this may have been broken with some earlier p4c versions, including the one included in the tutorials VM. If you are already using the latest p4c version, please share the bmv2 JSON file generated by the compiler.

antoninbas avatar Aug 26 '20 19:08 antoninbas

[12:07:51.104] [bmv2] [T] [thread 23672] [0.0] [cxt 0] Action MyEgress.add_swtrace
[12:07:51.104] [bmv2] [T] [thread 23672] [0.0] [cxt 0] Buffer.p4(217) Primitive hdr.mri.count = hdr.mri.count + 1
[12:07:51.104] [bmv2] [T] [thread 23672] [0.0] [cxt 0] Buffer.p4(218) Primitive hdr.swtraces.push_front(1)
[12:07:51.104] [bmv2] [T] [thread 23672] [0.0] [cxt 0] Buffer.p4(219) Primitive hdr.swtraces[0].setValid()
[12:07:51.104] [bmv2] [T] [thread 23672] [0.0] [cxt 0] Buffer.p4(220) Primitive hdr.swtraces[0].swid = swid; ...
[12:07:51.104] [bmv2] [T] [thread 23672] [0.0] [cxt 0] Buffer.p4(221) Primitive hdr.swtraces[0].enq_qdepth = (enq_qdepth_t)standard_metadata.enq_qdepth
[12:07:51.104] [bmv2] [T] [thread 23672] [0.0] [cxt 0] Buffer.p4(222) Primitive hdr.swtraces[0].deq_qdepth = (deq_qdepth_t)standard_metadata.deq_qdepth
[12:07:51.104] [bmv2] [T] [thread 23672] [0.0] [cxt 0] Buffer.p4(223) Primitive hdr.swtraces[0].enq_timestamp = (enq_timestamp_t)standard_metadata.enq_timestamp
[12:07:51.104] [bmv2] [T] [thread 23672] [0.0] [cxt 0] Buffer.p4(224) Primitive hdr.swtraces[0].deq_timedelta = (deq_timedelta_t)standard_metadata.deq_timedelta
[12:07:51.104] [bmv2] [T] [thread 23672] [0.0] [cxt 0] Buffer.p4(225) Primitive hdr.swtraces[0].ingress_global_timestamp = (ingress_global_timestamp_t)standard_metadata.ingress_global_timestamp
[12:07:51.104] [bmv2] [T] [thread 23672] [0.0] [cxt 0] Buffer.p4(226) Primitive hdr.swtraces[0].egress_global_timestamp = (egress_global_timestamp_t)standard_metadata.egress_global_timestamp
[12:07:51.104] [bmv2] [T] [thread 23672] [0.0] [cxt 0] Buffer.p4(228) Primitive hdr.ipv4.ihl = hdr.ipv4.ihl + 4
[12:07:51.104] [bmv2] [T] [thread 23672] [0.0] [cxt 0] Buffer.p4(229) Primitive hdr.ipv4_option.optionLength = hdr.ipv4_option.optionLength + 16
[12:07:51.104] [bmv2] [T] [thread 23672] [0.0] [cxt 0] Buffer.p4(230) Primitive hdr.ipv4.totalLen = hdr.ipv4.totalLen + 16
[12:07:51.104] [bmv2] [T] [thread 23672] [0.0] [cxt 0] Applying table 'tbl_Buffer248'
[12:07:51.104] [bmv2] [D] [thread 23672] [0.0] [cxt 0] Looking up key:

[12:07:51.104] [bmv2] [D] [thread 23672] [0.0] [cxt 0] Table 'tbl_Buffer248': miss
[12:07:51.104] [bmv2] [D] [thread 23672] [0.0] [cxt 0] Action entry is Buffer248 - 
[12:07:51.104] [bmv2] [T] [thread 23672] [0.0] [cxt 0] Action Buffer248
[12:07:51.104] [bmv2] [T] [thread 23672] [0.0] [cxt 0] Buffer.p4(248) Primitive             log_msg(\"v1={} v2={}\", {standard_metadata.ingress_global_timestamp, standard_metadata.deq_timedelta});
[12:07:51.104] [bmv2] [I] [thread 23672] v1=4040107 v2=34
[12:07:51.104] [bmv2] [T] [thread 23672] [0.0] [cxt 0] Buffer.p4(249) Primitive             log_msg(\"v1={} v2={}\", {hdr.swtraces[0].ingress_global_timestamp, hdr.swtraces[0].deq_timedelta});
[12:07:51.104] [bmv2] [I] [thread 23672] v1=4040107 v2=34
[12:07:51.104] [bmv2] [D] [thread 23672] [0.0] [cxt 0] Pipeline 'egress': end

antoninbas avatar Aug 26 '20 19:08 antoninbas

I am not able to reproduce. I changed your program a bit to call the log_msg extern and log the values of these fields, and the values looked correct (non-zero).

If you are not using the latest version of the p4c compiler, I encourage you to upgrade it. Similar issues were reported in the past so I believe this may have been broken with some earlier p4c versions, including the one included in the tutorials VM. If you are already using the latest p4c version, please share the bmv2 JSON file generated by the compiler.

I update the p4c compiler and the problem continue. I attached the bmv2 JSON file. Buffer.json.zip

leandrocalmeida avatar Aug 27 '20 23:08 leandrocalmeida

I used log_msg and had a similar result...

[16:48:04.174] [bmv2] [T] [thread 55057] [9.0] [cxt 0] Buffer.p4(245) Primitive log_msg("standard_metadata.enq_timestamp = {}", {standard_metadata.enq_timestamp}); [16:48:04.174] [bmv2] [I] [thread 55057] standard_metadata.enq_timestamp = 26916443 [16:48:04.174] [bmv2] [T] [thread 55057] [9.0] [cxt 0] Buffer.p4(246) Primitive log_msg("standard_metadata.deq_timedelta = {}", {standard_metadata.deq_timedelta}); [16:48:04.174] [bmv2] [I] [thread 55057] standard_metadata.deq_timedelta = 8383 [16:48:04.174] [bmv2] [T] [thread 55057] [9.0] [cxt 0] Buffer.p4(247) Primitive log_msg("standard_metadata.ingress_global_timestamp = {}", {standard_metadata.ingress_global_timestamp}); [16:48:04.174] [bmv2] [I] [thread 55057] standard_metadata.ingress_global_timestamp = 26914425 [16:48:04.174] [bmv2] [T] [thread 55057] [9.0] [cxt 0] Buffer.p4(248) Primitive log_msg("standard_metadata.egress_global_timestamp = {}", {standard_metadata.egress_global_timestamp}); [16:48:04.174] [bmv2] [I] [thread 55057] standard_metadata.egress_global_timestamp = 26924821 [16:48:04.174] [bmv2] [T] [thread 55057] [9.0] [cxt 0] Buffer.p4(250) Condition "hdr.mri.isValid()" (node_7) is true [16:48:04.174] [bmv2] [T] [thread 55057] [9.0] [cxt 0] Applying table 'MyEgress.swtrace' [16:48:04.174] [bmv2] [D] [thread 55057] [9.0] [cxt 0] Looking up key:

leandrocalmeida avatar Aug 28 '20 16:08 leandrocalmeida

Since the metadata values are correct based on these outputs, did you capture the packets on egress to check if the values are populated in the packet correctly? Any chance this is a bug in the receiver code?

antoninbas avatar Aug 31 '20 19:08 antoninbas

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

github-actions[bot] avatar Sep 01 '22 00:09 github-actions[bot]