WL18xx Driver Debug

From Texas Instruments Wiki
Jump to: navigation, search

Introduction

This page will review the tools and commands available within the WL18xx driver that can help a user debug.


Acquire WL18xx driver and firmware version

You may find the driver and firmware versions available through the commands below:

Driver version

Supported only if version was built using the "./build_wl18xx.sh" script.

root@am335x-evm:~# strings /lib/modules/{kernel version}/updates/drivers/net/wireless/ti/wl18xx/wl18xx.ko | grep 'ol_r8\|Build-' -m1
ol_r8.a9.14

or:

root@am335x-evm:~# strings /lib/modules/{kernel version}/updates/drivers/net/wireless/ti/wl18xx/wl18xx.ko | grep 'R8\|Build-' -m1
R8.4


Firmware version

Prints out MAC FW version and PHY FW version.

root@am335x-evm:~# strings /lib/firmware/ti-connectivity/wl18xx-fw-4.bin | grep Rev
FRev 8.9.0.0.17
FRev 8.2.0.0.212

Debug with Kernel Message

Debug Parameters

WL18xx driver supports a configurable and very detailed debug information.
The log system of WL18xx driver prints only those log output which have an appropriate debug mode. All other debug logs are not printed. In this way, it is possible to receive only necessary debug information. All available debug modes are defined in the compat-wireless/drivers/net/wireless/ti/wlcore/debug.h file

DEBUG_NONE      = 0,
DEBUG_IRQ       = BIT(0),  /* 1 */ 
DEBUG_SPI       = BIT(1),  /* 2 */
DEBUG_BOOT      = BIT(2),  /* 4 */
DEBUG_MAILBOX   = BIT(3),  /* 8 */
DEBUG_TESTMODE  = BIT(4),  /* 16 */
DEBUG_EVENT     = BIT(5),  /* 32 */
DEBUG_TX        = BIT(6),  /* 64 */
DEBUG_RX        = BIT(7),  /* 128 */
DEBUG_SCAN      = BIT(8),  /* 256 */
DEBUG_CRYPT     = BIT(9),  /* 512 */
DEBUG_PSM       = BIT(10), /* 1024 */
DEBUG_MAC80211  = BIT(11), /* 2048 */
DEBUG_CMD       = BIT(12), /* 4096 */
DEBUG_ACX       = BIT(13), /* 8192 */
DEBUG_SDIO      = BIT(14), /* 16384 */
DEBUG_FILTERS   = BIT(15), /* 32768 */
DEBUG_ADHOC     = BIT(16), /* 65536 */
DEBUG_AP        = BIT(17), /* 131072 */
DEBUG_PROBE     = BIT(18), /* 262144 */
DEBUG_IO        = BIT(19), /* 524288 */
DEBUG_MASTER    = (DEBUG_ADHOC | DEBUG_AP), /* 196608 */
DEBUG_ALL       = ~0,

Activation of debug print out

  • To instruct kernel to send log messages to the console, do following:
echo 8 > /proc/sys/kernel/printk
  • To configure debug mode of the driver write one of the above debug category number to /sys/module/wl12xx/parameters/debug_level file. For example, this following command will configures driver to print debug messages related to scanning operation - DEBUG_SCAN.
echo 256 > /sys/module/wlcore/parameters/debug_level

Alternatively, you may enter hex number instead of decimal.

echo 0x100 > /sys/module/wlcore/parameters/debug_level
  • Reading log messages is done by opening /proc/kmsg.
root@am37x-evm:~# cat /proc/kmsg &

In this example when we run "iw wlan0 scan", the debug messages related to scan operation (DEBUG_SCAN) will be printed from /proc/kmsg:

