From: Jaroslav Kysela Date: Fri, 29 Dec 2017 18:16:31 +0000 (+0100) Subject: cclient, cwc, cccam: add cc_name, fix log messages X-Git-Url: http://git.ipfire.org/gitweb.cgi?a=commitdiff_plain;h=f3d3ae7153db61b1d82ed6bf535fd84ea8a14a15;p=thirdparty%2Ftvheadend.git cclient, cwc, cccam: add cc_name, fix log messages --- diff --git a/src/descrambler/cccam.c b/src/descrambler/cccam.c index fff7ade40..1a87bdd9f 100644 --- a/src/descrambler/cccam.c +++ b/src/descrambler/cccam.c @@ -271,7 +271,7 @@ cccam_handle_keys(cccam_t *cccam, cc_service_t *ct, cc_ecm_section_t *es, dcw_even = buf[1] == MSG_ECM_REQUEST ? _dcw : NULL; dcw_odd = buf[1] == MSG_ECM_REQUEST ? _dcw + 8 : NULL; - tvhtrace(cccam->cc_subsys, "HEADER:"); + tvhtrace(cccam->cc_subsys, "%s: HEADER:", cccam->cc_name); tvhlog_hexdump(cccam->cc_subsys, buf, 4); cc_ecm_reply(ct, es, DESCRAMBLER_CSA_CBC, dcw_even, dcw_odd, seq); @@ -292,30 +292,26 @@ cccam_running_reply(cccam_t *cccam, uint8_t *buf, int len) if (len < 4) return -1; - tvhtrace(cccam->cc_subsys, "%s:%i: response msg type=%d, response:", - cccam->cc_hostname, cccam->cc_port, buf[1]); + tvhtrace(cccam->cc_subsys, "%s: response msg type=%d, response:", + cccam->cc_name, buf[1]); tvhlog_hexdump(cccam->cc_subsys, buf, len); switch (buf[1]) { case MSG_NEW_CARD_SIDINFO: case MSG_NEW_CARD: - tvhtrace(cccam->cc_subsys, "%s:%i: add card message received", - cccam->cc_hostname, cccam->cc_port); + tvhtrace(cccam->cc_subsys, "%s: add card message received", cccam->cc_name); cccam_decode_card_data_reply(cccam, buf); break; case MSG_CARD_REMOVED: - tvhtrace(cccam->cc_subsys, "%s:%i: del card message received", - cccam->cc_hostname, cccam->cc_port); + tvhtrace(cccam->cc_subsys, "%s: del card message received", cccam->cc_name); break; case MSG_KEEPALIVE: - tvhtrace(cccam->cc_subsys, "%s:%i: keepalive", - cccam->cc_hostname, cccam->cc_port); + tvhtrace(cccam->cc_subsys, "%s: keepalive", cccam->cc_name); break; case MSG_EMM_REQUEST: /* emm ack */ //cccam_send_msg(cccam, MSG_EMM_REQUEST, NULL, 0, 0, 0, 0); //sem_post(&cccam->ecm_mutex); - tvhtrace(cccam->cc_subsys, "%s:%i: EMM message ACK received", - cccam->cc_hostname, cccam->cc_port); + tvhtrace(cccam->cc_subsys, "%s: EMM message ACK received", cccam->cc_name); break; case MSG_ECM_NOK1: /* retry */ case MSG_ECM_NOK2: /* decode failed */ @@ -329,8 +325,8 @@ cccam_running_reply(cccam_t *cccam, uint8_t *buf, int len) if (es->es_resolved) { mpegts_service_t *t = (mpegts_service_t *)ct->td_service; tvhdebug(cccam->cc_subsys, - "%s:%i: Ignore %sECM (PID %d) for service \"%s\" from %s (seq %i)", - cccam->cc_hostname, cccam->cc_port, + "%s: Ignore %sECM (PID %d) for service \"%s\" from %s (seq %i)", + cccam->cc_name, es->es_pending ? "duplicate " : "", ep->ep_capid, t->s_dvb_svcname, ct->td_nicename, es->es_seq); return 0; @@ -340,22 +336,24 @@ cccam_running_reply(cccam_t *cccam, uint8_t *buf, int len) return 0; } } - tvhwarn(cccam->cc_subsys, "Got unexpected ECM reply (seqno: %d)", seq); + tvhwarn(cccam->cc_subsys, "%s: Got unexpected ECM reply (seqno: %d)", + cccam->cc_name, seq); break; } case MSG_SRV_DATA: - tvhinfo(cccam->cc_subsys, "%s:%i: CCcam server version %s nodeid=%02x%02x%02x%02x%02x%02x%02x%02x", - cccam->cc_hostname, cccam->cc_port, buf + 12, + tvhinfo(cccam->cc_subsys, + "%s: CCcam server version %s nodeid=%02x%02x%02x%02x%02x%02x%02x%02x", + cccam->cc_name, buf + 12, buf[4], buf[5], buf[6], buf[7], buf[8], buf[9], buf[10], buf[11]); break; case MSG_CLI_DATA: - tvhinfo(cccam->cc_subsys, "%s:%i: CCcam server authentication completed", - cccam->cc_hostname, cccam->cc_port); + tvhinfo(cccam->cc_subsys, "%s: CCcam server authentication completed", + cccam->cc_name); break; default: - tvhwarn(cccam->cc_subsys, "%s:%i: Unknown message received", - cccam->cc_hostname, cccam->cc_port); + tvhwarn(cccam->cc_subsys, "%s: Unknown message received", + cccam->cc_name); break; } return 0; @@ -374,24 +372,22 @@ cccam_read_message(cccam_t *cccam, const char *state, uint8_t *buf, int len, int ret = tcp_read_timeout(cccam->cc_fd, buf, 4, timeout); pthread_mutex_lock(&cccam->cc_mutex); if (ret) { - tvhdebug(cccam->cc_subsys, "%s:%i: recv error %d or timeout", - cccam->cc_hostname, cccam->cc_port, ret); + tvhdebug(cccam->cc_subsys, "%s: recv error %d or timeout", + cccam->cc_name, ret); return -1; } cccam_decrypt(&cccam->recvblock, buf, 4); msglen = (buf[2] << 8) | buf[3]; if (msglen > 0) { if (msglen > len - 2) { - tvhdebug(cccam->cc_subsys, "%s:%i: received message too large", - cccam->cc_hostname, cccam->cc_port); + tvhdebug(cccam->cc_subsys, "%s: received message too large", cccam->cc_name); return -1; } pthread_mutex_unlock(&cccam->cc_mutex); ret = tcp_read_timeout(cccam->cc_fd, buf + 4, msglen, 5000); pthread_mutex_lock(&cccam->cc_mutex); if (ret) { - tvhdebug(cccam->cc_subsys, "%s:%i: timeout reading message", - cccam->cc_hostname, cccam->cc_port); + tvhdebug(cccam->cc_subsys, "%s: timeout reading message", cccam->cc_name); return -1; } cccam_decrypt(&cccam->recvblock, buf + 4, msglen); @@ -449,7 +445,7 @@ cccam_send_ka(void *cc) buf[2] = 0; buf[3] = 0; - tvhdebug(cccam->cc_subsys, "send keepalive"); + tvhdebug(cccam->cc_subsys, "%s: send keepalive", cccam->cc_name); cccam_send_msg(cccam, MSG_NO_HEADER, buf, 4, 0, 0, 0); } @@ -468,7 +464,7 @@ sha1_make_login_key(cccam_t *cccam, uint8_t *buf) SHA1_Update(&sha1, buf, 16); SHA1_Final(hash, &sha1); - tvhdebug(cccam->cc_subsys, "sha1 hash:"); + tvhdebug(cccam->cc_subsys, "%s: sha1 hash:", cccam->cc_name); tvhlog_hexdump(cccam->cc_subsys, hash, sizeof(hash)); cccam_crypt_init(&cccam->recvblock, hash, 20); @@ -513,19 +509,19 @@ cccam_send_login(cccam_t *cccam) cccam_send_msg(cccam, MSG_NO_HEADER, buf, 6, 0, 0, 0); if (cc_read((cclient_t *)cccam, data, 20, 5000)) { - tvherror(cccam->cc_subsys, "login failed, pwd ack not received"); + tvherror(cccam->cc_subsys, "%s: login failed, pwd ack not received", cccam->cc_name); return -2; } cccam_decrypt(&cccam->recvblock, data, 20); - tvhdebug(cccam->cc_subsys, "login ack, response:"); + tvhdebug(cccam->cc_subsys, "%s: login ack, response:", cccam->cc_name); tvhlog_hexdump(cccam->cc_subsys, data, 20); if (memcmp(data, "CCcam", 5)) { - tvherror(cccam->cc_subsys, "login failed, usr/pwd invalid"); + tvherror(cccam->cc_subsys, "%s: login failed, usr/pwd invalid", cccam->cc_name); return -2; } else { - tvhinfo(cccam->cc_subsys, "login succeeded"); + tvhinfo(cccam->cc_subsys, "%s: login succeeded", cccam->cc_name); } return 0; @@ -562,12 +558,10 @@ cccam_init_session(void *cc) * Get init seed */ if((r = cc_read(cc, buf, 16, 5000))) { - tvhinfo(cccam->cc_subsys, "%s:%i: init error (no init seed received)", - cccam->cc_hostname, cccam->cc_port); + tvhinfo(cccam->cc_subsys, "%s: init error (no init seed received)", cccam->cc_name); return -1; } - tvhtrace(cccam->cc_subsys, "%s:%d: init seed received:", - cccam->cc_hostname, cccam->cc_port); + tvhtrace(cccam->cc_subsys, "%s: init seed received:", cccam->cc_name); tvhlog_hexdump(cccam->cc_subsys, buf, 16); /* check for oscam-cccam */ @@ -578,8 +572,7 @@ cccam_init_session(void *cc) sum += buf[i]; } if (sum == recv_sum) - tvhinfo(cccam->cc_subsys, "%s:%i: oscam server detected", - cccam->cc_hostname, cccam->cc_port); + tvhinfo(cccam->cc_subsys, "%s: oscam server detected", cccam->cc_name); sha1_make_login_key(cccam, buf); @@ -609,8 +602,7 @@ cccam_send_ecm(void *cc, cc_service_t *ct, cc_ecm_section_t *es, int seq; if (len > 255) { - tvherror(cccam->cc_subsys, "%s:%i: ECM too big (%d bytes)", - cccam->cc_hostname, cccam->cc_port, len); + tvherror(cccam->cc_subsys, "%s: ECM too big (%d bytes)", cccam->cc_name, len); return 0; } @@ -653,8 +645,8 @@ cccam_send_emm(void *cc, cc_service_t *ct, cc_card_data_t *pcard, int seq; if (len > 255) { - tvherror(cccam->cc_subsys, "%s:%i: EMM too big (%d bytes)", - cccam->cc_hostname, cccam->cc_port, len); + tvherror(cccam->cc_subsys, "%s: EMM too big (%d bytes)", + cccam->cc_name, len); return; } diff --git a/src/descrambler/cclient.c b/src/descrambler/cclient.c index 1c5a4c57c..21822aeac 100644 --- a/src/descrambler/cclient.c +++ b/src/descrambler/cclient.c @@ -69,30 +69,28 @@ cc_new_card(cclient_t *cc, uint16_t caid, uint8_t *ua, n = caid2name(caid) ?: "Unknown"; if (ua) { - tvhinfo(cc->cc_subsys, "%s:%i: Connected as user %s " + tvhinfo(cc->cc_subsys, "%s: Connected as user %s " "to a %s-card [0x%04x : %02x.%02x.%02x.%02x.%02x.%02x.%02x.%02x] " "with %d provider%s", - cc->cc_hostname, cc->cc_port, - cc->cc_username, n, caid, + cc->cc_name, cc->cc_username, n, caid, ua[0], ua[1], ua[2], ua[3], ua[4], ua[5], ua[6], ua[7], pcount, pcount > 1 ? "s" : ""); } else { - tvhinfo(cc->cc_subsys, "%s:%i: Connected as user %s " + tvhinfo(cc->cc_subsys, "%s: Connected as user %s " "to a %s-card [0x%04x] with %d provider%s", - cc->cc_hostname, cc->cc_port, - cc->cc_username, n, caid, + cc->cc_name, cc->cc_username, n, caid, pcount, pcount > 1 ? "s" : ""); } for (i = 0, ep = pcard->cs_ra.providers; i < pcount; i++, ep++) { if (psa) { sa = ep->sa; - tvhinfo(cc->cc_subsys, "%s:%i: Provider ID #%d: 0x%04x:0x%06x %02x.%02x.%02x.%02x.%02x.%02x.%02x.%02x", - cc->cc_hostname, cc->cc_port, i + 1, caid, ep->id, + tvhinfo(cc->cc_subsys, "%s: Provider ID #%d: 0x%04x:0x%06x %02x.%02x.%02x.%02x.%02x.%02x.%02x.%02x", + cc->cc_name, i + 1, caid, ep->id, sa[0], sa[1], sa[2], sa[3], sa[4], sa[5], sa[6], sa[7]); } else { - tvhinfo(cc->cc_subsys, "%s:%i: Provider ID #%d: 0x%04x:0x%06x", - cc->cc_hostname, cc->cc_port, i + 1, caid, ep->id); + tvhinfo(cc->cc_subsys, "%s: Provider ID #%d: 0x%04x:0x%06x", + cc->cc_name, i + 1, caid, ep->id); } } @@ -181,16 +179,16 @@ cc_ecm_reply(cc_service_t *ct, cc_ecm_section_t *es, if (es->es_nok >= CC_MAX_NOKS) { tvhdebug(cc->cc_subsys, - "Too many NOKs[%i] for service \"%s\"%s from %s", - es->es_section, t->s_dvb_svcname, chaninfo, ct->td_nicename); + "%s: Too many NOKs[%i] for service \"%s\"%s from %s", + cc->cc_name, es->es_section, t->s_dvb_svcname, chaninfo, ct->td_nicename); es->es_keystate = ES_FORBIDDEN; goto forbid; } if (descrambler_resolved((service_t *)t, (th_descrambler_t *)ct)) { tvhdebug(cc->cc_subsys, - "NOK[%i] from %s: Already has a key for service \"%s\"", - es->es_section, ct->td_nicename, t->s_dvb_svcname); + "%s: NOK[%i] from %s: Already has a key for service \"%s\"", + cc->cc_name, es->es_section, ct->td_nicename, t->s_dvb_svcname); es->es_nok = CC_MAX_NOKS; /* do not send more ECM requests */ es->es_keystate = ES_IDLE; if (ct->td_keystate == DS_READY) @@ -198,9 +196,9 @@ cc_ecm_reply(cc_service_t *ct, cc_ecm_section_t *es, } tvhdebug(cc->cc_subsys, - "Received NOK[%i] for service \"%s\"%s " + "%s: Received NOK[%i] for service \"%s\"%s " "(seqno: %d Req delay: %"PRId64" ms)", - es->es_section, t->s_dvb_svcname, chaninfo, seq, delay); + cc->cc_name, es->es_section, t->s_dvb_svcname, chaninfo, seq, delay); forbid: i = 0; @@ -226,9 +224,9 @@ forbid: if (ep == NULL) { /* !UNKNOWN && !RESOLVED */ tvherror(cc->cc_subsys, - "Can not descramble service \"%s\", access denied (seqno: %d " + "%s: Can not descramble service \"%s\", access denied (seqno: %d " "Req delay: %"PRId64" ms) from %s", - t->s_dvb_svcname, seq, delay, ct->td_nicename); + cc->cc_name, t->s_dvb_svcname, seq, delay, ct->td_nicename); descrambler_change_keystate((th_descrambler_t *)ct, DS_FORBIDDEN, 1); ct->ecm_state = ECM_RESET; /* this pid is not valid, force full scan */ @@ -247,20 +245,20 @@ forbid: (t->s_dvb_prefcapid != ct->cs_capid && t->s_dvb_prefcapid_lock == PREFCAPID_OFF)) { t->s_dvb_prefcapid = ct->cs_capid; - tvhdebug(cc->cc_subsys, "Saving prefered PID %d for %s", - t->s_dvb_prefcapid, ct->td_nicename); + tvhdebug(cc->cc_subsys, "%s: Saving prefered PID %d for %s", + cc->cc_name, t->s_dvb_prefcapid, ct->td_nicename); service_request_save((service_t*)t, 0); } tvhdebug(cc->cc_subsys, - "Received ECM reply%s for service \"%s\" [%d] " + "%s: Received ECM reply%s for service \"%s\" [%d] " "(seqno: %d Req delay: %"PRId64" ms)", - chaninfo, t->s_dvb_svcname, es->es_section, seq, delay); + cc->cc_name, chaninfo, t->s_dvb_svcname, es->es_section, seq, delay); if(es->es_keystate != ES_RESOLVED) tvhdebug(cc->cc_subsys, - "Obtained DES keys for service \"%s\" in %"PRId64" ms, from %s", - t->s_dvb_svcname, delay, ct->td_nicename); + "%s: Obtained DES keys for service \"%s\" in %"PRId64" ms, from %s", + cc->cc_name, t->s_dvb_svcname, delay, ct->td_nicename); es->es_keystate = ES_RESOLVED; es->es_resolved = 1; @@ -330,7 +328,8 @@ cc_read(cclient_t *cc, void *buf, size_t len, int timeout) pthread_mutex_lock(&cc->cc_mutex); if (r && tvheadend_is_running()) - tvhwarn(cc->cc_subsys, "read error %d (%s)", r, strerror(r)); + tvhwarn(cc->cc_subsys, "%s: read error %d (%s)", + cc->cc_name, r, strerror(r)); if(cc_must_break(cc)) return ECONNABORTED; @@ -344,8 +343,8 @@ cc_read(cclient_t *cc, void *buf, size_t len, int timeout) void cc_write_message(cclient_t *cc, cc_message_t *msg, int enq) { - tvhtrace(cc->cc_subsys, "%s:%i: sending message len %u enq %d", - cc->cc_hostname, cc->cc_port, msg->cm_len, enq); + tvhtrace(cc->cc_subsys, "%s: sending message len %u enq %d", + cc->cc_name, msg->cm_len, enq); tvhlog_hexdump(cc->cc_subsys, msg->cm_data, msg->cm_len); if (enq) { @@ -355,7 +354,8 @@ cc_write_message(cclient_t *cc, cc_message_t *msg, int enq) pthread_mutex_unlock(&cc->cc_writer_mutex); } else { if (tvh_write(cc->cc_fd, msg->cm_data, msg->cm_len)) - tvhinfo(cc->cc_subsys, "write error %s", strerror(errno)); + tvhinfo(cc->cc_subsys, "%s: write error %s", + cc->cc_name, strerror(errno)); free(msg); } } @@ -380,7 +380,8 @@ cc_writer_thread(void *aux) pthread_mutex_unlock(&cc->cc_writer_mutex); // int64_t ts = getfastmonoclock(); if (tvh_write(cc->cc_fd, cm->cm_data, cm->cm_len)) - tvhinfo(cc->cc_subsys, "write error %s", strerror(errno)); + tvhinfo(cc->cc_subsys, "%s: write error %s", + cc->cc_name, strerror(errno)); // printf("Write took %lld usec\n", getfastmonoclock() - ts); free(cm); pthread_mutex_lock(&cc->cc_writer_mutex); @@ -442,7 +443,7 @@ cc_session(cclient_t *cc) if (cc->cc_read(cc)) break; } - tvhdebug(cc->cc_subsys, "session thread exiting"); + tvhdebug(cc->cc_subsys, "%s: session exiting", cc->cc_name); /** * Collect the writer thread @@ -451,7 +452,7 @@ cc_session(cclient_t *cc) cc->cc_writer_running = 0; tvh_cond_signal(&cc->cc_writer_cond, 0); pthread_join(writer_thread_id, NULL); - tvhdebug(cc->cc_subsys, "Write thread joined"); + tvhdebug(cc->cc_subsys, "%s: Write thread joined", cc->cc_name); } /** @@ -463,6 +464,7 @@ cc_thread(void *aux) cclient_t *cc = aux; int fd, d, r; char errbuf[100]; + char name[256]; char hostname[256]; int port; int attempts = 0; @@ -475,10 +477,13 @@ cc_thread(void *aux) cc_invalidate_cards(cc); caclient_set_status((caclient_t *)cc, CACLIENT_STATUS_READY); + snprintf(name, sizeof(name), "%s:%d", cc->cc_hostname, cc->cc_port); + cc->cc_name = name; + snprintf(hostname, sizeof(hostname), "%s", cc->cc_hostname); port = cc->cc_port; - tvhinfo(cc->cc_subsys, "Attemping to connect to %s:%d", hostname, port); + tvhinfo(cc->cc_subsys, "%s: Attemping to connect to server", cc->cc_name); pthread_mutex_unlock(&cc->cc_mutex); @@ -489,8 +494,7 @@ cc_thread(void *aux) if(fd == -1) { attempts++; tvhinfo(cc->cc_subsys, - "%s:%d: Connection failed: %s", - hostname, port, errbuf); + "%s: Connection failed: %s", cc->cc_name, errbuf); } else { if(cc->cc_running == 0) { @@ -498,7 +502,7 @@ cc_thread(void *aux) break; } - tvhinfo(cc->cc_subsys, "%s:%i: Connected", hostname, port); + tvhinfo(cc->cc_subsys, "%s: Connected", cc->cc_name); attempts = 0; cc->cc_fd = fd; @@ -508,7 +512,7 @@ cc_thread(void *aux) cc->cc_fd = -1; close(fd); - tvhinfo(cc->cc_subsys, "%s:%i: Disconnected", hostname, port); + tvhinfo(cc->cc_subsys, "%s: Disconnected", cc->cc_name); } if(cc->cc_running == 0) continue; @@ -522,8 +526,8 @@ cc_thread(void *aux) d = 3; tvhinfo(cc->cc_subsys, - "%s:%i: Automatic connection attempt in %d seconds", - cc->cc_hostname, cc->cc_port, d-1); + "%s: Automatic connection attempt in %d seconds", + cc->cc_name, d-1); mono = mclk() + sec2mono(d); do { @@ -533,7 +537,7 @@ cc_thread(void *aux) } while (ERRNO_AGAIN(r)); } - tvhinfo(cc->cc_subsys, "%s:%i inactive", cc->cc_hostname, cc->cc_port); + tvhinfo(cc->cc_subsys, "%s: Inactive, thread exit", cc->cc_name); cc_free_cards(cc); pthread_mutex_unlock(&cc->cc_mutex); return NULL; @@ -567,18 +571,17 @@ cc_emm_set_allowed(cclient_t *cc, int emm_allowed) if (!emm_allowed) { tvhinfo(cc->cc_subsys, - "%s:%i: Will not forward EMMs (not allowed by server)", - cc->cc_hostname, cc->cc_port); + "%s: Will not forward EMMs (not allowed by server)", + cc->cc_name); } else { LIST_FOREACH(pcard, &cc->cc_cards, cs_card) if (pcard->cs_ra.type != CARD_UNKNOWN) break; if (pcard) { - tvhinfo(cc->cc_subsys, "%s:%i: Will forward EMMs", - cc->cc_hostname, cc->cc_port); + tvhinfo(cc->cc_subsys, "%s: Will forward EMMs", cc->cc_name); } else { tvhinfo(cc->cc_subsys, - "%s:%i: Will not forward EMMs (unsupported CA system)", - cc->cc_hostname, cc->cc_port); + "%s: Will not forward EMMs (unsupported CA system)", + cc->cc_name); emm_allowed = 0; } } @@ -594,7 +597,8 @@ cc_emm_send(void *aux, const uint8_t *radata, int ralen, void *mux) cc_card_data_t *pcard = aux; cclient_t *cc = pcard->cs_client; - tvhtrace(cc->cc_subsys, "sending EMM for %04x mux %p", pcard->cs_ra.caid, mux); + tvhtrace(cc->cc_subsys, "%s: sending EMM for %04x mux %p", + cc->cc_name, pcard->cs_ra.caid, mux); tvhlog_hexdump(cc->cc_subsys, radata, ralen); cc->cc_send_emm(cc, NULL, pcard, 0, radata, ralen); } @@ -671,8 +675,8 @@ cc_table_input(void *opaque, int pid, const uint8_t *data, int len, int emm) ct->ecm_state = ECM_INIT; ct->cs_capid = -1; t->s_dvb_prefcapid = 0; - tvhdebug(cc->cc_subsys, "%s:%i: Reset after unexpected or no reply for service \"%s\"", - cc->cc_hostname, cc->cc_port, t->s_dvb_svcname); + tvhdebug(cc->cc_subsys, "%s: Reset after unexpected or no reply for service \"%s\"", + cc->cc_name, t->s_dvb_svcname); } LIST_FOREACH(ep, &ct->cs_pids, ep_link) @@ -681,8 +685,7 @@ cc_table_input(void *opaque, int pid, const uint8_t *data, int len, int emm) if(ep == NULL) { if (ct->ecm_state == ECM_INIT) { // Validate prefered ECM PID - tvhdebug(cc->cc_subsys, "%s:%i: ECM state INIT", - cc->cc_hostname, cc->cc_port); + tvhdebug(cc->cc_subsys, "%s: ECM state INIT", cc->cc_name); if(t->s_dvb_prefcapid_lock != PREFCAPID_OFF) { st = service_stream_find((service_t*)t, t->s_dvb_prefcapid); @@ -693,9 +696,8 @@ cc_table_input(void *opaque, int pid, const uint8_t *data, int len, int emm) pcard->cs_ra.caid == c->caid && verify_provider(pcard, c->providerid)) goto prefcapid_ok; - tvhdebug(cc->cc_subsys, "%s:%i: Invalid prefered ECM (PID %d) found for service \"%s\"", - cc->cc_hostname, cc->cc_port, - t->s_dvb_prefcapid, t->s_dvb_svcname); + tvhdebug(cc->cc_subsys, "%s: Invalid prefered ECM (PID %d) found for service \"%s\"", + cc->cc_name, cc->cc_port, t->s_dvb_svcname); t->s_dvb_prefcapid = 0; } @@ -705,9 +707,8 @@ prefcapid_ok: ep = calloc(1, sizeof(cc_ecm_pid_t)); ep->ep_capid = pid; LIST_INSERT_HEAD(&ct->cs_pids, ep, ep_link); - tvhdebug(cc->cc_subsys, "%s:%i: Insert %s ECM (PID %d) for service \"%s\"", - cc->cc_hostname, cc->cc_port, - t->s_dvb_prefcapid ? "preferred" : "new", pid, t->s_dvb_svcname); + tvhdebug(cc->cc_subsys, "%s: Insert %s ECM (PID %d) for service \"%s\"", + cc->cc_name, t->s_dvb_prefcapid ? "preferred" : "new", pid, t->s_dvb_svcname); } } if(ep == NULL) @@ -770,22 +771,22 @@ found: es->es_resolved = 0; if(ct->cs_capid >= 0 && capid > 0 && ct->cs_capid != capid) { - tvhdebug(cc->cc_subsys, "%s:%i: Filtering ECM (PID %d)", - cc->cc_hostname, cc->cc_port, capid); + tvhdebug(cc->cc_subsys, "%s: Filtering ECM (PID %d)", + cc->cc_name, capid); goto end; } es->es_seq = cc->cc_send_ecm(cc, ct, es, pcard, data, len); tvhdebug(cc->cc_subsys, - "%s:%i: Sending ECM%s section=%d/%d, for service \"%s\" (seqno: %d)", - cc->cc_hostname, cc->cc_port, chaninfo, section, + "%s: Sending ECM%s section=%d/%d, for service \"%s\" (seqno: %d)", + cc->cc_name, chaninfo, section, ep->ep_last_section, t->s_dvb_svcname, es->es_seq); es->es_time = getfastmonoclock(); } else { if (cc->cc_forward_emm && data[0] >= 0x82 && data[0] <= 0x92) { - tvhtrace(cc->cc_subsys, "%s:%i: sending EMM for %04X:%06X service \"%s\"", - cc->cc_hostname, cc->cc_port, pcard->cs_ra.caid, provid, + tvhtrace(cc->cc_subsys, "%s: sending EMM for %04X:%06X service \"%s\"", + cc->cc_name, pcard->cs_ra.caid, provid, t->s_dvb_svcname); tvhlog_hexdump(cc->cc_subsys, data, len); cc->cc_send_emm(cc, ct, pcard, provid, data, len); @@ -931,7 +932,8 @@ cc_service_start(caclient_t *cac, service_t *t) ct->ecm_state = ECM_INIT; td = (th_descrambler_t *)ct; - snprintf(buf, sizeof(buf), "cc-%s-%i-%04X", cc->cc_hostname, cc->cc_port, pcard->cs_ra.caid); + snprintf(buf, sizeof(buf), "%s-%s-%04X", + cc->cc_id, cc->cc_name, pcard->cs_ra.caid); td->td_nicename = strdup(buf); td->td_service = t; td->td_stop = cc_service_destroy; @@ -966,8 +968,8 @@ add: } if (reuse != 1) - tvhdebug(cc->cc_subsys, "%s %susing CWC %s:%d", - service_nicename(t), reuse ? "re" : "", cc->cc_hostname, cc->cc_port); + tvhdebug(cc->cc_subsys, "%s: %s %susing CWC %s:%d", + cc->cc_name, service_nicename(t), reuse ? "re" : "", cc->cc_hostname, cc->cc_port); end: pthread_mutex_unlock(&t->s_stream_mutex); @@ -1002,8 +1004,8 @@ cc_caid_update(caclient_t *cac, mpegts_mux_t *mux, uint16_t caid, uint16_t pid, cc_card_data_t *pcard; tvhtrace(cc->cc_subsys, - "caid update event - client %s mux %p caid %04x (%i) pid %04x (%i) valid %i", - cac->cac_name, mux, caid, caid, pid, pid, valid); + "%s: caid update event - client %s mux %p caid %04x (%i) pid %04x (%i) valid %i", + cc->cc_name, cac->cac_name, mux, caid, caid, pid, pid, valid); pthread_mutex_lock(&cc->cc_mutex); if (valid < 0 || cc->cc_running) { LIST_FOREACH(pcard, &cc->cc_cards, cs_card) { @@ -1061,6 +1063,10 @@ cc_conf_changed(caclient_t *cac) pthread_kill(tid, SIGHUP); pthread_join(tid, NULL); caclient_set_status(cac, CACLIENT_STATUS_NONE); + pthread_mutex_lock(&cc->cc_mutex); + free(cc->cc_name); + cc->cc_name = NULL; + pthread_mutex_unlock(&cc->cc_mutex); } } diff --git a/src/descrambler/cclient.h b/src/descrambler/cclient.h index e9049ad01..89f237248 100644 --- a/src/descrambler/cclient.h +++ b/src/descrambler/cclient.h @@ -136,6 +136,7 @@ typedef struct cclient { caclient_t; int cc_subsys; + char *cc_name; const char *cc_id; /* Callbacks */ diff --git a/src/descrambler/cwc.c b/src/descrambler/cwc.c index 94f0c65f5..b1d3dbbd4 100644 --- a/src/descrambler/cwc.c +++ b/src/descrambler/cwc.c @@ -319,16 +319,14 @@ cwc_decode_card_data_reply(cwc_t *cwc, uint8_t *msg, int len) len -= 12; if(len < 3) { - tvhinfo(cwc->cc_subsys, "%s:%i: Invalid card data reply", - cwc->cc_hostname, cwc->cc_port); + tvhinfo(cwc->cc_subsys, "%s: Invalid card data reply", cwc->cc_name); return -1; } plen = (msg[1] & 0xf) << 8 | msg[2]; if(plen < 14) { - tvhinfo(cwc->cc_subsys, "%s:%i: Invalid card data reply (message)", - cwc->cc_hostname, cwc->cc_port); + tvhinfo(cwc->cc_subsys, "%s: Invalid card data reply (message)", cwc->cc_name); return -1; } @@ -338,8 +336,8 @@ cwc_decode_card_data_reply(cwc_t *cwc, uint8_t *msg, int len) plen -= 12; if(plen < nprov * 11) { - tvhinfo(cwc->cc_subsys, "%s:%i: Invalid card data reply (provider list)", - cwc->cc_hostname, cwc->cc_port); + tvhinfo(cwc->cc_subsys, "%s: Invalid card data reply (provider list)", + cwc->cc_name); return -1; } @@ -410,7 +408,8 @@ handle_ecm_reply(cc_service_t *ct, cc_ecm_section_t *es, off = 16; type = DESCRAMBLER_AES128_ECB; } else { - tvherror(cwc->cc_subsys, "wrong ECM reply length %d", len); + tvherror(cwc->cc_subsys, "%s: wrong ECM reply length %d", + cwc->cc_name, len); return; } cc_ecm_reply(ct, es, type, msg + 3, msg + 3 + off, seq); @@ -436,7 +435,8 @@ cwc_running_reply(cwc_t *cwc, uint8_t msgtype, uint8_t *msg, int len) case 0x80: case 0x81: if (len < 12) { - tvherror(cwc->cc_subsys, "wrong 0x%02X length %d", msgtype, len); + tvherror(cwc->cc_subsys, "%s: wrong 0x%02X length %d", + cwc->cc_name, msgtype, len); return -1; } seq = (msg[2] << 8) | msg[3]; @@ -449,7 +449,8 @@ cwc_running_reply(cwc_t *cwc, uint8_t msgtype, uint8_t *msg, int len) if (es->es_resolved) { mpegts_service_t *t = (mpegts_service_t *)ct->td_service; tvhdebug(cwc->cc_subsys, - "Ignore %sECM (PID %d) for service \"%s\" from %s (seq %i)", + "%s: Ignore %sECM (PID %d) for service \"%s\" from %s (seq %i)", + cwc->cc_name, es->es_pending ? "duplicate " : "", ep->ep_capid, t->s_dvb_svcname, ct->td_nicename, es->es_seq); return 0; @@ -459,12 +460,13 @@ cwc_running_reply(cwc_t *cwc, uint8_t msgtype, uint8_t *msg, int len) return 0; } } - tvhwarn(cwc->cc_subsys, "Got unexpected ECM reply (seqno: %d, len: %d)", seq, len); + tvhwarn(cwc->cc_subsys, "%s: Got unexpected ECM reply (seqno: %d, len: %d)", + cwc->cc_name, seq, len); break; case 0xD3: if (len < 16) { - tvherror(cwc->cc_subsys, "wrong 0xD3 length %d", len); + tvherror(cwc->cc_subsys, "%s: wrong 0xD3 length %d", cwc->cc_name, len); return -1; } @@ -472,14 +474,14 @@ cwc_running_reply(cwc_t *cwc, uint8_t msgtype, uint8_t *msg, int len) if (caid){ if(len < 3) { - tvhinfo(cwc->cc_subsys, "Invalid card data reply"); + tvhinfo(cwc->cc_subsys, "%s: Invalid card data reply", cwc->cc_name); return -1; } plen = (msg[1] & 0xf) << 8 | msg[2]; if(plen < 14) { - tvhinfo(cwc->cc_subsys, "Invalid card data reply (message)"); + tvhinfo(cwc->cc_subsys, "%s: Invalid card data reply (message)", cwc->cc_name); return -1; } @@ -502,16 +504,16 @@ cwc_read_message if((r = cc_read((cclient_t *)cwc, buf, 2, timeout))) { if (tvheadend_is_running()) - tvhinfo(cwc->cc_subsys, "%s:%i: %s: Read error (header): %s", - cwc->cc_hostname, cwc->cc_port, state, strerror(r)); + tvhinfo(cwc->cc_subsys, "%s: %s: Read error (header): %s", + cwc->cc_name, state, strerror(r)); return -1; } msglen = (buf[0] << 8) | buf[1]; if(msglen > len) { if (tvheadend_is_running()) - tvhinfo(cwc->cc_subsys, "%s:%i: %s: Invalid message size: %d", - cwc->cc_hostname, cwc->cc_port, state, msglen); + tvhinfo(cwc->cc_subsys, "%s: %s: Invalid message size: %d", + cwc->cc_name, state, msglen); return -1; } @@ -520,14 +522,14 @@ cwc_read_message if((r = cc_read((cclient_t *)cwc, buf + 2, msglen, 1000))) { if (tvheadend_is_running()) - tvhinfo(cwc->cc_subsys, "%s:%i: %s: Read error: %s", - cwc->cc_hostname, cwc->cc_port, state, strerror(r)); + tvhinfo(cwc->cc_subsys, "%s: %s: Read error: %s", + cwc->cc_name, state, strerror(r)); return -1; } if((msglen = des_decrypt(buf, msglen + 2, cwc)) < 15) { - tvhinfo(cwc->cc_subsys, "%s:%i: %s: Decrypt failed", - cwc->cc_hostname, cwc->cc_port, state); + tvhinfo(cwc->cc_subsys, "%s: %s: Decrypt failed", + cwc->cc_name, state); return -1; } @@ -548,8 +550,8 @@ cwc_init_session(void *cc) * Get login key */ if ((r = cc_read((cclient_t *)cwc, buf, 14, 5000))) { - tvhinfo(cwc->cc_subsys, "%s:%i: No login key received: %s", - cwc->cc_hostname, cwc->cc_port, strerror(r)); + tvhinfo(cwc->cc_subsys, "%s: No login key received: %s", + cwc->cc_name, strerror(r)); return -1; } @@ -565,8 +567,7 @@ cwc_init_session(void *cc) return -1; if(buf[12] != MSG_CLIENT_2_SERVER_LOGIN_ACK) { - tvhinfo(cwc->cc_subsys, "%s:%i: Login failed", - cwc->cc_hostname, cwc->cc_port); + tvhinfo(cwc->cc_subsys, "%s: Login failed", cwc->cc_name); return -1; } @@ -580,8 +581,7 @@ cwc_init_session(void *cc) return -1; if (buf[12] != MSG_CARD_DATA) { - tvhinfo(cwc->cc_subsys, "%s:%i: Card data request failed", - cwc->cc_hostname, cwc->cc_port); + tvhinfo(cwc->cc_subsys, "%s: Card data request failed", cwc->cc_name); return -1; }