Donate to e Foundation | Murena handsets with /e/OS | Own a part of Murena! Learn more

Commit c9e5f371 authored by Mark Salyzyn's avatar Mark Salyzyn
Browse files

liblog: add android_lookupEventTagNum 

android_lookupEventTagNum added.  Adds support for creating a new
log tag at runtime, registered to the logd service.

Tested on Hikey, all services stopped, shell only access, CPUs not
locked (there is enough repeatability on this platform).

$ /data/nativetest64/liblog-benchmarks/liblog-benchmarks BM_lookupEventTagNum

                          iterations      ns/op
Precharge: start
Precharge: stop 231
NB: only Tag matching, linear lookup (as reference, before unordered_map)
BM_lookupEventTagNum         1000000       1017
NB: unordered_map with full Tag & Format lookup, but with Tag hashing
BM_lookupEventTagNum         2000000        683
NB: with full Tag & Format hash and lookup for matching
BM_lookupEventTagNum         2000000        814
NB: only Tag matching (Hail Mary path)
BM_lookupEventTagNum         5000000        471

Because the database can now be dynamic, we added reader/writer locks
which adds a 65ns (uncontended) premium on lookups, and switch to
check for an allocation adds 25ns (either open code, or using
string_view, no difference) which means our overall speed takes 90%
as long as the requests did before we switched to unordered_map.
Faster than before where we originally utilized binary lookup on
static content, but not by much.  Dynamic updates that are not cached
locally take the following times to acquire long path to logd to
generate.

BM_lookupEventTag           20000000         139
BM_lookupEventTag_NOT       20000000         87
BM_lookupEventFormat        20000000         139
BM_lookupEventTagNum_logd_new   5000         335936
BM_lookupEventTagNum_logd_existing 10000     249226

The long path pickups are mitigated by the built-in caching, and
the public mapping in /dev/event-log-tags.

SideEffects: Event tags and signal handlers do not mix
Test: liblog benchmarks
Bug: 31456426
Change-Id: I69e6489d899cf35cdccffcee0d8d7cad469ada0a
parent 7da7fab7

liblog/event_tag_map.cpp

+200 −17
Original line number Diff line number Diff line
@@ -19,6 +19,7 @@ 
#include <errno.h>

#include <fcntl.h>

#include <inttypes.h>

#include <limits.h>

#include <stdio.h>

#include <stdlib.h>

#include <string.h>
@@ -26,15 +27,63 @@ 


#include <experimental/string_view>

#include <functional>

#include <string>

#include <unordered_map>



#include <log/event_tag_map.h>

#include <utils/FastStrcmp.h>

#include <utils/RWLock.h>

#include <private/android_logger.h>



#include "log_portability.h"

#include "logd_reader.h"



#define OUT_TAG "EventTagMap"



typedef std::experimental::string_view MapString;

class MapString {

private:

    const std::string* alloc; // HAS-AN

    const std::experimental::string_view str; // HAS-A



public:

    operator const std::experimental::string_view() const { return str; }



    const char* data() const { return str.data(); }

    size_t length() const { return str.length(); }



    bool operator== (const MapString& rval) const {

        if (length() != rval.length()) return false;

        if (length() == 0) return true;

        return fastcmp<strncmp>(data(), rval.data(), length()) == 0;

    }

    bool operator!= (const MapString& rval) const {

        return !(*this == rval);

    }



    MapString(const char* str, size_t len) : alloc(NULL), str(str, len) { }

    explicit MapString(const std::string& str) :

            alloc(new std::string(str)),

            str(alloc->data(), alloc->length()) { }

    MapString(MapString &&rval) :

            alloc(rval.alloc),

            str(rval.data(), rval.length()) {

        rval.alloc = NULL;

    }

    explicit MapString(const MapString &rval) :

            alloc(rval.alloc ? new std::string(*rval.alloc) : NULL),

            str(alloc ? alloc->data() : rval.data(), rval.length()) { }



    ~MapString() { if (alloc) delete alloc; }

};



// Hash for MapString

template <> struct std::hash<MapString>

        : public std::unary_function<const MapString&, size_t> {

    size_t operator()(const MapString& __t) const noexcept {

        if (!__t.length()) return 0;

        return std::hash<std::experimental::string_view>()(std::experimental::string_view(__t));

    }

};



