Commit e1c5d144 authored by Marius Tillner's avatar Marius Tillner

initial commit;

added latseq files to repository;
added latseq flags to Cmake
parent 214aa505
......@@ -349,6 +349,7 @@ add_boolean_option(UE_AUTOTEST_TRACE False "Activate UE autotest specific logs
add_boolean_option(UE_DEBUG_TRACE False "Activate UE debug trace")
add_boolean_option(UE_TIMING_TRACE False "Activate UE timing trace")
add_boolean_option(DEBUG_CONSOLE False "disables stdout/stderr buffering")
add_boolean_option(LATSEQ False "Activate Latency Sequence tool")
set (OCP_ITTI ${OPENAIR_DIR}/common/utils/ocp_itti)
add_library(ITTI
......@@ -876,6 +877,7 @@ add_library(UTIL
${OPENAIR_DIR}/common/utils/backtrace.c
${OPENAIR_DIR}/common/utils/time_meas.c
${OPENAIR_DIR}/common/utils/time_stat.c
${OPENAIR_DIR}/common/utils/LATSEQ/latseq.c
)
target_link_libraries(UTIL PRIVATE asn1_nr_rrc asn1_lte_rrc)
......@@ -1397,6 +1399,7 @@ set(PHY_MEX_UE
${OPENAIR_DIR}/common/utils/LOG/log.c
${OPENAIR_DIR}/common/utils/T/T.c
${OPENAIR_DIR}/common/utils/T/local_tracer.c
${OPENAIR_DIR}/common/utils/LATSEQ/latseq.c
)
add_library(PHY_MEX ${PHY_MEX_UE} ${CONFIG_LIB})
target_link_libraries(PHY_MEX PRIVATE asn1_lte_rrc)
......
......@@ -67,6 +67,7 @@ RU=0
CMAKE_C_FLAGS=()
CMAKE_CXX_FLAGS=()
function print_help() {
echo_info "
This script compiles OpenAirInterface Software, and can install dependencies
......@@ -175,6 +176,8 @@ Options:
Enable the address sanitizer on all targets
--sanitize-undefined | -fsanitize=undefined
Enable the undefined behavior sanitizer on all targets
--enable-latseq
enables latency sequence tool, https://github.com/Orange-OpenSource/LatSeq
-h | --help
Print this help"
}
......@@ -422,6 +425,10 @@ function main() {
--sanitize-undefined | -fundefined=address)
CMAKE_CMD="$CMAKE_CMD -DSANITIZE_UNDEFINED=True"
shift;;
--enable-latseq)
LATSEQ='True'
echo info "Enabling Latency Sequence measures, https://github.com/Orange-OpenSource/LatSeq"
shift;;
-h | --help)
print_help
exit 1;;
......
# LATency SEQuence analysis extension for OpenAirInterface
A tool for internal latency analysis in Base Station.
Code licenced under BSD-3. See more on https://github.com/Orange-OpenSource/LatSeq
Author : Flavien Ronteix--Jacquet (Orange Innovation), Alexandre Ferrieux (Orange Innovation)
Email : flavien.ronteixjacquet@orange.com, alexandre.ferrieux@orange.com
## Installation
- Put LatSeq extension source code in OAI code (https://gitlab.eurecom.fr/oai/openairinterface5g). We recommend to put it in the path common/utils/LATSEQ.
- In cmake_targets/CMakeLists.txt put `add_boolean_option(LATSEQ True "Active Latency Sequence tools")`. Also add Latseq to compiled source `set(UTIL_SRC... ${OPENAIR_DIR}/common/utils/LATSEQ/latseq.c`
- Put test/ in targets/TEST/LATSEQ/
- Verify installation of LatSeq with `make` in targets/TEST/LATSEQ
## Usage
0) Add init_latseq(appname) and close_latseq() in main Base Station thread at the start and end.
1) Add a new LatSeq measure point in the code with
#include "common/utils/LATSEQ/latseq.h"
#if LATSEQ
LATSEQ_P("D pdcp--rlc", "pdcp%d.rlc%d", 0, 1);
#endif
where first argument is the direction, the second the observed segment and the third argument is a string of data_identifier
1) Compile OAI code with cmake option LATSEQ at True
2) Run scanario for Uplink and Downlink
3) Process lseq traces to yield data do statistics with LatSeq tools
More in docs/Latseq.pdf
## LatSeq measurement module
For now, latseq is designed to be the more independant as possible : Means that it does not use oai LOG system (not register by logInit()) and the flag "LATSEQ" disable all lines related to latseq in the code (using #ifdef). In a second time, it could be conceivable to integrate more deeply latseq into oai code.
latseq_t, global structure for latseq embodied the latseq logging info. log_buffer is a circular buffer with 2 head index, i_write_head and i_read_head. this buffer of latseq_element_t is designed to bo mutex-less.
LATSEQ_P macro calls log_measure(). The idea is to have a low-footprint at logging explains why log_measure() should do a minimal amount of operations.
latseq_log_to_file() is the function run in the logger thread. It writes log_elements in the log file.
LATSEQ_P with direction of D (Downlink) or U (Uplink) observed the passage of a data.
LATSEQ_P with direction of I (Information) observed a scalar property at a point of code. e.g. buffer occupancy.
**We assume that**:
- All the point and latseq module run on the same machine (to don't have to synchronize clock of different machines)
- Clock give by asm rdtsc is same for all the CPU cores (constant_tsc enabled)
### TODO
- [ ] "gtp.in--pdcp.in.gtp" and "ip.in--gtp.in" has been deleted since "gtpv1u_eNB.c" and "NwGtpv1u.c" has been deleted
## TOOLS
Get scripts on https://github.com/Orange-OpenSource/LatSeq/tools
- latseq_checker : verify constitency of Latseq points before compiling
- latseq_logs : convert lseq log file into useful json file for statistics and visualization
- latseq_filter : filter output of latseq_logs
- latseq_stats : perform statistic
### latseq_checker
Checker to verify that points LATSEQ_P points are consistent.
Verify the number of argument, the emptiness, format...
ex. ./latseq_checker.sh /home/oai/
### rdtsctots
convert rdtsc value to unix timestamp value
ex. `./rdtsctots.py trace_raw.lseq > trace.lseq`
### latseq_logs
Proceeds LatSeq logs.
A *.lseq is required.
By default, builds the latseq_log object.
- Reads lseq file given in raw_input
- Cleans raw_input to inputs.
- Builds points structure and paths possible.
- Saves object related to the *.lseq files to a *.plk (pickle)
**Arguments**:
- "-h" : help
- "-C" : cleans pickle file associated to the log file and rebuild
- "-l" : required lseq file of fingerprints
- "-i" : request cleaned input measurements in the case of command line script
- "-r" returns the paths present in the log file as json.
```
{
"D": [
["ip", "pdcp.in",...],
...
],
"U": ...
}
``̀
- "-p" returns points structure as json.
Becareful, if journeys has not been rebuilt, then you do not have "duration" attibute which is used for statistics.
```
{
"layer1.point": {
"next": [layer2.point2,...],
"count": 5,
"dir": [0],
"duration": {
"journeys uid": 0.0115,
...
}
}
}
{
...
}
```
- "-j" returns journeys structure as json.
- Rebuilds journeys with rebuild_packets_journey method
- Builds out_journeys
```
{
"uid": 52,
"dir": 0,
"glob": {
"rnti": "54614",...
},
"set": [[1542, 1592409314.253678, "rlc.rx.am--pdcp.rx"],[...],...], # set of pointer to input entry
"set_ids": {
"drb": "1",...
},
"path": 0, # path according to direction and paths obtainable by -p
"completed": true,
"ts_in": 123.456,
"ts_out": 789.012
}
{
...
}
```
- "-m" returns metadata of information as list
```
20200423_143226.191801 rlc.am.txbuf occ1:drb1
20200423_143226.191802 rlc.am.txbuf occ2:drb1
...
20200423_143226.192000 rlc.um.txbuf occ15:drb2
```
- "-o" returns a latseq journey file line by line. redirects output to a file to have a *.lseqj for waterfall generation
```
#funcId ip pdcp.in pdcp.tx rlc.tx.um rlc.seg.um mac.mux mac.txreq phy.out.proc phy.in.proc mac.demux rlc.rx.um rlc.unseg.um pdcp.rx
20200423_143226.191801 D (len64) ip--pdcp.in.gtp uid0.rnti54614.drb1.gsn12
20200423_143226.191802 D (len64) pdcp.in--pdcp.tx uid0.rnti54614.drb1.gsn12.psn10
20200423_143226.191803 D (len66) pdcp.tx--rlc.tx.um uid0.rnti54614.drb1.psn10.lcid3.rsdu0
```
Requested json are printed in stdout line by line
Errors, Warnings, Informations are printed in stderr
Example of usage:
./latseq_logs.py -l ~/latseq.23042020.lseq 2>/dev/null
./latseq_logs.py -j -l ~/latseq.23042020.lseq 2>/dev/null
./latseq_logs.py -p -l ~/latseq.23042020.lseq 2>/dev/null
./latseq_logs.py -o -l ~/latseq.23042020.lseq > 23042020.lseqj 2>/dev/null
### latseq_filter
Applies a filter to a json stream.
It uses jq filters.
Help website to design jq filter : https://jqplay.org/
Takes a file with a filter or a filter as string in argument.
Example of usage:
./latseq_filter.sh journeys_downlinks_gsn.lfilter
cat journeys_downlinks_gsn.lfilter
> select(.["dir"] == 0 and .["set_ids"]["gsn"] == "18")
### latseq_stats
Performs statistics from json. Report json or print in stdout.
By default, reads on stdin. "-l" *.lseq will try to open a *.json associated.
By default, returns a json report on stdout.
Arguments:
- "-f" enables to choose format "json", "csv",...
- "-P" prints statistics formated by the latseq_stats module.
- "-sj" returns statistics on journeys
`̀``
{
"D": {
"size": 34,
"min": 0.19598,
"max": 1.187086,
"mean": 0.788976,
"stdev": 0.153623,
"quantiles": [0.694859, 0.699043, 0.834942, 0.838041, 0.955701]
}
`̀``
- "-sjpp" returns the shares of delay introduced by each point for each journeys by path.
```
{
"U02": { # Uplinks, path 0, point 2
"size": 4,
"min": 0,
"max": 0.7273,
"mean": 0.36239999999999994,
"stdev": 0.2915949673776967,
"quantiles": [
0.025005000000000003,
0.125025,
0.36114999999999997,
0.598525,
0.7015449999999999
]
}
}
```
- "-sp" returns statistics on points
```
{
"pdcp.rx": {
"dir": "U",
"size": 4,
"min": 0.01,
"max": 0.02,
"mean": 0.015,
"stdev": 0.005,
"quantiles": [0.012,...] # 5%, 25%, 50%, 75%, 95%
},
...
}
`̀``
- "-djd" returns data journeys' duration
`̀``
{
"00": { # first decimal indicates uplink/downlink followed by the journey unique id
"ts": 1587645146.191801,
"durations": 0.19598 # in ms
},
...
}
`̀``
Example of usage of the full toolchain for LatSeq Analysis Module
./latseq_logs.py -l ~/latseq.simple.lseq -j 2>/dev/null | ./latseq_filter.sh journeys_downlinks_gsn.lfilt | ./latseq_stats.py -sj --print
## TEST_LATSEQ
in targets/TEST/LATSEQ test_latseq test different part of latseq module
- "h" : help menu
- "i" : test init and close latseq
- "a" : test init, capture 2 fingerprints and close
- "t" : same test as "a" but with 2 concurrent threads
- "m" : test measurement time to capture 1000000 fingerprints
- "n" : test measurement time to capture 1000 fingerprints with 1,2,3,5,10 data identifiers
- "w" : test writer speed for a simplified data collector
/*
* Software Name : LatSeq
* Version: 1.0
* SPDX-FileCopyrightText: Copyright (c) 2020-2021 Orange Labs
* SPDX-License-Identifier: BSD-3-Clause
*
* This software is distributed under the BSD 3-clause,
* the text of which is available at https://opensource.org/licenses/BSD-3-Clause
* or see the "license.txt" file for more details.
*
* Author: Flavien Ronteix--Jacquet
* Software description: LatSeq measurement part core
*/
#define _GNU_SOURCE // required for pthread_setname_np()
#include "latseq.h"
/*--- GLOBALS and EXTERNS ----------------------------------------------------*/
latseq_t g_latseq;
__thread latseq_thread_data_t tls_latseq = {
.th_latseq_id = 0
}; // need to be a thread local storage variable.
pthread_t logger_thread;
pthread_t fflusher_thread;
//double cpuf; //cpu frequency in MHz -> usec. Should be initialized in main.c
extern volatile int oai_exit; //oai is ended. Close latseq
/*--- UTILS FUNCTIONS --------------------------------------------------------*/
uint64_t get_cpu_freq_cycles(void)
{
uint64_t ts = l_rdtsc();
sleep(1);
return (l_rdtsc() - ts);
}
/*--- MAIN THREAD FUNCTIONS --------------------------------------------------*/
int init_latseq(const char * appname, uint64_t cpufreq)
{
// init members
g_latseq.is_running = 0;
//synchronise time and rdtsc
struct timespec ts;
clock_gettime(CLOCK_REALTIME, &ts);
g_latseq.time_zero = (uint64_t)ts.tv_sec * 1000000000LL + (uint64_t)ts.tv_nsec;
g_latseq.rdtsc_zero = l_rdtsc(); //check at compile time that constant_tsc is enabled in /proc/cpuinfo
if (cpufreq == 0) {
g_latseq.cpu_freq = get_cpu_freq_cycles();
} else {
g_latseq.cpu_freq = cpufreq;
}
// Open traces
char time_string[16];
strftime(time_string, sizeof (time_string), "%d%m%Y_%H%M%S", localtime(&ts.tv_sec));
g_latseq.filelog_name = (char *)malloc(LATSEQ_MAX_STR_SIZE);
sprintf(g_latseq.filelog_name, "%s.%s.lseq", appname, time_string);
//open logfile
g_latseq.outstream = fopen(g_latseq.filelog_name, "w");
if (g_latseq.outstream == NULL) {
g_latseq.is_running = 0;
printf("[LATSEQ] Error at opening log file\n");
return -1;
}
//write header
char hdr[] = "# LatSeq packet fingerprints\n# By Alexandre Ferrieux and Flavien Ronteix Jacquet\n# timestamp\tU/D\tsrc--dest\tlen:ctxtId:localId\n";
size_t ret = fwrite(hdr, sizeof(char), sizeof(hdr) - 1, g_latseq.outstream);
if (ret < 0) {
printf("[LATSEQ] Error at opening log file\n");
g_latseq.is_running = 0;
return -1;
}
fprintf(g_latseq.outstream, "%ld S rdtsc--gettimeofday %ld.%09ld\n", g_latseq.rdtsc_zero, ts.tv_sec, ts.tv_nsec);
fflush(g_latseq.outstream);
// init registry
g_latseq.local_log_buffers.read_ith_thread = 0;
g_latseq.local_log_buffers.nb_th = 0;
memset(&g_latseq.local_log_buffers.i_read_heads, 0, MAX_NB_THREAD * sizeof(unsigned int));
// init stat
g_latseq.stats.entry_counter = 0;
g_latseq.stats.bytes_counter = 0;
// init latseq_thread_t
tls_latseq.th_latseq_id = 0;
// init logger thread
g_latseq.is_running = 1;
return init_logger_latseq();
}
int init_logger_latseq(void)
{
// init thread to write buffer to file
if(pthread_create(&logger_thread, NULL, (void *) &latseq_log_to_file, NULL) > 0) {
printf("[LATSEQ] Error at starting data collector\n");
g_latseq.is_running = 0;
return -1;
}
// init thread to flush into file
pthread_create(&fflusher_thread, NULL, (void *) &fflush_latseq_periodically, NULL);
return g_latseq.is_running;
}
void latseq_print_stats(void)
{
printf("[LATSEQ] === stats ===\n");
printf("[LATSEQ] number of entry in log : %d\n", g_latseq.stats.entry_counter);
//printf("[LATSEQ] heads positions : %d (Write) : %d (Read)\n", g_latseq.i_write_head, g_latseq.i_read_head);
}
int close_latseq(void)
{
g_latseq.is_running = 0;
//Wait logger finish to write data
pthread_join(logger_thread, NULL);
//At this point, data_ids and points should be freed by the logger thread
free((char*) g_latseq.filelog_name);
if (fclose(g_latseq.outstream)){
fprintf(stderr, "[LATSEQ] error on closing %s\n", g_latseq.filelog_name);
exit(EXIT_FAILURE);
}
return 1;
}
/*--- INSTRUMENTED THREAD FUNCTIONS ------------------------------------------*/
int init_thread_for_latseq(void)
{
//Init tls_latseq for local thread
tls_latseq.i_write_head = 0; //local thread tls_latseq
//memset(tls_latseq.log_buffer, 0, sizeof(tls_latseq.log_buffer));
//Register thread in the registry
latseq_registry_t * reg = &g_latseq.local_log_buffers;
//Check if space left in registry
if (reg->nb_th >= MAX_NB_THREAD) {
g_latseq.is_running = 0;
fprintf(g_latseq.outstream, "Max instrumented thread MAX_NB_THREAD reached\n");
return -1;
}
reg->tls[reg->nb_th] = &tls_latseq;
reg->i_read_heads[reg->nb_th] = 0;
//Give id to the thread
reg->nb_th++;
tls_latseq.th_latseq_id = reg->nb_th;
return 0;
//TODO : No destroy function ? What happens when thread is stopped and data had not been written in the log file ?
}
/*--- DATA COLLECTOR THREAD FUNCTIONS ----------------------------------------*/
static int write_latseq_entry(void)
{
//reference to latseq_thread_data
latseq_thread_data_t * th = g_latseq.local_log_buffers.tls[g_latseq.local_log_buffers.read_ith_thread];
//read_head for this thread_data
unsigned int * i_read_head = &g_latseq.local_log_buffers.i_read_heads[g_latseq.local_log_buffers.read_ith_thread];
//reference to element to write
latseq_element_t * e = &th->log_buffer[(*i_read_head)%RING_BUFFER_SIZE];
char * tmps;
//Convert latseq_element to a string
tmps = calloc(LATSEQ_MAX_STR_SIZE, sizeof(char));
//Write the data identifier, e.g. do the vsprintf() here and not at measure()
//We put the first NB_DATA_IDENTIFIERS elements of array, even there are no NB_DATA_IDENTIFIERS element to write. sprintf will get the firsts...
sprintf(
tmps,
e->format,
e->data_id[0],
e->data_id[1],
e->data_id[2],
e->data_id[3],
e->data_id[4],
e->data_id[5],
e->data_id[6],
e->data_id[7],
e->data_id[8],
e->data_id[9]);
// Write into file
int ret = fprintf(g_latseq.outstream, "%ld %s %s\n",
e->ts,
e->point,
tmps);
if (ret < 0) {
g_latseq.is_running = 0;
fclose(g_latseq.outstream);
fprintf(stderr, "[LATSEQ] output log file cannot be written\n");
exit(EXIT_FAILURE);
}
#ifdef LATSEQ_DEBUG
fprintf(g_latseq.outstream, "# debug %ld.%06ld : log an entry (len %d) for %s\n", etv.tv_sec, etv.tv_usec, ret, e->point);
fprintf(g_latseq.outstream, "# info %ld.%06ld : buffer occupancy (%d / %d) for thread which embedded %s\n",etv.tv_sec, etv.tv_usec, OCCUPANCY((*(&th->i_write_head)%RING_BUFFER_SIZE), ((*i_read_head)%RING_BUFFER_SIZE)), RING_BUFFER_SIZE, e->point);
#endif
free(tmps);
// cleanup buffer element
e->ts = 0;
memset(e->data_id, 0, (sizeof(uint32_t) * e->len_id));
e->len_id = 0;
//Update read_head for the current read_ith_thread
//Update g_latseq.local_log_buffers.i_read_heads[g_latseq.local_log_buffers.read_ith_thread] head position
(*i_read_head)++;
return ret;
}
void latseq_log_to_file(void)
{
// pthread config
pthread_t thId = pthread_self();
//set name
pthread_setname_np(thId, "latseq_log_to_file");
//set priority
int prio_for_policy = 10;
pthread_setschedprio(thId, prio_for_policy);
latseq_registry_t * reg = &g_latseq.local_log_buffers;
int items_to_read = 0;
while (!oai_exit) { // run until oai is stopped
if (!g_latseq.is_running) { break; } //running flag is at 0, not running
//If no thread registered, continue and wait
if (reg->nb_th == 0) { usleep(1000); continue; }
//Select a thread to read with read_ith_thread.
// Using RR for now, WRR in near future according to occupancy
if (reg->read_ith_thread + 1 >= reg->nb_th) {
reg->read_ith_thread = 0;
} else {
reg->read_ith_thread++;
}
//If max occupancy reached for a local buffer
if (reg->tls[reg->read_ith_thread]->i_write_head < reg->i_read_heads[reg->read_ith_thread]) {
fprintf(g_latseq.outstream, "# Error\tring buffer of thread (%d) reach max occupancy of %d\n", reg->read_ith_thread, RING_BUFFER_SIZE);
}
items_to_read = CHUNK_SIZE_ITEMS;
// Write by chunk
while (reg->tls[reg->read_ith_thread]->i_write_head > reg->i_read_heads[reg->read_ith_thread] && items_to_read > 0 ) {
//printf("[debug] th %d : (%d)w (%d)r : (%d)items_to_read\n", reg->read_ith_thread, reg->tls[reg->read_ith_thread]->i_write_head, reg->i_read_heads[reg->read_ith_thread], items_to_read);
items_to_read--;
//Write pointed entry into log file
g_latseq.stats.bytes_counter += (uint32_t)write_latseq_entry();
g_latseq.stats.entry_counter++;
}
usleep(1);
} // while(!oai_exit)
//Write all remaining data
for (uint8_t i = 0; i < reg->nb_th; i++) {
reg->read_ith_thread = i;
while (reg->tls[reg->read_ith_thread]->i_write_head > reg->i_read_heads[reg->read_ith_thread])
{
g_latseq.stats.bytes_counter += (uint32_t)write_latseq_entry();
g_latseq.stats.entry_counter++;
}
}
//close_latseq(); // function to close latseq properly
//exit thread
pthread_exit(NULL);
}
void fflush_latseq_periodically(void)
{
struct timespec ts;
while(1){
sleep(1);
fflush(g_latseq.outstream);
clock_gettime(CLOCK_REALTIME, &ts);
fprintf(g_latseq.outstream, "%ld S rdtsc--gettimeofday %ld.%09ld\n", l_rdtsc(), ts.tv_sec, ts.tv_nsec);
}
pthread_exit(NULL);
}
/*
* Software Name : LatSeq
* Version: 1.0
* SPDX-FileCopyrightText: Copyright (c) 2020-2021 Orange Labs
* SPDX-License-Identifier: BSD-3-Clause
*
* This software is distributed under the BSD 3-clause,
* the text of which is available at https://opensource.org/licenses/BSD-3-Clause
* or see the "license.txt" file for more details.
*
* Author: Flavien Ronteix--Jacquet
* Software description: LatSeq measurement part core
*/
#ifndef __LATSEQ_H__
#define __LATSEQ_H__
/*--- INCLUDES ---------------------------------------------------------------*/
#include <unistd.h>
#include <stdio.h>
#include <stdlib.h>
#include <string.h>
#include <syslog.h>
#include <assert.h>
#include <sys/types.h>
#include <sys/stat.h>
#include <sys/time.h>
#include <fcntl.h>
#include <stdarg.h>
#include <time.h>
#include <stdint.h>
#ifndef __STDC_FORMAT_MACROS
#define __STDC_FORMAT_MACROS
#endif
#include <inttypes.h>
#ifndef _GNU_SOURCE
#define _GNU_SOURCE
#endif
#include <pthread.h>
#include <utils.h>
/*--- DEFINE -----------------------------------------------------------------*/
#define RING_BUFFER_SIZE 1024 // Number of fingerprints in Ring Buffer
#define NB_DATA_IDENTIFIERS 10 // to update according to distinct data identifier used in point
#define LATSEQ_MAX_STR_SIZE 128 // Length for filelog_name AND latseq fingerprint string size
#define CHUNK_SIZE_ITEMS 16 // Size of chunk of ring buffer to read at data collector. 1 correspoding to full RR, RING_BUFFER_SIZE read all buffer by passage
#define MAX_NB_THREAD 32 // Maximum number of instrumented threads expected
/*--- MACRO ------------------------------------------------------------------*/
#define LATSEQ_P3(p, f, i1) do {log_measure1(p, f, (uint32_t)i1); } while(0)
#define LATSEQ_P4(p, f, i1, i2) do {log_measure2(p, f, (uint32_t)i1, (uint32_t)i2); } while(0)
#define LATSEQ_P5(p, f, i1, i2, i3) do {log_measure3(p, f, (uint32_t)i1, (uint32_t)i2, (uint32_t)i3); } while(0)
#define LATSEQ_P6(p, f, i1, i2, i3, i4) do {log_measure4(p, f, (uint32_t)i1, (uint32_t)i2, (uint32_t)i3, (uint32_t)i4);} while(0)
#define LATSEQ_P7(p, f, i1, i2, i3, i4, i5) do {log_measure5(p, f, (uint32_t)i1, (uint32_t)i2, (uint32_t)i3, (uint32_t)i4, (uint32_t)i5); } while(0)
#define LATSEQ_P8(p, f, i1, i2, i3, i4, i5, i6) do {log_measure6(p, f, (uint32_t)i1, (uint32_t)i2, (uint32_t)i3, (uint32_t)i4, (uint32_t)i5, (uint32_t)i6); } while(0)
#define LATSEQ_P9(p, f, i1, i2, i3, i4, i5, i6, i7) do {log_measure7(p, f, (uint32_t)i1, (uint32_t)i2, (uint32_t)i3, (uint32_t)i4, (uint32_t)i5, (uint32_t)i6, (uint32_t)i7); } while(0)
#define LATSEQ_P10(p, f, i1, i2, i3, i4, i5, i6, i7, i8) do {log_measure8(p, f, (uint32_t)i1, (uint32_t)i2, (uint32_t)i3, (uint32_t)i4, (uint32_t)i5, (uint32_t)i6, (uint32_t)i7, (uint32_t)i8); } while(0)
#define LATSEQ_P11(p, f, i1, i2, i3, i4, i5, i6, i7, i8, i9) do {log_measure9(p, f, (uint32_t)i1, (uint32_t)i2, (uint32_t)i3, (uint32_t)i4, (uint32_t)i5, (uint32_t)i6, (uint32_t)i7, (uint32_t)i8, (uint32_t)i9); } while(0)
#define LATSEQ_P12(p, f, i1, i2, i3, i4, i5, i6, i7, i8, i9, i10) do {log_measure10(p, f, (uint32_t)i1, (uint32_t)i2, (uint32_t)i3, (uint32_t)i4, (uint32_t)i5, (uint32_t)i6, (uint32_t)i7, (uint32_t)i8, (uint32_t)i9, (uint32_t)i10); } while(0)
#define GET_MACRO(_1,_2,_3,_4,_5,_6,_7,_8,_9,_10,_11,_12,NAME,...) NAME
#define LATSEQ_P(...) GET_MACRO(__VA_ARGS__, LATSEQ_P12, LATSEQ_P11, LATSEQ_P10, LATSEQ_P9, LATSEQ_P8, LATSEQ_P7, LATSEQ_P6, LATSEQ_P5, LATSEQ_P4, LATSEQ_P3)(__VA_ARGS__)
#define OCCUPANCY(w, r) (w - r)
/*--- STRUCT -----------------------------------------------------------------*/
// A latseq element of the buffer
typedef struct latseq_element_t {
uint64_t ts; // timestamp of the measure
const char * point;
const char * format;
ushort len_id; // Number data identifiers
uint32_t data_id[NB_DATA_IDENTIFIERS]; // values for the data identifier. What is the best type ?
} latseq_element_t;
// Statistics structures for latseq
typedef struct latseq_stats_t {
uint32_t entry_counter;
uint32_t bytes_counter;
} latseq_stats_t;
//thread specific data struct
typedef struct latseq_thread_data_t {
uint8_t th_latseq_id; //Identifier of pthread for registry
latseq_element_t log_buffer[RING_BUFFER_SIZE]; //log buffer, structure mutex-less
unsigned int i_write_head; // position of writer in the log_buffer (main thread)
} latseq_thread_data_t;
//Registry of pointers to thread-specific struct latseq_data_thread
typedef struct latseq_registry_t {
uint8_t read_ith_thread;
uint8_t nb_th;
latseq_thread_data_t * tls[MAX_NB_THREAD];
unsigned int i_read_heads[MAX_NB_THREAD]; // position of reader in the ith log buffer (logger thread)
} latseq_registry_t;
// Global structure of LatSeq module
typedef struct latseq_t {
int is_running; //1 is running, 0 not running
char * filelog_name;
FILE * outstream; //Output descriptor
uint64_t time_zero; // time zero
uint64_t rdtsc_zero; //rdtsc zero
uint64_t cpu_freq; //cpu frequency
latseq_registry_t local_log_buffers; //Register of thread-specific buffers
latseq_stats_t stats; // stats of latseq instance
} latseq_t;
/*--- EXTERNS ----------------------------------------------------------------*/
extern latseq_t g_latseq; // global structure
extern __thread latseq_thread_data_t tls_latseq;
/*--- FUNCTIONS --------------------------------------------------------------*/
/** \fn int init_latseq(const char * appname);
* \brief init latency sequences module.
* \param appname app's name. The output file is appname.date_hour.lseq
* \param cpufreq. cpu frequency in cycles.
* \return -1 if error 1 otherwise
*/
int init_latseq(const char * appname, uint64_t cpufreq);
/** \fn init_logger_to_mem(void);
* \brief init thread logger
* \return -1 if error 1 otherwise
*/
int init_logger_latseq(void);
/** \fn init_thread_for_latseq(void);
* \brief init tls_latseq for local oai thread
* \return -1 if error, 0 otherwise
*/
int init_thread_for_latseq(void);
/** \fn l_rdtsc(void);
* \brief rdtsc wrapper
* \return time
*/
static __inline__ uint64_t l_rdtsc(void) {
uint32_t a, d;
__asm__ volatile ("rdtsc" : "=a" (a), "=d" (d));
return (((uint64_t)d)<<32) | ((uint64_t)a);
}
/** \fn get_cpu_freq_cycles(void);
* \brief Compute CPU clock in a 1 second experiment
* \return CPU clock in cycles
*/
uint64_t get_cpu_freq_cycles(void);
/*--- MEASUREMENTS -----------------------------------------------------------*/
/** \fn void log_measure(const char * point, const char *identifier);
* \brief function to log a new measure into buffer.
* From 1 to NB_DATA_IDENTIFIERS
* \param point name of the measurement point
* \param id identifier for the data pointed
* \todo measure latency introduced by this function
*/
static __inline__ void log_measure1(const char * point, const char *fmt, uint32_t i1)
{
//check if the oai thread is already registered
if (tls_latseq.th_latseq_id == 0) {
//is not initialized yet
if (init_thread_for_latseq()) {
return;
}
}
//get reference on new element
latseq_element_t * e = &tls_latseq.log_buffer[tls_latseq.i_write_head%RING_BUFFER_SIZE];
e->ts = l_rdtsc();
e->point = point;
e->format = fmt;
e->len_id = 1;
e->data_id[0] = i1;
//Update head position
tls_latseq.i_write_head++;
}
static __inline__ void log_measure2(const char * point, const char *fmt, uint32_t i1, uint32_t i2)
{
if (tls_latseq.th_latseq_id == 0) {
//is not initialized yet
if (init_thread_for_latseq()) {
return;
}
}
latseq_element_t * e = &tls_latseq.log_buffer[tls_latseq.i_write_head%RING_BUFFER_SIZE];
e->ts = l_rdtsc();
e->point = point;
e->format = fmt;
e->len_id = 2;
e->data_id[0] = i1;
e->data_id[1] = i2;
tls_latseq.i_write_head++;
}
static __inline__ void log_measure3(const char * point, const char *fmt, uint32_t i1, uint32_t i2, uint32_t i3)
{
if (tls_latseq.th_latseq_id == 0) {
//is not initialized yet
if (init_thread_for_latseq()) {
return;
}
}
latseq_element_t * e = &tls_latseq.log_buffer[tls_latseq.i_write_head%RING_BUFFER_SIZE];
e->ts = l_rdtsc();
e->point = point;
e->format = fmt;
e->len_id = 3;
e->data_id[0] = i1;
e->data_id[1] = i2;
e->data_id[2] = i3;
tls_latseq.i_write_head++;
}
static __inline__ void log_measure4(const char * point, const char *fmt, uint32_t i1, uint32_t i2, uint32_t i3, uint32_t i4)
{
if (tls_latseq.th_latseq_id == 0) {
//is not initialized yet
if (init_thread_for_latseq()) {
return;
}
}
latseq_element_t * e = &tls_latseq.log_buffer[tls_latseq.i_write_head%RING_BUFFER_SIZE];
e->ts = l_rdtsc();
e->point = point;
e->format = fmt;
e->len_id = 4;
e->data_id[0] = i1;
e->data_id[1] = i2;
e->data_id[2] = i3;
e->data_id[3] = i4;
tls_latseq.i_write_head++;
}
static __inline__ void log_measure5(const char * point, const char *fmt, uint32_t i1, uint32_t i2, uint32_t i3, uint32_t i4, uint32_t i5)
{
if (tls_latseq.th_latseq_id == 0) {
//is not initialized yet
if (init_thread_for_latseq()) {
return;
}
}
latseq_element_t * e = &tls_latseq.log_buffer[tls_latseq.i_write_head%RING_BUFFER_SIZE];
e->ts = l_rdtsc();
e->point = point;
e->format = fmt;
e->len_id = 5;
e->data_id[0] = i1;
e->data_id[1] = i2;
e->data_id[2] = i3;
e->data_id[3] = i4;
e->data_id[4] = i5;
tls_latseq.i_write_head++;
}
static __inline__ void log_measure6(const char * point, const char *fmt, uint32_t i1, uint32_t i2, uint32_t i3, uint32_t i4, uint32_t i5, uint32_t i6)
{
if (tls_latseq.th_latseq_id == 0) {
//is not initialized yet
if (init_thread_for_latseq()) {
return;
}
}
latseq_element_t * e = &tls_latseq.log_buffer[tls_latseq.i_write_head%RING_BUFFER_SIZE];
e->ts = l_rdtsc();
e->point = point;
e->format = fmt;
e->len_id = 6;
e->data_id[0] = i1;
e->data_id[1] = i2;
e->data_id[2] = i3;
e->data_id[3] = i4;
e->data_id[4] = i5;
e->data_id[5] = i6;
tls_latseq.i_write_head++;
}
static __inline__ void log_measure7(const char * point, const char *fmt, uint32_t i1, uint32_t i2, uint32_t i3, uint32_t i4, uint32_t i5, uint32_t i6, uint32_t i7)
{
if (tls_latseq.th_latseq_id == 0) {
//is not initialized yet
if (init_thread_for_latseq()) {
return;
}
}
latseq_element_t * e = &tls_latseq.log_buffer[tls_latseq.i_write_head%RING_BUFFER_SIZE];
e->ts = l_rdtsc();
e->point = point;
e->format = fmt;
e->len_id = 7;
e->data_id[0] = i1;
e->data_id[1] = i2;
e->data_id[2] = i3;
e->data_id[3] = i4;
e->data_id[4] = i5;
e->data_id[5] = i6;
e->data_id[6] = i7;
tls_latseq.i_write_head++;
}
static __inline__ void log_measure8(const char * point, const char *fmt, uint32_t i1, uint32_t i2, uint32_t i3, uint32_t i4, uint32_t i5, uint32_t i6, uint32_t i7, uint32_t i8)
{
if (tls_latseq.th_latseq_id == 0) {
//is not initialized yet
if (init_thread_for_latseq()) {
return;
}
}
latseq_element_t * e = &tls_latseq.log_buffer[tls_latseq.i_write_head%RING_BUFFER_SIZE];
e->ts = l_rdtsc();
e->point = point;
e->format = fmt;
e->len_id = 8;
e->data_id[0] = i1;
e->data_id[1] = i2;
e->data_id[2] = i3;
e->data_id[3] = i4;
e->data_id[4] = i5;
e->data_id[5] = i6;
e->data_id[6] = i7;
e->data_id[7] = i8;
tls_latseq.i_write_head++;
}
static __inline__ void log_measure9(const char * point, const char *fmt, uint32_t i1, uint32_t i2, uint32_t i3, uint32_t i4, uint32_t i5, uint32_t i6, uint32_t i7, uint32_t i8, uint32_t i9)
{
if (tls_latseq.th_latseq_id == 0) {
//is not initialized yet
if (init_thread_for_latseq()) {
return;
}
}
latseq_element_t * e = &tls_latseq.log_buffer[tls_latseq.i_write_head%RING_BUFFER_SIZE];
e->ts = l_rdtsc();
e->point = point;
e->format = fmt;
e->len_id = 9;
e->data_id[0] = i1;
e->data_id[1] = i2;
e->data_id[2] = i3;
e->data_id[3] = i4;
e->data_id[4] = i5;
e->data_id[5] = i6;
e->data_id[6] = i7;
e->data_id[7] = i8;
e->data_id[8] = i9;
tls_latseq.i_write_head++;
}
static __inline__ void log_measure10(const char * point, const char *fmt, uint32_t i1, uint32_t i2, uint32_t i3, uint32_t i4, uint32_t i5, uint32_t i6, uint32_t i7, uint32_t i8, uint32_t i9, uint32_t i10)
{
if (tls_latseq.th_latseq_id == 0) {
//is not initialized yet
if (init_thread_for_latseq()) {
return;
}
}
latseq_element_t * e = &tls_latseq.log_buffer[tls_latseq.i_write_head%RING_BUFFER_SIZE];
e->ts = l_rdtsc();
e->point = point;
e->format = fmt;
e->len_id = 10;
e->data_id[0] = i1;
e->data_id[1] = i2;
e->data_id[2] = i3;
e->data_id[3] = i4;
e->data_id[4] = i5;
e->data_id[5] = i6;
e->data_id[6] = i7;
e->data_id[7] = i8;
e->data_id[8] = i9;
e->data_id[9] = i10;
tls_latseq.i_write_head++;
}
/** \fn static int write_latseq_entry(void);
* \brief private function to write an entry in the log file
*/
//static int write_latseq_entry(void);
/** \fn void log_to_file(void);
* \brief function to save buffer of logs into a file
*/
void latseq_log_to_file(void);
/** \fn void fflush_latseq_periodically(void);
* \brief flush periodically into fprintf
*/
void fflush_latseq_periodically(void);
/** \fn void latseq_print_stats(void);
* \brief print some stats about latseq
*/
void latseq_print_stats(void);
/** \fn int close_latseq(void);
* \brief finish latseq measurement if a latseq is running
* \return 0 if error 1 otherwise
*/
int close_latseq(void);
/*----------------------------------------------------------------------------*/
#endif
#################################################################################
# Software Name : LatSeq
# Version: 1.0
# SPDX-FileCopyrightText: Copyright (c) 2020-2021 Orange Labs
# SPDX-License-Identifier: BSD-3-Clause
#
# This software is distributed under the BSD 3-clause,
# the text of which is available at https://opensource.org/licenses/BSD-3-Clause
# or see the "license.txt" file for more details.
#
# Author: Flavien Ronteix--Jacquet
# Software description: tests makefile
#################################################################################
TEST_DIR = $(shell pwd)
OPENAIR_DIR = $(TEST_DIR)/../../..
OPENAIR2_COMMON = $(OPENAIR_DIR)/openair2/COMMON
UTILS_DIR = $(OPENAIR_DIR)/common/utils
LATSEQ_DIR = $(UTILS_DIR)/LATSEQ
CC = gcc
#CFLAGS += -m32 -DPHYSIM -DNB_ANTENNAS_RX=2 -DNB_ANTENNAS_TX=2 -I/usr/include/X11
#CFLAGS += -I/usr/include/libxml2 -L/usr/local/lib -I/usr/include/atlas -L/usr/X11R6/lib
CFLAGS += -std=gnu99 # to be compiled in c99 like all oai
CFLAGS += -Wall -Wconversion
CFLAGS += -g
#CFLAGS += -pg
#CFLAGS += -O3
CFLAGS += -DLATSEQ
#CFLAGS += -DLATSEQ_DEBUG
CFLAGS += -DTEST_LATSEQ
CFLAGS += -I$(OPENAIR_DIR) -I$(OPENAIR2_COMMON) -I$(UTILS_DIR) -I$(LATSEQ_DIR)
LDLIBS = -lpthread
VPATH += $(LATSEQ_DIR)
VPATH += $(MEAS_DIR)
EXE = test_latseq
SRCS = test_latseq.c latseq.c
OBJS = $(SRCS:.c=.o)
all: $(EXE)
$(EXE): $(OBJS)
@echo "Compiling test_latseq"
$(CC) $(CFLAGS) -o $@ $(OBJS) $(LDLIBS)
run: $(EXE)
@echo "Run test_latseq"
./test_latseq a
run-parsing: $(LATSEQ_DIR)/lseq_stats/lseqlogs.py
cd $(LATSEQ_DIR)/lseq_stats/;\
./lseqlogs.py -l $(TEST_DIR)/test1.lseq
clean:
rm -f core gmon.out $(EXE) *.o test.*.lseq
/*
* Software Name : LatSeq
* Version: 1.0
* SPDX-FileCopyrightText: Copyright (c) 2020-2021 Orange Labs
* SPDX-License-Identifier: BSD-3-Clause
*
* This software is distributed under the BSD 3-clause,
* the text of which is available at https://opensource.org/licenses/BSD-3-Clause
* or see the "license.txt" file for more details.
*
* Author: Flavien Ronteix--Jacquet
* Software description: LatSeq measurement part core
*/
/*! \file test_latseq.c
* \brief latency sequence tool test program
* \author Flavien Ronteix--Jacquet
* \date 2020
* \version 1.0
* @ingroup util
*/
#define _GNU_SOURCE
#include <stdio.h>
#include <unistd.h>
#include <pthread.h>
#include "latseq.h"
double cpuf;
const char * test_log = "test";
volatile int oai_exit = 1; //Emulate global variable used by oai to indicate that oai is running
void print_usage(void)
{
printf("help test_latseq\n");
printf("h \t: Help\n");
printf("a \t: test_full() \t: a full unit test\n");
printf("i \t: test_init_and_close() \t: test a simple init/close case\n");
printf("t \t: test_multi_thread() \t: test multi-producers in different thread case\n");
printf("m \t: measure_log_measure() \t: measure time took by log_measure\n");
printf("n \t: measure_log_n() \t: measure time took by log_measure with n varargs\n");
printf("w \t: measure_writer() \t: measure time to write\n");
}
int test_init_and_close()
{
oai_exit = 0;
printf("[TEST] %s\n",__func__);
if(!init_latseq(test_log, 0)) {
printf("[ERROR] : init_latseq()\n");
exit(EXIT_FAILURE);
}
sleep(1);
if(!close_latseq()) {
printf("[ERROR] : close_latseq()\n");
exit(EXIT_FAILURE);
}
return 0;
}
int test_full()
{
oai_exit = 0;
printf("[TEST] %s\n",__func__);
if(!init_latseq(test_log, 0)) {
printf("[ERROR] : init_latseq()\n");
exit(EXIT_FAILURE);
}
//int num = 1000000;
int num = 1;
int i;
for (i=0; i < num; i++){
LATSEQ_P("full3 D", "ip%d", 0);
//sleep(1);
usleep(1);
LATSEQ_P("full2 D", "ip%d.mac%d", 0, 1);
}
printf("sizeof latseq_element : %ld\n", sizeof(struct latseq_element_t));
oai_exit = 1;
if(!close_latseq()) {
printf("[ERROR] : close_latseq()\n");
exit(EXIT_FAILURE);
}
return 0;
}
void thread_test1(void)
{
pthread_t thId = pthread_self();
printf("[TEST] [%ld] thread started\n", thId);
int i = 0;
while(!oai_exit) {
if (!i) {
LATSEQ_P("full3 D", "ip%d", 0);
usleep(11000);
LATSEQ_P("full2 D", "ip%d.mac%d", 0, 1);
i = 1;
continue;
}
}
pthread_exit(NULL);
}
void thread_test2(void)
{
pthread_t thId = pthread_self();
printf("[TEST] [%ld] thread started\n", thId);
int i = 0;
while(!oai_exit) {
if (!i) {
LATSEQ_P("full3 D", "ip%d", 1);
usleep(1000);
LATSEQ_P("full2 D", "ip%d.mac%d", 1, 1);
usleep(9000);
LATSEQ_P("full1 D", "ip%d.mac%d.phy%d", 1, 1, 4);
i = 1;
continue;
}
}
printf("[TEST] [%ld] thread stopped\n", thId);
pthread_exit(NULL);
}
int test_multithread()
{
oai_exit = 0;
printf("[TEST] %s\n",__func__);
if(!init_latseq(test_log, 0)) {
printf("[ERROR] : init_latseq()\n");
exit(EXIT_FAILURE);
}
pthread_t th1;
pthread_t th2;
pthread_create(&th1, NULL, (void *) &thread_test1, NULL);
pthread_create(&th2, NULL, (void *) &thread_test2, NULL);
usleep(25000);
oai_exit = 1;
pthread_join(th1, NULL);
pthread_join(th2, NULL);
if(!close_latseq()) {
printf("[ERROR] : close_latseq()\n");
exit(EXIT_FAILURE);
}
return 0;
}
// Repeat experiment 3 times for i in {1..3}; do ./test_latseq m | awk '{print $6}' | sed -r '/^\s*$/d' >> measurement_res.txt; done
int measure_log_measure()
{
oai_exit = 0;
printf("[TEST] %s\n",__func__);
if(!init_latseq(test_log, 0)) {
printf("[ERROR] : init_latseq()\n");
exit(EXIT_FAILURE);
}
#ifdef TEST_LATSEQ
struct timeval begin, end;
gettimeofday(&begin, NULL);
#endif
const uint32_t num_call = 1000000;
for (int i = 0; i < num_call; i++)
{
//LATSEQ_P("meas", "call.%d.%d.%d.%d.%d.%d.%d.%d.%d.%d", i,i,i,i,i,i,i,i,i,i);
LATSEQ_P("meas", "call.%d.%d.%d.%d.%d.%d.%d", i,i,i,i,i,i,i);
//LATSEQ_P("meas", "call.%d.%d.%d.%d.%d", i,i,i,i,i);
//LATSEQ_P("meas", "call.%d", i);
//usleep(1);
}
#ifdef TEST_LATSEQ
gettimeofday(&end, NULL);
#endif
oai_exit = 1;
//sleep(1);
if(!close_latseq()) {
printf("[ERROR] : close_latseq()\n");
exit(EXIT_FAILURE);
}
#ifdef TEST_LATSEQ
printf("[LATSEQ] %d log_measure took : %lu us\n", num_call, (end.tv_usec - begin.tv_usec)); //at 23-03, 0.0328usec
#endif
return 0;
}
int measure_log_n()
{
oai_exit = 0;
printf("[TEST] %s\n",__func__);
if(!init_latseq(test_log, 0)) {
printf("[ERROR] : init_latseq()\n");
exit(EXIT_FAILURE);
}
//usleep(10000); //TODO : with this, generate a corrupted size vs. prev_size
#ifdef TEST_LATSEQ
struct timeval begin, end;
gettimeofday(&begin, NULL);
long t1, t2, t3, t5, t10;
#endif
const uint32_t num_call = 1000;
int i;
for (i = 0; i < num_call; i++)
{
LATSEQ_P("meas1", "call.%d", i);
}
#ifdef TEST_LATSEQ
gettimeofday(&end, NULL);
t1 = end.tv_usec - begin.tv_usec;
gettimeofday(&begin, NULL);
#endif
//test n=2
for (i = 0; i < num_call; i++)
{
LATSEQ_P("meas2", "call.%d.%d", i,0);
}
#ifdef TEST_LATSEQ
gettimeofday(&end, NULL);
t2 = end.tv_usec - begin.tv_usec;
gettimeofday(&begin, NULL);
#endif
//test n=3
for (i = 0; i < num_call; i++)
{
LATSEQ_P("meas3", "call.%d.%d.%d", i,0,1);
}
#ifdef TEST_LATSEQ
gettimeofday(&end, NULL);
t3 = end.tv_usec - begin.tv_usec;
gettimeofday(&begin, NULL);
#endif
//test n=5
for (i = 0; i < num_call; i++)
{
LATSEQ_P("meas3", "call.%d.%d.%d.%d.%d", i,0,1,2,3);
}
#ifdef TEST_LATSEQ
gettimeofday(&end, NULL);
t5 = end.tv_usec - begin.tv_usec;
gettimeofday(&begin, NULL);
#endif
//test n=10 (max given by NB_DATA_IDENTIFIERS)
for (i = 0; i < num_call; i++)
{
LATSEQ_P("meas4", "call.%d.%d.%d.%d.%d.%d.%d.%d.%d.%d",i,0,1,2,3,4,5,7,8,9);
}
#ifdef TEST_LATSEQ
gettimeofday(&end, NULL);
t10 = end.tv_usec - begin.tv_usec;
#endif
oai_exit = 1;
sleep(1);
if(!close_latseq()) {
printf("[ERROR] : close_latseq()\n");
exit(EXIT_FAILURE);
}
#ifdef TEST_LATSEQ
printf("[LATSEQ] log_measure took :\n"); //at 23-03, 32.8ns
printf("\tvar_args=1 : %.1f ns/call\n", 1000*(double)t1/num_call); // mean : 19ns at 23-03
printf("\tvar_args=2 : %.1f ns/call\n", 1000*(double)t2/num_call); // mean : 22ns at 23-03
printf("\tvar_args=3 : %.1f ns/call\n", 1000*(double)t3/num_call); // mean : 25ns at 23-03
printf("\tvar_args=5 : %.1f ns/call\n", 1000*(double)t5/num_call); // mean : 32ns at 23-03
printf("\tvar_args=10 : %.1f ns/call\n", 1000*(double)t10/num_call); // mean : 61ns at 23-03
#endif
return 0;
}
void test_writer(FILE * f, char * tmps, int i)
{
sprintf(tmps, "a%d.b%d", i, i+1);
fprintf(f, "%d.%06d %s %s\n", 1, 234567, "D write", tmps);
}
/*
* Compiler avec -pg
* résultats au 6-04-2020
* % cumulative self self * total
* time seconds seconds calls ms/call ms/call name
* 71.46 0.05 0.05 1 50.02 70.03 measure_writer
* 28.58 0.07 0.02 10000000 0.00 0.00 test_writer
*/
int measure_writer()
{
oai_exit = 0;
printf("[TEST] %s\n",__func__);
FILE * fout = fopen("test1.lseq", "w");
//write header
char hdr[] = "# LatSeq format\n# By Alexandre Ferrieux and Flavien Ronteix Jacquet\n# timestamp\tU/D\tsrc--dest\tdataId\n#funcId ip.entry sdap.mapping sdap.header pdcp.txbuf pdcp.rohc pdcp.intcipher pdcp.header pdcp.routing rlc.am.txbuf rlc.am.seg rlc.am.header rlc.am.retbuf mac.mux mac.harq.[0-7] phy.crc phy.cbseg phy.msc phy.mod phy.map phy.ant\n";
fwrite(hdr, sizeof(char), sizeof(hdr) - 1, fout);
const int num_call = 1000000;
char * tmps;
tmps = calloc(2*10, sizeof(char));
#ifdef TEST_LATSEQ
struct timeval begin, end;
gettimeofday(&begin, NULL);
#endif
for (int i = 0; i < num_call; i++) {
test_writer(fout, tmps, i);
}
#ifdef TEST_LATSEQ
gettimeofday(&end, NULL);
printf("[LATSEQ] measure_write took : "); //at 23-03, 32.8ns
printf("%d writes : %.1ld us\n", num_call, (end.tv_usec - begin.tv_usec));
#endif
fclose(fout);
free(tmps);
oai_exit = 1;
return 0;
}
int main (int argc, char **argv)
{
#ifdef LATSEQ
printf("[TEST] #ifdef LATSEQ\n");
#endif
if (argc != 2) {
print_usage();
exit(-1);
}
char opt = (char)argv[1][0];
switch (opt)
{
case 'h':
print_usage();
break;
case 'i':
(void)test_init_and_close();
break;
case 'a':
(void)test_full();
break;
case 't':
(void)test_multithread();
break;
case 'm':
(void)measure_log_measure();
break;
case 'n':
(void)measure_log_n();
break;
case 'w':
(void)measure_writer();
break;
default:
print_usage();
break;
}
//#endif
oai_exit = 1;
return 0;
}
Markdown is supported
0%
or
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment