Skip to content
This repository was archived by the owner on Jul 19, 2018. It is now read-only.

WIP: Logger Strawman #2475

Open
jzulauf-lunarg wants to merge 2 commits into
base: master
Choose a base branch
from
Open

WIP: Logger Strawman #2475

Show file tree
Hide file tree
Changes from 1 commit
Commits
Show all changes
2 commits
Select commit Hold shift + click to select a range
d92ce37
layers: Update CmdPushConstant Valid Usages
jzulauf-lunarg Mar 5, 2018
c513ac2
layers: Strawman/dartboard new message logger
jzulauf-lunarg Mar 9, 2018
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
26 changes: 10 additions & 16 deletions layers/core_validation.cpp
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -412,11 +412,10 @@ static bool ValidateMemoryIsValid(layer_data *dev_data, VkDeviceMemory mem, uint
DEVICE_MEM_INFO *mem_info = GetMemObjInfo(dev_data, mem);
if (mem_info) {
if (!mem_info->bound_ranges[bound_object_handle].valid) {
return log_msg(dev_data->report_data, VK_DEBUG_REPORT_WARNING_BIT_EXT, VK_DEBUG_REPORT_OBJECT_TYPE_DEVICE_MEMORY_EXT,
HandleToUint64(mem), __LINE__, MEMTRACK_INVALID_MEM_REGION, "MEM",
"%s: Cannot read invalid region of memory allocation 0x%" PRIx64 " for bound %s object 0x%" PRIx64
", please fill the memory before using.",
functionName, HandleToUint64(mem), object_string[type], bound_object_handle);
LOG_WARN_MSG(nullptr, msg, dev_data->report_data, mem, MEMTRACK_INVALID_MEM_REGION, "MEM");

@jzulauf-lunarg jzulauf-lunarg Mar 9, 2018

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

In looking for good examples I stumbled across VerifyBoundMemoryIsValid , which is using the wrong object types (hard coded image for things that can be buffers)... implementing the auto detection is going to take changing some interfaces (like that one) to not convert handles (which will probably fix some latent bugs) and templatizing things like VerifyBoundMemoryIsValid... that or adding LogMsg constructors that take uint64_t/object_type pairs.

msg.add(functionName).add(": Cannot read invalid region of memory allocation ").add_h(mem);
msg.add_fmt(" for bound %s object ", object_string[type]).add_h(bound_object_handle);
return msg.report();
}
}
return false;
Expand Down Expand Up @@ -1303,11 +1302,8 @@ static bool ValidatePipelineLocked(layer_data *dev_data, std::vector<std::unique
"Invalid Pipeline CreateInfo: exactly one of base pipeline index and handle must be specified");
} else if (pPipeline->graphicsPipelineCI.basePipelineIndex != -1) {
if (pPipeline->graphicsPipelineCI.basePipelineIndex >= pipelineIndex) {
skip |=
log_msg(dev_data->report_data, VK_DEBUG_REPORT_ERROR_BIT_EXT, VK_DEBUG_REPORT_OBJECT_TYPE_PIPELINE_EXT,
HandleToUint64(pPipeline->pipeline), __LINE__, VALIDATION_ERROR_208005a0, "DS",
"Invalid Pipeline CreateInfo: base pipeline must occur earlier in array than derivative pipeline. %s",
validation_error_map[VALIDATION_ERROR_208005a0]);
LOG_ERR_MSG(&skip, msg, dev_data->report_data, pPipeline->pipeline, VALIDATION_ERROR_208005a0, "DS");
msg.add("Invalid Pipeline CreateInfo: base pipeline must occur earlier in array than derivative pipeline.");
} else {
pBasePipeline = pPipelines[pPipeline->graphicsPipelineCI.basePipelineIndex].get();
}
Expand Down Expand Up @@ -2681,12 +2677,10 @@ static bool validateQueueFamilyIndices(layer_data *dev_data, GLOBAL_CB_NODE *pCB

if (pPool && queue_state) {
if (pPool->queueFamilyIndex != queue_state->queueFamilyIndex) {
skip |= log_msg(dev_data->report_data, VK_DEBUG_REPORT_ERROR_BIT_EXT, VK_DEBUG_REPORT_OBJECT_TYPE_COMMAND_BUFFER_EXT,
HandleToUint64(pCB->commandBuffer), __LINE__, VALIDATION_ERROR_31a00094, "DS",
"vkQueueSubmit: Primary command buffer 0x%" PRIx64
" created in queue family %d is being submitted on queue 0x%" PRIx64 " from queue family %d. %s",
HandleToUint64(pCB->commandBuffer), pPool->queueFamilyIndex, HandleToUint64(queue),
queue_state->queueFamilyIndex, validation_error_map[VALIDATION_ERROR_31a00094]);
LOG_ERR_MSG(&skip, msg, dev_data->report_data, pCB->commandBuffer, VALIDATION_ERROR_31a00094, "DS");
msg.add("vkQueueSubmit: Primary command buffer ").add_h(pCB->commandBuffer);

@jzulauf-lunarg jzulauf-lunarg Mar 9, 2018

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

with more code gen, the add_h could be removed in favor of "overloads per handle type", s.t. all handles are known for what they are.

@krOoze krOoze Mar 10, 2018

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

skip, report_data, objType + object, layer name, and function name are usually constants for the whole function.
Would be nice not having to repeat them. Maybe class Logger? Then Logger log(all the above) and then per case log.err(veid, msg) or log.warn()?

@jzulauf-lunarg jzulauf-lunarg Mar 11, 2018

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Perhaps a LoggerContext that could be used in a LogMsg constructor

msg << " created in queue family " << pPool->queueFamilyIndex << "is being submitted on queue ";
msg.add_h(queue) << " from queue family " << queue_state->queueFamilyIndex;
}

// Ensure that any bound images or buffers created with SHARING_MODE_CONCURRENT have access to the current queue family
Expand Down
157 changes: 150 additions & 7 deletions layers/vk_layer_logging.h
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -26,13 +26,16 @@
#include "vk_layer_config.h"
#include "vk_layer_data.h"
#include "vk_layer_table.h"
#include "vk_validation_error_messages.h"
#include "vk_loader_platform.h"
#include "vk_object_types.h"
#include "vulkan/vk_layer.h"
#include <signal.h>
#include <cinttypes>
#include <stdarg.h>
#include <stdbool.h>
#include <stdio.h>
#include <sstream>
#include <unordered_map>
#include <vector>

Expand Down Expand Up @@ -314,29 +317,42 @@ static inline void layer_disable_tmp_callbacks(debug_report_data *debug_data, ui
// Checks if the message will get logged.
// Allows layer to defer collecting & formating data if the
// message will be discarded.
static inline bool will_log_msg(debug_report_data *debug_data, VkFlags msgFlags) {
static inline bool will_log_msg(const debug_report_data *debug_data, VkFlags msgFlags) {
if (!debug_data || !(debug_data->active_flags & msgFlags)) {
// Message is not wanted
return false;
}

return true;
}

// sprintf to std::string, concatenating onto to_string if non-null, returns formatted string by value
#ifndef WIN32
static inline int string_sprintf(std::string *output, const char *fmt, ...) __attribute__((format(printf, 2, 3)));
static inline std::string string_sprintf(std::string *to_string, const char *fmt, ...) __attribute__((format(printf, 2, 3)));

@jzulauf-lunarg jzulauf-lunarg Mar 9, 2018

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

ignore this... I was planning to use it in the logger and discovered it wasn't actually working... these changes to show up in a separate PR.

#endif
static inline int string_sprintf(std::string *output, const char *fmt, ...) {
std::string &formatted = *output;
static inline std::string string_sprintf(std::string *to_string, const char *fmt, ...) {
std::string local;
to_string = (nullptr != to_string) ? to_string : &local;
std::string &formatted = *to_string;
size_t offset = formatted.size();

// Find out how many bytes we'll need.
va_list argptr;
va_start(argptr, fmt);
int reserve = vsnprintf(nullptr, 0, fmt, argptr);
va_end(argptr);
formatted.reserve(reserve + 1);
formatted.reserve(offset + reserve + 1);
formatted.resize(offset + reserve);

// sprintf those bytes to the output
va_start(argptr, fmt);
int result = vsnprintf((char *)formatted.data(), formatted.capacity(), fmt, argptr);
#ifndef NDEBUG
int result =
#endif
vsnprintf((char *)formatted.data() + offset, formatted.capacity(), fmt, argptr);
va_end(argptr);
assert(result == reserve);
return result;
return formatted;
}

#ifdef WIN32
Expand Down Expand Up @@ -439,4 +455,131 @@ uint64_t HandleToUint64(HANDLE_T h);

static inline uint64_t HandleToUint64(uint64_t h) { return h; }

class LogMsg {

@jzulauf-lunarg jzulauf-lunarg Mar 9, 2018

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Clearly some comments are in order here... see the PR description for the "theory of operation" stuff.

public:
template <typename ObjectType>
LogMsg(bool *status, const debug_report_data *debug_data, VkFlags msg_flags, ObjectType src_object, size_t location,
int32_t msg_code, const char *layer_prefix)
: status_(status),
debug_data_(debug_data),
msg_flags_(msg_flags),
src_object_(HandleToUint64(src_object)),
src_object_type_(VkObjectTypeTraits<ObjectType>::kObjectType),
location_(location),
msg_code_(msg_code),
msg_code_is_vu_(false),
layer_prefix_(layer_prefix),
will_report_(will_log_msg(debug_data, msg_flags)),
reported_(false) {}
template <typename ObjectType>
LogMsg(bool *status, const debug_report_data *debug_data, VkFlags msg_flags, ObjectType src_object, size_t location,
UNIQUE_VALIDATION_ERROR_CODE msg_code, const char *layer_prefix)
: LogMsg(status, debug_data, msg_flags, src_object, location, static_cast<int32_t>(msg_code), layer_prefix) {
msg_code_is_vu_ = true;
}

template <typename IntType>
LogMsg &add_x(IntType out) {
if (will_report_) {

@jzulauf-lunarg jzulauf-lunarg Mar 9, 2018

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

note the noop'ing controlled by will_report_

// We could use string_sprintf, but we'll try the awful native formatting support for this at least
report_ << "0x";
auto save_fill = report_.fill('0');
auto save_width = report_.width(2 * sizeof(IntType));
report_ << std::hex << out << std::dec;
report_.fill(save_fill);
report_.width(save_width);
}
return *this;
}

template <typename RefType>
LogMsg &add(RefType *out) {
return add_x<RefType *>(out);
}

template <typename HandleType>
LogMsg &add_h(const HandleType h) {
if (!will_report_) {
add_x(HandleToUint64(h));
}
return *this;
}

// Anything with an acceptable stringstream operation can just use add
template <typename OutType>
LogMsg &add(const OutType out) {
if (will_report_) {
report_ << out;
}
return *this;
}

// use sprintf to add formatted information

@jzulauf-lunarg jzulauf-lunarg Mar 9, 2018

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Thar be va_dragons here. See something, say something.

#ifndef WIN32
#define LOG_MSG_ADD_FMT_ATTR __attribute__((format(printf, 2, 3)))
#else
#define LOG_MSG_ADD_FMT_ATTR
#endif
LogMsg &add_fmt(const char *fmt, ...) LOG_MSG_ADD_FMT_ATTR {
if (will_report_) {
va_list argptr;
va_start(argptr, fmt);
char *str;
if (-1 != vasprintf(&str, fmt, argptr)) {
report_ << str;
free(str);
}
va_end(argptr);
}
return *this;
}

bool will_report() const { return will_report_; };
bool report() {

@jzulauf-lunarg jzulauf-lunarg Mar 9, 2018

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This call is only needed if you supply a nullptr status... otherwise, just going out of scope takes care of sending the debug_report_log_msg

bool result = false;
if (will_report_ && !reported_) {
if (msg_code_is_vu_) {
add(" ");
add(validation_error_map[msg_code_]);
}
result = debug_report_log_msg(debug_data_, msg_flags_, get_debug_report_enum[src_object_type_], src_object_, location_,
msg_code_, layer_prefix_, report_.str().c_str());
reported_ = true;
if (status_) {
// Update this in the same chaining way as log_msg usage
*status_ |= result;
}
}
return result;
}

~LogMsg() { report(); }

private:
bool *status_;
const debug_report_data *debug_data_;
VkFlags msg_flags_;
uint64_t src_object_;
VulkanObjectType src_object_type_;
size_t location_;
int32_t msg_code_;
bool msg_code_is_vu_;
const char *layer_prefix_;
bool will_report_;
std::stringstream report_;
bool reported_;
};

// stream out to log msg using the public interface
template <typename OutType>
LogMsg &operator<<(LogMsg &logger, const OutType &out) {
return logger.add(out);
}

#define LOG_ERR_MSG(skip, msg, report_data, object, code, prefix) \

@jzulauf-lunarg jzulauf-lunarg Mar 9, 2018

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

if the __LINE__ and prefix are going away, we can avoid the macro by subclassing LogMsg for the two common cases without loss of brevity.

LogMsg msg(skip, report_data, VK_DEBUG_REPORT_ERROR_BIT_EXT, object, __LINE__, code, prefix);

#define LOG_WARN_MSG(skip, msg, report_data, object, code, prefix) \
LogMsg msg(skip, report_data, VK_DEBUG_REPORT_WARNING_BIT_EXT, object, __LINE__, code, prefix);

#endif // LAYER_LOGGING_H
48 changes: 33 additions & 15 deletions scripts/helper_file_generator.py
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -682,6 +682,7 @@ def GenerateObjectTypesHelperHeader(self):
object_types_helper_header += '#include <vulkan/vulkan.h>\n\n'
object_types_helper_header += self.GenerateObjectTypesHeader()
return object_types_helper_header

#
# Object types header: create object enum type header file
def GenerateObjectTypesHeader(self):
Expand Down Expand Up @@ -716,32 +717,49 @@ def GenerateObjectTypesHeader(self):
object_types_header += '// Helper array to get Vulkan VK_EXT_debug_report object type enum from the internal layers version\n'
object_types_header += 'const VkDebugReportObjectTypeEXT get_debug_report_enum[] = {\n'
object_types_header += ' VK_DEBUG_REPORT_OBJECT_TYPE_UNKNOWN_EXT, // No Match\n'

@jzulauf-lunarg jzulauf-lunarg Mar 9, 2018

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

For the templates below, I want to have a cross-reference map... and since I had it... thought I'd use it.

# Use map comprehensions to convert from k<Name> to VK<Name> with this helper
to_key = lambda regex, raw_key: re.search(regex, raw_key).group(1).lower().replace("_","")

dbg_re = '^VK_DEBUG_REPORT_OBJECT_TYPE_(.*)_EXT$'
dbg_map = {to_key(dbg_re, dbg) : dbg for dbg in self.debug_report_object_types}
for object_type in type_list:
search_type = object_type.replace("kVulkanObjectType", "").lower()
for vk_object_type in self.debug_report_object_types:
target_type = vk_object_type.replace("VK_DEBUG_REPORT_OBJECT_TYPE_", "").lower()
target_type = target_type[:-4]
target_type = target_type.replace("_", "")
if search_type == target_type:
object_types_header += ' %s, // %s\n' % (vk_object_type, object_type)
break
vk_object_type = dbg_map[object_type.replace("kVulkanObjectType", "").lower()]
object_types_header += ' %s, // %s\n' % (vk_object_type, object_type)
object_types_header += '};\n'

# Output a conversion routine from the layer object definitions to the core object type definitions
object_types_header += '\n'
object_types_header += '// Helper array to get Official Vulkan VkObjectType enum from the internal layers version\n'
object_types_header += 'const VkObjectType get_object_type_enum[] = {\n'
object_types_header += ' VK_OBJECT_TYPE_UNKNOWN, // No Match\n'
vko_re = '^VK_OBJECT_TYPE_(.*)'
vko_map = {to_key(vko_re, vko) : vko for vko in self.core_object_types}
for object_type in type_list:
search_type = object_type.replace("kVulkanObjectType", "").lower()
for vk_object_type in self.core_object_types:
target_type = vk_object_type.replace("VK_OBJECT_TYPE_", "").lower()
target_type = target_type.replace("_", "")
if search_type == target_type:
object_types_header += ' %s, // %s\n' % (vk_object_type, object_type)
break
vk_object_type = vko_map[object_type.replace("kVulkanObjectType", "").lower()]

@jzulauf-lunarg jzulauf-lunarg Mar 9, 2018

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

since I already have the map, why not use it.

object_types_header += ' %s, // %s\n' % (vk_object_type, object_type)
object_types_header += '};\n'

# Output template cross reference between the various enums, types, and strings
object_types_header += '#ifdef __cplusplus\n'
object_types_header += '// Helper template to get object type enum from a given type\n'
object_types_header += 'template <typename V> struct VkObjectTypeTraits {\n'
vko_template_body_fmt = (' static const VulkanObjectType kObjectType = {};\n' +
' static const VkDebugReportObjectTypeEXT kDebugObjectType = {};\n' +
' static const VkObjectType kCoreObjectType = {};\n')
unknown_enums = ( "kVulkanObjectTypeUnknown", "VK_DEBUG_REPORT_OBJECT_TYPE_UNKNOWN_EXT", "VK_OBJECT_TYPE_UNKNOWN")
object_types_header += vko_template_body_fmt.format(*unknown_enums)
object_types_header += '};\n\n'

for object_type in type_list:
ot_key = object_type.replace("kVulkanObjectType", "").lower()
vk_type = object_type.replace("kVulkanObjectType", "Vk")
object_types_header += '// Object type enums for %s\n' % (vk_type)

@jzulauf-lunarg jzulauf-lunarg Mar 9, 2018

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

You could get away with just the kVulkanObjectType enum (and look up the others) but as the compiler is likely just constexpr the whole thing, it's free so have them all.

object_types_header += 'template <> struct VkObjectTypeTraits<%s> {\n' % (vk_type)
object_types_header += vko_template_body_fmt.format(object_type, dbg_map[ot_key], vko_map[ot_key])
object_types_header += '};\n\n'

object_types_header += '#endif // __cplusplus\n'
return object_types_header
#
# Determine if a structure needs a safe_struct helper function
Expand Down