Erstellt vor 9 Jahren

Geschlossen vor 9 Jahren

Zuletzt geändert vor 8 Jahren

#608 closed defect (fixed)

libpcap (und damit knockd) defekt seit Versionsbump

Erstellt von: cuma Verantwortlicher: oliver
Priorität: normal Meilenstein: freetz-1.2
Komponente: packages Version: devel
Stichworte: Beobachter:
Product Id: Firmware Version:

Beschreibung

Beim starten von knockd erscheint im Syslog

kernel: libpcap.so.1.0<3>Call Trace:
kernel: [<9400d824>] dump_stack+0x8/0x34
kernel: [<94050b40>] __alloc_pages+0x2b8/0x2f0
kernel: [<94050bb0>] __get_free_pages+0x38/0x70
kernel: [<941a3050>] packet_set_ring+0xfc/0x32c
kernel: [<941a3584>] packet_setsockopt+0x304/0x380
kernel: [<94137460>] sys_setsockopt+0x98/0xd4
kernel: [<94010300>] stack_done+0x20/0x3c
kernel: 
kernel: knockd: page allocation failure. order:5, mode:0xC0D0
kernel: Mem-info:
kernel: DMA per-cpu:
kernel: CPU    0: Hot: hi:  186, btch:  31 usd:  46   Cold: hi:   62, btch:  15 usd:  52
kernel: Active:6154 inactive:2366 dirty:0 writeback:0 unstable:0 free:918 slab:3170 mapped:2922 pagetables:181
kernel: DMA free:3672kB min:2496kB low:3120kB high:3744kB active:24616kB inactive:9464kB present:389892kB pages_scanned:0 all_unreclaimable? no
kernel: lowmem_reserve[]: 0 0
kernel: DMA: 184*4kB 33*8kB 21*16kB 31*32kB 19*64kB 1*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 3672kB
kernel: Swap cache: add 0, delete 0, find 0/0, race 0+0
kernel: Free swap  = 0kB
kernel: Total swap = 0kB
kernel: Free swap:            0kB
kernel: 16320 pages of RAM
kernel: 0 pages of HIGHMEM
kernel: 869 reserved pages
kernel: 39425 pages shared
kernel: 0 pages swap cached
kernel: Call Trace:
kernel: [<9400d824>] dump_stack+0x8/0x34
kernel: [<94050b40>] __alloc_pages+0x2b8/0x2f0
kernel: [<94050bb0>] __get_free_pages+0x38/0x70
kernel: [<941a3050>] packet_set_ring+0xfc/0x32c
kernel: [<941a3584>] packet_setsockopt+0x304/0x380
kernel: [<94137460>] sys_setsockopt+0x98/0xd4
kernel: [<94010300>] stack_done+0x20/0x3c
kernel: 
kernel: knockd: page allocation failure. order:5, mode:0xC0D0
kernel: Mem-info:
kernel: DMA per-cpu:
kernel: CPU    0: Hot: hi:  186, btch:  31 usd:  60   Cold: hi:   62, btch:  15 usd:  51
kernel: Active:6158 inactive:2258 dirty:0 writeback:0 unstable:0 free:1023 slab:3156 mapped:2922 pagetables:181
kernel: DMA free:4092kB min:2496kB low:3120kB high:3744kB active:24632kB inactive:9032kB present:389892kB pages_scanned:0 all_unreclaimable? no
kernel: lowmem_reserve[]: 0 0
kernel: DMA: 251*4kB 42*8kB 26*16kB 31*32kB 19*64kB 1*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 4092kB
kernel: Swap cache: add 0, delete 0, find 0/0, race 0+0
kernel: Free swap  = 0kB
kernel: Total swap = 0kB
kernel: Free swap:            0kB
kernel: 16320 pages of RAM
kernel: 0 pages of HIGHMEM
kernel: 869 reserved pages
kernel: 39387 pages shared

Anhänge (6)

knock-error.txt (13.2 KB) - hinzugefügt von Whoopie vor 9 Jahren.
reproduced error
start.txt (17.0 KB) - hinzugefügt von cuma vor 9 Jahren.
stop.txt (17.0 KB) - hinzugefügt von cuma vor 9 Jahren.
startstop-diff.patch (11.8 KB) - hinzugefügt von cuma vor 9 Jahren.
libpcap_ring.diff (4.6 KB) - hinzugefügt von oliver vor 9 Jahren.
knockd.patch (612 Byte) - hinzugefügt von oliver vor 9 Jahren.

