Toon posts:

[C] TCP Sequence brengt CPU naar 100%

Pagina: 1
Acties:

Vraag

dinsdag 14 juli 2020 17:49

Acties:
  • 0 Henk 'm!
  • CurlyMo
  • Registratie: Februari 2011
  • Laatst online: 22:57

CurlyMo

Topicstarter
Ik heb in mijn software een MQTT broker gemaakt die in de meeste gevallen prima werkt. Van één gebruiker krijg ik echter de klacht dat na een X aantal uur het programma vastloopt en de CPU richting de 100% gaat. Nu heb ik de mogelijkheid gehad om een tcpdump te doen van specifiek de MQTT poort. Deze dump heb ik ingeladen in wireshark waarna een duidelijk patroon zichtbaar werd.

Afbeeldingslocatie: https://tweakers.net/i/Kn63HpeTBRFw8vDmExydl1j02CE=/full-fit-in/4920x3264/filters:max_bytes(3145728):no_upscale():strip_icc():fill(white):strip_exif()/f/image/bYRq397G8HM6OfOmU6QDpwnV.jpg?f=user_large

Er zijn verschillende clients actief die vrijwel allemaal tegen het eind van de capture hetzelfde patroon laten zien:

code:
1
2
3
4
5
6
7
8

[FIN, ACK]
[SYN]
----
[TCP Retransmission]
[TCP Retransmission]
[TCP Retransmission]
[TCP Retransmission]
---- repeat


Ofwel

code:
1
2
3
4
5
6
7

[FIN, ACK]
[SYN]
----
[TCP Retransmission]
[RST, ACK]
[SYN]
---- repeat


De output van lsof is als volgt:
pilight-d 3284 root   11u     IPv4      25026      0t0   TCP *:5555 (LISTEN)
pilight-d 3284 root   12u     IPv4      25027      0t0   TCP localhost:48862->localhost:5555 (ESTABLISHED)
pilight-d 3284 root   13u     IPv4      24186      0t0   TCP localhost:5555->localhost:48862 (ESTABLISHED)
pilight-d 3284 root   14u     IPv4      22413      0t0   TCP *:1883 (LISTEN)
pilight-d 3284 root   15u     IPv4      22414      0t0   TCP localhost:49200->localhost:1883 (ESTABLISHED)
pilight-d 3284 root   16u      REG       0,15     4096 18584 /sys/devices/platform/soc/3f200000.gpio/gpiochip0/gpio/gpio18/value
pilight-d 3284 root   17u     IPv4      22415      0t0   TCP localhost:49202->localhost:1883 (ESTABLISHED)
pilight-d 3284 root   18u     IPv4      17245      0t0   TCP localhost:48870->localhost:5555 (ESTABLISHED)
pilight-d 3284 root   19u     IPv4      22416      0t0   TCP *:56662 (LISTEN)
pilight-d 3284 root   20u     IPv4      22417      0t0   TCP *:54321 (LISTEN)
pilight-d 3284 root   21u     IPv4      22418      0t0   TCP localhost:49204->localhost:1883 (ESTABLISHED)
pilight-d 3284 root   22u     IPv4      22419      0t0   TCP localhost:1883->localhost:49200 (ESTABLISHED)
pilight-d 3284 root   23u     IPv4      24187      0t0   TCP localhost:5555->localhost:48870 (ESTABLISHED)
pilight-d 3284 root   24u     IPv4      22420      0t0   TCP 192.168.1.18:1883->RASPI4:57951 (CLOSE_WAIT)
pilight-d 3284 root   25u     IPv4      22422      0t0   TCP localhost:1883->localhost:49204 (ESTABLISHED)
pilight-d 3284 root   26u     IPv4      22423      0t0   TCP localhost:1883->localhost:49202 (ESTABLISHED)
pilight-d 3284 root   27u     IPv4      22427      0t0   TCP 192.168.1.18:1883->192.168.1.9:52456 (CLOSE_WAIT)
pilight-d 3284 root   28u     IPv4      17246      0t0   TCP 192.168.1.18:1883->RASPI3:41633 (CLOSE_WAIT)
pilight-d 3284 root   29u     IPv4      17247      0t0   TCP 192.168.1.18:1883->192.168.1.179:1174 (CLOSE_WAIT)
pilight-d 3284 root   30u     IPv4      17272      0t0   TCP 192.168.1.18:1883->RASPI1:51033 (CLOSE_WAIT)
pilight-d 3284 root   31u     IPv4      17273      0t0   TCP 192.168.1.18:1883->RASPI4:33404 (CLOSE_WAIT)
pilight-d 3284 root   32u     IPv4      24234      0t0   TCP 192.168.1.18:1883->RASPI4:59147 (CLOSE_WAIT)
pilight-d 3284 root   33u     IPv4      24235      0t0   TCP 192.168.1.18:1883->RASPI4:38467 (CLOSE_WAIT)


En de output van strace is een eindeloze stroom van:
epoll_ctl(3, EPOLL_CTL_MOD, 21, {EPOLLIN|EPOLLOUT, {u32=21, u64=21}}) = 0
epoll_ctl(3, EPOLL_CTL_MOD, 21, {EPOLLIN|EPOLLOUT, {u32=21, u64=21}}) = 0
epoll_ctl(3, EPOLL_CTL_MOD, 21, {EPOLLIN|EPOLLOUT, {u32=21, u64=21}}) = 0
epoll_ctl(3, EPOLL_CTL_MOD, 21, {EPOLLIN|EPOLLOUT, {u32=21, u64=21}}) = 0
epoll_ctl(3, EPOLL_CTL_MOD, 21, {EPOLLIN|EPOLLOUT, {u32=21, u64=21}}) = 0
epoll_ctl(3, EPOLL_CTL_MOD, 21, {EPOLLIN|EPOLLOUT, {u32=21, u64=21}}) = 0
epoll_ctl(3, EPOLL_CTL_MOD, 21, {EPOLLIN|EPOLLOUT, {u32=21, u64=21}}) = 0
epoll_ctl(3, EPOLL_CTL_MOD, 21, {EPOLLIN|EPOLLOUT, {u32=21, u64=21}}) = 0
epoll_ctl(3, EPOLL_CTL_MOD, 21, {EPOLLIN|EPOLLOUT, {u32=21, u64=21}}) = 0
epoll_ctl(3, EPOLL_CTL_MOD, 21, {EPOLLIN|EPOLLOUT, {u32=21, u64=21}}) = 0
epoll_ctl(3, EPOLL_CTL_MOD, 21, {EPOLLIN|EPOLLOUT, {u32=21, u64=21}}) = 0
epoll_ctl(3, EPOLL_CTL_MOD, 21, {EPOLLIN|EPOLLOUT, {u32=21, u64=21}}) = 0
epoll_ctl(3, EPOLL_CTL_MOD, 21, {EPOLLIN|EPOLLOUT, {u32=21, u64=21}}) = 0
epoll_ctl(3, EPOLL_CTL_MOD, 21, {EPOLLIN|EPOLLOUT, {u32=21, u64=21}}) = 0
epoll_ctl(3, EPOLL_CTL_MOD, 21, {EPOLLIN|EPOLLOUT, {u32=21, u64=21}}) = 0
epoll_ctl(3, EPOLL_CTL_MOD, 21, {EPOLLIN|EPOLLOUT, {u32=21, u64=21}}) = 0
epoll_ctl(3, EPOLL_CTL_MOD, 21, {EPOLLIN|EPOLLOUT, {u32=21, u64=21}}) = 0
epoll_ctl(3, EPOLL_CTL_MOD, 21, {EPOLLIN|EPOLLOUT, {u32=21, u64=21}}) = 0
epoll_ctl(3, EPOLL_CTL_MOD, 21, {EPOLLIN|EPOLLOUT, {u32=21, u64=21}}) = 0
epoll_ctl(3, EPOLL_CTL_MOD, 21, {EPOLLIN|EPOLLOUT, {u32=21, u64=21}}) = 0
epoll_ctl(3, EPOLL_CTL_MOD, 21, {EPOLLIN|EPOLLOUT, {u32=21, u64=21}}) = 0
epoll_ctl(3, EPOLL_CTL_MOD, 21, {EPOLLIN|EPOLLOUT, {u32=21, u64=21}}) = 0


Dat er dus iets mis gaat met een socket verbinding is me duidelijk, maar wat? Dat mijn server de verbindingen met de clients niet goed afsluit? Dat de client de verbroken verbinding vanuit de server niet respecteren? Dat het de clients niet lukt om opnieuw verbinding te maken.

Ik ben al een tijdje met betreffende gebruiker deze bug aan het debuggen, maar ik kom er maar niet uit.

Sinds de 2 dagen regel reageer ik hier niet meer

Alle reacties

woensdag 15 juli 2020 21:20

Acties:
  • 0 Henk 'm!
  • Matis
  • Registratie: Januari 2007
  • Laatst online: 21:46

Matis

Rubber Rocket

Even voor de zekerheid: In jouw TCP dump, ga ik ervan uit dat .9 de client is en .18 de server?
Is het dan niet vreemd dat de client de connectie sluit er dan toch nog data op de lijn komt?

Zou het kunnen dat de file descriptors niet goed komen te staan en zodoende een poll/reaf op de socket altijd (ten onrechte) data teruggeeft?
Je zou ook kunnen kijken of de TCP transactie IDs toevallig niet op de verkeerde stream terecht komen. Dus dat verkeer voor .8 ineens per ongeluk naar .9 gaat of vice versa. Dan snap ik dat de TCP stack aan de andere kant van de lijn over de zeik gaat en telkens een retransmission vraagt. Of natuurlijk precies andersom, dat jij ineens verkeer van .9 interpreteert als .8 al lijkt me dat onwaarschijnlijk omdat dat in de kernel al geregeld wordt.

Wel een leuke bug overigens. Heb bij mijn vorige werkgever ook heel veel TCP cliënt/server sockets in C geschreven.

[ Voor 7% gewijzigd door Matis op 15-07-2020 21:21 ]

If money talks then I'm a mime
If time is money then I'm out of time

woensdag 15 juli 2020 21:30

Acties:
  • 0 Henk 'm!
  • CurlyMo
  • Registratie: Februari 2011
  • Laatst online: 22:57

CurlyMo

Topicstarter
Matis schreef op woensdag 15 juli 2020 @ 21:20:
Even voor de zekerheid: In jouw TCP dump, ga ik ervan uit dat .9 de client is en .18 de server?
Is het dan niet vreemd dat de client de connectie sluit er dan toch nog data op de lijn komt?
Klopt. Dat er nog communicatie is vind ik inderdaad ook vreemd.

