Skip to content

Commit 13de2c8

Browse files
prateek-kumar-improvingprateek-kumar-improving
authored
PHP: Add logging (#68)
* PHP: Add logging Signed-off-by: Prateek Kumar <[email protected]>
1 parent e73d115 commit 13de2c8

13 files changed

+631
-274
lines changed

‎.gitignore‎

Lines changed: 5 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -18,6 +18,11 @@ Cargo.lock
1818
*.pdb
1919
dump.rdb
2020
.env
21+
22+
# Log files
23+
logs/
24+
*.log
25+
*.log.*
2126
python/.env*
2227
benchmarks/results
2328

‎command_response.c‎

Lines changed: 51 additions & 50 deletions
Original file line numberDiff line numberDiff line change
@@ -19,6 +19,7 @@
1919
#include "include/glide/command_request.pb-c.h"
2020
#include "include/glide/response.pb-c.h"
2121
#include "include/glide_bindings.h"
22+
#include "logger.h"
2223
#include "valkey_glide_commands_common.h"
2324

2425
#define DEBUG_COMMAND_RESPONSE_TO_ZVAL 0
@@ -162,7 +163,7 @@ uint8_t* create_route_bytes_from_route(cluster_route_t* route, size_t* route_byt
162163
case ROUTE_TYPE_KEY:
163164
/* Validate key data */
164165
if (!route->data.key_route.key || route->data.key_route.key_len == 0) {
165-
printf("Error: Invalid key data for route\n");
166+
VALKEY_LOG_ERROR("route_processing", "Invalid key data for route");
166167
*route_bytes_len = 0;
167168
return NULL;
168169
}
@@ -195,33 +196,36 @@ uint8_t* create_route_bytes_from_route(cluster_route_t* route, size_t* route_byt
195196
routes.simple_routes = simple_route;
196197
break;
197198

198-
default:
199+
default: {
199200
/* Unknown route type */
200-
printf("Error: Unknown route type: %d\n", route->type);
201+
VALKEY_LOG_ERROR_FMT("route_processing", "Unknown route type: %d", route->type);
201202
*route_bytes_len = 0;
202203
return NULL;
204+
}
203205
}
204206

205207
/* Get serialized size and allocate buffer */
206208
*route_bytes_len = command_request__routes__get_packed_size(&routes);
207209
if (*route_bytes_len == 0) {
208-
printf("Error: Failed to get packed size for route\n");
210+
VALKEY_LOG_ERROR("route_processing", "Failed to get packed size for route");
209211
return NULL;
210212
}
211213

212214
route_bytes = (uint8_t*) emalloc(*route_bytes_len);
213215

214216
if (!route_bytes) {
215-
printf("Error: Failed to allocate memory for route bytes\n");
217+
VALKEY_LOG_ERROR("memory_allocation", "Failed to allocate memory for route bytes");
216218
*route_bytes_len = 0;
217219
return NULL;
218220
}
219221

220222
/* Serialize the routes */
221223
size_t packed_size = command_request__routes__pack(&routes, route_bytes);
222224
if (packed_size != *route_bytes_len) {
223-
printf(
224-
"Error: Packed size mismatch: expected %zu, got %zu\n", *route_bytes_len, packed_size);
225+
VALKEY_LOG_ERROR_FMT("route_processing",
226+
"Packed size mismatch: expected %zu, got %zu",
227+
*route_bytes_len,
228+
packed_size);
225229
efree(route_bytes);
226230
*route_bytes_len = 0;
227231
return NULL;
@@ -240,7 +244,7 @@ CommandResult* execute_command_with_route(const void* glide_client,
240244
zval* arg_route) {
241245
/* Validate route parameter */
242246
if (!arg_route) {
243-
printf("Error: arg_route is NULL\n");
247+
VALKEY_LOG_ERROR("route_processing", "arg_route is NULL");
244248
return NULL;
245249
}
246250

@@ -249,15 +253,15 @@ CommandResult* execute_command_with_route(const void* glide_client,
249253
memset(&route, 0, sizeof(cluster_route_t));
250254
if (!parse_cluster_route(arg_route, &route)) {
251255
/* Failed to parse the route */
252-
printf("Error: Failed to parse cluster route\n");
256+
VALKEY_LOG_ERROR("route_processing", "Failed to parse cluster route");
253257
return NULL;
254258
}
255259

256260
/* Create serialized route bytes */
257261
size_t route_bytes_len = 0;
258262
uint8_t* route_bytes = create_route_bytes_from_route(&route, &route_bytes_len);
259263
if (!route_bytes) {
260-
printf("Error: Failed to create route bytes\n");
264+
VALKEY_LOG_ERROR("route_processing", "Failed to create route bytes");
261265
/* Free dynamically allocated key if needed before returning */
262266
if (route.type == ROUTE_TYPE_KEY && route.data.key_route.key_allocated) {
263267
efree(route.data.key_route.key);
@@ -267,24 +271,28 @@ CommandResult* execute_command_with_route(const void* glide_client,
267271

268272
/* Validate all parameters before FFI call */
269273
if (!glide_client) {
270-
printf("ERROR: glide_client is NULL\n");
274+
VALKEY_LOG_ERROR("parameter_validation", "glide_client is NULL");
271275
return NULL;
272276
}
273277

274278
if (arg_count > 0) {
275279
if (!args) {
276-
printf("ERROR: args is NULL but arg_count is %lu\n", arg_count);
280+
VALKEY_LOG_ERROR_FMT(
281+
"parameter_validation", "args is NULL but arg_count is %lu", arg_count);
277282
return NULL;
278283
}
279284
if (!args_len) {
280-
printf("ERROR: args_len is NULL but arg_count is %lu\n", arg_count);
285+
VALKEY_LOG_ERROR_FMT(
286+
"parameter_validation", "args_len is NULL but arg_count is %lu", arg_count);
281287
return NULL;
282288
}
283289
}
284290

285291
if (route_bytes_len > 0) {
286292
if (!route_bytes) {
287-
printf("ERROR: route_bytes is NULL but route_bytes_len is %zu\n", route_bytes_len);
293+
VALKEY_LOG_ERROR_FMT("parameter_validation",
294+
"route_bytes is NULL but route_bytes_len is %zu",
295+
route_bytes_len);
288296
return NULL;
289297
}
290298
}
@@ -313,12 +321,13 @@ CommandResult* execute_command_with_route(const void* glide_client,
313321

314322
/* Validate result before returning */
315323
if (!result) {
316-
printf("Error: Command execution returned NULL result\n");
324+
VALKEY_LOG_ERROR("command_response", "Command execution returned NULL result");
317325
} else if (result->command_error) {
318-
printf("Error: Command execution failed: %s\n",
319-
result->command_error->command_error_message
320-
? result->command_error->command_error_message
321-
: "Unknown error");
326+
VALKEY_LOG_ERROR_FMT("command_response",
327+
"Command execution failed: %s",
328+
result->command_error->command_error_message
329+
? result->command_error->command_error_message
330+
: "Unknown command error");
322331
}
323332

324333
return result;
@@ -359,6 +368,11 @@ int handle_string_response(CommandResult* result, char** output, size_t* output_
359368

360369
/* Check if there was an error */
361370
if (result->command_error) {
371+
VALKEY_LOG_ERROR_FMT("command_response",
372+
"Command execution failed with error: %s",
373+
result->command_error->command_error_message
374+
? result->command_error->command_error_message
375+
: "Unknown error");
362376
return -1;
363377
}
364378

@@ -432,7 +446,7 @@ int command_response_to_zval(CommandResponse* response,
432446
switch (response->response_type) {
433447
case Null:
434448
#if DEBUG_COMMAND_RESPONSE_TO_ZVAL
435-
printf("%s:%d - CommandResponse is NULL\n", __FILE__, __LINE__);
449+
VALKEY_LOG_DEBUG("response_processing", "CommandResponse is NULL");
436450
#endif
437451
if (use_false_if_null) {
438452
// printf("%s:%d - CommandResponse is converted to false\n", __FILE__, __LINE__);
@@ -444,54 +458,42 @@ int command_response_to_zval(CommandResponse* response,
444458
return 0;
445459
case Int:
446460
#if DEBUG_COMMAND_RESPONSE_TO_ZVAL
447-
448-
printf(
449-
"%s:%d - CommandResponse is Int: %ld\n", __FILE__, __LINE__, response->int_value);
461+
VALKEY_LOG_DEBUG_FMT(
462+
"response_processing", "CommandResponse is Int: %ld", response->int_value);
450463
#endif
451464
ZVAL_LONG(output, response->int_value);
452465
return 1;
453466
case Float:
454467
#if DEBUG_COMMAND_RESPONSE_TO_ZVAL
455-
456-
printf("%s:%d - CommandResponse is Float: %f\n",
457-
__FILE__,
458-
__LINE__,
459-
response->float_value);
468+
VALKEY_LOG_DEBUG_FMT(
469+
"response_processing", "CommandResponse is Float: %f", response->float_value);
460470
#endif
461471
ZVAL_DOUBLE(output, response->float_value);
462472
#if DEBUG_COMMAND_RESPONSE_TO_ZVAL
463-
464-
printf("%s:%d - Converted CommandResponse to double: %f\n",
465-
__FILE__,
466-
__LINE__,
467-
Z_DVAL_P(output));
473+
VALKEY_LOG_DEBUG_FMT(
474+
"response_processing", "Converted CommandResponse to double: %f", Z_DVAL_P(output));
468475
#endif
469476
return 1;
470477
case Bool:
471478
#if DEBUG_COMMAND_RESPONSE_TO_ZVAL
472-
473-
printf(
474-
"%s:%d - CommandResponse is Bool: %d\n", __FILE__, __LINE__, response->bool_value);
479+
VALKEY_LOG_DEBUG_FMT(
480+
"response_processing", "CommandResponse is Bool: %d", response->bool_value);
475481
#endif
476482
ZVAL_BOOL(output, response->bool_value);
477483
return 1;
478484
case String:
479485
#if DEBUG_COMMAND_RESPONSE_TO_ZVAL
480-
481-
printf("%s:%d - CommandResponse is String with length: %ld\n",
482-
__FILE__,
483-
__LINE__,
484-
response->string_value_len);
486+
VALKEY_LOG_DEBUG_FMT("response_processing",
487+
"CommandResponse is String with length: %ld",
488+
response->string_value_len);
485489
#endif
486490
ZVAL_STRINGL(output, response->string_value, response->string_value_len);
487491
return 1;
488492
case Array:
489493
#if DEBUG_COMMAND_RESPONSE_TO_ZVAL
490-
491-
printf(
492-
"%s:%d - CommandResponse is Array with length: %ld, use_associative_array = %d\n ",
493-
__FILE__,
494-
__LINE__,
494+
VALKEY_LOG_DEBUG_FMT(
495+
"response_processing",
496+
"CommandResponse is Array with length: %ld, use_associative_array = %d",
495497
response->array_value_len,
496498
use_associative_array);
497499
#endif
@@ -520,10 +522,9 @@ int command_response_to_zval(CommandResponse* response,
520522
}
521523
} else if (use_associative_array == COMMAND_RESPONSE_ARRAY_ASSOCIATIVE) {
522524
#if DEBUG_COMMAND_RESPONSE_TO_ZVAL
523-
printf("%s:%d - response->array_value[0]->command_response_type = %d\n ",
524-
__FILE__,
525-
__LINE__,
526-
response->array_value[0].response_type);
525+
VALKEY_LOG_DEBUG_FMT("response_processing",
526+
"response->array_value[0]->command_response_type = %d",
527+
response->array_value[0].response_type);
527528
#endif
528529
array_init(output);
529530
for (int64_t i = 0; i < response->array_value_len; ++i) {

‎logger.h‎

Lines changed: 44 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -156,6 +156,50 @@ void valkey_glide_c_log_trace(const char* identifier, const char* message);
156156
#define VALKEY_LOG_DEBUG(identifier, message) valkey_glide_c_log_debug(identifier, message)
157157
#define VALKEY_LOG_TRACE(identifier, message) valkey_glide_c_log_trace(identifier, message)
158158

159+
/* Base macro for formatted logging with dynamic allocation */
160+
#define VALKEY_LOG_FMT_BASE(level_constant, level_function, level_name, category, format, ...) \
161+
do { \
162+
if (valkey_glide_logger_get_level() == VALKEY_LOG_LEVEL_OFF || \
163+
level_constant > valkey_glide_logger_get_level()) \
164+
break; \
165+
int needed_size = snprintf(NULL, 0, format, __VA_ARGS__) + 1; \
166+
char* log_msg = emalloc(needed_size); \
167+
if (log_msg) { \
168+
snprintf(log_msg, needed_size, format, __VA_ARGS__); \
169+
level_function(category, log_msg); \
170+
efree(log_msg); \
171+
} else { \
172+
VALKEY_LOG_ERROR(category, "Failed to allocate memory for " level_name " message"); \
173+
} \
174+
} while (0)
175+
176+
/* Dynamic allocation macro for formatted debug logging */
177+
#define VALKEY_LOG_DEBUG_FMT(category, format, ...) \
178+
VALKEY_LOG_FMT_BASE(VALKEY_LOG_LEVEL_DEBUG, \
179+
VALKEY_LOG_DEBUG, \
180+
VALKEY_LOG_LEVEL_DEBUG_STR, \
181+
category, \
182+
format, \
183+
__VA_ARGS__)
184+
185+
/* Dynamic allocation macro for formatted error logging */
186+
#define VALKEY_LOG_ERROR_FMT(category, format, ...) \
187+
VALKEY_LOG_FMT_BASE(VALKEY_LOG_LEVEL_ERROR, \
188+
VALKEY_LOG_ERROR, \
189+
VALKEY_LOG_LEVEL_ERROR_STR, \
190+
category, \
191+
format, \
192+
__VA_ARGS__)
193+
194+
/* Dynamic allocation macro for formatted warning logging */
195+
#define VALKEY_LOG_WARN_FMT(category, format, ...) \
196+
VALKEY_LOG_FMT_BASE(VALKEY_LOG_LEVEL_WARN, \
197+
VALKEY_LOG_WARN, \
198+
VALKEY_LOG_LEVEL_WARN_STR, \
199+
category, \
200+
format, \
201+
__VA_ARGS__)
202+
159203
/* ============================================================================
160204
* Utility Functions
161205
* ============================================================================ */

‎src/client_constructor_mock.c‎

Lines changed: 5 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -15,6 +15,7 @@
1515

1616
#include "common.h"
1717
#include "ext/standard/info.h"
18+
#include "logger.h"
1819
#include "php.h"
1920
#include "zend_exceptions.h"
2021

@@ -42,6 +43,7 @@ static zval* build_php_connection_request(uint8_t*
4243
valkey_glide_base_client_configuration_t* base_config) {
4344
if (!request_bytes) {
4445
const char* error_message = "Protobuf memory allocation error.";
46+
VALKEY_LOG_ERROR("mock_construct", error_message);
4547
zend_throw_exception(get_valkey_glide_exception_ce(), error_message, 0);
4648
valkey_glide_cleanup_client_config(base_config);
4749
return NULL;
@@ -100,13 +102,15 @@ PHP_METHOD(ClientConstructorMock, simulate_standalone_constructor) {
100102
if (!common_params.addresses ||
101103
zend_hash_num_elements(Z_ARRVAL_P(common_params.addresses)) == 0) {
102104
const char* error_message = "Addresses array cannot be empty";
105+
VALKEY_LOG_ERROR("mock_construct", error_message);
103106
zend_throw_exception(get_valkey_glide_exception_ce(), error_message, 0);
104107
return;
105108
}
106109

107110
/* Validate database_id range before setting */
108111
if (!common_params.database_id_is_null && common_params.database_id < 0) {
109112
const char* error_message = "Database ID must be non-negative.";
113+
VALKEY_LOG_ERROR("mock_construct", error_message);
110114
zend_throw_exception(get_valkey_glide_exception_ce(), error_message, 0);
111115
return;
112116
}
@@ -154,6 +158,7 @@ PHP_METHOD(ClientConstructorMock, simulate_cluster_constructor) {
154158
/* Validate database_id range before setting */
155159
if (!common_params.database_id_is_null && common_params.database_id < 0) {
156160
const char* error_message = "Database ID must be non-negative.";
161+
VALKEY_LOG_ERROR("mock_construct", error_message);
157162
zend_throw_exception(get_valkey_glide_exception_ce(), error_message, 0);
158163
return;
159164
}

0 commit comments

Comments
 (0)