Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

nonsense response latency - equal to unix timestamp #222

Closed
pspacek opened this issue Feb 1, 2023 · 2 comments · Fixed by #223 · May be fixed by #220
Closed

nonsense response latency - equal to unix timestamp #222

pspacek opened this issue Feb 1, 2023 · 2 comments · Fixed by #223 · May be fixed by #220

Comments

@pspacek
Copy link
Contributor

pspacek commented Feb 1, 2023

Sometimes the reported latency is equal to the current unix timestamp.

I've confirmed in GDB that recvd[i].sent time is set to 0 while packet is being processed in do_recv() inner loop. Dunno how is that possible.

Commit: 432b47f - i.e. before merging support for periodic stats and latency histograms, but with the recent errno fixes.

Log:

$ src/dnsperf -Q 5 -d /tmp/qlist -s 192.168.0.1 -l 10 -S1  -O suppress=unexpected,timeout -l5 -t0.1 -S1
DNS Performance Testing Tool
Version 2.10.0

[Status] Command line: dnsperf -Q 5 -d /tmp/qlist -s 192.168.0.1 -l 10 -S1 -O suppress=unexpected,timeout -l5 -t0.1 -S1
[Status] Sending queries (to 192.168.0.1:53)
[Status] Started at: Wed Feb  1 11:21:45 2023
[Status] Stopping after 5.000000 seconds
1675246906.520453: 4.993758
1675246907.521559: 4.994476
1675246908.522734: 4.994132
1675246909.523736: 4.994995
[Status] Testing complete (time limit)

Statistics:

  Queries sent:         25
  Queries completed:    25 (100.00%)
  Queries lost:         1 (4.00%)

  Response codes:       NOERROR 25 (100.00%)
  Average packet size:  request 17, response 92
  Run time (s):         5.000322
  Queries per second:   4.999678

  Average Latency (s):  67009876.346007 (min 0.014435, max 1675246908.065011)
  Latency StdDev (s):   -nan

PCAP with the session: dns.pcap.zip
@pspacek
Copy link
Contributor Author

pspacek commented Feb 1, 2023

Digging deeper:

  • 2.10.0 from master branch sometimes ends up in infinite loop, so I'm not able to confirm if it was affected or not.
  • 2.10.0 + cherry-pick 84c8e72 (negative outstanding fix) already exhibits the problem

@pspacek
Copy link
Contributor Author

pspacek commented Feb 1, 2023

LOL. Accidentally the fix is part of #220 .

This happens only with -O suppress=unexpected. The error was introduced in 8e9f4a2 by me 🤦‍♂️

@pspacek pspacek mentioned this issue Feb 1, 2023
Open
jelu added a commit to jelu/dnsperf that referenced this issue Feb 1, 2023
@jelu
Suppress unexpected
fb81481 
- `dnsperf`: Fix DNS-OARC#222: don't process unexpected message if the message is suppressed
@jelu jelu mentioned this issue Feb 1, 2023
Merged
@jelu jelu closed this as completed in #223 Feb 1, 2023
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

Successfully merging a pull request may close this issue.

Suppress unexpected jelu/dnsperf
Add stats for unexpected message ID occurences pspacek/dnsperf
1 participant
@pspacek