Hier een stukje uit tcpdump zelf:
5224-12:19:47.991188 IP 192.168.1.15.41633 > 192.168.1.18.1883: Flags [P.], seq 115776:115817, ack 289, win 229, options [nop,nop,TS val 827794673 ecr 1939549925], length 41
5225-12:19:47.991216 IP 192.168.1.18.1883 > 192.168.1.15.41633: Flags [.], ack 115817, win 229, options [nop,nop,TS val 1939554932 ecr 827794673], length 0
5226-12:19:52.998031 IP 192.168.1.15.41633 > 192.168.1.18.1883: Flags [P.], seq 115817:115858, ack 289, win 229, options [nop,nop,TS val 827795173 ecr 1939554932], length 41
5227-12:19:52.998056 IP 192.168.1.18.1883 > 192.168.1.15.41633: Flags [.], ack 115858, win 229, options [nop,nop,TS val 1939559939 ecr 827795173], length 0
5228-12:19:58.004937 IP 192.168.1.15.41633 > 192.168.1.18.1883: Flags [P.], seq 115858:115899, ack 289, win 229, options [nop,nop,TS val 827795674 ecr 1939559939], length 41
5229-12:19:58.004968 IP 192.168.1.18.1883 > 192.168.1.15.41633: Flags [.], ack 115899, win 229, options [nop,nop,TS val 1939564946 ecr 827795674], length 0
5230-12:19:59.085404 IP 192.168.1.15.41633 > 192.168.1.18.1883: Flags [P.], seq 115899:115940, ack 289, win 229, options [nop,nop,TS val 827795782 ecr 1939564946], length 41
5231-12:19:59.085440 IP 192.168.1.18.1883 > 192.168.1.15.41633: Flags [.], ack 115940, win 229, options [nop,nop,TS val 1939566027 ecr 827795782], length 0
5232-12:19:59.170399 IP 192.168.1.15.41633 > 192.168.1.18.1883: Flags [P.], seq 115940:116050, ack 289, win 229, options [nop,nop,TS val 827795790 ecr 1939566027], length 110
5233-12:19:59.170416 IP 192.168.1.18.1883 > 192.168.1.15.41633: Flags [.], ack 116050, win 229, options [nop,nop,TS val 1939566112 ecr 827795790], length 0
5234:12:20:03.177942 IP 192.168.1.15.41633 > 192.168.1.18.1883: Flags [F.], seq 116050, ack 289, win 229, options [nop,nop,TS val 827796191 ecr 1939566112], length 0
5235-12:20:03.223786 IP 192.168.1.18.1883 > 192.168.1.15.41633: Flags [.], ack 116051, win 229, options [nop,nop,TS val 1939570165 ecr 827796191], length 0
5236-12:20:04.181524 IP 192.168.1.15.44777 > 192.168.1.18.1883: Flags [S], seq 3691131083, win 29200, options [mss 1460,sackOK,TS val 827796292 ecr 0,nop,wscale 7], length 0
5237-12:20:05.260710 IP 192.168.1.15.44777 > 192.168.1.18.1883: Flags [S], seq 3691131083, win 29200, options [mss 1460,sackOK,TS val 827796400 ecr 0,nop,wscale 7], length 0

De client stuurt een FIN, de server een ACK, maar daarna blijven er SYN packages van de client naar de server gestuurd worden.
Zou het kunnen dat de file descriptors niet goed komen te staan en zodoende een poll/read op de socket altijd (ten onrechte) data teruggeeft?
Zou kunnen, maar ik heb tot nu toe niet de aanleiding dat te veronderstellen.
Je zou ook kunnen kijken of de TCP transactie IDs toevallig niet op de verkeerde stream terecht komen.
Hoe check ik dat?
Wel een leuke bug overigens. Heb bij mijn vorige werkgever ook heel veel TCP cliënt/server sockets in C geschreven.
Wat je leuk noemt. Ik breek mijn hoofd er al weken tot maanden over.



Heeft mijn vorige rots in de branding nog een idee: @.oisyn, maar ik denk ook zeker aan een @farlane ?

Sinds de 2 dagen regel reageer ik hier niet meer

woensdag 15 juli 2020 21:41

Acties:
  • 0 Henk 'm!
  • Matis
  • Registratie: Januari 2007
  • Laatst online: 21:46

Matis

Rubber Rocket

Omdat ineens alle clients hetzelfde gedrag vertonen, moet de oorzaak bijna wel in de server liggen. En dat betekent hoogstwaarschijnlijk dat er ergens met de file descriptors iets fout gaat.

Je zou kunnen kijken of de Sequence number of de Ack number van de ene stream in de andere terecht komen. Maar dan zit je al zo dicht op de hardware, dat het daarin bijna niet fout kán gaan.

Ik ben momenteel op vakantie en doe dit alles vanaf m'n telefoon, dus m'n antwoorden zijn niet van zo'n kwalitatieve aard als dat ik graag zou willen.

Ik denk dat je je moet focussen op meerdere TCP verbindingen tegelijkertijd dan je blind te staren op die ene TCP socket.

If money talks then I'm a mime
If time is money then I'm out of time

woensdag 15 juli 2020 22:00

Acties:
  • +1 Henk 'm!
  • Ghehe
  • Registratie: April 2011
  • Laatst online: 12-09 15:58

Ghehe

400 pound hacker

CurlyMo schreef op dinsdag 14 juli 2020 @ 17:49:
Dat mijn server de verbindingen met de clients niet goed afsluit?
Dit lijkt me sowieso het geval. De server zelf moet ook een FIN terugsturen en dat zie ik niet in je tcpdump/wireshark. Daarom dat je CLOSE_WAIT hebt in je lsof.
Matis schreef op woensdag 15 juli 2020 @ 21:20:
Is het dan niet vreemd dat de client de connectie sluit er dan toch nog data op de lijn komt?
Waar zie je dit? Ik zie gewoon een client disconnecten en daarna een nieuwe TCP connectie opzetten waarop niet gereageerd wordt langs de server kant waardoor je retransmissions en nieuwe pogingen ziet elke 10 seocnden?

woensdag 15 juli 2020 22:54

Acties:
  • 0 Henk 'm!
  • CurlyMo
  • Registratie: Februari 2011
  • Laatst online: 22:57

CurlyMo

Topicstarter
Ghehe schreef op woensdag 15 juli 2020 @ 22:00:
[...]


Dit lijkt me sowieso het geval. De server zelf moet ook een FIN terugsturen en dat zie ik niet in je tcpdump/wireshark. Daarom dat je CLOSE_WAIT hebt in je lsof.
Mijn epoll_wait krijgt vervolgens de vraag of ik naar de socket kan schrijven. Kan het dan voorkomen dat epoll_wait dat eindeloos blijft accorderen, omdat door de gesloten socket dit nooit zal daadwerkelijk kan lukken? Dat dat is wat de 100% CPU veroorzaakt?

Sinds de 2 dagen regel reageer ik hier niet meer

donderdag 16 juli 2020 01:53

Acties:
  • 0 Henk 'm!
  • DataGhost
  • Registratie: Augustus 2003
  • Laatst online: 14:20

DataGhost

iPL dev

Je moet zelf altijd de state van je sockets checken natuurlijk, en zorgen dat je je buffers ook altijd leegleest. Als je 100% cpu hebt kan dat best door een fout met je sockets komen waardoor 'ie altijd direct iets returnt (error of fds).

donderdag 16 juli 2020 07:41

Acties:
  • 0 Henk 'm!
  • Matis
  • Registratie: Januari 2007
  • Laatst online: 21:46

Matis

Rubber Rocket

DataGhost schreef op donderdag 16 juli 2020 @ 01:53:
Je moet zelf altijd de state van je sockets checken natuurlijk, en zorgen dat je je buffers ook altijd leegleest. Als je 100% cpu hebt kan dat best door een fout met je sockets komen waardoor 'ie altijd direct iets returnt (error of fds).
Klopt, dat is waar ik op doelde. Thuis heb ik legio voorbeelden hoe je daarop kunt checken.

Tevens zitten er ook nog een aantal extra "mitsen en maren" checks bij qua race conditions.

If money talks then I'm a mime
If time is money then I'm out of time

donderdag 16 juli 2020 08:00

Acties:
  • 0 Henk 'm!
  • Matis
  • Registratie: Januari 2007
  • Laatst online: 21:46

Matis

Rubber Rocket

Ghehe schreef op woensdag 15 juli 2020 @ 22:00:
Waar zie je dit? Ik zie gewoon een client disconnecten en daarna een nieuwe TCP connectie opzetten waarop niet gereageerd wordt langs de server kant waardoor je retransmissions en nieuwe pogingen ziet elke 10 seocnden?
Je hebt gelijk.
Omdat hij het over 100% CPU had, ging ik ervan uit dat het ook een grote load op het netwerk veroorzaakte. Ik concentreerde me alleen op de sub-secondes waardoor ik niet opmerkte dat er feitelijk 10 seconde tussen zat. Goed gezien (y)

@CurlyMo ik denk inderdaad dat de POLL op de socket al direct door de eerste FD wordt getriggerd. Daardoor komen de overige connecties in verval omdat ze niet meer afgewerkt worden. Hierdoor loopt hun buffer vol en stokt ook daar de communicatie.

Dat zou wel eens een verklaring kunnen zijn waarom ineens alles fout gaat indien er ééntje rouge gaat.

If money talks then I'm a mime
If time is money then I'm out of time

donderdag 16 juli 2020 09:00

Acties:
  • 0 Henk 'm!
  • CurlyMo
  • Registratie: Februari 2011
  • Laatst online: 22:57

CurlyMo

Topicstarter
DataGhost schreef op donderdag 16 juli 2020 @ 01:53:
Je moet zelf altijd de state van je sockets checken natuurlijk, en zorgen dat je je buffers ook altijd leegleest. Als je 100% cpu hebt kan dat best door een fout met je sockets komen waardoor 'ie altijd direct iets returnt (error of fds).
Dit is wel een no brainer ;) De vraag is wat precies de oorzaak is?
Matis schreef op donderdag 16 juli 2020 @ 08:00:
[...]
Je hebt gelijk.
Omdat hij het over 100% CPU had, ging ik ervan uit dat het ook een grote load op het netwerk veroorzaakte. Ik concentreerde me alleen op de sub-secondes waardoor ik niet opmerkte dat er feitelijk 10 seconde tussen zat. Goed gezien (y)
Was mij ook niet opgevallen.

Wat er dus gebeurt is dat de cliënt de verbinding verbreekt, de server bevestigd dit. Ondertussen schiet de CPU naar 100% waardoor de opvolgende pogingen tot opnieuw verbinden falen. Dat is al heel erg belangrijke info.

Hier nog een paar van die sequenties van een andere cliënt:
19869:12:19:13.309987 IP 192.168.1.179.1174 > 192.168.1.18.1883: Flags [F.], seq 1367998, ack 1734, win 512, length 0
19870-12:19:13.353788 IP 192.168.1.18.1883 > 192.168.1.179.1174: Flags [.], ack 1367999, win 65024, length 0
19871-12:19:23.367797 IP 192.168.1.179.1175 > 192.168.1.18.1883: Flags [S], seq 202864, win 512, options [mss 512], length 0
19872-12:19:23.367864 IP 192.168.1.18.1883 > 192.168.1.179.1175: Flags [S.], seq 129782952, ack 202865, win 29200, options [mss 1460], length 0
19873-12:19:23.378832 IP 192.168.1.179.1175 > 192.168.1.18.1883: Flags [.], ack 1, win 512, length 0
19874-12:19:23.399782 IP 192.168.1.179.1175 > 192.168.1.18.1883: Flags [P.], seq 1:17, ack 1, win 512, length 16
19875-12:19:23.399806 IP 192.168.1.18.1883 > 192.168.1.179.1175: Flags [.], ack 17, win 10720, length 0
19876:12:19:28.384144 IP 192.168.1.179.1175 > 192.168.1.18.1883: Flags [F.], seq 17, ack 1, win 512, length 0
19877-12:19:28.433787 IP 192.168.1.18.1883 > 192.168.1.179.1175: Flags [.], ack 18, win 10720, length 0
19878-12:19:33.358405 IP 192.168.1.179.1176 > 192.168.1.18.1883: Flags [S], seq 203024, win 512, options [mss 512], length 0
19879-12:19:34.357757 IP 192.168.1.179.1176 > 192.168.1.18.1883: Flags [S], seq 203024, win 512, options [mss 512], length 0
19880-12:19:36.105871 IP 192.168.1.179.1176 > 192.168.1.18.1883: Flags [S], seq 203024, win 512, options [mss 512], length 0
19881-12:19:39.352545 IP 192.168.1.179.1176 > 192.168.1.18.1883: Flags [S], seq 203024, win 512, options [mss 512], length 0
19882-12:19:45.596268 IP 192.168.1.179.1176 > 192.168.1.18.1883: Flags [S], seq 203024, win 512, options [mss 512], length 0
19883-12:19:57.834178 IP 192.168.1.179.1176 > 192.168.1.18.1883: Flags [R.], seq 203024, ack 0, win 512, length 0


