From d404f984d480318da799a96dc29727e55df8feb4 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Andreas=20=C3=96man?= Date: Fri, 8 Jan 2010 15:02:16 +0000 Subject: [PATCH] Improve logging when subscriptions fail to start --- debian/changelog | 2 ++ src/dvb/dvb.h | 2 +- src/dvb/dvb_fe.c | 7 +++-- src/dvb/dvb_transport.c | 26 +++++++++------- src/dvr/dvr_rec.c | 7 +++-- src/htsp.c | 2 +- src/streaming.c | 1 + src/subscriptions.c | 8 +++-- src/transports.c | 69 +++++++++++++++++++++++++++++++++-------- src/transports.h | 12 ++++++- 10 files changed, 102 insertions(+), 34 deletions(-) diff --git a/debian/changelog b/debian/changelog index 5831f7af..c4cfae72 100644 --- a/debian/changelog +++ b/debian/changelog @@ -10,6 +10,8 @@ hts-tvheadend (2.8) hts; urgency=low for people and it's only useful if you have complex setups with multiple adapters, etc. + * Improve logging when subscriptions fail to start + hts-tvheadend (2.7) hts; urgency=low * Added support for DVB subtitles. Currently only forwarded over HTSP diff --git a/src/dvb/dvb.h b/src/dvb/dvb.h index b52b39ea..2a835da6 100644 --- a/src/dvb/dvb.h +++ b/src/dvb/dvb.h @@ -299,7 +299,7 @@ htsmsg_t *dvb_transport_build_msg(th_transport_t *t); /** * DVB Frontend */ -void dvb_fe_tune(th_dvb_mux_instance_t *tdmi, const char *reason); +int dvb_fe_tune(th_dvb_mux_instance_t *tdmi, const char *reason); void dvb_fe_stop(th_dvb_mux_instance_t *tdmi); diff --git a/src/dvb/dvb_fe.c b/src/dvb/dvb_fe.c index d49e3bf9..769a5559 100644 --- a/src/dvb/dvb_fe.c +++ b/src/dvb/dvb_fe.c @@ -37,6 +37,7 @@ #include "dvb_support.h" #include "diseqc.h" #include "notify.h" +#include "transports.h" /** @@ -283,7 +284,7 @@ dvb_fe_tune_s2(th_dvb_mux_instance_t *tdmi, dvb_mux_conf_t *dmc) /** * */ -void +int dvb_fe_tune(th_dvb_mux_instance_t *tdmi, const char *reason) { th_dvb_adapter_t *tda = tdmi->tdmi_adapter; @@ -299,7 +300,7 @@ dvb_fe_tune(th_dvb_mux_instance_t *tdmi, const char *reason) lock_assert(&global_lock); if(tda->tda_mux_current == tdmi) - return; + return 0; if(tdmi->tdmi_scan_queue != NULL) { TAILQ_REMOVE(tdmi->tdmi_scan_queue, tdmi, tdmi_scan_link); @@ -368,6 +369,7 @@ dvb_fe_tune(th_dvb_mux_instance_t *tdmi, const char *reason) tvhlog(LOG_ERR, "dvb", "\"%s\" tuning to \"%s\"" " -- Front configuration failed -- %s, frequency: %ld", tda->tda_rootpath, buf, strerror(errno), p->frequency); + return TRANSPORT_NOSTART_TUNING_FAILED; } tda->tda_mux_current = tdmi; @@ -377,4 +379,5 @@ dvb_fe_tune(th_dvb_mux_instance_t *tdmi, const char *reason) dvb_table_add_default(tdmi); dvb_adapter_notify(tda); + return 0; } diff --git a/src/dvb/dvb_transport.c b/src/dvb/dvb_transport.c index 0a9d495a..4492791f 100644 --- a/src/dvb/dvb_transport.c +++ b/src/dvb/dvb_transport.c @@ -103,17 +103,17 @@ dvb_transport_open_demuxers(th_dvb_adapter_t *tda, th_transport_t *t) static int dvb_transport_start(th_transport_t *t, unsigned int weight, int force_start) { - int w; + int w, r; th_dvb_adapter_t *tda = t->tht_dvb_mux_instance->tdmi_adapter; th_dvb_mux_instance_t *tdmi = tda->tda_mux_current; lock_assert(&global_lock); if(tda->tda_rootpath == NULL) - return 1; /* hardware not present */ + return TRANSPORT_NOSTART_NO_HARDWARE; - if(tdmi && !tdmi->tdmi_enabled) - return 1; /* Mux is disabled */ + if(t->tht_dvb_mux_instance && !t->tht_dvb_mux_instance->tdmi_enabled) + return TRANSPORT_NOSTART_MUX_NOT_ENABLED; /* Mux is disabled */ /* Check if adapter is idle, or already tuned */ @@ -121,20 +121,24 @@ dvb_transport_start(th_transport_t *t, unsigned int weight, int force_start) w = transport_compute_weight(&tdmi->tdmi_adapter->tda_transports); if(w >= weight) - return 1; /* We are outranked by weight, cant use it */ + /* We are outranked by weight, cant use it */ + return TRANSPORT_NOSTART_NOT_FREE; dvb_adapter_clean(tda); } - dvb_transport_open_demuxers(tda, t); - pthread_mutex_lock(&tda->tda_delivery_mutex); - LIST_INSERT_HEAD(&tda->tda_transports, t, tht_active_link); - dvb_fe_tune(t->tht_dvb_mux_instance, "Transport start"); + r = dvb_fe_tune(t->tht_dvb_mux_instance, "Transport start"); + if(!r) + LIST_INSERT_HEAD(&tda->tda_transports, t, tht_active_link); pthread_mutex_unlock(&tda->tda_delivery_mutex); - return 0; + + if(!r) + dvb_transport_open_demuxers(tda, t); + + return r; } @@ -285,7 +289,7 @@ dvb_transport_quality(th_transport_t *t) lock_assert(&global_lock); - return tdmi->tdmi_enabled ? tdmi->tdmi_quality : 0; + return tdmi->tdmi_adapter->tda_qmon ? tdmi->tdmi_quality : 100; } diff --git a/src/dvr/dvr_rec.c b/src/dvr/dvr_rec.c index b2a0bf3d..6d9eb743 100644 --- a/src/dvr/dvr_rec.c +++ b/src/dvr/dvr_rec.c @@ -239,7 +239,9 @@ dvr_rec_fatal_error(dvr_entry_t *de, const char *fmt, ...) vsnprintf(msgbuf, sizeof(msgbuf), fmt, ap); va_end(ap); - tvhlog(LOG_ERR, "pvr", "%s: %s", de->de_filename, msgbuf); + tvhlog(LOG_ERR, "pvr", + "Recording error: \"%s\": %s", + de->de_filename ?: de->de_title, msgbuf); } @@ -440,7 +442,8 @@ dvr_thread(void *aux) case SMT_NOSOURCE: dvr_rec_fatal_error(de, - "No source transport available, automatic retry"); + "Unable to start -- %s", + transport_nostart2txt(sm->sm_code)); break; case SMT_MPEGTS: diff --git a/src/htsp.c b/src/htsp.c index ecf7d0f9..f9dd00d3 100644 --- a/src/htsp.c +++ b/src/htsp.c @@ -1517,7 +1517,7 @@ htsp_streaming_input(void *opaque, streaming_message_t *sm) break; case SMT_NOSOURCE: - htsp_subscription_status(hs, "No available sources"); + htsp_subscription_status(hs, transport_nostart2txt(sm->sm_code)); break; case SMT_MPEGTS: diff --git a/src/streaming.c b/src/streaming.c index b58e21e0..82b1eff3 100644 --- a/src/streaming.c +++ b/src/streaming.c @@ -172,6 +172,7 @@ streaming_msg_clone(streaming_message_t *src) case SMT_STOP: case SMT_TRANSPORT_STATUS: + case SMT_NOSOURCE: dst->sm_code = src->sm_code; break; diff --git a/src/subscriptions.c b/src/subscriptions.c index 1d496d2f..e522b37b 100644 --- a/src/subscriptions.c +++ b/src/subscriptions.c @@ -132,7 +132,8 @@ subscription_reschedule(void *aux) th_subscription_t *s; th_transport_t *t; streaming_message_t *sm; - + char buf[128]; + int errorcode; lock_assert(&global_lock); gtimer_arm(&subscription_reschedule_timer, subscription_reschedule, NULL, 2); @@ -144,12 +145,13 @@ subscription_reschedule(void *aux) if(s->ths_channel == NULL) continue; /* stale entry, channel has been destroyed */ - t = transport_find(s->ths_channel, s->ths_weight); + snprintf(buf, sizeof(buf), "Subscription \"%s\"", s->ths_title); + t = transport_find(s->ths_channel, s->ths_weight, buf, &errorcode); if(t == NULL) { /* No transport available */ - sm = streaming_msg_create(SMT_NOSOURCE); + sm = streaming_msg_create_code(SMT_NOSOURCE, errorcode); streaming_target_deliver(s->ths_output, sm); continue; } diff --git a/src/transports.c b/src/transports.c index d61cd3dc..f9ae02b1 100644 --- a/src/transports.c +++ b/src/transports.c @@ -53,6 +53,23 @@ static struct th_transport_list transporthash[TRANSPORT_HASH_WIDTH]; static void transport_data_timeout(void *aux); +/** + * + */ +const char * +transport_nostart2txt(int code) +{ + switch(code) { + case TRANSPORT_NOSTART_NO_HARDWARE: return "No hardware present"; + case TRANSPORT_NOSTART_MUX_NOT_ENABLED: return "No mux enabled"; + case TRANSPORT_NOSTART_NOT_FREE: return "Adapter in use by other subscription"; + case TRANSPORT_NOSTART_TUNING_FAILED: return "Tuning failed"; + case TRANSPORT_NOSTART_SVC_NOT_ENABLED: return "No service enabled"; + case TRANSPORT_NOSTART_BAD_SIGNAL: return "Too bad signal quality"; + } + return "Unknown error"; +} + /** * @@ -243,6 +260,7 @@ int transport_start(th_transport_t *t, unsigned int weight, int force_start) { th_stream_t *st; + int r; lock_assert(&global_lock); @@ -253,8 +271,8 @@ transport_start(th_transport_t *t, unsigned int weight, int force_start) t->tht_dts_start = AV_NOPTS_VALUE; t->tht_pcr_drift = 0; - if(t->tht_start_feed(t, weight, force_start)) - return -1; + if((r = t->tht_start_feed(t, weight, force_start))) + return r; pthread_mutex_lock(&t->tht_stream_mutex); @@ -341,26 +359,44 @@ transportcmp(const void *A, const void *B) * */ th_transport_t * -transport_find(channel_t *ch, unsigned int weight) +transport_find(channel_t *ch, unsigned int weight, const char *loginfo, + int *errorp) { th_transport_t *t, **vec; - int cnt = 0, i; - + int cnt = 0, i, r; + int error = 0; + lock_assert(&global_lock); /* First, sort all transports in order */ LIST_FOREACH(t, &ch->ch_transports, tht_ch_link) - if(t->tht_enabled && t->tht_quality_index(t) > 10) - cnt++; + cnt++; vec = alloca(cnt * sizeof(th_transport_t *)); - i = 0; - LIST_FOREACH(t, &ch->ch_transports, tht_ch_link) - if(t->tht_enabled && t->tht_quality_index(t) > 10) - vec[i++] = t; + cnt = 0; + LIST_FOREACH(t, &ch->ch_transports, tht_ch_link) { - assert(i == cnt); + if(!t->tht_enabled) { + error = TRANSPORT_NOSTART_SVC_NOT_ENABLED; + if(loginfo != NULL) { + tvhlog(LOG_NOTICE, "Transport", "%s: Skipping \"%s\" -- not enabled", + loginfo, transport_nicename(t)); + } + continue; + } + + if(t->tht_quality_index(t) < 10) { + error = TRANSPORT_NOSTART_BAD_SIGNAL; + if(loginfo != NULL) { + tvhlog(LOG_NOTICE, "Transport", + "%s: Skipping \"%s\" -- Quality below 10%", + loginfo, transport_nicename(t)); + } + continue; + } + vec[cnt++] = t; + } /* Sort transports, lower priority should come come earlier in the vector (i.e. it will be more favoured when selecting a transport */ @@ -383,9 +419,16 @@ transport_find(channel_t *ch, unsigned int weight) for(i = 0; i < cnt; i++) { t = vec[i]; - if(!transport_start(t, weight, 0)) + if((r = transport_start(t, weight, 0)) == 0) return t; + error = r; + if(loginfo != NULL) + tvhlog(LOG_NOTICE, "Transport", + "%s: Skipping \"%s\" -- %s", + loginfo, transport_nicename(t), transport_nostart2txt(r)); } + if(errorp != NULL) + *errorp = error; return NULL; } diff --git a/src/transports.h b/src/transports.h index 775ca922..c215a9b0 100644 --- a/src/transports.h +++ b/src/transports.h @@ -23,6 +23,13 @@ #include "htsmsg.h" #include "subscriptions.h" +#define TRANSPORT_NOSTART_NO_HARDWARE 1 +#define TRANSPORT_NOSTART_MUX_NOT_ENABLED 2 +#define TRANSPORT_NOSTART_NOT_FREE 3 +#define TRANSPORT_NOSTART_TUNING_FAILED 4 +#define TRANSPORT_NOSTART_SVC_NOT_ENABLED 5 +#define TRANSPORT_NOSTART_BAD_SIGNAL 6 + void transport_init(void); unsigned int transport_compute_weight(struct th_transport_list *head); @@ -40,7 +47,8 @@ th_transport_t *transport_find_by_identifier(const char *identifier); void transport_map_channel(th_transport_t *t, channel_t *ch, int save); -th_transport_t *transport_find(channel_t *ch, unsigned int weight); +th_transport_t *transport_find(channel_t *ch, unsigned int weight, + const char *loginfo, int *errorp); th_stream_t *transport_stream_find(th_transport_t *t, int pid); @@ -97,4 +105,6 @@ const char *transport_nicename(th_transport_t *t); const char *transport_component_nicename(th_stream_t *st); +const char *transport_nostart2txt(int code); + #endif /* TRANSPORTS_H */