1 /* aklog.c - Application Black (K) Box Logging Library
2 *
3 * Copyright (c) 2006,2012 Sampo Kellomaki (sampo@iki.fi), All Rights Reserved.
4 * This is unpublished proprietary source code. All dissemination
5 * prohibited. Contains trade secrets. NO WARRANTY. See file COPYING.
6 * Special grant: aktab.h may be used with zxid open source project under
7 * same licensing terms as zxid itself.
8 *
9 * Application Black (K) Box provides a lock-less logging facility
10 * using a circular memory buffer per thread. These buffers will
11 * hold recent history of application and will be part of any core
12 * dump that may happen, facilitating interpretation of such core. */
13
14 #include "errmac.h"
15 #include "akbox.h"
16
17 #include <string.h>
18 #include <stdarg.h>
19 #include <stdio.h>
stencil_add_ellipse(int cx,int cy,int sa,int ea,int xradius,int yradius,unsigned char * stencil)20 #include <stdlib.h>
21 #include <sys/time.h>
22 #include <sys/types.h>
23 #include <sys/stat.h>
24 #ifndef MINGW
25 #include <sys/utsname.h>
26 #endif
27 #include <fcntl.h>
28 #include <unistd.h>
29
30 #ifdef LINUX
31 #include <sys/sysinfo.h>
32 #endif
33 #ifdef SUNOS
34 #include <sys/systeminfo.h>
35 #endif
36 #ifdef AIXOS
37 #include <sys/systemcfg.h>
38 #include <nlist.h>
39 #endif
40
41 AKEXPORT pthread_key_t akmem_pool_key;
42
43 /* AFR master block is statically intialized so its always available. */
44 struct ak_master_rec ak_master =
45 { AK_MASTER_STAMP, 0, AK_LOGKEY_MARK, AK_ENDIAN_MARK, __DATE__, __TIME__, PTHREAD_MUTEX_INITIALIZER, 0, 0, 0, 0 };
46
47 /* pthread specific data key for locating the logging buffer */
48 pthread_key_t ak_buf_key;
49
50 /* Called by: main, zxbusd_main */
51 void ak_init(char* argv0) {
52 char buf[8192];
53 int x,n=0;
54 fdtype f;
55 #ifdef MINGW
56 pthread_mutex_init(&ak_master.ak_mutex, 0);
57 #endif
58 #ifdef LINUX
59 mallopt(M_MMAP_MAX, 0); /* Disable use of mmap(2) in malloc(3) as mmaps do not appear in core. */
60 #endif
61
62 ak_master.first_sec = time(0); /** Not used in linux, maybe in a future ...*/
63 /** Adding Machine INFO **/
64 #ifndef INTERIXOS
65 #ifndef MINGW
66 struct utsname os_info;
67 int res;
68 #ifdef LINUX
69 struct sysinfo system_info;
70 char mem[100];
71 int copied_before = 0;
72 FILE * file;
73 /** Getting proc info from /proc/cpuinfo **/
74 if ((file = fopen("/proc/cpuinfo","rt")) != NULL ) { /** /proc/cpuinfo found **/
75 while (!feof(file)){
76 fgets(mem,100,file);
77 if (!strncmp(mem,"processor",9))
78 ak_master.ProcNum++;
79 if (!copied_before && !strncmp(mem,"model name",10)){
80 int j = 10;
81 copied_before = 1; /** Only one copy needed **/
82 while ((mem[j] != ':') && (j<100)) j++;
83 j+=2; /** jump over ':' and next space **/
84 strncpy(ak_master.ModelName, &mem[j], MIN(strlen(&mem[j])+1, INFO_BUF));
85 ak_master.ModelName[INFO_BUF]='\0';
86 }
87 }
88 fclose(file);
89 }
90
91 res = sysinfo(&system_info);
92 ak_master.MaxMem = system_info.totalram;
93 ak_master.MaxSwap = system_info.totalswap;
94 ak_master.MemUnit = system_info.mem_unit;
95 #endif
96 #ifdef SUNOS /** SOLARIS **/
97 long resp;
98 resp = sysinfo (SI_ARCHITECTURE, ak_master.ModelName, INFO_BUF);
99 ak_master.ProcNum = sysconf(_SC_NPROCESSORS_ONLN);
100 ak_master.first_tick = gethrtime();
101 #endif
102 #ifdef AIXOS
103 struct nlist info;
104 int fd;
105 info.n_name = "_system_configuration";
106 fd = open("/dev/kmem",O_RDONLY);
107 knlist(&info,1,sizeof(struct nlist));
108 lseek(fd,info.n_value,0);
109 read(fd,&_system_configuration,sizeof(_system_configuration));
110 ak_master.ProcNum = _system_configuration.ncpus;
111 ak_master.MaxMem = _system_configuration.physmem;
112 ak_master.ProcImp = _system_configuration.implementation;
113 ak_master.ProcArch = _system_configuration.architecture;
114 ak_master.ProcVer = _system_configuration.version;
115 ak_master.Width = _system_configuration.width;
116 close(fd);
117 #endif /* AIXOS */
118 ak_master.HostId = gethostid();
119 res = uname(&os_info);
120 if (!res){ /** Success **/
121 strncpy(ak_master.nodename, os_info.nodename, MIN(strlen(os_info.nodename)+1 ,INFO_BUF));
122 strncpy(ak_master.sysname, os_info.sysname, MIN(strlen(os_info.sysname)+1 ,INFO_BUF));
123 strncpy(ak_master.os_release, os_info.release, MIN(strlen(os_info.release)+1 ,INFO_BUF));
124 strncpy(ak_master.os_version, os_info.version, MIN(strlen(os_info.version)+1 ,INFO_BUF));
125 strncpy(ak_master.machine, os_info.machine, MIN(strlen(os_info.machine)+1 ,INFO_BUF));
126 }
127 #endif /* MINGW */
128 #endif /* INTERIXOS */
129
130 /** Machine info for windows **/
131 #ifdef MINGW
132 SYSTEM_INFO system_info;
133 DWORD dwVersion = 0;
134 DWORD dwMajorVersion = 0;
135 DWORD dwMinorVersion = 0;
136 DWORD dwBuild = 0;
137 LPDWORD siz = INFO_BUF;
138
139 QueryPerformanceFrequency(&ak_master.ticksPerSecond);
140 QueryPerformanceCounter(&ak_master.first_tick);
141
142 GetSystemInfo(&system_info);
143 ak_master.ProcNum = system_info.dwNumberOfProcessors;
144 ak_master.ProcArch = system_info.wProcessorArchitecture;
145 ak_master.ProcType = system_info.dwProcessorType;
146 ak_master.ProcLevel = system_info.wProcessorLevel;
147 ak_master.ProcRev = system_info.wProcessorRevision;
148
149 dwVersion = GetVersion();
150 /** Get os version **/
151 dwMajorVersion = (DWORD)(LOBYTE(LOWORD(dwVersion)));
152 dwMinorVersion = (DWORD)(HIBYTE(LOWORD(dwVersion)));
153 if (dwVersion < 0x80000000)
154 dwBuild = (DWORD)(HIWORD(dwVersion));
155 sprintf(ak_master.os_version, "%d.%d (%d)", dwMajorVersion, dwMinorVersion, dwBuild);
156 GetComputerName( &ak_master.sysname, &siz);
157
158 #endif
159
160 /** End of machine info **/
161
162 pthread_key_create(&ak_buf_key, 0 /* no destructor */ );
163 ak_master.self = &ak_master; /* helps to compute (or double check) offset */
164 /*fprintf(stderr, "logkey(%s)\n", STRNULLCHK(ak_master.lkmark));*/
165
166 #ifndef INTERIXOS
167 #ifndef MINGW
168 /* Copy the executable file into heap memory so it will be included in an eventual
169 * core that may be generated. */
170 realpath(argv0, ak_master.realpath);
171 ak_master.realpath[sizeof(ak_master.realpath)-1] = 0;
172 f = open(argv0, O_RDONLY);
173 if (f < 0) goto bad;
174 x = fstat(f, &ak_master.binary_st);
175 if (x < 0) goto bad;
176 ak_master.binary = malloc(ak_master.binary_st.st_size);
177 if (!ak_master.binary) goto bad;
178 while (n < ak_master.binary_st.st_size) {
179 x = read(f, ak_master.binary + n, sizeof(buf));
180 if (x <= 0) goto badio;
181 n += x;
182 }
183 closefile(f);
184 #endif
185 #endif
186 #ifdef MINGW
187 DWORD pathlength;
188 char argv0exe[strlen(argv0) + 4 + 1];
189 if (strstr(argv0, ".exe") == 0) {
190 /* the extension was not passed; not 100% certain... */
191 strcpy(argv0exe, argv0);
192 strcpy(argv0exe + strlen(argv0), ".exe");
193 argv0exe[strlen(argv0) + 5] = '\0';
194 } else {
195 strcpy(argv0exe, argv0);
196 }
197 if ((pathlength = GetFullPathName(argv0exe, sizeof(ak_master.realpath), ak_master.realpath, 0)) == 0) {
198 errno = GetLastError();
199 goto bad;
200 }
201 ak_master.realpath[pathlength] = 0;
202 f = openfile_ro(argv0exe);
203 if (f == BADFD) goto bad;
204 // need to change this to GetFileSizeEx()
205 DWORD filesize;
206 if ((filesize = GetFileSize(f, 0)) == INVALID_FILE_SIZE) {
207 errno = GetLastError();
208 goto bad;
209 }
210 ak_master.binary_st.st_size = filesize;
211 ak_master.binary = malloc(ak_master.binary_st.st_size);
212 if (!ak_master.binary) goto bad;
213 DWORD got;
214 int howMuchToRead = 0;
215 while (n < ak_master.binary_st.st_size) {
216 howMuchToRead = (sizeof(buf) > ak_master.binary_st.st_size - n) ? (ak_master.binary_st.st_size - n) : sizeof(buf);
217 x = ReadFile(f, ak_master.binary + n, howMuchToRead, &got, 0);
218 if (x == 0) {
219 errno = GetLastError();
220 goto badio;
221 }
222 n += got;
223 }
224 closefile(f);
225 #endif /* MINGW */
226 #ifdef AFRDBG
227 fprintf(stderr,"Recorded executable: %s (%d).\n", argv0, (int)ak_master.binary_st.st_size);
228 #endif
229 return;
230 badio:
231 closefile(f);
232 fprintf(stderr,"Read error on executable: %s (%x/%x/%x). This installation is not supported.\n",
233 argv0, x, n, (int)ak_master.binary_st.st_size);
234 return;
235 bad:
236 fprintf(stderr,"Failed to read executable: %s. This installation is not supported.\n", argv0);
237 }
238
239 /* Creates AFR buffer explicitly. You may want to call this directly if you need
240 * a special buffer other than thread buffer. */
241
242 /* Called by: ak_add_thread */
243 struct ak_buf* ak_add_buf(int afr_buffer_size, int flags, char* comment)
244 {
245 struct ak_buf* buf = 0;
246
247 pthread_mutex_lock(&ak_master.ak_mutex);
248 if (ak_master.n_threads >= AK_MAX_BUFS) goto out;
249
250 buf = malloc(sizeof(struct ak_buf)+afr_buffer_size);
251 if (!buf) goto out;
252 if (flags == 2){
253 ak_master.st_buf = buf;
254 sprintf(buf->stamp, AK_ST_BUFFER_STAMP);
255 buf->mem_pool = 0;
256 }else{
257 ak_master.bufs[ak_master.n_threads] = buf;
258 sprintf(buf->stamp, AK_BUFFER_STAMP, ++ak_master.n_threads);
259 buf->mem_pool = (unsigned int)pthread_getspecific(akmem_pool_key);
260 }
261 buf->p = buf->start;
262 buf->lim = (struct ak_ts*)(((char*)(buf->start)) + afr_buffer_size);
263 buf->flags = flags;
264 buf->wrap_around = 0;
265 if (comment)
266 strncpy(buf->comment, comment, AK_COMMENT_SIZE);
267 else
268 buf->comment[0] = 0;
269
270 out:
271 pthread_mutex_unlock(&ak_master.ak_mutex);
272 return buf;
273 }
274
275 /* ak_add_thread() should be called from each thread that wishes to
276 * use AFR facilities. It allocates and registers the buffer and records
277 * a pointer to it as thread specific data. If this thread specific data is not
278 * found, then AFR logging functions do nothing, but are still safe to call.
279 * The prefix forms an important part of the buffer comment. The first letter
280 * of buffer comment is used as thread role prefix in displays. E.g:
281 * T=regular worket thread, W=witer thread, F=fe polling thead, f=fe consumer thread,
282 * B=backend poller thread, b=backedn consumer thread, S=shuffler, s=static, etc. */
283
284 /* Called by: main, opt, thread_loop */
285 void ak_add_thread(int afr_buffer_size, char* prefix, int flags)
286 {
287 struct ak_buf* buf;
288 buf = ak_add_buf(afr_buffer_size, flags, 0);
289 if (!buf) return;
290 buf->tid = pthread_self();
291 pthread_setspecific(ak_buf_key, buf);
292 sprintf(buf->comment, "%s%d", prefix, buf->tid);
293 }
294
295 /* Allocate a new AFR line from the circular buffer */
296
297 /* Called by: ak_buf_err_va, ak_buf_ini, ak_buf_io, ak_buf_mem, ak_buf_pdu, ak_buf_pdu_arg, ak_buf_pdu_lite, ak_buf_report, ak_buf_run, ak_buf_trace, ak_buf_ts, ak_buf_tsa */
298 struct ak_ts* ak_new_line(struct ak_buf* buf, int func, int line, char* logkey)
299 {
300 struct ak_ts* p;
301 if (!buf) return 0;
302 p = buf->p;
303 ++buf->p;
304 if (buf->p > buf->lim) { /* did it fit? */
305 p = buf->p = buf->start; /* wrap around */
306 ++buf->p;
307 ++buf->wrap_around;
308 }
309 p->h.func = func;
310 p->h.line = line;
311 p->h.logkey = logkey;
312 #ifdef MINGW
313 QueryPerformanceCounter(&p->h.tv);
314 #endif
315 #ifdef SUNOS
316 p->h.tv = gethrtime();
317 #endif
318 #if (!defined(SUNOS)&&!defined(MINGW))
319 gettimeofday(&p->h.tv, 0);
320 #endif
321 #ifdef AFRDBG
322 fprintf(stderr, "AFR %x:%x k(%x)\t", func, line, logkey);
323 #endif
324 return p;
325 }
326
327 /* -------------- R e p o r t i n g f u n c t i o n s -------------- */
328
329 /* Report an error. If error involved PDU or ses, they will be separately reported. */
330
331 /* Called by: ak_buf_errf, ak_err_va */
332 void ak_buf_err_va(struct ak_buf* buf, int func, int line, int sev, int act, int err_code, int arg, char* format, va_list pv)
333 {
334 struct ak_err* p = (struct ak_err*)ak_new_line(buf, func, line, (char*)arg);
335 if (!p) return;
336 p->raz = AK_ERR_RAZ;
337 p->severity = sev;
338 p->action = act;
339 p->error_code = err_code;
340 vsnprintf(p->msg, sizeof(p->msg), format, pv);
341 #ifdef AFRDBG
342 fprintf(stderr, "ERR(%x,%x)=%d `%s'\n", sev, act, err_code, p->msg);
343 #endif
344 }
345
346 /* Called by: ak_errf */
347 void ak_err_va(int func, int line, int sev, int act, int err_code, int arg, char* format, va_list pv)
348 {
349 ak_buf_err_va((struct ak_buf*)pthread_getspecific(ak_buf_key), func, line, sev, act, err_code, arg, format, pv);
350 }
351
352 /* Called by: */
353 void ak_buf_errf(struct ak_buf* buf, int func, int line, int sev, int act, int err_code, int arg, char* format, ...)
354 {
355 va_list pv;
356 va_start(pv, format);
357 ak_buf_err_va(buf, func, line, sev, act, err_code, arg, format, pv);
358 va_end(pv);
359 }
360
361 /* Called by: */
362 void ak_errf(int func, int line, int sev, int act, int err_code, int arg, char* format, ...)
363 {
364 va_list pv;
365 va_start(pv, format);
366 ak_err_va(func, line, sev, act, err_code, arg, format, pv);
367 va_end(pv);
368 }
369
370 /** Included info **/
371
372 /* Called by: ak_ini */
373 void ak_buf_ini(struct ak_buf* buf, uint32 size, char* md5v, int func, int line, int raz, char* logkey, char* msg)
374 {
375 struct ak_ini* p;
376 p = (struct ak_ini*)ak_new_line(buf, func, line, logkey);
377 if (!p) return;
378 strncpy((char *)p->md5val, md5v, sizeof(p->md5val));
379 p->size = size;
380 p->raz = raz;
381 if (msg){
382 int len = strlen(msg);
383 int siz;
384 len = len - sizeof(p->msg)+1;
385 if (len<0) len = 0;
386 siz = MIN(sizeof(p->msg)-1, strlen(&msg[len]));
387 strncpy(p->msg, &msg[len], siz);
388 p->msg[siz] = '\0';
389 }else
390 p->msg[0] = 0;
391 #ifdef AFRDBG
392 fprintf(stderr, "INC(%x) `%s'\n", raz, msg);
393 #endif
394 }
395
396 /* Called by: */
397 void ak_ini(struct ak_buf* buf, uint32 size, char* md5v, int func, int line, int raz, char* logkey, char* message)
398 {
399 ak_buf_ini(buf, size, md5v, func, line, raz, logkey, message);
400 }
401
402 /* Simple message with timestamp. */
403
404 /* Called by: ak_buf_tsf, ak_ts_va */
405 void ak_buf_ts_va(struct ak_buf* buf, int func, int line, int raz, char* logkey, char* format, va_list pv)
406 {
407 char b[64];
408 vsnprintf(b, sizeof(b), format, pv);
409 ak_buf_ts(buf, func, line, raz, logkey, b);
410 }
411
412 /* Called by: ak_tsf */
413 void ak_ts_va(int func, int line, int raz, char* logkey, char* format, va_list pv)
414 {
415 ak_buf_ts_va((struct ak_buf*)pthread_getspecific(ak_buf_key), func, line, raz, logkey, format, pv);
416 }
417
418 /* Called by: */
419 void ak_buf_tsf(struct ak_buf* buf, int func, int line, int raz, char* logkey, char* format, ...)
420 {
421 va_list pv;
422 va_start(pv, format);
423 ak_buf_ts_va(buf, func, line, raz, logkey, format, pv);
424 va_end(pv);
425 }
426
427 /* Called by: */
428 void ak_tsf(int func, int line, int raz, char* logkey, char* format, ...)
429 {
430 va_list pv;
431 va_start(pv, format);
432 ak_ts_va(func, line, raz, logkey, format, pv);
433 va_end(pv);
434 }
435
436 /* Called by: ak_buf_ts_va, ak_ts */
437 void ak_buf_ts(struct ak_buf* buf, int func, int line, int raz, char* logkey, char* msg)
438 {
439 struct ak_ts* p;
440 p = ak_new_line(buf, func, line, logkey);
441 /*printf("buf=%p raz=%x func=%x line=%d %s [%s]\n", buf, raz, func, line, msg, STRNULLCHK(logkey));*/
442 if (!p) return;
443 p->raz = raz;
444 if (msg)
445 strncpy(p->msg, msg, sizeof(p->msg));
446 else
447 p->msg[0] = 0;
448 #ifdef AFRDBG
449 fprintf(stderr, "TS(%x) `%s'\n", raz, msg); // this outputs too much...
450 #endif
451 }
452
453 /* Called by: */
454 void ak_ts(int func, int line, int raz, char* logkey, char* msg) {
455 ak_buf_ts((struct ak_buf*)pthread_getspecific(ak_buf_key), func, line, raz, logkey, msg);
456 }
457
458 /* Called by: ak_tsa */
459 void ak_buf_tsa(struct ak_buf* buf, int func, int line, int raz, char* logkey, char* msg, void* arg)
460 {
461 struct ak_tsa* p;
462 p = (struct ak_tsa*)ak_new_line(buf, func, line, logkey);
463 /*printf("buf=%p raz=%x func=%x line=%d %s [%s]\n", buf, raz, func, line, msg, STRNULLCHK(logkey));*/
464 if (!p) return;
465 p->raz = raz;
466 if (msg)
467 strncpy(p->msg, msg, sizeof(p->msg));
468 else
469 p->msg[0] = 0;
470 p->arg = arg;
471 #ifdef AFRDBG
472 fprintf(stderr, "TS(%x) `%s'\n", raz, msg); // this outputs too much...
473 #endif
474 }
475
476 /* Called by: */
477 void ak_tsa(int func, int line, int raz, char* logkey, char* msg, void* arg) {
478 ak_buf_tsa((struct ak_buf*)pthread_getspecific(ak_buf_key), func, line, raz, logkey, msg, arg);
479 }
480
481 /* Analysis of FE */
482
483 /* Called by: ak_buf_io_full, ak_buf_io_va, ak_io */
484 void ak_buf_io(struct ak_buf* buf, int func, int line, int raz, char* logkey, struct io* io, char* msg)
485 {
486 struct ak_io* p = (struct ak_io*)ak_new_line(buf, func, line, logkey);
487 if (!p) return;
488 p->raz = raz;
489 if (msg)
490 strncpy(p->msg, msg, sizeof(p->msg));
491 else
492 p->msg[0] = 0;
493 p->io = io;
494 if (!io) return;
495 p->role = io->role;
496 p->proto = io->proto;
497 p->fd = io->fd;
498 p->flags = io->ioflags;
499 switch (io->role) {
500 case IO_ROLE_FE: /* 0 */
501 p->req_head = (((struct io_fe*)io)->req_head.pdunext != ANY_PDU(&((struct io_fe*)io)->req_tail)) ? ((struct io_fe*)io)->req_head.pdunext : 0;
502 p->req_tail = (((struct io_fe*)io)->req_tail.pduprev != ANY_PDU(&((struct io_fe*)io)->req_head)) ? ((struct io_fe*)io)->req_tail.pduprev : 0;
503 break;
504 case IO_ROLE_BE: /* 1 */
505 case IO_ROLE_LISTENER: /* 2 */
506 case IO_ROLE_UDP_LISTENER: /* 3 */
507 case IO_ROLE_SUPERVISOR: /* 4 */
508 case IO_ROLE_HOPELESS: /* 5 */
509 default:
510 p->req_head = 0;
511 p->req_tail = 0;
512 }
513 #ifdef AFRDBG
514 fprintf(stderr, "IO(%x) io(%x.%p) `%s'\n", raz, io->fd, io, msg);
515 #endif
516 }
517
518 /* Called by: */
519 void ak_io(int func, int line, int raz, char* logkey, struct io* io, char* msg) {
520 ak_buf_io((struct ak_buf*)pthread_getspecific(ak_buf_key), func, line, raz, logkey, io, msg);
521 }
522
523 /* Called by: ak_buf_iof, ak_io_va */
524 void ak_buf_io_va(struct ak_buf* buf, int func, int line, int raz, char* logkey, struct io* io, char* format, va_list pv)
525 {
526 char b[64];
527 vsnprintf(b, sizeof(b), format, pv);
528 ak_buf_io(buf, func, line, raz, logkey, io, b);
529 }
530
531 /* Called by: ak_iof */
532 void ak_io_va(int func, int line, int raz, char* logkey, struct io* io, char* msg, va_list pv)
533 {
534 ak_buf_io_va((struct ak_buf*)pthread_getspecific(ak_buf_key), func, line, raz, logkey, io, msg,pv);
535 }
536
537 /* Called by: */
538 void ak_buf_iof(struct ak_buf* buf, int func, int line, int raz, char* logkey, struct io* io, char* format, ...)
539 {
540 va_list pv;
541 va_start(pv, format);
542 ak_buf_io_va(buf, func, line, raz, logkey, io, format, pv);
543 va_end(pv);
544 }
545
546 /* Called by: */
547 void ak_iof(int func, int line, int raz, char* logkey, struct io* io, char* format, ...)
548 {
549 va_list pv;
550 va_start(pv, format);
551 ak_io_va(func, line, raz, logkey, io, format, pv);
552 va_end(pv);
553 }
554
555 /* Called by: ak_io_full */
556 void ak_buf_io_full(struct ak_buf* buf, int func, int line, int raz, char* logkey, struct io* io, char* msg)
557 {
558 ak_buf_io(buf, func, line, raz, logkey, io, msg);
559 if (!io) return;
560 if (!io->role) {
561 if (((struct io_fe*)io)->req_head.pdunext != ANY_PDU(&((struct io_fe*)io)->req_tail))
562 ak_buf_pdu(buf, func, line, AK_REQ_HEAD_RAZ, logkey, ((struct io_fe*)io)->req_head.pdunext, "rqhd");
563 if (((struct io_fe*)io)->req_tail.pduprev != ANY_PDU(&((struct io_fe*)io)->req_head))
564 ak_buf_pdu(buf, func, line, AK_REQ_TAIL_RAZ, logkey, ((struct io_fe*)io)->req_tail.pduprev, "rqtl");
565 }
566 }
567
568 /* Called by: */
569 void ak_io_full(int func, int line, int raz, char* logkey, struct io* io, char* msg) {
570 ak_buf_io_full((struct ak_buf*)pthread_getspecific(ak_buf_key), func, line, raz, logkey, io, msg);
571 }
572
573 /* Lite analysis of PDU */
574
575 /* Called by: ak_buf_pdu_litef, ak_pdu_lite_va */
576 void ak_buf_pdu_lite_va(struct ak_buf* buf, int func, int line, int raz, char* logkey, struct any_pdu* pdu, char* format, va_list pv)
577 {
578 char b[64];
579 vsnprintf(b, sizeof(b), format, pv);
580 ak_buf_pdu_lite(buf, func, line, raz, logkey, pdu, b);
581 }
582
583 /* Called by: ak_pdu_litef */
584 void ak_pdu_lite_va(int func, int line, int raz, char* logkey, struct any_pdu* pdu, char* msg, va_list pv)
585 {
586 ak_buf_pdu_lite_va((struct ak_buf*)pthread_getspecific(ak_buf_key), func, line, raz, logkey, pdu, msg,pv);
587 }
588
589 /* Called by: */
590 void ak_buf_pdu_litef(struct ak_buf* buf, int func, int line, int raz, char* logkey, struct any_pdu* pdu, char* format, ...)
591 {
592 va_list pv;
593 va_start(pv, format);
594 ak_buf_pdu_lite_va(buf, func, line, raz, logkey, pdu, format, pv);
595 va_end(pv);
596 }
597
598 /* Called by: */
599 void ak_pdu_litef(int func, int line, int raz, char* logkey, struct any_pdu* pdu, char* format, ...)
600 {
601 va_list pv;
602 va_start(pv, format);
603 ak_pdu_lite_va(func, line, raz, logkey, pdu, format, pv);
604 va_end(pv);
605 }
606
607 /* dSpRAiii
608 * d = dirty
609 * S = synth_done
610 * p = parent set (i.e. PDU is a sub)
611 * R = req set (i.e. PDU is a response)
612 * A = all seen set on request
613 * i = 3 bits of inthread - 16 info (zero means not in thread) */
614 #define DIGEST_PDU_FLAGS(p) \
615 (((p)->inthread == 0 ? 0 : \
616 ((p)->inthread < PRIO_LAST_PRIO ? 1 : ((p)->inthread - 16) & 0x7 )) \
617 | ((p)->noise.s<=SYNTH_PDU?0x80:0) /* dirty flag */ \
618 | ((p)->synth_done?0x40:0) /* has synthesized a done flag */ \
619 | ((p)->parent?0x20:0) /* has parent flag */ \
620 | ((p)->req || (p)->all_seen == DETACHED_RESP_MARK ? 0x10 : ((p)->all_seen ? 0x08 : 0 )))
621
622 /* Called by: ak_buf_pdu_lite_va, ak_pdu_lite */
623 void ak_buf_pdu_lite(struct ak_buf* buf, int func, int line, int raz, char* logkey, struct any_pdu* pdu, char* msg)
624 {
625 struct ak_pdu_lite* p = (struct ak_pdu_lite*)ak_new_line(buf, func, line, logkey);
626 if (!p) return;
627 p->ph.raz = raz;
628 if (msg)
629 strncpy(p->msg, msg, sizeof(p->msg));
630 else
631 p->msg[0] = 0;
632 p->ph.pdu = pdu;
633 if (!pdu) return;
634 p->ph.pdu_op = pdu->op;
635 p->ph.pdu_flags = DIGEST_PDU_FLAGS(pdu);
636 p->ph.pdu_mid = pdu->req ? ((struct ldap_pdu*)pdu)->new_mid : ((struct ldap_pdu*)pdu)->mid;
637 #ifdef AFRDBG
638 fprintf(stderr, "PDU_LITE(%x) pdu(%x:%p) `%s'\n", raz, pdu->op, pdu, msg);
639 #endif
640 }
641
642 /* Called by: */
643 void ak_pdu_lite(int func, int line, int raz, char* logkey, struct any_pdu* pdu, char* msg)
644 {
645 ak_buf_pdu_lite((struct ak_buf*)pthread_getspecific(ak_buf_key), func, line, raz, logkey, pdu, msg);
646 }
647
648 /* Analysis of PDU */
649
650 /* Called by: ak_buf_io_full x2, ak_pdu */
651 void ak_buf_pdu(struct ak_buf* buf, int func, int line, int raz, char* logkey, struct any_pdu* pdu, char* msg)
652 {
653 struct ak_pdu* p = (struct ak_pdu*)ak_new_line(buf, func, line, logkey);
654 if (!p) return;
655 p->ph.raz = raz;
656 if (msg)
657 strncpy(p->msg, msg, sizeof(p->msg));
658 else
659 p->msg[0] = 0;
660 p->ph.pdu = pdu;
661 if (!pdu) return;
662 memcpy(&p->pdunext, pdu, sizeof(void*)*8);
663 p->ph.pdu_op = pdu->op;
664 p->ph.pdu_flags = DIGEST_PDU_FLAGS(pdu);
665 p->ph.pdu_mid = pdu->req ? ((struct ldap_pdu*)pdu)->new_mid : ((struct ldap_pdu*)pdu)->mid;
666 #ifdef AFRDBG
667 fprintf(stderr, "PDU(%x) pdu(%x:%p) `%s'\n", raz, pdu->op, pdu, msg);
668 #endif
669 }
670
671 /* Called by: */
672 void ak_pdu(int func, int line, int raz, char* logkey, struct any_pdu* pdu, char* msg) {
673 ak_buf_pdu((struct ak_buf*)pthread_getspecific(ak_buf_key), func, line, raz, logkey, pdu, msg);
674 }
675
676 /* PDU with an argument instead of a message. */
677
678 /* Called by: ak_pdu_arg */
679 void ak_buf_pdu_arg(struct ak_buf* buf, int func, int line, int raz, char* logkey, struct any_pdu* pdu, int arg)
680 {
681 struct ak_pdu_arg* p = (struct ak_pdu_arg*)ak_new_line(buf, func, line, logkey);
682 if (!p) return;
683 p->ph.raz = raz;
684 p->arg = arg;
685 p->ph.pdu = pdu;
686 if (!pdu) return;
687 memcpy(&p->pdunext, pdu, sizeof(void*)*8);
688 p->ph.pdu_op = pdu->op;
689 p->ph.pdu_flags = DIGEST_PDU_FLAGS(pdu);
690 p->ph.pdu_mid = pdu->req ? ((struct ldap_pdu*)pdu)->new_mid : ((struct ldap_pdu*)pdu)->mid;
691 #ifdef AFRDBG
692 fprintf(stderr, "PDU(%x) pdu(%x:%p) arg(%x)\n", raz, pdu->op, pdu, arg);
693 #endif
694 }
695
696 /* Called by: */
697 void ak_pdu_arg(int func, int line, int raz, char* logkey, struct any_pdu* pdu, int arg) {
698 ak_buf_pdu_arg((struct ak_buf*)pthread_getspecific(ak_buf_key), func, line, raz, logkey, pdu, arg);
699 }
700
701 /* run that may have a PDU */
702
703 /* Called by: ak_run */
704 void ak_buf_run(struct ak_buf* buf, int func, int line, int raz, char* logkey, struct zx_run* run, char* msg)
705 {
706 struct ak_run* p = (struct ak_run*)ak_new_line(buf, func, line, logkey);
707 if (!p) return;
708 p->ph.raz = raz;
709 if (msg)
710 strncpy(p->msg, msg, sizeof(p->msg));
711 else
712 p->msg[0] = 0;
713 p->run = run;
714 if (!run) return;
715 p->ph.pdu = run->pdu;
716 if (!run->pdu) return;
717 p->ph.pdu_op = ANY_PDU(run->pdu)->op;
718 p->ph.pdu_flags = DIGEST_PDU_FLAGS(ANY_PDU(run->pdu));
719 p->ph.pdu_mid = ANY_PDU(run->pdu)->req
720 ? ((struct ldap_pdu*)(run->pdu))->new_mid
721 : ((struct ldap_pdu*)(run->pdu))->mid;
722 #ifdef AFRDBG
723 fprintf(stderr, "RUN(%x) run(%p) pdu(%x:%p) `%s'\n", raz, run, ANY_PDU(run->pdu)->op, run->pdu, msg);
724 #endif
725 }
726
727 /* Called by: */
728 void ak_run(int func, int line, int raz, char* logkey, struct zx_run* run, char* msg)
729 {
730 ak_buf_run((struct ak_buf*)pthread_getspecific(ak_buf_key), func, line, raz, logkey, run, msg);
731 }
732
733 /* low level memory allocator reporting */
734
735 /* Called by: ak_mem */
736 void
737 ak_buf_mem(struct ak_buf* buf, int func, int line, int raz, char* logkey, void* pool, void* mem, int len, char* msg)
738 {
739 struct ak_mem* p = (struct ak_mem*)ak_new_line(buf, func, line, logkey);
740 if (!p) return;
741 p->raz = raz;
742 if (msg)
743 strncpy(p->msg, msg, sizeof(p->msg));
744 else
745 p->msg[0] = 0;
746 p->pool = pool;
747 p->pool_blocks = pool?((struct mem_pool*)pool)->block_counter:0;
748 p->mem = mem;
749 p->len = len;
750 #ifdef AFRDBG
751 fprintf(stderr, "MEM(%x) `%s'\n", raz, msg);
752 #endif
753 }
754
755 /* Called by: */
756 void
757 ak_mem(int func, int line, int raz, char* logkey, void* pool, void* mem, int len, char* msg)
758 {
759 ak_buf_mem((struct ak_buf*)pthread_getspecific(ak_buf_key), func, line, raz, logkey, pool, mem, len, msg);
760 }
761
762 /* Reporting memory leak counters. */
763
764 /* Called by: ak_report */
765 void ak_buf_report(struct ak_buf* buf, int func, int line, int raz, char* logkey, struct mem_pool* pool, char* msg)
766 {
767 struct ak_report* p = (struct ak_report*)ak_new_line(buf, func, line, logkey);
768 if (!p) return;
769 p->raz = raz;
770 if (msg)
771 strncpy(p->msg, msg, sizeof(p->msg));
772 else
773 p->msg[0] = 0;
774 p->block_size = pool->block_size;
775 memcpy(&p->malloc_cnt, &pool->malloc_cnt, 6*sizeof(int));
776 #ifdef AFRDBG
777 fprintf(stderr, "REPORT(%x) `%s'\n", raz, msg);
778 #endif
779 }
780
781 /* Called by: */
782 void ak_report(int func, int line, int raz, char* logkey, struct mem_pool* pool, char* msg)
783 {
784 ak_buf_report((struct ak_buf*)pthread_getspecific(ak_buf_key), func, line, raz, logkey, pool, msg);
785 }
786
787 /* DirectoryScript Virtual Machine Tracing */
788
789 #define AK_STR_TAIL_LEN 5 /* TUNE: How much of end of string to print if whole string does not fit. */
790
791 /* Called by: ak_buf_trace x8 */
792 static void ak_cpy_to_msg(char* msg, int max_len, unsigned char* s, int len)
793 {
794 if (len > max_len) { /* Too long. Print start and end. */
795 memcpy(msg, s, max_len - AK_STR_TAIL_LEN - 1);
796 msg[max_len - AK_STR_TAIL_LEN - 1] = '.'; /* Continuation indicator. */
797 memcpy(msg + max_len - AK_STR_TAIL_LEN,
798 s + len - AK_STR_TAIL_LEN, AK_STR_TAIL_LEN);
799 } else {
800 memcpy(msg, s, len);
801 if (len < max_len)
802 msg[len] = 0;
803 }
804 }
805
806 /* Called by: ak_trace */
807 void ak_buf_trace(struct ak_buf* buf, int raz, struct zx_run* run,
808 struct binid* id, struct val* SP, long* PC, long sum, int tag,
809 long R0, int T0, long R1, int T1, long R2, int T2, long R3, int T3)
810 {
811 int len = 0, len2 = 0, file = 0, line = 0;
812 struct ginfo* gi;
813 struct ak_disasm* p;
814 U8 *s = NULL, *s2 = NULL;
815
816 gi = run->st->prog->gi;
817 if (gi && (*PC != MCOB)) { /* figure out script file and line, if available */
818 gi = gi + (PC - run->st->prog->code);
819 file = gi->file;
820 line = gi->line;
821 }
822
823 p = (struct ak_disasm*)ak_new_line(buf, file, line, (char*)PC);
824 if (!p) return;
825 p->raz = raz;
826
827 p->recurse = run->currecurse;
828 p->cur_func = id;
829 p->SP = SP;
830 p->reg_B = sum;
831 p->tag_B = tag;
832
833 switch (raz) {
834 case AK_TRACE_RAZ:
835 if (PC) {
836 switch (*PC & AMASK) {
837 case REG_0: p->tag_A = T0; p->reg_A = R0; break;
838 case REG_1: p->tag_A = T1; p->reg_A = R1; break;
839 case REG_2: p->tag_A = T2; p->reg_A = R2; break;
840 case REG_3: p->tag_A = T3; p->reg_A = R3; break;
841 }
842 }
843 break;
844 case AK_TRACE_CALL_RAZ: p->tag_A = T0; p->reg_A = R0; break;
845 }
846
847 /* Try to squeeze as much useful string data as possible into the message buffer. */
848
849 if (ONE_OF_2(tag, VAL_STR, VAL_LSTR) && sum) {
850 switch (tag) {
851 case VAL_STR: len = S_LEN(sum); s = S_S(sum); break;
852 case VAL_LSTR: len = LSTR_LEN(sum); s = LSTR_S(sum); break;
853 }
854
855 if (ONE_OF_2(p->tag_A, VAL_STR, VAL_LSTR) && p->reg_A) {
856 /* Both */
857 switch (p->tag_A) {
858 case VAL_STR: len2 = DSS_LEN(p->reg_A); s2 = S_S(p->reg_A); break;
859 case VAL_LSTR: len2 = LSTR_LEN(p->reg_A); s2 = LSTR_S(p->reg_A); break;
860 }
861
862 if (len + len2 + 1 > (int)sizeof(p->msg)) {
863 if (len < (int)sizeof(p->msg)/2) {
864 ak_cpy_to_msg(p->msg, sizeof(p->msg) - len - 1, s2, len2);
865 p->msg[sizeof(p->msg) - len - 1] = '.';
866 ak_cpy_to_msg(p->msg + sizeof(p->msg) - len, len, s, len);
867 } else if (len2 < (int)sizeof(p->msg)/2) {
868 ak_cpy_to_msg(p->msg, len2, s2, len2);
869 p->msg[len2] = '.';
870 ak_cpy_to_msg(p->msg + len2 + 1, sizeof(p->msg) - len2 - 1, s, len);
871 } else {
872 ak_cpy_to_msg(p->msg, sizeof(p->msg)/2, s2, len2);
873 p->msg[sizeof(p->msg)/2] = '.';
874 ak_cpy_to_msg(p->msg + sizeof(p->msg)/2 + 1, sizeof(p->msg) - sizeof(p->msg)/2 - 1,
875 s, len);
876 }
877 } else { /* Both fit */
878 memcpy(p->msg, s2, len2);
879 p->msg[len2] = '.';
880 memcpy(p->msg+len2+1, s, len);
881 if (len + len2 + 1 < (int)sizeof(p->msg))
882 p->msg[len + len2 + 1] = 0;
883 }
884
885 } else { /* B only */
886 ak_cpy_to_msg(p->msg, sizeof(p->msg), s, len);
887 }
888
889 } else if (ONE_OF_2(p->tag_A, VAL_STR, VAL_LSTR) && p->reg_A) { /* A only */
890 switch (p->tag_A) {
891 case VAL_STR: len = S_LEN(p->reg_A); s = S_S(p->reg_A); break;
892 case VAL_LSTR: len = LSTR_LEN(p->reg_A); s = LSTR_S(p->reg_A); break;
893 }
894 ak_cpy_to_msg(p->msg, sizeof(p->msg), s, len);
895 } else {
896 /* Neither was a string */
897 p->msg[0] = 0;
898 }
899 #ifdef AFRDBG
900 fprintf(stderr, "TRACE(%x)\n", raz);
901 #endif
902 }
903
904 /* Called by: */
905 void ak_trace(int raz, struct run* run,
906 struct binid* id, struct val* SP, long* PC, long sum, int tag,
907 long R0, int T0, long R1, int T1, long R2, int T2, long R3, int T3) {
908 ak_buf_trace((struct ak_buf*)pthread_getspecific(ak_buf_key),
909 raz, run, id, SP, PC, sum, tag, R0,T0, R1,T1, R2,T2, R3,T3);
910 }
911
912 /* ------------------------------------------------------------------ */
913
914 #include "errmac.h"
915
916 #ifdef AK_TEST
917 /* gcc -g -Wall -fmessage-length=0 -Wno-unused-label -Wno-unknown-pragmas -fno-strict-aliasing -DAK_TEST -D_REENTRANT -o aktest aklog.c -lpthread */
918
919 #define PRINT_SIZE(x) printf("%5d bytes sizeof(" #x ")\n", sizeof(x))
920
921 char* vals[65536];
922 int adhoc = 1;
923
924 /* Called by: */
925 int main(int argc, char** argv)
926 {
927 struct ds_run run;
928 struct dsio io;
929 struct any_pdu pdu;
930 int x, coll = 0, n_func = 0;
931 x = ("abc"[2]);
932 printf("x=%d\n", x);
933 printf("main=%x (self)\n", AK_FUNCNO(__FUNCTION__));
934 printf("main=%x\n", AK_FUNCNO("main"));
935 printf("main=%d\n", AK_FUNCNO("main"));
936 printf("moin=%d\n", AK_FUNCNO("moin"));
937 printf("mainn=%d\n", AK_FUNCNO("mainn"));
938
939 #define FUNC_DEF(f,file) x = AK_FUNCNO(f); printf("0x%04x %5d: %s\t\t\t\t%s\n", x, x, f, vals[x]?vals[x]:""); ++n_func; if (vals[x]) ++coll; vals[x] = f;
940
941 #include "../function.list"
942
943 printf("%d/%d function number collisions\n", coll, n_func);
944
945 PRINT_SIZE(struct ak_header);
946 PRINT_SIZE(struct ak_pdu_header);
947 PRINT_SIZE(struct ak_ts);
948 PRINT_SIZE(struct ak_err);
949 PRINT_SIZE(struct ak_pdu_lite);
950 PRINT_SIZE(struct ak_pdu);
951 PRINT_SIZE(struct ak_pdu_arg);
952 PRINT_SIZE(struct ak_io);
953 PRINT_SIZE(struct ak_buf);
954 PRINT_SIZE(struct ak_master_rec);
955
956 D("foo %d",1);
957 DD("bar",2);
958 D("foo again %d",3);
959 NEVER("never %d",4);
960
961 memset(&io, 0, sizeof(io));
962 memset(&run, 0, sizeof(run));
963 memset(&pdu, 0, sizeof(pdu));
964
965 ak_init(*argv);
966 ak_add_thread(4096,1);
967 AK_TS(TS, 0,0);
968 AK_TS(TS, "logkey0",0);
969 AK_TS(TS, "logkey1","test string here");
970
971 AK_IO(FE, "logkey2", &io, "test2");
972 AK_IOF(FE, "logkey3", &io, "test3 string %d here", 3);
973 AK_IO(FE, "logkey4", 0, "test4 string here");
974 AK_IOF(FE, "logkey5", 0, "test5 string %d here", 4);
975
976 AK_PDU_LITE(PDU_LITE, "logkey6", &pdu, "test6 string here");
977 AK_PDU_LITEF(PDU_LITE, "logkey7", &pdu, "test7 string %d here", 7);
978 AK_PDU_LITE(PDU_LITE, "logkey8", 0, "test8 string here");
979
980 AK_PDU(PDU, "logkey09", &pdu, "test09 string here");
981 /*AK_PDU_FULL(PDU, "logkey10", &pdu, "test10 string here");*/
982 AK_PDU(PDU, "logkey11", 0, "test11 string here");
983 /*AK_PDU_FULL(PDU, "logkey12", 0, "test12 string here");*/
984
985 AK_TSF(TS, "logkey13", "test12 string %d here", 13);
986
987 AK_PDU_ARG(PDU, "func14_name", &pdu, 14);
988 AK_PDU_ARG(PDU, "func15_name", 0, 15);
989 AK_RUN(RUN_LOCK, "logkey16", &run, "test16 string here");
990
991 #if 0
992 if (!argc) return 0;
993 if (!strcmp(argv[0], "-f")) {
994 --argc; ++argv;
995 while (argc) {
996 x = AK_FUNCNO(*argv);
997 printf("%d: %s %s\n", x, *argv, vals[x]?vals[x]:"-");
998 fflush(stdout);
999 vals[x] = *argv;
1000 --argc; ++argv;
1001 }
1002 }
1003 #endif
1004
1005 if (argc>1 && !strcmp(argv[1], "-t")) {
1006 printf("staying alive so you can attach, e.g. ./ak -p %d\n", getpid());
1007 x = 1;
1008 while (1) {
1009 AK_TSF(TS, "looping", "iter %d", x);
1010 printf(".");
1011 sleep(1);
1012 ++x;
1013 }
1014 }
1015
1016 printf("provoking seg fault so you can analyze the core\n");
1017 fflush(stdout);
1018
1019 NEVERNEVER("never never %d",4);
1020
1021 *((int*)0xffffffff) = 1;
1022 return 0;
1023 }
1024
1025 #endif
1026
1027 /* EOF - aklog.c */
1028