Difference between revisions of "Log services"

From Nintendo Switch Brew
Jump to navigation Jump to search
m (Clarify the unknown destination entry. I was being silly. This would obviously correspond with the default output mechanism.)
m
 
(7 intermediate revisions by 2 users not shown)
Line 1: Line 1:
 
= lm =
 
= lm =
 
This is "nn::lm::ILogService".
 
This is "nn::lm::ILogService".
 +
 +
This service is stubbed on retail, with all the commands/interfaces being present but returning success and doing nothing.
  
 
{| class="wikitable" border="1"
 
{| class="wikitable" border="1"
Line 13: Line 15:
 
Takes an input u64 value representing a process ID and returns an [[#ILogger]] instance.
 
Takes an input u64 value representing a process ID and returns an [[#ILogger]] instance.
  
−
== ILogger ==
+
= lm:get =
 +
This is "nn::lm::ILogGetter". This service doesn't exist on retail.
 +
 
 +
This service can be used to retrieve log messages (only the TextLog field, see [[#Logging]])
 +
 
 +
{| class="wikitable" border="1"
 +
|-
 +
! Cmd || Name
 +
|-
 +
| 0 || [[#StartLogging]]
 +
|-
 +
| 1 || [[#StopLogging]]
 +
|-
 +
| 2 || [[#GetLog]]
 +
|}
 +
 
 +
== StartLogging ==
 +
Takes no input and no output, and just sets a global flag to true.
 +
 
 +
== StopLogging ==
 +
Same as above, but the flag is set to false.
 +
 
 +
== GetLog ==
 +
Takes an output type-0x22 buffer, returns two output u64s (read size and packet drop count)
 +
The flag mentioned above is not checked here, as it is used in a different place (see [[#Logging]])
 +
 
 +
= ILogger =
 
This is "nn::lm::ILogger".
 
This is "nn::lm::ILogger".
  
Line 27: Line 55:
 
== Log ==
 
== Log ==
  
−
Takes an input buffer containing the message to log.
+
Takes a type-0x21 input buffer containing the message to log.
 
Will always return successfully.
 
Will always return successfully.
  
 
== SetDestination ==
 
== SetDestination ==
  
−
Takes an input u32 mask value indicating the logging destinations to send incoming log messages to. The mask entries are as follows:
+
Takes an input u32 mask value indicating the logging destinations to send incoming log messages to. This is stored as a global value. The mask entries are as follows:
  
 
{| class="wikitable" border="1"
 
{| class="wikitable" border="1"
Line 38: Line 66:
 
! Value || Description
 
! Value || Description
 
|-
 
|-
−
| 1 || Default
+
| 1 || TMA
 
|-
 
|-
 
| 2 || UART
 
| 2 || UART
Line 47: Line 75:
 
|}
 
|}
  
−
= lm:get =
+
= LogPacketHeader =
−
This is "nn::lm::ILogGetter".
+
This is "nn::lm::detail::LogPacketHeader"
 +
 
 +
{| class="wikitable" border="1"
 +
|-
 +
! Offset || Size || Description
 +
|-
 +
| 0x0 || 0x8 || Process ID
 +
|-
 +
| 0x8 || 0x8 || Thread ID
 +
|-
 +
| 0x10 || 0x1 || [[#LogPacketFlags]]
 +
|-
 +
| 0x11 || 0x1 || Padding/reserved
 +
|-
 +
| 0x12 || 0x1 || [[#LogSeverity]]
 +
|-
 +
| 0x13 || 0x1 || Verbosity
 +
|-
 +
| 0x14 || 0x4 || Payload size
 +
|}
 +
 
 +
= LogPacketFlags =
 +
 
 +
{| class="wikitable" border="1"
 +
|-
 +
! Value || Name
 +
|-
 +
| 1 || Head
 +
|-
 +
| 2 || Tail
 +
|-
 +
| 4 || LittleEndian
 +
|}
 +
 
 +
= Binary header =
 +
Binary log files saved in SD card have this extra header (see [[#Logging]])
 +
 
 +
{| class="wikitable" border="1"
 +
|-
 +
! Offset || Size || Description
 +
|-
 +
| 0x0 || 0x4 || Magic ("hphp")
 +
|-
 +
| 0x4 || 0x1 || Version (1)
 +
|-
 +
| 0x5 || 0x3 || Padding/reserved
 +
|}
 +
 
 +
= LogSeverity =
 +
This is "nn::diag::LogSeverity"
 +
 
 +
{| class="wikitable" border="1"
 +
|-
 +
! Value || Name
 +
|-
 +
| 0 || Trace
 +
|-
 +
| 1 || Info
 +
|-
 +
| 2 || Warn
 +
|-
 +
| 3 || Error
 +
|-
 +
| 4 || Fatal
 +
|}
 +
 
 +
= LogDataChunkKey =
 +
 
 +
{| class="wikitable" border="1"
 +
|-
 +
! Value || Name || Description
 +
|-
 +
| 0 || LogSessionBegin || Special field sent when a process starts logging (see [[#Logging]])
 +
|-
 +
| 1 || LogSessionEnd || Special field sent when a process finishes logging (see [[#Logging]])
 +
|-
 +
| 2 || TextLog || Actual log text.
 +
|-
 +
| 3 || LineNumber || Line number.
 +
|-
 +
| 4 || FileName || File name.
 +
|-
 +
| 5 || FunctionName || Function name.
 +
|-
 +
| 6 || ModuleName || Module name.
 +
|-
 +
| 7 || ThreadName || Thread name.
 +
|-
 +
| 8 || LogPacketDropCount || Special field containing the amount of packets missed (failed to log/flush, see [[#Logging]])
 +
|-
 +
| 9 || UserSystemClock  || Time value.
 +
|-
 +
| 10 || ProcessName || Process name.
 +
|}
 +
 
 +
= Data chunks =
 +
Data chunks (log packet data fields) follow this format:
  
 
{| class="wikitable" border="1"
 
{| class="wikitable" border="1"
 
|-
 
|-
−
! Cmd || Name
+
! Offset || Size || Description
 +
|-
 +
| 0x0 || Variable (normally 0x1) || [[#LogDataChunkKey]] in LEB128 format
 +
|-
 +
| Variable || Variable (normally 0x1) || Chunk size in LEB128 format
 +
|-
 +
| Variable || Chunk size || Chunk data
 +
|}
 +
 
 +
= Log packet =
 +
 
 +
{| class="wikitable" border="1"
 
|-
 
|-
−
| 0 || StartLogging
+
! Offset || Size || Description
 
|-
 
|-
−
| 1 || StopLogging
+
| 0x0 || 0x18 || [[#LogPacketHeader]]
 
|-
 
|-
−
| 2 || GetLog
+
| 0x18 || Variable || Data chunks
 
|}
 
|}
  
−
This service doesn't normally exist on retail.
+
= Logging =
 +
 
 +
LogManager uses two separate threads: a flushing thread and a htcs thread (main thread is handling both IPC and PM module requests):
 +
 
 +
* The flushing calls Flush() on the "LogBuffer" object, which is the object responsible for flushing logged data though the other objects, and sends a LogPacketDropCount packet via the EventLogTransmitter object (see below) if there any dropped packets and the flushing succeeds - this is done in a loop, waiting until the process starts finalization.
 +
 
 +
* The htcs thread continously reads from the server connection, and will close and reopen the client socket if the connection happened to be lost - this is done in a loop, waiting until the process starts finalization.
 +
 
 +
Different global objects are used for different purposes:
 +
 
 +
* SdCardLogging object - saves logs on the SD card, if both <code>lm!sd_card_log_output_directory</code> and <code>lm!enable_sd_card_logging</code> are present and the last one is true:
 +
** The file name format used is <code>sd:/<log_output_directory>/<serial_no>_<year><month><day><hour><min><sec>[_<extra_index>].nxbinlog</code>, where the extra index is added if the file is already present (several logs being saved at the same time), with a maximum value of 100 (otherwise the saving fails).
 +
** These binary files contain multiple log packets, always preceded by a binary header (see above).
 +
** A single file is used for all the log packets, if the SD card gets ejected or something similar happens the code will re-mount it when it's ready and create a new file.
 +
 
 +
* LogServerProxy object - sends log data via HTCS (see [[TMA_services]])
 +
 
 +
* CustomSinkBuffer object - retains log data which can be later retrieved by [[#lm:get]]:
 +
** When processes log via [[#lm]] service, some code analyzes the log packet, locates the TextLog ([[#LogDataChunkKey]]) chunk (if present) and saves it's contents in a global buffer (therefore, only the actual log message gets retained).
 +
** Log packets are only analyzed/retained after enabling it (by calling [[#StartLogging]]), and the [[#GetLog]] command just reads data from the global buffer.
 +
** The analyzing code also keeps track of which packets are "missed" (skipped/not properly logged), and that missed packet count can be also retrieved on the [[#GetLog]] command.
 +
** When the global buffer is full, nothing will get logged until a process reads the logged data, cleaning the buffer.
 +
 
 +
* EventLogTransmitter object - sends special log packets (event logs):
 +
** When an [[#ILogger]] gets created, this object will send a packet containing the logger's process ID and a LogSessionBegin chunk, telling the remote connection that a new process has started logging. Analogously, when the logger gets destroyed, a simple packet with the process ID and a LogSessionEnd chunk gets sent, telling the remote connection that the process has stopped logging.
 +
** As mentioned above, the flush thread will tell this object to send a simple packet with a LogPacketDropCount chunk after flushing succeeds (and if there any dropped packets).
 +
** These event log packets are logged via the LogBuffer object, like process logs, but they are not analized by the CustomSinkBuffer object since they have no text to be saved.
 +
 
 +
* LogBuffer object - responsible for flushing log packets:
 +
** It internally calls the SdCardLogging and LogServerProxy objects when flushing, so that log packets get flushed to both SD card (if enabled) and HTCS.
 +
** It uses a secondary object to flush, alternating between itself and that secondary object when flushing.
  
 
[[Category:Services]]
 
[[Category:Services]]

Latest revision as of 23:44, 1 December 2020

lm

This is "nn::lm::ILogService".

This service is stubbed on retail, with all the commands/interfaces being present but returning success and doing nothing.

Cmd Name
0 #OpenLogger

OpenLogger

Takes an input u64 value representing a process ID and returns an #ILogger instance.

lm:get

This is "nn::lm::ILogGetter". This service doesn't exist on retail.

This service can be used to retrieve log messages (only the TextLog field, see #Logging)

Cmd Name
0 #StartLogging
1 #StopLogging
2 #GetLog

StartLogging

Takes no input and no output, and just sets a global flag to true.

StopLogging

Same as above, but the flag is set to false.

GetLog

Takes an output type-0x22 buffer, returns two output u64s (read size and packet drop count) The flag mentioned above is not checked here, as it is used in a different place (see #Logging)

ILogger

This is "nn::lm::ILogger".

Cmd Name
0 #Log
1 [3.0.0+] #SetDestination

Log

Takes a type-0x21 input buffer containing the message to log. Will always return successfully.

SetDestination

Takes an input u32 mask value indicating the logging destinations to send incoming log messages to. This is stored as a global value. The mask entries are as follows:

Value Description
1 TMA
2 UART
4 UART when sleeping
0xFFFF Log to all destinations

LogPacketHeader

This is "nn::lm::detail::LogPacketHeader"

Offset Size Description
0x0 0x8 Process ID
0x8 0x8 Thread ID
0x10 0x1 #LogPacketFlags
0x11 0x1 Padding/reserved
0x12 0x1 #LogSeverity
0x13 0x1 Verbosity
0x14 0x4 Payload size

LogPacketFlags

Value Name
1 Head
2 Tail
4 LittleEndian

Binary header

Binary log files saved in SD card have this extra header (see #Logging)

Offset Size Description
0x0 0x4 Magic ("hphp")
0x4 0x1 Version (1)
0x5 0x3 Padding/reserved

LogSeverity

This is "nn::diag::LogSeverity"

Value Name
0 Trace
1 Info
2 Warn
3 Error
4 Fatal

LogDataChunkKey

Value Name Description
0 LogSessionBegin Special field sent when a process starts logging (see #Logging)
1 LogSessionEnd Special field sent when a process finishes logging (see #Logging)
2 TextLog Actual log text.
3 LineNumber Line number.
4 FileName File name.
5 FunctionName Function name.
6 ModuleName Module name.
7 ThreadName Thread name.
8 LogPacketDropCount Special field containing the amount of packets missed (failed to log/flush, see #Logging)
9 UserSystemClock Time value.
10 ProcessName Process name.

Data chunks

Data chunks (log packet data fields) follow this format:

Offset Size Description
0x0 Variable (normally 0x1) #LogDataChunkKey in LEB128 format
Variable Variable (normally 0x1) Chunk size in LEB128 format
Variable Chunk size Chunk data

Log packet

Offset Size Description
0x0 0x18 #LogPacketHeader
0x18 Variable Data chunks

Logging

LogManager uses two separate threads: a flushing thread and a htcs thread (main thread is handling both IPC and PM module requests):

  • The flushing calls Flush() on the "LogBuffer" object, which is the object responsible for flushing logged data though the other objects, and sends a LogPacketDropCount packet via the EventLogTransmitter object (see below) if there any dropped packets and the flushing succeeds - this is done in a loop, waiting until the process starts finalization.
  • The htcs thread continously reads from the server connection, and will close and reopen the client socket if the connection happened to be lost - this is done in a loop, waiting until the process starts finalization.

Different global objects are used for different purposes:

  • SdCardLogging object - saves logs on the SD card, if both lm!sd_card_log_output_directory and lm!enable_sd_card_logging are present and the last one is true:
    • The file name format used is sd:/<log_output_directory>/<serial_no>_<year><month><day><hour><min><sec>[_<extra_index>].nxbinlog, where the extra index is added if the file is already present (several logs being saved at the same time), with a maximum value of 100 (otherwise the saving fails).
    • These binary files contain multiple log packets, always preceded by a binary header (see above).
    • A single file is used for all the log packets, if the SD card gets ejected or something similar happens the code will re-mount it when it's ready and create a new file.
  • LogServerProxy object - sends log data via HTCS (see TMA_services)
  • CustomSinkBuffer object - retains log data which can be later retrieved by #lm:get:
    • When processes log via #lm service, some code analyzes the log packet, locates the TextLog (#LogDataChunkKey) chunk (if present) and saves it's contents in a global buffer (therefore, only the actual log message gets retained).
    • Log packets are only analyzed/retained after enabling it (by calling #StartLogging), and the #GetLog command just reads data from the global buffer.
    • The analyzing code also keeps track of which packets are "missed" (skipped/not properly logged), and that missed packet count can be also retrieved on the #GetLog command.
    • When the global buffer is full, nothing will get logged until a process reads the logged data, cleaning the buffer.
  • EventLogTransmitter object - sends special log packets (event logs):
    • When an #ILogger gets created, this object will send a packet containing the logger's process ID and a LogSessionBegin chunk, telling the remote connection that a new process has started logging. Analogously, when the logger gets destroyed, a simple packet with the process ID and a LogSessionEnd chunk gets sent, telling the remote connection that the process has stopped logging.
    • As mentioned above, the flush thread will tell this object to send a simple packet with a LogPacketDropCount chunk after flushing succeeds (and if there any dropped packets).
    • These event log packets are logged via the LogBuffer object, like process logs, but they are not analized by the CustomSinkBuffer object since they have no text to be saved.
  • LogBuffer object - responsible for flushing log packets:
    • It internally calls the SdCardLogging and LogServerProxy objects when flushing, so that log packets get flushed to both SD card (if enabled) and HTCS.
    • It uses a secondary object to flush, alternating between itself and that secondary object when flushing.
Retrieved from "https://switchbrew.org/w/index.php?title=Log_services&oldid=10359"