Improve AngelBeats! to keep state across sessions, also changing "perf on master

looking for new angel" to "every X seconds".


git-svn-id: http://opensvn.csie.org/pttbbs/trunk@5803 63ad8ddf-47c3-0310-b6dd-a9e9d9715204

3 files changed, 212 insertions, 122 deletions

diff --git a/pttbbs/daemon/angelbeats/angel_perf.py b/pttbbs/daemon/angelbeats/angel_perf.py
index d33f79e6..da5d5151 100755
--- a/pttbbs/daemon/angelbeats/angel_perf.py
+++ b/pttbbs/daemon/angelbeats/angel_perf.py
@@ -17,41 +17,32 @@ REPORT_SAMPLE_STAT = False
 
 PREFIX_DOC = '''== 本週小天使查翅膀建議名單 (系統自動產生: %s) ==
 
-說明: 天使公會在新小主人找天使時即時統計所有的小天使狀態，
+說明: 天使公會每十分鐘會統計一次所有的小天使狀態，
       確認 (1) 小天使當時是否在線上 (2) 神諭呼叫器是否停收/關閉。
       依據天使之書對於查翅膀的定義「抽查到太多次都沒開啟呼叫器」，
       若上線時間過少或是關呼叫時間過高則會出現在每週統計的名單中，
-      以供品管及大天使參考。 ([關呼叫] 現在為「關閉」與「停收」的合計)
+      以供品管及大天使參考。
 
   ** 為幫助理解名單產生方法及數字意義，簡單例子如下: 若有小天使 ABC 三名,
-     A 在線上開呼叫, B 在線上但關呼叫, C 不在線上:
-     某日早上 10:20 有某使用者(無天使)按下 hh 找新天使，系統就會記錄:
-                     [ID] [線上] [關呼叫] 
-                     A    1      0        
-                     B    1      1        
-                     C    0      0        
-              10:21 有一使用者換天使；但為避免有人洗數字，所以統計
-                    每10分鐘最多一次；因此這次呼叫不會改變統計結果
-	      10:30 十分鐘已到，系統已可再次統計 (但不主動執行)
-              10:31 該使用者與小天使A在互丟水球 (丟水球不統計)
-              10:32 C 上線了 (也還不統計 - 只在有人找/換天使才算)
-              10:33 A 改為停收 (也還不統計 - 只在有人找/換天使才算)
-              10:35 又有一使用者找新天使，系統更改記錄如下:
-	            (ABC都在線上，AB關呼叫，C開呼叫)
-		     [ID] [線上] [關呼叫] 
-		     A    1+1=2  0+1=1    
-		     B    1+1=2  1+1=2    
-		     C    0+1=1  0+0=0    
-		    且下次可統計時間為 10:45 之後。
+     A 在線上開呼叫, B 在線上但關閉呼叫器, C 不在線上:
+     某日早上 10:30 系統進行統計，系統就會記錄:
+                     [ID] [線上] [停收] [關閉]
+                     A    1      0      0     
+                     B    1      0      1     
+                     C    0      0      0     
+              10:31 使用者與小天使A在互丟水球 (丟水球不統計)
+              10:32 C 上線了 (還不統計 - 十分鐘才算一次)
+              10:33 A 改為停收 (還不統計 - 十分鐘才算一次)
+              10:40 系統再次進行統計，更改記錄如下:
+	            (ABC都在線上，A停收，B關閉，C開呼叫)
+		     [ID] [線上] [停收] [關閉]
+		     A    1+1=2  0+1=1  0+0=0  
+		     B    1+1=2  0+0=0  1+1=2 
+		     C    0+1=1  0+0=0  0+0=0  
+		    且下次統計時間為 10:50。
 
+     換句話說，(數字/6) 就大約是線上/停收/關閉的總小時數。
 ''' % (time.ctime())