Alle Anhänge herunterladen als: .zip

Änderungshistorie (32)

comment:1 Geändert vor 9 Jahren durch Whoopie

Schau mal hier: https://dev.openwrt.org/ticket/5455


Das hat irgendwas mit Speicherverbrauch zu tun.

Geändert vor 9 Jahren durch Whoopie

reproduced error

comment:2 Geändert vor 9 Jahren durch cuma

Hm, bei OpenWRT steht, dass man mehr freien Ram benötigt. Nur das ganze hatte ja vorher sehr lange Zeit so funktioniert

comment:3 Geändert vor 9 Jahren durch oliver

@Whoopie
Wie hast du den Fehler denn jetzt reproduziert?

comment:4 Geändert vor 9 Jahren durch Whoopie

@oliver: knock kompiliert, auf die Box kopiert und mit der Standard-Konfiguration aus /usr/share/knock gestartet. Und schon hab ich das in "logread" gesehen.

comment:5 Geändert vor 9 Jahren durch cuma

Ich hab jetzt auch noch Probleme sowohl auf Boxen mit altem als auch neuem Kernel. Knockd, tcpdump & nmap waren seit dem letzten Reboot nicht gestartet. Nach Aktivieren vom Wlan:

21:03:14 kernel: ZAR5416, REGOPS_FUNC
21:03:14 kernel: drivers.pandu
21:03:16 kernel: avmEEPROM: Reading calibration data #1
21:03:16 kernel: avmEEPROM: Got calibration data version: 2
21:03:16 kernel: Chan  Freq  RegPwr  HT   CTL CTL_U CTL_L DFS
21:03:16 kernel:    1  2412n     20  HT20  1    0    1     N
21:03:16 kernel:    2  2417n     20  HT20  1    0    1     N
21:03:16 kernel:    3  2422n     20  HT40  1    0    1     N
21:03:16 kernel:    4  2427n     20  HT40  1    0    1     N
21:03:16 kernel:    5  2432n     20  HT40  1    1    1     N
21:03:16 kernel:    6  2437n     20  HT40  1    1    1     N
21:03:16 kernel:    7  2442n     20  HT40  1    1    1     N
21:03:16 kernel:    8  2447n     20  HT40  1    1    1     N
21:03:16 kernel:    9  2452n     20  HT40  1    1    1     N
21:03:16 kernel:   10  2457n     20  HT40  1    1    0     N
21:03:16 kernel:   11  2462n     20  HT40  1    1    0     N
21:03:16 kernel:   12  2467n     20  HT20  1    1    0     N
21:03:16 kernel:   13  2472n     20  HT20  1    1    0     N
21:03:16 kernel:   36  5180n     30  HT20  1    0    1     N
21:03:16 kernel:   38  5190n     20  HT40  1    0    0     N
21:03:16 kernel:   40  5200n     30  HT20  1    1    0     N
21:03:16 kernel:   44  5220n     30  HT20  1    0    1     N
21:03:16 kernel:   46  5230n     20  HT40  1    0    0     N
21:03:16 kernel:   48  5240n     30  HT20  1    1    0     N
21:03:16 kernel:   52  5260n     20  HT20  1    0    1     Y
21:03:16 kernel:   54  5270n     20  HT40  1    0    0     Y
21:03:16 kernel:   56  5280n     20  HT20  1    1    0     Y
21:03:16 kernel:   60  5300n     20  HT20  1    0    1     Y
21:03:16 kernel:   62  5310n     20  HT40  1    0    0     Y
21:03:16 kernel:   64  5320n     20  HT20  1    1    0     Y
21:03:16 kernel:  100  5500n     27  HT20  1    0    1     Y
21:03:16 kernel:  102  5510n     27  HT40  1    0    0     Y
21:03:16 kernel:  104  5520n     27  HT20  1    1    0     Y
21:03:16 kernel:  108  5540n     27  HT20  1    0    1     Y
21:03:16 kernel:  110  5550n     27  HT40  1    0    0     Y
21:03:16 kernel:  112  5560n     27  HT20  1    1    0     Y
21:03:16 kernel:  116  5580n     27  HT20  1    0    1     Y
21:03:16 kernel:  118  5590n     27  HT40  1    0    0     Y
21:03:16 kernel:  120  5600n     27  HT20  1    1    0     Y
21:03:16 kernel:  124  5620n     27  HT20  1    0    1     Y
21:03:16 kernel:  126  5630n     27  HT40  1    0    0     Y
21:03:16 kernel:  128  5640n     27  HT20  1    1    0     Y
21:03:16 kernel:  132  5660n     27  HT20  1    0    1     Y
21:03:16 kernel:  134  5670n     27  HT40  1    0    0     Y
21:03:16 kernel:  136  5680n     27  HT20  1    1    0     Y
21:03:16 kernel:  140  5700n     27  HT20  1    0    0     Y
21:03:16 kernel: Call Trace:
21:03:16 kernel: [<9400d824>] dump_stack+0x8/0x34
21:03:16 kernel: [<94050b40>] __alloc_pages+0x2b8/0x2f0
21:03:16 kernel: [<94050bb0>] __get_free_pages+0x38/0x70
21:03:16 kernel: [<940166b4>] dma_alloc_noncoherent+0x74/0xb4
21:03:16 kernel: [<9401670c>] dma_alloc_coherent+0x18/0x58
21:03:16 kernel: [<c0690288>] ath_descdma_setup+0xcc/0xffe5be44 [ath_pci]
21:03:16 kernel: [<c069a3b8>] ath_attach+0x618/0xffe52260 [ath_pci]
21:03:16 kernel: [<c06a6ed0>] ath_pci_probe+0x2d0/0xffe45400 [ath_pci]
21:03:16 kernel: [<940e2670>] pci_device_probe+0x64/0xa4
21:03:16 kernel: [<94109844>] really_probe+0x68/0x120
21:03:16 kernel: [<941099e0>] driver_probe_device+0xcc/0xf4
21:03:16 kernel: [<94109b78>] __driver_attach+0x98/0x11c
21:03:16 kernel: [<94108900>] bus_for_each_dev+0x4c/0x90
21:03:16 kernel: [<941090d0>] bus_add_driver+0x78/0x1e8
21:03:16 kernel: [<940e2440>] __pci_register_driver+0x80/0xc0
21:03:16 kernel: [<c0506070>] init_ath_pci+0x70/0x3fafa000 [ath_pci]
21:03:16 kernel: [<94046ac8>] sys_init_module+0x17a4/0x18c4
21:03:16 kernel: [<94010300>] stack_done+0x20/0x3c
21:03:16 kernel: 
21:03:16 kernel: [pcmlink]error: trigger to late 15702 usec (293A9D0C 2965BE08 2966193F)
21:03:16 kernel: Mem-info:
21:03:16 kernel: DMA per-cpu:
21:03:16 kernel: CPU    0: Hot: hi:  186, btch:  31 usd:  73   Cold: hi:   62, btch:  15 usd:  61
21:03:16 kernel: Active:3054 inactive:1253 dirty:0 writeback:0 unstable:0 free:6580 slab:2184 mapped:834 pagetables:169
21:03:16 kernel: DMA free:26320kB min:2496kB low:3120kB high:3744kB active:12216kB inactive:5012kB present:389892kB pages_scanned:666 all_unreclaimable? no
21:03:16 kernel: lowmem_reserve[]: 0 0
21:03:16 kernel: DMA: 0*4kB 954*8kB 500*16kB 218*32kB 42*64kB 6*128kB 1*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 26320kB
21:03:16 kernel: Swap cache: add 0, delete 0, find 0/0, race 0+0
21:03:16 kernel: Free swap  = 0kB
21:03:16 kernel: Total swap = 0kB
21:03:16 kernel: Free swap:            0kB
21:03:16 kernel: 16320 pages of RAM
21:03:16 kernel: 0 pages of HIGHMEM
21:03:16 kernel: 869 reserved pages
21:03:16 kernel: 17334 pages shared
21:03:16 kernel: 0 pages swap cached

