Adds rudimentary support for parsing dlog

Adds basic functionality allowing reading and parsing dlog.
Adds wait_for_tts command, which waits for given text to be
read by screen-reader.

Change-Id: Ie9ec90898c060926d2c4a8087e81c21c570bbdda

diff --git a/src/batch/BatchRunner.cpp b/src/batch/BatchRunner.cpp
index 9be75eb..0f8a5c5 100644 (file)
--- a/src/batch/BatchRunner.cpp
+++ b/src/batch/BatchRunner.cpp
@@ -29,6 +29,7 @@
 #include "Monitor.hpp"
 #include "../DoneCallback.hpp"
 #include "../DBus.hpp"
+#include "Dlog.hpp"
 
 #include <mutex>
 #include <chrono>
@@ -36,6 +37,7 @@
 #include <fstream>
 #include <cmath>
 #include <type_traits>
+#include <regex>
 
 
 namespace WrapDetails
@@ -210,6 +212,11 @@ struct TestExecutor : ExecutorInterface {
                std::string rootName;
        };
        Monitor<ContextInfo> contextInfo;
+       struct TTSInfo {
+               Optional<std::regex> searchLine;
+               bool found = false;
+       };
+       Monitor<TTSInfo> ttsInfo;
        std::unordered_map<std::string, EvaluationValue> variables;
        std::unordered_map<std::pair<detail::Kind, std::string>, EvaluationValue> setters;
        std::unordered_map<std::pair<detail::Kind, std::string>, EvaluationValue> getters;
@@ -250,16 +257,46 @@ struct TestExecutor : ExecutorInterface {
                                return {};
                        }
                };