root@am335x-evm:~# iw wlan0 scan > /dev/null
[ 3132.079650] wlcore: normal scan role_id 0
[ 3132.083862] wlcore: freq 2467, ch. 012, flags 0x36, power 20, min/max_dwell 25/50, PASSIVE
[ 3132.092529] wlcore: freq 2472, ch. 013, flags 0x36, power 20, min/max_dwell 25/50, PASSIVE
[ 3132.101165] wlcore: freq 2484, ch. 014, flags 0x36, power 20, min/max_dwell 25/50, PASSIVE
[ 3132.109802] wlcore: freq 2412, ch. 001, flags 0x20, power 20, min/max_dwell 25/50
[ 3132.117614] wlcore: freq 2417, ch. 002, flags 0x20, power 20, min/max_dwell 25/50
[ 3132.125427] wlcore: freq 2422, ch. 003, flags 0x20, power 20, min/max_dwell 25/50
[ 3132.133239] wlcore: freq 2427, ch. 004, flags 0x20, power 20, min/max_dwell 25/50
[ 3132.141052] wlcore: freq 2432, ch. 005, flags 0x00, power 20, min/max_dwell 25/50
[ 3132.148864] wlcore: freq 2437, ch. 006, flags 0x00, power 20, min/max_dwell 25/50
[ 3132.156677] wlcore: freq 2442, ch. 007, flags 0x00, power 20, min/max_dwell 25/50
[ 3132.164489] wlcore: freq 2447, ch. 008, flags 0x10, power 20, min/max_dwell 25/50
[ 3132.172332] wlcore: freq 2452, ch. 009, flags 0x10, power 20, min/max_dwell 25/50
[ 3132.180145] wlcore: freq 2457, ch. 010, flags 0x10, power 20, min/max_dwell 25/50
[ 3132.187957] wlcore: freq 2462, ch. 011, flags 0x10, power 20, min/max_dwell 25/50
[ 3132.195770] wlcore:     2.4GHz: active 11 passive 3
[ 3132.200866] wlcore:     5GHz: active 0 passive 0
[ 3132.205688] wlcore:     DFS: 0
[ 3132.208862] wlcore: build probe request band 0
7>[ 3132.079650] wlcore: normal scan role_id 0
<7>[ 3132.083862] wlcore: freq 2467, ch. 012, flags 0x36, power 20, min/max_dwell 25/50, PASSIVE
<7>[ 3132.092529] wlcore: freq 2472, ch. 013, flags 0x36, power 20, min/max_dwell 25/50, PASSIVE
<7>[ 3132.101165] wlcore: freq 2484, ch. 014, flags 0x36, power 20, min/max_dwell 25/50, PASSIVE
<7>[ 3132.109802] wlcore: freq 2412, ch. 001, flags 0x20, power 20, min/max_dwell 25/50
<7>[ 3132.117614] wlcore: freq 2417, ch. 002, flags 0x20, power 20, min/max_dwell 25/50
<7>[ 3132.125427] wlcore: freq 2422, ch. 003, flags 0x20, power 20, min/max_dwell 25/50
<7>[ 3132.133239] wlcore: freq 2427, ch. 004, flags 0x20, power 20, min/max_dwell 25/50
<7>[ 3132.141052] wlcore: freq 2432, ch. 005, flags 0x00, power 20, min/max_dwell 25/50
<7>[ 3132.148864] wlcore: freq 2437, ch. 006, flags 0x00, power 20, min/max_dwell 25/50
<7>[ 3132.156677] wlcore: freq 2442, ch. 007, flags 0x00, power 20, min/max_dwell 25/50
<7>[ 3132.164489] wlcore: freq 2447, ch. 008, flags 0x10, power 20, min/max_dwell 25/50
<7>[ 3132.172332] wlcore: freq 2452, ch. 009, flags 0x10, power 20, min/max_dwell 25/50
<7>[ 3132.180145] wlcore: freq 2457, ch. 010, flags 0x10, power 20, min/max_dwell 25/50
<7>[ 3132.187957] wlcore: freq 2462, ch. 011, flags 0x10, power 20, min/max_dwell 25/50
<7>[ 3132.195770] wlcore:     2.4GHz: active 11 passive 3
<7>[ 3132.200866] wlcore:     5GHz: active 0 passive 0
<7>[ 3132.205688] wlcore:     DFS: 0
<7>[ 3132.208862] wlcore: build probe request band 0
[ 3133.002990] wlcore: Scanning complete
<7>[ 3133.002990[ 3133.007568] wlcore: normal scan role_id 0
] wlcore: Scanni[ 3133.012573] wlcore: freq 5190, ch. 038, flags 0x26, power 20, min/max_dwell 25/50, PASSIVE
ng complete
[ 3133.022583] wlcore: freq 5200, ch. 040, flags 0x06, power 20, min/max_dwell 25/50, PASSIVE
[ 3133.032318] wlcore: freq 5210, ch. 042, flags 0x06, power 20, min/max_dwell 25/50, PASSIVE
[ 3133.040954] wlcore: freq 5220, ch. 044, flags 0x06, power 20, min/max_dwell 25/50, PASSIVE
[ 3133.049591] wlcore: freq 5230, ch. 046, flags 0x16, power 20, min/max_dwell 25/50, PASSIVE
[ 3133.058227] wlcore: freq 5240, ch. 048, flags 0x16, power 20, min/max_dwell 25/50, PASSIVE
[ 3133.066833] wlcore: freq 5745, ch. 149, flags 0x26, power 20, min/max_dwell 25/50, PASSIVE
[ 3133.075469] wlcore: freq 5765, ch. 153, flags 0x06, power 20, min/max_dwell 25/50, PASSIVE
[ 3133.084106] wlcore: freq 5785, ch. 157, flags 0x06, power 20, min/max_dwell 25/50, PASSIVE
[ 3133.092742] wlcore: freq 5805, ch. 161, flags 0x06, power 20, min/max_dwell 25/50, PASSIVE
[ 3133.101379] wlcore: freq 5825, ch. 165, flags 0x16, power 20, min/max_dwell 25/50, PASSIVE
[ 3133.110015] wlcore: freq 5180, ch. 036, flags 0x20, power 20, min/max_dwell 25/50
[ 3133.117828] wlcore:     2.4GHz: active 0 passive 0
[ 3133.122833] wlcore:     5GHz: active 1 passive 11
[ 3133.127746] wlcore:     DFS: 0
[ 3133.130920] wlcore: build probe request band 1
<7>[ 3133.007568] wlcore: normal scan role_id 0
<7>[ 3133.012573] wlcore: freq 5190, ch. 038, flags 0x26, power 20, min/max_dwell 25/50, PASSIVE
<7>[ 3133.022583] wlcore: freq 5200, ch. 040, flags 0x06, power 20, min/max_dwell 25/50, PASSIVE
<7>[ 3133.032318] wlcore: freq 5210, ch. 042, flags 0x06, power 20, min/max_dwell 25/50, PASSIVE
<7>[ 3133.040954] wlcore: freq 5220, ch. 044, flags 0x06, power 20, min/max_dwell 25/50, PASSIVE
<7>[ 3133.049591] wlcore: freq 5230, ch. 046, flags 0x16, power 20, min/max_dwell 25/50, PASSIVE
<7>[ 3133.058227] wlcore: freq 5240, ch. 048, flags 0x16, power 20, min/max_dwell 25/50, PASSIVE
<7>[ 3133.066833] wlcore: freq 5745, ch. 149, flags 0x26, power 20, min/max_dwell 25/50, PASSIVE
<7>[ 3133.075469] wlcore: freq 5765, ch. 153, flags 0x06, power 20, min/max_dwell 25/50, PASSIVE
<7>[ 3133.084106] wlcore: freq 5785, ch. 157, flags 0x06, power 20, min/max_dwell 25/50, PASSIVE
<7>[ 3133.092742] wlcore: freq 5805, ch. 161, flags 0x06, power 20, min/max_dwell 25/50, PASSIVE
<7>[ 3133.101379] wlcore: freq 5825, ch. 165, flags 0x16, power 20, min/max_dwell 25/50, PASSIVE
<7>[ 3133.110015] wlcore: freq 5180, ch. 036, flags 0x20, power 20, min/max_dwell 25/50
<7>[ 3133.117828] wlcore:     2.4GHz: active 0 passive 0
<7>[ 3133.122833] wlcore:     5GHz: active 1 passive 11
<7>[ 3133.127746] wlcore:     DFS: 0
<7>[ 3133.130920] wlcore: build probe request band 1
[ 3134.271667] wlcore: Scanning complete


