Hi all,
one of the problems when debugging PCU issues is: How to take proper logs on-site where a problem shows up and give them back to the developer(s) for analysis. If you capture the PCU stdout or configure file-based logging, you will have a hard time corellating that with PCAP traces taken on the RLC/MAC side and/or on the Gb side.
Therefore I propose a new idea here and would like to get your review:
What about implementing a "GSMTAP" log target for libosmocore? This way we could encapsulate the log messages into a special GSMTAP message, which would be sent synchronously in the GSMTAP stream together with RLC/MAC messages on the lower end.
The same could in fact be utilized in osmo-bts, too. This way we could capture BTS log/debug output in-order to L1 messages that we receive and transmit.
What do you think about it? I would be willing to draft the GSMTAP sub-header format and write + submit the wireshark dissector, if somebody wants to write libosmocore log target.
Ideally we would log _all_ messages to that target, and include the subsystem and log level in a header field, so the log verbosity could still be adjusted at the point of review, instead only at the time of logging.
Regards, Harald
Hi Harald,
On Tue, Jan 29, 2013 at 2:22 PM, Harald Welte laforge@gnumonks.org wrote:
one of the problems when debugging PCU issues is: How to take proper logs on-site where a problem shows up and give them back to the developer(s) for analysis. If you capture the PCU stdout or configure file-based logging, you will have a hard time corellating that with PCAP traces taken on the RLC/MAC side and/or on the Gb side.
Therefore I propose a new idea here and would like to get your review:
What about implementing a "GSMTAP" log target for libosmocore? This way we could encapsulate the log messages into a special GSMTAP message, which would be sent synchronously in the GSMTAP stream together with RLC/MAC messages on the lower end.
Yes, debugging PCU is PITA and we've been discussing logging improvements with Ivan for some time already. From our discussions it seems that the biggest issue is to correlate log messages with the actual user and/or session. How do you want to solve this issue with the GSMTAP?
PS In general, the proposal to use GSMTAP is ... interesting. :)
-- Regards, Alexander Chemeris. CEO, Fairwaves LLC / ООО УмРадио http://fairwaves.ru
Hi Alexander,
On Tue, Jan 29, 2013 at 04:11:26PM +0400, Alexander Chemeris wrote:
Yes, debugging PCU is PITA and we've been discussing logging improvements with Ivan for some time already. From our discussions it seems that the biggest issue is to correlate log messages with the actual user and/or session. How do you want to solve this issue with the GSMTAP?
I would treat those two independent. The case for GSMTAP is simply to have a synchronous / monotonic log (pcap in this case) that combines both actual packets on Gb and Um, as well as the human-readable log messages generated by the PCU code in between.
As for the human-readable PCU log messages, I would suggest something like pre-fixing all of them with the TLLI in the beginning like [1a2b3d4e] at the start of every line. I would guess that for most of the log messages, the TLLI to which they relate should be known. The same is not the case for other identifiers like the IMSI.
On Tue, Jan 29, 2013 at 4:33 PM, Harald Welte laforge@gnumonks.org wrote:
Hi Alexander,
On Tue, Jan 29, 2013 at 04:11:26PM +0400, Alexander Chemeris wrote:
Yes, debugging PCU is PITA and we've been discussing logging improvements with Ivan for some time already. From our discussions it seems that the biggest issue is to correlate log messages with the actual user and/or session. How do you want to solve this issue with the GSMTAP?
I would treat those two independent. The case for GSMTAP is simply to have a synchronous / monotonic log (pcap in this case) that combines both actual packets on Gb and Um, as well as the human-readable log messages generated by the PCU code in between.
Just to clarify. Do you just want to transfer a normal log string as a payload in a GSMTAP message, so that it'll be shown in Wireshark "Info" column?
As for the human-readable PCU log messages, I would suggest something like pre-fixing all of them with the TLLI in the beginning like [1a2b3d4e] at the start of every line. I would guess that for most of the log messages, the TLLI to which they relate should be known. The same is not the case for other identifiers like the IMSI.
I'll let Ivan comment on that. My knowledge is somewhat lacking in this area.
-- Regards, Alexander Chemeris. CEO, Fairwaves LLC / ООО УмРадио http://fairwaves.ru
On Tue, Jan 29, 2013 at 04:37:38PM +0400, Alexander Chemeris wrote:
I would treat those two independent. The case for GSMTAP is simply to have a synchronous / monotonic log (pcap in this case) that combines both actual packets on Gb and Um, as well as the human-readable log messages generated by the PCU code in between.
Just to clarify. Do you just want to transfer a normal log string as a payload in a GSMTAP message, so that it'll be shown in Wireshark "Info" column?
yes.
Hi all,
Yes, I actually have many problems when debugging PCU too, so I think that using GSMTAP is good solution, because it is fast solution, and it will be really helpful. About human-readable PCU log messages, I think that using prefixes is normal, but we should use TFI+TLLI for prefix, because especially for PCU debugging it is very important to have ability to control particular TBF.
2013/1/29 Harald Welte laforge@gnumonks.org:
On Tue, Jan 29, 2013 at 04:37:38PM +0400, Alexander Chemeris wrote:
I would treat those two independent. The case for GSMTAP is simply to have a synchronous / monotonic log (pcap in this case) that combines both actual packets on Gb and Um, as well as the human-readable log messages generated by the PCU code in between.
Just to clarify. Do you just want to transfer a normal log string as a payload in a GSMTAP message, so that it'll be shown in Wireshark "Info" column?
yes.
--
- Harald Welte laforge@gnumonks.org http://laforge.gnumonks.org/
============================================================================ "Privacy in residential applications is a desirable marketing option." (ETSI EN 300 175-7 Ch. A6)
Harald Welte wrote:
What about implementing a "GSMTAP" log target for libosmocore? This way we could encapsulate the log messages into a special GSMTAP message, which would be sent synchronously in the GSMTAP stream together with RLC/MAC messages on the lower end.
it would be nice, if the "GSMTAP" target is supported by all projects that generate gsmtap, like osmocom-bb, openbsc, ...
as you said, the target should have header fields for logging catergory and level, so one can filter individually. there should be also a field which flags the logging messages that are actually displayed on the screen (filtered by the application), so one does not need to select the same filter in wireshark again.
i doubt that wireshark supports colors, so i suggest to prefix the logging catergory in the summary (the list of packets shown in the upper part of wireshark's window) like this: ".... [DRLCMAC] gprs_rlcmac_data.cpp:100 [<tlli>] Poll timeout for DL TBF=0".
Hi Jolly,
On Wed, Jan 30, 2013 at 07:57:54AM +0100, jolly wrote:
as you said, the target should have header fields for logging catergory and level, so one can filter individually. there should be also a field which flags the logging messages that are actually displayed on the screen (filtered by the application), so one does not need to select the same filter in wireshark again.
good idea. yes, there should be a 'visible' flag, indeed.
i doubt that wireshark supports colors,
it supports coloring, but the normal use case is to allow the user to specify coloring rules. They are actually very useful, e.g. for automatically displaying uplink messages with a different color compared to downlink messages. If you're not familiar with that feature yet, I recommend to try it.
I don't yet know if a dissector plugin could overload the colors. It might be possible. But even if it is, I think it should be a preference of the gsmtap-log dissector, as e.g. yellow on white background doens't look nearly as well as the yellow-on-black we use on the terminal/console output...
so i suggest to prefix the logging catergory in the summary (the list of packets shown in the upper part of wireshark's window) like this: ".... [DRLCMAC] gprs_rlcmac_data.cpp:100 [<tlli>] Poll timeout for DL TBF=0".
I was actually thinking of representing the category, filename and line number as separate "fields" in wireshark. This way, you can (or can not) add them as separate columns to your list of packtes in wireshark.
I've hacked up most of the required libosmocore code, although the separation of filename/line-number needs some modifications to the current logging architecture (where the string-printing is done in the core and the plugins only get the final result as opposed to the input).
Regards, Harald
osmocom-net-gprs@lists.osmocom.org
-
Alexander Chemeris -
Harald Welte -
Ivan Kluchnikov -
jolly