LinuxLists.cc - Regression: at24 eeprom writing times out on sama5d3

[permalink] [raw]

Subject: Re: Regression: at24 eeprom writing times out on sama5d3

On 09.06.2022 17:28, Peter Rosin wrote:
> Hi!

Hi Peter,

>
> I have not actually bisected this issue but reverting the effects of
> patch a4bd8da893a3 ("ARM: dts: at91: sama5d3: add i2c gpio pinctrl")
> makes the problem go away.
>
> I.e. I need something like this in my dts
>
> &i2c2 {
> status = "okay";
>
> pinctrl-names = "default";
> /delete-property/ pinctrl-1;
> /delete-property/ sda-gpios;
> /delete-property/ scl-gpios;
>
> eeprom@50 {
> compatible = "st,24c64", "atmel,24c64";
> reg = <0x50>;
> wp-gpios = <&filter_gpio 7 GPIO_ACTIVE_HIGH>;
> };
> };
>
> for multi-page eeprom writes to not time out (a page is 32 bytes on this
> eeprom).
>
> For reference, the current defaults for this SoC/I2C-bus, that I modify,
> are:
>
> pinctrl-names = "default", "gpio";
> pinctrl-0 = <&pinctrl_i2c2>;
> pinctrl-1 = <&pinctrl_i2c2_gpio>;
> sda-gpios = <&pioA 18 GPIO_ACTIVE_HIGH>;
> scl-gpios = <&pioA 19 (GPIO_ACTIVE_HIGH | GPIO_OPEN_DRAIN)>;
>
> I suspect that the underlying reason is that the bus recovery takes
> too long and that the at24 eeprom driver gives up prematurely. I doubt
> that this is chip specific, but I don't know that.
>
> I can work around the issue in user space with by writing in 4 byte
> chunks, like so
>
> dd if=source.file of=/sys/bus/i2c/devices/2-0050/eeprom obs=4
>
> but that is really ugly and gets slow too, about 20 seconds to program
> the full 8kB eeprom. With the above in my dts it takes a second or
> so (a bit more with dynamic debug active).
>
>
> If I run
>
> dd if=source.file of=/sys/bus/i2c/devices/2-0050/eeprom
>
> with a source.file of 8kB and the upstream dts properties in place, I can
> collect the following debug output from at24, i2c-core and i2c-at91:
>
> Jun 9 15:56:34 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: transfer complete
> Jun 9 15:56:34 me20 kernel: at24 2-0050: write 32@0 --> 0 (-23170)
> Jun 9 15:56:34 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: received nack
> Jun 9 15:56:34 me20 kernel: i2c i2c-2: Trying i2c bus recovery
> Jun 9 15:56:34 me20 kernel: at24 2-0050: write 32@32 --> -121 (-23169)
> Jun 9 15:56:34 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: transfer complete
> Jun 9 15:56:34 me20 kernel: at24 2-0050: write 32@32 --> 0 (-23168)
> Jun 9 15:56:34 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: received nack
> Jun 9 15:56:34 me20 kernel: i2c i2c-2: Trying i2c bus recovery
> Jun 9 15:56:34 me20 kernel: at24 2-0050: write 32@64 --> -121 (-23168)
> Jun 9 15:56:34 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: transfer complete
> Jun 9 15:56:34 me20 kernel: at24 2-0050: write 32@64 --> 0 (-23167)
> Jun 9 15:56:34 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: received nack
> Jun 9 15:56:34 me20 kernel: i2c i2c-2: Trying i2c bus recovery
> Jun 9 15:56:34 me20 kernel: at24 2-0050: write 32@96 --> -121 (-23167)
> Jun 9 15:56:34 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: controller timed out
> Jun 9 15:56:34 me20 kernel: i2c i2c-2: Trying i2c bus recovery
> Jun 9 15:56:34 me20 kernel: at24 2-0050: write 32@96 --> -110 (-23155)
> Jun 9 15:56:34 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: controller timed out
> Jun 9 15:56:34 me20 kernel: i2c i2c-2: Trying i2c bus recovery
> Jun 9 15:56:34 me20 kernel: at24 2-0050: write 32@96 --> -110 (-23143)
>
> And then there is no more action. I.e. only a couple of 32 byte pages
> are written.
>
> With the above mentioned dts override in place I instead get this, which is
> a lot more sensible:
>
> Jun 9 15:48:53 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer complete
> Jun 9 15:48:53 me20 kernel: at24 2-0050: write 32@0 --> 0 (753629)
> Jun 9 15:48:53 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: received nack
> Jun 9 15:48:53 me20 kernel: at24 2-0050: write 32@32 --> -121 (753629)
> Jun 9 15:48:53 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer complete
> Jun 9 15:48:53 me20 kernel: at24 2-0050: write 32@32 --> 0 (753630)
> Jun 9 15:48:53 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: received nack
> Jun 9 15:48:53 me20 kernel: at24 2-0050: write 32@64 --> -121 (753630)
> Jun 9 15:48:53 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer complete
> Jun 9 15:48:53 me20 kernel: at24 2-0050: write 32@64 --> 0 (753631)
> Jun 9 15:48:53 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: received nack
> Jun 9 15:48:53 me20 kernel: at24 2-0050: write 32@96 --> -121 (753631)
> Jun 9 15:48:53 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer complete
> Jun 9 15:48:53 me20 kernel: at24 2-0050: write 32@96 --> 0 (753632)
> Jun 9 15:48:53 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: received nack
> Jun 9 15:48:53 me20 kernel: at24 2-0050: write 32@128 --> -121 (753632)
> Jun 9 15:48:53 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer complete
> Jun 9 15:48:53 me20 kernel: at24 2-0050: write 32@128 --> 0 (753633)
> Jun 9 15:48:53 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: received nack
> Jun 9 15:48:53 me20 kernel: at24 2-0050: write 32@160 --> -121 (753633)
> Jun 9 15:48:53 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer complete
> Jun 9 15:48:53 me20 kernel: at24 2-0050: write 32@160 --> 0 (753634)
> ... snip ...
> Jun 9 15:48:55 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
> Jun 9 15:48:55 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
> Jun 9 15:48:55 me20 kernel: at91_i2c f801c000.i2c: received nack
> Jun 9 15:48:55 me20 kernel: at24 2-0050: write 32@8128 --> -121 (753883)
> Jun 9 15:48:55 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
> Jun 9 15:48:55 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
> Jun 9 15:48:55 me20 kernel: at91_i2c f801c000.i2c: transfer complete
> Jun 9 15:48:55 me20 kernel: at24 2-0050: write 32@8128 --> 0 (753884)
> Jun 9 15:48:55 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
> Jun 9 15:48:55 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
> Jun 9 15:48:55 me20 kernel: at91_i2c f801c000.i2c: received nack
> Jun 9 15:48:55 me20 kernel: at24 2-0050: write 32@8160 --> -121 (753884)
> Jun 9 15:48:55 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
> Jun 9 15:48:55 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
> Jun 9 15:48:55 me20 kernel: at91_i2c f801c000.i2c: transfer complete
> Jun 9 15:48:55 me20 kernel: at24 2-0050: write 32@8160 --> 0 (753885)

could you please apply this patch-set [1] and let us know if it
addresses your issue?

Thanks and best regards,
Codrin

https://patchwork.ozlabs.org/project/linux-i2c/list/?series=255408

2022-06-10 21:26:13

[permalink] [raw]

Subject: Re: Regression: at24 eeprom writing times out on sama5d3

Hi!

2022-06-10 at 09:35, [email protected] wrote:
> On 09.06.2022 17:28, Peter Rosin wrote:
>> Hi!
>
> Hi Peter,
>
>>
>> I have not actually bisected this issue but reverting the effects of
>> patch a4bd8da893a3 ("ARM: dts: at91: sama5d3: add i2c gpio pinctrl")
>> makes the problem go away.
>>
>> I.e. I need something like this in my dts
>>
>> &i2c2 {
>> status = "okay";
>>
>> pinctrl-names = "default";
>> /delete-property/ pinctrl-1;
>> /delete-property/ sda-gpios;
>> /delete-property/ scl-gpios;
>>
>> eeprom@50 {
>> compatible = "st,24c64", "atmel,24c64";
>> reg = <0x50>;
>> wp-gpios = <&filter_gpio 7 GPIO_ACTIVE_HIGH>;
>> };
>> };
>>
>> for multi-page eeprom writes to not time out (a page is 32 bytes on this
>> eeprom).
>>
>> For reference, the current defaults for this SoC/I2C-bus, that I modify,
>> are:
>>
>> pinctrl-names = "default", "gpio";
>> pinctrl-0 = <&pinctrl_i2c2>;
>> pinctrl-1 = <&pinctrl_i2c2_gpio>;
>> sda-gpios = <&pioA 18 GPIO_ACTIVE_HIGH>;
>> scl-gpios = <&pioA 19 (GPIO_ACTIVE_HIGH | GPIO_OPEN_DRAIN)>;
>>
>> I suspect that the underlying reason is that the bus recovery takes
>> too long and that the at24 eeprom driver gives up prematurely. I doubt
>> that this is chip specific, but I don't know that.
>>
>> I can work around the issue in user space with by writing in 4 byte
>> chunks, like so
>>
>> dd if=source.file of=/sys/bus/i2c/devices/2-0050/eeprom obs=4
>>
>> but that is really ugly and gets slow too, about 20 seconds to program
>> the full 8kB eeprom. With the above in my dts it takes a second or
>> so (a bit more with dynamic debug active).
>>
>>
>> If I run
>>
>> dd if=source.file of=/sys/bus/i2c/devices/2-0050/eeprom
>>
>> with a source.file of 8kB and the upstream dts properties in place, I can
>> collect the following debug output from at24, i2c-core and i2c-at91:
>>
>> Jun 9 15:56:34 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: transfer complete
>> Jun 9 15:56:34 me20 kernel: at24 2-0050: write 32@0 --> 0 (-23170)
>> Jun 9 15:56:34 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: received nack
>> Jun 9 15:56:34 me20 kernel: i2c i2c-2: Trying i2c bus recovery
>> Jun 9 15:56:34 me20 kernel: at24 2-0050: write 32@32 --> -121 (-23169)
>> Jun 9 15:56:34 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: transfer complete
>> Jun 9 15:56:34 me20 kernel: at24 2-0050: write 32@32 --> 0 (-23168)
>> Jun 9 15:56:34 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: received nack
>> Jun 9 15:56:34 me20 kernel: i2c i2c-2: Trying i2c bus recovery
>> Jun 9 15:56:34 me20 kernel: at24 2-0050: write 32@64 --> -121 (-23168)
>> Jun 9 15:56:34 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: transfer complete
>> Jun 9 15:56:34 me20 kernel: at24 2-0050: write 32@64 --> 0 (-23167)
>> Jun 9 15:56:34 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: received nack
>> Jun 9 15:56:34 me20 kernel: i2c i2c-2: Trying i2c bus recovery
>> Jun 9 15:56:34 me20 kernel: at24 2-0050: write 32@96 --> -121 (-23167)
>> Jun 9 15:56:34 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: controller timed out
>> Jun 9 15:56:34 me20 kernel: i2c i2c-2: Trying i2c bus recovery
>> Jun 9 15:56:34 me20 kernel: at24 2-0050: write 32@96 --> -110 (-23155)
>> Jun 9 15:56:34 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: controller timed out
>> Jun 9 15:56:34 me20 kernel: i2c i2c-2: Trying i2c bus recovery
>> Jun 9 15:56:34 me20 kernel: at24 2-0050: write 32@96 --> -110 (-23143)
>>
>> And then there is no more action. I.e. only a couple of 32 byte pages
>> are written.
>>
>> With the above mentioned dts override in place I instead get this, which is
>> a lot more sensible:
>>
>> Jun 9 15:48:53 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer complete
>> Jun 9 15:48:53 me20 kernel: at24 2-0050: write 32@0 --> 0 (753629)
>> Jun 9 15:48:53 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: received nack
>> Jun 9 15:48:53 me20 kernel: at24 2-0050: write 32@32 --> -121 (753629)
>> Jun 9 15:48:53 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer complete
>> Jun 9 15:48:53 me20 kernel: at24 2-0050: write 32@32 --> 0 (753630)
>> Jun 9 15:48:53 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: received nack
>> Jun 9 15:48:53 me20 kernel: at24 2-0050: write 32@64 --> -121 (753630)
>> Jun 9 15:48:53 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer complete
>> Jun 9 15:48:53 me20 kernel: at24 2-0050: write 32@64 --> 0 (753631)
>> Jun 9 15:48:53 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: received nack
>> Jun 9 15:48:53 me20 kernel: at24 2-0050: write 32@96 --> -121 (753631)
>> Jun 9 15:48:53 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer complete
>> Jun 9 15:48:53 me20 kernel: at24 2-0050: write 32@96 --> 0 (753632)
>> Jun 9 15:48:53 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: received nack
>> Jun 9 15:48:53 me20 kernel: at24 2-0050: write 32@128 --> -121 (753632)
>> Jun 9 15:48:53 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer complete
>> Jun 9 15:48:53 me20 kernel: at24 2-0050: write 32@128 --> 0 (753633)
>> Jun 9 15:48:53 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: received nack
>> Jun 9 15:48:53 me20 kernel: at24 2-0050: write 32@160 --> -121 (753633)
>> Jun 9 15:48:53 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer complete
>> Jun 9 15:48:53 me20 kernel: at24 2-0050: write 32@160 --> 0 (753634)
>> ... snip ...
>> Jun 9 15:48:55 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>> Jun 9 15:48:55 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>> Jun 9 15:48:55 me20 kernel: at91_i2c f801c000.i2c: received nack
>> Jun 9 15:48:55 me20 kernel: at24 2-0050: write 32@8128 --> -121 (753883)
>> Jun 9 15:48:55 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>> Jun 9 15:48:55 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>> Jun 9 15:48:55 me20 kernel: at91_i2c f801c000.i2c: transfer complete
>> Jun 9 15:48:55 me20 kernel: at24 2-0050: write 32@8128 --> 0 (753884)
>> Jun 9 15:48:55 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>> Jun 9 15:48:55 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>> Jun 9 15:48:55 me20 kernel: at91_i2c f801c000.i2c: received nack
>> Jun 9 15:48:55 me20 kernel: at24 2-0050: write 32@8160 --> -121 (753884)
>> Jun 9 15:48:55 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>> Jun 9 15:48:55 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>> Jun 9 15:48:55 me20 kernel: at91_i2c f801c000.i2c: transfer complete
>> Jun 9 15:48:55 me20 kernel: at24 2-0050: write 32@8160 --> 0 (753885)
>
> could you please apply this patch-set [1] and let us know if it
> addresses your issue?
>
> Thanks and best regards,
> Codrin
>
> https://patchwork.ozlabs.org/project/linux-i2c/list/?series=255408

