1 /* LOGGER.C (c) Copyright Jan Jaeger, 2003-2009 */
2 /* System logger functions */
3
4 /* If standard output or standard error is redirected then the log */
5 /* is written to the redirection. */
6 /* If standard output and standard error are both redirected then */
7 /* the system log is written to the redirection of standard error */
8 /* the redirection of standard output is ignored in this case, */
9 /* and background mode is assumed. */
10
11 /* Any thread can determine background mode by inspecting stderr */
12 /* for isatty() */
13
14 #include "hstdinc.h"
15
16 #define _LOGGER_C_
17 #define _HUTIL_DLL_
18
19 #include "hercules.h"
20 #include "opcode.h" /* Required for SETMODE macro */
21 static COND logger_cond;
22 static LOCK logger_lock;
23 static TID logger_tid;
24
25 static char *logger_buffer;
26 static int logger_bufsize;
27
28 static int logger_currmsg;
29 static int logger_wrapped;
30
31 static int logger_active=0;
32
33 static FILE *logger_syslog[2]; /* Syslog read/write pipe */
34 int logger_syslogfd[2]; /* pairs */
35 static FILE *logger_hrdcpy; /* Hardcopy log or zero */
36 static int logger_hrdcpyfd; /* Hardcopt fd or -1 */
37
38 /* Find the index for a specific line number in the log, */
39 /* one being the most recent line */
40 /* Example: */
41 /* read the last 5 lines in the syslog: */
42 /* */
43 /* int msgnum; */
44 /* int msgidx; */
45 /* char *msgbuf; */
46 /* */
47 /* msgidx = log_line(5); */
48 /* while((msgcnt = log_read(&msgbuf, &msgidx, LOG_NOBLOCK))) */
49 /* function_to_process_log(msgbuf, msgcnt); */
50 /* */
log_line(int linenumber)51 DLL_EXPORT int log_line(int linenumber)
52 {
53 char *msgbuf[2] = {NULL, NULL}, *tmpbuf = NULL;
54 int msgidx[2] = { -1, -1 };
55 int msgcnt[2] = {0, 0};
56 int i;
57
58 if(!linenumber++)
59 return logger_currmsg;
60
61 /* Find the last two blocks in the log */
62 do {
63 msgidx[0] = msgidx[1];
64 msgbuf[0] = msgbuf[1];
65 msgcnt[0] = msgcnt[1];
66 } while((msgcnt[1] = log_read(&msgbuf[1], &msgidx[1], LOG_NOBLOCK)));
67
68 for(i = 0; i < 2 && linenumber; i++)
69 if(msgidx[i] != -1)
70 {
71 for(; linenumber > 0; linenumber--)
72 {
73 if(!(tmpbuf = (void *)memrchr(msgbuf[i],'\n',msgcnt[i])))
74 break;
75 msgcnt[i] = tmpbuf - msgbuf[i];
76 }
77 if(!linenumber)
78 break;
79 }
80
81 while(i < 2 && tmpbuf && (*tmpbuf == '\r' || *tmpbuf == '\n'))
82 {
83 tmpbuf++;
84 msgcnt[i]++;
85 }
86
87 return i ? msgcnt[i] + msgidx[0] : msgcnt[i];
88 }
89
90
91 /* log_read - read system log */
92 /* parameters: */
93 /* buffer - pointer to bufferpointer */
94 /* the bufferpointer will be returned */
95 /* msgindex - an index used on multiple read requests */
96 /* a value of -1 ensures that reading starts at the */
97 /* oldest entry in the log */
98 /* block - LOG_NOBLOCK - non blocking request */
99 /* LOG_BLOCK - blocking request */
100 /* returns: */
101 /* number of bytes in buffer or zero */
102 /* */
103 /* */
log_read(char ** buffer,int * msgindex,int block)104 DLL_EXPORT int log_read(char **buffer, int *msgindex, int block)
105 {
106 int bytes_returned;
107
108 obtain_lock(&logger_lock);
109
110 if(*msgindex == logger_currmsg && block)
111 {
112 if(logger_active)
113 {
114 wait_condition(&logger_cond, &logger_lock);
115 }
116 else
117 {
118 *msgindex = logger_currmsg;
119 *buffer = logger_buffer + logger_currmsg;
120 release_lock(&logger_lock);
121 return 0;
122 }
123 }
124
125 if(*msgindex != logger_currmsg)
126 {
127 if(*msgindex < 0)
128 *msgindex = logger_wrapped ? logger_currmsg : 0;
129
130 if(*msgindex < 0 || *msgindex >= logger_bufsize)
131 *msgindex = 0;
132
133 *buffer = logger_buffer + *msgindex;
134
135 if(*msgindex >= logger_currmsg)
136 {
137 bytes_returned = logger_bufsize - *msgindex;
138 *msgindex = 0;
139 }
140 else
141 {
142 bytes_returned = logger_currmsg - *msgindex;
143 *msgindex = logger_currmsg;
144 }
145 }
146 else
147 bytes_returned = 0;
148
149 release_lock(&logger_lock);
150
151 return bytes_returned;
152 }
153
154
logger_term(void * arg)155 static void logger_term(void *arg)
156 {
157 UNREFERENCED(arg);
158
159 if(logger_active)
160 {
161 char* term_msg = _("HHCLG014I logger thread terminating\n");
162 size_t term_msg_len = strlen(term_msg);
163
164 obtain_lock(&logger_lock);
165
166 /* Flush all pending logger o/p before redirecting?? */
167 fflush(stdout);
168
169 /* Redirect all output to stderr */
170 dup2(STDERR_FILENO, STDOUT_FILENO);
171
172 /* Tell logger thread we want it to exit */
173 logger_active = 0;
174
175 /* Send the logger a message to wake it up */
176 write_pipe( logger_syslogfd[LOG_WRITE], term_msg, term_msg_len );
177
178 release_lock(&logger_lock);
179
180 /* Wait for the logger to terminate */
181 join_thread( logger_tid, NULL );
182 detach_thread( logger_tid );
183 }
184 }
logger_logfile_write(void * pBuff,size_t nBytes)185 static void logger_logfile_write( void* pBuff, size_t nBytes )
186 {
187 if ( fwrite( pBuff, nBytes, 1, logger_hrdcpy ) != 1 )
188 {
189 fprintf(logger_hrdcpy, _("HHCLG003E Error writing hardcopy log: %s\n"),
190 strerror(errno));
191 }
192 if ( sysblk.shutdown )
193 fflush ( logger_hrdcpy );
194 }
195
196 #ifdef OPTION_TIMESTAMP_LOGFILE
197 /* ZZ FIXME:
198 * This should really be part of logmsg, as the timestamps have currently
199 * the time when the logger reads the message from the log pipe. There can be
200 * quite a delay at times when there is a high system activity. Moving the timestamp
201 * to logmsg() will fix this.
202 * The timestamp option should also NOT depend on anything like daemon mode.
203 * logs entries should always be timestamped, in a fixed format, such that
204 * log readers may decide to skip the timestamp when displaying (ie panel.c).
205 */
logger_logfile_timestamp()206 static void logger_logfile_timestamp()
207 {
208 if (!sysblk.daemon_mode)
209 {
210 struct timeval now;
211 time_t tt;
212 char hhmmss[10];
213
214 gettimeofday( &now, NULL ); tt = now.tv_sec;
215 strlcpy( hhmmss, ctime(&tt)+11, sizeof(hhmmss) );
216 logger_logfile_write( hhmmss, strlen(hhmmss) );
217 }
218 }
219 #endif
220
221
logger_thread(void * arg)222 static void logger_thread(void *arg)
223 {
224 int bytes_read;
225
226 UNREFERENCED(arg);
227
228 /* Set root mode in order to set priority */
229 SETMODE(ROOT);
230
231 /* Set device thread priority; ignore any errors */
232 setpriority(PRIO_PROCESS, 0, sysblk.devprio);
233
234 /* Back to user mode */
235 SETMODE(USER);
236
237 #if !defined( _MSVC_ )
238 /* Redirect stdout to the logger */
239 if(dup2(logger_syslogfd[LOG_WRITE],STDOUT_FILENO) == -1)
240 {
241 if(logger_hrdcpy)
242 fprintf(logger_hrdcpy, _("HHCLG001E Error redirecting stdout: %s\n"), strerror(errno));
243 exit(1);
244 }
245 #endif /* !defined( _MSVC_ ) */
246
247 setvbuf (stdout, NULL, _IONBF, 0);
248
249 /* call logger_term on system shutdown */
250 hdl_adsc("logger_term",logger_term, NULL);
251
252 obtain_lock(&logger_lock);
253
254 logger_active = 1;
255
256 /* Signal initialization complete */
257 signal_condition(&logger_cond);
258
259 release_lock(&logger_lock);
260
261 /* ZZ FIXME: We must empty the read pipe before we terminate */
262 /* (Couldn't we just loop waiting for a 'select(,&readset,,,timeout)'
263 to return zero?? Or use the 'poll' function similarly?? - Fish) */
264
265 while(logger_active)
266 {
267 bytes_read = read_pipe(logger_syslogfd[LOG_READ],logger_buffer + logger_currmsg,
268 ((logger_bufsize - logger_currmsg) > LOG_DEFSIZE ? LOG_DEFSIZE : logger_bufsize - logger_currmsg));
269
270 if(bytes_read == -1)
271 {
272 int read_pipe_errno = HSO_errno;
273
274 // (ignore any/all errors at shutdown)
275 if (sysblk.shutdown) continue;
276
277 if (HSO_EINTR == read_pipe_errno)
278 continue;
279
280 if(logger_hrdcpy)
281 fprintf(logger_hrdcpy, _("HHCLG002E Error reading syslog pipe: %s\n"),
282 strerror(read_pipe_errno));
283 bytes_read = 0;
284 }
285
286 /* If Hercules is not running in daemon mode and panel
287 initialization is not yet complete, write message
288 to stderr so the user can see it on the terminal */
289 if (!sysblk.daemon_mode)
290 {
291 if (!sysblk.panel_init)
292 {
293 /* (ignore any errors; we did the best we could) */
294 fwrite( logger_buffer + logger_currmsg, bytes_read, 1, stderr );
295 }
296 }
297
298 /* Write log data to hardcopy file */
299 if (logger_hrdcpy)
300 #if !defined( OPTION_TIMESTAMP_LOGFILE )
301 {
302 char* pLeft2 = logger_buffer + logger_currmsg;
303 int nLeft2 = bytes_read;
304 #if defined( OPTION_MSGCLR )
305 /* Remove "<pnl,..." color string if it exists */
306 if (1
307 && nLeft2 > 5
308 && strncasecmp( pLeft2, "<pnl", 4 ) == 0
309 && (pLeft2 = memchr( pLeft2+4, '>', nLeft2-4 )) != NULL
310 )
311 {
312 pLeft2++;
313 nLeft2 -= (pLeft2 - (logger_buffer + logger_currmsg));
314 }
315 else
316 {
317 pLeft2 = logger_buffer + logger_currmsg;
318 nLeft2 = bytes_read;
319 }
320 #endif // defined( OPTION_MSGCLR )
321
322 logger_logfile_write( pLeft2, nLeft2 );
323 }
324 #else // defined( OPTION_TIMESTAMP_LOGFILE )
325 {
326 /* Need to prefix each line with a timestamp. */
327
328 static int needstamp = 1;
329 char* pLeft = logger_buffer + logger_currmsg;
330 int nLeft = bytes_read;
331 char* pRight = NULL;
332 int nRight = 0;
333 char* pNL = NULL; /* (pointer to NEWLINE character) */
334
335 if (needstamp)
336 {
337 if (!sysblk.logoptnotime) logger_logfile_timestamp();
338 needstamp = 0;
339 }
340
341 while ( (pNL = memchr( pLeft, '\n', nLeft )) != NULL )
342 {
343 pRight = pNL + 1;
344 nRight = nLeft - (pRight - pLeft);
345 nLeft -= nRight;
346
347 #if defined( OPTION_MSGCLR )
348 /* Remove "<pnl...>" color string if it exists */
349 {
350 char* pLeft2 = pLeft;
351 int nLeft2 = nLeft;
352
353 if (1
354 && nLeft > 5
355 && strncasecmp( pLeft, "<pnl", 4 ) == 0
356 && (pLeft2 = memchr( pLeft+4, '>', nLeft-4 )) != NULL
357 )
358 {
359 pLeft2++;
360 nLeft2 -= (pLeft2 - pLeft);
361 }
362 else
363 {
364 pLeft2 = pLeft;
365 nLeft2 = nLeft;
366 }
367
368 logger_logfile_write( pLeft2, nLeft2 );
369 }
370 #else // !defined( OPTION_MSGCLR )
371
372 logger_logfile_write( pLeft, nLeft );
373
374 #endif // defined( OPTION_MSGCLR )
375
376 pLeft = pRight;
377 nLeft = nRight;
378
379 if (!nLeft)
380 {
381 needstamp = 1;
382 break;
383 }
384
385 if (!sysblk.logoptnotime) logger_logfile_timestamp();
386 }
387
388 if (nLeft)
389 logger_logfile_write( pLeft, nLeft );
390 }
391 #endif // !defined( OPTION_TIMESTAMP_LOGFILE )
392
393 /* Increment buffer index to next available position */
394 logger_currmsg += bytes_read;
395 if(logger_currmsg >= logger_bufsize)
396 {
397 logger_currmsg = 0;
398 logger_wrapped = 1;
399 }
400
401 /* Notify all interested parties new log data is available */
402 obtain_lock(&logger_lock);
403 broadcast_condition(&logger_cond);
404 release_lock(&logger_lock);
405 }
406
407 /* Logger is now terminating */
408 obtain_lock(&logger_lock);
409
410 /* Write final message to hardcopy file */
411 if (logger_hrdcpy)
412 {
413 char* term_msg = _("HHCLG014I logger thread terminating\n");
414 size_t term_msg_len = strlen(term_msg);
415 #ifdef OPTION_TIMESTAMP_LOGFILE
416 if (!sysblk.logoptnotime) logger_logfile_timestamp();
417 #endif
418 logger_logfile_write( term_msg, term_msg_len );
419 }
420
421 /* Redirect all msgs to stderr */
422 logger_syslog[LOG_WRITE] = stderr;
423 logger_syslogfd[LOG_WRITE] = STDERR_FILENO;
424 fflush(stderr);
425
426 /* Signal any waiting tasks */
427 broadcast_condition(&logger_cond);
428
429 release_lock(&logger_lock);
430 }
431
432
logger_init(void)433 DLL_EXPORT void logger_init(void)
434 {
435 initialize_condition (&logger_cond);
436 initialize_lock (&logger_lock);
437
438 obtain_lock(&logger_lock);
439
440 if(fileno(stdin)>=0 ||
441 fileno(stdout)>=0 ||
442 fileno(stderr)>=0)
443 {
444 logger_syslog[LOG_WRITE] = stderr;
445
446 /* If standard error is redirected, then use standard error
447 as the log file. */
448 if(!isatty(STDOUT_FILENO) && !isatty(STDERR_FILENO))
449 {
450 /* Ignore standard output to the extent that it is
451 treated as standard error */
452 logger_hrdcpyfd = dup(STDOUT_FILENO);
453 if(dup2(STDERR_FILENO,STDOUT_FILENO) == -1)
454 {
455 fprintf(stderr, _("HHCLG004E Error duplicating stderr: %s\n"),
456 strerror(errno));
457 exit(1);
458 }
459 }
460 else
461 {
462 if(!isatty(STDOUT_FILENO))
463 {
464 logger_hrdcpyfd = dup(STDOUT_FILENO);
465 if(dup2(STDERR_FILENO,STDOUT_FILENO) == -1)
466 {
467 fprintf(stderr, _("HHCLG004E Error duplicating stderr: %s\n"),
468 strerror(errno));
469 exit(1);
470 }
471 }
472 if(!isatty(STDERR_FILENO))
473 {
474 logger_hrdcpyfd = dup(STDERR_FILENO);
475 if(dup2(STDOUT_FILENO,STDERR_FILENO) == -1)
476 {
477 fprintf(stderr, _("HHCLG005E Error duplicating stdout: %s\n"),
478 strerror(errno));
479 exit(1);
480 }
481 }
482 }
483
484 if(logger_hrdcpyfd == -1)
485 {
486 logger_hrdcpyfd = 0;
487 fprintf(stderr, _("HHCLG006E Duplicate error redirecting hardcopy log: %s\n"),
488 strerror(errno));
489 }
490
491 if(logger_hrdcpyfd)
492 {
493 if(!(logger_hrdcpy = fdopen(logger_hrdcpyfd,"w")))
494 fprintf(stderr, _("HHCLG007S Hardcopy log fdopen failed: %s\n"),
495 strerror(errno));
496 }
497
498 if(logger_hrdcpy)
499 setvbuf(logger_hrdcpy, NULL, _IONBF, 0);
500 }
501 else
502 {
503 logger_syslog[LOG_WRITE]=fopen("LOG","a");
504 }
505
506 logger_bufsize = LOG_DEFSIZE;
507
508 if(!(logger_buffer = malloc(logger_bufsize)))
509 {
510 fprintf(stderr, _("HHCLG008S logbuffer malloc failed: %s\n"),
511 strerror(errno));
512 exit(1);
513 }
514
515 if(create_pipe(logger_syslogfd))
516 {
517 fprintf(stderr, _("HHCLG009S Syslog message pipe creation failed: %s\n"),
518 strerror(errno));
519 exit(1); /* Hercules running without syslog */
520 }
521
522 setvbuf (logger_syslog[LOG_WRITE], NULL, _IONBF, 0);
523
524 if (create_thread (&logger_tid, JOINABLE,
525 logger_thread, NULL, "logger_thread")
526 )
527 {
528 fprintf(stderr, _("HHCLG012E Cannot create logger thread: %s\n"),
529 strerror(errno));
530 exit(1);
531 }
532
533 wait_condition(&logger_cond, &logger_lock);
534
535 release_lock(&logger_lock);
536
537 }
538
539
log_sethrdcpy(char * filename)540 DLL_EXPORT void log_sethrdcpy(char *filename)
541 {
542 FILE *temp_hrdcpy = logger_hrdcpy;
543 FILE *new_hrdcpy;
544 int new_hrdcpyfd;
545
546 if(!filename)
547 {
548 if(!logger_hrdcpy)
549 {
550 logmsg(_("HHCLG014E log not active\n"));
551 return;
552 }
553 else
554 {
555 obtain_lock(&logger_lock);
556 logger_hrdcpy = 0;
557 logger_hrdcpyfd = 0;
558 release_lock(&logger_lock);
559 fprintf(temp_hrdcpy,_("HHCLG015I log closed\n"));
560 fclose(temp_hrdcpy);
561 logmsg(_("HHCLG015I log closed\n"));
562 return;
563 }
564 }
565 else
566 {
567 char pathname[MAX_PATH];
568 hostpath(pathname, filename, sizeof(pathname));
569
570 new_hrdcpyfd = hopen(pathname,
571 O_WRONLY | O_CREAT | O_TRUNC /* O_SYNC */,
572 S_IRUSR | S_IWUSR | S_IRGRP);
573 if(new_hrdcpyfd < 0)
574 {
575 logmsg(_("HHCLG016E Error opening logfile %s: %s\n"),
576 filename,strerror(errno));
577 return;
578 }
579 else
580 {
581 if(!(new_hrdcpy = fdopen(new_hrdcpyfd,"w")))
582 {
583 logmsg(_("HHCLG017S log file fdopen failed for %s: %s\n"),
584 filename, strerror(errno));
585 return;
586 }
587 else
588 {
589 setvbuf(new_hrdcpy, NULL, _IONBF, 0);
590
591 obtain_lock(&logger_lock);
592 logger_hrdcpy = new_hrdcpy;
593 logger_hrdcpyfd = new_hrdcpyfd;
594 release_lock(&logger_lock);
595
596 if(temp_hrdcpy)
597 {
598 fprintf(temp_hrdcpy,_("HHCLG018I log switched to %s\n"),
599 filename);
600 fclose(temp_hrdcpy);
601 }
602 }
603 }
604 }
605 }
606
607 /* log_wakeup - Wakeup any blocked threads. Useful during shutdown. */
log_wakeup(void * arg)608 DLL_EXPORT void log_wakeup(void *arg)
609 {
610 UNREFERENCED(arg);
611
612 obtain_lock(&logger_lock);
613
614 broadcast_condition(&logger_cond);
615
616 release_lock(&logger_lock);
617 }
618