source: trunk/WINDOW/AW_status.cxx

Last change on this file was 19167, checked in by westram, 2 years ago
  • Property svn:eol-style set to native
  • Property svn:keywords set to Author Date Id Revision
File size: 39.1 KB
Line 
1// =============================================================== //
2//                                                                 //
3//   File      : AW_status.cxx                                     //
4//   Purpose   :                                                   //
5//                                                                 //
6//   Institute of Microbiology (Technical University Munich)       //
7//   http://www.arb-home.de/                                       //
8//                                                                 //
9// =============================================================== //
10
11#include <aw_root.hxx>
12#include <aw_question.hxx>
13#include <aw_awars.hxx>
14#include <aw_window.hxx>
15#include "aw_msg.hxx"
16#include "aw_status.hxx"
17#include "aw_preset.hxx"
18
19#include <arbdbt.h>
20#include <arb_strbuf.h>
21#include <arb_sleep.h>
22#include <SigHandler.h>
23
24#include <cerrno>
25#include <cstdarg>
26#include <ctime>
27#include <unistd.h>
28
29using namespace std;
30
31#define FD_SET_TYPE
32
33// Globals
34#define AW_GAUGE_SIZE        40 // length of gauge display (in characters)
35#define AW_GAUGE_GRANULARITY 10000 // how fine the gauge is transported to status (no of steps) [old value = 1000]
36
37#define AW_STATUS_KILL_DELAY       4000             // in ms
38#define AW_STATUS_LISTEN_DELAY     300              // in ms
39#define AW_STATUS_HIDE_DELAY       60               // in sec
40#define AW_STATUS_PIPE_CHECK_DELAY 1000*2           // in ms (a pipe check every 2 seconds)
41
42#define AWAR_STATUS         "tmp/status/"
43#define AWAR_STATUS_TITLE   AWAR_STATUS "title"
44#define AWAR_STATUS_TEXT    AWAR_STATUS "text"
45#define AWAR_STATUS_GAUGE   AWAR_STATUS "gauge"
46#define AWAR_STATUS_ELAPSED AWAR_STATUS "elapsed"
47
48#define AW_MESSAGE_LINES        500
49
50#if defined(DEBUG)
51
52// ARB_LOGGING should always be undefined in SVN version!
53// #define ARB_LOGGING
54// #define TRACE_STATUS // // // enable debug output for status window (which runs forked!)
55// #define TRACE_STATUS_MORE // // enable more debug output
56// #define PIPE_DEBUGGING // // enable debug output for pipes (for write commands)
57
58// Note: basic logging of progress information is done to console
59
60#endif // DEBUG
61
62#if !defined(DEVEL_RELEASE)
63# define FORCE_WEIGHTED_ESTIMATION // see also ../CORE/arb_progress.h@FORCEWEIGHTEDESTIMATION
64#endif
65
66enum StatusCommand {
67    // messages send from status-process to main-process :
68    AW_STATUS_OK    = 0,
69    AW_STATUS_ABORT = 1,
70    // messages send from main-process to status-process :
71    AW_STATUS_CMD_INIT,
72    AW_STATUS_CMD_OPEN,
73    AW_STATUS_CMD_CLOSE,
74    AW_STATUS_CMD_NEW_TITLE,
75    AW_STATUS_CMD_TEXT,
76    AW_STATUS_CMD_GAUGE,
77    AW_STATUS_CMD_MESSAGE
78};
79
80#define AW_EST_BUFFER 5 // size of buffer used to smoothen estimations
81
82struct aw_stg_struct {
83    int        fd_to[2];
84    int        fd_from[2];
85    bool       mode;
86    int        hide;
87    int        hide_delay;                          // in seconds
88    pid_t      pid;
89    bool       is_child;                            // true in status window process
90    int        pipe_broken;
91    int        err_no;
92    AW_window *aws;
93    AW_window *awm;
94    bool       status_initialized;
95    char      *lines[AW_MESSAGE_LINES];
96    bool       need_refresh;                        // if true -> message list needs to refresh
97    time_t     last_refresh_time;
98    time_t     last_message_time;
99    int        local_message;
100    time_t     last_start;                          // time of last status start
101    long       last_est_count;
102    long       last_estimation[AW_EST_BUFFER];
103    long       last_used_est;                       // most recent estimation (overall runtime in seconds)
104};
105
106static aw_stg_struct aw_stg = {
107    { 0, 0 },             // fd_to
108    { 0, 0 },             // fd_from
109    AW_STATUS_OK,         // mode
110    0,                    // hide
111    0,                    // hide_delay
112    0,                    // pid
113    false,                // is_child
114    0,                    // pipe_broken
115    0,                    // errno
116    NULp,                 // aws
117    NULp,                 // awm
118    false,                // status_initialized
119    { NULp, NULp, NULp }, // lines
120    false,                // need_refresh
121    0,                    // last_refresh_time
122    0,                    // last_message_time
123    0,                    // local_message
124    0,                    // last_start
125    0,                    // last_est_count
126    { 0 },                // last_estimation
127    -1,                   // last_used_est
128};
129
130// timeouts :
131
132#define POLL_TIMEOUT 0         // idle wait POLL_TIMEOUT microseconds before returning EOF when polling
133
134#if defined(DEBUG)
135#define WRITE_TIMEOUT 1000      // 1 second for debug version (short because it always reaches timeout inside debugger)
136#else
137#define WRITE_TIMEOUT 10000     // 10 seconds for release
138#endif // DEBUG
139
140static void mark_pipe_broken(int err_no) {
141#if defined(PIPE_DEBUGGING)
142    if (aw_stg.pipe_broken != 0) {
143        fprintf(stderr,
144                "Pipe already broken in mark_pipe_broken(); pipe_broken=%i aw_stg.errno=%i errno=%i\n",
145                aw_stg.pipe_broken, aw_stg.err_no, err_no);
146    }
147
148    fprintf(stderr, "Marking pipe as broken (errno=%i)\n", err_no);
149#endif // PIPE_DEBUGGING
150
151    aw_stg.err_no       = err_no;
152    aw_stg.pipe_broken = 1;
153
154    static bool error_shown = false;
155    if (!error_shown) {
156        fprintf(stderr,
157                "******************************************************************\n"
158                "The connection to the status window was blocked unexpectedly!\n"
159                "This happens if you run the program from inside the debugger\n"
160                "or when the process is blocked longer than %5.2f seconds.\n"
161                "Further communication with the status window is suppressed.\n"
162                "******************************************************************\n"
163                , WRITE_TIMEOUT/1000.0);
164    }
165}
166
167static ssize_t safe_write(int fd, const char *buf, int count) {
168    if (aw_stg.pipe_broken != 0) {
169#if defined(PIPE_DEBUGGING)
170        fprintf(stderr, "pipe is broken -- avoiding write of %i bytes\n", count);
171#endif // PIPE_DEBUGGING
172        return -1;
173    }
174
175    aw_assert(count>0); // write nothing - bad idea
176
177    ssize_t result = -1;
178    {
179        fd_set         set;
180        struct timeval timeout;
181        timeout.tv_sec  = WRITE_TIMEOUT/1000;
182        timeout.tv_usec = WRITE_TIMEOUT%1000;
183
184        FD_ZERO(&set);
185        FD_SET(fd, &set);
186
187        int sel_res = select(fd+1, NULp, &set, NULp, &timeout);
188
189        if (sel_res == -1) {
190            fprintf(stderr, "select (before write) returned error (errno=%i)\n", errno);
191            exit(EXIT_FAILURE);
192        }
193
194        bool pipe_would_block = !FD_ISSET(fd, &set);
195
196#if defined(PIPE_DEBUGGING)
197        fprintf(stderr, "select returned %i, pipe_would_block=%i (errno=%i)\n",
198                sel_res, int(pipe_would_block), errno);
199
200        if (pipe_would_block) {
201            fprintf(stderr, "  Avoiding to write to pipe (because it would block!)\n");
202        }
203        else {
204            fprintf(stderr, "  Write %i bytes to pipe.\n", count);
205        }
206#endif // PIPE_DEBUGGING
207
208        if (!pipe_would_block) {
209            result = write(fd, buf, count);
210        }
211    }
212
213    if (result<0) {
214        mark_pipe_broken(errno);
215    }
216    else if (result != count) {
217#if defined(PIPE_DEBUGGING)
218        fprintf(stderr, "write wrote %i bytes instead of %i as requested.\n", result, count);
219#endif // PIPE_DEBUGGING
220        mark_pipe_broken(0);
221    }
222
223    return result;
224}
225
226static void aw_status_write(int fd, int cmd) {
227    char buf = cmd;
228    safe_write(fd, &buf, 1);
229}
230
231static int aw_status_read_byte(int fd, int poll_flag) {
232    /* read one byte from the pipe,
233     * if poll ==1 then don't wait for any data, but return EOF */
234    int erg;
235    unsigned char buffer[2];
236
237    if (poll_flag) {
238        fd_set         set;
239        struct timeval timeout;
240        timeout.tv_sec  = POLL_TIMEOUT/1000;
241        timeout.tv_usec = POLL_TIMEOUT%1000;
242
243        FD_ZERO (&set);
244        FD_SET (fd, &set);
245
246        erg = select(FD_SETSIZE, FD_SET_TYPE &set, NULp, NULp, &timeout);
247        if (erg == 0) return EOF;
248    }
249    erg = read(fd, (char *)&(buffer[0]), 1);
250    if (erg<=0) {
251        //      process died
252        fprintf(stderr, "father died, now i kill myself\n");
253        exit(EXIT_FAILURE);
254    }
255    return buffer[0];
256}
257
258static int aw_status_read_int(int fd, int poll_flag) {
259    /* read one integer from the pipe,
260     * if poll ==1 then don't wait for any data, but return EOF */
261
262    int erg;
263
264    if (poll_flag) {
265        fd_set set;
266        struct timeval timeout;
267        timeout.tv_sec  = POLL_TIMEOUT/1000;
268        timeout.tv_usec = POLL_TIMEOUT%1000;
269
270        FD_ZERO (&set);
271        FD_SET (fd, &set);
272
273        erg = select(FD_SETSIZE, FD_SET_TYPE &set, NULp, NULp, &timeout);
274        if (erg == 0) return EOF;
275    }
276    union {
277        unsigned char buffer[sizeof(int)+1];
278        int as_int;
279    } input;
280
281    erg = read(fd, input.buffer, sizeof(int));
282    if (erg<=0) { // process died
283        fprintf(stderr, "father died, now i kill myself\n");
284        exit(EXIT_FAILURE);
285    }
286    return input.as_int;
287}
288
289static int aw_status_read_command(int fd, int poll_flag, char*& str, int *gaugePtr = NULp) {
290    char buffer[1024];
291    int  cmd = aw_status_read_byte(fd, poll_flag);
292
293    if (cmd == AW_STATUS_CMD_TEXT ||
294            cmd == AW_STATUS_CMD_OPEN ||
295            cmd == AW_STATUS_CMD_NEW_TITLE ||
296            cmd == AW_STATUS_CMD_MESSAGE) {
297        char *p = buffer;
298        int c;
299        for (
300             c = aw_status_read_byte(fd, 0);
301             c;
302             c = aw_status_read_byte(fd, 0)) {
303            *(p++) = c;
304        }
305        *(p++) = c;
306
307        str = strdup(buffer);
308    }
309    else if (cmd == AW_STATUS_CMD_GAUGE) {
310        int gauge = aw_status_read_int(fd, 0);
311        if (gaugePtr) *gaugePtr = gauge;
312
313        char *p = buffer;
314        int   i = 0;
315
316        int rough_gauge = (gauge*AW_GAUGE_SIZE)/AW_GAUGE_GRANULARITY;
317        for (; i<rough_gauge && i<AW_GAUGE_SIZE; ++i) *p++ = '*';
318        for (; i<AW_GAUGE_SIZE; ++i) *p++ = '-';
319
320        if (rough_gauge<AW_GAUGE_SIZE) {
321            int fine_gauge = (gauge*AW_GAUGE_SIZE*4)/AW_GAUGE_GRANULARITY;
322            buffer[rough_gauge]  = "-\\|/"[fine_gauge%4];
323        }
324
325        *= 0;
326        str = strdup(buffer);
327    }
328    else {
329        str = NULp;
330    }
331    return cmd;
332}
333
334static void aw_status_check_pipe() {
335    if (getppid() <= 1) {
336#if defined(TRACE_STATUS)
337        fprintf(stderr, "Terminating status process.\n");
338#endif // TRACE_STATUS
339        exit(EXIT_FAILURE);
340    }
341}
342
343static void aw_status_wait_for_open(int fd) {
344    char *str = NULp;
345    int   cmd;
346    int   erg;
347
348    for (cmd = 0; cmd != AW_STATUS_CMD_INIT;) {
349        for (erg = 0; !erg;) {
350            struct timeval timeout;
351            timeout.tv_sec  = AW_STATUS_PIPE_CHECK_DELAY / 1000;
352            timeout.tv_usec = AW_STATUS_PIPE_CHECK_DELAY % 1000;
353
354            fd_set set;
355
356            FD_ZERO (&set);
357            FD_SET (fd, &set);
358
359#if defined(TRACE_STATUS)
360            fprintf(stderr, "Waiting for status open command..\n"); fflush(stderr);
361#endif // TRACE_STATUS
362            erg = select(FD_SETSIZE, FD_SET_TYPE &set, NULp, NULp, &timeout);
363            if (!erg) aw_status_check_pipe();   // time out
364        }
365        freenull(str);
366        cmd = aw_status_read_command(fd, 0, str);
367    }
368    aw_stg.mode = AW_STATUS_OK;
369    freenull(str);
370
371#if defined(TRACE_STATUS)
372    fprintf(stderr, "OK got status open command!\n"); fflush(stderr);
373#endif // TRACE_STATUS
374}
375
376
377static unsigned aw_status_timer_hide_event(AW_root *) {
378    if (aw_stg.hide) {
379        aw_stg.aws->show();
380        aw_stg.hide = 0;
381    }
382    return 0; // do not recall
383}
384
385static void aw_status_hide(AW_window *aws) {
386    aw_stg.hide = 1;
387    aws->hide();
388
389    // install timer event
390    aws->get_root()->add_timed_callback(aw_stg.hide_delay*1000, makeTimedCallback(aw_status_timer_hide_event));
391
392    // increase hide delay for next press of hide button
393    if (aw_stg.hide_delay < (60*60)) { // max hide delay is 1 hour
394        aw_stg.hide_delay *= 3; // initial: 60sec -> 3min -> 9min -> 27min -> 60min (max)
395    }
396    else {
397        aw_stg.hide_delay = 60*60;
398    }
399}
400
401
402static unsigned aw_status_timer_event(AW_root *awr) {
403#if defined(TRACE_STATUS_MORE)
404    fprintf(stderr, "in aw_status_timer_event\n"); fflush(stdout);
405#endif // TRACE_STATUS_MORE
406    if (aw_stg.mode == AW_STATUS_ABORT) {
407        int action = aw_question(NULp,
408                                 "Couldn't quit properly in time.\n"
409                                 "Now you can either\n"
410                                 "- wait again (recommended),\n"
411                                 "- kill the whole application(!) or\n"
412                                 "- continue.",
413                                 "Wait again,Kill application!,Continue");
414
415        switch (action) {
416            case 0:
417                break;
418            case 1: {
419                char buf[255];
420                sprintf(buf, "kill -9 %i", aw_stg.pid);
421                aw_message_if(GBK_system(buf));
422                exit(EXIT_SUCCESS);
423            }
424            case 2: {
425                char *title    = awr->awar(AWAR_STATUS_TITLE)->read_string();
426                char *subtitle = awr->awar(AWAR_STATUS_TEXT)->read_string();
427
428                aw_message(GBS_global_string("If you think the process should be made abortable,\n"
429                                             "please send the following information to devel@arb-home.de:\n"
430                                             "\n"
431                                             "Calculation not abortable from status window.\n"
432                                             "Title:    %s\n"
433                                             "Subtitle: %s\n",
434                                             title, subtitle));
435                aw_stg.mode = AW_STATUS_OK;
436
437                free(subtitle);
438                free(title);
439                break;
440            }
441        }
442    }
443    return 0; // do not recall
444}
445
446static void aw_status_kill(AW_window *aws) {
447    if (aw_stg.mode == AW_STATUS_ABORT) {
448        aw_status_timer_event(aws->get_root());
449        if (aw_stg.mode == AW_STATUS_OK) { // continue
450            return;
451        }
452    }
453    else {
454        if (!aw_ask_sure("aw_status_kill", "Are you sure to abort running calculation?")) {
455            return; // don't abort
456        }
457        aw_stg.mode = AW_STATUS_ABORT;
458    }
459    aw_status_write(aw_stg.fd_from[1], aw_stg.mode);
460
461    if (aw_stg.mode == AW_STATUS_ABORT) {
462#if defined(TRACE_STATUS_MORE)
463        fprintf(stderr, "add aw_status_timer_event with delay = %i\n", AW_STATUS_KILL_DELAY); fflush(stdout);
464#endif // TRACE_STATUS_MORE
465        aws->get_root()->add_timed_callback(AW_STATUS_KILL_DELAY, makeTimedCallback(aw_status_timer_event)); // install timer event
466    }
467}
468
469static void aw_refresh_tmp_message_display(AW_root *awr) {
470    GBS_strstruct msgs(AW_MESSAGE_LINES*60);
471
472    for (int i = AW_MESSAGE_LINES-1; i>=0; i--) {
473        if (aw_stg.lines[i]) {
474            msgs.cat(aw_stg.lines[i]);
475            msgs.put('\n');
476        }
477    };
478
479    awr->awar(AWAR_ERROR_MESSAGES)->write_string(msgs.get_data());
480
481    aw_stg.need_refresh      = false;
482    aw_stg.last_refresh_time = aw_stg.last_message_time;
483}
484
485static void aw_insert_message_in_tmp_message_delayed(const char *message) {
486    free(aw_stg.lines[0]);
487    for (int i = 1; i< AW_MESSAGE_LINES; i++) {
488        aw_stg.lines[i-1] = aw_stg.lines[i];
489    };
490
491    time_t      t    = time(NULp);
492    struct tm  *lt   = localtime(&t);
493    const char *lf   = strchr(message, '\n');
494    char       *copy = NULp;
495
496    if (lf) { // contains linefeeds
497        const int indentation = 10;
498        int       count       = 1;
499
500        while (lf) { lf = strchr(lf+1, '\n'); ++count; }
501
502        int newsize = strlen(message)+count*indentation+1;
503        ARB_alloc(copy, newsize);
504
505        lf       = strchr(message, '\n');
506        char *cp = copy;
507        while (lf) {
508            int len  = lf-message;
509            memcpy(cp, message, len+1);
510            cp      += len+1;
511            memset(cp, ' ', indentation);
512            cp      += indentation;
513
514            message = lf+1;
515            lf      = strchr(message, '\n');
516        }
517
518        strcpy(cp, message);
519
520        message = copy;
521    }
522
523    aw_stg.lines[AW_MESSAGE_LINES-1] = GBS_global_string_copy("%02i:%02i.%02i  %s",
524                                                              lt->tm_hour, lt->tm_min, lt->tm_sec,
525                                                              message);
526    aw_stg.last_message_time         = t;
527    free(copy);
528
529    aw_stg.need_refresh = true;
530}
531
532static void aw_insert_message_in_tmp_message(AW_root *awr, const char *message) {
533    aw_insert_message_in_tmp_message_delayed(message);
534    aw_refresh_tmp_message_display(awr);
535}
536
537#define MAX_SEC_WIDTH     7 // max width reported from sec2disp
538#define MAX_SEC_WIDTH_STR stringize_pscan(MAX_SEC_WIDTH)
539
540inline const char *sec2disp(long seconds) { // @@@ pass seconds as double (=return value from difftime)
541    static char buffer[50];
542
543    if (seconds<0) seconds = 0;
544    if (seconds<100) {
545        sprintf(buffer, "%li sec", seconds);
546    }
547    else {
548        long minutes = (seconds+30)/60;
549
550        if (minutes<60) {
551            sprintf(buffer, "%li min", minutes);
552        }
553        else {
554            long hours = minutes/60;
555            if (hours<24) {
556                minutes = minutes%60;
557                if (minutes == 0 && hours<10) sprintf(buffer, "%li hour%s", hours, plural(hours));
558                else                          sprintf(buffer, "%lih:%02lim", hours, minutes);
559            }
560            else {
561                long days = hours/24;
562                if (days<7) {
563                    hours = hours%24;
564                    if (hours == 0) sprintf(buffer, "%li day%s", days, plural(days));
565                    else            sprintf(buffer, "%lid:%02lih", days, hours);
566                }
567                else {
568                    long weeks = days/7;
569                    if (days<31) {
570                        days = days%7;
571                        if (days == 0) sprintf(buffer, "%li week%s", weeks, plural(weeks));
572                        else           sprintf(buffer, "%liw:%02lid", weeks, days);
573                    }
574                    else {
575                        const double MEAN_MONTH_DAYS = 365/12.0;
576                        long         months          = days/MEAN_MONTH_DAYS;
577                        if (days<365) {
578                            days  = days - long(months*MEAN_MONTH_DAYS);
579                            weeks = days/7;
580                            if (weeks == 0) {
581                                if (months == 1) strcpy(buffer, "1 month");
582                                else             sprintf(buffer, "%li mon", months);
583                            }
584                            else sprintf(buffer, "%liM:%02liw", months, weeks);
585                        }
586                        else {
587                            long years = days/365;
588                            days       = days%365;
589                            months     = days/MEAN_MONTH_DAYS;
590
591                            if (months == 0) sprintf(buffer, "%li year%s", years, plural(years));
592                            else             sprintf(buffer, "%liy:%02liM", years, months);
593                        }
594                    }
595                }
596            }
597        }
598    }
599    arb_assert(strlen(buffer)<=MAX_SEC_WIDTH);
600    return buffer;
601}
602
603
604static time_t status_started;   // @@@ later use 'aw_stg.last_start' instead!
605static bool   timer_ok = false; // @@@ put a similar flag into 'aw_stg'!
606
607enum LogLevel {
608    LOG_ALWAYS,
609    LOG_ALWAYS_RESET_ONCE_LIMITS,
610    LOG_ALWAYS_WITH_ESTIMATION,
611    LOG_ONCE_PER_SECOND,
612    LOG_ONCE_PER_MINUTE_WITH_ESTIMATION,
613    LOG_ONCE_PER_15_MINUTES_WITH_ESTIMATION,
614};
615
616inline const char *readableTime(const time_t& t) {
617    char *timestr = ctime(&t);
618    char *nl      = strchr(timestr, '\n');
619    if (nl) nl[0] = 0; // cut off LF
620    return timestr;
621}
622
623inline void LOG_STATUS(const char *txt1, const char *txt2, LogLevel level) { // @@@ rename
624    time_t now;
625    bool   hide = false;
626
627    if (time(&now) != -1 && timer_ok) {
628        static time_t last_minute = 0;
629        static time_t last_second = 0;
630
631        if (level == LOG_ONCE_PER_SECOND) {
632            double since_last_second      = difftime(now, last_second);
633            if (since_last_second<1) hide = true;
634            else   last_second            = now;
635        }
636        else if (level == LOG_ONCE_PER_MINUTE_WITH_ESTIMATION) {
637            double since_last_minute       = difftime(now, last_minute);
638            if (since_last_minute<60) hide = true;
639            else   last_minute             = now;
640        }
641        else if (level == LOG_ONCE_PER_15_MINUTES_WITH_ESTIMATION) {
642            double since_last_minute            = difftime(now, last_minute);
643            if (since_last_minute<(15*60)) hide = true;
644            else   last_minute                  = now;
645        }
646        else if (level == LOG_ALWAYS_RESET_ONCE_LIMITS) {
647            last_second = 0;   // used to show subtitles
648            last_minute = now; // used to show progress %
649        }
650
651        if (!hide) {
652            const char *nowstr      = readableTime(now);
653            double      sec_elapsed = difftime(now, status_started);
654            const char *elapsed     = sec2disp(sec_elapsed);
655
656            fprintf(stderr, "[ %s - %" MAX_SEC_WIDTH_STR "s ", nowstr, elapsed);
657
658            // show estimation?
659            if (level == LOG_ONCE_PER_MINUTE_WITH_ESTIMATION     ||
660                level == LOG_ONCE_PER_15_MINUTES_WITH_ESTIMATION ||
661                level == LOG_ALWAYS_WITH_ESTIMATION)
662            {
663                if (aw_stg.last_used_est != -1) {
664                    time_t finish = status_started + aw_stg.last_used_est; // estimated finish time
665                    // @@@ move functionality above into a global function 'time_t addtime(time_t t0, double diffsec) - opposed to difftime()
666
667                    double      sec_ahead = aw_stg.last_used_est - sec_elapsed;
668                    const char *finstr    = readableTime(finish);
669                    const char *ahead     = sec2disp(sec_ahead);
670
671                    fprintf(stderr, "| Rest: %" MAX_SEC_WIDTH_STR "s - %s ", ahead, finstr);
672                }
673            }
674
675            fputc(']', stderr);
676        }
677    }
678    else {
679        fputs("[unknown time + duration]", stderr);
680    }
681    if (!hide) {
682        fputc(' ', stderr);
683        fputs(txt1, stderr);
684        fputs(txt2, stderr);
685        fputc('\n', stderr);
686    }
687}
688
689#ifdef ARB_LOGGING
690static void aw_status_append_to_log(const char* str) {
691    static const char *logname = 0;
692    if (!logname) {
693        logname = GBS_global_string_copy("%s/arb.log", GB_getenvHOME());
694    }
695
696    int fd           = open(logname, O_WRONLY|O_APPEND);
697    if (fd == -1) fd = open(logname, O_CREAT|O_WRONLY|O_APPEND, S_IWUSR | S_IRUSR);
698    if (fd == -1) return;
699
700    write(fd, str, strlen(str));
701    write(fd, "\n", 1);
702    close(fd);
703}
704#endif
705
706
707static unsigned aw_status_timer_listen_event(AW_root *awr) {
708    static int  delay      = AW_STATUS_LISTEN_DELAY;
709    int         cmd;
710    char       *str        = NULp;
711    int         gaugeValue = 0;
712
713#if defined(TRACE_STATUS_MORE)
714    fprintf(stderr, "in aw_status_timer_listen_event (aw_stg.is_child=%i)\n", (int)aw_stg.is_child); fflush(stdout);
715#endif // TRACE_STATUS_MORE
716
717    if (aw_stg.need_refresh && aw_stg.last_refresh_time != aw_stg.last_message_time) {
718        aw_refresh_tmp_message_display(awr); // force refresh each second
719    }
720
721    cmd = aw_status_read_command(aw_stg.fd_to[0], 1, str, &gaugeValue);
722    if (cmd == EOF) {
723        aw_status_check_pipe();
724        delay = delay*3/2+1;      // wait a longer time
725        if (aw_stg.need_refresh) aw_refresh_tmp_message_display(awr); // and do the refresh here
726    }
727    else {
728        delay = delay*2/3+1;       // shorten time  (was *2/3+1)
729    }
730    char *gauge = NULp;
731    while (cmd != EOF) {
732        switch (cmd) {
733            case AW_STATUS_CMD_OPEN:
734#if defined(TRACE_STATUS)
735                fprintf(stderr, "received AW_STATUS_CMD_OPEN\n"); fflush(stdout);
736#endif // TRACE_STATUS
737                aw_stg.mode           = AW_STATUS_OK;
738                aw_stg.last_start     = time(NULp);
739                aw_stg.last_est_count = 0;
740                aw_stg.last_used_est  = -1;
741                aw_stg.aws->show();
742                aw_stg.hide           = 0;
743                aw_stg.hide_delay     = AW_STATUS_HIDE_DELAY;
744
745                timer_ok = time(&status_started) != -1;
746                LOG_STATUS("start /", str, LOG_ALWAYS_RESET_ONCE_LIMITS);
747
748#if defined(ARB_LOGGING)
749                aw_status_append_to_log("----------------------------");
750#endif // ARB_LOGGING
751                awr->awar(AWAR_STATUS_TITLE)->write_string(str);
752                awr->awar(AWAR_STATUS_GAUGE)->write_string("----------------------------");
753                awr->awar(AWAR_STATUS_TEXT)->write_string("");
754                awr->awar(AWAR_STATUS_ELAPSED)->write_string("");
755                cmd = EOF;
756                freenull(str);
757                continue;       // break while loop
758
759            case AW_STATUS_CMD_CLOSE:
760                if (aw_stg.mode == AW_STATUS_ABORT) {
761                    LOG_STATUS("user abort", "", LOG_ALWAYS);
762                }
763                LOG_STATUS("end   \\", awr->awar(AWAR_STATUS_TITLE)->read_char_pntr(), LOG_ALWAYS);
764#if defined(TRACE_STATUS)
765                fprintf(stderr, "received AW_STATUS_CMD_CLOSE\n"); fflush(stdout);
766#endif // TRACE_STATUS
767                aw_stg.mode = AW_STATUS_OK;
768                aw_stg.aws->hide();
769                break;
770
771            case AW_STATUS_CMD_TEXT:
772#if defined(FORCE_WEIGHTED_ESTIMATION)
773                if (strcmp(str, "REQUEST_ESTIMATION") == 0) {
774                    if (aw_stg.last_used_est != -1) { // suppress if not possible (yet)
775                        LOG_STATUS("forced estimation", "", LOG_ALWAYS_WITH_ESTIMATION);
776                    }
777                    break;
778                }
779#endif
780                LOG_STATUS("       ", str, LOG_ONCE_PER_SECOND);
781#if defined(TRACE_STATUS)
782                fprintf(stderr, "received AW_STATUS_CMD_TEXT\n"); fflush(stdout);
783#endif // TRACE_STATUS
784#if defined(ARB_LOGGING)
785                aw_status_append_to_log(str);
786#endif // ARB_LOGGING
787                awr->awar(AWAR_STATUS_TEXT)->write_string(str);
788                break;
789
790            case AW_STATUS_CMD_NEW_TITLE:
791                LOG_STATUS("start+/", str, LOG_ALWAYS_RESET_ONCE_LIMITS);
792#if defined(TRACE_STATUS)
793                fprintf(stderr, "received AW_STATUS_CMD_NEW_TITLE\n"); fflush(stdout);
794#endif // TRACE_STATUS
795#if defined(ARB_LOGGING)
796                aw_status_append_to_log(str);
797#endif // ARB_LOGGING
798                awr->awar(AWAR_STATUS_TITLE)->write_string(str);
799                break;
800
801            case AW_STATUS_CMD_GAUGE: {
802#if defined(TRACE_STATUS)
803                fprintf(stderr, "received AW_STATUS_CMD_GAUGE\n"); fflush(stdout);
804#endif // TRACE_STATUS
805
806                reassign(gauge, str);
807
808                if (gaugeValue>0) {
809                    // @@@ use double here?
810                    long sec_elapsed   = time(NULp)-aw_stg.last_start;                  // @@@ better use difftime
811                    long sec_estimated = (sec_elapsed*AW_GAUGE_GRANULARITY)/gaugeValue; // guess overall time
812                    int  gaugePercent  = gaugeValue*100/AW_GAUGE_GRANULARITY;
813
814                    char buffer[200];
815                    int  off  = 0;
816                    off      += sprintf(buffer+off, "%i%%  ", gaugePercent);
817                    off      += sprintf(buffer+off, "Elapsed: %s  ", sec2disp(sec_elapsed));
818
819                    // rotate estimations
820                    memmove(aw_stg.last_estimation, aw_stg.last_estimation+1, sizeof(aw_stg.last_estimation[0])*(AW_EST_BUFFER-1));
821                    aw_stg.last_estimation[AW_EST_BUFFER-1] = sec_estimated;
822
823                    if (aw_stg.last_est_count == AW_EST_BUFFER) { // now we can estimate!
824                        long used_estimation = 0;
825                        int  i;
826
827                        for (i = 0; i<AW_EST_BUFFER; ++i) {
828                            used_estimation += aw_stg.last_estimation[i];
829                        }
830                        used_estimation /= AW_EST_BUFFER;
831
832                        if (aw_stg.last_used_est != -1) {
833                            long diff = labs(aw_stg.last_used_est-used_estimation);
834                            if (diff <= 1) { used_estimation = aw_stg.last_used_est; } // fake away low frequency changes
835                        }
836
837                        long sec_rest         = used_estimation-sec_elapsed;
838                        off                  += sprintf(buffer+off, "Rest: %s", sec2disp(sec_rest));
839                        aw_stg.last_used_est  = used_estimation;
840                    }
841                    else {
842                        if (sec_elapsed>0) aw_stg.last_est_count++;
843                        off += sprintf(buffer+off, "Rest: ???");
844                    }
845
846                    awr->awar(AWAR_STATUS_ELAPSED)->write_string(buffer);
847
848#if defined(TRACE_STATUS)
849                    fprintf(stderr, "gauge=%i\n", gaugeValue); fflush(stdout);
850#endif // TRACE_STATUS
851
852                    static int last_logged_gaugePercent = 0;
853
854                    if (gaugePercent != last_logged_gaugePercent &&     // do not show repeated
855                        gaugePercent>0 && gaugePercent<100)             //  do not show begin/end gauge
856                    {
857                        sprintf(buffer, "%i%%", gaugePercent);
858                        LOG_STATUS("progress ", buffer,
859                                   (gaugePercent%5) == 0
860                                   ? LOG_ONCE_PER_MINUTE_WITH_ESTIMATION     // show 5% steps each minute
861                                   : LOG_ONCE_PER_15_MINUTES_WITH_ESTIMATION // show 1% steps each 15 minutes
862                            );
863
864                        last_logged_gaugePercent = gaugePercent;
865                    }
866                }
867                else if (gaugeValue == 0) { // restart timer
868                    aw_stg.last_start     = time(NULp);
869                    aw_stg.last_est_count = 0;
870                    aw_stg.last_used_est  = -1;
871#if defined(TRACE_STATUS)
872                    fprintf(stderr, "reset status timer (gauge=0)\n"); fflush(stdout);
873#endif // TRACE_STATUS
874                    timer_ok = time(&status_started) != -1;
875                }
876                break;
877            }
878            case AW_STATUS_CMD_MESSAGE:
879#if defined(TRACE_STATUS)
880                fprintf(stderr, "received AW_STATUS_CMD_MESSAGE\n"); fflush(stdout);
881#endif // TRACE_STATUS
882#if defined(ARB_LOGGING)
883                aw_status_append_to_log(str);
884#endif // ARB_LOGGING
885                aw_stg.awm->activate();
886                aw_insert_message_in_tmp_message_delayed(str);
887                break;
888
889            default:
890                break;
891        }
892        freenull(str);
893        cmd = aw_status_read_command(aw_stg.fd_to[0], 1, str, &gaugeValue);
894    }
895    freenull(str);
896
897#if defined(TRACE_STATUS_MORE)
898    fprintf(stderr, "exited while loop\n"); fflush(stdout);
899#endif // TRACE_STATUS_MORE
900
901    if (gauge) {
902        awr->awar(AWAR_STATUS_GAUGE)->write_string(gauge);
903        free(gauge);
904    }
905    if (delay>AW_STATUS_LISTEN_DELAY) delay = AW_STATUS_LISTEN_DELAY;
906    else if (delay<0) delay                 = 0;
907#if defined(TRACE_STATUS_MORE)
908    fprintf(stderr, "add aw_status_timer_listen_event with delay = %i\n", delay); fflush(stdout);
909#endif // TRACE_STATUS_MORE
910    aw_assert(delay>0);
911    return delay;
912}
913
914void aw_clear_message_cb(AW_window *aww) {
915    AW_root *awr = aww->get_root();
916    for (int i = 0; i< AW_MESSAGE_LINES; i++) freenull(aw_stg.lines[i]);
917    awr->awar(AWAR_ERROR_MESSAGES)->write_string("");
918}
919
920static void aw_clear_and_hide_message_cb(AW_window *aww) {
921    aw_clear_message_cb(aww);
922    AW_POPDOWN(aww);
923}
924
925static void save_messagebox_content_to(const char *name) {
926    const char *fullname = GB_path_in_HOME(name);
927    FILE       *out      = fopen(fullname, "wt");
928    GB_ERROR    error    = NULp;
929    if (!out) {
930        error = GB_IO_error("saving message box content to", fullname);
931    }
932    for (int i = 0; i<AW_MESSAGE_LINES; ++i) {
933        const char *line = aw_stg.lines[i];
934        if (line) {
935            fputs(line, out);
936            fputc('\n', out);
937        }
938    }
939    if (fclose(out) != 0) {
940        error = GB_IO_error("saving message box content to", fullname);
941    }
942    aw_message_if(error);
943}
944
945static void aw_message_save_cb(AW_window *aww) {
946    const char *name = "arb-message-box.txt";
947    char       *msg  = GBS_global_string_copy("Saving content to ~/%s", name);
948
949    aw_insert_message_in_tmp_message(aww->get_root(), "Saving properties.");
950    AW_save_properties(aww);
951
952    aw_insert_message_in_tmp_message(aww->get_root(), msg);
953    save_messagebox_content_to(name);
954
955    free(msg);
956}
957
958static void create_status_awars(AW_root *aw_root) {
959    aw_root->awar_string(AWAR_STATUS_TITLE,   "------------------------------------");
960    aw_root->awar_string(AWAR_STATUS_TEXT,    "");
961    aw_root->awar_string(AWAR_STATUS_GAUGE,   "------------------------------------");
962    aw_root->awar_string(AWAR_STATUS_ELAPSED, "");
963    aw_root->awar_string(AWAR_ERROR_MESSAGES, "");
964}
965
966void aw_initstatus() {
967    // fork status window.
968    // Note: call this function once as early as possible
969
970    aw_assert(aw_stg.pid == 0);                     // do not init status twice!
971    aw_assert(!AW_root::SINGLETON);                 // aw_initstatus has to be called before constructing AW_root
972    aw_assert(GB_open_DBs() == 0);                  // aw_initstatus has to be called before opening the first ARB-DB
973
974    int error = pipe(aw_stg.fd_to);
975    if (error) GBK_terminate("Cannot create socketpair [1]");
976    error = pipe(aw_stg.fd_from);
977    if (error) GBK_terminate("Cannot create socketpair [2]");
978
979    aw_stg.pid = getpid();
980    GB_install_pid(1);
981    pid_t clientid = fork();
982
983    if (clientid) { // i am the father
984#if defined(TRACE_STATUS)
985        fprintf(stderr, "Forked status! (i am the father)\n"); fflush(stderr);
986#endif // TRACE_STATUS
987        return;
988    }
989    else {
990        GB_install_pid(1);
991
992#if defined(TRACE_STATUS)
993        fprintf(stderr, "Forked status! (i am the child)\n"); fflush(stderr);
994#endif // TRACE_STATUS
995
996        aw_stg.is_child = true; // mark as child
997
998        GB_shell shell;
999        AW_root *aw_root = new AW_root("status.arb", "ARB_STATUS", true, new NullTracker); // uses_pix_res("icons/ARB_STATUS.xpm"); see ../SOURCE_TOOLS/check_resources.pl@uses_pix_res
1000        create_status_awars(aw_root);
1001
1002        {
1003            // create progress window
1004            AW_window_simple *aws = new AW_window_simple;
1005            aws->init(aw_root, "PROGRESS_BAR", "ARB PROGRESS");
1006            aws->load_xfig("status.fig");
1007
1008            aws->button_length(AW_GAUGE_SIZE+4);
1009            aws->at("Titel");
1010            aws->create_button(NULp, AWAR_STATUS_TITLE);
1011
1012            aws->at("Text");
1013            aws->create_button(NULp, AWAR_STATUS_TEXT);
1014
1015            aws->at("Gauge");
1016            aws->create_button(NULp, AWAR_STATUS_GAUGE);
1017
1018            aws->at("elapsed");
1019            aws->create_button(NULp, AWAR_STATUS_ELAPSED);
1020
1021            aws->at("Hide");
1022            aws->callback(aw_status_hide);
1023            aws->create_button("HIDE", "Hide", "h");
1024
1025            aws->at("Kill");
1026            aws->callback(aw_status_kill);
1027            aws->create_button("ABORT", "Abort", "k");
1028
1029            aw_stg.hide = 0;
1030            aw_stg.aws = aws;
1031        }
1032
1033        {
1034            // create message box
1035            AW_window_simple *awm = new AW_window_simple;
1036            awm->init(aw_root, "MESSAGE_BOX", "MESSAGE BOX");
1037            awm->load_xfig("message.fig");
1038
1039            awm->button_length(8);
1040            awm->auto_space(5, 5);
1041
1042            awm->at("Message");
1043            awm->create_text_field(AWAR_ERROR_MESSAGES, 10, 2);
1044
1045            awm->at("buttons");
1046            awm->callback(AW_POPDOWN);
1047            awm->create_button("HIDE", "Hide", "h");
1048
1049            awm->callback(aw_message_save_cb);
1050            awm->create_button("SAVE_PROPS", "Save", "S");
1051
1052            awm->callback(aw_clear_message_cb);
1053            awm->create_button("CLEAR", "Clear", "C");
1054
1055            awm->callback(aw_clear_and_hide_message_cb);
1056            awm->create_button("HIDE_CLEAR", "Ok", "O");
1057
1058            aw_stg.awm = awm;
1059        }
1060
1061#if defined(TRACE_STATUS)
1062        fprintf(stderr, "Created status window!\n"); fflush(stderr);
1063#endif // TRACE_STATUS
1064
1065        aw_status_wait_for_open(aw_stg.fd_to[0]);
1066
1067        // install callback
1068        aw_root->add_timed_callback_never_disabled(30, makeTimedCallback(aw_status_timer_listen_event)); // use short delay for first callback
1069
1070        // do NOT AWT_install_cb_guards here!
1071        aw_root->main_loop();                       // never returns
1072    }
1073}
1074
1075static void status_write_cmd_and_text(StatusCommand cmd, const char *text, int textlen) {
1076    aw_status_write(aw_stg.fd_to[1], cmd);
1077    safe_write(aw_stg.fd_to[1], text, textlen+1);
1078}
1079static void status_write_cmd_and_text(StatusCommand cmd, const char *text) {
1080    if (!text) text = "";
1081    status_write_cmd_and_text(cmd, text, strlen(text));
1082}
1083
1084void aw_openstatus(const char *title) {
1085    aw_stg.mode = AW_STATUS_OK;
1086    if (!aw_stg.status_initialized) {
1087        aw_stg.status_initialized = true;
1088        aw_status_write(aw_stg.fd_to[1], AW_STATUS_CMD_INIT);
1089    }
1090    status_write_cmd_and_text(AW_STATUS_CMD_OPEN, title);
1091}
1092
1093void aw_closestatus() {
1094    aw_status_write(aw_stg.fd_to[1], AW_STATUS_CMD_CLOSE);
1095}
1096
1097void aw_status_title(const char *new_title) {
1098    status_write_cmd_and_text(AW_STATUS_CMD_NEW_TITLE, new_title);
1099}
1100void aw_status_subtitle(const char *text) {
1101    status_write_cmd_and_text(AW_STATUS_CMD_TEXT, text);
1102}
1103
1104void aw_status_gauge(double gauge) {
1105    static int last_val = -1;
1106    int        val      = (int)(gauge*AW_GAUGE_GRANULARITY);
1107
1108    if (val != last_val) {
1109        if (val>0 || gauge == 0.0) {            // only write 0 if gauge really is 0 (cause 0 resets the timer)
1110            aw_assert(gauge <= 1.0);            // please fix the gauge calculation in caller!
1111            aw_status_write(aw_stg.fd_to[1], AW_STATUS_CMD_GAUGE);
1112            safe_write(aw_stg.fd_to[1], (char*)&val, sizeof(int));
1113        }
1114        last_val = val;
1115    }
1116}
1117
1118bool aw_status_aborted() {
1119    if (aw_stg.mode != AW_STATUS_ABORT) {
1120        // check if user has pressed the 'Abort' button
1121        static ARB_timestamp last_check;
1122        if (last_check.sec_since() >= 1) { // perform check not more often than every second!
1123            char *str = NULp;
1124            for (int cmd = 0; cmd != EOF; cmd = aw_status_read_command(aw_stg.fd_from[0], 1, str)) {
1125                freenull(str);
1126                if (cmd == AW_STATUS_ABORT) aw_stg.mode = AW_STATUS_ABORT;
1127            }
1128            last_check.update();
1129        }
1130    }
1131    return aw_stg.mode;
1132}
1133
1134// -------------------
1135//      aw_message
1136
1137void aw_set_local_message() {
1138    aw_stg.local_message = 1;
1139}
1140
1141
1142void aw_message(const char *msg) {
1143    aw_assert(!RUNNING_TEST()); // aw_message hangs when called from nightly builds
1144#if defined(DEBUG)
1145    printf("aw_message: '%s'\n", msg);
1146#endif // DEBUG
1147    if (aw_stg.local_message) {
1148        aw_insert_message_in_tmp_message(AW_root::SINGLETON, msg);
1149    }
1150    else {
1151        if (!aw_stg.status_initialized) {
1152            aw_stg.status_initialized = true;
1153            aw_status_write(aw_stg.fd_to[1], AW_STATUS_CMD_INIT);
1154        }
1155        status_write_cmd_and_text(AW_STATUS_CMD_MESSAGE, msg);
1156    }
1157}
1158
Note: See TracBrowser for help on using the repository browser.