- 12 Dec, 2022 12 commits
-
-
Kirill Smelkov authored
Add JupyterLab notebook that shows how to build KPI-computing pipeline and to compute the KPIs. The notebook comes with extensive comments describing every step. Please see those comments for details.
-
Kirill Smelkov authored
Add demo program that shows how to build KPI-computing pipeline and to compute the KPIs. It can be used e.g. as follows: $ ./demo/kpidemo.py 60 https://lab.nexedi.com/kirr/misc/raw/162307b9/lte/20221211-overload.xlog The program comes with extensive comments describing every step. Please see those comments for details. The next patch will also add analogous JupyterLab notebook.
-
Kirill Smelkov authored
kpi.Calc is calculator to compute KPIs. It can be instantiated on MeasurementLog and time interval over which to perform computations. It currently implements calculations for only one "E-RAB Accessibility KPI". Please see added docstrings and tests for details. The next patch will also add demo program that uses all kpi.Calc and other parts of KPI-computation pipeline to build and visualize E-RAB Accessibility from real data.
-
Kirill Smelkov authored
amari.kpi: New package with driver for Amarisoft LTE stack to retrieve KPI-related measurements from logs amari.kpi provides LogMeasure that takes enb.xlog (TODO and enb.log) as input, and produces kpi.Measurements on output. enb.xlog ───────── ─────────> │ Log │ │ │ ────> []kpi.Measurement ─────────> │ Measure │ enb.log ───────── We read log data organizing periods around stats queries, and for now we build Measurement from stats' counters. To do so we take δ(stats_prev, stat) and process it mapping Amarisoft counters to 3GPP ones specified by kpi.Measurement. We emit measurement X after reading stats X+2 - i.e. we emit measurement for a period after reading data covering _next_ period. It is organized this way to account for init/fini correction: fini adjust ------------- ' ' Sx v Sx+1 ' Sx+2 ────|───────────|───────────|──── Measurement Measurement X X+1 This approach has following limitations: - for most of the counters there is no direct mapping in between Amarisoft and 3GPP. For example we currently use s1_erab_setup_request for ERAB.EstabAddAtt.sum, but this mapping is not strictly correct and will break if corresponding S1 E-RAB SETUP REQUEST message contains multiple ERABs. The code has corresponding FIXME marks where such approximations are used. - it is not possible to implement init/fini correction precisely. From aggregated statistics we only get total amount for a fini value for a period - without knowing which part of it corresponds to init events from previous period, and which part to init events from current one. With that it is only possible to make a reasonable guess and try to preserve statistical properties, but not more. See m_initfini in the code for details. - it is possible to handle eNB with single cell only. This limitation comes from the fact that in Amarisoft LTE stack S1-related counters come as "globals" ones, while e.g. RRC-related counters are "per-cell". It is thus not possible to see how much S1 connection establishments are associated with one particular cell if there are several of them. TODO also parse enb.log to fix those issues.
-
Kirill Smelkov authored
xlog.Reader could be used to parse and read back data previously saved by xlog. In the next patch we will use it in Amarisoft driver for KPI measurements.
-
Kirill Smelkov authored
Start the package to process measurements and compute KPIs from them. In this patch we add kpi.Measurement - a central part to represent measurement results in intermediate generic form. kpi.Measurement will be used by both KPI calculator, and by drivers for particular LTE stacks to provide their KPI-related data in this uniform common format. kpi.Measurement also establishes semantic for such measurement results to be followed by drivers. The semantic is stated in kpi.Measurement docstring and in comment for every field. Also in particular, according to TS 32.401 and common sense, measurement data are required to be correctly accounted for initiation/termination events to avoid discrepancies. Quoting kpi.Measurement documentation: Important note (init/fini correction): Termination events should be counted in the same granularity period, where corresponding initiation event occurred, even if termination event happens _after_ granularity period covering the initiation event. For example in the following illustration "ConnEstab Success" event should be counted in the same granularity period 1 as "ConnEstab Initiate" event: ----------------------- ' ' | p e r ' i o d 1 | p e r ' i o d 2 | | ' | v | ────'───────x───────────────'───────x────────────'────────────> ConnEstab ConnEstab time Initiate Success This preserves invariant that N(initiations) is always ≥ N(results) and goes in line with what TS 32.401 4.3.2 "Perceived accuracy -> Same period for the same two events" requires. kpi.Measurement comes accompanied by kpi.MeasurementLog which in essence is array of kpi.Measurements. We will use kpi.Measurement and kpi.MeasurementLog in later patches to both provide Amarisoft-specific data in this common format, and to compute KPIs from it.
-
Kirill Smelkov authored
-
Kirill Smelkov authored
Upon rotation we want to emit trailing part to the old file, and emit new header into new log file. All this is custom and cannot be handled reliably when rotation is done by external tool.
-
Kirill Smelkov authored
Document kind of messages and events that could be emitted by xlog. The messages come from Amarisoft software directly, but events are xlog-specific and without proper documentation it is easy to miss what they are and which information and semantic they carry.
-
Kirill Smelkov authored
The time emitted in messages by Amarisoft is in seconds. It also makes sense to emit meta/event times in seconds as well for uniformity. This is backward-incompatible change, but it should be ok at this early time.
-
Kirill Smelkov authored
xlog logging is kind of slow - usually it comes once per several seconds or once per minute. And without flushing many entries can remain sitting up in the file buffer in userspace without being conveyed to OS kernel. Which is not very convenient because in such situation we cannot make good use of tools like `tail -f`. Since flushing is relatively cheap operation - it is just one write syscall - let's do it after every emitted line. The write syscall does not force data to be synced to disk, so it should not slow things down, but make it convenient to have latest logs right away in the filesystem view.
-
Kirill Smelkov authored
Conn multiplexes many requests/responses over single WebSocket connection. To do so it organizes dedicated receive thread that continuously receives messages from underlying websocket connection and dispatches received replies back to threads that issued corresponding requests. An rx timeout in that receive thread is thus not something unexpected - it can happen e.g. if there is simply no requests sent. But I missed that in 61ad9032 (amari: Add functionality to interoperate with an Amarisoft LTE service via WebSocket) and implicitly did not ignored such global rx timeout. As the result `amari xlog` does not work properly if period of requests is greater than timeout value, for example: $ xamari xlog ws://localhost:9001 ue_get/30s {"meta": {"event": "start", "time": 1670588996.0623107, "generator": "xlog ws://localhost:9001 ue_get[]/30.0s"}} {"meta": {"event": "service attach", "time": 1670588996.1852894, "srv_name": "ENB", "srv_type": "ENB", "srv_version": "2022-12-01"}} {"message":"config_get", ...} note {"message":"ue_get","ue_list":[],"message_id":2,"time":3045.323,"utc":1670588996.423} ----> {"meta": {"event": "service detach", "time": 1670589026.3569217, "srv_name": "ENB", "srv_type": "ENB", "srv_version": "2022-12-01", "reason": "timed out"}} {"meta": {"event": "service attach", "time": 1670589029.485363, "srv_name": "ENB", "srv_type": "ENB", "srv_version": "2022-12-01"}} {"message":"config_get", ...} {"message":"ue_get","ue_list":[],"message_id":2,"time":3078.606,"utc":1670589029.706} ... -> Fix it by ignoring global rx timeout. NOTE: we must also add manual handling of per-request timeout when waiting for corresponding reply. If we don't do that a situation where particular reply does not come back, but replies for other requests are coming back ok, will never be detected. Here is how fixed version works now: $ xamari xlog ws://localhost:9001 ue_get/30s {"meta": {"event": "start", "time": 1670589223.0339117, "generator": "xlog ws://localhost:9001 ue_get[]/30.0s"}} {"meta": {"event": "service attach", "time": 1670589223.1970558, "srv_name": "ENB", "srv_type": "ENB", "srv_version": "2022-12-01"}} {"message":"config_get", ...} {"message":"ue_get","ue_list":[],"message_id":2,"time":3272.292,"utc":1670589223.391} {"message":"ue_get","ue_list":[],"message_id":3,"time":3302.274,"utc":1670589253.373} {"message":"ue_get","ue_list":[],"message_id":4,"time":3332.266,"utc":1670589283.365} ... Note that ue_get messages are coming sequentially and there is no "service detach" event, that was artificially popping up due to wrong timeout handling.
-
- 02 Nov, 2022 1 commit
-
-
Kirill Smelkov authored
For example with `stats/100s` stats query is emitted every 100 seconds, but currently it will be first emitted only after waiting for 100 seconds after `xamari xlog` startup, or after reconnection to eNB if eNB itself was restarted. And this way it will be hard to interpret obtained numbers in relation to last 100s time interval. -> Start emitting queries right after reconnection / xlog start, so that we see the values as observed at the beginning, and can compare result of further queries to them.
-
- 19 Oct, 2022 7 commits
-
-
Kirill Smelkov authored
`xamari xlog` can be used to maintin extra log for an Amarisoft LTE service: in addition to native logs, xlog contains results of periodic queries done via WebSocket. For example with the following aguments xamari xlog <wsuri> stats/10s ue_get/3s erab_get/3s xlog will emit results of stats query - every 10 seconds, results from ue_get query - every 3 seconds, and similarly for erab_get query. The results are saved into xlog in JSON Lines format for easy future processing. For the reference below is a copy of corresponding help entries: xlte$ xamari help xlog Usage: xamari xlog [OPTIONS] <wsuri> <logspec>+ Maintain extra log for a service. The service is queried periodically according to logspec and results are saved in JSON format to a file (see 'xamari help jsonlog'). <wsuri> is URI (see 'xamari help websock') of an Amarisoft-service. <logspec> is specification of what to log. It has the following parts: <query>[<options>]/<period> The query specifies a message, that should be used to query service. For example "stats", "ue_get", "erab_get", ... Query part is mandatory. Options specifies additional flags for the query. Options part can be omitted. Period specifies periodicity of how often the service should be queried. Period is optional and defaults to 60 seconds. Example for <logspec>+: stats[samples,rf]/30s ue_get[stats] erab_get/10s qos_flow_get Options: -h --help show this help xlte$ xamari help jsonlog Some commands produce logs with JSON entries. Such logs are organized with JSON Lines format(*) with each entry occupying one line. Logs in JSON Lines format are handy to exchange in between programs, and with corresponding tools, e.g. jq(+), they can be also displayed in human-readable form and inspected quickly. (*) https://jsonlines.org/ (+) https://stedolan.github.io/jq/ Example output: (xlte3.venv) kirr@deca:~/src/wendelin/xlte$ xamari xlog ws://localhost:9001 ue_get/3s erab_get/3s {"meta": {"event": "start", "time": "Wed, 19 Oct 2022 15:05:50 -0000", "generator": "xlog ws://localhost:9001 ue_get[]/3.0s erab_get[]/3.0s"}} {"meta": {"event": "service attach", "time": "Wed, 19 Oct 2022 15:05:51 -0000", "srv_name": "ENB", "srv_type": "ENB", "srv_version": "2022-09-16"}} {"message":"config_get","version":"2022-09-16","type":"ENB","name":"ENB","license_id":"d9a961c166d2d4b15249fc559cdec925efbbe942d73b143aff","license_user":"rapid.space","logs":{"layers":{"PHY":{"level":"error","max_size":0,"key":false,"crypto":false,"payload":false},"MAC":{"level":"error","max_size":0,"key":false,"crypto":false,"payload":false},"RLC":{"level":"error","max_size":0,"key":false,"crypto":false,"payload":false},"PDCP":{"level":"error","max_size":0,"key":false,"crypto":false,"payload":false},"RRC":{"level":"debug","max_size":1,"key":false,"crypto":false,"payload":false},"NAS":{"level":"debug","max_size":1,"key":false,"crypto":false,"payload":false},"S1AP":{"level":"debug","max_size":1,"key":false,"crypto":false,"payload":false},"NGAP":{"level":"error","max_size":0,"key":false,"crypto":false,"payload":false},"GTPU":{"level":"error","max_size":0,"key":false,"crypto":false,"payload":false},"X2AP":{"level":"debug","max_size":1,"key":false,"crypto":false,"payload":false},"XnAP":{"level":"error","max_size":0,"key":false,"crypto":false,"payload":false},"M2AP":{"level":"error","max_size":0,"key":false,"crypto":false,"payload":false},"LPPa":{"level":"error","max_size":0,"key":false,"crypto":false,"payload":false},"NRPPa":{"level":"error","max_size":0,"key":false,"crypto":false,"payload":false},"TRX":{"level":"error","max_size":0,"key":false,"crypto":false,"payload":false}},"bcch":false,"mib":false,"signal":false,"cch":false,"rep":false,"dci_size":false,"csi":false,"cell_meas":false,"count":8192,"rotate":250000000,"path":"/var/log/lte"},"tai":9610.092,"global_enb_id":{"plmn":"00101","enb_id_type":"macro","enb_id":107216,"enb_name":"enb1a2d0"},"cells":{"1":{"n_antenna_dl":2,"n_antenna_ul":2,"n_layer_dl":2,"n_layer_ul":1,"gain":0,"ul_disabled":false,"rf_port":0,"dl_qam":256,"ul_qam":64,"ecgi":{"plmn":"00101","eci":27447297},"n_id_cell":1,"n_rb_dl":100,"n_rb_ul":100,"dl_earfcn":38350,"ul_earfcn":38350,"band":39,"dl_freq":1890000000,"ul_freq":1890000000,"mode":"TDD","uldl_config":2,"sp_config":7,"prach_sequence_index":204,"dl_cyclic_prefix":"normal","ul_cyclic_prefix":"normal","prach_config_index":4,"prach_freq_offset":11,"delta_pucch_shift":2,"n_rb_cqi":1,"n_cs_an":0,"pucch_allocation":[{"type":"2/2a/2b","rbs":1,"n":6}],"pucch_ack_nack_start":11,"pucch_reserved_rbs":[0,0,22,0,0,0,0,22,0,0],"sr_resource_count":44,"cqi_resource_count":48,"srs_resources":{"offsets":16,"freqs":20,"total":640},"gbr":{"dl_limit":7123840,"ul_limit":1797120},"tac":1,"plmn_list":[{"plmn":"00101","reserved":false}]}},"rx_channels":[{"gain":9,"freq":1890,"port":0},{"gain":9,"freq":1890,"port":0}],"tx_channels":[{"gain":60,"freq":1890,"port":0},{"gain":60,"freq":1890,"port":0}],"rf_ports":[{"sample_rate":30720000}],"message_id":1,"time":9610.087} {"message":"ue_get","ue_list":[],"message_id":2,"time":9613.347} {"message":"erab_get","erab_list":[],"timestamp":9613704,"message_id":3,"time":9613.704} {"message":"ue_get","ue_list":[],"message_id":4,"time":9616.355} {"message":"erab_get","erab_list":[],"timestamp":9616618,"message_id":5,"time":9616.618} {"message":"ue_get","ue_list":[],"message_id":6,"time":9619.272} {"message":"erab_get","erab_list":[],"timestamp":9619547,"message_id":7,"time":9619.547} {"message":"ue_get","ue_list":[],"message_id":8,"time":9622.319} {"message":"erab_get","erab_list":[],"timestamp":9622588,"message_id":9,"time":9622.588} {"message":"ue_get","ue_list":[],"message_id":10,"time":9625.263} {"message":"erab_get","erab_list":[],"timestamp":9625663,"message_id":11,"time":9625.663} {"message":"ue_get","ue_list":[],"message_id":12,"time":9628.403} {"message":"erab_get","erab_list":[],"timestamp":9628725,"message_id":13,"time":9628.725} {"message":"ue_get","ue_list":[],"message_id":14,"time":9631.381} {"message":"erab_get","erab_list":[],"timestamp":9631798,"message_id":15,"time":9631.798} {"message":"ue_get","ue_list":[],"message_id":16,"time":9634.303} {"message":"erab_get","erab_list":[],"timestamp":9634596,"message_id":17,"time":9634.596} {"message":"ue_get","ue_list":[],"message_id":18,"time":9637.268} {"message":"erab_get","erab_list":[],"timestamp":9637568,"message_id":19,"time":9637.568} (below an UE registers with eNB) {"message":"ue_get","ue_list":[{"enb_ue_id":8,"mme_ue_id":107,"rnti":68,"cells":[{"cell_id":1}]}],"message_id":20,"time":9640.296} {"message":"erab_get","erab_list":[{"erab_id":5,"qci":9,"dl_total_bytes":0,"ul_total_bytes":0,"enb_ue_id":8}],"timestamp":9640831,"message_id":21,"time":9640.831} {"message":"ue_get","ue_list":[{"enb_ue_id":8,"mme_ue_id":107,"rnti":68,"cells":[{"cell_id":1}]}],"message_id":22,"time":9643.268} {"message":"erab_get","erab_list":[{"erab_id":5,"qci":9,"dl_total_bytes":0,"ul_total_bytes":0,"enb_ue_id":8}],"timestamp":9643555,"message_id":23,"time":9643.555} {"message":"ue_get","ue_list":[{"enb_ue_id":8,"mme_ue_id":107,"rnti":68,"cells":[{"cell_id":1}]}],"message_id":24,"time":9646.326} {"message":"erab_get","erab_list":[{"erab_id":5,"qci":9,"dl_total_bytes":0,"ul_total_bytes":0,"enb_ue_id":8}],"timestamp":9646850,"message_id":25,"time":9646.85} {"message":"ue_get","ue_list":[],"message_id":26,"time":9649.287} {"message":"erab_get","erab_list":[],"timestamp":9649646,"message_id":27,"time":9649.646} ^CTraceback (most recent call last): File "/home/kirr/src/wendelin/venv/xlte3.venv/bin/xamari", line 33, in <module> sys.exit(load_entry_point('xlte', 'console_scripts', 'xamari')()) File "/home/kirr/src/wendelin/xlte/amari/xamari.py", line 130, in main return command_module.main(argv) File "/home/kirr/src/wendelin/xlte/amari/xlog.py", line 275, in main xlog(wsuri, logspecv) File "/home/kirr/src/wendelin/xlte/amari/xlog.py", line 108, in xlog xl.xlog1() File "/home/kirr/src/wendelin/venv/xlte3.venv/lib/python3.9/site-packages/decorator.py", line 232, in fun return caller(func, *(extras + args), **kw) File "/home/kirr/src/wendelin/venv/xlte3.venv/lib/python3.9/site-packages/golang/__init__.py", line 103, in _ return f(*argv, **kw) File "/home/kirr/src/wendelin/xlte/amari/xlog.py", line 157, in xlog1 xl._xlog1(conn) File "/home/kirr/src/wendelin/xlte/amari/xlog.py", line 208, in _xlog1 time.sleep(δtsleep) KeyboardInterrupt
-
Kirill Smelkov authored
- amari.connect() connects to a service and returns Conn. - Conn can be used to issue requests, receive replies and (TODO) event notifications. Several requests could be issued simultaneously and handled in parallel.
-
Kirill Smelkov authored
Only main driver framework here without actual subcommands. Based on similar main driver from Zodbtools: https://lab.nexedi.com/nexedi/zodbtools/blob/master/zodbtools/zodb.py
-
Kirill Smelkov authored
So that import xlte.abc resolves to xlte/abc.py Based on similar top-level import redirector from wendelin.core See nexedi/wendelin.core@e870781d for context and links in added code for further details.
-
Kirill Smelkov authored
Stub setup.py, README/CHANGELOG, .gitignore.
-
Kirill Smelkov authored
Follow standard GPL3 + wide exception for Free and Open-source software. See https://www.nexedi.com/licensing for details.
-
Kirill Smelkov authored
The project to implement assorted functionality related to LTE. In particular I intend for it to be the place where KPI-related functionality will live.
-