Harald Welte has uploaded this change for review. ( 
https://gerrit.osmocom.org/14066


Change subject: ccid: Integrate libosmocore logging
......................................................................

ccid: Integrate libosmocore logging

Change-Id: I3436827f658653273af21f1deaf030c2a389f91a
---
M ccid/Makefile
M ccid/ccid_device.c
M ccid/ccid_device.h
M ccid/ccid_main_functionfs.c
4 files changed, 97 insertions(+), 22 deletions(-)



  git pull ssh://gerrit.osmocom.org:29418/osmo-ccid-firmware 
refs/changes/66/14066/1

diff --git a/ccid/Makefile b/ccid/Makefile
index 317fcbd..cd8321f 100644
--- a/ccid/Makefile
+++ b/ccid/Makefile
@@ -1,7 +1,7 @@
 CFLAGS=-Wall -g

 ccid_functionfs: ccid_main_functionfs.o ccid_proto.o ccid_device.o
-       $(CC) $(CFLAGS) -lasan -losmocore -laio -o $@ $^
+       $(CC) $(CFLAGS) -lasan -losmocore -ltalloc -laio -o $@ $^

 %.o: %.c
        $(CC) $(CFLAGS) -o $@ -c $^
diff --git a/ccid/ccid_device.c b/ccid/ccid_device.c
index e3705ae..ffcbacc 100644
--- a/ccid/ccid_device.c
+++ b/ccid/ccid_device.c
@@ -6,6 +6,7 @@

 #include <osmocom/core/msgb.h>
 #include <osmocom/core/utils.h>
+#include <osmocom/core/logging.h>

 #include "ccid_proto.h"
 #include "ccid_device.h"
@@ -157,6 +158,15 @@
 /* Send given CCID message */
 static int ccid_send(struct ccid_instance *ci, struct msgb *msg)
 {
+       struct ccid_header *ch = (struct ccid_header *) msgb_ccid_in(msg);
+       struct ccid_slot *cs = get_ccid_slot(ci, ch->bSlot);
+       if (cs) {
+               LOGPCS(cs, LOGL_DEBUG, "Tx CCID(IN) %s %s\n",
+                       get_value_string(ccid_msg_type_vals, ch->bMessageType), 
msgb_hexdump(msg));
+       } else {
+               LOGPCI(ci, LOGL_DEBUG, "Tx CCID(IN) %s %s\n",
+                       get_value_string(ccid_msg_type_vals, ch->bMessageType), 
msgb_hexdump(msg));
+       }
        return ci->ops->send_in(ci, msg);
 }

@@ -470,24 +480,32 @@
        switch (spar->bProtocolNum) {
        case CCID_PROTOCOL_NUM_T0:
                rc = decode_ccid_pars_t0(&pars_dec, &spar->abProtocolData.t0);
-               if (rc < 0)
+               if (rc < 0) {
+                       LOGP(DCCID, LOGL_ERROR, "SetParameters: Unable to parse 
T0: %d\n", rc);
                        resp = ccid_gen_parameters_t0(cs, seq, 
CCID_CMD_STATUS_FAILED, -rc);
+                       goto out;
+               }
                /* FIXME: validate parameters; abort if they are not supported 
*/
                cs->pars = pars_dec;
                resp = ccid_gen_parameters_t0(cs, seq, CCID_CMD_STATUS_OK, 0);
                break;
        case CCID_PROTOCOL_NUM_T1:
                rc = decode_ccid_pars_t1(&pars_dec, &spar->abProtocolData.t1);
-               if (rc < 0)
+               if (rc < 0) {
+                       LOGP(DCCID, LOGL_ERROR, "SetParameters: Unable to parse 
T1: %d\n", rc);
                        resp = ccid_gen_parameters_t1(cs, seq, 
CCID_CMD_STATUS_FAILED, -rc);
+                       goto out;
+               }
                /* FIXME: validate parameters; abort if they are not supported 
*/
                cs->pars = pars_dec;
                resp = ccid_gen_parameters_t1(cs, seq, CCID_CMD_STATUS_OK, 0);
                break;
        default:
+               LOGP(DCCID, LOGL_ERROR, "SetParameters: Invalid Protocol 
0x%02x\n",spar->bProtocolNum);
                resp = ccid_gen_parameters_t0(cs, seq, CCID_CMD_STATUS_FAILED, 
0);
                break;
        }
+out:
        return ccid_slot_send_unbusy(cs, resp);
 }

@@ -573,6 +591,7 @@
        //case PC_to_RDR_Abort: /* seriously? WTF! */
                break;
        default:
+               LOGP(DCCID, LOGL_ERROR, "Abort for non-Abortable Message 
Type\n");
                /* CCID spec lists CMD_NOT_ABORTED, but gives no numberic value 
?!? */
                resp = ccid_gen_slot_status(cs, seq, CCID_CMD_STATUS_FAILED, 
CCID_ERR_CMD_NOT_SUPPORTED);
                return ccid_slot_send_unbusy(cs, resp);
@@ -617,18 +636,23 @@
        /* Check for invalid slot number */
        cs = get_ccid_slot(ci, ch->bSlot);
        if (!cs) {
+               LOGPCI(ci, LOGL_ERROR, "Invalid bSlot %u\n", ch->bSlot);
                resp = gen_err_resp(ch->bMessageType, ch->bSlot, 
CCID_ICC_STATUS_NO_ICC, ch->bSeq, 5);
                return ccid_send(ci, resp);
        }

        /* Check if slot is already busy; Reject any additional commands 
meanwhile */
        if (cs->cmd_busy) {
+               LOGPCS(cs, LOGL_ERROR, "Slot Busy, but another cmd received\n");
                /* FIXME: ABORT logic as per section 5.3.1 of CCID Spec v1.1 */
                resp = gen_err_resp(ch->bMessageType, ch->bSlot, 
get_icc_status(cs), ch->bSeq,
                                        CCID_ERR_CMD_SLOT_BUSY);
                return ccid_send(ci, resp);
        }

+       LOGPCS(cs, LOGL_DEBUG, "Rx CCID(OUT) %s %s\n",
+               get_value_string(ccid_msg_type_vals, ch->bMessageType), 
msgb_hexdump(msg));
+
        /* we're now processing a command for the slot; mark slot as busy */
        cs->cmd_busy = true;

@@ -707,6 +731,7 @@
                break;
        default:
                /* generic response with bERror = 0 (command not supported) */
+               LOGP(DCCID, LOGL_NOTICE, "Unknown CCID Message received: 
0x%02x\n", ch->bMessageType);
                resp = gen_err_resp(ch->bMessageType, ch->bSlot, 
CCID_ICC_STATUS_NO_ICC, ch->bSeq,
                                    CCID_ERR_CMD_NOT_SUPPORTED);
                return ccid_slot_send_unbusy(cs, resp);
@@ -714,7 +739,7 @@
        return 0;

 short_msg:
-       /* FIXME */
+       LOGP(DCCID, LOGL_ERROR, "Short CCID message received: %s; ignoring\n", 
msgb_hexdump(msg));
        return -1;
 }

diff --git a/ccid/ccid_device.h b/ccid/ccid_device.h
index 4cdb325..68ec98a 100644
--- a/ccid/ccid_device.h
+++ b/ccid/ccid_device.h
@@ -2,12 +2,16 @@
 #include <stdbool.h>
 #include <stdint.h>

+enum {
+       DCCID,
+       DUSB,
+};

 #define NR_SLOTS       8

 #define LOGPCI(ci, lvl, fmt, args ...) LOGP(DCCID, lvl, "%s: " fmt, 
(ci)->name, ## args)
 #define LOGPCS(cs, lvl, fmt, args ...) \
-       LOGP(DCCID, lvl, "%s(%u): " fmt, (cc)->ci->name, (cc)->slot_nr, ## args)
+       LOGP(DCCID, lvl, "%s(%u): " fmt, (cs)->ci->name, (cs)->slot_nr, ## args)

 struct msgb;

diff --git a/ccid/ccid_main_functionfs.c b/ccid/ccid_main_functionfs.c
index 2b57182..717a6ae 100644
--- a/ccid/ccid_main_functionfs.c
+++ b/ccid/ccid_main_functionfs.c
@@ -1,4 +1,5 @@

+#include <errno.h>
 #include <stdint.h>
 #include <endian.h>
 #include <sys/types.h>
@@ -132,6 +133,9 @@
 #include <osmocom/core/select.h>
 #include <osmocom/core/utils.h>
 #include <osmocom/core/msgb.h>
+#include <osmocom/core/utils.h>
+#include <osmocom/core/application.h>
+#include <osmocom/core/logging.h>

 #include "ccid_device.h"

@@ -161,7 +165,7 @@

 static int ep_int_cb(struct osmo_fd *ofd, unsigned int what)
 {
-       printf("INT\n");
+       LOGP(DUSB, LOGL_DEBUG, "%s\n", __func__);
        return 0;
 }

@@ -171,7 +175,7 @@
        struct msgb *msg = msgb_alloc(512, "OUT-Rx");
        int rc;

-       printf("OUT\n");
+       LOGP(DUSB, LOGL_DEBUG, "%s\n", __func__);
        if (what & BSC_FD_READ) {
                rc = read(ofd->fd, msgb_data(msg), msgb_tailroom(msg));
                if (rc <= 0) {
@@ -187,7 +191,7 @@

 static int ep_in_cb(struct osmo_fd *ofd, unsigned int what)
 {
-       printf("IN\n");
+       LOGP(DUSB, LOGL_DEBUG, "%s\n", __func__);
        if (what & BSC_FD_WRITE) {
                /* write what we have to write */
        }
@@ -207,11 +211,10 @@

 static void handle_setup(const struct usb_ctrlrequest *setup)
 {
-       printf("bRequestType = %d\n", setup->bRequestType);
-       printf("bRequest     = %d\n", setup->bRequest);
-       printf("wValue       = %d\n", le16_to_cpu(setup->wValue));
-       printf("wIndex       = %d\n", le16_to_cpu(setup->wIndex));
-       printf("wLength      = %d\n", le16_to_cpu(setup->wLength));
+       LOGP(DUSB, LOGL_NOTICE, "EP0 SETUP bRequestType=0x%02x, bRequest=0x%02x 
wValue=0x%04x, "
+               "wIndex=0x%04x, wLength=%u\n", setup->bRequestType, 
setup->bRequest,
+               le16_to_cpu(setup->wValue), le16_to_cpu(setup->wIndex), 
le16_to_cpu(setup->wLength));
+       /* FIXME: Handle control transfer */
 }

 static void aio_refill_out(struct ufunc_handle *uh);
@@ -221,14 +224,12 @@
        struct ufunc_handle *uh = (struct ufunc_handle *) ofd->data;
        int rc;

-       printf("EP0\n");
-
        if (what & BSC_FD_READ) {
                struct usb_functionfs_event evt;
                rc = read(ofd->fd, (uint8_t *)&evt, sizeof(evt));
                if (rc < sizeof(evt))
                        return -23;
-               printf("\t%s\n", get_value_string(ffs_evt_type_names, 
evt.type));
+               LOGP(DUSB, LOGL_NOTICE, "EP0 %s\n", 
get_value_string(ffs_evt_type_names, evt.type));
                switch (evt.type) {
                case FUNCTIONFS_ENABLE:
                        aio_refill_out(uh);
@@ -248,6 +249,8 @@
 {
        int rc;
        struct aio_help *ah = &uh->aio_out;
+
+       LOGP(DUSB, LOGL_DEBUG, "%s\n", __func__);
        msgb_reset(ah->msg);
        io_prep_pread(ah->iocb, uh->ep_out.fd, msgb_data(ah->msg), 
msgb_tailroom(ah->msg), 0);
        io_set_eventfd(ah->iocb, uh->aio_evfd.fd);
@@ -266,24 +269,31 @@
        assert(rc == sizeof(ev_cnt));

        rc = io_getevents(uh->aio_ctx, 1, 3, evt, NULL);
-       if (rc <= 0)
+       if (rc <= 0) {
+               LOGP(DUSB, LOGL_ERROR, "error in io_getevents(): %d\n", rc);
                return rc;
+       }

        for (i = 0; i < rc; i++) {
                int fd = evt[i].obj->aio_fildes;
                if (fd == uh->ep_int.fd) {
                        /* interrupt endpoint AIO has completed. This means the 
IRQ transfer
                         * which we generated has reached the host */
+                       LOGP(DUSB, LOGL_DEBUG, "IRQ AIO completed, free()ing 
msgb\n");
+                       msgb_free(uh->aio_in.msg);
+                       uh->aio_in.msg = NULL;
                } else if (fd == uh->ep_in.fd) {
                        /* IN endpoint AIO has completed. This means the IN 
transfer which
                         * we sent to the host has completed */
+                       LOGP(DUSB, LOGL_DEBUG, "IN AIO completed, free()ing 
msgb\n");
                        msgb_free(uh->aio_in.msg);
                        uh->aio_in.msg = NULL;
                } else if (fd == uh->ep_out.fd) {
-                       /* IN endpoint AIO has completed. This means the host 
has sent us
+                       /* OUT endpoint AIO has completed. This means the host 
has sent us
                         * some OUT data */
+                       LOGP(DUSB, LOGL_DEBUG, "OUT AIO completed, dispatching 
received msg\n");
                        msgb_put(uh->aio_out.msg, evt[i].res);
-                       printf("\t%s\n", msgb_hexdump(uh->aio_out.msg));
+                       //printf("\t%s\n", msgb_hexdump(uh->aio_out.msg));
                        //ccid_handle_out(uh->ccid_handle, uh->aio_out.buf, 
evt[i].res);
                        ccid_handle_out(uh->ccid_handle, uh->aio_out.msg);
                        aio_refill_out(uh);
@@ -304,11 +314,15 @@
        osmo_fd_setup(&uh->ep0, rc, BSC_FD_READ, &ep_0_cb, uh, 0);
        osmo_fd_register(&uh->ep0);
        rc = write(uh->ep0.fd, &descriptors, sizeof(descriptors));
-       if (rc != sizeof(descriptors))
+       if (rc != sizeof(descriptors)) {
+               LOGP(DUSB, LOGL_ERROR, "Cannot write descriptors: %s\n", 
strerror(errno));
                return -1;
+       }
        rc = write(uh->ep0.fd, &strings, sizeof(strings));
-       if (rc != sizeof(strings))
+       if (rc != sizeof(strings)) {
+               LOGP(DUSB, LOGL_ERROR, "Cannot write strings: %s\n", 
strerror(errno));
                return -1;
+       }

        /* open other endpoint file descriptors */
        rc = open("ep1", O_RDWR);
@@ -378,20 +392,52 @@
        .send_in = ccid_ops_send_in,
 };

+static const struct log_info_cat log_info_cat[] = {
+       [DUSB] = {
+               .name = "USB",
+               .description = "USB Transport",
+               .enabled = 1,
+               .loglevel = LOGL_NOTICE,
+       },
+       [DCCID] = {
+               .name = "CCID",
+               .description = "CCID Core",
+               .color = "\033[1;35m",
+               .enabled = 1,
+               .loglevel = LOGL_DEBUG,
+       },
+};
+
+static const struct log_info log_info = {
+       .cat = log_info_cat,
+       .num_cat = ARRAY_SIZE(log_info_cat),
+};
+
+static void *tall_main_ctx;
+
 int main(int argc, char **argv)
 {
        struct ufunc_handle ufh = (struct ufunc_handle) { 0, };
        struct ccid_instance ci = (struct ccid_instance) { 0, };
        int rc;

+       tall_main_ctx = talloc_named_const(NULL, 0, "ccid_main_functionfs");
+       msgb_talloc_ctx_init(tall_main_ctx, 0);
+       osmo_init_logging2(tall_main_ctx, &log_info);
+
        ccid_instance_init(&ci, &c_ops, "", &ufh);
        ufh.ccid_handle = &ci;

+       if (argc < 2) {
+               fprintf(stderr, "You have to specify the mount-path of the 
functionfs\n");
+               exit(2);
+       }
+
        chdir(argv[1]);
        rc = ep0_init(&ufh);
        if (rc < 0) {
                fprintf(stderr, "Error %d\n", rc);
-               exit(2);
+               exit(1);
        }

        while (1) {

--
To view, visit https://gerrit.osmocom.org/14066
To unsubscribe, or for help writing mail filters, visit 
https://gerrit.osmocom.org/settings

Gerrit-Project: osmo-ccid-firmware
Gerrit-Branch: master
Gerrit-MessageType: newchange
Gerrit-Change-Id: I3436827f658653273af21f1deaf030c2a389f91a
Gerrit-Change-Number: 14066
Gerrit-PatchSet: 1
Gerrit-Owner: Harald Welte <[email protected]>

Reply via email to