-# 小天使名稱後面的數字為該小天使被統計到的次數 (以下稱 SAMPLE 數)，
-# 因為 SAMPLE 數字是有人呼叫時才會更新，且為避免惡意洗數字造成結果不公，
-# 統計每 600 秒最多更新一次(否則有人會趁自己上線開分身狂換小天使)，
-# 所以此數字大略上接近(但不等於)小天使實際上線時間比例。
-#
-# 換句話說，即使為零也不代表此小天使都沒上線過，可能只是上線停留時間都
-# 過短或是上線時都沒有新使用者要呼叫小天使。
 
 def is_lazy(e):
     # 'LAZY'
@@ -61,7 +52,7 @@ def is_lazy(e):
 
 def is_all_reject2(e):
     # 'ALL_REJECT2'
-    '\033[1;31m以下是[關呼叫]統計比例過高([線上]減[關呼叫]小於2)的小天使\033[m'
+    '\033[1;31m以下是關呼叫統計比例過高([線上]減[關閉]與[停收]小於2)的小天使\033[m'
     return (e.pause2 + e.pause1 >= e.sample - 1)
 
 def parse_perf_file(filename):
@@ -101,7 +92,7 @@ def build_badges(max_sample, avg_sample, std_sample, data):
     result = {}
     filters = [is_all_reject2]
     for uid, e in data.items():
-	nick = '%s (線上%d 關呼叫%d)' % (get_nick(uid), e[0], e[1]+e[2])
+	nick = '%s (線上%d 停收%d 關閉%d)' % (get_nick(uid), e[0], e[1], e[2])
 	if DEBUG:
 	    nick += ' {%s/%d/%d/%d}' % (uid, e[0], e[1], e[2])
 	entry = Entry(e[0], e[1], e[2], max_sample, avg_sample, std_sample)
diff --git a/pttbbs/daemon/angelbeats/angelbeats.c b/pttbbs/daemon/angelbeats/angelbeats.c
index 2a2a94e9..a0a32129 100644
--- a/pttbbs/daemon/angelbeats/angelbeats.c
+++ b/pttbbs/daemon/angelbeats/angelbeats.c
@@ -17,7 +17,6 @@
 //    and/or other materials provided with the distribution.
 // --------------------------------------------------------------------------
 // TODO cache report results.
-// TODO able to persist perf data.
 
 #include <stdio.h>
 #include <stdlib.h>
@@ -28,6 +27,10 @@
 #include "bbs.h"
 #include "daemons.h"
 
+#define error(x...) fprintf(stderr, "ERROR: " x)
+#define log(x...) fprintf(stderr, x)
+#define debug(x...) { if(debug) fprintf(stderr, "DEBUG: " x); }
+
 //////////////////////////////////////////////////////////////////////////////
 // configuration
 #ifdef DEBUG
@@ -65,6 +68,11 @@ static int debug = 0;
 #define ANGELBEATS_PERF_OUTPUT_FILE BBSHOME "/log/angel_perf.txt"
 #endif
 
+#ifndef ANGEL_STATE_FILE
+#define ANGEL_STATE_FILE  BBSHOME "/log/angel_state.txt"
+#endif
+#define ANGEL_STATE_VERSION   (1)
+
 //////////////////////////////////////////////////////////////////////////////
 // AngelInfo list operation
 
