Actions
Anomalie #4497
ferméLogs kernel inquiétantes sur la vm bastion
Début:
22/05/2020
Echéance:
% réalisé:
0%
Temps estimé:
Difficulté:
2 Facile
Description
Les fichiers de log /var/log/messages* ne contiennent que des logs kernels bizarre :
Jan 8 01:59:03 bastion kernel: [1555109.098927] Code: df 5b e9 ab fe ff ff 48 c7 c7 78 0c e4 89 e8 bd fd d5 ff 0f 0b 8b 45 08 e9 24 df ff ff 90 90 90 90 90 66 66 66 66 90 48 8b 07 <48> 85 c0 74 0f 48 3b 70 c8 73 0a 48 8b 40 10 48 85 c0 75 f1 c3 76 Jan 8 01:59:03 bastion kernel: [1555109.098927] RIP: 0010:elv_rb_find+0x8/0x30 Jan 8 01:59:03 bastion kernel: [1555109.098928] RAX: 0000000000000000 RBX: 0000000000001c20 RCX: 0000000000000001 Jan 8 01:59:03 bastion kernel: [1555109.098928] RSP: 0018:ffffb3870024f848 EFLAGS: 00000246 ORIG_RAX: ffffffffffffffd2 Jan 8 01:59:03 bastion kernel: [1555109.098929] RBP: ffff9bec4f337670 R08: ffff9bec4f14bc00 R09: 0000000000000001 Jan 8 01:59:03 bastion kernel: [1555109.098929] RDX: 0000000000000000 RSI: 0000000000001c20 RDI: ffff9bec4e97b880 Jan 8 01:59:03 bastion kernel: [1555109.098930] R10: 0000000000001000 R11: ffff9bec44fc5001 R12: ffffb3870024f878 Jan 8 01:59:03 bastion kernel: [1555109.098930] R13: 0000000000000001 R14: 00000000ffffffff R15: ffffb3870024fc18 Jan 8 01:59:03 bastion kernel: [1555109.098932] ? elv_merge+0x63/0xe0 Jan 8 01:59:03 bastion kernel: [1555109.098933] dd_request_merge+0x3f/0x80 Jan 8 01:59:03 bastion kernel: [1555109.098934] blk_mq_sched_try_merge+0x31/0x170 Jan 8 01:59:03 bastion kernel: [1555109.098936] dd_bio_merge+0x51/0x90 Jan 8 01:59:03 bastion kernel: [1555109.098937] blk_mq_make_request+0xd7/0x530 Jan 8 01:59:03 bastion kernel: [1555109.098939] generic_make_request+0x1a4/0x400 Jan 8 01:59:03 bastion kernel: [1555109.098940] submit_bio+0x45/0x140 Jan 8 01:59:03 bastion kernel: [1555109.098942] ? get_swap_bio+0xbb/0xf0 Jan 8 01:59:03 bastion kernel: [1555109.098943] swap_readpage+0x13f/0x1e0 Jan 8 01:59:03 bastion kernel: [1555109.098945] read_swap_cache_async+0x58/0x60 Jan 8 01:59:03 bastion kernel: [1555109.098947] swap_cluster_readahead+0x273/0x2f0 Jan 8 01:59:03 bastion kernel: [1555109.098948] ? blk_mq_make_request+0x1e5/0x530 Jan 8 01:59:03 bastion kernel: [1555109.098949] swapin_readahead+0x334/0x4c0 Jan 8 01:59:03 bastion kernel: [1555109.098951] ? radix_tree_lookup_slot+0x1e/0x50 Jan 8 01:59:03 bastion kernel: [1555109.098952] ? find_get_entry+0x19/0xf0 Jan 8 01:59:03 bastion kernel: [1555109.098953] ? pagecache_get_page+0x30/0x2c0 Jan 8 01:59:03 bastion kernel: [1555109.098954] do_swap_page+0x44b/0x960 Jan 8 01:59:03 bastion kernel: [1555109.098955] ? __switch_to_asm+0x41/0x70 Jan 8 01:59:03 bastion kernel: [1555109.098956] ? __switch_to_asm+0x35/0x70 Jan 8 01:59:03 bastion kernel: [1555109.098957] ? __switch_to_asm+0x41/0x70 Jan 8 01:59:03 bastion kernel: [1555109.098958] __handle_mm_fault+0x876/0x1270 Jan 8 01:59:03 bastion kernel: [1555109.098959] ? __switch_to_asm+0x35/0x70 Jan 8 01:59:03 bastion kernel: [1555109.098960] handle_mm_fault+0xd6/0x200 Jan 8 01:59:03 bastion kernel: [1555109.098961] __do_page_fault+0x249/0x4f0 Jan 8 01:59:03 bastion kernel: [1555109.098962] async_page_fault+0x1e/0x30
Dans /var/log/syslog, c'est plus discret mais ça coïncide avec la coupure Mumble April de ce matin (#4447) :
May 22 10:59:40 bastion icinga2[510]: [2020-05-22 10:59:40 +0200] information/RemoteCheckQueue: items: 0, rate: 0/s (6/min 30/5min 90/15min); May 22 10:59:50 bastion icinga2[510]: [2020-05-22 10:59:50 +0200] information/RemoteCheckQueue: items: 0, rate: 0/s (12/min 60/5min 180/15min); May 22 11:00:00 bastion icinga2[510]: [2020-05-22 11:00:00 +0200] information/RemoteCheckQueue: items: 0, rate: 0/s (6/min 30/5min 90/15min); May 22 11:00:00 bastion kernel: [1027919.996688] warn_alloc: 62 callbacks suppressed May 22 11:00:00 bastion kernel: [1027919.996692] ksoftirqd/0: page allocation failure: order:0, mode:0x480020(GFP_ATOMIC), nodemask=(null) May 22 11:00:00 bastion kernel: [1027919.996693] ksoftirqd/0 cpuset=/ mems_allowed=0 May 22 11:00:00 bastion kernel: [1027919.996698] CPU: 0 PID: 9 Comm: ksoftirqd/0 Not tainted 4.19.0-9-amd64 #1 Debian 4.19.118-2 May 22 11:00:00 bastion kernel: [1027919.996699] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.12.0-1 04/01/2014 May 22 11:00:00 bastion kernel: [1027919.996700] Call Trace: May 22 11:00:00 bastion kernel: [1027919.996719] dump_stack+0x66/0x90 May 22 11:00:00 bastion kernel: [1027919.996726] warn_alloc.cold.120+0x6c/0xec May 22 11:00:00 bastion kernel: [1027919.996730] __alloc_pages_slowpath+0xc73/0xcb0 May 22 11:00:00 bastion kernel: [1027919.996733] __alloc_pages_nodemask+0x28b/0x2b0 May 22 11:00:00 bastion kernel: [1027919.996734] page_frag_alloc+0x124/0x150 May 22 11:00:00 bastion kernel: [1027919.996737] __napi_alloc_skb+0x88/0xe0 May 22 11:00:00 bastion kernel: [1027919.996740] ? dev_gro_receive+0x39b/0x660 May 22 11:00:00 bastion kernel: [1027919.996755] page_to_skb+0x62/0x330 [virtio_net] May 22 11:00:00 bastion kernel: [1027919.996758] receive_buf+0x61d/0x14c0 [virtio_net] May 22 11:00:00 bastion kernel: [1027919.996762] ? enqueue_entity+0x108/0x640 May 22 11:00:00 bastion kernel: [1027919.996766] ? vring_unmap_one+0x16/0x70 [virtio_ring] May 22 11:00:00 bastion kernel: [1027919.996768] ? detach_buf+0x69/0x110 [virtio_ring] May 22 11:00:00 bastion kernel: [1027919.996770] virtnet_poll+0x143/0x328 [virtio_net] May 22 11:00:00 bastion kernel: [1027919.996773] net_rx_action+0x149/0x3b0 May 22 11:00:00 bastion kernel: [1027919.996776] __do_softirq+0xde/0x2d8 May 22 11:00:00 bastion kernel: [1027919.996779] ? sort_range+0x20/0x20 May 22 11:00:00 bastion kernel: [1027919.996782] run_ksoftirqd+0x26/0x40 May 22 11:00:00 bastion kernel: [1027919.996785] smpboot_thread_fn+0xc5/0x160 May 22 11:00:00 bastion kernel: [1027919.996788] kthread+0x112/0x130 May 22 11:00:00 bastion kernel: [1027919.996789] ? kthread_bind+0x30/0x30 May 22 11:00:00 bastion kernel: [1027919.996791] ret_from_fork+0x35/0x40 May 22 11:00:00 bastion kernel: [1027919.996795] warn_alloc_show_mem: 9 callbacks suppressed May 22 11:00:00 bastion kernel: [1027919.996796] Mem-Info: May 22 11:00:00 bastion kernel: [1027919.996799] active_anon:3924 inactive_anon:5484 isolated_anon:0 May 22 11:00:00 bastion kernel: [1027919.996799] active_file:11966 inactive_file:10683 isolated_file:0 May 22 11:00:00 bastion kernel: [1027919.996799] unevictable:0 dirty:2253 writeback:0 unstable:0 May 22 11:00:00 bastion kernel: [1027919.996799] slab_reclaimable:10120 slab_unreclaimable:9080 May 22 11:00:00 bastion kernel: [1027919.996799] mapped:7645 shmem:454 pagetables:452 bounce:0 May 22 11:00:00 bastion kernel: [1027919.996799] free:1485 free_pcp:81 free_cma:0 May 22 11:00:00 bastion kernel: [1027919.996802] Node 0 active_anon:15696kB inactive_anon:21936kB active_file:47864kB inactive_file:42732kB unevictable:0kB isolated(anon):0kB isolated(file):0kB mapped:30580kB dirty:9012kB writeback:0kB shmem:1816kB shmem_thp: 0kB shmem_pmdmapped: 0kB anon_thp: 0kB writeback_tmp:0kB unstable:0kB all_unreclaimable? no May 22 11:00:00 bastion kernel: [1027919.996803] Node 0 DMA free:2004kB min:140kB low:172kB high:204kB active_anon:372kB inactive_anon:500kB active_file:2352kB inactive_file:4644kB unevictable:0kB writepending:64kB present:15992kB managed:15908kB mlocked:0kB kernel_stack:256kB pagetables:36kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB May 22 11:00:00 bastion kernel: [1027919.996806] lowmem_reserve[]: 0 184 184 184 184 May 22 11:00:00 bastion kernel: [1027919.996808] Node 0 DMA32 free:3936kB min:1664kB low:2080kB high:2496kB active_anon:15324kB inactive_anon:21436kB active_file:45508kB inactive_file:38088kB unevictable:0kB writepending:8940kB present:245604kB managed:220820kB mlocked:0kB kernel_stack:1680kB pagetables:1772kB bounce:0kB free_pcp:324kB local_pcp:324kB free_cma:0kB May 22 11:00:00 bastion kernel: [1027919.996811] lowmem_reserve[]: 0 0 0 0 0Questions :
- Faut-il s'inquiéter ?
- D'où viennent ces logs ?
- Quel impact sur les services ? Coupure Mumble ?
Actions
#1
Mis à jour par Christian P. Momon il y a plus de 4 ans
- Statut changé de Nouveau à En cours de traitement
- Assigné à mis à Christian P. Momon
Le 23/05/2020 à 22:09, Romain a écrit :
C'est une VM assez critique dans l'infra, du coup je pense que c'est
important qu'elle fonctionne bien.
[…]- faut-il rajouter de la mémoire à la vm bastion ?
- combien ?Je pense que ça serait bien de récupérer les 512 Mo libérés par la
suppression de la VM photos.
Fait. Passage de la RAM de la vm bastion de 256 Mo à 768 Mo.
Actions
#2
Mis à jour par Christian P. Momon il y a plus de 4 ans
- Statut changé de En cours de traitement à Résolu
Après plusieurs jours, plus aucun message inquiétant. On va dire que c'était ça.
Actions