blob: e321a8ed2a2d6bf78581673b967cc9fe45186435 [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,
Michael Holzheu66a464d2005-06-25 14:55:33 -070015it is possible to look at the debug logs on a live system via the Linux
16debugfs filesystem.
Linus Torvalds1da177e2005-04-16 15:20:36 -070017The 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
Michael Holzheu66a464d2005-06-25 14:55:33 -070055the debugfs-filesystem. Under the toplevel directory "s390dbf" there is
Linus Torvalds1da177e2005-04-16 15:20:36 -070056a directory for each registered component, which is named like the
Michael Holzheu66a464d2005-06-25 14:55:33 -070057corresponding component. The debugfs normally should be mounted to
58/sys/kernel/debug therefore the debug feature can be accessed unter
59/sys/kernel/debug/s390dbf.
Linus Torvalds1da177e2005-04-16 15:20:36 -070060
61The content of the directories are files which represent different views
62to the debug log. Each component can decide which views should be
63used through registering them with the function debug_register_view().
64Predefined views for hex/ascii, sprintf and raw binary data are provided.
65It is also possible to define other views. The content of
Michael Holzheu66a464d2005-06-25 14:55:33 -070066a view can be inspected simply by reading the corresponding debugfs file.
Linus Torvalds1da177e2005-04-16 15:20:36 -070067
68All debug logs have an an actual debug level (range from 0 to 6).
69The default level is 3. Event and Exception functions have a 'level'
70parameter. Only debug entries with a level that is lower or equal
71than the actual level are written to the log. This means, when
72writing events, high priority log entries should have a low level
73value whereas low priority entries should have a high one.
Michael Holzheu66a464d2005-06-25 14:55:33 -070074The actual debug level can be changed with the help of the debugfs-filesystem
75through writing a number string "x" to the 'level' debugfs file which is
Linus Torvalds1da177e2005-04-16 15:20:36 -070076provided for every debug log. Debugging can be switched off completely
Michael Holzheu66a464d2005-06-25 14:55:33 -070077by using "-" on the 'level' debugfs file.
Linus Torvalds1da177e2005-04-16 15:20:36 -070078
79Example:
80
Michael Holzheu66a464d2005-06-25 14:55:33 -070081> echo "-" > /sys/kernel/debug/s390dbf/dasd/level
Linus Torvalds1da177e2005-04-16 15:20:36 -070082
83It is also possible to deactivate the debug feature globally for every
84debug log. You can change the behavior using 2 sysctl parameters in
85/proc/sys/s390dbf:
86There are currently 2 possible triggers, which stop the debug feature
87globally. The first possbility is to use the "debug_active" sysctl. If
88set to 1 the debug feature is running. If "debug_active" is set to 0 the
89debug feature is turned off.
90The second trigger which stops the debug feature is an kernel oops.
91That prevents the debug feature from overwriting debug information that
92happened before the oops. After an oops you can reactivate the debug feature
93by piping 1 to /proc/sys/s390dbf/debug_active. Nevertheless, its not
94suggested to use an oopsed kernel in an production environment.
95If you want to disallow the deactivation of the debug feature, you can use
96the "debug_stoppable" sysctl. If you set "debug_stoppable" to 0 the debug
97feature cannot be stopped. If the debug feature is already stopped, it
98will stay deactivated.
99
100Kernel Interfaces:
101------------------
102
103----------------------------------------------------------------------------
Michael Holzheu66a464d2005-06-25 14:55:33 -0700104debug_info_t *debug_register(char *name, int pages, int nr_areas,
Linus Torvalds1da177e2005-04-16 15:20:36 -0700105 int buf_size);
106
Michael Holzheu66a464d2005-06-25 14:55:33 -0700107Parameter: name: Name of debug log (e.g. used for debugfs entry)
108 pages: number of pages, which will be allocated per area
Linus Torvalds1da177e2005-04-16 15:20:36 -0700109 nr_areas: number of debug areas
110 buf_size: size of data area in each debug entry
111
112Return Value: Handle for generated debug area
113 NULL if register failed
114
115Description: Allocates memory for a debug log
116 Must not be called within an interrupt handler
117
118---------------------------------------------------------------------------
119void debug_unregister (debug_info_t * id);
120
121Parameter: id: handle for debug log
122
123Return Value: none
124
125Description: frees memory for a debug log
126 Must not be called within an interrupt handler
127
128---------------------------------------------------------------------------
129void debug_set_level (debug_info_t * id, int new_level);
130
131Parameter: id: handle for debug log
132 new_level: new debug level
133
134Return Value: none
135
136Description: Sets new actual debug level if new_level is valid.
137
138---------------------------------------------------------------------------
Michael Holzheu66a464d2005-06-25 14:55:33 -0700139void debug_stop_all(void);
Linus Torvalds1da177e2005-04-16 15:20:36 -0700140
141Parameter: none
142
143Return Value: none
144
145Description: stops the debug feature if stopping is allowed. Currently
146 used in case of a kernel oops.
147
148---------------------------------------------------------------------------
149debug_entry_t* debug_event (debug_info_t* id, int level, void* data,
150 int length);
151
152Parameter: id: handle for debug log
153 level: debug level
154 data: pointer to data for debug entry
155 length: length of data in bytes
156
157Return Value: Address of written debug entry
158
159Description: writes debug entry to active debug area (if level <= actual
160 debug level)
161
162---------------------------------------------------------------------------
163debug_entry_t* debug_int_event (debug_info_t * id, int level,
164 unsigned int data);
165debug_entry_t* debug_long_event(debug_info_t * id, int level,
166 unsigned long data);
167
168Parameter: id: handle for debug log
169 level: debug level
170 data: integer value for debug entry
171
172Return Value: Address of written debug entry
173
174Description: writes debug entry to active debug area (if level <= actual
175 debug level)
176
177---------------------------------------------------------------------------
178debug_entry_t* debug_text_event (debug_info_t * id, int level,
179 const char* data);
180
181Parameter: id: handle for debug log
182 level: debug level
183 data: string for debug entry
184
185Return Value: Address of written debug entry
186
187Description: writes debug entry in ascii format to active debug area
188 (if level <= actual debug level)
189
190---------------------------------------------------------------------------
191debug_entry_t* debug_sprintf_event (debug_info_t * id, int level,
192 char* string,...);
193
194Parameter: id: handle for debug log
195 level: debug level
196 string: format string for debug entry
197 ...: varargs used as in sprintf()
198
199Return Value: Address of written debug entry
200
201Description: writes debug entry with format string and varargs (longs) to
202 active debug area (if level $<=$ actual debug level).
203 floats and long long datatypes cannot be used as varargs.
204
205---------------------------------------------------------------------------
206
207debug_entry_t* debug_exception (debug_info_t* id, int level, void* data,
208 int length);
209
210Parameter: id: handle for debug log
211 level: debug level
212 data: pointer to data for debug entry
213 length: length of data in bytes
214
215Return Value: Address of written debug entry
216
217Description: writes debug entry to active debug area (if level <= actual
218 debug level) and switches to next debug area
219
220---------------------------------------------------------------------------
221debug_entry_t* debug_int_exception (debug_info_t * id, int level,
222 unsigned int data);
223debug_entry_t* debug_long_exception(debug_info_t * id, int level,
224 unsigned long data);
225
226Parameter: id: handle for debug log
227 level: debug level
228 data: integer value for debug entry
229
230Return Value: Address of written debug entry
231
232Description: writes debug entry to active debug area (if level <= actual
233 debug level) and switches to next debug area
234
235---------------------------------------------------------------------------
236debug_entry_t* debug_text_exception (debug_info_t * id, int level,
237 const char* data);
238
239Parameter: id: handle for debug log
240 level: debug level
241 data: string for debug entry
242
243Return Value: Address of written debug entry
244
245Description: writes debug entry in ascii format to active debug area
246 (if level <= actual debug level) and switches to next debug
247 area
248
249---------------------------------------------------------------------------
250debug_entry_t* debug_sprintf_exception (debug_info_t * id, int level,
251 char* string,...);
252
253Parameter: id: handle for debug log
254 level: debug level
255 string: format string for debug entry
256 ...: varargs used as in sprintf()
257
258Return Value: Address of written debug entry
259
260Description: writes debug entry with format string and varargs (longs) to
261 active debug area (if level $<=$ actual debug level) and
262 switches to next debug area.
263 floats and long long datatypes cannot be used as varargs.
264
265---------------------------------------------------------------------------
266
267int debug_register_view (debug_info_t * id, struct debug_view *view);
268
269Parameter: id: handle for debug log
270 view: pointer to debug view struct
271
272Return Value: 0 : ok
273 < 0: Error
274
Michael Holzheu66a464d2005-06-25 14:55:33 -0700275Description: registers new debug view and creates debugfs dir entry
Linus Torvalds1da177e2005-04-16 15:20:36 -0700276
277---------------------------------------------------------------------------
278int debug_unregister_view (debug_info_t * id, struct debug_view *view);
279
280Parameter: id: handle for debug log
281 view: pointer to debug view struct
282
283Return Value: 0 : ok
284 < 0: Error
285
Michael Holzheu66a464d2005-06-25 14:55:33 -0700286Description: unregisters debug view and removes debugfs dir entry
Linus Torvalds1da177e2005-04-16 15:20:36 -0700287
288
289
290Predefined views:
291-----------------
292
293extern struct debug_view debug_hex_ascii_view;
294extern struct debug_view debug_raw_view;
295extern struct debug_view debug_sprintf_view;
296
297Examples
298--------
299
300/*
301 * hex_ascii- + raw-view Example
302 */
303
304#include <linux/init.h>
305#include <asm/debug.h>
306
307static debug_info_t* debug_info;
308
309static int init(void)
310{
311 /* register 4 debug areas with one page each and 4 byte data field */
312
Michael Holzheu66a464d2005-06-25 14:55:33 -0700313 debug_info = debug_register ("test", 1, 4, 4 );
Linus Torvalds1da177e2005-04-16 15:20:36 -0700314 debug_register_view(debug_info,&debug_hex_ascii_view);
315 debug_register_view(debug_info,&debug_raw_view);
316
317 debug_text_event(debug_info, 4 , "one ");
318 debug_int_exception(debug_info, 4, 4711);
319 debug_event(debug_info, 3, &debug_info, 4);
320
321 return 0;
322}
323
324static void cleanup(void)
325{
326 debug_unregister (debug_info);
327}
328
329module_init(init);
330module_exit(cleanup);
331
332---------------------------------------------------------------------------
333
334/*
335 * sprintf-view Example
336 */
337
338#include <linux/init.h>
339#include <asm/debug.h>
340
341static debug_info_t* debug_info;
342
343static int init(void)
344{
345 /* register 4 debug areas with one page each and data field for */
346 /* format string pointer + 2 varargs (= 3 * sizeof(long)) */
347
Michael Holzheu66a464d2005-06-25 14:55:33 -0700348 debug_info = debug_register ("test", 1, 4, sizeof(long) * 3);
Linus Torvalds1da177e2005-04-16 15:20:36 -0700349 debug_register_view(debug_info,&debug_sprintf_view);
350
351 debug_sprintf_event(debug_info, 2 , "first event in %s:%i\n",__FILE__,__LINE__);
352 debug_sprintf_exception(debug_info, 1, "pointer to debug info: %p\n",&debug_info);
353
354 return 0;
355}
356
357static void cleanup(void)
358{
359 debug_unregister (debug_info);
360}
361
362module_init(init);
363module_exit(cleanup);
364
365
366
Michael Holzheu66a464d2005-06-25 14:55:33 -0700367Debugfs Interface
Linus Torvalds1da177e2005-04-16 15:20:36 -0700368----------------
369Views to the debug logs can be investigated through reading the corresponding
Michael Holzheu66a464d2005-06-25 14:55:33 -0700370debugfs-files:
Linus Torvalds1da177e2005-04-16 15:20:36 -0700371
372Example:
373
Michael Holzheu66a464d2005-06-25 14:55:33 -0700374> ls /sys/kernel/debug/s390dbf/dasd
375flush hex_ascii level pages raw
376> cat /sys/kernel/debug/s390dbf/dasd/hex_ascii | sort +1
Linus Torvalds1da177e2005-04-16 15:20:36 -070037700 00974733272:680099 2 - 02 0006ad7e 07 ea 4a 90 | ....
37800 00974733272:682210 2 - 02 0006ade6 46 52 45 45 | FREE
37900 00974733272:682213 2 - 02 0006adf6 07 ea 4a 90 | ....
38000 00974733272:682281 1 * 02 0006ab08 41 4c 4c 43 | EXCP
38101 00974733272:682284 2 - 02 0006ab16 45 43 4b 44 | ECKD
38201 00974733272:682287 2 - 02 0006ab28 00 00 00 04 | ....
38301 00974733272:682289 2 - 02 0006ab3e 00 00 00 20 | ...
38401 00974733272:682297 2 - 02 0006ad7e 07 ea 4a 90 | ....
38501 00974733272:684384 2 - 00 0006ade6 46 52 45 45 | FREE
38601 00974733272:684388 2 - 00 0006adf6 07 ea 4a 90 | ....
387
388See section about predefined views for explanation of the above output!
389
390Changing the debug level
391------------------------
392
393Example:
394
395
Michael Holzheu66a464d2005-06-25 14:55:33 -0700396> cat /sys/kernel/debug/s390dbf/dasd/level
Linus Torvalds1da177e2005-04-16 15:20:36 -07003973
Michael Holzheu66a464d2005-06-25 14:55:33 -0700398> echo "5" > /sys/kernel/debug/s390dbf/dasd/level
399> cat /sys/kernel/debug/s390dbf/dasd/level
Linus Torvalds1da177e2005-04-16 15:20:36 -07004005
401
402Flushing debug areas
403--------------------
404Debug areas can be flushed with piping the number of the desired
Michael Holzheu66a464d2005-06-25 14:55:33 -0700405area (0...n) to the debugfs file "flush". When using "-" all debug areas
Linus Torvalds1da177e2005-04-16 15:20:36 -0700406are flushed.
407
408Examples:
409
4101. Flush debug area 0:
Michael Holzheu66a464d2005-06-25 14:55:33 -0700411> echo "0" > /sys/kernel/debug/s390dbf/dasd/flush
Linus Torvalds1da177e2005-04-16 15:20:36 -0700412
4132. Flush all debug areas:
Michael Holzheu66a464d2005-06-25 14:55:33 -0700414> echo "-" > /sys/kernel/debug/s390dbf/dasd/flush
415
416Changing the size of debug areas
417------------------------------------
418It is possible the change the size of debug areas through piping
419the number of pages to the debugfs file "pages". The resize request will
420also flush the debug areas.
421
422Example:
423
424Define 4 pages for the debug areas of debug feature "dasd":
425> echo "4" > /sys/kernel/debug/s390dbf/dasd/pages
Linus Torvalds1da177e2005-04-16 15:20:36 -0700426
427Stooping the debug feature
428--------------------------
429Example:
430
4311. Check if stopping is allowed
432> cat /proc/sys/s390dbf/debug_stoppable
4332. Stop debug feature
434> echo 0 > /proc/sys/s390dbf/debug_active
435
436lcrash Interface
437----------------
438It is planned that the dump analysis tool lcrash gets an additional command
439's390dbf' to display all the debug logs. With this tool it will be possible
440to investigate the debug logs on a live system and with a memory dump after
441a system crash.
442
443Investigating raw memory
444------------------------
445One last possibility to investigate the debug logs at a live
446system and after a system crash is to look at the raw memory
447under VM or at the Service Element.
448It is possible to find the anker of the debug-logs through
449the 'debug_area_first' symbol in the System map. Then one has
450to follow the correct pointers of the data-structures defined
451in debug.h and find the debug-areas in memory.
452Normally modules which use the debug feature will also have
453a global variable with the pointer to the debug-logs. Following
454this pointer it will also be possible to find the debug logs in
455memory.
456
457For this method it is recommended to use '16 * x + 4' byte (x = 0..n)
458for the length of the data field in debug_register() in
459order to see the debug entries well formatted.
460
461
462Predefined Views
463----------------
464
465There are three predefined views: hex_ascii, raw and sprintf.
466The hex_ascii view shows the data field in hex and ascii representation
467(e.g. '45 43 4b 44 | ECKD').
468The raw view returns a bytestream as the debug areas are stored in memory.
469
470The sprintf view formats the debug entries in the same way as the sprintf
Tobias Klauserd533f672005-09-10 00:26:46 -0700471function would do. The sprintf event/expection functions write to the
Linus Torvalds1da177e2005-04-16 15:20:36 -0700472debug entry a pointer to the format string (size = sizeof(long))
473and for each vararg a long value. So e.g. for a debug entry with a format
474string plus two varargs one would need to allocate a (3 * sizeof(long))
475byte data area in the debug_register() function.
476
477
478NOTE: If using the sprintf view do NOT use other event/exception functions
479than the sprintf-event and -exception functions.
480
481The format of the hex_ascii and sprintf view is as follows:
482- Number of area
483- Timestamp (formatted as seconds and microseconds since 00:00:00 Coordinated
484 Universal Time (UTC), January 1, 1970)
485- level of debug entry
486- Exception flag (* = Exception)
487- Cpu-Number of calling task
488- Return Address to caller
489- data field
490
491The format of the raw view is:
492- Header as described in debug.h
493- datafield
494
495A typical line of the hex_ascii view will look like the following (first line
496is only for explanation and will not be displayed when 'cating' the view):
497
498area time level exception cpu caller data (hex + ascii)
499--------------------------------------------------------------------------
50000 00964419409:440690 1 - 00 88023fe
501
502
503Defining views
504--------------
505
506Views are specified with the 'debug_view' structure. There are defined
Michael Holzheu66a464d2005-06-25 14:55:33 -0700507callback functions which are used for reading and writing the debugfs files:
Linus Torvalds1da177e2005-04-16 15:20:36 -0700508
509struct debug_view {
510 char name[DEBUG_MAX_PROCF_LEN];
511 debug_prolog_proc_t* prolog_proc;
512 debug_header_proc_t* header_proc;
513 debug_format_proc_t* format_proc;
514 debug_input_proc_t* input_proc;
515 void* private_data;
516};
517
518where
519
520typedef int (debug_header_proc_t) (debug_info_t* id,
521 struct debug_view* view,
522 int area,
523 debug_entry_t* entry,
524 char* out_buf);
525
526typedef int (debug_format_proc_t) (debug_info_t* id,
527 struct debug_view* view, char* out_buf,
528 const char* in_buf);
529typedef int (debug_prolog_proc_t) (debug_info_t* id,
530 struct debug_view* view,
531 char* out_buf);
532typedef int (debug_input_proc_t) (debug_info_t* id,
533 struct debug_view* view,
534 struct file* file, const char* user_buf,
535 size_t in_buf_size, loff_t* offset);
536
537
538The "private_data" member can be used as pointer to view specific data.
539It is not used by the debug feature itself.
540
Michael Holzheu66a464d2005-06-25 14:55:33 -0700541The output when reading a debugfs file is structured like this:
Linus Torvalds1da177e2005-04-16 15:20:36 -0700542
543"prolog_proc output"
544
545"header_proc output 1" "format_proc output 1"
546"header_proc output 2" "format_proc output 2"
547"header_proc output 3" "format_proc output 3"
548...
549
Michael Holzheu66a464d2005-06-25 14:55:33 -0700550When a view is read from the debugfs, the Debug Feature calls the
Linus Torvalds1da177e2005-04-16 15:20:36 -0700551'prolog_proc' once for writing the prolog.
552Then 'header_proc' and 'format_proc' are called for each
553existing debug entry.
554
555The input_proc can be used to implement functionality when it is written to
Michael Holzheu66a464d2005-06-25 14:55:33 -0700556the view (e.g. like with 'echo "0" > /sys/kernel/debug/s390dbf/dasd/level).
Linus Torvalds1da177e2005-04-16 15:20:36 -0700557
558For header_proc there can be used the default function
559debug_dflt_header_fn() which is defined in in debug.h.
560and which produces the same header output as the predefined views.
561E.g:
56200 00964419409:440761 2 - 00 88023ec
563
564In order to see how to use the callback functions check the implementation
565of the default views!
566
567Example
568
569#include <asm/debug.h>
570
571#define UNKNOWNSTR "data: %08x"
572
573const char* messages[] =
574{"This error...........\n",
575 "That error...........\n",
576 "Problem..............\n",
577 "Something went wrong.\n",
578 "Everything ok........\n",
579 NULL
580};
581
582static int debug_test_format_fn(
583 debug_info_t * id, struct debug_view *view,
584 char *out_buf, const char *in_buf
585)
586{
587 int i, rc = 0;
588
589 if(id->buf_size >= 4) {
590 int msg_nr = *((int*)in_buf);
591 if(msg_nr < sizeof(messages)/sizeof(char*) - 1)
592 rc += sprintf(out_buf, "%s", messages[msg_nr]);
593 else
594 rc += sprintf(out_buf, UNKNOWNSTR, msg_nr);
595 }
596 out:
597 return rc;
598}
599
600struct debug_view debug_test_view = {
601 "myview", /* name of view */
602 NULL, /* no prolog */
603 &debug_dflt_header_fn, /* default header for each entry */
604 &debug_test_format_fn, /* our own format function */
605 NULL, /* no input function */
606 NULL /* no private data */
607};
608
609=====
610test:
611=====
612debug_info_t *debug_info;
613...
614debug_info = debug_register ("test", 0, 4, 4 ));
615debug_register_view(debug_info, &debug_test_view);
616for(i = 0; i < 10; i ++) debug_int_event(debug_info, 1, i);
617
Michael Holzheu66a464d2005-06-25 14:55:33 -0700618> cat /sys/kernel/debug/s390dbf/test/myview
Linus Torvalds1da177e2005-04-16 15:20:36 -070061900 00964419734:611402 1 - 00 88042ca This error...........
62000 00964419734:611405 1 - 00 88042ca That error...........
62100 00964419734:611408 1 - 00 88042ca Problem..............
62200 00964419734:611411 1 - 00 88042ca Something went wrong.
62300 00964419734:611414 1 - 00 88042ca Everything ok........
62400 00964419734:611417 1 - 00 88042ca data: 00000005
62500 00964419734:611419 1 - 00 88042ca data: 00000006
62600 00964419734:611422 1 - 00 88042ca data: 00000007
62700 00964419734:611425 1 - 00 88042ca data: 00000008
62800 00964419734:611428 1 - 00 88042ca data: 00000009