36
37:- module(http_log,
38 [ http_log_stream/1, 39 http_log/2, 40 http_log_close/1, 41 post_data_encoded/2, 42 http_logrotate/1, 43 http_schedule_logrotate/2 44 ]). 45:- use_module(library(http/http_header)). 46:- use_module(library(settings)). 47:- use_module(library(option)). 48:- use_module(library(error)). 49:- use_module(library(debug)). 50:- use_module(library(broadcast)). 51
52:- setting(http:logfile, callable, 'httpd.log',
53 'File in which to log HTTP requests'). 54:- setting(http:log_post_data, integer, 0,
55 'Log POST data up to N bytes long'). 56:- setting(http:on_log_error, any, retry,
57 'Action if logging fails'). 58
71
72:- multifile
73 nolog/1,
74 password_field/1,
75 nolog_post_content_type/1. 76
79
80:- listen(settings(changed(http:logfile, _, New)),
81 http_log_close(changed(New))). 82:- listen(http(Message),
83 http_message(Message)). 84:- listen(logrotate,
85 http_log_close(logrotate)). 86
87http_message(Message) :-
88 log_message(Message),
89 http_log_stream(Stream),
90 catch(http_message(Message, Stream), E,
91 log_error(E)).
92
93log_message(request_start(_Id, _Request)).
94log_message(request_finished(_Id, _Code, _Status, _CPU, _Bytes)).
95
96http_message(request_start(Id, Request), Stream) :-
97 log_started(Request, Id, Stream).
98http_message(request_finished(Id, Code, Status, CPU, Bytes), Stream) :-
99 log_completed(Code, Status, Bytes, Id, CPU, Stream).
100
122
123log_error(E) :-
124 print_message(warning, E),
125 log_error_continue.
126
127log_error_continue :-
128 setting(http:on_log_error, Action),
129 log_error_continue(Action).
130
131log_error_continue(retry) :-
132 http_log_close(error).
133log_error_continue(exit) :-
134 log_error_continue(exit(1)).
135log_error_continue(exit(Code)) :-
136 halt(Code).
137
138
139
140 143
144:- dynamic
145 log_stream/2. 146
161
162http_log_stream(Stream) :-
163 log_stream(Stream, _Opened),
164 !,
165 Stream \== [].
166http_log_stream([]) :-
167 setting(http:logfile, ''),
168 !,
169 get_time(Now),
170 assert(log_stream([], Now)).
171http_log_stream(Stream) :-
172 setting(http:logfile, Term),
173 broadcast(http_log_open(Term)),
174 catch(absolute_file_name(Term, File,
175 [ access(append)
176 ]),
177 E, open_error(E)),
178 with_mutex(http_log, open_log(File, Stream0)),
179 Stream = Stream0.
180
181open_log(_File, Stream) :-
182 log_stream(Stream, Opened),
183 ( Stream == []
184 -> ( get_time(Now),
185 Now - Opened > 60
186 -> retractall(log_stream(_,_)),
187 fail
188 ; !, fail
189 )
190 ; true
191 ), !.
192open_log(File, Stream) :-
193 catch(open(File, append, Stream,
194 [ close_on_abort(false),
195 encoding(utf8),
196 buffer(line)
197 ]), E, open_error(E)),
198 get_time(Time),
199 format(Stream,
200 'server(started, ~0f).~n',
201 [ Time ]),
202 assert(log_stream(Stream, Time)),
203 at_halt(close_log(stopped)).
204
205open_error(E) :-
206 print_message(error, E),
207 log_open_error_continue.
208
209log_open_error_continue :-
210 setting(http:on_log_error, Action),
211 log_open_error_continue(Action).
212
213log_open_error_continue(retry) :-
214 !,
215 get_time(Now),
216 assert(log_stream([], Now)),
217 fail.
218log_open_error_continue(Action) :-
219 log_error_continue(Action).
220
221
236
237http_log_close(Reason) :-
238 with_mutex(http_log, close_log(Reason)).
239
240close_log(Reason) :-
241 retract(log_stream(Stream, _Opened)),
242 !,
243 ( is_stream(Stream)
244 -> get_time(Time),
245 catch(( format(Stream, 'server(~q, ~0f).~n', [ Reason, Time ]),
246 close(Stream)
247 ), E, print_message(warning, E))
248 ; true
249 ).
250close_log(_).
251
257
258http_log(Format, Args) :-
259 ( http_log_stream(Stream)
260 -> system:format(Stream, Format, Args) 261 ; true
262 ).
263
264
270
271log_started(Request, Id, Stream) :-
272 is_stream(Stream),
273 !,
274 get_time(Now),
275 add_post_data(Request, Request1),
276 log_request(Request1, LogRequest),
277 format_time(string(HDate), '%+', Now),
278 format(Stream,
279 '/*~s*/ request(~q, ~3f, ~q).~n',
280 [HDate, Id, Now, LogRequest]).
281log_started(_, _, _).
282
287
288log_request([], []).
289log_request([search(Search0)|T0], [search(Search)|T]) :-
290 !,
291 mask_passwords(Search0, Search),
292 log_request(T0, T).
293log_request([H|T0], T) :-
294 nolog(H),
295 !,
296 log_request(T0, T).
297log_request([H|T0], [H|T]) :-
298 log_request(T0, T).
299
300mask_passwords([], []).
301mask_passwords([Name=_|T0], [Name=xxx|T]) :-
302 password_field(Name),
303 !,
304 mask_passwords(T0, T).
305mask_passwords([H|T0], [H|T]) :-
306 mask_passwords(T0, T).
307
312
313password_field(password).
314password_field(pwd0).
315password_field(pwd1).
316password_field(pwd2).
317
318
323
324nolog(input(_)).
325nolog(accept(_)).
326nolog(accept_language(_)).
327nolog(accept_encoding(_)).
328nolog(accept_charset(_)).
329nolog(pool(_)).
330nolog(protocol(_)).
331nolog(referer(R)) :-
332 sub_atom(R, _, _, _, password),
333 !.
334
349
356
357add_post_data(Request0, Request) :-
358 setting(http:log_post_data, MaxLen),
359 integer(MaxLen), MaxLen > 0,
360 memberchk(input(In), Request0),
361 memberchk(content_length(CLen), Request0),
362 CLen =< MaxLen,
363 memberchk(content_type(Type), Request0),
364 http_parse_header_value(content_type, Type, media(MType/MSubType, _)),
365 \+ nolog_post_content_type(MType/MSubType),
366 catch(peek_string(In, CLen, PostData), _, fail),
367 !,
368 post_data_encoded(PostData, Encoded),
369 Request = [post_data(Encoded)|Request0].
370add_post_data(Request, Request).
371
378
379post_data_encoded(Bytes, Hex) :-
380 nonvar(Bytes),
381 !,
382 setup_call_cleanup(
383 new_memory_file(HMem),
384 ( setup_call_cleanup(
385 ( open_memory_file(HMem, write, Out, [encoding(octet)]),
386 zopen(Out, ZOut, [])
387 ),
388 format(ZOut, '~s', [Bytes]),
389 close(ZOut)),
390 memory_file_to_codes(HMem, Codes, octet)
391 ),
392 free_memory_file(HMem)),
393 phrase(base64(Codes), EncCodes),
394 string_codes(Hex, EncCodes).
395post_data_encoded(Bytes, Hex) :-
396 string_codes(Hex, EncCodes),
397 phrase(base64(Codes), EncCodes),
398 string_codes(ZBytes, Codes),
399 setup_call_cleanup(
400 open_string(ZBytes, In),
401 zopen(In, Zin, []),
402 read_string(Zin, _, Bytes)).
403
412
413log_completed(Code, Status, Bytes, Id, CPU, Stream) :-
414 is_stream(Stream),
415 log_check_deleted(Stream),
416 !,
417 log(Code, Status, Bytes, Id, CPU, Stream).
418log_completed(Code, Status, Bytes, Id, CPU0, _) :-
419 http_log_stream(Stream), 420 !,
421 log_completed(Code, Status, Bytes, Id, CPU0, Stream).
422log_completed(_,_,_,_,_,_).
423
424
425log(Code, ok, Bytes, Id, CPU, Stream) :-
426 !,
427 format(Stream, 'completed(~q, ~q, ~q, ~q, ok).~n',
428 [ Id, CPU, Bytes, Code ]).
429log(Code, Status, Bytes, Id, CPU, Stream) :-
430 ( map_exception(Status, Term)
431 -> true
432 ; message_to_string(Status, String),
433 Term = error(String)
434 ),
435 format(Stream, 'completed(~q, ~q, ~q, ~q, ~W).~n',
436 [ Id, CPU, Bytes, Code,
437 Term, [ quoted(true),
438 ignore_ops(true),
439 blobs(portray),
440 portray_goal(write_blob)
441 ]
442 ]).
443
444:- public write_blob/2. 445write_blob(Blob, _Options) :-
446 format(string(S), '~q', [Blob]),
447 writeq(blob(S)).
448
449map_exception(http_reply(bytes(ContentType,Bytes),_), bytes(ContentType,L)) :-
450 string_length(Bytes, L). 451map_exception(http_reply(Reply), Reply).
452map_exception(http_reply(Reply, _), Reply).
453map_exception(error(existence_error(http_location, Location), _Stack),
454 error(404, Location)).
455
456
457 460
470
471log_check_deleted(Stream) :-
472 stream_property(Stream, nlink(Links)),
473 Links == 0,
474 !,
475 http_log_close(log_file_deleted),
476 fail.
477log_check_deleted(_).
478
507
508http_logrotate(Options) :-
509 select_option(background(true), Options, Options1),
510 !,
511 thread_create(http_logrotate(Options1), _,
512 [ alias('__logrotate'),
513 detached(true)
514 ]).
515http_logrotate(Options) :-
516 option(keep_logs(Keep), Options, 10),
517 option(compress_logs(Format), Options, gzip),
518 compress_extension(Format, ZExt),
519 log_file_and_ext(Base, Ext),
520 ( log_too_small(Base, Ext, Options)
521 -> true
522 ; rotate_logs(Base, Ext, ZExt, Keep)
523 ).
524
525rotate_logs(Base, Ext, ZExt, N1) :-
526 N1 > 0,
527 !,
528 N0 is N1 - 1,
529 old_log_file(Base, Ext, N0, ZO, Old),
530 ( exists_file(Old)
531 -> new_log_file(Base, Ext, N1, ZO, ZExt, ZN, New),
532 rename_log_file(ZO, Old, ZN, New)
533 ; true
534 ),
535 rotate_logs(Base, Ext, ZExt, N0).
536rotate_logs(_, _, _, _).
537
538rename_log_file(ZExt, Old, ZExt, New) :-
539 !,
540 debug(logrotate, 'Rename ~p --> ~p', [Old, New]),
541 rename_file(Old, New).
542rename_log_file('', Old, ZExt, New) :-
543 file_name_extension(NoExt, ZExt, New),
544 debug(logrotate, 'Rename ~p --> ~p', [Old, NoExt]),
545 rename_file(Old, NoExt),
546 debug(logrotate, 'Closing log file', []),
547 http_log_close(logrotate),
548 compress_extension(Format, ZExt),
549 debug(logrotate, 'Compressing (~w) ~p', [Format, NoExt]),
550 compress_file(NoExt, Format).
551
552old_log_file(Base, Ext, N, ZExt, File) :-
553 log_file(Base, Ext, N, File0),
554 ( compress_extension(_, ZExt),
555 file_name_extension(File0, ZExt, File1),
556 exists_file(File1)
557 -> File = File1
558 ; ZExt = '',
559 File = File0
560 ).
561
562new_log_file(Base, Ext, N, '', '', '', File) :-
563 !,
564 log_file(Base, Ext, N, File).
565new_log_file(Base, Ext, N, '', ZExt, ZExt, File) :-
566 !,
567 log_file(Base, Ext, N, File0),
568 file_name_extension(File0, ZExt, File).
569new_log_file(Base, Ext, N, ZExt, _, ZExt, File) :-
570 log_file(Base, Ext, N, File0),
571 file_name_extension(File0, ZExt, File).
572
573log_file(Base, Ext, 0, File) :-
574 !,
575 file_name_extension(Base, Ext, File).
576log_file(Base, Ext, N, File) :-
577 atomic_list_concat([Base, -, N], Base1),
578 file_name_extension(Base1, Ext, File).
579
580log_file_and_ext(Base, Ext) :-
581 setting(http:logfile, Term),
582 catch(absolute_file_name(Term, File,
583 [ access(exist)
584 ]), _, fail),
585 file_name_extension(Base, Ext, File).
586
587log_too_small(Base, Ext, Options) :-
588 DefMin is 1024*1024,
589 option(min_size(MinBytes), Options, DefMin),
590 file_name_extension(Base, Ext, File),
591 ( exists_file(File)
592 -> size_file(File, Bytes),
593 Bytes < MinBytes,
594 debug(logrotate, '~w has ~D bytes; not rotating', [File, Bytes])
595 ; debug(logrotate, '~w does not exist; not rotating', [File])
596 ).
597
602
603compress_file(File, Format) :-
604 ( compress_extension(Format, Ext)
605 -> true
606 ; domain_error(compress_format, Format)
607 ),
608 file_name_extension(File, Ext, ZFile),
609 catch(setup_call_cleanup(
610 gzopen(ZFile, write, Out, [type(binary)]),
611 setup_call_cleanup(
612 open(File, read, In, [type(binary)]),
613 copy_stream_data(In, Out),
614 close(In)),
615 close(Out)),
616 Error,
617 ( print_message(error, Error),
618 catch(delete_file(Out), _, true),
619 throw(Error)
620 )),
621 delete_file(File).
622
623compress_extension(gzip, gz).
624
625:- dynamic
626 scheduled_logrotate/2. 627
646
647http_schedule_logrotate(When, Options) :-
648 listen(maintenance(_,_), http_consider_logrotate),
649 compile_schedule(When, Schedule),
650 retractall(scheduled_logrotate(_,_)),
651 asserta(scheduled_logrotate(Schedule, Options)).
652
653compile_schedule(Var, _) :-
654 var(Var),
655 !,
656 instantiation_error(Var).
657compile_schedule(daily(Time0), daily(Time)) :-
658 compile_time(Time0, Time).
659compile_schedule(weekly(Day0, Time0), weekly(Day, Time)) :-
660 compile_weekday(Day0, Day),
661 compile_time(Time0, Time).
662compile_schedule(monthly(Day, Time0), monthly(Day, Time)) :-
663 must_be(between(0, 31), Day),
664 compile_time(Time0, Time).
665
666compile_time(HH:MM0, HH:MM) :-
667 must_be(between(0, 23), HH),
668 must_be(between(0, 59), MM0),
669 MM is ((MM0+4)//5)*5.
670
671compile_weekday(N, _) :-
672 var(N),
673 !,
674 instantiation_error(N).
675compile_weekday(N, N) :-
676 integer(N),
677 !,
678 must_be(between(1,7), N).
679compile_weekday(Day, N) :-
680 downcase_atom(Day, Lwr),
681 ( sub_atom(Lwr, 0, 3, _, Abbr),
682 day(N, Abbr)
683 -> !
684 ; domain_error(day, Day)
685 ).
686
690
691http_consider_logrotate :-
692 scheduled_logrotate(Schedule, Options),
693 get_time(NowF),
694 Now is round(NowF/60.0)*60,
695 scheduled(Schedule, Now),
696 !,
697 http_logrotate([background(true)|Options]).
698
699scheduled(daily(HH:MM), Now) :-
700 stamp_date_time(Now, DateTime, local),
701 date_time_value(time, DateTime, time(HH,MM,_)).
702scheduled(weekly(Day, Time), Now) :-
703 stamp_date_time(Now, DateTime, local),
704 date_time_value(date, DateTime, Date),
705 day_of_the_week(Date, Day),
706 scheduled(daily(Time), Now).
707scheduled(monthly(Day, Time), Now) :-
708 stamp_date_time(Now, DateTime, local),
709 date_time_value(day, DateTime, Day),
710 scheduled(daily(Time), Now).
711
712day(1, mon).
713day(2, tue).
714day(3, wed).
715day(4, thu).
716day(5, fri).
717day(6, sat).
718day(7, sun)