Het gaat hier nog één keer goed. Een gesloten verbinding en weer opnieuw verbinden. Daarna lukt het inderdaad niet meer.

Het fenomeen van gesloten socket verbindingen vanuit de cliënt had ik dacht ik al verwerkt. Een stukje aanvullende code die ik nu heb toegevoegd is het volgende:
C:
1
2
3

if(recv(fd, buffer, BUFFER_SIZE, MSG_PEEK | MSG_DONTWAIT) == 0) {
   // socket is gesloten vanaf de cliënt zijde
}

Deze wordt gedraaid bij elke lees actie vanuit POLL.

Sinds de 2 dagen regel reageer ik hier niet meer

donderdag 16 juli 2020 09:07

Acties:
  • 0 Henk 'm!
  • Matis
  • Registratie: Januari 2007
  • Laatst online: 21:46

Matis

Rubber Rocket

Zoals eerder aangegeven, zit ik momenteel op m'n telefoon en heb geen mogelijkheid om "mijn" code omtrent het uitlezen van sockets te bekijken.

Maar er moet inderdaad bijgehouden worden welke sockets open en actief zijn, welke gesloten zijn/worden en welke nieuwe verbinding kunnen accepteren.

Deze info moet je dan weer gebruiken bij het pollen van deze sockets, zodat je geen false positives krijgt op gesloten sockets.

Ik ga kijken of ik online wat kan vinden hieromtrent.

Edit: ik ken je code niet, maar ik meen me te herinneren dat deze macro's heel belangrijk zijn: https://www.mkssoftware.com/docs/man3/select.3.asp

[ Voor 13% gewijzigd door Matis op 16-07-2020 09:17 ]

If money talks then I'm a mime
If time is money then I'm out of time

donderdag 16 juli 2020 09:37

Acties:
  • 0 Henk 'm!
  • CurlyMo
  • Registratie: Februari 2011
  • Laatst online: 22:57

CurlyMo