@@ -80,6 +88,11 @@ typedef struct {
 } PerfData;
 
 typedef struct {
+    time4_t start;
+    int samples;
+} GlobalPerfData;
+
+typedef struct {
     PerfData perf;
     time_t last_activity;   // last known activity from master
     time_t last_assigned;   // last time being assigned with new master
@@ -91,6 +104,10 @@ typedef struct {
 AngelInfo *g_angel_list;
 size_t g_angel_list_capacity, g_angel_list_size;   // capacity and current size
 
+struct timeval g_perf_timer_duration = { .tv_sec = ANGELBEATS_PERF_MIN_PERIOD };
+struct event g_perf_timer_event;
+GlobalPerfData g_perf;
+
 // quick sort stubs
 
 int angel_list_comp_uid(const void *pva, const void *pvb) {
@@ -166,7 +183,7 @@ angel_list_sort() {
 AngelInfo *
 angel_list_add(const char *userid, int uid) {
     AngelInfo *kanade = angel_list_find_by_userid(userid);
-    // printf("adding angel: %s (%s)\n", userid, kanade ? "exist" : "new");
+    debug("adding angel: %s (%s)\n", userid, kanade ? "exist" : "new");
     if (kanade)
         return kanade;
 
@@ -216,27 +233,44 @@ int get_angel_state(const AngelInfo *kanade,
     return logins > 0;
 }
 
+void
+perf_angels() {
+    size_t i;
+    int is_pause, logins;
+    time4_t clk = time4(0);
+    AngelInfo *kanade = g_angel_list;
+
+    debug("%s %s\n", Cdatelite(&clk), __func__);
+    if (!g_perf.start)
+        g_perf.start = clk;
+    g_perf.samples++;
+
+    for (i = 0; i < g_angel_list_size; i++, kanade++) {
+
+        if (!get_angel_state(kanade, &is_pause, &logins))
+            continue;
+
+        kanade->perf.samples++;
+        kanade->perf.pause1 += (is_pause == 1);
+        kanade->perf.pause2 += (is_pause == 2);
+    }
+}
+
 int 
 suggest_online_angel(int master_uid) {
     size_t i;
     int is_pause, logins;
-    int uid = 0, do_perf = 0;
-    static time_t perf_time = 0;
+    int uid = 0;
     time_t clk = time(0);
     int found = 0;
+    AngelInfo *kanade = g_angel_list;
 
 #ifdef ANGELBEATS_ASSIGN_BY_RANDOM
     int random_uids[ANGELBEATS_RANDOM_RANGE];
     int crandom_uids = 0;
 #endif
 
-    if (clk - perf_time > ANGELBEATS_PERF_MIN_PERIOD) {
-        perf_time = clk;
-        do_perf = 1;
-    }
-
-    for (i = 0; i < g_angel_list_size; i++) {
-        AngelInfo *kanade = g_angel_list + i;
+    for (i = 0; i < g_angel_list_size; i++, kanade++) {
 
         // skip the master himself
         if (kanade->uid == master_uid)
@@ -245,32 +279,24 @@ suggest_online_angel(int master_uid) {
         if (!get_angel_state(kanade, &is_pause, &logins))
             continue;
 
-#if   defined(ANGELBEATS_ASSIGN_BY_LAST_ACTIVITY)
-        // select if angel is online and not paused.
-        if (!uid && !is_pause) {
-            uid = kanade->uid;
-            if (found++ < 5) {
-                fprintf(stderr, "%d.%s(masters=%d,assigned=%d,act=%d) ",
-                        found,
-                        kanade->userid, kanade->masters,
-                        (int)(kanade->last_activity - clk),
-                        (int)(kanade->last_assigned - clk));
-            }
-        }
-#elif defined(ANGELBEATS_ASSIGN_BY_RANDOM)
-        if (!uid && !is_pause)
-            random_uids[crandom_uids++] = kanade->uid;
-#endif
+        if (is_pause)
+            continue;
 
+#if defined(ANGELBEATS_ASSIGN_BY_LAST_ACTIVITY)
+        if (!uid)
+            uid = kanade->uid;
 
-        // update perf data; otherwise abort.
-        if (do_perf) {
-            kanade->perf.samples++;
-            kanade->perf.pause1 += (is_pause == 1);
-            kanade->perf.pause2 += (is_pause == 2);
-        } else if (uid) {
+        if (found++ > 5)
             break;
-        }
+        log("%d.%s(masters=%d,act=%d,assigned=%d) ", found,
+            kanade->userid, kanade->masters,
+            (int)(clk - kanade->last_activity),
+            (int)(clk - kanade->last_assigned));
+#elif defined(ANGELBEATS_ASSIGN_BY_RANDOM)
+        random_uids[crandom_uids++] = kanade->uid;
+        if (crandom_uids >= ANGELBEATS_RANDOM_RANGE)
+            break;
+#endif
     }
 #ifdef ANGELBEATS_ASSIGN_BY_RANDOM
     if (crandom_uids > 0) {
@@ -299,8 +325,8 @@ dec_angel_master(int uid) {
     if (!kanade)
         return 0;
     if (kanade->masters == 0) {
-        fprintf(stderr, "warning: trying to decrease angel master "
-                "which was already zero: %d\n", uid);
+        error("trying to decrease angel master "
+              "which was already zero: %d\n", uid);
         return 0;
     }
     kanade->masters--;
@@ -364,7 +390,6 @@ init_angel_list_callback(void *ctx GCC_UNUSED, int uidx, userec_t *u) {
 
     // found an angel?
     if (kanade) {
-        // printf(" * %s -> angel = %s\n", u->userid, xuser.userid);
         kanade->masters++;
     }
     return 1;
@@ -396,17 +421,16 @@ create_angel_report(int myuid, angel_beats_report *prpt) {
 
         // Print state information.
         if (from_cmd) {
-            fprintf(stderr, " - %03zu. %-14s: ", i+1, kanade->userid);
-            fprintf(stderr,
-                    "{samples=%d, pause1=%d, pause2=%d} "
-                    "(masters=%d, logins=%d, activity=%d, assigned=%d)",
-                    kanade->perf.samples, kanade->perf.pause1,
-                    kanade->perf.pause2, kanade->masters, logins,
-                    (int)kanade->last_activity,
-                    (int)kanade->last_assigned);
+            log(" - %03zu. %-14s: ", i+1, kanade->userid);
+            log("{samples=%d, pause1=%d, pause2=%d} "
+                "(masters=%d, logins=%d, activity=%d, assigned=%d)",
+                kanade->perf.samples, kanade->perf.pause1,
+                kanade->perf.pause2, kanade->masters, logins,
+                (int)kanade->last_activity,
+                (int)kanade->last_assigned);
             if (is_pause)
-                fprintf(stderr, " [PAUSE %d]", is_pause);
-            fputc('\n', stderr);
+                log(" [PAUSE %d]", is_pause);
+            log("\n");
         }
 
         // update report numbers
@@ -440,7 +464,6 @@ create_angel_report(int myuid, angel_beats_report *prpt) {
     if (myuid > 0 && (kanade = angel_list_find_by_uid(myuid))) {
         prpt->my_active_masters = kanade->masters;
     }
-    if(from_cmd) fflush(stderr);
     return 0;
 }
 
@@ -473,22 +496,84 @@ void print_dash(FILE *fp, int len, const char *prefix) {
     fputc('\n', fp);
 }
 
+void load_state_data() {
+    int version = -1, i = 0;
+    int activity, assigned;
+    char uid[256];
+    PerfData d;
+    AngelInfo *kanade;
+    FILE *fp = fopen(ANGEL_STATE_FILE, "rt");
+    if (!fp)
+        return;
+
+    if (fscanf(fp, "%d\n", &version) != 1 ||
+        version != ANGEL_STATE_VERSION) {
+        error("Invalid state file (version=%d)\n", version);
+        fclose(fp);
+        return;
+    }
+    fscanf(fp, "%d %d\n", &g_perf.start, &g_perf.samples);
+    while (fscanf(fp, "%s %d %d %d %d %d\n",
+                  uid, &activity, &assigned,
+                  &d.samples, &d.pause1, &d.pause2) == 6) {
+        i++;
+        kanade = angel_list_find_by_userid(uid);
+        if (!kanade)
+            continue;
+        kanade->last_activity = activity;
+        kanade->last_assigned = assigned;
+        memcpy(&kanade->perf, &d, sizeof(d));
+    }
+    log("%s: got %d records.\n", __func__, i);
+    fclose(fp);
+}
+
+void save_state_data() {
+    FILE *fp = fopen(ANGEL_STATE_FILE, "wt");
+    size_t i;
+    AngelInfo *kanade = g_angel_list;
+    if (!fp)
+        return;
+    fprintf(fp, "%d\n%d %d\n", ANGEL_STATE_VERSION, g_perf.start,
+            g_perf.samples);
+    for (i = 0; i < g_angel_list_size; i++, kanade++) {
+        fprintf(fp, "%s %d %d %d %d %d\n",
+                kanade->userid, 
+                (int)kanade->last_activity, (int)kanade->last_assigned,
+                kanade->perf.samples, kanade->perf.pause1, kanade->perf.pause2);
+    }
+    fclose(fp);
+}
+
 void export_perf_data(FILE *fp) {
     size_t i = 0;
     time4_t clk = time4(0);
     AngelInfo *kanade = g_angel_list;
     fprintf(fp, "# Angel Performance Data (%s)\n", Cdatelite(&clk));
+    fprintf(fp, "# Start: %s, Duration: %ld, Count: %d\n",
+            Cdatelite(&g_perf.start), g_perf_timer_duration.tv_sec,
+            g_perf.samples);
     fprintf(fp, "# No. %-*s Sample Pause1 Pause2\n# ", IDLEN, "UserID");
     print_dash(fp, 70, "# ");
     for (i = 0; i < g_angel_list_size; i++, kanade++) {
         fprintf(fp, "%4lu. %-*s %6d %6d %6d\n", i + 1, IDLEN, kanade->userid,
                 kanade->perf.samples, kanade->perf.pause1, kanade->perf.pause2);
-        // reset perf data
-        memset(&kanade->perf, 0, sizeof(kanade->perf));
     }
     print_dash(fp, 70, "# ");
 }
 
+void reset_perf_data() {
+    size_t i;
+    AngelInfo *kanade = g_angel_list;
+    g_perf.start = 0;
+    g_perf.samples = 0;
+
+    for (i = 0; i < g_angel_list_size; i++, kanade++) {
+        memset(&kanade->perf, 0, sizeof(kanade->perf));
+    }
+}
+
+
 //////////////////////////////////////////////////////////////////////////////
 // network libevent
 struct timeval tv = {5, 0};
@@ -500,7 +585,7 @@ static struct event ev_listen, ev_sighup;
 static void
 sighup_cb(int signal GCC_UNUSED, short event GCC_UNUSED, void *arg GCC_UNUSED) {
     time4_t clk = time(0);
-    fprintf(stderr, "%s reload (HUP)\n", Cdatelite(&clk));
+    log("%s %s: reload (HUP)\n", Cdatelite(&clk), __func__);
     init_angel_list();
 }
 
@@ -520,29 +605,28 @@ client_cb(int fd, short event, void *arg) {
     if (data.cb != sizeof(data))
         goto end;
 
-    if (debug) {
-        fprintf(stderr, "%s request: op=%d, mid=%d, aid=%d\n", Cdatelite(&clk),
-                data.operation, data.master_uid, data.angel_uid);
-    }
+    debug("%s request: op=%d, mid=%d, aid=%d\n", Cdatelite(&clk),
+          data.operation, data.master_uid, data.angel_uid);
+
     // solve user ids
     if (data.angel_uid && (uid = getuserid(data.angel_uid)))
         strlcpy(angel_uid, uid, sizeof(angel_uid));
     if (data.master_uid && (uid = getuserid(data.master_uid)))
         strlcpy(master_uid, uid, sizeof(master_uid));
 
-    if (debug) printf("got request: %d\n", data.operation);
+    debug("got request: %d\n", data.operation);
     switch(data.operation) {
         case ANGELBEATS_REQ_INVALID:
-            fprintf(stderr, "%s got invalid request [%s/%s]\n", 
-                    Cdatelite(&clk), master_uid, angel_uid);
+            error("%s got invalid request [%s/%s]\n", 
+                  Cdatelite(&clk), master_uid, angel_uid);
             break;
         case ANGELBEATS_REQ_RELOAD:
-            fprintf(stderr, "%s reload\n", Cdatelite(&clk));
+            log("%s reload\n", Cdatelite(&clk));
             init_angel_list();
             break;
         case ANGELBEATS_REQ_SUGGEST_AND_LINK:
-            fprintf(stderr, "%s request suggest&link from [%s], ", 
-                    Cdatelite(&clk), master_uid);
+            log("%s request suggest&link from [%s], ", 
+                Cdatelite(&clk), master_uid);
             data.angel_uid = suggest_online_angel(data.master_uid);
             if (data.angel_uid > 0) {
                 inc_angel_master(data.angel_uid);
@@ -550,37 +634,38 @@ client_cb(int fd, short event, void *arg) {
                 strlcpy(angel_uid, uid, sizeof(angel_uid));
                 angel_list_sort();
             }
-            fprintf(stderr, "result: [%s]\n", data.angel_uid > 0 ?
-                    angel_uid : "<none>");
+            log("result: [%s]\n", data.angel_uid > 0 ?  angel_uid : "<none>");
             break;
         case ANGELBEATS_REQ_REMOVE_LINK:
-            fprintf(stderr, "%s request remove link by "
-                    "master [%s] to angel [%s]\n",
-                    Cdatelite(&clk), master_uid, angel_uid);
+            log("%s request remove link by "
+                "master [%s] to angel [%s]\n",
+                Cdatelite(&clk), master_uid, angel_uid);
             if (dec_angel_master(data.angel_uid))
                 angel_list_sort();
             break;
         case ANGELBEATS_REQ_HEARTBEAT:
-            fprintf(stderr, "%s update angel activity to [%s]\n",
-                    Cdatelite(&clk), angel_uid);
+            log("%s update angel activity to [%s]\n",
+                Cdatelite(&clk), angel_uid);
             if (touch_angel_activity(data.angel_uid))
                 angel_list_sort();
             break;
         case ANGELBEATS_REQ_EXPORT_PERF:
-            fprintf(stderr, "%s export_perf_data\n", Cdatelite(&clk));
+            log("%s export_perf_data\n", Cdatelite(&clk));
             {
                 FILE *fp = fopen(ANGELBEATS_PERF_OUTPUT_FILE, "at");
                 if (fp) {
                     export_perf_data(fp);
                     fclose(fp);
+                    reset_perf_data();
+                    save_state_data();
                 } else {
-                    fprintf(stderr, "%s ERROR: cannot output perf: %s\n",
-                            Cdatelite(&clk), ANGELBEATS_PERF_OUTPUT_FILE);
+                    error("%s cannot output perf: %s\n",
+                          Cdatelite(&clk), ANGELBEATS_PERF_OUTPUT_FILE);
                 }
             }
             break;
         case ANGELBEATS_REQ_REPORT:
-            fprintf(stderr, "%s report by [%s]\n", Cdatelite(&clk), master_uid);
+            log("%s report by [%s]\n", Cdatelite(&clk), master_uid);
             {
                 angel_beats_report rpt = {0};
                 rpt.cb = sizeof(rpt);
@@ -591,7 +676,7 @@ client_cb(int fd, short event, void *arg) {
             }
             break;
         case ANGELBEATS_REQ_GET_ONLINE_LIST:
-            fprintf(stderr, "%s get_online_uid_list\n", Cdatelite(&clk));
+            log("%s get_online_uid_list\n", Cdatelite(&clk));
             {
                 angel_beats_uid_list list = {0};
                 list.cb = sizeof(list);
@@ -603,8 +688,8 @@ client_cb(int fd, short event, void *arg) {
             }
             break;
         default:
-            fprintf(stderr, "%s UNKNOWN REQUEST (%d)\n", Cdatelite(&clk),
-                    data.operation);
+            error("%s UNKNOWN REQUEST (%d)\n", Cdatelite(&clk),
+                  data.operation);
             break;
     }
     write(fd, &data, sizeof(data));
@@ -622,13 +707,26 @@ listen_cb(int fd, short event GCC_UNUSED, void *arg GCC_UNUSED) {
     if ((cfd = accept(fd, NULL, NULL)) < 0 )
 	return;
 
-    if (debug) printf("accept new connection!\n");
+    debug("accept new connection!\n");
     struct event *ev = malloc(sizeof(struct event));
 
     event_set(ev, cfd, EV_READ, client_cb, ev);
     event_add(ev, &tv);
 }
 
+static void
+perf_timer_cb(int fd GCC_UNUSED, short event GCC_UNUSED, void *arg GCC_UNUSED) {
+    // libevent needs us to do so...
+    evtimer_del(&g_perf_timer_event);
+    evtimer_add(&g_perf_timer_event, &g_perf_timer_duration);
+
+    // Do perf now!
+    perf_angels();
+
+    // Save last state!
+    save_state_data();
+}
+
 int 
 main(int argc, char *argv[]) {
     size_t i;
@@ -655,7 +753,7 @@ main(int argc, char *argv[]) {
 
 	case 'h':
 	default:
-	    fprintf(stderr, "usage: %s [-D] [-i [interface_ip]:port]\n", argv[0]);
+	    log("usage: %s [-D] [-i [interface_ip]:port]\n", argv[0]);
 	    return 1;
 	}
     }
@@ -665,33 +763,34 @@ main(int argc, char *argv[]) {
     chdir(BBSHOME);
     attach_SHM();
 
-    printf("initializing angel list...\n");
+    log("initializing angel list...\n");
     init_angel_list();
+    load_state_data();
     if (go_daemon)
         daemonize(BBSHOME "/run/angelbeats.pid", BBSHOME "/log/angelbeats.log");
 
     if ( (sfd = tobind(iface_ip)) < 0 )
 	return 1;
 
-    fprintf(stderr, "found %zd angels. (cap=%zd)\n", 
-            g_angel_list_size, g_angel_list_capacity);
+    log("found %zd angels. (cap=%zd)\n", 
+        g_angel_list_size, g_angel_list_capacity);
     kanade = g_angel_list;
     for (i = 0; i < g_angel_list_size; i++, kanade++) {
-        fprintf(stderr,
-                "%zu [%s] uid=%d, masters=%d\n", 
-                i+1, 
-                kanade->userid,
-                kanade->uid,
-                kanade->masters);
+        log("%zu [%s] uid=%d, masters=%d\n", 
+            i+1, 
+            kanade->userid,
+            kanade->uid,
+            kanade->masters);
     }
-    if (debug)
-        fprintf(stderr, "suggested angel=%d\n", suggest_online_angel(0));
+    debug("suggested angel=%d\n", suggest_online_angel(0));
 
     event_init();
     event_set(&ev_listen, sfd, EV_READ | EV_PERSIST, listen_cb, &ev_listen);
     event_add(&ev_listen, NULL);
     signal_set(&ev_sighup, SIGHUP, sighup_cb, &ev_sighup);
     signal_add(&ev_sighup, NULL);
+    evtimer_set(&g_perf_timer_event, perf_timer_cb, 0);
+    evtimer_add(&g_perf_timer_event, &g_perf_timer_duration);
     event_dispatch();
     
     return 0;
diff --git a/pttbbs/util/angel.c b/pttbbs/util/angel.c
index 8d799566..0359721d 100644
--- a/pttbbs/util/angel.c
+++ b/pttbbs/util/angel.c
@@ -136,11 +136,11 @@ int generateReport(FILE *fp, AngelRecord *rec, int num_recs, int delete_file) {
 
     appendLogFile(fp, "log/angel_perf.txt",
                   "\n== 本周小天使活動資料記錄 ==\n"
-                  " (說明: Sample 指的是新小主人新找天使時有在線上的次數\n"
+                  " (說明: Start 是開始統計的時間\n"
+                  "        Duration 是幾秒統計一次\n"
+                  "        Sample 指的是每次統計時天使在線上的次數\n"
                   "        Pause1 指的是 Sample 中有幾次神諭呼叫器設停收\n"
-                  "        Pause2 指的是 Sample 中有幾次神諭呼叫器設關閉\n"
-                  "  另外, Sample 每"  STR_ANGELBEATS_PERF_MIN_PERIOD
-                  "秒最多更新一次)\n",
+                  "        Pause2 指的是 Sample 中有幾次神諭呼叫器設關閉)\n",
                   delete_file);
 
     appendLogFile(fp, "log/changeangel.log",