Bug#897266: systemd: journalctl assertion failure

Sat May 5 04:27:48 BST 2018

On Sat, May 05, 2018 at 03:23:35AM +0200, Michael Biebl <biebl at debian.org> wrote:
> Is this problem reproducible?

Yes.

> If so, can you please install the dbgsym package for systemd/libsystemd0
> and get a backtrace from the crash [1].

Cool, I didn't know about the debug symbols repository. See below.

> Do you have persistent journal enabled?

Yes.

> What does journalctl --verify say?

A lot of pass, but also 27 FAIL and "File corruption" and similar messages
(as usual with systemd).

Example:

PASS: /var/log/journal/a1002e4c6eb50c7b5cdd5e004698a90b/user-65533 at 1614fbd80d4f42e8a21cc0a4825e4de1-0000000000795bfa-00056a6baca9f49a.journal
12dddc8: Invalid object                                                         
File corruption detected at /var/log/journal/a1002e4c6eb50c7b5cdd5e004698a90b/system at 7ea033a201334367b130dd1201659ee1-000000000079ca96-00056a74a6a87814.journal:12dddc8 (of 33554432 bytes, 58%).

Backtrace as follows:

(gdb) r -fu cron
Starting program: /usr/bin/journalctl -fu cron
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
Assertion 'p > 0' failed at ../src/journal/journal-file.c:2280, function test_object_offset(). Aborting.

Program received signal SIGABRT, Aborted.
__GI_raise (sig=sig at entry=6) at ../sysdeps/unix/sysv/linux/raise.c:51
51      ../sysdeps/unix/sysv/linux/raise.c: No such file or directory.
(gdb) bt
#0  __GI_raise (sig=sig at entry=6) at ../sysdeps/unix/sysv/linux/raise.c:51
#1  0x00007fffefb3242a in __GI_abort () at abort.c:89
#2  0x00007fffeff81a42 in log_assert_failed (text=<optimized out>, file=<optimized out>, line=<optimized out>, func=<optimized out>) at ../src/basic/log.c:795
#3  0x00007fffeffbe17f in test_object_offset (f=<optimized out>, p=<optimized out>, needle=<optimized out>) at ../src/journal/journal-file.c:2280
#4  0x00007fffeffbfe13 in generic_array_bisect (f=f at entry=0x55555557ad10, first=<optimized out>, first at entry=3739384, n=n at entry=2343, needle=11772088, test_object=0x7fffeffbe100 <test_object_offset>, direction=direction at entry=DIRECTION_UP, ret=0x0, offset=0x7fffffffdbd0, idx=0x0) at ../src/journal/journal-file.c:2019
#5  0x00007fffeffc025c in generic_array_bisect_plus_one (f=<optimized out>, extra=<optimized out>, first=<optimized out>, n=<optimized out>, needle=<optimized out>, test_object=<optimized out>, direction=<optimized out>, ret=<optimized out>, offset=<optimized out>, idx=<optimized out>, idx=<optimized out>, offset=<optimized out>, ret=<optimized out>, direction=<optimized out>, test_object=<optimized out>, needle=<optimized out>, n=<optimized out>, first=<optimized out>, extra=<optimized out>, f=<optimized out>) at ../src/journal/journal-file.c:2251
#6  0x00007fffeffc056e in journal_file_move_to_entry_by_offset_for_data (f=<optimized out>, data_offset=<optimized out>, p=<optimized out>, direction=<optimized out>, ret=<optimized out>, offset=<optimized out>) at ../src/journal/journal-file.c:2688
#7  0x00007fffefee310c in next_for_match (j=j at entry=0x555555567050, m=m at entry=0x555555569380, f=f at entry=0x55555557ad10, after_offset=after_offset at entry=11772088, direction=direction at entry=DIRECTION_UP, ret=ret at entry=0x0, offset=0x7fffffffdbd0) at ../src/journal/sd-journal.c:524
#8  0x00007fffefee3184 in next_for_match (j=0x555555567050, m=<optimized out>, f=0x55555557ad10, after_offset=11772088, direction=DIRECTION_UP, ret=ret at entry=0x0, offset=0x7fffffffdc58) at ../src/journal/sd-journal.c:534
#9  0x00007fffefee31d4 in next_for_match (j=j at entry=0x555555567050, m=m at entry=0x5555555692e0, f=f at entry=0x55555557ad10, after_offset=after_offset at entry=11772088, direction=direction at entry=DIRECTION_UP, ret=ret at entry=0x0, offset=0x7fffffffdd88) at ../src/journal/sd-journal.c:556
#10 0x00007fffefee361a in find_location_for_match (j=j at entry=0x555555567050, m=m at entry=0x5555555692e0, f=f at entry=0x55555557ad10, direction=direction at entry=DIRECTION_UP, ret=ret at entry=0x0, offset=offset at entry=0x7fffffffdd88) at ../src/journal/sd-journal.c:687
#11 0x00007fffefee3758 in find_location_for_match (j=j at entry=0x555555567050, m=m at entry=0x555555569290, f=f at entry=0x55555557ad10, direction=direction at entry=DIRECTION_UP, ret=ret at entry=0x0, offset=offset at entry=0x7fffffffde28) at ../src/journal/sd-journal.c:641
#12 0x00007fffefee35d4 in find_location_for_match (j=j at entry=0x555555567050, m=0x555555569240, f=f at entry=0x55555557ad10, direction=direction at entry=DIRECTION_UP, ret=ret at entry=0x7fffffffdf00, offset=offset at entry=0x7fffffffdf08) at ../src/journal/sd-journal.c:679
#13 0x00007fffefee3a2a in find_location_with_matches (offset=0x7fffffffdf08, ret=0x7fffffffdf00, direction=DIRECTION_UP, f=0x55555557ad10, j=0x555555567050) at ../src/journal/sd-journal.c:724
#14 next_beyond_location (direction=DIRECTION_UP, f=0x55555557ad10, j=0x555555567050) at ../src/journal/sd-journal.c:784
#15 real_journal_next (j=j at entry=0x555555567050, direction=direction at entry=DIRECTION_UP) at ../src/journal/sd-journal.c:832
#16 0x00007fffefee42f6 in real_journal_next_skip (j=0x555555567050, direction=DIRECTION_UP, skip=10) at ../src/journal/sd-journal.c:892
#17 0x000055555555ba25 in main (argc=<optimized out>, argv=<optimized out>) at ../src/journal/journalctl.c:2458

