漫谈android系统(7)-log系统1

前言

罗升阳的《Android系统源代码情景分析》一书，有关log是如何显示，那么真的在代码中是如何实现的呢？就该问题我想需要细细分析

bootloader层的log

在firmware中的log是如何产生的，我没有看过firmware的code,不清楚它是如何实现的，这是我的短板，回头得补上！在这里先分析lk中是如何实现的。

从aboot.c着手

相信在源码中看到bootable\bootloader\lk下的app\aboot.c中最常用于打log信息的语句为dprintf。那么它的原型在哪里？

其原型非常好找，在lk\include\debug.h中就有定义。

/* debug levels */
#define CRITICAL 0
#define ALWAYS 0
#define INFO 1
#define SPEW 2

/* output */
void _dputc(char c); // XXX for now, platform implements
int _dputs(const char *str);
int _dprintf(const char *fmt, ...) __PRINTFLIKE(1, 2);
int _dvprintf(const char *fmt, va_list ap);

#define dputc(level, str) do { if ((level) <= DEBUGLEVEL) { _dputc(str); } } while (0)
#define dputs(level, str) do { if ((level) <= DEBUGLEVEL) { _dputs(str); } } while (0)
#define dprintf(level, x...) do { if ((level) <= DEBUGLEVEL) { _dprintf(x); } } while (0)
#define dvprintf(level, x...) do { if ((level) <= DEBUGLEVEL) { _dvprintf(x); } } while (0)

宏定义dprintf(level, x…)让我们可以看到其实际调用的还是 _dprintf(x),然后我们去定位到lk\platform\msm_share\debug.c

int _dprintf(const char *fmt, ...)
{
char buf[256];
char ts_buf[13];
int err;

snprintf(ts_buf, sizeof(ts_buf), "[%u] ",(unsigned int)current_time());
dputs(ALWAYS, ts_buf);

va_list ap;
va_start(ap, fmt);
err = vsnprintf(buf, sizeof(buf), fmt, ap);
va_end(ap);

dputs(ALWAYS, buf);

return err;
}

因而不难看出它最后是将buf组成后扔给dputs。看前面有宏定义dputs

int _dputs(const char *str)
{
while(*str != 0) {
_dputc(*str++);
}

return 0;
}
//
void _dputc(char c)
{
#if WITH_DEBUG_LOG_BUF
log_putc(c);
#endif
#if WITH_DEBUG_DCC
if (c == '\n') {
write_dcc('\r');
}
write_dcc(c) ;
#endif
#if WITH_DEBUG_UART
uart_putc(0, c);
#endif
#if WITH_DEBUG_FBCON && WITH_DEV_FBCON
fbcon_putc(c);
#endif
#if WITH_DEBUG_JTAG
jtag_dputc(c);
#endif
}

在这里，我表示追捕不到WITH_DEBUG_UART的宏是如何定义的，如果有知道的朋友，欢迎留言帮我解决这个问题。

我猜想应该是使用WITH_DEBUG_UART这个宏

这样我们可以去找到uart_putc的实现方法，然后逐层分析。可以定位到lk\platform\msm_share\uart_dm.c

/* UART_DM uses four character word FIFO where as UART core
* uses a character FIFO. so it's really inefficient to try
* to write single character. But that's how dprintf has been
* implemented.
*/
int uart_putc(int port, char c)
{
uint32_t uart_base = port_lookup[port];

/* Don't do anything if UART is not initialized */
if (!uart_init_flag)
return -1;

msm_boot_uart_dm_write(uart_base, &c, 1);

return 0;
}

