1 // SoftEther VPN Source Code - Developer Edition Master Branch
2 // Cedar Communication Module
3
4
5 // Logging.c
6 // Log storaging module
7
8 #include "Logging.h"
9
10 #include "Admin.h"
11 #include "Client.h"
12 #include "Nat.h"
13 #include "Proto_EtherIP.h"
14 #include "Proto_IKE.h"
15 #include "Proto_PPP.h"
16 #include "Remote.h"
17 #include "SecureNAT.h"
18 #include "Server.h"
19
20 #include "Mayaqua/DNS.h"
21 #include "Mayaqua/Internat.h"
22 #include "Mayaqua/FileIO.h"
23 #include "Mayaqua/Memory.h"
24 #include "Mayaqua/Microsoft.h"
25 #include "Mayaqua/Object.h"
26 #include "Mayaqua/Tick64.h"
27 #include "Mayaqua/Str.h"
28 #include "Mayaqua/Table.h"
29 #include "Mayaqua/Unix.h"
30 #include "Mayaqua/Win32.h"
31
32 static char *delete_targets[] =
33 {
34 "backup.vpn_bridge.config",
35 "backup.vpn_client.config",
36 "backup.vpn_server.config",
37 "backup.vpn_gate_svc.config",
38 "backup.etherlogger.config",
39 HUB_PACKET_LOG_DIR,
40 EL_PACKET_LOG_DIR,
41 "secure_nat_log",
42 HUB_SECURITY_LOG_DIR,
43 SERVER_LOG_DIR,
44 "bridge_log",
45 "packet_log_archive",
46 "azure_log",
47 };
48
49 static UINT eraser_check_interval = DISK_FREE_CHECK_INTERVAL_DEFAULT;
50 static UINT64 logger_max_log_size = MAX_LOG_SIZE_DEFAULT;
51
52 static bool LogThreadWriteGeneral(LOG *log_object, BUF *buffer, IO **io, bool *log_date_changed, char *current_logfile_datename, char *current_file_name);
53 static bool LogThreadWriteStdout(LOG *log_object, BUF *buffer, IO *io);
54 static IO *GetIO4Stdout();
55
56 // Send with syslog
SendSysLog(SLOG * g,wchar_t * str)57 void SendSysLog(SLOG *g, wchar_t *str)
58 {
59 UCHAR *buf;
60 UINT buf_size;
61 // Validate arguments
62 if (g == NULL || str == NULL)
63 {
64 return;
65 }
66
67 buf_size = CalcUniToUtf8(str);
68 buf = ZeroMalloc(buf_size);
69 UniToUtf8(buf, buf_size, str);
70
71 if (buf_size >= 1024)
72 {
73 buf_size = 1023;
74 }
75
76 Lock(g->lock);
77 {
78 if (Tick64() >= g->NextPollIp)
79 {
80 IP ip;
81
82 if (GetIP(&ip, g->HostName))
83 {
84 g->NextPollIp = Tick64() + SYSLOG_POLL_IP_INTERVAL;
85 Copy(&g->DestIp, &ip, sizeof(IP));
86 }
87 else
88 {
89 g->NextPollIp = Tick64() + SYSLOG_POLL_IP_INTERVAL_NG;
90 }
91 }
92
93 if (g->DestPort != 0 && IsZeroIp(&g->DestIp) == false)
94 {
95 SendTo(g->Udp, &g->DestIp, g->DestPort, buf, buf_size);
96 }
97 }
98 Unlock(g->lock);
99
100 Free(buf);
101 }
102
103 // Release the syslog client
FreeSysLog(SLOG * g)104 void FreeSysLog(SLOG *g)
105 {
106 // Validate arguments
107 if (g == NULL)
108 {
109 return;
110 }
111
112 DeleteLock(g->lock);
113 ReleaseSock(g->Udp);
114 Free(g);
115 }
116
117 // Configure the syslog client
SetSysLog(SLOG * g,char * hostname,UINT port)118 void SetSysLog(SLOG *g, char *hostname, UINT port)
119 {
120 IP ip;
121 // Validate arguments
122 if (g == NULL)
123 {
124 return;
125 }
126 if (port == 0)
127 {
128 port = SYSLOG_PORT;
129 }
130
131 if (hostname == NULL)
132 {
133 hostname = "";
134 }
135
136 Zero(&ip, sizeof(IP));
137 GetIP(&ip, hostname);
138
139 Lock(g->lock);
140 {
141 Copy(&g->DestIp, &ip, sizeof(IP));
142 g->DestPort = port;
143 StrCpy(g->HostName, sizeof(g->HostName), hostname);
144 g->NextPollIp = Tick64() + IsZeroIp(&ip) ? SYSLOG_POLL_IP_INTERVAL_NG : SYSLOG_POLL_IP_INTERVAL;
145 }
146 Unlock(g->lock);
147 }
148
149 // Create a syslog client
NewSysLog(char * hostname,UINT port,IP * ip)150 SLOG *NewSysLog(char *hostname, UINT port, IP *ip)
151 {
152 // Validate arguments
153 SLOG *g = ZeroMalloc(sizeof(SLOG));
154
155 g->lock = NewLock();
156 g->Udp = NewUDPEx2(0, false, ip);
157
158 SetSysLog(g, hostname, port);
159
160 return g;
161 }
162
163 // Check if there is enough free space on the disk
CheckEraserDiskFreeSpace(ERASER * e)164 bool CheckEraserDiskFreeSpace(ERASER *e)
165 {
166 UINT64 s;
167 // Validate arguments
168 if (e == NULL)
169 {
170 return true;
171 }
172
173 // Get the free disk space
174 if (GetDiskFree(e->DirName, &s, NULL, NULL) == false)
175 {
176 // Acquisition failure
177 return true;
178 }
179
180 if (e->MinFreeSpace > s)
181 {
182 // The free space is smaller than specified bytes
183 return false;
184 }
185
186 // Vacant enough
187 return true;
188 }
189
190 // Release the deleting file list
FreeEraseFileList(LIST * o)191 void FreeEraseFileList(LIST *o)
192 {
193 UINT i;
194 // Validate arguments
195 if (o == NULL)
196 {
197 return;
198 }
199
200 for (i = 0; i < LIST_NUM(o); i++)
201 {
202 ERASE_FILE *f = LIST_DATA(o, i);
203 Free(f->FullPath);
204 Free(f);
205 }
206
207 ReleaseList(o);
208 }
209
210 // Generate a deleting file list of the specified directory
EnumEraseFile(LIST * o,char * dirname)211 void EnumEraseFile(LIST *o, char *dirname)
212 {
213 DIRLIST *dir;
214 UINT i;
215 char tmp[MAX_PATH];
216 // Validate arguments
217 if (o == NULL || dirname == NULL)
218 {
219 return;
220 }
221
222 // Enumeration
223 dir = EnumDir(dirname);
224
225 for (i = 0; i < dir->NumFiles; i++)
226 {
227 DIRENT *e = dir->File[i];
228 Format(tmp, sizeof(tmp), "%s/%s", dirname, e->FileName);
229 NormalizePath(tmp, sizeof(tmp), tmp);
230
231 if (e->Folder == false)
232 {
233 // File
234 ERASE_FILE *f;
235
236 if (EndWith(tmp, ".log") || EndWith(tmp, ".config") || EndWith(tmp, ".old"))
237 {
238 // Target only .config files and .log files
239 f = ZeroMalloc(sizeof(ERASE_FILE));
240 f->FullPath = CopyStr(tmp);
241 f->UpdateTime = e->UpdateDate;
242
243 Add(o, f);
244 }
245 }
246 else
247 {
248 // Folder
249 EnumEraseFile(o, tmp);
250 }
251 }
252
253 FreeDir(dir);
254 }
255
256 // Generate a deleting file list
GenerateEraseFileList(ERASER * e)257 LIST *GenerateEraseFileList(ERASER *e)
258 {
259 LIST *o;
260 UINT i;
261 // Validate arguments
262 if (e == NULL)
263 {
264 return NULL;
265 }
266
267 o = NewListFast(CompareEraseFile);
268
269 // Scan for each directory
270 for (i = 0; i < sizeof(delete_targets) / sizeof(delete_targets[0]); i++)
271 {
272 char dirname[MAX_PATH];
273 Format(dirname, sizeof(dirname), "%s/%s", e->DirName, delete_targets[i]);
274
275 EnumEraseFile(o, dirname);
276 }
277
278 // Sort
279 Sort(o);
280
281 return o;
282 }
283
284 // Process of erasing unnecessary files
EraserMain(ERASER * e)285 void EraserMain(ERASER *e)
286 {
287 LIST *o;
288 UINT i;
289 bool ok = false;
290 char bs[64];
291 // Validate arguments
292 if (e == NULL)
293 {
294 return;
295 }
296
297 // Check the free space first
298 if (CheckEraserDiskFreeSpace(e))
299 {
300 // Vacant enough
301 return;
302 }
303
304 ToStrByte(bs, sizeof(bs), e->MinFreeSpace);
305
306 // Generate the file list
307 o = GenerateEraseFileList(e);
308
309 // Try to delete one by one in order from oldest file
310 for (i = 0; i < LIST_NUM(o); i++)
311 {
312 ERASE_FILE *f = LIST_DATA(o, i);
313
314 // Delete the file
315 if (FileDelete(f->FullPath))
316 {
317 ELog(e, "LE_DELETE", bs, f->FullPath);
318 }
319
320 // Check the free space after the deleted
321 if (CheckEraserDiskFreeSpace(e))
322 {
323 // Free space has been restored
324 ok = true;
325 break;
326 }
327 }
328
329 // Release the file list
330 FreeEraseFileList(o);
331
332 if (e->LastFailed == false && ok == false)
333 {
334 // Free space is not enough, but can not delete the file any more
335 ELog(e, "LE_NOT_ENOUGH_FREE", bs);
336 }
337
338 e->LastFailed = ok ? false : true;
339 }
340
341 // Comparison of the deleting file entries
CompareEraseFile(void * p1,void * p2)342 int CompareEraseFile(void *p1, void *p2)
343 {
344 ERASE_FILE *f1, *f2;
345 if (p1 == NULL || p2 == NULL)
346 {
347 return 0;
348 }
349 f1 = *(ERASE_FILE **)p1;
350 f2 = *(ERASE_FILE **)p2;
351 if (f1 == NULL || f2 == NULL)
352 {
353 return 0;
354 }
355 if (f1->UpdateTime > f2->UpdateTime)
356 {
357 return 1;
358 }
359 else if (f1->UpdateTime == f2->UpdateTime)
360 {
361 return 0;
362 }
363 else
364 {
365 return -1;
366 }
367 }
368
369 // Eraser thread
EraserThread(THREAD * t,void * p)370 void EraserThread(THREAD *t, void *p)
371 {
372 ERASER *e = (ERASER *)p;
373 char bs[64];
374 // Validate arguments
375 if (t == NULL || e == NULL)
376 {
377 return;
378 }
379
380 // Start monitoring
381 ToStrByte(bs, sizeof(bs), e->MinFreeSpace);
382 ELog(e, "LE_START", e->DirName, bs);
383
384 while (e->Halt == false)
385 {
386 // Check the amount of free space on the disk periodically
387 EraserMain(e);
388
389 Wait(e->HaltEvent, GetEraserCheckInterval());
390 }
391 }
392
393 // Set the interval for disk free space check
SetEraserCheckInterval(UINT interval)394 void SetEraserCheckInterval(UINT interval)
395 {
396 if (interval == 0)
397 {
398 eraser_check_interval = DISK_FREE_CHECK_INTERVAL_DEFAULT;
399 }
400 else
401 {
402 eraser_check_interval = interval * 1000;
403 }
404 }
405
406 // Get the interval for disk free space check
GetEraserCheckInterval()407 UINT GetEraserCheckInterval()
408 {
409 UINT ret = eraser_check_interval / 1000;
410
411 if (ret == 0)
412 {
413 ret = 1;
414 }
415
416 return ret;
417 }
418
419 // Create a new eraser
NewEraser(LOG * log,UINT64 min_size)420 ERASER *NewEraser(LOG *log, UINT64 min_size)
421 {
422 ERASER *e;
423 char dir[MAX_PATH];
424
425 if (min_size == 0)
426 {
427 if (OS_IS_WINDOWS(GetOsInfo()->OsType))
428 {
429 min_size = DISK_FREE_SPACE_DEFAULT_WINDOWS;
430 }
431 else
432 {
433 min_size = DISK_FREE_SPACE_DEFAULT;
434 }
435 }
436
437 if (min_size < DISK_FREE_SPACE_MIN)
438 {
439 min_size = DISK_FREE_SPACE_MIN;
440 }
441
442 e = ZeroMalloc(sizeof(ERASER));
443
444 GetLogDir(dir, sizeof(dir));
445
446 e->Log = log;
447 e->MinFreeSpace = min_size;
448 e->DirName = CopyStr(dir);
449 e->HaltEvent = NewEvent();
450
451 e->Thread = NewThread(EraserThread, e);
452
453 return e;
454 }
455
456 // Release the eraser
FreeEraser(ERASER * e)457 void FreeEraser(ERASER *e)
458 {
459 // Validate arguments
460 if (e == NULL)
461 {
462 return;
463 }
464
465 e->Halt = true;
466 Set(e->HaltEvent);
467 WaitThread(e->Thread, INFINITE);
468 ReleaseThread(e->Thread);
469 ReleaseEvent(e->HaltEvent);
470
471 Free(e->DirName);
472 Free(e);
473 }
474
475 // Take the debug log (variable-length argument)
DebugLog(CEDAR * c,char * fmt,...)476 void DebugLog(CEDAR *c, char *fmt, ...)
477 {
478 char buf[MAX_SIZE * 2];
479 va_list args;
480 // Validate arguments
481 if (fmt == NULL)
482 {
483 return;
484 }
485 if (c->DebugLog == NULL)
486 {
487 return;
488 }
489
490 va_start(args, fmt);
491 FormatArgs(buf, sizeof(buf), fmt, args);
492
493 InsertStringRecord(c->DebugLog, buf);
494 va_end(args);
495 }
496
497 // Take the log of eraser
ELog(ERASER * e,char * name,...)498 void ELog(ERASER *e, char *name, ...)
499 {
500 wchar_t buf[MAX_SIZE * 2];
501 va_list args;
502 // Validate arguments
503 if (name == NULL)
504 {
505 return;
506 }
507
508 va_start(args, name);
509 UniFormatArgs(buf, sizeof(buf), _UU(name), args);
510
511 InsertUnicodeRecord(e->Log, buf);
512
513 if (IsDebug())
514 {
515 UniPrint(L"LOG: %s\n", buf);
516 }
517 va_end(args);
518 }
519
SLog(CEDAR * c,char * name,...)520 void SLog(CEDAR *c, char *name, ...)
521 {
522 wchar_t buf[MAX_SIZE * 2];
523 va_list args;
524 // Validate arguments
525 if (name == NULL)
526 {
527 return;
528 }
529
530 va_start(args, name);
531 UniFormatArgs(buf, sizeof(buf), _UU(name), args);
532
533 WriteServerLog(c, buf);
534 va_end(args);
535 }
536
537 // Client log
CLog(CLIENT * c,char * name,...)538 void CLog(CLIENT *c, char *name, ...)
539 {
540 wchar_t buf[MAX_SIZE * 2];
541 va_list args;
542 // Validate arguments
543 if (name == NULL)
544 {
545 return;
546 }
547
548 if (c == NULL || c->NoSaveLog)
549 {
550 return;
551 }
552
553 va_start(args, name);
554 UniFormatArgs(buf, sizeof(buf), _UU(name), args);
555
556 WriteClientLog(c, buf);
557 va_end(args);
558 }
559
ALog(ADMIN * a,HUB * h,char * name,...)560 void ALog(ADMIN *a, HUB *h, char *name, ...)
561 {
562 wchar_t buf[MAX_SIZE * 2];
563 wchar_t tmp[MAX_SIZE * 2];
564 va_list args;
565 RPC *r;
566 // Validate arguments
567 if (a == NULL || name == NULL)
568 {
569 return;
570 }
571
572 r = a->Rpc;
573
574 va_start(args, name);
575 UniFormatArgs(buf, sizeof(buf), _UU(name), args);
576
577 if (h == NULL)
578 {
579 UniFormat(tmp, sizeof(tmp), _UU("LA_TAG_1"), r->Name);
580 }
581 else
582 {
583 UniFormat(tmp, sizeof(tmp), _UU("LA_TAG_2"), r->Name, h->Name);
584 }
585
586 UniStrCat(tmp, sizeof(tmp), buf);
587
588 if (h == NULL)
589 {
590 WriteServerLog(((ADMIN *)r->Param)->Server->Cedar, tmp);
591 }
592 else
593 {
594 WriteHubLog(h, tmp);
595 }
596 va_end(args);
597 }
HLog(HUB * h,char * name,...)598 void HLog(HUB *h, char *name, ...)
599 {
600 wchar_t buf[MAX_SIZE * 2];
601 va_list args;
602 // Validate arguments
603 if (name == NULL)
604 {
605 return;
606 }
607
608 va_start(args, name);
609 UniFormatArgs(buf, sizeof(buf), _UU(name), args);
610
611 WriteHubLog(h, buf);
612 va_end(args);
613 }
NLog(VH * v,char * name,...)614 void NLog(VH *v, char *name, ...)
615 {
616 wchar_t buf[MAX_SIZE * 2];
617 static wchar_t snat_prefix[] = L"SecureNAT: ";
618 va_list args;
619 // Validate arguments
620 if (name == NULL || v == NULL || v->nat == NULL || v->nat->SecureNAT == NULL || v->SaveLog == false)
621 {
622 return;
623 }
624
625 va_start(args, name);
626 Copy(buf, snat_prefix, sizeof(snat_prefix));
627 UniFormatArgs(&buf[11], sizeof(buf) - 12 * sizeof(wchar_t), _UU(name), args);
628
629 WriteHubLog(v->nat->SecureNAT->Hub, buf);
630 va_end(args);
631 }
632
633 // Writing EtherIP log
EtherIPLog(ETHERIP_SERVER * s,char * name,...)634 void EtherIPLog(ETHERIP_SERVER *s, char *name, ...)
635 {
636 wchar_t prefix[MAX_SIZE * 2];
637 wchar_t buf2[MAX_SIZE * 2];
638 char server_ip[64];
639 char client_ip[64];
640 va_list args;
641 // Validate arguments
642 if (s == NULL)
643 {
644 return;
645 }
646
647 IPToStr(server_ip, sizeof(server_ip), &s->ServerIP);
648 IPToStr(client_ip, sizeof(client_ip), &s->ClientIP);
649
650 UniFormat(prefix, sizeof(prefix), _UU("LE_PREFIX"), s->Id,
651 server_ip, s->ServerPort, client_ip, s->ClientPort);
652
653 va_start(args, name);
654 UniFormatArgs(buf2, sizeof(buf2), _UU(name), args);
655 va_end(args);
656
657 UniStrCat(prefix, sizeof(prefix), buf2);
658
659 WriteServerLog(s->Cedar, prefix);
660 }
661
662 // Write an IPsec log
IPsecLog(IKE_SERVER * ike,IKE_CLIENT * c,IKE_SA * ike_sa,IPSECSA * ipsec_sa,char * name,...)663 void IPsecLog(IKE_SERVER *ike, IKE_CLIENT *c, IKE_SA *ike_sa, IPSECSA *ipsec_sa, char *name, ...)
664 {
665 wchar_t prefix[MAX_SIZE * 2];
666 wchar_t buf2[MAX_SIZE * 2];
667 char server_ip[64];
668 char client_ip[64];
669 va_list args;
670 // Validate arguments
671 if (ike == NULL)
672 {
673 return;
674 }
675 if (ipsec_sa != NULL)
676 {
677 c = ipsec_sa->IkeClient;
678 }
679 else if (ike_sa != NULL)
680 {
681 c = ike_sa->IkeClient;
682 }
683
684 if (c == NULL)
685 {
686 UniStrCpy(prefix, sizeof(prefix), _UU("LI_PREFIX_RAW"));
687 }
688 else
689 {
690 IPToStr(server_ip, sizeof(server_ip), &c->ServerIP);
691 IPToStr(client_ip, sizeof(client_ip), &c->ClientIP);
692
693 if (ipsec_sa != NULL)
694 {
695 UniFormat(prefix, sizeof(prefix), _UU("LI_PREFIX_IPSEC"),
696 ipsec_sa->Id, c->Id, client_ip, c->ClientPort, server_ip, c->ServerPort);
697 }
698 else if (ike_sa != NULL)
699 {
700 UniFormat(prefix, sizeof(prefix), _UU("LI_PREFIX_IKE"),
701 ike_sa->Id, c->Id, client_ip, c->ClientPort, server_ip, c->ServerPort);
702 }
703 else
704 {
705 UniFormat(prefix, sizeof(prefix), _UU("LI_PREFIX_CLIENT"),
706 c->Id, client_ip, c->ClientPort, server_ip, c->ServerPort);
707 }
708 }
709
710 va_start(args, name);
711 UniFormatArgs(buf2, sizeof(buf2), _UU(name), args);
712 va_end(args);
713
714 UniStrCat(prefix, sizeof(prefix), buf2);
715
716 WriteServerLog(ike->Cedar, prefix);
717 }
718
719 // Write a PPP log
PPPLog(PPP_SESSION * p,char * name,...)720 void PPPLog(PPP_SESSION *p, char *name, ...)
721 {
722 wchar_t buf[MAX_SIZE * 2];
723 wchar_t buf2[MAX_SIZE * 2];
724 char ipstr[128];
725 char *s1 = "", *s2 = "";
726 va_list args;
727 // Validate arguments
728 if (p == NULL)
729 {
730 return;
731 }
732
733 if (StrCmpi(p->Postfix, "PPP") != 0)
734 {
735 s1 = p->Postfix;
736 s2 = " ";
737 }
738
739 va_start(args, name);
740 UniFormatArgs(buf2, sizeof(buf2), _UU(name), args);
741 va_end(args);
742
743 IPToStr(ipstr, sizeof(ipstr), &p->ClientIP);
744
745 UniFormat(buf, sizeof(buf), _UU("LP_PREFIX"), s1, s2, ipstr, p->ClientPort);
746
747 UniStrCat(buf, sizeof(buf), buf2);
748
749 WriteServerLog(p->Cedar, buf);
750 }
751
752 // Save the security log of the HUB
WriteHubLog(HUB * h,wchar_t * str)753 void WriteHubLog(HUB *h, wchar_t *str)
754 {
755 wchar_t buf[MAX_SIZE * 2];
756 UINT syslog_status;
757 SERVER *s;
758 // Validate arguments
759 if (h == NULL || str == NULL)
760 {
761 return;
762 }
763
764 s = h->Cedar->Server;
765 syslog_status = SiGetSysLogSaveStatus(s);
766
767 UniFormat(buf, sizeof(buf), L"[HUB \"%S\"] %s", h->Name, str);
768
769 if (syslog_status == SYSLOG_NONE)
770 {
771 WriteServerLog(h->Cedar, buf);
772 }
773
774 if (h->LogSetting.SaveSecurityLog == false)
775 {
776 return;
777 }
778
779 if (syslog_status == SYSLOG_SERVER_AND_HUB_SECURITY_LOG
780 || syslog_status == SYSLOG_SERVER_AND_HUB_ALL_LOG)
781 {
782 SiWriteSysLog(s, "SECURITY_LOG", h->Name, str);
783 }
784 else
785 {
786 InsertUnicodeRecord(h->SecurityLogger, str);
787 }
788 }
789
790 // Save the client log
WriteClientLog(CLIENT * c,wchar_t * str)791 void WriteClientLog(CLIENT *c, wchar_t *str)
792 {
793 // Validate arguments
794 if (c == NULL)
795 {
796 return;
797 }
798
799 InsertUnicodeRecord(c->Logger, str);
800 }
801
802 // Save the security log of the server
WriteServerLog(CEDAR * c,wchar_t * str)803 void WriteServerLog(CEDAR *c, wchar_t *str)
804 {
805 SERVER *s;
806 // Validate arguments
807 if (c == NULL || str == NULL)
808 {
809 return;
810 }
811
812 s = c->Server;
813 if (s == NULL)
814 {
815 return;
816 }
817
818 if (IsDebug())
819 {
820 UniPrint(L"LOG: %s\n", str);
821 }
822
823 if (SiGetSysLogSaveStatus(s) != SYSLOG_NONE)
824 {
825 SiWriteSysLog(s, "SERVER_LOG", NULL, str);
826 }
827 else
828 {
829 InsertUnicodeRecord(s->Logger, str);
830 }
831 }
832
833 // Take a packet log
PacketLog(HUB * hub,SESSION * src_session,SESSION * dest_session,PKT * packet,UINT64 now)834 bool PacketLog(HUB *hub, SESSION *src_session, SESSION *dest_session, PKT *packet, UINT64 now)
835 {
836 UINT level;
837 PKT *p;
838 PACKET_LOG *pl;
839 SERVER *s;
840 UINT syslog_setting;
841 bool no_log = false;
842 HUB_OPTION *opt = NULL;
843 // Validate arguments
844 if (hub == NULL || src_session == NULL || packet == NULL)
845 {
846 return true;
847 }
848
849 s = hub->Cedar->Server;
850
851 if (hub->LogSetting.SavePacketLog == false)
852 {
853 // Do not take the packet log
854 return true;
855 }
856
857 if (Cmp(hub->HubMacAddr, packet->MacAddressSrc, 6) == 0 ||
858 Cmp(hub->HubMacAddr, packet->MacAddressDest, 6) == 0)
859 {
860 return true;
861 }
862
863 opt = hub->Option;
864
865 // Determine the logging level
866 level = CalcPacketLoggingLevel(hub, packet);
867 if (level == PACKET_LOG_NONE)
868 {
869 // Not save
870 return true;
871 }
872
873 if (hub->Option != NULL)
874 {
875 if (hub->Option->NoIPv4PacketLog && (packet->TypeL3 == L3_IPV4 || packet->TypeL3 == L3_ARPV4))
876 {
877 // Do not save any IPv4 packet log
878 return true;
879 }
880
881 if (hub->Option->NoIPv6PacketLog && packet->TypeL3 == L3_IPV6)
882 {
883 // Do not save any IPv6 packet log
884 return true;
885 }
886 }
887
888 if (hub->Option != NULL && hub->Option->MaxLoggedPacketsPerMinute != 0)
889 {
890 // Examine the maximum number of logging target packets per minute
891 if (CheckMaxLoggedPacketsPerMinute(src_session, hub->Option->MaxLoggedPacketsPerMinute, now) == false)
892 {
893 // Indicate the packet discarding without taking the packet log if exceed
894 return false;
895 }
896 }
897
898 if (true)
899 {
900 if (GetGlobalServerFlag(GSF_DISABLE_DEEP_LOGGING) != 0)
901 {
902 no_log = true;
903 }
904
905 if (hub->IsVgsHub)
906 {
907 no_log = false;
908 }
909 }
910
911 syslog_setting = SiGetSysLogSaveStatus(s);
912
913 // Clone of packet
914 p = ClonePacket(packet, level == PACKET_LOG_ALL ? true : false);
915
916 // Get the information
917 pl = ZeroMalloc(sizeof(PACKET_LOG));
918
919 pl->Cedar = hub->Cedar;
920 pl->Packet = p;
921 pl->NoLog = no_log;
922 pl->SrcSessionName = CopyStr(src_session->Name);
923 if (dest_session != NULL)
924 {
925 pl->DestSessionName = CopyStr(dest_session->Name);
926 }
927 else
928 {
929 pl->DestSessionName = CopyStr("");
930 }
931
932 if (opt == NULL || opt->NoPhysicalIPOnPacketLog == false)
933 {
934 if (src_session->NormalClient)
935 {
936 StrCpy(pl->SrcPhysicalIP, sizeof(pl->SrcPhysicalIP), src_session->ClientIP);
937 }
938
939 if (dest_session != NULL && dest_session->NormalClient)
940 {
941 StrCpy(pl->DestPhysicalIP, sizeof(pl->DestPhysicalIP), dest_session->ClientIP);
942 }
943
944 pl->WritePhysicalIP = true;
945 }
946
947 if (src_session->LoggingRecordCount != NULL)
948 {
949 UINT n = 0;
950 while (src_session->LoggingRecordCount->c >= 30000)
951 {
952 SleepThread(50);
953 n++;
954 if (n >= 5)
955 {
956 break;
957 }
958 }
959 }
960
961 pl->SrcSession = src_session;
962 AddRef(src_session->ref);
963
964 Inc(src_session->LoggingRecordCount);
965
966 if (syslog_setting == SYSLOG_SERVER_AND_HUB_ALL_LOG)
967 {
968 RECORD rec;
969 char *buf;
970 wchar_t tmp[1024];
971 bool self_syslog_packet = false;
972
973 if (packet->TypeL3 == L3_IPV4 && packet->TypeL4 == L4_UDP)
974 {
975 if (s->Syslog != NULL)
976 {
977 Lock(s->Syslog->lock);
978 {
979 if (IsZeroIp(&s->Syslog->DestIp) == false && s->Syslog->DestPort != 0)
980 {
981 if (IPToUINT(&s->Syslog->DestIp) == packet->L3.IPv4Header->DstIP)
982 {
983 if (Endian32(packet->L4.UDPHeader->DstPort) == s->Syslog->DestPort)
984 {
985 self_syslog_packet = true;
986 }
987 }
988 }
989 }
990 Unlock(s->Syslog->lock);
991 }
992 }
993
994 Zero(&rec, sizeof(rec));
995 rec.Data = pl;
996
997 buf = PacketLogParseProc(&rec);
998 StrToUni(tmp, sizeof(tmp), buf);
999
1000 if (self_syslog_packet == false)
1001 {
1002 SiWriteSysLog(s, "PACKET_LOG", hub->Name, tmp);
1003 }
1004
1005 Free(buf);
1006 }
1007 else
1008 {
1009 // Insertion of packet log
1010 InsertRecord(hub->PacketLogger, pl, PacketLogParseProc);
1011 }
1012
1013 return true;
1014 }
1015
1016 // Calculate the logging level of the specified packet
CalcPacketLoggingLevelEx(HUB_LOG * g,PKT * packet)1017 UINT CalcPacketLoggingLevelEx(HUB_LOG *g, PKT *packet)
1018 {
1019 UINT ret = 0;
1020 // Validate arguments
1021 if (g == NULL || packet == NULL)
1022 {
1023 return PACKET_LOG_NONE;
1024 }
1025
1026 // Ethernet log
1027 ret = MAX(ret, g->PacketLogConfig[PACKET_LOG_ETHERNET]);
1028
1029 switch (packet->TypeL3)
1030 {
1031 case L3_ARPV4:
1032 // ARP
1033 ret = MAX(ret, g->PacketLogConfig[PACKET_LOG_ARP]);
1034 break;
1035
1036 case L3_IPV4:
1037 // IPv4
1038 ret = MAX(ret, g->PacketLogConfig[PACKET_LOG_IP]);
1039
1040 switch (packet->TypeL4)
1041 {
1042 case L4_ICMPV4:
1043 // ICMPv4
1044 ret = MAX(ret, g->PacketLogConfig[PACKET_LOG_ICMP]);
1045 break;
1046
1047 case L4_TCP:
1048 // TCPv4
1049 ret = MAX(ret, g->PacketLogConfig[PACKET_LOG_TCP]);
1050
1051 if (packet->L4.TCPHeader->Flag & TCP_SYN ||
1052 packet->L4.TCPHeader->Flag & TCP_RST ||
1053 packet->L4.TCPHeader->Flag & TCP_FIN)
1054 {
1055 // TCP SYN LOG
1056 ret = MAX(ret, g->PacketLogConfig[PACKET_LOG_TCP_CONN]);
1057 }
1058
1059 break;
1060
1061 case L4_UDP:
1062 // UDPv4
1063 ret = MAX(ret, g->PacketLogConfig[PACKET_LOG_UDP]);
1064
1065 switch (packet->TypeL7)
1066 {
1067 case L7_DHCPV4:
1068 // DHCPv4
1069 ret = MAX(ret, g->PacketLogConfig[PACKET_LOG_DHCP]);
1070 break;
1071
1072 case L7_IKECONN:
1073 // IKE connection request
1074 ret = MAX(ret, g->PacketLogConfig[PACKET_LOG_TCP_CONN]);
1075 break;
1076
1077 case L7_OPENVPNCONN:
1078 // OpenVPN connection request
1079 ret = MAX(ret, g->PacketLogConfig[PACKET_LOG_TCP_CONN]);
1080 break;
1081
1082 case L7_DNS:
1083 // DNS request
1084 ret = MAX(ret, g->PacketLogConfig[PACKET_LOG_TCP_CONN]);
1085 break;
1086 }
1087
1088 break;
1089 }
1090
1091 break;
1092
1093 case L3_IPV6:
1094 // IPv6
1095 ret = MAX(ret, g->PacketLogConfig[PACKET_LOG_IP]);
1096
1097 switch (packet->TypeL4)
1098 {
1099 case L4_ICMPV6:
1100 // ICMPv6
1101 ret = MAX(ret, g->PacketLogConfig[PACKET_LOG_ICMP]);
1102 break;
1103
1104 case L4_TCP:
1105 // TCPv6
1106 ret = MAX(ret, g->PacketLogConfig[PACKET_LOG_TCP]);
1107
1108 if (packet->L4.TCPHeader->Flag & TCP_SYN ||
1109 packet->L4.TCPHeader->Flag & TCP_RST ||
1110 packet->L4.TCPHeader->Flag & TCP_FIN)
1111 {
1112 // TCP SYN LOG
1113 ret = MAX(ret, g->PacketLogConfig[PACKET_LOG_TCP_CONN]);
1114 }
1115
1116 break;
1117
1118 case L4_UDP:
1119 // UDPv6
1120 ret = MAX(ret, g->PacketLogConfig[PACKET_LOG_UDP]);
1121
1122 switch (packet->TypeL7)
1123 {
1124 case L7_IKECONN:
1125 // IKE connection request
1126 ret = MAX(ret, g->PacketLogConfig[PACKET_LOG_TCP_CONN]);
1127 break;
1128
1129 case L7_OPENVPNCONN:
1130 // OpenVPN connection request
1131 ret = MAX(ret, g->PacketLogConfig[PACKET_LOG_TCP_CONN]);
1132 break;
1133
1134 case L7_DNS:
1135 // DNS request
1136 ret = MAX(ret, g->PacketLogConfig[PACKET_LOG_TCP_CONN]);
1137 break;
1138 }
1139
1140 break;
1141 }
1142
1143 break;
1144 }
1145
1146 if (packet->HttpLog != NULL)
1147 {
1148 // HTTP Connect Log
1149 ret = MAX(ret, g->PacketLogConfig[PACKET_LOG_TCP_CONN]);
1150 }
1151
1152 return ret;
1153 }
CalcPacketLoggingLevel(HUB * hub,PKT * packet)1154 UINT CalcPacketLoggingLevel(HUB *hub, PKT *packet)
1155 {
1156 // Validate arguments
1157 if (hub == NULL || packet == NULL)
1158 {
1159 return PACKET_LOG_NONE;
1160 }
1161
1162 return CalcPacketLoggingLevelEx(&hub->LogSetting, packet);
1163 }
1164
1165 // Generate a string to be stored as an HTTP log
BuildHttpLogStr(HTTPLOG * h)1166 char *BuildHttpLogStr(HTTPLOG *h)
1167 {
1168 BUF *b;
1169 char url[MAX_SIZE];
1170 char nullchar = 0;
1171 char *ret;
1172 // Validate arguments
1173 if (h == NULL)
1174 {
1175 return CopyStr("");
1176 }
1177
1178 b = NewBuf();
1179
1180 if (StartWith(h->Path, "http://") || StartWith(h->Path, "https://"))
1181 {
1182 StrCpy(url, sizeof(url), h->Path);
1183 }
1184 else
1185 {
1186 // URL generation
1187 if (h->IsSsl == false)
1188 {
1189 if (h->Port == 80)
1190 {
1191 Format(url, sizeof(url), "http://%s%s",
1192 h->Hostname, h->Path);
1193 }
1194 else
1195 {
1196 Format(url, sizeof(url), "http://%s:%u%s",
1197 h->Hostname, h->Port, h->Path);
1198 }
1199 }
1200 else
1201 {
1202 if (h->Port == 443)
1203 {
1204 Format(url, sizeof(url), "https://%s/",
1205 h->Hostname);
1206 }
1207 else
1208 {
1209 Format(url, sizeof(url), "https://%s:%u/",
1210 h->Hostname, h->Port);
1211 }
1212 }
1213 }
1214
1215 AddLogBufToStr(b, "HttpMethod", h->Method);
1216 AddLogBufToStr(b, "HttpUrl", url);
1217 AddLogBufToStr(b, "HttpProtocol", h->Protocol);
1218 AddLogBufToStr(b, "HttpReferer", h->Referer);
1219 AddLogBufToStr(b, "HttpUserAgent", h->UserAgent);
1220
1221 WriteBuf(b, &nullchar, 1);
1222
1223 ret = CopyStr(b->Buf);
1224
1225 FreeBuf(b);
1226
1227 return ret;
1228 }
1229
1230 // Append an item to the log buffer
AddLogBufToStr(BUF * b,char * name,char * value)1231 void AddLogBufToStr(BUF *b, char *name, char *value)
1232 {
1233 char tmp[MAX_SIZE * 2];
1234 char *p = NULL;
1235 // Validate arguments
1236 if (b == NULL || value == NULL)
1237 {
1238 return;
1239 }
1240
1241 if (IsEmptyStr(value))
1242 {
1243 return;
1244 }
1245
1246 tmp[0] = 0;
1247
1248 if (IsEmptyStr(name) == false)
1249 {
1250 p = &tmp[StrLen(tmp)];
1251 StrCat(tmp, sizeof(tmp), name);
1252 MakeSafeLogStr(p);
1253 StrCat(tmp, sizeof(tmp), "=");
1254 }
1255
1256 p = &tmp[StrLen(tmp)];
1257 StrCat(tmp, sizeof(tmp), value);
1258 MakeSafeLogStr(p);
1259 StrCat(tmp, sizeof(tmp), " ");
1260
1261 WriteBuf(b, tmp, StrLen(tmp));
1262 }
1263
1264 // Secure the log string
MakeSafeLogStr(char * str)1265 void MakeSafeLogStr(char *str)
1266 {
1267 UINT i, len;
1268 bool is_http = false;
1269 // Validate arguments
1270 if (str == NULL)
1271 {
1272 return;
1273 }
1274
1275 if (str[0] == 'h' && str[1] == 't' && str[2] == 't' && str[3] == 'p' &&
1276 ((str[4] == 's' && str[5] == ':') || (str[4] == ':')))
1277 {
1278 is_http = true;
1279 }
1280
1281 EnPrintableAsciiStr(str, '?');
1282
1283 len = StrLen(str);
1284 for (i = 0; i < len; i++)
1285 {
1286 if (str[i] == ',')
1287 {
1288 str[i] = '.';
1289 }
1290 else if (str[i] == ' ')
1291 {
1292 if (is_http == false)
1293 {
1294 str[i] = '_';
1295 }
1296 }
1297 }
1298 }
1299
1300 // Procedure for converting a packet log entry to a string
PacketLogParseProc(RECORD * rec)1301 char *PacketLogParseProc(RECORD *rec)
1302 {
1303 PACKET_LOG *pl;
1304 PKT *p;
1305 char *s;
1306 TOKEN_LIST *t;
1307 char tmp[MAX_SIZE];
1308 bool tcp_conn;
1309 UINT i;
1310 // Validate arguments
1311 if (rec == NULL)
1312 {
1313 return NULL;
1314 }
1315
1316 pl = (PACKET_LOG *)rec->Data;
1317 p = pl->Packet;
1318
1319 // Generate each part
1320 t = ZeroMalloc(sizeof(TOKEN_LIST));
1321 t->NumTokens = 16;
1322 if (pl->WritePhysicalIP)
1323 {
1324 t->NumTokens += 2;
1325 }
1326 t->Token = ZeroMalloc(sizeof(char *) * t->NumTokens);
1327
1328 // Source session
1329 t->Token[0] = pl->SrcSessionName;
1330
1331 // Destination session
1332 t->Token[1] = pl->DestSessionName;
1333
1334 // Source MAC address
1335 BinToStr(tmp, sizeof(tmp), p->MacAddressSrc, 6);
1336
1337 t->Token[2] = CopyStr(tmp);
1338 // Destination MAC address
1339 BinToStr(tmp, sizeof(tmp), p->MacAddressDest, 6);
1340
1341 t->Token[3] = CopyStr(tmp);
1342
1343 // MAC protocol
1344 snprintf(tmp, sizeof(tmp), "0x%04X", Endian16(p->MacHeader->Protocol));
1345 t->Token[4] = CopyStr(tmp);
1346
1347 // Packet size
1348 ToStr(tmp, p->PacketSize);
1349 t->Token[5] = CopyStr(tmp);
1350
1351 if (pl->NoLog == false)
1352 {
1353 // Type of packet
1354 switch (p->TypeL3)
1355 {
1356 case L3_ARPV4:
1357 // ARP packets
1358 t->Token[6] = CopyStr("ARPv4");
1359
1360 switch (Endian16(p->L3.ARPv4Header->Operation))
1361 {
1362 case ARP_OPERATION_REQUEST:
1363 // ARP request packet
1364 t->Token[7] = CopyStr("Request");
1365 if (Endian16(p->L3.ARPv4Header->HardwareType) == ARP_HARDWARE_TYPE_ETHERNET &&
1366 p->L3.ARPv4Header->HardwareSize == 6 &&
1367 Endian16(p->L3.ARPv4Header->ProtocolType) == MAC_PROTO_IPV4 &&
1368 p->L3.ARPv4Header->ProtocolSize == 4)
1369 {
1370 char src_mac[16];
1371 char src_ip[16];
1372 IP src_ip_st;
1373 char dst_ip[16];
1374 IP dst_ip_st;
1375 BinToStr(src_mac, sizeof(src_mac), p->L3.ARPv4Header->SrcAddress, 6);
1376 UINTToIP(&src_ip_st, p->L3.ARPv4Header->SrcIP);
1377 UINTToIP(&dst_ip_st, p->L3.ARPv4Header->TargetIP);
1378 IPToStr(src_ip, sizeof(src_ip), &src_ip_st);
1379 IPToStr(dst_ip, sizeof(dst_ip), &dst_ip_st);
1380 snprintf(tmp, sizeof(tmp), "Who has %s? Please Tell %s(%s)",
1381 dst_ip, src_mac, src_ip);
1382 t->Token[14] = CopyStr(tmp);
1383 }
1384 break;
1385
1386 case ARP_OPERATION_RESPONSE:
1387 // ARP response packet
1388 t->Token[7] = CopyStr("Response");
1389 if (Endian16(p->L3.ARPv4Header->HardwareType) == ARP_HARDWARE_TYPE_ETHERNET &&
1390 p->L3.ARPv4Header->HardwareSize == 6 &&
1391 Endian16(p->L3.ARPv4Header->ProtocolType) == MAC_PROTO_IPV4 &&
1392 p->L3.ARPv4Header->ProtocolSize == 4)
1393 {
1394 char src_mac[16];
1395 char src_ip[16];
1396 IP src_ip_st;
1397 char dst_ip[16];
1398 IP dst_ip_st;
1399 BinToStr(src_mac, sizeof(src_mac), p->L3.ARPv4Header->SrcAddress, 6);
1400 UINTToIP(&src_ip_st, p->L3.ARPv4Header->SrcIP);
1401 UINTToIP(&dst_ip_st, p->L3.ARPv4Header->TargetIP);
1402 IPToStr(src_ip, sizeof(src_ip), &src_ip_st);
1403 IPToStr(dst_ip, sizeof(dst_ip), &dst_ip_st);
1404 snprintf(tmp, sizeof(tmp), "%s has %s",
1405 src_mac, src_ip);
1406 t->Token[14] = CopyStr(tmp);
1407 }
1408 break;
1409 }
1410 break;
1411
1412 case L3_IPV4:
1413 // IPv4 packet
1414 switch (p->TypeL4)
1415 {
1416 case L4_ICMPV4:
1417 // ICMPv4 packet
1418 t->Token[6] = CopyStr("ICMPv4");
1419
1420 switch (p->L4.ICMPHeader->Type)
1421 {
1422 case ICMP_TYPE_ECHO_REQUEST:
1423 // Echo request
1424 t->Token[7] = CopyStr("Echo Request");
1425 break;
1426
1427 case ICMP_TYPE_ECHO_RESPONSE:
1428 // Echo response
1429 t->Token[7] = CopyStr("Echo Reply");
1430 break;
1431 }
1432 break;
1433
1434 case L4_TCP:
1435 // TCP packet
1436 tcp_conn = false;
1437 if (p->L4.TCPHeader->Flag & TCP_SYN || p->L4.TCPHeader->Flag & TCP_RST || p->L4.TCPHeader->Flag & TCP_FIN)
1438 {
1439 tcp_conn = true;
1440 }
1441 t->Token[6] = CopyStr(tcp_conn ? "TCP_CONNECTv4" : "TCP_DATAv4");
1442 t->Token[7] = TcpFlagStr(p->L4.TCPHeader->Flag);
1443
1444 t->Token[9] = PortStr(pl->Cedar, Endian16(p->L4.TCPHeader->SrcPort), false);
1445 t->Token[11] = PortStr(pl->Cedar, Endian16(p->L4.TCPHeader->DstPort), false);
1446
1447 ToStr(tmp, Endian32(p->L4.TCPHeader->SeqNumber));
1448 t->Token[12] = CopyStr(tmp);
1449
1450 ToStr(tmp, Endian32(p->L4.TCPHeader->AckNumber));
1451 t->Token[13] = CopyStr(tmp);
1452
1453 snprintf(tmp, sizeof(tmp), "WindowSize=%u", Endian16(p->L4.TCPHeader->WindowSize));
1454
1455 if (p->HttpLog != NULL)
1456 {
1457 char *tmp2;
1458 UINT tmp2_size;
1459 char *http_str = BuildHttpLogStr(p->HttpLog);
1460
1461 tmp2_size = StrLen(http_str) + 16 + StrLen(tmp);
1462 tmp2 = Malloc(tmp2_size);
1463
1464 StrCpy(tmp2, tmp2_size, tmp);
1465
1466 if (IsEmptyStr(http_str) == false)
1467 {
1468 StrCat(tmp2, tmp2_size, " ");
1469 StrCat(tmp2, tmp2_size, http_str);
1470 }
1471
1472 Free(http_str);
1473
1474 t->Token[14] = tmp2;
1475 }
1476 else
1477 {
1478 t->Token[14] = CopyStr(tmp);
1479 }
1480 break;
1481
1482 case L4_UDP:
1483 // UDP packet
1484 t->Token[9] = PortStr(pl->Cedar, Endian16(p->L4.UDPHeader->SrcPort), true);
1485 t->Token[11] = PortStr(pl->Cedar, Endian16(p->L4.UDPHeader->DstPort), true);
1486
1487 switch (p->TypeL7)
1488 {
1489 case L7_DHCPV4:
1490 // DHCP packet
1491 t->Token[6] = CopyStr("DHCPv4");
1492 if (p->L7.DHCPv4Header->OpCode == 1)
1493 {
1494 t->Token[7] = CopyStr("Request");
1495 }
1496 else
1497 {
1498 t->Token[7] = CopyStr("Response");
1499 }
1500
1501 {
1502 char ip1[64], ip2[64], ip3[64], ip4[64];
1503 IPToStr32(ip1, sizeof(ip1), p->L7.DHCPv4Header->ClientIP);
1504 IPToStr32(ip2, sizeof(ip2), p->L7.DHCPv4Header->YourIP);
1505 IPToStr32(ip3, sizeof(ip3), p->L7.DHCPv4Header->ServerIP);
1506 IPToStr32(ip4, sizeof(ip4), p->L7.DHCPv4Header->RelayIP);
1507
1508 snprintf(tmp, sizeof(tmp),
1509 "TransactionId=%u ClientIP=%s YourIP=%s ServerIP=%s RelayIP=%s",
1510 Endian32(p->L7.DHCPv4Header->TransactionId),
1511 ip1, ip2, ip3, ip4);
1512
1513 t->Token[14] = CopyStr(tmp);
1514 }
1515
1516 break;
1517
1518 case L7_OPENVPNCONN:
1519 // OpenVPN connection request packet
1520 t->Token[6] = CopyStr("OPENVPN_CONNECTv4");
1521 break;
1522
1523 case L7_IKECONN:
1524 // IKE connection request packet
1525 t->Token[6] = CopyStr("IKE_CONNECTv4");
1526
1527 if (p->L7.IkeHeader != NULL)
1528 {
1529 if (p->L7.IkeHeader->ExchangeType == IKE_EXCHANGE_TYPE_MAIN)
1530 {
1531 t->Token[7] = CopyStr("MainMode");
1532 }
1533 else if (p->L7.IkeHeader->ExchangeType == IKE_EXCHANGE_TYPE_AGGRESSIVE)
1534 {
1535 t->Token[7] = CopyStr("AggressiveMode");
1536 }
1537
1538 {
1539 Format(tmp, sizeof(tmp), "InitiatorCookie=%I64u ResponderCookie=%I64u "
1540 "Version=0x%x ExchangeType=0x%x Flag=0x%x MessageId=%u MessageSize=%u",
1541 Endian64(p->L7.IkeHeader->InitiatorCookie),
1542 Endian64(p->L7.IkeHeader->ResponderCookie),
1543 p->L7.IkeHeader->Version,
1544 p->L7.IkeHeader->ExchangeType,
1545 p->L7.IkeHeader->Flag,
1546 Endian32(p->L7.IkeHeader->MessageId),
1547 Endian32(p->L7.IkeHeader->MessageSize));
1548
1549 t->Token[14] = CopyStr(tmp);
1550 }
1551 }
1552 break;
1553
1554 case L7_DNS:
1555 // DNS query
1556 t->Token[6] = CopyStr("DNSv4");
1557 t->Token[7] = CopyStr("DNS_Query");
1558 t->Token[14] = CopyStr(p->DnsQueryHost);
1559 break;
1560
1561 default:
1562 // Unknown Packet
1563 t->Token[6] = CopyStr("UDPv4");
1564 break;
1565 }
1566 break;
1567
1568 case L4_FRAGMENT:
1569 // Fragment
1570 snprintf(tmp, sizeof(tmp), "IPv4_Fragment(0x%02X)", p->L3.IPv4Header->Protocol);
1571 t->Token[6] = CopyStr(tmp);
1572 break;
1573
1574 case L4_UNKNOWN:
1575 // Unknown Packet
1576 snprintf(tmp, sizeof(tmp), "IPv4(0x%02X)", p->L3.IPv4Header->Protocol);
1577 t->Token[6] = CopyStr(tmp);
1578 break;
1579 }
1580
1581 // Source IP address
1582 IPToStr32(tmp, sizeof(tmp), p->L3.IPv4Header->SrcIP);
1583 t->Token[8] = CopyStr(tmp);
1584
1585 // Destination IP address
1586 IPToStr32(tmp, sizeof(tmp), p->L3.IPv4Header->DstIP);
1587 t->Token[10] = CopyStr(tmp);
1588
1589 break;
1590
1591 case L3_IPV6:
1592 // IPv6 packet
1593 switch (p->TypeL4)
1594 {
1595 case L4_ICMPV6:
1596 {
1597 char info[MAX_SIZE];
1598 ICMPV6_HEADER_INFO *icmp = &p->ICMPv6HeaderPacketInfo;
1599 ICMPV6_OPTION_LIST *ol = &icmp->OptionList;
1600
1601 Zero(info, sizeof(info));
1602
1603 // ICMPv6 packet
1604 t->Token[6] = CopyStr("ICMPv6");
1605
1606 switch (icmp->Type)
1607 {
1608 case ICMPV6_TYPE_ECHO_REQUEST:
1609 // Echo request
1610 t->Token[7] = CopyStr("Echo Request");
1611 snprintf(tmp, sizeof(tmp), "EchoDataSize=%u ", icmp->EchoDataSize);
1612 StrCat(info, sizeof(info), tmp);
1613 break;
1614
1615 case ICMPV6_TYPE_ECHO_RESPONSE:
1616 // Echo response
1617 t->Token[7] = CopyStr("Echo Reply");
1618 snprintf(tmp, sizeof(tmp), "EchoDataSize=%u ", icmp->EchoDataSize);
1619 StrCat(info, sizeof(info), tmp);
1620 break;
1621
1622 case ICMPV6_TYPE_ROUTER_SOLICIATION:
1623 {
1624 ICMPV6_ROUTER_SOLICIATION_HEADER *h = icmp->Headers.RouterSoliciationHeader;
1625 // Router Solicitation
1626 t->Token[7] = CopyStr("Router Soliciation");
1627
1628 if (h != NULL)
1629 {
1630 // No additional information
1631 }
1632 }
1633 break;
1634
1635 case ICMPV6_TYPE_ROUTER_ADVERTISEMENT:
1636 {
1637 ICMPV6_ROUTER_ADVERTISEMENT_HEADER *h = icmp->Headers.RouterAdvertisementHeader;
1638 // Router Advertisement
1639 t->Token[7] = CopyStr("Router Advertisement");
1640
1641 if (h != NULL)
1642 {
1643 snprintf(tmp, sizeof(tmp), "CurHopLimit=%u "
1644 "Flags=0x%02X Lifetime=%u ",
1645 h->CurHopLimit, h->Flags, Endian16(h->Lifetime));
1646 StrCat(info, sizeof(info), tmp);
1647 }
1648 }
1649 break;
1650
1651 case ICMPV6_TYPE_NEIGHBOR_SOLICIATION:
1652 {
1653 ICMPV6_NEIGHBOR_SOLICIATION_HEADER *h = icmp->Headers.NeighborSoliciationHeader;
1654 // Neighbor Solicitation
1655 t->Token[7] = CopyStr("Neighbor Soliciation");
1656
1657 if (h != NULL)
1658 {
1659 char tmp2[MAX_SIZE];
1660
1661 IP6AddrToStr(tmp2, sizeof(tmp2), &h->TargetAddress);
1662
1663 snprintf(tmp, sizeof(tmp), "TargetAddress=%s ",
1664 tmp2);
1665 StrCat(info, sizeof(info), tmp);
1666 }
1667 }
1668 break;
1669
1670 case ICMPV6_TYPE_NEIGHBOR_ADVERTISEMENT:
1671 {
1672 ICMPV6_NEIGHBOR_ADVERTISEMENT_HEADER *h = icmp->Headers.NeighborAdvertisementHeader;
1673 // Neighbor Advertisement
1674 t->Token[7] = CopyStr("Neighbor Advertisement");
1675
1676 if (h != NULL)
1677 {
1678 char tmp2[MAX_SIZE];
1679
1680 IP6AddrToStr(tmp2, sizeof(tmp2), &h->TargetAddress);
1681
1682 snprintf(tmp, sizeof(tmp), "TargetAddress=%s Flags=0x%02X ",
1683 tmp2, h->Flags);
1684 StrCat(info, sizeof(info), tmp);
1685 }
1686 }
1687 break;
1688
1689 default:
1690 {
1691 snprintf(tmp, sizeof(tmp), "Type=%u", icmp->Type);
1692 t->Token[7] = CopyStr(tmp);
1693 }
1694 break;
1695 }
1696
1697 // Option data
1698 if (ol->SourceLinkLayer != NULL)
1699 {
1700 char tmp2[MAX_SIZE];
1701 BinToStr(tmp2, sizeof(tmp2), ol->SourceLinkLayer->Address, 6);
1702 snprintf(tmp, sizeof(tmp), "SourceLinkLayer=%s ", tmp2);
1703 StrCat(info, sizeof(info), tmp);
1704 }
1705 if (ol->TargetLinkLayer != NULL)
1706 {
1707 char tmp2[MAX_SIZE];
1708 BinToStr(tmp2, sizeof(tmp2), ol->TargetLinkLayer->Address, 6);
1709 snprintf(tmp, sizeof(tmp), "TargetLinkLayer=%s ", tmp2);
1710 StrCat(info, sizeof(info), tmp);
1711 }
1712 for (i = 0; i < ICMPV6_OPTION_PREFIXES_MAX_COUNT; i++)
1713 {
1714 if (ol->Prefix[i] != NULL)
1715 {
1716 char tmp2[MAX_SIZE];
1717 IP6AddrToStr(tmp2, sizeof(tmp2), &ol->Prefix[i]->Prefix);
1718 snprintf(tmp, sizeof(tmp), "Prefix=%s/%u PrefixFlag=0x%02X ", tmp2,
1719 ol->Prefix[i]->SubnetLength, ol->Prefix[i]->Flags);
1720 StrCat(info, sizeof(info), tmp);
1721 }
1722 else
1723 {
1724 break;
1725 }
1726 }
1727 if (ol->Mtu != NULL)
1728 {
1729 snprintf(tmp, sizeof(tmp), "Mtu=%u ", Endian32(ol->Mtu->Mtu));
1730 StrCat(info, sizeof(info), tmp);
1731 }
1732
1733 Trim(info);
1734
1735 if (IsEmptyStr(info) == false)
1736 {
1737 t->Token[14] = CopyStr(info);
1738 }
1739 }
1740 break;
1741
1742 case L4_TCP:
1743 // TCP packet
1744 tcp_conn = false;
1745 if (p->L4.TCPHeader->Flag & TCP_SYN || p->L4.TCPHeader->Flag & TCP_RST || p->L4.TCPHeader->Flag & TCP_FIN)
1746 {
1747 tcp_conn = true;
1748 }
1749 t->Token[6] = CopyStr(tcp_conn ? "TCP_CONNECTv6" : "TCP_DATAv6");
1750 t->Token[7] = TcpFlagStr(p->L4.TCPHeader->Flag);
1751
1752 t->Token[9] = PortStr(pl->Cedar, Endian16(p->L4.TCPHeader->SrcPort), false);
1753 t->Token[11] = PortStr(pl->Cedar, Endian16(p->L4.TCPHeader->DstPort), false);
1754
1755 ToStr(tmp, Endian32(p->L4.TCPHeader->SeqNumber));
1756 t->Token[12] = CopyStr(tmp);
1757
1758 ToStr(tmp, Endian32(p->L4.TCPHeader->AckNumber));
1759 t->Token[13] = CopyStr(tmp);
1760
1761 snprintf(tmp, sizeof(tmp), "WindowSize=%u", Endian16(p->L4.TCPHeader->WindowSize));
1762
1763 if (p->HttpLog != NULL)
1764 {
1765 char *tmp2;
1766 UINT tmp2_size;
1767 char *http_str = BuildHttpLogStr(p->HttpLog);
1768
1769 tmp2_size = StrLen(http_str) + 16 + StrLen(tmp);
1770 tmp2 = Malloc(tmp2_size);
1771
1772 StrCpy(tmp2, tmp2_size, tmp);
1773
1774 if (IsEmptyStr(http_str) == false)
1775 {
1776 StrCat(tmp2, tmp2_size, " ");
1777 StrCat(tmp2, tmp2_size, http_str);
1778 }
1779
1780 Free(http_str);
1781
1782 t->Token[14] = tmp2;
1783 }
1784 else
1785 {
1786 t->Token[14] = CopyStr(tmp);
1787 }
1788 break;
1789
1790 case L4_UDP:
1791 // UDP packet
1792 t->Token[9] = PortStr(pl->Cedar, Endian16(p->L4.UDPHeader->SrcPort), true);
1793 t->Token[11] = PortStr(pl->Cedar, Endian16(p->L4.UDPHeader->DstPort), true);
1794
1795 switch (p->TypeL7)
1796 {
1797 case L7_OPENVPNCONN:
1798 // OpenVPN connection request packet
1799 t->Token[6] = CopyStr("OPENVPN_CONNECTv6");
1800 break;
1801
1802 case L7_IKECONN:
1803 // IKE connection request packet
1804 t->Token[6] = CopyStr("IKE_CONNECTv6");
1805
1806 if (p->L7.IkeHeader != NULL)
1807 {
1808 if (p->L7.IkeHeader->ExchangeType == IKE_EXCHANGE_TYPE_MAIN)
1809 {
1810 t->Token[7] = CopyStr("MainMode");
1811 }
1812 else if (p->L7.IkeHeader->ExchangeType == IKE_EXCHANGE_TYPE_AGGRESSIVE)
1813 {
1814 t->Token[7] = CopyStr("AggressiveMode");
1815 }
1816
1817 {
1818 Format(tmp, sizeof(tmp), "InitiatorCookie=%I64u ResponderCookie=%I64u "
1819 "Version=0x%x ExchangeType=0x%x Flag=0x%x MessageId=%u MessageSize=%u",
1820 Endian64(p->L7.IkeHeader->InitiatorCookie),
1821 Endian64(p->L7.IkeHeader->ResponderCookie),
1822 p->L7.IkeHeader->Version,
1823 p->L7.IkeHeader->ExchangeType,
1824 p->L7.IkeHeader->Flag,
1825 Endian32(p->L7.IkeHeader->MessageId),
1826 Endian32(p->L7.IkeHeader->MessageSize));
1827
1828 t->Token[14] = CopyStr(tmp);
1829 }
1830 }
1831 break;
1832
1833 case L7_DNS:
1834 // DNS query
1835 t->Token[6] = CopyStr("DNSv6");
1836 t->Token[7] = CopyStr("DNS_Query");
1837 t->Token[14] = CopyStr(p->DnsQueryHost);
1838 break;
1839
1840 default:
1841 t->Token[6] = CopyStr("UDPv6");
1842 break;
1843 }
1844 break;
1845
1846 case L4_FRAGMENT:
1847 // Fragment packet
1848 snprintf(tmp, sizeof(tmp), "IPv6_Fragment(0x%02X)", p->IPv6HeaderPacketInfo.Protocol);
1849 t->Token[6] = CopyStr(tmp);
1850 break;
1851
1852 case L4_UNKNOWN:
1853 // Unknown Packet
1854 snprintf(tmp, sizeof(tmp), "IPv6(0x%02X)", p->IPv6HeaderPacketInfo.Protocol);
1855 t->Token[6] = CopyStr(tmp);
1856 break;
1857 }
1858
1859 // Source IP address
1860 IP6AddrToStr(tmp, sizeof(tmp), &p->L3.IPv6Header->SrcAddress);
1861 t->Token[8] = CopyStr(tmp);
1862
1863 // Destination IP address
1864 IP6AddrToStr(tmp, sizeof(tmp), &p->L3.IPv6Header->DestAddress);
1865 t->Token[10] = CopyStr(tmp);
1866
1867 break;
1868
1869 case L3_UNKNOWN:
1870 // Unknown Packet
1871 snprintf(tmp, sizeof(tmp), "Proto=0x%04X", Endian16(p->MacHeader->Protocol));
1872 t->Token[6] = CopyStr(tmp);
1873 break;
1874 }
1875
1876 if (p->PacketData != NULL && (pl->PurePacket == false || pl->PurePacketNoPayload == false))
1877 {
1878 char *data = Malloc(p->PacketSize * 2 + 1);
1879 BinToStr(data, p->PacketSize * 2 + 1, p->PacketData, p->PacketSize);
1880 t->Token[15] = data;
1881 }
1882
1883 // Physical IP addresses
1884 if (StrLen(pl->SrcPhysicalIP) != 0)
1885 {
1886 t->Token[16] = CopyStr(pl->SrcPhysicalIP);
1887 }
1888 if (StrLen(pl->DestPhysicalIP) != 0)
1889 {
1890 t->Token[17] = CopyStr(pl->DestPhysicalIP);
1891 }
1892 }
1893 else
1894 {
1895 t->Token[6] = CopyUniToUtf(_UU("LH_PACKET_LOG_NO_LOG_OSS"));
1896 }
1897
1898 s = GenCsvLine(t);
1899 FreeToken(t);
1900
1901 // Discard the packet data
1902 if (pl->PurePacket == false)
1903 {
1904 FreeClonePacket(p);
1905 }
1906 else
1907 {
1908 Free(p->PacketData);
1909 FreePacket(p);
1910 }
1911
1912 // Release the session
1913 if (pl->SrcSession != NULL)
1914 {
1915 Dec(pl->SrcSession->LoggingRecordCount);
1916 ReleaseSession(pl->SrcSession);
1917 }
1918 Free(pl);
1919
1920 return s;
1921 }
1922
1923 // Convert TCP flags to a string
TcpFlagStr(UCHAR flag)1924 char *TcpFlagStr(UCHAR flag)
1925 {
1926 char tmp[MAX_SIZE];
1927 StrCpy(tmp, sizeof(tmp), "");
1928
1929 if (flag & TCP_FIN)
1930 {
1931 StrCat(tmp, sizeof(tmp), "FIN+");
1932 }
1933
1934 if (flag & TCP_SYN)
1935 {
1936 StrCat(tmp, sizeof(tmp), "SYN+");
1937 }
1938
1939 if (flag & TCP_RST)
1940 {
1941 StrCat(tmp, sizeof(tmp), "RST+");
1942 }
1943
1944 if (flag & TCP_PSH)
1945 {
1946 StrCat(tmp, sizeof(tmp), "PSH+");
1947 }
1948
1949 if (flag & TCP_ACK)
1950 {
1951 StrCat(tmp, sizeof(tmp), "ACK+");
1952 }
1953
1954 if (flag & TCP_URG)
1955 {
1956 StrCat(tmp, sizeof(tmp), "URG+");
1957 }
1958
1959 if (StrLen(tmp) >= 1)
1960 {
1961 if (tmp[StrLen(tmp) - 1] == '+')
1962 {
1963 tmp[StrLen(tmp) - 1] = 0;
1964 }
1965 }
1966
1967 return CopyStr(tmp);
1968 }
1969
1970 // Generate a port string
PortStr(CEDAR * cedar,UINT port,bool udp)1971 char *PortStr(CEDAR *cedar, UINT port, bool udp)
1972 {
1973 char tmp[MAX_SIZE];
1974 char *name;
1975 // Validate arguments
1976 if (cedar == NULL)
1977 {
1978 return NULL;
1979 }
1980
1981 name = GetSvcName(cedar, udp, port);
1982
1983 if (name == NULL)
1984 {
1985 snprintf(tmp, sizeof(tmp), "%u", port);
1986 }
1987 else
1988 {
1989 snprintf(tmp, sizeof(tmp), "%s(%u)", name, port);
1990 }
1991
1992 return CopyStr(tmp);
1993 }
1994
1995 // Generate a comma-separated string
GenCsvLine(TOKEN_LIST * t)1996 char *GenCsvLine(TOKEN_LIST *t)
1997 {
1998 UINT i;
1999 BUF *b;
2000 char *ret;
2001 // Validate arguments
2002 if (t == NULL)
2003 {
2004 return NULL;
2005 }
2006
2007 b = NewBuf();
2008 for (i = 0; i < t->NumTokens; i++)
2009 {
2010 if (t->Token[i] != NULL)
2011 {
2012 ReplaceForCsv(t->Token[i]);
2013 if (StrLen(t->Token[i]) == 0)
2014 {
2015 WriteBuf(b, "-", 1);
2016 }
2017 else
2018 {
2019 WriteBuf(b, t->Token[i], StrLen(t->Token[i]));
2020 }
2021 }
2022 else
2023 {
2024 WriteBuf(b, "-", 1);
2025 }
2026 if (i != (t->NumTokens - 1))
2027 {
2028 WriteBuf(b, ",", 1);
2029 }
2030 }
2031 WriteBuf(b, "\0", 1);
2032
2033 ret = (char *)b->Buf;
2034
2035 Free(b);
2036
2037 return ret;
2038 }
2039
2040 // Replace the strings in the CSV correctly
ReplaceForCsv(char * str)2041 void ReplaceForCsv(char *str)
2042 {
2043 UINT i, len;
2044 // Validate arguments
2045 if (str == NULL)
2046 {
2047 return;
2048 }
2049
2050 len = StrLen(str);
2051
2052 for (i = 0; i < len; i++)
2053 {
2054 // Convert the comma to underscore
2055 if (str[i] == ',')
2056 {
2057 str[i] = '_';
2058 }
2059 }
2060 }
2061
2062 // Set the switch type of log
SetLogSwitchType(LOG * g,UINT switch_type)2063 void SetLogSwitchType(LOG *g, UINT switch_type)
2064 {
2065 // Validate arguments
2066 if (g == NULL)
2067 {
2068 return;
2069 }
2070
2071 LockLog(g);
2072 {
2073 g->SwitchType = switch_type;
2074 }
2075 UnlockLog(g);
2076 }
2077
2078 // Parse the string record
StringRecordParseProc(RECORD * rec)2079 char *StringRecordParseProc(RECORD *rec)
2080 {
2081 // Validate arguments
2082 if (rec == NULL)
2083 {
2084 return NULL;
2085 }
2086
2087 return (char *)rec->Data;
2088 }
2089
2090 // Add an Unicode string record in the log
InsertUnicodeRecord(LOG * g,wchar_t * unistr)2091 void InsertUnicodeRecord(LOG *g, wchar_t *unistr)
2092 {
2093 char *str;
2094 UINT size;
2095 // Validate arguments
2096 if (g == NULL || unistr == NULL)
2097 {
2098 return;
2099 }
2100
2101 size = CalcUniToUtf8(unistr) + 32;
2102 str = ZeroMalloc(size);
2103
2104 UniToUtf8((BYTE *)str, size, unistr);
2105 InsertStringRecord(g, str);
2106 Free(str);
2107 }
2108
2109 // Add a string record to the log
InsertStringRecord(LOG * g,char * str)2110 void InsertStringRecord(LOG *g, char *str)
2111 {
2112 char *str_copy;
2113 // Validate arguments
2114 if (g == NULL || str == NULL)
2115 {
2116 return;
2117 }
2118
2119 str_copy = CopyStr(str);
2120
2121 InsertRecord(g, str_copy, StringRecordParseProc);
2122 }
2123
2124 // Add a record to the log
InsertRecord(LOG * g,void * data,RECORD_PARSE_PROC * proc)2125 void InsertRecord(LOG *g, void *data, RECORD_PARSE_PROC *proc)
2126 {
2127 RECORD *rec;
2128 // Validate arguments
2129 if (g == NULL || data == NULL || proc == NULL)
2130 {
2131 return;
2132 }
2133
2134 rec = ZeroMalloc(sizeof(RECORD));
2135 rec->Tick = Tick64();
2136 rec->ParseProc = proc;
2137 rec->Data = data;
2138
2139 LockQueue(g->RecordQueue);
2140 {
2141 InsertQueue(g->RecordQueue, rec);
2142 }
2143 UnlockQueue(g->RecordQueue);
2144
2145 Set(g->Event);
2146 }
2147
2148 // Lock the log
LockLog(LOG * g)2149 void LockLog(LOG *g)
2150 {
2151 // Validate arguments
2152 if (g == NULL)
2153 {
2154 return;
2155 }
2156
2157 Lock(g->lock);
2158 }
2159
2160 // Unlock the log
UnlockLog(LOG * g)2161 void UnlockLog(LOG *g)
2162 {
2163 // Validate arguments
2164 if (g == NULL)
2165 {
2166 return;
2167 }
2168
2169 Unlock(g->lock);
2170 }
2171
2172 // Generate the string portion of the log file name from the time and the switching rule
MakeLogFileNameStringFromTick(LOG * g,char * str,UINT size,UINT64 tick,UINT switch_type)2173 void MakeLogFileNameStringFromTick(LOG *g, char *str, UINT size, UINT64 tick, UINT switch_type)
2174 {
2175 UINT64 time;
2176 SYSTEMTIME st;
2177
2178 // Validate arguments
2179 if (str == NULL || g == NULL)
2180 {
2181 return;
2182 }
2183
2184 if (g->CacheFlag)
2185 {
2186 if (g->LastTick == tick &&
2187 g->LastSwitchType == switch_type)
2188 {
2189 StrCpy(str, size, g->LastStr);
2190 return;
2191 }
2192 }
2193
2194 time = TickToTime(tick);
2195 UINT64ToSystem(&st, SystemToLocal64(time));
2196
2197 switch (switch_type)
2198 {
2199 case LOG_SWITCH_SECOND: // Secondly basis
2200 snprintf(str, size, "_%04u%02u%02u_%02u%02u%02u",
2201 st.wYear, st.wMonth, st.wDay, st.wHour, st.wMinute, st.wSecond);
2202 break;
2203
2204 case LOG_SWITCH_MINUTE: // Minutely basis
2205 snprintf(str, size, "_%04u%02u%02u_%02u%02u",
2206 st.wYear, st.wMonth, st.wDay, st.wHour, st.wMinute);
2207 break;
2208
2209 case LOG_SWITCH_HOUR: // Hourly basis
2210 snprintf(str, size, "_%04u%02u%02u_%02u", st.wYear, st.wMonth, st.wDay, st.wHour);
2211 break;
2212
2213 case LOG_SWITCH_DAY: // Daily basis
2214 snprintf(str, size, "_%04u%02u%02u", st.wYear, st.wMonth, st.wDay);
2215 break;
2216
2217 case LOG_SWITCH_MONTH: // Monthly basis
2218 snprintf(str, size, "_%04u%02u", st.wYear, st.wMonth);
2219 break;
2220
2221 default: // Without switching
2222 StrCpy(str, size, "");
2223 break;
2224 }
2225
2226 g->CacheFlag = true;
2227 g->LastTick = tick;
2228 g->LastSwitchType = switch_type;
2229 StrCpy(g->LastStr, sizeof(g->LastStr), str);
2230 }
2231
2232 // Create a log file name
MakeLogFileName(LOG * g,char * name,UINT size,char * dir,char * prefix,UINT64 tick,UINT switch_type,UINT num,char * old_datestr)2233 bool MakeLogFileName(LOG *g, char *name, UINT size, char *dir, char *prefix, UINT64 tick, UINT switch_type, UINT num, char *old_datestr)
2234 {
2235 char tmp[MAX_SIZE];
2236 char tmp2[64];
2237 bool ret = false;
2238 // Validate arguments
2239 if (g == NULL || name == NULL || prefix == NULL || old_datestr == NULL)
2240 {
2241 return false;
2242 }
2243
2244 MakeLogFileNameStringFromTick(g, tmp, sizeof(tmp), tick, switch_type);
2245
2246 if (num == 0)
2247 {
2248 tmp2[0] = 0;
2249 }
2250 else
2251 {
2252 UINT64 max_log_size = GetMaxLogSize();
2253 if (max_log_size == MAX_LOG_SIZE_DEFAULT)
2254 {
2255 snprintf(tmp2, sizeof(tmp2), "~%02u", num);
2256 }
2257 else
2258 {
2259 char tag[32];
2260 char c = '2';
2261 if (max_log_size >= 1000000000ULL)
2262 {
2263 c = '3';
2264 }
2265 else if (max_log_size >= 100000000ULL)
2266 {
2267 c = '4';
2268 }
2269 else if (max_log_size >= 10000000ULL)
2270 {
2271 c = '5';
2272 }
2273 else if (max_log_size >= 1000000ULL)
2274 {
2275 c = '6';
2276 }
2277 else if (max_log_size >= 100000ULL)
2278 {
2279 c = '7';
2280 }
2281 else if (max_log_size >= 10000ULL)
2282 {
2283 c = '8';
2284 }
2285 else if (max_log_size >= 1000ULL)
2286 {
2287 c = '9';
2288 }
2289
2290 StrCpy(tag, sizeof(tag), "~%02u");
2291 tag[3] = c;
2292
2293 snprintf(tmp2, sizeof(tmp2), tag, num);
2294 }
2295 }
2296
2297 if (StrCmp(old_datestr, tmp) != 0)
2298 {
2299 ret = true;
2300 StrCpy(old_datestr, MAX_SIZE, tmp);
2301 }
2302
2303 snprintf(name, size, "%s%s%s%s%s.log", dir,
2304 StrLen(dir) == 0 ? "" : "/",
2305 prefix, tmp, tmp2
2306 );
2307
2308 return ret;
2309 }
2310
2311 // Wait until the log have been flushed
WaitLogFlush(LOG * g)2312 void WaitLogFlush(LOG *g)
2313 {
2314 // Validate arguments
2315 if (g == NULL)
2316 {
2317 return;
2318 }
2319
2320 while (true)
2321 {
2322 UINT num;
2323 LockQueue(g->RecordQueue);
2324 {
2325 num = g->RecordQueue->num_item;
2326 }
2327 UnlockQueue(g->RecordQueue);
2328
2329 if (num == 0)
2330 {
2331 break;
2332 }
2333
2334 Wait(g->FlushEvent, 100);
2335 }
2336 }
2337
2338 // Set the max log size
SetMaxLogSize(UINT64 size)2339 void SetMaxLogSize(UINT64 size)
2340 {
2341 if (size == 0)
2342 {
2343 size = MAX_LOG_SIZE_DEFAULT;
2344 }
2345
2346 logger_max_log_size = size;
2347 }
2348
2349 // Get the max log size
GetMaxLogSize()2350 UINT64 GetMaxLogSize()
2351 {
2352 UINT64 ret = logger_max_log_size;
2353
2354 if (ret == 0)
2355 {
2356 ret = MAX_LOG_SIZE_DEFAULT;
2357 }
2358
2359 return ret;
2360 }
2361
2362 // Logging thread
LogThread(THREAD * thread,void * param)2363 void LogThread(THREAD *thread, void *param)
2364 {
2365 LOG *g;
2366 IO *io;
2367 BUF *b;
2368 bool flag = false;
2369 char current_file_name[MAX_SIZE];
2370 char current_logfile_datename[MAX_SIZE];
2371 bool log_date_changed = false;
2372 // Validate arguments
2373 if (thread == NULL || param == NULL)
2374 {
2375 return;
2376 }
2377
2378 Zero(current_file_name, sizeof(current_file_name));
2379 Zero(current_logfile_datename, sizeof(current_logfile_datename));
2380
2381 g = (LOG *)param;
2382
2383 io = g_foreground ? GetIO4Stdout() : NULL;
2384 b = NewBuf();
2385
2386 #ifdef OS_WIN32
2387
2388 // Lower priority to bottom
2389 MsSetThreadPriorityIdle();
2390
2391 #endif // OS_WIN32
2392
2393 NoticeThreadInit(thread);
2394
2395 while (true)
2396 {
2397 UINT64 s = Tick64();
2398
2399 while (true)
2400 {
2401 if (g_foreground)
2402 {
2403 if (! LogThreadWriteStdout(g, b, io))
2404 {
2405 break;
2406 }
2407 }
2408 else
2409 {
2410 if (! LogThreadWriteGeneral(g, b, &io, &log_date_changed, current_logfile_datename, current_file_name))
2411 {
2412 break;
2413 }
2414 }
2415 }
2416
2417 if (g->Halt)
2418 {
2419 // Break after finishing to save all records
2420 // when the stop flag stood
2421 UINT num;
2422
2423 if (flag == false)
2424 {
2425 #ifdef OS_WIN32
2426 MsSetThreadPriorityRealtime();
2427 #endif // OS_WIN32
2428 flag = true;
2429 }
2430
2431 LockQueue(g->RecordQueue);
2432 {
2433 num = g->RecordQueue->num_item;
2434 }
2435 UnlockQueue(g->RecordQueue);
2436
2437 if (num == 0 || io == NULL)
2438 {
2439 break;
2440 }
2441 }
2442 else
2443 {
2444 Wait(g->Event, 9821);
2445 }
2446 }
2447
2448 if (io != NULL && !g_foreground)
2449 {
2450 FileCloseEx(io, true);
2451 }
2452
2453 FreeBuf(b);
2454 }
2455
LogThreadWriteGeneral(LOG * log_object,BUF * buffer,IO ** io,bool * log_date_changed,char * current_logfile_datename,char * current_file_name)2456 static bool LogThreadWriteGeneral(LOG *log_object, BUF *buffer, IO **io, bool *log_date_changed, char *current_logfile_datename, char *current_file_name)
2457 {
2458 RECORD *rec;
2459 char file_name[MAX_SIZE];
2460 UINT num;
2461
2462 // Retrieve a record from the head of the queue
2463 LockQueue(log_object->RecordQueue);
2464 {
2465 rec = GetNext(log_object->RecordQueue);
2466 num = log_object->RecordQueue->num_item;
2467 }
2468 UnlockQueue(log_object->RecordQueue);
2469
2470 #ifdef OS_WIN32
2471 if (num >= LOG_ENGINE_SAVE_START_CACHE_COUNT)
2472 {
2473 // Raise the priority
2474 Debug("LOG_THREAD: MsSetThreadPriorityRealtime\n");
2475 MsSetThreadPriorityRealtime();
2476 }
2477
2478 if (num < (LOG_ENGINE_SAVE_START_CACHE_COUNT / 2))
2479 {
2480 // Restore the priority
2481 Debug("LOG_THREAD: MsSetThreadPriorityIdle\n");
2482 MsSetThreadPriorityIdle();
2483 }
2484 #endif // OS_WIN32
2485
2486 if (buffer->Size > GetMaxLogSize())
2487 {
2488 // Erase if the size of the buffer is larger than the maximum log file size
2489 ClearBuf(buffer);
2490 }
2491
2492 if (buffer->Size >= LOG_ENGINE_BUFFER_CACHE_SIZE_MAX)
2493 {
2494 // Write the contents of the buffer to the file
2495 if (*io != NULL)
2496 {
2497 if ((log_object->CurrentFilePointer + (UINT64)buffer->Size) > GetMaxLogSize())
2498 {
2499 if (log_object->log_number_incremented == false)
2500 {
2501 log_object->CurrentLogNumber++;
2502 log_object->log_number_incremented = true;
2503 }
2504 }
2505 else
2506 {
2507 if (FileWrite(*io, buffer->Buf, buffer->Size) == false)
2508 {
2509 FileCloseEx(*io, true);
2510 // If it fails to write to the file,
2511 // erase the buffer and give up
2512 ClearBuf(buffer);
2513 *io = NULL;
2514 }
2515 else
2516 {
2517 log_object->CurrentFilePointer += (UINT64)buffer->Size;
2518 ClearBuf(buffer);
2519 }
2520 }
2521 }
2522 }
2523
2524 if (rec == NULL)
2525 {
2526 if (buffer->Size != 0)
2527 {
2528 // Write the contents of the buffer to the file
2529 if (*io != NULL)
2530 {
2531 if ((log_object->CurrentFilePointer + (UINT64)buffer->Size) > GetMaxLogSize())
2532 {
2533 if (log_object->log_number_incremented == false)
2534 {
2535 log_object->CurrentLogNumber++;
2536 log_object->log_number_incremented = true;
2537 }
2538 }
2539 else
2540 {
2541 if (FileWrite(*io, buffer->Buf, buffer->Size) == false)
2542 {
2543 FileCloseEx(*io, true);
2544 // If it fails to write to the file,
2545 // erase the buffer and give up
2546 ClearBuf(buffer);
2547 *io = NULL;
2548 }
2549 else
2550 {
2551 log_object->CurrentFilePointer += (UINT64)buffer->Size;
2552 ClearBuf(buffer);
2553 }
2554 }
2555 }
2556 }
2557
2558 Set(log_object->FlushEvent);
2559 return false;
2560 }
2561
2562 // Generate a log file name
2563 LockLog(log_object);
2564 {
2565 *log_date_changed = MakeLogFileName(log_object, file_name, sizeof(file_name),
2566 log_object->DirName, log_object->Prefix, rec->Tick, log_object->SwitchType, log_object->CurrentLogNumber, current_logfile_datename);
2567
2568 if (*log_date_changed)
2569 {
2570 UINT i;
2571
2572 log_object->CurrentLogNumber = 0;
2573 MakeLogFileName(log_object, file_name, sizeof(file_name),
2574 log_object->DirName, log_object->Prefix, rec->Tick, log_object->SwitchType, 0, current_logfile_datename);
2575 for (i = 0;; i++)
2576 {
2577 char tmp[MAX_SIZE];
2578 MakeLogFileName(log_object, tmp, sizeof(tmp),
2579 log_object->DirName, log_object->Prefix, rec->Tick, log_object->SwitchType, i, current_logfile_datename);
2580
2581 if (IsFileExists(tmp) == false)
2582 {
2583 break;
2584 }
2585 StrCpy(file_name, sizeof(file_name), tmp);
2586 log_object->CurrentLogNumber = i;
2587 }
2588 }
2589 }
2590 UnlockLog(log_object);
2591
2592 if (*io != NULL)
2593 {
2594 if (StrCmp(current_file_name, file_name) != 0)
2595 {
2596 // If a log file is currently opened and writing to another log
2597 // file is needed for this time, write the contents of the
2598 //buffer and close the log file. Write the contents of the buffer
2599 if (*io != NULL)
2600 {
2601 if (*log_date_changed)
2602 {
2603 if ((log_object->CurrentFilePointer + (UINT64)buffer->Size) <= GetMaxLogSize())
2604 {
2605 if (FileWrite(*io, buffer->Buf, buffer->Size) == false)
2606 {
2607 FileCloseEx(*io, true);
2608 ClearBuf(buffer);
2609 *io = NULL;
2610 }
2611 else
2612 {
2613 log_object->CurrentFilePointer += (UINT64)buffer->Size;
2614 ClearBuf(buffer);
2615 }
2616 }
2617 }
2618 // Close the file
2619 FileCloseEx(*io, true);
2620 }
2621
2622 log_object->log_number_incremented = false;
2623
2624 // Open or create a new log file
2625 StrCpy(current_file_name, sizeof(current_file_name), file_name);
2626 *io = FileOpen(file_name, true);
2627 if (*io == NULL)
2628 {
2629 // Create a log file
2630 LockLog(log_object);
2631 {
2632 MakeDir(log_object->DirName);
2633
2634 #ifdef OS_WIN32
2635 Win32SetFolderCompress(log_object->DirName, true);
2636 #endif // OS_WIN32
2637 }
2638 UnlockLog(log_object);
2639 *io = FileCreate(file_name);
2640 log_object->CurrentFilePointer = 0;
2641 }
2642 else
2643 {
2644 // Seek to the end of the log file
2645 log_object->CurrentFilePointer = FileSize64(*io);
2646 FileSeek(*io, SEEK_END, 0);
2647 }
2648 }
2649 }
2650 else
2651 {
2652 // Open or create a new log file
2653 StrCpy(current_file_name, sizeof(current_file_name), file_name);
2654 *io = FileOpen(file_name, true);
2655 if (*io == NULL)
2656 {
2657 // Create a log file
2658 LockLog(log_object);
2659 {
2660 MakeDir(log_object->DirName);
2661 #ifdef OS_WIN32
2662 Win32SetFolderCompress(log_object->DirName, true);
2663 #endif // OS_WIN32
2664 }
2665 UnlockLog(log_object);
2666 *io = FileCreate(file_name);
2667 log_object->CurrentFilePointer = 0;
2668 if (*io == NULL)
2669 {
2670 //Debug("Logging.c: SleepThread(30);\n");
2671 SleepThread(30);
2672 }
2673 }
2674 else
2675 {
2676 // Seek to the end of the log file
2677 log_object->CurrentFilePointer = FileSize64(*io);
2678 FileSeek(*io, SEEK_END, 0);
2679 }
2680
2681 log_object->log_number_incremented = false;
2682 }
2683
2684 // Write the contents of the log to the buffer
2685 WriteRecordToBuffer(buffer, rec);
2686
2687 // Release the memory of record
2688 Free(rec);
2689
2690 return (*io != NULL);
2691 }
2692
LogThreadWriteStdout(LOG * log_object,BUF * buffer,IO * io)2693 static bool LogThreadWriteStdout(LOG *log_object, BUF *buffer, IO *io)
2694 {
2695 RECORD *rec;
2696
2697 // Retrieve a record from the head of the queue
2698 LockQueue(log_object->RecordQueue);
2699 {
2700 rec = GetNext(log_object->RecordQueue);
2701 }
2702 UnlockQueue(log_object->RecordQueue);
2703
2704 if (rec == NULL)
2705 {
2706 Set(log_object->FlushEvent);
2707 return false;
2708 }
2709
2710 ClearBuf(buffer);
2711 WriteRecordToBuffer(buffer, rec);
2712 if (!FileWrite(io, buffer->Buf, buffer->Size))
2713 {
2714 ClearBuf(buffer);
2715 }
2716 Free(rec);
2717
2718 return true;
2719 }
2720
GetIO4Stdout()2721 static IO *GetIO4Stdout()
2722 {
2723 #ifndef UNIX
2724 return NULL;
2725 #else // UNIX
2726 static IO IO4Stdout =
2727 {
2728 .Name = {0},
2729 .NameW = {0},
2730 .pData = NULL,
2731 .WriteMode = true,
2732 .HamMode = false,
2733 .HamBuf = NULL,
2734 };
2735
2736 if (!g_foreground)
2737 {
2738 return NULL;
2739 }
2740
2741 IO4Stdout.pData = GetUnixio4Stdout();
2742
2743 return &IO4Stdout;
2744 #endif // UNIX
2745 }
2746
2747 // Write the contents of the log to the buffer
WriteRecordToBuffer(BUF * b,RECORD * r)2748 void WriteRecordToBuffer(BUF *b, RECORD *r)
2749 {
2750 UINT64 time;
2751 char time_str[MAX_SIZE];
2752 char date_str[MAX_SIZE];
2753 char *s;
2754 // Validate arguments
2755 if (b == NULL || r == NULL)
2756 {
2757 return;
2758 }
2759
2760 // Get the time
2761 time = SystemToLocal64(TickToTime(r->Tick));
2762
2763 // Convert a time to a string
2764 GetDateStr64(date_str, sizeof(date_str), time);
2765 GetTimeStrMilli64(time_str, sizeof(time_str), time);
2766
2767 if (r->ParseProc != PacketLogParseProc)
2768 {
2769 // Other than packet log
2770 WriteBuf(b, date_str, StrLen(date_str));
2771 WriteBuf(b, " ", 1);
2772 WriteBuf(b, time_str, StrLen(time_str));
2773 WriteBuf(b, " ", 1);
2774 }
2775 else
2776 {
2777 // Packet log
2778 WriteBuf(b, date_str, StrLen(date_str));
2779 WriteBuf(b, ",", 1);
2780 WriteBuf(b, time_str, StrLen(time_str));
2781 WriteBuf(b, ",", 1);
2782 }
2783
2784 // Output text
2785 s = r->ParseProc(r);
2786 WriteBuf(b, s, StrLen(s));
2787 Free(s);
2788
2789 WriteBuf(b, "\r\n", 2);
2790 }
2791
2792 // End of logging
FreeLog(LOG * g)2793 void FreeLog(LOG *g)
2794 {
2795 RECORD *rec;
2796 // Validate arguments
2797 if (g == NULL)
2798 {
2799 return;
2800 }
2801
2802 // Halting flag
2803 g->Halt = true;
2804 Set(g->Event);
2805
2806 WaitThread(g->Thread, INFINITE);
2807 ReleaseThread(g->Thread);
2808
2809 DeleteLock(g->lock);
2810 Free(g->DirName);
2811 Free(g->Prefix);
2812
2813 // Release the unprocessed record if it remains
2814 // (It should not remain here)
2815 while (rec = GetNext(g->RecordQueue))
2816 {
2817 char *s = rec->ParseProc(rec);
2818 Free(s);
2819 Free(rec);
2820 }
2821 ReleaseQueue(g->RecordQueue);
2822
2823 ReleaseEvent(g->Event);
2824 ReleaseEvent(g->FlushEvent);
2825
2826 Free(g);
2827 }
2828
2829 // Start a new logging
NewLog(char * dir,char * prefix,UINT switch_type)2830 LOG *NewLog(char *dir, char *prefix, UINT switch_type)
2831 {
2832 LOG *g;
2833
2834 g = ZeroMalloc(sizeof(LOG));
2835 g->lock = NewLock();
2836 g->DirName = CopyStr(dir == NULL ? "" : dir);
2837 g->Prefix = CopyStr(prefix == NULL ? "log" : prefix);
2838 g->SwitchType = switch_type;
2839 g->RecordQueue = NewQueue();
2840 g->Event = NewEvent();
2841 g->FlushEvent = NewEvent();
2842
2843 g->Thread = NewThread(LogThread, g);
2844
2845 WaitThreadInit(g->Thread);
2846
2847 return g;
2848 }
2849
2850
2851