Cellular Network Infrastructure » Core Network (CN) » OsmoGGSN (former OpenGGSN)

It took me a while to reproduce because i was using only 1 MS. For some reason until I didn't register a 2nd MS (while 1st one was downloading a big file), I didn't start seeing the queue dump every few seconds.

So to given a better example, one first sees for instance this state:

20190527125321073 DGGSN <0002> /home/pespin/dev/sysmocom/git/osmo-ggsn/ggsn/ggsn.c:852 PDP(901700000015254:6): Packet received on APN(internet): forwarding to tun tun4
20190527125321106 DTUN <0001> /home/pespin/dev/sysmocom/git/osmo-ggsn/ggsn/ggsn.c:818 Received packet for APN(internet) from tun tun4
Begin queue_seqget seq = 26654
End queue_seqget. Not found
queue_newmsg 26654
Begin queue_seqset seq = 26654
SIZEOF PEER 8, *PEER 16
End queue_seqset
Queue: 0x7fffe9ac7800 Next: 31 First: 0 Last: 30
# State seq next prev timeout retrans
0 1 26624 1 -1 1558952675 0
1 1 26625 2 0 1558952853 0
2 1 26626 3 1 1558952858 0
3 1 26627 4 2 1558953034 0
4 1 26628 5 3 1558953037 0
5 1 26629 6 4 1558953207 0
6 1 26630 7 5 1558953268 0
7 1 26631 8 6 1558953537 0
8 1 26632 9 7 1558953579 0
9 1 26633 10 8 1558953662 0
10 1 26634 11 9 1558953784 0
11 1 26635 12 10 1558953969 0
12 1 26636 13 11 1558953971 0
13 1 26637 14 12 1558954371 0
14 1 26638 15 13 1558954373 0
15 1 26639 16 14 1558954377 0
16 1 26640 17 15 1558954380 0
17 1 26641 18 16 1558954383 0
18 1 26642 19 17 1558954389 0
19 1 26643 20 18 1558954395 0
20 1 26644 21 19 1558954401 0
21 1 26645 22 20 1558954407 0
22 1 26646 23 21 1558954413 0
23 1 26647 24 22 1558954419 0
24 1 26648 25 23 1558954425 0
25 1 26649 26 24 1558954431 0
26 1 26650 27 25 1558954437 0
27 1 26651 28 26 1558954443 0
28 1 26652 29 27 1558954449 0
29 1 26653 30 28 1558954455 0
30 1 26654 -1 29 0 0
31 0 0 0 0 0 0
32 0 0 0 0 0 0
33 0 0 0 0 0 0
34 0 0 0 0 0 0

Then, a few seconds later:

Begin queue_seqget seq = 26677
End queue_seqget. Not found
queue_newmsg 26677
Begin queue_seqset seq = 26677
SIZEOF PEER 8, *PEER 16
End queue_seqset
Queue: 0x7fffe9ac7800 Next: 54 First: 0 Last: 53
# State seq next prev timeout retrans
0 1 26624 1 -1 1558952675 0
1 1 26625 2 0 1558952853 0
2 1 26626 3 1 1558952858 0
3 1 26627 4 2 1558953034 0
4 1 26628 5 3 1558953037 0
5 1 26629 6 4 1558953207 0
6 1 26630 7 5 1558953268 0
7 1 26631 8 6 1558953537 0
8 1 26632 9 7 1558953579 0
9 1 26633 10 8 1558953662 0
10 1 26634 11 9 1558953784 0
11 1 26635 12 10 1558953969 0
12 1 26636 13 11 1558953971 0
13 1 26637 14 12 1558954371 0
14 1 26638 15 13 1558954373 0
15 1 26639 16 14 1558954377 0
16 1 26640 17 15 1558954380 0
17 1 26641 18 16 1558954383 0
18 1 26642 19 17 1558954389 0
19 1 26643 20 18 1558954395 0
20 1 26644 21 19 1558954401 0
21 1 26645 22 20 1558954407 0
22 1 26646 23 21 1558954413 0
23 1 26647 24 22 1558954419 0
24 1 26648 25 23 1558954425 0
25 1 26649 26 24 1558954431 0
26 1 26650 27 25 1558954437 0
27 1 26651 28 26 1558954443 0
28 1 26652 29 27 1558954449 0
29 1 26653 30 28 1558954455 0
30 1 26654 31 29 1558954461 0
31 1 26655 32 30 1558954471 0
32 1 26656 33 31 1558954473 0
33 1 26657 34 32 1558954479 0
34 1 26658 35 33 1558954485 0
35 1 26659 36 34 1558954491 0
36 1 26660 37 35 1558954497 0
37 1 26661 38 36 1558954503 0
38 1 26662 39 37 1558954509 0
39 1 26663 40 38 1558954515 0
40 1 26664 41 39 1558954521 0
41 1 26665 42 40 1558954527 0
42 1 26666 43 41 1558954533 0
43 1 26667 44 42 1558954539 0
44 1 26668 45 43 1558954545 0
45 1 26669 46 44 1558954551 0
46 1 26670 47 45 1558954557 0
47 1 26671 48 46 1558954563 0
48 1 26672 49 47 1558954569 0
49 1 26673 50 48 1558954575 0
50 1 26674 51 49 1558954581 0
51 1 26675 52 50 1558954587 0
52 1 26676 53 51 1558954593 0
53 1 26677 -1 52 0 0
54 0 0 0 0 0 0
55 0 0 0 0 0 0

