Hangs at `Analyzing collected trace output to …`

[paulmenzel]

Today, asn hung at analyzing collected trace output.

$ git log --oneline --no-decorate -1
23b2d39 Minor tweaks

────────────────────────────────────────────────────────────
            WARNING 

No IPQualityScore token found, so disabling in-depth threat 
analysis and IP reputation lookups. Please visit 
https://github.com/nitefood/asn#ip-reputation-api-token 
for instructions on how to enable it. 
────────────────────────────────────────────────────────────

╭─────────────────────────────────╮
│ ASN lookup for www.tu-berlin.de │
╰─────────────────────────────────╯

- Resolving "www.tu-berlin.de"... 1 IP address found:

 130.149.7.201 ┌PTR www.tu-berlin.de
               ├ASN 680 (DFN Verein zur Foerderung eines Deutschen Forschungsnetzes e.V., DE)
               ├ORG DFN
               ├NET 130.149.0.0/16 (TUB)
               ├ABU abuse@ripe.net
               ├ROA ✓ UNKNOWN (no ROAs found)
               ├GEO Berlin, Berlin (DE)
               └REP ✓ NONE

╭───────────────────────────╮
│ Trace to www.tu-berlin.de │
╰───────────────────────────╯

 Hop IP Address                                                                               Loss%      Ping avg     AS Information                  
  1. 10.31.96.1                                                                                  0%        2.7 ms    BOGON  rfc1918 (Private Space)   
  2. 10.31.251.254                                                                               0%        2.5 ms    BOGON  rfc1918 (Private Space)   
  3. 141.42.5.254                                                                                0%        2.7 ms   [AS680] DFN Verein zur Foerderung eines Deutschen Forschungsnetzes e.V., DE
  4. rouxwin-tg-3.charite.de (193.175.73.2)                                                      0%       15.2 ms   [AS680] DFN Verein zur Foerderung eines Deutschen Forschungsnetzes e.V., DE
  5. roubrain-tg-3.charite.de (193.175.73.3)                                                     0%        3.4 ms   [AS680] DFN Verein zur Foerderung eines Deutschen Forschungsnetzes e.V., DE
Analyzing collected trace output to 130.149.7.201 (press CTRL-C to cancel)...^C                                                                       
Interrupted

I had to cancel it with Ctrl + c.

$ mtr -s 10 -r -c 10 www.tu-berlin.de
Start: 2022-03-29T09:29:06+0200
HOST: ersatz                      Loss%   Snt   Last   Avg  Best  Wrst StDev
  1.|-- _gateway                   0.0%    10   62.4   8.3   1.8  62.4  19.0
  2.|-- 10.31.251.254              0.0%    10    2.0   2.0   1.8   3.2   0.4
  3.|-- 141.42.5.254               0.0%    10    2.6   2.5   2.1   3.5   0.4
  4.|-- rouxwin-tg-3.charite.de    0.0%    10    2.6   3.0   2.6   3.5   0.3
  5.|-- roubrain-tg-3.charite.de   0.0%    10    3.3   3.1   2.6   3.6   0.3
  6.|-- 192.86.163.97              0.0%    10    3.2   3.1   2.5   3.5   0.3
  7.|-- ???                       100.0    10    0.0   0.0   0.0   0.0   0.0
  8.|-- ???                       100.0    10    0.0   0.0   0.0   0.0   0.0
  9.|-- 130.149.126.189            0.0%    10    3.5   3.7   3.0   6.2   0.9
 10.|-- e-ns-e-n.gate.tu-berlin.d  0.0%    10    4.1   7.2   3.5  33.2   9.2
 11.|-- www.tu-berlin.de           0.0%    10    2.8   3.3   2.8   3.9   0.3
$ traceroute www.tu-berlin.de
traceroute to www.tu-berlin.de (130.149.7.201), 30 hops max, 60 byte packets
 1  _gateway (10.31.96.1)  1.886 ms  2.162 ms  2.556 ms
 2  10.31.251.254 (10.31.251.254)  2.802 ms  3.195 ms  3.180 ms
 3  rouxwin-tg-3.charite.de (193.175.73.2)  5.365 ms  4.705 ms  4.262 ms
 4  roubrain-tg-3.charite.de (193.175.73.3)  5.319 ms  5.305 ms  4.924 ms
 5  192.86.163.97 (192.86.163.97)  5.276 ms  5.669 ms  5.655 ms
 6  * * *
 7  * * *
 8  130.149.126.189 (130.149.126.189)  5.170 ms  5.466 ms  6.123 ms
 9  e-ns-e-n.gate.tu-berlin.de (130.149.126.78)  6.109 ms  6.094 ms  6.080 ms
10  www.tu-berlin.de (130.149.7.201)  6.395 ms  7.051 ms  6.366 ms

[nitefood]

Please try updating to the latest commit, and can you confirm it happens repeatedly on the same target? If it doesn't repeat, it might have been a momentarily slow/frozen reply from one of the sources queried during the trace (e.g. asname lookup for that hop IP's origin AS). Does it happen all the time, and for every target, or just this one? Any patterns that might help identifying when the slowdown happens would be useful.

[paulmenzel]

I think it only happens from the Charité network, where I was connected over Eduroam.

Is there a verbose mode, so it shows exactly what is currently queried?

[nitefood]

I added the -v option in c95d75e to display curl targets and variables being assigned. Please try using that when launching your trace and let me know if it helps pinpointing the slowdown.

[paulmenzel]

Sorry for the late response. I tried to reproduce the issue, but wasn’t able to. I am going to remember the verbose switch, should it happen again.