msm_boot_uart_dm_write(uint32_t base, char *data, unsigned int num_of_chars)
{
unsigned int tx_word_count = 0;
unsigned int tx_char_left = 0, tx_char = 0;
unsigned int tx_word = 0;
int i = 0;
char *tx_data = NULL;
uint8_t num_chars_written;

if ((data == NULL) || (num_of_chars <= 0)) {
return MSM_BOOT_UART_DM_E_INVAL;
}

msm_boot_uart_calculate_num_chars_to_write(data, &num_of_chars);

tx_data = data;

/* Write to NO_CHARS_FOR_TX register number of characters
* to be transmitted. However, before writing TX_FIFO must
* be empty as indicated by TX_READY interrupt in IMR register
*/

/* Check if transmit FIFO is empty.
* If not we'll wait for TX_READY interrupt. */
if (!(readl(MSM_BOOT_UART_DM_SR(base)) & MSM_BOOT_UART_DM_SR_TXEMT)) {
while (!(readl(MSM_BOOT_UART_DM_ISR(base)) & MSM_BOOT_UART_DM_TX_READY)) {
udelay(1);
/* Kick watchdog? */
}
}

//We need to make sure the DM_NO_CHARS_FOR_TX&DM_TF are are programmed atmoically.
enter_critical_section();
/* We are here. FIFO is ready to be written. */
/* Write number of characters to be written */
writel(num_of_chars, MSM_BOOT_UART_DM_NO_CHARS_FOR_TX(base));

/* Clear TX_READY interrupt */
writel(MSM_BOOT_UART_DM_GCMD_RES_TX_RDY_INT, MSM_BOOT_UART_DM_CR(base));

/* We use four-character word FIFO. So we need to divide data into
* four characters and write in UART_DM_TF register */
tx_word_count = (num_of_chars % 4) ? ((num_of_chars / 4) + 1) :
(num_of_chars / 4);
tx_char_left = num_of_chars;

for (i = 0; i < (int)tx_word_count; i++) {
tx_char = (tx_char_left < 4) ? tx_char_left : 4;
num_chars_written = pack_chars_into_words((uint8_t *)tx_data, tx_char, &tx_word);

/* Wait till TX FIFO has space */
while (!(readl(MSM_BOOT_UART_DM_SR(base)) & MSM_BOOT_UART_DM_SR_TXRDY)) {
udelay(1);
}

/* TX FIFO has space. Write the chars */
writel(tx_word, MSM_BOOT_UART_DM_TF(base, 0));
tx_char_left = num_of_chars - (i + 1) * 4;
tx_data = tx_data + num_chars_written;
}
exit_critical_section();

return MSM_BOOT_UART_DM_E_SUCCESS;
}

在这里的code明显看出是否初始化uart成功，然后调用msm_boot_uart_dm_write函数，验证输入字符，检查fifo队列是否已经清空数据，重置tx中断，写入相关的寄存器，等等，在这里我不详细解释了，可以慢慢看code，细细体会其中神奇的地方。

//验证输入字符自动加\n
/*
* Helper function to keep track of Line Feed char "\n" with
* Carriage Return "\r\n".
*/
static unsigned int
msm_boot_uart_calculate_num_chars_to_write(char *data_in,
uint32_t *num_of_chars)
{
uint32_t i = 0, j = 0;

if ((data_in == NULL)) {
return MSM_BOOT_UART_DM_E_INVAL;
}

for (i = 0, j = 0; i < *num_of_chars; i++, j++) {
if (data_in[i] == '\n') {
j++;
}

}

*num_of_chars = j;

return MSM_BOOT_UART_DM_E_SUCCESS;
}

其实在这里我们仅仅只是对发送log做了解析。对于我们在终端可以向机台发送命令，其机制也有，其基本与发送的机制一样。

/* UART_DM uses four character word FIFO whereas uart_getc
* is supposed to read only one character. So we need to
* read a word and keep track of each character in the word.
*/
int uart_getc(int port, bool wait)
{
int byte;
static unsigned int word = 0;
uint32_t uart_base = port_lookup[port];

/* Don't do anything if UART is not initialized */
if (!uart_init_flag)
return -1;

if (!word) {
/* Read from FIFO only if it's a first read or all the four
* characters out of a word have been read */
if (msm_boot_uart_dm_read(uart_base, &word, wait) != MSM_BOOT_UART_DM_E_SUCCESS) {
return -1;
}

}

byte = (int)word & 0xff;
word = word >> 8;

return byte;
}
/*
* UART Receive operation
* Reads a word from the RX FIFO.
*/
static unsigned int
msm_boot_uart_dm_read(uint32_t base, unsigned int *data, int wait)
{
static int rx_last_snap_count = 0;
static int rx_chars_read_since_last_xfer = 0;

if (data == NULL) {
return MSM_BOOT_UART_DM_E_INVAL;
}

/* We will be polling RXRDY status bit */
while (!(readl(MSM_BOOT_UART_DM_SR(base)) & MSM_BOOT_UART_DM_SR_RXRDY)) {
/* if this is not a blocking call, we'll just return */
if (!wait) {
return MSM_BOOT_UART_DM_E_RX_NOT_READY;
}
}

/* Check for Overrun error. We'll just reset Error Status */
if (readl(MSM_BOOT_UART_DM_SR(base)) & MSM_BOOT_UART_DM_SR_UART_OVERRUN) {
writel(MSM_BOOT_UART_DM_CMD_RESET_ERR_STAT, MSM_BOOT_UART_DM_CR(base));
}

/* RX FIFO is ready; read a word. */
*data = readl(MSM_BOOT_UART_DM_RF(base, 0));

/* increment the total count of chars we've read so far */
rx_chars_read_since_last_xfer += 4;

/* Rx transfer ends when one of the conditions is met:
* - The number of characters received since the end of the previous
*   xfer equals the value written to DMRX at Transfer Initialization
* - A stale event occurred
*/

/* If RX transfer has not ended yet */
if (rx_last_snap_count == 0) {
/* Check if we've received stale event */
if (readl(MSM_BOOT_UART_DM_MISR(base)) & MSM_BOOT_UART_DM_RXSTALE) {
/* Send command to reset stale interrupt */
writel(MSM_BOOT_UART_DM_CMD_RES_STALE_INT, MSM_BOOT_UART_DM_CR(base));
}

/* Check if we haven't read more than DMRX value */
else if ((unsigned int)rx_chars_read_since_last_xfer <
readl(MSM_BOOT_UART_DM_DMRX(base))) {
/* We can still continue reading before initializing RX transfer */
return MSM_BOOT_UART_DM_E_SUCCESS;
}

/* If we've reached here it means RX
* xfer end conditions been met
*/

/* Read UART_DM_RX_TOTAL_SNAP register
* to know how many valid chars
* we've read so far since last transfer
*/
rx_last_snap_count = readl(MSM_BOOT_UART_DM_RX_TOTAL_SNAP(base));

}

/* If there are still data left in FIFO we'll read them before
* initializing RX Transfer again */
if ((rx_last_snap_count - rx_chars_read_since_last_xfer) >= 0) {
return MSM_BOOT_UART_DM_E_SUCCESS;
}

msm_boot_uart_dm_init_rx_transfer(base);
rx_last_snap_count = 0;
rx_chars_read_since_last_xfer = 0;

return MSM_BOOT_UART_DM_E_SUCCESS;
}