Dynamic Debug

WL18xx driver uses Linux kernel dynamic debug mechanism (debugfs) but it implements its own interface above. To enable debug output, the whole module has to be enabled in the dynamic debug Linux kernel subsystem and configuring the specific debug information one might be interested in is done via driver debug categories.
To configure debug output using dynamic debug subsystem, the following steps have to done:

  1. mount debugfs (this should have been done by system automatically)Type: mount -t debugfs none /sys/kernel/debug
  2. enable kernel print out
  3. enable debug output for either of wl12xx,mac80211, cfg80211 modules, or for all of them.
  4. write the required debug category to /sys/module/wl12xx/parameters/debug_level file.
  • Enable the dynamic debug statistics type the following after bring the wlan0 interface up.
root@am335x-evm:~# ifconfig wlan0 up
[  382.611846] wlcore: PHY firmware version: Rev 8.2.0.0.212
[  382.708557] wlcore: firmware booted (Rev 8.9.0.0.17)
root@am335x-evm:~# echo 8 > /proc/sys/kernel/printk
root@am335x-evm:~# echo 0x8800 > /sys/module/wlcore/parameters/debug_level
root@am335x-evm:~# echo -n 'module wlcore +p' > /sys/kernel/debug/dynamic_debug/control
root@am335x-evm:~# echo -n 'module wl18xx +p' > /sys/kernel/debug/dynamic_debug/control
root@am335x-evm:~# echo -n 'module mac80211 +p' > /sys/kernel/debug/dynamic_debug/control
root@am335x-evm:~# echo -n 'module cfg80211 +p' > /sys/kernel/debug/dynamic_debug/control
  • Compilation switch: dynamic debug option should be enabled in the Driver. Make sure the following parameter is set to "y"
