On 4/6/2025 2:18 PM, Shradha Gupta wrote:
Allow the KVP daemon to log the KVP updates triggered in the VM
with a new debug flag(-d).
When the daemon is started with this flag, it logs updates and debug
information in syslog with loglevel LOG_DEBUG. This information comes
in handy for debugging issues where the key-value pairs for certain
pools show mismatch/incorrect values.
The distro-vendors can further consume these changes and modify the
respective service files to redirect the logs to specific files as
needed.
Signed-off-by: Shradha Gupta <shradhagu...@linux.microsoft.com>
---
Changes in v3:
* remove timestamp from raw message
* use i+1 instead of i while printing record array
* add debug logs in delete operation
---
Changes in v2:
* log the debug logs in syslog(debug) instead of a seperate file that
we will have to maintain.
* fix the commit message to indicate the same.
---
tools/hv/hv_kvp_daemon.c | 71 +++++++++++++++++++++++++++++++++++-----
1 file changed, 63 insertions(+), 8 deletions(-)
diff --git a/tools/hv/hv_kvp_daemon.c b/tools/hv/hv_kvp_daemon.c
index 04ba035d67e9..7a1b7b0a9233 100644
--- a/tools/hv/hv_kvp_daemon.c
+++ b/tools/hv/hv_kvp_daemon.c
@@ -83,6 +83,7 @@ enum {
};
static int in_hand_shake;
+static int debug_enabled;
static char *os_name = "";
static char *os_major = "";
@@ -183,6 +184,20 @@ static void kvp_update_file(int pool)
kvp_release_lock(pool);
}
+static void kvp_dump_initial_pools(int pool)
+{
+ int i;
+
+ syslog(LOG_DEBUG, "===Start dumping the contents of pool %d ===\n",
+ pool);
+
+ for (i = 0; i < kvp_file_info[pool].num_records; i++)
+ syslog(LOG_DEBUG, "pool: %d, %d/%d key=%s val=%s\n",
+ pool, i + 1, kvp_file_info[pool].num_records,
+ kvp_file_info[pool].records[i].key,
+ kvp_file_info[pool].records[i].value);
+}
+
static void kvp_update_mem_state(int pool)
{
FILE *filep;
@@ -270,6 +285,8 @@ static int kvp_file_init(void)
return 1;
kvp_file_info[i].num_records = 0;
kvp_update_mem_state(i);
+ if (debug_enabled)
+ kvp_dump_initial_pools(i);
}
return 0;
@@ -297,6 +314,9 @@ static int kvp_key_delete(int pool, const __u8 *key, int
key_size)
* Found a match; just move the remaining
* entries up.
*/
+ if (debug_enabled)
+ syslog(LOG_DEBUG, "%s: deleting the KVP: pool=%d key=%s
val=%s",
+ __func__, pool, record[i].key, record[i].value);
if (i == (num_records - 1)) {
kvp_file_info[pool].num_records--;
kvp_update_file(pool);
@@ -315,20 +335,36 @@ static int kvp_key_delete(int pool, const __u8 *key, int
key_size)
kvp_update_file(pool);
return 0;
}
+
+ if (debug_enabled)
+ syslog(LOG_DEBUG, "%s: could not delete KVP: pool=%d key=%s. Record
not found",
+ __func__, pool, key);
+
return 1;
}
static int kvp_key_add_or_modify(int pool, const __u8 *key, int key_size,
const __u8 *value, int value_size)
{
- int i;
- int num_records;
struct kvp_record *record;
+ int num_records;
int num_blocks;
+ int i;
+
+ if (debug_enabled)
+ syslog(LOG_DEBUG, "%s: got a KVP: pool=%d key=%s val=%s",
+ __func__, pool, key, value);
if ((key_size > HV_KVP_EXCHANGE_MAX_KEY_SIZE) ||
- (value_size > HV_KVP_EXCHANGE_MAX_VALUE_SIZE))
+ (value_size > HV_KVP_EXCHANGE_MAX_VALUE_SIZE)) {
+ syslog(LOG_ERR, "Got a too long key or value: key=%s, val=%s",
+ key, value);
+
+ if (debug_enabled)
+ syslog(LOG_DEBUG, "%s: Got a too long key or value: pool=%d,
key=%s, val=%s",
There's a checkpatch warning here for 100 chars, but splitting it across
2 lines again complains. So I think its fine. Otherwise we can change it to:
"%s: Too long key or value: pool=%d, key=%s, val=%s"
+ __func__, pool, key, value);
return 1;
+ }
/*
* First update the in-memory state.
@@ -348,6 +384,9 @@ static int kvp_key_add_or_modify(int pool, const __u8 *key,
int key_size,
*/
memcpy(record[i].value, value, value_size);
kvp_update_file(pool);
+ if (debug_enabled)
+ syslog(LOG_DEBUG, "%s: updated: pool=%d key=%s val=%s",
+ __func__, pool, key, value);
return 0;
}
@@ -359,8 +398,10 @@ static int kvp_key_add_or_modify(int pool, const __u8 *key, int key_size,
record = realloc(record, sizeof(struct kvp_record) *
ENTRIES_PER_BLOCK * (num_blocks + 1));
- if (record == NULL)
+ if (!record) {
+ syslog(LOG_ERR, "%s: Memory alloc failure", __func__);
return 1;
+ }
kvp_file_info[pool].num_blocks++;
}
@@ -368,6 +409,11 @@ static int kvp_key_add_or_modify(int pool, const __u8
*key, int key_size,
memcpy(record[i].key, key, key_size);
kvp_file_info[pool].records = record;
kvp_file_info[pool].num_records++;
+
+ if (debug_enabled)
+ syslog(LOG_DEBUG, "%s: added: pool=%d key=%s val=%s",
+ __func__, pool, key, value);
+
kvp_update_file(pool);
return 0;
}
@@ -1662,6 +1708,7 @@ void print_usage(char *argv[])
fprintf(stderr, "Usage: %s [options]\n"
"Options are:\n"
" -n, --no-daemon stay in foreground, don't daemonize\n"
+ " -d, --debug-enabled Enable debug logs(syslog debug by
default)\n"
" -h, --help print this help\n", argv[0]);
}
@@ -1681,12 +1728,13 @@ int main(int argc, char *argv[])
int daemonize = 1, long_index = 0, opt;
static struct option long_options[] = {
- {"help", no_argument, 0, 'h' },
- {"no-daemon", no_argument, 0, 'n' },
- {0, 0, 0, 0 }
+ {"help", no_argument, 0, 'h' },
+ {"no-daemon", no_argument, 0, 'n' },
+ {"debug-enabled", no_argument, 0, 'd' },
+ {0, 0, 0, 0 }
};
- while ((opt = getopt_long(argc, argv, "hn", long_options,
+ while ((opt = getopt_long(argc, argv, "hnd", long_options,
&long_index)) != -1) {
switch (opt) {
case 'n':
@@ -1695,6 +1743,9 @@ int main(int argc, char *argv[])
case 'h':
print_usage(argv);
exit(0);
+ case 'd':
+ debug_enabled = 1;
+ break;
default:
print_usage(argv);
exit(EXIT_FAILURE);
@@ -1717,6 +1768,9 @@ int main(int argc, char *argv[])
*/
kvp_get_domain_name(full_domain_name, sizeof(full_domain_name));
+ if (debug_enabled)
+ syslog(LOG_INFO, "Logging debug info in syslog(debug)");
+
if (kvp_file_init()) {
syslog(LOG_ERR, "Failed to initialize the pools");
exit(EXIT_FAILURE);
LGTM.
Reviewed-by: Naman Jain <namj...@linux.microsoft.com>