Topicstarter 
# tcpdump -r /tmp/tcpdump.log |  grep -n 'Flags \[F' -C 10
81231-12:19:12.303419 IP 192.168.1.16.38467 > 192.168.1.18.1883: Flags [P.], seq 115696:115737, ack 291, win 229, options [nop,nop,TS val 250761905 ecr 3929061360], length 41
81232-12:19:12.303463 IP 192.168.1.18.1883 > 192.168.1.16.38467: Flags [.], ack 115737, win 229, options [nop,nop,TS val 3929066366 ecr 250761905], length 0
81233-12:19:12.708943 IP 192.168.1.179.1174 > 192.168.1.18.1883: Flags [P.], seq 1367842:1367998, ack 1734, win 512, length 156
81234-12:19:12.708972 IP 192.168.1.18.1883 > 192.168.1.179.1174: Flags [.], ack 1367998, win 65024, length 0
81235-12:19:12.760094 IP 192.168.1.16.59147 > 192.168.1.18.1883: Flags [P.], seq 594406:594474, ack 291, win 229, options [nop,nop,TS val 250761951 ecr 3929065821], length 68
81236-12:19:12.760112 IP 192.168.1.18.1883 > 192.168.1.16.59147: Flags [.], ack 594474, win 229, options [nop,nop,TS val 3929066823 ecr 250761951], length 0
81237-12:19:12.775290 IP 192.168.1.15.41633 > 192.168.1.18.1883: Flags [P.], seq 115338:115379, ack 289, win 229, options [nop,nop,TS val 827791151 ecr 1939514709], length 41
81238-12:19:12.775309 IP 192.168.1.18.1883 > 192.168.1.15.41633: Flags [.], ack 115379, win 229, options [nop,nop,TS val 1939519716 ecr 827791151], length 0
81239-12:19:12.952124 IP 192.168.1.9.52456 > 192.168.1.18.1883: Flags [P.], seq 1301046:1301196, ack 1754, win 1912, length 150
81240-12:19:12.952144 IP 192.168.1.18.1883 > 192.168.1.9.52456: Flags [.], ack 1301196, win 65392, length 0
81241:12:19:13.309987 IP 192.168.1.179.1174 > 192.168.1.18.1883: Flags [F.], seq 1367998, ack 1734, win 512, length 0
81242-12:19:13.353788 IP 192.168.1.18.1883 > 192.168.1.179.1174: Flags [.], ack 1367999, win 65024, length 0
81243-12:19:13.761870 IP 192.168.1.16.59147 > 192.168.1.18.1883: Flags [P.], seq 594474:594542, ack 291, win 229, options [nop,nop,TS val 250762051 ecr 3929066823], length 68
81244-12:19:13.761904 IP 192.168.1.18.1883 > 192.168.1.16.59147: Flags [.], ack 594542, win 229, options [nop,nop,TS val 3929067825 ecr 250762051], length 0
81245-12:19:13.951920 IP 192.168.1.9.52456 > 192.168.1.18.1883: Flags [P.], seq 1301196:1301346, ack 1754, win 1912, length 150
81246-12:19:13.951954 IP 192.168.1.18.1883 > 192.168.1.9.52456: Flags [.], ack 1301346, win 65392, length 0
81247-12:19:14.763603 IP 192.168.1.16.59147 > 192.168.1.18.1883: Flags [P.], seq 594542:594610, ack 291, win 229, options [nop,nop,TS val 250762151 ecr 3929067825], length 68
81248-12:19:14.763642 IP 192.168.1.18.1883 > 192.168.1.16.59147: Flags [.], ack 594610, win 229, options [nop,nop,TS val 3929068826 ecr 250762151], length 0
81249-12:19:14.951947 IP 192.168.1.9.52456 > 192.168.1.18.1883: Flags [P.], seq 1301346:1301496, ack 1754, win 1912, length 150
81250-12:19:14.951979 IP 192.168.1.18.1883 > 192.168.1.9.52456: Flags [.], ack 1301496, win 65392, length 0
81251-12:19:15.615713 IP 192.168.1.13.51033 > 192.168.1.18.1883: Flags [P.], seq 115021:115062, ack 289, win 457, options [nop,nop,TS val 60782510 ecr 3847849617], length 41
--
81255-12:19:15.951950 IP 192.168.1.9.52456 > 192.168.1.18.1883: Flags [P.], seq 1301496:1301646, ack 1754, win 1912, length 150
81256-12:19:15.951980 IP 192.168.1.18.1883 > 192.168.1.9.52456: Flags [.], ack 1301646, win 65392, length 0
81257-12:19:16.748352 IP 192.168.1.16.33404 > 192.168.1.18.1883: Flags [P.], seq 253895:253934, ack 291, win 229, options [nop,nop,TS val 250762350 ecr 3929065805], length 39
81258-12:19:16.748398 IP 192.168.1.18.1883 > 192.168.1.16.33404: Flags [.], ack 253934, win 237, options [nop,nop,TS val 3929070811 ecr 250762350], length 0
81259-12:19:16.748702 IP 192.168.1.16.33404 > 192.168.1.18.1883: Flags [P.], seq 253934:254040, ack 291, win 229, options [nop,nop,TS val 250762350 ecr 3929070811], length 106
81260-12:19:16.748717 IP 192.168.1.18.1883 > 192.168.1.16.33404: Flags [.], ack 254040, win 237, options [nop,nop,TS val 3929070812 ecr 250762350], length 0
81261-12:19:16.767023 IP 192.168.1.16.59147 > 192.168.1.18.1883: Flags [P.], seq 594678:594746, ack 291, win 229, options [nop,nop,TS val 250762351 ecr 3929069828], length 68
81262-12:19:16.767038 IP 192.168.1.18.1883 > 192.168.1.16.59147: Flags [.], ack 594746, win 229, options [nop,nop,TS val 3929070830 ecr 250762351], length 0
81263-12:19:16.951921 IP 192.168.1.9.52456 > 192.168.1.18.1883: Flags [P.], seq 1301646:1301796, ack 1754, win 1912, length 150
81264-12:19:16.951947 IP 192.168.1.18.1883 > 192.168.1.9.52456: Flags [.], ack 1301796, win 65392, length 0
81265:12:19:16.960048 IP 192.168.1.9.52456 > 192.168.1.18.1883: Flags [F.], seq 1301796, ack 1754, win 1912, length 0
81266-12:19:17.003772 IP 192.168.1.18.1883 > 192.168.1.9.52456: Flags [.], ack 1301797, win 65392, length 0
81267-12:19:17.309500 IP 192.168.1.16.38467 > 192.168.1.18.1883: Flags [P.], seq 115737:115778, ack 291, win 229, options [nop,nop,TS val 250762406 ecr 3929066366], length 41
81268-12:19:17.309533 IP 192.168.1.18.1883 > 192.168.1.16.38467: Flags [.], ack 115778, win 229, options [nop,nop,TS val 3929071372 ecr 250762406], length 0
81269-12:19:17.768773 IP 192.168.1.16.59147 > 192.168.1.18.1883: Flags [P.], seq 594746:594814, ack 291, win 229, options [nop,nop,TS val 250762452 ecr 3929070830], length 68
81270-12:19:17.768809 IP 192.168.1.18.1883 > 192.168.1.16.59147: Flags [.], ack 594814, win 229, options [nop,nop,TS val 3929071832 ecr 250762452], length 0
81271-12:19:17.782180 IP 192.168.1.15.41633 > 192.168.1.18.1883: Flags [P.], seq 115379:115420, ack 289, win 229, options [nop,nop,TS val 827791652 ecr 1939519716], length 41
81272-12:19:17.782212 IP 192.168.1.18.1883 > 192.168.1.15.41633: Flags [.], ack 115420, win 229, options [nop,nop,TS val 1939524723 ecr 827791652], length 0
81273-12:19:18.770541 IP 192.168.1.16.59147 > 192.168.1.18.1883: Flags [P.], seq 594814:594882, ack 291, win 229, options [nop,nop,TS val 250762552 ecr 3929071832], length 68
81274-12:19:18.770580 IP 192.168.1.18.1883 > 192.168.1.16.59147: Flags [.], ack 594882, win 229, options [nop,nop,TS val 3929072833 ecr 250762552], length 0
81275-12:19:19.772287 IP 192.168.1.16.59147 > 192.168.1.18.1883: Flags [P.], seq 594882:594950, ack 291, win 229, options [nop,nop,TS val 250762652 ecr 3929072833], length 68
--
81312-12:19:26.761606 IP 192.168.1.16.33404 > 192.168.1.18.1883: Flags [P.], seq 254226:254332, ack 291, win 229, options [nop,nop,TS val 250763351 ecr 3929080824], length 106
81313-12:19:26.761621 IP 192.168.1.18.1883 > 192.168.1.16.33404: Flags [.], ack 254332, win 237, options [nop,nop,TS val 3929080825 ecr 250763351], length 0
81314-12:19:26.783733 IP 192.168.1.16.59147 > 192.168.1.18.1883: Flags [P.], seq 595358:595426, ack 291, win 229, options [nop,nop,TS val 250763353 ecr 3929079845], length 68
81315-12:19:26.783750 IP 192.168.1.18.1883 > 192.168.1.16.59147: Flags [.], ack 595426, win 229, options [nop,nop,TS val 3929080847 ecr 250763353], length 0
81316-12:19:27.321615 IP 192.168.1.16.38467 > 192.168.1.18.1883: Flags [P.], seq 115819:115860, ack 291, win 229, options [nop,nop,TS val 250763407 ecr 3929076379], length 41
81317-12:19:27.321658 IP 192.168.1.18.1883 > 192.168.1.16.38467: Flags [.], ack 115860, win 229, options [nop,nop,TS val 3929081385 ecr 250763407], length 0
81318-12:19:27.785492 IP 192.168.1.16.59147 > 192.168.1.18.1883: Flags [P.], seq 595426:595494, ack 291, win 229, options [nop,nop,TS val 250763453 ecr 3929080847], length 68
81319-12:19:27.785539 IP 192.168.1.18.1883 > 192.168.1.16.59147: Flags [.], ack 595494, win 229, options [nop,nop,TS val 3929081848 ecr 250763453], length 0
81320-12:19:27.795838 IP 192.168.1.15.41633 > 192.168.1.18.1883: Flags [P.], seq 115461:115502, ack 289, win 229, options [nop,nop,TS val 827792653 ecr 1939529730], length 41
81321-12:19:27.795865 IP 192.168.1.18.1883 > 192.168.1.15.41633: Flags [.], ack 115502, win 229, options [nop,nop,TS val 1939534737 ecr 827792653], length 0
81322:12:19:28.384144 IP 192.168.1.179.1175 > 192.168.1.18.1883: Flags [F.], seq 17, ack 1, win 512, length 0
81323-12:19:28.433787 IP 192.168.1.18.1883 > 192.168.1.179.1175: Flags [.], ack 18, win 10720, length 0
81324-12:19:28.787225 IP 192.168.1.16.59147 > 192.168.1.18.1883: Flags [P.], seq 595494:595562, ack 291, win 229, options [nop,nop,TS val 250763553 ecr 3929081848], length 68
81325-12:19:28.787266 IP 192.168.1.18.1883 > 192.168.1.16.59147: Flags [.], ack 595562, win 229, options [nop,nop,TS val 3929082850 ecr 250763553], length 0
81326-12:19:28.879174 IP 192.168.1.15.41633 > 192.168.1.18.1883: Flags [P.], seq 115502:115543, ack 289, win 229, options [nop,nop,TS val 827792761 ecr 1939534737], length 41
81327-12:19:28.879214 IP 192.168.1.18.1883 > 192.168.1.15.41633: Flags [.], ack 115543, win 229, options [nop,nop,TS val 1939535820 ecr 827792761], length 0
81328-12:19:28.959393 IP 192.168.1.9.52459 > 192.168.1.18.1883: Flags [R.], seq 2957602922, ack 0, win 24584, length 0
81329-12:19:28.964800 IP 192.168.1.15.41633 > 192.168.1.18.1883: Flags [P.], seq 115543:115653, ack 289, win 229, options [nop,nop,TS val 827792770 ecr 1939535820], length 110
81330-12:19:28.964819 IP 192.168.1.18.1883 > 192.168.1.15.41633: Flags [.], ack 115653, win 229, options [nop,nop,TS val 1939535906 ecr 827792770], length 0
81331-12:19:29.789014 IP 192.168.1.16.59147 > 192.168.1.18.1883: Flags [P.], seq 595562:595630, ack 291, win 229, options [nop,nop,TS val 250763654 ecr 3929082850], length 68
81332-12:19:29.789059 IP 192.168.1.18.1883 > 192.168.1.16.59147: Flags [.], ack 595630, win 229, options [nop,nop,TS val 3929083852 ecr 250763654], length 0
--
81478-12:19:58.839686 IP 192.168.1.16.59147 > 192.168.1.18.1883: Flags [P.], seq 597536:597604, ack 291, win 229, options [nop,nop,TS val 250766559 ecr 3929111901], length 68
81479-12:19:58.839730 IP 192.168.1.18.1883 > 192.168.1.16.59147: Flags [.], ack 597604, win 229, options [nop,nop,TS val 3929112903 ecr 250766559], length 0
81480-12:19:58.956389 IP 192.168.1.9.52462 > 192.168.1.18.1883: Flags [R.], seq 2969263933, ack 0, win 24584, length 0
81481-12:19:59.085404 IP 192.168.1.15.41633 > 192.168.1.18.1883: Flags [P.], seq 115899:115940, ack 289, win 229, options [nop,nop,TS val 827795782 ecr 1939564946], length 41
81482-12:19:59.085440 IP 192.168.1.18.1883 > 192.168.1.15.41633: Flags [.], ack 115940, win 229, options [nop,nop,TS val 1939566027 ecr 827795782], length 0
81483-12:19:59.170399 IP 192.168.1.15.41633 > 192.168.1.18.1883: Flags [P.], seq 115940:116050, ack 289, win 229, options [nop,nop,TS val 827795790 ecr 1939566027], length 110
81484-12:19:59.170416 IP 192.168.1.18.1883 > 192.168.1.15.41633: Flags [.], ack 116050, win 229, options [nop,nop,TS val 1939566112 ecr 827795790], length 0
81485-12:19:59.332684 IP 192.168.1.179.1177 > 192.168.1.18.1883: Flags [S], seq 203424, win 512, options [mss 512], length 0
81486-12:19:59.841407 IP 192.168.1.16.59147 > 192.168.1.18.1883: Flags [P.], seq 597604:597672, ack 291, win 229, options [nop,nop,TS val 250766659 ecr 3929112903], length 68
81487-12:19:59.841444 IP 192.168.1.18.1883 > 192.168.1.16.59147: Flags [.], ack 597672, win 229, options [nop,nop,TS val 3929113905 ecr 250766659], length 0
81488:12:20:00.444183 IP 192.168.1.16.38467 > 192.168.1.18.1883: Flags [F.], seq 116257, ack 291, win 229, options [nop,nop,TS val 250766719 ecr 3929111504], length 0
81489-12:20:00.493792 IP 192.168.1.18.1883 > 192.168.1.16.38467: Flags [.], ack 116258, win 229, options [nop,nop,TS val 3929114557 ecr 250766719], length 0
81490-12:20:00.843163 IP 192.168.1.16.59147 > 192.168.1.18.1883: Flags [P.], seq 597672:597740, ack 291, win 229, options [nop,nop,TS val 250766759 ecr 3929113905], length 68
81491-12:20:00.843190 IP 192.168.1.18.1883 > 192.168.1.16.59147: Flags [.], ack 597740, win 229, options [nop,nop,TS val 3929114906 ecr 250766759], length 0
81492-12:20:00.904099 IP 192.168.1.13.51033 > 192.168.1.18.1883: Flags [P.], seq 115543:115584, ack 289, win 457, options [nop,nop,TS val 60787039 ecr 3847894910], length 41
81493-12:20:00.904119 IP 192.168.1.18.1883 > 192.168.1.13.51033: Flags [.], ack 115584, win 229, options [nop,nop,TS val 3847899917 ecr 60787039], length 0
81494-12:20:01.080826 IP 192.168.1.179.1177 > 192.168.1.18.1883: Flags [S], seq 203424, win 512, options [mss 512], length 0
81495-12:20:01.445776 IP 192.168.1.16.37336 > 192.168.1.18.1883: Flags [S], seq 2619628093, win 29200, options [mss 1460,sackOK,TS val 250766819 ecr 0,nop,wscale 7], length 0
81496-12:20:01.805713 IP 192.168.1.16.33404 > 192.168.1.18.1883: Flags [P.], seq 255202:255241, ack 291, win 229, options [nop,nop,TS val 250766855 ecr 3929110863], length 39
81497-12:20:01.805755 IP 192.168.1.18.1883 > 192.168.1.16.33404: Flags [.], ack 255241, win 237, options [nop,nop,TS val 3929115869 ecr 250766855], length 0
81498-12:20:01.806087 IP 192.168.1.16.33404 > 192.168.1.18.1883: Flags [P.], seq 255241:255347, ack 291, win 229, options [nop,nop,TS val 250766855 ecr 3929115869], length 106
81499-12:20:01.806101 IP 192.168.1.18.1883 > 192.168.1.16.33404: Flags [.], ack 255347, win 237, options [nop,nop,TS val 3929115869 ecr 250766855], length 0
81500-12:20:01.844850 IP 192.168.1.16.59147 > 192.168.1.18.1883: Flags [P.], seq 597740:597808, ack 291, win 229, options [nop,nop,TS val 250766859 ecr 3929114906], length 68
81501-12:20:01.844874 IP 192.168.1.18.1883 > 192.168.1.16.59147: Flags [.], ack 597808, win 229, options [nop,nop,TS val 3929115908 ecr 250766859], length 0
81502-12:20:02.437600 IP 192.168.1.16.37336 > 192.168.1.18.1883: Flags [S], seq 2619628093, win 29200, options [mss 1460,sackOK,TS val 250766919 ecr 0,nop,wscale 7], length 0
81503-12:20:02.846713 IP 192.168.1.16.59147 > 192.168.1.18.1883: Flags [P.], seq 597808:597876, ack 291, win 229, options [nop,nop,TS val 250766959 ecr 3929115908], length 68
81504-12:20:02.846763 IP 192.168.1.18.1883 > 192.168.1.16.59147: Flags [.], ack 597876, win 229, options [nop,nop,TS val 3929116910 ecr 250766959], length 0
81505:12:20:03.177942 IP 192.168.1.15.41633 > 192.168.1.18.1883: Flags [F.], seq 116050, ack 289, win 229, options [nop,nop,TS val 827796191 ecr 1939566112], length 0
81506-12:20:03.223786 IP 192.168.1.18.1883 > 192.168.1.15.41633: Flags [.], ack 116051, win 229, options [nop,nop,TS val 1939570165 ecr 827796191], length 0
81507-12:20:03.848471 IP 192.168.1.16.59147 > 192.168.1.18.1883: Flags [P.], seq 597876:597944, ack 291, win 229, options [nop,nop,TS val 250767060 ecr 3929116910], length 68
81508-12:20:03.848494 IP 192.168.1.18.1883 > 192.168.1.16.59147: Flags [.], ack 597944, win 229, options [nop,nop,TS val 3929117912 ecr 250767060], length 0
81509-12:20:03.955637 IP 192.168.1.9.52463 > 192.168.1.18.1883: Flags [S], seq 2971596172, win 2144, options [mss 536,nop,nop,sackOK], length 0
81510-12:20:04.181524 IP 192.168.1.15.44777 > 192.168.1.18.1883: Flags [S], seq 3691131083, win 29200, options [mss 1460,sackOK,TS val 827796292 ecr 0,nop,wscale 7], length 0
81511-12:20:04.326452 IP 192.168.1.179.1177 > 192.168.1.18.1883: Flags [S], seq 203424, win 512, options [mss 512], length 0
81512-12:20:04.437566 IP 192.168.1.16.37336 > 192.168.1.18.1883: Flags [S], seq 2619628093, win 29200, options [mss 1460,sackOK,TS val 250767119 ecr 0,nop,wscale 7], length 0
81513-12:20:04.850194 IP 192.168.1.16.59147 > 192.168.1.18.1883: Flags [P.], seq 597944:598012, ack 291, win 229, options [nop,nop,TS val 250767160 ecr 3929117912], length 68
81514-12:20:04.850240 IP 192.168.1.18.1883 > 192.168.1.16.59147: Flags [.], ack 598012, win 229, options [nop,nop,TS val 3929118914 ecr 250767160], length 0
81515-12:20:05.260710 IP 192.168.1.15.44777 > 192.168.1.18.1883: Flags [S], seq 3691131083, win 29200, options [mss 1460,sackOK,TS val 827796400 ecr 0,nop,wscale 7], length 0
--
81591-12:20:22.809107 IP 192.168.1.179.1177 > 192.168.1.18.1883: Flags [R.], seq 203424, ack 2226058263, win 512, length 0
81592-12:20:22.882162 IP 192.168.1.16.59147 > 192.168.1.18.1883: Flags [P.], seq 599168:599236, ack 291, win 229, options [nop,nop,TS val 250768963 ecr 3929135944], length 68
81593-12:20:22.882207 IP 192.168.1.18.1883 > 192.168.1.16.59147: Flags [.], ack 599236, win 229, options [nop,nop,TS val 3929136946 ecr 250768963], length 0
81594-12:20:23.308312 IP 192.168.1.179.skkserv > 192.168.1.18.1883: Flags [S], seq 203824, win 512, options [mss 512], length 0
81595-12:20:23.883918 IP 192.168.1.16.59147 > 192.168.1.18.1883: Flags [P.], seq 599236:599304, ack 291, win 229, options [nop,nop,TS val 250769063 ecr 3929136946], length 68
81596-12:20:23.883961 IP 192.168.1.18.1883 > 192.168.1.16.59147: Flags [.], ack 599304, win 229, options [nop,nop,TS val 3929137947 ecr 250769063], length 0
81597-12:20:23.955983 IP 192.168.1.9.52465 > 192.168.1.18.1883: Flags [S], seq 2976260710, win 2144, options [mss 536,nop,nop,sackOK], length 0
81598-12:20:24.307678 IP 192.168.1.179.skkserv > 192.168.1.18.1883: Flags [S], seq 203824, win 512, options [mss 512], length 0
81599-12:20:24.885665 IP 192.168.1.16.59147 > 192.168.1.18.1883: Flags [P.], seq 599304:599372, ack 291, win 229, options [nop,nop,TS val 250769163 ecr 3929137947], length 68
81600-12:20:24.885712 IP 192.168.1.18.1883 > 192.168.1.16.59147: Flags [.], ack 599372, win 229, options [nop,nop,TS val 3929138949 ecr 250769163], length 0
81601:12:20:25.838547 IP 192.168.1.16.33404 > 192.168.1.18.1883: Flags [F.], seq 255927, ack 291, win 229, options [nop,nop,TS val 250769259 ecr 3929135896], length 0
81602-12:20:25.883796 IP 192.168.1.18.1883 > 192.168.1.16.33404: Flags [.], ack 255928, win 237, options [nop,nop,TS val 3929139947 ecr 250769259], length 0
81603-12:20:25.887396 IP 192.168.1.16.59147 > 192.168.1.18.1883: Flags [P.], seq 599372:599440, ack 291, win 229, options [nop,nop,TS val 250769263 ecr 3929138949], length 68
81604-12:20:25.887422 IP 192.168.1.18.1883 > 192.168.1.16.59147: Flags [.], ack 599440, win 229, options [nop,nop,TS val 3929139951 ecr 250769263], length 0
81605-12:20:26.055843 IP 192.168.1.179.skkserv > 192.168.1.18.1883: Flags [S], seq 203824, win 512, options [mss 512], length 0
81606-12:20:26.152322 IP 192.168.1.13.51033 > 192.168.1.18.1883: Flags [P.], seq 115899:115940, ack 289, win 457, options [nop,nop,TS val 60789564 ecr 3847920158], length 41
81607-12:20:26.152359 IP 192.168.1.18.1883 > 192.168.1.13.51033: Flags [.], ack 115940, win 229, options [nop,nop,TS val 3847925166 ecr 60789564], length 0
81608-12:20:26.647687 IP 192.168.1.9.52465 > 192.168.1.18.1883: Flags [S], seq 2976260710, win 2144, options [mss 536,nop,nop,sackOK], length 0
81609-12:20:26.840839 IP 192.168.1.16.49174 > 192.168.1.18.1883: Flags [S], seq 1019566411, win 29200, options [mss 1460,sackOK,TS val 250769359 ecr 0,nop,wscale 7], length 0
81610-12:20:26.889139 IP 192.168.1.16.59147 > 192.168.1.18.1883: Flags [P.], seq 599440:599508, ack 291, win 229, options [nop,nop,TS val 250769364 ecr 3929139951], length 68
81611-12:20:26.889179 IP 192.168.1.18.1883 > 192.168.1.16.59147: Flags [.], ack 599508, win 229, options [nop,nop,TS val 3929140953 ecr 250769364], length 0
--
81618-12:20:29.301461 IP 192.168.1.179.skkserv > 192.168.1.18.1883: Flags [S], seq 203824, win 512, options [mss 512], length 0
81619-12:20:29.837574 IP 192.168.1.16.49174 > 192.168.1.18.1883: Flags [S], seq 1019566411, win 29200, options [mss 1460,sackOK,TS val 250769659 ecr 0,nop,wscale 7], length 0
81620-12:20:29.894384 IP 192.168.1.16.59147 > 192.168.1.18.1883: Flags [P.], seq 599644:599712, ack 291, win 229, options [nop,nop,TS val 250769664 ecr 3929142956], length 68
81621-12:20:29.894427 IP 192.168.1.18.1883 > 192.168.1.16.59147: Flags [.], ack 599712, win 229, options [nop,nop,TS val 3929143958 ecr 250769664], length 0
81622-12:20:30.896133 IP 192.168.1.16.59147 > 192.168.1.18.1883: Flags [P.], seq 599712:599780, ack 291, win 229, options [nop,nop,TS val 250769764 ecr 3929143958], length 68
81623-12:20:30.896187 IP 192.168.1.18.1883 > 192.168.1.16.59147: Flags [.], ack 599780, win 229, options [nop,nop,TS val 3929144960 ecr 250769764], length 0
81624-12:20:31.160382 IP 192.168.1.13.51033 > 192.168.1.18.1883: Flags [P.], seq 115940:115981, ack 289, win 457, options [nop,nop,TS val 60790065 ecr 3847925166], length 41
81625-12:20:31.160429 IP 192.168.1.18.1883 > 192.168.1.13.51033: Flags [.], ack 115981, win 229, options [nop,nop,TS val 3847930174 ecr 60790065], length 0
81626-12:20:31.897939 IP 192.168.1.16.59147 > 192.168.1.18.1883: Flags [P.], seq 599780:599848, ack 291, win 229, options [nop,nop,TS val 250769865 ecr 3929144960], length 68
81627-12:20:31.897988 IP 192.168.1.18.1883 > 192.168.1.16.59147: Flags [.], ack 599848, win 229, options [nop,nop,TS val 3929145962 ecr 250769865], length 0
81628:12:20:31.898436 IP 192.168.1.16.59147 > 192.168.1.18.1883: Flags [F.], seq 599848, ack 291, win 229, options [nop,nop,TS val 250769865 ecr 3929145962], length 0
81629-12:20:31.943775 IP 192.168.1.18.1883 > 192.168.1.16.59147: Flags [.], ack 599849, win 229, options [nop,nop,TS val 3929146007 ecr 250769865], length 0
81630-12:20:32.527572 IP 192.168.1.16.37336 > 192.168.1.18.1883: Flags [S], seq 2619628093, win 29200, options [mss 1460,sackOK,TS val 250769928 ecr 0,nop,wscale 7], length 0
81631-12:20:32.900754 IP 192.168.1.16.39198 > 192.168.1.18.1883: Flags [S], seq 3544415431, win 29200, options [mss 1460,sackOK,TS val 250769965 ecr 0,nop,wscale 7], length 0
81632-12:20:33.847565 IP 192.168.1.16.49174 > 192.168.1.18.1883: Flags [S], seq 1019566411, win 29200, options [mss 1460,sackOK,TS val 250770060 ecr 0,nop,wscale 7], length 0
81633-12:20:33.897531 IP 192.168.1.16.39198 > 192.168.1.18.1883: Flags [S], seq 3544415431, win 29200, options [mss 1460,sackOK,TS val 250770065 ecr 0,nop,wscale 7], length 0
81634-12:20:33.955643 IP 192.168.1.9.52466 > 192.168.1.18.1883: Flags [S], seq 2978593009, win 2144, options [mss 536,nop,nop,sackOK], length 0
81635-12:20:35.546207 IP 192.168.1.179.skkserv > 192.168.1.18.1883: Flags [S], seq 203824, win 512, options [mss 512], length 0
81636-12:20:35.897593 IP 192.168.1.16.39198 > 192.168.1.18.1883: Flags [S], seq 3544415431, win 29200, options [mss 1460,sackOK,TS val 250770265 ecr 0,nop,wscale 7], length 0
81637-12:20:36.140691 IP 192.168.1.15.44777 > 192.168.1.18.1883: Flags [S], seq 3691131083, win 29200, options [mss 1460,sackOK,TS val 827799488 ecr 0,nop,wscale 7], length 0
81638-12:20:36.175447 IP 192.168.1.13.51033 > 192.168.1.18.1883: Flags [P.], seq 115981:116022, ack 289, win 457, options [nop,nop,TS val 60790566 ecr 3847930174], length 41
81639-12:20:36.175494 IP 192.168.1.18.1883 > 192.168.1.13.51033: Flags [.], ack 116022, win 229, options [nop,nop,TS val 3847935189 ecr 60790566], length 0
81640:12:20:36.266149 IP 192.168.1.13.51033 > 192.168.1.18.1883: Flags [F.], seq 116022, ack 289, win 457, options [nop,nop,TS val 60790576 ecr 3847935189], length 0
81641-12:20:36.313773 IP 192.168.1.18.1883 > 192.168.1.13.51033: Flags [.], ack 116023, win 229, options [nop,nop,TS val 3847935327 ecr 60790576], length 0
81642-12:20:36.719254 IP 192.168.1.9.52466 > 192.168.1.18.1883: Flags [S], seq 2978593009, win 2144, options [mss 536,nop,nop,sackOK], length 0
81643-12:20:37.196218 IP 192.168.1.13.55755 > 192.168.1.18.1883: Flags [S], seq 1560457535, win 29200, options [mss 1460,sackOK,TS val 60790669 ecr 0,nop,wscale 6], length 0
81644-12:20:38.265965 IP 192.168.1.13.55755 > 192.168.1.18.1883: Flags [S], seq 1560457535, win 29200, options [mss 1460,sackOK,TS val 60790776 ecr 0,nop,wscale 6], length 0
81645-12:20:38.956810 IP 192.168.1.9.52466 > 192.168.1.18.1883: Flags [R.], seq 2978593010, ack 0, win 24584, length 0
81646-12:20:39.907572 IP 192.168.1.16.39198 > 192.168.1.18.1883: Flags [S], seq 3544415431, win 29200, options [mss 1460,sackOK,TS val 250770666 ecr 0,nop,wscale 7], length 0
81647-12:20:40.346009 IP 192.168.1.13.55755 > 192.168.1.18.1883: Flags [S], seq 1560457535, win 29200, options [mss 1460,sackOK,TS val 60790984 ecr 0,nop,wscale 6], length 0
81648-12:20:41.867578 IP 192.168.1.16.49174 > 192.168.1.18.1883: Flags [S], seq 1019566411, win 29200, options [mss 1460,sackOK,TS val 250770862 ecr 0,nop,wscale 7], length 0
81649:12:20:42.283306 IP 192.168.1.16.57951 > 192.168.1.18.1883: Flags [F.], seq 922, ack 291, win 229, options [nop,nop,TS val 250770903 ecr 3929127307], length 0
81650-12:20:42.323790 IP 192.168.1.18.1883 > 192.168.1.16.57951: Flags [.], ack 923, win 229, options [nop,nop,TS val 3929156387 ecr 250770903], length 0
81651-12:20:43.285669 IP 192.168.1.16.44062 > 192.168.1.18.1883: Flags [S], seq 3373190377, win 29200, options [mss 1460,sackOK,TS val 250771003 ecr 0,nop,wscale 7], length 0
81652-12:20:43.957357 IP 192.168.1.9.52467 > 192.168.1.18.1883: Flags [S], seq 2980925328, win 2144, options [mss 536,nop,nop,sackOK], length 0
81653-12:20:44.277553 IP 192.168.1.16.44062 > 192.168.1.18.1883: Flags [S], seq 3373190377, win 29200, options [mss 1460,sackOK,TS val 250771103 ecr 0,nop,wscale 7], length 0
81654-12:20:44.426041 IP 192.168.1.13.55755 > 192.168.1.18.1883: Flags [S], seq 1560457535, win 29200, options [mss 1460,sackOK,TS val 60791392 ecr 0,nop,wscale 6], length 0
81655-12:20:46.277584 IP 192.168.1.16.44062 > 192.168.1.18.1883: Flags [S], seq 3373190377, win 29200, options [mss 1460,sackOK,TS val 250771303 ecr 0,nop,wscale 7], length 0
81656-12:20:46.894454 IP 192.168.1.9.52467 > 192.168.1.18.1883: Flags [S], seq 2980925328, win 2144, options [mss 536,nop,nop,sackOK], length 0
81657-12:20:47.784055 IP 192.168.1.179.skkserv > 192.168.1.18.1883: Flags [R.], seq 203824, ack 2226058263, win 512, length 0
81658-12:20:47.927551 IP 192.168.1.16.39198 > 192.168.1.18.1883: Flags [S], seq 3544415431, win 29200, options [mss 1460,sackOK,TS val 250771468 ecr 0,nop,wscale 7], length 0
81659-12:20:48.283231 IP 192.168.1.179.1179 > 192.168.1.18.1883: Flags [S], seq 204224, win 512, options [mss 512], length 0