root@am335x-evm:~# cat /proc/config.gz | gunzip | grep CONFIG_DYNAMIC_DEBUG
# CONFIG_DYNAMIC_DEBUG=y
  • Navigate to interface debug directory. You can see debug information by performing "cat" on any files. In this example, we performed "cat driver_state" to exam driver information.
root@am335x-evm:~# cd /sys/kernel/debug/ieee80211/phy0/wlcore/
root@am335x-evm:/sys/kernel/debug/ieee80211/phy0/wlcore# ls
beacon_filtering       gpio_power             split_scan_timeout
beacon_interval        irq_blk_threshold      start_recovery
driver_state           irq_pkt_threshold      stats_tx_aggr
dtim_interval          irq_timeout            suspend_dtim_interval
dynamic_ps_timeout     mem                    tx_queue_len
excessive_retries      retry_count            vifs_state
forced_ps              rx_streaming           wl18xx
fw_stats_raw           sleep_auth
root@am335x-evm:/sys/kernel/debug/ieee80211/phy0/wlcore# cat driver_state
version = ol_r8.a9.14
timestamp = Fri Jun 26 10:42:35 2014
tx_blocks_available = 44
tx_allocated_blocks = 0
tx_allocated_pkts[0] = 0
tx_allocated_pkts[1] = 0
tx_allocated_pkts[2] = 0
tx_allocated_pkts[3] = 0
tx_frames_cnt = 0
tx_frames_map[0] = 0x0
tx_queue_count[0] = 0
tx_queue_count[1] = 0
tx_queue_count[2] = 0
tx_queue_count[3] = 0
tx_packets_count = 0
tx_results_count = 0
flags = 0x19
tx_blocks_freed = 0
rx_counter = 0
state = 2
band = 0
power_level = 0
sg_enabled = 1
enable_11a = 1
noise = 0
ap_fw_ps_map = 0x0
ap_ps_map = 0x0
quirks = 0xe8c
irq = 0xc7
hw_pg_ver = 0x2
platform_quirks = 0x1
chip.id = 0x6030111
chip.fw_ver_str = Rev 8.6.0.0.5
chip.phy_fw_ver_str = Rev 8.2.0.0.168
recovery_count = 0
  • You may also navigate to firmware debug directory for firmware information.