+               variables["wait_for_tts"] = detail::UserFunctionType<std::string> {
+                       [&](EvaluationContext & ec, std::string pattern) -> EvaluationValue {
+                               std::regex regex;
+                               try
+                               {
+                                       regex = std::regex {
+                                               pattern,
+                                               std::regex_constants::nosubs |
+                                               std::regex_constants::optimize |
+                                               std::regex_constants::ECMAScript
+                                       };
+                               } catch (...)
+                               {
+                                       throw EvaluationFailure{} << "invalid regex pattern '" << pattern << "'";
+                               }
+
+                               auto h = ttsInfo.lock();
+                               h->searchLine = std::move(regex);
+                               h->found = false;
+                               auto untilMoment = std::chrono::high_resolution_clock::now() + 3s;
+                               auto success = h.waitForCondition(untilMoment, [&]()
+                               {
+                                       return h->found;
+                               });
+                               if (!success)
+                                       throw EvaluationFailure{} << "wait_for_dlog('" << pattern << "'): operation timeouted";
+                               return {};
+                       }
+               };
                variables["wait_for_application"] = detail::UserFunctionType<std::string> {
                        [&](EvaluationContext & ec, std::string name) -> EvaluationValue {
                                auto h = contextInfo.lock();
                                auto untilMoment = std::chrono::high_resolution_clock::now() + 3000ms;
-                               auto success = h.waitForCondition(untilMoment, [&]() {
+                               auto success = h.waitForCondition(untilMoment, [&]()
+                               {
                                        return h->rootName == name;
                                });
                                if (!success)
                                        throw EvaluationFailure{} << "wait_for_application('" << name << "'): operation timeouted, " <<
-                                                                                                 "current root name is '" << h->rootName << "'";
+                                                                                 "current root name is '" << h->rootName << "'";
                                return {};
                        }
                };
@@ -808,49 +845,71 @@ Optional<std::thread> runBatch(const std::string &sourceName, std::string output
                return {};
        }
 
+       Dlog dlog;
+       if (!dlog.start()) {
+               output << "launching dlogutil failed\n";
+               return {};
+       }
        // std::ostringstream os;
        // result->debug(os, 0);
        // output << os.str() << "\n";
 
        output << "executing test '" << sourceName << "'\n";
        auto exec = std::make_unique<TestExecutor>(*outputPtr);
-       return std::thread { [result = std::move(result), exec = std::move(exec), outputPtr = std::move(outputPtr)]()
-       {
-               EvaluationContext &ec = exec->ec;
-               exec->outputStream() << "waiting for context change...\n";
-               bool hasContext = false;
-               auto until = std::chrono::high_resolution_clock::now() + std::chrono::seconds{ 2 };
+       return std::thread { [result = std::move(result), exec = std::move(exec), outputPtr = std::move(outputPtr), dlog = std::move(dlog) ]() mutable
                {
-                       auto h = exec->contextInfo.lock();
-                       hasContext = h.waitForCondition(until, [&]() {
-                               // h->root is pointer to root of visible at-spi hierarchy
-                               // if it's null, then either context building machinery didn't yet finish,
-                               // there's nothing visible to show or something went wrong
-                               // here we wait for it to be non-null (context finished constructing)
-                               // if it timeouts - something went wrong, so we bail out with an error
-                               return bool(h->root);
-                       });
-               }
-               if (hasContext) {
-                       exec->outputStream() << "evaluation started\n";
-                       try {
-                               result->evaluate(ec);
-                               exec->outputStream() << "evaluation successed\n";
-                       } catch (EvaluationFailure &e) {
-                               if (e.hasLocation())
-                                       exec->outputStream() << e.location().toString() << ": ";
-                               exec->outputStream() << e.message() << "\nevaluation failed\n";
-                       } catch (...) {
-                               exec->outputStream() << "unhandled exception\nevaluation failed\n";
+                       EvaluationContext &ec = exec->ec;
+                       exec->outputStream() << "waiting for context change...\n";
+                       auto until = std::chrono::high_resolution_clock::now() + std::chrono::seconds{ 2 };
+                       bool hasContext = false;
+                       {
+                               auto h = exec->contextInfo.lock();
+                               hasContext = h.waitForCondition(until, [&]()
+                               {
+                                       // h->root is pointer to root of visible at-spi hierarchy
+                                       // if it's null, then either context building machinery didn't yet finish,
+                                       // there's nothing visible to show or something went wrong
+                                       // here we wait for it to be non-null (context finished constructing)
+                                       // if it timeouts - something went wrong, so we bail out with an error
+                                       return bool(h->root);
+                               });
                        }
-               } else {
-                       exec->outputStream() << "timeouted\n";
-                       DEBUG("timeouted, when waiting for context change");
-               }
-               outputPtr->flush();
-               executeOnMainThread([]() {
-                       ecore_main_loop_quit();
-               });
-               DEBUG("done batch");
-       } };
+                       if (hasContext)
+                       {
+                               auto ttsMainRegex = std::regex {
+                                       "^D/SCREEN-READER[^>]*?> READ COMMAND PARAMS, TEXT: (.*?), DISCARDABLE: 0",
+                                       std::regex_constants::optimize | std::regex_constants::ECMAScript
+                               };
+                               auto ttsDlogHandler = dlog.registerCallback([&exec, ttsMainRegex = std::move(ttsMainRegex)](const std::string & txt) {
+                                       auto h = exec->ttsInfo.lock();
+                                       if (h->searchLine && !h->found) {
+                                               std::smatch result;
+                                               if (std::regex_search(txt, result, ttsMainRegex)) {
+                                                       auto sub = result[1].str();
+                                                       h->found = std::regex_search(sub, *h->searchLine);
+                                               }
+                                       }
+                               });
+                               exec->outputStream() << "evaluation started\n";
+                               try {
+                                       result->evaluate(ec);
+                                       exec->outputStream() << "evaluation successed\n";
+                               } catch (EvaluationFailure &e) {
+                                       if (e.hasLocation())
+                                               exec->outputStream() << e.location().toString() << ": ";
+                                       exec->outputStream() << e.message() << "\nevaluation failed\n";
+                               } catch (...) {
+                                       exec->outputStream() << "unhandled exception\nevaluation failed\n";
+                               }
+                       } else {
+                               exec->outputStream() << "timeouted\n";
+                               DEBUG("timeouted, when waiting for context change");
+                       }
+                       outputPtr->flush();
+                       executeOnMainThread([]()
+                       {
+                               ecore_main_loop_quit();
+                       });
+                       DEBUG("done batch");
+               } };
 }

diff --git a/src/batch/Dlog.cpp b/src/batch/Dlog.cpp
new file mode 100644 (file)
index 0000000..7a26f37
--- /dev/null
+++ b/src/batch/Dlog.cpp
@@ -0,0 +1,124 @@
+#include "Dlog.hpp"
+#include "../UniversalSwitchLog.hpp"
+#include <sys/types.h>
+#include <sys/stat.h>
+#include <fcntl.h>
+#include <unistd.h>
+#include <vector>
+#include <string>
+#include <sstream>
+
+Dlog::Handler::~Handler()
+{
+       auto h = state->lock();
+       h->listeners.erase(it);
+}
+
+Dlog::~Dlog()
+{
+       terminate();
+}
+
+auto Dlog::registerCallback(Callback c) -> Handler
+{
+       auto h = state->lock();
+       h->listeners.push_back(std::move(c));
+       auto it = --h->listeners.end();
+       return Handler{ state, it };
+}
+
+void Dlog::terminate()
+{
+       if (fdForClosing) {
+               char c = 0;
+               (void)write(*fdForClosing, &c, 1);
+               ASSERT(thr.joinable());
+               DEBUG("waiting for thread...");
+               thr.join();
+               DEBUG("waiting for thread done");
+               fdForClosing = {};
+       }
+}
+
+bool Dlog::start()
+{
+       int closingFd[2] = { -1, -1 };
+
+       if (pipe(closingFd) == -1) {
+               ERROR("failed to create pipes (%s)", strerror(errno));
+               return false;
+       }
+
+       auto const dlogFilePath = "/tmp/qe9fh483fb4i3fb8we3_universal_switch_dlog.txt";
+       int dlogFile = open(dlogFilePath, O_RDONLY);
+       if (dlogFile < 0) {
+               ERROR("failed to open file '%s' (%s)", dlogFilePath, strerror(errno));
+               return false;
+       }
+
+       fdForClosing = std::make_unique<int>(closingFd[1]);
+       thr = std::thread{ [state = this->state, closingFd = closingFd[0], dlogFile] {
+                       std::vector<char> tmp(1024 * 128);
+                       std::string line;
+                       size_t pos = 0;
+
+                       while (true)
+                       {
+                               fd_set set;
+                               FD_ZERO(&set);
+                               FD_SET(closingFd, &set);
+                               FD_SET(dlogFile, &set);
+                               auto result = select(std::max(closingFd, dlogFile) + 1, &set, NULL, NULL, NULL);
+                               if (result < 0) {
+                                       ERROR("select failed");
+                                       break;
+                               }
+                               if (FD_ISSET(closingFd, &set)) {
+                                       DEBUG("terminating...");
+                                       break;
+                               }
+                               if (FD_ISSET(dlogFile, &set)) {
+                                       if (pos + 1024 > tmp.size())
+                                               tmp.resize(tmp.size() * 2);
+                                       ASSERT(pos + 1024 <= tmp.size());
+                                       auto count = read(dlogFile, tmp.data() + pos, 1024);
+                                       if (count < 0) {
+                                               ERROR("failed to read from pipe (%s)", strerror(errno));
+                                               break;
+                                       } else if (count == 0) {
+                                               // sanity sleep to prevent consumption of all resources, when something goes hirewire
+                                               // and we'll get count = 0 all the time
+                                               // NOTE: for some reason this is currently mandatory, as select returns dlogFile as always ready
+                                               DEBUG("!!");
+                                               std::this_thread::sleep_for(std::chrono::milliseconds{ 10 });
+                                               continue;
+                                       }
+                                       {
+                                               auto h = state->lock();
+                                               Optional<size_t> lastEndOfLine = {};
+                                               auto finalPos = pos + static_cast<size_t>(count);
+                                               for (; pos < finalPos; ++pos) {
+                                                       if (tmp[pos] == '\n') {
+                                                               auto first = lastEndOfLine ? (*lastEndOfLine + 1) : 0;
+                                                               line.replace(0, line.size(), tmp.data() + first, pos - first);
+                                                               ASSERT(line.size() == pos - first);
+                                                               for (auto &f : h->listeners)
+                                                                       f(line);
+                                                               lastEndOfLine = pos;
+                                                       }
+                                               }
+                                               if (lastEndOfLine) {
+                                                       auto remainingSize = pos - (*lastEndOfLine + 1);
+                                                       memmove(tmp.data(), tmp.data() + *lastEndOfLine + 1, remainingSize);
+                                                       pos = remainingSize;
+                                               }
+                                       }
+                               } else {
+                                       DEBUG("spurious wake...");
+                               }
+                       }
+                       close(closingFd);
+                       close(dlogFile);
+               } };
+       return true;
+}
\ No newline at end of file

diff --git a/src/batch/Dlog.hpp b/src/batch/Dlog.hpp
new file mode 100644 (file)
index 0000000..e0d4e1d
--- /dev/null
+++ b/src/batch/Dlog.hpp
@@ -0,0 +1,58 @@
+#ifndef DLOG_HPP
+#define DLOG_HPP
+
+#include "Monitor.hpp"
+
+#include <list>
+#include <memory>
+#include <functional>
+#include <thread>
+
+class Dlog
+{
+       struct State;
+public:
+       Dlog() = default;
+       Dlog(Dlog &&) = default;
+       Dlog(const Dlog &) = delete;
+       ~Dlog();
+
+       Dlog &operator = (const Dlog &) = delete;
+       Dlog &operator = (Dlog &&) = default;
+
+       using Callback = std::function<void(const std::string &)>;
+       using CallbacksList = std::list<Callback>;
+       using MonitoredState = std::shared_ptr<Monitor<State>>;
+
+       class Handler
+       {
+       public:
+               Handler() = default;
+               Handler(const Handler &) = delete;
+               Handler(Handler &&) = default;
+               ~Handler();
+
+               Handler &operator = (const Handler &) = delete;
+               Handler &operator = (Handler &&) = default;
+       private:
+               friend class Dlog;
+
+               Handler(MonitoredState state, CallbacksList::iterator it) : state(std::move(state)), it(it) { }
+
+               MonitoredState state;
+               CallbacksList::iterator it;
+       };
+
+       bool start();
+       Handler registerCallback(Callback c);
+       void terminate();
+private:
+       struct State {
+               CallbacksList listeners;
+       };
+       MonitoredState state = std::make_shared<Monitor<State>>();
+       std::unique_ptr<int> fdForClosing;
+       std::thread thr;
+};
+
+#endif