From d00a86667ce6381d3fda35e0b2536158921f2ad5 Mon Sep 17 00:00:00 2001 From: Guillaume Knispel Date: Thu, 12 Jul 2012 15:24:51 +0200 Subject: some debug code (mainly?) --- tdm/xivo_tdm.c | 229 +++++++++++++++++++++++++++++++++++++++++++++++++++++---- 1 file changed, 214 insertions(+), 15 deletions(-) diff --git a/tdm/xivo_tdm.c b/tdm/xivo_tdm.c index ed9c4a3..c814a4b 100644 --- a/tdm/xivo_tdm.c +++ b/tdm/xivo_tdm.c @@ -26,6 +26,7 @@ #include #include #include +#include #include #include @@ -33,6 +34,36 @@ #include + +#define DEBUGFS_MY_STUFF +// #undef DEBUGFS_MY_STUFF + + + +#ifdef DEBUGFS_MY_STUFF + +#define TRACE_BUF_SIZE 32768 + +static unsigned debug_buffer[TRACE_BUF_SIZE + 42]; +static int debug_index; +static spinlock_t debug_lock ____cacheline_aligned; + +static struct hrtimer debug_timer; + +static ktime_t debug_interval; +static ktime_t ktime_prev; + +static void debug_trace_push_ts(void); +static void debug_trace_push_value(u32 value); + +#else // !DEBUGFS_MY_STUFF + +static inline void debug_trace_push_ts(void) {} +static inline void debug_trace_push_value(u32 value) {} + +#endif // DEBUGFS_MY_STUFF + + /* GRUIK HACK UGLY grrrr: */ #define REF_0_0 #undef REF_1_1 @@ -71,9 +102,6 @@ MODULE_PARM_DESC(dump_count, "number of traces to emit " #include // ICP_HSSACC_MAX_NUM_CHANNELS -#define DEBUGFS_MY_STUFF -// #undef DEBUGFS_MY_STUFF - #ifdef DEBUGFS_MY_STUFF # include #endif /* DEBUGFS_MY_STUFF */ @@ -124,10 +152,12 @@ struct xivo_tdm_callbacks_struct { }; static struct xivo_tdm_callbacks_struct xivo_tdm_callbacks; -#define DATA_QUEUE_DEPTH_LOG2 (2) +#define DATA_QUEUE_DEPTH_LOG2 (3) #define DATA_QUEUE_DEPTH (1u << DATA_QUEUE_DEPTH_LOG2) #define DATA_QUEUE_MASK (DATA_QUEUE_DEPTH - 1) +#define TX_TARGET (7) + /* The multiplication by 2 is for Rx and Tx */ #define DATA_CH_SIZE (2 * DATA_QUEUE_DEPTH * XIVO_TDM_VOICE_CHUNK_SZ) @@ -180,6 +210,7 @@ static u32 global_count; static u32 rxq_empty; static u32 rxq_entries; static u32 ref_ts_not_started; +static unsigned tx_sent[MIN_HSS_PORTS_WANTED][8]; static DECLARE_MUTEX(xivo_tdm_mutex); @@ -216,7 +247,6 @@ static void dealloc_one_chan( printk(KERN_ERR "%s: icp_HssAccChannelDelete returned " "error %d\n", __func__, (int) status); port_ts[chid].port = XIVO_TDM_PORT_TS_FREE; - port_ts[chid].port = XIVO_TDM_PORT_TS_FREE; xtp->ts_allocated &= ~(1u << cnum); xtp->hss_chan_ids[cnum] = 0; } @@ -467,7 +497,8 @@ int xivo_tdm_config_port( icp_status_t status; icp_hssacc_port_config_params_t hss_port_config; - g_leb_cs_debug = leb_cs_debug; + if (leb_cs_debug) + g_leb_cs_debug = leb_cs_debug; if (port_config >= ICP_HSSDRV_PORT_CONFIG_DELIMITER) { printk(KERN_ERR "%s: invalid port config %u\n", @@ -506,7 +537,7 @@ int xivo_tdm_config_port( } if (xtp->port_num == 0 && xivo_tdm_callbacks.port0_configured) { - msleep(3); + msleep(2); xivo_tdm_callbacks.port0_configured( xivo_tdm_callbacks.port0_configured_data); } @@ -808,6 +839,8 @@ static int xivo_tdm_port_txrx( if (!(xivo_tdm_ports[port].ts_started & (1u << port))) // XXX hack ref channel return 0; + debug_trace_push_value(0xD0 | (port << 8) | (tick << 16)); + for (ts = 0; ts < XIVO_TDM_TS_NUM; ts++) { int fill, low; u8 ** readchunk_ptr; @@ -833,6 +866,8 @@ static int xivo_tdm_port_txrx( writechunk_ptr = xivo_tdm_ports[port].writechunk_ptrs[ts]; if (writechunk_ptr) { + unsigned before; + qid = xivo_tdm_qid(port, ts); if (unlikely(qid >= IX_QMGR_MAX_NUM_QUEUES)) panic("WHERE IS MY QUEUE GRRRRRR!\n"); @@ -847,7 +882,8 @@ static int xivo_tdm_port_txrx( IX_QMGR_Q_SHADOW_TAIL_ONLY, num_entries); - if (unlikely(num_entries > local_txq_level(port, ts))) { + if (unlikely(num_entries > + (before = local_txq_level(port, ts)))) { printk(KERN_CRIT "port %d ts %d: mismatch " "local/PIU TXQ!!!\n", @@ -860,14 +896,19 @@ static int xivo_tdm_port_txrx( num_entries; fill = (int)local_txq_level(port, ts); - if (fill == 0) /* underflow */ + if (fill == 0) /* underflow */ xivo_tdm_ports[port].ts_tx_unsync |= (1u << ts); - if (fill <= 3 - tick) { // XXX X-Ref 3 + debug_trace_push_value((0xE0 + ts) | + (num_entries << 8) | + (before << 16) | + (fill << 24)); + + if (fill <= TX_TARGET - tick) { if (xivo_tdm_ports[port].ts_tx_unsync & (1u << ts)) xivo_tdm_ports[port] - .tx_data_cpt[ts].head += 3 - tick; + .tx_data_cpt[ts].head += TX_TARGET - tick; *writechunk_ptr = local_txq_data_head(port, ts); xivo_tdm_ports[port].tx_data_cpt[ts].head++; ts_tx_enqueue |= (1u << ts); @@ -901,7 +942,7 @@ static int xivo_tdm_port_txrx( suppl_sync = 0; if (unlikely((xivo_tdm_ports[port].ts_tx_unsync) & (1u << ts))){ - suppl_sync = 3 - tick; // XXX X-Ref 3 + suppl_sync = TX_TARGET - tick; xivo_tdm_ports[port].ts_tx_unsync &= ~(1u << ts); } @@ -917,6 +958,10 @@ static int xivo_tdm_port_txrx( qe->packet_len = 0; qe->entry_ptr = 0; (*txq_info->queue.byteHead)++; // volatile real counter + if (ts < 8) { + if ((++tx_sent[port][ts]) > 9999) + tx_sent[port][ts] -= 10000; + } } while (unlikely(suppl_sync-- > 0)); } @@ -956,6 +1001,7 @@ void xivo_tdm_trigger_handler(void) if (g_leb_cs_debug) writeb(0, g_leb_cs_debug); + debug_trace_push_ts(); do { const u32 rx_entry = vrxq_info->queue.content[ // volatile @@ -990,6 +1036,10 @@ void xivo_tdm_trigger_handler(void) #else # error XIVO_TDM_VOICE_CHUNK_SZ != 8: update code #endif + + debug_trace_push_value((0xF0 + ts) | (full << 8) + | (local_rxq_level(port, ts) << 16)); + xivo_tdm_ports[port].rx_data_cpt[ts].head++; xivo_tdm_ports[port].rx_data_cpt[ts].tail += full; xivo_tdm_ports[port].err += (full & ~(port ^ ts)); // XXX hack ref channel @@ -1038,10 +1088,12 @@ void xivo_tdm_trigger_handler(void) tick = (int)local_rxq_level(1, 1) - 1; #endif if (tick <= 0) - return; + break; for (port = 0; port < MIN_HSS_PORTS_WANTED; port++) xivo_tdm_port_txrx(port, tick); } while (1); + + debug_trace_push_value((unsigned)-1); } @@ -1224,6 +1276,8 @@ DBG_GLOBAL_ENT #undef G static struct dentry *dbg_all; +static struct dentry *dbg_traces; +static struct dentry *dbg_trace_trigger; #define PORT_LIST \ E(u32, ts_rx_unsync) \ @@ -1261,7 +1315,7 @@ static int dbg_all_show(struct seq_file *f, void *_d) struct trucs_globaux blop; u32 levels_copy[5]; - int i; + int i, ts; unsigned long flags; spin_lock_irqsave(&atom_lock, flags); /* gruik hack */ @@ -1296,7 +1350,9 @@ static int dbg_all_show(struct seq_file *f, void *_d) #define E(t,n) seq_printf(f, " %s: %u\n", #n, deux[i].n); PORT_LIST #undef E - seq_printf(f, "\n"); + for (ts = 0; ts < 8; ts++) + seq_printf(f, "%04u ", tx_sent[i][ts]); + seq_printf(f, "\n\n"); } seq_printf(f, "LOOOOOOOOOOL\n"); @@ -1317,6 +1373,130 @@ static const struct file_operations dbg_all_fops = { .release = single_release, }; +static ssize_t debug_trace_trigger(struct file *f, const char __user *u, + size_t s, loff_t *l) +{ + unsigned long flags; + spin_lock_irqsave(&debug_lock, flags); + if (debug_index < 0) { + debug_index = 0; + hrtimer_start(&debug_timer, debug_interval, HRTIMER_MODE_REL); + } + spin_unlock_irqrestore(&debug_lock, flags); + + if (l) + *l += s; + return s; +} + +static const struct file_operations dbg_trig_fops = { + .owner = THIS_MODULE, + .write = debug_trace_trigger, +}; + +static struct debugfs_blob_wrapper blob = { + .data = debug_buffer, + .size = TRACE_BUF_SIZE * sizeof(debug_buffer[0]), +}; + +// FUCCCCCCCCCCCCCCCCCCCK +// Telephony is fucked up +// I want to suicide, yes +static unsigned +monitor_txq_fill(unsigned port, unsigned ts) +{ + unsigned qid = xivo_tdm_qid(port, ts); + u32 num_entries; + if (unlikely(qid >= IX_QMGR_MAX_NUM_QUEUES)) + return (unsigned)-1; + num_entries = 0; + ixQMgrShadowDeltaGet(qid, IX_QMGR_Q_SHADOW_TAIL_ONLY, + &num_entries); + return local_txq_level(port, ts) - num_entries; +} + +static void debug_trace_push_ts(void) +{ + unsigned long flags; + ktime_t now; + + spin_lock_irqsave(&debug_lock, flags); + + if (debug_index < 0 + || debug_index >= TRACE_BUF_SIZE) { // abstract BUGBUG + spin_unlock_irqrestore(&debug_lock, flags); + return; + } + + now = ktime_get(); + debug_buffer[debug_index++] = ktime_to_ns(ktime_sub(now, ktime_prev)) + | 0xFF000000; + ktime_prev = now; + + spin_unlock_irqrestore(&debug_lock, flags); +} + +static void debug_trace_push_value(u32 value) +{ + unsigned long flags; + spin_lock_irqsave(&debug_lock, flags); + if (debug_index < 0 + || debug_index >= TRACE_BUF_SIZE) { // abstract BUGBUG + spin_unlock_irqrestore(&debug_lock, flags); + return; + } + debug_buffer[debug_index++] = value; + spin_unlock_irqrestore(&debug_lock, flags); +} + +static enum hrtimer_restart debug_trace(struct hrtimer *timer) +{ + unsigned long flags; + ktime_t now; + unsigned rxql, txql, txqfill; + unsigned char *b; + int ts; + + spin_lock_irqsave(&debug_lock, flags); + + if (debug_index < 0 + || debug_index >= TRACE_BUF_SIZE) { // abstract BUGBUG + debug_index = -1; + spin_unlock_irqrestore(&debug_lock, flags); + return HRTIMER_NORESTART; + } + while (debug_index & 3) + debug_buffer[debug_index++] = 0xffffffff; + now = ktime_get(); + debug_buffer[debug_index++] = ktime_to_ns(ktime_sub(now, ktime_prev)); + ktime_prev = now; + rxql = local_rxq_level(0, 0); + txql = local_txq_level(0, 0); + txqfill = monitor_txq_fill(0, 0); + debug_buffer[debug_index++] = rxql | (txql << 8) | (txqfill << 16); + + b = (unsigned char*)&(debug_buffer[debug_index]); + for (ts = 0; ts < 4; ts++) { + u8 tail, head; + unsigned qid = xivo_tdm_qid(0, ts); + if (likely(qid < IX_QMGR_MAX_NUM_QUEUES)) { + IxQMgrQueue *txq_info = &ixQMgrQueues[qid]; + tail = *txq_info->shadowInfo.byteRealTailCounter; + head = *txq_info->queue.byteHead; + } else { + tail = head = 0xff; + } + b[ts * 2] = tail; + b[ts * 2 + 1] = head; + } + debug_index += 2; + + spin_unlock_irqrestore(&debug_lock, flags); + + hrtimer_forward(timer, now, debug_interval); + return HRTIMER_RESTART; +} + #endif /* DEBUGFS_MY_STUFF */ static int __init xivo_tdm_init(void) @@ -1324,6 +1504,12 @@ static int __init xivo_tdm_init(void) int rc; #ifdef DEBUGFS_MY_STUFF + spin_lock_init(&debug_lock); + debug_index = -1; + hrtimer_init(&debug_timer, CLOCK_MONOTONIC, HRTIMER_MODE_REL); + debug_timer.function = debug_trace; + debug_interval = ktime_set(0, 10000); + dbg_dir = debugfs_create_dir("xivo_tdm", NULL); if (dbg_dir) { #define F(t, n) dbg_1_ ## n = debugfs_create_ ## t ( \ @@ -1361,6 +1547,12 @@ static int __init xivo_tdm_init(void) dbg_all = debugfs_create_file("zoby", 0444, dbg_dir, NULL, &dbg_all_fops); + + dbg_traces = debugfs_create_blob("traces", 0444, + dbg_dir, &blob); + + dbg_trace_trigger = debugfs_create_file("dtt", 0220, dbg_dir, + NULL, &dbg_trig_fops); } #endif /* DEBUGFS_MY_STUFF */ @@ -1386,6 +1578,9 @@ static void __exit xivo_tdm_exit(void) xivo_internal_cleanup(); #ifdef DEBUGFS_MY_STUFF + hrtimer_cancel(&debug_timer); + msleep(42); + if (dbg_dir) { #define F(t, n) debugfs_remove(dbg_1_ ## n); DBG_FIELDS @@ -1405,6 +1600,10 @@ static void __exit xivo_tdm_exit(void) debugfs_remove(dbg_all); + debugfs_remove(dbg_traces); + + debugfs_remove(dbg_trace_trigger); + debugfs_remove(dbg_dir); } #endif /* DEBUGFS_MY_STUFF */ -- cgit v1.2.3