blob: 2d1cd939b4df784d3644c6572d54693ff70b6b96 [file] [log] [blame]
Linus Torvalds1da177e2005-04-16 15:20:36 -07001S390 Debug Feature
2==================
3
4files: arch/s390/kernel/debug.c
5 include/asm-s390/debug.h
6
7Description:
8------------
9The goal of this feature is to provide a kernel debug logging API
10where log records can be stored efficiently in memory, where each component
11(e.g. device drivers) can have one separate debug log.
12One purpose of this is to inspect the debug logs after a production system crash
13in order to analyze the reason for the crash.
14If the system still runs but only a subcomponent which uses dbf failes,
15it is possible to look at the debug logs on a live system via the Linux proc
16filesystem.
17The debug feature may also very useful for kernel and driver development.
18
19Design:
20-------
21Kernel components (e.g. device drivers) can register themselves at the debug
22feature with the function call debug_register(). This function initializes a
23debug log for the caller. For each debug log exists a number of debug areas
24where exactly one is active at one time. Each debug area consists of contiguous
25pages in memory. In the debug areas there are stored debug entries (log records)
26which are written by event- and exception-calls.
27
28An event-call writes the specified debug entry to the active debug
29area and updates the log pointer for the active area. If the end
30of the active debug area is reached, a wrap around is done (ring buffer)
31and the next debug entry will be written at the beginning of the active
32debug area.
33
34An exception-call writes the specified debug entry to the log and
35switches to the next debug area. This is done in order to be sure
36that the records which describe the origin of the exception are not
37overwritten when a wrap around for the current area occurs.
38
39The debug areas itselve are also ordered in form of a ring buffer.
40When an exception is thrown in the last debug area, the following debug
41entries are then written again in the very first area.
42
43There are three versions for the event- and exception-calls: One for
44logging raw data, one for text and one for numbers.
45
46Each debug entry contains the following data:
47
48- Timestamp
49- Cpu-Number of calling task
50- Level of debug entry (0...6)
51- Return Address to caller
52- Flag, if entry is an exception or not
53
54The debug logs can be inspected in a live system through entries in
55the proc-filesystem. Under the path /proc/s390dbf there is
56a directory for each registered component, which is named like the
57corresponding component.
58
59The content of the directories are files which represent different views
60to the debug log. Each component can decide which views should be
61used through registering them with the function debug_register_view().
62Predefined views for hex/ascii, sprintf and raw binary data are provided.
63It is also possible to define other views. The content of
64a view can be inspected simply by reading the corresponding proc file.
65
66All debug logs have an an actual debug level (range from 0 to 6).
67The default level is 3. Event and Exception functions have a 'level'
68parameter. Only debug entries with a level that is lower or equal
69than the actual level are written to the log. This means, when
70writing events, high priority log entries should have a low level
71value whereas low priority entries should have a high one.
72The actual debug level can be changed with the help of the proc-filesystem
73through writing a number string "x" to the 'level' proc file which is
74provided for every debug log. Debugging can be switched off completely
75by using "-" on the 'level' proc file.
76
77Example:
78
79> echo "-" > /proc/s390dbf/dasd/level
80
81It is also possible to deactivate the debug feature globally for every
82debug log. You can change the behavior using 2 sysctl parameters in
83/proc/sys/s390dbf:
84There are currently 2 possible triggers, which stop the debug feature
85globally. The first possbility is to use the "debug_active" sysctl. If
86set to 1 the debug feature is running. If "debug_active" is set to 0 the
87debug feature is turned off.
88The second trigger which stops the debug feature is an kernel oops.
89That prevents the debug feature from overwriting debug information that
90happened before the oops. After an oops you can reactivate the debug feature
91by piping 1 to /proc/sys/s390dbf/debug_active. Nevertheless, its not
92suggested to use an oopsed kernel in an production environment.
93If you want to disallow the deactivation of the debug feature, you can use
94the "debug_stoppable" sysctl. If you set "debug_stoppable" to 0 the debug
95feature cannot be stopped. If the debug feature is already stopped, it
96will stay deactivated.
97
98Kernel Interfaces:
99------------------
100
101----------------------------------------------------------------------------
102debug_info_t *debug_register(char *name, int pages_index, int nr_areas,
103 int buf_size);
104
105Parameter: name: Name of debug log (e.g. used for proc entry)
106 pages_index: 2^pages_index pages will be allocated per area
107 nr_areas: number of debug areas
108 buf_size: size of data area in each debug entry
109
110Return Value: Handle for generated debug area
111 NULL if register failed
112
113Description: Allocates memory for a debug log
114 Must not be called within an interrupt handler
115
116---------------------------------------------------------------------------
117void debug_unregister (debug_info_t * id);
118
119Parameter: id: handle for debug log
120
121Return Value: none
122
123Description: frees memory for a debug log
124 Must not be called within an interrupt handler
125
126---------------------------------------------------------------------------
127void debug_set_level (debug_info_t * id, int new_level);
128
129Parameter: id: handle for debug log
130 new_level: new debug level
131
132Return Value: none
133
134Description: Sets new actual debug level if new_level is valid.
135
136---------------------------------------------------------------------------
137+void debug_stop_all(void);
138
139Parameter: none
140
141Return Value: none
142
143Description: stops the debug feature if stopping is allowed. Currently
144 used in case of a kernel oops.
145
146---------------------------------------------------------------------------
147debug_entry_t* debug_event (debug_info_t* id, int level, void* data,
148 int length);
149
150Parameter: id: handle for debug log
151 level: debug level
152 data: pointer to data for debug entry
153 length: length of data in bytes
154
155Return Value: Address of written debug entry
156
157Description: writes debug entry to active debug area (if level <= actual
158 debug level)
159
160---------------------------------------------------------------------------
161debug_entry_t* debug_int_event (debug_info_t * id, int level,
162 unsigned int data);
163debug_entry_t* debug_long_event(debug_info_t * id, int level,
164 unsigned long data);
165
166Parameter: id: handle for debug log
167 level: debug level
168 data: integer value for debug entry
169
170Return Value: Address of written debug entry
171
172Description: writes debug entry to active debug area (if level <= actual
173 debug level)
174
175---------------------------------------------------------------------------
176debug_entry_t* debug_text_event (debug_info_t * id, int level,
177 const char* data);
178
179Parameter: id: handle for debug log
180 level: debug level
181 data: string for debug entry
182
183Return Value: Address of written debug entry
184
185Description: writes debug entry in ascii format to active debug area
186 (if level <= actual debug level)
187
188---------------------------------------------------------------------------
189debug_entry_t* debug_sprintf_event (debug_info_t * id, int level,
190 char* string,...);
191
192Parameter: id: handle for debug log
193 level: debug level
194 string: format string for debug entry
195 ...: varargs used as in sprintf()
196
197Return Value: Address of written debug entry
198
199Description: writes debug entry with format string and varargs (longs) to
200 active debug area (if level $<=$ actual debug level).
201 floats and long long datatypes cannot be used as varargs.
202
203---------------------------------------------------------------------------
204
205debug_entry_t* debug_exception (debug_info_t* id, int level, void* data,
206 int length);
207
208Parameter: id: handle for debug log
209 level: debug level
210 data: pointer to data for debug entry
211 length: length of data in bytes
212
213Return Value: Address of written debug entry
214
215Description: writes debug entry to active debug area (if level <= actual
216 debug level) and switches to next debug area
217
218---------------------------------------------------------------------------
219debug_entry_t* debug_int_exception (debug_info_t * id, int level,
220 unsigned int data);
221debug_entry_t* debug_long_exception(debug_info_t * id, int level,
222 unsigned long data);
223
224Parameter: id: handle for debug log
225 level: debug level
226 data: integer value for debug entry
227
228Return Value: Address of written debug entry
229
230Description: writes debug entry to active debug area (if level <= actual
231 debug level) and switches to next debug area
232
233---------------------------------------------------------------------------
234debug_entry_t* debug_text_exception (debug_info_t * id, int level,
235 const char* data);
236
237Parameter: id: handle for debug log
238 level: debug level
239 data: string for debug entry
240
241Return Value: Address of written debug entry
242
243Description: writes debug entry in ascii format to active debug area
244 (if level <= actual debug level) and switches to next debug
245 area
246
247---------------------------------------------------------------------------
248debug_entry_t* debug_sprintf_exception (debug_info_t * id, int level,
249 char* string,...);
250
251Parameter: id: handle for debug log
252 level: debug level
253 string: format string for debug entry
254 ...: varargs used as in sprintf()
255
256Return Value: Address of written debug entry
257
258Description: writes debug entry with format string and varargs (longs) to
259 active debug area (if level $<=$ actual debug level) and
260 switches to next debug area.
261 floats and long long datatypes cannot be used as varargs.
262
263---------------------------------------------------------------------------
264
265int debug_register_view (debug_info_t * id, struct debug_view *view);
266
267Parameter: id: handle for debug log
268 view: pointer to debug view struct
269
270Return Value: 0 : ok
271 < 0: Error
272
273Description: registers new debug view and creates proc dir entry
274
275---------------------------------------------------------------------------
276int debug_unregister_view (debug_info_t * id, struct debug_view *view);
277
278Parameter: id: handle for debug log
279 view: pointer to debug view struct
280
281Return Value: 0 : ok
282 < 0: Error
283
284Description: unregisters debug view and removes proc dir entry
285
286
287
288Predefined views:
289-----------------
290
291extern struct debug_view debug_hex_ascii_view;
292extern struct debug_view debug_raw_view;
293extern struct debug_view debug_sprintf_view;
294
295Examples
296--------
297
298/*
299 * hex_ascii- + raw-view Example
300 */
301
302#include <linux/init.h>
303#include <asm/debug.h>
304
305static debug_info_t* debug_info;
306
307static int init(void)
308{
309 /* register 4 debug areas with one page each and 4 byte data field */
310
311 debug_info = debug_register ("test", 0, 4, 4 );
312 debug_register_view(debug_info,&debug_hex_ascii_view);
313 debug_register_view(debug_info,&debug_raw_view);
314
315 debug_text_event(debug_info, 4 , "one ");
316 debug_int_exception(debug_info, 4, 4711);
317 debug_event(debug_info, 3, &debug_info, 4);
318
319 return 0;
320}
321
322static void cleanup(void)
323{
324 debug_unregister (debug_info);
325}
326
327module_init(init);
328module_exit(cleanup);
329
330---------------------------------------------------------------------------
331
332/*
333 * sprintf-view Example
334 */
335
336#include <linux/init.h>
337#include <asm/debug.h>
338
339static debug_info_t* debug_info;
340
341static int init(void)
342{
343 /* register 4 debug areas with one page each and data field for */
344 /* format string pointer + 2 varargs (= 3 * sizeof(long)) */
345
346 debug_info = debug_register ("test", 0, 4, sizeof(long) * 3);
347 debug_register_view(debug_info,&debug_sprintf_view);
348
349 debug_sprintf_event(debug_info, 2 , "first event in %s:%i\n",__FILE__,__LINE__);
350 debug_sprintf_exception(debug_info, 1, "pointer to debug info: %p\n",&debug_info);
351
352 return 0;
353}
354
355static void cleanup(void)
356{
357 debug_unregister (debug_info);
358}
359
360module_init(init);
361module_exit(cleanup);
362
363
364
365ProcFS Interface
366----------------
367Views to the debug logs can be investigated through reading the corresponding
368proc-files:
369
370Example:
371
372> ls /proc/s390dbf/dasd
373flush hex_ascii level raw
374> cat /proc/s390dbf/dasd/hex_ascii | sort +1
37500 00974733272:680099 2 - 02 0006ad7e 07 ea 4a 90 | ....
37600 00974733272:682210 2 - 02 0006ade6 46 52 45 45 | FREE
37700 00974733272:682213 2 - 02 0006adf6 07 ea 4a 90 | ....
37800 00974733272:682281 1 * 02 0006ab08 41 4c 4c 43 | EXCP
37901 00974733272:682284 2 - 02 0006ab16 45 43 4b 44 | ECKD
38001 00974733272:682287 2 - 02 0006ab28 00 00 00 04 | ....
38101 00974733272:682289 2 - 02 0006ab3e 00 00 00 20 | ...
38201 00974733272:682297 2 - 02 0006ad7e 07 ea 4a 90 | ....
38301 00974733272:684384 2 - 00 0006ade6 46 52 45 45 | FREE
38401 00974733272:684388 2 - 00 0006adf6 07 ea 4a 90 | ....
385
386See section about predefined views for explanation of the above output!
387
388Changing the debug level
389------------------------
390
391Example:
392
393
394> cat /proc/s390dbf/dasd/level
3953
396> echo "5" > /proc/s390dbf/dasd/level
397> cat /proc/s390dbf/dasd/level
3985
399
400Flushing debug areas
401--------------------
402Debug areas can be flushed with piping the number of the desired
403area (0...n) to the proc file "flush". When using "-" all debug areas
404are flushed.
405
406Examples:
407
4081. Flush debug area 0:
409> echo "0" > /proc/s390dbf/dasd/flush
410
4112. Flush all debug areas:
412> echo "-" > /proc/s390dbf/dasd/flush
413
414Stooping the debug feature
415--------------------------
416Example:
417
4181. Check if stopping is allowed
419> cat /proc/sys/s390dbf/debug_stoppable
4202. Stop debug feature
421> echo 0 > /proc/sys/s390dbf/debug_active
422
423lcrash Interface
424----------------
425It is planned that the dump analysis tool lcrash gets an additional command
426's390dbf' to display all the debug logs. With this tool it will be possible
427to investigate the debug logs on a live system and with a memory dump after
428a system crash.
429
430Investigating raw memory
431------------------------
432One last possibility to investigate the debug logs at a live
433system and after a system crash is to look at the raw memory
434under VM or at the Service Element.
435It is possible to find the anker of the debug-logs through
436the 'debug_area_first' symbol in the System map. Then one has
437to follow the correct pointers of the data-structures defined
438in debug.h and find the debug-areas in memory.
439Normally modules which use the debug feature will also have
440a global variable with the pointer to the debug-logs. Following
441this pointer it will also be possible to find the debug logs in
442memory.
443
444For this method it is recommended to use '16 * x + 4' byte (x = 0..n)
445for the length of the data field in debug_register() in
446order to see the debug entries well formatted.
447
448
449Predefined Views
450----------------
451
452There are three predefined views: hex_ascii, raw and sprintf.
453The hex_ascii view shows the data field in hex and ascii representation
454(e.g. '45 43 4b 44 | ECKD').
455The raw view returns a bytestream as the debug areas are stored in memory.
456
457The sprintf view formats the debug entries in the same way as the sprintf
458function would do. The sprintf event/expection fuctions write to the
459debug entry a pointer to the format string (size = sizeof(long))
460and for each vararg a long value. So e.g. for a debug entry with a format
461string plus two varargs one would need to allocate a (3 * sizeof(long))
462byte data area in the debug_register() function.
463
464
465NOTE: If using the sprintf view do NOT use other event/exception functions
466than the sprintf-event and -exception functions.
467
468The format of the hex_ascii and sprintf view is as follows:
469- Number of area
470- Timestamp (formatted as seconds and microseconds since 00:00:00 Coordinated
471 Universal Time (UTC), January 1, 1970)
472- level of debug entry
473- Exception flag (* = Exception)
474- Cpu-Number of calling task
475- Return Address to caller
476- data field
477
478The format of the raw view is:
479- Header as described in debug.h
480- datafield
481
482A typical line of the hex_ascii view will look like the following (first line
483is only for explanation and will not be displayed when 'cating' the view):
484
485area time level exception cpu caller data (hex + ascii)
486--------------------------------------------------------------------------
48700 00964419409:440690 1 - 00 88023fe
488
489
490Defining views
491--------------
492
493Views are specified with the 'debug_view' structure. There are defined
494callback functions which are used for reading and writing the proc files:
495
496struct debug_view {
497 char name[DEBUG_MAX_PROCF_LEN];
498 debug_prolog_proc_t* prolog_proc;
499 debug_header_proc_t* header_proc;
500 debug_format_proc_t* format_proc;
501 debug_input_proc_t* input_proc;
502 void* private_data;
503};
504
505where
506
507typedef int (debug_header_proc_t) (debug_info_t* id,
508 struct debug_view* view,
509 int area,
510 debug_entry_t* entry,
511 char* out_buf);
512
513typedef int (debug_format_proc_t) (debug_info_t* id,
514 struct debug_view* view, char* out_buf,
515 const char* in_buf);
516typedef int (debug_prolog_proc_t) (debug_info_t* id,
517 struct debug_view* view,
518 char* out_buf);
519typedef int (debug_input_proc_t) (debug_info_t* id,
520 struct debug_view* view,
521 struct file* file, const char* user_buf,
522 size_t in_buf_size, loff_t* offset);
523
524
525The "private_data" member can be used as pointer to view specific data.
526It is not used by the debug feature itself.
527
528The output when reading a debug-proc file is structured like this:
529
530"prolog_proc output"
531
532"header_proc output 1" "format_proc output 1"
533"header_proc output 2" "format_proc output 2"
534"header_proc output 3" "format_proc output 3"
535...
536
537When a view is read from the proc fs, the Debug Feature calls the
538'prolog_proc' once for writing the prolog.
539Then 'header_proc' and 'format_proc' are called for each
540existing debug entry.
541
542The input_proc can be used to implement functionality when it is written to
543the view (e.g. like with 'echo "0" > /proc/s390dbf/dasd/level).
544
545For header_proc there can be used the default function
546debug_dflt_header_fn() which is defined in in debug.h.
547and which produces the same header output as the predefined views.
548E.g:
54900 00964419409:440761 2 - 00 88023ec
550
551In order to see how to use the callback functions check the implementation
552of the default views!
553
554Example
555
556#include <asm/debug.h>
557
558#define UNKNOWNSTR "data: %08x"
559
560const char* messages[] =
561{"This error...........\n",
562 "That error...........\n",
563 "Problem..............\n",
564 "Something went wrong.\n",
565 "Everything ok........\n",
566 NULL
567};
568
569static int debug_test_format_fn(
570 debug_info_t * id, struct debug_view *view,
571 char *out_buf, const char *in_buf
572)
573{
574 int i, rc = 0;
575
576 if(id->buf_size >= 4) {
577 int msg_nr = *((int*)in_buf);
578 if(msg_nr < sizeof(messages)/sizeof(char*) - 1)
579 rc += sprintf(out_buf, "%s", messages[msg_nr]);
580 else
581 rc += sprintf(out_buf, UNKNOWNSTR, msg_nr);
582 }
583 out:
584 return rc;
585}
586
587struct debug_view debug_test_view = {
588 "myview", /* name of view */
589 NULL, /* no prolog */
590 &debug_dflt_header_fn, /* default header for each entry */
591 &debug_test_format_fn, /* our own format function */
592 NULL, /* no input function */
593 NULL /* no private data */
594};
595
596=====
597test:
598=====
599debug_info_t *debug_info;
600...
601debug_info = debug_register ("test", 0, 4, 4 ));
602debug_register_view(debug_info, &debug_test_view);
603for(i = 0; i < 10; i ++) debug_int_event(debug_info, 1, i);
604
605> cat /proc/s390dbf/test/myview
60600 00964419734:611402 1 - 00 88042ca This error...........
60700 00964419734:611405 1 - 00 88042ca That error...........
60800 00964419734:611408 1 - 00 88042ca Problem..............
60900 00964419734:611411 1 - 00 88042ca Something went wrong.
61000 00964419734:611414 1 - 00 88042ca Everything ok........
61100 00964419734:611417 1 - 00 88042ca data: 00000005
61200 00964419734:611419 1 - 00 88042ca data: 00000006
61300 00964419734:611422 1 - 00 88042ca data: 00000007
61400 00964419734:611425 1 - 00 88042ca data: 00000008
61500 00964419734:611428 1 - 00 88042ca data: 00000009