了解uart是如何初始化的

还记得有一文中有讲到如何进行lk的启动的，在kmain(void)函数中会调用target_early_init()此时就是对uart的寄存器做了初始化。

void target_early_init(void)
{
#if WITH_DEBUG_UART
uart_dm_init(1, 0, BLSP1_UART0_BASE);
#endif
}

而uart_dm_init函数就是对uart的初始化动作

/* Defining functions that's exposed to outside world and in coformance to
* existing uart implemention. These functions are being called to initialize
* UART and print debug messages in bootloader.
*/
void uart_dm_init(uint8_t id, uint32_t gsbi_base, uint32_t uart_dm_base)
{
static uint8_t port = 0;
char *data = "Android Bootloader - UART_DM Initialized!!!\n";

/* Configure the uart clock */
clock_config_uart_dm(id);
dsb();

/* Configure GPIO to provide connectivity between UART block
product ports and chip pads */
gpio_config_uart_dm(id);
dsb();

/* Configure GSBI for UART_DM protocol.
* I2C on 2 ports, UART (without HS flow control) on the other 2.
* This is only on chips that have GSBI block
*/
if(gsbi_base)
writel(GSBI_PROTOCOL_CODE_I2C_UART <<
GSBI_CTRL_REG_PROTOCOL_CODE_S,
GSBI_CTRL_REG(gsbi_base));
dsb();

/* Configure clock selection register for tx and rx rates.
* Selecting 115.2k for both RX and TX.
*/
writel(UART_DM_CLK_RX_TX_BIT_RATE, MSM_BOOT_UART_DM_CSR(uart_dm_base));
dsb();

/* Intialize UART_DM */
msm_boot_uart_dm_init(uart_dm_base);

msm_boot_uart_dm_write(uart_dm_base, data, 44);

ASSERT(port < ARRAY_SIZE(port_lookup));
port_lookup[port++] = uart_dm_base;

/* Set UART init flag */
uart_init_flag = 1;
}

因而我们可以看到uart初始化时钟后，设定gpio,设置频率，设置寄存器，设置flag。

/* Configure UART clock based on the UART block id*/
void clock_config_uart_dm(uint8_t id)
{
int ret;
char iclk[64];
char cclk[64];

snprintf(iclk, sizeof(iclk), "uart%u_iface_clk", id);
snprintf(cclk, sizeof(cclk), "uart%u_core_clk", id);

ret = clk_get_set_enable(iclk, 0, 1);
if(ret)
{
dprintf(CRITICAL, "failed to set %s ret = %d\n", iclk, ret);
ASSERT(0);
}

ret = clk_get_set_enable(cclk, 7372800, 1);
if(ret)
{
dprintf(CRITICAL, "failed to set %s ret = %d\n", cclk, ret);
ASSERT(0);
}
}

/* Configure gpio for blsp uart 2 */
void gpio_config_uart_dm(uint8_t id)
{
/* configure rx gpio */
gpio_tlmm_config(5, 2, GPIO_INPUT, GPIO_NO_PULL,
GPIO_8MA, GPIO_DISABLE);

/* configure tx gpio */
gpio_tlmm_config(4, 2, GPIO_OUTPUT, GPIO_NO_PULL,
GPIO_8MA, GPIO_DISABLE);
}