Hier nog een bevestiging van het vermoedde dat het in gesloten sockets zit. De betreffende gebruiker gaf aan dat het probleem rond 12:18 ontstond. Om 12:19 is de FIN te zien vanuit cliënt 179. Daarna sluiten de overige cliënts de socket en ontstaat de eindeloze SYN stroom.

@Matis Ik weet wat sockets doen en hoe asynchrone sockets werken. Ik heb tientallen prima werkende socket servers geschreven. De huidige server bezorgd me echter meer hoofdpijn dan anders. De specifieke 100% bug heb ik ook niet eerder van andere gebruikers terug gehoord en zelf geen last van, dus heel duidelijk was de bug ook niet.

Bugfixen is eerst weten waar je het moet zoeken. In dat debugging process liep ik vast, omdat ik zelf het probleem niet ervaar en niet kon reproduceren. Nu ik een sterk vermoedde van de oorzaak heb, heb ik ook wel wat ideeën om het op te lossen.

Sinds de 2 dagen regel reageer ik hier niet meer

donderdag 16 juli 2020 09:47

Acties:
  • +1 Henk 'm!
  • farlane
  • Registratie: Maart 2000
  • Laatst online: 16-09 22:43

farlane

Hoe ziet je socket close logic er uit? Onder normale omstandigheden zou je eerst een shutdown doen, receiven totdat je geen data meer krijgt en dan pas je socket closen.