Additional info:

#4  0x00007fffeffbfe13 in generic_array_bisect (f=f at entry=0x55555557ad10, first=<optimized out>, first at entry=3739384, n=n at entry=2343, needle=11772088, test_object=0x7fffeffbe100 <test_object_offset>, direction=direction at entry=DIRECTION_UP, ret=0x0, offset=0x7fffffffdbd0, idx=0x0) at ../src/journal/journal-file.c:2019
2019    in ../src/journal/journal-file.c
(gdb) p *f
$1 = {
  fd = 13, 
  mode = 0, 
  flags = 0, 
  prot = 1, 
  writable = false, 
  compress_xz = false, 
  compress_lz4 = true, 
  seal = false, 
  defrag_on_close = false, 
  close_fd = true, 
  archive = false, 
  tail_entry_monotonic_valid = false, 
  last_direction = DIRECTION_UP, 
  location_type = LOCATION_HEAD, 
  last_n_entries = 8977, 
  path = 0x55555557aef0 "/var/log/journal/a1002e4c6eb50c7b5cdd5e004698a90b/system at 7ea033a201334367b130dd1201659ee1-00000000007a33f3-00056a7eb6600ac0.journal", 
  last_stat = {
    st_dev = 25, 
    st_ino = 788380, 
    st_nlink = 1, 
    st_mode = 33184, 
    st_uid = 0, 
    st_gid = 137, 
    __pad0 = 0, 
    st_rdev = 0, 
    st_size = 16777216, 
    st_blksize = 4096, 
    st_blocks = 32768, 
    st_atim = {
      tv_sec = 1524467341, 
      tv_nsec = 170198568
    }, 
    st_mtim = {
      tv_sec = 1524512161, 
      tv_nsec = 130419538
    }, 
    st_ctim = {
      tv_sec = 1524512161, 
      tv_nsec = 278419226
    }, 
    __glibc_reserved = {0, 0, 0}
  }, 
  last_stat_usec = 2182963690030, 
  header = 0x7fffe9039000, 
  data_hash_table = 0x7fffe903a5e0, 
  field_hash_table = 0x0, 
  current_offset = 0, 
  current_seqnum = 0, 
  current_realtime = 0, 
  current_monotonic = 0, 
  current_boot_id = {
    bytes = '\000' <repeats 15 times>, 
    qwords = {0, 0}
  }, 
  current_xor_hash = 0, 
  metrics = {
    max_size = 0, 
    min_size = 0, 
    max_use = 0, 
    min_use = 0, 
    keep_free = 0, 
    n_max_files = 0
  }, 
  mmap = 0x555555569190, 
  post_change_timer = 0x0, 
  post_change_timer_period = 0, 
  chain_cache = 0x555555567378, 
  offline_thread = 0, 
  offline_state = OFFLINE_JOINED, 
  compress_buffer = 0x0, 
  compress_buffer_size = 0, 
  hmac = 0x0, 
  hmac_running = false, 
  fss_file = 0x0, 
  fss_file_size = 0, 
  fss_start_usec = 0, 
  fss_interval_usec = 0, 
  fsprg_state = 0x0, 
  fsprg_state_size = 0, 
  fsprg_seed = 0x0, 
  fsprg_seed_size = 0
}

-- 
                The choice of a       Deliantra, the free code+content MORPG
      -----==-     _GNU_              http://www.deliantra.net
      ----==-- _       generation
      ---==---(_)__  __ ____  __      Marc Lehmann
      --==---/ / _ \/ // /\ \/ /      schmorp at schmorp.de
      -=====/_/_//_/\_,_/ /_/\_\