So it can be seen that the amount of used packets in the queue increses over time (every few seconds).

From seq numbers seen in log and matching with wireshark output, that filling of the list is triggered by osmo-sgsn sending an Echo Request and osmo-ggsn answering with an Echo Response.
I now need to look into why the list increases when that happens.

Osmo-ggsn is receiving the request and inserting the echo response in gsn->queue_resp through gtp_dublicate()->queue_seqget()).

retrans are handled and freed through gtp_retrans() called upon trigger of ggsn->gtp_timer. But that timer was never started during startup, so it will never trigger.

Following patch fixes the issue, as can be seen in sample output below:
https://gerrit.osmocom.org/#/c/osmo-ggsn/+/14201 ggsn: Start gtp retrans timer during startup

Begin queue_seqget seq = 28725
End queue_seqget. Not found
queue_newmsg 28725
Begin queue_seqset seq = 28725
SIZEOF PEER 8, *PEER 16
End queue_seqset
Queue: 0x7fffe9ac7800 Next: 54 First: 43 Last: 53
# State seq next prev timeout retrans
0 0 0 0 0 0 0
1 0 0 0 0 0 0
2 0 0 0 0 0 0
3 0 0 0 0 0 0
4 0 0 0 0 0 0
5 0 0 0 0 0 0
6 0 0 0 0 0 0
7 0 0 0 0 0 0
8 0 0 0 0 0 0
9 0 0 0 0 0 0
10 0 0 0 0 0 0
11 0 0 0 0 0 0
12 0 0 0 0 0 0
13 0 0 0 0 0 0
14 0 0 0 0 0 0
15 0 0 0 0 0 0
16 0 0 0 0 0 0
17 0 0 0 0 0 0
18 0 0 0 0 0 0
19 0 0 0 0 0 0
20 0 0 0 0 0 0
21 0 0 0 0 0 0
22 0 0 0 0 0 0
23 0 0 0 0 0 0
24 0 0 0 0 0 0
25 0 0 0 0 0 0
26 0 0 0 0 0 0
27 0 0 0 0 0 0
28 0 0 0 0 0 0
29 0 0 0 0 0 0
30 0 0 0 0 0 0
31 0 0 0 0 0 0
32 0 0 0 0 0 0
33 0 0 0 0 0 0
34 0 0 0 0 0 0
35 0 0 0 0 0 0
36 0 0 0 0 0 0
37 0 0 0 0 0 0
38 0 0 0 0 0 0
39 0 0 0 0 0 0
40 0 0 0 0 0 0
41 0 0 0 0 0 0
42 0 0 0 0 0 0
43 1 28715 44 -1 1558969344 0
44 1 28716 45 43 1558969350 0
45 1 28717 46 44 1558969356 0
46 1 28718 47 45 1558969362 0
47 1 28719 48 46 1558969368 0
48 1 28720 49 47 1558969374 0
49 1 28721 50 48 1558969380 0
50 1 28722 51 49 1558969386 0
51 1 28723 52 50 1558969392 0
52 1 28724 53 51 1558969398 0
53 1 28725 -1 52 0 0
54 0 0 0 0 0 0
55 0 0 0 0 0 0
56 0 0 0 0 0 0

This patch should also improve a bit the amount of packets in the resp queue in some specific scenarios:
https://gerrit.osmocom.org/#/c/osmo-ggsn/+/14211 gtp: Take queue_resp into account to schedule retrans timer

Submitted one test to verify retrans queue_resp in osmo-ggsn:

https://gerrit.osmocom.org/#/c/osmo-ttcn3-hacks/+/14240 ggsn: Add test to verify retransmit queue_resp

Submitted similar patch to test retransmit queues in osmo-sgsn:
https://gerrit.osmocom.org/#/c/osmo-ttcn3-hacks/+/14262 sgsn: Add tests to check GTP retransmit queue

Once merged we can close the ticket.

Merged, closing.