Projet

Général

Profil

Anomalie #4497

Logs kernel inquiétantes sur la vm bastion

Ajouté par Christian P. Momon il y a presque 4 ans. Mis à jour il y a presque 4 ans.

Statut:
Fermé
Priorité:
Urgente
Assigné à:
Christian P. Momon
Catégorie:
-
Version cible:
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 0

Questions :
  • Faut-il s'inquiéter ?
  • D'où viennent ces logs ?
  • Quel impact sur les services ? Coupure Mumble ?

Historique

#1

Mis à jour par Christian P. Momon il y a presque 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.

#2

Mis à jour par Christian P. Momon il y a presque 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.

#3

Mis à jour par Quentin Gibeaux il y a presque 4 ans

  • Statut changé de Résolu à Fermé

Formats disponibles : Atom PDF