Project

General

Profile

Actions

Bug #5328

closed

log_file_msg related memory leak

Added by laforge 11 days ago. Updated 8 days ago.

Status:
Resolved
Priority:
Urgent
Assignee:
Category:
-
Target version:
-
Start date:
11/25/2021
Due date:
% Done:

100%

Spec Reference:

Description

After running osmo-bts-trx some 24 hours and then issuing a SIGUSR1, I get tons of talloc reports about log_file_ms:

                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x6210014e2560
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x6210014e3960
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x6210014e4d60
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x6210014e6160
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x6210014e8960
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x6210014e9d60
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x6210014eb160
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x6210014ec560
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x6210014ed960
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x6210014f0160
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x6210014f1560
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x6210014f3d60                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621005e5b160
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621005e59d60
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621005e58960
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621005e57560
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621005e56160
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621005e54d60
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621005e53960
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621005e52560
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621005e51160
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621005e4fd60
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621005e4d560
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621005e4c160
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621005e4ad60
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621005e49960
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621005e48560
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621005e47160
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621005e45d60
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621005e44960
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621005e43560
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621005e42160
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621005e40d60
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621005e3f960
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621005e3d160
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621005e3bd60
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621005e3a960
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621005e39560
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621005e38160
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621005e36d60
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621005e35960
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621005e34560
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621005e33160
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621005e31d60
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621005e30960
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621005e2f560
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621005e2cd60
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621005e2b960                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621005373d60
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621005372960
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621005371560
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621005370160
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x62100529e160
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x6210052ae560
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x6210052be960
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x6210052ced60
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x6210052ee160
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x6210052fe560
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x62100530e960
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x62100531ed60
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x62100533e160
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x62100534e560
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x62100535e960
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x62100536ed60
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x62100536d960
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x62100536c560
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x62100536b160
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621005369d60
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621005368960
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621005367560
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621005366160
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621005364d60
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x6210048ae560
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x6210048be960
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x6210048ced60
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x6210048ee160
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x6210048fe560
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x62100490e960
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x62100491ed60
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x62100491d960
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x62100491c560
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x62100491b160
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621004919d60
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621004918960
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621004917560
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621004916160
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621004914d60
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621004913960                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621004868560
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621004867160
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621004865d60
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621004864960
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621004863560
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621004862160
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621004860d60
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x62100485f960
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x62100485d160
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x62100485bd60
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x62100485a960
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621004859560
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621004858160
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621004856d60
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621004855960
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621004854560
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621004853160
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621004851d60
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621004850960
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x62100484f560
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x62100484cd60
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621003e60d60
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621003e5f960
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621003e5d160
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621003e5bd60
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621003e5a960
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621003e59560
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621003e58160
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621003e56d60
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621003e55960
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621003e54560
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621003e53160
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621003e51d60
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621003e50960
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621003e4f560
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621003e4cd60                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621001da3960
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621001da2560
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621001da1160
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621001d9fd60
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621001d9d560
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621001d9c160
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621001d9ad60
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621001d99960
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621001d98560
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621001d97160
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621001d95d60
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621001d94960
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621001d93560
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621001d92160
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621001d90d60
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621001d8f960
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621001d8d160
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621001d8bd60
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621001d8a960
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621001d89560
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621001d88160
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621001d86d60
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621001d85960
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621001d84560
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621001d83160
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621001d81d60
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621001d80960
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621001d7f560
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621001d7cd60
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621001d7b960
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621001d7a560
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621001d79160
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621001d77d60
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621001d76960
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621001d75560
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621001d74160
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621001d72d60
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621001d71960
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621001d70560
                log_file_msg                   contains   4232 bytes in   1 blocks (ref 0) 0x621001d6f16

I'm wondering why nobody has seend this so far. I've not been doing much develpment in recent months, but I would expect everyone would call SIGUSR1 every so often and look at suspicious leaks?


Related issues

Related to libosmocore - Bug #5329: osmo_wqueue_enqueue*() doesn't msgb_free in case enqueing failsResolvedlaforge11/25/2021

Actions
Actions #1

Updated by laforge 11 days ago

so

  • allocation happens in _file_raw_output()
  • if the queue is empty, we immediately try to print the message
    • if it succeeds, we call msgb_free(msg)
    • if it fails, or there is already a backlog, we enqueue
  • osmo_wqueue_enqueue_quiet() doesn't call msgb_free() in case the queue is full, and we don't check the return value!
Actions #2

Updated by laforge 11 days ago

  • Related to Bug #5329: osmo_wqueue_enqueue*() doesn't msgb_free in case enqueing fails added
Actions #3

Updated by laforge 11 days ago

https://gerrit.osmocom.org/c/libosmocore/+/26360 should fix at least one leak (I currently cannot see other leaky code paths)

Actions #4

Updated by laforge 11 days ago

Actions #5

Updated by laforge 11 days ago

  • Status changed from New to Resolved
  • % Done changed from 0 to 100
Actions #6

Updated by fixeria 8 days ago

I'm wondering why nobody has seend this so far. I've not been doing much develpment in recent months, but I would expect everyone would call SIGUSR1 every so often and look at suspicious leaks?

Personally I rarely send SIGUSR1 during development. Mostly when I know for sure that there is a memleak, but still the VTY's talloc introspection commands are much more useful. Sometimes I rely on talloc reports printed by osmo-apps on exit, but this works only in a few projects.

As a quick solution I propose this approach to facilitate detecting memleaks:

https://gerrit.osmocom.org/c/docker-playground/+/26408 ttcn3-*-test/jenkins.sh: write the SUT's PID to /tmp/sut.pid [NEW]
https://gerrit.osmocom.org/c/osmo-ttcn3-hacks/+/26407 ttcn3-tcpdump-stop.sh: order the SUT to print talloc report [NEW]

TL;DR this makes the SUT write talloc reports to stderr when a test case execution is finished. A potential improvement is to write talloc reports into separate files matching the test case name, but I don't have a quick solution for this. Can be implemented later, in addition or as a replacement for this approach.

Actions

Also available in: Atom PDF

Add picture from clipboard (Maximum size: 48.8 MB)