From 14f4bb38628da19b69b3bae46e762be9f81f2e8c Mon Sep 17 00:00:00 2001 From: Francis Galiegue Date: Thu, 8 May 2008 20:23:21 +0200 Subject: [PATCH] Reinclude the log framework, working version for David Plamella. Testified to have worked with WPA2 STA association for more than a minute, which is good enough, I guess ;) --- Makefile | 2 +- acx_config.h | 6 - acx_debug.h | 158 +++----------- acx_func.h | 22 +- acx_log.h | 104 +++++++++ acx_struct.h | 2 + common.c | 662 ++++++++++++++++++++++++++++----------------------------- log.c | 240 +++++++++++++++++++++ pci.c | 679 +++++++++++++++++++++++++++++++++-------------------------- usb.c | 278 ++++++++++++------------ 10 files changed, 1226 insertions(+), 927 deletions(-) rewrite acx_debug.h (91%) create mode 100644 acx_log.h create mode 100644 log.c diff --git a/Makefile b/Makefile index 529a804..44c35b0 100644 --- a/Makefile +++ b/Makefile @@ -7,7 +7,7 @@ #acx-mac80211-objs := common.o $(acx-mac80211-obj-y) obj-m = acx-mac80211.o -acx-mac80211-objs := common.o pci.o #usb.o +acx-mac80211-objs := common.o pci.o log.o #usb.o # Use this if you have proper Kconfig integration: diff --git a/acx_config.h b/acx_config.h index 7fb023f..369d0ea 100644 --- a/acx_config.h +++ b/acx_config.h @@ -7,12 +7,6 @@ #define ACX_RELEASE "v0.3.38-mac80211" -/* set to 0 if you don't want any debugging code to be compiled in */ -/* set to 1 if you want some debugging */ -/* set to 2 if you want extensive debug log */ -#define ACX_DEBUG 2 -#define ACX_DEFAULT_MSG (L_ASSOC|L_INIT) - /* assume 32bit I/O width * (16bit is also compatible with Compact Flash) */ #define ACX_IO_WIDTH 32 diff --git a/acx_debug.h b/acx_debug.h dissimilarity index 91% index 6940039..ba35870 100644 --- a/acx_debug.h +++ b/acx_debug.h @@ -1,131 +1,27 @@ -#ifndef _ACX_DEBUG_H_ -#define _ACX_DEBUG_H_ - -/* - * acx_debug.h: logging constants and helpers - * - * Copyright (c) 2008, the ACX100 project (http://acx100.sourceforge.net). - * - * See the README file for licensing. -*/ - -#include "acx.h" - -/*********************************************************************** -** Debug / log functionality -*/ -enum { - L_LOCK = (ACX_DEBUG>1)*0x0001, /* locking debug log */ - L_INIT = (ACX_DEBUG>0)*0x0002, /* special card initialization logging */ - L_IRQ = (ACX_DEBUG>0)*0x0004, /* interrupt stuff */ - L_ASSOC = (ACX_DEBUG>0)*0x0008, /* assocation (network join) and station log */ - L_FUNC = (ACX_DEBUG>1)*0x0020, /* logging of function enter / leave */ - L_XFER = (ACX_DEBUG>1)*0x0080, /* logging of transfers and mgmt */ - L_DATA = (ACX_DEBUG>1)*0x0100, /* logging of transfer data */ - L_DEBUG = (ACX_DEBUG>1)*0x0200, /* log of debug info */ - L_IOCTL = (ACX_DEBUG>0)*0x0400, /* log ioctl calls */ - L_CTL = (ACX_DEBUG>1)*0x0800, /* log of low-level ctl commands */ - L_BUFR = (ACX_DEBUG>1)*0x1000, /* debug rx buffer mgmt (ring buffer etc.) */ - L_XFER_BEACON = (ACX_DEBUG>1)*0x2000, /* also log beacon packets */ - L_BUFT = (ACX_DEBUG>1)*0x4000, /* debug tx buffer mgmt (ring buffer etc.) */ - L_USBRXTX = (ACX_DEBUG>0)*0x8000, /* debug USB rx/tx operations */ - L_BUF = L_BUFR + L_BUFT, - L_ANY = 0xffff -}; - -#if ACX_DEBUG -extern unsigned int acx_debug; -#else -enum { acx_debug = 0 }; -#endif - -/*********************************************************************** -** LOGGING -** -** - Avoid SHOUTING needlessly. Avoid excessive verbosity. -** Gradually remove messages which are old debugging aids. -** -** - Use printk() for messages which are to be always logged. -** Supply either 'acx:' or ':' prefix so that user -** can figure out who's speaking among other kernel chatter. -** acx: is for general issues (e.g. "acx: no firmware image!") -** while : is related to a particular device -** (think about multi-card setup). Double check that message -** is not confusing to the average user. -** -** - use printk KERN_xxx level only if message is not a WARNING -** but is INFO, ERR etc. -** -** - Use printk_ratelimited() for messages which may flood -** (e.g. "rx DUP pkt!"). -** -** - Use log() for messages which may be omitted (and they -** _will_ be omitted in non-debug builds). Note that -** message levels may be disabled at compile-time selectively, -** thus select them wisely. Example: L_DEBUG is the lowest -** (most likely to be compiled out) -> use for less important stuff. -** -** - Do not print important stuff with log(), or else people -** will never build non-debug driver. -** -** Style: -** hex: capital letters, zero filled (e.g. 0x02AC) -** str: dont start from capitals, no trailing periods ("tx: queue is stopped") -*/ -#if ACX_DEBUG > 1 - -void log_fn_enter(const char *funcname); -void log_fn_exit(const char *funcname); -void log_fn_exit_v(const char *funcname, int v); - -#define FN_ENTER \ - do { \ - if (unlikely(acx_debug & L_FUNC)) { \ - log_fn_enter(__func__); \ - } \ - } while (0) - -#define FN_EXIT1(v) \ - do { \ - if (unlikely(acx_debug & L_FUNC)) { \ - log_fn_exit_v(__func__, v); \ - } \ - } while (0) -#define FN_EXIT0 \ - do { \ - if (unlikely(acx_debug & L_FUNC)) { \ - log_fn_exit(__func__); \ - } \ - } while (0) - -#else - -#define FN_ENTER do {} while(0) -#define FN_EXIT1(v) do {} while(0) -#define FN_EXIT0 do {} while(0) - -#endif /* ACX_DEBUG > 1 */ - - -#if ACX_DEBUG - -#define log(chan, args...) \ - do { \ - if (acx_debug & (chan)) \ - printk(args); \ - } while (0) -#define printk_ratelimited(args...) printk(args) - -#else /* Non-debug build: */ - -#define log(chan, args...) -/* Standard way of log flood prevention */ -#define printk_ratelimited(args...) \ -do { \ - if (printk_ratelimit()) \ - printk(args); \ -} while (0) - -#endif /* ACX_DEBUG */ - -#endif /* _ACX_DEBUG_H_ */ +#ifndef _ACX_DEBUG_H_ +#define _ACX_DEBUG_H_ + +/* + * acx_debug.h: logging constants and helpers + * + * Copyright (c) 2008, the ACX100 project (http://acx100.sourceforge.net). + * + * See the README file for licensing. +*/ + +/* + * ACX_DEBUG: + * set to 0 if you don't want any debugging code to be compiled in + * set to 1 if you want some debugging + * set to 2 if you want extensive debug log + */ +#define ACX_DEBUG 2 +#define ACX_DEFAULT_MSG (L_INIT|L_IRQ|L_ASSOC) + +#if ACX_DEBUG +extern unsigned int acx_debug; +#else +enum { acx_debug = 0 }; +#endif + +#endif /* _ACX_DEBUG_H_ */ diff --git a/acx_func.h b/acx_func.h index 25d3b7a..8782176 100644 --- a/acx_func.h +++ b/acx_func.h @@ -7,18 +7,11 @@ #include #include "acx_debug.h" +#include "acx_log.h" void acx_print_mac(const char *head, const u8 *mac, const char *tail); /* Optimized out to nothing in non-debug build */ -static inline void -acxlog_mac(int level, const char *head, const u8 *mac, const char *tail) -{ - if (acx_debug & level) { - acx_print_mac(head, mac, tail); - } -} - /*********************************************************************** ** MAC address helpers @@ -80,15 +73,6 @@ mac_is_mcast(const u8 *mac) return (mac[0] & 1) && !mac_is_bcast(mac); } -#define MACSTR "%02X:%02X:%02X:%02X:%02X:%02X" -#define MAC(bytevector) \ - ((unsigned char *)bytevector)[0], \ - ((unsigned char *)bytevector)[1], \ - ((unsigned char *)bytevector)[2], \ - ((unsigned char *)bytevector)[3], \ - ((unsigned char *)bytevector)[4], \ - ((unsigned char *)bytevector)[5] - /*********************************************************************** ** Random helpers @@ -243,7 +227,7 @@ acx_stop_queue(struct ieee80211_hw *hw, const char *msg) */ ieee80211_stop_queues(hw); if (msg) - log(L_BUFT, "tx: stop queue %s\n", msg); + acx_log(LOG_DEBUG, L_BUFT, "tx: stop queue %s\n", msg); } /*static inline int @@ -266,7 +250,7 @@ acx_wake_queue(struct ieee80211_hw *hw, const char *msg) { ieee80211_wake_queues(hw); if (msg) - log(L_BUFT, "tx: wake queue %s\n", msg); + acx_log(LOG_DEBUG, L_BUFT, "tx: wake queue %s\n", msg); } /* static inline void diff --git a/acx_log.h b/acx_log.h new file mode 100644 index 0000000..60427f2 --- /dev/null +++ b/acx_log.h @@ -0,0 +1,104 @@ +#ifndef _ACX_LOG_H_ +#define _ACX_LOG_H_ + +/* + * acx_log.h: logging constants and functions. + * + * Copyright (c) 2008, the ACX100 project (http://acx100.sourceforge.net). + * + * See the README file for licensing. + */ + +/* + * For KERN_*, and printk() + */ +#include + +/* + * The acx_debug.h file defines the log level and default log mask. + */ +#include "acx_debug.h" + +#define ACX_LOG_LEVEL ACX_DEBUG + +/* + * Helpers to log MAC addresses + */ + +#define MACSTR "%02X:%02X:%02X:%02X:%02X:%02X" +#define MAC(bytevector) \ + ((unsigned char *)bytevector)[0], \ + ((unsigned char *)bytevector)[1], \ + ((unsigned char *)bytevector)[2], \ + ((unsigned char *)bytevector)[3], \ + ((unsigned char *)bytevector)[4], \ + ((unsigned char *)bytevector)[5] + +/* + * What to log. + */ +#define L_LOCK 0x0001 /* Locking */ +#define L_INIT 0x0002 /* Card initialization */ +#define L_IRQ 0x0004 /* Interrupt handling */ +#define L_ASSOC 0x0008 /* Assocation (network join) and station log */ +#define L_FUNC 0x0010 /* Function enter/leave */ +#define L_XFER 0x0020 /* TX management */ +#define L_DATA 0x0040 /* Data transfer */ +#define L_IOCTL 0x0080 /* Log ioctl calls */ +#define L_CTL 0x0100 /* Log of low-level ctl commands */ +#define L_BUFR 0x0200 /* Debug rx buffer mgmt (ring buffer etc.) */ +#define L_XFER_BEACON 0x0400 /* Also log beacon packets */ +#define L_BUFT 0x0800 /* Debug tx buffer mgmt (ring buffer etc.) */ +#define L_USBRXTX 0x1000 /* Debug USB rx/tx operations */ +#define L_BUF (L_BUFR|L_BUFT) +#define L_REALLYVERBOSE 0x2000 /* Flood me, baby! */ +#define L_ANY 0xffff + +/* + * Log levels. + */ +#define LOG_WARNING 0 +#define LOG_INFO 1 +#define LOG_DEBUG 2 + +#define MAX_LOG_LEVEL 2 + +/* + * Function declarations. + * + * The acx_log_dump() function also dumps a buffer taken as an argument. + */ + +void acx_log(int level, int what, const char *fmt, ...); +void acx_log_ratelimited(int level, int what, const char *fmt, ...); +void acx_log_dump(int level, int what, const void *buf, ssize_t buflen, + const char *fmt, ...); + +#if ACX_LOG_LEVEL == 2 + +#define __FUNCTION_ENTER 0 +#define __FUNCTION_EXIT 1 +#define __FUNCTION_EXIT_WITHARG 2 + +void __function_enter_exit(const char *, int, int); +#define FN_ENTER do { \ + __function_enter_exit(__func__, __FUNCTION_ENTER, 0); \ +} while (0) + +#define FN_EXIT0 do { \ + __function_enter_exit(__func__, __FUNCTION_EXIT, 0); \ +} while (0) + +#define FN_EXIT1(retcode) do { \ + __function_enter_exit(__func__, __FUNCTION_EXIT_WITHARG, retcode); \ +} while (0) + +#else + +#define FN_ENTER do {} while(0) +#define FN_EXIT do {} while(0) +#define FN_EXIT1(retcode) do {} while(0) + +#endif /* ACX_LOG_LEVEL == 2 */ + +#endif /* _ACX_LOG_H_ */ diff --git a/acx_struct.h b/acx_struct.h index a360de2..4ab219a 100644 --- a/acx_struct.h +++ b/acx_struct.h @@ -5,6 +5,8 @@ ** Copyright (C) 2003 ACX100 Open Source Project */ +#include "acx_debug.h" + /*********************************************************************** ** Forward declarations of types */ diff --git a/common.c b/common.c index a7381ff..5606147 100644 --- a/common.c +++ b/common.c @@ -23,6 +23,8 @@ //#include #include "acx.h" +#include "acx_debug.h" +#include "acx_log.h" /*********************************************************************** @@ -149,8 +151,9 @@ void acx_unlock_debug(acx_device_t * adev, const char *where) diff -= adev->lock_time; if (diff > max_lock_time) { where = sanitize_str(where); - printk("max lock hold time %ld CPU ticks from %s " - "to %s\n", diff, adev->last_lock, where); + acx_log(LOG_DEBUG, L_LOCK, "max lock hold time " + "%ld CPU ticks from %s to %s\n", diff, + adev->last_lock, where); max_lock_time = diff; } } @@ -158,67 +161,6 @@ void acx_unlock_debug(acx_device_t * adev, const char *where) #endif /* PARANOID_LOCKING */ -/*********************************************************************** -*/ -#if ACX_DEBUG > 1 - -static int acx_debug_func_indent; -#define DEBUG_TSC 0 -#define FUNC_INDENT_INCREMENT 2 - -#if DEBUG_TSC -#define TIMESTAMP(d) unsigned long d; rdtscl(d) -#else -#define TIMESTAMP(d) unsigned long d = jiffies -#endif - -static const char spaces[] = " " " "; /* Nx10 spaces */ - -void log_fn_enter(const char *funcname) -{ - int indent; - TIMESTAMP(d); - - indent = acx_debug_func_indent; - if (indent >= sizeof(spaces)) - indent = sizeof(spaces) - 1; - - printk("%08ld %s==> %s\n", - d % 100000000, spaces + (sizeof(spaces) - 1) - indent, funcname); - - acx_debug_func_indent += FUNC_INDENT_INCREMENT; -} -void log_fn_exit(const char *funcname) -{ - int indent; - TIMESTAMP(d); - - acx_debug_func_indent -= FUNC_INDENT_INCREMENT; - - indent = acx_debug_func_indent; - if (indent >= sizeof(spaces)) - indent = sizeof(spaces) - 1; - - printk("%08ld %s<== %s\n", - d % 100000000, spaces + (sizeof(spaces) - 1) - indent, funcname); -} -void log_fn_exit_v(const char *funcname, int v) -{ - int indent; - TIMESTAMP(d); - - acx_debug_func_indent -= FUNC_INDENT_INCREMENT; - - indent = acx_debug_func_indent; - if (indent >= sizeof(spaces)) - indent = sizeof(spaces) - 1; - - printk("%08ld %s<== %s: %08X\n", - d % 100000000, - spaces + (sizeof(spaces) - 1) - indent, funcname, v); -} -#endif /* ACX_DEBUG > 1 */ - /*********************************************************************** ** Basically a mdelay/msleep with logging @@ -275,42 +217,6 @@ const char *acx_cmd_status_str(unsigned int state) } /*********************************************************************** -*/ -#if ACX_DEBUG -void acx_dump_bytes(const void *data, int num) -{ - const u8 *ptr = (const u8 *)data; - - FN_ENTER; - - if (num <= 0) { - printk("\n"); - return; - } - - while (num >= 16) { - printk("%02X %02X %02X %02X %02X %02X %02X %02X " - "%02X %02X %02X %02X %02X %02X %02X %02X\n", - ptr[0], ptr[1], ptr[2], ptr[3], - ptr[4], ptr[5], ptr[6], ptr[7], - ptr[8], ptr[9], ptr[10], ptr[11], - ptr[12], ptr[13], ptr[14], ptr[15]); - num -= 16; - ptr += 16; - } - if (num > 0) { - while (--num > 0) - printk("%02X ", *ptr++); - printk("%02X\n", *ptr); - } - - FN_EXIT0; - -} -#endif - - -/*********************************************************************** ** acx_s_get_firmware_version ** ** Obvious @@ -330,11 +236,11 @@ void acx_s_get_firmware_version(acx_device_t * adev) memcpy(adev->firmware_version, fw.fw_id, FW_ID_SIZE); adev->firmware_version[FW_ID_SIZE] = '\0'; - log(L_DEBUG, "fw_ver: fw_id='%s' hw_id=%08X\n", + acx_log(LOG_DEBUG, L_ANY, "fw_ver: fw_id='%s' hw_id=%08X\n", adev->firmware_version, fw.hw_id); if (strncmp(fw.fw_id, "Rev ", 4) != 0) { - printk("acx: strange firmware version string " + acx_log(LOG_INFO, L_ANY, "acx: strange firmware version string " "'%s', please report\n", adev->firmware_version); adev->firmware_numver = 0x01090407; /* assume 1.9.4.7 */ } else { @@ -358,13 +264,15 @@ void acx_s_get_firmware_version(acx_device_t * adev) adev->firmware_numver = (u32) ((hexarr[0] << 24) | (hexarr[1] << 16) | (hexarr[2] << 8) | hexarr[3]); - log(L_DEBUG, "firmware_numver 0x%08X\n", adev->firmware_numver); + acx_log(LOG_DEBUG, L_ANY, "firmware_numver 0x%08X\n", + adev->firmware_numver); } if (IS_ACX111(adev)) { if (adev->firmware_numver == 0x00010011) { /* This one does not survive floodpinging */ - printk("acx: firmware '%s' is known to be buggy, " - "please upgrade\n", adev->firmware_version); + acx_log(LOG_INFO, L_ANY, "firmware '%s' is known " + "to be buggy, please upgrade\n", + adev->firmware_version); } } @@ -387,8 +295,8 @@ void acx_s_get_firmware_version(acx_device_t * adev) adev->chip_name = "TNETW1450"; break; default: - printk("acx: unknown chip ID 0x%08X, " - "please report\n", adev->firmware_id); + acx_log(LOG_INFO, L_ANY,"unknown chip ID 0x%08X, " + "please report\n", adev->firmware_id); break; } @@ -456,7 +364,7 @@ void acx_display_hardware_details(acx_device_t * adev) break; } - printk("acx: chipset %s, radio type 0x%02X (%s), " + acx_log(LOG_INFO, L_ANY, "acx: chipset %s, radio type 0x%02X (%s), " "form factor 0x%02X (%s), EEPROM version 0x%02X, " "uploaded firmware '%s'\n", adev->chip_name, adev->radio_type, radio_str, @@ -715,9 +623,9 @@ acx_s_configure_debug(acx_device_t * adev, void *pdr, int type, else len = adev->ie_len_dot11[type - 0x1000]; - log(L_CTL, FUNC "(type:%s,len:%u)\n", typestr, len); + acx_log(LOG_DEBUG, L_CTL, FUNC "(type:%s,len:%u)\n", typestr, len); if (unlikely(!len)) { - log(L_DEBUG, "zero-length type %s?!\n", typestr); + acx_log(LOG_DEBUG, L_ANY, "zero-length type %s?!\n", typestr); } ((acx_ie_generic_t *) pdr)->type = cpu_to_le16(type); @@ -725,11 +633,11 @@ acx_s_configure_debug(acx_device_t * adev, void *pdr, int type, res = acx_s_issue_cmd(adev, ACX1xx_CMD_CONFIGURE, pdr, len + 4); if (unlikely(OK != res)) { #if ACX_DEBUG - printk("%s: " FUNC "(type:%s) FAILED\n", wiphy_name(adev->ieee->wiphy), - typestr); + acx_log(LOG_INFO, L_ANY, "%s: " FUNC "(type:%s) FAILED\n", + wiphy_name(adev->ieee->wiphy), typestr); #else - printk("%s: " FUNC "(type:0x%X) FAILED\n", wiphy_name(adev->ieee->wiphy), - type); + acx_log(LOG_INFO, L_ANY, "%s: " FUNC "(type:0x%X) FAILED\n", + wiphy_name(adev->ieee->wiphy), type); #endif /* dump_stack() is already done in issue_cmd() */ } @@ -759,18 +667,18 @@ acx_s_interrogate_debug(acx_device_t * adev, void *pdr, int type, else len = adev->ie_len_dot11[type - 0x1000]; - log(L_CTL, FUNC "(type:%s,len:%u)\n", typestr, len); + acx_log(LOG_DEBUG, L_CTL, FUNC "(type:%s,len:%u)\n", typestr, len); ((acx_ie_generic_t *) pdr)->type = cpu_to_le16(type); ((acx_ie_generic_t *) pdr)->len = cpu_to_le16(len); res = acx_s_issue_cmd(adev, ACX1xx_CMD_INTERROGATE, pdr, len + 4); if (unlikely(OK != res)) { #if ACX_DEBUG - printk("%s: " FUNC "(type:%s) FAILED\n", wiphy_name(adev->ieee->wiphy), - typestr); + acx_log(LOG_INFO, L_ANY, "%s: " FUNC "(type:%s) FAILED\n", + wiphy_name(adev->ieee->wiphy), typestr); #else - printk("%s: " FUNC "(type:0x%X) FAILED\n", wiphy_name(adev->ieee->wiphy), - type); + acx_log(LOG_INFO, L_ANY, "%s: " FUNC "(type:0x%X) FAILED\n", + wiphy_name(adev->ieee->wiphy), type); #endif /* dump_stack() is already done in issue_cmd() */ } @@ -1400,14 +1308,14 @@ static int manage_proc_entries(struct ieee80211_hw *hw, int remove) for (i = 0; i < ARRAY_SIZE(proc_files); i++) { snprintf(procbuf, sizeof(procbuf), "driver/acx%s", proc_files[i]); - log(L_INIT, "%sing /proc entry %s\n", + acx_log(LOG_INFO, L_INIT, "%sing /proc entry %s\n", remove ? "remov" : "creat", procbuf); if (!remove) { if (!create_proc_read_entry (procbuf, 0, NULL, proc_funcs[i], adev)) { - printk("acx: cannot register /proc entry %s\n", - procbuf); - FN_EXIT1(NOT_OK); + acx_log(LOG_INFO, L_ANY, + "cannot register /proc entry %s\n", procbuf); + FN_EXIT1(NOT_OK); return NOT_OK; } } else { @@ -1601,7 +1509,9 @@ acx_s_set_beacon_template(acx_device_t *adev, struct sk_buff *skb) int len, result; FN_ENTER; - printk("Size of template: %08zX, Size of beacon: %08X\n", sizeof(struct acx_template_beacon),skb->len); + acx_log(LOG_INFO, L_ANY, "size of template: %08zX, " + "size of beacon: %08X\n", + sizeof(struct acx_template_beacon),skb->len); len = acx_fill_beacon_or_proberesp_template(adev, &bcn, skb); result = acx_s_issue_cmd(adev, ACX1xx_CMD_CONFIG_BEACON, &bcn, len); @@ -1676,13 +1586,14 @@ void acx_s_cmd_join_bssid(acx_device_t *adev, const u8 *bssid) ** Just use RATE111_nnn constants... */ tmp.u.acx111.dtim_interval = dtim_interval; tmp.u.acx111.rates_basic = cpu_to_le16(adev->rate_basic); - log(L_ASSOC, "rates_basic:%04X, rates_supported:%04X\n", + acx_log(LOG_INFO, L_ASSOC, "rates_basic:%04X, " + "rates_supported:%04X\n", adev->rate_basic, adev->rate_oper); } else { tmp.u.acx100.dtim_interval = dtim_interval; tmp.u.acx100.rates_basic = rate111to5bits(adev->rate_basic); tmp.u.acx100.rates_supported = rate111to5bits(adev->rate_oper); - log(L_ASSOC, "rates_basic:%04X->%02X, " + acx_log(LOG_INFO, L_ASSOC, "rates_basic:%04X->%02X, " "rates_supported:%04X->%02X\n", adev->rate_basic, tmp.u.acx100.rates_basic, adev->rate_oper, tmp.u.acx100.rates_supported); @@ -1707,8 +1618,9 @@ void acx_s_cmd_join_bssid(acx_device_t *adev, const u8 *bssid) memcpy(tmp.essid, adev->essid, tmp.essid_len); acx_s_issue_cmd(adev, ACX1xx_CMD_JOIN, &tmp, tmp.essid_len + 0x11); - log(L_ASSOC|L_DEBUG, "BSS_Type = %u\n", tmp.macmode); - acxlog_mac(L_ASSOC|L_DEBUG, "JoinBSSID MAC:", adev->bssid, "\n"); + acx_log(LOG_DEBUG, L_ASSOC, "BSS_Type = %u\n", tmp.macmode); + acx_log(LOG_DEBUG, L_ASSOC, "JoinBSSID MAC:" MACSTR "\n", + adev->bssid, "\n"); /* acx_update_capabilities(adev); */ FN_EXIT0; @@ -1780,7 +1692,7 @@ acx111_s_get_feature_config(acx_device_t * adev, FN_EXIT1(NOT_OK); return NOT_OK; } - log(L_DEBUG, + acx_log(LOG_DEBUG, L_REALLYVERBOSE, "got Feature option:0x%X, DataFlow option: 0x%X\n", feat.feature_options, feat.data_flow_options); @@ -1833,7 +1745,7 @@ acx111_s_set_feature_config(acx_device_t * adev, SET_BIT(feat.data_flow_options, cpu_to_le32(data_flow_options)); } - log(L_DEBUG, + acx_log(LOG_DEBUG, L_REALLYVERBOSE, "old: feature 0x%08X dataflow 0x%08X. mode: %u\n" "new: feature 0x%08X dataflow 0x%08X\n", feature_options, data_flow_options, mode, @@ -1896,7 +1808,7 @@ acx100_s_init_memory_pools(acx_device_t * adev, const acx_ie_memmap_t * mmt) (le32_to_cpu(mmt->PoolEnd) - le32_to_cpu(mmt->PoolStart)) / adev->memblocksize; - log(L_DEBUG, "TotalMemoryBlocks=%u (%u bytes)\n", + acx_log(LOG_DEBUG, L_REALLYVERBOSE, "TotalMemoryBlocks=%u (%u bytes)\n", TotalMemoryBlocks, TotalMemoryBlocks * adev->memblocksize); /* MemoryConfigOption.DMA_config bitmask: @@ -1912,9 +1824,10 @@ acx100_s_init_memory_pools(acx_device_t * adev, const acx_ie_memmap_t * mmt) /* Declare start of the Rx host pool */ MemoryConfigOption.pRxHostDesc = cpu2acx(adev->rxhostdesc_startphy); - log(L_DEBUG, "pRxHostDesc 0x%08X, rxhostdesc_startphy 0x%lX\n", - acx2cpu(MemoryConfigOption.pRxHostDesc), - (long)adev->rxhostdesc_startphy); + acx_log(LOG_DEBUG, L_REALLYVERBOSE, "pRxHostDesc 0x%08X, " + "rxhostdesc_startphy 0x%lX\n", + acx2cpu(MemoryConfigOption.pRxHostDesc), + (long)adev->rxhostdesc_startphy); } else { MemoryConfigOption.DMA_config = cpu_to_le32(0x20000); } @@ -1930,9 +1843,9 @@ acx100_s_init_memory_pools(acx_device_t * adev, const acx_ie_memmap_t * mmt) /* size of the tx and rx descriptor queues */ TotalTxBlockSize = TxBlockNum * adev->memblocksize; TotalRxBlockSize = RxBlockNum * adev->memblocksize; - log(L_DEBUG, "TxBlockNum %u RxBlockNum %u TotalTxBlockSize %u " - "TotalTxBlockSize %u\n", TxBlockNum, RxBlockNum, - TotalTxBlockSize, TotalRxBlockSize); + acx_log(LOG_DEBUG, L_REALLYVERBOSE, "TxBlockNum %u RxBlockNum %u " + "TotalTxBlockSize %u TotalTxBlockSize %u\n", + TxBlockNum, RxBlockNum, TotalTxBlockSize, TotalRxBlockSize); /* align the tx descriptor queue to an alignment of 0x20 (32 bytes) */ @@ -1944,8 +1857,8 @@ acx100_s_init_memory_pools(acx_device_t * adev, const acx_ie_memmap_t * mmt) MemoryConfigOption.tx_mem = cpu_to_le32((le32_to_cpu(mmt->PoolStart) + TotalRxBlockSize + 0x1f) & ~0x1f); - log(L_DEBUG, "rx_mem %08X rx_mem %08X\n", MemoryConfigOption.tx_mem, - MemoryConfigOption.rx_mem); + acx_log(LOG_DEBUG, L_REALLYVERBOSE, "rx_mem %08X rx_mem %08X\n", + MemoryConfigOption.tx_mem, MemoryConfigOption.rx_mem); /* alert the device to our decision */ if (OK != @@ -1990,7 +1903,7 @@ static int acx100_s_create_dma_regions(acx_device_t * adev) tx_queue_start = le32_to_cpu(memmap.QueueStart); rx_queue_start = tx_queue_start + TX_CNT * sizeof(txdesc_t); - log(L_DEBUG, "initializing Queue Indicator\n"); + acx_log(LOG_DEBUG, L_REALLYVERBOSE, "initializing Queue Indicator\n"); memset(&queueconf, 0, sizeof(queueconf)); @@ -2126,16 +2039,16 @@ static int acx111_s_create_dma_regions(acx_device_t * adev) tx_queue_start = le32_to_cpu(queueconf.tx1_queue_address); rx_queue_start = le32_to_cpu(queueconf.rx1_queue_address); - log(L_INIT, "dump queue head (from card):\n" - "len: %u\n" - "tx_memory_block_address: %X\n" - "rx_memory_block_address: %X\n" - "tx1_queue address: %X\n" - "rx1_queue address: %X\n", - le16_to_cpu(queueconf.len), - le32_to_cpu(queueconf.tx_memory_block_address), - le32_to_cpu(queueconf.rx_memory_block_address), - tx_queue_start, rx_queue_start); + acx_log(LOG_DEBUG, L_INIT, "dump queue head (from card):\n" + "len: %u\n" + "tx_memory_block_address: %X\n" + "rx_memory_block_address: %X\n" + "tx1_queue address: %X\n" + "rx1_queue address: %X\n", + le16_to_cpu(queueconf.len), + le32_to_cpu(queueconf.tx_memory_block_address), + le32_to_cpu(queueconf.rx_memory_block_address), + tx_queue_start, rx_queue_start); if (IS_PCI(adev)) acxpci_create_desc_queues(adev, tx_queue_start, rx_queue_start); @@ -2227,8 +2140,9 @@ static void acx_s_initialize_rx_config(acx_device_t * adev) else adev->phy_header_len = 0; - log(L_INIT, "setting RXconfig to %04X:%04X\n", - adev->rx_config_1, adev->rx_config_2); + acx_log(LOG_DEBUG, L_INIT, "setting RXconfig to %04X:%04X\n", + adev->rx_config_1, adev->rx_config_2); + cfg.rx_cfg1 = cpu_to_le16(adev->rx_config_1); cfg.rx_cfg2 = cpu_to_le16(adev->rx_config_2); acx_s_configure(adev, &cfg, ACX1xx_IE_RXCONFIG); @@ -2265,9 +2179,9 @@ static int acx111_s_set_tx_level(acx_device_t * adev, u8 level_dbm) adev->tx_level_dbm = 15; } if (level_dbm != adev->tx_level_dbm) - log(L_INIT, "acx111 firmware has specific " - "power levels only: adjusted %d dBm to %d dBm!\n", - level_dbm, adev->tx_level_dbm); + acx_log(LOG_INFO, L_INIT, "acx111 firmware has specific " + "power levels only: adjusted %d dBm to %d dBm!\n", + level_dbm, adev->tx_level_dbm); return acx_s_configure(adev, &tx_level, ACX1xx_IE_DOT11_TX_POWER_LEVEL); } @@ -2463,11 +2377,7 @@ void acx_l_process_rxbuf(acx_device_t * adev, rxbuffer_t * rxbuf) /* length of frame from control field to first byte of FCS */ buf_len = RXBUF_BYTES_RCVD(adev, rxbuf); - if (unlikely(acx_debug & L_DATA)) { - printk("rx: 802.11 buf[%u]: \n", buf_len); - acx_dump_bytes(hdr, buf_len); - } - + acx_log_dump(LOG_DEBUG, L_DATA, hdr, buf_len, "RX: 802.11 buffer:\n"); acx_l_rx(adev, rxbuf); /* Now check Rx quality level, AFTER processing packet. @@ -2577,8 +2487,9 @@ acx_i_start_xmit(struct ieee80211_hw *hw, tx = acx_l_alloc_tx(adev); if (unlikely(!tx)) { - printk_ratelimited("%s: start_xmit: txdesc ring is full, " - "dropping tx\n", wiphy_name(adev->ieee->wiphy)); + acx_log_ratelimited(LOG_INFO, L_ANY, "%s: start_xmit: " + "txdesc ring is full, dropping tx\n", + wiphy_name(adev->ieee->wiphy)); txresult = NOT_OK; goto out_unlock; } @@ -2649,10 +2560,10 @@ void acx_l_update_ratevector(acx_device_t * adev) bcfg >>= 1; } adev->rate_supported_len = supp - adev->rate_supported; - if (acx_debug & L_ASSOC) { - printk("new ratevector: "); - acx_dump_bytes(adev->rate_supported, adev->rate_supported_len); - } + + acx_log_dump(LOG_DEBUG, L_ASSOC, adev->rate_supported, + adev->rate_supported_len, "new ratevector:\n"); + FN_EXIT0; } @@ -2692,10 +2603,12 @@ void acx_set_timer(acx_device_t * adev, int timeout_us) { FN_ENTER; - log(L_DEBUG | L_IRQ, "%s(%u ms)\n", __func__, timeout_us / 1000); + acx_log(LOG_DEBUG, L_REALLYVERBOSE | L_IRQ, + "%s(%u ms)\n", __func__, timeout_us / 1000); + if (!(adev->dev_state_mask & ACX_STATE_IFACE_UP)) { - printk("attempt to set the timer " - "when the card interface is not up!\n"); + acx_log(LOG_INFO, L_ANY, "attempt to set the timer " + "when the card interface is not up!\n"); goto end; } @@ -2835,21 +2748,22 @@ firmware_image_t *acx_s_read_fw(struct device *dev, const char *file, const struct firmware *fw_entry; res = NULL; - log(L_INIT, "requesting firmware image '%s'\n", file); + acx_log(LOG_INFO, L_INIT, "requesting firmware image '%s'\n", file); if (!request_firmware(&fw_entry, file, dev)) { *size = 8; if (fw_entry->size >= 8) *size = 8 + le32_to_cpu(*(u32 *) (fw_entry->data + 4)); if (fw_entry->size != *size) { - printk("acx: firmware size does not match " - "firmware header: %d != %d, " - "aborting fw upload\n", + acx_log(LOG_INFO, L_ANY, + "acx: firmware size does not match " + "firmware header: %d != %d, " + "aborting fw upload\n", (int)fw_entry->size, (int)*size); goto release_ret; } res = vmalloc(*size); if (!res) { - printk("acx: no memory for firmware " + acx_log(LOG_INFO, L_ANY, "acx: no memory for firmware " "(%u bytes)\n", *size); goto release_ret; } @@ -2858,8 +2772,8 @@ firmware_image_t *acx_s_read_fw(struct device *dev, const char *file, release_firmware(fw_entry); return res; } - printk("acx: firmware image '%s' was not provided. " - "Check your hotplug scripts\n", file); + acx_log(LOG_INFO, L_ANY, "acx: firmware image '%s' was not provided. " + "Check your hotplug scripts\n", file); /* checksum will be verified in write_fw, so don't bother here */ return res; @@ -2876,8 +2790,9 @@ static void acx100_s_set_wepkey(acx_device_t * adev) for (i = 0; i < DOT11_MAX_DEFAULT_WEP_KEYS; i++) { if (adev->wep_keys[i].size != 0) { - log(L_INIT, "setting WEP key: %d with " - "total size: %d\n", i, (int)adev->wep_keys[i].size); + acx_log(LOG_DEBUG, L_INIT, "setting WEP key: %d with " + "total size: %d\n", + i, (int)adev->wep_keys[i].size); dk.action = 1; dk.keySize = adev->wep_keys[i].size; dk.defaultKeyNum = i; @@ -2895,8 +2810,9 @@ static void acx111_s_set_wepkey(acx_device_t * adev) for (i = 0; i < DOT11_MAX_DEFAULT_WEP_KEYS; i++) { if (adev->wep_keys[i].size != 0) { - log(L_INIT, "setting WEP key: %d with " - "total size: %d\n", i, (int)adev->wep_keys[i].size); + acx_log(LOG_DEBUG, L_INIT, "setting WEP key: %d with " + "total size: %d\n", i, + (int)adev->wep_keys[i].size); memset(&dk, 0, sizeof(dk)); dk.action = cpu_to_le16(1); /* "add key"; yes, that's a 16bit value */ dk.keySize = adev->wep_keys[i].size; @@ -2942,7 +2858,7 @@ static int acx100_s_init_wep(acx_device_t * adev) goto fail; } - log(L_DEBUG, "CodeEnd:%X\n", pt.CodeEnd); + acx_log(LOG_DEBUG, L_REALLYVERBOSE, "CodeEnd:%X\n", pt.CodeEnd); pt.WEPCacheStart = cpu_to_le32(le32_to_cpu(pt.CodeEnd) + 0x4); pt.WEPCacheEnd = cpu_to_le32(le32_to_cpu(pt.CodeEnd) + 0x4); @@ -2955,14 +2871,15 @@ static int acx100_s_init_wep(acx_device_t * adev) options.NumKeys = cpu_to_le16(DOT11_MAX_DEFAULT_WEP_KEYS + 10); options.WEPOption = 0x00; - log(L_ASSOC, "writing WEP options\n"); + acx_log(LOG_DEBUG, L_ASSOC, "writing WEP options\n"); acx_s_configure(adev, &options, ACX100_IE_WEP_OPTIONS); acx100_s_set_wepkey(adev); if (adev->wep_keys[adev->wep_current_index].size != 0) { - log(L_ASSOC, "setting active default WEP key number: %d\n", - adev->wep_current_index); + acx_log(LOG_DEBUG, L_ASSOC, + "setting active default WEP key number: %d\n", + adev->wep_current_index); dk.KeyID = adev->wep_current_index; acx_s_configure(adev, &dk, ACX1xx_IE_DOT11_WEP_DEFAULT_KEY_SET); /* 0x1010 */ } @@ -2984,8 +2901,9 @@ static int acx100_s_init_wep(acx_device_t * adev) /* now retrieve the updated WEPCacheEnd pointer... */ if (OK != acx_s_interrogate(adev, &pt, ACX1xx_IE_MEMORY_MAP)) { - printk("%s: ACX1xx_IE_MEMORY_MAP read #2 FAILED\n", - wiphy_name(adev->ieee->wiphy)); + acx_log(LOG_INFO, L_ANY, + "%s: ACX1xx_IE_MEMORY_MAP read #2 FAILED\n", + wiphy_name(adev->ieee->wiphy)); goto fail; } /* ...and tell it to start allocating templates at that location */ @@ -2993,8 +2911,9 @@ static int acx100_s_init_wep(acx_device_t * adev) pt.PacketTemplateStart = pt.WEPCacheEnd; if (OK != acx_s_configure(adev, &pt, ACX1xx_IE_MEMORY_MAP)) { - printk("%s: ACX1xx_IE_MEMORY_MAP write #2 FAILED\n", - wiphy_name(adev->ieee->wiphy)); + acx_log(LOG_INFO, L_ANY, + "%s: ACX1xx_IE_MEMORY_MAP write #2 FAILED\n", + wiphy_name(adev->ieee->wiphy)); goto fail; } res = OK; @@ -3165,7 +3084,8 @@ static int acx_s_init_packet_templates(acx_device_t * adev) FN_ENTER; - log(L_DEBUG | L_INIT, "initializing max packet templates\n"); + acx_log(LOG_DEBUG, L_REALLYVERBOSE | L_INIT, + "initializing max packet templates\n"); if (OK != acx_s_init_max_probe_request_template(adev)) goto failed; @@ -3195,7 +3115,8 @@ static int acx_s_init_packet_templates(acx_device_t * adev) if (OK != acx_s_set_tim_template(adev)) goto failed_acx100; - log(L_DEBUG, "sizeof(memmap)=%d bytes\n", (int)sizeof(mm)); + acx_log(LOG_DEBUG, L_REALLYVERBOSE, + "sizeof(memmap)=%d bytes\n", (int)sizeof(mm)); if (OK != acx_s_interrogate(adev, &mm, ACX1xx_IE_MEMORY_MAP)) goto failed_acx100; @@ -3208,7 +3129,7 @@ static int acx_s_init_packet_templates(acx_device_t * adev) goto success; failed_acx100: - log(L_DEBUG | L_INIT, + acx_log(LOG_DEBUG, L_REALLYVERBOSE | L_INIT, /* "cb=0x%X\n" */ "ACXMemoryMap:\n" ".CodeStart=0x%X\n" @@ -3225,7 +3146,8 @@ static int acx_s_init_packet_templates(acx_device_t * adev) le32_to_cpu(mm.PacketTemplateEnd)); failed: - printk("%s: %s() FAILED\n", wiphy_name(adev->ieee->wiphy), __func__); + acx_log(LOG_INFO, L_ANY, "%s: %s() FAILED\n", + wiphy_name(adev->ieee->wiphy), __func__); success: FN_EXIT1(result); @@ -3270,8 +3192,9 @@ int acx_s_init_mac(acx_device_t * adev) if (OK != acx_s_init_packet_templates(adev)) goto fail; if (OK != acx111_s_create_dma_regions(adev)) { - printk("%s: acx111_create_dma_regions FAILED\n", - wiphy_name(adev->ieee->wiphy)); + acx_log(LOG_INFO, L_ANY, + "%s: acx111_create_dma_regions FAILED\n", + wiphy_name(adev->ieee->wiphy)); goto fail; } } else { @@ -3280,8 +3203,9 @@ int acx_s_init_mac(acx_device_t * adev) if (OK != acx_s_init_packet_templates(adev)) goto fail; if (OK != acx100_s_create_dma_regions(adev)) { - printk("%s: acx100_create_dma_regions FAILED\n", - wiphy_name(adev->ieee->wiphy)); + acx_log(LOG_INFO, L_ANY, + "%s: acx100_create_dma_regions FAILED\n", + wiphy_name(adev->ieee->wiphy)); goto fail; } } @@ -3291,7 +3215,7 @@ int acx_s_init_mac(acx_device_t * adev) fail: if (result) - printk("acx: init_mac() FAILED\n"); + acx_log(LOG_INFO, L_ANY, "init_mac() FAILED\n"); FN_EXIT1(result); return result; } @@ -3308,26 +3232,27 @@ static void acx_s_update_80211_powersave_mode(acx_device_t * adev) } pm; /* change 802.11 power save mode settings */ - log(L_INIT, "updating 802.11 power save mode settings: " - "wakeup_cfg 0x%02X, listen interval %u, " - "options 0x%02X, hangover period %u, " - "enhanced_ps_transition_time %u\n", - adev->ps_wakeup_cfg, adev->ps_listen_interval, - adev->ps_options, adev->ps_hangover_period, - adev->ps_enhanced_transition_time); + acx_log(LOG_DEBUG, L_INIT, "updating 802.11 power save mode settings: " + "wakeup_cfg 0x%02X, listen interval %u, " + "options 0x%02X, hangover period %u, " + "enhanced_ps_transition_time %u\n", + adev->ps_wakeup_cfg, adev->ps_listen_interval, + adev->ps_options, adev->ps_hangover_period, + adev->ps_enhanced_transition_time); acx_s_interrogate(adev, &pm, ACX1xx_IE_POWER_MGMT); - log(L_INIT, "Previous PS mode settings: wakeup_cfg 0x%02X, " - "listen interval %u, options 0x%02X, " - "hangover period %u, " - "enhanced_ps_transition_time %u, beacon_rx_time %u\n", - pm.acx111.wakeup_cfg, - pm.acx111.listen_interval, - pm.acx111.options, - pm.acx111.hangover_period, - IS_ACX111(adev) ? - pm.acx111.enhanced_ps_transition_time - : pm.acx100.enhanced_ps_transition_time, - IS_ACX111(adev) ? pm.acx111.beacon_rx_time : (u32) - 1); + acx_log(LOG_DEBUG, L_INIT, "Previous PS mode settings: " + "wakeup_cfg 0x%02X, " + "listen interval %u, options 0x%02X, " + "hangover period %u, " + "enhanced_ps_transition_time %u, beacon_rx_time %u\n", + pm.acx111.wakeup_cfg, + pm.acx111.listen_interval, + pm.acx111.options, + pm.acx111.hangover_period, + IS_ACX111(adev) ? + pm.acx111.enhanced_ps_transition_time + : pm.acx100.enhanced_ps_transition_time, + IS_ACX111(adev) ? pm.acx111.beacon_rx_time : (u32) - 1); pm.acx111.wakeup_cfg = adev->ps_wakeup_cfg; pm.acx111.listen_interval = adev->ps_listen_interval; pm.acx111.options = adev->ps_options; @@ -3342,13 +3267,15 @@ static void acx_s_update_80211_powersave_mode(acx_device_t * adev) } acx_s_configure(adev, &pm, ACX1xx_IE_POWER_MGMT); acx_s_interrogate(adev, &pm, ACX1xx_IE_POWER_MGMT); - log(L_INIT, "wakeup_cfg: 0x%02X\n", pm.acx111.wakeup_cfg); + acx_log(LOG_DEBUG, L_INIT, "wakeup_cfg: 0x%02X\n", + pm.acx111.wakeup_cfg); acx_s_mwait(40); acx_s_interrogate(adev, &pm, ACX1xx_IE_POWER_MGMT); - log(L_INIT, "wakeup_cfg: 0x%02X\n", pm.acx111.wakeup_cfg); - log(L_INIT, "power save mode change %s\n", - (pm.acx111. - wakeup_cfg & PS_CFG_PENDING) ? "FAILED" : "was successful"); + acx_log(LOG_DEBUG, L_INIT, "wakeup_cfg: 0x%02X\n", + pm.acx111.wakeup_cfg); + acx_log(LOG_DEBUG, L_INIT, "power save mode change %s\n", + (pm.acx111.wakeup_cfg & PS_CFG_PENDING) ? + "FAILED" : "was successful"); /* FIXME: maybe verify via PS_CFG_PENDING bit here * that power save mode change was successful. */ /* FIXME: we shouldn't trigger a scan immediately after @@ -3376,10 +3303,11 @@ void acx_s_set_sane_reg_domain(acx_device_t *adev, int do_set) break; if (sizeof(acx_reg_domain_ids) == i) { - log(L_INIT, "Invalid or unsupported regulatory domain" - " 0x%02X specified, falling back to FCC (USA)!" - " Please report if this sounds fishy!\n", - adev->reg_dom_id); + acx_log(LOG_INFO, L_INIT, + "Invalid or unsupported regulatory domain" + " 0x%02X specified, falling back to FCC (USA)!" + " Please report if this sounds fishy!\n", + adev->reg_dom_id); i = 0; adev->reg_dom_id = acx_reg_domain_ids[i]; @@ -3396,19 +3324,28 @@ void acx_s_set_sane_reg_domain(acx_device_t *adev, int do_set) adev->reg_dom_chanmask = reg_domain_channel_masks[i]; mask = (1 << (adev->channel - 1)); - if (!(adev->reg_dom_chanmask & mask)) { - /* hmm, need to adjust our channel to reside within domain */ - mask = 1; - for (i = 1; i <= 14; i++) { - if (adev->reg_dom_chanmask & mask) { - printk("%s: adjusting selected channel from %d " - "to %d due to new regulatory domain\n", - wiphy_name(adev->ieee->wiphy), adev->channel, i); - adev->channel = i; - break; - } + + /* + * Check our channels wrt the current regulatory domain + */ + if (adev->reg_dom_chanmask & mask) + return; + + /* + * Hmm nope, need to adjust channels! + */ + + mask = 1; + for (i = 1; i <= 14; i++) { + if (!(adev->reg_dom_chanmask & mask)) { mask <<= 1; + continue; } + acx_log(LOG_INFO, L_ANY, "%s: adjusting selected channel " + "from %d to %d due to new regulatory domain\n", + wiphy_name(adev->ieee->wiphy), adev->channel, i); + adev->channel = i; + break; } } @@ -3417,8 +3354,9 @@ static void acx111_s_sens_radio_16_17(acx_device_t * adev) u32 feature1, feature2; if ((adev->sensitivity < 1) || (adev->sensitivity > 3)) { - printk("%s: invalid sensitivity setting (1..3), " - "setting to 1\n", wiphy_name(adev->ieee->wiphy)); + acx_log(LOG_INFO, L_ANY, + "%s: invalid sensitivity setting (1..3), " + "setting to 1\n", wiphy_name(adev->ieee->wiphy)); adev->sensitivity = 1; } acx111_s_get_feature_config(adev, &feature1, &feature2); @@ -3439,14 +3377,15 @@ void acx_s_update_card_settings(acx_device_t *adev) FN_ENTER; - log(L_INIT, "get_mask 0x%08X, set_mask 0x%08X\n", - adev->get_mask, adev->set_mask); + acx_log(LOG_DEBUG, L_INIT, "get_mask 0x%08X, set_mask 0x%08X\n", + adev->get_mask, adev->set_mask); /* Track dependencies betweed various settings */ if (adev->set_mask & (GETSET_MODE | GETSET_RESCAN | GETSET_WEP)) { - log(L_INIT, "important setting has been changed. " - "Need to update packet templates, too\n"); + acx_log(LOG_DEBUG, L_INIT, + "important setting has been changed. " + "Need to update packet templates, too\n"); SET_BIT(adev->set_mask, SET_TEMPLATES); } if (adev->set_mask & GETSET_CHANNEL) { @@ -3493,11 +3432,13 @@ void acx_s_update_card_settings(acx_device_t *adev) || (RADIO_RALINK_15 == adev->radio_type)) { acx_s_read_phy_reg(adev, 0x30, &adev->sensitivity); } else { - log(L_INIT, "don't know how to get sensitivity " - "for radio type 0x%02X\n", adev->radio_type); + acx_log(LOG_INFO, L_INIT, + "don't know how to get sensitivity " + "for radio type 0x%02X\n", adev->radio_type); adev->sensitivity = 0; } - log(L_INIT, "got sensitivity value %u\n", adev->sensitivity); + acx_log(LOG_DEBUG, L_INIT, "got sensitivity value %u\n", + adev->sensitivity); CLEAR_BIT(adev->get_mask, GETSET_SENSITIVITY); } @@ -3509,7 +3450,8 @@ void acx_s_update_card_settings(acx_device_t *adev) acx_s_interrogate(adev, antenna, ACX1xx_IE_DOT11_CURRENT_ANTENNA); adev->antenna = antenna[4]; - log(L_INIT, "got antenna value 0x%02X\n", adev->antenna); + acx_log(LOG_INFO, L_INIT, "got antenna value 0x%02X\n", + adev->antenna); CLEAR_BIT(adev->get_mask, GETSET_ANTENNA); } @@ -3522,11 +3464,13 @@ void acx_s_update_card_settings(acx_device_t *adev) ACX100_IE_DOT11_ED_THRESHOLD); adev->ed_threshold = ed_threshold[4]; } else { - log(L_INIT, "acx111 doesn't support ED\n"); + acx_log(LOG_INFO, L_INIT, + "acx111 doesn't support ED\n"); adev->ed_threshold = 0; } - log(L_INIT, "got Energy Detect (ED) threshold %u\n", - adev->ed_threshold); + acx_log(LOG_INFO, L_INIT, + "got Energy Detect (ED) threshold %u\n", + adev->ed_threshold); CLEAR_BIT(adev->get_mask, GETSET_ED_THRESH); } @@ -3539,11 +3483,13 @@ void acx_s_update_card_settings(acx_device_t *adev) ACX1xx_IE_DOT11_CURRENT_CCA_MODE); adev->cca = cca[4]; } else { - log(L_INIT, "acx111 doesn't support CCA\n"); + acx_log(LOG_INFO, L_INIT, + "acx111 doesn't support CCA\n"); adev->cca = 0; } - log(L_INIT, "got Channel Clear Assessment (CCA) value %u\n", - adev->cca); + acx_log(LOG_INFO, L_INIT, + "got Channel Clear Assessment (CCA) value %u\n", + adev->cca); CLEAR_BIT(adev->get_mask, GETSET_CCA); } @@ -3554,7 +3500,8 @@ void acx_s_update_card_settings(acx_device_t *adev) ACX1xx_IE_DOT11_CURRENT_REG_DOMAIN); adev->reg_dom_id = dom.m.bytes[0]; acx_s_set_sane_reg_domain(adev, 0); - log(L_INIT, "got regulatory domain 0x%02X\n", adev->reg_dom_id); + acx_log(LOG_INFO, L_INIT, + "got regulatory domain 0x%02X\n", adev->reg_dom_id); CLEAR_BIT(adev->get_mask, GETSET_REG_DOMAIN); } @@ -3585,20 +3532,21 @@ void acx_s_update_card_settings(acx_device_t *adev) rate[4] = (adev-> rate_auto) ? /* adev->txrate_fallback_retries */ 1 : 0; - log(L_INIT, "updating Tx fallback to %u retries\n", rate[4]); + acx_log(LOG_DEBUG, L_INIT, + "updating Tx fallback to %u retries\n", rate[4]); acx_s_configure(adev, &rate, ACX1xx_IE_RATE_FALLBACK); CLEAR_BIT(adev->set_mask, SET_RATE_FALLBACK); } if (adev->set_mask & GETSET_TXPOWER) { - log(L_INIT, "updating transmit power: %u dBm\n", - adev->tx_level_dbm); + acx_log(LOG_DEBUG, L_INIT, "updating transmit power: %u dBm\n", + adev->tx_level_dbm); acx_s_set_tx_level(adev, adev->tx_level_dbm); CLEAR_BIT(adev->set_mask, GETSET_TXPOWER); } if (adev->set_mask & GETSET_SENSITIVITY) { - log(L_INIT, "updating sensitivity value: %u\n", - adev->sensitivity); + acx_log(LOG_DEBUG, L_INIT, "updating sensitivity value: %u\n", + adev->sensitivity); switch (adev->radio_type) { case RADIO_RFMD_11: case RADIO_MAXIM_0D: @@ -3610,8 +3558,9 @@ void acx_s_update_card_settings(acx_device_t *adev) acx111_s_sens_radio_16_17(adev); break; default: - log(L_INIT, "don't know how to modify sensitivity " - "for radio type 0x%02X\n", adev->radio_type); + acx_log(LOG_INFO, L_INIT, + "don't know how to modify sensitivity " + "for radio type 0x%02X\n", adev->radio_type); } CLEAR_BIT(adev->set_mask, GETSET_SENSITIVITY); } @@ -3622,7 +3571,8 @@ void acx_s_update_card_settings(acx_device_t *adev) memset(antenna, 0, sizeof(antenna)); antenna[4] = adev->antenna; - log(L_INIT, "updating antenna value: 0x%02X\n", adev->antenna); + acx_log(LOG_DEBUG, L_INIT, "updating antenna value: 0x%02X\n", + adev->antenna); acx_s_configure(adev, &antenna, ACX1xx_IE_DOT11_CURRENT_ANTENNA); CLEAR_BIT(adev->set_mask, GETSET_ANTENNA); @@ -3630,8 +3580,9 @@ void acx_s_update_card_settings(acx_device_t *adev) if (adev->set_mask & GETSET_ED_THRESH) { /* ed_threshold */ - log(L_INIT, "updating Energy Detect (ED) threshold: %u\n", - adev->ed_threshold); + acx_log(LOG_INFO, L_INIT, + "updating Energy Detect (ED) threshold: %u\n", + adev->ed_threshold); if (IS_ACX100(adev)) { u8 ed_threshold[4 + ACX100_IE_DOT11_ED_THRESHOLD_LEN]; @@ -3640,14 +3591,16 @@ void acx_s_update_card_settings(acx_device_t *adev) acx_s_configure(adev, &ed_threshold, ACX100_IE_DOT11_ED_THRESHOLD); } else - log(L_INIT, "acx111 doesn't support ED!\n"); + acx_log(LOG_INFO, L_INIT, + "acx111 doesn't support ED!\n"); CLEAR_BIT(adev->set_mask, GETSET_ED_THRESH); } if (adev->set_mask & GETSET_CCA) { /* CCA value */ - log(L_INIT, "updating Channel Clear Assessment " - "(CCA) value: 0x%02X\n", adev->cca); + acx_log(LOG_DEBUG, L_INIT, + "updating Channel Clear Assessment (CCA) value: " + "0x%02X\n", adev->cca); if (IS_ACX100(adev)) { u8 cca[4 + ACX1xx_IE_DOT11_CURRENT_CCA_MODE_LEN]; @@ -3656,13 +3609,15 @@ void acx_s_update_card_settings(acx_device_t *adev) acx_s_configure(adev, &cca, ACX1xx_IE_DOT11_CURRENT_CCA_MODE); } else - log(L_INIT, "acx111 doesn't support CCA!\n"); + acx_log(LOG_INFO, L_INIT, + "acx111 doesn't support CCA!\n"); CLEAR_BIT(adev->set_mask, GETSET_CCA); } if (adev->set_mask & GETSET_LED_POWER) { /* Enable Tx */ - log(L_INIT, "updating power LED status: %u\n", adev->led_power); + acx_log(LOG_INFO, L_INIT, + "updating power LED status: %u\n", adev->led_power); acx_lock(adev, flags); /* acxpci_l_power_led expects that the lock is already taken! */ if (IS_PCI(adev)) @@ -3680,14 +3635,15 @@ void acx_s_update_card_settings(acx_device_t *adev) if (adev->set_mask & GETSET_CHANNEL) { /* channel */ - log(L_INIT, "updating channel to: %u\n", adev->channel); + acx_log(LOG_INFO, L_INIT, "updating channel to: %u\n", + adev->channel); CLEAR_BIT(adev->set_mask, GETSET_CHANNEL); } if (adev->set_mask & GETSET_TX) { /* set Tx */ - log(L_INIT, "updating: %s Tx\n", - adev->tx_disabled ? "disable" : "enable"); + acx_log(LOG_INFO, L_INIT, "updating: %s Tx\n", + adev->tx_disabled ? "disable" : "enable"); if (adev->tx_disabled) acx_s_issue_cmd(adev, ACX1xx_CMD_DISABLE_TX, NULL, 0); else { @@ -3705,8 +3661,8 @@ void acx_s_update_card_settings(acx_device_t *adev) if (adev->set_mask & GETSET_RX) { /* Enable Rx */ - log(L_INIT, "updating: enable Rx on channel: %u\n", - adev->channel); + acx_log(LOG_INFO, L_INIT, + "updating: enable Rx on channel: %u\n", adev->channel); acx_s_issue_cmd(adev, ACX1xx_CMD_ENABLE_RX, &adev->channel, 1); CLEAR_BIT(adev->set_mask, GETSET_RX); } @@ -3715,9 +3671,10 @@ void acx_s_update_card_settings(acx_device_t *adev) u8 short_retry[4 + ACX1xx_IE_DOT11_SHORT_RETRY_LIMIT_LEN]; u8 long_retry[4 + ACX1xx_IE_DOT11_LONG_RETRY_LIMIT_LEN]; - log(L_INIT, - "updating short retry limit: %u, long retry limit: %u\n", - adev->short_retry, adev->long_retry); + acx_log(LOG_INFO, L_INIT, + "updating short retry limit: %u, " + "long retry limit: %u\n", + adev->short_retry, adev->long_retry); short_retry[0x4] = adev->short_retry; long_retry[0x4] = adev->long_retry; acx_s_configure(adev, &short_retry, @@ -3731,8 +3688,8 @@ void acx_s_update_card_settings(acx_device_t *adev) u8 xmt_msdu_lifetime[4 + ACX1xx_IE_DOT11_MAX_XMIT_MSDU_LIFETIME_LEN]; - log(L_INIT, "updating tx MSDU lifetime: %u\n", - adev->msdu_lifetime); + acx_log(LOG_DEBUG, L_INIT, "updating tx MSDU lifetime: %u\n", + adev->msdu_lifetime); *(u32 *) & xmt_msdu_lifetime[4] = cpu_to_le32((u32) adev->msdu_lifetime); acx_s_configure(adev, &xmt_msdu_lifetime, @@ -3741,8 +3698,9 @@ void acx_s_update_card_settings(acx_device_t *adev) } if (adev->set_mask & GETSET_REG_DOMAIN) { - log(L_INIT, "updating regulatory domain: 0x%02X\n", - adev->reg_dom_id); + acx_log(LOG_INFO, L_INIT, + "updating regulatory domain: 0x%02X\n", + adev->reg_dom_id); acx_s_set_sane_reg_domain(adev, 1); CLEAR_BIT(adev->set_mask, GETSET_REG_DOMAIN); } @@ -3813,13 +3771,14 @@ void acx_s_update_card_settings(acx_device_t *adev) u8 val; } ACX_PACKED keyindic; #endif - log(L_INIT, "updating WEP key settings\n"); + acx_log(LOG_DEBUG, L_INIT, "updating WEP key settings\n"); acx_s_set_wepkey(adev); if (adev->wep_enabled) { dkey.KeyID = adev->wep_current_index; - log(L_INIT, "setting WEP key %u as default\n", - dkey.KeyID); + acx_log(LOG_DEBUG, L_INIT, + "setting WEP key %u as default\n", + dkey.KeyID); acx_s_configure(adev, &dkey, ACX1xx_IE_DOT11_WEP_DEFAULT_KEY_SET); #ifdef DEBUG_WEP @@ -3836,10 +3795,11 @@ void acx_s_update_card_settings(acx_device_t *adev) acx100_ie_wep_options_t options; if (IS_ACX111(adev)) { - log(L_DEBUG, - "setting WEP Options for acx111 is not supported\n"); + acx_log(LOG_DEBUG, L_REALLYVERBOSE, + "setting WEP Options for acx111 " + "is not supported\n"); } else { - log(L_INIT, "setting WEP Options\n"); + acx_log(LOG_DEBUG, L_INIT, "setting WEP Options\n"); /* let's choose maximum setting: 4 default keys, * plus 10 other keys: */ @@ -4001,7 +3961,7 @@ void acx_e_after_interrupt_task(struct work_struct *work) /* 1) we detected that no Scan_Complete IRQ came from fw, or ** 2) we found too many STAs */ if (adev->after_interrupt_jobs & ACX_AFTER_IRQ_CMD_STOP_SCAN) { - log(L_IRQ, "sending a stop scan cmd...\n"); + acx_log(LOG_DEBUG, L_IRQ, "sending a stop scan cmd...\n"); acx_unlock(adev, flags); acx_s_issue_cmd(adev, ACX1xx_CMD_STOP_SCAN, NULL, 0); acx_lock(adev, flags); @@ -4031,7 +3991,7 @@ void acx_e_after_interrupt_task(struct work_struct *work) /* STA auth or assoc timed out, start over again */ if (adev->after_interrupt_jobs & ACX_AFTER_IRQ_RESTART_SCAN) { - log(L_IRQ, "sending a start_scan cmd...\n"); + acx_log(LOG_DEBUG, L_IRQ, "sending a start_scan cmd...\n"); CLEAR_BIT(adev->after_interrupt_jobs, ACX_AFTER_IRQ_RESTART_SCAN); } @@ -4044,7 +4004,8 @@ void acx_e_after_interrupt_task(struct work_struct *work) end: if(adev->after_interrupt_jobs) { - printk("Jobs still to be run: %x\n",adev->after_interrupt_jobs); + acx_log(LOG_DEBUG, L_ANY, "Jobs still to be run: %x\n", + adev->after_interrupt_jobs); adev->after_interrupt_jobs = 0; } acx_unlock(adev, flags); @@ -4096,7 +4057,8 @@ void acx_s_start(acx_device_t * adev) GETSET_CCA | GETSET_REG_DOMAIN | GETSET_MODE | GETSET_CHANNEL | GETSET_TX | GETSET_RX | GETSET_STATION_ID); - log(L_INIT, "updating initial settings on iface activation\n"); + acx_log(LOG_INFO, L_INIT, + "updating initial settings on iface activation\n"); acx_s_update_card_settings(adev); FN_EXIT0; @@ -4243,11 +4205,11 @@ int acx_add_interface(struct ieee80211_hw *ieee, err = 0; - printk(KERN_INFO "Virtual interface added " - "(type: 0x%08X, ID: %d, MAC: %s)\n", - conf->type, - adev->interface.if_id, - print_mac(mac, conf->mac_addr)); + acx_log(LOG_INFO, L_ANY, "Virtual interface added " + "(type: 0x%08X, ID: %d, MAC: %s)\n", + conf->type, + adev->interface.if_id, + print_mac(mac, conf->mac_addr)); out_unlock: acx_unlock(adev, flags); @@ -4277,16 +4239,18 @@ void acx_remove_interface(struct ieee80211_hw *hw, adev->interface.operating = 0; } - printk("Removing interface: %d %d\n", adev->interface.operating, conf->type); + acx_log(LOG_INFO, L_ANY, "Removing interface: %d %d\n", + adev->interface.operating, conf->type); acx_sem_unlock(adev); if (adev->initialized) acx_s_select_opmode(adev); flush_scheduled_work(); - printk(KERN_INFO "Virtual interface removed " - "(type: 0x%08X, ID: %d, MAC: %s)\n", - conf->type, adev->interface.if_id, print_mac(mac, conf->mac_addr)); + acx_log(LOG_INFO, L_ANY, "Virtual interface removed " + "(type: 0x%08X, ID: %d, MAC: %s)\n", + conf->type, adev->interface.if_id, + print_mac(mac, conf->mac_addr)); FN_EXIT0; } @@ -4325,7 +4289,7 @@ int acx_selectchannel(acx_device_t * adev, u8 channel, int freq) adev->channel = channel; /* hmm, the following code part is strange, but this is how * it was being done before... */ - log(L_IOCTL, "Changing to channel %d\n", channel); + acx_log(LOG_DEBUG, L_IOCTL, "Changing to channel %d\n", channel); SET_BIT(adev->set_mask, GETSET_CHANNEL); result = -EINPROGRESS; /* need to call commit handler */ @@ -4782,20 +4746,20 @@ acx_s_parse_configoption(acx_device_t * adev, int i; int is_acx111 = IS_ACX111(adev); - if (acx_debug & L_DEBUG) { - printk("configoption struct content:\n"); - acx_dump_bytes(pcfg, sizeof(*pcfg)); - } + acx_log_dump(LOG_DEBUG, L_REALLYVERBOSE, pcfg, sizeof(*pcfg), + "configoption struct content:\n"); if ((is_acx111 && (adev->eeprom_version == 5)) || (!is_acx111 && (adev->eeprom_version == 4)) || (!is_acx111 && (adev->eeprom_version == 5))) { /* these versions are known to be supported */ } else { - printk("unknown chip and EEPROM version combination (%s, v%d), " - "don't know how to parse config options yet. " - "Please report\n", is_acx111 ? "ACX111" : "ACX100", - adev->eeprom_version); + acx_log(LOG_INFO, L_ANY, + "unknown chip and EEPROM version combination " + "(%s, v%d), " + "don't know how to parse config options yet. " + "Please report\n", is_acx111 ? "ACX111" : "ACX100", + adev->eeprom_version); return; } @@ -4822,8 +4786,9 @@ acx_s_parse_configoption(acx_device_t * adev, pEle += sizeof(adev->cfgopt_probe_delay); if ((adev->cfgopt_probe_delay < 100) || (adev->cfgopt_probe_delay > 500)) { - printk("strange probe_delay value %d, " - "tweaking to 200\n", adev->cfgopt_probe_delay); + acx_log(LOG_INFO, L_ANY, + "strange probe_delay value %d, " + "tweaking to 200\n", adev->cfgopt_probe_delay); adev->cfgopt_probe_delay = 200; } } @@ -4831,9 +4796,10 @@ acx_s_parse_configoption(acx_device_t * adev, adev->cfgopt_eof_memory = le32_to_cpu(*(u32 *) pEle); pEle += sizeof(adev->cfgopt_eof_memory); - printk("NVS_vendor_offs:%04X probe_delay:%d eof_memory:%d\n", - adev->cfgopt_NVS_vendor_offs, - adev->cfgopt_probe_delay, adev->cfgopt_eof_memory); + acx_log(LOG_INFO, L_ANY, "NVS_vendor_offs:%04X probe_delay:%d " + "eof_memory:%d\n", + adev->cfgopt_NVS_vendor_offs, adev->cfgopt_probe_delay, + adev->cfgopt_eof_memory); adev->cfgopt_dot11CCAModes = *pEle++; adev->cfgopt_dot11Diversity = *pEle++; @@ -4842,14 +4808,13 @@ acx_s_parse_configoption(acx_device_t * adev, adev->cfgopt_dot11ChannelAgility = *pEle++; adev->cfgopt_dot11PhyType = *pEle++; adev->cfgopt_dot11TempType = *pEle++; - printk("CCAModes:%02X Diversity:%02X ShortPreOpt:%02X " - "PBCC:%02X ChanAgil:%02X PHY:%02X Temp:%02X\n", - adev->cfgopt_dot11CCAModes, - adev->cfgopt_dot11Diversity, - adev->cfgopt_dot11ShortPreambleOption, - adev->cfgopt_dot11PBCCOption, - adev->cfgopt_dot11ChannelAgility, - adev->cfgopt_dot11PhyType, adev->cfgopt_dot11TempType); + acx_log(LOG_INFO, L_ANY, + "CCAModes:%02X Diversity:%02X ShortPreOpt:%02X " + "PBCC:%02X ChanAgil:%02X PHY:%02X Temp:%02X\n", + adev->cfgopt_dot11CCAModes, adev->cfgopt_dot11Diversity, + adev->cfgopt_dot11ShortPreambleOption, + adev->cfgopt_dot11PBCCOption, adev->cfgopt_dot11ChannelAgility, + adev->cfgopt_dot11PhyType, adev->cfgopt_dot11TempType); /* then use common parsing for next part which has common layout */ @@ -4857,8 +4822,12 @@ acx_s_parse_configoption(acx_device_t * adev, adev->cfgopt_antennas.type = pEle[0]; adev->cfgopt_antennas.len = pEle[1]; - printk("AntennaID:%02X Len:%02X Data:", - adev->cfgopt_antennas.type, adev->cfgopt_antennas.len); + + /* + * FIXME: a candidate for acx_log_dump(), but the code is bizarre + */ + acx_log(LOG_INFO, L_ANY, "AntennaID:%02X Len:%02X Data:", + adev->cfgopt_antennas.type, adev->cfgopt_antennas.len); for (i = 0; i < pEle[1]; i++) { adev->cfgopt_antennas.list[i] = pEle[i + 2]; printk("%02X ", pEle[i + 2]); @@ -4868,8 +4837,12 @@ acx_s_parse_configoption(acx_device_t * adev, pEle += pEle[1] + 2; adev->cfgopt_power_levels.type = pEle[0]; adev->cfgopt_power_levels.len = pEle[1]; - printk("PowerLevelID:%02X Len:%02X Data:", - adev->cfgopt_power_levels.type, adev->cfgopt_power_levels.len); + + /* + * FIXME: see above + */ + acx_log(LOG_INFO, L_ANY, "PowerLevelID:%02X Len:%02X Data:", + adev->cfgopt_power_levels.type, adev->cfgopt_power_levels.len); for (i = 0; i < pEle[1]; i++) { adev->cfgopt_power_levels.list[i] = le16_to_cpu(*(u16 *) & pEle[i * 2 + 2]); @@ -4880,8 +4853,12 @@ acx_s_parse_configoption(acx_device_t * adev, pEle += pEle[1] * 2 + 2; adev->cfgopt_data_rates.type = pEle[0]; adev->cfgopt_data_rates.len = pEle[1]; - printk("DataRatesID:%02X Len:%02X Data:", - adev->cfgopt_data_rates.type, adev->cfgopt_data_rates.len); + + /* + * FIXME again + */ + acx_log(LOG_INFO, L_ANY, "DataRatesID:%02X Len:%02X Data:", + adev->cfgopt_data_rates.type, adev->cfgopt_data_rates.len); for (i = 0; i < pEle[1]; i++) { adev->cfgopt_data_rates.list[i] = pEle[i + 2]; printk("%02X ", pEle[i + 2]); @@ -4891,8 +4868,12 @@ acx_s_parse_configoption(acx_device_t * adev, pEle += pEle[1] + 2; adev->cfgopt_domains.type = pEle[0]; adev->cfgopt_domains.len = pEle[1]; - printk("DomainID:%02X Len:%02X Data:", - adev->cfgopt_domains.type, adev->cfgopt_domains.len); + + /* + * And again + */ + acx_log(LOG_INFO, L_ANY, "DomainID:%02X Len:%02X Data:", + adev->cfgopt_domains.type, adev->cfgopt_domains.len); for (i = 0; i < pEle[1]; i++) { adev->cfgopt_domains.list[i] = pEle[i + 2]; printk("%02X ", pEle[i + 2]); @@ -4905,10 +4886,10 @@ acx_s_parse_configoption(acx_device_t * adev, for (i = 0; i < pEle[1]; i++) { adev->cfgopt_product_id.list[i] = pEle[i + 2]; } - printk("ProductID:%02X Len:%02X Data:%.*s\n", - adev->cfgopt_product_id.type, adev->cfgopt_product_id.len, - adev->cfgopt_product_id.len, - (char *)adev->cfgopt_product_id.list); + acx_log(LOG_INFO, L_ANY, "ProductID:%02X Len:%02X Data:%.*s\n", + adev->cfgopt_product_id.type, adev->cfgopt_product_id.len, + adev->cfgopt_product_id.len, + (char *)adev->cfgopt_product_id.list); pEle += pEle[1] + 2; adev->cfgopt_manufacturer.type = pEle[0]; @@ -4916,10 +4897,10 @@ acx_s_parse_configoption(acx_device_t * adev, for (i = 0; i < pEle[1]; i++) { adev->cfgopt_manufacturer.list[i] = pEle[i + 2]; } - printk("ManufacturerID:%02X Len:%02X Data:%.*s\n", - adev->cfgopt_manufacturer.type, adev->cfgopt_manufacturer.len, - adev->cfgopt_manufacturer.len, - (char *)adev->cfgopt_manufacturer.list); + acx_log(LOG_INFO, L_ANY, "ManufacturerID:%02X Len:%02X Data:%.*s\n", + adev->cfgopt_manufacturer.type, adev->cfgopt_manufacturer.len, + adev->cfgopt_manufacturer.len, + (char *)adev->cfgopt_manufacturer.list); /* printk("EEPROM part:\n"); for (i=0; i<58; i++) { @@ -4939,10 +4920,11 @@ static int __init acx_e_init_module(void) acx_struct_size_check(); - printk("acx: this driver is still EXPERIMENTAL\n" - "acx: reading README file and/or Craig's HOWTO is " - "recommended, visit http://acx100.sourceforge.net/wiki in case " - "of further questions/discussion\n"); + acx_log(LOG_INFO, L_ANY, "this driver is still EXPERIMENTAL\n"); + acx_log(LOG_INFO, L_ANY, "acx: reading README file and/or " + "Craig's HOWTO is recommended, " + "visit http://acx100.sourceforge.net/wiki in case " + "of further questions/discussion\n"); #if defined(CONFIG_ACX_MAC80211_PCI) r1 = acxpci_e_init_module(); diff --git a/log.c b/log.c new file mode 100644 index 0000000..489e614 --- /dev/null +++ b/log.c @@ -0,0 +1,240 @@ +/* + * log.c: logging framework. + * + * This file should disappear some day, when the driver is known to work + * reliably. Until then, this will contain all logging routines used everywhere + * in the code. + * + * Copyright (c) 2008, the ACX100 project (http://acx100.sourceforge.net). + * + * See the README file for licensing conditions. + */ +#include + +#include "acx_config.h" +#include "acx_log.h" + +/* + * Forward declarations + */ + +static void acx_dump_bytes(const char *prefix, const void *data, + ssize_t len); + +static const char *const printk_levels[MAX_LOG_LEVEL + 1] = { + KERN_WARNING, + KERN_INFO, + KERN_DEBUG +}; + +/** + * acx_log: the logging function + * @level: what level to log (LOG_WARNING, LOG_INFO or LOG_DEBUG). + * @what: what channel to log (any of the L_* values defined in acx_log.h). + * @fmt: the format string, and its arguments if any. + * + */ + +void acx_log(int level, int what, const char *fmt, ...) +{ + va_list args; + const char *printk_level; + + if (level > ACX_LOG_LEVEL) + return; + if (!(what & ACX_DEFAULT_MSG)) + return; + + /* + * FIXME: this shouldn't be necessary, but I don't rely on luck + */ + if (level > MAX_LOG_LEVEL) + level = MAX_LOG_LEVEL; + + printk_level = printk_levels[level]; + va_start(args, fmt); + + printk("%sacx: ", printk_level); + vprintk(fmt, args); + va_end(args); + + return; +} + +/** + * acx_log_dump(): logs a message, and dumps a buffer. Basically, this is + * acx_log(), and a call to acx_dump_bytes() below. + * @level: see acx_log(). + * @what: see acx_log(). + * @buf: the buffer to dump. + * @buflen: the length of the buffer to dump. + */ + +void acx_log_dump(int level, int what, const void *buf, ssize_t buflen, + const char *fmt, ...) +{ + va_list args; + const char *printk_level; + + if (level > ACX_LOG_LEVEL) + return; + if (!(what & ACX_DEFAULT_MSG)) + return; + + /* + * FIXME: this shouldn't be necessary, but I don't rely on luck + */ + if (level > MAX_LOG_LEVEL) + level = MAX_LOG_LEVEL; + + printk_level = printk_levels[level]; + va_start(args, fmt); + + acx_log(level, what, fmt, args); + acx_dump_bytes(printk_level, buf, buflen); +} +/** + * acx_log_ratelimited: like acx_log(), but rate limited via printk_ratelimit(). + * Note that we log anyway if ACX_LOG_LEVEL is 2. + */ +void acx_log_ratelimited(int level, int what, const char *fmt, ...) +{ + va_list args; + + if (ACX_LOG_LEVEL < 2) + if (printk_ratelimit()) + return; + + va_start(args, fmt); + acx_log(level, what, fmt, args); + va_end(args); +} + +/** + * acx_dump_bytes: hex dump of a buffer + * @printk_prefix: the KERN_* char constant, passed to this function by + * acx_log(). + * @buf: the buffer to dump. + * @buflen: the length of the buffer. + * + * This function is static: it's not supposed to be called from anywhere else + * than this file. There is no "acx:" prefix here. + */ +static void acx_dump_bytes(const char *printk_prefix, const void *data, + ssize_t len) +{ + const u8 *ptr = (const u8 *)data; + unsigned int size = 0; + /* + * buf holds: + * - the printk prefix (3 bytes); + * - the size printed as "0x%08X" (10 bytes); + * - the following semicolon (1 bytes); + * - 16 bytes printed as " %02X" (48 bytes); + * - the final '\0' (1 byte). + */ + char buf[63], *p; + + printk("%s--- BEGIN DUMP (%d bytes) ---\n", printk_prefix, + (int) len); + + if (len <= 0) + return; + + goto inside; + + do { + p += sprintf(p, " %02X", *ptr); + size++, ptr++; + if (size % 16) + continue; + printk("%s\n", buf); +inside: + p = buf; + p += sprintf(p, "%s0x%08X:", printk_prefix, size); + } while (size < len); + + if (size % 16) + printk("%s\n", buf); + + printk("%s--- END DUMP ---\n", printk_prefix); +} +/* + * Only in case of heavy debugging + */ + +#if ACX_LOG_LEVEL == 2 + +/** + * __function_enter_exit: display entering/exiting of a function + * @fname: the function name. + * @enter_exit: 0 on enter, 1 on exit, 2 on exit with return value to be + * printed. + * @retcode: the return code to be printed if enter_exit is 2. + */ + +#define DEBUG_TSC 0 + +#if DEBUG_TSC +#define TIMESTAMP(d) unsigned long d; rdtscl(d) +#else +#define TIMESTAMP(d) unsigned long d = jiffies +#endif + +/* + * MAX_INDENT is the size of the spaces[] string below. + */ +#define MAX_INDENT 10 +void __function_enter_exit(const char *fname, int enter_exit, + int retcode) +{ + static int indent = 0; + static const char spaces[] = " "; + const char *p = spaces + MAX_INDENT; + /* + * Note that we MUST "declare" TIMESTAMP last: in case DEBUG_TSC is set, + * an rdtscl() is done on the argument, and, well, that's C. + */ + TIMESTAMP(stamp); + stamp = stamp % 1000000; + + switch (enter_exit) { + case __FUNCTION_ENTER: + if (indent < MAX_INDENT) + indent++; + break; + case __FUNCTION_EXIT: + case __FUNCTION_EXIT_WITHARG: + /* Nothing */ + break; + default: /* Meh? */ + return; + } + + p -= indent; + + switch (enter_exit) { + case __FUNCTION_ENTER: + acx_log(LOG_DEBUG, L_FUNC, "%08ld %s-> %s\n", + stamp, p, fname); + break; + case __FUNCTION_EXIT: + acx_log(LOG_DEBUG, L_FUNC, "%08ld %s<- %s\n", + stamp, p, fname); + break; + case __FUNCTION_EXIT_WITHARG: + acx_log(LOG_DEBUG, L_FUNC, "%08ld %s<- %s: %08X\n", + stamp, p, fname, retcode); + } + + /* + * The below test is enough: we already sanitized away illegal values of + * enter_exit at the beginning. + */ + if (enter_exit != __FUNCTION_ENTER) + indent--; + +} + +#endif /* ACX_LOG_LEVEL == 2 */ + diff --git a/pci.c b/pci.c index dcfe727..8f68379 100644 --- a/pci.c +++ b/pci.c @@ -35,6 +35,7 @@ #endif #include "acx.h" +#include "acx_log.h" /*********************************************************************** */ @@ -187,12 +188,12 @@ static txhostdesc_t *get_txhostdesc(acx_device_t * adev, txdesc_t * txdesc) FN_ENTER; if (unlikely(ACX_DEBUG && (index % adev->txdesc_size))) { - printk("bad txdesc ptr %p\n", txdesc); + acx_log(LOG_INFO, L_ANY, "bad txdesc ptr %p\n", txdesc); return NULL; } index /= adev->txdesc_size; if (unlikely(ACX_DEBUG && (index >= TX_CNT))) { - printk("bad txdesc ptr %p\n", txdesc); + acx_log(LOG_INFO, L_ANY, "bad txdesc ptr %p\n", txdesc); return NULL; } @@ -242,8 +243,9 @@ int acxpci_read_eeprom_byte(acx_device_t * adev, u32 addr, u8 * charbuf) * awful delay, sometimes also failure. * Doesn't matter anyway (only small delay). */ if (unlikely(!--count)) { - printk("%s: timeout waiting for EEPROM read\n", - wiphy_name(adev->ieee->wiphy)); + acx_log(LOG_INFO, L_ANY, + "%s: timeout waiting for EEPROM read\n", + wiphy_name(adev->ieee->wiphy)); result = NOT_OK; goto fail; } @@ -251,7 +253,8 @@ int acxpci_read_eeprom_byte(acx_device_t * adev, u32 addr, u8 * charbuf) } *charbuf = read_reg8(adev, IO_ACX_EEPROM_DATA); - log(L_DEBUG, "EEPROM at 0x%04X = 0x%02X\n", addr, *charbuf); + acx_log(LOG_DEBUG, L_REALLYVERBOSE, "EEPROM at 0x%04X = 0x%02X\n", + addr, *charbuf); result = OK; fail: @@ -275,15 +278,15 @@ acxpci_s_write_eeprom(acx_device_t * adev, u32 addr, u32 len, int result = NOT_OK; u16 gpio_orig; - printk("acx: WARNING! I would write to EEPROM now. " - "Since I really DON'T want to unless you know " - "what you're doing (THIS CODE WILL PROBABLY " - "NOT WORK YET!), I will abort that now. And " - "definitely make sure to make a " - "/proc/driver/acx_wlan0_eeprom backup copy first!!! " - "(the EEPROM content includes the PCI config header!! " - "If you kill important stuff, then you WILL " - "get in trouble and people DID get in trouble already)\n"); + acx_log(LOG_INFO, L_ANY, "WARNING! I would write to EEPROM now. " + "Since I really DON'T want to unless you know " + "what you're doing (THIS CODE WILL PROBABLY " + "NOT WORK YET!), I will abort that now. And " + "definitely make sure to make a " + "/proc/driver/acx_wlan0_eeprom backup copy first!!! " + "(the EEPROM content includes the PCI config header!! " + "If you kill important stuff, then you WILL " + "get in trouble and people DID get in trouble already)\n"); return OK; FN_ENTER; @@ -314,8 +317,8 @@ acxpci_s_write_eeprom(acx_device_t * adev, u32 addr, u32 len, count = 0xffff; while (read_reg16(adev, IO_ACX_EEPROM_CTL)) { if (unlikely(!--count)) { - printk("WARNING, DANGER!!! " - "Timeout waiting for EEPROM write\n"); + acx_log(LOG_INFO, L_ANY, "WARNING, DANGER!!! " + "Timeout waiting for EEPROM write\n"); goto end; } cpu_relax(); @@ -336,7 +339,8 @@ acxpci_s_write_eeprom(acx_device_t * adev, u32 addr, u32 len, count = 0xffff; while (read_reg16(adev, IO_ACX_EEPROM_CTL)) { if (unlikely(!--count)) { - printk("timeout waiting for EEPROM read\n"); + acx_log(LOG_INFO, L_ANY, + "timeout waiting for EEPROM read\n"); goto end; } cpu_relax(); @@ -380,18 +384,20 @@ int acxpci_s_read_phy_reg(acx_device_t * adev, u32 reg, u8 * charbuf) * awful delay, sometimes also failure. * Doesn't matter anyway (only small delay). */ if (unlikely(!--count)) { - printk("%s: timeout waiting for phy read\n", - wiphy_name(adev->ieee->wiphy)); + acx_log(LOG_INFO, L_ANY, + "%s: timeout waiting for phy read\n", + wiphy_name(adev->ieee->wiphy)); *charbuf = 0; goto fail; } cpu_relax(); } - log(L_DEBUG, "count was %u\n", count); + acx_log(LOG_DEBUG, L_REALLYVERBOSE, "count was %u\n", count); *charbuf = read_reg8(adev, IO_ACX_PHY_DATA); - log(L_DEBUG, "radio PHY at 0x%04X = 0x%02X\n", *charbuf, reg); + acx_log(LOG_DEBUG, L_REALLYVERBOSE, "radio PHY at 0x%04X = 0x%02X\n", + *charbuf, reg); result = OK; goto fail; /* silence compiler warning */ fail: @@ -414,7 +420,9 @@ int acxpci_s_write_phy_reg(acx_device_t * adev, u32 reg, u8 value) write_flush(adev); write_reg32(adev, IO_ACX_PHY_CTL, 1); write_flush(adev); - log(L_DEBUG, "radio PHY write 0x%02X at 0x%04X\n", value, reg); + acx_log(LOG_DEBUG, L_REALLYVERBOSE, + "radio PHY write 0x%02X at 0x%04X\n", + value, reg); FN_EXIT0; return OK; @@ -480,8 +488,9 @@ acxpci_s_write_fw(acx_device_t * adev, const firmware_image_t *fw_image, write_reg32(adev, IO_ACX_SLV_MEM_DATA, v32); } - log(L_DEBUG, "firmware written, size:%d sum1:%x sum2:%x\n", - size, sum, le32_to_cpu(fw_image->chksum)); + acx_log(LOG_DEBUG, L_REALLYVERBOSE, + "firmware written, size:%d sum1:%x sum2:%x\n", + size, sum, le32_to_cpu(fw_image->chksum)); /* compare our checksum with the stored image checksum */ FN_EXIT1(sum != le32_to_cpu(fw_image->chksum)); @@ -544,11 +553,12 @@ acxpci_s_validate_fw(acx_device_t * adev, const firmware_image_t *fw_image, w32 = read_reg32(adev, IO_ACX_SLV_MEM_DATA); if (unlikely(w32 != v32)) { - printk("acx: FATAL: firmware upload: " - "data parts at offset %d don't match (0x%08X vs. 0x%08X)! " - "I/O timing issues or defective memory, with DWL-xx0+? " - "ACX_IO_WIDTH=16 may help. Please report\n", - len, v32, w32); + acx_log(LOG_INFO, L_ANY,"FATAL: firmware upload: " + "data parts at offset %d don't match " + "(0x%08X vs. 0x%08X)! I/O timing issues " + "or defective memory, with DWL-xx0+? " + "ACX_IO_WIDTH=16 may help. Please report\n", + len, v32, w32); result = NOT_OK; break; } @@ -561,8 +571,8 @@ acxpci_s_validate_fw(acx_device_t * adev, const firmware_image_t *fw_image, /* sum control verification */ if (result != NOT_OK) { if (sum != le32_to_cpu(fw_image->chksum)) { - printk("acx: FATAL: firmware upload: " - "checksums don't match!\n"); + acx_log(LOG_INFO, L_ANY, "FATAL: firmware upload: " + "checksums don't match!\n"); result = NOT_OK; } } @@ -593,23 +603,30 @@ static int acxpci_s_upload_fw(acx_device_t * adev) * really get a clue on which files exactly they need to provide. * Firmware loading is a frequent end-user PITA with these chipsets. */ - printk( "acx: need firmware for acx1%02d chipset with radio ID %02X\n" - "Please provide via firmware hotplug:\n" - "either combined firmware (single file named 'tiacx1%02dc%02X')\n" + acx_log(LOG_INFO, L_ANY, + "need firmware for acx1%02d chipset " + "with radio ID %02X\n", + IS_ACX111(adev)*11, adev->radio_type); + acx_log(LOG_INFO, L_ANY, "Please provide via firmware hotplug:\n"); + acx_log(LOG_INFO, L_ANY, "either combined firmware " + "(single file named 'tiacx1%02dc%02X')\n" "or two files (base firmware file 'tiacx1%02d' " "+ radio fw 'tiacx1%02dr%02X')\n", IS_ACX111(adev)*11, adev->radio_type, - IS_ACX111(adev)*11, adev->radio_type, IS_ACX111(adev)*11, IS_ACX111(adev)*11, adev->radio_type ); - /* print exact chipset and radio ID to make sure people really get a clue on which files exactly they are supposed to provide, - * since firmware loading is the biggest enduser PITA with these chipsets. - * Not printing radio ID in 0xHEX in order to not confuse them into wrong file naming */ - printk( "acx: need to load firmware for acx1%02d chipset with radio ID %02x, please provide via firmware hotplug:\n" - "acx: either one file only (ombined firmware image file, radio-specific) or two files (radio-less base image file *plus* separate adio-specific extension file)\n", - IS_ACX111(adev)*11, adev->radio_type); + /* print exact chipset and radio ID to make sure people really get a + * clue on which files exactly they are supposed to provide, since + * firmware loading is the biggest enduser PITA with these chipsets. + * Not printing radio ID in 0xHEX in order to not confuse them into + * wrong file naming + * COMMENTED OUT: this was already printed above + */ +// printk( "acx: need to load firmware for acx1%02d chipset with radio ID %02x, please provide via firmware hotplug:\n" +// "acx: either one file only (ombined firmware image file, radio-specific) or two files (radio-less base image file *plus* separate adio-specific extension file)\n", +// IS_ACX111(adev)*11, adev->radio_type); /* Try combined, then main image */ adev->need_radio_fw = 0; @@ -630,19 +647,21 @@ static int acxpci_s_upload_fw(acx_device_t * adev) for (try = 1; try <= 5; try++) { res = acxpci_s_write_fw(adev, fw_image, 0); - log(L_DEBUG | L_INIT, "acx_write_fw (main/combined): %d\n", res); + acx_log(LOG_DEBUG, L_INIT | L_REALLYVERBOSE, + "acx_write_fw (main/combined): %d\n", res); if (OK == res) { res = acxpci_s_validate_fw(adev, fw_image, 0); - log(L_DEBUG | L_INIT, "acx_validate_fw " - "(main/combined): %d\n", res); + acx_log(LOG_DEBUG, L_INIT | L_REALLYVERBOSE, + "acx_validate_fw (main/combined): %d\n", res); } if (OK == res) { SET_BIT(adev->dev_state_mask, ACX_STATE_FW_LOADED); break; } - printk("acx: firmware upload attempt #%d FAILED, " - "retrying...\n", try); + acx_log(LOG_INFO, L_ANY, + "firmware upload attempt #%d FAILED, " + "retrying...\n", try); acx_s_mwait(1000); /* better wait for a while... */ } @@ -683,7 +702,8 @@ int acxpci_s_upload_radio(acx_device_t * adev) IS_ACX111(adev) * 11, adev->radio_type); radio_image = acx_s_read_fw(adev->bus_dev, filename, &size); if (!radio_image) { - printk("acx: can't load radio module '%s'\n", filename); + acx_log(LOG_INFO, L_ANY, "can't load radio module '%s'\n", + filename); goto fail; } @@ -691,17 +711,19 @@ int acxpci_s_upload_radio(acx_device_t * adev) for (try = 1; try <= 5; try++) { res = acxpci_s_write_fw(adev, radio_image, offset); - log(L_DEBUG | L_INIT, "acx_write_fw (radio): %d\n", res); + acx_log(LOG_DEBUG, L_INIT | L_REALLYVERBOSE, + "acx_write_fw (radio): %d\n", res); if (OK == res) { res = acxpci_s_validate_fw(adev, radio_image, offset); - log(L_DEBUG | L_INIT, "acx_validate_fw (radio): %d\n", - res); + acx_log(LOG_DEBUG, L_INIT | L_REALLYVERBOSE, + "acx_validate_fw (radio): %d\n", res); } if (OK == res) break; - printk("acx: radio firmware upload attempt #%d FAILED, " - "retrying...\n", try); + acx_log(LOG_INFO, L_ANY, + "radio firmware upload attempt #%d FAILED, " + "retrying...\n", try); acx_s_mwait(1000); /* better wait for a while... */ } @@ -747,12 +769,13 @@ static void acxpci_l_reset_mac(acx_device_t * adev) /* now do soft reset of eCPU, set bit */ temp = read_reg16(adev, IO_ACX_SOFT_RESET) | 0x1; - log(L_DEBUG, "enable soft reset\n"); + acx_log(LOG_DEBUG, L_REALLYVERBOSE, "enable soft reset\n"); write_reg16(adev, IO_ACX_SOFT_RESET, temp); write_flush(adev); /* now clear bit again: deassert eCPU reset */ - log(L_DEBUG, "disable soft reset and go to init mode\n"); + acx_log(LOG_DEBUG, L_REALLYVERBOSE, + "disable soft reset and go to init mode\n"); write_reg16(adev, IO_ACX_SOFT_RESET, temp & ~0x1); /* now start a burst read from initial EEPROM */ @@ -833,8 +856,8 @@ static u32 acxpci_read_cmd_type_status(acx_device_t * adev) cmd_status = (cmd_type >> 16); cmd_type = (u16) cmd_type; - log(L_CTL, "cmd_type:%04X cmd_status:%04X [%s]\n", - cmd_type, cmd_status, acx_cmd_status_str(cmd_status)); + acx_log(LOG_DEBUG, L_CTL, "cmd_type:%04X cmd_status:%04X [%s]\n", + cmd_type, cmd_status, acx_cmd_status_str(cmd_status)); FN_EXIT1(cmd_status); return cmd_status; @@ -868,11 +891,12 @@ static inline void init_mboxes(acx_device_t * adev) info_offs = read_reg32(adev, IO_ACX_INFO_MAILBOX_OFFS); adev->cmd_area = (u8 *) adev->iobase2 + cmd_offs; adev->info_area = (u8 *) adev->iobase2 + info_offs; - log(L_DEBUG, "iobase2=%p\n" - "cmd_mbox_offset=%X cmd_area=%p\n" - "info_mbox_offset=%X info_area=%p\n", - adev->iobase2, - cmd_offs, adev->cmd_area, info_offs, adev->info_area); + acx_log(LOG_DEBUG, L_REALLYVERBOSE, "iobase2=%p\n", adev->iobase2); + acx_log(LOG_DEBUG, L_REALLYVERBOSE, "cmd_mbox_offset=%X cmd_area=%p\n", + cmd_offs, adev->cmd_area); + acx_log(LOG_DEBUG, L_REALLYVERBOSE, + "info_mbox_offset=%X info_area=%p\n", + info_offs, adev->info_area); FN_EXIT0; } @@ -964,14 +988,16 @@ int acxpci_s_reset_dev(acx_device_t * adev) /* now start eCPU by clearing bit */ write_reg16(adev, IO_ACX_ECPU_CTRL, ecpu_ctrl & ~0x1); - log(L_DEBUG, "booted eCPU up and waiting for completion...\n"); + acx_log(LOG_DEBUG, L_REALLYVERBOSE, + "booted eCPU up and waiting for completion...\n"); /* wait for eCPU bootup */ if (OK != acxpci_s_verify_init(adev)) { msg = "timeout waiting for eCPU. "; goto end_fail; } - log(L_DEBUG, "eCPU has woken up, card is ready to be configured\n"); + acx_log(LOG_DEBUG, L_REALLYVERBOSE, + "eCPU has woken up, card is ready to be configured\n"); init_mboxes(adev); acxpci_write_cmd_type_status(adev, 0, 0); @@ -986,7 +1012,7 @@ int acxpci_s_reset_dev(acx_device_t * adev) end_unlock: acx_unlock(adev, flags); end_fail: - printk("acx: %sreset_dev() FAILED\n", msg); + acx_log(LOG_INFO, L_ANY, "%sreset_dev() FAILED\n", msg); end: FN_EXIT1(result); return result; @@ -1036,20 +1062,21 @@ acxpci_s_issue_cmd_timeo_debug(acx_device_t * adev, if (!devname || !devname[0] || devname[4] == '%') devname = "acx"; - log(L_CTL, FUNC "(cmd:%s,buflen:%u,timeout:%ums,type:0x%04X)\n", - cmdstr, buflen, cmd_timeout, - buffer ? le16_to_cpu(((acx_ie_generic_t *) buffer)->type) : -1); + acx_log(LOG_DEBUG, L_CTL, + FUNC "(cmd:%s,buflen:%u,timeout:%ums,type:0x%04X)\n", + cmdstr, buflen, cmd_timeout, + buffer ? le16_to_cpu(((acx_ie_generic_t *) buffer)->type) : -1); if (!(adev->dev_state_mask & ACX_STATE_FW_LOADED)) { - printk("%s: " FUNC "(): firmware is not loaded yet, " - "cannot execute commands!\n", devname); + acx_log(LOG_INFO, L_ANY, + "%s: " FUNC "(): firmware is not loaded yet, " + "cannot execute commands!\n", devname); goto bad; } - if ((acx_debug & L_DEBUG) && (cmd != ACX1xx_CMD_INTERROGATE)) { - printk("input buffer (len=%u):\n", buflen); - acx_dump_bytes(buffer, buflen); - } + if (cmd != ACX1xx_CMD_INTERROGATE) + acx_log_dump(LOG_DEBUG, L_REALLYVERBOSE, buffer, buflen, + "input buffer: "); /* wait for firmware to become idle for our command submission */ timeout = HZ / 5; @@ -1072,12 +1099,14 @@ acxpci_s_issue_cmd_timeo_debug(acx_device_t * adev, if (!counter) { /* the card doesn't get idle, we're in trouble */ - printk("%s: " FUNC "(): cmd_status is not IDLE: 0x%04X!=0\n", - devname, cmd_status); + acx_log(LOG_INFO, L_ANY, + "%s: " FUNC "(): cmd_status is not IDLE: 0x%04X!=0\n", + devname, cmd_status); goto bad; } else if (counter < 190) { /* if waited >10ms... */ - log(L_CTL | L_DEBUG, FUNC "(): waited for IDLE %dms. " - "Please report\n", 199 - counter); + acx_log(LOG_DEBUG, L_CTL | L_REALLYVERBOSE, + FUNC "(): waited for IDLE %dms. " + "Please report\n", 199 - counter); } /* now write the parameters of the command if needed */ @@ -1142,30 +1171,37 @@ acxpci_s_issue_cmd_timeo_debug(acx_device_t * adev, acxpci_write_cmd_type_status(adev, 0, 0); if ((cmd_timeout - counter) == 0) { /* timed out! */ - printk("%s: " FUNC "(): timed out %s for CMD_COMPLETE. " - "irq bits:0x%04X irq_status:0x%04X timeout:%dms " - "cmd_status:%d (%s)\n", - devname, (adev->irqs_active) ? "waiting" : "polling", - irqtype, adev->irq_status, cmd_timeout, - cmd_status, acx_cmd_status_str(cmd_status)); - printk("hack: don't do: 'goto bad;'\ncounter: %d cmd_timeout: %d cmd_timeout-counter: %d\n",counter, cmd_timeout, cmd_timeout - counter); + acx_log(LOG_INFO, L_ANY, + "%s: " FUNC "(): timed out %s for CMD_COMPLETE. " + "irq bits:0x%04X irq_status:0x%04X timeout:%dms " + "cmd_status:%d (%s)\n", + devname, (adev->irqs_active) ? "waiting" : "polling", + irqtype, adev->irq_status, cmd_timeout, + cmd_status, acx_cmd_status_str(cmd_status)); + acx_log(LOG_INFO, L_ANY, "hack: don't do: 'goto bad;' " + "counter: %d, cmd_timeout: %d, " + "cmd_timeout-counter: %d\n", + counter, cmd_timeout, cmd_timeout - counter); } else if (counter == 0) { /* maybe timed out! */ - log(L_CTL | L_DEBUG, FUNC "(): %s for CMD_COMPLETE %dms. " - "count:%d. Please report\n", - (adev->irqs_active) ? "waited" : "polled", - cmd_timeout - counter, counter); + acx_log(LOG_DEBUG, L_CTL | L_REALLYVERBOSE, + FUNC "(): %s for CMD_COMPLETE %dms. " + "count:%d. Please report\n", + (adev->irqs_active) ? "waited" : "polled", + cmd_timeout - counter, counter); } else if ((cmd_timeout - counter) > 30) { /* if waited >30ms... */ - log(L_CTL | L_DEBUG, FUNC "(): %s for CMD_COMPLETE %dms. " - "count:%d. Please report\n", - (adev->irqs_active) ? "waited" : "polled", - cmd_timeout - counter, counter); + acx_log(LOG_DEBUG, L_CTL | L_REALLYVERBOSE, + FUNC "(): %s for CMD_COMPLETE %dms. " + "count:%d. Please report\n", + (adev->irqs_active) ? "waited" : "polled", + cmd_timeout - counter, counter); } if (1 != cmd_status) { /* it is not a 'Success' */ - printk("%s: " FUNC "(): cmd_status is not SUCCESS: %d (%s). " - "Took %dms of %d\n", - devname, cmd_status, acx_cmd_status_str(cmd_status), - cmd_timeout - counter, cmd_timeout); + acx_log(LOG_INFO, L_ANY, + "%s: " FUNC "(): cmd_status is not SUCCESS: %d (%s). " + "Took %dms of %d\n", + devname, cmd_status, acx_cmd_status_str(cmd_status), + cmd_timeout - counter, cmd_timeout); /* zero out result buffer * WARNING: this will trash stack in case of illegally large input * length! */ @@ -1178,14 +1214,12 @@ acxpci_s_issue_cmd_timeo_debug(acx_device_t * adev, if (buffer && buflen && (cmd == ACX1xx_CMD_INTERROGATE)) { /* adev->cmd_area points to PCI device's memory, not to RAM! */ memcpy_fromio(buffer, adev->cmd_area + 4, buflen); - if (acx_debug & L_DEBUG) { - printk("output buffer (len=%u): ", buflen); - acx_dump_bytes(buffer, buflen); - } + acx_log_dump(LOG_DEBUG, L_REALLYVERBOSE, buffer, buflen, + "output buffer:\n"); } /* ok: */ - log(L_CTL, FUNC "(%s): took %ld jiffies to complete\n", - cmdstr, jiffies - start); + acx_log(LOG_DEBUG, L_CTL, FUNC "(%s): took %ld jiffies to complete\n", + cmdstr, jiffies - start); FN_EXIT1(OK); return OK; @@ -1193,9 +1227,11 @@ acxpci_s_issue_cmd_timeo_debug(acx_device_t * adev, /* Give enough info so that callers can avoid ** printing their own diagnostic messages */ #if ACX_DEBUG - printk("%s: " FUNC "(cmd:%s) FAILED\n", devname, cmdstr); + acx_log(LOG_INFO, L_ANY, + "%s: " FUNC "(cmd:%s) FAILED\n", devname, cmdstr); #else - printk("%s: " FUNC "(cmd:0x%04X) FAILED\n", devname, cmd); + acx_log(LOG_INFO, L_ANY, + "%s: " FUNC "(cmd:0x%04X) FAILED\n", devname, cmd); #endif dump_stack(); FN_EXIT1(NOT_OK); @@ -1249,25 +1285,28 @@ static void acx_show_card_eeprom_id(acx_device_t * adev) if (OK != acxpci_read_eeprom_byte(adev, ACX100_EEPROM_ID_OFFSET + i, &buffer[i])) { - printk("acx: reading EEPROM FAILED\n"); + acx_log(LOG_DEBUG, L_ANY, "reading EEPROM FAILED\n"); break; } } for (i = 0; i < ARRAY_SIZE(device_ids); i++) { - if (!memcmp(&buffer, device_ids[i].id, CARD_EEPROM_ID_SIZE)) { - if (device_ids[i].descr) { - printk("acx: EEPROM card ID string check " - "found %s card ID: is this %s?\n", - device_ids[i].descr, device_ids[i].type); - } - break; + if (memcmp(&buffer, device_ids[i].id, CARD_EEPROM_ID_SIZE)) + continue; + if (device_ids[i].descr) { + acx_log(LOG_INFO, L_ANY, + "EEPROM card ID string check " + "found %s card ID: is this %s?\n", + device_ids[i].descr, + device_ids[i].type); } + break; } if (i == ARRAY_SIZE(device_ids)) { - printk("acx: EEPROM card ID string check found " - "unknown card: expected 'Global', got '%.*s\'. " - "Please report\n", CARD_EEPROM_ID_SIZE, buffer); + acx_log(LOG_INFO, L_ANY, + "EEPROM card ID string check found " + "unknown card: expected 'Global', got '%.*s\'. " + "Please report\n", CARD_EEPROM_ID_SIZE, buffer); } FN_EXIT0; } @@ -1486,8 +1525,9 @@ acxpci_e_probe(struct pci_dev *pdev, const struct pci_device_id *id) ieee = ieee80211_alloc_hw(sizeof(struct acx_device), &acxpci_hw_ops); if (!ieee) { - printk("acx: could not allocate ieee80211 structure %s\n", - pci_name(pdev)); + acx_log(LOG_INFO, L_ANY, + "could not allocate ieee80211 structure %s\n", + pci_name(pdev)); goto fail_alloc_netdev; } ieee->flags &= ~IEEE80211_HW_RX_INCLUDES_FCS; @@ -1504,7 +1544,8 @@ acxpci_e_probe(struct pci_dev *pdev, const struct pci_device_id *id) /** Set up our private interface **/ spin_lock_init(&adev->spinlock); /* initial state: unlocked */ /* We do not start with downed sem: we want PARANOID_LOCKING to work */ - printk("mutex_init(&adev->mutex); // adev = 0x%px\n", adev); + acx_log(LOG_INFO, L_ANY, + "mutex_init(&adev->mutex); // adev = 0x%px\n", adev); mutex_init(&adev->mutex); /* since nobody can see new netdev yet, we can as well ** just _presume_ that we're under sem (instead of actually taking it): */ @@ -1521,7 +1562,7 @@ acxpci_e_probe(struct pci_dev *pdev, const struct pci_device_id *id) /* Enable the PCI device */ if (pci_enable_device(pdev)) { - printk("acx: pci_enable_device() FAILED\n"); + acx_log(LOG_INFO, L_ANY, "pci_enable_device() FAILED\n"); result = -ENODEV; goto fail_pci_enable_device; } @@ -1549,7 +1590,8 @@ acxpci_e_probe(struct pci_dev *pdev, const struct pci_device_id *id) mem_region2 = PCI_ACX111_REGION2; mem_region2_size = PCI_ACX111_REGION2_SIZE; } else { - printk("acx: unknown chip type 0x%04X\n", chip_type); + acx_log(LOG_INFO, L_ANY, + "unknown chip type 0x%04X\n", chip_type); goto fail_unknown_chiptype; } @@ -1559,7 +1601,7 @@ acxpci_e_probe(struct pci_dev *pdev, const struct pci_device_id *id) */ err = pci_request_region(pdev, mem_region1, "acx_1"); if (err) { - printk(KERN_WARNING "acx: pci_request_region (1/2) FAILED!" + acx_log(LOG_INFO, L_ANY, "pci_request_region (1/2) FAILED!" "No cardbus support in kernel?\n"); goto fail_request_mem_region1; } @@ -1568,7 +1610,7 @@ acxpci_e_probe(struct pci_dev *pdev, const struct pci_device_id *id) err = pci_request_region(pdev, mem_region2, "acx_2"); if (err) { - printk(KERN_WARNING "acx: pci_request_region (2/2) FAILED!\n"); + acx_log(LOG_INFO, L_ANY, "pci_request_region (2/2) FAILED!\n"); goto fail_request_mem_region2; } @@ -1583,22 +1625,22 @@ acxpci_e_probe(struct pci_dev *pdev, const struct pci_device_id *id) mem1 = pci_iomap(pdev, mem_region1, 0); if (!mem1) { - printk(KERN_WARNING "acx: ioremap() FAILED\n"); + acx_log(LOG_INFO, L_ANY, "ioremap() FAILED\n"); goto fail_ioremap1; } mem2 = pci_iomap(pdev, mem_region2, 0); if (!mem2) { - printk(KERN_WARNING "acx: ioremap() #2 FAILED\n"); + acx_log(LOG_INFO, L_ANY, "ioremap() #2 FAILED\n"); goto fail_ioremap2; } - printk("acx: found %s-based wireless network card at %s, irq:%d, " - "phymem1:0x%lX, phymem2:0x%lX, mem1:0x%p, mem1_size:%ld, " - "mem2:0x%p, mem2_size:%ld\n", - chip_name, pci_name(pdev), pdev->irq, phymem1, phymem2, - mem1, mem_region1_size, mem2, mem_region2_size); - log(L_ANY, "initial debug setting is 0x%04X\n", acx_debug); + acx_log(LOG_INFO, L_ANY, "found %s-based wireless network card at %s, " + "irq:%d, phymem1:0x%lX, phymem2:0x%lX, mem1:0x%p, " + "mem1_size:%ld, mem2:0x%p, mem2_size:%ld\n", + chip_name, pci_name(pdev), pdev->irq, phymem1, phymem2, + mem1, mem_region1_size, mem2, mem_region2_size); + //log(L_ANY, "initial debug setting is 0x%04X\n", acx_debug); adev->chip_type = chip_type; adev->chip_name = chip_name; adev->io = (CHIPTYPE_ACX100 == chip_type) ? IO_ACX100 : IO_ACX111; @@ -1610,7 +1652,7 @@ acxpci_e_probe(struct pci_dev *pdev, const struct pci_device_id *id) if (0 == pdev->irq) { - printk("acx: can't use IRQ 0\n"); + acx_log(LOG_INFO, L_ANY, "can't use IRQ 0\n"); goto fail_irq; } SET_IEEE80211_DEV(ieee, &pdev->dev); @@ -1618,11 +1660,13 @@ acxpci_e_probe(struct pci_dev *pdev, const struct pci_device_id *id) /* request shared IRQ handler */ if (request_irq (adev->irq, acxpci_i_interrupt, IRQF_SHARED, KBUILD_MODNAME, adev)) { - printk("%s: request_irq FAILED\n", wiphy_name(adev->ieee->wiphy)); + acx_log(LOG_INFO, L_ANY, "%s: request_irq FAILED\n", + wiphy_name(adev->ieee->wiphy)); result = -EAGAIN; goto done; } - log(L_DEBUG | L_IRQ, "request_irq %d successful\n", adev->irq); + acx_log(LOG_DEBUG, L_IRQ | L_REALLYVERBOSE, + "request_irq %d successful\n", adev->irq); /* to find crashes due to weird driver access * to unconfigured interface (ifup) */ @@ -1678,13 +1722,14 @@ acxpci_e_probe(struct pci_dev *pdev, const struct pci_device_id *id) * (in particular, on other CPUs), we only need to up the sem */ /* acx_sem_unlock(adev); */ - printk("acx " ACX_RELEASE ": net device %s, driver compiled " - "against wireless extensions %d and Linux %s\n", - wiphy_name(adev->ieee->wiphy), WIRELESS_EXT, UTS_RELEASE); + acx_log(LOG_INFO, L_ANY, "driver version " ACX_RELEASE + ": net device %s, driver compiled " + "against wireless extensions %d and Linux %s\n", + wiphy_name(adev->ieee->wiphy), WIRELESS_EXT, UTS_RELEASE); MAC_COPY(adev->ieee->wiphy->perm_addr, adev->dev_addr); - log(L_IRQ | L_INIT, "using IRQ %d\n", pdev->irq); + acx_log(LOG_INFO, L_IRQ | L_INIT, "using IRQ %d\n", pdev->irq); /** done with board specific setup **/ @@ -1695,14 +1740,15 @@ acxpci_e_probe(struct pci_dev *pdev, const struct pci_device_id *id) err = acx_setup_modes(adev); if (err) { - printk("can't register hwmode\n"); + acx_log(LOG_INFO, L_ANY, "can't register hwmode\n"); goto fail_register_netdev; } acx_init_task_scheduler(adev); err = ieee80211_register_hw(ieee); if (OK != err) { - printk("acx: ieee80211_register_hw() FAILED: %d\n", err); + acx_log(LOG_INFO, L_ANY, + "ieee80211_register_hw() FAILED: %d\n", err); goto fail_register_netdev; } #if CMD_DISCOVERY @@ -1769,8 +1815,9 @@ static void __devexit acxpci_e_remove(struct pci_dev *pdev) FN_ENTER; if (!hw) { - log(L_DEBUG, "%s: card is unused. Skipping any release code\n", - __func__); + acx_log(LOG_DEBUG, L_REALLYVERBOSE, + "%s: card is unused. Skipping any release code\n", + __func__); goto end; } @@ -1791,7 +1838,8 @@ static void __devexit acxpci_e_remove(struct pci_dev *pdev) #endif acx_lock(adev, flags); /* disable power LED to save power :-) */ - log(L_INIT, "switching off power LED to save power\n"); + acx_log(LOG_INFO, L_INIT, + "switching off power LED to save power\n"); acxpci_l_power_led(adev, 0); /* stop our eCPU */ if (IS_ACX111(adev)) { @@ -1818,7 +1866,8 @@ static void __devexit acxpci_e_remove(struct pci_dev *pdev) * have to do so manually... */ acxpci_e_close(hw); - log(L_INIT, "removing device %s\n", wiphy_name(adev->ieee->wiphy)); + acx_log(LOG_INFO, L_INIT, + "removing device %s\n", wiphy_name(adev->ieee->wiphy)); ieee80211_unregister_hw(adev->ieee); /* unregister_netdev ensures that no references to us left. @@ -1883,72 +1932,72 @@ acxpci_e_suspend(struct pci_dev *pdev, pm_message_t state) acx_device_t *adev; FN_ENTER; - printk("acx: suspend handler is experimental!\n"); - printk("sus: dev %p\n", hw); + acx_log(LOG_INFO, L_ANY, "suspend handler is experimental!\n"); + acx_log(LOG_INFO, L_ANY, "suspend: dev %p\n", hw); /* if (!netif_running(ndev)) goto end; */ adev = ieee2adev(hw); - printk("sus: adev %p\n", adev); - - acx_sem_lock(adev); - - ieee80211_unregister_hw(hw); /* this one cannot sleep */ - acxpci_s_down(hw); - /* down() does not set it to 0xffff, but here we really want that */ - write_reg16(adev, IO_ACX_IRQ_MASK, 0xffff); - write_reg16(adev, IO_ACX_FEMR, 0x0); - acxpci_s_delete_dma_regions(adev); - pci_save_state(pdev); - pci_set_power_state(pdev, PCI_D3hot); - - acx_sem_unlock(adev); - FN_EXIT0; - return OK; +acx_log(LOG_INFO, L_ANY, "suspend: adev %p\n", adev); + +acx_sem_lock(adev); + +ieee80211_unregister_hw(hw); /* this one cannot sleep */ +acxpci_s_down(hw); +/* down() does not set it to 0xffff, but here we really want that */ +write_reg16(adev, IO_ACX_IRQ_MASK, 0xffff); +write_reg16(adev, IO_ACX_FEMR, 0x0); +acxpci_s_delete_dma_regions(adev); +pci_save_state(pdev); +pci_set_power_state(pdev, PCI_D3hot); + +acx_sem_unlock(adev); +FN_EXIT0; +return OK; } static int acxpci_e_resume(struct pci_dev *pdev) { - struct ieee80211_hw *hw = pci_get_drvdata(pdev); - acx_device_t *adev; +struct ieee80211_hw *hw = pci_get_drvdata(pdev); +acx_device_t *adev; - FN_ENTER; +FN_ENTER; - printk("acx: resume handler is experimental!\n"); - printk("rsm: got dev %p\n", hw); +acx_log(LOG_INFO, L_ANY, "resume handler is experimental!\n"); +acx_log(LOG_INFO, L_ANY, "resume: got dev %p\n", hw); - adev = ieee2adev(hw); - printk("rsm: got adev %p\n", adev); +adev = ieee2adev(hw); +acx_log(LOG_INFO, L_ANY, "resume: got adev %p\n", adev); - acx_sem_lock(adev); +acx_sem_lock(adev); - pci_set_power_state(pdev, PCI_D0); - printk("rsm: power state PCI_D0 set\n"); - pci_restore_state(pdev); - printk("rsm: PCI state restored\n"); +pci_set_power_state(pdev, PCI_D0); +acx_log(LOG_INFO, L_ANY, "resume: power state PCI_D0 set\n"); +pci_restore_state(pdev); +acx_log(LOG_INFO, L_ANY, "resume: PCI state restored\n"); - if (OK != acxpci_s_reset_dev(adev)) - goto end_unlock; - printk("rsm: device reset done\n"); - if (OK != acx_s_init_mac(adev)) - goto end_unlock; - printk("rsm: init MAC done\n"); +if (OK != acxpci_s_reset_dev(adev)) + goto end_unlock; +acx_log(LOG_INFO, L_ANY, "resume: device reset done\n"); +if (OK != acx_s_init_mac(adev)) + goto end_unlock; +acx_log(LOG_INFO, L_ANY, "resume: init MAC done\n"); - acxpci_s_up(hw); - printk("rsm: acx up done\n"); +acxpci_s_up(hw); +acx_log(LOG_INFO, L_ANY, "resume: acx up done\n"); /* now even reload all card parameters as they were before suspend, * and possibly be back in the network again already :-) */ if (ACX_STATE_IFACE_UP & adev->dev_state_mask) { adev->set_mask = GETSET_ALL; acx_s_update_card_settings(adev); - printk("rsm: settings updated\n"); + acx_log(LOG_INFO, L_ANY, "resume: settings updated\n"); } ieee80211_register_hw(hw); - printk("rsm: device attached\n"); + acx_log(LOG_INFO, L_ANY, "resume: device attached\n"); end_unlock: acx_sem_unlock(adev); @@ -2175,7 +2224,7 @@ static void acxpci_e_close(struct ieee80211_hw *hw) */ acx_sem_unlock(adev); - log(L_INIT, "closed device\n"); + acx_log(LOG_INFO, L_INIT, "closed device\n"); FN_EXIT0; } @@ -2206,7 +2255,7 @@ static void log_rxbuffer(const acx_device_t * adev) for (i = 0; i < RX_CNT; i++) { if ((rxhostdesc->Ctl_16 & cpu_to_le16(DESC_CTL_HOSTOWN)) && (rxhostdesc->Status & cpu_to_le32(DESC_STATUS_FULL))) - printk("rx: buf %d full\n", i); + acx_log(LOG_INFO, L_ANY, "rx: buf %d full\n", i); rxhostdesc++; } } @@ -2242,8 +2291,9 @@ static void acxpci_l_process_rxdesc(acx_device_t * adev) /* now process descriptors, starting with the first we figured out */ while (1) { - log(L_BUFR, "rx: tail=%u Ctl_16=%04X Status=%08X\n", - tail, hostdesc->Ctl_16, hostdesc->Status); + acx_log(LOG_DEBUG, L_BUFR, + "rx: tail=%u Ctl_16=%04X Status=%08X\n", + tail, hostdesc->Ctl_16, hostdesc->Status); acx_l_process_rxbuf(adev, hostdesc->data); hostdesc->Status = 0; @@ -2341,11 +2391,12 @@ static void handle_info_irq(acx_device_t * adev) write_reg16(adev, IO_ACX_INT_TRIG, INT_TRIG_INFOACK); write_flush(adev); - log(L_CTL, "info_type:%04X info_status:%04X\n", info_type, info_status); + acx_log(LOG_DEBUG, L_CTL, + "info_type:%04X info_status:%04X\n", info_type, info_status); - log(L_IRQ, "got Info IRQ: status %04X type %04X: %s\n", - info_status, info_type, - info_type_msg[(info_type >= ARRAY_SIZE(info_type_msg)) ? + acx_log(LOG_DEBUG, L_IRQ, "got Info IRQ: status %04X type %04X: %s\n", + info_status, info_type, + info_type_msg[(info_type >= ARRAY_SIZE(info_type_msg)) ? 0 : info_type] ); } @@ -2374,7 +2425,7 @@ static void log_unusual_irq(u16 irqtype) printk(" Beacon"); } if (irqtype & HOST_INT_TIMER) { - log(L_IRQ, " Timer"); + printk(" Timer"); } if (irqtype & HOST_INT_KEY_NOT_FOUND) { printk(" Key_Not_Found"); @@ -2469,11 +2520,11 @@ void acx_interrupt_tasklet(struct work_struct *work) /* Handle most important IRQ types first */ if (irqtype & HOST_INT_RX_COMPLETE) { - log(L_IRQ, "got Rx_Complete IRQ\n"); + acx_log(LOG_DEBUG, L_IRQ, "got Rx_Complete IRQ\n"); acxpci_l_process_rxdesc(adev); } if (irqtype & HOST_INT_TX_COMPLETE) { - log(L_IRQ, "got Tx_Complete IRQ\n"); + acx_log(LOG_DEBUG, L_IRQ, "got Tx_Complete IRQ\n"); /* don't clean up on each Tx complete, wait a bit * unless we're going towards full, in which case * we do it immediately, too (otherwise we might lockup @@ -2493,7 +2544,8 @@ void acx_interrupt_tasklet(struct work_struct *work) handle_info_irq(adev); } if (irqtype & HOST_INT_SCAN_COMPLETE) { - log(L_IRQ, "got Scan_Complete IRQ\n"); + acx_log(LOG_DEBUG, L_IRQ, + "got Scan_Complete IRQ\n"); /* need to do that in process context */ /* remember that fw is not scanning anymore */ SET_BIT(adev->irq_status, @@ -2530,8 +2582,8 @@ void acx_interrupt_tasklet(struct work_struct *work) if (unlikely (++adev->irq_loops_this_jiffy > MAX_IRQLOOPS_PER_JIFFY)) { - printk(KERN_ERR - "acx: too many interrupts per jiffy!\n"); + acx_log(LOG_INFO, L_ANY, + "too many interrupts per jiffy!\n"); /* Looks like card floods us with IRQs! Try to stop that */ write_reg16(adev, IO_ACX_IRQ_MASK, 0xffff); /* This will short-circuit all future attempts to handle IRQ. @@ -2582,7 +2634,8 @@ static irqreturn_t acxpci_i_interrupt(int irq, void *dev_id) /* 0xffff value hints at missing hardware, * so don't do anything. * Not very clean, but other drivers do the same... */ - log(L_IRQ, "IRQ type:FFFF - device removed? IRQ_NONE\n"); + acx_log(LOG_INFO, L_IRQ, + "IRQ type:FFFF - device removed? IRQ_NONE\n"); goto none; } @@ -2590,16 +2643,16 @@ static irqreturn_t acxpci_i_interrupt(int irq, void *dev_id) irqtype = unmasked & ~adev->irq_mask; if (!irqtype) { /* We are on a shared IRQ line and it wasn't our IRQ */ - log(L_IRQ, - "IRQ type:%04X, mask:%04X - all are masked, IRQ_NONE\n", - unmasked, adev->irq_mask); + acx_log(LOG_DEBUG, L_IRQ, + "IRQ type:%04X, mask:%04X - all are masked, IRQ_NONE\n", + unmasked, adev->irq_mask); goto none; } /* Go ahead and ACK our interrupt */ write_reg16(adev, IO_ACX_IRQ_ACK, 0xffff); if (irqtype & HOST_INT_CMD_COMPLETE) { - log(L_IRQ, "got Command_Complete IRQ\n"); + acx_log(LOG_DEBUG, L_IRQ, "got Command_Complete IRQ\n"); /* save the state for the running issue_cmd() */ SET_BIT(adev->irq_status, HOST_INT_CMD_COMPLETE); } @@ -2642,8 +2695,9 @@ void acxpci_l_power_led(acx_device_t * adev, int enable) static int rate_limit = 0; if (rate_limit++ < 3) - log(L_IOCTL, "Please report in case toggling the power " - "LED doesn't work for your card!\n"); + acx_log(LOG_INFO, L_IOCTL, + "Please report in case toggling the power LED " + "doesn't work for your card!\n"); if (enable) write_reg16(adev, IO_ACX_GPIO_OUT, read_reg16(adev, IO_ACX_GPIO_OUT) & ~gpio_pled); @@ -2949,13 +3003,15 @@ acx100pci_ioctl_set_phy_amp_bias(struct net_device *ndev, * hardware, since we're tweaking GPIOs here after all!!! * You've been warned... * WARNING!!! */ - printk("acx: sorry, setting bias level for non-acx100 " - "is not supported yet\n"); + acx_log(LOG_INFO, L_ANY, + "sorry, setting bias level for non-acx100 " + "is not supported yet\n"); return OK; } if (*extra > 7) { - printk("acx: invalid bias parameter, range is 0-7\n"); + acx_log(LOG_INFO, L_ANY, + "invalid bias parameter, range is 0-7\n"); return -EINVAL; } @@ -2969,9 +3025,10 @@ acx100pci_ioctl_set_phy_amp_bias(struct net_device *ndev, (gpio_old & 0xf8ff) | ((u16) * extra << 8)); acx_unlock(adev, flags); - log(L_DEBUG, "gpio_old: 0x%04X\n", gpio_old); - printk("%s: PHY power amplifier bias: old:%d, new:%d\n", - ndev->name, (gpio_old & 0x0700) >> 8, (unsigned char)*extra); + acx_log(LOG_DEBUG, L_REALLYVERBOSE, "gpio_old: 0x%04X\n", gpio_old); + acx_log(LOG_INFO, L_ANY, + "%s: PHY power amplifier bias: old:%d, new:%d\n", + ndev->name, (gpio_old & 0x0700) >> 8, (unsigned char)*extra); acx_sem_unlock(adev); @@ -2996,7 +3053,7 @@ tx_t *acxpci_l_alloc_tx(acx_device_t * adev) FN_ENTER; if (unlikely(!adev->tx_free)) { - printk("acx: BUG: no free txdesc left\n"); + acx_log(LOG_INFO, L_ANY, "BUG: no free txdesc left\n"); txdesc = NULL; goto end; } @@ -3010,8 +3067,8 @@ tx_t *acxpci_l_alloc_tx(acx_device_t * adev) if (unlikely(DESC_CTL_HOSTOWN != (ctl8 & DESC_CTL_ACXDONE_HOSTOWN))) { /* whoops, descr at current index is not free, so probably * ring buffer already full */ - printk("acx: BUG: tx_head:%d Ctl8:0x%02X - failed to find " - "free txdesc\n", head, ctl8); + acx_log(LOG_INFO, L_ANY, "BUG: tx_head:%d Ctl8:0x%02X - " + "failed to find free txdesc\n", head, ctl8); txdesc = NULL; goto end; } @@ -3020,11 +3077,13 @@ tx_t *acxpci_l_alloc_tx(acx_device_t * adev) txdesc->Ctl_8 = DESC_CTL_ACXDONE_HOSTOWN; adev->tx_free--; - log(L_BUFT, "tx: got desc %u, %u remain\n", head, adev->tx_free); + acx_log(LOG_DEBUG, L_BUFT, "tx: got desc %u, %u remain\n", + head, adev->tx_free); /* Keep a few free descs between head and tail of tx ring. ** It is not absolutely needed, just feels safer */ if (adev->tx_free < TX_STOP_QUEUE) { - log(L_BUF, "stop queue (%u tx desc left)\n", adev->tx_free); + acx_log(LOG_DEBUG, L_BUF, "stop queue (%u tx desc left)\n", + adev->tx_free); acx_stop_queue(adev->ieee, NULL); } @@ -3096,7 +3155,7 @@ acxpci_l_tx_data(acx_device_t * adev, tx_t * tx_opaque, int len, rate_cur = ieeectl->tx_rate; if (unlikely(!rate_cur)) { - printk("acx: driver bug! bad ratemask\n"); + acx_log(LOG_INFO, L_ANY, "driver bug! bad ratemask\n"); goto end; } @@ -3211,7 +3270,7 @@ static void log_txbuffer(acx_device_t * adev) txdesc = adev->txdesc_start; if (unlikely(!txdesc)) return; - printk("tx: desc->Ctl8's:"); + acx_log(LOG_DEBUG, L_REALLYVERBOSE, "tx: desc->Ctl8's:"); for (i = 0; i < TX_CNT; i++) { printk(" %02X", txdesc->Ctl_8); txdesc = advance_txdesc(adev, txdesc, 1); @@ -3276,15 +3335,18 @@ static void handle_tx_error(acx_device_t * adev, u8 error, unsigned int finger, * ok, just do it. */ if (++adev->retry_errors_msg_ratelimit % 4 == 0) { if (adev->retry_errors_msg_ratelimit <= 20) { - printk("%s: several excessive Tx " - "retry errors occurred, attempting " - "to recalibrate radio. Radio " - "drift might be caused by increasing " - "card temperature, please check the card " - "before it's too late!\n", - wiphy_name(adev->ieee->wiphy)); + acx_log(LOG_INFO, L_ANY, + "%s: several excessive Tx " + "retry errors occurred, attempting " + "to recalibrate radio\n", + wiphy_name(adev->ieee->wiphy)); + acx_log(LOG_INFO, L_ANY, + "Radio drift might be caused by " + "increasing card temperature, please " + "check the card before it's too late!\n"); if (adev->retry_errors_msg_ratelimit == 20) - printk("disabling above message\n"); + acx_log(LOG_INFO, L_ANY, + "disabling above message\n"); } acx_schedule_task(adev, @@ -3312,11 +3374,13 @@ static void handle_tx_error(acx_device_t * adev, u8 error, unsigned int finger, } adev->stats.tx_errors++; if (adev->stats.tx_errors <= 20) - printk("%s: tx error 0x%02X, buf %02u! (%s)\n", - wiphy_name(adev->ieee->wiphy), error, finger, err); + acx_log(LOG_INFO, L_ANY, + "%s: tx error 0x%02X, buf %02u! (%s)\n", + wiphy_name(adev->ieee->wiphy), error, finger, err); else - printk("%s: tx error 0x%02X, buf %02u!\n", - wiphy_name(adev->ieee->wiphy), error, finger); + acx_log(LOG_INFO, L_ANY, + "%s: tx error 0x%02X, buf %02u!\n", + wiphy_name(adev->ieee->wiphy), error, finger); } @@ -3331,10 +3395,11 @@ unsigned int acxpci_l_clean_txdesc(acx_device_t * adev) FN_ENTER; - if (unlikely(acx_debug & L_DEBUG)) + if (unlikely(acx_debug & L_REALLYVERBOSE)) log_txbuffer(adev); - log(L_BUFT, "tx: cleaning up bufs from %u\n", adev->tx_tail); + acx_log(LOG_DEBUG, L_BUFT, "tx: cleaning up bufs from %u\n", + adev->tx_tail); /* We know first descr which is not free yet. We advance it as far ** as we see correct bits set in following descs (if next desc @@ -3356,9 +3421,10 @@ unsigned int acxpci_l_clean_txdesc(acx_device_t * adev) if ((txdesc->Ctl_8 & DESC_CTL_ACXDONE_HOSTOWN) != DESC_CTL_ACXDONE_HOSTOWN) { if (unlikely(!num_cleaned)) { /* maybe remove completely */ - log(L_BUFT, "clean_txdesc: tail isn't free. " - "tail:%d head:%d\n", - adev->tx_tail, adev->tx_head); + acx_log(LOG_DEBUG, L_BUFT, + "clean_txdesc: tail isn't free. " + "tail:%d head:%d\n", + adev->tx_tail, adev->tx_head); } break; } @@ -3403,8 +3469,9 @@ unsigned int acxpci_l_clean_txdesc(acx_device_t * adev) /* && (adev->status == ACX_STATUS_4_ASSOCIATED) */ /*&& (acx_queue_stopped(adev->ieee))*/ ) { - log(L_BUF, "tx: wake queue (avail. Tx desc %u)\n", - adev->tx_free); + acx_log(LOG_DEBUG, L_BUF, + "tx: wake queue (avail. Tx desc %u)\n", + adev->tx_free); acx_wake_queue(adev->ieee, NULL); } @@ -3432,13 +3499,15 @@ unsigned int acxpci_l_clean_txdesc(acx_device_t * adev) handle_tx_error(adev, error, finger, &hostdesc->txstatus); if (IS_ACX111(adev)) - log(L_BUFT, - "tx: cleaned %u: !ACK=%u !RTS=%u RTS=%u r111=%04X tx_free=%u\n", - finger, ack_failures, rts_failures, rts_ok, r111, adev->tx_free); + acx_log(LOG_DEBUG, L_BUFT, "tx: cleaned %u: !ACK=%u " + "!RTS=%u RTS=%u r111=%04X tx_free=%u\n", + finger, ack_failures, + rts_failures, rts_ok, r111, adev->tx_free); else - log(L_BUFT, - "tx: cleaned %u: !ACK=%u !RTS=%u RTS=%u rate=%u\n", - finger, ack_failures, rts_failures, rts_ok, r100); + acx_log(LOG_DEBUG, L_BUFT, "tx: cleaned %u: !ACK=%u " + "!RTS=%u RTS=%u rate=%u\n", + finger, ack_failures, + rts_failures, rts_ok, r100); /* And finally report upstream */ if (hostdesc) @@ -3496,13 +3565,14 @@ static void *allocate(acx_device_t * adev, size_t size, dma_addr_t * phy, ptr = dma_alloc_coherent(adev->bus_dev, size, phy, GFP_KERNEL); if (ptr) { - log(L_DEBUG, "%s sz=%d adr=0x%p phy=0x%08llx\n", - msg, (int)size, ptr, (unsigned long long)*phy); + acx_log(LOG_DEBUG, L_REALLYVERBOSE, + "%s sz=%d adr=0x%p phy=0x%08llx\n", + msg, (int)size, ptr, (unsigned long long)*phy); memset(ptr, 0, size); return ptr; } - printk(KERN_ERR "acx: %s allocation FAILED (%d bytes)\n", - msg, (int)size); + acx_log(LOG_INFO, L_ANY, "%s allocation FAILED (%d bytes)\n", + msg, (int)size); return NULL; } @@ -3533,8 +3603,8 @@ static int acxpci_s_create_tx_host_desc_queue(acx_device_t * adev) goto fail; /* check for proper alignment of TX host descriptor pool */ if ((long)adev->txhostdesc_start & 3) { - printk - ("acx: driver bug: dma alloc returns unaligned address\n"); + acx_log(LOG_INFO, L_ANY, + "driver bug: dma alloc returns unaligned address\n"); goto fail; } @@ -3622,7 +3692,7 @@ static int acxpci_s_create_tx_host_desc_queue(acx_device_t * adev) FN_EXIT1(OK); return OK; fail: - printk("acx: create_tx_host_desc_queue FAILED\n"); + acx_log(LOG_INFO, L_ANY, "create_tx_host_desc_queue FAILED\n"); /* dealloc will be done by free function on error case */ FN_EXIT1(NOT_OK); return NOT_OK; @@ -3655,8 +3725,8 @@ static int acxpci_s_create_rx_host_desc_queue(acx_device_t * adev) goto fail; /* check for proper alignment of RX host descriptor pool */ if ((long)adev->rxhostdesc_start & 3) { - printk - ("acx: driver bug: dma alloc returns unaligned address\n"); + acx_log(LOG_INFO, L_ANY, + "driver bug: dma alloc returns unaligned address\n"); goto fail; } @@ -3692,7 +3762,7 @@ static int acxpci_s_create_rx_host_desc_queue(acx_device_t * adev) FN_EXIT1(OK); return OK; fail: - printk("acx: create_rx_host_desc_queue FAILED\n"); + acx_log(LOG_INFO, L_ANY, "create_rx_host_desc_queue FAILED\n"); /* dealloc will be done by free function on error case */ FN_EXIT1(NOT_OK); return NOT_OK; @@ -3734,10 +3804,9 @@ static void acxpci_create_tx_desc_queue(acx_device_t * adev, u32 tx_queue_start) adev->txdesc_start = (txdesc_t *) (adev->iobase2 + tx_queue_start); - log(L_DEBUG, "adev->iobase2=%p\n" - "tx_queue_start=%08X\n" - "adev->txdesc_start=%p\n", - adev->iobase2, tx_queue_start, adev->txdesc_start); + acx_log(LOG_DEBUG, L_REALLYVERBOSE, "adev->iobase2=%p\n" + "tx_queue_start=%08X\n adev->txdesc_start=%p\n", + adev->iobase2, tx_queue_start, adev->txdesc_start); adev->tx_free = TX_CNT; /* done by memset: adev->tx_head = 0; */ @@ -3766,8 +3835,9 @@ static void acxpci_create_tx_desc_queue(acx_device_t * adev, u32 tx_queue_start) /* loop over whole send pool */ for (i = 0; i < TX_CNT; i++) { - log(L_DEBUG, "configure card tx descriptor: 0x%p, " - "size: 0x%X\n", txdesc, adev->txdesc_size); + acx_log(LOG_DEBUG, L_REALLYVERBOSE, + "configure card tx descriptor: 0x%p, " + "size: 0x%X\n", txdesc, adev->txdesc_size); /* pointer to hostdesc memory */ txdesc->HostMemPtr = ptr2acx(hostmemptr); @@ -3819,7 +3889,8 @@ static void acxpci_create_rx_desc_queue(acx_device_t * adev, u32 rx_queue_start) rxdesc = adev->rxdesc_start; for (i = 0; i < RX_CNT; i++) { - log(L_DEBUG, "rx descriptor %d @ 0x%p\n", i, rxdesc); + acx_log(LOG_DEBUG, L_REALLYVERBOSE, + "rx descriptor %d @ 0x%p\n", i, rxdesc); rxdesc = adev->rxdesc_start = (rxdesc_t *) (adev->iobase2 + acx2cpu(rxdesc->pNextDesc)); } @@ -3838,7 +3909,8 @@ static void acxpci_create_rx_desc_queue(acx_device_t * adev, u32 rx_queue_start) rxdesc = adev->rxdesc_start; mem_offs = rx_queue_start; for (i = 0; i < RX_CNT; i++) { - log(L_DEBUG, "rx descriptor @ 0x%p\n", rxdesc); + acx_log(LOG_DEBUG, L_REALLYVERBOSE, + "rx descriptor @ 0x%p\n", rxdesc); rxdesc->Ctl_8 = DESC_CTL_RECLAIM | DESC_CTL_AUTODMA; /* point to next rxdesc */ rxdesc->pNextDesc = cpu2acx(mem_offs + sizeof(*rxdesc)); @@ -4049,12 +4121,14 @@ int acx100pci_s_set_tx_level(acx_device_t * adev, u8 level_dbm) table = &dbm2val_rfmd[0]; break; default: - printk("%s: unknown/unsupported radio type, " - "cannot modify tx power level yet!\n", wiphy_name(adev->ieee->wiphy)); + acx_log(LOG_INFO, L_ANY, "%s: unknown/unsupported radio type, " + "cannot modify tx power level yet!\n", + wiphy_name(adev->ieee->wiphy)); return NOT_OK; } - printk("%s: changing radio power level to %u dBm (%u)\n", - wiphy_name(adev->ieee->wiphy), level_dbm, table[level_dbm]); + acx_log(LOG_INFO, L_ANY, + "%s: changing radio power level to %u dBm (%u)\n", + wiphy_name(adev->ieee->wiphy), level_dbm, table[level_dbm]); acxpci_s_write_phy_reg(adev, 0x11, table[level_dbm]); return OK; } @@ -4169,8 +4243,8 @@ static __devinit int vlynq_probe(struct vlynq_device *vdev, addr = (u32)ioremap(vdev->mem_start, 0x1000); if (!addr) { - printk(KERN_ERR "%s: failed to remap io memory\n", - vdev->dev.bus_id); + acx_log(LOG_INFO, L_ANY, "%s: failed to remap io memory\n", + vdev->dev.bus_id); result = -ENXIO; goto fail; } @@ -4183,8 +4257,9 @@ static __devinit int vlynq_probe(struct vlynq_device *vdev, ieee = ieee80211_alloc_hw(sizeof(struct acx_device), &acxpci_hw_ops); if (!ieee) { - printk("acx: could not allocate ieee80211 structure %s\n", - vdev->dev.bus_id); + acx_log(LOG_INFO, L_ANY, + "could not allocate ieee80211 structure %s\n", + vdev->dev.bus_id); goto fail_alloc_netdev; } ieee->flags &= ~IEEE80211_HW_RX_INCLUDES_FCS; @@ -4209,13 +4284,13 @@ static __devinit int vlynq_probe(struct vlynq_device *vdev, vlynq_set_drvdata(vdev, ieee); if (!request_mem_region(vdev->mem_start, vdev->mem_end - vdev->mem_start, "acx")) { - printk("acx: cannot reserve VLYNQ memory region\n"); + acx_log(LOG_INFO, L_ANY, "cannot reserve VLYNQ memory region\n"); goto fail_request_mem_region; } adev->iobase = ioremap(vdev->mem_start, vdev->mem_end - vdev->mem_start); if (!adev->iobase) { - printk("acx: ioremap() FAILED\n"); + acx_log(LOG_INFO, L_ANY, "ioremap() FAILED\n"); goto fail_ioremap; } adev->iobase2 = adev->iobase + match->rx_mapping[0].size; @@ -4224,14 +4299,15 @@ static __devinit int vlynq_probe(struct vlynq_device *vdev, adev->io = IO_ACX111; adev->irq = vlynq_virq_to_irq(vdev, match->irq); - printk("acx: found %s-based wireless network card at %s, irq:%d, " - "phymem:0x%x, mem:0x%p\n", - match->name, vdev->dev.bus_id, adev->irq, - vdev->mem_start, adev->iobase); - log(L_ANY, "initial debug setting is 0x%04X\n", acx_debug); + acx_log(LOG_INFO, L_ANY, "found %s-based wireless network card at %s, " + "irq:%d, phymem:0x%x, mem:0x%p\n", + match->name, vdev->dev.bus_id, adev->irq, + vdev->mem_start, adev->iobase); +// acx_log(LOG_INFO, L_ANY, +// "initial debug setting is 0x%04X\n", acx_debug); if (0 == adev->irq) { - printk("acx: can't use IRQ 0\n"); + acx_log(LOG_INFO, L_ANY, "can't use IRQ 0\n"); goto fail_irq; } SET_IEEE80211_DEV(ieee, &vdev->dev); @@ -4239,11 +4315,13 @@ static __devinit int vlynq_probe(struct vlynq_device *vdev, /* request shared IRQ handler */ if (request_irq (adev->irq, acxpci_i_interrupt, IRQF_SHARED, KBUILD_MODNAME, adev)) { - printk("%s: request_irq FAILED\n", wiphy_name(adev->ieee->wiphy)); + acx_log(LOG_INFO, L_ANY, "%s: request_irq FAILED\n", + wiphy_name(adev->ieee->wiphy)); result = -EAGAIN; goto done; } - log(L_DEBUG | L_IRQ, "request_irq %d successful\n", adev->irq); + acx_log(LOG_DEBUG, L_IRQ | L_REALLYVERBOSE, + "request_irq %d successful\n", adev->irq); /* to find crashes due to weird driver access * to unconfigured interface (ifup) */ @@ -4286,26 +4364,27 @@ static __devinit int vlynq_probe(struct vlynq_device *vdev, * (in particular, on other CPUs), we only need to up the sem */ /* acx_sem_unlock(adev); */ - printk("acx " ACX_RELEASE ": net device %s, driver compiled " - "against wireless extensions %d and Linux %s\n", - wiphy_name(adev->ieee->wiphy), WIRELESS_EXT, UTS_RELEASE); + acx_log(LOG_INFO, L_ANY, "driver " ACX_RELEASE ", net device %s, " + "driver compiled against wireless extensions %d and Linux %s\n", + wiphy_name(adev->ieee->wiphy), WIRELESS_EXT, UTS_RELEASE); MAC_COPY(adev->ieee->wiphy->perm_addr, adev->dev_addr); - log(L_IRQ | L_INIT, "using IRQ %d\n", adev->irq); + acx_log(LOG_DEBUG, L_IRQ | L_INIT, "using IRQ %d\n", adev->irq); /** done with board specific setup **/ result = acx_setup_modes(adev); if (result) { - printk("can't register hwmode\n"); + acx_log(LOG_INFO, L_ANY, "can't register hwmode\n"); goto fail_register_netdev; } acx_init_task_scheduler(adev); result = ieee80211_register_hw(adev->ieee); if (OK != result) { - printk("acx: ieee80211_register_hw() FAILED: %d\n", result); + acx_log(LOG_INFO, L_ANY, + "acx: ieee80211_register_hw() FAILED: %d\n", result); goto fail_register_netdev; } #if CMD_DISCOVERY @@ -4349,8 +4428,9 @@ static void vlynq_remove(struct vlynq_device *vdev) FN_ENTER; if (!hw) { - log(L_DEBUG, "%s: card is unused. Skipping any release code\n", - __func__); + acx_log(LOG_DEBUG, L_REALLYVERBOSE, + "%s: card is unused. Skipping any release code\n", + __func__); goto end; } @@ -4371,7 +4451,8 @@ static void vlynq_remove(struct vlynq_device *vdev) } acx_lock(adev, flags); /* disable power LED to save power :-) */ - log(L_INIT, "switching off power LED to save power\n"); + acx_log(L_INFO, L_INIT, + "switching off power LED to save power\n"); acxpci_l_power_led(adev, 0); /* stop our eCPU */ acx_unlock(adev, flags); @@ -4387,7 +4468,8 @@ static void vlynq_remove(struct vlynq_device *vdev) * have to do so manually... */ acxpci_e_close(hw); - log(L_INIT, "removing device %s\n", wiphy_name(adev->ieee->wiphy)); + acx_log(LOG_INFO, L_INIT, "removing device %s\n", + wiphy_name(adev->ieee->wiphy)); ieee80211_unregister_hw(adev->ieee); /* unregister_netdev ensures that no references to us left. @@ -4495,12 +4577,12 @@ int __init acxpci_e_init_module(void) FN_ENTER; #if (ACX_IO_WIDTH==32) - printk("acx: compiled to use 32bit I/O access. " - "I/O timing issues might occur, such as " - "non-working firmware upload. Report them\n"); + acx_log(LOG_INFO, L_ANY, "compiled to use 32bit I/O access. " + "I/O timing issues might occur, such as " + "non-working firmware upload. Report them\n"); #else - printk("acx: compiled to use 16bit I/O access only " - "(compatibility mode)\n"); + acx_log(LOG_INFO, L_ANY, "compiled to use 16bit I/O access only " + "(compatibility mode)\n"); #endif #ifdef __LITTLE_ENDIAN @@ -4508,10 +4590,9 @@ int __init acxpci_e_init_module(void) #else #define ENDIANNESS_STRING "running on a BIG-ENDIAN CPU\n" #endif - log(L_INIT, - "acx: " ENDIANNESS_STRING - "acx: PCI/VLYNQ module " ACX_RELEASE " initialized, " - "waiting for cards to probe...\n"); + acx_log(LOG_INFO, L_INIT, ENDIANNESS_STRING); + acx_log(LOG_INFO, L_INIT, "PCI/VLYNQ module " ACX_RELEASE + " initialized, waiting for cards to probe...\n"); #ifdef CONFIG_PCI res = pci_register_driver(&acxpci_drv_id); @@ -4538,7 +4619,7 @@ void __exit acxpci_e_cleanup_module(void) #elif CONFIG_VLYNQ vlynq_unregister_driver(&vlynq_acx); #endif - log(L_INIT, - "acx: PCI module " ACX_RELEASE " unloaded\n"); + acx_log(LOG_INFO, L_INIT, + "PCI module " ACX_RELEASE " unloaded\n"); FN_EXIT0; } diff --git a/usb.c b/usb.c index 0787ece..0e37651 100644 --- a/usb.c +++ b/usb.c @@ -32,6 +32,7 @@ #include #include "acx.h" +#include "acx_log.h" /*********************************************************************** @@ -172,7 +173,7 @@ static void acxusb_unlink_urb(struct urb *urb) mdelay(1); } if (!timeout) { - printk(KERN_ERR "acx_usb: urb unlink timeout!\n"); + acx_log(LOG_INFO, L_ANY, "urb unlink timeout!\n"); } } } @@ -190,7 +191,8 @@ int acxusb_s_read_phy_reg(acx_device_t * adev, u32 reg, u8 * charbuf) FN_ENTER; - printk("%s doesn't seem to work yet, disabled.\n", __func__); + acx_log(LOG_INFO, L_ANY, + "%s doesn't seem to work yet, disabled.\n", __func__); /* mem.addr = cpu_to_le16(reg); @@ -198,7 +200,7 @@ int acxusb_s_read_phy_reg(acx_device_t * adev, u32 reg, u8 * charbuf) mem.len = cpu_to_le32(4); acx_s_issue_cmd(adev, ACX1xx_CMD_MEM_READ, &mem, sizeof(mem)); *charbuf = mem.data; - log(L_DEBUG, "read radio PHY[0x%04X]=0x%02X\n", reg, *charbuf); + acx_log(LOG_DEBUG, L_REALLYVERBOSE, "read radio PHY[0x%04X]=0x%02X\n", reg, *charbuf); */ FN_EXIT1(OK); @@ -219,7 +221,8 @@ int acxusb_s_write_phy_reg(acx_device_t * adev, u32 reg, u8 value) mem.len = cpu_to_le32(4); mem.data = value; acx_s_issue_cmd(adev, ACX1xx_CMD_MEM_WRITE, &mem, sizeof(mem)); - log(L_DEBUG, "write radio PHY[0x%04X]=0x%02X\n", reg, value); + acx_log(L_DEBUG, L_REALLYVERBOSE, + "write radio PHY[0x%04X]=0x%02X\n", reg, value); FN_EXIT1(OK); return OK; @@ -276,13 +279,14 @@ acxusb_s_issue_cmd_timeo_debug(acx_device_t * adev, if (!devname || !devname[0] || devname[4] == '%') devname = "acx"; - log(L_CTL, FUNC "(cmd:%s,buflen:%u,type:0x%04X)\n", - cmdstr, buflen, - buffer ? le16_to_cpu(((acx_ie_generic_t *) buffer)->type) : -1); + acx_log(LOG_DEBUG, L_CTL, FUNC "(cmd:%s,buflen:%u,type:0x%04X)\n", + cmdstr, buflen, + buffer ? le16_to_cpu(((acx_ie_generic_t *) buffer)->type) : -1); loc = kmalloc(buflen + 4 + BOGUS_SAFETY_PADDING, GFP_KERNEL); if (!loc) { - printk("%s: " FUNC "(): no memory for data buffer\n", devname); + acx_log(LOG_INFO, L_ANY, + "%s: " FUNC "(): no memory for data buffer\n", devname); goto bad; } @@ -320,11 +324,11 @@ acxusb_s_issue_cmd_timeo_debug(acx_device_t * adev, /* obtain the I/O pipes */ outpipe = usb_sndctrlpipe(usbdev, 0); inpipe = usb_rcvctrlpipe(usbdev, 0); - log(L_CTL, "ctrl inpipe=0x%X outpipe=0x%X\n", inpipe, outpipe); - log(L_CTL, "sending USB control msg (out) (blocklen=%d)\n", blocklen); - if (acx_debug & L_DATA) - acx_dump_bytes(loc, blocklen); - + acx_log(LOG_DEBUG, L_CTL, "ctrl inpipe=0x%X outpipe=0x%X\n", + inpipe, outpipe); + acx_log(LOG_DEBUG, L_CTL, + "sending USB control msg (out) (blocklen=%d)\n", blocklen); + acx_log_dump(LOG_DEBUG, L_DATA, loc, blocklen, "Control msg:\n"); result = usb_control_msg(usbdev, outpipe, ACX_USB_REQ_CMD, /* request */ USB_TYPE_VENDOR | USB_DIR_OUT, /* requesttype */ 0, /* value */ @@ -335,17 +339,18 @@ acxusb_s_issue_cmd_timeo_debug(acx_device_t * adev, ); if (result == -ENODEV) { - log(L_CTL, "no device present (unplug?)\n"); + acx_log(LOG_INFO, L_CTL, "no device present (unplug?)\n"); goto good; } - log(L_CTL, "wrote %d bytes\n", result); + acx_log(LOG_DEBUG, L_CTL, "wrote %d bytes\n", result); if (result < 0) { goto bad; } /* check for device acknowledge */ - log(L_CTL, "sending USB control msg (in) (acklen=%d)\n", acklen); + acx_log(LOG_DEBUG, L_CTL, "sending USB control msg (in) (acklen=%d)\n", + acklen); loc->status = 0; /* delete old status flag -> set to IDLE */ /* shall we zero out the rest? */ result = usb_control_msg(usbdev, inpipe, ACX_USB_REQ_CMD, /* request */ @@ -357,13 +362,12 @@ acxusb_s_issue_cmd_timeo_debug(acx_device_t * adev, ACX_USB_CTRL_TIMEOUT /* timeout in ms */ ); if (result < 0) { - printk("%s: " FUNC "(): USB read error %d\n", devname, result); + acx_log(LOG_INFO, L_ANY, "%s: " FUNC "(): USB read error %d\n", + devname, result); goto bad; } - if (acx_debug & L_CTL) { - printk("read %d bytes: ", result); - acx_dump_bytes(loc, result); - } + + acx_log_dump(LOG_DEBUG, L_CTL, loc, result, "read %d bytes:\n", result); /* check for result==buflen+4? Was seen: @@ -380,14 +384,16 @@ read 4 bytes <==== MUST BE 12!! cmd_status = le16_to_cpu(loc->status); if (cmd_status != 1) { - printk("%s: " FUNC "(): cmd_status is not SUCCESS: %d (%s)\n", - devname, cmd_status, acx_cmd_status_str(cmd_status)); + acx_log(LOG_INFO, L_ANY, "%s: " FUNC + "(): cmd_status is not SUCCESS: %d (%s)\n", + devname, cmd_status, acx_cmd_status_str(cmd_status)); /* TODO: goto bad; ? */ } if ((cmd == ACX1xx_CMD_INTERROGATE) && buffer && buflen) { memcpy(buffer, loc->data, buflen); - log(L_CTL, "response frame: cmd=0x%04X status=%d\n", - le16_to_cpu(loc->cmd), cmd_status); + acx_log(LOG_DEBUG, L_CTL, + "response frame: cmd=0x%04X status=%d\n", + le16_to_cpu(loc->cmd), cmd_status); } good: kfree(loc); @@ -397,9 +403,11 @@ read 4 bytes <==== MUST BE 12!! /* Give enough info so that callers can avoid ** printing their own diagnostic messages */ #if ACX_DEBUG - printk("%s: " FUNC "(cmd:%s) FAILED\n", devname, cmdstr); + acx_log(LOG_INFO, L_ANY, "%s: " FUNC "(cmd:%s) FAILED\n", + devname, cmdstr); #else - printk("%s: " FUNC "(cmd:0x%04X) FAILED\n", devname, cmd); + acx_log(LOG_INFO, L_ANY, "%s: " FUNC "(cmd:0x%04X) FAILED\n", + devname, cmd); #endif dump_stack(); kfree(loc); @@ -450,9 +458,9 @@ acxusb_boot(struct usb_device *usbdev, int is_tnetw1450, int *radio_type) usbbuf = kmalloc(USB_RWMEM_MAXLEN, GFP_KERNEL); if (!usbbuf) { - printk(KERN_ERR - "acx: no memory for USB transfer buffer (%d bytes)\n", - USB_RWMEM_MAXLEN); + acx_log(LOG_INFO, L_ANY, + "no memory for USB transfer buffer (%d bytes)\n", + USB_RWMEM_MAXLEN); result = -ENOMEM; goto end; } @@ -461,7 +469,7 @@ acxusb_boot(struct usb_device *usbdev, int is_tnetw1450, int *radio_type) outpipe = usb_sndbulkpipe(usbdev, 1); inpipe = usb_rcvbulkpipe(usbdev, 2); - printk(KERN_DEBUG "wait for device ready\n"); + acx_log(LOG_DEBUG, L_ANY, "wait for device ready\n"); for (i = 0; i <= 2; i++) { result = usb_bulk_msg(usbdev, inpipe, usbbuf, @@ -496,7 +504,7 @@ acxusb_boot(struct usb_device *usbdev, int is_tnetw1450, int *radio_type) result = -EIO; goto end; } - log(L_INIT, "firmware size: %d bytes\n", file_size); + acx_log(LOG_DEBUG, L_INIT, "firmware size: %d bytes\n", file_size); img_checksum = le32_to_cpu(fw_image->chksum); @@ -536,9 +544,9 @@ acxusb_boot(struct usb_device *usbdev, int is_tnetw1450, int *radio_type) } if (sum != le32_to_cpu(fw_image->chksum)) { - printk("acx: FATAL: firmware upload: " - "checksums don't match! " - "(0x%08x vs. 0x%08x)\n", sum, fw_image->chksum); + acx_log(LOG_INFO, L_ANY,"FATAL: firmware upload: " + "checksums don't match! " + "(0x%08x vs. 0x%08x)\n", sum, fw_image->chksum); goto fw_end; } @@ -549,9 +557,9 @@ acxusb_boot(struct usb_device *usbdev, int is_tnetw1450, int *radio_type) blk_len = USB_RWMEM_MAXLEN; } - log(L_INIT, - "uploading firmware (%d bytes, offset=%d)\n", - blk_len, offset); + acx_log(LOG_DEBUG, L_INIT, + "uploading firmware (%d bytes, offset=%d)\n", + blk_len, offset); memcpy(usbbuf, ((u8 *) fw_image) + offset, blk_len); p = usbbuf; @@ -568,7 +576,7 @@ acxusb_boot(struct usb_device *usbdev, int is_tnetw1450, int *radio_type) offset += blk_len; } if (need_padding) { - printk(KERN_DEBUG "send padding\n"); + acx_log(LOG_DEBUG, L_ANY, "send padding\n"); memset(usbbuf, 0, 4); result = usb_bulk_msg(usbdev, outpipe, usbbuf, 4, @@ -576,7 +584,7 @@ acxusb_boot(struct usb_device *usbdev, int is_tnetw1450, int *radio_type) if ((result < 0) || (num_processed != 4)) goto fw_end; } - printk(KERN_DEBUG "read firmware upload result\n"); + acx_log(LOG_DEBUG, L_ANY, "read firmware upload result\n"); memset(cmdbuf, 0, 20); /* additional memset */ result = usb_bulk_msg(usbdev, inpipe, cmdbuf, 20, &num_processed, @@ -614,7 +622,8 @@ acxusb_boot(struct usb_device *usbdev, int is_tnetw1450, int *radio_type) goto fw_end; } - printk("TNETW1450 firmware upload successful!\n"); + acx_log(LOG_INFO, L_ANY, + "TNETW1450 firmware upload successful!\n"); result = 0; goto end; fw_end: @@ -630,9 +639,9 @@ acxusb_boot(struct usb_device *usbdev, int is_tnetw1450, int *radio_type) if (blk_len > USB_RWMEM_MAXLEN) { blk_len = USB_RWMEM_MAXLEN; } - log(L_INIT, - "uploading firmware (%d bytes, offset=%d)\n", - blk_len, offset); + acx_log(LOG_DEBUG, L_INIT, + "uploading firmware (%d bytes, offset=%d)\n", + blk_len, offset); memcpy(usbbuf, ((u8 *) fw_image) + offset, blk_len); result = usb_control_msg(usbdev, outpipe, ACX_USB_REQ_UPLOAD_FW, USB_TYPE_VENDOR | USB_DIR_OUT, (file_size - 8) & 0xffff, /* value */ (file_size - 8) >> 16, /* index */ @@ -642,8 +651,9 @@ acxusb_boot(struct usb_device *usbdev, int is_tnetw1450, int *radio_type) ); offset += blk_len; if (result < 0) { - printk(KERN_ERR "acx: error %d during upload " - "of firmware, aborting\n", result); + acx_log(LOG_INFO, L_ANY, + "error %d during upload " + "of firmware, aborting\n", result); goto end; } } @@ -657,8 +667,9 @@ acxusb_boot(struct usb_device *usbdev, int is_tnetw1450, int *radio_type) 3000 /* timeout in ms */ ); if (result < 0) { - printk(KERN_ERR "acx: error %d during tx of checksum, " - "aborting\n", result); + acx_log(LOG_INFO, L_ANY, + "error %d during tx of checksum, aborting\n", + result); goto end; } result = usb_control_msg(usbdev, inpipe, ACX_USB_REQ_ACK_CS, USB_TYPE_VENDOR | USB_DIR_IN, img_checksum & 0xffff, /* value */ @@ -668,12 +679,13 @@ acxusb_boot(struct usb_device *usbdev, int is_tnetw1450, int *radio_type) 3000 /* timeout in ms */ ); if (result < 0) { - printk(KERN_ERR "acx: error %d during ACK of checksum, " - "aborting\n", result); + acx_log(LOG_INFO, L_ANY, + "error %d during ACK of checksum, aborting\n", + result); goto end; } if (*usbbuf != 0x10) { - printk(KERN_ERR "acx: invalid checksum?\n"); + acx_log(LOG_INFO, L_ANY, "invalid checksum?\n"); result = -EINVAL; goto end; } @@ -789,8 +801,8 @@ acxusb_e_probe(struct usb_interface *intf, const struct usb_device_id *devID) * other purpose than booting the firmware, * simply return immediately. */ - log(L_INIT, - "finished booting, returning from probe()\n"); + acx_log(LOG_INFO, L_INIT, + "finished booting, returning from probe()\n"); result = OK; /* success */ goto end; } else { @@ -806,7 +818,7 @@ acxusb_e_probe(struct usb_interface *intf, const struct usb_device_id *devID) ieee = ieee80211_alloc_hw(sizeof(*adev), &acxusb_hw_ops); if (!ieee) { - msg = "acx: no memory for ieee80211_dev\n"; + msg = "no memory for ieee80211_dev\n"; goto end_nomem; } @@ -848,20 +860,20 @@ acxusb_e_probe(struct usb_interface *intf, const struct usb_device_id *devID) */ numconfigs = (int)usbdev->descriptor.bNumConfigurations; if (numconfigs != 1) - printk("acx: number of configurations is %d, " + acx_log(LOG_INFO, L_ANY, "number of configurations is %d, " "this driver only knows how to handle 1, " "be prepared for surprises\n", numconfigs); config = &usbdev->config->desc; numfaces = config->bNumInterfaces; if (numfaces != 1) - printk("acx: number of interfaces is %d, " + acx_log(LOG_INFO, L_ANY, "number of interfaces is %d, " "this driver only knows how to handle 1, " "be prepared for surprises\n", numfaces); ifdesc = &intf->altsetting->desc; numep = ifdesc->bNumEndpoints; - log(L_DEBUG, "# of endpoints: %d\n", numep); + acx_log(LOG_DEBUG, L_REALLYVERBOSE, "# of endpoints: %d\n", numep); if (is_tnetw1450) { adev->bulkoutep = 1; @@ -887,22 +899,23 @@ acxusb_e_probe(struct usb_interface *intf, const struct usb_device_id *devID) } } } - log(L_DEBUG, "bulkout ep: 0x%X\n", adev->bulkoutep); - log(L_DEBUG, "bulkin ep: 0x%X\n", adev->bulkinep); + acx_log(LOG_DEBUG, L_REALLYVERBOSE, + "bulkout ep: 0x%X\n", adev->bulkoutep); + acx_log(LOG_DEBUG, L_REALLYVERBOSE, "bulkin ep: 0x%X\n", adev->bulkinep); /* already done by memset: adev->rxtruncsize = 0; */ - log(L_DEBUG, "TXBUFSIZE=%d RXBUFSIZE=%d\n", + acx_log(LOG_DEBUG, L_REALLYVERBOSE, "TXBUFSIZE=%d RXBUFSIZE=%d\n", (int)TXBUFSIZE, (int)RXBUFSIZE); /* Allocate the RX/TX containers. */ adev->usb_tx = kmalloc(sizeof(usb_tx_t) * ACX_TX_URB_CNT, GFP_KERNEL); if (!adev->usb_tx) { - msg = "acx: no memory for tx container"; + msg = "no memory for tx container"; goto end_nomem; } adev->usb_rx = kmalloc(sizeof(usb_rx_t) * ACX_RX_URB_CNT, GFP_KERNEL); if (!adev->usb_rx) { - msg = "acx: no memory for rx container"; + msg = "no memory for rx container"; goto end_nomem; } @@ -910,7 +923,7 @@ acxusb_e_probe(struct usb_interface *intf, const struct usb_device_id *devID) for (i = 0; i < ACX_RX_URB_CNT; i++) { adev->usb_rx[i].urb = usb_alloc_urb(0, GFP_KERNEL); if (!adev->usb_rx[i].urb) { - msg = "acx: no memory for input URB\n"; + msg = "no memory for input URB\n"; goto end_nomem; } adev->usb_rx[i].urb->status = 0; @@ -921,7 +934,7 @@ acxusb_e_probe(struct usb_interface *intf, const struct usb_device_id *devID) for (i = 0; i < ACX_TX_URB_CNT; i++) { adev->usb_tx[i].urb = usb_alloc_urb(0, GFP_KERNEL); if (!adev->usb_tx[i].urb) { - msg = "acx: no memory for output URB\n"; + msg = "no memory for output URB\n"; goto end_nomem; } adev->usb_tx[i].urb->status = 0; @@ -959,10 +972,10 @@ acxusb_e_probe(struct usb_interface *intf, const struct usb_device_id *devID) } /* Register the network device */ - log(L_INIT, "registering network device\n"); + acx_log(LOG_DEBUG, L_INIT, "registering network device\n"); result = ieee80211_register_hw(adev->ieee); if (result) { - msg = "acx: failed to register USB network device " + msg = "failed to register USB network device " "(error %d)\n"; goto end_nomem; } @@ -970,7 +983,8 @@ acxusb_e_probe(struct usb_interface *intf, const struct usb_device_id *devID) acx_proc_register_entries(ieee); - printk("acx: USB module " ACX_RELEASE " loaded successfully\n"); + acx_log(LOG_INFO, L_ANY, "USB module " ACX_RELEASE + " loaded successfully\n"); acx_init_task_scheduler(adev); @@ -1207,14 +1221,15 @@ void acxusb_l_poll_rx(acx_device_t * adev, usb_rx_t * rx) inpipe = usb_rcvbulkpipe(usbdev, adev->bulkinep); if (unlikely(rxurb->status == -EINPROGRESS)) { - printk(KERN_ERR - "acx: error, rx triggered while rx urb in progress\n"); + acx_log(LOG_INFO, L_ANY, + "error, rx triggered while rx urb in progress\n"); /* FIXME: this is nasty, receive is being cancelled by this code * on the other hand, this should not happen anyway... */ usb_unlink_urb(rxurb); } else if (unlikely(rxurb->status == -ECONNRESET)) { - log(L_USBRXTX, "acx_usb: _poll_rx: connection reset\n"); + acx_log(LOG_DEBUG, L_USBRXTX, + "_poll_rx: connection reset\n"); goto end; } rxurb->actual_length = 0; @@ -1286,14 +1301,14 @@ void acxusb_i_complete_rx(struct urb *urb) acxusb_l_poll_rx(adev, &adev->usb_rx[rxnum ^ 1]); if (unlikely(size > sizeof(rxbuffer_t))) - printk("acx_usb: rx too large: %d, please report\n", size); + acx_log(LOG_INFO, L_ANY, "acx_usb: rx too large: %d, please report\n", size); /* check if the transfer was aborted */ switch (urb->status) { case 0: /* No error */ break; case -EOVERFLOW: - printk(KERN_ERR "acx: rx data overrun\n"); + acx_log(LOG_INFO, L_ANY, "rx data overrun\n"); adev->rxtruncsize = 0; /* Not valid anymore. */ goto end_unlock; case -ECONNRESET: @@ -1305,12 +1320,12 @@ void acxusb_i_complete_rx(struct urb *urb) default: adev->rxtruncsize = 0; adev->stats.rx_errors++; - printk("acx: rx error (urb status=%d)\n", urb->status); + acx_log(LOG_INFO, L_ANY, "rx error (urb status=%d)\n", urb->status); goto end_unlock; } if (unlikely(!size)) - printk("acx: warning, encountered zerolength rx packet\n"); + acx_log(LOG_INFO, L_ANY, "warning, encountered zerolength rx packet\n"); if (urb->transfer_buffer != inbuf) goto end_unlock; @@ -1326,7 +1341,7 @@ void acxusb_i_complete_rx(struct urb *urb) ptr = &adev->rxtruncbuf; packetsize = RXBUF_BYTES_USED(ptr); if (acx_debug & L_USBRXTX) { - printk("handling truncated frame (truncsize=%d size=%d " + acx_log(LOG_INFO, L_ANY, "handling truncated frame (truncsize=%d size=%d " "packetsize(from trunc)=%d)\n", adev->rxtruncsize, size, packetsize); acx_dump_bytes(ptr, RXBUF_HDRSIZE); @@ -1357,7 +1372,7 @@ void acxusb_i_complete_rx(struct urb *urb) tail_size); if (acx_debug & L_USBRXTX) { - printk("full trailing packet + 12 bytes:\n"); + acx_log(LOG_INFO, L_ANY, "full trailing packet + 12 bytes:\n"); acx_dump_bytes(inbuf, tail_size + RXBUF_HDRSIZE); } @@ -1376,7 +1391,7 @@ void acxusb_i_complete_rx(struct urb *urb) */ while (remsize) { if (remsize < RXBUF_HDRSIZE) { - printk("acx: truncated rx header (%d bytes)!\n", + acx_log(LOG_INFO, L_ANY, "truncated rx header (%d bytes)!\n", remsize); if (ACX_DEBUG) acx_dump_bytes(ptr, remsize); @@ -1415,7 +1430,7 @@ void acxusb_i_complete_rx(struct urb *urb) } if (packetsize > sizeof(rxbuffer_t)) { - printk("acx: packet exceeds max wlan " + acx_log(LOG_INFO, L_ANY, "packet exceeds max wlan " "frame size (%d > %d). size=%d\n", packetsize, (int)sizeof(rxbuffer_t), size); if (ACX_DEBUG) @@ -1427,7 +1442,7 @@ void acxusb_i_complete_rx(struct urb *urb) if (packetsize > remsize) { /* frame truncation handling */ if (acx_debug & L_USBRXTX) { - printk("need to truncate packet, " + acx_log(LOG_INFO, L_ANY, "need to truncate packet, " "packetsize=%d remsize=%d " "size=%d bytes:", packetsize, remsize, size); @@ -1445,7 +1460,7 @@ void acxusb_i_complete_rx(struct urb *urb) ptr = (rxbuffer_t *) (((char *)ptr) + packetsize); remsize -= packetsize; if ((acx_debug & L_USBRXTX) && remsize) { - printk("more than one packet in buffer, " + acx_log(LOG_INFO, L_ANY, "more than one packet in buffer, " "second packet hdr:"); acx_dump_bytes(ptr, RXBUF_HDRSIZE); } @@ -1508,7 +1523,7 @@ void acxusb_i_complete_tx(struct urb *urb) break; /* FIXME: real error-handling code here please */ default: - printk(KERN_ERR "acx: tx error, urb status=%d\n", urb->status); + acx_log(LOG_INFO, L_ANY, "tx error, urb status=%d\n", urb->status); /* FIXME: real error-handling code here please */ } @@ -1559,7 +1574,7 @@ tx_t *acxusb_l_alloc_tx(acx_device_t * adev) } } while (likely(head != adev->tx_head)); tx = NULL; - printk_ratelimited("acx: tx buffers full\n"); + acx_log_ratelimited(LOG_INFO, L_ANY, "tx buffers full\n"); end: adev->tx_head = head; FN_EXIT0; @@ -1612,7 +1627,7 @@ void acxusb_l_tx_data(acx_device_t * adev, tx_t * tx_opaque, int wlanpkt_len, st whdr = (struct ieee80211_hdr *) txbuf->data; txnum = tx - adev->usb_tx; - log(L_DEBUG, "using buf#%d free=%d len=%d\n", + acx_log(LOG_DEBUG, L_REALLYVERBOSE, "using buf#%d free=%d len=%d\n", txnum, adev->tx_free, wlanpkt_len); /* switch (adev->mode) { @@ -1628,7 +1643,7 @@ void acxusb_l_tx_data(acx_device_t * adev, tx_t * tx_opaque, int wlanpkt_len, st break; } if (unlikely(clt && !clt->rate_cur)) { - printk("acx: driver bug! bad ratemask\n"); + acx_log(LOG_INFO, L_ANY, "driver bug! bad ratemask\n"); goto end; } */ @@ -1647,13 +1662,13 @@ void acxusb_l_tx_data(acx_device_t * adev, tx_t * tx_opaque, int wlanpkt_len, st txbuf->data_len = cpu_to_le16(wlanpkt_len); if (unlikely(acx_debug & L_DATA)) { - printk("dump of bulk out urb:\n"); + acx_log(LOG_INFO, L_ANY, "dump of bulk out urb:\n"); acx_dump_bytes(txbuf, wlanpkt_len + USB_TXBUF_HDRSIZE); } if (unlikely(txurb->status == -EINPROGRESS)) { - printk - ("acx: trying to submit tx urb while already in progress\n"); + acx_log(LOG_INFO, L_ANY, + "trying to submit tx urb while already in progress\n"); } /* now schedule the USB transfer */ @@ -1668,12 +1683,13 @@ void acxusb_l_tx_data(acx_device_t * adev, tx_t * tx_opaque, int wlanpkt_len, st txurb->transfer_flags = URB_ASYNC_UNLINK | URB_ZERO_PACKET; ucode = usb_submit_urb(txurb, GFP_ATOMIC); - log(L_USBRXTX, "SUBMIT TX (%d): outpipe=0x%X buf=%p txsize=%d " - "rate=%u errcode=%d\n", txnum, outpipe, txbuf, - wlanpkt_len + USB_TXBUF_HDRSIZE, txbuf->rate, ucode); + acx_log(LOG_DEBUG, L_USBRXTX, + "SUBMIT TX (%d): outpipe=0x%X buf=%p txsize=%d " + "rate=%u errcode=%d\n", txnum, outpipe, txbuf, + wlanpkt_len + USB_TXBUF_HDRSIZE, txbuf->rate, ucode); if (unlikely(ucode)) { - printk(KERN_ERR "acx: submit_urb() error=%d txsize=%d\n", + acx_log(LOG_INFO, L_ANY, "submit_urb() error=%d txsize=%d\n", ucode, wlanpkt_len + USB_TXBUF_HDRSIZE); /* on error, just mark the frame as done and update @@ -1733,8 +1749,8 @@ void acxusb_i_tx_timeout(struct net_device *ndev) */ int __init acxusb_e_init_module(void) { - log(L_INIT, "USB module " ACX_RELEASE " initialized, " - "probing for devices...\n"); + acx_log(LOG_INFO, L_INIT, "USB module " ACX_RELEASE " initialized, " + "probing for devices...\n"); return usb_register(&acxusb_driver); } @@ -1749,7 +1765,7 @@ int __init acxusb_e_init_module(void) void __exit acxusb_e_cleanup_module(void) { usb_deregister(&acxusb_driver); - log(L_INIT, "USB module " ACX_RELEASE " unloaded\n"); + acx_log(LOG_INFO, L_INIT, "USB module " ACX_RELEASE " unloaded\n"); } @@ -1764,36 +1780,36 @@ static void dump_device(struct usb_device *usbdev) int i; struct usb_config_descriptor *cd; - printk("acx device dump:\n"); - printk(" devnum: %d\n", usbdev->devnum); - printk(" speed: %d\n", usbdev->speed); - printk(" tt: 0x%X\n", (unsigned int)(usbdev->tt)); - printk(" ttport: %d\n", (unsigned int)(usbdev->ttport)); - printk(" toggle[0]: 0x%X toggle[1]: 0x%X\n", + acx_log(LOG_INFO, L_ANY, "acx device dump:\n"); + acx_log(LOG_INFO, L_ANY, " devnum: %d\n", usbdev->devnum); + acx_log(LOG_INFO, L_ANY, " speed: %d\n", usbdev->speed); + acx_log(LOG_INFO, L_ANY, " tt: 0x%X\n", (unsigned int)(usbdev->tt)); + acx_log(LOG_INFO, L_ANY, " ttport: %d\n", (unsigned int)(usbdev->ttport)); + acx_log(LOG_INFO, L_ANY, " toggle[0]: 0x%X toggle[1]: 0x%X\n", (unsigned int)(usbdev->toggle[0]), (unsigned int)(usbdev->toggle[1])); /* This saw a change after 2.6.10 */ - printk(" ep_in wMaxPacketSize: "); + acx_log(LOG_INFO, L_ANY, " ep_in wMaxPacketSize: "); for (i = 0; i < 16; ++i) if (usbdev->ep_in[i] != NULL) printk("%d:%d ", i, usbdev->ep_in[i]->desc.wMaxPacketSize); printk("\n"); - printk(" ep_out wMaxPacketSize: "); + acx_log(LOG_INFO, L_ANY, " ep_out wMaxPacketSize: "); for (i = 0; i < ARRAY_SIZE(usbdev->ep_out); ++i) if (usbdev->ep_out[i] != NULL) printk("%d:%d ", i, usbdev->ep_out[i]->desc.wMaxPacketSize); printk("\n"); - printk(" parent: 0x%X\n", (unsigned int)usbdev->parent); - printk(" bus: 0x%X\n", (unsigned int)usbdev->bus); + acx_log(LOG_INFO, L_ANY, " parent: 0x%X\n", (unsigned int)usbdev->parent); + acx_log(LOG_INFO, L_ANY, " bus: 0x%X\n", (unsigned int)usbdev->bus); #ifdef NO_DATATYPE - printk(" configs: "); + acx_log(LOG_INFO, L_ANY, " configs: "); for (i = 0; i < usbdev->descriptor.bNumConfigurations; i++) printk("0x%X ", usbdev->config[i]); printk("\n"); #endif - printk(" actconfig: %p\n", usbdev->actconfig); + acx_log(LOG_INFO, L_ANY, " actconfig: %p\n", usbdev->actconfig); dump_device_descriptor(&usbdev->descriptor); cd = &usbdev->config->desc; @@ -1805,54 +1821,54 @@ static void dump_device(struct usb_device *usbdev) */ static void dump_config_descriptor(struct usb_config_descriptor *cd) { - printk("Configuration Descriptor:\n"); + acx_log(LOG_INFO, L_ANY, "Configuration Descriptor:\n"); if (!cd) { - printk("NULL\n"); + acx_log(LOG_INFO, L_ANY, "NULL\n"); return; } - printk(" bLength: %d (0x%X)\n", cd->bLength, cd->bLength); - printk(" bDescriptorType: %d (0x%X)\n", cd->bDescriptorType, + acx_log(LOG_INFO, L_ANY, " bLength: %d (0x%X)\n", cd->bLength, cd->bLength); + acx_log(LOG_INFO, L_ANY, " bDescriptorType: %d (0x%X)\n", cd->bDescriptorType, cd->bDescriptorType); - printk(" bNumInterfaces: %d (0x%X)\n", cd->bNumInterfaces, + acx_log(LOG_INFO, L_ANY, " bNumInterfaces: %d (0x%X)\n", cd->bNumInterfaces, cd->bNumInterfaces); - printk(" bConfigurationValue: %d (0x%X)\n", cd->bConfigurationValue, + acx_log(LOG_INFO, L_ANY, " bConfigurationValue: %d (0x%X)\n", cd->bConfigurationValue, cd->bConfigurationValue); - printk(" iConfiguration: %d (0x%X)\n", cd->iConfiguration, + acx_log(LOG_INFO, L_ANY, " iConfiguration: %d (0x%X)\n", cd->iConfiguration, cd->iConfiguration); - printk(" bmAttributes: %d (0x%X)\n", cd->bmAttributes, + acx_log(LOG_INFO, L_ANY, " bmAttributes: %d (0x%X)\n", cd->bmAttributes, cd->bmAttributes); - /* printk(" MaxPower: %d (0x%X)\n", cd->bMaxPower, cd->bMaxPower); */ + /* acx_log(LOG_INFO, L_ANY, " MaxPower: %d (0x%X)\n", cd->bMaxPower, cd->bMaxPower); */ } static void dump_device_descriptor(struct usb_device_descriptor *dd) { - printk("Device Descriptor:\n"); + acx_log(LOG_INFO, L_ANY, "Device Descriptor:\n"); if (!dd) { - printk("NULL\n"); + acx_log(LOG_INFO, L_ANY, "NULL\n"); return; } - printk(" bLength: %d (0x%X)\n", dd->bLength, dd->bLength); - printk(" bDescriptortype: %d (0x%X)\n", dd->bDescriptorType, + acx_log(LOG_INFO, L_ANY, " bLength: %d (0x%X)\n", dd->bLength, dd->bLength); + acx_log(LOG_INFO, L_ANY, " bDescriptortype: %d (0x%X)\n", dd->bDescriptorType, dd->bDescriptorType); - printk(" bcdUSB: %d (0x%X)\n", dd->bcdUSB, dd->bcdUSB); - printk(" bDeviceClass: %d (0x%X)\n", dd->bDeviceClass, + acx_log(LOG_INFO, L_ANY, " bcdUSB: %d (0x%X)\n", dd->bcdUSB, dd->bcdUSB); + acx_log(LOG_INFO, L_ANY, " bDeviceClass: %d (0x%X)\n", dd->bDeviceClass, dd->bDeviceClass); - printk(" bDeviceSubClass: %d (0x%X)\n", dd->bDeviceSubClass, + acx_log(LOG_INFO, L_ANY, " bDeviceSubClass: %d (0x%X)\n", dd->bDeviceSubClass, dd->bDeviceSubClass); - printk(" bDeviceProtocol: %d (0x%X)\n", dd->bDeviceProtocol, + acx_log(LOG_INFO, L_ANY, " bDeviceProtocol: %d (0x%X)\n", dd->bDeviceProtocol, dd->bDeviceProtocol); - printk(" bMaxPacketSize0: %d (0x%X)\n", dd->bMaxPacketSize0, + acx_log(LOG_INFO, L_ANY, " bMaxPacketSize0: %d (0x%X)\n", dd->bMaxPacketSize0, dd->bMaxPacketSize0); - printk(" idVendor: %d (0x%X)\n", dd->idVendor, dd->idVendor); - printk(" idProduct: %d (0x%X)\n", dd->idProduct, dd->idProduct); - printk(" bcdDevice: %d (0x%X)\n", dd->bcdDevice, dd->bcdDevice); - printk(" iManufacturer: %d (0x%X)\n", dd->iManufacturer, + acx_log(LOG_INFO, L_ANY, " idVendor: %d (0x%X)\n", dd->idVendor, dd->idVendor); + acx_log(LOG_INFO, L_ANY, " idProduct: %d (0x%X)\n", dd->idProduct, dd->idProduct); + acx_log(LOG_INFO, L_ANY, " bcdDevice: %d (0x%X)\n", dd->bcdDevice, dd->bcdDevice); + acx_log(LOG_INFO, L_ANY, " iManufacturer: %d (0x%X)\n", dd->iManufacturer, dd->iManufacturer); - printk(" iProduct: %d (0x%X)\n", dd->iProduct, dd->iProduct); - printk(" iSerialNumber: %d (0x%X)\n", dd->iSerialNumber, + acx_log(LOG_INFO, L_ANY, " iProduct: %d (0x%X)\n", dd->iProduct, dd->iProduct); + acx_log(LOG_INFO, L_ANY, " iSerialNumber: %d (0x%X)\n", dd->iSerialNumber, dd->iSerialNumber); - printk(" bNumConfigurations: %d (0x%X)\n", dd->bNumConfigurations, + acx_log(LOG_INFO, L_ANY, " bNumConfigurations: %d (0x%X)\n", dd->bNumConfigurations, dd->bNumConfigurations); } #endif /* UNUSED */ -- 2.11.4.GIT