paulmataruso/osmo-mgw
1
0
Fork 0
mirror of https://gitea.osmocom.org/cellular-infrastructure/osmo-mgw.git synced 2025-11-03 13:33:29 +00:00
Code Issues Packages Projects Releases Wiki Activity

gtphub: review log levels, add level arg to LOG().

Browse Source 
For maintenance, it is convenient to have the log level explicit at each
log statement.

Tweak some log levels / message formatting while at it.

Sponsored-by: On-Waves ehi
This commit is contained in:
Neels Hofmeyr
2015-11-16 14:35:13 +01:00
parent 390e910125
commit 063a802d46
1 changed files with 133 additions and 141 deletions
Download Patch File Download Diff File Expand all files Collapse all files

186
openbsc/src/gprs/gtphub.c
View File

@@ -40,17 +40,13 @@
#include <osmocom/core/socket.h> #include <osmocom/core/socket.h>
#define GTPHUB_DEBUG 1
static const int GTPH_GC_TICK_SECONDS = 1; static const int GTPH_GC_TICK_SECONDS = 1;
void *osmo_gtphub_ctx; void *osmo_gtphub_ctx;
#define LOGERR(fmt, args...) \ /* Convenience makro, note: only within this C file. */
LOGP(DGTPHUB, LOGL_ERROR, fmt, ##args) #define LOG(level, fmt, args...) \
LOGP(DGTPHUB, level, fmt, ##args)
#define LOG(fmt, args...) \
LOGP(DGTPHUB, LOGL_NOTICE, fmt, ##args)
#define ZERO_STRUCT(struct_pointer) memset(struct_pointer, '\0', sizeof(*(struct_pointer))) #define ZERO_STRUCT(struct_pointer) memset(struct_pointer, '\0', sizeof(*(struct_pointer)))
@@ -126,7 +122,7 @@ int gsn_addr_from_str(struct gsn_addr *gsna, const char *numeric_addr_str)
int rc = inet_pton(af, numeric_addr_str, gsna->buf); int rc = inet_pton(af, numeric_addr_str, gsna->buf);
if (rc != 1) { if (rc != 1) {
LOGERR("Cannot resolve numeric address: '%s'\n", numeric_addr_str); LOG(LOGL_ERROR, "Cannot resolve numeric address: '%s'\n", numeric_addr_str);
return -1; return -1;
} }
return 0; return 0;
@@ -156,7 +152,7 @@ const char *gsn_addr_to_strb(const struct gsn_addr *gsna,
const char *r = inet_ntop(af, gsna->buf, strbuf, strbuf_len); const char *r = inet_ntop(af, gsna->buf, strbuf, strbuf_len);
if (!r) { if (!r) {
LOGERR("Cannot convert gsn_addr to string: %s: len=%d, buf=%s\n", LOG(LOGL_ERROR, "Cannot convert gsn_addr to string: %s: len=%d, buf=%s\n",
strerror(errno), strerror(errno),
(int)gsna->len, (int)gsna->len,
osmo_hexdump(gsna->buf, sizeof(gsna->buf))); osmo_hexdump(gsna->buf, sizeof(gsna->buf)));
@@ -204,7 +200,7 @@ static int gsn_addr_put(const struct gsn_addr *gsna, struct gtp_packet_desc *p,
struct gtpie_tlv *ie = &p->ie[ie_idx]->tlv; struct gtpie_tlv *ie = &p->ie[ie_idx]->tlv;
int ie_l = ntoh16(ie->l); int ie_l = ntoh16(ie->l);
if (ie_l != gsna->len) { if (ie_l != gsna->len) {
LOG("Not implemented: replace an IE address of different size:" LOG(LOGL_ERROR, "Not implemented: replace an IE address of different size:"
" replace %d with %d\n", (int)ie_l, (int)gsna->len); " replace %d with %d\n", (int)ie_l, (int)gsna->len);
return -1; return -1;
} }
@@ -225,7 +221,7 @@ void validate_gtp0_header(struct gtp_packet_desc *p)
OSMO_ASSERT(p->version == 0); OSMO_ASSERT(p->version == 0);
if (p->data_len < GTP0_HEADER_SIZE) { if (p->data_len < GTP0_HEADER_SIZE) {
LOGERR("GTP0 packet too short: %d\n", p->data_len); LOG(LOGL_ERROR, "GTP0 packet too short: %d\n", p->data_len);
p->rc = GTP_RC_TOOSHORT; p->rc = GTP_RC_TOOSHORT;
return; return;
} }
@@ -242,7 +238,7 @@ void validate_gtp0_header(struct gtp_packet_desc *p)
/* Check packet length field versus length of packet */ /* Check packet length field versus length of packet */
if (p->data_len != (ntoh16(pheader->length) + GTP0_HEADER_SIZE)) { if (p->data_len != (ntoh16(pheader->length) + GTP0_HEADER_SIZE)) {
LOGERR("GTP packet length field (%d + %d) does not match" LOG(LOGL_ERROR, "GTP packet length field (%d + %d) does not match"
" actual length (%d)\n", " actual length (%d)\n",
GTP0_HEADER_SIZE, (int)ntoh16(pheader->length), GTP0_HEADER_SIZE, (int)ntoh16(pheader->length),
p->data_len); p->data_len);
@@ -250,7 +246,7 @@ void validate_gtp0_header(struct gtp_packet_desc *p)
return; return;
} }
LOG("GTP v0 TID = %" PRIu64 "\n", pheader->tid); LOG(LOGL_DEBUG, "GTP v0 TID = %" PRIu64 "\n", pheader->tid);
p->header_len = GTP0_HEADER_SIZE; p->header_len = GTP0_HEADER_SIZE;
p->rc = GTP_RC_PDU_C; p->rc = GTP_RC_PDU_C;
} }
@@ -268,7 +264,7 @@ void validate_gtp1_header(struct gtp_packet_desc *p)
if ((p->data_len < GTP1_HEADER_SIZE_LONG) if ((p->data_len < GTP1_HEADER_SIZE_LONG)
&& (p->data_len != GTP1_HEADER_SIZE_SHORT)){ && (p->data_len != GTP1_HEADER_SIZE_SHORT)){
LOGERR("GTP packet too short: %d\n", p->data_len); LOG(LOGL_ERROR, "GTP packet too short: %d\n", p->data_len);
p->rc = GTP_RC_TOOSHORT; p->rc = GTP_RC_TOOSHORT;
return; return;
} }
@@ -277,18 +273,18 @@ void validate_gtp1_header(struct gtp_packet_desc *p)
p->header_tei = ntoh32(pheader->tei); p->header_tei = ntoh32(pheader->tei);
p->seq = ntoh16(pheader->seq); p->seq = ntoh16(pheader->seq);
LOG("|GTPv1\n"); LOG(LOGL_DEBUG, "GTPv1\n"
LOG("| type = %" PRIu8 " 0x%02" PRIx8 "\n", "| type = %" PRIu8 " 0x%02" PRIx8 "\n"
p->type, p->type); "| length = %" PRIu16 " 0x%04" PRIx16 "\n"
LOG("| length = %" PRIu16 " 0x%04" PRIx16 "\n", "| TEI = %" PRIu32 " 0x%08" PRIx32 "\n"
ntoh16(pheader->length), ntoh16(pheader->length)); "| seq = %" PRIu16 " 0x%04" PRIx16 "\n"
LOG("| TEI = %" PRIu32 " 0x%08" PRIx32 "\n", "| npdu = %" PRIu8 " 0x%02" PRIx8 "\n"
p->header_tei, p->header_tei); "| next = %" PRIu8 " 0x%02" PRIx8 "\n",
LOG("| seq = %" PRIu16 " 0x%04" PRIx16 "\n", p->type, p->type,
p->seq, p->seq); ntoh16(pheader->length), ntoh16(pheader->length),
LOG("| npdu = %" PRIu8 " 0x%02" PRIx8 "\n", p->header_tei, p->header_tei,
pheader->npdu, pheader->npdu); p->seq, p->seq,
LOG("| next = %" PRIu8 " 0x%02" PRIx8 "\n", pheader->npdu, pheader->npdu,
pheader->next, pheader->next); pheader->next, pheader->next);
if (p->data_len <= GTP1_HEADER_SIZE_LONG) { if (p->data_len <= GTP1_HEADER_SIZE_LONG) {
@@ -299,7 +295,7 @@ void validate_gtp1_header(struct gtp_packet_desc *p)
/* Check packet length field versus length of packet */ /* Check packet length field versus length of packet */
if (p->data_len != (ntoh16(pheader->length) + GTP1_HEADER_SIZE_SHORT)) { if (p->data_len != (ntoh16(pheader->length) + GTP1_HEADER_SIZE_SHORT)) {
LOGERR("GTP packet length field (%d + %d) does not match" LOG(LOGL_ERROR, "GTP packet length field (%d + %d) does not match"
" actual length (%d)\n", " actual length (%d)\n",
GTP1_HEADER_SIZE_SHORT, (int)ntoh16(pheader->length), GTP1_HEADER_SIZE_SHORT, (int)ntoh16(pheader->length),
p->data_len); p->data_len);
@@ -320,7 +316,7 @@ void validate_gtp_header(struct gtp_packet_desc *p)
/* Need at least 1 byte in order to check version */ /* Need at least 1 byte in order to check version */
if (p->data_len < 1) { if (p->data_len < 1) {
LOGERR("Discarding packet - too small: %d\n", p->data_len); LOG(LOGL_ERROR, "Discarding packet - too small: %d\n", p->data_len);
p->rc = GTP_RC_TOOSHORT; p->rc = GTP_RC_TOOSHORT;
return; return;
} }
@@ -335,7 +331,7 @@ void validate_gtp_header(struct gtp_packet_desc *p)
validate_gtp1_header(p); validate_gtp1_header(p);
break; break;
default: default:
LOGERR("Unsupported GTP version: %d\n", p->version); LOG(LOGL_ERROR, "Unsupported GTP version: %d\n", p->version);
p->rc = GTP_RC_UNSUPPORTED_VERSION; p->rc = GTP_RC_UNSUPPORTED_VERSION;
break; break;
} }
@@ -410,7 +406,7 @@ static int get_ie_apn_str(union gtpie_member *ie[], const char **apn_str)
return 0; return 0;
if (len < 2) { if (len < 2) {
LOGERR("APN IE: invalid length: %d\n", LOG(LOGL_ERROR, "APN IE: invalid length: %d\n",
(int)len); (int)len);
return -1; return -1;
} }
@@ -421,7 +417,7 @@ static int get_ie_apn_str(union gtpie_member *ie[], const char **apn_str)
*apn_str = gprs_apn_to_str(apn_buf, (uint8_t*)apn_buf, len); *apn_str = gprs_apn_to_str(apn_buf, (uint8_t*)apn_buf, len);
if (!(*apn_str)) { if (!(*apn_str)) {
LOGERR("APN IE: present but cannot be decoded: %s\n", LOG(LOGL_ERROR, "APN IE: present but cannot be decoded: %s\n",
osmo_hexdump((uint8_t*)apn_buf, len)); osmo_hexdump((uint8_t*)apn_buf, len));
return -1; return -1;
} }
@@ -444,11 +440,11 @@ static void gtp_decode(const uint8_t *data, int data_len,
validate_gtp_header(res); validate_gtp_header(res);
if (res->rc <= 0) { if (res->rc <= 0) {
LOGERR("INVALID: dropping GTP packet.\n"); LOG(LOGL_ERROR, "INVALID: dropping GTP packet.\n");
return; return;
} }
LOG("Valid GTP header (v%d)\n", res->version); LOG(LOGL_DEBUG, "Valid GTP header (v%d)\n", res->version);
if (from_plane_idx == GTPH_PLANE_USER) { if (from_plane_idx == GTPH_PLANE_USER) {
res->rc = GTP_RC_PDU_U; res->rc = GTP_RC_PDU_U;
@@ -456,7 +452,7 @@ static void gtp_decode(const uint8_t *data, int data_len,
} }
if (res->rc != GTP_RC_PDU_C) { if (res->rc != GTP_RC_PDU_C) {
LOG("no IEs in this GTP packet\n"); LOG(LOGL_DEBUG, "no IEs in this GTP packet\n");
return; return;
} }
@@ -464,38 +460,39 @@ static void gtp_decode(const uint8_t *data, int data_len,
(void*)(data + res->header_len), (void*)(data + res->header_len),
res->data_len - res->header_len) != 0) { res->data_len - res->header_len) != 0) {
res->rc = GTP_RC_INVALID_IE; res->rc = GTP_RC_INVALID_IE;
LOGERR("INVALID: cannot decode IEs. Dropping GTP packet.\n"); LOG(LOGL_ERROR, "INVALID: cannot decode IEs. Dropping GTP packet.\n");
return; return;
} }
#if GTPHUB_DEBUG #if 1
/* TODO if (<loglevel is debug>) { ... (waiting for a commit from jerlbeck) */
int i; int i;
for (i = 0; i < 10; i++) { for (i = 0; i < 10; i++) {
const char *imsi; const char *imsi;
if (get_ie_imsi_str(res->ie, i, &imsi) < 1) if (get_ie_imsi_str(res->ie, i, &imsi) < 1)
break; break;
LOG("| IMSI %s\n", imsi); LOG(LOGL_DEBUG, "| IMSI %s\n", imsi);
} }
for (i = 0; i < 10; i++) { for (i = 0; i < 10; i++) {
uint8_t nsapi; uint8_t nsapi;
if (!get_ie_nsapi(res->ie, i, &nsapi)) if (!get_ie_nsapi(res->ie, i, &nsapi))
break; break;
LOG("| NSAPI %d\n", (int)nsapi); LOG(LOGL_DEBUG, "| NSAPI %d\n", (int)nsapi);
} }
for (i = 0; i < 2; i++) { for (i = 0; i < 2; i++) {
struct gsn_addr addr; struct gsn_addr addr;
if (gsn_addr_get(&addr, res, i) == 0) if (gsn_addr_get(&addr, res, i) == 0)
LOG("| addr %s\n", gsn_addr_to_str(&addr)); LOG(LOGL_DEBUG, "| addr %s\n", gsn_addr_to_str(&addr));
} }
for (i = 0; i < 10; i++) { for (i = 0; i < 10; i++) {
uint32_t tei; uint32_t tei;
if (gtpie_gettv4(res->ie, GTPIE_TEI_DI, i, &tei) != 0) if (gtpie_gettv4(res->ie, GTPIE_TEI_DI, i, &tei) != 0)
break; break;
LOG("| TEI DI (USER) %" PRIu32 " 0x%08" PRIx32 "\n", LOG(LOGL_DEBUG, "| TEI DI (USER) %" PRIu32 " 0x%08" PRIx32 "\n",
tei, tei); tei, tei);
} }
@@ -503,7 +500,7 @@ static void gtp_decode(const uint8_t *data, int data_len,
uint32_t tei; uint32_t tei;
if (gtpie_gettv4(res->ie, GTPIE_TEI_C, i, &tei) != 0) if (gtpie_gettv4(res->ie, GTPIE_TEI_C, i, &tei) != 0)
break; break;
LOG("| TEI (CTRL) %" PRIu32 " 0x%08" PRIx32 "\n", LOG(LOGL_DEBUG, "| TEI (CTRL) %" PRIu32 " 0x%08" PRIx32 "\n",
tei, tei); tei, tei);
} }
#endif #endif
@@ -729,11 +726,11 @@ static int gtphub_sock_init(struct osmo_fd *ofd,
int ofd_id) int ofd_id)
{ {
if (!addr->addr_str) { if (!addr->addr_str) {
LOGERR("Cannot bind: empty address.\n"); LOG(LOGL_FATAL, "Cannot bind: empty address.\n");
return -1; return -1;
} }
if (!addr->port) { if (!addr->port) {
LOGERR("Cannot bind: zero port not permitted.\n"); LOG(LOGL_FATAL, "Cannot bind: zero port not permitted.\n");
return -1; return -1;
} }
@@ -748,7 +745,7 @@ static int gtphub_sock_init(struct osmo_fd *ofd,
addr->addr_str, addr->port, addr->addr_str, addr->port,
OSMO_SOCK_F_BIND); OSMO_SOCK_F_BIND);
if (rc < 1) { if (rc < 1) {
LOGERR("Cannot bind to %s port %d (rc %d)\n", LOG(LOGL_FATAL, "Cannot bind to %s port %d (rc %d)\n",
addr->addr_str, (int)addr->port, rc); addr->addr_str, (int)addr->port, rc);
return -1; return -1;
} }
@@ -792,21 +789,16 @@ static int gtphub_read(const struct osmo_fd *from,
* is not truncated. Then maybe reduce buf's size. */ * is not truncated. Then maybe reduce buf's size. */
if (received <= 0) { if (received <= 0) {
if (errno != EAGAIN) LOG((errno == EAGAIN? LOGL_DEBUG : LOGL_ERROR),
LOGERR("error: %s\n", strerror(errno)); "error: %s\n", strerror(errno));
return 0; return 0;
} }
if (from_addr) { if (from_addr) {
LOG("from %s\n", osmo_sockaddr_to_str(from_addr)); LOG(LOGL_DEBUG, "from %s\n", osmo_sockaddr_to_str(from_addr));
} }
if (received <= 0) { LOG(LOGL_DEBUG, "Received %d\n", (int)received); //%s\n", (int)received, osmo_hexdump(buf, received));
LOGERR("error: %s\n", strerror(errno));
return 0;
}
LOG("Received %d\n%s\n", (int)received, osmo_hexdump(buf, received));
return received; return received;
} }
@@ -908,7 +900,7 @@ static void gtphub_mapping_del_cb(struct expiring_item *expi)
/* Just for log */ /* Just for log */
struct gtphub_peer_port *from = nrm->origin; struct gtphub_peer_port *from = nrm->origin;
OSMO_ASSERT(from); OSMO_ASSERT(from);
LOG("expired: %d: nr mapping from %s: %d->%d\n", LOG(LOGL_DEBUG, "expired: %d: nr mapping from %s: %d->%d\n",
(int)nrm->expiry_entry.expiry, (int)nrm->expiry_entry.expiry,
gtphub_port_str(from), gtphub_port_str(from),
(int)nrm->orig, (int)nrm->repl); (int)nrm->orig, (int)nrm->repl);
@@ -933,7 +925,7 @@ static struct nr_mapping *gtphub_mapping_have(struct nr_map *map,
nrm->origin = from; nrm->origin = from;
nr_map_add(map, nrm, now); nr_map_add(map, nrm, now);
gtphub_port_ref_count_inc(from); gtphub_port_ref_count_inc(from);
LOG("peer %s: MAP %d --> %d\n", LOG(LOGL_DEBUG, "peer %s: sequence map %d --> %d\n",
gtphub_port_str(from), gtphub_port_str(from),
(int)(nrm->orig), (int)(nrm->repl)); (int)(nrm->orig), (int)(nrm->repl));
} else { } else {
@@ -954,7 +946,7 @@ static uint32_t gtphub_tei_mapping_have(struct gtphub *hub,
{ {
struct nr_mapping *nrm = gtphub_mapping_have(&hub->tei_map[plane_idx], struct nr_mapping *nrm = gtphub_mapping_have(&hub->tei_map[plane_idx],
from, orig_tei, now); from, orig_tei, now);
LOG("New %s TEI: (from %s, TEI %d) <-- TEI %d\n", LOG(LOGL_DEBUG, "New %s TEI: (from %s, TEI %d) <-- TEI %d\n",
gtphub_plane_idx_names[plane_idx], gtphub_plane_idx_names[plane_idx],
gtphub_port_str(from), gtphub_port_str(from),
(int)orig_tei, (int)nrm->repl); (int)orig_tei, (int)nrm->repl);
@@ -986,7 +978,7 @@ static struct gtphub_peer_port *gtphub_unmap_seq(struct gtp_packet_desc *p,
p->seq); p->seq);
if (!nrm) if (!nrm)
return NULL; return NULL;
LOG("peer %p: UNMAP %d <-- %d\n", nrm->origin, (int)(nrm->orig), (int)(nrm->repl)); LOG(LOGL_DEBUG, "peer %p: sequence unmap %d <-- %d\n", nrm->origin, (int)(nrm->orig), (int)(nrm->repl));
set_seq(p, nrm->orig); set_seq(p, nrm->orig);
return nrm->origin; return nrm->origin;
} }
@@ -1098,7 +1090,7 @@ static int gtphub_unmap_header_tei(struct gtphub_peer_port **to_port_p,
struct nr_mapping *nrm; struct nr_mapping *nrm;
nrm = nr_map_get_inv(&hub->tei_map[p->plane_idx], tei); nrm = nr_map_get_inv(&hub->tei_map[p->plane_idx], tei);
if (!nrm) { if (!nrm) {
LOGERR("Received unknown TEI %" PRIu32 " from %s\n", LOG(LOGL_ERROR, "Received unknown TEI %" PRIu32 " from %s\n",
tei, gtphub_port_str(from_port)); tei, gtphub_port_str(from_port));
return -1; return -1;
} }
@@ -1107,7 +1099,7 @@ static int gtphub_unmap_header_tei(struct gtphub_peer_port **to_port_p,
uint32_t unmapped_tei = nrm->orig; uint32_t unmapped_tei = nrm->orig;
set_tei(p, unmapped_tei); set_tei(p, unmapped_tei);
LOG("Unmapped TEI coming from %s: %d -> %d (to %s)\n", LOG(LOGL_DEBUG, "Unmapped TEI coming from %s: %d -> %d (to %s)\n",
gtphub_port_str(from_port), tei, unmapped_tei, gtphub_port_str(from_port), tei, unmapped_tei,
gtphub_port_str2(to_port)); gtphub_port_str2(to_port));
@@ -1156,11 +1148,11 @@ static int gtphub_handle_pdp_ctx_ies(struct gtphub *hub,
/* Fetch GSN Address and TEI from IEs */ /* Fetch GSN Address and TEI from IEs */
rc = gsn_addr_get(&addr_from_ie, p, plane_idx); rc = gsn_addr_get(&addr_from_ie, p, plane_idx);
if (rc) { if (rc) {
LOGERR("Cannot read %s GSN Address IE\n", LOG(LOGL_ERROR, "Cannot read %s GSN Address IE\n",
gtphub_plane_idx_names[plane_idx]); gtphub_plane_idx_names[plane_idx]);
return -1; return -1;
} }
LOG("Read %s GSN addr %s (%d)\n", LOG(LOGL_DEBUG, "Read %s GSN addr %s (%d)\n",
gtphub_plane_idx_names[plane_idx], gtphub_plane_idx_names[plane_idx],
gsn_addr_to_str(&addr_from_ie), gsn_addr_to_str(&addr_from_ie),
addr_from_ie.len); addr_from_ie.len);
@@ -1168,7 +1160,7 @@ static int gtphub_handle_pdp_ctx_ies(struct gtphub *hub,
ie_idx = gtpie_getie(p->ie, ie_type[plane_idx], 0); ie_idx = gtpie_getie(p->ie, ie_type[plane_idx], 0);
if (ie_idx < 0) { if (ie_idx < 0) {
if (ie_mandatory) { if (ie_mandatory) {
LOGERR("Create PDP Context message invalid:" LOG(LOGL_ERROR, "Create PDP Context message invalid:"
" missing IE %d\n", (int)ie_type[plane_idx]); " missing IE %d\n", (int)ie_type[plane_idx]);
return -1; return -1;
} }
@@ -1197,7 +1189,7 @@ static int gtphub_handle_pdp_ctx_ies(struct gtphub *hub,
/* Replace the GSN address to reflect gtphub. */ /* Replace the GSN address to reflect gtphub. */
rc = gsn_addr_put(&to_bind[plane_idx].local_addr, p, plane_idx); rc = gsn_addr_put(&to_bind[plane_idx].local_addr, p, plane_idx);
if (rc) { if (rc) {
LOGERR("Cannot write %s GSN Address IE\n", LOG(LOGL_ERROR, "Cannot write %s GSN Address IE\n",
gtphub_plane_idx_names[plane_idx]); gtphub_plane_idx_names[plane_idx]);
return -1; return -1;
} }
@@ -1215,18 +1207,18 @@ static int gtphub_write(const struct osmo_fd *to,
(struct sockaddr*)&to_addr->a, to_addr->l); (struct sockaddr*)&to_addr->a, to_addr->l);
if (to_addr) { if (to_addr) {
LOG("to %s\n", osmo_sockaddr_to_str(to_addr)); LOG(LOGL_DEBUG, "to %s\n", osmo_sockaddr_to_str(to_addr));
} }
if (sent == -1) { if (sent == -1) {
LOGERR("error: %s\n", strerror(errno)); LOG(LOGL_ERROR, "error: %s\n", strerror(errno));
return -EINVAL; return -EINVAL;
} }
if (sent != buf_len) if (sent != buf_len)
LOGERR("sent(%d) != data_len(%d)\n", (int)sent, (int)buf_len); LOG(LOGL_ERROR, "sent(%d) != data_len(%d)\n", (int)sent, (int)buf_len);
else else
LOG("Sent %d\n%s\n", (int)sent, osmo_hexdump(buf, sent)); LOG(LOGL_DEBUG, "Sent %d\n%s\n", (int)sent, osmo_hexdump(buf, sent));
return 0; return 0;
} }
@@ -1235,7 +1227,7 @@ static int from_ggsns_read_cb(struct osmo_fd *from_ggsns_ofd, unsigned int what)
{ {
unsigned int plane_idx = from_ggsns_ofd->priv_nr; unsigned int plane_idx = from_ggsns_ofd->priv_nr;
OSMO_ASSERT(plane_idx < GTPH_PLANE_N); OSMO_ASSERT(plane_idx < GTPH_PLANE_N);
LOG("\n\n=== reading from GGSN (%s)\n", gtphub_plane_idx_names[plane_idx]); LOG(LOGL_DEBUG, "\n\n=== reading from GGSN (%s)\n", gtphub_plane_idx_names[plane_idx]);
if (!(what & BSC_FD_READ)) if (!(what & BSC_FD_READ))
return 0; return 0;
@@ -1291,7 +1283,7 @@ static int gtphub_unmap(struct gtphub *hub,
struct gtphub_peer *from_peer = from->peer_addr->peer; struct gtphub_peer *from_peer = from->peer_addr->peer;
if (from_seq && from_tei && (from_seq != from_tei)) { if (from_seq && from_tei && (from_seq != from_tei)) {
LOGERR("Seq unmap and TEI unmap yield two different peers. Using seq unmap." LOG(LOGL_DEBUG, "Seq unmap and TEI unmap yield two different peers. Using seq unmap."
"(from %s %s: seq %d yields %s, tei %u yields %s)\n", "(from %s %s: seq %d yields %s, tei %u yields %s)\n",
gtphub_plane_idx_names[p->plane_idx], gtphub_plane_idx_names[p->plane_idx],
gtphub_peer_str(from_peer), gtphub_peer_str(from_peer),
@@ -1304,7 +1296,7 @@ static int gtphub_unmap(struct gtphub *hub,
unmapped = (from_seq? from_seq : from_tei); unmapped = (from_seq? from_seq : from_tei);
if (unmapped && to_proxy && (unmapped != to_proxy)) { if (unmapped && to_proxy && (unmapped != to_proxy)) {
LOGERR("Unmap yields a different peer than the configured proxy. Using proxy." LOG(LOGL_NOTICE, "Unmap yields a different peer than the configured proxy. Using proxy."
" unmapped: %s proxy: %s\n", " unmapped: %s proxy: %s\n",
gtphub_port_str(unmapped), gtphub_port_str(unmapped),
gtphub_port_str2(to_proxy) gtphub_port_str2(to_proxy)
@@ -1317,7 +1309,7 @@ static int gtphub_unmap(struct gtphub *hub,
return 0; return 0;
} }
LOG("from seq %p; from tei %p; unmapped => %p\n", LOG(LOGL_DEBUG, "from seq %p; from tei %p; unmapped => %p\n",
from_seq, from_tei, unmapped); from_seq, from_tei, unmapped);
if (unmapped_from_seq) if (unmapped_from_seq)
@@ -1383,7 +1375,7 @@ int gtphub_from_ggsns_handle_buf(struct gtphub *hub,
struct osmo_fd **to_ofd, struct osmo_fd **to_ofd,
struct osmo_sockaddr *to_addr) struct osmo_sockaddr *to_addr)
{ {
LOG("<- rx %s from GGSN %s\n", LOG(LOGL_DEBUG, "<- rx %s from GGSN %s\n",
gtphub_plane_idx_names[plane_idx], gtphub_plane_idx_names[plane_idx],
osmo_sockaddr_to_str(from_addr)); osmo_sockaddr_to_str(from_addr));
@@ -1412,7 +1404,7 @@ int gtphub_from_ggsns_handle_buf(struct gtphub *hub,
struct gtphub_peer_port *ggsn = hub->ggsn_proxy[plane_idx]; struct gtphub_peer_port *ggsn = hub->ggsn_proxy[plane_idx];
if (ggsn) { if (ggsn) {
if (osmo_sockaddr_cmp(&ggsn->sa, from_addr) != 0) { if (osmo_sockaddr_cmp(&ggsn->sa, from_addr) != 0) {
LOGERR("Rejecting: GGSN proxy configured, but GTP packet" LOG(LOGL_ERROR, "Rejecting: GGSN proxy configured, but GTP packet"
" received on GGSN bind is from another sender:" " received on GGSN bind is from another sender:"
" proxy: %s sender: %s\n", " proxy: %s sender: %s\n",
gtphub_port_str(ggsn), gtphub_port_str(ggsn),
@@ -1432,12 +1424,12 @@ int gtphub_from_ggsns_handle_buf(struct gtphub *hub,
* this GGSN. If we don't have an entry, the GGSN has nothing to tell * this GGSN. If we don't have an entry, the GGSN has nothing to tell
* us about. */ * us about. */
if (!ggsn) { if (!ggsn) {
LOGERR("Dropping packet: unknown GGSN peer: %s\n", LOG(LOGL_ERROR, "Dropping packet: unknown GGSN peer: %s\n",
osmo_sockaddr_to_str(from_addr)); osmo_sockaddr_to_str(from_addr));
return -1; return -1;
} }
LOG("GGSN peer: %s\n", gtphub_port_str(ggsn)); LOG(LOGL_DEBUG, "GGSN peer: %s\n", gtphub_port_str(ggsn));
struct gtphub_peer_port *sgsn_from_seq; struct gtphub_peer_port *sgsn_from_seq;
struct gtphub_peer_port *sgsn; struct gtphub_peer_port *sgsn;
@@ -1453,7 +1445,7 @@ int gtphub_from_ggsns_handle_buf(struct gtphub *hub,
if (!sgsn) { if (!sgsn) {
/* A GGSN initiated request would go to a known TEI. So this is /* A GGSN initiated request would go to a known TEI. So this is
* bogus. */ * bogus. */
LOGERR("No SGSN to send to. Dropping packet.\n"); LOG(LOGL_ERROR, "No SGSN to send to. Dropping packet.\n");
return -1; return -1;
} }
@@ -1479,7 +1471,7 @@ int gtphub_from_ggsns_handle_buf(struct gtphub *hub,
*reply_buf = (uint8_t*)p.data; *reply_buf = (uint8_t*)p.data;
LOG("<-- Forward to SGSN: %d bytes to %s\n", LOG(LOGL_DEBUG, "<-- Forward to SGSN: %d bytes to %s\n",
(int)received, osmo_sockaddr_to_str(to_addr)); (int)received, osmo_sockaddr_to_str(to_addr));
return received; return received;
} }
@@ -1488,7 +1480,7 @@ static int from_sgsns_read_cb(struct osmo_fd *from_sgsns_ofd, unsigned int what)
{ {
unsigned int plane_idx = from_sgsns_ofd->priv_nr; unsigned int plane_idx = from_sgsns_ofd->priv_nr;
OSMO_ASSERT(plane_idx < GTPH_PLANE_N); OSMO_ASSERT(plane_idx < GTPH_PLANE_N);
LOG("\n\n=== reading from SGSN (%s)\n", gtphub_plane_idx_names[plane_idx]); LOG(LOGL_DEBUG, "\n\n=== reading from SGSN (%s)\n", gtphub_plane_idx_names[plane_idx]);
if (!(what & BSC_FD_READ)) if (!(what & BSC_FD_READ))
return 0; return 0;
@@ -1526,7 +1518,7 @@ int gtphub_from_sgsns_handle_buf(struct gtphub *hub,
struct osmo_fd **to_ofd, struct osmo_fd **to_ofd,
struct osmo_sockaddr *to_addr) struct osmo_sockaddr *to_addr)
{ {
LOG("-> rx %s from SGSN %s\n", LOG(LOGL_DEBUG, "-> rx %s from SGSN %s\n",
gtphub_plane_idx_names[plane_idx], gtphub_plane_idx_names[plane_idx],
osmo_sockaddr_to_str(from_addr)); osmo_sockaddr_to_str(from_addr));
@@ -1555,7 +1547,7 @@ int gtphub_from_sgsns_handle_buf(struct gtphub *hub,
struct gtphub_peer_port *sgsn = hub->sgsn_proxy[plane_idx]; struct gtphub_peer_port *sgsn = hub->sgsn_proxy[plane_idx];
if (sgsn) { if (sgsn) {
if (osmo_sockaddr_cmp(&sgsn->sa, from_addr) != 0) { if (osmo_sockaddr_cmp(&sgsn->sa, from_addr) != 0) {
LOGERR("Rejecting: GGSN proxy configured, but GTP packet" LOG(LOGL_ERROR, "Rejecting: GGSN proxy configured, but GTP packet"
" received on GGSN bind is from another sender:" " received on GGSN bind is from another sender:"
" proxy: %s sender: %s\n", " proxy: %s sender: %s\n",
gtphub_port_str(sgsn), gtphub_port_str(sgsn),
@@ -1576,7 +1568,7 @@ int gtphub_from_sgsns_handle_buf(struct gtphub *hub,
* first contact without being known yet, so create the peer * first contact without being known yet, so create the peer
* struct for the current sender. */ * struct for the current sender. */
if (plane_idx != GTPH_PLANE_CTRL) { if (plane_idx != GTPH_PLANE_CTRL) {
LOGERR("User plane peer was not announced by PDP Context, discarding: %s\n", LOG(LOGL_ERROR, "User plane peer was not announced by PDP Context, discarding: %s\n",
osmo_sockaddr_to_str(from_addr)); osmo_sockaddr_to_str(from_addr));
return -1; return -1;
} }
@@ -1592,11 +1584,11 @@ int gtphub_from_sgsns_handle_buf(struct gtphub *hub,
if (!sgsn) { if (!sgsn) {
/* This could theoretically happen for invalid address data or somesuch. */ /* This could theoretically happen for invalid address data or somesuch. */
LOGERR("Dropping packet: invalid SGSN peer: %s\n", LOG(LOGL_ERROR, "Dropping packet: invalid SGSN peer: %s\n",
osmo_sockaddr_to_str(from_addr)); osmo_sockaddr_to_str(from_addr));
return -1; return -1;
} }
LOG("SGSN peer: %s\n", gtphub_port_str(sgsn)); LOG(LOGL_DEBUG, "SGSN peer: %s\n", gtphub_port_str(sgsn));
struct gtphub_peer_port *ggsn_from_seq; struct gtphub_peer_port *ggsn_from_seq;
struct gtphub_peer_port *ggsn; struct gtphub_peer_port *ggsn;
@@ -1615,7 +1607,7 @@ int gtphub_from_sgsns_handle_buf(struct gtphub *hub,
} }
if (!ggsn) { if (!ggsn) {
LOGERR("No GGSN to send to. Dropping packet.\n"); LOG(LOGL_ERROR, "No GGSN to send to. Dropping packet.\n");
return -1; return -1;
} }
@@ -1641,7 +1633,7 @@ int gtphub_from_sgsns_handle_buf(struct gtphub *hub,
*reply_buf = (uint8_t*)p.data; *reply_buf = (uint8_t*)p.data;
LOG("--> Forward to GGSN: %d bytes to %s\n", LOG(LOGL_DEBUG, "--> Forward to GGSN: %d bytes to %s\n",
(int)received, osmo_sockaddr_to_str(to_addr)); (int)received, osmo_sockaddr_to_str(to_addr));
return received; return received;
} }
@@ -1667,13 +1659,13 @@ void gtphub_resolved_ggsn(struct gtphub *hub, const char *apn_oi_str,
struct gtphub_peer_port *pp; struct gtphub_peer_port *pp;
struct gtphub_resolved_ggsn *ggsn; struct gtphub_resolved_ggsn *ggsn;
LOG("Resolved GGSN callback: %s %s\n", LOG(LOGL_DEBUG, "Resolved GGSN callback: %s %s\n",
apn_oi_str, osmo_hexdump((unsigned char*)resolved_addr, sizeof(*resolved_addr))); apn_oi_str, osmo_hexdump((unsigned char*)resolved_addr, sizeof(*resolved_addr)));
pp = gtphub_port_have(hub, &hub->to_ggsns[GTPH_PLANE_CTRL], pp = gtphub_port_have(hub, &hub->to_ggsns[GTPH_PLANE_CTRL],
resolved_addr, 2123); resolved_addr, 2123);
if (!pp) { if (!pp) {
LOGERR("Internal: Cannot create/find peer '%s'\n", LOG(LOGL_ERROR, "Internal: Cannot create/find peer '%s'\n",
gsn_addr_to_str(resolved_addr)); gsn_addr_to_str(resolved_addr));
return; return;
} }
@@ -1702,7 +1694,7 @@ static int gtphub_gc_peer_addr(struct gtphub_peer_addr *pa)
struct gtphub_peer_port *pp, *npp; struct gtphub_peer_port *pp, *npp;
llist_for_each_entry_safe(pp, npp, &pa->ports, entry) { llist_for_each_entry_safe(pp, npp, &pa->ports, entry) {
if (gtphub_gc_peer_port(pp)) { if (gtphub_gc_peer_port(pp)) {
LOG("expired: peer %s\n", LOG(LOGL_DEBUG, "expired: peer %s\n",
gtphub_port_str(pp)); gtphub_port_str(pp));
gtphub_peer_port_del(pp); gtphub_peer_port_del(pp);
} }
@@ -1828,7 +1820,7 @@ int gtphub_start(struct gtphub *hub, struct gtphub_cfg *cfg)
&cfg->to_ggsns[plane_idx], &cfg->to_ggsns[plane_idx],
from_ggsns_read_cb, hub, plane_idx); from_ggsns_read_cb, hub, plane_idx);
if (rc) { if (rc) {
LOGERR("Failed to bind for GGSNs (%s)\n", LOG(LOGL_FATAL, "Failed to bind for GGSNs (%s)\n",
gtphub_plane_idx_names[plane_idx]); gtphub_plane_idx_names[plane_idx]);
return rc; return rc;
} }
@@ -1837,7 +1829,7 @@ int gtphub_start(struct gtphub *hub, struct gtphub_cfg *cfg)
&cfg->to_sgsns[plane_idx], &cfg->to_sgsns[plane_idx],
from_sgsns_read_cb, hub, plane_idx); from_sgsns_read_cb, hub, plane_idx);
if (rc) { if (rc) {
LOGERR("Failed to bind for SGSNs (%s)\n", LOG(LOGL_FATAL, "Failed to bind for SGSNs (%s)\n",
gtphub_plane_idx_names[plane_idx]); gtphub_plane_idx_names[plane_idx]);
return rc; return rc;
} }
@@ -1850,7 +1842,7 @@ int gtphub_start(struct gtphub *hub, struct gtphub_cfg *cfg)
&hub->to_sgsns[plane_idx], &hub->to_sgsns[plane_idx],
&cfg->sgsn_proxy[plane_idx]) &cfg->sgsn_proxy[plane_idx])
!= 0) { != 0) {
LOGERR("Cannot configure SGSN proxy %s port %d.\n", LOG(LOGL_FATAL, "Cannot configure SGSN proxy %s port %d.\n",
cfg->sgsn_proxy[plane_idx].addr_str, cfg->sgsn_proxy[plane_idx].addr_str,
(int)cfg->sgsn_proxy[plane_idx].port); (int)cfg->sgsn_proxy[plane_idx].port);
return -1; return -1;
@@ -1860,21 +1852,21 @@ int gtphub_start(struct gtphub *hub, struct gtphub_cfg *cfg)
&hub->to_ggsns[plane_idx], &hub->to_ggsns[plane_idx],
&cfg->ggsn_proxy[plane_idx]) &cfg->ggsn_proxy[plane_idx])
!= 0) { != 0) {
LOGERR("Cannot configure GGSN proxy.\n"); LOG(LOGL_ERROR, "Cannot configure GGSN proxy.\n");
return -1; return -1;
} }
} }
for (plane_idx = 0; plane_idx < GTPH_PLANE_N; plane_idx++) { for (plane_idx = 0; plane_idx < GTPH_PLANE_N; plane_idx++) {
if (hub->sgsn_proxy[plane_idx]) if (hub->sgsn_proxy[plane_idx])
LOG("Using SGSN %s proxy %s\n", LOG(LOGL_NOTICE, "Using SGSN %s proxy %s\n",
gtphub_plane_idx_names[plane_idx], gtphub_plane_idx_names[plane_idx],
gtphub_port_str(hub->sgsn_proxy[plane_idx])); gtphub_port_str(hub->sgsn_proxy[plane_idx]));
} }
for (plane_idx = 0; plane_idx < GTPH_PLANE_N; plane_idx++) { for (plane_idx = 0; plane_idx < GTPH_PLANE_N; plane_idx++) {
if (hub->sgsn_proxy[plane_idx]) if (hub->sgsn_proxy[plane_idx])
LOG("Using GGSN %s proxy %s\n", LOG(LOGL_NOTICE, "Using GGSN %s proxy %s\n",
gtphub_plane_idx_names[plane_idx], gtphub_plane_idx_names[plane_idx],
gtphub_port_str(hub->ggsn_proxy[plane_idx])); gtphub_port_str(hub->ggsn_proxy[plane_idx]));
} }
@@ -1986,7 +1978,7 @@ static struct gtphub_peer_addr *gtphub_addr_have(struct gtphub *hub,
a = gtphub_peer_add_addr(peer, addr); a = gtphub_peer_add_addr(peer, addr);
LOG("New peer address: %s %s\n", LOG(LOGL_DEBUG, "New peer address: %s %s\n",
bind->label, bind->label,
gsn_addr_to_str(&a->addr)); gsn_addr_to_str(&a->addr));
@@ -2010,7 +2002,7 @@ static struct gtphub_peer_port *gtphub_addr_add_port(struct gtphub_peer_addr *a,
llist_add(&pp->entry, &a->ports); llist_add(&pp->entry, &a->ports);
LOG("New peer port: %s port %d\n", LOG(LOGL_DEBUG, "New peer port: %s port %d\n",
gsn_addr_to_str(&a->addr), gsn_addr_to_str(&a->addr),
(int)port); (int)port);
@@ -2122,7 +2114,7 @@ int osmo_sockaddr_init(struct osmo_sockaddr *addr,
rc = _osmo_getaddrinfo(&res, family, type, proto, host, port); rc = _osmo_getaddrinfo(&res, family, type, proto, host, port);
if (rc != 0) { if (rc != 0) {
LOGERR("getaddrinfo returned error %d\n", (int)rc); LOG(LOGL_ERROR, "getaddrinfo returned error %d\n", (int)rc);
return -EINVAL; return -EINVAL;
} }