Re: [PATCH] app/testpmd: fix auto completion for indirect list action
Hello Ferruh, > But I guess it won't catch this issue, as it uses full flow commands. > This issue is related to the testpmd command parsing code. I wonder if > we can find a way to verify testpmd parsing code? What if flow command validation program breaks a tested command into tokens and then pass each token followed by the TAB key to the controlled testpmd process ? There are 3 possible outputs for the token + TAB sequence: 1. a valid token will trigger meaningful testpmd help ouput that can be matched. 2. invalid token output will fail [1]. 3. invalid token will crash the controlled testpmd process. I've compiled a small programm to test that idea. Please check it out. Regards, Gregory. commit e4a27c2c2892cfd408b473b18192b30927e4281c Author: Gregory Etelson Date: Sat Mar 23 11:38:44 2024 +0200 validate testpmd flow command diff --git a/Cargo.toml b/Cargo.toml new file mode 100644 index 000..3498868 --- /dev/null +++ b/Cargo.toml @@ -0,0 +1,12 @@ +[package] +name = "testpmd-validate" +version = "0.1.0" +edition = "2021" +rust-version = "1.76.0" + +# See more keys and their definitions at https://doc.rust-lang.org/cargo/reference/manifest.html + +[dependencies] +ssh2 = { version = "0.9.4", features = ["vendored-openssl"] } +time = "0.3.34" +regex = "1.10.4" diff --git a/src/main.rs b/src/main.rs new file mode 100644 index 000..90dfdac --- /dev/null +++ b/src/main.rs @@ -0,0 +1,128 @@ +use std::io::{Read, Write}; +use std::{io, thread, time}; +use std::path::Path; +use std::ops::Add; +use std::time::{SystemTime}; +use ssh2::{Channel, Error, ExtendedData, Session}; +use regex::{RegexSet}; + +fn continue_after_error(err:&io::Error) -> bool { +match err.kind() { +io::ErrorKind::WouldBlock => return true, +_ => return false, +} +} + +fn wrap_ssh(mut func:F) -> T +where F: FnMut() -> Result { +loop { +match func() { +Ok(val) => { return val }, +Err(ssh_err) => { +let io_err = io::Error::from(ssh_err); +if !continue_after_error(&io_err) { +panic!("ssh2 error: {:?}", io_err); +} +} +} +} +} + +fn rsh_write(channel:&mut Channel, buf:&str) { +match channel.write(buf.as_bytes()) { +Ok(_) => (), +Err(e) => panic!("write failure: {:?}", e) +} +} + +const RSH_READ_MAX_DURATION:time::Duration = time::Duration::from_millis(350); +const RSH_READ_IDLE_TIMEOUT:time::Duration = time::Duration::from_millis(10); +fn rsh_read(channel:&mut Channel) -> String { +let mut end = SystemTime::now().add(RSH_READ_MAX_DURATION); +let mut output = String::new(); +loop { +let mut buffer: [u8; 1024] = [0; 1024]; +match channel.read(&mut buffer) { +Ok(0) => { return output } +Ok(_) => { +let aux = String::from_utf8(buffer.into()).unwrap(); +// println!("{aux}"); +output.push_str(&aux); +end = SystemTime::now().add(RSH_READ_MAX_DURATION); +} +Err(err) => { +if !continue_after_error(&err) { panic!("read error {:?}", err) } +if SystemTime::now().gt(&end) { break; } +thread::sleep(RSH_READ_IDLE_TIMEOUT); +} +} +} +output +} + +const TESTPMD_PATH:&str = "/tmp/build/app"; +const TESTPMD_CMD:&str = "dpdk-testpmd -a :01:00.0 -- -i"; + +const TOKEN_PATTERN:[&str; 2] = [ +r#"(?m)\[.*\]:"#, +r#"(?m)\[RETURN]"#, +]; + +const CTRL_C:[u8;1] = [0x3]; + + +fn rsh_connect(hostname:&str) -> Channel { +let stream = std::net::TcpStream::connect(format!("{}:22", hostname)).unwrap(); +stream.set_nonblocking(true).unwrap(); +let mut session = Session::new().unwrap(); +let private_key = Path::new("/home/garik/.ssh/id_rsa"); +session.set_blocking(false); +session.set_tcp_stream(stream); +wrap_ssh(|| session.handshake()); +wrap_ssh(|| session.userauth_pubkey_file("root", None, &private_key, None)); +let mut ch = wrap_ssh(|| session.channel_session()); +wrap_ssh(|| ch.handle_extended_data(ExtendedData::Merge)); +wrap_ssh(|| ch.request_pty("vt100", None, None)); +ch +} + +fn validate_flow_command(command:&str, ch:&mut Channel) { +let rset = RegexSet::new(TOKEN_PATTERN).unwrap(); +let delay = time::Duration::from_millis(300); + +println!("validate: {command}"); +for token in command.split_whitespace() { +let candid = format!("{token} \t"); +rsh_write(ch, &candid); +print!("validate token \'{token}\' "); +thread::sleep(delay); +let output = rsh_read(ch); +if rset.is_match(&output) { +println!(" ok"); +} else { +println!("failed"); +println!(">>"); +println!("{output}"); +println!("<<"); +break; +} +}
Re: meson option to customize RTE_PKTMBUF_HEADROOM patch
So we right now (at WEKA) have a somewhat older version of DPDK that we have customized heavily, and I am going to to need to to make the headroom *dynamic* (passed in at run time, and per port.) We have this requirement because we need payload to be at a specific offset, but have to deal with different header lengths for IPv4 and now IPv6. My reason for pointing this out, is that I would dearly like if we could collaborate on this -- this change is going to touch pretty much every PMD (we don't need it on all of them as we only support a subset of PMDs, but its still a significant set.) I'm not sure if anyone else has considered such a need -- this particular message caught my eye as I'm looking specifically in this area right now. On Feb 15, 2024 at 11:02 AM -0800, Parthakumar Roy , wrote: > Hello, > Bruce Richardson suggested that I submit this patch - at IBM we needed to > adjust the pkt_mbuf_headroom for our application to work. This is my first > ever patch through a mailing list, I have only done it through Pull Requests > before, so let me know if I need to correct something. > > Message: > Add meson configuration option to adjust RTE_PKTMBUF_HEADROOM > > diff --git a/config/meson.build b/config/meson.build > index 7cd375e991..43b765ade1 100644 > --- a/config/meson.build > +++ b/config/meson.build > @@ -304,6 +304,7 @@ endforeach > dpdk_conf.set('RTE_MAX_ETHPORTS', get_option('max_ethports')) > dpdk_conf.set('RTE_LIBEAL_USE_HPET', get_option('use_hpet')) > dpdk_conf.set('RTE_ENABLE_TRACE_FP', get_option('enable_trace_fp')) > +dpdk_conf.set('RTE_PKTMBUF_HEADROOM', get_option('pkt_mbuf_headroom')) > # values which have defaults which may be overridden > dpdk_conf.set('RTE_MAX_VFIO_GROUPS', 64) > dpdk_conf.set('RTE_DRIVER_MEMPOOL_BUCKET_SIZE_KB', 64) > diff --git a/config/rte_config.h b/config/rte_config.h > index 7b8c85e948..a2bb4ea61b 100644 > --- a/config/rte_config.h > +++ b/config/rte_config.h > @@ -51,7 +51,6 @@ > > /* mbuf defines */ > #define RTE_MBUF_DEFAULT_MEMPOOL_OPS "ring_mp_mc" > -#define RTE_PKTMBUF_HEADROOM 128 > > /* ether defines */ > #define RTE_MAX_QUEUES_PER_PORT 1024 > diff --git a/meson_options.txt b/meson_options.txt > index 08528492f7..169fcc94c7 100644 > --- a/meson_options.txt > +++ b/meson_options.txt > @@ -36,6 +36,8 @@ option('machine', type: 'string', value: 'auto', > description: > 'Alias of cpu_instruction_set.') > option('max_ethports', type: 'integer', value: 32, description: > 'maximum number of Ethernet devices') > +option('pkt_mbuf_headroom', type: 'integer', value: 128, description: > + 'number of bytes skipped on Rx at the start of the packet buffer to > leave room for additional packet headers') > option('max_lcores', type: 'string', value: 'default', description: > 'Set maximum number of cores/threads supported by EAL; "default" is > different per-arch, "detect" detects the number of cores on the build > machine.') > option('max_numa_nodes', type: 'string', value: 'default', description: >
[PATCH v11 0/9] Logging unification and enhancements
Improvements and unification of logging library (for 24.07 release). This version works on all platforms: Linux, Windows and FreeBSD. This is update to rework patch set. It adds several new features to the console log output. * Putting a timestamp on console output which is useful for analyzing performance of startup codes. Timestamp is optional and must be enabled on command line. * Displaying console output with colors. It uses the standard conventions used by many other Linux commands for colorized display. The default is to enable color if the console output is going to a terminal. But it can be always on or disabled by command line flag. This default was chosen based on what dmesg(1) command does. I find color helpful because DPDK drivers and libraries print lots of not very useful messages. And having error messages highlighted in bold face helps. This might also get users to pay more attention to error messages. Many bug reports have earlier messages that are lost because there are so many info messages. * Use of syslog on Linux is replaced by using journal API (over unix domain socket). This replaces legacy syslog; (almost) all Linux distros have switched to journal. Will add a release note in next release (after this is merged) v11 - rework to be portable to Windows drop syslog support and support journal instead Stephen Hemminger (9): windows: make getopt functions have const properties eal: make eal_log_level_parse common eal: do not duplicate rte_init_alert() messages eal: change rte_exit() output to match rte_log() log: drop syslog support, and make code common log: add hook for printing log messages log: add timestamp option log: add support for systemd journal log: colorize log output app/test/test_eal_flags.c | 38 +- doc/guides/linux_gsg/linux_eal_parameters.rst | 27 - .../prog_guide/env_abstraction_layer.rst | 5 +- doc/guides/prog_guide/log_lib.rst | 41 +- lib/eal/common/eal_common_debug.c | 11 +- lib/eal/common/eal_common_options.c | 123 ++--- lib/eal/common/eal_internal_cfg.h | 2 +- lib/eal/common/eal_options.h | 7 +- lib/eal/freebsd/eal.c | 54 +- lib/eal/linux/eal.c | 52 +- lib/eal/unix/eal_debug.c | 3 +- lib/eal/windows/eal.c | 39 +- lib/eal/windows/getopt.c | 23 +- lib/eal/windows/include/getopt.h | 8 +- lib/log/log.c | 513 -- lib/log/log_freebsd.c | 12 - lib/log/log_internal.h| 16 +- lib/log/log_linux.c | 61 --- lib/log/log_windows.c | 18 - lib/log/meson.build | 5 +- lib/log/version.map | 2 + 21 files changed, 656 insertions(+), 404 deletions(-) delete mode 100644 lib/log/log_freebsd.c delete mode 100644 lib/log/log_linux.c delete mode 100644 lib/log/log_windows.c -- 2.43.0
[PATCH v11 1/9] windows: make getopt functions have const properties
Having different prototypes on different platforms can lead to lots of unnecessary workarounds. Looks like the version of getopt used from windows was based on an older out of date version from FreeBSD. This patch changes getopt, getopt_long, etc to have the same const attributes as Linux and FreeBSD. The changes are derived from the current FreeBSD version of getopt_long. Signed-off-by: Stephen Hemminger Acked-by: Tyler Retzlaff Acked-by: Dmitry Kozlyuk --- lib/eal/windows/getopt.c | 23 --- lib/eal/windows/include/getopt.h | 8 2 files changed, 16 insertions(+), 15 deletions(-) diff --git a/lib/eal/windows/getopt.c b/lib/eal/windows/getopt.c index a1f51c6c23..50ff71b930 100644 --- a/lib/eal/windows/getopt.c +++ b/lib/eal/windows/getopt.c @@ -20,7 +20,7 @@ #include #include -const char*optarg; /* argument associated with option */ +char*optarg; /* argument associated with option */ intopterr = 1; /* if error message should be printed */ intoptind = 1; /* index into parent argv vector */ intoptopt = '?'; /* character checked for validity */ @@ -39,9 +39,9 @@ static void pass(const char *a) {(void) a; } #defineBADARG ((*options == ':') ? (int)':' : (int)'?') #defineINORDER 1 -#defineEMSG"" +static char EMSG[] = ""; -static const char *place = EMSG; /* option letter processing */ +static char *place = EMSG; /* option letter processing */ /* XXX: set optreset to 1 rather than these two */ static int nonopt_start = -1; /* first non option argument (for permute) */ @@ -80,7 +80,7 @@ gcd(int a, int b) */ static void permute_args(int panonopt_start, int panonopt_end, int opt_end, - char **nargv) + char * const *nargv) { int cstart, cyclelen, i, j, ncycle, nnonopts, nopts, pos; char *swap; @@ -101,11 +101,12 @@ permute_args(int panonopt_start, int panonopt_end, int opt_end, pos -= nnonopts; else pos += nopts; + swap = nargv[pos]; /* LINTED const cast */ - ((char **) nargv)[pos] = nargv[cstart]; + ((char **)(uintptr_t)nargv)[pos] = nargv[cstart]; /* LINTED const cast */ - ((char **)nargv)[cstart] = swap; + ((char **)(uintptr_t)nargv)[cstart] = swap; } } } @@ -116,7 +117,7 @@ permute_args(int panonopt_start, int panonopt_end, int opt_end, * Returns -1 if short_too is set and the option does not match long_options. */ static int -parse_long_options(char **nargv, const char *options, +parse_long_options(char * const *nargv, const char *options, const struct option *long_options, int *idx, int short_too) { const char *current_argv; @@ -236,7 +237,7 @@ parse_long_options(char **nargv, const char *options, * Parse argc/argv argument vector. Called by user level routines. */ static int -getopt_internal(int nargc, char **nargv, const char *options, +getopt_internal(int nargc, char *const nargv[], const char *options, const struct option *long_options, int *idx, int flags) { char *oli; /* option letter list index */ @@ -434,7 +435,7 @@ getopt_internal(int nargc, char **nargv, const char *options, * Parse argc/argv argument vector. */ int -getopt(int nargc, char *nargv[], const char *options) +getopt(int nargc, char *const nargv[], const char *options) { return getopt_internal(nargc, nargv, options, NULL, NULL, FLAG_PERMUTE); @@ -445,7 +446,7 @@ getopt(int nargc, char *nargv[], const char *options) * Parse argc/argv argument vector. */ int -getopt_long(int nargc, char *nargv[], const char *options, +getopt_long(int nargc, char *const nargv[], const char *options, const struct option *long_options, int *idx) { @@ -458,7 +459,7 @@ getopt_long(int nargc, char *nargv[], const char *options, * Parse argc/argv argument vector. */ int -getopt_long_only(int nargc, char *nargv[], const char *options, +getopt_long_only(int nargc, char *const nargv[], const char *options, const struct option *long_options, int *idx) { diff --git a/lib/eal/windows/include/getopt.h b/lib/eal/windows/include/getopt.h index 6f57af454b..e4cf6873cb 100644 --- a/lib/eal/windows/include/getopt.h +++ b/lib/eal/windows/include/getopt.h @@ -44,7 +44,7 @@ /** argument to current option, or NULL if it has none */ -extern const char *optarg; +extern char *optarg; /** Current position in arg string. Starts from 1. * Setting to 0 resets state. */ @@ -80,14 +80,14 @@ struct option { }; /** Compat: getopt */ -int getopt(int argc, char *argv[], const char *options); +int getopt(int argc, char *const
[PATCH v11 2/9] eal: make eal_log_level_parse common
The code to parse for log-level option should be same on all OS variants. Signed-off-by: Stephen Hemminger --- lib/eal/common/eal_common_options.c | 46 + lib/eal/common/eal_options.h| 1 + lib/eal/freebsd/eal.c | 42 -- lib/eal/linux/eal.c | 39 lib/eal/windows/eal.c | 35 -- 5 files changed, 47 insertions(+), 116 deletions(-) diff --git a/lib/eal/common/eal_common_options.c b/lib/eal/common/eal_common_options.c index e541f07939..5435399b85 100644 --- a/lib/eal/common/eal_common_options.c +++ b/lib/eal/common/eal_common_options.c @@ -1640,6 +1640,51 @@ eal_parse_huge_unlink(const char *arg, struct hugepage_file_discipline *out) return -1; } +/* Parse the all arguments looking for log related ones */ +int +eal_log_level_parse(int argc, char * const argv[]) +{ + struct internal_config *internal_conf = eal_get_internal_configuration(); + int option_index, opt; + const int old_optind = optind; + const int old_optopt = optopt; + const int old_opterr = opterr; + char *old_optarg = optarg; +#ifdef RTE_EXEC_ENV_FREEBSD + const int old_optreset = optreset; + optreset = 1; +#endif + + optind = 1; + opterr = 0; + + while ((opt = getopt_long(argc, argv, eal_short_options, + eal_long_options, &option_index)) != EOF) { + + switch (opt) { + case OPT_LOG_LEVEL_NUM: + if (eal_parse_common_option(opt, optarg, internal_conf) < 0) + return -1; + break; + case '?': + /* getopt is not happy, stop right now */ + goto out; + default: + continue; + } + } +out: + /* restore getopt lib */ + optind = old_optind; + optopt = old_optopt; + optarg = old_optarg; + opterr = old_opterr; +#ifdef RTE_EXEC_ENV_FREEBSD + optreset = old_optreset; +#endif + return 0; +} + int eal_parse_common_option(int opt, const char *optarg, struct internal_config *conf) @@ -2173,6 +2218,7 @@ rte_vect_set_max_simd_bitwidth(uint16_t bitwidth) return 0; } + void eal_common_usage(void) { diff --git a/lib/eal/common/eal_options.h b/lib/eal/common/eal_options.h index 3cc9cb6412..f3f2e104f6 100644 --- a/lib/eal/common/eal_options.h +++ b/lib/eal/common/eal_options.h @@ -96,6 +96,7 @@ enum { extern const char eal_short_options[]; extern const struct option eal_long_options[]; +int eal_log_level_parse(int argc, char * const argv[]); int eal_parse_common_option(int opt, const char *argv, struct internal_config *conf); int eal_option_device_parse(void); diff --git a/lib/eal/freebsd/eal.c b/lib/eal/freebsd/eal.c index bab77118e9..9825bcea0b 100644 --- a/lib/eal/freebsd/eal.c +++ b/lib/eal/freebsd/eal.c @@ -363,48 +363,6 @@ eal_get_hugepage_mem_size(void) return (size < SIZE_MAX) ? (size_t)(size) : SIZE_MAX; } -/* Parse the arguments for --log-level only */ -static void -eal_log_level_parse(int argc, char **argv) -{ - int opt; - char **argvopt; - int option_index; - const int old_optind = optind; - const int old_optopt = optopt; - const int old_optreset = optreset; - char * const old_optarg = optarg; - struct internal_config *internal_conf = - eal_get_internal_configuration(); - - argvopt = argv; - optind = 1; - optreset = 1; - - while ((opt = getopt_long(argc, argvopt, eal_short_options, - eal_long_options, &option_index)) != EOF) { - - int ret; - - /* getopt is not happy, stop right now */ - if (opt == '?') - break; - - ret = (opt == OPT_LOG_LEVEL_NUM) ? - eal_parse_common_option(opt, optarg, internal_conf) : 0; - - /* common parser is not happy */ - if (ret < 0) - break; - } - - /* restore getopt lib */ - optind = old_optind; - optopt = old_optopt; - optreset = old_optreset; - optarg = old_optarg; -} - /* Parse the argument given in the command line of the application */ static int eal_parse_args(int argc, char **argv) diff --git a/lib/eal/linux/eal.c b/lib/eal/linux/eal.c index fd422f1f62..bffeb1f34e 100644 --- a/lib/eal/linux/eal.c +++ b/lib/eal/linux/eal.c @@ -546,45 +546,6 @@ eal_parse_vfio_vf_token(const char *vf_token) return -1; } -/* Parse the arguments for --log-level only */ -static void -eal_log_level_parse(int argc, char **argv) -{ - int opt; - char **argvopt; - int option_index; - const int old_optind = optind; - const
[PATCH v11 3/9] eal: do not duplicate rte_init_alert() messages
The message already goes through logging, and does not need to be printed on stderr. Message level should be ALERT to match function name. Signed-off-by: Stephen Hemminger --- lib/eal/freebsd/eal.c | 3 +-- lib/eal/linux/eal.c | 3 +-- 2 files changed, 2 insertions(+), 4 deletions(-) diff --git a/lib/eal/freebsd/eal.c b/lib/eal/freebsd/eal.c index 9825bcea0b..17b56f38aa 100644 --- a/lib/eal/freebsd/eal.c +++ b/lib/eal/freebsd/eal.c @@ -529,8 +529,7 @@ rte_eal_iopl_init(void) static void rte_eal_init_alert(const char *msg) { - fprintf(stderr, "EAL: FATAL: %s\n", msg); - EAL_LOG(ERR, "%s", msg); + EAL_LOG(ALERT, "%s", msg); } /* Launch threads, called at application init(). */ diff --git a/lib/eal/linux/eal.c b/lib/eal/linux/eal.c index bffeb1f34e..23dc26b124 100644 --- a/lib/eal/linux/eal.c +++ b/lib/eal/linux/eal.c @@ -840,8 +840,7 @@ static int rte_eal_vfio_setup(void) static void rte_eal_init_alert(const char *msg) { - fprintf(stderr, "EAL: FATAL: %s\n", msg); - EAL_LOG(ERR, "%s", msg); + EAL_LOG(ALERT, "%s", msg); } /* -- 2.43.0
[PATCH v11 4/9] eal: change rte_exit() output to match rte_log()
The rte_exit() output format confuses the timestamp and coloring options. Change it to use be a single line with proper prefix. Before: [ 0.006481] EAL: Error - exiting with code: 1 Cause: [ 0.006489] Cannot init EAL: Permission denied After: [ 0.006238] EAL: Error - exiting with code: 1 [ 0.006250] EAL: Cause - Cannot init EAL: Permission denied Signed-off-by: Stephen Hemminger --- lib/eal/common/eal_common_debug.c | 11 ++- 1 file changed, 6 insertions(+), 5 deletions(-) diff --git a/lib/eal/common/eal_common_debug.c b/lib/eal/common/eal_common_debug.c index 3e77995896..3f37879144 100644 --- a/lib/eal/common/eal_common_debug.c +++ b/lib/eal/common/eal_common_debug.c @@ -34,17 +34,18 @@ void rte_exit(int exit_code, const char *format, ...) { va_list ap; + char *msg = NULL; if (exit_code != 0) - RTE_LOG(CRIT, EAL, "Error - exiting with code: %d\n" - " Cause: ", exit_code); + EAL_LOG(CRIT, "Error - exiting with code: %d", exit_code); va_start(ap, format); - rte_vlog(RTE_LOG_CRIT, RTE_LOGTYPE_EAL, format, ap); + vasprintf(&msg, format, ap); va_end(ap); + rte_log(RTE_LOG_CRIT, RTE_LOGTYPE_EAL, "EAL: Cause - %s", msg); + if (rte_eal_cleanup() != 0 && rte_errno != EALREADY) - EAL_LOG(CRIT, - "EAL could not release all resources"); + EAL_LOG(CRIT, "EAL could not release all resources"); exit(exit_code); } -- 2.43.0
[PATCH v11 5/9] log: drop syslog support, and make code common
This patch removes syslog support from logging. Which allows the logging code to all be common across Linux, Windows and FreeBSD. It also initializes log subsystem much earlier in the init process so that all messages get processed. It drops syslog was only used on Linux. Modern Linux systems have systemd and journal support. A later patch will add direct native journal support. Removing syslog means lots of other parts of the log system can be simplified and made portable. Remove the syslog tests and documentation as well. Signed-off-by: Stephen Hemminger --- app/test/test_eal_flags.c | 21 +-- doc/guides/linux_gsg/linux_eal_parameters.rst | 27 .../prog_guide/env_abstraction_layer.rst | 5 +- doc/guides/prog_guide/log_lib.rst | 3 +- lib/eal/common/eal_common_options.c | 62 --- lib/eal/common/eal_internal_cfg.h | 2 +- lib/eal/common/eal_options.h | 2 - lib/eal/freebsd/eal.c | 9 +-- lib/eal/linux/eal.c | 10 +-- lib/eal/unix/eal_debug.c | 3 +- lib/eal/windows/eal.c | 4 +- lib/log/log.c | 46 +- lib/log/log_freebsd.c | 12 lib/log/log_internal.h| 2 +- lib/log/log_linux.c | 61 -- lib/log/log_windows.c | 18 -- lib/log/meson.build | 5 +- 17 files changed, 34 insertions(+), 258 deletions(-) delete mode 100644 lib/log/log_freebsd.c delete mode 100644 lib/log/log_linux.c delete mode 100644 lib/log/log_windows.c diff --git a/app/test/test_eal_flags.c b/app/test/test_eal_flags.c index 6cb4b06757..bea5465168 100644 --- a/app/test/test_eal_flags.c +++ b/app/test/test_eal_flags.c @@ -984,17 +984,10 @@ test_misc_flags(void) const char *argv1[] = {prgname, prefix, mp_flag, "--no-pci"}; /* With -v */ const char *argv2[] = {prgname, prefix, mp_flag, "-v"}; - /* With valid --syslog */ - const char *argv3[] = {prgname, prefix, mp_flag, - "--syslog", "syslog"}; - /* With empty --syslog (should fail) */ - const char *argv4[] = {prgname, prefix, mp_flag, "--syslog"}; - /* With invalid --syslog */ - const char *argv5[] = {prgname, prefix, mp_flag, "--syslog", "error"}; + /* With no-sh-conf, also use no-huge to ensure this test runs on BSD */ const char *argv6[] = {prgname, "-m", DEFAULT_MEM_SIZE, no_shconf, nosh_prefix, no_huge}; - /* With --huge-dir */ const char *argv7[] = {prgname, "-m", DEFAULT_MEM_SIZE, "--file-prefix=hugedir", "--huge-dir", hugepath}; @@ -1079,18 +1072,6 @@ test_misc_flags(void) return 0; #endif - if (launch_proc(argv3) != 0) { - printf("Error - process did not run ok with --syslog flag\n"); - goto fail; - } - if (launch_proc(argv4) == 0) { - printf("Error - process run ok with empty --syslog flag\n"); - goto fail; - } - if (launch_proc(argv5) == 0) { - printf("Error - process run ok with invalid --syslog flag\n"); - goto fail; - } if (launch_proc(argv7) != 0) { printf("Error - process did not run ok with --huge-dir flag\n"); goto fail; diff --git a/doc/guides/linux_gsg/linux_eal_parameters.rst b/doc/guides/linux_gsg/linux_eal_parameters.rst index ea8f381391..d86f94d8a8 100644 --- a/doc/guides/linux_gsg/linux_eal_parameters.rst +++ b/doc/guides/linux_gsg/linux_eal_parameters.rst @@ -108,30 +108,3 @@ Memory-related options * ``--match-allocations`` Free hugepages back to system exactly as they were originally allocated. - -Other options -~ - -* ``--syslog `` - -Set syslog facility. Valid syslog facilities are:: - -auth -cron -daemon -ftp -kern -lpr -mail -news -syslog -user -uucp -local0 -local1 -local2 -local3 -local4 -local5 -local6 -local7 diff --git a/doc/guides/prog_guide/env_abstraction_layer.rst b/doc/guides/prog_guide/env_abstraction_layer.rst index 9559c12a98..9a73628907 100644 --- a/doc/guides/prog_guide/env_abstraction_layer.rst +++ b/doc/guides/prog_guide/env_abstraction_layer.rst @@ -855,9 +855,8 @@ Signal Safety Other functions are not signal safe because they use one or more library routines that are not themselves signal safe. For example, calling ``rte_panic()`` is not safe in a signal handler - because it uses ``rte_log()`` and ``rte_log()`` calls the - ``syslog()`` library function which is in the list of - signal safe functions in + because it uses ``rte_l
[PATCH v11 6/9] log: add hook for printing log messages
This is useful for when decorating log output for console or journal. Provide basic version in this patch. No functional changes in this patch, just infrastructure addition. Signed-off-by: Stephen Hemminger --- lib/log/log.c | 19 --- 1 file changed, 16 insertions(+), 3 deletions(-) diff --git a/lib/log/log.c b/lib/log/log.c index 4c8666ac93..4cc871911c 100644 --- a/lib/log/log.c +++ b/lib/log/log.c @@ -26,16 +26,21 @@ struct rte_log_dynamic_type { uint32_t loglevel; }; +typedef int (*log_print_t)(FILE *f, uint32_t level, const char *fmt, va_list ap); +static int log_print(FILE *f, uint32_t level, const char *format, va_list ap); + /** The rte_log structure. */ static struct rte_logs { uint32_t type; /**< Bitfield with enabled logs. */ uint32_t level; /**< Log level. */ FILE *file; /**< Output file set by rte_openlog_stream, or NULL. */ + log_print_t print_func; size_t dynamic_types_len; struct rte_log_dynamic_type *dynamic_types; } rte_logs = { .type = UINT32_MAX, .level = RTE_LOG_DEBUG, + .print_func = log_print, }; struct rte_eal_opt_loglevel { @@ -67,8 +72,6 @@ struct log_cur_msg { /* per core log */ static RTE_DEFINE_PER_LCORE(struct log_cur_msg, log_cur_msg); -/* default logs */ - /* Change the stream that will be used by logging system */ int rte_openlog_stream(FILE *f) @@ -77,6 +80,7 @@ rte_openlog_stream(FILE *f) fclose(rte_logs.file); rte_logs.file = f; + rte_logs.print_func = log_print; return 0; } @@ -473,7 +477,7 @@ rte_vlog(uint32_t level, uint32_t logtype, const char *format, va_list ap) RTE_PER_LCORE(log_cur_msg).loglevel = level; RTE_PER_LCORE(log_cur_msg).logtype = logtype; - ret = vfprintf(f, format, ap); + ret = (*rte_logs.print_func)(f, level, format, ap); fflush(f); return ret; } @@ -509,6 +513,15 @@ rte_eal_log_cleanup(void) } } +/* default log print function */ +__rte_format_printf(3, 0) +static int +log_print(FILE *f, uint32_t level __rte_unused, + const char *format, va_list ap) +{ + return vfprintf(f, format, ap); +} + /* initialize logging */ void eal_log_init(const char *id __rte_unused) -- 2.43.0
[PATCH v11 7/9] log: add timestamp option
When debugging driver or startup issues, it is useful to have a timestamp on each message printed. The messages in syslog already have a timestamp, but often syslog is not available during testing. There are multiple timestamp formats similar to Linux dmesg. The default is time relative since startup (when first step of logging initialization is done by constructor). Other alternative formats are delta, ctime, reltime and iso formats. Example: $ dpdk-testpmd --log-timestamp -- -i [ 0.008610] EAL: Detected CPU lcores: 8 [ 0.008634] EAL: Detected NUMA nodes: 1 [ 0.008792] EAL: Detected static linkage of DPDK [ 0.010620] EAL: Multi-process socket /var/run/dpdk/rte/mp_socket [ 0.012618] EAL: Selected IOVA mode 'VA' [ 0.016675] testpmd: No probed ethernet devices Interactive-mode selected Signed-off-by: Stephen Hemminger --- app/test/test_eal_flags.c | 17 +++ doc/guides/prog_guide/log_lib.rst | 26 + lib/eal/common/eal_common_options.c | 14 ++- lib/eal/common/eal_options.h| 2 + lib/log/log.c | 168 +++- lib/log/log_internal.h | 9 ++ lib/log/version.map | 1 + 7 files changed, 234 insertions(+), 3 deletions(-) diff --git a/app/test/test_eal_flags.c b/app/test/test_eal_flags.c index bea5465168..def74e34d5 100644 --- a/app/test/test_eal_flags.c +++ b/app/test/test_eal_flags.c @@ -1048,6 +1048,14 @@ test_misc_flags(void) const char * const argv22[] = {prgname, prefix, mp_flag, "--huge-worker-stack=512"}; + /* Try running with --log-timestamp */ + const char * const argv23[] = {prgname, prefix, mp_flag, + "--log-timestamp" }; + + /* Try running with --log-timestamp=iso */ + const char * const argv24[] = {prgname, prefix, mp_flag, + "--log-timestamp=iso" }; + /* run all tests also applicable to FreeBSD first */ if (launch_proc(argv0) == 0) { @@ -1143,6 +1151,15 @@ test_misc_flags(void) printf("Error - process did not run ok with --huge-worker-stack=size parameter\n"); goto fail; } + if (launch_proc(argv23) != 0) { + printf("Error - process did not run ok with --log-timestamp parameter\n"); + goto fail; + } + if (launch_proc(argv24) != 0) { + printf("Error - process did not run ok with --log-timestamp=iso parameter\n"); + goto fail; + } + rmdir(hugepath_dir3); rmdir(hugepath_dir2); diff --git a/doc/guides/prog_guide/log_lib.rst b/doc/guides/prog_guide/log_lib.rst index 17ed8426b2..83949cce35 100644 --- a/doc/guides/prog_guide/log_lib.rst +++ b/doc/guides/prog_guide/log_lib.rst @@ -58,6 +58,32 @@ For example:: Within an application, the same result can be got using the ``rte_log_set_level_pattern()`` or ``rte_log_set_level_regex()`` APIs. +Console timestamp +~ + +An optional timestamp can be added before each message when printing on the console +by adding the ``--log-timestamp`` option. +For example:: + + /path/to/app --log-level=lib.*:debug --log-timestamp + +Multiple timestamp alternative timestamp formats are available: + +.. csv-table:: Log time stamp format + :header: "Format", "Description", "Example" + :widths: 6, 30, 32 + + "ctime", "Unix ctime", "``[Wed Mar 20 07:26:12 2024]``" + "delta", "Offset since last", "``[<3.162373>]``" + "reltime", "Seconds since last or time if minute changed", "``[ +3.001791]`` or ``[Mar20 07:26:12]``" + "iso", "ISO-8601", "``[2024-03-20T07:26:12−07:00]``" + +To prefix all console messages with ISO format time the syntax is:: + + /path/to/app --log-timestamp=iso + + + Using Logging APIs to Generate Log Messages --- diff --git a/lib/eal/common/eal_common_options.c b/lib/eal/common/eal_common_options.c index 73167d4603..bc6d87266d 100644 --- a/lib/eal/common/eal_common_options.c +++ b/lib/eal/common/eal_common_options.c @@ -74,6 +74,7 @@ eal_long_options[] = { {OPT_IOVA_MODE, 1, NULL, OPT_IOVA_MODE_NUM}, {OPT_LCORES,1, NULL, OPT_LCORES_NUM }, {OPT_LOG_LEVEL, 1, NULL, OPT_LOG_LEVEL_NUM}, + {OPT_LOG_TIMESTAMP, 2, NULL, OPT_LOG_TIMESTAMP_NUM}, {OPT_TRACE, 1, NULL, OPT_TRACE_NUM}, {OPT_TRACE_DIR, 1, NULL, OPT_TRACE_DIR_NUM}, {OPT_TRACE_BUF_SIZE,1, NULL, OPT_TRACE_BUF_SIZE_NUM }, @@ -1614,6 +1615,7 @@ eal_log_level_parse(int argc, char * const argv[]) switch (opt) { case OPT_LOG_LEVEL_NUM: + case OPT_LOG_TIMESTAMP_NUM: if (eal_parse_common_option(opt, optarg, internal_conf) < 0) return -1;
[PATCH v11 8/9] log: add support for systemd journal
If DPDK application is being run as a systemd service, then it can use the journal protocol which allows putting more information in the log such as priority and other information. The use of journal protocol is automatically detected and handled. Rather than having a dependency on libsystemd, just use the protocol directly as defined in: https://systemd.io/JOURNAL_NATIVE_PROTOCOL/ The journal protocol supports more information that could be added later. Signed-off-by: Stephen Hemminger --- lib/log/log.c | 141 -- 1 file changed, 136 insertions(+), 5 deletions(-) diff --git a/lib/log/log.c b/lib/log/log.c index bd488dff1b..4cfa160e3b 100644 --- a/lib/log/log.c +++ b/lib/log/log.c @@ -13,15 +13,20 @@ #include #include +#ifdef RTE_EXEC_ENV_WINDOWS +#include +#else +#include +#include +#include +#include +#endif + #include #include #include "log_internal.h" -#ifdef RTE_EXEC_ENV_WINDOWS -#include -#endif - struct rte_log_dynamic_type { const char *name; uint32_t loglevel; @@ -39,11 +44,13 @@ enum eal_log_time_format { typedef int (*log_print_t)(FILE *f, uint32_t level, const char *fmt, va_list ap); static int log_print(FILE *f, uint32_t level, const char *format, va_list ap); + /** The rte_log structure. */ static struct rte_logs { uint32_t type; /**< Bitfield with enabled logs. */ uint32_t level; /**< Log level. */ FILE *file; /**< Output file set by rte_openlog_stream, or NULL. */ + int journal_fd; /**< Journal file descriptor if using */ log_print_t print_func; enum eal_log_time_format time_format; @@ -681,6 +688,116 @@ log_print_with_timestamp(FILE *f, uint32_t level, return log_print(f, level, format, ap); } +#ifdef RTE_EXEC_ENV_LINUX +/* + * send message using journal protocol to journald + */ +__rte_format_printf(3, 0) +static int +journal_print(FILE *f __rte_unused, uint32_t level, const char *format, va_list ap) +{ + struct iovec iov[3]; + char *buf = NULL; + size_t len; + char msg[] = "MESSAGE="; + char *prio; + + iov[0].iov_base = msg; + iov[0].iov_len = strlen(msg); + + len = vasprintf(&buf, format, ap); + if (len == 0) + return 0; + + /* check that message ends with newline */ + if (buf[len - 1] != '\n') { + char *clone = alloca(len + 1); + if (clone == NULL) + return 0; + memcpy(clone, buf, len); + clone[len++] = '\n'; + buf = clone; + } + + iov[1].iov_base = buf; + iov[1].iov_len = len; + + /* priority value between 0 ("emerg") and 7 ("debug") */ + len = asprintf(&prio, "PRIORITY=%i\n", level - 1); + iov[2].iov_base = prio; + iov[2].iov_len = len; + + return writev(rte_logs.journal_fd, iov, 3); +} + +static void +journal_send_id(int fd, const char *id) +{ + char *syslog_id = NULL; + size_t len; + + len = asprintf(&syslog_id, "SYSLOG_IDENTIFIER=%s\n", id); + if (len > 0) + write(fd, syslog_id, len); + +} + +/* + * Check if stderr is going to system journal. + * This is the documented way to handle systemd journal + * + * See: https://systemd.io/JOURNAL_NATIVE_PROTOCOL/ + * + */ +static bool +using_journal(void) +{ + char *jenv, *endp = NULL; + struct stat st; + unsigned long dev, ino; + + jenv = getenv("JOURNAL_STREAM"); + if (jenv == NULL) + return false; + + if (fstat(STDERR_FILENO, &st) < 0) + return false; + + /* systemd sets colon-separated list of device and inode number */ + dev = strtoul(jenv, &endp, 10); + if (endp == NULL || *endp != ':') + return false; /* missing colon */ + + ino = strtoul(endp + 1, NULL, 10); + + return dev == st.st_dev && ino == st.st_ino; +} + +/* + * If we are being run as systemd service and stderr is going to journal + * then upgrade to use journal protocol. + */ +static int +open_journal(void) +{ + struct sockaddr_un sun = { + .sun_family = AF_UNIX, + .sun_path = "/run/systemd/journal/socket", + }; + int s; + + s = socket(AF_UNIX, SOCK_DGRAM, 0); + if (s < 0) + return -1; + + if (connect(s, (struct sockaddr *)&sun, sizeof(sun)) < 0) { + close(s); + return -1; + } + return s; +} +#endif + /* initialize logging */ void eal_log_init(const char *id __rte_unused) @@ -689,8 +806,22 @@ eal_log_init(const char *id __rte_unused) if (rte_logs.file != NULL) return; - if (rte_logs.time_format != EAL_LOG_TIMESTAMP_NONE) +#ifdef RTE_EXEC_ENV_LINUX + if (using_journal()) { + int jfd = open_journal(); + + if (jfd < 0) { + RTE_LOG_LINE(NOTIC
[PATCH v11 9/9] log: colorize log output
Like dmesg, colorize the log output (unless redirected to file). Timestamp is green, the subsystem is in yellow and the message is red if urgent, boldface if an error, and normal for info and debug messages. Signed-off-by: Stephen Hemminger --- doc/guides/prog_guide/log_lib.rst | 14 ++- lib/eal/common/eal_common_options.c | 1 + lib/eal/common/eal_options.h| 2 + lib/log/log.c | 153 +++- lib/log/log_internal.h | 5 + lib/log/version.map | 1 + 6 files changed, 173 insertions(+), 3 deletions(-) diff --git a/doc/guides/prog_guide/log_lib.rst b/doc/guides/prog_guide/log_lib.rst index 83949cce35..e0cb9bb9ed 100644 --- a/doc/guides/prog_guide/log_lib.rst +++ b/doc/guides/prog_guide/log_lib.rst @@ -58,6 +58,19 @@ For example:: Within an application, the same result can be got using the ``rte_log_set_level_pattern()`` or ``rte_log_set_level_regex()`` APIs. +Color output + + +It is useful ot be able see important messages highlighted. This is controlled by the +``--log-color`` option. The optional argument ``when`` can be ``auto``, ``never``, +or ``always``.The default setting is ``auto`` which enables color when the output to +``stderr`` is a terminal. If the ``when`` argument is omitted, it defaults to ``always``. + +For example to turn off all coloring:: + + /path/to/app --log-color=none + + Console timestamp ~ @@ -83,7 +96,6 @@ To prefix all console messages with ISO format time the syntax is:: /path/to/app --log-timestamp=iso - Using Logging APIs to Generate Log Messages --- diff --git a/lib/eal/common/eal_common_options.c b/lib/eal/common/eal_common_options.c index bc6d87266d..0da6729c64 100644 --- a/lib/eal/common/eal_common_options.c +++ b/lib/eal/common/eal_common_options.c @@ -75,6 +75,7 @@ eal_long_options[] = { {OPT_LCORES,1, NULL, OPT_LCORES_NUM }, {OPT_LOG_LEVEL, 1, NULL, OPT_LOG_LEVEL_NUM}, {OPT_LOG_TIMESTAMP, 2, NULL, OPT_LOG_TIMESTAMP_NUM}, + {OPT_LOG_COLOR, 1, NULL, OPT_LOG_COLOR_NUM}, {OPT_TRACE, 1, NULL, OPT_TRACE_NUM}, {OPT_TRACE_DIR, 1, NULL, OPT_TRACE_DIR_NUM}, {OPT_TRACE_BUF_SIZE,1, NULL, OPT_TRACE_BUF_SIZE_NUM }, diff --git a/lib/eal/common/eal_options.h b/lib/eal/common/eal_options.h index 197b7b25ef..c1696d75e5 100644 --- a/lib/eal/common/eal_options.h +++ b/lib/eal/common/eal_options.h @@ -37,6 +37,8 @@ enum { OPT_LOG_LEVEL_NUM, #define OPT_LOG_TIMESTAMP "log-timestamp" OPT_LOG_TIMESTAMP_NUM, +#define OPT_LOG_COLOR"log-color" + OPT_LOG_COLOR_NUM, #define OPT_TRACE "trace" OPT_TRACE_NUM, #define OPT_TRACE_DIR "trace-dir" diff --git a/lib/log/log.c b/lib/log/log.c index 4cfa160e3b..e75ed804ec 100644 --- a/lib/log/log.c +++ b/lib/log/log.c @@ -22,6 +22,7 @@ #include #endif +#include #include #include @@ -41,6 +42,12 @@ enum eal_log_time_format { EAL_LOG_TIMESTAMP_ISO, }; +enum eal_log_color { + EAL_LOG_COLOR_AUTO = 0, /* default */ + EAL_LOG_COLOR_NEVER, + EAL_LOG_COLOR_ALWAYS, +}; + typedef int (*log_print_t)(FILE *f, uint32_t level, const char *fmt, va_list ap); static int log_print(FILE *f, uint32_t level, const char *format, va_list ap); @@ -53,6 +60,7 @@ static struct rte_logs { int journal_fd; /**< Journal file descriptor if using */ log_print_t print_func; + enum eal_log_color color_mode; enum eal_log_time_format time_format; struct timespec started; /* when log was initialized */ struct timespec previous; /* when last msg was printed */ @@ -665,6 +673,74 @@ format_timestamp(char *tsbuf, size_t tsbuflen) return 0; } +enum color { + COLOR_NONE, + COLOR_RED, + COLOR_GREEN, + COLOR_YELLOW, + COLOR_BLUE, + COLOR_MAGENTA, + COLOR_CYAN, + COLOR_WHITE, + COLOR_BOLD, + COLOR_CLEAR +}; + +static const char * const color_code[] = { + [COLOR_NONE]= "", + [COLOR_RED] = "\e[31m", + [COLOR_GREEN] = "\e[32m", + [COLOR_YELLOW] = "\e[33m", + [COLOR_BLUE]= "\e[34m", + [COLOR_MAGENTA] = "\e[35m", + [COLOR_CYAN]= "\e[36m", + [COLOR_WHITE] = "\e[37m", + [COLOR_BOLD]= "\e[1m", + [COLOR_CLEAR] = "\e[0m", +}; + +__rte_format_printf(3, 4) +static int color_fprintf(FILE *out, enum color color, const char *fmt, ...) +{ + va_list args; + int ret = 0; + + va_start(args, fmt); + ret = fprintf(out, "%s", color_code[color]); + ret += vfprintf(out, fmt, args); + ret += fprintf(out, "%s", color_code[COLOR_CLEAR]); + + return ret; +} + +static ssize_t +color_log_write(FILE *f, int level, char *msg)