comment:6 Geändert vor 9 Jahren durch Whoopie

Hab das grad mal mit der libcap 1.0.1pre aus dem git-Repository getestet und auch damit reproduziert. Wir sollten den knockd-Entwickler mal fragen, ob er eine Idee hat.

comment:7 als Antwort auf: ↑ description Geändert vor 9 Jahren durch ralf

Fehlt hier Kernel-Speicher oder Benutzer-Speicher?
Tritt das Problem auch auf, wenn SWAP-Speicher zur Verfügung steht?
Was wird in /proc/meminfo und /proc/slabinfo angezeigt im Vergleich zu den Werten, wenn das Programm nicht läuft?

Wenn ich es richtig sehe, wird hier versucht, 128kB am Stück im Kernel zu belegen. Entweder ist das zu viel, oder es gibt ein anderes Problem.

Evtl. hat sich hier der Default-Wert gegenüber früheren Versionen vergrößert.

comment:8 Geändert vor 9 Jahren durch Whoopie

@ralf: ja, das Problem tritt auch mit SWAP-Speicher auf.


Die anderen Traces kann ich erst nächste Woche sammeln, aber vielleicht ist cuma ja schneller. ;)

comment:9 Geändert vor 9 Jahren durch cuma

Hab momentan wieder die ältere libpcap installiert, wenn ich das nächte mal ein Image baue nehm ich die neue wieder mit rein.
Bei "/proc/slabinfo" fällt mit digitemp ein, das lässt den RAM der 7270 nach ~30h vollaufen

