From 3699c3b966dec936bbbe9ec610d48feb41e0880a Mon Sep 17 00:00:00 2001 From: "Anand V. Avati" Date: Tue, 21 Apr 2009 21:34:38 +0530 Subject: cleanup of logs in socket and ib-verbs transports Signed-off-by: Anand V. Avati --- transport/ib-verbs/src/ib-verbs.c | 54 +++++++++++++++---------------- transport/socket/src/name.c | 8 ++--- transport/socket/src/socket.c | 67 ++++++++++++++++++++------------------- 3 files changed, 65 insertions(+), 64 deletions(-) (limited to 'transport') diff --git a/transport/ib-verbs/src/ib-verbs.c b/transport/ib-verbs/src/ib-verbs.c index dc5ae1137..7b1095c92 100644 --- a/transport/ib-verbs/src/ib-verbs.c +++ b/transport/ib-verbs/src/ib-verbs.c @@ -208,7 +208,7 @@ __ib_verbs_disconnect (transport_t *this) fcntl (priv->sock, F_SETFL, O_NONBLOCK); if (shutdown (priv->sock, SHUT_RDWR) != 0) { gf_log ("transport/ib-verbs", - GF_LOG_ERROR, + GF_LOG_DEBUG, "shutdown () - error: %s", strerror (errno)); ret = -errno; @@ -266,7 +266,7 @@ __ib_verbs_ioq_churn_entry (ib_verbs_peer_t *peer, ib_verbs_ioq_t *entry) len = iov_length ((const struct iovec *)&entry->vector, entry->count); if (len >= (options->send_size + 2048)) { - gf_log ("transport/ib-verbs", GF_LOG_CRITICAL, + gf_log ("transport/ib-verbs", GF_LOG_ERROR, "increase value of option 'transport.ib-verbs." "work-request-send-size' (given=> %"PRId64") " "to send bigger (%d) messages", @@ -283,7 +283,7 @@ __ib_verbs_ioq_churn_entry (ib_verbs_peer_t *peer, ib_verbs_ioq_t *entry) __ib_verbs_ioq_entry_free (entry); ret = len; } else { - gf_log ("transport/ib-verbs", GF_LOG_ERROR, + gf_log ("transport/ib-verbs", GF_LOG_DEBUG, "ibv_post_send failed with ret = %d", ret); ib_verbs_put_post (&device->sendq, post); __ib_verbs_disconnect (peer->trans); @@ -387,7 +387,7 @@ ib_verbs_writev (transport_t *this, pthread_mutex_lock (&priv->write_mutex); { if (!priv->connected) { - gf_log (this->xl->name, GF_LOG_ERROR, + gf_log (this->xl->name, GF_LOG_DEBUG, "ib-verbs is not connected to post a " "send request"); ret = -1; @@ -503,7 +503,7 @@ ib_verbs_receive (transport_t *this, char **hdr_p, size_t *hdrlen_p, header = (ib_verbs_header_t *)copy_from; if (strcmp (header->colonO, ":O")) { - gf_log ("transport/ib-verbs", GF_LOG_ERROR, + gf_log ("transport/ib-verbs", GF_LOG_DEBUG, "%s: corrupt header received", this->xl->name); ret = -1; goto err; @@ -513,7 +513,7 @@ ib_verbs_receive (transport_t *this, char **hdr_p, size_t *hdrlen_p, size2 = ntoh32 (header->size2); if (data_len != (size1 + size2 + sizeof (*header))) { - gf_log ("transport/ib-verbs", GF_LOG_ERROR, + gf_log ("transport/ib-verbs", GF_LOG_DEBUG, "%s: sizeof data read from transport is not equal " "to the size specified in the header", this->xl->name); @@ -989,7 +989,7 @@ __tcp_rwv (transport_t *this, struct iovec *vector, int count, if (errno == EINTR) continue; - gf_log (this->xl->name, GF_LOG_ERROR, + gf_log (this->xl->name, GF_LOG_DEBUG, "%s failed (%s)", write ? "writev" : "readv", strerror (errno)); if (write && !priv->connected && @@ -1149,7 +1149,7 @@ ib_verbs_recv_completion_proc (void *data) if ((ret = peer->trans->xl->notify (peer->trans->xl, GF_EVENT_POLLIN, peer->trans, NULL)) == -1) { gf_log ("transport/ib-verbs", - GF_LOG_ERROR, + GF_LOG_DEBUG, "pollin notification to %s " "failed, disconnecting " "transport", @@ -1235,7 +1235,7 @@ ib_verbs_send_completion_proc (void *data) if (peer) { int quota_ret = ib_verbs_quota_put (peer); if (quota_ret < 0) { - gf_log ("ib-verbs", GF_LOG_WARNING, + gf_log ("ib-verbs", GF_LOG_DEBUG, "failed to send message"); } @@ -1308,12 +1308,12 @@ ib_verbs_options_init (transport_t *this) break; default: if (temp) - gf_log ("transport/ib-verbs", GF_LOG_ERROR, + gf_log ("transport/ib-verbs", GF_LOG_WARNING, "%s: unrecognized MTU value '%s', defaulting " "to '2048'", this->xl->name, data_to_str (temp)); else - gf_log ("transport/ib-verbs", GF_LOG_DEBUG, + gf_log ("transport/ib-verbs", GF_LOG_TRACE, "%s: defaulting MTU to '2048'", this->xl->name); options->mtu = IBV_MTU_2048; @@ -1384,7 +1384,7 @@ ib_verbs_get_device (transport_t *this, trav->send_chan = ibv_create_comp_channel (trav->context); if (!trav->send_chan) { - gf_log ("transport/ib-verbs", GF_LOG_CRITICAL, + gf_log ("transport/ib-verbs", GF_LOG_ERROR, "%s: could not create send completion channel", device_name); /* TODO: cleanup current mess */ @@ -1393,7 +1393,7 @@ ib_verbs_get_device (transport_t *this, trav->recv_chan = ibv_create_comp_channel (trav->context); if (!trav->recv_chan) { - gf_log ("transport/ib-verbs", GF_LOG_CRITICAL, + gf_log ("transport/ib-verbs", GF_LOG_ERROR, "could not create recv completion channel"); /* TODO: cleanup current mess */ return NULL; @@ -1410,7 +1410,7 @@ ib_verbs_get_device (transport_t *this, trav->pd = ibv_alloc_pd (trav->context); if (!trav->pd) { - gf_log ("transport/ib-verbs", GF_LOG_CRITICAL, + gf_log ("transport/ib-verbs", GF_LOG_ERROR, "%s: could not allocate protection domain", this->xl->name); return NULL; @@ -1425,7 +1425,7 @@ ib_verbs_get_device (transport_t *this, trav->srq = ibv_create_srq (trav->pd, &attr); if (!trav->srq) { - gf_log ("transport/ib-verbs", GF_LOG_CRITICAL, + gf_log ("transport/ib-verbs", GF_LOG_ERROR, "%s: could not create SRQ", this->xl->name); return NULL; @@ -1647,7 +1647,7 @@ ib_verbs_handshake_pollin (transport_t *this) } if (ret > 0) { - gf_log (this->xl->name, GF_LOG_DEBUG, + gf_log (this->xl->name, GF_LOG_TRACE, "partial header read on NB socket. continue later"); goto unlock; } @@ -1683,7 +1683,7 @@ ib_verbs_handshake_pollin (transport_t *this) if (send_buf_size < priv->peer.send_size) priv->peer.send_size = send_buf_size; - gf_log ("transport/ib-verbs", GF_LOG_DEBUG, + gf_log ("transport/ib-verbs", GF_LOG_TRACE, "%s: transacted recv_size=%d " "send_size=%d", this->xl->name, priv->peer.recv_size, @@ -1715,7 +1715,7 @@ ib_verbs_handshake_pollin (transport_t *this) } if (ret > 0) { - gf_log (this->xl->name, GF_LOG_DEBUG, + gf_log (this->xl->name, GF_LOG_TRACE, "partial header read on NB " "socket. continue later"); goto unlock; @@ -1729,7 +1729,7 @@ ib_verbs_handshake_pollin (transport_t *this) case IB_VERBS_HANDSHAKE_RECEIVED_ACK: if (strncmp (buf, "DONE", 4)) { gf_log ("transport/ib-verbs", - GF_LOG_ERROR, + GF_LOG_DEBUG, "%s: handshake-3 did not " "return 'DONE' (%s)", this->xl->name, buf); @@ -1799,7 +1799,7 @@ ib_verbs_handshake_pollout (transport_t *this) } if (ret > 0) { - gf_log (this->xl->name, GF_LOG_DEBUG, + gf_log (this->xl->name, GF_LOG_TRACE, "partial header read on NB socket. continue later"); goto unlock; } @@ -1826,7 +1826,7 @@ ib_verbs_handshake_pollout (transport_t *this) } if (ret > 0) { - gf_log (this->xl->name, GF_LOG_DEBUG, + gf_log (this->xl->name, GF_LOG_TRACE, "partial header read on NB " "socket. continue later"); goto unlock; @@ -2052,7 +2052,7 @@ ib_verbs_connect (struct transport *this) ret = ibverbs_client_get_remote_sockaddr (this, (struct sockaddr *)&sockaddr, &sockaddr_len); if (ret != 0) { - gf_log (this->xl->name, GF_LOG_ERROR, + gf_log (this->xl->name, GF_LOG_DEBUG, "cannot get remote address to connect"); return ret; } @@ -2074,7 +2074,7 @@ ib_verbs_connect (struct transport *this) goto unlock; } - gf_log (this->xl->name, GF_LOG_DEBUG, + gf_log (this->xl->name, GF_LOG_TRACE, "socket fd = %d", priv->sock); memcpy (&this->peerinfo.sockaddr, &sockaddr, sockaddr_len); @@ -2234,7 +2234,7 @@ ib_verbs_listen (transport_t *this) (struct sockaddr *)&sockaddr, &sockaddr_len); if (ret != 0) { - gf_log (this->xl->name, GF_LOG_ERROR, + gf_log (this->xl->name, GF_LOG_DEBUG, "cannot find network address of server to bind to"); goto err; } @@ -2270,14 +2270,14 @@ ib_verbs_listen (transport_t *this) (struct sockaddr *)&sockaddr, sockaddr_len) != 0) { ret = -1; - gf_log ("ib-verbs/server", GF_LOG_CRITICAL, + gf_log ("ib-verbs/server", GF_LOG_ERROR, "init: failed to bind to socket for %s (%s)", this->myinfo.identifier, strerror (errno)); goto err; } if (listen (priv->sock, 10) != 0) { - gf_log ("ib-verbs/server", GF_LOG_CRITICAL, + gf_log ("ib-verbs/server", GF_LOG_ERROR, "init: listen () failed on socket for %s (%s)", this->myinfo.identifier, strerror (errno)); ret = -1; @@ -2329,7 +2329,7 @@ fini (struct transport *this) pthread_mutex_destroy (&priv->read_mutex); /* pthread_cond_destroy (&priv->recv_cond); */ - gf_log (this->xl->name, GF_LOG_CRITICAL, + gf_log (this->xl->name, GF_LOG_TRACE, "called fini on transport: %p", this); free (priv); diff --git a/transport/socket/src/name.c b/transport/socket/src/name.c index 831b9fd43..bb41c1cd0 100644 --- a/transport/socket/src/name.c +++ b/transport/socket/src/name.c @@ -93,7 +93,7 @@ af_unix_client_bind (transport_t *this, if (path_data) { char *path = data_to_str (path_data); if (!path || strlen (path) > UNIX_PATH_MAX) { - gf_log (this->xl->name, GF_LOG_DEBUG, + gf_log (this->xl->name, GF_LOG_TRACE, "bind-path not specfied for unix socket, " "letting connect to assign default value"); goto err; @@ -109,7 +109,7 @@ af_unix_client_bind (transport_t *this, goto err; } } else { - gf_log (this->xl->name, GF_LOG_DEBUG, + gf_log (this->xl->name, GF_LOG_TRACE, "bind-path not specfied for unix socket, " "letting connect to assign default value"); } @@ -213,7 +213,7 @@ af_inet_client_get_remote_sockaddr (transport_t *this, remote_port_data = dict_get (options, "remote-port"); if (remote_port_data == NULL) { - gf_log (this->xl->name, GF_LOG_DEBUG, + gf_log (this->xl->name, GF_LOG_TRACE, "option remote-port missing in volume %s. Defaulting to %d", this->xl->name, GF_DEFAULT_SOCKET_LISTEN_PORT); @@ -286,7 +286,7 @@ af_unix_client_get_remote_sockaddr (transport_t *this, goto err; } - gf_log (this->xl->name, GF_LOG_DEBUG, + gf_log (this->xl->name, GF_LOG_TRACE, "using connect-path %s", connect_path); sockaddr_un = (struct sockaddr_un *)sockaddr; strcpy (sockaddr_un->sun_path, connect_path); diff --git a/transport/socket/src/socket.c b/transport/socket/src/socket.c index b37c49090..fa6b10ec7 100644 --- a/transport/socket/src/socket.c +++ b/transport/socket/src/socket.c @@ -97,7 +97,7 @@ __socket_rwv (transport_t *this, struct iovec *vector, int count, if (errno == EINTR) continue; - gf_log (this->xl->name, GF_LOG_ERROR, + gf_log (this->xl->name, GF_LOG_DEBUG, "%s failed (%s)", write ? "writev" : "readv", strerror (errno)); opcount = -1; @@ -170,7 +170,7 @@ __socket_disconnect (transport_t *this) if (priv->sock != -1) { ret = shutdown (priv->sock, SHUT_RDWR); priv->connected = -1; - gf_log (this->xl->name, GF_LOG_DEBUG, + gf_log (this->xl->name, GF_LOG_TRACE, "shutdown() returned %d. set connection state to -1", ret); } @@ -457,7 +457,7 @@ __socket_proto_validate_header (transport_t *this, size_t size2 = 0; if (strcmp (header->colonO, ":O")) { - gf_log (this->xl->name, GF_LOG_ERROR, + gf_log (this->xl->name, GF_LOG_DEBUG, "socket header signature does not match :O (%x.%x.%x)", header->colonO[0], header->colonO[1], header->colonO[2]); @@ -465,7 +465,7 @@ __socket_proto_validate_header (transport_t *this, } if (header->version != 42) { - gf_log (this->xl->name, GF_LOG_ERROR, + gf_log (this->xl->name, GF_LOG_DEBUG, "socket header version does not match 42 != %d", header->version); return -1; @@ -475,14 +475,14 @@ __socket_proto_validate_header (transport_t *this, size2 = ntoh32 (header->size2); if (size1 <= 0 || size1 > 1048576) { - gf_log (this->xl->name, GF_LOG_ERROR, + gf_log (this->xl->name, GF_LOG_DEBUG, "socket header has incorrect size1=%"GF_PRI_SIZET, size1); return -1; } if (size2 > (131072)) { - gf_log (this->xl->name, GF_LOG_ERROR, + gf_log (this->xl->name, GF_LOG_DEBUG, "socket header has incorrect size2=%"GF_PRI_SIZET, size2); return -1; @@ -518,7 +518,7 @@ __socket_proto_state_machine (transport_t *this) while (priv->incoming.state != SOCKET_PROTO_STATE_COMPLETE) { /* debug check against infinite loops */ if (previous_state == priv->incoming.state) { - gf_log (this->xl->name, GF_LOG_ERROR, + gf_log (this->xl->name, GF_LOG_DEBUG, "state did not change! (%d) breaking", previous_state); ret = -1; @@ -555,7 +555,7 @@ __socket_proto_state_machine (transport_t *this) } if (ret == -1) { - gf_log (this->xl->name, GF_LOG_ERRNO (errno), + gf_log (this->xl->name, GF_LOG_DEBUG, "read (%s) in state %d (%s)", strerror (errno), SOCKET_PROTO_STATE_HEADER_COMING, @@ -564,7 +564,7 @@ __socket_proto_state_machine (transport_t *this) } if (ret > 0) { - gf_log (this->xl->name, GF_LOG_DEBUG, + gf_log (this->xl->name, GF_LOG_TRACE, "partial header read on NB socket."); goto unlock; } @@ -641,7 +641,7 @@ __socket_proto_state_machine (transport_t *this) } if (ret == -1) { - gf_log (this->xl->name, GF_LOG_ERROR, + gf_log (this->xl->name, GF_LOG_DEBUG, "read (%s) in state %d (%s)", strerror (errno), SOCKET_PROTO_STATE_DATA_COMING, @@ -650,7 +650,7 @@ __socket_proto_state_machine (transport_t *this) } if (ret > 0) { - gf_log (this->xl->name, GF_LOG_DEBUG, + gf_log (this->xl->name, GF_LOG_TRACE, "partial data read on NB socket"); goto unlock; } @@ -669,7 +669,7 @@ __socket_proto_state_machine (transport_t *this) break; default: - gf_log (this->xl->name, GF_LOG_ERROR, + gf_log (this->xl->name, GF_LOG_DEBUG, "undefined state reached: %d", priv->incoming.state); goto unlock; @@ -719,10 +719,10 @@ socket_event_poll_in (transport_t *this) int socket_connect_finish (transport_t *this) { - int ret = -1; + int ret = -1; socket_private_t *priv = NULL; - int event = -1; - char notify_xlator = 0; + int event = -1; + char notify_xlator = 0; priv = this->private; @@ -759,7 +759,7 @@ socket_connect_finish (transport_t *this) SA (&this->myinfo.sockaddr), &this->myinfo.sockaddr_len); if (ret == -1) { - gf_log (this->xl->name, GF_LOG_ERROR, + gf_log (this->xl->name, GF_LOG_DEBUG, "getsockname on (%d) failed (%s)", priv->sock, strerror (errno)); __socket_disconnect (this); @@ -854,7 +854,7 @@ socket_server_event_handler (int fd, int idx, void *data, ret = __socket_nonblock (new_sock); if (ret == -1) { - gf_log (this->xl->name, GF_LOG_ERROR, + gf_log (this->xl->name, GF_LOG_DEBUG, "NBIO on %d failed (%s)", new_sock, strerror (errno)); close (new_sock); @@ -877,7 +877,7 @@ socket_server_event_handler (int fd, int idx, void *data, SA (&new_trans->myinfo.sockaddr), &new_trans->myinfo.sockaddr_len); if (ret == -1) { - gf_log (this->xl->name, GF_LOG_ERROR, + gf_log (this->xl->name, GF_LOG_DEBUG, "getsockname on %d failed (%s)", new_sock, strerror (errno)); close (new_sock); @@ -949,7 +949,7 @@ socket_connect (transport_t *this) ctx = this->xl->ctx; if (!priv) { - gf_log (this->xl->name, GF_LOG_ERROR, + gf_log (this->xl->name, GF_LOG_DEBUG, "connect() called on uninitialized transport"); goto err; } @@ -977,7 +977,7 @@ socket_connect (transport_t *this) pthread_mutex_lock (&priv->lock); { if (priv->sock != -1) { - gf_log (this->xl->name, GF_LOG_DEBUG, + gf_log (this->xl->name, GF_LOG_TRACE, "connect() -- already connected"); goto unlock; } @@ -1072,7 +1072,7 @@ socket_listen (transport_t *this) pthread_mutex_unlock (&priv->lock); if (sock != -1) { - gf_log (this->xl->name, GF_LOG_ERROR, + gf_log (this->xl->name, GF_LOG_DEBUG, "alreading listening"); return ret; } @@ -1087,7 +1087,7 @@ socket_listen (transport_t *this) pthread_mutex_lock (&priv->lock); { if (priv->sock != -1) { - gf_log (this->xl->name, GF_LOG_ERROR, + gf_log (this->xl->name, GF_LOG_DEBUG, "already listening"); goto unlock; } @@ -1145,7 +1145,7 @@ socket_listen (transport_t *this) this, 1, 0); if (priv->idx == -1) { - gf_log (this->xl->name, GF_LOG_ERROR, + gf_log (this->xl->name, GF_LOG_DEBUG, "could not register socket %d with events", priv->sock); ret = -1; @@ -1173,13 +1173,13 @@ socket_receive (transport_t *this, char **hdr_p, size_t *hdrlen_p, pthread_mutex_lock (&priv->lock); { if (priv->connected != 1) { - gf_log (this->xl->name, GF_LOG_ERROR, + gf_log (this->xl->name, GF_LOG_DEBUG, "socket not connected to receive"); goto unlock; } if (!hdr_p || !hdrlen_p || !iobuf_p) { - gf_log (this->xl->name, GF_LOG_ERROR, + gf_log (this->xl->name, GF_LOG_DEBUG, "bad parameters %p %p %p", hdr_p, hdrlen_p, iobuf_p); goto unlock; @@ -1223,7 +1223,7 @@ socket_submit (transport_t *this, char *buf, int len, { if (priv->connected != 1) { if (!priv->submit_log && !priv->connect_finish_log) { - gf_log (this->xl->name, GF_LOG_ERROR, + gf_log (this->xl->name, GF_LOG_DEBUG, "not connected (priv->connected = %d)", priv->connected); priv->submit_log = 1; @@ -1276,9 +1276,11 @@ int socket_init (transport_t *this) { socket_private_t *priv = NULL; + gf_boolean_t tmp_bool = 0; + char *nb_connect = NULL; if (this->private) { - gf_log (this->xl->name, GF_LOG_ERROR, + gf_log (this->xl->name, GF_LOG_DEBUG, "double init attempted"); return -1; } @@ -1300,8 +1302,7 @@ socket_init (transport_t *this) INIT_LIST_HEAD (&priv->ioq); if (dict_get (this->xl->options, "non-blocking-io")) { - gf_boolean_t tmp_bool = 0; - char *nb_connect = data_to_str (dict_get (this->xl->options, + nb_connect = data_to_str (dict_get (this->xl->options, "non-blocking-io")); if (gf_string2boolean (nb_connect, &tmp_bool) == -1) { @@ -1328,7 +1329,8 @@ void fini (transport_t *this) { socket_private_t *priv = this->private; - gf_log (this->xl->name, GF_LOG_DEBUG, + + gf_log (this->xl->name, GF_LOG_TRACE, "transport %p destroyed", this); pthread_mutex_destroy (&priv->lock); @@ -1343,9 +1345,8 @@ init (transport_t *this) ret = socket_init (this); - if (ret == -1) - { - gf_log (this->xl->name, GF_LOG_ERROR, "socket_init() failed"); + if (ret == -1) { + gf_log (this->xl->name, GF_LOG_DEBUG, "socket_init() failed"); } return ret; -- cgit