root@am335x-evm:/sys/kernel/debug/ieee80211/phy0/wlcore# cd wl18xx/fw_stats/
root@am335x-evm:/sys/kernel/debug/ieee80211/phy0/wlcore/wl18xx/fw_stats# ls
aggr_size_rx_size                   rx_filter_dup_filter
aggr_size_tx_agg_vs_rate            rx_filter_ibss_filter
clear_fw_stats                      rx_filter_max_arp_queue_dep
debug_debug1                        rx_filter_mc_filter
debug_debug2                        rx_filter_protection_filter
debug_debug3                        rx_rate_rx_frames_per_rates
debug_debug4                        rx_rx_beacon_early_term
debug_debug5                        rx_rx_checksum_result
debug_debug6                        rx_rx_cmplt
error_error_bar_retry               rx_rx_cmplt_task
error_error_frame                   rx_rx_defrag
error_error_frame_cts_nul_flid      rx_rx_defrag_end
error_error_null_Frame_tx_start     rx_rx_done
error_error_numll_frame_cts_start   rx_rx_dropped_frame
isr_irqs                            rx_rx_frame_checksum
mem_fw_gen_free_mem_blks            rx_rx_hdr_overflow
mem_fwlog_free_mem_blks             rx_rx_out_of_mpdu_nodes
mem_rx_free_mem_blks                rx_rx_phy_hdr
mem_tx_free_mem_blks                rx_rx_pre_complt
pipeline_cs_rx_packet_in            rx_rx_timeout
pipeline_cs_rx_packet_out           rx_rx_timeout_wa
pipeline_csum_to_rx_xfer_swi        rx_rx_tkip_replays
pipeline_dec_packet_in              rx_rx_wa_ba_not_expected
pipeline_dec_packet_in_fifo_full    rx_rx_wa_density_dropped_frame
pipeline_dec_packet_out             tx_frag_bad_mblk_num
pipeline_defrag_to_csum_swi         tx_frag_cache_hit
pipeline_enc_rx_stat_fifo_int       tx_frag_cache_miss
pipeline_enc_tx_stat_fifo_int       tx_frag_called
pipeline_hs_tx_stat_fifo_int        tx_frag_failed
pipeline_pipeline_fifo_full         tx_frag_in_process_called
pipeline_post_proc_swi              tx_frag_init_called
pipeline_pre_proc_swi               tx_frag_key_not_found
pipeline_pre_to_defrag_swi          tx_frag_mpdu_alloc_failed
pipeline_rx_complete_stat_fifo_int  tx_frag_need_fragmentation
pipeline_sec_frag_swi               tx_frag_tkip_called
pipeline_tcp_rx_stat_fifo_int       tx_tx_burst_programmed
pipeline_tcp_tx_stat_fifo_int       tx_tx_checksum_result
ps_poll_ps_poll_max_ap_turn         tx_tx_cmplt
ps_poll_ps_poll_timeouts            tx_tx_data_prepared
ps_poll_ps_poll_utilization         tx_tx_data_programmed
ps_poll_upsd_max_ap_turn            tx_tx_done_data
ps_poll_upsd_timeouts               tx_tx_done_int_template
ps_poll_upsd_utilization            tx_tx_done_template
pwr_connection_out_of_sync          tx_tx_exch
pwr_cont_miss_bcns_spread           tx_tx_exch_expiry
pwr_missing_bcns_cnt                tx_tx_exch_pending
pwr_rcvd_awake_bcns_cnt             tx_tx_frame_checksum
pwr_rcvd_bcns_cnt                   tx_tx_imm_resp
rx_decrypt_key_not_found            tx_tx_prepared_descs
rx_defrag_called                    tx_tx_retry_data
rx_defrag_decrypt_failed            tx_tx_retry_template
rx_defrag_in_process_called         tx_tx_start_data
rx_defrag_init_called               tx_tx_start_fw_gen
rx_defrag_need_decrypt              tx_tx_start_int_templates
rx_defrag_need_defrag               tx_tx_start_null_frame
rx_defrag_tkip_called               tx_tx_start_templates
rx_filter_accum_arp_pend_requests   tx_tx_starts
rx_filter_arp_filter                tx_tx_template_prepared
rx_filter_beacon_filter             tx_tx_template_programmed
rx_filter_data_filter


802.11 events

Listening to 802.11 events:

iw event

When debugging, it can be useful to see the auth/assoc/deauth/disassoc frames, use

iw event -f

and sometimes timing information is also useful:

iw event -t

you can also get very helpful nl80211 events using this command:

iw event -t -f


Debug Commands

Mount Debug Folder
mkdir -p /debug
mount -t debugfs none /debug/


Increase Debug Level
echo -n 'module wlcore +p' > /sys/kernel/debug/dynamic_debug/control
echo -n 'module wl18xx +p' > /sys/kernel/debug/dynamic_debug/control
echo -n 'module mac80211 +p' > /sys/kernel/debug/dynamic_debug/control
echo -n 'module cfg80211 +p' > /sys/kernel/debug/dynamic_debug/control
echo 0x1840 > /sys/module/wlcore/parameters/debug_level
echo 8 > /proc/sys/kernel/printk
Reset DFS channels state
echo 1 > /sys/kernel/debug/ieee80211/phy0/dfs_reset

The number is a bitmap: bit0 - reset all AVAILABLE dfs channels (to USABLE) bit1 - reset all UNAVAILABLE dfs channels (to USABLE)


Trigger a debug radar detection command
echo 60 > /sys/kernel/debug/ieee80211/phy0/wlcore/wl18xx/radar_detection

The number is the channel. Note:

 * Trying to trigger a radar on non operational channel will results with no command
 * For 40Mhz: trigger the radar on the primary channel only


Disable/Enable ELP

Disable ELP:

iw wlan0 set power_save off
echo 0 > /sys/kernel/debug/ieee80211/phy0/wlcore/sleep_auth

Enable ELP:

iw wlan0 set power_save on
echo 2 > /sys/kernel/debug/ieee80211/phy0/wlcore/sleep_auth


Trigger a debug recovery
echo 1 > /sys/kernel/debug/ieee80211/phy0/wlcore/start_recovery


Configure force power save mode
echo 1 > /sys/kernel/debug/ieee80211/phy0/wlcore/forced_ps