comment:10 Geändert vor 9 Jahren durch oliver

Ich kann das auf meiner 7270 nicht nachvollziehen. Als Interface hab ich lan gewählt, da die Box nicht am DSL hängt.

Geändert vor 9 Jahren durch cuma

Geändert vor 9 Jahren durch cuma

Geändert vor 9 Jahren durch cuma

comment:11 Geändert vor 9 Jahren durch oliver

  • Status von new nach accepted geändert
  • Verantwortlicher auf oliver gesetzt

Ich kann das Problem jetzt auch nach vollziehen. Wenn es beim ersten Prozess nicht auftritt, dann hilft es den knock mehrmals zu starten.
Ich hänge mal den diff zum aktuellen GIT an. Da sieht man, dass mit der nächsten Release Version das "Problem" noch schlimmer wird. Hier wird ein 2 MB Puffer reserviert (Wo? Ich konnte im slabinfo die 2 MB nicht finden). Derzeit wird die Größe pro "Fehler" halbiert. Im Patch wird die Größe nur noch um 5% verkleinert. Die Meldung wird dann wahrscheinlich mehrmals im Syslog auftauchen. Ein Fehler ist das aber nicht, da die maximal mögliche Puffer Größe reserviert wird.
Wir könnten natürlich für die FBox die "initiale" Puffer Größe von 2 auf 1 MB erniedrigen. Oder wir nutzen dieses neue Feature mit dem TX Ring Buffer nicht und belassen es bei der alten Methode.

Geändert vor 9 Jahren durch oliver

comment:12 Geändert vor 9 Jahren durch cuma

Libpcap ist wird dann aber ein ziehmlicher RAM-Fresser

comment:13 Geändert vor 9 Jahren durch oliver

Ja, es kommt sogar noch schlimmer. Die Paket Länge wird von knockd auf 64KB eingestellt. Da libpcap zusätzliche Informationen speichert werden 65600 Bytes pro Paket benötigt. Daher wird die Block Größe auf 128kb erhöht und es werden 31 * 128 KB alloziert. Was 3968 KB entspricht.

Geändert vor 9 Jahren durch oliver

comment:14 Geändert vor 9 Jahren durch oliver

@cuma
Magst du mal probieren, ob knockd auch mit 4KB statt 64KB snapshot Länge tut? Dann könnten wir evtl. den ringsize in der libpcap kleiner machen. Der angehängte Patch ändert den knockd, aber erstmal nichts an der Größe des libpcap ringsize.

comment:15 Geändert vor 9 Jahren durch cuma

Oki, ich teste mal auf der 7170 mit libpcap 1.0.0 und dem Patch. Mal gespannt wie tcpdump läuft

comment:16 Geändert vor 9 Jahren durch cuma

Komische Sache. Knock hat mit dem Patch noch reagiert. Allerdings konnte ich keine 10MB-Datei mehr mit vsftpd auf die Box laden, bzw mit 50KB/s und nachher korrupt. Knockd war zu dem Zeitpunkt beendet. Bin jetzt aber auch nicht 100% sicher ob es an libpcap lag…
Vielleicht kann noch jemand das ausprobieren

