Merge changes Ib441cecf,Ieb1bbe3d,I3e63e430,I531b4317,I8dd60545, ...

* changes:
  logcat: Add --wrap timeout
  logcat: Add low hanging fruit long arguments
  logcat: Add long arguments to logcat, support for pid filter
  liblog: Support for ANDROID_LOG_WRAP mode flag on reader
  logd: test wakeup on wrap timeout
  logd: wakeup on wrap or timeout

include/log/logger.h

@@ -163,6 +163,8 @@ int android_logger_set_prune_list(struct logger_list *logger_list,
 #define ANDROID_LOG_RDWR     O_RDWR
 #define ANDROID_LOG_ACCMODE  O_ACCMODE
 #define ANDROID_LOG_NONBLOCK O_NONBLOCK
+#define ANDROID_LOG_WRAP     0x40000000 /* Block until buffer about to wrap */
+#define ANDROID_LOG_WRAP_DEFAULT_TIMEOUT 7200 /* 2 hour default */
 #define ANDROID_LOG_PSTORE   0x80000000
 
 struct logger_list *android_logger_list_alloc(int mode,

liblog/README

@@ -116,6 +116,10 @@ DESCRIPTION
        code,  otherwise the  android_logger_list_read  call will block for new
        entries.
 
+       The  ANDROID_LOG_WRAP  mode flag to the  android_logger_list_alloc_time
+       signals  logd to quiesce  the reader until the buffer is about to prune
+       at the start time then proceed to dumping content.
+
        The  ANDROID_LOG_PSTORE mode flag to the android_logger_open is used to
        switch from the active logs to the persistent logs from before the last
        reboot.

liblog/log_read.c

@@ -797,6 +797,14 @@ int android_logger_list_read(struct logger_list *logger_list,
         }
 
         if (logger_list->start.tv_sec || logger_list->start.tv_nsec) {
+            if (logger_list->mode & ANDROID_LOG_WRAP) {
+                // ToDo: alternate API to allow timeout to be adjusted.
+                ret = snprintf(cp, remaining, " timeout=%u",
+                               ANDROID_LOG_WRAP_DEFAULT_TIMEOUT);
+                ret = min(ret, remaining);
+                remaining -= ret;
+                cp += ret;
+            }
             ret = snprintf(cp, remaining, " start=%" PRIu32 ".%09" PRIu32,
                            logger_list->start.tv_sec,
                            logger_list->start.tv_nsec);

logcat/logcat.cpp

@@ -6,6 +6,7 @@
 #include <dirent.h>
 #include <errno.h>
 #include <fcntl.h>
+#include <getopt.h>
 #include <math.h>
 #include <sched.h>
 #include <signal.h>
@@ -256,13 +257,19 @@ static void show_help(const char *cmd)
                     "  -s              Set default filter to silent.\n"
                     "                  Like specifying filterspec '*:S'\n"
                     "  -f <filename>   Log to file. Default is stdout\n"
+                    "  --file=<filename>\n"
                     "  -r <kbytes>     Rotate log every kbytes. Requires -f\n"
+                    "  --rotate_kbytes=<kbytes>\n"
                     "  -n <count>      Sets max number of rotated logs to <count>, default 4\n"
-                    "  -v <format>     Sets the log print format, where <format> is:\n\n"
+                    "  --rotate_count=<count>\n"
+                    "  -v <format>     Sets the log print format, where <format> is:\n"
+                    "  --format=<format>\n"
                     "                      brief color epoch long monotonic printable process raw\n"
                     "                      tag thread threadtime time usec UTC year zone\n\n"
                     "  -D              print dividers between each log buffer\n"
+                    "  --dividers\n"
                     "  -c              clear (flush) the entire log and exit\n"
+                    "  --clear\n"
                     "  -d              dump the log and then exit (don't block)\n"
                     "  -t <count>      print only the most recent <count> lines (implies -d)\n"
                     "  -t '<time>'     print most recent lines since specified time (implies -d)\n"
@@ -271,22 +278,32 @@ static void show_help(const char *cmd)
                     "                  count is pure numerical, time is 'MM-DD hh:mm:ss.mmm...'\n"
                     "                  'YYYY-MM-DD hh:mm:ss.mmm...' or 'sssss.mmm...' format\n"
                     "  -g              get the size of the log's ring buffer and exit\n"
+                    "  --buffer_size\n"
+                    "  -G <size>       set size of log ring buffer, may suffix with K or M.\n"
+                    "  --buffer_size=<size>\n"
                     "  -L              dump logs from prior to last reboot\n"
+                    "  --last\n"
                     "  -b <buffer>     Request alternate ring buffer, 'main', 'system', 'radio',\n"
-                    "                  'events', 'crash' or 'all'. Multiple -b parameters are\n"
+                    "  --buffer=<buffer> 'events', 'crash' or 'all'. Multiple -b parameters are\n"
                     "                  allowed and results are interleaved. The default is\n"
                     "                  -b main -b system -b crash.\n"
                     "  -B              output the log in binary.\n"
+                    "  --binary\n"
                     "  -S              output statistics.\n"
-                    "  -G <size>       set size of log ring buffer, may suffix with K or M.\n"
+                    "  --statistics\n"
                     "  -p              print prune white and ~black list. Service is specified as\n"
-                    "                  UID, UID/PID or /PID. Weighed for quicker pruning if prefix\n"
+                    "  --prune         UID, UID/PID or /PID. Weighed for quicker pruning if prefix\n"
                     "                  with ~, otherwise weighed for longevity if unadorned. All\n"
                     "                  other pruning activity is oldest first. Special case ~!\n"
                     "                  represents an automatic quicker pruning for the noisiest\n"
                     "                  UID as determined by the current statistics.\n"
                     "  -P '<list> ...' set prune white and ~black list, using same format as\n"
-                    "                  printed above. Must be quoted.\n");
+                    "  --prune='<list> ...'  printed above. Must be quoted.\n"
+                    "  --pid=<pid>     Only prints logs from the given pid.\n"
+                    // Check ANDROID_LOG_WRAP_DEFAULT_TIMEOUT value
+                    "  --wrap          Sleep for 2 hours or when buffer about to wrap whichever\n"
+                    "                  comes first. Improves efficiency of polling by providing\n"
+                    "                  an about-to-wrap wakeup.\n");
 
     fprintf(stderr,"\nfilterspecs are a series of \n"
                    "  <tag>[:priority]\n\n"
@@ -348,15 +365,19 @@ static const char *multiplier_of_size(unsigned long value)
 static bool getSizeTArg(char *ptr, size_t *val, size_t min = 0,
                         size_t max = SIZE_MAX)
 {
-    char *endp;
+    if (!ptr) {
-    errno = 0;
-    size_t ret = (size_t) strtoll(ptr, &endp, 0);
-
-    if (endp[0] != '\0' || errno != 0 ) {
         return false;
     }
 
-    if (ret >  max || ret <  min) {
+    char *endp;
+    errno = 0;
+    size_t ret = (size_t)strtoll(ptr, &endp, 0);
+
+    if (endp[0] || errno) {
+        return false;
+    }
+
+    if ((ret > max) || (ret < min)) {
         return false;
     }
 
@@ -497,6 +518,7 @@ int main(int argc, char **argv)
     struct logger_list *logger_list;
     size_t tail_lines = 0;
     log_time tail_time(log_time::EPOCH);
+    size_t pid = 0;
 
     signal(SIGPIPE, exit);
 
@@ -510,13 +532,66 @@ int main(int argc, char **argv)
     for (;;) {
         int ret;
 
-        ret = getopt(argc, argv, ":cdDLt:T:gG:sQf:r:n:v:b:BSpP:");
+        int option_index = 0;
+        static const char pid_str[] = "pid";
+        static const char wrap_str[] = "wrap";
+        static const struct option long_options[] = {
+          { "binary",        no_argument,       NULL,   'B' },
+          { "buffer",        required_argument, NULL,   'b' },
+          { "buffer_size",   optional_argument, NULL,   'g' },
+          { "clear",         no_argument,       NULL,   'c' },
+          { "dividers",      no_argument,       NULL,   'D' },
+          { "file",          required_argument, NULL,   'f' },
+          { "format",        required_argument, NULL,   'v' },
+          { "last",          no_argument,       NULL,   'L' },
+          { pid_str,         required_argument, NULL,   0 },
+          { "prune",         optional_argument, NULL,   'p' },
+          { "rotate_count",  required_argument, NULL,   'n' },
+          { "rotate_kbytes", required_argument, NULL,   'r' },
+          { "statistics",    no_argument,       NULL,   'S' },
+          // support, but ignore and do not document, the optional argument
+          { wrap_str,        optional_argument, NULL,   0 },
+          { NULL,            0,                 NULL,   0 }
+        };
+
+        ret = getopt_long(argc, argv, ":cdDLt:T:gG:sQf:r:n:v:b:BSpP:",
+                          long_options, &option_index);
 
         if (ret < 0) {
             break;
         }
 
-        switch(ret) {
+        switch (ret) {
+            case 0:
+                // One of the long options
+                if (long_options[option_index].name == pid_str) {
+                    // ToDo: determine runtime PID_MAX?
+                    if (!getSizeTArg(optarg, &pid, 1)) {
+                        logcat_panic(true, "%s %s out of range\n",
+                                     long_options[option_index].name, optarg);
+                    }
+                    break;
+                }
+                if (long_options[option_index].name == wrap_str) {
+                    mode |= ANDROID_LOG_WRAP |
+                            ANDROID_LOG_RDONLY |
+                            ANDROID_LOG_NONBLOCK;
+                    // ToDo: implement API that supports setting a wrap timeout
+                    size_t dummy = ANDROID_LOG_WRAP_DEFAULT_TIMEOUT;
+                    if (optarg && !getSizeTArg(optarg, &dummy, 1)) {
+                        logcat_panic(true, "%s %s out of range\n",
+                                     long_options[option_index].name, optarg);
+                    }
+                    if (dummy != ANDROID_LOG_WRAP_DEFAULT_TIMEOUT) {
+                        fprintf(stderr,
+                                "WARNING: %s %u seconds, ignoring %zu\n",
+                                long_options[option_index].name,
+                                ANDROID_LOG_WRAP_DEFAULT_TIMEOUT, dummy);
+                    }
+                    break;
+                }
+            break;
+
             case 's':
                 // default to all silent
                 android_log_addFilterRule(g_logformat, "*:s");
@@ -568,8 +643,11 @@ int main(int argc, char **argv)
             break;
 
             case 'g':
-                getLogSize = 1;
+                if (!optarg) {
-            break;
+                    getLogSize = 1;
+                    break;
+                }
+                // FALLTHRU
 
             case 'G': {
                 char *cp;
@@ -607,8 +685,11 @@ int main(int argc, char **argv)
             break;
 
             case 'p':
-                getPruneList = 1;
+                if (!optarg) {
-            break;
+                    getPruneList = 1;
+                    break;
+                }
+                // FALLTHRU
 
             case 'P':
                 setPruneList = optarg;
@@ -838,9 +919,9 @@ int main(int argc, char **argv)
 
     dev = devices;
     if (tail_time != log_time::EPOCH) {
-        logger_list = android_logger_list_alloc_time(mode, tail_time, 0);
+        logger_list = android_logger_list_alloc_time(mode, tail_time, pid);
     } else {
-        logger_list = android_logger_list_alloc(mode, tail_lines, 0);
+        logger_list = android_logger_list_alloc(mode, tail_lines, pid);
     }
     const char *openDeviceFail = NULL;
     const char *clearFail = NULL;

logd/FlushCommand.cpp

@@ -27,13 +27,15 @@ FlushCommand::FlushCommand(LogReader &reader,
                            unsigned long tail,
                            unsigned int logMask,
                            pid_t pid,
-                           uint64_t start) :
+                           uint64_t start,
+                           uint64_t timeout) :
         mReader(reader),
         mNonBlock(nonBlock),
         mTail(tail),
         mLogMask(logMask),
         mPid(pid),
-        mStart(start) {
+        mStart(start),
+        mTimeout(timeout) {
 }
 
 // runSocketCommand is called once for every open client on the
@@ -54,6 +56,10 @@ void FlushCommand::runSocketCommand(SocketClient *client) {
     while(it != times.end()) {
         entry = (*it);
         if (entry->mClient == client) {
+            if (entry->mTimeout.tv_sec || entry->mTimeout.tv_nsec) {
+                LogTimeEntry::unlock();
+                return;
+            }
             entry->triggerReader_Locked();
             if (entry->runningReader_Locked()) {
                 LogTimeEntry::unlock();
@@ -71,7 +77,8 @@ void FlushCommand::runSocketCommand(SocketClient *client) {
             LogTimeEntry::unlock();
             return;
         }
-        entry = new LogTimeEntry(mReader, client, mNonBlock, mTail, mLogMask, mPid, mStart);
+        entry = new LogTimeEntry(mReader, client, mNonBlock, mTail, mLogMask,
+                                 mPid, mStart, mTimeout);
         times.push_front(entry);
     }
 

logd/FlushCommand.h

@@ -32,6 +32,7 @@ class FlushCommand : public SocketClientCommand {
     unsigned int mLogMask;
     pid_t mPid;
     uint64_t mStart;
+    uint64_t mTimeout;
 
 public:
     FlushCommand(LogReader &mReader,
@@ -39,7 +40,8 @@ public:
                  unsigned long tail = -1,
                  unsigned int logMask = -1,
                  pid_t pid = 0,
-                 uint64_t start = 1);
+                 uint64_t start = 1,
+                 uint64_t timeout = 0);
     virtual void runSocketCommand(SocketClient *client);
 
     static bool hasReadLogs(SocketClient *client);

logd/LogBuffer.cpp

@@ -129,41 +129,57 @@ void LogBuffer::init() {
     }
     bool lastMonotonic = monotonic;
     monotonic = android_log_clockid() == CLOCK_MONOTONIC;
-    if (lastMonotonic == monotonic) {
+    if (lastMonotonic != monotonic) {
-        return;
+        //
+        // Fixup all timestamps, may not be 100% accurate, but better than
+        // throwing what we have away when we get 'surprised' by a change.
+        // In-place element fixup so no need to check reader-lock. Entries
+        // should already be in timestamp order, but we could end up with a
+        // few out-of-order entries if new monotonics come in before we
+        // are notified of the reinit change in status. A Typical example would
+        // be:
+        //  --------- beginning of system
+        //      10.494082   184   201 D Cryptfs : Just triggered post_fs_data
+        //  --------- beginning of kernel
+        //       0.000000     0     0 I         : Initializing cgroup subsys
+        // as the act of mounting /data would trigger persist.logd.timestamp to
+        // be corrected. 1/30 corner case YMMV.
+        //
+        pthread_mutex_lock(&mLogElementsLock);
+        LogBufferElementCollection::iterator it = mLogElements.begin();
+        while((it != mLogElements.end())) {
+            LogBufferElement *e = *it;
+            if (monotonic) {
+                if (!android::isMonotonic(e->mRealTime)) {
+                    LogKlog::convertRealToMonotonic(e->mRealTime);
+                }
+            } else {
+                if (android::isMonotonic(e->mRealTime)) {
+                    LogKlog::convertMonotonicToReal(e->mRealTime);
+                }
+            }
+            ++it;
+        }
+        pthread_mutex_unlock(&mLogElementsLock);
     }
 
+    // We may have been triggered by a SIGHUP. Release any sleeping reader
+    // threads to dump their current content.
     //
-    // Fixup all timestamps, may not be 100% accurate, but better than
+    // NB: this is _not_ performed in the context of a SIGHUP, it is
-    // throwing what we have away when we get 'surprised' by a change.
+    // performed during startup, and in context of reinit administrative thread
-    // In-place element fixup so no need to check reader-lock. Entries
+    LogTimeEntry::lock();
-    // should already be in timestamp order, but we could end up with a
+
-    // few out-of-order entries if new monotonics come in before we
+    LastLogTimes::iterator times = mTimes.begin();
-    // are notified of the reinit change in status. A Typical example would
+    while(times != mTimes.end()) {
-    // be:
+        LogTimeEntry *entry = (*times);
-    //  --------- beginning of system
+        if (entry->owned_Locked()) {
-    //      10.494082   184   201 D Cryptfs : Just triggered post_fs_data
+            entry->triggerReader_Locked();
-    //  --------- beginning of kernel
-    //       0.000000     0     0 I         : Initializing cgroup subsys cpuacct
-    // as the act of mounting /data would trigger persist.logd.timestamp to
-    // be corrected. 1/30 corner case YMMV.
-    //
-    pthread_mutex_lock(&mLogElementsLock);
-    LogBufferElementCollection::iterator it = mLogElements.begin();
-    while((it != mLogElements.end())) {
-        LogBufferElement *e = *it;
-        if (monotonic) {
-            if (!android::isMonotonic(e->mRealTime)) {
-                LogKlog::convertRealToMonotonic(e->mRealTime);
-            }
-        } else {
-            if (android::isMonotonic(e->mRealTime)) {
-                LogKlog::convertMonotonicToReal(e->mRealTime);
-            }
         }
-        ++it;
+        times++;
     }
-    pthread_mutex_unlock(&mLogElementsLock);
+
+    LogTimeEntry::unlock();
 }
 
 LogBuffer::LogBuffer(LastLogTimes *times):
@@ -429,7 +445,10 @@ bool LogBuffer::prune(log_id_t id, unsigned long pruneRows, uid_t caller_uid) {
     while(t != mTimes.end()) {
         LogTimeEntry *entry = (*t);
         if (entry->owned_Locked() && entry->isWatching(id)
-                && (!oldest || (oldest->mStart > entry->mStart))) {
+                && (!oldest ||
+                    (oldest->mStart > entry->mStart) ||
+                    ((oldest->mStart == entry->mStart) &&
+                     (entry->mTimeout.tv_sec || entry->mTimeout.tv_nsec)))) {
             oldest = entry;
         }
         t++;
@@ -448,8 +467,12 @@ bool LogBuffer::prune(log_id_t id, unsigned long pruneRows, uid_t caller_uid) {
             }
 
             if (oldest && (oldest->mStart <= e->getSequence())) {
-                oldest->triggerSkip_Locked(id, pruneRows);
                 busy = true;
+                if (oldest->mTimeout.tv_sec || oldest->mTimeout.tv_nsec) {
+                    oldest->triggerReader_Locked();
+                } else {
+                    oldest->triggerSkip_Locked(id, pruneRows);
+                }
                 break;
             }
 
@@ -523,6 +546,9 @@ bool LogBuffer::prune(log_id_t id, unsigned long pruneRows, uid_t caller_uid) {
 
             if (oldest && (oldest->mStart <= e->getSequence())) {
                 busy = true;
+                if (oldest->mTimeout.tv_sec || oldest->mTimeout.tv_nsec) {
+                    oldest->triggerReader_Locked();
+                }
                 break;
             }
 
@@ -648,6 +674,8 @@ bool LogBuffer::prune(log_id_t id, unsigned long pruneRows, uid_t caller_uid) {
             if (stats.sizes(id) > (2 * log_buffer_size(id))) {
                 // kick a misbehaving log reader client off the island
                 oldest->release_Locked();
+            } else if (oldest->mTimeout.tv_sec || oldest->mTimeout.tv_nsec) {
+                oldest->triggerReader_Locked();
             } else {
                 oldest->triggerSkip_Locked(id, pruneRows);
             }
@@ -680,6 +708,8 @@ bool LogBuffer::prune(log_id_t id, unsigned long pruneRows, uid_t caller_uid) {
                 if (stats.sizes(id) > (2 * log_buffer_size(id))) {
                     // kick a misbehaving log reader client off the island
                     oldest->release_Locked();
+                } else if (oldest->mTimeout.tv_sec || oldest->mTimeout.tv_nsec) {
+                    oldest->triggerReader_Locked();
                 } else {
                     oldest->triggerSkip_Locked(id, pruneRows);
                 }

logd/LogReader.cpp

@@ -67,6 +67,14 @@ bool LogReader::onDataAvailable(SocketClient *cli) {
         start.strptime(cp + sizeof(_start) - 1, "%s.%q");
     }
 
+    uint64_t timeout = 0;
+    static const char _timeout[] = " timeout=";
+    cp = strstr(buffer, _timeout);
+    if (cp) {
+        timeout = atol(cp + sizeof(_timeout) - 1) * NS_PER_SEC +
+                  log_time(CLOCK_REALTIME).nsec();
+    }
+
     unsigned int logMask = -1;
     static const char _logIds[] = " lids=";
     cp = strstr(buffer, _logIds);
@@ -166,7 +174,7 @@ bool LogReader::onDataAvailable(SocketClient *cli) {
         }
     }
 
-    FlushCommand command(*this, nonBlock, tail, logMask, pid, sequence);
+    FlushCommand command(*this, nonBlock, tail, logMask, pid, sequence, timeout);
     command.runSocketCommand(cli);
     return true;
 }

logd/LogTimes.cpp

@@ -14,6 +14,7 @@
  * limitations under the License.
  */
 
+#include <errno.h>
 #include <sys/prctl.h>
 
 #include "FlushCommand.h"
@@ -26,7 +27,7 @@ pthread_mutex_t LogTimeEntry::timesLock = PTHREAD_MUTEX_INITIALIZER;
 LogTimeEntry::LogTimeEntry(LogReader &reader, SocketClient *client,
                            bool nonBlock, unsigned long tail,
                            unsigned int logMask, pid_t pid,
-                           uint64_t start) :
+                           uint64_t start, uint64_t timeout) :
         mRefCount(1),
         mRelease(false),
         mError(false),
@@ -42,6 +43,8 @@ LogTimeEntry::LogTimeEntry(LogReader &reader, SocketClient *client,
         mStart(start),
         mNonBlock(nonBlock),
         mEnd(LogBufferElement::getCurrentSequence()) {
+    mTimeout.tv_sec = timeout / NS_PER_SEC;
+    mTimeout.tv_nsec = timeout % NS_PER_SEC;
     pthread_cond_init(&threadTriggeredCondition, NULL);
     cleanSkip_Locked();
 }
@@ -131,6 +134,19 @@ void *LogTimeEntry::threadStart(void *obj) {
     uint64_t start = me->mStart;
 
     while (me->threadRunning && !me->isError_Locked()) {
+
+        if (me->mTimeout.tv_sec || me->mTimeout.tv_nsec) {
+            if (pthread_cond_timedwait(&me->threadTriggeredCondition,
+                                       &timesLock,
+                                       &me->mTimeout) == ETIMEDOUT) {
+                me->mTimeout.tv_sec = 0;
+                me->mTimeout.tv_nsec = 0;
+            }
+            if (!me->threadRunning || me->isError_Locked()) {
+                break;
+            }
+        }
+
         unlock();
 
         if (me->mTail) {
@@ -154,7 +170,9 @@ void *LogTimeEntry::threadStart(void *obj) {
 
         me->cleanSkip_Locked();
 
-        pthread_cond_wait(&me->threadTriggeredCondition, &timesLock);
+        if (!me->mTimeout.tv_sec && !me->mTimeout.tv_nsec) {
+            pthread_cond_wait(&me->threadTriggeredCondition, &timesLock);
+        }
     }
 
     unlock();

logd/LogTimes.h

@@ -50,10 +50,11 @@ class LogTimeEntry {
 public:
     LogTimeEntry(LogReader &reader, SocketClient *client, bool nonBlock,
                  unsigned long tail, unsigned int logMask, pid_t pid,
-                 uint64_t start);
+                 uint64_t start, uint64_t timeout);
 
     SocketClient *mClient;
     uint64_t mStart;
+    struct timespec mTimeout;
     const bool mNonBlock;
     const uint64_t mEnd; // only relevant if mNonBlock
 

logd/tests/logd_test.cpp

@@ -243,6 +243,12 @@ static void dump_log_msg(const char *prefix,
     case 3:
         fprintf(stderr, "lid=system ");
         break;
+    case 4:
+        fprintf(stderr, "lid=crash ");
+        break;
+    case 5:
+        fprintf(stderr, "lid=kernel ");
+        break;
     default:
         if (lid >= 0) {
             fprintf(stderr, "lid=%d ", lid);
@@ -519,3 +525,68 @@ TEST(logd, benchmark) {
     // 50% threshold for SPAM filter (<20% typical, lots of engineering margin)
     ASSERT_GT(totalSize, nowSpamSize * 2);
 }
+
+TEST(logd, timeout) {
+    log_msg msg_wrap, msg_timeout;
+    bool content_wrap = false, content_timeout = false, written = false;
+    unsigned int alarm_wrap = 0, alarm_timeout = 0;
+    // A few tries to get it right just in case wrap kicks in due to
+    // content providers being active during the test.
+    int i = 3;
+
+    while (--i) {
+        int fd = socket_local_client("logdr",
+                                     ANDROID_SOCKET_NAMESPACE_RESERVED,
+                                     SOCK_SEQPACKET);
+        ASSERT_LT(0, fd);
+
+        struct sigaction ignore, old_sigaction;
+        memset(&ignore, 0, sizeof(ignore));
+        ignore.sa_handler = caught_signal;
+        sigemptyset(&ignore.sa_mask);
+        sigaction(SIGALRM, &ignore, &old_sigaction);
+        unsigned int old_alarm = alarm(3);
+
+        static const char ask[] = "dumpAndClose lids=0,1,2,3,4,5 timeout=6";
+        written = write(fd, ask, sizeof(ask)) == sizeof(ask);
+        if (!written) {
+            alarm(old_alarm);
+            sigaction(SIGALRM, &old_sigaction, NULL);
+            close(fd);
+            continue;
+        }
+
+        content_wrap = recv(fd, msg_wrap.buf, sizeof(msg_wrap), 0) > 0;
+
+        alarm_wrap = alarm(5);
+
+        content_timeout = recv(fd, msg_timeout.buf, sizeof(msg_timeout), 0) > 0;
+
+        alarm_timeout = alarm((old_alarm <= 0)
+            ? old_alarm
+            : (old_alarm > (1 + 3 - alarm_wrap))
+                ? old_alarm - 3 + alarm_wrap
+                : 2);
+        sigaction(SIGALRM, &old_sigaction, NULL);
+
+        close(fd);
+
+        if (!content_wrap && !alarm_wrap && content_timeout && !alarm_timeout) {
+            break;
+        }
+    }
+
+    if (content_wrap) {
+        dump_log_msg("wrap", &msg_wrap, 3, -1);
+    }
+
+    if (content_timeout) {
+        dump_log_msg("timeout", &msg_timeout, 3, -1);
+    }
+
+    EXPECT_TRUE(written);
+    EXPECT_FALSE(content_wrap);
+    EXPECT_EQ(0U, alarm_wrap);
+    EXPECT_TRUE(content_timeout);
+    EXPECT_NE(0U, alarm_timeout);
+}