You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@qpid.apache.org by as...@apache.org on 2019/11/08 20:32:57 UTC
[qpid-proton] branch master updated: PROTON-2131: Introduce new
proton logging API - Converted all uses in the Proton core library to use
the new API - Currently no higher language API bindings (Python/Ruby/C++) -
This introduces some portable library infrastructure to globally
initialise/ shutdown the library independent of it's clients.
This is an automated email from the ASF dual-hosted git repository.
astitcher pushed a commit to branch master
in repository https://gitbox.apache.org/repos/asf/qpid-proton.git
The following commit(s) were added to refs/heads/master by this push:
new 9dd0133 PROTON-2131: Introduce new proton logging API - Converted all uses in the Proton core library to use the new API - Currently no higher language API bindings (Python/Ruby/C++) - This introduces some portable library infrastructure to globally initialise/ shutdown the library independent of it's clients.
9dd0133 is described below
commit 9dd013335de0694bc52848897b17190f297450c1
Author: Andrew Stitcher <as...@apache.org>
AuthorDate: Fri Oct 4 17:24:19 2019 -0400
PROTON-2131: Introduce new proton logging API
- Converted all uses in the Proton core library to use the new API
- Currently no higher language API bindings (Python/Ruby/C++)
- This introduces some portable library infrastructure to globally initialise/
shutdown the library independent of it's clients.
---
c/CMakeLists.txt | 64 ++++-------
c/include/proton/log.h | 15 +--
c/include/proton/logger.h | 171 +++++++++++++++++++++++++++++
c/include/proton/transport.h | 14 +++
c/src/compiler/gcc/start.c | 32 ++++++
c/src/compiler/msvc/start.c | 49 +++++++++
c/src/core/codec.c | 6 +-
c/src/core/connection_driver.c | 10 +-
c/src/core/dispatcher.c | 20 ++--
c/src/core/engine-internal.h | 4 +-
c/src/core/init.c | 30 ++++++
c/src/core/init.h | 28 +++++
c/src/core/log.c | 23 ++--
c/src/core/logger.c | 190 +++++++++++++++++++++++++++++++++
c/src/core/logger_private.h | 59 ++++++++++
c/src/core/transport.c | 118 ++++++++++----------
c/src/proactor/epoll.c | 10 +-
c/src/proactor/libuv.c | 4 +-
c/src/proactor/win_iocp.c | 15 +--
c/src/sasl/cyrus_sasl.c | 4 +-
c/src/sasl/sasl.c | 27 ++---
c/src/ssl/openssl.c | 121 ++++++++++-----------
c/src/ssl/schannel.c | 100 ++++++++---------
c/tests/fuzz/fuzz-connection-driver.c | 9 +-
python/setup.py.in | 9 +-
python/tests/proton_tests/transport.py | 2 +-
26 files changed, 835 insertions(+), 299 deletions(-)
diff --git a/c/CMakeLists.txt b/c/CMakeLists.txt
index 63d8762..9981a08 100644
--- a/c/CMakeLists.txt
+++ b/c/CMakeLists.txt
@@ -177,15 +177,6 @@ if (PN_WINAPI)
list(APPEND PLATFORM_DEFINITIONS "PN_WINAPI")
endif (PN_WINAPI)
-# Flags for example self-test build, CACHE INTERNAL for visibility
-set(C_EXAMPLE_FLAGS "${COMPILE_WARNING_FLAGS}")
-set(C_EXAMPLE_LINK_FLAGS "${SANITIZE_FLAGS}")
-
-if (CMAKE_C_COMPILER_ID MATCHES "Clang" OR CMAKE_COMPILER_IS_GNUCC)
- # Ensure that examples build with c90, to deal with older c++03-as-c compilers.
- set(C_EXAMPLE_FLAGS "${C_EXAMPLE_FLAGS} -std=iso9899:1990 -pedantic")
-endif()
-
if (MSVC)
set(CMAKE_DEBUG_POSTFIX "d")
add_definitions(
@@ -194,9 +185,22 @@ if (MSVC)
/wd4800
/wd4996
)
- set (qpid-proton-platform src/compiler/msvc/snprintf.c)
endif (MSVC)
+# Ensure that examples build with c90 on gcc/clang, to deal with older c++03-as-c compilers.
+set(C_EXAMPLE_FLAGS_GNU "-std=iso9899:1990 -pedantic")
+set(C_EXAMPLE_FLAGS_Clang "-std=iso9899:1990 -pedantic")
+
+# Flags for example self-test build
+set(C_EXAMPLE_FLAGS "${COMPILE_WARNING_FLAGS} ${C_EXAMPLE_FLAGS_${CMAKE_C_COMPILER_ID}}")
+set(C_EXAMPLE_LINK_FLAGS "${SANITIZE_FLAGS}")
+
+set(qpid-proton-platform_GNU src/compiler/gcc/start.c)
+set(qpid-proton-platform_Clang src/compiler/gcc/start.c)
+set(qpid-proton-platform_MSVC src/compiler/msvc/snprintf.c src/compiler/msvc/start.c)
+
+set(qpid-proton-platform ${qpid-proton-platform_${CMAKE_C_COMPILER_ID}})
+
# for full source distribution:
set (qpid-proton-platform-all
src/platform/platform.c
@@ -240,7 +244,8 @@ set (qpid-proton-core
src/core/object/iterator.c
src/core/object/record.c
- src/core/log.c
+ src/core/init.c
+ src/core/logger.c
src/core/util.c
src/core/error.c
src/core/buffer.c
@@ -267,39 +272,9 @@ set (qpid-proton-include-generated
${CMAKE_CURRENT_BINARY_DIR}/include/proton/version.h
)
-set (qpid-proton-private-includes
- src/messenger/store.h
- src/messenger/subscription.h
- src/messenger/messenger.h
- src/messenger/transform.h
- src/ssl/ssl-internal.h
- src/sasl/sasl-internal.h
- src/core/autodetect.h
- src/core/log_private.h
- src/core/config.h
- src/core/encoder.h
- src/core/dispatch_actions.h
- src/core/engine-internal.h
- src/core/transport.h
- src/core/framing.h
- src/core/buffer.h
- src/core/util.h
- src/core/dispatcher.h
- src/core/data.h
- src/core/decoder.h
- src/core/max_align.h
- src/core/message-internal.h
- src/reactor/io/windows/iocp.h
- src/reactor/selector.h
- src/reactor/io.h
- src/reactor/reactor.h
- src/reactor/selectable.h
- src/platform/platform.h
- src/platform/platform_fmt.h
- src/proactor/proactor-internal.h
- )
-
set (qpid-proton-extra
+ src/core/log.c
+
src/extra/url.c
src/reactor/reactor.c
@@ -333,7 +308,7 @@ set (qpid-proton-include
include/proton/import_export.h
include/proton/link.h
include/proton/listener.h
- include/proton/log.h
+ include/proton/logger.h
include/proton/message.h
include/proton/netaddr.h
include/proton/object.h
@@ -350,6 +325,7 @@ set (qpid-proton-include
set (qpid-proton-include-extra
include/proton/handlers.h
+ include/proton/log.h
include/proton/messenger.h
include/proton/reactor.h
include/proton/selectable.h
diff --git a/c/include/proton/log.h b/c/include/proton/log.h
index 2f2046b..8601565 100644
--- a/c/include/proton/log.h
+++ b/c/include/proton/log.h
@@ -20,6 +20,7 @@
*/
#include <proton/import_export.h>
+#include <proton/logger.h>
#include <proton/type_compat.h>
#ifdef __cplusplus
@@ -31,18 +32,6 @@ extern "C" {
*/
/**
- * @file
- *
- * Control log messages that are not associated with a transport.
- * See pn_transport_trace for transport-related logging.
- */
-
-/**
- * Callback for customized logging.
- */
-typedef void (*pn_logger_t)(const char *message);
-
-/**
* Enable/disable global logging.
*
* By default, logging is enabled by environment variable PN_TRACE_LOG.
@@ -58,7 +47,7 @@ PN_EXTERN void pn_log_enable(bool enabled);
* @param logger is called with each log message if logging is enabled.
* Passing 0 disables logging regardless of pn_log_enable() or environment settings.
*/
-PN_EXTERN void pn_log_logger(pn_logger_t logger);
+PN_EXTERN void pn_log_logger(void (*logger)(const char *message));
/**
* @endcond
diff --git a/c/include/proton/logger.h b/c/include/proton/logger.h
new file mode 100644
index 0000000..ae4d153
--- /dev/null
+++ b/c/include/proton/logger.h
@@ -0,0 +1,171 @@
+#ifndef LOGGER_H
+#define LOGGER_H
+/*
+ * Licensed to the Apache Software Foundation (ASF) under one
+ * or more contributor license agreements. See the NOTICE file
+ * distributed with this work for additional information
+ * regarding copyright ownership. The ASF licenses this file
+ * to you 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.
+ */
+
+/**@file
+ *
+ * General proton logging facility
+ */
+
+#include <proton/import_export.h>
+#include <proton/object.h>
+
+#include <stdarg.h>
+#include <stdint.h>
+
+#ifdef __cplusplus
+extern "C" {
+#endif
+
+typedef struct pn_logger_t pn_logger_t;
+
+/**
+ * Definitions for different subsystems that can log messages
+ * Note that these are exclusive bits so that you can specify multiple
+ * subsystems to filter
+ */
+typedef enum pn_log_subsystem_t {
+ PN_SUBSYSTEM_NONE = 0,
+ PN_SUBSYSTEM_IO = 1,
+ PN_SUBSYSTEM_EVENT = 2,
+ PN_SUBSYSTEM_AMQP = 4,
+ PN_SUBSYSTEM_SSL = 8,
+ PN_SUBSYSTEM_SASL = 16,
+ PN_SUBSYSTEM_BINDING = 32,
+ PN_SUBSYSTEM_ALL = 65535
+} pn_log_subsystem_t; /* We hint to the compiler it can use 16 bits for this value */
+
+/**
+ * Definitions for different severities of log messages
+ * Note that these are exclusive bits so that you can specify multiple
+ * severities to filter
+ */
+typedef enum pn_log_level_t {
+ PN_LEVEL_NONE = 0,
+ PN_LEVEL_CRITICAL = 1, /* Something is wrong and can't be fixed - probably a library bug */
+ PN_LEVEL_ERROR = 2, /* Something went wrong */
+ PN_LEVEL_WARNING = 4, /* Something unusual happened but not necessarily an error */
+ PN_LEVEL_INFO = 8, /* Something that might be interesting happened */
+ PN_LEVEL_DEBUG = 16, /* Something you might want to know about happened */
+ PN_LEVEL_TRACE = 32, /* Detail about something that happened */
+ PN_LEVEL_FRAME = 64, /* Protocol frame traces */
+ PN_LEVEL_RAW = 128, /* Raw protocol bytes */
+ PN_LEVEL_ALL = 65535 /* Every possible severity */
+} pn_log_level_t; /* We hint to the compiler that it can use 16 bits for this value */
+
+/**
+ * Callback for sinking logger messages.
+ */
+typedef void (*pn_log_sink_t)(intptr_t sink_context, pn_log_subsystem_t subsystem, pn_log_level_t severity, const char *message);
+
+/*
+ * Return the default library logger
+ */
+PN_EXTERN pn_logger_t *pn_default_logger(void);
+
+/**
+ * Create a new logger
+ */
+PN_EXTERN pn_logger_t *pn_logger(void);
+
+/**
+ * Free an existing logger
+ */
+PN_EXTERN void pn_logger_free(pn_logger_t *logger);
+
+/**
+ * Get a human readable name for a logger severity
+ */
+PN_EXTERN const char *pn_logger_level_name(pn_log_level_t severity);
+
+/**
+ * Get a human readable name for a logger subsystem
+ */
+PN_EXTERN const char *pn_logger_subsystem_name(pn_log_subsystem_t subsystem);
+
+/**
+ * Set a logger's tracing flags.
+ *
+ * Set trace flags to control what a logger logs.
+ *
+ * The trace flags for a logger control what sort of information is
+ * logged. See pn_log_severity_t and pn_log_subsystem_t for more details.
+ *
+ * @param[in] logger the logger
+ */
+PN_EXTERN void pn_logger_set_mask(pn_logger_t *logger, pn_log_subsystem_t subsystem, pn_log_level_t severity);
+
+/**
+ * Clear a logger's tracing flags.
+ *
+ * Clear trace flags to control what a logger logs.
+ *
+ * The trace flags for a logger control what sort of information is
+ * logged. See pn_log_severity_t and pn_log_subsystem_t for more details.
+ *
+ * @param[in] logger the logger
+ */
+PN_EXTERN void pn_logger_reset_mask(pn_logger_t *logger, pn_log_subsystem_t subsystem, pn_log_level_t severity);
+
+/**
+ * Set the tracing function used by a logger.
+ *
+ * The tracing function is called to perform logging. Overriding this
+ * function allows embedding applications to divert the engine's
+ * logging to a place of their choice.
+ *
+ * @param[in] logger the logger
+ * @param[in] sink the tracing function
+ * @param[in] sink_context user specified context to pass into each call of the tracing callback
+ */
+PN_EXTERN void pn_logger_set_log_sink(pn_logger_t *logger, pn_log_sink_t sink, intptr_t sink_context);
+
+/**
+ * Get the tracing function used by a logger.
+ *
+ * @param[in] logger the logger
+ * @return the tracing sink function used by a logger
+ */
+PN_EXTERN pn_log_sink_t pn_logger_get_log_sink(pn_logger_t *logger);
+
+/**
+ * Get the sink context used by a logger.
+ *
+ * @param[in] logger the logger
+ * @return the sink context used by a logger
+ */
+PN_EXTERN intptr_t pn_logger_get_log_sink_context(pn_logger_t *logger);
+
+/**
+ * * Log a printf formatted using the logger
+ *
+ * This is mainly for use in proton internals , but will allow application log messages to
+ * be processed the same way.
+ *
+ * @param[in] logger the logger
+ * @param[in] fmt the printf formatted message to be logged
+ */
+PN_EXTERN void pn_logger_logf(pn_logger_t *logger, pn_log_subsystem_t subsystem, pn_log_level_t severity, const char *fmt, ...);
+
+#ifdef __cplusplus
+}
+#endif
+
+#endif
diff --git a/c/include/proton/transport.h b/c/include/proton/transport.h
index 72dc6c8..dbde8b1 100644
--- a/c/include/proton/transport.h
+++ b/c/include/proton/transport.h
@@ -25,6 +25,7 @@
#include <proton/import_export.h>
#include <proton/type_compat.h>
#include <proton/condition.h>
+#include <proton/logger.h>
#include <stddef.h>
#ifdef __cplusplus
@@ -227,6 +228,19 @@ PN_EXTERN bool pn_transport_is_encrypted(pn_transport_t *transport);
PN_EXTERN pn_condition_t *pn_transport_condition(pn_transport_t *transport);
/**
+ * Get the transport logger
+ *
+ * This can be used to control the logging information emitted by the transport
+ *
+ * The pointer returned by this operation is valid until the
+ * transport object is freed.
+ *
+ * @param[in] transport the transport object
+ * @return the transport's logger object
+ */
+PN_EXTERN pn_logger_t *pn_transport_logger(pn_transport_t *transport);
+
+/**
* **Deprecated** - Use ::pn_transport_condition().
*/
PN_EXTERN pn_error_t *pn_transport_error(pn_transport_t *transport);
diff --git a/c/src/compiler/gcc/start.c b/c/src/compiler/gcc/start.c
new file mode 100644
index 0000000..756d2b9
--- /dev/null
+++ b/c/src/compiler/gcc/start.c
@@ -0,0 +1,32 @@
+/*
+ * Licensed to the Apache Software Foundation (ASF) under one
+ * or more contributor license agreements. See the NOTICE file
+ * distributed with this work for additional information
+ * regarding copyright ownership. The ASF licenses this file
+ * to you 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.
+ */
+
+#include "core/init.h"
+
+__attribute__((constructor))
+static void init(void)
+{
+ pn_init();
+}
+
+__attribute__((destructor))
+static void fini(void)
+{
+ pn_fini();
+}
diff --git a/c/src/compiler/msvc/start.c b/c/src/compiler/msvc/start.c
new file mode 100644
index 0000000..929d6b7
--- /dev/null
+++ b/c/src/compiler/msvc/start.c
@@ -0,0 +1,49 @@
+/*
+ * Licensed to the Apache Software Foundation (ASF) under one
+ * or more contributor license agreements. See the NOTICE file
+ * distributed with this work for additional information
+ * regarding copyright ownership. The ASF licenses this file
+ * to you 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.
+ */
+
+#define WIN32_LEAN_AMD_MEAN
+#include <windows.h>
+
+#include "core/init.h"
+
+BOOL WINAPI DllMain(HINSTANCE dLL, DWORD reason, LPVOID reserved)
+{
+// Perform actions based on the reason for calling.
+ switch (reason)
+ {
+ case DLL_PROCESS_ATTACH:
+ // Initialize once for each new process.
+ pn_init();
+ break;
+
+ case DLL_THREAD_ATTACH:
+ // Do thread-specific initialization.
+ break;
+
+ case DLL_THREAD_DETACH:
+ // Do thread-specific cleanup.
+ break;
+
+ case DLL_PROCESS_DETACH:
+ // Perform any necessary cleanup.
+ pn_fini();
+ break;
+ }
+ return TRUE;
+}
diff --git a/c/src/core/codec.c b/c/src/core/codec.c
index 93b209f..300dd3d 100644
--- a/c/src/core/codec.c
+++ b/c/src/core/codec.c
@@ -36,7 +36,7 @@
#include "decoder.h"
#include "encoder.h"
#include "data.h"
-#include "log_private.h"
+#include "logger_private.h"
const char *pn_type_name(pn_type_t type)
{
@@ -717,7 +717,7 @@ int pn_data_vfill(pn_data_t *data, const char *fmt, va_list ap)
}
break;
default:
- pn_logf("unrecognized * code: 0x%.2X '%c'", code, code);
+ PN_LOG_DEFAULT(PN_SUBSYSTEM_AMQP, PN_LEVEL_CRITICAL, "unrecognized * code: 0x%.2X '%c'", code, code);
return PN_ARG_ERR;
}
}
@@ -742,7 +742,7 @@ int pn_data_vfill(pn_data_t *data, const char *fmt, va_list ap)
break;
}
default:
- pn_logf("unrecognized fill code: 0x%.2X '%c'", code, code);
+ PN_LOG_DEFAULT(PN_SUBSYSTEM_AMQP, PN_LEVEL_CRITICAL, "unrecognized fill code: 0x%.2X '%c'", code, code);
return PN_ARG_ERR;
}
diff --git a/c/src/core/connection_driver.c b/c/src/core/connection_driver.c
index b7d71fe..935a2b0 100644
--- a/c/src/core/connection_driver.c
+++ b/c/src/core/connection_driver.c
@@ -49,10 +49,10 @@ static pn_event_t *batch_next(pn_event_batch_t *batch) {
}
/* Log the next event that will be processed */
pn_event_t *next = pn_collector_next(d->collector);
- if (next && d->transport->trace & PN_TRACE_EVT) {
+ if (next && PN_SHOULD_LOG(&d->transport->logger, PN_SUBSYSTEM_EVENT, PN_LEVEL_DEBUG)) {
pn_string_clear(d->transport->scratch);
pn_inspect(next, d->transport->scratch);
- pn_transport_log(d->transport, pn_string_get(d->transport->scratch));
+ pni_logger_log(&d->transport->logger, PN_SUBSYSTEM_EVENT, PN_LEVEL_DEBUG, pn_string_get(d->transport->scratch));
}
return next;
}
@@ -169,18 +169,18 @@ void pn_connection_driver_errorf(pn_connection_driver_t *d, const char *name, co
}
void pn_connection_driver_log(pn_connection_driver_t *d, const char *msg) {
- pn_transport_log(d->transport, msg);
+ pni_logger_log(&d->transport->logger, PN_SUBSYSTEM_IO, PN_LEVEL_TRACE, msg);
}
void pn_connection_driver_logf(pn_connection_driver_t *d, const char *fmt, ...) {
va_list ap;
va_start(ap, fmt);
- pn_transport_vlogf(d->transport, fmt, ap);
+ pni_logger_vlogf(&d->transport->logger, PN_SUBSYSTEM_IO, PN_LEVEL_TRACE, fmt, ap);
va_end(ap);
}
void pn_connection_driver_vlogf(pn_connection_driver_t *d, const char *fmt, va_list ap) {
- pn_transport_vlogf(d->transport, fmt, ap);
+ pni_logger_vlogf(&d->transport->logger, PN_SUBSYSTEM_IO, PN_LEVEL_TRACE, fmt, ap);
}
pn_connection_driver_t* pn_event_batch_connection_driver(pn_event_batch_t *batch) {
diff --git a/c/src/core/dispatcher.c b/c/src/core/dispatcher.c
index 87e4d97..3458429 100644
--- a/c/src/core/dispatcher.c
+++ b/c/src/core/dispatcher.c
@@ -21,20 +21,21 @@
#include "dispatcher.h"
+#include "engine-internal.h"
#include "framing.h"
+#include "logger_private.h"
#include "protocol.h"
-#include "engine-internal.h"
#include "dispatch_actions.h"
int pni_bad_frame(pn_transport_t *transport, uint8_t frame_type, uint16_t channel, pn_data_t *args, const pn_bytes_t *payload) {
- pn_transport_logf(transport, "Error dispatching frame: type: %d: Unknown performative", frame_type);
+ PN_LOG(&transport->logger, PN_SUBSYSTEM_AMQP, PN_LEVEL_ERROR, "Error dispatching frame: type: %d: Unknown performative", frame_type);
return PN_ERR;
}
int pni_bad_frame_type(pn_transport_t *transport, uint8_t frame_type, uint16_t channel, pn_data_t *args, const pn_bytes_t *payload) {
- pn_transport_logf(transport, "Error dispatching frame: Unknown frame type: %d", frame_type);
- return PN_ERR;
+ PN_LOG(&transport->logger, PN_SUBSYSTEM_AMQP, PN_LEVEL_ERROR, "Error dispatching frame: Unknown frame type: %d", frame_type);
+ return PN_ERR;
}
// We could use a table based approach here if we needed to dynamically
@@ -44,7 +45,7 @@ static inline int pni_dispatch_action(pn_transport_t* transport, uint64_t lcode,
pn_action_t *action;
switch (frame_type) {
case AMQP_FRAME_TYPE:
- /* Regular AMQP fames */
+ /* Regular AMQP frames */
switch (lcode) {
case OPEN: action = pn_do_open; break;
case BEGIN: action = pn_do_begin; break;
@@ -77,8 +78,7 @@ static inline int pni_dispatch_action(pn_transport_t* transport, uint64_t lcode,
static int pni_dispatch_frame(pn_transport_t * transport, pn_data_t *args, pn_frame_t frame)
{
if (frame.size == 0) { // ignore null frames
- if (transport->trace & PN_TRACE_FRM)
- pn_transport_logf(transport, "%u <- (EMPTY FRAME)", frame.channel);
+ PN_LOG(&transport->logger, PN_SUBSYSTEM_AMQP, PN_LEVEL_FRAME, "%u <- (EMPTY FRAME)", frame.channel);
return 0;
}
@@ -88,7 +88,7 @@ static int pni_dispatch_frame(pn_transport_t * transport, pn_data_t *args, pn_fr
"Error decoding frame: %s %s\n", pn_code(dsize),
pn_error_text(pn_data_error(args)));
pn_quote(transport->scratch, frame.payload, frame.size);
- pn_transport_log(transport, pn_string_get(transport->scratch));
+ PN_LOG(&transport->logger, PN_SUBSYSTEM_AMQP, PN_LEVEL_ERROR, pn_string_get(transport->scratch));
return dsize;
}
@@ -100,11 +100,11 @@ static int pni_dispatch_frame(pn_transport_t * transport, pn_data_t *args, pn_fr
bool scanned;
int e = pn_data_scan(args, "D?L.", &scanned, &lcode);
if (e) {
- pn_transport_log(transport, "Scan error");
+ PN_LOG(&transport->logger, PN_SUBSYSTEM_AMQP, PN_LEVEL_ERROR, "Scan error");
return e;
}
if (!scanned) {
- pn_transport_log(transport, "Error dispatching frame");
+ PN_LOG(&transport->logger, PN_SUBSYSTEM_AMQP, PN_LEVEL_ERROR, "Error dispatching frame");
return PN_ERR;
}
size_t payload_size = frame.size - dsize;
diff --git a/c/src/core/engine-internal.h b/c/src/core/engine-internal.h
index 66a892d..1e56562 100644
--- a/c/src/core/engine-internal.h
+++ b/c/src/core/engine-internal.h
@@ -28,6 +28,7 @@
#include "buffer.h"
#include "dispatcher.h"
+#include "logger_private.h"
#include "util.h"
typedef enum pn_endpoint_type_t {CONNECTION, SESSION, SENDER, RECEIVER} pn_endpoint_type_t;
@@ -124,6 +125,7 @@ typedef struct pni_sasl_t pni_sasl_t;
typedef struct pni_ssl_t pni_ssl_t;
struct pn_transport_t {
+ pn_logger_t logger;
pn_tracer_t tracer;
pni_sasl_t *sasl;
pni_ssl_t *ssl;
@@ -188,8 +190,6 @@ struct pn_transport_t {
pn_record_t *context;
- pn_trace_t trace;
-
/*
* The maximum channel number can be constrained in several ways:
* 1. an unchangeable limit imposed by this library code
diff --git a/c/src/core/init.c b/c/src/core/init.c
new file mode 100644
index 0000000..105ec41
--- /dev/null
+++ b/c/src/core/init.c
@@ -0,0 +1,30 @@
+/*
+ * Licensed to the Apache Software Foundation (ASF) under one
+ * or more contributor license agreements. See the NOTICE file
+ * distributed with this work for additional information
+ * regarding copyright ownership. The ASF licenses this file
+ * to you 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.
+ */
+
+#include "core/logger_private.h"
+
+void pn_init(void)
+{
+ pni_init_default_logger();
+}
+
+void pn_fini(void)
+{
+ pni_fini_default_logger();
+}
diff --git a/c/src/core/init.h b/c/src/core/init.h
new file mode 100644
index 0000000..6fcf4e3
--- /dev/null
+++ b/c/src/core/init.h
@@ -0,0 +1,28 @@
+#ifndef PROTON_INIT_H
+#define PROTON_INIT_H 1
+
+/*
+ *
+ * Licensed to the Apache Software Foundation (ASF) under one
+ * or more contributor license agreements. See the NOTICE file
+ * distributed with this work for additional information
+ * regarding copyright ownership. The ASF licenses this file
+ * to you 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.
+ *
+ */
+
+void pn_init(void);
+void pn_fini(void);
+
+#endif // init.h
diff --git a/c/src/core/log.c b/c/src/core/log.c
index 9a71d1e..6ee83c5 100644
--- a/c/src/core/log.c
+++ b/c/src/core/log.c
@@ -18,17 +18,13 @@
*/
#include "log_private.h"
+#include "logger_private.h"
#include "util.h"
#include <proton/error.h>
#include <proton/log.h>
#include <proton/object.h>
-static void stderr_logger(const char *message) {
- fprintf(stderr, "%s\n", message);
-}
-
-static pn_logger_t logger = stderr_logger;
static int enabled_env = -1; /* Set from environment variable. */
static int enabled_call = -1; /* set by pn_log_enable */
@@ -43,15 +39,12 @@ bool pni_log_enabled(void) {
return enabled_env;
}
-void pn_log_logger(pn_logger_t new_logger) {
- logger = new_logger;
- if (!logger) pn_log_enable(false);
+void pn_log_logger(void (*new_logger)(const char* message)) {
+ if (!new_logger) pn_log_enable(false);
}
void pni_vlogf_impl(const char *fmt, va_list ap) {
- vfprintf(stderr, fmt, ap);
- fprintf(stderr, "\n");
- fflush(stderr);
+ pni_logger_vlogf(pn_default_logger(), PN_SUBSYSTEM_ALL, PN_LEVEL_TRACE, fmt, ap);
}
/**@internal
@@ -71,13 +64,15 @@ void pni_logf_impl(const char *fmt, ...) {
void pn_log_data(const char *msg, const char *bytes, size_t size)
{
+ if (!pni_log_enabled()) return;
+
char buf[256];
ssize_t n = pn_quote_data(buf, 256, bytes, size);
if (n >= 0) {
- pn_logf("%s: %s", msg, buf);
+ pni_logf_impl("%s: %s", msg, buf);
} else if (n == PN_OVERFLOW) {
- pn_logf("%s: %s (truncated)", msg, buf);
+ pni_logf_impl("%s: %s (truncated)", msg, buf);
} else {
- pn_logf("%s: cannot log data: %s", msg, pn_code(n));
+ pni_logf_impl("%s: cannot log data: %s", msg, pn_code(n));
}
}
diff --git a/c/src/core/logger.c b/c/src/core/logger.c
new file mode 100644
index 0000000..4ff0d3c
--- /dev/null
+++ b/c/src/core/logger.c
@@ -0,0 +1,190 @@
+/*
+ * Licensed to the Apache Software Foundation (ASF) under one
+ * or more contributor license agreements. See the NOTICE file
+ * distributed with this work for additional information
+ * regarding copyright ownership. The ASF licenses this file
+ * to you 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.
+ */
+
+#include <proton/logger.h>
+#include <proton/error.h>
+
+#include "logger_private.h"
+#include "util.h"
+
+#include <assert.h>
+#include <stdio.h>
+#include <stdlib.h>
+
+static void pni_default_log_sink(intptr_t logger, pn_log_subsystem_t subsystem, pn_log_level_t severity, const char *message)
+{
+ fprintf(stderr, "[%p]:%5s:%5s:%s\n", (void *) logger, pn_logger_subsystem_name(subsystem), pn_logger_level_name(severity), message);
+ fflush(stderr);
+}
+
+static pn_logger_t the_default_logger = {
+ pni_default_log_sink,
+ (intptr_t) &the_default_logger,
+ PN_LEVEL_CRITICAL,
+ PN_SUBSYSTEM_ALL,
+ NULL
+};
+
+void pni_logger_init(pn_logger_t *logger)
+{
+ *logger = the_default_logger;
+ logger->sink_context = (intptr_t) logger;
+ logger->scratch = pn_string(NULL);
+}
+
+void pni_logger_fini(pn_logger_t *logger)
+{
+ pn_free(logger->scratch);
+ logger->scratch = NULL;
+}
+
+void pni_init_default_logger(void)
+{
+ int sev_mask = 0;
+ int sub_mask = 0;
+ /* Back compatible environment settings */
+ if (pn_env_bool("PN_TRACE_RAW")) { sev_mask |= PN_LEVEL_RAW; }
+ if (pn_env_bool("PN_TRACE_FRM")) { sev_mask |= PN_LEVEL_FRAME; }
+
+ /* These aren't used enough to make them back compatible */
+ if (pn_env_bool("PN_TRACE_DRV")) { sev_mask |= PN_LEVEL_TRACE | PN_LEVEL_DEBUG; }
+ if (pn_env_bool("PN_TRACE_EVT")) { sev_mask |= PN_LEVEL_DEBUG; }
+
+ if (pn_env_bool("PN_TRACE_LOG")) { sev_mask |= PN_LEVEL_TRACE; }
+ if (pn_env_bool("PN_DEBUG_LOG")) { sev_mask |= PN_LEVEL_DEBUG; }
+ if (pn_env_bool("PN_INFO_LOG")) { sev_mask |= PN_LEVEL_INFO; }
+ if (pn_env_bool("PN_WARNING_LOG")) { sev_mask |= PN_LEVEL_WARNING; }
+ if (pn_env_bool("PN_ERROR_LOG")) { sev_mask |= PN_LEVEL_ERROR; }
+ the_default_logger.sev_mask = (pn_log_level_t) (the_default_logger.sev_mask | sev_mask);
+ the_default_logger.sub_mask = (pn_log_subsystem_t) (the_default_logger.sub_mask | sub_mask);
+ the_default_logger.scratch = pn_string(NULL);
+}
+
+void pni_fini_default_logger(void)
+{
+ pni_logger_fini(&the_default_logger);
+}
+
+const char *pn_logger_level_name(pn_log_level_t severity)
+{
+ if (severity==PN_LEVEL_ALL) return "*ALL*";
+ if (severity&PN_LEVEL_CRITICAL) return "CRITICAL";
+ if (severity&PN_LEVEL_ERROR) return "ERROR";
+ if (severity&PN_LEVEL_WARNING) return "WARNING";
+ if (severity&PN_LEVEL_INFO) return "INFO";
+ if (severity&PN_LEVEL_DEBUG) return "DEBUG";
+ if (severity&PN_LEVEL_TRACE) return "TRACE";
+ if (severity&PN_LEVEL_FRAME) return "FRAME";
+ if (severity&PN_LEVEL_RAW) return "RAW";
+ return "UNKNOWN";
+}
+
+const char *pn_logger_subsystem_name(pn_log_subsystem_t subsystem)
+{
+ if (subsystem==PN_SUBSYSTEM_ALL) return "*ALL*";
+ if (subsystem&PN_SUBSYSTEM_IO) return "IO";
+ if (subsystem&PN_SUBSYSTEM_EVENT) return "EVENT";
+ if (subsystem&PN_SUBSYSTEM_AMQP) return "AMQP";
+ if (subsystem&PN_SUBSYSTEM_SSL) return "SSL";
+ if (subsystem&PN_SUBSYSTEM_SASL) return "SASL";
+ if (subsystem&PN_SUBSYSTEM_BINDING) return "BINDING";
+ return "UNKNOWN";
+}
+
+pn_logger_t *pn_logger(void)
+{
+ pn_logger_t *l = (pn_logger_t*) malloc(sizeof(pn_logger_t));
+ pni_logger_init(l);
+ return l;
+}
+
+void pn_logger_free(pn_logger_t *logger)
+{
+ if (!logger) return;
+ pni_logger_fini(logger);
+ free(logger);
+}
+
+pn_logger_t *pn_default_logger(void)
+{
+ return &the_default_logger;
+}
+
+void pn_logger_set_mask(pn_logger_t *logger, pn_log_subsystem_t subsystem, pn_log_level_t severity)
+{
+ logger->sev_mask = (pn_log_level_t) (logger->sev_mask | severity);
+ logger->sub_mask = (pn_log_subsystem_t) (logger->sub_mask | subsystem);
+}
+
+void pn_logger_reset_mask(pn_logger_t *logger, pn_log_subsystem_t subsystem, pn_log_level_t severity)
+{
+ logger->sev_mask = (pn_log_level_t) (logger->sev_mask & ~severity);
+ logger->sub_mask = (pn_log_subsystem_t) (logger->sub_mask & ~subsystem);
+}
+
+void pn_logger_set_log_sink(pn_logger_t *logger, pn_log_sink_t sink, intptr_t sink_context)
+{
+ logger->sink = sink;
+ logger->sink_context = sink_context;
+}
+
+pn_log_sink_t pn_logger_get_log_sink(pn_logger_t *logger)
+{
+ return logger->sink;
+}
+
+intptr_t pn_logger_get_log_sink_context(pn_logger_t *logger)
+{
+ return logger->sink_context;
+}
+
+void pni_logger_log_data(pn_logger_t *logger, pn_log_subsystem_t subsystem, pn_log_level_t severity, const char *msg, const char *bytes, size_t size)
+{
+ char buf[256];
+ ssize_t n = pn_quote_data(buf, 256, bytes, size);
+ if (n >= 0) {
+ pn_logger_logf(logger, subsystem, severity, "%s: %s", msg, buf);
+ } else if (n == PN_OVERFLOW) {
+ pn_logger_logf(logger, subsystem, severity, "%s: %s (truncated)", msg, buf);
+ } else {
+ pn_logger_logf(logger, subsystem, severity, "%s: cannot log data: %s", msg, pn_code(n));
+ }
+}
+
+void pni_logger_log(pn_logger_t *logger, pn_log_subsystem_t subsystem, pn_log_level_t severity, const char *message)
+{
+ assert(logger);
+ logger->sink(logger->sink_context, subsystem, severity, message);
+}
+
+void pni_logger_vlogf(pn_logger_t *logger, pn_log_subsystem_t subsystem, pn_log_level_t severity, const char *fmt, va_list ap)
+{
+ assert(logger);
+ pn_string_vformat(logger->scratch, fmt, ap);
+ pni_logger_log(logger, subsystem, severity, pn_string_get(logger->scratch));
+}
+
+void pn_logger_logf(pn_logger_t *logger, pn_log_subsystem_t subsystem, pn_log_level_t severity, const char *fmt, ...)
+{
+ va_list ap;
+
+ va_start(ap, fmt);
+ pni_logger_vlogf(logger, subsystem, severity, fmt, ap);
+ va_end(ap);
+}
diff --git a/c/src/core/logger_private.h b/c/src/core/logger_private.h
new file mode 100644
index 0000000..d48e97e
--- /dev/null
+++ b/c/src/core/logger_private.h
@@ -0,0 +1,59 @@
+#ifndef LOGGER_PRIVATE_H
+#define LOGGER_PRIVATE_H
+/*
+ * Licensed to the Apache Software Foundation (ASF) under one
+ * or more contributor license agreements. See the NOTICE file
+ * distributed with this work for additional information
+ * regarding copyright ownership. The ASF licenses this file
+ * to you 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.
+ */
+
+#include <proton/logger.h>
+
+struct pn_logger_t {
+ pn_log_sink_t sink;
+ intptr_t sink_context;
+ pn_log_level_t sev_mask;
+ pn_log_subsystem_t sub_mask;
+ pn_string_t *scratch;
+};
+
+void pni_init_default_logger(void);
+void pni_fini_default_logger(void);
+
+void pni_logger_init(pn_logger_t*);
+void pni_logger_fini(pn_logger_t*);
+
+void pni_logger_log(pn_logger_t *logger, pn_log_subsystem_t subsystem, pn_log_level_t severity, const char *message);
+void pni_logger_vlogf(pn_logger_t *logger, pn_log_subsystem_t subsystem, pn_log_level_t severity, const char *fmt, va_list ap);
+void pni_logger_log_data(pn_logger_t *logger, pn_log_subsystem_t subsystem, pn_log_level_t severity, const char *msg, const char *bytes, size_t size);
+
+#define PN_SHOULD_LOG(logger, subsys, sev) \
+ (((sev) & PN_LEVEL_CRITICAL) || (((logger)->sub_mask & (subsys)) && ((logger)->sev_mask & (sev))))
+
+#define PN_LOG(logger, subsys, sev, ...) \
+ do { \
+ if (PN_SHOULD_LOG(logger, subsys, sev)) \
+ pn_logger_logf(logger, (pn_log_subsystem_t) (subsys), (pn_log_level_t) (sev), __VA_ARGS__); \
+ } while(0)
+
+#define PN_LOG_DEFAULT(subsys, sev, ...) PN_LOG(pn_default_logger(), subsys, sev, __VA_ARGS__)
+
+#define PN_LOG_DATA(logger, subsys, sev, ...) \
+ do { \
+ if (PN_SHOULD_LOG(logger, subsys, sev)) \
+ pni_logger_log_data(logger, (pn_log_subsystem_t) (subsys), (pn_log_level_t) (sev), __VA_ARGS__); \
+ } while(0)
+
+#endif
diff --git a/c/src/core/transport.c b/c/src/core/transport.c
index ff4162e..f8a2d97 100644
--- a/c/src/core/transport.c
+++ b/c/src/core/transport.c
@@ -30,7 +30,7 @@
#include "protocol.h"
#include "dispatch_actions.h"
#include "config.h"
-#include "log_private.h"
+#include "logger_private.h"
#include "proton/event.h"
@@ -132,12 +132,6 @@ static void pni_delivery_map_clear(pn_delivery_map_t *dm)
dm->next = 0;
}
-static void pni_default_tracer(pn_transport_t *transport, const char *message)
-{
- fprintf(stderr, "[%p]:%s\n", (void *) transport, message);
- fflush(stderr);
-}
-
static ssize_t pn_io_layer_input_passthru(pn_transport_t *, unsigned int, const char *, size_t );
static ssize_t pn_io_layer_output_passthru(pn_transport_t *, unsigned int, char *, size_t );
@@ -279,8 +273,7 @@ ssize_t pn_io_layer_input_autodetect(pn_transport_t *transport, unsigned int lay
return PN_EOS;
}
pni_protocol_type_t protocol = pni_sniff_header(bytes, available);
- if (transport->trace & PN_TRACE_DRV)
- pn_transport_logf(transport, "%s detected", pni_protocol_name(protocol));
+ PN_LOG(&transport->logger, PN_SUBSYSTEM_IO, PN_LEVEL_DEBUG, "%s detected", pni_protocol_name(protocol));
switch (protocol) {
case PNI_PROTOCOL_SSL:
if (!(transport->allowed_layers & LAYER_SSL)) {
@@ -320,8 +313,7 @@ ssize_t pn_io_layer_input_autodetect(pn_transport_t *transport, unsigned int lay
}
transport->io_layers[layer] = &sasl_write_header_layer;
transport->io_layers[layer+1] = &pni_autodetect_layer;
- if (transport->trace & PN_TRACE_FRM)
- pn_transport_logf(transport, " <- %s", "SASL");
+ PN_LOG(&transport->logger, PN_SUBSYSTEM_SASL, PN_LEVEL_FRAME, " <- %s", "SASL");
pni_sasl_set_external_security(transport, pn_ssl_get_ssf((pn_ssl_t*)transport), pn_ssl_get_remote_subject((pn_ssl_t*)transport));
return 8;
case PNI_PROTOCOL_AMQP1:
@@ -344,8 +336,7 @@ ssize_t pn_io_layer_input_autodetect(pn_transport_t *transport, unsigned int lay
return 8;
}
transport->io_layers[layer] = &amqp_write_header_layer;
- if (transport->trace & PN_TRACE_FRM)
- pn_transport_logf(transport, " <- %s", "AMQP");
+ PN_LOG(&transport->logger, PN_SUBSYSTEM_AMQP, PN_LEVEL_FRAME, " <- %s", "AMQP");
return 8;
case PNI_PROTOCOL_INSUFFICIENT:
if (!eos) return 0;
@@ -410,7 +401,8 @@ static void pn_transport_initialize(void *object)
transport->output_size = PN_TRANSPORT_INITIAL_BUFFER_SIZE;
transport->input_buf = NULL;
transport->input_size = PN_TRANSPORT_INITIAL_BUFFER_SIZE;
- transport->tracer = pni_default_tracer;
+ pni_logger_init(&transport->logger);
+ transport->tracer = NULL;
transport->sasl = NULL;
transport->ssl = NULL;
@@ -495,12 +487,6 @@ static void pn_transport_initialize(void *object)
transport->encryption_required = false;
transport->referenced = true;
-
- transport->trace =
- (pn_env_bool("PN_TRACE_RAW") ? PN_TRACE_RAW : PN_TRACE_OFF) |
- (pn_env_bool("PN_TRACE_FRM") ? PN_TRACE_FRM : PN_TRACE_OFF) |
- (pn_env_bool("PN_TRACE_DRV") ? PN_TRACE_DRV : PN_TRACE_OFF) |
- (pn_env_bool("PN_TRACE_EVT") ? PN_TRACE_EVT : PN_TRACE_OFF) ;
}
@@ -682,6 +668,7 @@ static void pn_transport_finalize(void *object)
pn_buffer_free(transport->frame);
pn_free(transport->context);
pn_buffer_free(transport->output_buffer);
+ pni_logger_fini(&transport->logger);
}
static void pni_post_remote_open_events(pn_transport_t *transport, pn_connection_t *connection) {
@@ -822,6 +809,12 @@ pn_condition_t *pn_transport_condition(pn_transport_t *transport)
return &transport->condition;
}
+pn_logger_t *pn_transport_logger(pn_transport_t *transport)
+{
+ assert(transport);
+ return &transport->logger;
+}
+
static void pni_map_remote_handle(pn_link_t *link, uint32_t handle)
{
link->state.remote_handle = handle;
@@ -890,7 +883,7 @@ static int pni_disposition_encode(pn_disposition_t *disposition, pn_data_t *data
void pn_do_trace(pn_transport_t *transport, uint16_t ch, pn_dir_t dir,
pn_data_t *args, const char *payload, size_t size)
{
- if (transport->trace & PN_TRACE_FRM) {
+ if (PN_SHOULD_LOG(&transport->logger, PN_SUBSYSTEM_AMQP, PN_LEVEL_FRAME) ) {
pn_string_format(transport->scratch, "%u %s ", ch, dir == OUT ? "->" : "<-");
pn_inspect(args, transport->scratch);
@@ -905,7 +898,7 @@ void pn_do_trace(pn_transport_t *transport, uint16_t ch, pn_dir_t dir,
e == PN_OVERFLOW ? "... (truncated)" : "");
}
- pn_transport_log(transport, pn_string_get(transport->scratch));
+ pni_logger_log(&transport->logger, PN_SUBSYSTEM_AMQP, PN_LEVEL_FRAME, pn_string_get(transport->scratch));
}
}
@@ -918,7 +911,7 @@ int pn_post_frame(pn_transport_t *transport, uint8_t type, uint16_t ch, const ch
int err = pn_data_vfill(transport->output_args, fmt, ap);
va_end(ap);
if (err) {
- pn_transport_logf(transport,
+ pn_logger_logf(&transport->logger, PN_SUBSYSTEM_AMQP, PN_LEVEL_ERROR,
"error posting frame: %s, %s: %s", fmt, pn_code(err),
pn_error_text(pn_data_error(transport->output_args)));
return PN_ERR;
@@ -937,7 +930,7 @@ int pn_post_frame(pn_transport_t *transport, uint8_t type, uint16_t ch, const ch
pn_buffer_ensure( frame_buf, pn_buffer_available( frame_buf ) * 2 );
goto encode_performatives;
}
- pn_transport_logf(transport,
+ pn_logger_logf(&transport->logger, PN_SUBSYSTEM_AMQP, PN_LEVEL_ERROR,
"error posting frame: %s", pn_code(wr));
return PN_ERR;
}
@@ -950,11 +943,11 @@ int pn_post_frame(pn_transport_t *transport, uint8_t type, uint16_t ch, const ch
pn_buffer_ensure(transport->output_buffer, AMQP_HEADER_SIZE+frame.ex_size+frame.size);
pn_write_frame(transport->output_buffer, frame);
transport->output_frames_ct += 1;
- if (transport->trace & PN_TRACE_RAW) {
+ if (PN_SHOULD_LOG(&transport->logger, PN_SUBSYSTEM_IO, PN_LEVEL_RAW)) {
pn_string_set(transport->scratch, "RAW: \"");
pn_buffer_quote(transport->output_buffer, transport->scratch, AMQP_HEADER_SIZE+frame.ex_size+frame.size);
pn_string_addf(transport->scratch, "\"");
- pn_transport_log(transport, pn_string_get(transport->scratch));
+ pni_logger_log(&transport->logger, PN_SUBSYSTEM_IO, PN_LEVEL_RAW, pn_string_get(transport->scratch));
}
return 0;
@@ -995,7 +988,7 @@ static int pni_post_amqp_transfer_frame(pn_transport_t *transport, uint16_t ch,
aborted, aborted,
batchable, batchable);
if (err) {
- pn_transport_logf(transport,
+ pn_logger_logf(&transport->logger, PN_SUBSYSTEM_AMQP, PN_LEVEL_ERROR,
"error posting transfer frame: %s: %s", pn_code(err),
pn_error_text(pn_data_error(transport->output_args)));
return PN_ERR;
@@ -1014,7 +1007,7 @@ static int pni_post_amqp_transfer_frame(pn_transport_t *transport, uint16_t ch,
pn_buffer_ensure( frame, pn_buffer_available( frame ) * 2 );
goto encode_performatives;
}
- pn_transport_logf(transport, "error posting frame: %s", pn_code(wr));
+ pn_logger_logf(&transport->logger, PN_SUBSYSTEM_AMQP, PN_LEVEL_ERROR, "error posting frame: %s", pn_code(wr));
return PN_ERR;
}
buf.size = wr;
@@ -1057,11 +1050,11 @@ static int pni_post_amqp_transfer_frame(pn_transport_t *transport, uint16_t ch,
pn_write_frame(transport->output_buffer, frame);
transport->output_frames_ct += 1;
framecount++;
- if (transport->trace & PN_TRACE_RAW) {
+ if (PN_SHOULD_LOG(&transport->logger, PN_SUBSYSTEM_IO, PN_LEVEL_RAW)) {
pn_string_set(transport->scratch, "RAW: \"");
pn_buffer_quote(transport->output_buffer, transport->scratch, AMQP_HEADER_SIZE+frame.ex_size+frame.size);
pn_string_addf(transport->scratch, "\"");
- pn_transport_log(transport, pn_string_get(transport->scratch));
+ pni_logger_log(&transport->logger, PN_SUBSYSTEM_IO, PN_LEVEL_RAW, pn_string_get(transport->scratch));
}
} while (payload->size > 0 && framecount < frame_limit);
@@ -1143,8 +1136,12 @@ int pn_do_error(pn_transport_t *transport, const char *condition, const char *fm
}
pn_collector_t *collector = pni_transport_collector(transport);
pn_collector_put(collector, PN_OBJECT, transport, PN_TRANSPORT_ERROR);
- if (transport->trace & PN_TRACE_DRV) {
- pn_transport_logf(transport, "ERROR %s %s", condition, buf);
+ // Special case being called with no condition and no fmt to log the existing error condition
+ if (fmt && condition) {
+ PN_LOG(&transport->logger, PN_SUBSYSTEM_AMQP, PN_LEVEL_ERROR, "%s %s", condition, buf);
+ } else {
+ PN_LOG(&transport->logger, PN_SUBSYSTEM_AMQP, PN_LEVEL_ERROR, "%s %s",
+ pn_condition_get_name(cond), pn_condition_get_description(cond));
}
for (int i = 0; i<PN_IO_LAYER_CT; ++i) {
@@ -1192,8 +1189,9 @@ int pn_do_open(pn_transport_t *transport, uint8_t frame_type, uint16_t channel,
if (transport->remote_max_frame > 0) {
if (transport->remote_max_frame < AMQP_MIN_MAX_FRAME_SIZE) {
- pn_transport_logf(transport, "Peer advertised bad max-frame (%u), forcing to %u",
- transport->remote_max_frame, AMQP_MIN_MAX_FRAME_SIZE);
+ pn_logger_logf(&transport->logger, PN_SUBSYSTEM_AMQP, PN_LEVEL_WARNING,
+ "Peer advertised bad max-frame (%u), forcing to %u",
+ transport->remote_max_frame, AMQP_MIN_MAX_FRAME_SIZE);
transport->remote_max_frame = AMQP_MIN_MAX_FRAME_SIZE;
}
}
@@ -1869,8 +1867,7 @@ static ssize_t transport_consume(pn_transport_t *transport)
break;
} else {
assert(n == PN_EOS);
- if (transport->trace & (PN_TRACE_RAW | PN_TRACE_FRM))
- pn_transport_log(transport, " <- EOS");
+ PN_LOG(&transport->logger, PN_SUBSYSTEM_AMQP | PN_SUBSYSTEM_IO, PN_LEVEL_FRAME | PN_LEVEL_RAW, " <- EOS");
transport->input_pending = 0; // XXX ???
return n;
}
@@ -1979,7 +1976,7 @@ static int pni_process_ssn_setup(pn_transport_t *transport, pn_endpoint_t *endpo
if (!(endpoint->state & PN_LOCAL_UNINIT) && state->local_channel == (uint16_t) -1)
{
if (! pni_map_local_channel(ssn)) {
- pn_transport_logf(transport, "unable to find an open available channel within limit of %d", transport->channel_max );
+ pn_logger_logf(&transport->logger, PN_SUBSYSTEM_AMQP, PN_LEVEL_WARNING, "unable to find an open available channel within limit of %d", transport->channel_max );
return PN_ERR;
}
state->incoming_window = pni_session_incoming_window(ssn);
@@ -2591,8 +2588,7 @@ static ssize_t pn_input_read_amqp_header(pn_transport_t* transport, unsigned int
} else {
transport->io_layers[layer] = &amqp_write_header_layer;
}
- if (transport->trace & PN_TRACE_FRM)
- pn_transport_logf(transport, " <- %s", "AMQP");
+ PN_LOG(&transport->logger, PN_SUBSYSTEM_AMQP, PN_LEVEL_FRAME, " <- %s", "AMQP");
return 8;
case PNI_PROTOCOL_INSUFFICIENT:
if (!eos) return 0;
@@ -2674,8 +2670,7 @@ static pn_timestamp_t pn_tick_amqp(pn_transport_t* transport, unsigned int layer
static ssize_t pn_output_write_amqp_header(pn_transport_t* transport, unsigned int layer, char* bytes, size_t available)
{
- if (transport->trace & PN_TRACE_FRM)
- pn_transport_logf(transport, " -> %s", "AMQP");
+ PN_LOG(&transport->logger, PN_SUBSYSTEM_AMQP, PN_LEVEL_FRAME, " -> %s", "AMQP");
assert(available >= 8);
memmove(bytes, AMQP_HEADER, 8);
if (pn_condition_is_set(&transport->condition)) {
@@ -2697,7 +2692,7 @@ static ssize_t pn_output_write_amqp(pn_transport_t* transport, unsigned int laye
if (transport->connection && !transport->done_processing) {
int err = pni_process(transport);
if (err) {
- pn_transport_logf(transport, "process error %i", err);
+ pn_logger_logf(&transport->logger, PN_SUBSYSTEM_AMQP, PN_LEVEL_ERROR, "process error %i", err);
transport->done_processing = true;
}
}
@@ -2760,9 +2755,7 @@ static ssize_t transport_produce(pn_transport_t *transport)
} else {
if (transport->output_pending)
break; // return what is available
- if (transport->trace & (PN_TRACE_RAW | PN_TRACE_FRM)) {
- pn_transport_log(transport, " -> EOS");
- }
+ PN_LOG(&transport->logger, PN_SUBSYSTEM_AMQP | PN_SUBSYSTEM_IO, PN_LEVEL_FRAME | PN_LEVEL_RAW, " -> EOS");
pni_close_head(transport);
return n;
}
@@ -2787,15 +2780,32 @@ ssize_t pn_transport_output(pn_transport_t *transport, char *bytes, size_t size)
void pn_transport_trace(pn_transport_t *transport, pn_trace_t trace)
{
- transport->trace = trace;
+ unsigned int level_mask = 0;
+ if (trace & PN_TRACE_FRM) level_mask = level_mask | PN_LEVEL_FRAME;
+ if (trace & PN_TRACE_RAW) level_mask = level_mask | PN_LEVEL_RAW;
+
+ // Don't change the subsystem bits, but forcibly set the level bits (back compat behaviour)
+ pn_logger_reset_mask(&transport->logger, PN_SUBSYSTEM_NONE, PN_LEVEL_ALL);
+ pn_logger_set_mask(&transport->logger, PN_SUBSYSTEM_NONE, (pn_log_level_t)level_mask);
+}
+
+static void pni_tracer_to_log_sink(intptr_t context, pn_log_subsystem_t subsystem, pn_log_level_t sev, const char* msg)
+{
+ pn_transport_t *transport = (pn_transport_t*)context;
+ // can't use either logger or transport scratch string as we could be called with either
+ char buf[2048]; // Arbitrarily large
+ strcpy(buf, pn_logger_level_name(sev));
+ strcat(buf, ": ");
+ strncat(buf, msg, 2037); // Up to 11 more characters than msg in buf
+ transport->tracer(transport, buf);
}
void pn_transport_set_tracer(pn_transport_t *transport, pn_tracer_t tracer)
{
assert(transport);
assert(tracer);
-
transport->tracer = tracer;
+ pn_logger_set_log_sink(&transport->logger, pni_tracer_to_log_sink, (intptr_t)transport);
}
pn_tracer_t pn_transport_get_tracer(pn_transport_t *transport)
@@ -2824,18 +2834,14 @@ pn_record_t *pn_transport_attachments(pn_transport_t *transport)
void pn_transport_log(pn_transport_t *transport, const char *message)
{
- assert(transport);
- transport->tracer(transport, message);
+ pn_logger_t *logger = transport ? &transport->logger : pn_default_logger();
+ pni_logger_log(logger, PN_SUBSYSTEM_ALL, PN_LEVEL_TRACE, message);
}
void pn_transport_vlogf(pn_transport_t *transport, const char *fmt, va_list ap)
{
- if (transport) {
- pn_string_vformat(transport->scratch, fmt, ap);
- pn_transport_log(transport, pn_string_get(transport->scratch));
- } else {
- pn_vlogf(fmt, ap);
- }
+ pn_logger_t *logger = transport ? &transport->logger : pn_default_logger();
+ pni_logger_vlogf(logger, PN_SUBSYSTEM_ALL, PN_LEVEL_TRACE, fmt, ap);
}
void pn_transport_logf(pn_transport_t *transport, const char *fmt, ...)
@@ -2865,7 +2871,7 @@ int pn_transport_set_channel_max(pn_transport_t *transport, uint16_t requested_c
* is sent.
*/
if(transport->open_sent) {
- pn_transport_logf(transport, "Cannot change local channel-max after OPEN frame sent.");
+ pn_logger_logf(&transport->logger, PN_SUBSYSTEM_AMQP, PN_LEVEL_WARNING, "Cannot change local channel-max after OPEN frame sent.");
return PN_STATE_ERR;
}
diff --git a/c/src/proactor/epoll.c b/c/src/proactor/epoll.c
index 998a1b9..677d6b6 100644
--- a/c/src/proactor/epoll.c
+++ b/c/src/proactor/epoll.c
@@ -26,8 +26,8 @@
/* Avoid GNU extensions, in particular the incompatible alternative strerror_r() */
#undef _GNU_SOURCE
-#include "../core/log_private.h"
-#include "./proactor-internal.h"
+#include "core/logger_private.h"
+#include "proactor-internal.h"
#include <proton/condition.h>
#include <proton/connection_driver.h>
@@ -684,7 +684,7 @@ static inline bool proactor_has_event(pn_proactor_t *p) {
static pn_event_t *log_event(void* p, pn_event_t *e) {
if (e) {
- pn_logf("[%p]:(%s)", (void*)p, pn_event_type_name(pn_event_type(e)));
+ PN_LOG_DEFAULT(PN_SUBSYSTEM_EVENT, PN_LEVEL_DEBUG, "[%p]:(%s)", (void*)p, pn_event_type_name(pn_event_type(e)));
}
return e;
}
@@ -1387,7 +1387,7 @@ void pn_proactor_connect2(pn_proactor_t *p, pn_connection_t *c, pn_transport_t *
assert(pc); // TODO: memory safety
const char *err = pconnection_setup(pc, p, c, t, false, addr);
if (err) { /* TODO aconway 2017-09-13: errors must be reported as events */
- pn_logf("pn_proactor_connect failure: %s", err);
+ PN_LOG_DEFAULT(PN_SUBSYSTEM_EVENT, PN_LEVEL_ERROR, "pn_proactor_connect failure: %s", err);
return;
}
// TODO: check case of proactor shutting down
@@ -1796,7 +1796,7 @@ void pn_listener_accept2(pn_listener_t *l, pn_connection_t *c, pn_transport_t *t
assert(pc); // TODO: memory safety
const char *err = pconnection_setup(pc, pn_listener_proactor(l), c, t, true, "");
if (err) {
- pn_logf("pn_listener_accept failure: %s", err);
+ PN_LOG_DEFAULT(PN_SUBSYSTEM_EVENT, PN_LEVEL_ERROR, "pn_listener_accept failure: %s", err);
return;
}
// TODO: fuller sanity check on input args
diff --git a/c/src/proactor/libuv.c b/c/src/proactor/libuv.c
index e25d771..6a5ecaf 100644
--- a/c/src/proactor/libuv.c
+++ b/c/src/proactor/libuv.c
@@ -24,7 +24,7 @@
#define _POSIX_C_SOURCE 200809L
#endif
-#include "../core/log_private.h"
+#include "core/logger_private.h"
#include "proactor-internal.h"
#include <proton/condition.h>
@@ -821,7 +821,7 @@ static pn_event_batch_t *proactor_batch_lh(pn_proactor_t *p, pn_event_type_t t)
static pn_event_t *log_event(void* p, pn_event_t *e) {
if (e) {
- pn_logf("[%p]:(%s)", (void*)p, pn_event_type_name(pn_event_type(e)));
+ PN_LOG_DEFAULT(PN_SUBSYSTEM_EVENT, PN_LEVEL_DEBUG, "[%p]:(%s)", (void*)p, pn_event_type_name(pn_event_type(e)));
}
return e;
}
diff --git a/c/src/proactor/win_iocp.c b/c/src/proactor/win_iocp.c
index d4951d0..732af7b 100644
--- a/c/src/proactor/win_iocp.c
+++ b/c/src/proactor/win_iocp.c
@@ -44,7 +44,8 @@
#include <iostream>
#include <sstream>
-#include "./netaddr-internal.h" /* Include after socket/inet headers */
+#include "netaddr-internal.h" /* Include after socket/inet headers */
+#include "core/logger_private.h"
/*
* Proactor for Windows using IO completion ports.
@@ -1556,8 +1557,8 @@ iocp_t *pni_iocp()
// Proton Proactor support
// ======================================================================
-#include "../core/log_private.h"
-#include "./proactor-internal.h"
+#include "core/logger_private.h"
+#include "proactor-internal.h"
class csguard {
public:
@@ -2031,7 +2032,7 @@ static inline bool proactor_has_event(pn_proactor_t *p) {
static pn_event_t *log_event(void* p, pn_event_t *e) {
if (e) {
- pn_logf("[%p]:(%s)", (void*)p, pn_event_type_name(pn_event_type(e)));
+ PN_LOG_DEFAULT(PN_SUBSYSTEM_EVENT, PN_LEVEL_DEBUG, "[%p]:(%s)", (void*)p, pn_event_type_name(pn_event_type(e)));
}
return e;
}
@@ -2531,7 +2532,7 @@ static pn_event_batch_t *proactor_completion_loop(struct pn_proactor_t* p, bool
if (!good_op && !overlapped) {
// Should never happen. shutdown?
// We aren't expecting a timeout, closed completion port, or other error here.
- pn_logf("%s", errno_str("Windows Proton proactor internal failure\n", false).c_str());
+ PN_LOG_DEFAULT(PN_SUBSYSTEM_EVENT, PN_LEVEL_CRITICAL, "%s", errno_str("Windows Proton proactor internal failure\n", false).c_str());
abort();
}
@@ -2727,7 +2728,7 @@ void pn_proactor_connect2(pn_proactor_t *p, pn_connection_t *c, pn_transport_t *
assert(pc); // TODO: memory safety
const char *err = pconnection_setup(pc, p, c, t, false, addr);
if (err) {
- pn_logf("pn_proactor_connect failure: %s", err);
+ PN_LOG_DEFAULT(PN_SUBSYSTEM_EVENT, PN_LEVEL_ERROR, "pn_proactor_connect failure: %s", err);
return;
}
// TODO: check case of proactor shutting down
@@ -3185,7 +3186,7 @@ void pn_listener_accept2(pn_listener_t *l, pn_connection_t *c, pn_transport_t *t
assert(pc); // TODO: memory safety
const char *err_str = pconnection_setup(pc, p, c, t, true, "");
if (err_str) {
- pn_logf("pn_listener_accept failure: %s", err_str);
+ PN_LOG_DEFAULT(PN_SUBSYSTEM_EVENT, PN_LEVEL_ERROR, "pn_listener_accept failure: %s", err_str);
return;
}
proactor_add(&pc->context);
diff --git a/c/src/sasl/cyrus_sasl.c b/c/src/sasl/cyrus_sasl.c
index 30c5784..27edad7 100644
--- a/c/src/sasl/cyrus_sasl.c
+++ b/c/src/sasl/cyrus_sasl.c
@@ -22,7 +22,7 @@
#define _GNU_SOURCE
#endif
-#include "core/log_private.h"
+#include "core/logger_private.h"
#include "proton/sasl.h"
#include "proton/sasl-plugin.h"
@@ -132,7 +132,7 @@ static void pni_cyrus_interact(pn_transport_t *transport, sasl_interact_t *inter
break;
}
default:
- pn_logf("(%s): %s - %s", i->challenge, i->prompt, i->defresult);
+ pnx_sasl_logf(transport, "(%s): %s - %s", i->challenge, i->prompt, i->defresult);
}
}
}
diff --git a/c/src/sasl/sasl.c b/c/src/sasl/sasl.c
index 991ac0b..c3f94ab 100644
--- a/c/src/sasl/sasl.c
+++ b/c/src/sasl/sasl.c
@@ -47,8 +47,8 @@ void pnx_sasl_logf(pn_transport_t *logger, const char *fmt, ...)
{
va_list ap;
va_start(ap, fmt);
- if (logger->trace & PN_TRACE_DRV)
- pn_transport_vlogf(logger, fmt, ap);
+ if (PN_SHOULD_LOG(&logger->logger, PN_SUBSYSTEM_SASL, PN_LEVEL_ERROR))
+ pni_logger_vlogf(&logger->logger, PN_SUBSYSTEM_SASL, PN_LEVEL_ERROR, fmt, ap);
va_end(ap);
}
@@ -150,7 +150,7 @@ void pnx_sasl_succeed_authentication(pn_transport_t *transport, const char *use
transport->sasl->outcome = PN_SASL_OK;
transport->authenticated = true;
- pnx_sasl_logf(transport, "Authenticated user: %s with mechanism %s",
+ PN_LOG(&transport->logger, PN_SUBSYSTEM_SASL, PN_LEVEL_INFO, "Authenticated user: %s with mechanism %s",
username, transport->sasl->selected_mechanism);
}
}
@@ -358,14 +358,11 @@ void pnx_sasl_set_desired_state(pn_transport_t *transport, enum pnx_sasl_state d
{
pni_sasl_t *sasl = transport->sasl;
if (sasl->last_state > desired_state) {
- if (transport->trace & PN_TRACE_DRV)
- pn_transport_logf(transport, "Trying to send SASL frame (%d), but illegal: already in later state (%d)", desired_state, sasl->last_state);
+ PN_LOG(&transport->logger, PN_SUBSYSTEM_SASL, PN_LEVEL_ERROR, "Trying to send SASL frame (%d), but illegal: already in later state (%d)", desired_state, sasl->last_state);
} else if (sasl->client && !pni_sasl_is_client_state(desired_state)) {
- if (transport->trace & PN_TRACE_DRV)
- pn_transport_logf(transport, "Trying to send server SASL frame (%d) on a client", desired_state);
+ PN_LOG(&transport->logger, PN_SUBSYSTEM_SASL, PN_LEVEL_ERROR, "Trying to send server SASL frame (%d) on a client", desired_state);
} else if (!sasl->client && !pni_sasl_is_server_state(desired_state)) {
- if (transport->trace & PN_TRACE_DRV)
- pn_transport_logf(transport, "Trying to send client SASL frame (%d) on a server", desired_state);
+ PN_LOG(&transport->logger, PN_SUBSYSTEM_SASL, PN_LEVEL_ERROR, "Trying to send client SASL frame (%d) on a server", desired_state);
} else {
// If we need to repeat CHALLENGE or RESPONSE frames adjust current state to seem
// like they haven't been sent yet
@@ -558,8 +555,7 @@ static ssize_t pn_input_read_sasl_header(pn_transport_t* transport, unsigned int
} else {
transport->io_layers[layer] = &sasl_write_header_layer;
}
- if (transport->trace & PN_TRACE_FRM)
- pn_transport_logf(transport, " <- %s", "SASL");
+ PN_LOG(&transport->logger, PN_SUBSYSTEM_SASL, PN_LEVEL_FRAME, " <- %s", "SASL");
pni_sasl_set_external_security(transport, pn_ssl_get_ssf((pn_ssl_t*)transport), pn_ssl_get_remote_subject((pn_ssl_t*)transport));
return SASL_HEADER_LEN;
case PNI_PROTOCOL_INSUFFICIENT:
@@ -613,8 +609,7 @@ static ssize_t pn_input_read_sasl(pn_transport_t* transport, unsigned int layer,
if (pni_sasl_impl_can_encrypt(transport)) {
sasl->max_encrypt_size = pni_sasl_impl_max_encrypt_size(transport);
- if (transport->trace & PN_TRACE_DRV)
- pn_transport_logf(transport, "SASL Encryption enabled: buffer=%" PN_ZU, sasl->max_encrypt_size);
+ PN_LOG(&transport->logger, PN_SUBSYSTEM_SASL, PN_LEVEL_INFO, "Encryption enabled: buffer=%" PN_ZU, sasl->max_encrypt_size);
transport->io_layers[layer] = &sasl_encrypt_layer;
} else {
transport->io_layers[layer] = &pni_passthru_layer;
@@ -651,8 +646,7 @@ static ssize_t pn_input_read_sasl_encrypt(pn_transport_t* transport, unsigned in
static ssize_t pn_output_write_sasl_header(pn_transport_t *transport, unsigned int layer, char *bytes, size_t size)
{
- if (transport->trace & PN_TRACE_FRM)
- pn_transport_logf(transport, " -> %s", "SASL");
+ PN_LOG(&transport->logger, PN_SUBSYSTEM_SASL, PN_LEVEL_FRAME, " -> %s", "SASL");
assert(size >= SASL_HEADER_LEN);
memmove(bytes, SASL_HEADER, SASL_HEADER_LEN);
if (transport->io_layers[layer]==&sasl_write_header_layer) {
@@ -692,8 +686,7 @@ static ssize_t pn_output_write_sasl(pn_transport_t* transport, unsigned int laye
// We know that auth succeeded or we're not in final input state
if (pni_sasl_impl_can_encrypt(transport)) {
sasl->max_encrypt_size = pni_sasl_impl_max_encrypt_size(transport);
- if (transport->trace & PN_TRACE_DRV)
- pn_transport_logf(transport, "SASL Encryption enabled: buffer=%" PN_ZU, sasl->max_encrypt_size);
+ PN_LOG(&transport->logger, PN_SUBSYSTEM_SASL, PN_LEVEL_INFO, "Encryption enabled: buffer=%" PN_ZU, sasl->max_encrypt_size);
transport->io_layers[layer] = &sasl_encrypt_layer;
} else {
transport->io_layers[layer] = &pni_passthru_layer;
diff --git a/c/src/ssl/openssl.c b/c/src/ssl/openssl.c
index 7ba5531..0ee5411 100644
--- a/c/src/ssl/openssl.c
+++ b/c/src/ssl/openssl.c
@@ -22,7 +22,7 @@
#include "platform/platform.h"
#include "platform/platform_fmt.h"
#include "core/engine-internal.h"
-#include "core/log_private.h"
+#include "core/logger_private.h"
#include "core/util.h"
#include <proton/ssl.h>
@@ -147,32 +147,29 @@ static void release_ssl_socket( pni_ssl_t * );
static size_t buffered_output( pn_transport_t *transport );
static X509 *get_peer_certificate(pni_ssl_t *ssl);
-static void ssl_vlog(pn_transport_t *transport, const char *fmt, va_list ap)
+static void ssl_vlog(pn_transport_t *transport, pn_log_level_t sev, const char *fmt, va_list ap)
{
- if (transport) {
- if (PN_TRACE_DRV & transport->trace) {
- pn_transport_vlogf(transport, fmt, ap);
- }
- } else {
- pn_transport_vlogf(transport, fmt, ap);
+ pn_logger_t *logger = transport ? &transport->logger : pn_default_logger();
+ if (PN_SHOULD_LOG(logger, PN_SUBSYSTEM_SSL, sev)) {
+ pni_logger_vlogf(logger, PN_SUBSYSTEM_SSL, sev, fmt, ap);
}
}
-static void ssl_log(pn_transport_t *transport, const char *fmt, ...)
+static void ssl_log(pn_transport_t *transport, pn_log_level_t sev, const char *fmt, ...)
{
va_list ap;
va_start(ap, fmt);
- ssl_vlog(transport, fmt, ap);
+ ssl_vlog(transport, sev, fmt, ap);
va_end(ap);
}
-static void ssl_log_flush(pn_transport_t* transport)
+static void ssl_log_flush(pn_transport_t* transport, pn_log_level_t sev)
{
char buf[128]; // see "man ERR_error_string_n()"
unsigned long err = ERR_get_error();
while (err) {
ERR_error_string_n(err, buf, sizeof(buf));
- ssl_log(transport, "%s", buf);
+ ssl_log(transport, sev, "%s", buf);
err = ERR_get_error();
}
}
@@ -183,17 +180,15 @@ static void ssl_log_error(const char *fmt, ...)
if (fmt) {
va_list ap;
va_start(ap, fmt);
- ssl_vlog(NULL, fmt, ap);
+ ssl_vlog(NULL, PN_LEVEL_ERROR, fmt, ap);
va_end(ap);
}
- ssl_log_flush(NULL);
+ ssl_log_flush(NULL, PN_LEVEL_ERROR);
}
static void ssl_log_clear_data(pn_transport_t *transport, const char *data, size_t len)
{
- if (PN_TRACE_RAW & transport->trace) {
- pn_log_data("SSL decrypted data", data, len );
- }
+ PN_LOG_DATA(&transport->logger, PN_SUBSYSTEM_SSL, PN_LEVEL_RAW, "decrypted data", data, len );
}
// unrecoverable SSL failure occurred, notify transport and generate error code.
@@ -211,7 +206,7 @@ static int ssl_failed(pn_transport_t *transport)
if (ssl_err) {
ERR_error_string_n( ssl_err, buf, sizeof(buf) );
}
- ssl_log_flush(transport); // spit out any remaining errors to the log file
+ ssl_log_flush(transport, PN_LEVEL_ERROR); // spit out any remaining errors to the log file
pn_do_error(transport, "amqp:connection:framing-error", "SSL Failure: %s", buf);
return PN_EOS;
}
@@ -283,24 +278,24 @@ static int verify_callback(int preverify_ok, X509_STORE_CTX *ctx)
X509 *cert = X509_STORE_CTX_get_current_cert(ctx);
SSL *ssn = (SSL *) X509_STORE_CTX_get_ex_data(ctx, SSL_get_ex_data_X509_STORE_CTX_idx());
if (!ssn) {
- pn_transport_logf(NULL, "Error: unexpected error - SSL session info not available for peer verify!");
+ ssl_log(NULL, PN_LEVEL_ERROR, "Error: unexpected error - SSL session info not available for peer verify!");
return 0; // fail connection
}
pn_transport_t *transport = (pn_transport_t *)SSL_get_ex_data(ssn, ssl_ex_data_index);
if (!transport) {
- pn_transport_logf(NULL, "Error: unexpected error - SSL context info not available for peer verify!");
+ ssl_log(transport, PN_LEVEL_ERROR, "Error: unexpected error - SSL context info not available for peer verify!");
return 0; // fail connection
}
pni_ssl_t *ssl = transport->ssl;
if (ssl->verify_mode != PN_SSL_VERIFY_PEER_NAME) return preverify_ok;
if (!ssl->peer_hostname) {
- pn_transport_logf(transport, "Error: configuration error: PN_SSL_VERIFY_PEER_NAME configured, but no peer hostname set!");
+ ssl_log(transport, PN_LEVEL_ERROR, "Error: configuration error: PN_SSL_VERIFY_PEER_NAME configured, but no peer hostname set!");
return 0; // fail connection
}
- ssl_log(transport, "Checking identifying name in peer cert against '%s'", ssl->peer_hostname);
+ ssl_log(transport, PN_LEVEL_TRACE, "Checking identifying name in peer cert against '%s'", ssl->peer_hostname);
bool matched = false;
@@ -317,7 +312,7 @@ static int verify_callback(int preverify_ok, X509_STORE_CTX *ctx)
unsigned char *str;
int len = ASN1_STRING_to_UTF8( &str, asn1 );
if (len >= 0) {
- ssl_log(transport, "SubjectAltName (dns) from peer cert = '%.*s'", len, str );
+ ssl_log(transport, PN_LEVEL_TRACE, "SubjectAltName (dns) from peer cert = '%.*s'", len, str );
matched = match_dns_pattern( ssl->peer_hostname, (const char *)str, len );
OPENSSL_free( str );
}
@@ -337,7 +332,7 @@ static int verify_callback(int preverify_ok, X509_STORE_CTX *ctx)
unsigned char *str;
int len = ASN1_STRING_to_UTF8( &str, name_asn1);
if (len >= 0) {
- ssl_log(transport, "commonName from peer cert = '%.*s'", len, str);
+ ssl_log(transport, PN_LEVEL_TRACE, "commonName from peer cert = '%.*s'", len, str);
matched = match_dns_pattern( ssl->peer_hostname, (const char *)str, len );
OPENSSL_free(str);
}
@@ -345,14 +340,14 @@ static int verify_callback(int preverify_ok, X509_STORE_CTX *ctx)
}
if (!matched) {
- ssl_log(transport, "Error: no name matching %s found in peer cert - rejecting handshake.",
+ ssl_log(transport, PN_LEVEL_ERROR, "Error: no name matching %s found in peer cert - rejecting handshake.",
ssl->peer_hostname);
preverify_ok = 0;
#ifdef X509_V_ERR_APPLICATION_VERIFICATION
X509_STORE_CTX_set_error( ctx, X509_V_ERR_APPLICATION_VERIFICATION );
#endif
} else {
- ssl_log(transport, "Name from peer cert matched - peer is valid.");
+ ssl_log(transport, PN_LEVEL_TRACE, "Name from peer cert matched - peer is valid.");
}
return preverify_ok;
}
@@ -438,10 +433,10 @@ static void ssn_restore(pn_transport_t *transport, pni_ssl_t *ssl) {
i = (i==0) ? SSL_CACHE_SIZE-1 : i-1;
if (ssl_cache[i].id == NULL) return;
if (strcmp(ssl_cache[i].id, ssl->session_id) == 0) {
- ssl_log( transport, "Restoring previous session id=%s", ssl->session_id );
+ ssl_log( transport, PN_LEVEL_TRACE, "Restoring previous session id=%s", ssl->session_id );
int rc = SSL_set_session( ssl->ssl, ssl_cache[i].session );
if (rc != 1) {
- ssl_log( transport, "Session restore failed, id=%s", ssl->session_id );
+ ssl_log( transport, PN_LEVEL_WARNING, "Session restore failed, id=%s", ssl->session_id );
}
return;
}
@@ -455,7 +450,7 @@ static void ssn_save(pn_transport_t *transport, pni_ssl_t *ssl) {
// So that if we find it in the cache later we can figure out the session id
SSL_SESSION *session = SSL_get1_session( ssl->ssl );
if (session) {
- ssl_log(transport, "Saving SSL session as %s", ssl->session_id );
+ ssl_log(transport, PN_LEVEL_TRACE, "Saving SSL session as %s", ssl->session_id );
// If we're overwriting a value, need to free it
free(ssl_cache[ssl_cache_ptr].id);
if (ssl_cache[ssl_cache_ptr].session) SSL_SESSION_free(ssl_cache[ssl_cache_ptr].session);
@@ -521,7 +516,7 @@ static bool pni_init_ssl_domain( pn_ssl_domain_t * domain, pn_ssl_mode_t mode )
break;
default:
- pn_transport_logf(NULL, "Invalid value for pn_ssl_mode_t: %d", mode);
+ ssl_log(NULL, PN_LEVEL_ERROR, "Invalid value for pn_ssl_mode_t: %d", mode);
return false;
}
@@ -710,7 +705,7 @@ int pn_ssl_domain_set_trusted_ca_db(pn_ssl_domain_t *domain,
// to SSL_CTX_load_verify_locations()
struct stat sbuf;
if (stat( certificate_db, &sbuf ) != 0) {
- pn_transport_logf(NULL, "stat(%s) failed: %s", certificate_db, strerror(errno));
+ ssl_log(NULL, PN_LEVEL_ERROR, "stat(%s) failed: %s", certificate_db, strerror(errno));
return -1;
}
@@ -751,11 +746,11 @@ int pn_ssl_domain_set_peer_authentication(pn_ssl_domain_t *domain,
// openssl requires that server connections supply a list of trusted CAs which is
// sent to the client
if (!trusted_CAs) {
- pn_transport_logf(NULL, "Error: a list of trusted CAs must be provided.");
+ ssl_log(NULL, PN_LEVEL_ERROR, "Error: a list of trusted CAs must be provided.");
return -1;
}
if (!domain->has_certificate) {
- pn_transport_logf(NULL, "Error: Server cannot verify peer without configuring a certificate, use pn_ssl_domain_set_credentials()");
+ ssl_log(NULL, PN_LEVEL_ERROR, "Error: Server cannot verify peer without configuring a certificate, use pn_ssl_domain_set_credentials()");
return -1;
}
@@ -766,7 +761,7 @@ int pn_ssl_domain_set_peer_authentication(pn_ssl_domain_t *domain,
if (cert_names != NULL)
SSL_CTX_set_client_CA_list(domain->ctx, cert_names);
else {
- pn_transport_logf(NULL, "Error: Unable to process file of trusted CAs: %s", trusted_CAs);
+ ssl_log(NULL, PN_LEVEL_ERROR, "Error: Unable to process file of trusted CAs: %s", trusted_CAs);
return -1;
}
}
@@ -800,7 +795,7 @@ int pn_ssl_domain_set_peer_authentication(pn_ssl_domain_t *domain,
break;
default:
- pn_transport_logf(NULL, "Invalid peer authentication mode given." );
+ ssl_log(NULL, PN_LEVEL_ERROR, "Invalid peer authentication mode given." );
return -1;
}
@@ -881,7 +876,7 @@ int pn_ssl_domain_allow_unsecured_client(pn_ssl_domain_t *domain)
{
if (!domain) return -1;
if (domain->mode != PN_SSL_MODE_SERVER) {
- pn_transport_logf(NULL, "Cannot permit unsecured clients - not a server.");
+ ssl_log(NULL, PN_LEVEL_ERROR, "Cannot permit unsecured clients - not a server.");
return -1;
}
domain->allow_unsecured = true;
@@ -936,7 +931,7 @@ void pn_ssl_free(pn_transport_t *transport)
{
pni_ssl_t *ssl = transport->ssl;
if (!ssl) return;
- ssl_log(transport, "SSL socket freed." );
+ ssl_log(transport, PN_LEVEL_TRACE, "SSL socket freed." );
release_ssl_socket( ssl );
if (ssl->session_id) free((void *)ssl->session_id);
if (ssl->peer_hostname) free((void *)ssl->peer_hostname);
@@ -996,7 +991,7 @@ static int start_ssl_shutdown(pn_transport_t *transport)
{
pni_ssl_t *ssl = transport->ssl;
if (!ssl->ssl_shutdown) {
- ssl_log(transport, "Shutting down SSL connection...");
+ ssl_log(transport, PN_LEVEL_TRACE, "Shutting down SSL connection...");
ssn_save(transport, ssl);
ssl->ssl_shutdown = true;
BIO_ssl_shutdown( ssl->bio_ssl );
@@ -1018,7 +1013,7 @@ static ssize_t process_input_ssl( pn_transport_t *transport, unsigned int layer,
transport->present_layers |= LAYER_SSL;
}
- ssl_log( transport, "process_input_ssl( data size=%d )",available );
+ ssl_log( transport, PN_LEVEL_TRACE, "process_input_ssl( data size=%d )",available );
ssize_t consumed = 0;
bool work_pending;
@@ -1038,12 +1033,12 @@ static ssize_t process_input_ssl( pn_transport_t *transport, unsigned int layer,
consumed += written;
ssl->read_blocked = false;
work_pending = (available > 0);
- ssl_log( transport, "Wrote %d bytes to BIO Layer, %" PN_ZU " left over", written, available );
+ ssl_log( transport, PN_LEVEL_TRACE, "Wrote %d bytes to BIO Layer, %" PN_ZU " left over", written, available );
}
} else if (shutdown_input) {
// lower layer (caller) has closed. Close the WRITE side of the BIO. This will cause
// an EOF to be passed to SSL once all pending inbound data has been consumed.
- ssl_log( transport, "Lower layer closed - shutting down BIO write side");
+ ssl_log( transport, PN_LEVEL_TRACE, "Lower layer closed - shutting down BIO write side");
(void)BIO_shutdown_wr( ssl->bio_net_io );
shutdown_input = false;
}
@@ -1053,7 +1048,7 @@ static ssize_t process_input_ssl( pn_transport_t *transport, unsigned int layer,
if (!ssl->ssl_closed && ssl->in_count < ssl->in_size) {
int read = BIO_read( ssl->bio_ssl, &ssl->inbuf[ssl->in_count], ssl->in_size - ssl->in_count );
if (read > 0) {
- ssl_log( transport, "Read %d bytes from SSL socket for app", read );
+ ssl_log( transport, PN_LEVEL_TRACE, "Read %d bytes from SSL socket for app", read );
ssl_log_clear_data(transport, &ssl->inbuf[ssl->in_count], read );
ssl->in_count += read;
work_pending = true;
@@ -1063,7 +1058,7 @@ static ssize_t process_input_ssl( pn_transport_t *transport, unsigned int layer,
switch (reason) {
case SSL_ERROR_ZERO_RETURN:
// SSL closed cleanly
- ssl_log(transport, "SSL connection has closed");
+ ssl_log(transport, PN_LEVEL_TRACE, "SSL connection has closed");
start_ssl_shutdown(transport); // KAG: not sure - this may not be necessary
ssl->ssl_closed = true;
break;
@@ -1074,11 +1069,11 @@ static ssize_t process_input_ssl( pn_transport_t *transport, unsigned int layer,
} else {
if (BIO_should_write( ssl->bio_ssl )) {
ssl->write_blocked = true;
- ssl_log(transport, "Detected write-blocked");
+ ssl_log(transport, PN_LEVEL_TRACE, "Detected write-blocked");
}
if (BIO_should_read( ssl->bio_ssl )) {
ssl->read_blocked = true;
- ssl_log(transport, "Detected read-blocked");
+ ssl_log(transport, PN_LEVEL_TRACE, "Detected read-blocked");
}
}
}
@@ -1094,9 +1089,9 @@ static ssize_t process_input_ssl( pn_transport_t *transport, unsigned int layer,
if (ssl->in_count)
memmove( ssl->inbuf, ssl->inbuf + consumed, ssl->in_count );
work_pending = true;
- ssl_log( transport, "Application consumed %d bytes from peer", (int) consumed );
+ ssl_log( transport, PN_LEVEL_TRACE, "Application consumed %d bytes from peer", (int) consumed );
} else if (consumed < 0) {
- ssl_log(transport, "Application layer closed its input, error=%d (discarding %d bytes)",
+ ssl_log(transport, PN_LEVEL_TRACE, "Application layer closed its input, error=%d (discarding %d bytes)",
(int) consumed, (int)ssl->in_count);
ssl->in_count = 0; // discard any pending input
ssl->app_input_closed = consumed;
@@ -1126,7 +1121,7 @@ static ssize_t process_input_ssl( pn_transport_t *transport, unsigned int layer,
// the application _must_ have enough data to process. If
// this is an oversized frame, the app _must_ handle it
// by returning an error code to SSL.
- pn_transport_log(transport, "Error: application unable to consume input.");
+ ssl_log(transport, PN_LEVEL_ERROR, "Error: application unable to consume input.");
}
}
}
@@ -1156,7 +1151,7 @@ static ssize_t process_input_ssl( pn_transport_t *transport, unsigned int layer,
transport->io_layers[layer] = &ssl_input_closed_layer;
}
}
- ssl_log(transport, "process_input_ssl() returning %d", (int) consumed);
+ ssl_log(transport, PN_LEVEL_TRACE, "process_input_ssl() returning %d", (int) consumed);
return consumed;
}
@@ -1185,10 +1180,10 @@ static ssize_t process_output_ssl( pn_transport_t *transport, unsigned int layer
if (app_bytes > 0) {
ssl->out_count += app_bytes;
work_pending = true;
- ssl_log(transport, "Gathered %" PN_ZI " bytes from app to send to peer", app_bytes);
+ ssl_log(transport, PN_LEVEL_TRACE, "Gathered %" PN_ZI " bytes from app to send to peer", app_bytes);
} else {
if (app_bytes < 0) {
- ssl_log(transport, "Application layer closed its output, error=%d (%d bytes pending send)",
+ ssl_log(transport, PN_LEVEL_TRACE, "Application layer closed its output, error=%d (%d bytes pending send)",
(int) app_bytes, (int) ssl->out_count);
ssl->app_output_closed = app_bytes;
}
@@ -1205,14 +1200,14 @@ static ssize_t process_output_ssl( pn_transport_t *transport, unsigned int layer
data += wrote;
ssl->out_count -= wrote;
work_pending = true;
- ssl_log( transport, "Wrote %d bytes from app to socket", wrote );
+ ssl_log( transport, PN_LEVEL_TRACE, "Wrote %d bytes from app to socket", wrote );
} else {
if (!BIO_should_retry(ssl->bio_ssl)) {
int reason = SSL_get_error( ssl->ssl, wrote );
switch (reason) {
case SSL_ERROR_ZERO_RETURN:
// SSL closed cleanly
- ssl_log(transport, "SSL connection has closed");
+ ssl_log(transport, PN_LEVEL_TRACE, "SSL connection has closed");
start_ssl_shutdown(transport); // KAG: not sure - this may not be necessary
ssl->out_count = 0; // can no longer write to socket, so erase app output data
ssl->ssl_closed = true;
@@ -1224,11 +1219,11 @@ static ssize_t process_output_ssl( pn_transport_t *transport, unsigned int layer
} else {
if (BIO_should_read( ssl->bio_ssl )) {
ssl->read_blocked = true;
- ssl_log(transport, "Detected read-blocked");
+ ssl_log(transport, PN_LEVEL_TRACE, "Detected read-blocked");
}
if (BIO_should_write( ssl->bio_ssl )) {
ssl->write_blocked = true;
- ssl_log(transport, "Detected write-blocked");
+ ssl_log(transport, PN_LEVEL_TRACE, "Detected write-blocked");
}
}
}
@@ -1254,7 +1249,7 @@ static ssize_t process_output_ssl( pn_transport_t *transport, unsigned int layer
written += available;
ssl->write_blocked = false;
work_pending = work_pending || max_len > 0;
- ssl_log(transport, "Read %d bytes from BIO Layer", available );
+ ssl_log(transport, PN_LEVEL_TRACE, "Read %d bytes from BIO Layer", available );
}
}
@@ -1279,7 +1274,7 @@ static ssize_t process_output_ssl( pn_transport_t *transport, unsigned int layer
transport->io_layers[layer] = &ssl_output_closed_layer;
}
}
- ssl_log(transport, "process_output_ssl() returning %d", (int) written);
+ ssl_log(transport, PN_LEVEL_TRACE, "process_output_ssl() returning %d", (int) written);
return written;
}
@@ -1290,8 +1285,8 @@ static int init_ssl_socket(pn_transport_t* transport, pni_ssl_t *ssl, pn_ssl_dom
ssl->ssl = SSL_new(domain->ctx);
if (!ssl->ssl) {
- pn_transport_logf(transport, "SSL socket setup failure." );
- ssl_log_flush(transport);
+ ssl_log(transport, PN_LEVEL_ERROR, "SSL socket setup failure." );
+ ssl_log_flush(transport, PN_LEVEL_ERROR);
return -1;
}
@@ -1310,14 +1305,14 @@ static int init_ssl_socket(pn_transport_t* transport, pni_ssl_t *ssl, pn_ssl_dom
// now layer a BIO over the SSL socket
ssl->bio_ssl = BIO_new(BIO_f_ssl());
if (!ssl->bio_ssl) {
- pn_transport_log(transport, "BIO setup failure." );
+ ssl_log(transport, PN_LEVEL_ERROR, "BIO setup failure." );
return -1;
}
(void)BIO_set_ssl(ssl->bio_ssl, ssl->ssl, BIO_NOCLOSE);
// create the "lower" BIO "pipe", and attach it below the SSL layer
if (!BIO_new_bio_pair(&ssl->bio_ssl_io, 0, &ssl->bio_net_io, 0)) {
- pn_transport_log(transport, "BIO setup failure." );
+ ssl_log(transport, PN_LEVEL_ERROR, "BIO setup failure." );
return -1;
}
SSL_set_bio(ssl->ssl, ssl->bio_ssl_io, ssl->bio_ssl_io);
@@ -1325,11 +1320,11 @@ static int init_ssl_socket(pn_transport_t* transport, pni_ssl_t *ssl, pn_ssl_dom
if (ssl->mode == PN_SSL_MODE_SERVER) {
SSL_set_accept_state(ssl->ssl);
BIO_set_ssl_mode(ssl->bio_ssl, 0); // server mode
- ssl_log( transport, "Server SSL socket created." );
+ ssl_log( transport, PN_LEVEL_TRACE, "Server SSL socket created." );
} else { // client mode
SSL_set_connect_state(ssl->ssl);
BIO_set_ssl_mode(ssl->bio_ssl, 1); // client mode
- ssl_log( transport, "Client SSL socket created." );
+ ssl_log( transport, PN_LEVEL_TRACE, "Client SSL socket created." );
}
ssl->subject = NULL;
ssl->peer_certificate = NULL;
diff --git a/c/src/ssl/schannel.c b/c/src/ssl/schannel.c
index daaf439..5938857 100644
--- a/c/src/ssl/schannel.c
+++ b/c/src/ssl/schannel.c
@@ -34,7 +34,7 @@
#include "core/autodetect.h"
#include "core/engine-internal.h"
-#include "core/log_private.h"
+#include "core/logger_private.h"
#include "core/util.h"
#include "platform/platform.h"
@@ -59,8 +59,8 @@
* This file contains an SChannel-based implemention of the SSL/TLS API for Windows platforms.
*/
+static void ssl_log(pn_transport_t *transport, pn_log_level_t sev, const char *fmt, ...);
static void ssl_log_error(const char *fmt, ...);
-static void ssl_log(pn_transport_t *transport, const char *fmt, ...);
static void ssl_log_error_status(HRESULT status, const char *fmt, ...);
static HCERTSTORE open_cert_db(const char *store_name, const char *passwd, int *error);
@@ -363,23 +363,29 @@ static bool grow_inbuf2(pn_transport_t *ssl, size_t minimum_size);
static HRESULT verify_peer(pni_ssl_t *ssl, HCERTSTORE root_store, const char *server_name, bool tracing);
// @todo: used to avoid littering the code with calls to printf...
-static void ssl_log_error(const char *fmt, ...)
+static void ssl_vlog(pn_transport_t *transport, pn_log_level_t sev, const char *fmt, va_list ap)
+{
+ pn_logger_t *logger = transport ? &transport->logger : pn_default_logger();
+ if (PN_SHOULD_LOG(logger, PN_SUBSYSTEM_SSL, sev)) {
+ pni_logger_vlogf(logger, PN_SUBSYSTEM_SSL, sev, fmt, ap);
+ }
+}
+
+static void ssl_log(pn_transport_t *transport, pn_log_level_t sev, const char *fmt, ...)
{
va_list ap;
va_start(ap, fmt);
- pn_vlogf(fmt, ap);
+ ssl_vlog(transport, sev, fmt, ap);
va_end(ap);
}
// @todo: used to avoid littering the code with calls to printf...
-static void ssl_log(pn_transport_t *transport, const char *fmt, ...)
+static void ssl_log_error(const char *fmt, ...)
{
- if (PN_TRACE_DRV & transport->trace) {
- va_list ap;
- va_start(ap, fmt);
- pn_vlogf(fmt, ap);
- va_end(ap);
- }
+ va_list ap;
+ va_start(ap, fmt);
+ ssl_vlog(NULL, PN_LEVEL_ERROR, fmt, ap);
+ va_end(ap);
}
static void ssl_log_error_status(HRESULT status, const char *fmt, ...)
@@ -389,22 +395,20 @@ static void ssl_log_error_status(HRESULT status, const char *fmt, ...)
if (fmt) {
va_start(ap, fmt);
- pn_vlogf(fmt, ap);
+ ssl_vlog(NULL, PN_LEVEL_ERROR, fmt, ap);
va_end(ap);
}
if (FormatMessage(FORMAT_MESSAGE_MAX_WIDTH_MASK | FORMAT_MESSAGE_FROM_SYSTEM,
0, status, 0, buf, sizeof(buf), 0))
- ssl_log_error(" : %s", buf);
+ ssl_log_error("%s", buf);
else
- pn_logf("pn internal Windows error: %x for %x", GetLastError(), status);
+ ssl_log_error("Internal Windows error: %x for %x", GetLastError(), status);
}
static void ssl_log_clear_data(pn_transport_t *transport, const char *data, size_t len)
{
- if (PN_TRACE_RAW & transport->trace) {
- pn_log_data("SSL decrypted data", data, len);
- }
+ PN_LOG_DATA(&transport->logger, PN_SUBSYSTEM_SSL, PN_LEVEL_RAW, "decrypted data", data, len );
}
static size_t _pni_min(size_t a, size_t b)
@@ -791,7 +795,7 @@ void pn_ssl_free( pn_transport_t *transport)
{
pni_ssl_t *ssl = transport->ssl;
if (!ssl) return;
- ssl_log( transport, "SSL socket freed." );
+ ssl_log( transport, PN_LEVEL_DEBUG, "SSL socket freed." );
// clean up Windows per TLS session data before releasing the domain count
csguard g(&ssl->cred->cslock);
if (SecIsValidHandle(&ssl->ctxt_handle))
@@ -985,7 +989,7 @@ static void ssl_encrypt(pn_transport_t *transport, char *app_data, size_t count)
ssl->sc_out_count = buffs[0].cbBuffer + buffs[1].cbBuffer + buffs[2].cbBuffer;
ssl->network_outp = ssl->sc_outbuf;
ssl->network_out_pending = ssl->sc_out_count;
- ssl_log(transport, "ssl_encrypt %d network bytes", ssl->network_out_pending);
+ ssl_log(transport, PN_LEVEL_TRACE, "ssl_encrypt %d network bytes", ssl->network_out_pending);
}
// Returns true if decryption succeeded (even for empty content)
@@ -1088,7 +1092,7 @@ static void client_handshake_init(pn_transport_t *transport)
ssl->network_out_pending = ssl->sc_out_count;
// the token is the whole quantity to send
ssl->network_outp = ssl->sc_outbuf;
- ssl_log(transport, "Sending client hello %d bytes", ssl->network_out_pending);
+ ssl_log(transport, PN_LEVEL_TRACE, "Sending client hello %d bytes", ssl->network_out_pending);
} else {
ssl_log_error_status(status, "InitializeSecurityContext failed");
ssl_failed(transport, 0);
@@ -1144,7 +1148,7 @@ static void client_handshake( pn_transport_t* transport) {
case SEC_E_INCOMPLETE_MESSAGE:
// Not enough - get more data from the server then try again.
// Leave input buffers untouched.
- ssl_log(transport, "client handshake: incomplete record");
+ ssl_log(transport, PN_LEVEL_TRACE, "client handshake: incomplete record");
ssl->sc_in_incomplete = true;
return;
@@ -1154,7 +1158,7 @@ static void client_handshake( pn_transport_t* transport) {
// the token is the whole quantity to send
ssl->network_out_pending = ssl->sc_out_count;
ssl->network_outp = ssl->sc_outbuf;
- ssl_log(transport, "client handshake token %d bytes", ssl->network_out_pending);
+ ssl_log(transport, PN_LEVEL_DEBUG, "client handshake token %d bytes", ssl->network_out_pending);
break;
case SEC_E_OK:
@@ -1165,7 +1169,7 @@ static void client_handshake( pn_transport_t* transport) {
// the token is the whole quantity to send
ssl->network_out_pending = ssl->sc_out_count;
ssl->network_outp = ssl->sc_outbuf;
- ssl_log(transport, "client shutdown token %d bytes", ssl->network_out_pending);
+ ssl_log(transport, PN_LEVEL_DEBUG, "client shutdown token %d bytes", ssl->network_out_pending);
} else {
ssl->state = SSL_CLOSED;
}
@@ -1181,7 +1185,7 @@ static void client_handshake( pn_transport_t* transport) {
break;
}
if (ssl->verify_mode == PN_SSL_VERIFY_PEER || ssl->verify_mode == PN_SSL_VERIFY_PEER_NAME) {
- bool tracing = PN_TRACE_DRV & transport->trace;
+ bool tracing = PN_SHOULD_LOG(&transport->logger, PN_SUBSYSTEM_SSL, PN_LEVEL_TRACE);
HRESULT ec = verify_peer(ssl, ssl->cred->trust_store, ssl->peer_hostname, tracing);
if (ec) {
if (ssl->peer_hostname)
@@ -1214,13 +1218,13 @@ static void client_handshake( pn_transport_t* transport) {
ssl->state = RUNNING;
ssl->max_data_size = max - ssl->sc_sizes.cbHeader - ssl->sc_sizes.cbTrailer;
- ssl_log(transport, "client handshake successful %d max record size", max);
+ ssl_log(transport, PN_LEVEL_DEBUG, "client handshake successful %d max record size", max);
break;
case SEC_I_CONTEXT_EXPIRED:
// ended before we got going
default:
- ssl_log(transport, "client handshake failed %d", (int) status);
+ ssl_log(transport, PN_LEVEL_ERROR, "client handshake failed %d", (int) status);
ssl_failed(transport, 0);
break;
}
@@ -1245,7 +1249,7 @@ static void server_handshake(pn_transport_t* transport)
// waiting for more bytes. Help out here.
pni_protocol_type_t type = pni_sniff_header(ssl->sc_inbuf, ssl->sc_in_count);
if (type == PNI_PROTOCOL_INSUFFICIENT) {
- ssl_log(transport, "server handshake: incomplete record");
+ ssl_log(transport, PN_LEVEL_DEBUG, "server handshake: incomplete record");
ssl->sc_in_incomplete = true;
return;
} else {
@@ -1307,7 +1311,7 @@ static void server_handshake(pn_transport_t* transport)
case SEC_E_INCOMPLETE_MESSAGE:
// Not enough - get more data from the client then try again.
// Leave input buffers untouched.
- ssl_log(transport, "server handshake: incomplete record");
+ ssl_log(transport, PN_LEVEL_DEBUG, "server handshake: incomplete record");
ssl->sc_in_incomplete = true;
return;
@@ -1323,7 +1327,7 @@ static void server_handshake(pn_transport_t* transport)
// the token is the whole quantity to send
ssl->network_out_pending = ssl->sc_out_count;
ssl->network_outp = ssl->sc_outbuf;
- ssl_log(transport, "server shutdown token %d bytes", ssl->network_out_pending);
+ ssl_log(transport, PN_LEVEL_DEBUG, "server shutdown token %d bytes", ssl->network_out_pending);
} else {
ssl->state = SSL_CLOSED;
}
@@ -1337,7 +1341,7 @@ static void server_handshake(pn_transport_t* transport)
// Handshake complete.
if (ssl->verify_mode == PN_SSL_VERIFY_PEER || ssl->verify_mode == PN_SSL_VERIFY_PEER_NAME) {
- bool tracing = PN_TRACE_DRV & transport->trace;
+ bool tracing = PN_SHOULD_LOG(&transport->logger, PN_SUBSYSTEM_SSL, PN_LEVEL_TRACE);
HRESULT ec = verify_peer(ssl, ssl->cred->trust_store, NULL, tracing);
if (ec) {
ssl_log_error_status(ec, "certificate verification failed");
@@ -1363,18 +1367,18 @@ static void server_handshake(pn_transport_t* transport)
ssl->state = RUNNING;
ssl->max_data_size = max - ssl->sc_sizes.cbHeader - ssl->sc_sizes.cbTrailer;
- ssl_log(transport, "server handshake successful %d max record size", max);
+ ssl_log(transport, PN_LEVEL_DEBUG, "server handshake successful %d max record size", max);
break;
case SEC_E_ALGORITHM_MISMATCH:
- ssl_log(transport, "server handshake failed: no common algorithm");
+ ssl_log(transport, PN_LEVEL_WARNING, "server handshake failed: no common algorithm");
ssl_failed(transport, "server handshake failed: no common algorithm");
break;
case SEC_I_CONTEXT_EXPIRED:
// ended before we got going
default:
- ssl_log(transport, "server handshake failed %d", (int) status);
+ ssl_log(transport, PN_LEVEL_ERROR, "server handshake failed %d", (int) status);
ssl_failed(transport, 0);
break;
}
@@ -1386,7 +1390,7 @@ static void server_handshake(pn_transport_t* transport)
// the token is the whole quantity to send
ssl->network_out_pending = ssl->sc_out_count;
ssl->network_outp = ssl->sc_outbuf;
- ssl_log(transport, "server handshake token %d bytes", ssl->network_out_pending);
+ ssl_log(transport, PN_LEVEL_DEBUG, "server handshake token %d bytes", ssl->network_out_pending);
}
if (token_buffs[1].BufferType == SECBUFFER_EXTRA && token_buffs[1].cbBuffer > 0 &&
@@ -1420,7 +1424,7 @@ static bool grow_inbuf2(pn_transport_t *transport, size_t minimum_size) {
if (max_frame != 0) {
if (old_capacity >= max_frame) {
// already big enough
- ssl_log(transport, "Application expecting %d bytes (> negotiated maximum frame)", new_capacity);
+ ssl_log(transport, PN_LEVEL_ERROR, "Application expecting %d bytes (> negotiated maximum frame)", new_capacity);
ssl_failed(transport, "TLS: transport maximum frame size error");
return false;
}
@@ -1429,7 +1433,7 @@ static bool grow_inbuf2(pn_transport_t *transport, size_t minimum_size) {
size_t extra_bytes = new_capacity - pn_buffer_size(ssl->inbuf2);
int err = pn_buffer_ensure(ssl->inbuf2, extra_bytes);
if (err) {
- ssl_log(transport, "TLS memory allocation failed for %d bytes", max_frame);
+ ssl_log(transport, PN_LEVEL_ERROR, "TLS memory allocation failed for %d bytes", max_frame);
ssl_failed(transport, "TLS memory allocation failed");
return false;
}
@@ -1449,7 +1453,7 @@ static void start_ssl_shutdown(pn_transport_t *transport)
if (ssl->queued_shutdown)
return;
ssl->queued_shutdown = true;
- ssl_log(transport, "Shutting down SSL connection...");
+ ssl_log(transport, PN_LEVEL_INFO, "Shutting down SSL connection...");
DWORD shutdown = SCHANNEL_SHUTDOWN;
SecBuffer shutBuff;
@@ -1615,7 +1619,7 @@ static void read_closed(pn_transport_t *transport, unsigned int layer, ssize_t e
static ssize_t process_input_ssl(pn_transport_t *transport, unsigned int layer, const char *input_data, size_t available)
{
pni_ssl_t *ssl = transport->ssl;
- ssl_log( transport, "process_input_ssl( data size=%d )",available );
+ ssl_log( transport, PN_LEVEL_TRACE, "process_input_ssl( data size=%d )",available );
ssize_t consumed = 0;
ssize_t forwarded = 0;
bool new_app_input;
@@ -1692,7 +1696,7 @@ static ssize_t process_input_ssl(pn_transport_t *transport, unsigned int layer,
rewind_sc_inbuf(ssl);
}
}
- ssl_log(transport, "Next decryption, %d left over", available);
+ ssl_log(transport, PN_LEVEL_TRACE, "Next decryption, %d left over", available);
}
}
@@ -1714,7 +1718,7 @@ static ssize_t process_input_ssl(pn_transport_t *transport, unsigned int layer,
forwarded += count;
// advance() can increase app_inbytes.size if double buffered
app_inbytes_advance(transport, count);
- ssl_log(transport, "Application consumed %d bytes from peer", (int) count);
+ ssl_log(transport, PN_LEVEL_TRACE, "Application consumed %d bytes from peer", (int) count);
} else if (count == 0) {
size_t old_size = ssl->app_inbytes.size;
app_inbytes_advance(transport, 0);
@@ -1723,13 +1727,13 @@ static ssize_t process_input_ssl(pn_transport_t *transport, unsigned int layer,
}
} else {
// count < 0
- ssl_log(transport, "Application layer closed its input, error=%d (discarding %d bytes)",
+ ssl_log(transport, PN_LEVEL_WARNING, "Application layer closed its input, error=%d (discarding %d bytes)",
(int) count, (int)ssl->app_inbytes.size);
app_inbytes_advance(transport, ssl->app_inbytes.size); // discard
read_closed(transport, layer, count);
}
} else {
- ssl_log(transport, "Input closed discard %d bytes",
+ ssl_log(transport, PN_LEVEL_WARNING, "Input closed discard %d bytes",
(int)ssl->app_inbytes.size);
app_inbytes_advance(transport, ssl->app_inbytes.size); // discard
}
@@ -1749,7 +1753,7 @@ static ssize_t process_input_ssl(pn_transport_t *transport, unsigned int layer,
}
}
}
- ssl_log(transport, "process_input_ssl() returning %d, forwarded %d", (int) consumed, (int) forwarded);
+ ssl_log(transport, PN_LEVEL_TRACE, "process_input_ssl() returning %d, forwarded %d", (int) consumed, (int) forwarded);
return consumed;
}
@@ -1757,7 +1761,7 @@ static ssize_t process_output_ssl( pn_transport_t *transport, unsigned int layer
{
pni_ssl_t *ssl = transport->ssl;
if (!ssl) return PN_EOS;
- ssl_log( transport, "process_output_ssl( max_len=%d )",max_len );
+ ssl_log( transport, PN_LEVEL_TRACE, "process_output_ssl( max_len=%d )",max_len );
ssize_t written = 0;
ssize_t total_app_bytes = 0;
@@ -1796,17 +1800,17 @@ static ssize_t process_output_ssl( pn_transport_t *transport, unsigned int layer
if (app_bytes > 0) {
app_outp += app_bytes;
remaining -= app_bytes;
- ssl_log( transport, "Gathered %d bytes from app to send to peer", app_bytes );
+ ssl_log( transport, PN_LEVEL_TRACE, "Gathered %d bytes from app to send to peer", app_bytes );
} else {
if (app_bytes < 0) {
- ssl_log(transport, "Application layer closed its output, error=%d (%d bytes pending send)",
+ ssl_log(transport, PN_LEVEL_WARNING, "Application layer closed its output, error=%d (%d bytes pending send)",
(int) app_bytes, (int) ssl->network_out_pending);
ssl->app_output_closed = app_bytes;
if (ssl->app_input_closed)
ssl->state = SHUTTING_DOWN;
} else if (total_app_bytes == 0 && ssl->app_input_closed) {
// We've drained all the App layer can provide
- ssl_log(transport, "Application layer blocked on input, closing");
+ ssl_log(transport, PN_LEVEL_WARNING, "Application layer blocked on input, closing");
ssl->state = SHUTTING_DOWN;
ssl->app_output_closed = PN_ERR;
}
@@ -1842,7 +1846,7 @@ static ssize_t process_output_ssl( pn_transport_t *transport, unsigned int layer
transport->io_layers[layer] = &ssl_output_closed_layer;
}
}
- ssl_log(transport, "process_output_ssl() returning %d", (int) written);
+ ssl_log(transport, PN_LEVEL_TRACE, "process_output_ssl() returning %d", (int) written);
return written;
}
diff --git a/c/tests/fuzz/fuzz-connection-driver.c b/c/tests/fuzz/fuzz-connection-driver.c
index 70ef650..62b4172 100644
--- a/c/tests/fuzz/fuzz-connection-driver.c
+++ b/c/tests/fuzz/fuzz-connection-driver.c
@@ -26,7 +26,7 @@
#include "proton/connection_driver.h"
#include "proton/engine.h"
-#include "proton/log.h"
+#include "proton/logger.h"
#include "proton/message.h"
#include "libFuzzingEngine.h"
@@ -56,7 +56,7 @@ const bool VERBOSE = false;
const bool ERRORS = false;
// I could not get rid of the error messages on stderr in any other way
-void devnull(pn_transport_t *transport, const char *message) {}
+void devnull(intptr_t context, pn_log_subsystem_t sub, pn_log_level_t sev, const char *message) {}
int LLVMFuzzerTestOneInput(const uint8_t *Data, size_t Size) {
if (VERBOSE)
@@ -71,10 +71,7 @@ int LLVMFuzzerTestOneInput(const uint8_t *Data, size_t Size) {
exit(1);
}
- pn_log_enable(false);
- pn_log_logger(NULL);
- pn_transport_trace(driver.transport, PN_TRACE_OFF);
- pn_transport_set_tracer(driver.transport, devnull);
+ pn_logger_set_log_sink(pn_default_logger(), devnull, 0);
uint8_t *data = (uint8_t *)Data;
size_t size = Size;
diff --git a/python/setup.py.in b/python/setup.py.in
index 8d0445c..a12ec73 100644
--- a/python/setup.py.in
+++ b/python/setup.py.in
@@ -133,7 +133,14 @@ class Configure(build_ext):
macros += [('PROTON_DECLARE_STATIC', None)]
if self.compiler_type=='msvc':
- sources.append(os.path.join(proton_src, 'compiler' , 'msvc', 'snprintf.c'))
+ sources += [
+ os.path.join(proton_src, 'compiler', 'msvc', 'snprintf.c'),
+ os.path.join(proton_src, 'compiler', 'msvc', 'start.c')
+ ]
+ elif self.compiler_type=='unix':
+ sources += [
+ os.path.join(proton_src, 'compiler' , 'gcc', 'start.c')
+ ]
# Check whether openssl is installed by poking
# pkg-config for a minimum version 0. If it's installed, it should
diff --git a/python/tests/proton_tests/transport.py b/python/tests/proton_tests/transport.py
index 78b7f0e..0c0481f 100644
--- a/python/tests/proton_tests/transport.py
+++ b/python/tests/proton_tests/transport.py
@@ -392,4 +392,4 @@ class LogTest(Test):
t.log("one")
t.log("two")
t.log("three")
- assert messages == [(t, "one"), (t, "two"), (t, "three")], messages
+ assert messages == [(t, "TRACE: one"), (t, "TRACE: two"), (t, "TRACE: three")], messages
---------------------------------------------------------------------
To unsubscribe, e-mail: commits-unsubscribe@qpid.apache.org
For additional commands, e-mail: commits-help@qpid.apache.org