That series does indeed help! I'll reply with a tested-by etc on the
first two patches, I can't test patch 3/3 with my sama5d3 board...

Thank you very much!

Cheers,
Peter

2022-06-11 14:14:16

[permalink] [raw]

Subject: Re: Regression: at24 eeprom writing times out on sama5d3

[TLDR: I'm adding this regression report to the list of tracked
regressions; all text from me you find below is based on a few templates
paragraphs you might have encountered already already in similar form.]

Hi, this is your Linux kernel regression tracker.

On 09.06.22 16:28, Peter Rosin wrote:
> Hi!
>
> I have not actually bisected this issue but reverting the effects of
> patch a4bd8da893a3 ("ARM: dts: at91: sama5d3: add i2c gpio pinctrl")
> makes the problem go away.

To be sure below issue doesn't fall through the cracks unnoticed, I'm
adding it to regzbot, my Linux kernel regression tracking bot:

#regzbot ^introduced a4bd8da893a3
#regzbot title i2c: at24 eeprom writing times out on sama5d3
#regzbot ignore-activity
#regzbot monitor:
https://lore.kernel.org/all/[email protected]/

This isn't a regression? This issue or a fix for it are already
discussed somewhere else? It was fixed already? You want to clarify when
the regression started to happen? Or point out I got the title or
something else totally wrong? Then just reply -- ideally with also
telling regzbot about it, as explained here:
https://linux-regtracking.leemhuis.info/tracked-regression/

Reminder for developers: When fixing the issue, add 'Link:' tags
pointing to the report (the mail this one replied to), as the kernel's
documentation call for; above page explains why this is important for
tracked regressions.

Ciao, Thorsten (wearing his 'the Linux kernel's regression tracker' hat)

P.S.: As the Linux kernel's regression tracker I deal with a lot of
reports and sometimes miss something important when writing mails like
this. If that's the case here, don't hesitate to tell me in a public
reply, it's in everyone's interest to set the public record straight.

> I.e. I need something like this in my dts
>
> &i2c2 {
> status = "okay";
>
> pinctrl-names = "default";
> /delete-property/ pinctrl-1;
> /delete-property/ sda-gpios;
> /delete-property/ scl-gpios;
>
> eeprom@50 {
> compatible = "st,24c64", "atmel,24c64";
> reg = <0x50>;
> wp-gpios = <&filter_gpio 7 GPIO_ACTIVE_HIGH>;
> };
> };
>
> for multi-page eeprom writes to not time out (a page is 32 bytes on this
> eeprom).
>
> For reference, the current defaults for this SoC/I2C-bus, that I modify,
> are:
>
> pinctrl-names = "default", "gpio";
> pinctrl-0 = <&pinctrl_i2c2>;
> pinctrl-1 = <&pinctrl_i2c2_gpio>;
> sda-gpios = <&pioA 18 GPIO_ACTIVE_HIGH>;
> scl-gpios = <&pioA 19 (GPIO_ACTIVE_HIGH | GPIO_OPEN_DRAIN)>;
>
> I suspect that the underlying reason is that the bus recovery takes
> too long and that the at24 eeprom driver gives up prematurely. I doubt
> that this is chip specific, but I don't know that.
>
> I can work around the issue in user space with by writing in 4 byte
> chunks, like so
>
> dd if=source.file of=/sys/bus/i2c/devices/2-0050/eeprom obs=4
>
> but that is really ugly and gets slow too, about 20 seconds to program
> the full 8kB eeprom. With the above in my dts it takes a second or
> so (a bit more with dynamic debug active).
>
>
> If I run
>
> dd if=source.file of=/sys/bus/i2c/devices/2-0050/eeprom
>
> with a source.file of 8kB and the upstream dts properties in place, I can
> collect the following debug output from at24, i2c-core and i2c-at91:
>
> Jun 9 15:56:34 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: transfer complete
> Jun 9 15:56:34 me20 kernel: at24 2-0050: write 32@0 --> 0 (-23170)
> Jun 9 15:56:34 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: received nack
> Jun 9 15:56:34 me20 kernel: i2c i2c-2: Trying i2c bus recovery
> Jun 9 15:56:34 me20 kernel: at24 2-0050: write 32@32 --> -121 (-23169)
> Jun 9 15:56:34 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: transfer complete
> Jun 9 15:56:34 me20 kernel: at24 2-0050: write 32@32 --> 0 (-23168)
> Jun 9 15:56:34 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: received nack
> Jun 9 15:56:34 me20 kernel: i2c i2c-2: Trying i2c bus recovery
> Jun 9 15:56:34 me20 kernel: at24 2-0050: write 32@64 --> -121 (-23168)
> Jun 9 15:56:34 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: transfer complete
> Jun 9 15:56:34 me20 kernel: at24 2-0050: write 32@64 --> 0 (-23167)
> Jun 9 15:56:34 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: received nack
> Jun 9 15:56:34 me20 kernel: i2c i2c-2: Trying i2c bus recovery
> Jun 9 15:56:34 me20 kernel: at24 2-0050: write 32@96 --> -121 (-23167)
> Jun 9 15:56:34 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: controller timed out
> Jun 9 15:56:34 me20 kernel: i2c i2c-2: Trying i2c bus recovery
> Jun 9 15:56:34 me20 kernel: at24 2-0050: write 32@96 --> -110 (-23155)
> Jun 9 15:56:34 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: controller timed out
> Jun 9 15:56:34 me20 kernel: i2c i2c-2: Trying i2c bus recovery
> Jun 9 15:56:34 me20 kernel: at24 2-0050: write 32@96 --> -110 (-23143)
>
> And then there is no more action. I.e. only a couple of 32 byte pages
> are written.
>
> With the above mentioned dts override in place I instead get this, which is
> a lot more sensible:
>
> Jun 9 15:48:53 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer complete
> Jun 9 15:48:53 me20 kernel: at24 2-0050: write 32@0 --> 0 (753629)
> Jun 9 15:48:53 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: received nack
> Jun 9 15:48:53 me20 kernel: at24 2-0050: write 32@32 --> -121 (753629)
> Jun 9 15:48:53 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer complete
> Jun 9 15:48:53 me20 kernel: at24 2-0050: write 32@32 --> 0 (753630)
> Jun 9 15:48:53 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: received nack
> Jun 9 15:48:53 me20 kernel: at24 2-0050: write 32@64 --> -121 (753630)
> Jun 9 15:48:53 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer complete
> Jun 9 15:48:53 me20 kernel: at24 2-0050: write 32@64 --> 0 (753631)
> Jun 9 15:48:53 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: received nack
> Jun 9 15:48:53 me20 kernel: at24 2-0050: write 32@96 --> -121 (753631)
> Jun 9 15:48:53 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer complete
> Jun 9 15:48:53 me20 kernel: at24 2-0050: write 32@96 --> 0 (753632)
> Jun 9 15:48:53 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: received nack
> Jun 9 15:48:53 me20 kernel: at24 2-0050: write 32@128 --> -121 (753632)
> Jun 9 15:48:53 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer complete
> Jun 9 15:48:53 me20 kernel: at24 2-0050: write 32@128 --> 0 (753633)
> Jun 9 15:48:53 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: received nack
> Jun 9 15:48:53 me20 kernel: at24 2-0050: write 32@160 --> -121 (753633)
> Jun 9 15:48:53 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer complete
> Jun 9 15:48:53 me20 kernel: at24 2-0050: write 32@160 --> 0 (753634)
> ... snip ...
> Jun 9 15:48:55 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
> Jun 9 15:48:55 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
> Jun 9 15:48:55 me20 kernel: at91_i2c f801c000.i2c: received nack
> Jun 9 15:48:55 me20 kernel: at24 2-0050: write 32@8128 --> -121 (753883)
> Jun 9 15:48:55 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
> Jun 9 15:48:55 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
> Jun 9 15:48:55 me20 kernel: at91_i2c f801c000.i2c: transfer complete
> Jun 9 15:48:55 me20 kernel: at24 2-0050: write 32@8128 --> 0 (753884)
> Jun 9 15:48:55 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
> Jun 9 15:48:55 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
> Jun 9 15:48:55 me20 kernel: at91_i2c f801c000.i2c: received nack
> Jun 9 15:48:55 me20 kernel: at24 2-0050: write 32@8160 --> -121 (753884)
> Jun 9 15:48:55 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
> Jun 9 15:48:55 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
> Jun 9 15:48:55 me20 kernel: at91_i2c f801c000.i2c: transfer complete
> Jun 9 15:48:55 me20 kernel: at24 2-0050: write 32@8160 --> 0 (753885)
>
> Cheers,
> Peter

2022-06-13 18:40:40

[permalink] [raw]

Subject: Re: Regression: at24 eeprom writing times out on sama5d3

Hi!

2022-06-13 at 16:58, Wolfram Sang wrote:
> Hi Codrin,
>
>> could you please apply this patch-set [1] and let us know if it
>> addresses your issue?
>
> Any comments to the comments I gave to [1]? :)

