Zephyr shell & log timestamp format

Hi All,

How do I get the raw timestamp in the shell out ?
I did try several log timestamp settings but no success.

Observer behavior:

*** Booting Zephyr OS build v3.0.99-ncs1-1 ***
[00:00:00.252,929] <inf> app_event_manager: e:module_state_event module:main state:READY

Expected beahaviour

*** Booting Zephyr OS build v3.0.99-ncs1-1 ***
[00008291] <inf> app_event_manager: e:module_state_event module:main state:READY

I wish for the raw timestamp in both log & shell responses.


System setup

CONFIG_LOG=y
CONFIG_LOG_DEFAULT_LEVEL=4
CONFIG_LOG_PRINTK=y
CONFIG_LOG_MODE_DEFERRED=y
CONFIG_LOG_MODE_OVERFLOW=y
CONFIG_LOG_OUTPUT_FORMAT_LINUX_TIMESTAMP=n
CONFIG_LOG_BACKEND_FORMAT_TIMESTAMP=n
CONFIG_LOG_BACKEND_SHOW_COLOR=n
CONFIG_LOG_BACKEND_NET=n
CONFIG_LOG_BACKEND_RTT=n
CONFIG_LOG_BACKEND_UART=n
CONFIG_RTT_CONSOLE=y
CONFIG_UART_CONSOLE=n

CONFIG_SHELL=y
CONFIG_SHELL_HELP=y
CONFIG_SHELL_CMDS=y
CONFIG_SHELL_STATS=y
CONFIG_SHELL_HISTORY=y
CONFIG_SHELL_LOG_BACKEND=y
CONFIG_SHELL_MINIMAL=y
CONFIG_SHELL_VT100_COMMANDS=y
CONFIG_SHELL_VT100_COLORS=n
CONFIG_SHELL_STATS=n
CONFIG_SHELL_BACKEND_SERIAL=n
CONFIG_SHELL_BACKEND_RTT=y
CONFIG_SHELL_RTT_INIT_LOG_LEVEL_DEFAULT=y

CONFIG_KERNEL_SHELL=n
CONFIG_DEVICE_SHELL=n
CONFIG_DATE_SHELL=n
CONFIG_DEVMEM_SHELL=n


Best regards,
   nRF5xFanBoy

Parents
  • I did dive into some of the zephyr source code for logging in the shell and the backends and I got confused: 

    Log_backend_native_posix.c

    static void put(const struct log_backend *const backend,
    		struct log_msg *msg)
    {
    	log_msg_get(msg);
    
    	uint32_t flags = LOG_OUTPUT_FLAG_LEVEL | LOG_OUTPUT_FLAG_TIMESTAMP;   /// <--  ????
    
    	if (IS_ENABLED(CONFIG_LOG_BACKEND_SHOW_COLOR)) {
    		if (posix_trace_over_tty(0)) {
    			flags |= LOG_OUTPUT_FLAG_COLORS;
    		}
    	}
    
    	if (IS_ENABLED(CONFIG_LOG_BACKEND_FORMAT_TIMESTAMP)) {
    		flags |= LOG_OUTPUT_FLAG_FORMAT_TIMESTAMP;   	/// <--  ???? why ??
    	}
    
    	log_output_msg_process(&log_output_posix, msg, flags);
    
    	log_msg_put(msg);
    
    }
    


    shell_log_backend.c
    static void msg_process(const struct log_output *log_output,
    			struct log_msg *msg, bool colors)
    {
    	uint32_t flags = LOG_OUTPUT_FLAG_LEVEL |
    		      LOG_OUTPUT_FLAG_TIMESTAMP |
    		      LOG_OUTPUT_FLAG_FORMAT_TIMESTAMP;
    
    	if (colors) {
    		flags |= LOG_OUTPUT_FLAG_COLORS;
    	}
    
    	log_output_msg_process(log_output, msg, flags);
    	log_msg_put(msg);
    }
    

    log_core.c

    static int timestamp_print(const struct log_output *output,
    			   uint32_t flags, log_timestamp_t timestamp)
    {
    	int length;
    	bool format =
    		(flags & LOG_OUTPUT_FLAG_FORMAT_TIMESTAMP) |   /// <--- always true
    		(flags & LOG_OUTPUT_FLAG_FORMAT_SYSLOG) |
    		IS_ENABLED(CONFIG_LOG_OUTPUT_FORMAT_LINUX_TIMESTAMP); /// ?????
    
    ...

    Based upon above statements it seems shell logging can never become raw
    Question to Zephyr is that intended by design or a bug?

Reply
  • I did dive into some of the zephyr source code for logging in the shell and the backends and I got confused: 

    Log_backend_native_posix.c

    static void put(const struct log_backend *const backend,
    		struct log_msg *msg)
    {
    	log_msg_get(msg);
    
    	uint32_t flags = LOG_OUTPUT_FLAG_LEVEL | LOG_OUTPUT_FLAG_TIMESTAMP;   /// <--  ????
    
    	if (IS_ENABLED(CONFIG_LOG_BACKEND_SHOW_COLOR)) {
    		if (posix_trace_over_tty(0)) {
    			flags |= LOG_OUTPUT_FLAG_COLORS;
    		}
    	}
    
    	if (IS_ENABLED(CONFIG_LOG_BACKEND_FORMAT_TIMESTAMP)) {
    		flags |= LOG_OUTPUT_FLAG_FORMAT_TIMESTAMP;   	/// <--  ???? why ??
    	}
    
    	log_output_msg_process(&log_output_posix, msg, flags);
    
    	log_msg_put(msg);
    
    }
    


    shell_log_backend.c
    static void msg_process(const struct log_output *log_output,
    			struct log_msg *msg, bool colors)
    {
    	uint32_t flags = LOG_OUTPUT_FLAG_LEVEL |
    		      LOG_OUTPUT_FLAG_TIMESTAMP |
    		      LOG_OUTPUT_FLAG_FORMAT_TIMESTAMP;
    
    	if (colors) {
    		flags |= LOG_OUTPUT_FLAG_COLORS;
    	}
    
    	log_output_msg_process(log_output, msg, flags);
    	log_msg_put(msg);
    }
    

    log_core.c

    static int timestamp_print(const struct log_output *output,
    			   uint32_t flags, log_timestamp_t timestamp)
    {
    	int length;
    	bool format =
    		(flags & LOG_OUTPUT_FLAG_FORMAT_TIMESTAMP) |   /// <--- always true
    		(flags & LOG_OUTPUT_FLAG_FORMAT_SYSLOG) |
    		IS_ENABLED(CONFIG_LOG_OUTPUT_FORMAT_LINUX_TIMESTAMP); /// ?????
    
    ...

    Based upon above statements it seems shell logging can never become raw
    Question to Zephyr is that intended by design or a bug?

Children
No Data
Related