Logging

Note: The logging from Foundation servers is supported only for standard build and is not supported in production builds.

NVIDIA DRIVE? OS has a logging component that allows logs from multiple NVIDIA DRIVE OS components to be obtained. Currently, support is only available for applications within NVIDIA DRIVE OS Linux Guest VM and Foundation servers to send logs that are stored in a file that is created and accessible from Linux Guest VM. This support will be enhanced in future releases to support more execution environments outside of Guest VM.

Terms

Logging Entity : Application threads(s) trying to log, each thread is an entity.

Entity Logging library : entity specific logging library build that is linked to Guest VM entities (libnvlog_guestvm_entity)

nvlogclient_fast : logging client/server combined application.

Logging library : full build of logging library that is linked to nvlogclient_fast (libnvlog.so)

Logging Pipeline

The logging pipeline is as follows:

(Logging Entity + libnvlog_guestvm_entity) -> (nvlogclient_fast + libnvlog.so) -> log storage file

Components

The following lists the source and binary locations within the SDK:

Pre-built binaries:

<top>/drive-linux/lib-target/libnvlog.so
<top>/drive-linux/filesystem/contents/bin/nvlogclient_fast
<top>/drive-linux/filesystem/contents/bin/nvlogtest
<top>/drive-linux/filesystem/contents/bin/nvlogtest_stdin

Post-processing script:

drive-linux/samples/tools/nvlog/scripts/host/systemlog_parser.py

Source code:
Note: Do not use test applications built from PDK as there are known issues. Use prebuilt binaries instead.
Source files for the test applications (nvlogtest*) and the Logging Client (nvlogclient_fast) can be found under:
```
<top>/drive-linux/samples/tools/nvlog/
```
Include files and user API:
Any application needing to send logs using this new framework must use the <top>/drive-linux/samples/tools/nvlog/include/nvlog.h header file and link to libnvlog_guestvm_entity library. API documentation can be found in the same header file.

In a booted DRIVE OS Linux Guest VM console, the following logging-related components are available:

/usr/local/bin/
nvlogclient_fast: Application component responsible for collecting logs from different Logging Entities within Linux Guest VM and storing them.
nvlogtest: Test application that has two threads sending log messages every second.
nvlogtest_stdin: Test application that takes input from stdin and sends each line as a log message.
/usr/local/lib/
libnvlog.so: Logging library that provides logging APIs.

Execution Steps

Step 1:

Default Behavior

The nvlog feature is enabled by default on AV + L for all the platforms. The following messages appear during boot:

Dec 21 00:54:11 tegra-ubuntu systemd[1]: Starting nvlog client logging service...
Dec 21 00:54:11 tegra-ubuntu bash[1140]: Launched /usr/local/bin/nvlogclient_fast !!!
Dec 21 00:54:11 tegra-ubuntu nvlogclient_fast: SHMDiscoveryClientThread: Discovery client thread starting..
Dec 21 00:54:11 tegra-ubuntu nvlogclient_fast: NvLogDiscoveryPlugin_nvsciipc_Init - Entry
Dec 21 00:54:11 tegra-ubuntu systemd[1]: Started nvlog client logging service.

For the standard build, the output log file is created in the /home/nvidia/ directory:

nvidia@tegra-ubuntu:~$ ls -al /home/nvidia/nvlog_system_log.txt
-rw-r--r--. 1 root root 20480 Dec 21 00:54 /home/nvidia/nvlog_system_log.txt

nvidia@tegra-ubuntu:~$ cat /home/nvidia/nvlog_system_log.txt
      EUID       PID ENTITY ID    SEQ     TIMESTAMP  MSG
         0      1305      1305              3      346841060    Module_id 51 Severity 5 : created TA endpoint: 1, created CA endpoints: 2
         0      1305      1305              2      346840076    Module_id 51 Severity 5 : Server trying IVC endpoint:  pkcs11_keystore_tk11_ivc_d2
         0      1305      1305              1      346838406    Module_id 51 Severity 5 : Server trying IVC endpoint:  pkcs11_keystore_tk11_ivc_d1
         0      1291      1304              1      346765176    Module_id 51 Severity 5 : Waiting for Suspend Request from Kernel:  pkcs11-keystore-tk10
         0      1291      1291              3      346758455    Module_id 51 Severity 5 : created TA endpoint: 1, created CA endpoints: 2
         0      1291      1291              2      346757262    Module_id 51 Severity 5 : Server trying IVC endpoint:  pkcs11_keystore_tk10_ivc_d2
         0      1291      1291              1      346755441    Module_id 51 Severity 5 : Server trying IVC endpoint:  pkcs11_keystore_tk10_ivc_d1
         0      1284      1299              1      346717953    Module_id 51 Severity 5 : Waiting for Suspend Request from Kernel:  pkcs11-keystore-tk1
         0      1284      1284              3      346711198    Module_id 51 Severity 5 : created TA endpoint: 1, created CA endpoints: 2
         0      1284      1284              2      346710136    Module_id 51 Severity 5 : Server trying IVC endpoint:  pkcs11_keystore_tk1_ivc_d2
         0      1284      1284              1      346708419    Module_id 51 Severity 5 : Server trying IVC endpoint:  pkcs11_keystore_tk1_ivc_d1
         0      1272      1281              1      346543194    Module_id 51 Severity 5 : Waiting for Suspend Request from Kernel:  nvmacsec
         0      1272      1272              3      346537165    Module_id 51 Severity 5 : created TA endpoint: 1, created CA endpoints: 2
         0      1272      1272              2      346536002    Module_id 51 Severity 5 : Server trying IVC endpoint:  nvmacsec_ta_d2
         0      1272      1272              1      346534344    Module_id 51 Severity 5 : Server trying IVC endpoint:  nvmacsec_ta_d1
         0      1260      1270              1      346428824    Module_id 51 Severity 5 : Waiting for Suspend Request from Kernel:  gp-se