Probeer je sockets te hergebruiken? Gebruik je socket linger opties? Multithreading issues misschien?

Somniferous whisperings of scarlet fields. Sleep calling me and in my dreams i wander. My reality is abandoned (I traverse afar). Not a care if I never everwake.

donderdag 16 juli 2020 10:08

Acties:
  • 0 Henk 'm!
  • CurlyMo
  • Registratie: Februari 2011
  • Laatst online: 22:57

CurlyMo

Topicstarter
farlane schreef op donderdag 16 juli 2020 @ 09:47:
Hoe ziet je socket close logic er uit?
In de basis:
C:
1
2

shutdown(fd, SHUT_RDWR);
close(fd);

Een shutdown met direct daarna een close.
Onder normale omstandigheden zou je eerst een shutdown doen, receiven totdat je geen data meer krijgt en dan pas je socket closen.
Dat is wel nieuw voor me (y)

Ondanks de vraag of dit de juiste manier is om een verbinding te verbreken, zou dit vanuit de server kant toch geen verkeer meer moeten genereren. Oftewel, de server accepteert geen verkeer meer door de shutdown / close ondanks dat de cliënt dat wellicht nog wel wilde sturen? Waardoor het ook geen POLL acties meer zou kunnen triggeren en vervolgens niet tot een 100% zou moeten leiden.

Of is het zo dat bij het hergebruik van de file descriptor door de kernel de oude buffers alsnog eerst leeggemaakt worden, maar die, doordat mijn server dit niet verwacht, ook niet juist worden verwerkt.

Komt nog bij dat op dit moment de socket close door de cliënt worden geïnitieerd. Dat is tenminste wat ik in de logs zie. Dan zou het verkeerd sluiten van de socket vanuit de server kant toch ook niet de 100% CPU moeten kunnen veroorzaken?

[ Voor 10% gewijzigd door CurlyMo op 16-07-2020 10:12 ]

Sinds de 2 dagen regel reageer ik hier niet meer

donderdag 16 juli 2020 11:35

Acties:
  • +1 Henk 'm!
  • Matis
  • Registratie: Januari 2007
  • Laatst online: 21:46

Matis

Rubber Rocket

Je zult/kunt ook controleren op de errno welke de read teruggeeft in het geval van een return value van <= 0 bij het lezen van de socket.

If money talks then I'm a mime
If time is money then I'm out of time

donderdag 16 juli 2020 11:47

Acties:
  • +1 Henk 'm!
  • farlane
  • Registratie: Maart 2000
  • Laatst online: 16-09 22:43

farlane