/*
* Initialize UART_DM - configure clock and required registers.
*/
static unsigned int msm_boot_uart_dm_init(uint32_t uart_dm_base)
{
/* Configure UART mode registers MR1 and MR2 */
/* Hardware flow control isn't supported */
writel(0x0, MSM_BOOT_UART_DM_MR1(uart_dm_base));

/* 8-N-1 configuration: 8 data bits - No parity - 1 stop bit */
writel(MSM_BOOT_UART_DM_8_N_1_MODE, MSM_BOOT_UART_DM_MR2(uart_dm_base));

/* Configure Interrupt Mask register IMR */
writel(MSM_BOOT_UART_DM_IMR_ENABLED, MSM_BOOT_UART_DM_IMR(uart_dm_base));

/* Configure Tx and Rx watermarks configuration registers */
/* TX watermark value is set to 0 - interrupt is generated when
* FIFO level is less than or equal to 0 */
writel(MSM_BOOT_UART_DM_TFW_VALUE, MSM_BOOT_UART_DM_TFWR(uart_dm_base));

/* RX watermark value */
writel(MSM_BOOT_UART_DM_RFW_VALUE, MSM_BOOT_UART_DM_RFWR(uart_dm_base));

/* Configure Interrupt Programming Register */
/* Set initial Stale timeout value */
writel(MSM_BOOT_UART_DM_STALE_TIMEOUT_LSB, MSM_BOOT_UART_DM_IPR(uart_dm_base));

/* Configure IRDA if required */
/* Disabling IRDA mode */
writel(0x0, MSM_BOOT_UART_DM_IRDA(uart_dm_base));

/* Configure and enable sim interface if required */

/* Configure hunt character value in HCR register */
/* Keep it in reset state */
writel(0x0, MSM_BOOT_UART_DM_HCR(uart_dm_base));

/* Configure Rx FIFO base address */
/* Both TX/RX shares same SRAM and default is half-n-half.
* Sticking with default value now.
* As such RAM size is (2^RAM_ADDR_WIDTH, 32-bit entries).
* We have found RAM_ADDR_WIDTH = 0x7f */

/* Issue soft reset command */
msm_boot_uart_dm_reset(uart_dm_base);

/* Enable/Disable Rx/Tx DM interfaces */
/* Data Mover not currently utilized. */
writel(0x0, MSM_BOOT_UART_DM_DMEN(uart_dm_base));

/* Enable transmitter and receiver */
writel(MSM_BOOT_UART_DM_CR_RX_ENABLE, MSM_BOOT_UART_DM_CR(uart_dm_base));
writel(MSM_BOOT_UART_DM_CR_TX_ENABLE, MSM_BOOT_UART_DM_CR(uart_dm_base));

/* Initialize Receive Path */
msm_boot_uart_dm_init_rx_transfer(uart_dm_base);

return MSM_BOOT_UART_DM_E_SUCCESS;
}

那么从code中我们看到了它的设置，那么为何它是这样设置的？那么就要看电路图了！







在这里我比较奇怪的是为什么，audiodebug的pin是如何也就是gpio87是如何工作，这个我会问了EE的同事后，再做解答。

至此，bootloader层的uart是如何建立的，已经有了很好的解释，而在target_init()函数再去设置一边gpio我个人觉得是没有必要的！

后记

system/core层logcat分析

在这里我们清晰的看到了《Android系统源代码情景分析》一书中提到的基础数据结构体。具体路径在/system/core/include/log/logger.h

/*
* The userspace structure for version 1 of the logger_entry ABI.
* This structure is returned to userspace by the kernel logger
* driver unless an upgrade to a newer ABI version is requested.
*/
struct logger_entry {
uint16_t    len;    /* length of the payload */
uint16_t    __pad;  /* no matter what, we get 2 bytes of padding */
int32_t     pid;    /* generating process's pid */
int32_t     tid;    /* generating process's tid */
int32_t     sec;    /* seconds since Epoch */
int32_t     nsec;   /* nanoseconds */
char        msg[0]; /* the entry's payload */
} __attribute__((__packed__));
/*
* The maximum size of the log entry payload that can be
* written to the logger. An attempt to write more than
* this amount will result in a truncated log entry.
*/
#define LOGGER_ENTRY_MAX_PAYLOAD    4076

/*
* The maximum size of a log entry which can be read from the
* kernel logger driver. An attempt to read less than this amount
* may result in read() returning EINVAL.
*/
#define LOGGER_ENTRY_MAX_LEN        (5*1024)

但是我越看越觉得不一样，看来androidM的log机制已经发生了变化，于是我觉得有书不如无书，带着这样的想法我又细细读了一遍。

决定再从init，kernel,framwork层分层去做解析，当然重点还是在kernel层。