I replied to patch 1/3 and 2/3 but have not seen them on the lists and
patchwork also appears to be in the dark.
Did the replies make it anywhere? Should I resend?

Cheers,
Peter

2022-06-13 18:56:49

by Wolfram Sang

[permalink] [raw]

Subject: Re: Regression: at24 eeprom writing times out on sama5d3

Hi Codrin,

> could you please apply this patch-set [1] and let us know if it
> addresses your issue?

Any comments to the comments I gave to [1]? :)

Happy hacking,

Wolfram

Attachments:

(No filename) (191.00 B)
signature.asc (849.00 B)
Download all attachments

2022-06-13 21:15:11

by Wolfram Sang

[permalink] [raw]

Subject: Re: Regression: at24 eeprom writing times out on sama5d3

> I replied to patch 1/3 and 2/3 but have not seen them on the lists and
> patchwork also appears to be in the dark.
> Did the replies make it anywhere? Should I resend?

I didn't get them. Yeah, maybe a resend will help?

Attachments:

(No filename) (231.00 B)
signature.asc (849.00 B)
Download all attachments

2022-06-14 08:38:40

[permalink] [raw]

Subject: Re: Regression: at24 eeprom writing times out on sama5d3

On 13.06.2022 18:43, Peter Rosin wrote:
> EXTERNAL EMAIL: Do not click links or open attachments unless you know the content is safe
>
> Hi!
>
> 2022-06-13 at 16:58, Wolfram Sang wrote:
>> Hi Codrin,
>>
>>> could you please apply this patch-set [1] and let us know if it
>>> addresses your issue?
>>
>> Any comments to the comments I gave to [1]? :)

I replied two times, but it looks like my e-mails also don't reach the
list.

>
> I replied to patch 1/3 and 2/3 but have not seen them on the lists and
> patchwork also appears to be in the dark.
> Did the replies make it anywhere? Should I resend?

Same in my case. I though it has something to do with my setup or
Microchip's IT, but it looks like it's not the case.

I can resend the patches. Hopefully it will help.

Best regards,
Codrin

2022-06-14 14:13:46

[permalink] [raw]

Subject: Re: Regression: at24 eeprom writing times out on sama5d3

On 14.06.2022 11:25, Codrin Ciubotariu wrote:
> On 13.06.2022 18:43, Peter Rosin wrote:
>> EXTERNAL EMAIL: Do not click links or open attachments unless you know
>> the content is safe
>>
>> Hi!
>>
>> 2022-06-13 at 16:58, Wolfram Sang wrote:
>>> Hi Codrin,
>>>
>>>> could you please apply this patch-set [1] and let us know if it
>>>> addresses your issue?
>>>
>>> Any comments to the comments I gave to [1]? :)
>
> I replied two times, but it looks like my e-mails also don't reach the
> list.
>
>>
>> I replied to patch 1/3 and 2/3 but have not seen them on the lists and
>> patchwork also appears to be in the dark.
>> Did the replies make it anywhere? Should I resend?
>
> Same in my case. I though it has something to do with my setup or
> Microchip's IT, but it looks like it's not the case.
>
> I can resend the patches. Hopefully it will help.

I resent the patch-set, replied and the replies still don't appear.

Best regards,
Codrin

2022-06-14 14:28:04

by Conor Dooley

[permalink] [raw]

Subject: Re: Regression: at24 eeprom writing times out on sama5d3

On 14/06/2022 14:53, [email protected] wrote:
> On 14.06.2022 11:25, Codrin Ciubotariu wrote:
>> On 13.06.2022 18:43, Peter Rosin wrote:
>>> EXTERNAL EMAIL: Do not click links or open attachments unless you know
>>> the content is safe
>>>
>>> Hi!
>>>
>>> 2022-06-13 at 16:58, Wolfram Sang wrote:
>>>> Hi Codrin,
>>>>
>>>>> could you please apply this patch-set [1] and let us know if it
>>>>> addresses your issue?
>>>>
>>>> Any comments to the comments I gave to [1]? :)
>>
>> I replied two times, but it looks like my e-mails also don't reach the
>> list.
>>
>>>
>>> I replied to patch 1/3 and 2/3 but have not seen them on the lists and
>>> patchwork also appears to be in the dark.
>>> Did the replies make it anywhere? Should I resend?
>>
>> Same in my case. I though it has something to do with my setup or
>> Microchip's IT, but it looks like it's not the case.
>>
>> I can resend the patches. Hopefully it will help.
>
> I resent the patch-set, replied and the replies still don't appear.

This one (and the other one mentioning IT) went through for me.
Anything you're doing differently?

I guess you can also always fall back to using send-email w/
the command from the lore page if for w/e reason using tbird
is failing for you?

Thanks,
Conor.

2022-06-15 09:04:54

[permalink] [raw]

Subject: Re: Regression: at24 eeprom writing times out on sama5d3

On 14.06.2022 17:25, Conor Dooley - M52691 wrote:
> On 14/06/2022 14:53, [email protected] wrote:
>> On 14.06.2022 11:25, Codrin Ciubotariu wrote:
>>> On 13.06.2022 18:43, Peter Rosin wrote:
>>>> EXTERNAL EMAIL: Do not click links or open attachments unless you know
>>>> the content is safe
>>>>
>>>> Hi!
>>>>
>>>> 2022-06-13 at 16:58, Wolfram Sang wrote:
>>>>> Hi Codrin,
>>>>>
>>>>>> could you please apply this patch-set [1] and let us know if it
>>>>>> addresses your issue?
>>>>>
>>>>> Any comments to the comments I gave to [1]? :)
>>>
>>> I replied two times, but it looks like my e-mails also don't reach the
>>> list.
>>>
>>>>
>>>> I replied to patch 1/3 and 2/3 but have not seen them on the lists and
>>>> patchwork also appears to be in the dark.
>>>> Did the replies make it anywhere? Should I resend?
>>>
>>> Same in my case. I though it has something to do with my setup or
>>> Microchip's IT, but it looks like it's not the case.
>>>
>>> I can resend the patches. Hopefully it will help.
>>
>> I resent the patch-set, replied and the replies still don't appear.
>
> This one (and the other one mentioning IT) went through for me.
> Anything you're doing differently?
>
> I guess you can also always fall back to using send-email w/
> the command from the lore page if for w/e reason using tbird
> is failing for you?

These replies worked fine, but the replies to the patches didn't.

Best regards,
Codrin

2022-06-30 08:08:12

[permalink] [raw]

Subject: Re: Regression: at24 eeprom writing times out on sama5d3

Hi again.

2022-06-10 at 22:51, Peter Rosin wrote:
> Hi!
>
> 2022-06-10 at 09:35, [email protected] wrote:
>> On 09.06.2022 17:28, Peter Rosin wrote:
>>> Hi!
>>
>> Hi Peter,
>>
>>>
>>> I have not actually bisected this issue but reverting the effects of
>>> patch a4bd8da893a3 ("ARM: dts: at91: sama5d3: add i2c gpio pinctrl")
>>> makes the problem go away.
>>>
>>> I.e. I need something like this in my dts
>>>
>>> &i2c2 {
>>> status = "okay";
>>>
>>> pinctrl-names = "default";
>>> /delete-property/ pinctrl-1;
>>> /delete-property/ sda-gpios;
>>> /delete-property/ scl-gpios;
>>>
>>> eeprom@50 {
>>> compatible = "st,24c64", "atmel,24c64";
>>> reg = <0x50>;
>>> wp-gpios = <&filter_gpio 7 GPIO_ACTIVE_HIGH>;
>>> };
>>> };
>>>
>>> for multi-page eeprom writes to not time out (a page is 32 bytes on this
>>> eeprom).
>>>
>>> For reference, the current defaults for this SoC/I2C-bus, that I modify,
>>> are:
>>>
>>> pinctrl-names = "default", "gpio";
>>> pinctrl-0 = <&pinctrl_i2c2>;
>>> pinctrl-1 = <&pinctrl_i2c2_gpio>;
>>> sda-gpios = <&pioA 18 GPIO_ACTIVE_HIGH>;
>>> scl-gpios = <&pioA 19 (GPIO_ACTIVE_HIGH | GPIO_OPEN_DRAIN)>;
>>>
>>> I suspect that the underlying reason is that the bus recovery takes
>>> too long and that the at24 eeprom driver gives up prematurely. I doubt
>>> that this is chip specific, but I don't know that.
>>>
>>> I can work around the issue in user space with by writing in 4 byte
>>> chunks, like so
>>>
>>> dd if=source.file of=/sys/bus/i2c/devices/2-0050/eeprom obs=4
>>>
>>> but that is really ugly and gets slow too, about 20 seconds to program
>>> the full 8kB eeprom. With the above in my dts it takes a second or
>>> so (a bit more with dynamic debug active).
>>>
>>>
>>> If I run
>>>
>>> dd if=source.file of=/sys/bus/i2c/devices/2-0050/eeprom
>>>
>>> with a source.file of 8kB and the upstream dts properties in place, I can
>>> collect the following debug output from at24, i2c-core and i2c-at91:
>>>
>>> Jun 9 15:56:34 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: transfer complete
>>> Jun 9 15:56:34 me20 kernel: at24 2-0050: write 32@0 --> 0 (-23170)
>>> Jun 9 15:56:34 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: received nack
>>> Jun 9 15:56:34 me20 kernel: i2c i2c-2: Trying i2c bus recovery
>>> Jun 9 15:56:34 me20 kernel: at24 2-0050: write 32@32 --> -121 (-23169)
>>> Jun 9 15:56:34 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: transfer complete
>>> Jun 9 15:56:34 me20 kernel: at24 2-0050: write 32@32 --> 0 (-23168)
>>> Jun 9 15:56:34 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: received nack
>>> Jun 9 15:56:34 me20 kernel: i2c i2c-2: Trying i2c bus recovery
>>> Jun 9 15:56:34 me20 kernel: at24 2-0050: write 32@64 --> -121 (-23168)
>>> Jun 9 15:56:34 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: transfer complete
>>> Jun 9 15:56:34 me20 kernel: at24 2-0050: write 32@64 --> 0 (-23167)
>>> Jun 9 15:56:34 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: received nack
>>> Jun 9 15:56:34 me20 kernel: i2c i2c-2: Trying i2c bus recovery
>>> Jun 9 15:56:34 me20 kernel: at24 2-0050: write 32@96 --> -121 (-23167)
>>> Jun 9 15:56:34 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: controller timed out
>>> Jun 9 15:56:34 me20 kernel: i2c i2c-2: Trying i2c bus recovery
>>> Jun 9 15:56:34 me20 kernel: at24 2-0050: write 32@96 --> -110 (-23155)
>>> Jun 9 15:56:34 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: controller timed out
>>> Jun 9 15:56:34 me20 kernel: i2c i2c-2: Trying i2c bus recovery
>>> Jun 9 15:56:34 me20 kernel: at24 2-0050: write 32@96 --> -110 (-23143)
>>>
>>> And then there is no more action. I.e. only a couple of 32 byte pages
>>> are written.
>>>
>>> With the above mentioned dts override in place I instead get this, which is
>>> a lot more sensible:
>>>
>>> Jun 9 15:48:53 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer complete
>>> Jun 9 15:48:53 me20 kernel: at24 2-0050: write 32@0 --> 0 (753629)
>>> Jun 9 15:48:53 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: received nack
>>> Jun 9 15:48:53 me20 kernel: at24 2-0050: write 32@32 --> -121 (753629)
>>> Jun 9 15:48:53 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer complete
>>> Jun 9 15:48:53 me20 kernel: at24 2-0050: write 32@32 --> 0 (753630)
>>> Jun 9 15:48:53 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: received nack
>>> Jun 9 15:48:53 me20 kernel: at24 2-0050: write 32@64 --> -121 (753630)
>>> Jun 9 15:48:53 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer complete
>>> Jun 9 15:48:53 me20 kernel: at24 2-0050: write 32@64 --> 0 (753631)
>>> Jun 9 15:48:53 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: received nack
>>> Jun 9 15:48:53 me20 kernel: at24 2-0050: write 32@96 --> -121 (753631)
>>> Jun 9 15:48:53 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer complete
>>> Jun 9 15:48:53 me20 kernel: at24 2-0050: write 32@96 --> 0 (753632)
>>> Jun 9 15:48:53 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: received nack
>>> Jun 9 15:48:53 me20 kernel: at24 2-0050: write 32@128 --> -121 (753632)
>>> Jun 9 15:48:53 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer complete
>>> Jun 9 15:48:53 me20 kernel: at24 2-0050: write 32@128 --> 0 (753633)
>>> Jun 9 15:48:53 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: received nack
>>> Jun 9 15:48:53 me20 kernel: at24 2-0050: write 32@160 --> -121 (753633)
>>> Jun 9 15:48:53 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer complete
>>> Jun 9 15:48:53 me20 kernel: at24 2-0050: write 32@160 --> 0 (753634)
>>> ... snip ...
>>> Jun 9 15:48:55 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>> Jun 9 15:48:55 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>> Jun 9 15:48:55 me20 kernel: at91_i2c f801c000.i2c: received nack
>>> Jun 9 15:48:55 me20 kernel: at24 2-0050: write 32@8128 --> -121 (753883)
>>> Jun 9 15:48:55 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>> Jun 9 15:48:55 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>> Jun 9 15:48:55 me20 kernel: at91_i2c f801c000.i2c: transfer complete
>>> Jun 9 15:48:55 me20 kernel: at24 2-0050: write 32@8128 --> 0 (753884)
>>> Jun 9 15:48:55 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>> Jun 9 15:48:55 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>> Jun 9 15:48:55 me20 kernel: at91_i2c f801c000.i2c: received nack
>>> Jun 9 15:48:55 me20 kernel: at24 2-0050: write 32@8160 --> -121 (753884)
>>> Jun 9 15:48:55 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>> Jun 9 15:48:55 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>> Jun 9 15:48:55 me20 kernel: at91_i2c f801c000.i2c: transfer complete
>>> Jun 9 15:48:55 me20 kernel: at24 2-0050: write 32@8160 --> 0 (753885)
>>
>> could you please apply this patch-set [1] and let us know if it
>> addresses your issue?
>>
>> Thanks and best regards,
>> Codrin
>>
>> https://patchwork.ozlabs.org/project/linux-i2c/list/?series=255408
>
> That series does indeed help! I'll reply with a tested-by etc on the
> first two patches, I can't test patch 3/3 with my sama5d3 board...
>
> Thank you very much!