CurlyMo schreef op donderdag 16 juli 2020 @ 10:08:
[...]
Dat is wel nieuw voor me (y)
Als je aan beide kanten op die manier doet, zorgt dat voor de correcte afbouw van de TCP verbinding, inclusief de laatste FIN/ACK transactie die je nu mist.
Ondanks de vraag of dit de juiste manier is om een verbinding te verbreken, zou dit vanuit de server kant toch geen verkeer meer moeten genereren. Oftewel, de server accepteert geen verkeer meer door de shutdown / close ondanks dat de cliënt dat wellicht nog wel wilde sturen? Waardoor het ook geen POLL acties meer zou kunnen triggeren en vervolgens niet tot een 100% zou moeten leiden.
Die 100% komt waarschijnlijk doordat je ergens een busy wait hebt zitten, (wat een gevolg kan zijn van een wait die wordt overgeslagen in je select/poll door een foutsituatie. Je handelt dus ergens een fout (of mischien signal) niet goed af waardoor die lus ontstaat.

Somniferous whisperings of scarlet fields. Sleep calling me and in my dreams i wander. My reality is abandoned (I traverse afar). Not a care if I never everwake.

donderdag 16 juli 2020 12:00

Acties:
  • 0 Henk 'm!
  • CurlyMo
  • Registratie: Februari 2011
  • Laatst online: 22:57

CurlyMo

Topicstarter
farlane schreef op donderdag 16 juli 2020 @ 11:47:
[...]

Als je aan beide kanten op die manier doet, zorgt dat voor de correcte afbouw van de TCP verbinding, inclusief de laatste FIN/ACK transactie die je nu mist.
Hoe kijk je dan naar mijn aanvulling om een MSG_PEEK op te nemen in mijn lees loop? Als op basis daarvan blijkt dat de client de socket verbinding heeft gesloten, de server de socket ook sluit, dan ben ik er toch ook?
Die 100% komt waarschijnlijk doordat je ergens een busy wait hebt zitten, (wat een gevolg kan zijn van een wait die wordt overgeslagen in je select/poll door een foutsituatie. Je handelt dus ergens een fout (of mischien signal) niet goed af waardoor die lus ontstaat.
Dan is weer de vraag hoe ik die fout ontdek. Dat die er is had ik door. De signalen (100%) zijn duidelijk genoeg :p

[ Voor 4% gewijzigd door CurlyMo op 16-07-2020 12:16 ]

Sinds de 2 dagen regel reageer ik hier niet meer

donderdag 16 juli 2020 12:28

Acties:
  • 0 Henk 'm!
  • Matis
  • Registratie: Januari 2007
  • Laatst online: 21:46

Matis

Rubber Rocket

Wij controleren op de return value van de read op de file descriptor. Is die <= 0 en is de errno ongelijk aan EINTR dan betekent dat de socket gesloten is en wordt deze vanuit de server ook gesloten.
De FD wordt vrijgegeven voor een nieuwe verbinding.

Edit, kleine kanttekening: errno is niet thread safe noch atomic, maar is de meest betrouwbare manier om de herkomst van de (foutieve) return value te herleiden.

[ Voor 24% gewijzigd door Matis op 16-07-2020 12:32 ]

If money talks then I'm a mime
If time is money then I'm out of time

donderdag 16 juli 2020 12:39

Acties:
  • 0 Henk 'm!
  • farlane
  • Registratie: Maart 2000
  • Laatst online: 16-09 22:43

farlane

CurlyMo schreef op donderdag 16 juli 2020 @ 12:00:
[...]
Hoe kijk je dan naar mijn aanvulling om een MSG_PEEK op te nemen in mijn lees loop? Als op basis daarvan blijkt dat de client de socket verbinding heeft gesloten, de server de socket ook sluit, dan ben ik er toch ook?
Volgens mij maakt dat de zaak alleen maar complexer. Als er na de shutdown nog data in het input kanaal zit om te lezen moet je die eerst consumen (vandaar lezen tot recv 0 retouneert) voordat je de socket (netjes) kunt sluiten.
Dan is weer de vraag hoe ik die fout ontdek. Dat die er is had ik door. De signalen (100%) zijn duidelijk genoeg :p
Goed analyseren waar je loops hebt zitten en kijken of je (error) condities niet checked, zoalsde return values/errno na een recv of na een poll(). Pak de manpages van die functies er bij en kijk of je alle situaties goed afvangt.

Als je een remote debugger kunt attachen en de situatie naspelen zou helemaal luxe zijn natuurlijk :)

Somniferous whisperings of scarlet fields. Sleep calling me and in my dreams i wander. My reality is abandoned (I traverse afar). Not a care if I never everwake.

donderdag 16 juli 2020 12:41

Acties:
  • 0 Henk 'm!
  • farlane
  • Registratie: Maart 2000
  • Laatst online: 16-09 22:43

farlane

Matis schreef op donderdag 16 juli 2020 @ 12:28:
Edit, kleine kanttekening: errno is niet thread safe noch atomic, maar is de meest betrouwbare manier om de herkomst van de (foutieve) return value te herleiden.
https://stackoverflow.com...4164/is-errno-thread-safe

Somniferous whisperings of scarlet fields. Sleep calling me and in my dreams i wander. My reality is abandoned (I traverse afar). Not a care if I never everwake.

donderdag 16 juli 2020 12:45

Acties:
  • 0 Henk 'm!
  • Matis
  • Registratie: Januari 2007
  • Laatst online: 21:46

Matis

Rubber Rocket

farlane schreef op donderdag 16 juli 2020 @ 12:41:
https://stackoverflow.com...4164/is-errno-thread-safe
Ah oké, dat wist ik niet. Ik baseerde me op de commentaren in de code. Daarnaast is onze code niet op een posix, maar op een (verouderde) uclibc versie gebaseerd.

Zoals ik al zei, ik ben daar al een aantal jaar weg. Dus mogelijk is het in de loop der tijd veranderd.

If money talks then I'm a mime
If time is money then I'm out of time

donderdag 16 juli 2020 13:20

Acties:
  • 0 Henk 'm!
  • CurlyMo
  • Registratie: Februari 2011
  • Laatst online: 22:57

CurlyMo

Topicstarter
farlane schreef op donderdag 16 juli 2020 @ 12:39:
[...]

Volgens mij maakt dat de zaak alleen maar complexer. Als er na de shutdown nog data in het input kanaal zit om te lezen moet je die eerst consumen (vandaar lezen tot recv 0 retouneert) voordat je de socket (netjes) kunt sluiten.
Je bedoelt zo simpel als?
code:
1
2
3

shutdown(fd, SHUT_RDWR);
while(recv(fd, buffer, BUFFER_SIZE, 0) > 0);
close(fd);

Sinds de 2 dagen regel reageer ik hier niet meer

donderdag 16 juli 2020 14:18

Acties:
  • 0 Henk 'm!
  • Voutloos
  • Registratie: Januari 2002
  • Niet online

Voutloos

Beetje lastig als je het zo simpel mogelijk presenteert, maar je controleeert bij elke system call ook de return value voor foutcondities, right?

{signature}

donderdag 16 juli 2020 15:54

Acties:
  • 0 Henk 'm!
  • farlane
  • Registratie: Maart 2000
  • Laatst online: 16-09 22:43

farlane

CurlyMo schreef op donderdag 16 juli 2020 @ 13:20:
[...]

Je bedoelt zo simpel als?
code:
1
2
3

shutdown(fd, SHUT_RDWR);
while(recv(fd, buffer, BUFFER_SIZE, 0) > 0);
close(fd);
code:
1
2
3

shutdown(fd, SHUT_WR);
while(recv(fd, buffer, BUFFER_SIZE, 0) > 0);
close(fd);

Alleen SHUT_WR dus, maar in principe wel ja.

Overigens kan het natuurlijk altijd voorkomen dat de verbinding niet netjes wordt afgesloten, ook dan moet je server kunnen overleven op de lange termijn.

Zoals @Verwijderd al aangaf lijkt je lsof te vertellen dat de .18 server de close() helemaal niet doet omdat er sockets in CLOSE_WAIT blijven hangen. Bij een close zou de server nog een FIN moeten sturen waarna de client nog een ACK stuurt.

Ik ben trouwens wel benieuwd welke socket options je gebruikt (non-blocking? linger? timeouts?)

Somniferous whisperings of scarlet fields. Sleep calling me and in my dreams i wander. My reality is abandoned (I traverse afar). Not a care if I never everwake.

donderdag 16 juli 2020 16:23

Acties:
  • 0 Henk 'm!
  • CurlyMo
  • Registratie: Februari 2011
  • Laatst online: 22:57

CurlyMo

Topicstarter
farlane schreef op donderdag 16 juli 2020 @ 15:54:
[...]

code:
1
2
3

shutdown(fd, SHUT_WR);
while(recv(fd, buffer, BUFFER_SIZE, 0) > 0);
close(fd);

Alleen SHUT_WR dus, maar in principe wel ja.
Nice, ga ik dat implementeren en kijken of het dan beter gaat.
Overigens kan het natuurlijk altijd voorkomen dat de verbinding niet netjes wordt afgesloten, ook dan moet je server kunnen overleven op de lange termijn.
Snap ik. Ik ga verder zoeken waar het specifiek bij deze server mis gaat.
Zoals @Verwijderd al aangaf lijkt je lsof te vertellen dat de .18 server de close() helemaal niet doet omdat er sockets in CLOSE_WAIT blijven hangen. Bij een close zou de server nog een FIN moeten sturen waarna de client nog een ACK stuurt.
Dat snap ik dus ook niet. Dat betekent dat ondanks dat ik mijn shutdown / close sequentie moet aanpassen, het erop lijkt dat het niet eens tot een shutdown / close komt.
Ik ben trouwens wel benieuwd welke socket options je gebruikt (non-blocking? linger? timeouts?)
Alles is non-blocking en deze server gebruikt geen linger.

Sinds de 2 dagen regel reageer ik hier niet meer

donderdag 16 juli 2020 16:27

Acties:
  • 0 Henk 'm!
  • CurlyMo
  • Registratie: Februari 2011
  • Laatst online: 22:57

CurlyMo

Topicstarter
Voutloos schreef op donderdag 16 juli 2020 @ 14:18:
Beetje lastig als je het zo simpel mogelijk presenteert, maar je controleeert bij elke system call ook de return value voor foutcondities, right?
Als het goed is wel. De kans bestaat echter van niet gezien de bug :p

Het gaat ook bij de andere services wel goed. Het is echt specifiek de MQTT broker die ik geschreven heb die loopt te ouwehoeren.

Even gesimplificeerd. Lezen gebeurt als volgt:
C:
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40

    [...]
    long int fromlen = 0;
    int n = 0, one = 1, zero = 0;
    char buffer[BUFFER_SIZE] = { 0 };

    if(is_udp == 1) {
        n = recv(fd, buffer, BUFFER_SIZE, 0);
        err = errno;
    } else {
        n = recvfrom(fd, buffer, BUFFER_SIZE, 0, NULL, (socklen_t *)&fromlen);
        err = errno;
    }

    if(n > 0) {
        read_cb(req, n, buffer);
    } else if(n < 0 && err != EINTR) {
        switch(err) {
            case ENOTCONN:
                one = 1;
                read_cb(req, &one, NULL);
            break;
            case EAGAIN:
            case EWOULDBLOCK:
                // Herhaal read actie
            break;
            default:
            break;
        }
    /*
     * Cliënt sluit verbinding
     */
    } else if(n == 0) {
        close_cb(req);
    } else {
        if(read_cb != NULL) {
            zero = 0;
            custom_poll_data->read_cb(req, &zero, NULL);
        }
    }
    [...]

[ Voor 47% gewijzigd door CurlyMo op 16-07-2020 16:41 ]

Sinds de 2 dagen regel reageer ik hier niet meer

donderdag 16 juli 2020 17:06

Acties:
  • 0 Henk 'm!
  • Matis
  • Registratie: Januari 2007
  • Laatst online: 21:46

Matis

Rubber Rocket

Volgens mij vergeet je errno op 0 te zetten voordat je een call doet naar de receive.

If money talks then I'm a mime
If time is money then I'm out of time

donderdag 16 juli 2020 17:24

Acties:
  • 0 Henk 'm!
  • farlane
  • Registratie: Maart 2000
  • Laatst online: 16-09 22:43

farlane

CurlyMo schreef op donderdag 16 juli 2020 @ 16:27:
[...]
Even gesimplificeerd. Lezen gebeurt als volgt:
Is dit over-gesimplificeerd? Ik zie je nergens een epoll doen?

Somniferous whisperings of scarlet fields. Sleep calling me and in my dreams i wander. My reality is abandoned (I traverse afar). Not a care if I never everwake.

donderdag 16 juli 2020 18:29

Acties:
  • 0 Henk 'm!
  • CurlyMo
  • Registratie: Februari 2011
  • Laatst online: 22:57

CurlyMo

Topicstarter
farlane schreef op donderdag 16 juli 2020 @ 17:24:
[...]

Is dit over-gesimplificeerd? Ik zie je nergens een epoll doen?
Voor dat deel maak ik gebruik van de libuv library. Die regelt de polling voor me. Ik heb ergens wel vertrouwen dat dat goed gaat, want anders hadden alle NodeJS programma's waarin async i/o wordt gebruikt een probleem :)

Nu kan ik de eerste zijn die een bug heeft gevonden, maar dat verwacht ik niet.

Een mogelijk relevante bug was deze:
C:
1
2
3
4
5
6
7
8
9
10

    if(is_udp == 1) {
        n = recv(fd, buffer, BUFFER_SIZE, 0);
    } else {
        n = recvfrom(fd, buffer, BUFFER_SIZE, 0, NULL, (socklen_t *)&fromlen);
    }

    if(n > 0) {
        // Logica
        read_cb(req, n, buffer);
    } else if(n < 0 && errno != EINTR) {


Op de plek van logica werd een functie gedraaid die op zichzelf weer een pthread_mutex_lock / unlock deed. pthread_mutex_lock beïnvloed op zichzelf weer de errno waardoor mogelijk het sluiten van de socket middels de niet goed werd herkent a.d.v. errno. Dat heb ik nu aangepast door de errno van recvfrom op te slaan in err.

Boeit toch niet, omdat logica alleen werd gedraaid wanneer recv succesvol werd uitgevoerd.

[ Voor 5% gewijzigd door CurlyMo op 16-07-2020 19:31 ]

Sinds de 2 dagen regel reageer ik hier niet meer

donderdag 16 juli 2020 19:07

Acties:
  • 0 Henk 'm!
  • CurlyMo
  • Registratie: Februari 2011
  • Laatst online: 22:57

CurlyMo

Topicstarter
Matis schreef op donderdag 16 juli 2020 @ 17:06:
Volgens mij vergeet je errno op 0 te zetten voordat je een call doet naar de receive.
Dat doet er niet toe. Als er geen fout is dan wordt de errno sowieso op 0 gezet naar mijn weten.

Sinds de 2 dagen regel reageer ik hier niet meer

donderdag 16 juli 2020 19:18

Acties:
  • 0 Henk 'm!
  • Matis
  • Registratie: Januari 2007
  • Laatst online: 21:46

Matis

Rubber Rocket

CurlyMo schreef op donderdag 16 juli 2020 @ 19:07:
Dat doet er niet toe. Als er fout is dan wordt de errno sowieso op 0 gezet naar mijn weten.
Ik denk dat je bedoelt dat errno juist niet naar 0 gezet wordt bij een fout, maar door hem zelf expliciet naar 0 te zetten, weet je zeker dat het de desbetreffende functie is die de errno naar een bepaalde waarde heeft gezet.

Anders bestaat de kans dat de errno nog staat vanuit een eerdere call naar een (mogelijk) compleet andere functie.

If money talks then I'm a mime
If time is money then I'm out of time

donderdag 16 juli 2020 19:20

Acties:
  • 0 Henk 'm!
  • CurlyMo
  • Registratie: Februari 2011
  • Laatst online: 22:57

CurlyMo

Topicstarter
Matis schreef op donderdag 16 juli 2020 @ 19:18:
[...]

Ik denk dat je bedoelt dat errno juist niet naar 0 gezet wordt bij een fout, maar door hem zelf expliciet naar 0 te zetten, weet je zeker dat het de desbetreffende functie is die de errno naar een bepaalde waarde heeft gezet.

Anders bestaat de kans dat de errno nog staat vanuit een eerdere call naar een (mogelijk) compleet andere functie.
Volgens mij zet de functie de errno zelf al naar 0 als er geen fout was. Daarbij check je errno alleen als er in je functie een fout is opgetreden. Zoals bij recv < 0.

Dat deed ik in mijn code echter niet goed.

Nope, kan toch niet de oorzaak zijn geweest. Ik deed het wel goed :(

[ Voor 17% gewijzigd door CurlyMo op 16-07-2020 19:23 ]

Sinds de 2 dagen regel reageer ik hier niet meer

donderdag 16 juli 2020 19:47

Acties:
  • 0 Henk 'm!
  • Matis
  • Registratie: Januari 2007
  • Laatst online: 21:46

Matis

Rubber Rocket

Volgens de manpages is wat jij beweert niet waar:
The value of errno is never set to zero by any system call or library function.
Vandaar mijn best practice om de errno zelf geforceerd naar 0 te zetten (als je zelf daadwerkelijk wat mee wilt doen in de afhandeling).

[ Voor 25% gewijzigd door Matis op 16-07-2020 19:49 ]

If money talks then I'm a mime
If time is money then I'm out of time

donderdag 16 juli 2020 22:09

Acties:
  • +1 Henk 'm!
  • farlane
  • Registratie: Maart 2000
  • Laatst online: 16-09 22:43

farlane

CurlyMo schreef op donderdag 16 juli 2020 @ 18:29:
Voor dat deel maak ik gebruik van de libuv library. Die regelt de polling voor me. Ik heb ergens wel vertrouwen dat dat goed gaat, want anders hadden alle NodeJS programma's waarin async i/o wordt gebruikt een probleem :)
Beetje meta argument maar soi ... in ieder geval zit in dit simpele voorbeeld geen loop waar je applicatie 100% CPU kan gaan trekken dus we missen wel degelijk relevante dingen.

Kun je niet de relevante *echte* code posten?

Somniferous whisperings of scarlet fields. Sleep calling me and in my dreams i wander. My reality is abandoned (I traverse afar). Not a care if I never everwake.

donderdag 16 juli 2020 22:20

Acties:
  • 0 Henk 'm!
  • Matis
  • Registratie: Januari 2007
  • Laatst online: 21:46

Matis

Rubber Rocket

Ik sluit me aan bij @farlane

Het blijft nu veelal gissen naar mogelijke fouten of adviseren naar wegen die al bewandeld zijn.

Ik zie ook nergens waar (mogelijk) meerdere file descriptors door elkaar heen gebruikt kunnen worden.

If money talks then I'm a mime
If time is money then I'm out of time

donderdag 16 juli 2020 22:50

Acties:
  • 0 Henk 'm!
  • CurlyMo
  • Registratie: Februari 2011
  • Laatst online: 22:57

CurlyMo

Topicstarter
farlane schreef op donderdag 16 juli 2020 @ 22:09:
[...]

Beetje meta argument maar soi ... in ieder geval zit in dit simpele voorbeeld geen loop waar je applicatie 100% CPU kan gaan trekken dus we missen wel degelijk relevante dingen.

Kun je niet de relevante *echte* code posten?
Dit forum is nogal allergisch voor complete code voorbeelden :)

Ik kan natuurlijk wel altijd linken naar echte code

mqtt broken/client implementatite: https://github.com/piligh.../libs/pilight/core/mqtt.c
eventpool https://github.com/piligh...ore/eventpool.c#L588-L882 en https://github.com/piligh...ore/eventpool.c#L930-L992
libuv epoll loop: https://github.com/piligh...ix/linux-core.c#L201-L470

libuv geeft allerlei abstracties over async i/o en dingen als threadpooling en timers. De meest low-level abstractie binnen libuv is poll. Daarmee wordt niet de lekkerlijke C poll bedoeld, maar een basis abstractie over de verschillende async io functies zoals poll, epoll, select e.d.

http://docs.libuv.org/en/v1.x/poll.html

Een van de nadelen van libuv is dat het geen SSL ondersteund. Door de poll abstractie te gebruiken zit je low-level genoeg om zelf een SSL abstractie toe te voegen. Dat is wat ik gedaan heb met de uv_custom_poll_cb functie. Je geeft aan of je je socket wil lezen en/of schrijven en/of sluiten, daarbij geef je aan of je SSL gebruikt. Zo ja, dan zorgt die functie ervoor dat de sockets op de juiste manier worden gelezen en de juiste callbacks (read_cb, write_cb, close_cb) worden aangeroepen. Of in ieder geval, dat dacht ik ;)

Ik kan een heel epistel schrijven over de werking van mijn implementatie van het geheel, maar beantwoord liever jullie gerichte vragen, na een eerste indruk.

PS. de correcte shutdown heb ik nog niet gepushed.

Sinds de 2 dagen regel reageer ik hier niet meer

donderdag 16 juli 2020 23:04

Acties:
  • 0 Henk 'm!
  • CurlyMo
  • Registratie: Februari 2011
  • Laatst online: 22:57

CurlyMo

Topicstarter
Ik ben nog even iets anders aan het uitzoeken. Het lijkt erop dat ik na een FIN telkens terecht kom in dit stukje code, die na recvfrom < 0 && errno == ENOTCONN waarna ik weer de read_cb activeer. Ik vraag me af of dat klopt.
https://github.com/piligh...ore/eventpool.c#L836-L840

Dit zijn de clients die proberen te verbinden met de server. Dit is dus ook vals alarm.

[ Voor 12% gewijzigd door CurlyMo op 17-07-2020 09:09 ]

Sinds de 2 dagen regel reageer ik hier niet meer

vrijdag 17 juli 2020 13:05

Acties:
  • 0 Henk 'm!
  • farlane
  • Registratie: Maart 2000
  • Laatst online: 16-09 22:43

farlane

CurlyMo schreef op donderdag 16 juli 2020 @ 22:50:
[...]
mqtt broken/client implementatite: https://github.com/piligh.../libs/pilight/core/mqtt.c
OK, da's too much.

Ik zie echter wel veel MT related spul, dus ik vraag me af of je niet bijvoorbeeld een socket probeert te closen die op een andere thread nog wordt gebruikt of zoiets dergelijks.

Somniferous whisperings of scarlet fields. Sleep calling me and in my dreams i wander. My reality is abandoned (I traverse afar). Not a care if I never everwake.

vrijdag 17 juli 2020 13:59

Acties:
  • 0 Henk 'm!
  • CurlyMo
  • Registratie: Februari 2011
  • Laatst online: 22:57

CurlyMo

Topicstarter
farlane schreef op vrijdag 17 juli 2020 @ 13:05:
[...]

OK, da's too much.
Dat dacht ik al.
Ik zie echter wel veel MT related spul
Zoals? Deze libraries zijn juist niet multithreaded maar puur async io.

Sinds de 2 dagen regel reageer ik hier niet meer

vrijdag 17 juli 2020 15:35

Acties:
  • 0 Henk 'm!
  • farlane
  • Registratie: Maart 2000
  • Laatst online: 16-09 22:43

farlane

CurlyMo schreef op vrijdag 17 juli 2020 @ 13:59:
Zoals? Deze libraries zijn juist niet multithreaded maar puur async io.
code:
1
2
3
4
5

    /*
    * Make sure we execute in the main thread
    */
    const uv_thread_t pth_cur_id = uv_thread_self();
    ...


code:
1
2
3

...
    pthread_mutex_lock(..)
...

Somniferous whisperings of scarlet fields. Sleep calling me and in my dreams i wander. My reality is abandoned (I traverse afar). Not a care if I never everwake.

vrijdag 17 juli 2020 15:49

Acties:
  • 0 Henk 'm!
  • CurlyMo
  • Registratie: Februari 2011
  • Laatst online: 22:57

CurlyMo

Topicstarter
farlane schreef op vrijdag 17 juli 2020 @ 15:35:
[...]
code:
1
2
3
4
5

    /*
    * Make sure we execute in the main thread
    */
    const uv_thread_t pth_cur_id = uv_thread_self();
    ...
Deze is bedoeld om mijn eigen fouten sneller te ontdekken. De async io moet vanuit de main thread afgehandeld worden. Mocht ik dat om een of andere reden vergeten, dan helpt deze assert mij eraan herinneren :)
code:
1
2
3

