Feature #5032
closed
Add VTY option to write TID in log line prefix
Added by pespin about 3 years ago.
Updated about 3 years ago.
Description
Similar to other options to prefix log lines with several information, it would be nice having some generic integrated way to log TID on each line, to ease debug and udnerstanding of multi-threaded processes.
A command under "logging ..." node, something like: "logging print tid (0|1)", which would be disabled by default.
This can easily be implemented now that we have "osmo_gettid()" API (see #5027).
We could even have an internal __thread variable with some osmo_gettid_cached() internal API which would fill the __thread variable if it is == 0, in order to avoid calling gettid() and potentially issuing a syscall everytime.
See as an example:
https://gerrit.osmocom.org/c/libosmocore/+/22952 logging: gsmtap: Store TID instead of PID in pkt hdr
- Related to Bug #5027: logging_gsmtap.c code not filling PID field in pkt header added
Submitted here:
https://gerrit.osmocom.org/c/libosmocore/+/22960 logging: Allow prefixing thread ID to each log line
I tested it with osmo-trx-uhd and it looks good (see second column):
20210218183349610 445807 DLGLOBAL <0008> cpu_sched_vty.c:470 Setting SCHED_RR priority 18
20210218183349610 445807 DLGLOBAL <0008> telnet_interface.c:104 Available via telnet 127.0.0.1 4237
20210218183349610 445807 DLCTRL <000f> control_if.c:916 CTRL at 127.0.0.1 4236
20210218183349610 445807 DMAIN <0000> osmo-trx.cpp:495 SSE3 support compiled in and supported by CPU
20210218183349610 445807 DMAIN <0000> osmo-trx.cpp:507 SSE4.1 support compiled in and supported by CPU
20210218183349610 445807 DMAIN <0000> osmo-trx.cpp:561 [tid=140304886954240] Config Settings
Log Level............... 0
Device args............. type=b200
TRX Base Port........... 5700
TRX Address............. 192.168.30.100
GSM BTS Address......... 192.168.30.1
Channels................ 1
Tx Samples-per-Symbol... 4
Rx Samples-per-Symbol... 4
EDGE support............ 1
Extended RACH support... 0
Reference............... 0
Filler Burst Type....... Empty bursts
Filler Burst TSC........ 0
Filler Burst RACH Delay. 0
Multi-Carrier........... 1
Tuning offset........... 0
RSSI to dBm offset...... 0 (relative)
Swap channels........... 0
Tx Antennas............. '<default>'
Rx Antennas............. '<default>'
20210218183349610 445807 DLGLOBAL <0008> rate_ctr.c:87 validating counter group 0x555fc07a90a0(trx:chan) with 14 counters
20210218183349611 445807 DDEV <0005> UHDDevice.cpp:175 [tid=140304886954240] Multi-ARFCN: 1 logical chans -> 1 physical chans
[INFO] [UHD] linux; GNU C++ version 10.2.0; Boost_107500; UHD_4.0.0.0-0-unknown
20210218183349644 445808 DDEVDRV <0006> b200_iface.cpp:219 [tid=140304830166592] [B200] Loading firmware image: /usr/share/uhd/images/usrp_b200_fw.hex...
20210218183351696 445807 DDEV <0005> UHDDevice.cpp:571 [tid=140304886954240] Using discovered UHD device type=b200,name=MyB200,serial=3166C0B,product=B200
20210218183351895 445808 DDEVDRV <0006> b200_impl.cpp:420 [tid=140304830166592] [B200] Detected Device: B200
20210218183351960 445808 DDEVDRV <0006> b200_iface.cpp:565 [tid=140304830166592] [B200] Loading FPGA image: /usr/share/uhd/images/usrp_b200_fpga.bin...
20210218183401463 445808 DDEVDRV <0006> b200_impl.cpp:467 [tid=140304830166592] [B200] Operating over USB 3.
20210218183401476 445808 DDEVDRV <0006> b200_impl.cpp:522 [tid=140304830166592] [B200] Detecting internal GPSDO....
20210218183402277 445808 DDEVDRV <0006> gps_ctrl.cpp:243 [tid=140304830166592] [GPS] No GPSDO found
20210218183402289 445808 DDEVDRV <0006> b200_impl.cpp:618 [tid=140304830166592] [B200] Initialize CODEC control...
20210218183402591 445808 DDEVDRV <0006> b200_impl.cpp:687 [tid=140304830166592] [B200] Initialize Radio control...
20210218183402632 445808 DDEVDRV <0006> b200_impl.cpp:1100 [tid=140304830166592] [B200] Performing register loopback test...
20210218183402652 445808 DDEVDRV <0006> b200_impl.cpp:1109 [tid=140304830166592] [B200] Register loopback test passed
20210218183402685 445808 DDEVDRV <0006> b200_impl.cpp:815 [tid=140304830166592] [B200] Setting master clock rate selection to 'automatic'.
20210218183402685 445808 DDEVDRV <0006> b200_impl.cpp:1150 [tid=140304830166592] [B200] Asking for clock rate 16.000000 MHz...
20210218183403011 445808 DDEVDRV <0006> b200_impl.cpp:1163 [tid=140304830166592] [B200] Actually got clock rate 16.000000 MHz.
20210218183403172 445807 DMAIN <0000> UHDDevice.cpp:222 [tid=140304886954240] Antennas configured successfully
20210218183403180 445808 DDEVDRV <0006> multi_usrp.cpp:504 [tid=140304830166592] [MULTI_USRP] Setting master clock rate selection to 'manual'.
20210218183403180 445808 DDEVDRV <0006> b200_impl.cpp:1150 [tid=140304830166592] [B200] Asking for clock rate 51.200000 MHz...
20210218183403392 445808 DDEVDRV <0006> b200_impl.cpp:1163 [tid=140304830166592] [B200] Actually got clock rate 51.200000 MHz.
20210218183403494 445807 DDEV <0005> UHDDevice.cpp:345 [tid=140304886954240] Rates configured for B200/B210 4 SPS Multi-ARFCN
20210218183403543 445807 DDEV <0005> UHDDevice.cpp:305 [tid=140304886954240] Supported Tx gain range [0; 89.75]
20210218183403543 445807 DDEV <0005> UHDDevice.cpp:310 [tid=140304886954240] Supported Rx gain range [0; 76]
20210218183403543 445807 DDEV <0005> UHDDevice.cpp:314 [tid=140304886954240] Default setting Tx gain for channel 0 to 44.875
20210218183403543 445807 DDEV <0005> UHDDevice.cpp:321 [tid=140304886954240] Default setting Rx gain for channel 0 to 38
20210218183403544 445807 DDEV <0005> UHDDevice.cpp:670 [tid=140304886954240] Device configuration: Single USRP:
Device: B-Series Device
Mboard 0: B200
RX Channel: 0
RX DSP: 0
RX Dboard: A
RX Subdev: FE-RX1
TX Channel: 0
TX DSP: 0
TX Dboard: A
TX Subdev: FE-TX1
20210218183403561 445807 DMAIN <0000> osmo-trx.cpp:609 [tid=140304886954240] -- Transceiver active with 1 channel(s)
20210218183403561 445807 DLSTATS <0011> stats.c:160 Stats timer expire_count=3: We missed 2 timers
- Status changed from New to Feedback
- Assignee set to pespin
- % Done changed from 0 to 80
The tid=... stuff from osmo-trx is actually printing the pthread related struct, which shouldn't be printed as an integer because specs don't even guarantee that's an integer. Specs says it's an opaque structure.
So, once the libosmocore patch is merged, I will remove those tid=... printings from osmo-trx.
- Category set to libosmocore
pespin, I think this has been fully implemented by now, right?
- Status changed from Feedback to Resolved
- % Done changed from 80 to 100
Also available in: Atom
PDF
