static void internal_emit_self_described_event_va()

in v2/src/log_sink_etw.c [212:560]


static void internal_emit_self_described_event_va(const char* event_name, uint16_t event_name_length, uint8_t trace_level, const LOG_CONTEXT_PROPERTY_VALUE_PAIR* context_property_value_pairs, uint16_t property_value_count, const char* file, const char* func, int32_t line, const char* message_format, va_list args)
{
    TraceLoggingHProvider const _tlgProv = log_sink_etw_provider;
    if (trace_level < _tlgProv->LevelPlus1)
    {
        // have a stack allocated buffer where we construct the event metadata and
        SELF_DESCRIBED_EVENT _tlgEvent;
        bool add_properties = true;

        // compute event metadata size
        // event_name_length includes NULL terminator
        /* Codes_SRS_LOG_SINK_ETW_01_042: [ log_sink_etw.log shall compute the metadata size for the self described event metadata as follows: ]*/
        /* Codes_SRS_LOG_SINK_ETW_01_043: [ Size of the event name. ]*/
        uint16_t i;

        // An eve

        // alias to the event bytes
        uint8_t* pos = &_tlgEvent.metadata[0];

        // fill metadata bytes
        // first one is the event name, followed by metadata for all the fields
        // copy event name
        (void)memcpy(pos, event_name, event_name_length); pos += event_name_length;

        // copy the field metadata (name and in type)

        /* Codes_SRS_LOG_SINK_ETW_01_034: [ log_sink_etw.log shall fill the event metadata: ]*/

        /* Codes_SRS_LOG_SINK_ETW_01_035: [ The string content (as field name, excluding zero terminator), followed by one byte with the value TlgInANSISTRING. ]*/
        /* Codes_SRS_LOG_SINK_ETW_01_044: [ Size of the content field name. ]*/
        (void)memcpy(pos, "content", sizeof("content")); pos += sizeof("content");
        *pos = TlgInANSISTRING;  pos++;

        /* Codes_SRS_LOG_SINK_ETW_01_036: [ The string file (as field name, excluding zero terminator), followed by one byte with the value TlgInANSISTRING. ]*/
        /* Codes_SRS_LOG_SINK_ETW_01_045: [ Size of the file field name. ]*/
        (void)memcpy(pos, "file", sizeof("file")); pos += sizeof("file");
        *pos = TlgInANSISTRING;  pos++;

        /* Codes_SRS_LOG_SINK_ETW_01_037: [ The string func (as field name, excluding zero terminator), followed by one byte with the value TlgInANSISTRING. ]*/
        /* Codes_SRS_LOG_SINK_ETW_01_046: [ Size of the func field name. ]*/
        (void)memcpy(pos, "func", sizeof("func")); pos += sizeof("func");
        *pos = TlgInANSISTRING;  pos++;

        /* Codes_SRS_LOG_SINK_ETW_01_038: [ The string line (as field name, excluding zero terminator), followed by one byte with the value TlgInINT32. ]*/
        /* Codes_SRS_LOG_SINK_ETW_01_047: [ Size of the line field name. ]*/
        (void)memcpy(pos, "line", sizeof("line")); pos += sizeof("line");
        *pos = TlgInINT32;  pos++;

        uint16_t metadata_size_without_properties = (uint16_t)(pos - &_tlgEvent.metadata[0]);

        if (property_value_count <= LOG_MAX_ETW_PROPERTY_VALUE_PAIR_COUNT)
        {
            /* Codes_SRS_LOG_SINK_ETW_01_053: [ For each property in log_context the following shall be added to the event metadata: ]*/
            for (i = 0; i < property_value_count; i++)
            {
                /* Codes_SRS_LOG_SINK_ETW_01_051: [ For each property in log_context, the length of the property name + 1 and one extra byte for the type of the field. ]*/
                size_t name_length = strlen(context_property_value_pairs[i].name);
                /* Codes_SRS_LOG_SINK_ETW_01_085: [ If the size of the metadata and the formatted message exceeds 4096 bytes, log_sink_etw.log shall not add any properties to the event. ]*/
                if ((name_length > UINT16_MAX) ||
                    ((uint16_t)(&_tlgEvent.metadata[MAX_METADATA_SIZE] - pos) < name_length + 1 + 1))
                {
                    (void)printf("Property %" PRIu16 "/%" PRIu16 " does not fit for ETW event, file=%s, func=%s, line=%" PRId32 ".\r\n",
                        i, property_value_count, file, func, line);
                    add_properties = false;
                    break;
                }
                else
                {
                    /* Codes_SRS_LOG_SINK_ETW_01_054: [ A string with the property name (including zero terminator) ]*/
                    (void)memcpy(pos, context_property_value_pairs[i].name, name_length + 1);
                    pos += name_length + 1;
                }

                LOG_CONTEXT_PROPERTY_TYPE property_type = context_property_value_pairs[i].type->get_type();

                /* Codes_SRS_LOG_SINK_ETW_01_055: [ A byte with the type of property, as follows: ]*/
                switch (property_type)
                {
                default:
                    /* Codes_SRS_LOG_SINK_ETW_01_081: [ If the property type is any other value, no property data shall be added to the event. ]*/
                    (void)printf("Invalid property type: %" PRI_MU_ENUM " for property %" PRIu16 "/%" PRIu16 " does not fit for ETW event, file=%s, func=%s, line=%" PRId32 ".\r\n",
                        MU_ENUM_VALUE(LOG_CONTEXT_PROPERTY_TYPE, property_type), i, property_value_count, file, func, line);
                    add_properties = false;
                    break;

                case LOG_CONTEXT_PROPERTY_TYPE_ascii_char_ptr:
                    /* Codes_SRS_LOG_SINK_ETW_01_063: [ If the property type is LOG_CONTEXT_PROPERTY_TYPE_ascii_char_ptr, a byte with the value TlgInANSISTRING shall be added in the metadata. ]*/
                    *pos = TlgInANSISTRING;
                    break;
                case LOG_CONTEXT_PROPERTY_TYPE_wchar_t_ptr:
                    /* Codes_SRS_LOG_SINK_ETW_07_003: [ If the property type is LOG_CONTEXT_PROPERTY_TYPE_wchar_t_ptr, a byte with the value TlgInUNICODESTRING shall be added in the metadata. */
                    *pos = TlgInUNICODESTRING;
                    break;
                case LOG_CONTEXT_PROPERTY_TYPE_bool:
                    /* Codes_SRS_LOG_SINK_ETW_07_001: [ If the property type is LOG_CONTEXT_PROPERTY_TYPE_bool, a byte with the value TlgInBOOL32 shall be added in the metadata. ]*/
                    *pos = TlgInBOOL32;
                    break;
                case LOG_CONTEXT_PROPERTY_TYPE_int64_t:
                    /* Codes_SRS_LOG_SINK_ETW_01_064: [ If the property type is LOG_CONTEXT_PROPERTY_TYPE_int64_t, a byte with the value TlgInINT64 shall be added in the metadata. ]*/
                    *pos = TlgInINT64;
                    break;
                case LOG_CONTEXT_PROPERTY_TYPE_uint64_t:
                    /* Codes_SRS_LOG_SINK_ETW_01_065: [ If the property type is LOG_CONTEXT_PROPERTY_TYPE_uint64_t, a byte with the value TlgInUINT64 shall be added in the metadata. ]*/
                    *pos = TlgInUINT64;
                    break;
                case LOG_CONTEXT_PROPERTY_TYPE_int32_t:
                    /* Codes_SRS_LOG_SINK_ETW_01_069: [ If the property type is LOG_CONTEXT_PROPERTY_TYPE_int32_t, a byte with the value TlgInINT32 shall be added in the metadata. ]*/
                    *pos = TlgInINT32;
                    break;
                case LOG_CONTEXT_PROPERTY_TYPE_uint32_t:
                    /* Codes_SRS_LOG_SINK_ETW_01_071: [ If the property type is LOG_CONTEXT_PROPERTY_TYPE_uint32_t, a byte with the value TlgInUINT32 shall be added in the metadata. ]*/
                    *pos = TlgInUINT32;
                    break;
                case LOG_CONTEXT_PROPERTY_TYPE_int16_t:
                    /* Codes_SRS_LOG_SINK_ETW_01_073: [ If the property type is LOG_CONTEXT_PROPERTY_TYPE_int16_t, a byte with the value TlgInINT16 shall be added in the metadata. ]*/
                    *pos = TlgInINT16;
                    break;
                case LOG_CONTEXT_PROPERTY_TYPE_uint16_t:
                    /* Codes_SRS_LOG_SINK_ETW_01_075: [ If the property type is LOG_CONTEXT_PROPERTY_TYPE_uint16_t, a byte with the value TlgInUINT16 shall be added in the metadata. ]*/
                    *pos = TlgInUINT16;
                    break;
                case LOG_CONTEXT_PROPERTY_TYPE_int8_t:
                    /* Codes_SRS_LOG_SINK_ETW_01_077: [ If the property type is LOG_CONTEXT_PROPERTY_TYPE_int8_t, a byte with the value TlgInINT8 shall be added in the metadata. ]*/
                    *pos = TlgInINT8;
                    break;
                case LOG_CONTEXT_PROPERTY_TYPE_uint8_t:
                    /* Codes_SRS_LOG_SINK_ETW_01_079: [ If the property type is LOG_CONTEXT_PROPERTY_TYPE_uint8_t, a byte with the value TlgInUINT8 shall be added in the metadata. ]*/
                    *pos = TlgInUINT8;
                    break;

                case LOG_CONTEXT_PROPERTY_TYPE_struct:
                    /* Codes_SRS_LOG_SINK_ETW_01_052: [ For struct properties one extra byte shall be added for the field count. ]*/
                    /* Codes_SRS_LOG_SINK_ETW_01_056: [ If the property type is LOG_CONTEXT_PROPERTY_TYPE_struct, a byte with the value _TlgInSTRUCT | _TlgInChain shall be added in the metadata. ]*/
                    *pos = _TlgInSTRUCT | _TlgInChain;
                    pos++;

                    if (pos == &_tlgEvent.metadata[MAX_METADATA_SIZE])
                    {
                        (void)printf("Property %" PRIu16 "/%" PRIu16 " does not fit for ETW event, file=%s, func=%s, line=%" PRId32 ".\r\n",
                            i, property_value_count, file, func, line);
                        add_properties = false;
                    }
                    else
                    {
                        /* Codes_SRS_LOG_SINK_ETW_01_057: [ If the property is a struct, an extra byte shall be added in the metadata containing the number of fields in the structure. ]*/
                        *pos = *((uint8_t*)context_property_value_pairs[i].value);
                    }
                    break;
                }

                if (!add_properties)
                {
                    break;
                }
                else
                {
                    pos++;
                }
            }
        }
        else
        {
            /* Codes_SRS_LOG_SINK_ETW_01_082: [ If more than 64 properties are given in log_context, log_sink_etw.log shall not add any properties to the event. ]*/
            add_properties = false;
        }

        /* Codes_SRS_LOG_SINK_ETW_01_026: [ log_sink_etw.log shall fill a SELF_DESCRIBED_EVENT structure, setting the following fields: ]*/
        uint16_t metadata_size;

        if (!add_properties)
        {
            metadata_size = metadata_size_without_properties;
            pos = &_tlgEvent.metadata[metadata_size_without_properties];
        }
        else
        {
            metadata_size = (uint16_t)(pos - &_tlgEvent.metadata[0]);
        }

        char* formatted_message = (char*)pos;
        size_t available_bytes = (char*)&_tlgEvent.metadata[MAX_METADATA_SIZE] - formatted_message;

        va_list saved_args;
        va_copy(saved_args, args);

        int formatted_message_length = vsnprintf(formatted_message, available_bytes, message_format, args);
        if (formatted_message_length < 0)
        {
            /* Codes_SRS_LOG_SINK_ETW_01_086: [ If any error occurs log_sink_etw.log shall print Error emitting ETW event and return. ]*/
            (void)printf("Error emitting ETW event with %" PRIu16 " properties, file=%s, func=%s, line=%" PRId32 ".\r\n",
                property_value_count, file, func, line);
        }
        else
        {
            if ((size_t)formatted_message_length >= available_bytes)
            {
                if (add_properties)
                {
                    // did not fit, print again without properties and limit it
                    /* Codes_SRS_LOG_SINK_ETW_01_085: [ If the size of the metadata and the formatted message exceeds 4096 bytes, log_sink_etw.log shall not add any properties to the event. ]*/
                    add_properties = false;
                    metadata_size = metadata_size_without_properties;

                    formatted_message = (char*)&_tlgEvent.metadata[metadata_size_without_properties];
                    available_bytes = (char*)&_tlgEvent.metadata[MAX_METADATA_SIZE] - formatted_message;
                    formatted_message_length = vsnprintf(formatted_message, available_bytes, message_format, saved_args);
                    if (formatted_message_length < 0)
                    {
                        /* Codes_SRS_LOG_SINK_ETW_01_086: [ If any error occurs log_sink_etw.log shall print Error emitting ETW event and return. ]*/
                        (void)printf("Error emitting ETW event with %" PRIu16 " properties, file=%s, func=%s, line=%" PRId32 ".\r\n",
                            property_value_count, file, func, line);
                    }
                    else
                    {
                        // make sure it is zero terminated
                        formatted_message[available_bytes - 1] = '\0';
                    }
                }
            }
            else
            {
                // Ok as is
            }

            if (formatted_message_length >= 0)
            {
                /* Codes_SRS_LOG_SINK_ETW_01_027: [ _tlgBlobTyp shall be set to _TlgBlobEvent4. ]*/
                _tlgEvent._tlgBlobTyp = _TlgBlobEvent4;

                /* Codes_SRS_LOG_SINK_ETW_01_028: [ _tlgChannel shall be set to 11. ]*/
                _tlgEvent._tlgChannel = 11;

                /* Codes_SRS_LOG_SINK_ETW_01_018: [ Logging level: ]*/
                /* Codes_SRS_LOG_SINK_ETW_01_029: [ _tlgLevel shall be set to the appropriate logging level. ]*/
                _tlgEvent._tlgLevel = trace_level;

                /* Codes_SRS_LOG_SINK_ETW_01_030: [ _tlgOpcode shall be set to 0. ]*/
                _tlgEvent._tlgOpcode = 0;

                /* Codes_SRS_LOG_SINK_ETW_01_031: [ _tlgKeyword shall be set to 0. ]*/
                _tlgEvent._tlgKeyword = 0;

                /* Codes_SRS_LOG_SINK_ETW_01_032: [ _tlgEvtMetaSize shall be set to the computed metadata size + 4. ]*/
                _tlgEvent._tlgEvtMetaSize = metadata_size + 4;

                /* Codes_SRS_LOG_SINK_ETW_01_033: [ _tlgEvtTag shall be set to 128. ]*/
                _tlgEvent._tlgEvtTag = 128;

                // now we need to fill in the event data descriptors
                // first 2 are actually reserved for the event descriptor and metadata respectively
                // all the rest starting at index 2 are actual data payloads in the event:
                // 1 for the content field (containing the formatted message)
                // 1 for the file field
                // 1 for the func field
                // 1 for the line field
                // n entries (1 for each property)
                /* Codes_SRS_LOG_SINK_ETW_01_039: [ log_sink_etw.log shall fill an EVENT_DATA_DESCRIPTOR array of size 2 + 1 + 1 + 1 + 1 + property count. ]*/
                EVENT_DATA_DESCRIPTOR _tlgData[2 + 1 + 1 + 1 + 1 + LOG_MAX_ETW_PROPERTY_VALUE_PAIR_COUNT];

                uint32_t _tlgIdx = 2;

                /* Codes_SRS_LOG_SINK_ETW_01_040: [ log_sink_etw.log shall set event data descriptor at index 2 by calling _tlgCreate1Sz_char with the value of the formatted message as obtained by using printf with the messages format message_format and the arguments in .... ]*/
                _tlgCreate1Sz_char(&_tlgData[_tlgIdx], formatted_message);
                _tlgIdx++;
                /* Codes_SRS_LOG_SINK_ETW_01_058: [ log_sink_etw.log shall set event data descriptor at index 3 by calling _tlgCreate1Sz_char with file. ]*/
                _tlgCreate1Sz_char(&_tlgData[_tlgIdx], file);
                _tlgIdx++;
                /* Codes_SRS_LOG_SINK_ETW_01_059: [ log_sink_etw.log shall set event data descriptor at index 4 by calling _tlgCreate1Sz_char with func. ]*/
                _tlgCreate1Sz_char(&_tlgData[_tlgIdx], func);
                _tlgIdx++;
                /* Codes_SRS_LOG_SINK_ETW_01_060: [ log_sink_etw.log shall set event data descriptor at index 5 by calling EventDataDescCreate with line. ]*/
                EventDataDescCreate(&_tlgData[_tlgIdx], &line, sizeof(int32_t));
                _tlgIdx++;

                if (add_properties)
                {
                    /* Codes_SRS_LOG_SINK_ETW_01_061: [ For each property in log_context: ]*/
                    for (i = 0; i < property_value_count; i++)
                    {
                        switch (context_property_value_pairs[i].type->get_type())
                        {
                        default:
                            break;
                        case LOG_CONTEXT_PROPERTY_TYPE_int64_t:
                            /* Codes_SRS_LOG_SINK_ETW_01_066: [ If the property type is LOG_CONTEXT_PROPERTY_TYPE_int64_t, the event data descriptor shall be filled with the value of the property by calling EventDataDescCreate. ]*/
                            EventDataDescCreate(&_tlgData[_tlgIdx], context_property_value_pairs[i].value, sizeof(int64_t));
                            break;
                        case LOG_CONTEXT_PROPERTY_TYPE_uint64_t:
                            /* Codes_SRS_LOG_SINK_ETW_01_068: [ If the property type is LOG_CONTEXT_PROPERTY_TYPE_uint64_t, the event data descriptor shall be filled with the value of the property by calling EventDataDescCreate. ]*/
                            EventDataDescCreate(&_tlgData[_tlgIdx], context_property_value_pairs[i].value, sizeof(uint64_t));
                            break;
                        case LOG_CONTEXT_PROPERTY_TYPE_int32_t:
                            /* Codes_SRS_LOG_SINK_ETW_01_070: [ If the property type is LOG_CONTEXT_PROPERTY_TYPE_int32_t, the event data descriptor shall be filled with the value of the property by calling EventDataDescCreate. ]*/
                            EventDataDescCreate(&_tlgData[_tlgIdx], context_property_value_pairs[i].value, sizeof(int32_t));
                            break;
                        case LOG_CONTEXT_PROPERTY_TYPE_uint32_t:
                            /* Codes_SRS_LOG_SINK_ETW_01_072: [ If the property type is LOG_CONTEXT_PROPERTY_TYPE_uint32_t, the event data descriptor shall be filled with the value of the property by calling EventDataDescCreate. ]*/
                            EventDataDescCreate(&_tlgData[_tlgIdx], context_property_value_pairs[i].value, sizeof(uint32_t));
                            break;
                        case LOG_CONTEXT_PROPERTY_TYPE_int16_t:
                            /* Codes_SRS_LOG_SINK_ETW_01_074: [ If the property type is LOG_CONTEXT_PROPERTY_TYPE_int16_t, the event data descriptor shall be filled with the value of the property by calling EventDataDescCreate. ]*/
                            EventDataDescCreate(&_tlgData[_tlgIdx], context_property_value_pairs[i].value, sizeof(int16_t));
                            break;
                        case LOG_CONTEXT_PROPERTY_TYPE_uint16_t:
                            /* Codes_SRS_LOG_SINK_ETW_01_076: [ If the property type is LOG_CONTEXT_PROPERTY_TYPE_uint16_t, the event data descriptor shall be filled with the value of the property by calling EventDataDescCreate. ]*/
                            EventDataDescCreate(&_tlgData[_tlgIdx], context_property_value_pairs[i].value, sizeof(uint16_t));
                            break;
                        case LOG_CONTEXT_PROPERTY_TYPE_int8_t:
                            /* Codes_SRS_LOG_SINK_ETW_01_078: [ If the property type is LOG_CONTEXT_PROPERTY_TYPE_int8_t, the event data descriptor shall be filled with the value of the property by calling EventDataDescCreate. ]*/
                            EventDataDescCreate(&_tlgData[_tlgIdx], context_property_value_pairs[i].value, sizeof(int8_t));
                            break;
                        case LOG_CONTEXT_PROPERTY_TYPE_uint8_t:
                            /* Codes_SRS_LOG_SINK_ETW_01_080: [ If the property type is LOG_CONTEXT_PROPERTY_TYPE_uint8_t, the event data descriptor shall be filled with the value of the property by calling EventDataDescCreate. ]*/
                            EventDataDescCreate(&_tlgData[_tlgIdx], context_property_value_pairs[i].value, sizeof(uint8_t));
                            break;
                        case LOG_CONTEXT_PROPERTY_TYPE_bool:
                            static const int32_t true_value = 1;
                            static const int32_t false_value = 0;
                            /* Codes_SRS_LOG_SINK_ETW_07_002: [ If the property type is LOG_CONTEXT_PROPERTY_TYPE_bool, the event data descriptor shall be filled with the value of the property by calling EventDataDescCreate. ]*/
                            EventDataDescCreate(&_tlgData[_tlgIdx], *(bool*)context_property_value_pairs[i].value ? &true_value : &false_value, sizeof(int32_t));
                            break;
                        case LOG_CONTEXT_PROPERTY_TYPE_ascii_char_ptr:
                            /* Codes_SRS_LOG_SINK_ETW_01_067: [ If the property type is LOG_CONTEXT_PROPERTY_TYPE_ascii_char_ptr, the event data descriptor shall be filled with the value of the property by calling _tlgCreate1Sz_char. ]*/
                            _tlgCreate1Sz_char(&_tlgData[_tlgIdx], context_property_value_pairs[i].value);
                            break;
                        case LOG_CONTEXT_PROPERTY_TYPE_wchar_t_ptr:
                            /* Codes_SRS_LOG_SINK_ETW_07_004: [ If the property type is LOG_CONTEXT_PROPERTY_TYPE_wchar_t_ptr, the event data descriptor shall be filled with the value of the property by calling _tlgCreate1Sz_wchar_t. ]*/
                            _tlgCreate1Sz_wchar_t(&_tlgData[_tlgIdx], context_property_value_pairs[i].value);
                            break;
                        case LOG_CONTEXT_PROPERTY_TYPE_struct:
                            /* Codes_SRS_LOG_SINK_ETW_01_062: [ If the property type is LOG_CONTEXT_PROPERTY_TYPE_struct, no event data descriptor shall be used. ]*/
                            _tlgIdx--;
                            break;
                        }

                        _tlgIdx++;
                    }
                }

                // ... AND drumrolls, emit the event
                /* Codes_SRS_LOG_SINK_ETW_01_041: [ log_sink_etw.log shall emit the event by calling _tlgWriteTransfer_EventWriteTransfer passing the provider, channel, number of event data descriptors and the data descriptor array. ]*/
                _tlgWriteTransfer_EventWriteTransfer(_tlgProv, &_tlgEvent._tlgChannel, NULL, NULL, _tlgIdx, _tlgData);
            }
        }

        va_end(saved_args);
    }
}