...
    pthread_mutex_lock(..)
...
De server en de client kant van de mqtt library maken gebruik van dezelfde linked list. Via de lock dwing ik af dat er nooit twee keer tegelijk een destructieve actie op de linked list wordt gedaan. Maar aangezien ik alles vanuit de main thread doe is doe lock wellicht overboden. Dat is een beetje mijn overvoorzichtigheid.

Sinds de 2 dagen regel reageer ik hier niet meer

vrijdag 17 juli 2020 23:02

Acties:
  • 0 Henk 'm!
  • farlane
  • Registratie: Maart 2000
  • Laatst online: 16-09 22:43

farlane

CurlyMo schreef op vrijdag 17 juli 2020 @ 15:49:
[...]
Be it as it may, ik denk dat je wel een andere richting op moet zoeken. Ik ken libuv niet maar dit komt bijvoorbeeld uit de docs van de uv_poll_t:
It is not okay to have multiple active poll handles for the same socket, this can cause libuv to busyloop or otherwise malfunction.
Je code is te complex om van te zeggen dat je alles goed doet. Misschien moet je kijken of het simpeler kan.....of eerst versimpelen en daarna weer verder uitbouwen.

Somniferous whisperings of scarlet fields. Sleep calling me and in my dreams i wander. My reality is abandoned (I traverse afar). Not a care if I never everwake.

vrijdag 17 juli 2020 23:28

Acties:
  • 0 Henk 'm!
  • CurlyMo
  • Registratie: Februari 2011
  • Laatst online: 22:57

CurlyMo

Topicstarter
farlane schreef op vrijdag 17 juli 2020 @ 23:02:
[...]

Be it as it may, ik denk dat je wel een andere richting op moet zoeken. Ik ken libuv niet maar dit komt bijvoorbeeld uit de docs van de uv_poll_t:
Ik poog dat inderdaad niet te doen :) Zolang mijn software bestaat is het ook niet fout gegaan. Behalve dus in deze MQTT implementatie die ik probeer te maken.
Je code is te complex om van te zeggen dat je alles goed doet. Misschien moet je kijken of het simpeler kan.....of eerst versimpelen en daarna weer verder uitbouwen.
De huidige MQTT library bevat nu twee onderdelen. Een server en een client. Ik kan eens uitzoeken of ik alleen de client kan testen zonder de server.

Sinds de 2 dagen regel reageer ik hier niet meer

donderdag 23 juli 2020 23:17

Acties:
  • 0 Henk 'm!
  • CurlyMo
  • Registratie: Februari 2011
  • Laatst online: 22:57

CurlyMo

Topicstarter
Ik ben nog steeds aan het debuggen, maar ik kan het wel een beetje meer terugbrengen naar de kern van het probleem. Daarbij stuitte ik op deze uitleg van recvfrom:
The recvfrom() and recvmsg() calls are used to receive messages from a socket, and may be used to receive data on a socket whether or not it is connection-oriented.
Kan iemand toelichten wat er met het dikgedrukte gedeelte wordt bedoeld?

Sinds de 2 dagen regel reageer ik hier niet meer

donderdag 23 juli 2020 23:49

Acties:
  • 0 Henk 'm!
  • WK100
  • Registratie: Februari 2011
  • Laatst online: 16-09 07:32

WK100

CurlyMo schreef op donderdag 23 juli 2020 @ 23:17:
Kan iemand toelichten wat er met het dikgedrukte gedeelte wordt bedoeld?
Ik denk dat ze het verschil tussen TCP en UDP bedoelen. Of generieker: stateful (connection-oriented) vs stateless.

[ Voor 11% gewijzigd door WK100 op 23-07-2020 23:50 ]

vrijdag 24 juli 2020 10:53

Acties:
  • +1 Henk 'm!
  • CurlyMo
  • Registratie: Februari 2011
  • Laatst online: 22:57

CurlyMo

Topicstarter
CurlyMo schreef op donderdag 16 juli 2020 @ 18:29:
[...]

Voor dat deel maak ik gebruik van de libuv library. Die regelt de polling voor me. Ik heb ergens wel vertrouwen dat dat goed gaat, want anders hadden alle NodeJS programma's waarin async i/o wordt gebruikt een probleem :)
Ik had toch meer vertrouwen in mezelf moeten hebben dat ik voor 99% wel weet wat ik doe :)

100% CPU + Sockets idling in CLOSE_WAIT state #11307
https://github.com/nodejs/node/issues/11307

:(



En nu ook hier: https://github.com/libuv/libuv/issues/2922

[ Voor 11% gewijzigd door CurlyMo op 24-07-2020 11:58 ]

Sinds de 2 dagen regel reageer ik hier niet meer

Pagina: 1
Reageer

Apple iPhone 16e LG OLED evo G5 Google Pixel 10 Samsung Galaxy S25 Star Wars: Outlaws Nintendo Switch 2 Apple AirPods Pro (2e generatie) Sony PlayStation 5 Pro

Tweakers is onderdeel van DPG Media B.V.
Alle rechten voorbehouden - Auteursrecht © 1998 - 2025 • Hosting door TrueFullstaq