cvmx-log.c revision 210284 
1/***********************license start***************
2 *  Copyright (c) 2003-2008 Cavium Networks (support@cavium.com). All rights
3 *  reserved.
4 *
5 *
6 *  Redistribution and use in source and binary forms, with or without
7 *  modification, are permitted provided that the following conditions are
8 *  met:
9 *
10 *      * Redistributions of source code must retain the above copyright
11 *        notice, this list of conditions and the following disclaimer.
12 *
13 *      * Redistributions in binary form must reproduce the above
14 *        copyright notice, this list of conditions and the following
15 *        disclaimer in the documentation and/or other materials provided
16 *        with the distribution.
17 *
18 *      * Neither the name of Cavium Networks nor the names of
19 *        its contributors may be used to endorse or promote products
20 *        derived from this software without specific prior written
21 *        permission.
22 *
23 *  TO THE MAXIMUM EXTENT PERMITTED BY LAW, THE SOFTWARE IS PROVIDED "AS IS"
24 *  AND WITH ALL FAULTS AND CAVIUM NETWORKS MAKES NO PROMISES, REPRESENTATIONS
25 *  OR WARRANTIES, EITHER EXPRESS, IMPLIED, STATUTORY, OR OTHERWISE, WITH
26 *  RESPECT TO THE SOFTWARE, INCLUDING ITS CONDITION, ITS CONFORMITY TO ANY
27 *  REPRESENTATION OR DESCRIPTION, OR THE EXISTENCE OF ANY LATENT OR PATENT
28 *  DEFECTS, AND CAVIUM SPECIFICALLY DISCLAIMS ALL IMPLIED (IF ANY) WARRANTIES
29 *  OF TITLE, MERCHANTABILITY, NONINFRINGEMENT, FITNESS FOR A PARTICULAR
30 *  PURPOSE, LACK OF VIRUSES, ACCURACY OR COMPLETENESS, QUIET ENJOYMENT, QUIET
31 *  POSSESSION OR CORRESPONDENCE TO DESCRIPTION.  THE ENTIRE RISK ARISING OUT
32 *  OF USE OR PERFORMANCE OF THE SOFTWARE LIES WITH YOU.
33 *
34 *
35 *  For any questions regarding licensing please contact marketing@caviumnetworks.com
36 *
37 ***********************license end**************************************/
38
39
40
41
42
43
44/**
45 * @file
46 *
47 * cvmx-log supplies a fast log buffer implementation. Each core writes
48 * log data to a differnet buffer to avoid synchronization overhead. Function
49 * call logging can be turned on with the GCC option "-pg".
50 *
51 * <hr>$Revision: 41586 $<hr>
52 */
53#include "cvmx.h"
54#include "cvmx-log.h"
55
56#define CVMX_LOG_BUFFER_SIZE (1<<15)
57#define CVMX_LOG_NUM_BUFFERS 4
58
59/**
60 * The possible types of log data that can be stored in the
61 * buffer.
62 */
63typedef enum
64{
65    CVMX_LOG_TYPE_PC = 0,   /**< Log of the program counter location. used for code profiling / tracing */
66    CVMX_LOG_TYPE_PRINTF,   /**< Constant printf format string with two 64bit arguments */
67    CVMX_LOG_TYPE_DATA,     /**< Arbitrary array of dwords. Max size is 31 dwords */
68    CVMX_LOG_TYPE_STRUCTURE,/**< Log a structured data element. Max size is 30 dwords */
69    CVMX_LOG_TYPE_PERF,     /**< Mips performance counters control registers followed by the data */
70} cvmx_log_type_t;
71
72/**
73 * Header definition for each log entry.
74 */
75typedef union
76{
77    uint64_t u64;
78    struct
79    {
80        cvmx_log_type_t     type    : 3; /* Data in the log entry */
81        uint64_t            size    : 8; /* Data size in 64bit words */
82        uint64_t            cycle   :53; /* Low bits of the cycle counter as a timestamp */
83    } s;
84} cvmx_log_header_t;
85
86/**
87 * Circular log buffer. Each processor gets a private one to
88 * write to. Log entries are added at the current write
89 * location, then the write location is incremented. The
90 * buffer may wrap in the middle of a log entry.
91 */
92static uint64_t cvmx_log_buffers[CVMX_LOG_NUM_BUFFERS][CVMX_LOG_BUFFER_SIZE];
93
94/**
95 * Current locations in the log.
96 */
97uint64_t *cvmx_log_buffer_write_ptr             = NULL; /* The next write will occur here */
98uint64_t *cvmx_log_buffer_end_ptr               = NULL; /* Write must move to the next buffer when it equals this */
99uint64_t *cvmx_log_buffer_head_ptr              = NULL; /* Pointer to begin extracting log data from */
100static uint64_t *cvmx_log_buffer_read_ptr       = NULL; /* Location cvmx_display is reading from */
101static uint64_t *cvmx_log_buffer_read_end_ptr   = NULL; /* Location where read will need the next buffer */
102uint64_t cvmx_log_mcd0_on_full                  = 0;    /* If this is set, cvm-log will assert MCD0 when the log
103                                                            is full. This is set by the remote logging utility through
104                                                            the debugger interface. */
105
106
107/**
108 * @INTERNAL
109 * Initialize the log for writing
110 */
111static void __cvmx_log_initialize(void) CVMX_LOG_DISABLE_PC_LOGGING;
112static void __cvmx_log_initialize(void)
113{
114    int buf_num;
115
116    /* Link the buffers together using the last element in each buffer */
117    for (buf_num=0; buf_num<CVMX_LOG_NUM_BUFFERS-1; buf_num++)
118        cvmx_log_buffers[buf_num][CVMX_LOG_BUFFER_SIZE-1] = CAST64(cvmx_log_buffers[buf_num+1]);
119    cvmx_log_buffers[CVMX_LOG_NUM_BUFFERS-1][CVMX_LOG_BUFFER_SIZE-1] = CAST64(NULL);
120
121    cvmx_log_buffer_head_ptr = &cvmx_log_buffers[0][0];
122    cvmx_log_buffer_write_ptr = &cvmx_log_buffers[0][0];
123    cvmx_log_buffer_end_ptr = cvmx_log_buffer_write_ptr + CVMX_LOG_BUFFER_SIZE-1;
124}
125
126
127/**
128 * @INTERNAL
129 * Called when the log is full of data. This function must
130 * make room for more log data before returning.
131 */
132static void __cvmx_log_full_process(void) CVMX_LOG_DISABLE_PC_LOGGING;
133static void __cvmx_log_full_process(void)
134{
135    if (cvmx_log_mcd0_on_full)
136    {
137        register uint64_t tmp;
138        /* Pulse MCD0 signal so a remote utility can extract the data */
139        asm volatile (
140            "dmfc0 %0, $22\n"
141	        "ori   %0, %0, 0x1110\n"
142            "dmtc0 %0, $22\n"
143            "nop\n"
144            "nop\n"
145            "nop\n"
146            "nop\n"
147            "nop\n"
148            "nop\n"
149            : "=r" (tmp));
150    }
151    /* The write ptr may have been modifed by the debugger, check it again */
152    if (!(volatile uint64_t)CAST64(cvmx_log_buffer_write_ptr))
153    {
154        #ifndef __KERNEL__
155            /* Disabled for the Linux kernel since printk is also profiled */
156            cvmx_dprintf("Log is full, reusing first buffer\n");
157        #endif
158        *cvmx_log_buffer_end_ptr = CAST64(cvmx_log_buffer_head_ptr);
159        cvmx_log_buffer_write_ptr = cvmx_log_buffer_head_ptr;
160        cvmx_log_buffer_end_ptr = cvmx_log_buffer_write_ptr + CVMX_LOG_BUFFER_SIZE-1;
161        cvmx_log_buffer_head_ptr = CASTPTR(uint64_t, *cvmx_log_buffer_end_ptr);
162        *cvmx_log_buffer_end_ptr = CAST64(NULL);
163    }
164}
165
166
167/**
168 * @INTERNAL
169 * Simple inline function to build a log header
170 *
171 * @param type   Type of header to build
172 * @param size   Amount of data that follows the header in dwords
173 * @return The header
174 */
175static inline uint64_t __cvmx_log_build_header(cvmx_log_type_t type, uint64_t size) CVMX_LOG_DISABLE_PC_LOGGING;
176static inline uint64_t __cvmx_log_build_header(cvmx_log_type_t type, uint64_t size)
177{
178    cvmx_log_header_t header;
179    header.u64 = 0;
180    header.s.type = type;
181    header.s.size = size;
182    header.s.cycle = cvmx_get_cycle();
183    return header.u64;
184}
185
186
187/**
188 * @INTERNAL
189 * Function to write and increment the position. It rotates
190 * to the next log buffer as necessary.
191 *
192 * @param data   Data to write to the log
193 */
194static inline void __cvmx_log_write(uint64_t data) CVMX_LOG_DISABLE_PC_LOGGING;
195static inline void __cvmx_log_write(uint64_t data)
196{
197    /* Check and see if we need to rotate the log */
198    if (cvmx_likely(cvmx_log_buffer_write_ptr != cvmx_log_buffer_end_ptr))
199    {
200        /* No rotate is necessary, just write the data */
201        *cvmx_log_buffer_write_ptr++ = data;
202    }
203    else
204    {
205        /* Initialize the log if necessary */
206        if (cvmx_unlikely(cvmx_log_buffer_head_ptr == NULL))
207            __cvmx_log_initialize();
208        else
209        {
210            cvmx_log_buffer_write_ptr = CASTPTR(uint64_t, *cvmx_log_buffer_end_ptr);
211            if (cvmx_likely(cvmx_log_buffer_write_ptr))
212            {
213                /* Rotate the log. Might be a good time to send the old buffer
214                    somewhere */
215                cvmx_log_buffer_end_ptr = cvmx_log_buffer_write_ptr + CVMX_LOG_BUFFER_SIZE-1;
216            }
217            else
218                __cvmx_log_full_process();    /* After this function returns, the log must be ready for updates */
219        }
220        *cvmx_log_buffer_write_ptr++ = data;
221    }
222}
223
224
225/**
226 * Log a program counter address to the log. This is caused by
227 * the assembly code function mcount when writing the PC value
228 * is more complicated that the simple case support by it.
229 *
230 * @param pc     Program counter address to log
231 */
232void cvmx_log_pc(uint64_t pc) CVMX_LOG_DISABLE_PC_LOGGING;
233void cvmx_log_pc(uint64_t pc)
234{
235    __cvmx_log_write(__cvmx_log_build_header(CVMX_LOG_TYPE_PC, 1));
236    __cvmx_log_write(pc);
237}
238
239
240/**
241 * Log a constant printf style format string with 0 to 4
242 * arguments. The string must persist until the log is read,
243 * but the parameters are copied into the log.
244 *
245 * @param format  Constant printf style format string.
246 */
247void cvmx_log_printf0(const char *format)
248{
249    __cvmx_log_write(__cvmx_log_build_header(CVMX_LOG_TYPE_PRINTF, 1));
250    __cvmx_log_write(CAST64(format));
251}
252
253
254/**
255 * Log a constant printf style format string with 0 to 4
256 * arguments. The string must persist until the log is read,
257 * but the parameters are copied into the log.
258 *
259 * @param format  Constant printf style format string.
260 * @param number1 64bit argument to the printf format string
261 */
262void cvmx_log_printf1(const char *format, uint64_t number1)
263{
264    __cvmx_log_write(__cvmx_log_build_header(CVMX_LOG_TYPE_PRINTF, 2));
265    __cvmx_log_write(CAST64(format));
266    __cvmx_log_write(number1);
267}
268
269
270/**
271 * Log a constant printf style format string with 0 to 4
272 * arguments. The string must persist until the log is read,
273 * but the parameters are copied into the log.
274 *
275 * @param format  Constant printf style format string.
276 * @param number1 64bit argument to the printf format string
277 * @param number2 64bit argument to the printf format string
278 */
279void cvmx_log_printf2(const char *format, uint64_t number1, uint64_t number2)
280{
281    __cvmx_log_write(__cvmx_log_build_header(CVMX_LOG_TYPE_PRINTF, 3));
282    __cvmx_log_write(CAST64(format));
283    __cvmx_log_write(number1);
284    __cvmx_log_write(number2);
285}
286
287
288/**
289 * Log a constant printf style format string with 0 to 4
290 * arguments. The string must persist until the log is read,
291 * but the parameters are copied into the log.
292 *
293 * @param format  Constant printf style format string.
294 * @param number1 64bit argument to the printf format string
295 * @param number2 64bit argument to the printf format string
296 * @param number3 64bit argument to the printf format string
297 */
298void cvmx_log_printf3(const char *format, uint64_t number1, uint64_t number2, uint64_t number3)
299{
300    __cvmx_log_write(__cvmx_log_build_header(CVMX_LOG_TYPE_PRINTF, 4));
301    __cvmx_log_write(CAST64(format));
302    __cvmx_log_write(number1);
303    __cvmx_log_write(number2);
304    __cvmx_log_write(number3);
305}
306
307
308/**
309 * Log a constant printf style format string with 0 to 4
310 * arguments. The string must persist until the log is read,
311 * but the parameters are copied into the log.
312 *
313 * @param format  Constant printf style format string.
314 * @param number1 64bit argument to the printf format string
315 * @param number2 64bit argument to the printf format string
316 * @param number3 64bit argument to the printf format string
317 * @param number4 64bit argument to the printf format string
318 */
319void cvmx_log_printf4(const char *format, uint64_t number1, uint64_t number2, uint64_t number3, uint64_t number4)
320{
321    __cvmx_log_write(__cvmx_log_build_header(CVMX_LOG_TYPE_PRINTF, 5));
322    __cvmx_log_write(CAST64(format));
323    __cvmx_log_write(number1);
324    __cvmx_log_write(number2);
325    __cvmx_log_write(number3);
326    __cvmx_log_write(number4);
327}
328
329
330/**
331 * Log an arbitrary block of 64bit words. At most 255 64bit
332 * words can be logged. The words are copied into the log.
333 *
334 * @param size_in_dwords
335 *               Number of 64bit dwords to copy into the log.
336 * @param data   Array of 64bit dwords to copy
337 */
338void cvmx_log_data(uint64_t size_in_dwords, const uint64_t *data)
339{
340    if (size_in_dwords > 255)
341        size_in_dwords = 255;
342
343    __cvmx_log_write(__cvmx_log_build_header(CVMX_LOG_TYPE_DATA, size_in_dwords));
344    while (size_in_dwords--)
345        __cvmx_log_write(*data++);
346}
347
348
349/**
350 * Log a structured data object. Post processing will use the
351 * debugging information in the ELF file to determine how to
352 * display the structure. Max of 2032 bytes.
353 *
354 * Example:
355 * cvmx_log_structure("cvmx_wqe_t", work, sizeof(*work));
356 *
357 * @param type   C typedef expressed as a string. This will be used to
358 *               lookup the structure in the debugging infirmation.
359 * @param data   Data to be written to the log.
360 * @param size_in_bytes
361 *               Size if the data in bytes. Normally you'll use the
362 *               sizeof() operator here.
363 */
364void cvmx_log_structure(const char *type, void *data, int size_in_bytes)
365{
366    uint64_t size_in_dwords = (size_in_bytes + 7) >> 3;
367    uint64_t *ptr = (uint64_t*)data;
368
369    if (size_in_dwords > 254)
370        size_in_dwords = 254;
371
372    __cvmx_log_write(__cvmx_log_build_header(CVMX_LOG_TYPE_STRUCTURE, size_in_dwords + 1));
373    __cvmx_log_write(CAST64(type));
374    while (size_in_dwords--)
375        __cvmx_log_write(*ptr++);
376}
377
378
379/**
380 * Setup the mips performance counters
381 *
382 * @param counter1 Event type for counter 1
383 * @param counter2 Event type for counter 2
384 */
385void cvmx_log_perf_setup(cvmx_log_perf_event_t counter1, cvmx_log_perf_event_t counter2)
386{
387    cvmx_log_perf_control_t control;
388
389    control.u32 = 0;
390    control.s.event = counter1;
391    control.s.U = 1;
392    control.s.S = 1;
393    control.s.K = 1;
394    control.s.EX = 1;
395    asm ("mtc0 %0, $25, 0\n" : : "r"(control.u32));
396    control.s.event = counter2;
397    asm ("mtc0 %0, $25, 2\n" : : "r"(control.u32));
398}
399
400
401/**
402 * Log the performance counters
403 */
404void cvmx_log_perf(void)
405{
406    uint64_t control1;
407    uint64_t control2;
408    uint64_t data1;
409    uint64_t data2;
410    asm ("dmfc0 %0, $25, 1\n" : "=r"(data1));
411    asm ("dmfc0 %0, $25, 3\n" : "=r"(data2));
412    asm ("mfc0 %0, $25, 0\n" : "=r"(control1));
413    asm ("mfc0 %0, $25, 2\n" : "=r"(control2));
414    __cvmx_log_write(__cvmx_log_build_header(CVMX_LOG_TYPE_PERF, 3));
415    __cvmx_log_write(((control1 & 0xffffffff) << 32) | (control2 & 0xffffffff));
416    __cvmx_log_write(data1);
417    __cvmx_log_write(data2);
418}
419
420
421/**
422 * @INTERNAL
423 * Read a dword from the log
424 *
425 * @return the dword
426 */
427static uint64_t __cvmx_log_read(void) CVMX_LOG_DISABLE_PC_LOGGING;
428static uint64_t __cvmx_log_read(void)
429{
430    uint64_t data;
431
432    /* Check and see if we need to rotate the log */
433    if (cvmx_likely(cvmx_log_buffer_read_ptr != cvmx_log_buffer_read_end_ptr))
434    {
435        /* No rotate is necessary, just read the data */
436        data = *cvmx_log_buffer_read_ptr++;
437    }
438    else
439    {
440        cvmx_log_buffer_read_ptr = CASTPTR(uint64_t, *cvmx_log_buffer_read_end_ptr);
441        if (cvmx_likely(cvmx_log_buffer_read_ptr))
442        {
443            /* Rotate to the next log buffer */
444            cvmx_log_buffer_read_end_ptr = cvmx_log_buffer_read_ptr + CVMX_LOG_BUFFER_SIZE-1;
445            data = *cvmx_log_buffer_read_ptr++;
446        }
447        else
448        {
449            /* No more log buffers, return 0 */
450            cvmx_log_buffer_read_end_ptr = NULL;
451            data = 0;
452        }
453    }
454
455    return data;
456}
457
458
459/**
460 * Display the current log in a human readable format.
461 */
462void cvmx_log_display(void)
463{
464    unsigned int i;
465    cvmx_log_header_t header;
466
467    cvmx_log_buffer_read_ptr = cvmx_log_buffer_head_ptr;
468    cvmx_log_buffer_read_end_ptr = cvmx_log_buffer_read_ptr + CVMX_LOG_BUFFER_SIZE-1;
469
470    while (cvmx_log_buffer_read_ptr && (cvmx_log_buffer_read_ptr != cvmx_log_buffer_write_ptr))
471    {
472        header.u64 = __cvmx_log_read();
473        if (header.s.cycle == 0)
474            continue;
475        printf("%llu: ", (unsigned long long)header.s.cycle);
476        switch (header.s.type)
477        {
478            case CVMX_LOG_TYPE_PC:
479                if (header.s.size == 1)
480                    printf("pc 0x%016llx\n", (unsigned long long)__cvmx_log_read());
481                else
482                    printf("Illegal size (%d) for log entry: pc\n", header.s.size);
483                break;
484            case CVMX_LOG_TYPE_PRINTF:
485                switch (header.s.size)
486                {
487                    case 1:
488                        printf(CASTPTR(const char, __cvmx_log_read()));
489                        break;
490                    case 2:
491                        printf(CASTPTR(const char, __cvmx_log_read()), __cvmx_log_read());
492                        break;
493                    case 3:
494                        printf(CASTPTR(const char, __cvmx_log_read()), __cvmx_log_read(), __cvmx_log_read());
495                        break;
496                    case 4:
497                        printf(CASTPTR(const char, __cvmx_log_read()), __cvmx_log_read(), __cvmx_log_read(), __cvmx_log_read());
498                        break;
499                    case 5:
500                        printf(CASTPTR(const char, __cvmx_log_read()), __cvmx_log_read(), __cvmx_log_read(), __cvmx_log_read(), __cvmx_log_read());
501                        break;
502                    default:
503                        printf("Illegal size (%d) for log entry: printf\n", header.s.size);
504                        break;
505                }
506                printf("\n");
507                break;
508            case CVMX_LOG_TYPE_DATA:
509                printf("data");
510                for (i=0; i<header.s.size; i++)
511                    printf(" 0x%016llx", (unsigned long long)__cvmx_log_read());
512                printf("\n");
513                break;
514            case CVMX_LOG_TYPE_STRUCTURE:
515                printf("struct %s", CASTPTR(const char, __cvmx_log_read()));
516                for (i=1; i<header.s.size; i++)
517                    printf(" 0x%016llx", (unsigned long long)__cvmx_log_read());
518                printf("\n");
519                break;
520            case CVMX_LOG_TYPE_PERF:
521                if (header.s.size == 3)
522                {
523                    unsigned long long control = __cvmx_log_read();
524                    unsigned long long data1 = __cvmx_log_read();
525                    unsigned long long data2 = __cvmx_log_read();
526                    printf("perf control=0x%016llx data1=0x%016llx data2=0x%016llx\n", control, data1, data2);
527                }
528                else
529                    printf("Illegal size (%d) for log entry: perf\n", header.s.size);
530                break;
531            default:
532                break;
533        }
534    }
535}
536
537