Since replying to the actual patches do not work for me, I'm writing here
instead. Sorry about that. As stated above, it /seems/ to work much better
with these patches. But I fooled myself and there is still some remaining
trouble. It is not uncommon that the second (32-byte) page in the eeprom
is not written correctly for whatever reason. I do not know why it's
always the second page that gets corrupted, but this is a bad problem since
the failure is completely silent.

Cheers,
Peter

2022-09-08 12:31:38

[permalink] [raw]

Subject: Re: Regression: at24 eeprom writing times out on sama5d3

Hi, this is your Linux kernel regression tracker. Top-posting for once,
to make this easily accessible to everyone.

Peter, Codrin, could you help me out here please: I still have the
regression report from Peter that started this thread in the list of
tracked issues. From Peter's last msg quoted below it seems the thread
just faded out without the regression being fixed. Or was it? If not:
what can we do to finally get this resolved?

Ciao, Thorsten (wearing his 'the Linux kernel's regression tracker' hat)

P.S.: As the Linux kernel's regression tracker I deal with a lot of
reports and sometimes miss something important when writing mails like
this. If that's the case here, don't hesitate to tell me in a public
reply, it's in everyone's interest to set the public record straight.

On 30.06.22 09:44, Peter Rosin wrote:
> 2022-06-10 at 22:51, Peter Rosin wrote:
>> 2022-06-10 at 09:35, [email protected] wrote:
>>> On 09.06.2022 17:28, Peter Rosin wrote:
>>>>
>>>> I have not actually bisected this issue but reverting the effects of
>>>> patch a4bd8da893a3 ("ARM: dts: at91: sama5d3: add i2c gpio pinctrl")
>>>> makes the problem go away.
>>>>
>>>> I.e. I need something like this in my dts
>>>>
>>>> &i2c2 {
>>>> status = "okay";
>>>>
>>>> pinctrl-names = "default";
>>>> /delete-property/ pinctrl-1;
>>>> /delete-property/ sda-gpios;
>>>> /delete-property/ scl-gpios;
>>>>
>>>> eeprom@50 {
>>>> compatible = "st,24c64", "atmel,24c64";
>>>> reg = <0x50>;
>>>> wp-gpios = <&filter_gpio 7 GPIO_ACTIVE_HIGH>;
>>>> };
>>>> };
>>>>
>>>> for multi-page eeprom writes to not time out (a page is 32 bytes on this
>>>> eeprom).
>>>>
>>>> For reference, the current defaults for this SoC/I2C-bus, that I modify,
>>>> are:
>>>>
>>>> pinctrl-names = "default", "gpio";
>>>> pinctrl-0 = <&pinctrl_i2c2>;
>>>> pinctrl-1 = <&pinctrl_i2c2_gpio>;
>>>> sda-gpios = <&pioA 18 GPIO_ACTIVE_HIGH>;
>>>> scl-gpios = <&pioA 19 (GPIO_ACTIVE_HIGH | GPIO_OPEN_DRAIN)>;
>>>>
>>>> I suspect that the underlying reason is that the bus recovery takes
>>>> too long and that the at24 eeprom driver gives up prematurely. I doubt
>>>> that this is chip specific, but I don't know that.
>>>>
>>>> I can work around the issue in user space with by writing in 4 byte
>>>> chunks, like so
>>>>
>>>> dd if=source.file of=/sys/bus/i2c/devices/2-0050/eeprom obs=4
>>>>
>>>> but that is really ugly and gets slow too, about 20 seconds to program
>>>> the full 8kB eeprom. With the above in my dts it takes a second or
>>>> so (a bit more with dynamic debug active).
>>>>
>>>>
>>>> If I run
>>>>
>>>> dd if=source.file of=/sys/bus/i2c/devices/2-0050/eeprom
>>>>
>>>> with a source.file of 8kB and the upstream dts properties in place, I can
>>>> collect the following debug output from at24, i2c-core and i2c-at91:
>>>>
>>>> Jun 9 15:56:34 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: transfer complete
>>>> Jun 9 15:56:34 me20 kernel: at24 2-0050: write 32@0 --> 0 (-23170)
>>>> Jun 9 15:56:34 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: received nack
>>>> Jun 9 15:56:34 me20 kernel: i2c i2c-2: Trying i2c bus recovery
>>>> Jun 9 15:56:34 me20 kernel: at24 2-0050: write 32@32 --> -121 (-23169)
>>>> Jun 9 15:56:34 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: transfer complete
>>>> Jun 9 15:56:34 me20 kernel: at24 2-0050: write 32@32 --> 0 (-23168)
>>>> Jun 9 15:56:34 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: received nack
>>>> Jun 9 15:56:34 me20 kernel: i2c i2c-2: Trying i2c bus recovery
>>>> Jun 9 15:56:34 me20 kernel: at24 2-0050: write 32@64 --> -121 (-23168)
>>>> Jun 9 15:56:34 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: transfer complete
>>>> Jun 9 15:56:34 me20 kernel: at24 2-0050: write 32@64 --> 0 (-23167)
>>>> Jun 9 15:56:34 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: received nack
>>>> Jun 9 15:56:34 me20 kernel: i2c i2c-2: Trying i2c bus recovery
>>>> Jun 9 15:56:34 me20 kernel: at24 2-0050: write 32@96 --> -121 (-23167)
>>>> Jun 9 15:56:34 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: controller timed out
>>>> Jun 9 15:56:34 me20 kernel: i2c i2c-2: Trying i2c bus recovery
>>>> Jun 9 15:56:34 me20 kernel: at24 2-0050: write 32@96 --> -110 (-23155)
>>>> Jun 9 15:56:34 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: controller timed out
>>>> Jun 9 15:56:34 me20 kernel: i2c i2c-2: Trying i2c bus recovery
>>>> Jun 9 15:56:34 me20 kernel: at24 2-0050: write 32@96 --> -110 (-23143)
>>>>
>>>> And then there is no more action. I.e. only a couple of 32 byte pages
>>>> are written.
>>>>
>>>> With the above mentioned dts override in place I instead get this, which is
>>>> a lot more sensible:
>>>>
>>>> Jun 9 15:48:53 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer complete
>>>> Jun 9 15:48:53 me20 kernel: at24 2-0050: write 32@0 --> 0 (753629)
>>>> Jun 9 15:48:53 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: received nack
>>>> Jun 9 15:48:53 me20 kernel: at24 2-0050: write 32@32 --> -121 (753629)
>>>> Jun 9 15:48:53 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer complete
>>>> Jun 9 15:48:53 me20 kernel: at24 2-0050: write 32@32 --> 0 (753630)
>>>> Jun 9 15:48:53 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: received nack
>>>> Jun 9 15:48:53 me20 kernel: at24 2-0050: write 32@64 --> -121 (753630)
>>>> Jun 9 15:48:53 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer complete
>>>> Jun 9 15:48:53 me20 kernel: at24 2-0050: write 32@64 --> 0 (753631)
>>>> Jun 9 15:48:53 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: received nack
>>>> Jun 9 15:48:53 me20 kernel: at24 2-0050: write 32@96 --> -121 (753631)
>>>> Jun 9 15:48:53 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer complete
>>>> Jun 9 15:48:53 me20 kernel: at24 2-0050: write 32@96 --> 0 (753632)
>>>> Jun 9 15:48:53 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: received nack
>>>> Jun 9 15:48:53 me20 kernel: at24 2-0050: write 32@128 --> -121 (753632)
>>>> Jun 9 15:48:53 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer complete
>>>> Jun 9 15:48:53 me20 kernel: at24 2-0050: write 32@128 --> 0 (753633)
>>>> Jun 9 15:48:53 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: received nack
>>>> Jun 9 15:48:53 me20 kernel: at24 2-0050: write 32@160 --> -121 (753633)
>>>> Jun 9 15:48:53 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer complete
>>>> Jun 9 15:48:53 me20 kernel: at24 2-0050: write 32@160 --> 0 (753634)
>>>> ... snip ...
>>>> Jun 9 15:48:55 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>> Jun 9 15:48:55 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>> Jun 9 15:48:55 me20 kernel: at91_i2c f801c000.i2c: received nack
>>>> Jun 9 15:48:55 me20 kernel: at24 2-0050: write 32@8128 --> -121 (753883)
>>>> Jun 9 15:48:55 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>> Jun 9 15:48:55 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>> Jun 9 15:48:55 me20 kernel: at91_i2c f801c000.i2c: transfer complete
>>>> Jun 9 15:48:55 me20 kernel: at24 2-0050: write 32@8128 --> 0 (753884)
>>>> Jun 9 15:48:55 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>> Jun 9 15:48:55 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>> Jun 9 15:48:55 me20 kernel: at91_i2c f801c000.i2c: received nack
>>>> Jun 9 15:48:55 me20 kernel: at24 2-0050: write 32@8160 --> -121 (753884)
>>>> Jun 9 15:48:55 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>> Jun 9 15:48:55 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>> Jun 9 15:48:55 me20 kernel: at91_i2c f801c000.i2c: transfer complete
>>>> Jun 9 15:48:55 me20 kernel: at24 2-0050: write 32@8160 --> 0 (753885)
>>>
>>> could you please apply this patch-set [1] and let us know if it
>>> addresses your issue?
>>>
>>> Thanks and best regards,
>>> Codrin
>>>
>>> https://patchwork.ozlabs.org/project/linux-i2c/list/?series=255408
>>
>> That series does indeed help! I'll reply with a tested-by etc on the
>> first two patches, I can't test patch 3/3 with my sama5d3 board...
>>
>> Thank you very much!
>
> Since replying to the actual patches do not work for me, I'm writing here
> instead. Sorry about that. As stated above, it /seems/ to work much better
> with these patches. But I fooled myself and there is still some remaining
> trouble. It is not uncommon that the second (32-byte) page in the eeprom
> is not written correctly for whatever reason. I do not know why it's
> always the second page that gets corrupted, but this is a bad problem since
> the failure is completely silent.
>
> Cheers,
> Peter

#regzbot poke

2022-09-08 14:14:21

[permalink] [raw]

Subject: Re: Regression: at24 eeprom writing times out on sama5d3

Hi!

2022-09-08 at 14:06, Thorsten Leemhuis wrote:
> Hi, this is your Linux kernel regression tracker. Top-posting for once,
> to make this easily accessible to everyone.
>
> Peter, Codrin, could you help me out here please: I still have the
> regression report from Peter that started this thread in the list of
> tracked issues. From Peter's last msg quoted below it seems the thread
> just faded out without the regression being fixed. Or was it? If not:
> what can we do to finally get this resolved?

No, it is not resolved that I know of. We are only writing during
production, but are working around it by verifying and looping back.
Sometimes it takes surprisingly long for the loop to finish, but
it's not a huge deal. But it is of course not completely satisfying
either...

Reading is never a problem, so post-production behavior is sane.

Cheers,
Peter

> Ciao, Thorsten (wearing his 'the Linux kernel's regression tracker' hat)
>
> P.S.: As the Linux kernel's regression tracker I deal with a lot of
> reports and sometimes miss something important when writing mails like
> this. If that's the case here, don't hesitate to tell me in a public
> reply, it's in everyone's interest to set the public record straight.
>
> On 30.06.22 09:44, Peter Rosin wrote:
>> 2022-06-10 at 22:51, Peter Rosin wrote:
>>> 2022-06-10 at 09:35, [email protected] wrote:
>>>> On 09.06.2022 17:28, Peter Rosin wrote:
>>>>>
>>>>> I have not actually bisected this issue but reverting the effects of
>>>>> patch a4bd8da893a3 ("ARM: dts: at91: sama5d3: add i2c gpio pinctrl")
>>>>> makes the problem go away.
>>>>>
>>>>> I.e. I need something like this in my dts
>>>>>
>>>>> &i2c2 {
>>>>> status = "okay";
>>>>>
>>>>> pinctrl-names = "default";
>>>>> /delete-property/ pinctrl-1;
>>>>> /delete-property/ sda-gpios;
>>>>> /delete-property/ scl-gpios;
>>>>>
>>>>> eeprom@50 {
>>>>> compatible = "st,24c64", "atmel,24c64";
>>>>> reg = <0x50>;
>>>>> wp-gpios = <&filter_gpio 7 GPIO_ACTIVE_HIGH>;
>>>>> };
>>>>> };
>>>>>
>>>>> for multi-page eeprom writes to not time out (a page is 32 bytes on this
>>>>> eeprom).
>>>>>
>>>>> For reference, the current defaults for this SoC/I2C-bus, that I modify,
>>>>> are:
>>>>>
>>>>> pinctrl-names = "default", "gpio";
>>>>> pinctrl-0 = <&pinctrl_i2c2>;
>>>>> pinctrl-1 = <&pinctrl_i2c2_gpio>;
>>>>> sda-gpios = <&pioA 18 GPIO_ACTIVE_HIGH>;
>>>>> scl-gpios = <&pioA 19 (GPIO_ACTIVE_HIGH | GPIO_OPEN_DRAIN)>;
>>>>>
>>>>> I suspect that the underlying reason is that the bus recovery takes
>>>>> too long and that the at24 eeprom driver gives up prematurely. I doubt
>>>>> that this is chip specific, but I don't know that.
>>>>>
>>>>> I can work around the issue in user space with by writing in 4 byte
>>>>> chunks, like so
>>>>>
>>>>> dd if=source.file of=/sys/bus/i2c/devices/2-0050/eeprom obs=4
>>>>>
>>>>> but that is really ugly and gets slow too, about 20 seconds to program
>>>>> the full 8kB eeprom. With the above in my dts it takes a second or
>>>>> so (a bit more with dynamic debug active).
>>>>>
>>>>>
>>>>> If I run
>>>>>
>>>>> dd if=source.file of=/sys/bus/i2c/devices/2-0050/eeprom
>>>>>
>>>>> with a source.file of 8kB and the upstream dts properties in place, I can
>>>>> collect the following debug output from at24, i2c-core and i2c-at91:
>>>>>
>>>>> Jun 9 15:56:34 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: transfer complete
>>>>> Jun 9 15:56:34 me20 kernel: at24 2-0050: write 32@0 --> 0 (-23170)
>>>>> Jun 9 15:56:34 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: received nack
>>>>> Jun 9 15:56:34 me20 kernel: i2c i2c-2: Trying i2c bus recovery
>>>>> Jun 9 15:56:34 me20 kernel: at24 2-0050: write 32@32 --> -121 (-23169)
>>>>> Jun 9 15:56:34 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: transfer complete
>>>>> Jun 9 15:56:34 me20 kernel: at24 2-0050: write 32@32 --> 0 (-23168)
>>>>> Jun 9 15:56:34 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: received nack
>>>>> Jun 9 15:56:34 me20 kernel: i2c i2c-2: Trying i2c bus recovery
>>>>> Jun 9 15:56:34 me20 kernel: at24 2-0050: write 32@64 --> -121 (-23168)
>>>>> Jun 9 15:56:34 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: transfer complete
>>>>> Jun 9 15:56:34 me20 kernel: at24 2-0050: write 32@64 --> 0 (-23167)
>>>>> Jun 9 15:56:34 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: received nack
>>>>> Jun 9 15:56:34 me20 kernel: i2c i2c-2: Trying i2c bus recovery
>>>>> Jun 9 15:56:34 me20 kernel: at24 2-0050: write 32@96 --> -121 (-23167)
>>>>> Jun 9 15:56:34 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: controller timed out
>>>>> Jun 9 15:56:34 me20 kernel: i2c i2c-2: Trying i2c bus recovery
>>>>> Jun 9 15:56:34 me20 kernel: at24 2-0050: write 32@96 --> -110 (-23155)
>>>>> Jun 9 15:56:34 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: controller timed out
>>>>> Jun 9 15:56:34 me20 kernel: i2c i2c-2: Trying i2c bus recovery
>>>>> Jun 9 15:56:34 me20 kernel: at24 2-0050: write 32@96 --> -110 (-23143)
>>>>>
>>>>> And then there is no more action. I.e. only a couple of 32 byte pages
>>>>> are written.
>>>>>
>>>>> With the above mentioned dts override in place I instead get this, which is
>>>>> a lot more sensible:
>>>>>
>>>>> Jun 9 15:48:53 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer complete
>>>>> Jun 9 15:48:53 me20 kernel: at24 2-0050: write 32@0 --> 0 (753629)
>>>>> Jun 9 15:48:53 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: received nack
>>>>> Jun 9 15:48:53 me20 kernel: at24 2-0050: write 32@32 --> -121 (753629)
>>>>> Jun 9 15:48:53 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer complete
>>>>> Jun 9 15:48:53 me20 kernel: at24 2-0050: write 32@32 --> 0 (753630)
>>>>> Jun 9 15:48:53 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: received nack
>>>>> Jun 9 15:48:53 me20 kernel: at24 2-0050: write 32@64 --> -121 (753630)
>>>>> Jun 9 15:48:53 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer complete
>>>>> Jun 9 15:48:53 me20 kernel: at24 2-0050: write 32@64 --> 0 (753631)
>>>>> Jun 9 15:48:53 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: received nack
>>>>> Jun 9 15:48:53 me20 kernel: at24 2-0050: write 32@96 --> -121 (753631)
>>>>> Jun 9 15:48:53 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer complete
>>>>> Jun 9 15:48:53 me20 kernel: at24 2-0050: write 32@96 --> 0 (753632)
>>>>> Jun 9 15:48:53 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: received nack
>>>>> Jun 9 15:48:53 me20 kernel: at24 2-0050: write 32@128 --> -121 (753632)
>>>>> Jun 9 15:48:53 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer complete
>>>>> Jun 9 15:48:53 me20 kernel: at24 2-0050: write 32@128 --> 0 (753633)
>>>>> Jun 9 15:48:53 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: received nack
>>>>> Jun 9 15:48:53 me20 kernel: at24 2-0050: write 32@160 --> -121 (753633)
>>>>> Jun 9 15:48:53 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer complete
>>>>> Jun 9 15:48:53 me20 kernel: at24 2-0050: write 32@160 --> 0 (753634)
>>>>> ... snip ...
>>>>> Jun 9 15:48:55 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>>> Jun 9 15:48:55 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>>> Jun 9 15:48:55 me20 kernel: at91_i2c f801c000.i2c: received nack
>>>>> Jun 9 15:48:55 me20 kernel: at24 2-0050: write 32@8128 --> -121 (753883)
>>>>> Jun 9 15:48:55 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>>> Jun 9 15:48:55 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>>> Jun 9 15:48:55 me20 kernel: at91_i2c f801c000.i2c: transfer complete
>>>>> Jun 9 15:48:55 me20 kernel: at24 2-0050: write 32@8128 --> 0 (753884)
>>>>> Jun 9 15:48:55 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>>> Jun 9 15:48:55 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>>> Jun 9 15:48:55 me20 kernel: at91_i2c f801c000.i2c: received nack
>>>>> Jun 9 15:48:55 me20 kernel: at24 2-0050: write 32@8160 --> -121 (753884)
>>>>> Jun 9 15:48:55 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>>> Jun 9 15:48:55 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>>> Jun 9 15:48:55 me20 kernel: at91_i2c f801c000.i2c: transfer complete
>>>>> Jun 9 15:48:55 me20 kernel: at24 2-0050: write 32@8160 --> 0 (753885)
>>>>
>>>> could you please apply this patch-set [1] and let us know if it
>>>> addresses your issue?
>>>>
>>>> Thanks and best regards,
>>>> Codrin
>>>>
>>>> https://patchwork.ozlabs.org/project/linux-i2c/list/?series=255408
>>>
>>> That series does indeed help! I'll reply with a tested-by etc on the
>>> first two patches, I can't test patch 3/3 with my sama5d3 board...
>>>
>>> Thank you very much!
>>
>> Since replying to the actual patches do not work for me, I'm writing here
>> instead. Sorry about that. As stated above, it /seems/ to work much better
>> with these patches. But I fooled myself and there is still some remaining
>> trouble. It is not uncommon that the second (32-byte) page in the eeprom
>> is not written correctly for whatever reason. I do not know why it's
>> always the second page that gets corrupted, but this is a bad problem since
>> the failure is completely silent.
>>
>> Cheers,
>> Peter
>
> #regzbot poke

2022-09-26 15:55:57

[permalink] [raw]

Subject: Re: Regression: at24 eeprom writing times out on sama5d3 #forregzbot

TWIMC: this mail is primarily send for documentation purposes and for
regzbot, my Linux kernel regression tracking bot. These mails usually
contain '#forregzbot' in the subject, to make them easy to spot and filter.

On 08.09.22 15:59, Peter Rosin wrote:
> 2022-09-08 at 14:06, Thorsten Leemhuis wrote:
>> Hi, this is your Linux kernel regression tracker. Top-posting for once,
>> to make this easily accessible to everyone.
>>
>> Peter, Codrin, could you help me out here please: I still have the
>> regression report from Peter that started this thread in the list of
>> tracked issues. From Peter's last msg quoted below it seems the thread
>> just faded out without the regression being fixed. Or was it? If not:
>> what can we do to finally get this resolved?
>
> No, it is not resolved that I know of. We are only writing during
> production, but are working around it by verifying and looping back.
> Sometimes it takes surprisingly long for the loop to finish, but
> it's not a huge deal. But it is of course not completely satisfying
> either...
>
> Reading is never a problem, so post-production behavior is sane.

FWIW, in that case:

#regzbot backburner: a proper fix will take some time and reporter has a
work-around

>> Ciao, Thorsten (wearing his 'the Linux kernel's regression tracker' hat)
>>
>> P.S.: As the Linux kernel's regression tracker I deal with a lot of
>> reports and sometimes miss something important when writing mails like
>> this. If that's the case here, don't hesitate to tell me in a public
>> reply, it's in everyone's interest to set the public record straight.
>>
>> On 30.06.22 09:44, Peter Rosin wrote:
>>> 2022-06-10 at 22:51, Peter Rosin wrote:
>>>> 2022-06-10 at 09:35, [email protected] wrote:
>>>>> On 09.06.2022 17:28, Peter Rosin wrote:
>>>>>>
>>>>>> I have not actually bisected this issue but reverting the effects of
>>>>>> patch a4bd8da893a3 ("ARM: dts: at91: sama5d3: add i2c gpio pinctrl")
>>>>>> makes the problem go away.
>>>>>>
>>>>>> I.e. I need something like this in my dts
>>>>>>
>>>>>> &i2c2 {
>>>>>> status = "okay";
>>>>>>
>>>>>> pinctrl-names = "default";
>>>>>> /delete-property/ pinctrl-1;
>>>>>> /delete-property/ sda-gpios;
>>>>>> /delete-property/ scl-gpios;
>>>>>>
>>>>>> eeprom@50 {
>>>>>> compatible = "st,24c64", "atmel,24c64";
>>>>>> reg = <0x50>;
>>>>>> wp-gpios = <&filter_gpio 7 GPIO_ACTIVE_HIGH>;
>>>>>> };
>>>>>> };
>>>>>>
>>>>>> for multi-page eeprom writes to not time out (a page is 32 bytes on this
>>>>>> eeprom).
>>>>>>
>>>>>> For reference, the current defaults for this SoC/I2C-bus, that I modify,
>>>>>> are:
>>>>>>
>>>>>> pinctrl-names = "default", "gpio";
>>>>>> pinctrl-0 = <&pinctrl_i2c2>;
>>>>>> pinctrl-1 = <&pinctrl_i2c2_gpio>;
>>>>>> sda-gpios = <&pioA 18 GPIO_ACTIVE_HIGH>;
>>>>>> scl-gpios = <&pioA 19 (GPIO_ACTIVE_HIGH | GPIO_OPEN_DRAIN)>;
>>>>>>
>>>>>> I suspect that the underlying reason is that the bus recovery takes
>>>>>> too long and that the at24 eeprom driver gives up prematurely. I doubt
>>>>>> that this is chip specific, but I don't know that.
>>>>>>
>>>>>> I can work around the issue in user space with by writing in 4 byte
>>>>>> chunks, like so
>>>>>>
>>>>>> dd if=source.file of=/sys/bus/i2c/devices/2-0050/eeprom obs=4
>>>>>>
>>>>>> but that is really ugly and gets slow too, about 20 seconds to program
>>>>>> the full 8kB eeprom. With the above in my dts it takes a second or
>>>>>> so (a bit more with dynamic debug active).
>>>>>>
>>>>>>
>>>>>> If I run
>>>>>>
>>>>>> dd if=source.file of=/sys/bus/i2c/devices/2-0050/eeprom
>>>>>>
>>>>>> with a source.file of 8kB and the upstream dts properties in place, I can
>>>>>> collect the following debug output from at24, i2c-core and i2c-at91:
>>>>>>
>>>>>> Jun 9 15:56:34 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>>>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>>>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: transfer complete
>>>>>> Jun 9 15:56:34 me20 kernel: at24 2-0050: write 32@0 --> 0 (-23170)
>>>>>> Jun 9 15:56:34 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>>>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>>>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: received nack
>>>>>> Jun 9 15:56:34 me20 kernel: i2c i2c-2: Trying i2c bus recovery
>>>>>> Jun 9 15:56:34 me20 kernel: at24 2-0050: write 32@32 --> -121 (-23169)
>>>>>> Jun 9 15:56:34 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>>>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>>>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: transfer complete
>>>>>> Jun 9 15:56:34 me20 kernel: at24 2-0050: write 32@32 --> 0 (-23168)
>>>>>> Jun 9 15:56:34 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>>>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>>>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: received nack
>>>>>> Jun 9 15:56:34 me20 kernel: i2c i2c-2: Trying i2c bus recovery
>>>>>> Jun 9 15:56:34 me20 kernel: at24 2-0050: write 32@64 --> -121 (-23168)
>>>>>> Jun 9 15:56:34 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>>>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>>>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: transfer complete
>>>>>> Jun 9 15:56:34 me20 kernel: at24 2-0050: write 32@64 --> 0 (-23167)
>>>>>> Jun 9 15:56:34 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>>>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>>>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: received nack
>>>>>> Jun 9 15:56:34 me20 kernel: i2c i2c-2: Trying i2c bus recovery
>>>>>> Jun 9 15:56:34 me20 kernel: at24 2-0050: write 32@96 --> -121 (-23167)
>>>>>> Jun 9 15:56:34 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>>>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>>>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: controller timed out
>>>>>> Jun 9 15:56:34 me20 kernel: i2c i2c-2: Trying i2c bus recovery
>>>>>> Jun 9 15:56:34 me20 kernel: at24 2-0050: write 32@96 --> -110 (-23155)
>>>>>> Jun 9 15:56:34 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>>>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>>>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: controller timed out
>>>>>> Jun 9 15:56:34 me20 kernel: i2c i2c-2: Trying i2c bus recovery
>>>>>> Jun 9 15:56:34 me20 kernel: at24 2-0050: write 32@96 --> -110 (-23143)
>>>>>>
>>>>>> And then there is no more action. I.e. only a couple of 32 byte pages
>>>>>> are written.
>>>>>>
>>>>>> With the above mentioned dts override in place I instead get this, which is
>>>>>> a lot more sensible:
>>>>>>
>>>>>> Jun 9 15:48:53 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer complete
>>>>>> Jun 9 15:48:53 me20 kernel: at24 2-0050: write 32@0 --> 0 (753629)
>>>>>> Jun 9 15:48:53 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: received nack
>>>>>> Jun 9 15:48:53 me20 kernel: at24 2-0050: write 32@32 --> -121 (753629)
>>>>>> Jun 9 15:48:53 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer complete
>>>>>> Jun 9 15:48:53 me20 kernel: at24 2-0050: write 32@32 --> 0 (753630)
>>>>>> Jun 9 15:48:53 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: received nack
>>>>>> Jun 9 15:48:53 me20 kernel: at24 2-0050: write 32@64 --> -121 (753630)
>>>>>> Jun 9 15:48:53 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer complete
>>>>>> Jun 9 15:48:53 me20 kernel: at24 2-0050: write 32@64 --> 0 (753631)
>>>>>> Jun 9 15:48:53 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: received nack
>>>>>> Jun 9 15:48:53 me20 kernel: at24 2-0050: write 32@96 --> -121 (753631)
>>>>>> Jun 9 15:48:53 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer complete
>>>>>> Jun 9 15:48:53 me20 kernel: at24 2-0050: write 32@96 --> 0 (753632)
>>>>>> Jun 9 15:48:53 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: received nack
>>>>>> Jun 9 15:48:53 me20 kernel: at24 2-0050: write 32@128 --> -121 (753632)
>>>>>> Jun 9 15:48:53 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer complete
>>>>>> Jun 9 15:48:53 me20 kernel: at24 2-0050: write 32@128 --> 0 (753633)
>>>>>> Jun 9 15:48:53 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: received nack
>>>>>> Jun 9 15:48:53 me20 kernel: at24 2-0050: write 32@160 --> -121 (753633)
>>>>>> Jun 9 15:48:53 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer complete
>>>>>> Jun 9 15:48:53 me20 kernel: at24 2-0050: write 32@160 --> 0 (753634)
>>>>>> ... snip ...
>>>>>> Jun 9 15:48:55 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>>>> Jun 9 15:48:55 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>>>> Jun 9 15:48:55 me20 kernel: at91_i2c f801c000.i2c: received nack
>>>>>> Jun 9 15:48:55 me20 kernel: at24 2-0050: write 32@8128 --> -121 (753883)
>>>>>> Jun 9 15:48:55 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>>>> Jun 9 15:48:55 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>>>> Jun 9 15:48:55 me20 kernel: at91_i2c f801c000.i2c: transfer complete
>>>>>> Jun 9 15:48:55 me20 kernel: at24 2-0050: write 32@8128 --> 0 (753884)
>>>>>> Jun 9 15:48:55 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>>>> Jun 9 15:48:55 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>>>> Jun 9 15:48:55 me20 kernel: at91_i2c f801c000.i2c: received nack
>>>>>> Jun 9 15:48:55 me20 kernel: at24 2-0050: write 32@8160 --> -121 (753884)
>>>>>> Jun 9 15:48:55 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>>>> Jun 9 15:48:55 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>>>> Jun 9 15:48:55 me20 kernel: at91_i2c f801c000.i2c: transfer complete
>>>>>> Jun 9 15:48:55 me20 kernel: at24 2-0050: write 32@8160 --> 0 (753885)
>>>>>
>>>>> could you please apply this patch-set [1] and let us know if it
>>>>> addresses your issue?
>>>>>
>>>>> Thanks and best regards,
>>>>> Codrin
>>>>>
>>>>> https://patchwork.ozlabs.org/project/linux-i2c/list/?series=255408
>>>>
>>>> That series does indeed help! I'll reply with a tested-by etc on the
>>>> first two patches, I can't test patch 3/3 with my sama5d3 board...
>>>>
>>>> Thank you very much!
>>>
>>> Since replying to the actual patches do not work for me, I'm writing here
>>> instead. Sorry about that. As stated above, it /seems/ to work much better
>>> with these patches. But I fooled myself and there is still some remaining
>>> trouble. It is not uncommon that the second (32-byte) page in the eeprom
>>> is not written correctly for whatever reason. I do not know why it's
>>> always the second page that gets corrupted, but this is a bad problem since
>>> the failure is completely silent.
>>>
>>> Cheers,
>>> Peter
>>
>> #regzbot poke
>

2022-12-15 18:12:11

[permalink] [raw]

Subject: Re: Regression: at24 eeprom writing times out on sama5d3

Hi, this is your Linux kernel regression tracker.

On 08.09.22 15:59, Peter Rosin wrote:
> Hi!
>
> 2022-09-08 at 14:06, Thorsten Leemhuis wrote:
>> Hi, this is your Linux kernel regression tracker. Top-posting for once,
>> to make this easily accessible to everyone.
>>
>> Peter, Codrin, could you help me out here please: I still have the
>> regression report from Peter that started this thread in the list of
>> tracked issues. From Peter's last msg quoted below it seems the thread
>> just faded out without the regression being fixed. Or was it? If not:
>> what can we do to finally get this resolved?
>
> No, it is not resolved that I know of. We are only writing during
> production, but are working around it by verifying and looping back.
> Sometimes it takes surprisingly long for the loop to finish, but
> it's not a huge deal. But it is of course not completely satisfying
> either...
>
> Reading is never a problem, so post-production behavior is sane.

I still have this regression that Peter reported in late July on my
list. :-(

Codrin (and maybe Wolfram), could you provide a update please? Afaics
this is the state of things (please correct me if I'm wrong!): In an
earlier mail
(https://lore.kernel.org/lkml/[email protected]/
) of this thread Peter stated that the following patch set Codrin posted
mid 2021 helped:
https://lore.kernel.org/all/[email protected]/

There where a few review comments from Wolfram, but looks like then
things stalled. Can we somehow get this rolling again to finally get
this regression fixed?

Ciao, Thorsten (wearing his 'the Linux kernel's regression tracker' hat)

P.S.: As the Linux kernel's regression tracker I deal with a lot of
reports and sometimes miss something important when writing mails like
this. If that's the case here, don't hesitate to tell me in a public
reply, it's in everyone's interest to set the public record straight.

>> Ciao, Thorsten (wearing his 'the Linux kernel's regression tracker' hat)
>>
>> P.S.: As the Linux kernel's regression tracker I deal with a lot of
>> reports and sometimes miss something important when writing mails like
>> this. If that's the case here, don't hesitate to tell me in a public
>> reply, it's in everyone's interest to set the public record straight.
>>
>> On 30.06.22 09:44, Peter Rosin wrote:
>>> 2022-06-10 at 22:51, Peter Rosin wrote:
>>>> 2022-06-10 at 09:35, [email protected] wrote:
>>>>> On 09.06.2022 17:28, Peter Rosin wrote:
>>>>>>
>>>>>> I have not actually bisected this issue but reverting the effects of
>>>>>> patch a4bd8da893a3 ("ARM: dts: at91: sama5d3: add i2c gpio pinctrl")
>>>>>> makes the problem go away.
>>>>>>
>>>>>> I.e. I need something like this in my dts
>>>>>>
>>>>>> &i2c2 {
>>>>>> status = "okay";
>>>>>>
>>>>>> pinctrl-names = "default";
>>>>>> /delete-property/ pinctrl-1;
>>>>>> /delete-property/ sda-gpios;
>>>>>> /delete-property/ scl-gpios;
>>>>>>
>>>>>> eeprom@50 {
>>>>>> compatible = "st,24c64", "atmel,24c64";
>>>>>> reg = <0x50>;
>>>>>> wp-gpios = <&filter_gpio 7 GPIO_ACTIVE_HIGH>;
>>>>>> };
>>>>>> };
>>>>>>
>>>>>> for multi-page eeprom writes to not time out (a page is 32 bytes on this
>>>>>> eeprom).
>>>>>>
>>>>>> For reference, the current defaults for this SoC/I2C-bus, that I modify,
>>>>>> are:
>>>>>>
>>>>>> pinctrl-names = "default", "gpio";
>>>>>> pinctrl-0 = <&pinctrl_i2c2>;
>>>>>> pinctrl-1 = <&pinctrl_i2c2_gpio>;
>>>>>> sda-gpios = <&pioA 18 GPIO_ACTIVE_HIGH>;
>>>>>> scl-gpios = <&pioA 19 (GPIO_ACTIVE_HIGH | GPIO_OPEN_DRAIN)>;
>>>>>>
>>>>>> I suspect that the underlying reason is that the bus recovery takes
>>>>>> too long and that the at24 eeprom driver gives up prematurely. I doubt
>>>>>> that this is chip specific, but I don't know that.
>>>>>>
>>>>>> I can work around the issue in user space with by writing in 4 byte
>>>>>> chunks, like so
>>>>>>
>>>>>> dd if=source.file of=/sys/bus/i2c/devices/2-0050/eeprom obs=4
>>>>>>
>>>>>> but that is really ugly and gets slow too, about 20 seconds to program
>>>>>> the full 8kB eeprom. With the above in my dts it takes a second or
>>>>>> so (a bit more with dynamic debug active).
>>>>>>
>>>>>>
>>>>>> If I run
>>>>>>
>>>>>> dd if=source.file of=/sys/bus/i2c/devices/2-0050/eeprom
>>>>>>
>>>>>> with a source.file of 8kB and the upstream dts properties in place, I can
>>>>>> collect the following debug output from at24, i2c-core and i2c-at91:
>>>>>>
>>>>>> Jun 9 15:56:34 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>>>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>>>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: transfer complete
>>>>>> Jun 9 15:56:34 me20 kernel: at24 2-0050: write 32@0 --> 0 (-23170)
>>>>>> Jun 9 15:56:34 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>>>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>>>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: received nack
>>>>>> Jun 9 15:56:34 me20 kernel: i2c i2c-2: Trying i2c bus recovery
>>>>>> Jun 9 15:56:34 me20 kernel: at24 2-0050: write 32@32 --> -121 (-23169)
>>>>>> Jun 9 15:56:34 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>>>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>>>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: transfer complete
>>>>>> Jun 9 15:56:34 me20 kernel: at24 2-0050: write 32@32 --> 0 (-23168)
>>>>>> Jun 9 15:56:34 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>>>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>>>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: received nack
>>>>>> Jun 9 15:56:34 me20 kernel: i2c i2c-2: Trying i2c bus recovery
>>>>>> Jun 9 15:56:34 me20 kernel: at24 2-0050: write 32@64 --> -121 (-23168)
>>>>>> Jun 9 15:56:34 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>>>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>>>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: transfer complete
>>>>>> Jun 9 15:56:34 me20 kernel: at24 2-0050: write 32@64 --> 0 (-23167)
>>>>>> Jun 9 15:56:34 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>>>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>>>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: received nack
>>>>>> Jun 9 15:56:34 me20 kernel: i2c i2c-2: Trying i2c bus recovery
>>>>>> Jun 9 15:56:34 me20 kernel: at24 2-0050: write 32@96 --> -121 (-23167)
>>>>>> Jun 9 15:56:34 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>>>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>>>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: controller timed out
>>>>>> Jun 9 15:56:34 me20 kernel: i2c i2c-2: Trying i2c bus recovery
>>>>>> Jun 9 15:56:34 me20 kernel: at24 2-0050: write 32@96 --> -110 (-23155)
>>>>>> Jun 9 15:56:34 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>>>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>>>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: controller timed out
>>>>>> Jun 9 15:56:34 me20 kernel: i2c i2c-2: Trying i2c bus recovery
>>>>>> Jun 9 15:56:34 me20 kernel: at24 2-0050: write 32@96 --> -110 (-23143)
>>>>>>
>>>>>> And then there is no more action. I.e. only a couple of 32 byte pages
>>>>>> are written.
>>>>>>
>>>>>> With the above mentioned dts override in place I instead get this, which is
>>>>>> a lot more sensible:
>>>>>>
>>>>>> Jun 9 15:48:53 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer complete
>>>>>> Jun 9 15:48:53 me20 kernel: at24 2-0050: write 32@0 --> 0 (753629)
>>>>>> Jun 9 15:48:53 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: received nack
>>>>>> Jun 9 15:48:53 me20 kernel: at24 2-0050: write 32@32 --> -121 (753629)
>>>>>> Jun 9 15:48:53 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer complete
>>>>>> Jun 9 15:48:53 me20 kernel: at24 2-0050: write 32@32 --> 0 (753630)
>>>>>> Jun 9 15:48:53 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: received nack
>>>>>> Jun 9 15:48:53 me20 kernel: at24 2-0050: write 32@64 --> -121 (753630)
>>>>>> Jun 9 15:48:53 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer complete
>>>>>> Jun 9 15:48:53 me20 kernel: at24 2-0050: write 32@64 --> 0 (753631)
>>>>>> Jun 9 15:48:53 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: received nack
>>>>>> Jun 9 15:48:53 me20 kernel: at24 2-0050: write 32@96 --> -121 (753631)
>>>>>> Jun 9 15:48:53 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer complete
>>>>>> Jun 9 15:48:53 me20 kernel: at24 2-0050: write 32@96 --> 0 (753632)
>>>>>> Jun 9 15:48:53 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: received nack
>>>>>> Jun 9 15:48:53 me20 kernel: at24 2-0050: write 32@128 --> -121 (753632)
>>>>>> Jun 9 15:48:53 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer complete
>>>>>> Jun 9 15:48:53 me20 kernel: at24 2-0050: write 32@128 --> 0 (753633)
>>>>>> Jun 9 15:48:53 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: received nack
>>>>>> Jun 9 15:48:53 me20 kernel: at24 2-0050: write 32@160 --> -121 (753633)
>>>>>> Jun 9 15:48:53 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer complete
>>>>>> Jun 9 15:48:53 me20 kernel: at24 2-0050: write 32@160 --> 0 (753634)
>>>>>> ... snip ...
>>>>>> Jun 9 15:48:55 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>>>> Jun 9 15:48:55 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>>>> Jun 9 15:48:55 me20 kernel: at91_i2c f801c000.i2c: received nack
>>>>>> Jun 9 15:48:55 me20 kernel: at24 2-0050: write 32@8128 --> -121 (753883)
>>>>>> Jun 9 15:48:55 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>>>> Jun 9 15:48:55 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>>>> Jun 9 15:48:55 me20 kernel: at91_i2c f801c000.i2c: transfer complete
>>>>>> Jun 9 15:48:55 me20 kernel: at24 2-0050: write 32@8128 --> 0 (753884)
>>>>>> Jun 9 15:48:55 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>>>> Jun 9 15:48:55 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>>>> Jun 9 15:48:55 me20 kernel: at91_i2c f801c000.i2c: received nack
>>>>>> Jun 9 15:48:55 me20 kernel: at24 2-0050: write 32@8160 --> -121 (753884)
>>>>>> Jun 9 15:48:55 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>>>> Jun 9 15:48:55 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>>>> Jun 9 15:48:55 me20 kernel: at91_i2c f801c000.i2c: transfer complete
>>>>>> Jun 9 15:48:55 me20 kernel: at24 2-0050: write 32@8160 --> 0 (753885)
>>>>>
>>>>> could you please apply this patch-set [1] and let us know if it
>>>>> addresses your issue?
>>>>>
>>>>> Thanks and best regards,
>>>>> Codrin
>>>>>
>>>>> https://patchwork.ozlabs.org/project/linux-i2c/list/?series=255408
>>>>
>>>> That series does indeed help! I'll reply with a tested-by etc on the
>>>> first two patches, I can't test patch 3/3 with my sama5d3 board...
>>>>
>>>> Thank you very much!
>>>
>>> Since replying to the actual patches do not work for me, I'm writing here
>>> instead. Sorry about that. As stated above, it /seems/ to work much better
>>> with these patches. But I fooled myself and there is still some remaining
>>> trouble. It is not uncommon that the second (32-byte) page in the eeprom
>>> is not written correctly for whatever reason. I do not know why it's
>>> always the second page that gets corrupted, but this is a bad problem since
>>> the failure is completely silent.
>>>
>>> Cheers,
>>> Peter
>>
>> #regzbot poke
>
> _______________________________________________
> linux-arm-kernel mailing list
> [email protected]
> http://lists.infradead.org/mailman/listinfo/linux-arm-kernel

#regzbot poke

2022-12-15 19:07:17

by Conor Dooley

[permalink] [raw]

Subject: Re: Regression: at24 eeprom writing times out on sama5d3

+CC Nicolas

On 15/12/2022 17:53, Thorsten Leemhuis wrote:
> EXTERNAL EMAIL: Do not click links or open attachments unless you know the content is safe
>
> Hi, this is your Linux kernel regression tracker.
>
> On 08.09.22 15:59, Peter Rosin wrote:
>> Hi!
>>
>> 2022-09-08 at 14:06, Thorsten Leemhuis wrote:
>>> Hi, this is your Linux kernel regression tracker. Top-posting for once,
>>> to make this easily accessible to everyone.
>>>
>>> Peter, Codrin, could you help me out here please: I still have the
>>> regression report from Peter that started this thread in the list of
>>> tracked issues. From Peter's last msg quoted below it seems the thread
>>> just faded out without the regression being fixed. Or was it? If not:
>>> what can we do to finally get this resolved?
>>
>> No, it is not resolved that I know of. We are only writing during
>> production, but are working around it by verifying and looping back.
>> Sometimes it takes surprisingly long for the loop to finish, but
>> it's not a huge deal. But it is of course not completely satisfying
>> either...
>>
>> Reading is never a problem, so post-production behavior is sane.
>
> I still have this regression that Peter reported in late July on my
> list. :-(
>
> Codrin (and maybe Wolfram), could you provide a update please? Afaics
> this is the state of things (please correct me if I'm wrong!): In an
> earlier mail
> (https://lore.kernel.org/lkml/[email protected]/
> ) of this thread Peter stated that the following patch set Codrin posted
> mid 2021 helped:
> https://lore.kernel.org/all/[email protected]/

IIRC (and I may well be wrong as it is not my neck of the woods) Codrin is
no longer at Microchip. Nicolas, do you know who has taken over this driver?

Thanks,
Conor.

>
> There where a few review comments from Wolfram, but looks like then
> things stalled. Can we somehow get this rolling again to finally get
> this regression fixed?
>
> Ciao, Thorsten (wearing his 'the Linux kernel's regression tracker' hat)
>
> P.S.: As the Linux kernel's regression tracker I deal with a lot of
> reports and sometimes miss something important when writing mails like
> this. If that's the case here, don't hesitate to tell me in a public
> reply, it's in everyone's interest to set the public record straight.
>
>>> Ciao, Thorsten (wearing his 'the Linux kernel's regression tracker' hat)
>>>
>>> P.S.: As the Linux kernel's regression tracker I deal with a lot of
>>> reports and sometimes miss something important when writing mails like
>>> this. If that's the case here, don't hesitate to tell me in a public
>>> reply, it's in everyone's interest to set the public record straight.
>>>
>>> On 30.06.22 09:44, Peter Rosin wrote:
>>>> 2022-06-10 at 22:51, Peter Rosin wrote:
>>>>> 2022-06-10 at 09:35, [email protected] wrote:
>>>>>> On 09.06.2022 17:28, Peter Rosin wrote:
>>>>>>>
>>>>>>> I have not actually bisected this issue but reverting the effects of
>>>>>>> patch a4bd8da893a3 ("ARM: dts: at91: sama5d3: add i2c gpio pinctrl")
>>>>>>> makes the problem go away.
>>>>>>>
>>>>>>> I.e. I need something like this in my dts
>>>>>>>
>>>>>>> &i2c2 {
>>>>>>> status = "okay";
>>>>>>>
>>>>>>> pinctrl-names = "default";
>>>>>>> /delete-property/ pinctrl-1;
>>>>>>> /delete-property/ sda-gpios;
>>>>>>> /delete-property/ scl-gpios;
>>>>>>>
>>>>>>> eeprom@50 {
>>>>>>> compatible = "st,24c64", "atmel,24c64";
>>>>>>> reg = <0x50>;
>>>>>>> wp-gpios = <&filter_gpio 7 GPIO_ACTIVE_HIGH>;
>>>>>>> };
>>>>>>> };
>>>>>>>
>>>>>>> for multi-page eeprom writes to not time out (a page is 32 bytes on this
>>>>>>> eeprom).
>>>>>>>
>>>>>>> For reference, the current defaults for this SoC/I2C-bus, that I modify,
>>>>>>> are:
>>>>>>>
>>>>>>> pinctrl-names = "default", "gpio";
>>>>>>> pinctrl-0 = <&pinctrl_i2c2>;
>>>>>>> pinctrl-1 = <&pinctrl_i2c2_gpio>;
>>>>>>> sda-gpios = <&pioA 18 GPIO_ACTIVE_HIGH>;
>>>>>>> scl-gpios = <&pioA 19 (GPIO_ACTIVE_HIGH | GPIO_OPEN_DRAIN)>;
>>>>>>>
>>>>>>> I suspect that the underlying reason is that the bus recovery takes
>>>>>>> too long and that the at24 eeprom driver gives up prematurely. I doubt
>>>>>>> that this is chip specific, but I don't know that.
>>>>>>>
>>>>>>> I can work around the issue in user space with by writing in 4 byte
>>>>>>> chunks, like so
>>>>>>>
>>>>>>> dd if=source.file of=/sys/bus/i2c/devices/2-0050/eeprom obs=4
>>>>>>>
>>>>>>> but that is really ugly and gets slow too, about 20 seconds to program
>>>>>>> the full 8kB eeprom. With the above in my dts it takes a second or
>>>>>>> so (a bit more with dynamic debug active).
>>>>>>>
>>>>>>>
>>>>>>> If I run
>>>>>>>
>>>>>>> dd if=source.file of=/sys/bus/i2c/devices/2-0050/eeprom
>>>>>>>
>>>>>>> with a source.file of 8kB and the upstream dts properties in place, I can
>>>>>>> collect the following debug output from at24, i2c-core and i2c-at91:
>>>>>>>
>>>>>>> Jun 9 15:56:34 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>>>>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>>>>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: transfer complete
>>>>>>> Jun 9 15:56:34 me20 kernel: at24 2-0050: write 32@0 --> 0 (-23170)
>>>>>>> Jun 9 15:56:34 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>>>>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>>>>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: received nack
>>>>>>> Jun 9 15:56:34 me20 kernel: i2c i2c-2: Trying i2c bus recovery
>>>>>>> Jun 9 15:56:34 me20 kernel: at24 2-0050: write 32@32 --> -121 (-23169)
>>>>>>> Jun 9 15:56:34 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>>>>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>>>>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: transfer complete
>>>>>>> Jun 9 15:56:34 me20 kernel: at24 2-0050: write 32@32 --> 0 (-23168)
>>>>>>> Jun 9 15:56:34 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>>>>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>>>>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: received nack
>>>>>>> Jun 9 15:56:34 me20 kernel: i2c i2c-2: Trying i2c bus recovery
>>>>>>> Jun 9 15:56:34 me20 kernel: at24 2-0050: write 32@64 --> -121 (-23168)
>>>>>>> Jun 9 15:56:34 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>>>>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>>>>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: transfer complete
>>>>>>> Jun 9 15:56:34 me20 kernel: at24 2-0050: write 32@64 --> 0 (-23167)
>>>>>>> Jun 9 15:56:34 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>>>>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>>>>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: received nack
>>>>>>> Jun 9 15:56:34 me20 kernel: i2c i2c-2: Trying i2c bus recovery
>>>>>>> Jun 9 15:56:34 me20 kernel: at24 2-0050: write 32@96 --> -121 (-23167)
>>>>>>> Jun 9 15:56:34 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>>>>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>>>>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: controller timed out
>>>>>>> Jun 9 15:56:34 me20 kernel: i2c i2c-2: Trying i2c bus recovery
>>>>>>> Jun 9 15:56:34 me20 kernel: at24 2-0050: write 32@96 --> -110 (-23155)
>>>>>>> Jun 9 15:56:34 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>>>>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>>>>> Jun 9 15:56:34 me20 kernel: at91_i2c f801c000.i2c: controller timed out
>>>>>>> Jun 9 15:56:34 me20 kernel: i2c i2c-2: Trying i2c bus recovery
>>>>>>> Jun 9 15:56:34 me20 kernel: at24 2-0050: write 32@96 --> -110 (-23143)
>>>>>>>
>>>>>>> And then there is no more action. I.e. only a couple of 32 byte pages
>>>>>>> are written.
>>>>>>>
>>>>>>> With the above mentioned dts override in place I instead get this, which is
>>>>>>> a lot more sensible:
>>>>>>>
>>>>>>> Jun 9 15:48:53 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer complete
>>>>>>> Jun 9 15:48:53 me20 kernel: at24 2-0050: write 32@0 --> 0 (753629)
>>>>>>> Jun 9 15:48:53 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: received nack
>>>>>>> Jun 9 15:48:53 me20 kernel: at24 2-0050: write 32@32 --> -121 (753629)
>>>>>>> Jun 9 15:48:53 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer complete
>>>>>>> Jun 9 15:48:53 me20 kernel: at24 2-0050: write 32@32 --> 0 (753630)
>>>>>>> Jun 9 15:48:53 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: received nack
>>>>>>> Jun 9 15:48:53 me20 kernel: at24 2-0050: write 32@64 --> -121 (753630)
>>>>>>> Jun 9 15:48:53 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer complete
>>>>>>> Jun 9 15:48:53 me20 kernel: at24 2-0050: write 32@64 --> 0 (753631)
>>>>>>> Jun 9 15:48:53 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: received nack
>>>>>>> Jun 9 15:48:53 me20 kernel: at24 2-0050: write 32@96 --> -121 (753631)
>>>>>>> Jun 9 15:48:53 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer complete
>>>>>>> Jun 9 15:48:53 me20 kernel: at24 2-0050: write 32@96 --> 0 (753632)
>>>>>>> Jun 9 15:48:53 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: received nack
>>>>>>> Jun 9 15:48:53 me20 kernel: at24 2-0050: write 32@128 --> -121 (753632)
>>>>>>> Jun 9 15:48:53 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer complete
>>>>>>> Jun 9 15:48:53 me20 kernel: at24 2-0050: write 32@128 --> 0 (753633)
>>>>>>> Jun 9 15:48:53 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: received nack
>>>>>>> Jun 9 15:48:53 me20 kernel: at24 2-0050: write 32@160 --> -121 (753633)
>>>>>>> Jun 9 15:48:53 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>>>>> Jun 9 15:48:53 me20 kernel: at91_i2c f801c000.i2c: transfer complete
>>>>>>> Jun 9 15:48:53 me20 kernel: at24 2-0050: write 32@160 --> 0 (753634)
>>>>>>> ... snip ...
>>>>>>> Jun 9 15:48:55 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>>>>> Jun 9 15:48:55 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>>>>> Jun 9 15:48:55 me20 kernel: at91_i2c f801c000.i2c: received nack
>>>>>>> Jun 9 15:48:55 me20 kernel: at24 2-0050: write 32@8128 --> -121 (753883)
>>>>>>> Jun 9 15:48:55 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>>>>> Jun 9 15:48:55 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>>>>> Jun 9 15:48:55 me20 kernel: at91_i2c f801c000.i2c: transfer complete
>>>>>>> Jun 9 15:48:55 me20 kernel: at24 2-0050: write 32@8128 --> 0 (753884)
>>>>>>> Jun 9 15:48:55 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>>>>> Jun 9 15:48:55 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>>>>> Jun 9 15:48:55 me20 kernel: at91_i2c f801c000.i2c: received nack
>>>>>>> Jun 9 15:48:55 me20 kernel: at24 2-0050: write 32@8160 --> -121 (753884)
>>>>>>> Jun 9 15:48:55 me20 kernel: i2c i2c-2: at91_xfer: processing 1 messages:
>>>>>>> Jun 9 15:48:55 me20 kernel: at91_i2c f801c000.i2c: transfer: write 34 bytes.
>>>>>>> Jun 9 15:48:55 me20 kernel: at91_i2c f801c000.i2c: transfer complete
>>>>>>> Jun 9 15:48:55 me20 kernel: at24 2-0050: write 32@8160 --> 0 (753885)
>>>>>>
>>>>>> could you please apply this patch-set [1] and let us know if it
>>>>>> addresses your issue?
>>>>>>
>>>>>> Thanks and best regards,
>>>>>> Codrin
>>>>>>
>>>>>> https://patchwork.ozlabs.org/project/linux-i2c/list/?series=255408
>>>>>
>>>>> That series does indeed help! I'll reply with a tested-by etc on the
>>>>> first two patches, I can't test patch 3/3 with my sama5d3 board...
>>>>>
>>>>> Thank you very much!
>>>>
>>>> Since replying to the actual patches do not work for me, I'm writing here
>>>> instead. Sorry about that. As stated above, it /seems/ to work much better
>>>> with these patches. But I fooled myself and there is still some remaining
>>>> trouble. It is not uncommon that the second (32-byte) page in the eeprom
>>>> is not written correctly for whatever reason. I do not know why it's
>>>> always the second page that gets corrupted, but this is a bad problem since
>>>> the failure is completely silent.
>>>>
>>>> Cheers,
>>>> Peter
>>>
>>> #regzbot poke
>>
>> _______________________________________________
>> linux-arm-kernel mailing list
>> [email protected]
>> http://lists.infradead.org/mailman/listinfo/linux-arm-kernel
>
> #regzbot poke

2023-03-15 11:58:50