…

For the production build, the output log file is created in the /var directory.

Disable nvlog

To disable nvlog,

Change the status of the nvlog node to disabled in the tegra234-linux-gos.dtsi file.
```
nvlog {
       status = "disabled";
       guest_vm {
                 ...
       }
}
```
Recompile and flash.

Step 2:

Copy the nvlog file 'nvlog_system_log.txt' to host and run post processing script as follows:

python3 drive-linux/samples/tools/nvlog/scripts/host/systemlog_parser.py -in ./nvlog_system_log.txt -out ./out.txt

The output is sorted order based on timestamps. An example:

0       109892006       sysmgr: [109892006] Event SmRequestStatus_help: Success=0 Failed=1 Pending=2 Reset=3 Number_of_Sidekick_Statuses=4
0       109892010       sysmgr: [109892010] Event return_code_help: Success=0 Invalid=4294967295
0       109962743       nvhost_server_native: [109962743] Event nvlog:nvhost server initialization completed
0       110284147       bpmp_server_native: [110284147] Event nvlog:Initialize:886
0       110286416       bpmp_server_native: [110286416] Event nvlog:BPMP Server Variant: qnx_std
0       110343965       bpmp_server_native: [110343965] Event nvlog:main_init: End of BPMP server main_init
0       110350297       bpmp_server_native: [110350297] Event nvlog:fw_init_channels: Init fw channel = 0 ia = 0xa85000 oa = 0xa84000 max size = 65536
0       110356320       bpmp_server_native: [110356320] Event nvlog:fw_init_channels: Init fw channel = 1 ia = 0xa85000 oa = 0xa84000 max size = 65536
0       110362322       bpmp_server_native: [110362322] Event nvlog:fw_init_channels: Init fw channel = 2 ia = 0xa85000 oa = 0xa84000 max size = 65536
0       110367767       bpmp_server_native: [110367767] Event nvlog:fw_init_channels: Init fw channel = 3 ia = 0xa85000 oa = 0xa84000 max size = 65536
0       110539946       audio_server_native: [110539946] Event nvlog: [             SetTraceVerbosity() :   59]     INFO: Log level set to INFO
0       110545031       audio_server_native: [110545031] Event nvlog: [            hvrtos_server_init() :  133]     INFO: NVLOG Init done
0                       Oct 16 19:41:23 tegra-ubuntu kernel: [    0.384006] tegra_hv: adding ivc0: rx_base=ffff80000c1b0000 tx_base = ffff80000c1b0100 size=100 irq = 229 (686)
0                       Oct 16 19:41:23 tegra-ubuntu kernel: [    0.383996] tegra_hv: added ivc200
0                       Oct 16 19:41:23 tegra-ubuntu kernel: [    0.383995] tegra_hv: adding ivc200: rx_base=ffff80000bbd0000 tx_base = ffff80000bbd0100 size=100 irq = 228 (685)
0                       Oct 16 19:41:23 tegra-ubuntu kernel: [    0.383986] tegra_hv: added ivc408
0       111491991       vsc_server_native_qspi: [111491991] Event nvlog: mempool#39
0       111494395       vsc_server_native_qspi: [111494395] Event nvlog: Priority#4
0       111506850       vsc_server_native_qspi: [111506850] Event nvlog:vsc_dev_mgr_get_storage_device_by_id: set up device qspi0
0       111518752       vsc_server_native_qspi: [111518752] Event nvlog:controller #qspi0, instance 0
0       111526877       vsc_server_native_qspi: [111526877] Event nvlog: Virtual Device Name: B_qspi_chain
0       111535113       vsc_server_native_qspi: [111535113] Event nvlog: offset #57409536 @ length #9699328
0       111537094       vsc_server_native_qspi: [111537094] Event nvlog: ivc#99
0       111539371       vsc_server_native_qspi: [111539371] Event nvlog: mempool#40
0       111543234       vsc_server_native_qspi: [111543234] Event nvlog: Priority#4

Note:

Log messages can be lost if entity (or producer) is spewing many log messages before nvlogclient_fast (or consumer) is able to read the messages.
The first log message is not currently retrieved or stored by the Logging Client. This is a known issue.
Currently, the priority of nvlogclient_fast and nvlogtest_stdin is set to a lower value, at 5. You should update this value based on priorities of other applications. It should not be set too high, leading to a possible DOS attack from rogue application by using nvlog feature and it should not be too low, where the nvlog application does not get a chance to run long enough to store the logs.