typedef std::pair<MapString, MapString> TagFmt;
@@ -60,6 +109,10 @@ struct EventTagMap { 


private:

    std::unordered_map<uint32_t, TagFmt> Idx2TagFmt;

    std::unordered_map<TagFmt, uint32_t> TagFmt2Idx;

    std::unordered_map<MapString, uint32_t> Tag2Idx;

    // protect unordered sets

    android::RWLock rwlock;



public:

    EventTagMap() {
@@ -69,6 +122,8 @@ public: 


    ~EventTagMap() {

        Idx2TagFmt.clear();

        TagFmt2Idx.clear();

        Tag2Idx.clear();

        for (size_t which = 0; which < NUM_MAPS; ++which) {

            if (mapAddr[which]) {

                munmap(mapAddr[which], mapLen[which]);
@@ -79,16 +134,22 @@ public: 


    bool emplaceUnique(uint32_t tag, const TagFmt& tagfmt, bool verbose = false);

    const TagFmt* find(uint32_t tag) const;

    int find(TagFmt&& tagfmt) const;

    int find(MapString&& tag) const;

};



bool EventTagMap::emplaceUnique(uint32_t tag, const TagFmt& tagfmt, bool verbose) {

    bool ret = true;

    static const char errorFormat[] = OUT_TAG ": duplicate tag entries %" PRIu32

                                      ":%.*s:%.*s and %" PRIu32

                                      ":%.*s:%.*s)\n";

    android::RWLock::AutoWLock writeLock(rwlock);

    {

        std::unordered_map<uint32_t, TagFmt>::const_iterator it;

        it = Idx2TagFmt.find(tag);

        if (it != Idx2TagFmt.end()) {

            if (verbose) {

            fprintf(stderr,

                    OUT_TAG ": duplicate tag entries %" PRIu32

                        ":%.*s:%.*s and %" PRIu32 ":%.*s:%.*s)\n",

                fprintf(stderr, errorFormat,

                        it->first,

                        (int)it->second.first.length(), it->second.first.data(),

                        (int)it->second.second.length(), it->second.second.data(),
@@ -96,20 +157,70 @@ bool EventTagMap::emplaceUnique(uint32_t tag, const TagFmt& tagfmt, bool verbose 
                        (int)tagfmt.first.length(), tagfmt.first.data(),

                        (int)tagfmt.second.length(), tagfmt.second.data());

            }

        return false;

            ret = false;

        } else {

            Idx2TagFmt.emplace(std::make_pair(tag, tagfmt));

        }

    }



    Idx2TagFmt.emplace(std::make_pair(tag, tagfmt));

    return true;

    {

        std::unordered_map<TagFmt, uint32_t>::const_iterator it;

        it = TagFmt2Idx.find(tagfmt);

        if (it != TagFmt2Idx.end()) {

            if (verbose) {

                fprintf(stderr, errorFormat,

                        it->second,

                        (int)it->first.first.length(), it->first.first.data(),

                        (int)it->first.second.length(), it->first.second.data(),

                        tag,

                        (int)tagfmt.first.length(), tagfmt.first.data(),

                        (int)tagfmt.second.length(), tagfmt.second.data());

            }

            ret = false;

        } else {

            TagFmt2Idx.emplace(std::make_pair(tagfmt, tag));

        }

    }



    {

        std::unordered_map<MapString, uint32_t>::const_iterator it;

        it = Tag2Idx.find(tagfmt.first);

        if (!tagfmt.second.length() && (it != Tag2Idx.end())) {

            Tag2Idx.erase(it);

            it = Tag2Idx.end();

        }

        if (it == Tag2Idx.end()) {

            Tag2Idx.emplace(std::make_pair(tagfmt.first, tag));

        }

    }



    return ret;

}



const TagFmt* EventTagMap::find(uint32_t tag) const {

    std::unordered_map<uint32_t, TagFmt>::const_iterator it;

    android::RWLock::AutoRLock readLock(const_cast<android::RWLock&>(rwlock));

    it = Idx2TagFmt.find(tag);

    if (it == Idx2TagFmt.end()) return NULL;

    return &(it->second);

}



int EventTagMap::find(TagFmt&& tagfmt) const {

    std::unordered_map<TagFmt, uint32_t>::const_iterator it;

    android::RWLock::AutoRLock readLock(const_cast<android::RWLock&>(rwlock));

    it = TagFmt2Idx.find(std::move(tagfmt));

    if (it == TagFmt2Idx.end()) return -1;

    return it->second;

}



int EventTagMap::find(MapString&& tag) const {

    std::unordered_map<MapString, uint32_t>::const_iterator it;

    android::RWLock::AutoRLock readLock(const_cast<android::RWLock&>(rwlock));

    it = Tag2Idx.find(std::move(tag));

    if (it == Tag2Idx.end()) return -1;

    return it->second;

}



// Scan one tag line.

//

// "*pData" should be pointing to the first digit in the tag number.  On
@@ -380,3 +491,75 @@ LIBLOG_ABI_PUBLIC const char* android_lookupEventTag(const EventTagMap* map, 
    if (*cp) *cp = '\0'; // Trigger copy on write :-( and why deprecated.

    return tagStr;

}



// Look up tagname, generate one if necessary, and return a tag

LIBLOG_ABI_PUBLIC int android_lookupEventTagNum(EventTagMap* map,

                                                const char* tagname,

                                                const char* format,

                                                int prio) {

    size_t len = strlen(tagname);

    if (!len) {

        errno = EINVAL;

        return -1;

    }



    if ((prio != ANDROID_LOG_UNKNOWN) && (prio < ANDROID_LOG_SILENT) &&

            !__android_log_is_loggable_len(prio, tagname, len,

                                           __android_log_is_debuggable() ?

                                             ANDROID_LOG_VERBOSE :

                                             ANDROID_LOG_DEBUG)) {

        errno = EPERM;

        return -1;

    }



    if (!format) format="";

    ssize_t fmtLen = strlen(format);

    int ret = map->find(TagFmt(std::make_pair(MapString(tagname, len),

                                              MapString(format, fmtLen))));

    if (ret != -1) return ret;



    // call event tag service to arrange for a new tag

    char *buf = NULL;

    // Can not use android::base::StringPrintf, asprintf + free instead.

    static const char command_template[] = "getEventTag name=%s format=\"%s\"";

    ret = asprintf(&buf, command_template, tagname, format);

    if (ret > 0) {

        // Add some buffer margin for an estimate of the full return content.

        char *cp;

        size_t size = ret - strlen(command_template) +

            strlen("65535\n4294967295\t?\t\t\t?\t# uid=32767\n\n\f?success?");

        if (size > (size_t)ret) {

            cp = static_cast<char*>(realloc(buf, size));

            if (cp) {

                buf = cp;

            } else {

                size = ret;

            }

        } else {

            size = ret;

        }

        // Ask event log tag service for an allocation

        if (__send_log_msg(buf, size) >= 0) {

            buf[size - 1] = '\0';

            unsigned long val = strtoul(buf, &cp, 10); // return size

            if ((buf != cp) && (val > 0) && (*cp == '\n')) { // truncation OK

                val = strtoul(cp + 1, &cp, 10); // allocated tag number

                if ((val > 0) && (val < UINT32_MAX) && (*cp == '\t')) {

                    free(buf);

                    ret = val;

                    // cache

                    map->emplaceUnique(ret, TagFmt(std::make_pair(

                            MapString(std::string(tagname, len)),

                            MapString(std::string(format, fmtLen)))));

                    return ret;

                }

            }

        }

        free(buf);

    }



    // Hail Mary

    ret = map->find(MapString(tagname, len));

    if (ret == -1) errno = ESRCH;

    return ret;

}

liblog/fake_log_device.c

+6 −0
Original line number Diff line number Diff line
@@ -715,6 +715,12 @@ LIBLOG_HIDDEN ssize_t fakeLogWritev(int fd, 
    return redirectWritev(fd, vector, count);

}



LIBLOG_HIDDEN ssize_t __send_log_msg(char *buf __unused,

                                     size_t buf_size __unused)

{

    return -ENODEV;

}



LIBLOG_ABI_PUBLIC int __android_log_is_loggable(int prio,

                                                const char *tag __unused,

                                                int def)

liblog/include/log/event_tag_map.h

+6 −0
Original line number Diff line number Diff line
@@ -58,6 +58,12 @@ const char* android_lookupEventTag_len(const EventTagMap* map, 
const char* android_lookupEventFormat_len(const EventTagMap* map,

                                          size_t* len, unsigned int tag);



/*

 * Look up tagname, generate one if necessary, and return a tag

 */

int android_lookupEventTagNum(EventTagMap* map, const char* tagname,

                              const char* format, int prio);



#ifdef __cplusplus

}

#endif

liblog/logd_reader.c

+6 −0
Original line number Diff line number Diff line
@@ -37,6 +37,7 @@ 


#include "config_read.h"

#include "log_portability.h"

#include "logd_reader.h"

#include "logger.h"



/* branchless on many architectures. */
@@ -324,6 +325,11 @@ done: 
    return ret;

}



LIBLOG_HIDDEN ssize_t __send_log_msg(char *buf, size_t buf_size)

{

    return send_log_msg(NULL, NULL, buf, buf_size);

}



static int check_log_success(char *buf, ssize_t ret)

{

    if (ret < 0) {

liblog/logd_reader.h

0 → 100644
+30 −0
Original line number Diff line number Diff line 
/*

 * Copyright (C) 2016 The Android Open Source Project

 *

 * Licensed under the Apache License, Version 2.0 (the "License");

 * you may not use this file except in compliance with the License.

 * You may obtain a copy of the License at

 *

 *      http://www.apache.org/licenses/LICENSE-2.0

 *

 * Unless required by applicable law or agreed to in writing, software

 * distributed under the License is distributed on an "AS IS" BASIS,

 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.

 * See the License for the specific language governing permissions and

 * limitations under the License.

 */



#ifndef _LIBLOG_LOGD_READER_H__

#define _LIBLOG_LOGD_READER_H__



#include <unistd.h>



#include "log_portability.h"



__BEGIN_DECLS



LIBLOG_HIDDEN ssize_t __send_log_msg(char *buf, size_t buf_size);



__END_DECLS



#endif /* _LIBLOG_LOGD_READER_H__ */