Message ID | 0baed35e98144bc7e29681264caf954b659cd481.camel@egauge.net |
---|---|
State | New |
Headers | show |
Series | RFC: wilc1000 module parameter to disable chip sleep | expand |
David Mosberger-Tang <davidm@egauge.net> writes: > At least on our SAMA5-based platform, the chip-sleep in the wilc1000 > driver degrades WILC1000 transmit throughput by more than three times, > without providing significant power-savings. Because of that, I have > been considering adding a module parameter that would make the chip > sleep optional. Something along these lines: > > diff --git a/drivers/net/wireless/microchip/wilc1000/wlan.c b/drivers/net/wireless/microchip/wilc1000/wlan.c > index 757bd4471fd4..421672488100 100644 > --- a/drivers/net/wireless/microchip/wilc1000/wlan.c > +++ b/drivers/net/wireless/microchip/wilc1000/wlan.c > @@ -10,6 +10,12 @@ > #include "cfg80211.h" > #include "wlan_cfg.h" > > +static bool enable_sleep; > +module_param(enable_sleep, bool, 0644); > +MODULE_PARM_DESC(enable_sleep, > + "Enable chip sleep whenever the host is done communicating\n" > + "\t\t\twith the WILC1000 chip."); > + > static inline bool is_wilc1000(u32 id) > { > return (id & (~WILC_CHIP_REV_FIELD)) == WILC_1000_BASE_ID; > @@ -18,13 +24,13 @@ static inline bool is_wilc1000(u32 id) > static inline void acquire_bus(struct wilc *wilc, enum bus_acquire acquire) > { > mutex_lock(&wilc->hif_cs); > - if (acquire == WILC_BUS_ACQUIRE_AND_WAKEUP) > + if (enable_sleep && acquire == WILC_BUS_ACQUIRE_AND_WAKEUP) > chip_wakeup(wilc); > } > > static inline void release_bus(struct wilc *wilc, enum bus_release release) > { > - if (release == WILC_BUS_RELEASE_ALLOW_SLEEP) > + if (enable_sleep && release == WILC_BUS_RELEASE_ALLOW_SLEEP) > chip_allow_sleep(wilc); > mutex_unlock(&wilc->hif_cs); > } > > However, based on the numbers below, I'm now wondering if it wouldn't > make more sense to remove the chip-sleep code altogether. > > Here is what I see: on a system configured for minimum power consumption > (all unnecessary daemons disabled, Ethernet unplugged) I measured 1,180 mW > when the WILC chip is in RESET (the ENABLE pin is always high on our platform). > > With the wilc1000-spi/wilc1000 modules loaded and the WILC chip > running but without being associated with a WLAN network, measured > power consumption was 1,460 mW, regardless of whether chip sleep was > enabled or disabled. > > On the other hand, chip-sleep makes a huge difference for TX > throughput and also reduces RX throughput, but to a smaller > extent. Specifically, I used ttcp to measure throughput on the > test system 5 times in a row, both in TX and RX direction > (TX meaning "ttcp -t" is run from the test system to a desktop > machine): > > TX throughput ("./ttcp -t DESKTOPIPADDR" on the DUT): > enable_sleep=1: 16777216 bytes in 41.22 real seconds = 397.50 KB/sec +++ > enable_sleep=1: 16777216 bytes in 40.67 real seconds = 402.81 KB/sec +++ > enable_sleep=1: 16777216 bytes in 41.08 real seconds = 398.83 KB/sec +++ > enable_sleep=1: 16777216 bytes in 41.35 real seconds = 396.25 KB/sec +++ > > enable_sleep=0: 16777216 bytes in 11.12 real seconds = 1472.78 KB/sec +++ > enable_sleep=0: 16777216 bytes in 10.76 real seconds = 1523.10 KB/sec +++ > enable_sleep=0: 16777216 bytes in 11.83 real seconds = 1385.21 KB/sec +++ > enable_sleep=0: 16777216 bytes in 10.94 real seconds = 1497.66 KB/sec +++ > enable_sleep=0: 16777216 bytes in 10.13 real seconds = 1617.21 KB/sec +++ > > RX throughput ("./ttcp -r" on the DUT): > > enable_sleep=1: 16777216 bytes in 8.44 real seconds = 1941.97 KB/sec +++ > enable_sleep=1: wilc1000, w/ sleep: 16777216 bytes in 12.69 real seconds = 1290.94 KB/sec +++ > enable_sleep=1: 16777216 bytes in 12.79 real seconds = 1280.93 KB/sec +++ > enable_sleep=1: 16777216 bytes in 12.39 real seconds = 1322.33 KB/sec +++ > > enable_sleep=0: 16777216 bytes in 5.83 real seconds = 2811.94 KB/sec +++ > enable_sleep=0: 16777216 bytes in 5.75 real seconds = 2848.09 KB/sec +++ > enable_sleep=0: 16777216 bytes in 5.97 real seconds = 2744.44 KB/sec +++ > enable_sleep=0: 16777216 bytes in 6.11 real seconds = 2681.96 KB/sec +++ > enable_sleep=0: 16777216 bytes in 6.01 real seconds = 2724.09 KB/sec +++ > >>From what I can tell, the chip-sleep code either isn't working or the chip > sleep just isn't making any real difference in power consumption. > > Given this, is there any reason to keep the chip-sleep code around? If it doesn't work I would just remove it to keep things simple. It can always added back if somebody fixes it.
On 09/12/21 00:20, David Mosberger-Tang wrote: > EXTERNAL EMAIL: Do not click links or open attachments unless you know the content is safe > > At least on our SAMA5-based platform, the chip-sleep in the wilc1000 > driver degrades WILC1000 transmit throughput by more than three times, > without providing significant power-savings. Because of that, I have > been considering adding a module parameter that would make the chip > sleep optional. Something along these lines: > > diff --git a/drivers/net/wireless/microchip/wilc1000/wlan.c b/drivers/net/wireless/microchip/wilc1000/wlan.c > index 757bd4471fd4..421672488100 100644 > --- a/drivers/net/wireless/microchip/wilc1000/wlan.c > +++ b/drivers/net/wireless/microchip/wilc1000/wlan.c > @@ -10,6 +10,12 @@ > #include "cfg80211.h" > #include "wlan_cfg.h" > > +static bool enable_sleep; > +module_param(enable_sleep, bool, 0644); > +MODULE_PARM_DESC(enable_sleep, > + "Enable chip sleep whenever the host is done communicating\n" > + "\t\t\twith the WILC1000 chip."); > + > static inline bool is_wilc1000(u32 id) > { > return (id & (~WILC_CHIP_REV_FIELD)) == WILC_1000_BASE_ID; > @@ -18,13 +24,13 @@ static inline bool is_wilc1000(u32 id) > static inline void acquire_bus(struct wilc *wilc, enum bus_acquire acquire) > { > mutex_lock(&wilc->hif_cs); > - if (acquire == WILC_BUS_ACQUIRE_AND_WAKEUP) > + if (enable_sleep && acquire == WILC_BUS_ACQUIRE_AND_WAKEUP) > chip_wakeup(wilc); > } > > static inline void release_bus(struct wilc *wilc, enum bus_release release) > { > - if (release == WILC_BUS_RELEASE_ALLOW_SLEEP) > + if (enable_sleep && release == WILC_BUS_RELEASE_ALLOW_SLEEP) > chip_allow_sleep(wilc); > mutex_unlock(&wilc->hif_cs); > } > > However, based on the numbers below, I'm now wondering if it wouldn't > make more sense to remove the chip-sleep code altogether. The "chip_wakeup" & "chip_allow_sleep" API's are required to configure the wake-up registers in wilc. These registers must be configured correctly when the power save mode is enabled. These API's get used for both SPI/SDIO bus. > Here is what I see: on a system configured for minimum power consumption > (all unnecessary daemons disabled, Ethernet unplugged) I measured 1,180 mW > when the WILC chip is in RESET (the ENABLE pin is always high on our platform). > > With the wilc1000-spi/wilc1000 modules loaded and the WILC chip > running but without being associated with a WLAN network, measured > power consumption was 1,460 mW, regardless of whether chip sleep was > enabled or disabled. Did you test by enabling the power-save mode with "wpa_supplicant" or using "iw" command. For power consumption measurement, please try by disabling the PSM mode. Below command can be used to enable/disable PSM mode. iw dev wlan0 set power_save on/off There is a document(link below) which contain details about the power consumption measured for WILC1000. Please check, it may be useful. https://ww1.microchip.com/downloads/en/Appnotes/ATWILC1000-Power-Measurement-for-Wi-Fi-Link-Controller-00002797A.pdf > On the other hand, chip-sleep makes a huge difference for TX > throughput and also reduces RX throughput, but to a smaller > extent. Specifically, I used ttcp to measure throughput on the > test system 5 times in a row, both in TX and RX direction > (TX meaning "ttcp -t" is run from the test system to a desktop > machine): > TX throughput ("./ttcp -t DESKTOPIPADDR" on the DUT): > enable_sleep=1: 16777216 bytes in 41.22 real seconds = 397.50 KB/sec +++ > enable_sleep=1: 16777216 bytes in 40.67 real seconds = 402.81 KB/sec +++ > enable_sleep=1: 16777216 bytes in 41.08 real seconds = 398.83 KB/sec +++ > enable_sleep=1: 16777216 bytes in 41.35 real seconds = 396.25 KB/sec +++ > > enable_sleep=0: 16777216 bytes in 11.12 real seconds = 1472.78 KB/sec +++ > enable_sleep=0: 16777216 bytes in 10.76 real seconds = 1523.10 KB/sec +++ > enable_sleep=0: 16777216 bytes in 11.83 real seconds = 1385.21 KB/sec +++ > enable_sleep=0: 16777216 bytes in 10.94 real seconds = 1497.66 KB/sec +++ > enable_sleep=0: 16777216 bytes in 10.13 real seconds = 1617.21 KB/sec +++ > > RX throughput ("./ttcp -r" on the DUT): > > enable_sleep=1: 16777216 bytes in 8.44 real seconds = 1941.97 KB/sec +++ > enable_sleep=1: wilc1000, w/ sleep: 16777216 bytes in 12.69 real seconds = 1290.94 KB/sec +++ > enable_sleep=1: 16777216 bytes in 12.79 real seconds = 1280.93 KB/sec +++ > enable_sleep=1: 16777216 bytes in 12.39 real seconds = 1322.33 KB/sec +++ > > enable_sleep=0: 16777216 bytes in 5.83 real seconds = 2811.94 KB/sec +++ > enable_sleep=0: 16777216 bytes in 5.75 real seconds = 2848.09 KB/sec +++ > enable_sleep=0: 16777216 bytes in 5.97 real seconds = 2744.44 KB/sec +++ > enable_sleep=0: 16777216 bytes in 6.11 real seconds = 2681.96 KB/sec +++ > enable_sleep=0: 16777216 bytes in 6.01 real seconds = 2724.09 KB/sec +++ These throughput number are low in your setup though I am not sure about the reason. Actually, the throughput depends on many factors. Below are the number, I got using iPerf on my setup in open environment with/without PS mode. The iPerf test duration was 100sec and the SPI max_speed_hz at 48Mhz. The test is executed with chip-sleep code. *power-save enabled* TCP Tx : [ 4] 0.0-100.1 sec 47.8 MBytes 4.01 Mbits/sec TCP Rx : [ 4] 0.0-100.3 sec 115 MBytes 9.65 Mbits/sec *power-save disabled* TCP Tx : [ 4] 0.0-100.1 sec 61.9 MBytes 5.19 Mbits/sec TCP Rx : [ 4] 0.0-100.0 sec 122 MBytes 10.2 Mbits/sec As I observed, there is an improvement of around ~1Mbps when the PS mode is disabled. These numbers would be higher when the test is performed in the shield room. For SDIO bus, the throughput numbers are higher and may cross 20Mbps+ for both Tx/Rx path. > From what I can tell, the chip-sleep code either isn't working or the chip > sleep just isn't making any real difference in power consumption. > > Given this, is there any reason to keep the chip-sleep code around? The chip-sleep code is needed to configure the registers properly for wilc and not using these sequence would have impact on sending the data to wilc, especially when the PS mode is enabled. Regards, Ajay
On Thu, 2021-12-09 at 09:20 +0000, Ajay.Kathat@microchip.com wrote: > On 09/12/21 00:20, David Mosberger-Tang wrote: > The "chip_wakeup" & "chip_allow_sleep" API's are required to configure > the wake-up registers in wilc. These registers must be configured > correctly when the power save mode is enabled. I see. > > Here is what I see: on a system configured for minimum power consumption > > (all unnecessary daemons disabled, Ethernet unplugged) I measured 1,180 mW > > when the WILC chip is in RESET (the ENABLE pin is always high on our > > platform). > > > > With the wilc1000-spi/wilc1000 modules loaded and the WILC chip > > running but without being associated with a WLAN network, measured > > power consumption was 1,460 mW, regardless of whether chip sleep was > > enabled or disabled. > > Did you test by enabling the power-save mode with "wpa_supplicant" or > using "iw" command. For power consumption measurement, please try by > disabling the PSM mode. No, I have not played with power-saving mode. There are some disconcerting messages when turning PSM on: [ 1764.070375] wilc1000_spi spi1.0: Failed cmd, cmd (ca), resp (00) [ 1764.076403] wilc1000_spi spi1.0: Failed cmd, read reg (000013f4)... The driver does still work, but occasionally, I get long streams of these messages, sometimes it gets to the point where there are so many that the watchdog timer ends up rebooting the system. > The chip-sleep code is needed to configure the registers properly for > wilc and not using these sequence would have impact on sending the data > to wilc, especially when the PS mode is enabled. How about something along the patch below then? With this patch, I see the following iperf3 performance (120 second average): PSM on: [ 4] 0.00-120.00 sec 47.6 MBytes 3.33 Mbits/sec 0 sender PSM off: [ 4] 0.00-120.00 sec 201 MBytes 14.0 Mbits/sec 12 sender In terms of power consumption: baseline : 1.2 W PSM on, idle : 1.2 W PSM on, TX @ 3.33 Mbps : 1.7 W PSM off, idle : 1.5 W PSM off, TX @ 14.0 Mbps : 2.4 W --david
[Sorry, my first email was accidentally had the patch appended as a MIME attachment.] On Thu, 2021-12-09 at 09:20 +0000, Ajay.Kathat@microchip.com wrote: > On 09/12/21 00:20, David Mosberger-Tang wrote: > The "chip_wakeup" & "chip_allow_sleep" API's are required to configure > the wake-up registers in wilc. These registers must be configured > correctly when the power save mode is enabled. I see. > > Here is what I see: on a system configured for minimum power consumption > > (all unnecessary daemons disabled, Ethernet unplugged) I measured 1,180 mW > > when the WILC chip is in RESET (the ENABLE pin is always high on our > > platform). > > > > With the wilc1000-spi/wilc1000 modules loaded and the WILC chip > > running but without being associated with a WLAN network, measured > > power consumption was 1,460 mW, regardless of whether chip sleep was > > enabled or disabled. > > Did you test by enabling the power-save mode with "wpa_supplicant" or > using "iw" command. For power consumption measurement, please try by > disabling the PSM mode. No, I have not played with power-saving mode. There are some disconcerting messages when turning PSM on: [ 1764.070375] wilc1000_spi spi1.0: Failed cmd, cmd (ca), resp (00) [ 1764.076403] wilc1000_spi spi1.0: Failed cmd, read reg (000013f4)... The driver does still work, but occasionally, I get long streams of these messages, sometimes it gets to the point where there are so many that the watchdog timer ends up rebooting the system. > The chip-sleep code is needed to configure the registers properly for > wilc and not using these sequence would have impact on sending the data > to wilc, especially when the PS mode is enabled. How about something along the patch below then? With this patch, I see the following iperf3 performance (120 second average): PSM on: [ 4] 0.00-120.00 sec 47.6 MBytes 3.33 Mbits/sec 0 sender PSM off: [ 4] 0.00-120.00 sec 201 MBytes 14.0 Mbits/sec 12 sender In terms of power consumption: baseline : 1.2 W PSM on, idle : 1.2 W PSM on, TX @ 3.33 Mbps : 1.7 W PSM off, idle : 1.5 W PSM off, TX @ 14.0 Mbps : 2.4 W --david diff --git a/drivers/net/wireless/microchip/wilc1000/hif.c b/drivers/net/wireless/microchip/wilc1000/hif.c index 44e93cd5e3df..09aa5ced19d3 100644 --- a/drivers/net/wireless/microchip/wilc1000/hif.c +++ b/drivers/net/wireless/microchip/wilc1000/hif.c @@ -1912,6 +1912,7 @@ int wilc_edit_station(struct wilc_vif *vif, const u8 *mac, int wilc_set_power_mgmt(struct wilc_vif *vif, bool enabled, u32 timeout) { + struct wilc *wilc = vif->wilc; struct wid wid; int result; s8 power_mode; @@ -1927,6 +1928,8 @@ int wilc_set_power_mgmt(struct wilc_vif *vif, bool enabled, u32 timeout) result = wilc_send_config_pkt(vif, WILC_SET_CFG, &wid, 1); if (result) netdev_err(vif->ndev, "Failed to send power management\n"); + else + wilc->power_save_mode = enabled; return result; } diff --git a/drivers/net/wireless/microchip/wilc1000/netdev.h b/drivers/net/wireless/microchip/wilc1000/netdev.h index 152408232d51..db149abc5d0d 100644 --- a/drivers/net/wireless/microchip/wilc1000/netdev.h +++ b/drivers/net/wireless/microchip/wilc1000/netdev.h @@ -267,6 +267,7 @@ struct wilc { int clients_count; struct workqueue_struct *hif_workqueue; + bool power_save_mode; enum chip_ps_states chip_ps_state; struct wilc_cfg cfg; void *bus_data; diff --git a/drivers/net/wireless/microchip/wilc1000/wlan.c b/drivers/net/wireless/microchip/wilc1000/wlan.c index ddd382996275..0e0e325d396e 100644 --- a/drivers/net/wireless/microchip/wilc1000/wlan.c +++ b/drivers/net/wireless/microchip/wilc1000/wlan.c @@ -18,13 +18,13 @@ static inline bool is_wilc1000(u32 id) static inline void acquire_bus(struct wilc *wilc, enum bus_acquire acquire) { mutex_lock(&wilc->hif_cs); - if (acquire == WILC_BUS_ACQUIRE_AND_WAKEUP) + if (acquire == WILC_BUS_ACQUIRE_AND_WAKEUP && wilc->power_save_mode) chip_wakeup(wilc); } static inline void release_bus(struct wilc *wilc, enum bus_release release) { - if (release == WILC_BUS_RELEASE_ALLOW_SLEEP) + if (release == WILC_BUS_RELEASE_ALLOW_SLEEP && wilc->power_save_mode) chip_allow_sleep(wilc); mutex_unlock(&wilc->hif_cs); }
On Thu, 2021-12-09 at 11:15 -0700, David Mosberger-Tang wrote: > > Did you test by enabling the power-save mode with "wpa_supplicant" or > > using "iw" command. For power consumption measurement, please try by > > disabling the PSM mode. > > No, I have not played with power-saving mode. There are some disconcerting > messages when turning PSM on: > > [ 1764.070375] wilc1000_spi spi1.0: Failed cmd, cmd (ca), resp (00) > [ 1764.076403] wilc1000_spi spi1.0: Failed cmd, read reg (000013f4)... As far as I can see, chip_wakeup() can trigger this legitimately: do { h->hif_read_reg(wilc, WILC_SPI_WAKEUP_REG, ®); h->hif_write_reg(wilc, WILC_SPI_WAKEUP_REG, reg | WILC_SPI_WAKEUP_BIT); h->hif_write_reg(wilc, WILC_SPI_WAKEUP_REG, reg & ~WILC_SPI_WAKEUP_BIT); do { usleep_range(2000, 2500); wilc_get_chipid(wilc, true); } while (wilc_get_chipid(wilc, true) == 0); } while (wilc_get_chipid(wilc, true) == 0); Actually, the above looks rather gross. wilc_get_chip() reads both WILC_CHIPID and WILC_RF_REVISION_ID and we do this at least three times in a row on each chip_wakeup(). Wow. Is this really necessary? In any case, for now, the below supresses the error messages: diff --git a/drivers/net/wireless/microchip/wilc1000/spi.c b/drivers/net/wireless/microchip/wilc1000/spi.c index b778284247f7..516787aa4a23 100644 --- a/drivers/net/wireless/microchip/wilc1000/spi.c +++ b/drivers/net/wireless/microchip/wilc1000/spi.c @@ -498,7 +498,7 @@ static int wilc_spi_single_read(struct wilc *wilc, u8 cmd, u32 adr, void *b, r = (struct wilc_spi_rsp_data *)&rb[cmd_len]; if (r->rsp_cmd_type != cmd) { if (!spi_priv->probing_crc) - dev_err(&spi->dev, + dev_dbg(&spi->dev, "Failed cmd, cmd (%02x), resp (%02x)\n", cmd, r->rsp_cmd_type); return -EINVAL; @@ -754,7 +754,8 @@ static int wilc_spi_read_reg(struct wilc *wilc, u32 addr, u32 *data) result = wilc_spi_single_read(wilc, cmd, addr, data, clockless); if (result) { - dev_err(&spi->dev, "Failed cmd, read reg (%08x)...\n", addr); + /* Register reads may fail legitimately, e.g., during chip_wakeup(). */ + dev_dbg(&spi->dev, "Failed cmd, read reg (%08x)...\n", addr); return result; } Maybe a parameter should be added to hif_read_reg() to indicate whether failure is an option? --david
On Thu, 2021-12-09 at 12:12 -0700, David Mosberger-Tang wrote: > On Thu, 2021-12-09 at 11:15 -0700, David Mosberger-Tang wrote: > > > > Did you test by enabling the power-save mode with "wpa_supplicant" or > > > using "iw" command. For power consumption measurement, please try by > > > disabling the PSM mode. > > > > No, I have not played with power-saving mode. There are some disconcerting > > messages when turning PSM on: > > > > [ 1764.070375] wilc1000_spi spi1.0: Failed cmd, cmd (ca), resp (00) > > [ 1764.076403] wilc1000_spi spi1.0: Failed cmd, read reg (000013f4)... > > As far as I can see, chip_wakeup() can trigger this legitimately: > > do { > h->hif_read_reg(wilc, WILC_SPI_WAKEUP_REG, ®); > h->hif_write_reg(wilc, WILC_SPI_WAKEUP_REG, > reg | WILC_SPI_WAKEUP_BIT); > h->hif_write_reg(wilc, WILC_SPI_WAKEUP_REG, > reg & ~WILC_SPI_WAKEUP_BIT); > > do { > usleep_range(2000, 2500); > wilc_get_chipid(wilc, true); > } while (wilc_get_chipid(wilc, true) == 0); > } while (wilc_get_chipid(wilc, true) == 0); > > Actually, the above looks rather gross. wilc_get_chip() reads both WILC_CHIPID > and WILC_RF_REVISION_ID and we do this at least three times in a row on each > chip_wakeup(). Wow. Is this really necessary? Looks like I'm on to something. If I replace the gross code with: h->hif_read_reg(wilc, WILC_SPI_WAKEUP_REG, ®); h->hif_write_reg(wilc, WILC_SPI_WAKEUP_REG, reg | WILC_SPI_WAKEUP_BIT); h->hif_write_reg(wilc, WILC_SPI_WAKEUP_REG, reg & ~WILC_SPI_WAKEUP_BIT); while (1) { if (wilc->hif_func->hif_read_reg(wilc, WILC_CHIPID, &chipid) == 0) break; usleep_range(2000, 2500); } Look what happens to TX throughput: [ 4] 0.00-120.00 sec 142 MBytes 9.92 Mbits/sec 6 sender This is with power_save mode turned on. Almost exactly 3 times faster than the 3.33 Mbits/sec I was seeing before. --david
I took linux-wireless off the CC list... On Thu, 2021-12-09 at 12:28 -0700, David Mosberger-Tang wrote: > On Thu, 2021-12-09 at 12:12 -0700, David Mosberger-Tang wrote: > > On Thu, 2021-12-09 at 11:15 -0700, David Mosberger-Tang wrote: > > > > As far as I can see, chip_wakeup() can trigger this legitimately: > > > > do { > > h->hif_read_reg(wilc, WILC_SPI_WAKEUP_REG, ®); > > h->hif_write_reg(wilc, WILC_SPI_WAKEUP_REG, > > reg | WILC_SPI_WAKEUP_BIT); > > h->hif_write_reg(wilc, WILC_SPI_WAKEUP_REG, > > reg & ~WILC_SPI_WAKEUP_BIT); > > > > do { > > usleep_range(2000, 2500); > > wilc_get_chipid(wilc, true); > > } while (wilc_get_chipid(wilc, true) == 0); > > } while (wilc_get_chipid(wilc, true) == 0); > > > > Actually, the above looks rather gross. wilc_get_chip() reads both WILC_CHIPID > > and WILC_RF_REVISION_ID and we do this at least three times in a row on each > > chip_wakeup(). Wow. Is this really necessary? > > Looks like I'm on to something. If I replace the gross code with: > > h->hif_read_reg(wilc, WILC_SPI_WAKEUP_REG, ®); > h->hif_write_reg(wilc, WILC_SPI_WAKEUP_REG, reg | WILC_SPI_WAKEUP_BIT); > h->hif_write_reg(wilc, WILC_SPI_WAKEUP_REG, reg & ~WILC_SPI_WAKEUP_BIT); > > while (1) { > if (wilc->hif_func->hif_read_reg(wilc, WILC_CHIPID, &chipid) == 0) > break; > usleep_range(2000, 2500); > } > > Look what happens to TX throughput: > > [ 4] 0.00-120.00 sec 142 MBytes 9.92 Mbits/sec 6 sender > > This is with power_save mode turned on. Almost exactly 3 times faster than the > 3.33 Mbits/sec I was seeing before. Over 120 seconds of iperf3, a histogram of the number of WILC_CHIPID reads required to get a successful read looked like this: [ 493.918785] hist[ 0]=70417 [ 493.921609] hist[ 1]=0 [ 493.923997] hist[ 2]=0 [ 493.926424] hist[ 3]=0 [ 493.928957] hist[ 4]=0 [ 493.931359] hist[ 5]=0 [ 493.933781] hist[ 6]=0 [ 493.936210] hist[ 7]=0 [ 493.938702] hist[ 8]=0 [ 493.941097] hist[ 9]=0 [ 493.943523] hist[ 10]=0 [ 493.945951] hist[ 11]=0 [ 493.948418] hist[ 12]=0 [ 493.950812] hist[ 13]=0 [ 493.953238] hist[ 14]=0 [ 493.955667] hist[ 15]=0 [ 493.958126] hist[ 16]=0 [ 493.960527] hist[ 17]=0 [ 493.962954] hist[ 18]=1 [ 493.965382] hist[ 19]=7 [ 493.967840] hist[ 20]=1 [ 493.970242] hist[ 21]=13 Based on this, I changed the above code to: while (1) { h->hif_read_reg(wilc, WILC_SPI_WAKEUP_REG, ®); h->hif_write_reg(wilc, WILC_SPI_WAKEUP_REG, reg | WILC_SPI_WAKEUP_BIT); h->hif_write_reg(wilc, WILC_SPI_WAKEUP_REG, reg & ~WILC_SPI_WAKEUP_BIT); if (wilc->hif_func->hif_read_reg(wilc, WILC_CHIPID, &chipid) == 0) break; usleep_range(2000, 2500); } This gets me: TX/PSM off: [ 4] 0.00-120.00 sec 198 MBytes 13.8 Mbits/sec 9 sender TX/PSM on : [ 4] 0.00-120.00 sec 140 MBytes 9.78 Mbits/sec 9 sender RX/PSM off: [ 5] 0.00-120.10 sec 304 MBytes 21.2 Mbits/sec receiver RX/PSM on : [ 5] 0.00-120.11 sec 288 MBytes 20.1 Mbits/sec receive Ajay, I'm guessing your kernel is either configured for tickless timer or HZ=1000? That would explain why you'd see higher throughput with the original code. My system is configured for HZ=100, so the usleep_range() would typically take 10ms. Any objections to the latest code? --david
On 09/12/21 23:45, David Mosberger-Tang wrote: > EXTERNAL EMAIL: Do not click links or open attachments unless you know the content is safe > > [Sorry, my first email was accidentally had the patch appended as a MIME > attachment.] > > On Thu, 2021-12-09 at 09:20 +0000, Ajay.Kathat@microchip.com wrote: >> On 09/12/21 00:20, David Mosberger-Tang wrote: >> The "chip_wakeup" & "chip_allow_sleep" API's are required to configure >> the wake-up registers in wilc. These registers must be configured >> correctly when the power save mode is enabled. > I see. > >>> Here is what I see: on a system configured for minimum power consumption >>> (all unnecessary daemons disabled, Ethernet unplugged) I measured 1,180 mW >>> when the WILC chip is in RESET (the ENABLE pin is always high on our >>> platform). >>> >>> With the wilc1000-spi/wilc1000 modules loaded and the WILC chip >>> running but without being associated with a WLAN network, measured >>> power consumption was 1,460 mW, regardless of whether chip sleep was >>> enabled or disabled. >> Did you test by enabling the power-save mode with "wpa_supplicant" or >> using "iw" command. For power consumption measurement, please try by >> disabling the PSM mode. > No, I have not played with power-saving mode. There are some disconcerting > messages when turning PSM on: > > [ 1764.070375] wilc1000_spi spi1.0: Failed cmd, cmd (ca), resp (00) > [ 1764.076403] wilc1000_spi spi1.0: Failed cmd, read reg (000013f4)... > > The driver does still work, but occasionally, I get long streams of these > messages, sometimes it gets to the point where there are so many that the > watchdog timer ends up rebooting the system. > >> The chip-sleep code is needed to configure the registers properly for >> wilc and not using these sequence would have impact on sending the data >> to wilc, especially when the PS mode is enabled. > How about something along the patch below then? Thanks. The changes looks okay to me. > With this patch, I see the following iperf3 performance (120 second average): > > PSM on: > [ 4] 0.00-120.00 sec 47.6 MBytes 3.33 Mbits/sec 0 sender > > PSM off: > [ 4] 0.00-120.00 sec 201 MBytes 14.0 Mbits/sec 12 sender > > In terms of power consumption: > > baseline : 1.2 W > PSM on, idle : 1.2 W > PSM on, TX @ 3.33 Mbps : 1.7 W > PSM off, idle : 1.5 W > PSM off, TX @ 14.0 Mbps : 2.4 W > > --david > > diff --git a/drivers/net/wireless/microchip/wilc1000/hif.c > b/drivers/net/wireless/microchip/wilc1000/hif.c > index 44e93cd5e3df..09aa5ced19d3 100644 > --- a/drivers/net/wireless/microchip/wilc1000/hif.c > +++ b/drivers/net/wireless/microchip/wilc1000/hif.c > @@ -1912,6 +1912,7 @@ int wilc_edit_station(struct wilc_vif *vif, const u8 *mac, > > int wilc_set_power_mgmt(struct wilc_vif *vif, bool enabled, u32 timeout) > { > + struct wilc *wilc = vif->wilc; > struct wid wid; > int result; > s8 power_mode; > @@ -1927,6 +1928,8 @@ int wilc_set_power_mgmt(struct wilc_vif *vif, bool > enabled, u32 timeout) > result = wilc_send_config_pkt(vif, WILC_SET_CFG, &wid, 1); > if (result) > netdev_err(vif->ndev, "Failed to send power management\n"); > + else > + wilc->power_save_mode = enabled; > > return result; > } > diff --git a/drivers/net/wireless/microchip/wilc1000/netdev.h > b/drivers/net/wireless/microchip/wilc1000/netdev.h > index 152408232d51..db149abc5d0d 100644 > --- a/drivers/net/wireless/microchip/wilc1000/netdev.h > +++ b/drivers/net/wireless/microchip/wilc1000/netdev.h > @@ -267,6 +267,7 @@ struct wilc { > > int clients_count; > struct workqueue_struct *hif_workqueue; > + bool power_save_mode; > enum chip_ps_states chip_ps_state; > struct wilc_cfg cfg; > void *bus_data; > diff --git a/drivers/net/wireless/microchip/wilc1000/wlan.c > b/drivers/net/wireless/microchip/wilc1000/wlan.c > index ddd382996275..0e0e325d396e 100644 > --- a/drivers/net/wireless/microchip/wilc1000/wlan.c > +++ b/drivers/net/wireless/microchip/wilc1000/wlan.c > @@ -18,13 +18,13 @@ static inline bool is_wilc1000(u32 id) > static inline void acquire_bus(struct wilc *wilc, enum bus_acquire acquire) > { > mutex_lock(&wilc->hif_cs); > - if (acquire == WILC_BUS_ACQUIRE_AND_WAKEUP) > + if (acquire == WILC_BUS_ACQUIRE_AND_WAKEUP && wilc->power_save_mode) > chip_wakeup(wilc); > } > > static inline void release_bus(struct wilc *wilc, enum bus_release release) > { > - if (release == WILC_BUS_RELEASE_ALLOW_SLEEP) > + if (release == WILC_BUS_RELEASE_ALLOW_SLEEP && wilc->power_save_mode) > chip_allow_sleep(wilc); > mutex_unlock(&wilc->hif_cs); > } >
On 10/12/21 00:42, David Mosberger-Tang wrote: > EXTERNAL EMAIL: Do not click links or open attachments unless you know the content is safe > > On Thu, 2021-12-09 at 11:15 -0700, David Mosberger-Tang wrote: > >>> Did you test by enabling the power-save mode with "wpa_supplicant" or >>> using "iw" command. For power consumption measurement, please try by >>> disabling the PSM mode. >> No, I have not played with power-saving mode. There are some disconcerting >> messages when turning PSM on: >> >> [ 1764.070375] wilc1000_spi spi1.0: Failed cmd, cmd (ca), resp (00) >> [ 1764.076403] wilc1000_spi spi1.0: Failed cmd, read reg (000013f4)... > As far as I can see, chip_wakeup() can trigger this legitimately: > > do { > h->hif_read_reg(wilc, WILC_SPI_WAKEUP_REG, ®); > h->hif_write_reg(wilc, WILC_SPI_WAKEUP_REG, > reg | WILC_SPI_WAKEUP_BIT); > h->hif_write_reg(wilc, WILC_SPI_WAKEUP_REG, > reg & ~WILC_SPI_WAKEUP_BIT); > > do { > usleep_range(2000, 2500); > wilc_get_chipid(wilc, true); > } while (wilc_get_chipid(wilc, true) == 0); > } while (wilc_get_chipid(wilc, true) == 0); > > Actually, the above looks rather gross. wilc_get_chip() reads both WILC_CHIPID > and WILC_RF_REVISION_ID and we do this at least three times in a row on each > chip_wakeup(). Wow. Is this really necessary? I believe you are using the old driver code so please check with latest code. 'chip_wakeup()' was changed recently so I don't think 'wilc_get_chipid()' call is valid anymore inside this API. https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git/commit/drivers/net/wireless/microchip/wilc1000?h=v5.15&id=5bb9de8bcb18c38ea089a287b77944ef8ee71abd > In any case, for now, the below supresses the error messages: > > diff --git a/drivers/net/wireless/microchip/wilc1000/spi.c b/drivers/net/wireless/microchip/wilc1000/spi.c > index b778284247f7..516787aa4a23 100644 > --- a/drivers/net/wireless/microchip/wilc1000/spi.c > +++ b/drivers/net/wireless/microchip/wilc1000/spi.c > @@ -498,7 +498,7 @@ static int wilc_spi_single_read(struct wilc *wilc, u8 cmd, u32 adr, void *b, > r = (struct wilc_spi_rsp_data *)&rb[cmd_len]; > if (r->rsp_cmd_type != cmd) { > if (!spi_priv->probing_crc) > - dev_err(&spi->dev, > + dev_dbg(&spi->dev, > "Failed cmd, cmd (%02x), resp (%02x)\n", > cmd, r->rsp_cmd_type); > return -EINVAL; > @@ -754,7 +754,8 @@ static int wilc_spi_read_reg(struct wilc *wilc, u32 addr, u32 *data) > > result = wilc_spi_single_read(wilc, cmd, addr, data, clockless); > if (result) { > - dev_err(&spi->dev, "Failed cmd, read reg (%08x)...\n", addr); > + /* Register reads may fail legitimately, e.g., during chip_wakeup(). */ > + dev_dbg(&spi->dev, "Failed cmd, read reg (%08x)...\n", addr); > return result; > } > > > Maybe a parameter should be added to hif_read_reg() to indicate whether failure is an option? I have not observed the failure log specifically during 'chip_wakeup' but if you see them often then we can add the information in comments. Regards, Ajay
On 10/12/21 01:38, David Mosberger-Tang wrote: > EXTERNAL EMAIL: Do not click links or open attachments unless you know the content is safe > > I took linux-wireless off the CC list... > > On Thu, 2021-12-09 at 12:28 -0700, David Mosberger-Tang wrote: >> On Thu, 2021-12-09 at 12:12 -0700, David Mosberger-Tang wrote: >>> On Thu, 2021-12-09 at 11:15 -0700, David Mosberger-Tang wrote: >>> >>> As far as I can see, chip_wakeup() can trigger this legitimately: >>> >>> do { >>> h->hif_read_reg(wilc, WILC_SPI_WAKEUP_REG, ®); >>> h->hif_write_reg(wilc, WILC_SPI_WAKEUP_REG, >>> reg | WILC_SPI_WAKEUP_BIT); >>> h->hif_write_reg(wilc, WILC_SPI_WAKEUP_REG, >>> reg & ~WILC_SPI_WAKEUP_BIT); >>> >>> do { >>> usleep_range(2000, 2500); >>> wilc_get_chipid(wilc, true); >>> } while (wilc_get_chipid(wilc, true) == 0); >>> } while (wilc_get_chipid(wilc, true) == 0); >>> >>> Actually, the above looks rather gross. wilc_get_chip() reads both WILC_CHIPID >>> and WILC_RF_REVISION_ID and we do this at least three times in a row on each >>> chip_wakeup(). Wow. Is this really necessary? >> Looks like I'm on to something. If I replace the gross code with: >> >> h->hif_read_reg(wilc, WILC_SPI_WAKEUP_REG, ®); >> h->hif_write_reg(wilc, WILC_SPI_WAKEUP_REG, reg | WILC_SPI_WAKEUP_BIT); >> h->hif_write_reg(wilc, WILC_SPI_WAKEUP_REG, reg & ~WILC_SPI_WAKEUP_BIT); >> >> while (1) { >> if (wilc->hif_func->hif_read_reg(wilc, WILC_CHIPID, &chipid) == 0) >> break; >> usleep_range(2000, 2500); >> } >> >> Look what happens to TX throughput: >> >> [ 4] 0.00-120.00 sec 142 MBytes 9.92 Mbits/sec 6 sender >> >> This is with power_save mode turned on. Almost exactly 3 times faster than the >> 3.33 Mbits/sec I was seeing before. > Over 120 seconds of iperf3, a histogram of the number of WILC_CHIPID reads > required to get a successful read looked like this: > > [ 493.918785] hist[ 0]=70417 > [ 493.921609] hist[ 1]=0 > [ 493.923997] hist[ 2]=0 > [ 493.926424] hist[ 3]=0 > [ 493.928957] hist[ 4]=0 > [ 493.931359] hist[ 5]=0 > [ 493.933781] hist[ 6]=0 > [ 493.936210] hist[ 7]=0 > [ 493.938702] hist[ 8]=0 > [ 493.941097] hist[ 9]=0 > [ 493.943523] hist[ 10]=0 > [ 493.945951] hist[ 11]=0 > [ 493.948418] hist[ 12]=0 > [ 493.950812] hist[ 13]=0 > [ 493.953238] hist[ 14]=0 > [ 493.955667] hist[ 15]=0 > [ 493.958126] hist[ 16]=0 > [ 493.960527] hist[ 17]=0 > [ 493.962954] hist[ 18]=1 > [ 493.965382] hist[ 19]=7 > [ 493.967840] hist[ 20]=1 > [ 493.970242] hist[ 21]=13 > > Based on this, I changed the above code to: > > while (1) { > h->hif_read_reg(wilc, WILC_SPI_WAKEUP_REG, ®); > h->hif_write_reg(wilc, WILC_SPI_WAKEUP_REG, > reg | WILC_SPI_WAKEUP_BIT); > h->hif_write_reg(wilc, WILC_SPI_WAKEUP_REG, > reg & ~WILC_SPI_WAKEUP_BIT); > > if (wilc->hif_func->hif_read_reg(wilc, WILC_CHIPID, &chipid) == 0) > break; > usleep_range(2000, 2500); > } > > This gets me: > > TX/PSM off: [ 4] 0.00-120.00 sec 198 MBytes 13.8 Mbits/sec 9 sender > TX/PSM on : [ 4] 0.00-120.00 sec 140 MBytes 9.78 Mbits/sec 9 sender > RX/PSM off: [ 5] 0.00-120.10 sec 304 MBytes 21.2 Mbits/sec receiver > RX/PSM on : [ 5] 0.00-120.11 sec 288 MBytes 20.1 Mbits/sec receive > > Ajay, I'm guessing your kernel is either configured for tickless timer or > HZ=1000? That would explain why you'd see higher throughput with the original > code. My system is configured for HZ=100, so the usleep_range() would typically > take 10ms. I think the issue may not be related to the HZ configuration because the "usleep_range" API may have a delay of the same magnitude.Btw I too have CONFIG_HZ=100 configured for my setup. I overlooked that the throughput number for ttcp was in Bytes/sec whereas iPerf specified in (bits/sec) so it looks like the numbers are in same range. > > Any objections to the latest code? The above modification are not required because the API is already changed but it would be good to have the other patch which uses "power_save_mode" flag to avoid calling of chip-sleep code. Regards, Ajay
On Fri, 2021-12-10 at 09:05 +0000, Ajay.Kathat@microchip.com wrote: > On 10/12/21 00:42, David Mosberger-Tang wrote: > > EXTERNAL EMAIL: Do not click links or open attachments unless you know the content is safe > > > > On Thu, 2021-12-09 at 11:15 -0700, David Mosberger-Tang wrote: > > > > > > Did you test by enabling the power-save mode with "wpa_supplicant" or > > > > using "iw" command. For power consumption measurement, please try by > > > > disabling the PSM mode. > > > No, I have not played with power-saving mode. There are some disconcerting > > > messages when turning PSM on: > > > > > > [ 1764.070375] wilc1000_spi spi1.0: Failed cmd, cmd (ca), resp (00) > > > [ 1764.076403] wilc1000_spi spi1.0: Failed cmd, read reg (000013f4)... > > As far as I can see, chip_wakeup() can trigger this legitimately: > > > > do { > > h->hif_read_reg(wilc, WILC_SPI_WAKEUP_REG, ®); > > h->hif_write_reg(wilc, WILC_SPI_WAKEUP_REG, > > reg | WILC_SPI_WAKEUP_BIT); > > h->hif_write_reg(wilc, WILC_SPI_WAKEUP_REG, > > reg & ~WILC_SPI_WAKEUP_BIT); > > > > do { > > usleep_range(2000, 2500); > > wilc_get_chipid(wilc, true); > > } while (wilc_get_chipid(wilc, true) == 0); > > } while (wilc_get_chipid(wilc, true) == 0); > > > > Actually, the above looks rather gross. wilc_get_chip() reads both WILC_CHIPID > > and WILC_RF_REVISION_ID and we do this at least three times in a row on each > > chip_wakeup(). Wow. Is this really necessary? > > I believe you are using the old driver code so please check with latest > code. 'chip_wakeup()' was changed recently so I don't think > 'wilc_get_chipid()' call is valid anymore inside this API. > > > https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git/commit/drivers/net/wireless/microchip/wilc1000?h=v5.15&id=5bb9de8bcb18c38ea089a287b77944ef8ee71abd Indeed I was. I switched to 5.15 recently but thought I had backported all patches, but I was missing a handful. Yes, the new code is much better, thanks! > > In any case, for now, the below supresses the error messages: > > > > diff --git a/drivers/net/wireless/microchip/wilc1000/spi.c b/drivers/net/wireless/microchip/wilc1000/spi.c > > index b778284247f7..516787aa4a23 100644 > > --- a/drivers/net/wireless/microchip/wilc1000/spi.c > > +++ b/drivers/net/wireless/microchip/wilc1000/spi.c > > @@ -498,7 +498,7 @@ static int wilc_spi_single_read(struct wilc *wilc, u8 cmd, u32 adr, void *b, > > r = (struct wilc_spi_rsp_data *)&rb[cmd_len]; > > if (r->rsp_cmd_type != cmd) { > > if (!spi_priv->probing_crc) > > - dev_err(&spi->dev, > > + dev_dbg(&spi->dev, > > "Failed cmd, cmd (%02x), resp (%02x)\n", > > cmd, r->rsp_cmd_type); > > return -EINVAL; > > @@ -754,7 +754,8 @@ static int wilc_spi_read_reg(struct wilc *wilc, u32 addr, u32 *data) > > > > result = wilc_spi_single_read(wilc, cmd, addr, data, clockless); > > if (result) { > > - dev_err(&spi->dev, "Failed cmd, read reg (%08x)...\n", addr); > > + /* Register reads may fail legitimately, e.g., during chip_wakeup(). */ > > + dev_dbg(&spi->dev, "Failed cmd, read reg (%08x)...\n", addr); > > return result; > > } > > > > > > Maybe a parameter should be added to hif_read_reg() to indicate whether failure is an option? > > I have not observed the failure log specifically during 'chip_wakeup' > but if you see them often then we can add the information in comments. My tree was missing the clockless register fixes as well so perhaps that's what caused these. It seems to be good now. This is actually starting to look quite good! Here is the current iperf3 throughput I'm getting: PSM off: [ 4] 0.00-120.00 sec 137 MBytes 9.60 Mbits/sec 7 sender [ 5] 0.00-120.03 sec 281 MBytes 19.6 Mbits/sec receiver PSM on: [ 4] 0.00-120.01 sec 140 MBytes 9.82 Mbits/sec 9 sender [ 5] 0.00-120.69 sec 283 MBytes 19.6 Mbits/sec receiver I'll submit a patch to skip wakeup/allow_sleep if power-save mode is off. The only remaining issue I'm seeing is that if I turn on power-save mode right after starting wpa_supplicant, the driver thinks that PSM is on, but power consumption indicates that it is not actually on (using about 1.5W of power). When it's in this state, I have to manually use iw to turn PSM off and then on again to get actual power-savings (power dropping to about 1.1W). --david
diff --git a/drivers/net/wireless/microchip/wilc1000/wlan.c b/drivers/net/wireless/microchip/wilc1000/wlan.c index 757bd4471fd4..421672488100 100644 --- a/drivers/net/wireless/microchip/wilc1000/wlan.c +++ b/drivers/net/wireless/microchip/wilc1000/wlan.c @@ -10,6 +10,12 @@ #include "cfg80211.h" #include "wlan_cfg.h" +static bool enable_sleep; +module_param(enable_sleep, bool, 0644); +MODULE_PARM_DESC(enable_sleep, + "Enable chip sleep whenever the host is done communicating\n" + "\t\t\twith the WILC1000 chip."); + static inline bool is_wilc1000(u32 id) { return (id & (~WILC_CHIP_REV_FIELD)) == WILC_1000_BASE_ID; @@ -18,13 +24,13 @@ static inline bool is_wilc1000(u32 id) static inline void acquire_bus(struct wilc *wilc, enum bus_acquire acquire) { mutex_lock(&wilc->hif_cs); - if (acquire == WILC_BUS_ACQUIRE_AND_WAKEUP) + if (enable_sleep && acquire == WILC_BUS_ACQUIRE_AND_WAKEUP) chip_wakeup(wilc); } static inline void release_bus(struct wilc *wilc, enum bus_release release) { - if (release == WILC_BUS_RELEASE_ALLOW_SLEEP) + if (enable_sleep && release == WILC_BUS_RELEASE_ALLOW_SLEEP) chip_allow_sleep(wilc); mutex_unlock(&wilc->hif_cs); }