Init error: failed to initialize history: timeout

[c0dev0id]

Hi,

yesterday, gomuks was working fine. Today it showed me the login screen. This happened before - and the problem has gone away when I tried to start gomuks a few hours later.

• There is no gomuks process running in the background.
• I can connect to the matrix server from another client.
• This is gomuks version 0.3.0

To start clean, I did rm -rf .local/share/gomuks .config/gomuks .cache/gomuks /tmp/gomuks

Then I start gomuks and enter my credentials.

debug.log:

======================= Debug init @ 2023-10-25 09:09:05 =======================
[2023-10-25 09:09:05] Config directory: /home/sdk/.config/gomuks
[2023-10-25 09:09:05] Data directory: /home/sdk/.local/share/gomuks
[2023-10-25 09:09:05] Cache directory: /home/sdk/.cache/gomuks
[2023-10-25 09:09:05] Download directory: /home/sdk/Downloads
[2023-10-25 09:09:36] Logging into https://tapenet.org:443 as @sdk:tapenet.org...
[2023-10-25 09:09:36] Using SQLite crypto store
[2023-10-25 09:09:36] Init error: failed to initialize history: bad address
[2023-10-25 09:09:36] Showing error failed to initialize history: bad address
[2023-10-25 09:09:45] Logging into https://tapenet.org as @sdk:tapenet.org...
[2023-10-25 09:09:45] Using SQLite crypto store
[2023-10-25 09:09:45] Init error: failed to initialize history: timeout
[2023-10-25 09:09:45] Showing error failed to initialize history: timeout
[2023-10-25 09:09:46] Disconnecting from Matrix...
[2023-10-25 09:09:46] Cleaning up UI...
[2023-10-25 09:09:46] Saving room list...
[2023-10-25 09:09:46] Room list saved to /home/sdk/.cache/gomuks/rooms.gob.gz 0 0
[2023-10-25 09:09:46] Exiting process

Does anyone have a hint what could cause this or how to debug it?

[c0dev0id]

Now, after a reboot it works again. No new login necessary. It just starts up. Is there any shared memory involved that can get left behind?

I'm trying to reboot right away next time and see if this helps.

[c0dev0id]

I repoen this issue, because I have the same exact situation again for days now.

One interesting bit: I can use gomuks on another machine. I tried to copy all gomuks files over. Which means I deleted .local/share/gomuks .config/gomuks .cache/gomuks /tmp/gomuks and copied those directories from the other machine.

No change... I get the same behavior.

Then I traced the executable. I think the interesting part is:

  52627 gomuks   CALL  open(0xc0000e5b90,0x10202<O_RDWR|O_CREAT|O_CLOEXEC>,0600<S_IRUSR|S_IWUSR>)
  52627 gomuks   NAMI  "/home/sdk/.cache/gomuks/history.db"
  52627 gomuks   RET   open 4
  52627 gomuks   CALL  fstat(4,0xc00063eab8)
  52627 gomuks   STRU  struct stat { dev=1054, ino=17304613, mode=-rw------- , nlink=1, uid=1000<"sdk">, gid=1000<"sdk">, rdev=69176856, atime=1701153179<"No
 v 28 07:32:59 2023">.316222194, mtime=1701153458<"Nov 28 07:37:38 2023">.236052820, ctime=1701153458<"Nov 28 07:37:38 2023">.236052820, size=27115520, block
 s=53120, blksize=65536, flags=0x0, gen=0x0 }
  52627 gomuks   RET   fstat 0
  52627 gomuks   CALL  kbind(0x75883ea06e20,24,0x78bb40950af3aabb)
  52627 gomuks   RET   kbind 0
  52627 gomuks   CALL  flock(4,0x6<LOCK_EX|LOCK_NB>)
  52627 gomuks   RET   flock 0
  52627 gomuks   CALL  fstat(4,0xc0004c60f8)

... and a bit later ....
  52627 gomuks   CALL  close(10)
  52627 gomuks   RET   close 0
  52627 gomuks   CALL  open(0xc00055e090,0x10202<O_RDWR|O_CREAT|O_CLOEXEC>,0600<S_IRUSR|S_IWUSR>)
  52627 gomuks   NAMI  "/home/sdk/.cache/gomuks/history.db"
  52627 gomuks   RET   open 10/0xa
  52627 gomuks   CALL  fstat(10,0xc0004ecb58)
  52627 gomuks   STRU  struct stat { dev=1054, ino=17304613, mode=-rw------- , nlink=1, uid=1000<"sdk">, gid=1000<"sdk">, rdev=69176856, atime=1701153179<"No v 28 07:32:59 2023">.316222194, mtime=1701153495<"Nov 28 07:38:15 2023">.126055608, ctime=1701153495<"Nov 28 07:38:15 2023">.126055608, size=27115520, block s=53120, blksize=65536, flags=0x0, gen=0x0 }
  52627 gomuks   RET   fstat 0
  52627 gomuks   CALL  flock(10,0x6<LOCK_EX|LOCK_NB>)
  52627 gomuks   RET   flock -1 errno 35 Resource temporarily unavailable
  52627 gomuks   CALL  flock(10,0x8<LOCK_UN>)
  52627 gomuks   RET   flock 0
  52627 gomuks   CALL  close(10)
  52627 gomuks   RET   close 0
  52627 gomuks   CALL  write(3,0xc00002e500,0x16)
  52627 gomuks   GIO   fd 3 wrote 22 bytes
        "[2023-11-28 07:38:15] "
  52627 gomuks   RET   write 22/0x16
  52627 gomuks   CALL  write(3,0xc00002e500,0x32)
  52627 gomuks   GIO   fd 3 wrote 50 bytes
*       "Init error: failed to initialize history: timeout
        "

Is gomuks trying to lock the database twice?

EDIT: I'm seeing a close() before the next open(), which should remove the lock. Yet it looks like the second flock is unsuccessful.

[c0dev0id]

It didn't happened in a while, so I close the issue again...

[mcepl]

Got the same, with gomuks 0.3.0 on openSUSE/Tumbleweed.