comment:17 Geändert vor 9 Jahren durch oliver

Was sollen wir hier machen? libpcap downgraden? Diesen Ringbuffer abschalten? Die snaplength im knockd heruntersetzen?

comment:18 Geändert vor 9 Jahren durch Whoopie

(In [4292]) knock: add patch to avoid zombies (Debian bug #373009), reduce buffer size (by olistudent, refs #608)

comment:19 Geändert vor 9 Jahren durch oliver

Hast du den Patch probiert? Funktioniert knockd damit noch richtig?

comment:20 Geändert vor 9 Jahren durch Whoopie

Natürlich hab ich es getestet. ;) Auf jeden Fall lief knockd und es reagierte auf knock-Anfragen von meinem Laptop (getestet über dsl-Interface). Zudem sah ich keine Meldungen in logread.

comment:21 Geändert vor 9 Jahren durch cuma

Also ich hab weiterhin Probleme mit vsftpd mit dem aktuellsten Trunk, getestet mit einer 7170. Wenn knockd läuft kann ich eine 10MB Datei mit 50-200 KB/s übertragen. Wenn knockd beendet ist wird der Upload so bei der Hälfte ständig abgebrochen

comment:22 Geändert vor 9 Jahren durch cuma

Auf der 7270 hat vsftpd das Problem übrigens nicht. Wenn ich die 7270 starte erscheint (mit aktiviertem Wlan):

18:54:33 kernel: tcpdump<3>Call Trace:
18:54:33 kernel: [<9400d8d4>] dump_stack+0x8/0x34
18:54:33 kernel: [<94050b80>] __alloc_pages+0x2b8/0x2f0
18:54:33 kernel: [<94050bf0>] __get_free_pages+0x38/0x70
18:54:33 kernel: [<941a43f0>] packet_set_ring+0xfc/0x32c
18:54:33 kernel: [<941a4924>] packet_setsockopt+0x304/0x380
18:54:33 kernel: [<94138b80>] sys_setsockopt+0x98/0xd4
18:54:33 kernel: [<940103c0>] stack_done+0x20/0x3c
18:54:33 kernel: tcpdump: page allocation failure. order:5, mode:0xC0D0
18:54:33 kernel: Mem-info:
18:54:33 kernel: DMA per-cpu:
18:54:33 kernel: CPU    0: Hot: hi:  186, btch:  31 usd:   5   Cold: hi:   62, btch:  15 usd:  49
18:54:33 kernel: Active:4379 inactive:4301 dirty:0 writeback:330 unstable:0 free:709 slab:2795 mapped:2514 pagetables:156
18:54:33 kernel: DMA free:2836kB min:2496kB low:3120kB high:3744kB active:17516kB inactive:17204kB present:389892kB pages_scanned:0 all_unreclaimable? no
18:54:33 kernel: lowmem_reserve[]: 0 0
18:54:33 kernel: DMA: 223*4kB 79*8kB 28*16kB 13*32kB 5*64kB 1*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 0*4096kB = 2836kB
18:54:33 kernel: Swap cache: add 0, delete 0, find 0/0, race 0+0
18:54:33 kernel: Free swap  = 0kB
18:54:33 kernel: Total swap = 0kB
18:54:33 kernel: Free swap:            0kB
18:54:33 kernel: 16320 pages of RAM
18:54:33 kernel: 0 pages of HIGHMEM
18:54:33 kernel: 873 reserved pages
18:54:33 kernel: 9089 pages shared

comment:23 Geändert vor 9 Jahren durch oliver

(In [4295]) * libpcap: Halve ring buffer size (2 → 1 MB)

comment:24 Geändert vor 9 Jahren durch cuma

Funktioniert jetzt ohne den Fehler :-]

comment:25 Geändert vor 9 Jahren durch oliver

  • Lösung auf fixed gesetzt
  • Status von accepted nach closed geändert

Bei weiteren Beschwerden bitte wieder öffnen…

→ closed

comment:26 Geändert vor 8 Jahren durch cuma

Ich hab seit ein paar Revisionen hohe CPU-Last durch tpdump: http://www.ip-phone-forum.de/showthread.php?p=1527500#post1527500. Bin aber nicht sicher ob es an libpcap & co liegt.

Hinweis: Hilfe zur Verwendung von Tickets finden Sie in TracTickets.