Re: Uartlite - ulite_transmit

Re: Uartlite - ulite_transmit

[Michal Simek]

Hi Peter, [cc: Grant]

I have found one thing which I would like to check with you.
It is about mdm console which is uartlite compatible but it is slow.
The problem which I think it is there is in ulite_transmit function if
TXFULL is reported then it was returned 0. ulite_transmit is called from
do-while loop in ulite_isr (shown below).

     do {
         int stat = readb(port->membase + ULITE_STATUS);
         busy  = ulite_receive(port, stat);
         busy |= ulite_transmit(port, stat);
     } while (busy);

If tx is full then loop ends but there could be a lot of characters
which need to be send that's why will be good to wait a little bit. I
think it could be done by returning 1 in that case.

What do you think? Patch is below.

Thanks,
Michal

P.S.: second email because c&p error.


diff --git a/drivers/serial/uartlite.c b/drivers/serial/uartlite.c
index ff5f248..cd2c94b 100644
--- a/drivers/serial/uartlite.c
+++ b/drivers/serial/uartlite.c
@@ -128,7 +128,7 @@ static int ulite_transmit(struct uart_port *port,
int stat)
         struct circ_buf *xmit  = &port->info->xmit;

         if (stat & ULITE_STATUS_TXFULL)
-               return 0;
+               return 1;

         if (port->x_char) {
                 writeb(port->x_char, port->membase + ULITE_TX);



-- 
Michal Simek, Ing. (M.Eng)
w: www.monstr.eu p: +42-0-721842854
Maintainer of Linux kernel 2.6 Microblaze Linux - http://www.monstr.eu/fdt/
Microblaze U-BOOT custodian

Re: Uartlite - ulite_transmit

[Peter Korsgaard]

>>>>> "Michal" == Michal Simek <monstr@monstr.eu> writes:

 Michal> Hi Peter, [cc: Grant]
 Michal> I have found one thing which I would like to check with you.
 Michal> It is about mdm console which is uartlite compatible but it is slow.
 Michal> The problem which I think it is there is in ulite_transmit function if
 Michal> TXFULL is reported then it was returned 0. ulite_transmit is called from
 Michal> do-while loop in ulite_isr (shown below).

 Michal>     do {
 Michal>         int stat = readb(port->membase + ULITE_STATUS);
 Michal>         busy  = ulite_receive(port, stat);
 Michal>         busy |= ulite_transmit(port, stat);
 Michal>     } while (busy);

 Michal> If tx is full then loop ends but there could be a lot of characters
 Michal> which need to be send that's why will be good to wait a little bit. I
 Michal> think it could be done by returning 1 in that case.

 Michal> What do you think? Patch is below.

That would make us spin in the interrupt for potentially quite a while,
E.G. until all data is transferred to the TX fifo.

What kind of problem are you trying to fix in the first place? You
should get an interrupt when the TX fifo empties, which fill completely
fill up the fifo again and so on - That should work just fine even with
a low baud rate.

-- 
Bye, Peter Korsgaard

Re: Uartlite - ulite_transmit

[Michal Simek]

Peter Korsgaard wrote:
>>>>>> "Michal" == Michal Simek <monstr@monstr.eu> writes:
> 
>  Michal> Hi Peter, [cc: Grant]
>  Michal> I have found one thing which I would like to check with you.
>  Michal> It is about mdm console which is uartlite compatible but it is slow.
>  Michal> The problem which I think it is there is in ulite_transmit function if
>  Michal> TXFULL is reported then it was returned 0. ulite_transmit is called from
>  Michal> do-while loop in ulite_isr (shown below).
> 
>  Michal>     do {
>  Michal>         int stat = readb(port->membase + ULITE_STATUS);
>  Michal>         busy  = ulite_receive(port, stat);
>  Michal>         busy |= ulite_transmit(port, stat);
>  Michal>     } while (busy);
> 
>  Michal> If tx is full then loop ends but there could be a lot of characters
>  Michal> which need to be send that's why will be good to wait a little bit. I
>  Michal> think it could be done by returning 1 in that case.
> 
>  Michal> What do you think? Patch is below.
> 
> That would make us spin in the interrupt for potentially quite a while,
> E.G. until all data is transferred to the TX fifo.

yep. That's truth but shouldn't be a problem for standard systems. Maybe 
worth to count how many times is tx fifo full on standard systems.

> 
> What kind of problem are you trying to fix in the first place? You
> should get an interrupt when the TX fifo empties, which fill completely
> fill up the fifo again and so on - That should work just fine even with
> a low baud rate.

I am trying to solve the problem for xilinx mdm IP (compatible with 
uartlite) where there are some missing characters on serial console.

Maybe there is something wrong in different place but there are 
definitely missing characters.

Just for the record: I also have to extend for loop in 
ulite_console_wait_tx to get all chars for console.

Michal



-- 
Michal Simek, Ing. (M.Eng)
w: www.monstr.eu p: +42-0-721842854
Maintainer of Linux kernel 2.6 Microblaze Linux - http://www.monstr.eu/fdt/
Microblaze U-BOOT custodian

Re: Uartlite - ulite_transmit

[Peter Korsgaard]

>>>>> "Michal" == Michal Simek <monstr@monstr.eu> writes:

Hi,

 >> That would make us spin in the interrupt for potentially quite a
 >> while, E.G. until all data is transferred to the TX fifo.

 Michal> yep. That's truth but shouldn't be a problem for standard
 Michal> systems. Maybe worth to count how many times is tx fifo full on
 Michal> standard systems.

But I still don't understand why you would want to burn CPU spinning
when you know the UART will be busy for a while. Leaving it alone until
it generates the TX fifo empty interrupt seems more logical to me.

 >> What kind of problem are you trying to fix in the first place? You
 >> should get an interrupt when the TX fifo empties, which fill completely
 >> fill up the fifo again and so on - That should work just fine even with
 >> a low baud rate.

 Michal> I am trying to solve the problem for xilinx mdm IP (compatible
 Michal> with uartlite) where there are some missing characters on
 Michal> serial console.

Strange. It's been a few years since I worked with Xilinx stuff and
never used microblaze, so I don't know anything about MDM.

 Michal> Maybe there is something wrong in different place but there are
 Michal> definitely missing characters.

 Michal> Just for the record: I also have to extend for loop in
 Michal> ulite_console_wait_tx to get all chars for console.

Yeah, that loop should probably be time based (and perhaps calculated
from baud rate).

-- 
Bye, Peter Korsgaard

Re: Uartlite - ulite_transmit

[Michal Simek]

Peter Korsgaard wrote:
>>>>>> "Michal" == Michal Simek <monstr@monstr.eu> writes:
> 
> Hi,
> 
>  >> That would make us spin in the interrupt for potentially quite a
>  >> while, E.G. until all data is transferred to the TX fifo.
> 
>  Michal> yep. That's truth but shouldn't be a problem for standard
>  Michal> systems. Maybe worth to count how many times is tx fifo full on
>  Michal> standard systems.
> 
> But I still don't understand why you would want to burn CPU spinning
> when you know the UART will be busy for a while. Leaving it alone until
> it generates the TX fifo empty interrupt seems more logical to me.

I didn't know when tx fifo was full and then empty interrupt is 
generated. I have added some debug things to driver and I am going to 
look into.

I just changed return value and I have got correct output and then I 
sent this email to check if is correct or not.


> 
>  >> What kind of problem are you trying to fix in the first place? You
>  >> should get an interrupt when the TX fifo empties, which fill completely
>  >> fill up the fifo again and so on - That should work just fine even with
>  >> a low baud rate.
> 
>  Michal> I am trying to solve the problem for xilinx mdm IP (compatible
>  Michal> with uartlite) where there are some missing characters on
>  Michal> serial console.
> 
> Strange. It's been a few years since I worked with Xilinx stuff and
> never used microblaze, so I don't know anything about MDM.

It is console over jtag. Just different connection.

> 
>  Michal> Maybe there is something wrong in different place but there are
>  Michal> definitely missing characters.
> 
>  Michal> Just for the record: I also have to extend for loop in
>  Michal> ulite_console_wait_tx to get all chars for console.
> 
> Yeah, that loop should probably be time based (and perhaps calculated
> from baud rate).

It is hard to say if you can find out any accurate number of loops which 
is baud rate dependent.

Michal

-- 
Michal Simek, Ing. (M.Eng)
w: www.monstr.eu p: +42-0-721842854
Maintainer of Linux kernel 2.6 Microblaze Linux - http://www.monstr.eu/fdt/
Microblaze U-BOOT custodian

Re: Uartlite - ulite_transmit

[Peter Korsgaard]

>>>>> "Michal" == Michal Simek <monstr@monstr.eu> writes:

Hi,

 >> But I still don't understand why you would want to burn CPU spinning
 >> when you know the UART will be busy for a while. Leaving it alone
 >> until it generates the TX fifo empty interrupt seems more logical to
 >> me.

 Michal> I didn't know when tx fifo was full and then empty interrupt is
 Michal> generated. I have added some debug things to driver and I am going to
 Michal> look into.

 Michal> I just changed return value and I have got correct output and
 Michal> then I sent this email to check if is correct or not.

According to the spec, you should get an interrupt when RX !empty or TX
empty.

We wouldn't ever be able to send more bytes than fits in the TX fifo if
it didn't.

 >> Yeah, that loop should probably be time based (and perhaps calculated
 >> from baud rate).

 Michal> It is hard to say if you can find out any accurate number of loops
 Michal> which is baud rate dependent.

Not loops, microseconds (or rather jiffies).

-- 
Bye, Peter Korsgaard

Re: Uartlite - ulite_transmit

[Michal Simek]

Peter Korsgaard wrote:
>>>>>> "Michal" == Michal Simek <monstr@monstr.eu> writes:
> 
> Hi,
> 
>  >> But I still don't understand why you would want to burn CPU spinning
>  >> when you know the UART will be busy for a while. Leaving it alone
>  >> until it generates the TX fifo empty interrupt seems more logical to
>  >> me.
> 
>  Michal> I didn't know when tx fifo was full and then empty interrupt is
>  Michal> generated. I have added some debug things to driver and I am going to
>  Michal> look into.
> 
>  Michal> I just changed return value and I have got correct output and
>  Michal> then I sent this email to check if is correct or not.
> 
> According to the spec, you should get an interrupt when RX !empty or TX
> empty.
> 
> We wouldn't ever be able to send more bytes than fits in the TX fifo if
> it didn't.

Yes, I know.

I looked at that loop and I think that we should reread actual status 
before ulite_transmit because status reg can be changed when 
ulite_receive is executed. What do you think? (BTW: status reading can 
be moved directly to ulite_receive/transmit functions)

     do {
         int stat = ioread32be(port->membase + ULITE_STATUS);
         busy  = ulite_receive(port, stat);
         stat = ioread32be(port->membase + ULITE_STATUS); // check 
status again
         busy |= ulite_transmit(port, stat);
         n++;
     } while (busy);



I did some investigating and I found:
1. xmit circ buffer contains what needs to be printed but it is not printed.

Here is circ_buf structure, pointer to buffer and head/tail

struct circ_buf {
	char *buf;
	int head;
	int tail;
};


Part of the broken log. ( There should be in Welcome to and log)

adding dns 172.16.0.5
 >
 >  >> Yeah, that loop should probably be time based (and perhaps calculated
 >  >> from baud rate).
 >
 >  Michal> It is hard to say if you can find out any accurate number of 
loops
 >  Michal> which is baud rate dependent.
 >
 > Not loops, microseconds (or rather jiffies).
 >
adding dns 172.16.10.1
Starting portmap:
Starting uWeb server:

Welc
mdm login:

Here is the circ buffer:
(NOTE: mdm login is coming from getty and it is at the beginning)

5ed72000: 0d0d0a6d 646d206c 6f67696e 3a20200d    ...mdm login:  .
5ed72010: 0a4d6f75 6e74696e 67207661 723a200d    .Mounting var: .
5ed72020: 0a506f70 756c6174 696e6720 2f766172    .Populating /var
5ed72030: 3a200d0a 52756e6e 696e6720 6c6f6361    : ..Running loca
5ed72040: 6c207374 61727420 73637269 7074732e    l start scripts.
...
5ed721b0: 646e7320 3137322e 31362e30 2e350d0a    dns 172.16.0.5..
5ed721c0: 61646469 6e672064 6e732031 37322e31    adding dns 172.1
5ed721d0: 362e3130 2e310d0a 53746172 74696e67    6.10.1..Starting
5ed721e0: 20706f72 746d6170 3a0d0a53 74617274     portmap:..Start
5ed721f0: 696e6720 75576562 20736572 7665723a    ing uWeb server:
5ed72200: 0d0a0d0a 57656c63 6f6d6520 746f0d0a    ....Welcome to..
5ed72210: 205f5f5f 5f5f2020 20202020 205f2020     _____       _
5ed72220: 20202020 20202020 205f2020 20202020             _
5ed72230: 5f0d0a7c 205f5f5f 205c2020 2020207c    _..| ___ \     |
5ed72240: 207c2020 20202020 2020207c 207c2020     |         | |
5ed72250: 2020285f 290d0a7c 207c5f2f 202f205f      (_)..| |_/ / _
5ed72260: 5f5f207c 207c5f20 20205f5f 205f207c    __ | |_   __ _ |
5ed72270: 207c2020 2020205f 20205f20 5f5f2020     |     _  _ __
5ed72280: 205f2020 205f205f 5f20205f 5f0d0a7c     _   _ __  __..|
5ed72290: 20205f5f 2f202f20 5f205c7c 205f5f7c      __/ / _ \| __|
5ed722a0: 202f205f 60207c7c 207c2020 20207c20     / _` || |    |
5ed722b0: 7c7c2027 5f205c20 7c207c20 7c207c5c    || '_ \ | | | |\
5ed722c0: 205c2f20 2f0d0a7c 207c2020 207c2020     \/ /..| |   |
5ed722d0: 5f5f2f7c 207c5f20 7c20285f 7c207c7c    __/| |_ | (_| ||
5ed722e0: 207c5f5f 5f5f7c20 7c7c207c 207c207c     |____| || | | |
5ed722f0: 7c207c5f 7c207c20 3e20203c 0d0a5c5f    | |_| | >  <..\_
5ed72300: 7c202020 205c5f5f 5f7c205c 5f5f7c20    |    \___| \__|
5ed72310: 5c5f5f2c 5f7c5c5f 5f5f5f5f 2f7c5f7c    \__,_|\_____/|_|
5ed72320: 7c5f7c20 7c5f7c20 5c5f5f2c 5f7c2f5f    |_| |_| \__,_|/_
5ed72330: 2f5c5f5c 0d0a0d0a 6f6e206d 646d0d0a    /\_\....on mdm..
5ed72340: 0d0a0000 00000000 00000000 00000000    ................

I look at head and tail values and they are OK "c" (in Welc) is called.
Exact values are: head:0x342, tail:208.(You can check that it is correct 
range in circ buffer)

Let me describe what driver did:

1. Before fault happen:
ISR is called, status is 0x18 (interrupt enabled, tx fifo full) just to 
ulite_transmit and detect TXFULL and return to ISR. Head and tail are 
correct
2. Broken part
ISR is called, status is 0x14 (interrupt enabled, tx fifo empty), jump 
to ulite_transmit. Here I am printing (head and tail values are zero). 
Xmit buffer address is the same. Then uart_circ_empty(xmit) detects that 
head and tail are the same which means nothing to print.

My question: Is there any part of the code which can change xmit head 
and tail values?

I will try to setup watchpoints on that addresses to see which part of 
the code is breaking that addresses.

BTW: Getty is providing that login prompt. Could it be an issue with getty?


Thanks,
Michal

-- 
Michal Simek, Ing. (M.Eng)
w: www.monstr.eu p: +42-0-721842854
Maintainer of Linux kernel 2.6 Microblaze Linux - http://www.monstr.eu/fdt/
Microblaze U-BOOT custodian

Re: Uartlite - ulite_transmit

[Michal Simek]

Michal Simek wrote:
> Peter Korsgaard wrote:
>>>>>>> "Michal" == Michal Simek <monstr@monstr.eu> writes:
>>
>> Hi,
>>
>>  >> But I still don't understand why you would want to burn CPU spinning
>>  >> when you know the UART will be busy for a while. Leaving it alone
>>  >> until it generates the TX fifo empty interrupt seems more logical to
>>  >> me.
>>
>>  Michal> I didn't know when tx fifo was full and then empty interrupt is
>>  Michal> generated. I have added some debug things to driver and I am 
>> going to
>>  Michal> look into.
>>
>>  Michal> I just changed return value and I have got correct output and
>>  Michal> then I sent this email to check if is correct or not.
>>
>> According to the spec, you should get an interrupt when RX !empty or TX
>> empty.
>>
>> We wouldn't ever be able to send more bytes than fits in the TX fifo if
>> it didn't.
> 
> Yes, I know.
> 
> I looked at that loop and I think that we should reread actual status 
> before ulite_transmit because status reg can be changed when 
> ulite_receive is executed. What do you think? (BTW: status reading can 
> be moved directly to ulite_receive/transmit functions)
> 
>     do {
>         int stat = ioread32be(port->membase + ULITE_STATUS);
>         busy  = ulite_receive(port, stat);
>         stat = ioread32be(port->membase + ULITE_STATUS); // check status 
> again
>         busy |= ulite_transmit(port, stat);
>         n++;
>     } while (busy);
> 
> 
> 
> I did some investigating and I found:
> 1. xmit circ buffer contains what needs to be printed but it is not 
> printed.
> 
> Here is circ_buf structure, pointer to buffer and head/tail
> 
> struct circ_buf {
>     char *buf;
>     int head;
>     int tail;
> };
> 
> 
> Part of the broken log. ( There should be in Welcome to and log)
> 
> adding dns 172.16.0.5
>  >
>  >  >> Yeah, that loop should probably be time based (and perhaps 
> calculated
>  >  >> from baud rate).
>  >
>  >  Michal> It is hard to say if you can find out any accurate number of 
> loops
>  >  Michal> which is baud rate dependent.
>  >
>  > Not loops, microseconds (or rather jiffies).
>  >
> adding dns 172.16.10.1
> Starting portmap:
> Starting uWeb server:
> 
> Welc
> mdm login:
> 
> Here is the circ buffer:
> (NOTE: mdm login is coming from getty and it is at the beginning)
> 
> 5ed72000: 0d0d0a6d 646d206c 6f67696e 3a20200d    ...mdm login:  .
> 5ed72010: 0a4d6f75 6e74696e 67207661 723a200d    .Mounting var: .
> 5ed72020: 0a506f70 756c6174 696e6720 2f766172    .Populating /var
> 5ed72030: 3a200d0a 52756e6e 696e6720 6c6f6361    : ..Running loca
> 5ed72040: 6c207374 61727420 73637269 7074732e    l start scripts.
> ...
> 5ed721b0: 646e7320 3137322e 31362e30 2e350d0a    dns 172.16.0.5..
> 5ed721c0: 61646469 6e672064 6e732031 37322e31    adding dns 172.1
> 5ed721d0: 362e3130 2e310d0a 53746172 74696e67    6.10.1..Starting
> 5ed721e0: 20706f72 746d6170 3a0d0a53 74617274     portmap:..Start
> 5ed721f0: 696e6720 75576562 20736572 7665723a    ing uWeb server:
> 5ed72200: 0d0a0d0a 57656c63 6f6d6520 746f0d0a    ....Welcome to..
> 5ed72210: 205f5f5f 5f5f2020 20202020 205f2020     _____       _
> 5ed72220: 20202020 20202020 205f2020 20202020             _
> 5ed72230: 5f0d0a7c 205f5f5f 205c2020 2020207c    _..| ___ \     |
> 5ed72240: 207c2020 20202020 2020207c 207c2020     |         | |
> 5ed72250: 2020285f 290d0a7c 207c5f2f 202f205f      (_)..| |_/ / _
> 5ed72260: 5f5f207c 207c5f20 20205f5f 205f207c    __ | |_   __ _ |
> 5ed72270: 207c2020 2020205f 20205f20 5f5f2020     |     _  _ __
> 5ed72280: 205f2020 205f205f 5f20205f 5f0d0a7c     _   _ __  __..|
> 5ed72290: 20205f5f 2f202f20 5f205c7c 205f5f7c      __/ / _ \| __|
> 5ed722a0: 202f205f 60207c7c 207c2020 20207c20     / _` || |    |
> 5ed722b0: 7c7c2027 5f205c20 7c207c20 7c207c5c    || '_ \ | | | |\
> 5ed722c0: 205c2f20 2f0d0a7c 207c2020 207c2020     \/ /..| |   |
> 5ed722d0: 5f5f2f7c 207c5f20 7c20285f 7c207c7c    __/| |_ | (_| ||
> 5ed722e0: 207c5f5f 5f5f7c20 7c7c207c 207c207c     |____| || | | |
> 5ed722f0: 7c207c5f 7c207c20 3e20203c 0d0a5c5f    | |_| | >  <..\_
> 5ed72300: 7c202020 205c5f5f 5f7c205c 5f5f7c20    |    \___| \__|
> 5ed72310: 5c5f5f2c 5f7c5c5f 5f5f5f5f 2f7c5f7c    \__,_|\_____/|_|
> 5ed72320: 7c5f7c20 7c5f7c20 5c5f5f2c 5f7c2f5f    |_| |_| \__,_|/_
> 5ed72330: 2f5c5f5c 0d0a0d0a 6f6e206d 646d0d0a    /\_\....on mdm..
> 5ed72340: 0d0a0000 00000000 00000000 00000000    ................
> 
> I look at head and tail values and they are OK "c" (in Welc) is called.
> Exact values are: head:0x342, tail:208.(You can check that it is correct 
> range in circ buffer)
> 
> Let me describe what driver did:
> 
> 1. Before fault happen:
> ISR is called, status is 0x18 (interrupt enabled, tx fifo full) just to 
> ulite_transmit and detect TXFULL and return to ISR. Head and tail are 
> correct
> 2. Broken part
> ISR is called, status is 0x14 (interrupt enabled, tx fifo empty), jump 
> to ulite_transmit. Here I am printing (head and tail values are zero). 
> Xmit buffer address is the same. Then uart_circ_empty(xmit) detects that 
> head and tail are the same which means nothing to print.
> 
> My question: Is there any part of the code which can change xmit head 
> and tail values?
> 
> I will try to setup watchpoints on that addresses to see which part of 
> the code is breaking that addresses.

uart_circ_clear reset circ head/tail values from uart_flush_buffer.

crisv10.c and 68360serial.c implement wait_until_sent function which is 
probably what I need to implement.

Michal

-- 
Michal Simek, Ing. (M.Eng)
w: www.monstr.eu p: +42-0-721842854
Maintainer of Linux kernel 2.6 Microblaze Linux - http://www.monstr.eu/fdt/
Microblaze U-BOOT custodian

Re: Uartlite - ulite_transmit

[Michal Simek]

Hi Peter,

sorry for delay. I had to look at another issue.

Below is full log:
1. I setup baudrate to 50. (It could be possible to set it up to 0 too)
That's why I think that doesn't matter what baudrate is setup.

2. You see where ulite_startup is called. It is called only once.

3. You see that there is no call __uart_wait_until_sent(). It could be 
called for ASYNC mode. The second thing is __uart_wait_until_sent 
function is checking if tx fifo is empty not circ buffer is empty.

4. Next thing is that in uart_close. port->count is 2 which means that
the executing path is
	if (port->count) {
		spin_unlock_irqrestore(&port->lock, flags);
		goto done;
	}
which means that there is no chance to call __uart_wait_until_sent 
function anyway.

5. I did one modification to add simple while loop till circ buffer is 
empty to the same location to see what happen (timouts are bogus values).

if (port->count) {
	spin_unlock_irqrestore(&port->lock, flags);
	printk("************ %x %x\n", (&uport->state->xmit)->tail, 
(&uport->state->xmit)->head);
	while (!uart_circ_empty(&uport->state->xmit)) {
		msleep_interruptible(jiffies_to_msecs((uport->timeout - HZ/50)));
		if (signal_pending(current))
			break;
		if (time_after(jiffies, jiffies + uport->timeout))
			break;
	}
	printk("************\n");
	goto done;
}

Here is log: (Between **** you can see what chars are not printed)

NET: Registered protocol family 17
uart_open(0) called
ulite_startup ------------------------
Freeing unused kernel memory: 11235k freed
Mounting proc:
Mounting var:
Populating /var:
Running local start scripts.
Mounting sysfs:
mdev: initialising /dev
Mounting /etc/config:
Populating /etc/config:
flatfsd: Created 8 configuration files (168 bytes)
Mounting denet eth0: Promiscuous mode disabled.
vpts:
Setting hostname:
Bringing up network interfaces:
udhcpc (v1.14.3) started
Sending discover...
Sending seuart_open(0) called
lect for 192.168uart_close(0) called, port->count 2
************ 172 362
.0.100...
Lease of 192.168.0.100 obtained, lease time 7200
adding dns 172.16.0.5
adding dns 172.16.10.1
Starting portmap:

Welcome to
  _____       _           _      _
| ___ \     | |         | |    (_)
| |_/ / ___ | |_   __ _ | |     _  _ __   _   _ __  __
|  __/ / _ \| __| / _` || |    | || '_ \ | | | |\ \/ /
| |   |  __/| |_ | (_| || |____| || | | || |_| | >  <
\_|    \___| \__| \__,_|\_____/|_||_| |_| \__,_|/_/\_\

on Xilinx-SP605-LTP-full-WB-pc-msr-next-22-watch-wt-mdm

************
uart_open(0) called
uart_flush_buffer(0) called

Xilinx-SP605-LTP-full-WB-pc-msr-next-22-watch-wt-mdm login:



I think that will be good to check if circ buffer is empty. As you 
suggest uart_close function will be probably the best place.

Any other suggestion?

Thanks,
Michal




Full log with debug messages:

Linux version 2.6.37-00014-g85eb775-dirty (monstr@monstr.eu) (gcc 
version 4.1.2) #15 Sun Jan 16 08:43:08 CET 2011
less 8
setup_cpuinfo: initialising
setup_cpuinfo: Using full CPU PVR support
cache: wt_msr_noirq
setup_memory: max_mapnr: 0x8000
setup_memory: min_low_pfn: 0x48000
setup_memory: max_low_pfn: 0x50000
On node 0 totalpages: 32768
free_area_init_node: node 0, pgdat c029f0b8, node_mem_map c0dab000
   Normal zone: 256 pages used for memmap
   Normal zone: 0 pages reserved
   Normal zone: 32512 pages, LIFO batch:7
pcpu-alloc: s0 r0 d32768 u32768 alloc=1*32768
pcpu-alloc: [0] 0
Built 1 zonelists in Zone order, mobility grouping on.  Total pages: 32512
Kernel command line: console=ttyUL0,50
PID hash table entries: 512 (order: -1, 2048 bytes)
Dentry cache hash table entries: 16384 (order: 4, 65536 bytes)
Inode-cache hash table entries: 8192 (order: 3, 32768 bytes)
Memory: 115776k/131072k available
NR_IRQS:32
xlnx,xps-intc-1.00.a #0 at 0xc8000000, num_irq=8, edge=0x93
xlnx,xps-timer-1.00.a #0 at 0xc8004000, irq=4
microblaze_timer_set_mode: shutdown
microblaze_timer_set_mode: periodic
Calibrating delay loop... 43.90 BogoMIPS (lpj=87808)
pid_max: default: 32768 minimum: 301
Mount-cache hash table entries: 512
NET: Registered protocol family 16
bio: create slab <bio-0> at 0
Switching to clocksource microblaze_clocksource
microblaze_timer_set_mode: oneshot
NET: Registered protocol family 2
IP route cache hash table entries: 1024 (order: 0, 4096 bytes)
TCP established hash table entries: 4096 (order: 3, 32768 bytes)
TCP bind hash table entries: 4096 (order: 2, 16384 bytes)
TCP: Hash tables configured (established 4096 bind 4096)
TCP reno registered
UDP hash table entries: 256 (order: 0, 4096 bytes)
UDP-Lite hash table entries: 256 (order: 0, 4096 bytes)
NET: Registered protocol family 1
RPC: Registered udp transport module.
RPC: Registered tcp transport module.
RPC: Registered tcp NFSv4.1 backchannel transport module.
Skipping unavailable RESET gpio -2 (reset)
GPIO pin is already allocated
JFFS2 version 2.2. (NAND) (SUMMARY)  © 2001-2006 Red Hat, Inc.
Block layer SCSI generic (bsg) driver version 0.4 loaded (major 254)
io scheduler noop registered
io scheduler deadline registered
io scheduler cfq registered (default)
84400000.debug: ttyUL0 at MMIO 0x84400000 (irq = 7) is a uartlite
console [ttyUL0] enabled
Xilinx SystemACE device driver, major=254
86000000.flash: Found 1 x16 devices at 0x0 in 16-bit bank. Manufacturer 
ID 0x000089 Chip ID 0x008919
Intel/Sharp Extended Query Table at 0x010A
Intel/Sharp Extended Query Table at 0x010A
Intel/Sharp Extended Query Table at 0x010A
Intel/Sharp Extended Query Table at 0x010A
Intel/Sharp Extended Query Table at 0x010A
Using buffer write method
Using auto-unlock on power-up/resume
cfi_cmdset_0001: Erase suspend on write enabled
erase region 0: offset=0x0,size=0x20000,blocks=255
erase region 1: offset=0x1fe0000,size=0x8000,blocks=4
RedBoot partition parsing not available
Creating 6 MTD partitions on "86000000.flash":
0x000000000000-0x000000100000 : "fpga"
0x000000100000-0x000000140000 : "boot"
0x000000140000-0x000000160000 : "bootenv"
0x000000160000-0x000000180000 : "config"
0x000000180000-0x000000b80000 : "image"
0x000000b80000-0x000002000000 : "spare"
Xilinx TEMAC MDIO: probed
eth0: Dropping NETIF_F_SG since no checksum feature.
TCP cubic registered
NET: Registered protocol family 17
uart_open(0) called
ulite_startup ------------------------
Freeing unused kernel memory: 11235k freed
Mounting proc:
Mounting var:
Populating /var:
Running local start scripts.
Mounting sysfs:
mdev: initialising /dev
Mounting /etc/config:
Populating /etc/config:
flatfsd: Created 8 configuration files (168 bytes)
Mounting devpnet eth0: Promiscuous mode disabled.
ts:
Setting hostname:
Bringing up network interfaces:
udhcpc (v1.14.3) started
Sending discover...
Sending seluart_open(0) called
ect for 192.168.uart_close(0) called
uart_open(0) called
uart_flush_buffer(0) called

Xilinx-SP605-LTP-full-WB-pc-msr-next-22-watch-wt-mdm login:




Peter Korsgaard wrote:
>>>>>> "Michal" == Michal Simek <monstr@monstr.eu> writes:
> 
> Hi,
> 
>  Michal> The point is that clearing is called but there are still some
>  Michal> characters which are not printed. If you call that clearing you
>  Michal> just lost the part of log.
> 
> Yes, but it shouldn't happen as __uart_wait_until_sent() is called
> first.
> 
>  >> What is the problem here? Is it that the uart gets closed and reopened
>  >> (which causes ulite_startup() to get called)
>  Michal>  while there's still data in
>  >> the uarts internal tx fifo (which then gets discarded)
> 
>  Michal> No data in internal tx fifo are not discarded.
> 
> It is if ulite_startup is called.
> 
>  Michal> , or is it that
>  >> there's still data in the sw xmit circular buffer that isn't sent to the
>  >> hardware yet?
> 
>  Michal> yes, data are in the circ buffer head and tail are correctly setup and
>  Michal> because sending is slow that circ buffer clearing is called and head
>  Michal> and tail is zeroed.
>  Michal> I think the best solution will be to wait if head/tail is not the same
>  Michal> value which means there is data in circ buffer. Not sure if driver can
>  Michal> do anything with it or if there is any way how to delay buffer
>  Michal> clearing in the driver.
> 
> I don't know much of the details of serial_core, but I believe
> uart_close (and hence uart_circ_clear) is only called when all
> characters in the circular buffer have been sent. What still might not
> be sent is any data in the uart TX fifo, but __uart_wait_until_sent()
> should handle that if you provide correct baudrate.
> 
>  >> What baudrate is your hardware running at?  What baudrate have you
>  >> configured the kernel to use? Even though the uartlite itself doesn't do
>  >> anything with the baudrate setting (E.G. it is fixed in hardware), the
>  >> baudrate is used by the kernel to calculate timeouts (E.G. in
>  >> __uart_wait_until_sent and similar).
> 
>  Michal> It is the same style. You can't even setup baudrate in EDK. There is
>  Michal> no hardware connection through serial line. The whole communication is
>  Michal> done through jtag. I really don't know how fast xilinx can communicate
>  Michal> with mdm.
> 
> Ok, does behaviour change if you set the kernel baudrate to something
> really low (300bps or so)? Also don't forget to adjust your getty
> settings!
> 


-- 
Michal Simek, Ing. (M.Eng)
w: www.monstr.eu p: +42-0-721842854
Maintainer of Linux kernel 2.6 Microblaze Linux - http://www.monstr.eu/fdt/
Microblaze U-BOOT custodian
--
To unsubscribe from this list: send the line "unsubscribe linux-serial" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: Uartlite - ulite_transmit

[Michal Simek]

Hi Peter,

sorry for delay. I had to look at another issue.

Below is full log:
1. I setup baudrate to 50. (It could be possible to set it up to 0 too)
That's why I think that doesn't matter what baudrate is setup.

2. You see where ulite_startup is called. It is called only once.

3. You see that there is no call __uart_wait_until_sent(). It could be 
called for ASYNC mode. The second thing is __uart_wait_until_sent 
function is checking if tx fifo is empty not circ buffer is empty.

4. Next thing is that in uart_close. port->count is 2 which means that
the executing path is
	if (port->count) {
		spin_unlock_irqrestore(&port->lock, flags);
		goto done;
	}
which means that there is no chance to call __uart_wait_until_sent 
function anyway.

5. I did one modification to add simple while loop till circ buffer is 
empty to the same location to see what happen (timouts are bogus values).

if (port->count) {
	spin_unlock_irqrestore(&port->lock, flags);
	printk("************ %x %x\n", (&uport->state->xmit)->tail, 
(&uport->state->xmit)->head);
	while (!uart_circ_empty(&uport->state->xmit)) {
		msleep_interruptible(jiffies_to_msecs((uport->timeout - HZ/50)));
		if (signal_pending(current))
			break;
		if (time_after(jiffies, jiffies + uport->timeout))
			break;
	}
	printk("************\n");
	goto done;
}

Here is log: (Between **** you can see what chars are not printed)

NET: Registered protocol family 17
uart_open(0) called
ulite_startup ------------------------
Freeing unused kernel memory: 11235k freed
Mounting proc:
Mounting var:
Populating /var:
Running local start scripts.
Mounting sysfs:
mdev: initialising /dev
Mounting /etc/config:
Populating /etc/config:
flatfsd: Created 8 configuration files (168 bytes)
Mounting denet eth0: Promiscuous mode disabled.
vpts:
Setting hostname:
Bringing up network interfaces:
udhcpc (v1.14.3) started
Sending discover...
Sending seuart_open(0) called
lect for 192.168uart_close(0) called, port->count 2
************ 172 362
.0.100...
Lease of 192.168.0.100 obtained, lease time 7200
adding dns 172.16.0.5
adding dns 172.16.10.1
Starting portmap:

Welcome to
  _____       _           _      _
| ___ \     | |         | |    (_)
| |_/ / ___ | |_   __ _ | |     _  _ __   _   _ __  __
|  __/ / _ \| __| / _` || |    | || '_ \ | | | |\ \/ /
| |   |  __/| |_ | (_| || |____| || | | || |_| | >  <
\_|    \___| \__| \__,_|\_____/|_||_| |_| \__,_|/_/\_\

on Xilinx-SP605-LTP-full-WB-pc-msr-next-22-watch-wt-mdm

************
uart_open(0) called
uart_flush_buffer(0) called

Xilinx-SP605-LTP-full-WB-pc-msr-next-22-watch-wt-mdm login:



I think that will be good to check if circ buffer is empty. As you 
suggest uart_close function will be probably the best place.

Any other suggestion?

Thanks,
Michal




Full log with debug messages:

Linux version 2.6.37-00014-g85eb775-dirty (monstr@monstr.eu) (gcc 
version 4.1.2) #15 Sun Jan 16 08:43:08 CET 2011
less 8
setup_cpuinfo: initialising
setup_cpuinfo: Using full CPU PVR support
cache: wt_msr_noirq
setup_memory: max_mapnr: 0x8000
setup_memory: min_low_pfn: 0x48000
setup_memory: max_low_pfn: 0x50000
On node 0 totalpages: 32768
free_area_init_node: node 0, pgdat c029f0b8, node_mem_map c0dab000
   Normal zone: 256 pages used for memmap
   Normal zone: 0 pages reserved
   Normal zone: 32512 pages, LIFO batch:7
pcpu-alloc: s0 r0 d32768 u32768 alloc=1*32768
pcpu-alloc: [0] 0
Built 1 zonelists in Zone order, mobility grouping on.  Total pages: 32512
Kernel command line: console=ttyUL0,50
PID hash table entries: 512 (order: -1, 2048 bytes)
Dentry cache hash table entries: 16384 (order: 4, 65536 bytes)
Inode-cache hash table entries: 8192 (order: 3, 32768 bytes)
Memory: 115776k/131072k available
NR_IRQS:32
xlnx,xps-intc-1.00.a #0 at 0xc8000000, num_irq=8, edge=0x93
xlnx,xps-timer-1.00.a #0 at 0xc8004000, irq=4
microblaze_timer_set_mode: shutdown
microblaze_timer_set_mode: periodic
Calibrating delay loop... 43.90 BogoMIPS (lpj=87808)
pid_max: default: 32768 minimum: 301
Mount-cache hash table entries: 512
NET: Registered protocol family 16
bio: create slab <bio-0> at 0
Switching to clocksource microblaze_clocksource
microblaze_timer_set_mode: oneshot
NET: Registered protocol family 2
IP route cache hash table entries: 1024 (order: 0, 4096 bytes)
TCP established hash table entries: 4096 (order: 3, 32768 bytes)
TCP bind hash table entries: 4096 (order: 2, 16384 bytes)
TCP: Hash tables configured (established 4096 bind 4096)
TCP reno registered
UDP hash table entries: 256 (order: 0, 4096 bytes)
UDP-Lite hash table entries: 256 (order: 0, 4096 bytes)
NET: Registered protocol family 1
RPC: Registered udp transport module.
RPC: Registered tcp transport module.
RPC: Registered tcp NFSv4.1 backchannel transport module.
Skipping unavailable RESET gpio -2 (reset)
GPIO pin is already allocated
JFFS2 version 2.2. (NAND) (SUMMARY)  © 2001-2006 Red Hat, Inc.
Block layer SCSI generic (bsg) driver version 0.4 loaded (major 254)
io scheduler noop registered
io scheduler deadline registered
io scheduler cfq registered (default)
84400000.debug: ttyUL0 at MMIO 0x84400000 (irq = 7) is a uartlite
console [ttyUL0] enabled
Xilinx SystemACE device driver, major=254
86000000.flash: Found 1 x16 devices at 0x0 in 16-bit bank. Manufacturer 
ID 0x000089 Chip ID 0x008919
Intel/Sharp Extended Query Table at 0x010A
Intel/Sharp Extended Query Table at 0x010A
Intel/Sharp Extended Query Table at 0x010A
Intel/Sharp Extended Query Table at 0x010A
Intel/Sharp Extended Query Table at 0x010A
Using buffer write method
Using auto-unlock on power-up/resume
cfi_cmdset_0001: Erase suspend on write enabled
erase region 0: offset=0x0,size=0x20000,blocks=255
erase region 1: offset=0x1fe0000,size=0x8000,blocks=4
RedBoot partition parsing not available
Creating 6 MTD partitions on "86000000.flash":
0x000000000000-0x000000100000 : "fpga"
0x000000100000-0x000000140000 : "boot"
0x000000140000-0x000000160000 : "bootenv"
0x000000160000-0x000000180000 : "config"
0x000000180000-0x000000b80000 : "image"
0x000000b80000-0x000002000000 : "spare"
Xilinx TEMAC MDIO: probed
eth0: Dropping NETIF_F_SG since no checksum feature.
TCP cubic registered
NET: Registered protocol family 17
uart_open(0) called
ulite_startup ------------------------
Freeing unused kernel memory: 11235k freed
Mounting proc:
Mounting var:
Populating /var:
Running local start scripts.
Mounting sysfs:
mdev: initialising /dev
Mounting /etc/config:
Populating /etc/config:
flatfsd: Created 8 configuration files (168 bytes)
Mounting devpnet eth0: Promiscuous mode disabled.
ts:
Setting hostname:
Bringing up network interfaces:
udhcpc (v1.14.3) started
Sending discover...
Sending seluart_open(0) called
ect for 192.168.uart_close(0) called
uart_open(0) called
uart_flush_buffer(0) called

Xilinx-SP605-LTP-full-WB-pc-msr-next-22-watch-wt-mdm login:




Peter Korsgaard wrote:
>>>>>> "Michal" == Michal Simek <monstr@monstr.eu> writes:
> 
> Hi,
> 
>  Michal> The point is that clearing is called but there are still some
>  Michal> characters which are not printed. If you call that clearing you
>  Michal> just lost the part of log.
> 
> Yes, but it shouldn't happen as __uart_wait_until_sent() is called
> first.
> 
>  >> What is the problem here? Is it that the uart gets closed and reopened
>  >> (which causes ulite_startup() to get called)
>  Michal>  while there's still data in
>  >> the uarts internal tx fifo (which then gets discarded)
> 
>  Michal> No data in internal tx fifo are not discarded.
> 
> It is if ulite_startup is called.
> 
>  Michal> , or is it that
>  >> there's still data in the sw xmit circular buffer that isn't sent to the
>  >> hardware yet?
> 
>  Michal> yes, data are in the circ buffer head and tail are correctly setup and
>  Michal> because sending is slow that circ buffer clearing is called and head
>  Michal> and tail is zeroed.
>  Michal> I think the best solution will be to wait if head/tail is not the same
>  Michal> value which means there is data in circ buffer. Not sure if driver can
>  Michal> do anything with it or if there is any way how to delay buffer
>  Michal> clearing in the driver.
> 
> I don't know much of the details of serial_core, but I believe
> uart_close (and hence uart_circ_clear) is only called when all
> characters in the circular buffer have been sent. What still might not
> be sent is any data in the uart TX fifo, but __uart_wait_until_sent()
> should handle that if you provide correct baudrate.
> 
>  >> What baudrate is your hardware running at?  What baudrate have you
>  >> configured the kernel to use? Even though the uartlite itself doesn't do
>  >> anything with the baudrate setting (E.G. it is fixed in hardware), the
>  >> baudrate is used by the kernel to calculate timeouts (E.G. in
>  >> __uart_wait_until_sent and similar).
> 
>  Michal> It is the same style. You can't even setup baudrate in EDK. There is
>  Michal> no hardware connection through serial line. The whole communication is
>  Michal> done through jtag. I really don't know how fast xilinx can communicate
>  Michal> with mdm.
> 
> Ok, does behaviour change if you set the kernel baudrate to something
> really low (300bps or so)? Also don't forget to adjust your getty
> settings!
> 


-- 
Michal Simek, Ing. (M.Eng)
w: www.monstr.eu p: +42-0-721842854
Maintainer of Linux kernel 2.6 Microblaze Linux - http://www.monstr.eu/fdt/
Microblaze U-BOOT custodian

Re: Uartlite - ulite_transmit

[Peter Korsgaard]

>>>>> "Michal" == Michal Simek <monstr@monstr.eu> writes:

Hi,

 Michal> Hi Peter,
 Michal> sorry for delay. I had to look at another issue.

No problem.

 Michal> Below is full log:
 Michal> 1. I setup baudrate to 50. (It could be possible to set it up to 0 too)
 Michal> That's why I think that doesn't matter what baudrate is setup.

 Michal> 2. You see where ulite_startup is called. It is called only once.

Ok, good.

 Michal> 3. You see that there is no call __uart_wait_until_sent(). It could be
 Michal> called for ASYNC mode. The second thing is __uart_wait_until_sent
 Michal> function is checking if tx fifo is empty not circ buffer is empty.

Yes, that's afaik what that function should do.

 Michal> 4. Next thing is that in uart_close. port->count is 2 which means that
 Michal> the executing path is
 Michal> 	if (port->count) {
 Michal> 		spin_unlock_irqrestore(&port->lock, flags);
 Michal> 		goto done;
 Michal> 	}
 Michal> which means that there is no chance to call __uart_wait_until_sent
 Michal> function anyway.

And no buffer flushing, so that's fine.

 Michal> 5. I did one modification to add simple while loop till circ buffer is
 Michal> empty to the same location to see what happen (timouts are bogus
 Michal> values).

 Michal> if (port->count) {
 Michal> 	spin_unlock_irqrestore(&port->lock, flags);
 Michal> 	printk("************ %x %x\n", (&uport->state->xmit)->tail,
 Michal> (&uport->state->xmit)->head);
 Michal> 	while (!uart_circ_empty(&uport->state->xmit)) {
 Michal> 		msleep_interruptible(jiffies_to_msecs((uport->timeout - HZ/50)));
 Michal> 		if (signal_pending(current))
 Michal> 			break;
 Michal> 		if (time_after(jiffies, jiffies + uport->timeout))
 Michal> 			break;
 Michal> 	}
 Michal> 	printk("************\n");
 Michal> 	goto done;
 Michal> }

Ok, so this shows that there's still data in the circular buffer when
uart is closed, like expected.

For me, it all looks normal:

1. serial port gets opened, uart_open -> uart_startup -> ulite_startup
   gets called, ASYNC_INITIALIZED gets set, circular buffer and hardware
   TX fifo cleared.

2. Some time later serial port gets opened again, and uart_startup is a
   NOP because ASYNC_INITIALIZED is set. No circular buffer / hw fifo
   clear.

3. serial port gets closed, uart_close is a NOP because port->count > 0

4. serial port gets opened again, NOP like in 2.

The problem is the uart_flush_buffer() call we see after uart_open() in
4. If doesn't seem to come from serial_core (only called from uart_close
/ uart_hangup), so presumably it comes from the TTY core or
userspace. Could you add a bit more debug to figure out where exactly it
comes from?

 Michal> ************
 Michal> uart_open(0) called
 Michal> uart_flush_buffer(0) called

-- 
Bye, Peter Korsgaard

Re: Uartlite - ulite_transmit

[Michal Simek]

Peter Korsgaard wrote:
>>>>>> "Michal" == Michal Simek <monstr@monstr.eu> writes:
> 
> Hi,
> 
>  Michal> Hi Peter,
>  Michal> sorry for delay. I had to look at another issue.
> 
> No problem.
> 
>  Michal> Below is full log:
>  Michal> 1. I setup baudrate to 50. (It could be possible to set it up to 0 too)
>  Michal> That's why I think that doesn't matter what baudrate is setup.
> 
>  Michal> 2. You see where ulite_startup is called. It is called only once.
> 
> Ok, good.
> 
>  Michal> 3. You see that there is no call __uart_wait_until_sent(). It could be
>  Michal> called for ASYNC mode. The second thing is __uart_wait_until_sent
>  Michal> function is checking if tx fifo is empty not circ buffer is empty.
> 
> Yes, that's afaik what that function should do.
> 
>  Michal> 4. Next thing is that in uart_close. port->count is 2 which means that
>  Michal> the executing path is
>  Michal> 	if (port->count) {
>  Michal> 		spin_unlock_irqrestore(&port->lock, flags);
>  Michal> 		goto done;
>  Michal> 	}
>  Michal> which means that there is no chance to call __uart_wait_until_sent
>  Michal> function anyway.
> 
> And no buffer flushing, so that's fine.
> 
>  Michal> 5. I did one modification to add simple while loop till circ buffer is
>  Michal> empty to the same location to see what happen (timouts are bogus
>  Michal> values).
> 
>  Michal> if (port->count) {
>  Michal> 	spin_unlock_irqrestore(&port->lock, flags);
>  Michal> 	printk("************ %x %x\n", (&uport->state->xmit)->tail,
>  Michal> (&uport->state->xmit)->head);
>  Michal> 	while (!uart_circ_empty(&uport->state->xmit)) {
>  Michal> 		msleep_interruptible(jiffies_to_msecs((uport->timeout - HZ/50)));
>  Michal> 		if (signal_pending(current))
>  Michal> 			break;
>  Michal> 		if (time_after(jiffies, jiffies + uport->timeout))
>  Michal> 			break;
>  Michal> 	}
>  Michal> 	printk("************\n");
>  Michal> 	goto done;
>  Michal> }
> 
> Ok, so this shows that there's still data in the circular buffer when
> uart is closed, like expected.
> 
> For me, it all looks normal:
> 
> 1. serial port gets opened, uart_open -> uart_startup -> ulite_startup
>    gets called, ASYNC_INITIALIZED gets set, circular buffer and hardware
>    TX fifo cleared.

But ASYNC_INITIALIZED is not set.

> 
> 2. Some time later serial port gets opened again, and uart_startup is a
>    NOP because ASYNC_INITIALIZED is set. No circular buffer / hw fifo
>    clear.
> 
> 3. serial port gets closed, uart_close is a NOP because port->count > 0
> 
> 4. serial port gets opened again, NOP like in 2.
> 
> The problem is the uart_flush_buffer() call we see after uart_open() in
> 4. If doesn't seem to come from serial_core (only called from uart_close
> / uart_hangup), so presumably it comes from the TTY core or
> userspace. Could you add a bit more debug to figure out where exactly it
> comes from?

ok. will do.

Thanks,
Michal

> 
>  Michal> ************
>  Michal> uart_open(0) called
>  Michal> uart_flush_buffer(0) called
> 


-- 
Michal Simek, Ing. (M.Eng)
w: www.monstr.eu p: +42-0-721842854
Maintainer of Linux kernel 2.6 Microblaze Linux - http://www.monstr.eu/fdt/
Microblaze U-BOOT custodian

Re: Uartlite - ulite_transmit

[Michal Simek]

Peter Korsgaard wrote:
>>>>>> "Michal" == Michal Simek <monstr@monstr.eu> writes:
> 
> Hi,
> 
>  Michal> Hi Peter,
>  Michal> sorry for delay. I had to look at another issue.
> 
> No problem.
> 
>  Michal> Below is full log:
>  Michal> 1. I setup baudrate to 50. (It could be possible to set it up to 0 too)
>  Michal> That's why I think that doesn't matter what baudrate is setup.
> 
>  Michal> 2. You see where ulite_startup is called. It is called only once.
> 
> Ok, good.
> 
>  Michal> 3. You see that there is no call __uart_wait_until_sent(). It could be
>  Michal> called for ASYNC mode. The second thing is __uart_wait_until_sent
>  Michal> function is checking if tx fifo is empty not circ buffer is empty.
> 
> Yes, that's afaik what that function should do.
> 
>  Michal> 4. Next thing is that in uart_close. port->count is 2 which means that
>  Michal> the executing path is
>  Michal> 	if (port->count) {
>  Michal> 		spin_unlock_irqrestore(&port->lock, flags);
>  Michal> 		goto done;
>  Michal> 	}
>  Michal> which means that there is no chance to call __uart_wait_until_sent
>  Michal> function anyway.
> 
> And no buffer flushing, so that's fine.
> 
>  Michal> 5. I did one modification to add simple while loop till circ buffer is
>  Michal> empty to the same location to see what happen (timouts are bogus
>  Michal> values).
> 
>  Michal> if (port->count) {
>  Michal> 	spin_unlock_irqrestore(&port->lock, flags);
>  Michal> 	printk("************ %x %x\n", (&uport->state->xmit)->tail,
>  Michal> (&uport->state->xmit)->head);
>  Michal> 	while (!uart_circ_empty(&uport->state->xmit)) {
>  Michal> 		msleep_interruptible(jiffies_to_msecs((uport->timeout - HZ/50)));
>  Michal> 		if (signal_pending(current))
>  Michal> 			break;
>  Michal> 		if (time_after(jiffies, jiffies + uport->timeout))
>  Michal> 			break;
>  Michal> 	}
>  Michal> 	printk("************\n");
>  Michal> 	goto done;
>  Michal> }
> 
> Ok, so this shows that there's still data in the circular buffer when
> uart is closed, like expected.
> 
> For me, it all looks normal:
> 
> 1. serial port gets opened, uart_open -> uart_startup -> ulite_startup
>    gets called, ASYNC_INITIALIZED gets set, circular buffer and hardware
>    TX fifo cleared.
> 
> 2. Some time later serial port gets opened again, and uart_startup is a
>    NOP because ASYNC_INITIALIZED is set. No circular buffer / hw fifo
>    clear.
> 
> 3. serial port gets closed, uart_close is a NOP because port->count > 0
> 
> 4. serial port gets opened again, NOP like in 2.
> 
> The problem is the uart_flush_buffer() call we see after uart_open() in
> 4. If doesn't seem to come from serial_core (only called from uart_close
> / uart_hangup), so presumably it comes from the TTY core or
> userspace. Could you add a bit more debug to figure out where exactly it
> comes from?

Last week I have also implemented simple ioctl function for uartlite - 
just printk to see what happen. Look at the second log below.



If there is defined uartlite ioctl function (but always returns 
-ENOIOCTLCMD)

Sending select for 192.168.0.100...
Lease of 192.168.0.100 obtaulite_ioctl 5401 bf9b1ed8
n_tty_ioctl
ined, lease time 7200
adding dns 172.16.0.5
adding dns 172.16.10.1
Stuart_open(0) called
arting portmap:

Welcome to
  ulite_ioctl 5401 bf9f8a8c
n_tty_ioctl
ulite_ioctl 5402 bf9f8a70
n_tty_ioctl
_____       _   uart_close(0) called, port->count 2
************ 210 362
         _      _
| ___ \     | |         | |    (_)
| |_/ / ___ | |_   __ _ | |     _  _ __   _   _ __  __
|  __/ / _ \| __| / _` || |    | || '_ \ | | | |\ \/ /
| |   |  __/| |_ | (_| || |____| || | | || |_| | >  <
\_|    \___| \__| \__,_|\_____/|_||_| |_| \__,_|/_/\_\

on Xilinx-SP605-LTP-full-WB-pc-msr-next-22-watch-wt-mdm

************
uart_open(0) called
ulite_ioctl 5401 bff76a18
n_tty_ioctl
ulite_ioctl 540b 2
n_tty_ioctl
n_tty_ioctl_helper TCFLSH
tty_perform_flush TCIOFLUSH
tty_perform_flush TCOFLUSH
tty_driver_flush_buffer
uart_flush_buffer(0) called
ulite_ioctl 5402 bff769a4
n_tty_ioctl
ulite_ioctl 540b 0
n_tty_ioctl
n_tty_ioctl_helper TCFLSH
tty_perform_flush TCIFLUSH
ulite_ioctl 5401 bff76558
n_tty_ioctl

Xilinx-SP605-LTP-full-WB-pc-msr-next-22-watch-wt-mdm login:


If uarlite ioctl is defined: (cases: TCFLSH, TCGETS, TCSETS) - return 0;
It is interested but maybe implement that function could be enough. What 
do you think?

Thanks,
Michal


NET: Registered protocol family 17
uart_open(0) called
ulite_startup ------------------------
Freeing unused kernel memory: 11218k freed
ulite_ioctl 5600 bf9d1bc8
n_tty_ioctl
ulite_ioctl TCGETS bf9d1b1c
ulite_ioctl TCSETS bf9d1b00
ulite_ioctl TCGETS bf9d1a8c
ulite_ioctl TCSETS bf9d1a70
ulite_ioctl TCGETS bff204d0
Mounting proc:
Mounting var:
Populatinulite_ioctl TCGETS bfd8b4c0
g /var:
Runningulite_ioctl TCGETS bf87e4c0
  local start scripts.
Mounting sysfs:
mdev: initialising /dev
ulite_ioctl TCGETS bf8164c0
Mounting /etc/config:
Populating /etc/culite_ioctl TCGETS bf95a4c0
onfig:
flatfsd:ulite_ioctl TCGETS bf9744c0
  Created 8 configulite_ioctl TCGETS bf9434c0
uration files (168 bytes)
Mounting devpts:
Setting hostname:
Bringing up network interfaces:
net eth0: Promiscuous mode disabled.
udhcpc (v1.14.3) started
Sending discover...
Sending select for 192.168.0.100...
Lease of 192.168.0.100 obtaulite_ioctl TCGETS bfa3bed8
ined, lease time 7200
adding dns 172.16.0.5
adding uart_open(0) called
ulite_ioctl TCGETS bf9d1a8c
ulite_ioctl TCSETS bf9d1a70
uart_close(0) called, port->count 2
************ 1dd 362

Starting portmap:

Welcome to
  _____       _           _      _
| ___ \     | |         | |    (_)
| |_/ / ___ | |_   __ _ | |     _  _ __   _   _ __  __
|  __/ / _ \| __| / _` || |    | || '_ \ | | | |\ \/ /
| |   |  __/| |_ | (_| || |____| || | | || |_| | >  <
\_|    \___| \__| \__,_|\_____/|_||_| |_| \__,_|/_/\_\

on Xilinx-SP605-LTP-full-WB-pc-msr-next-22-watch-wt-mdm

************
uart_open(0) called
ulite_ioctl TCGETS bfd98a18
ulite_ioctl TCFLSH 2
ulite_ioctl TCSETS bfd989a4
ulite_ioctl TCFLSH 0
ulite_ioctl TCGETS bfd98558

Xilinx-SP605-LTP-full-WB-pc-msr-next-22-watch-wt-mdm login:


-- 
Michal Simek, Ing. (M.Eng)
w: www.monstr.eu p: +42-0-721842854
Maintainer of Linux kernel 2.6 Microblaze Linux - http://www.monstr.eu/fdt/
Microblaze U-BOOT custodian

Re: Uartlite - ulite_transmit

[Peter Korsgaard]

>>>>> "Michal" == Michal Simek <monstr@monstr.eu> writes:

Hi,

 >> The problem is the uart_flush_buffer() call we see after uart_open() in
 >> 4. If doesn't seem to come from serial_core (only called from uart_close
 >> / uart_hangup), so presumably it comes from the TTY core or
 >> userspace. Could you add a bit more debug to figure out where exactly it
 >> comes from?

 Michal> Last week I have also implemented simple ioctl function for
 Michal> uartlite - just printk to see what happen. Look at the second
 Michal> log below.

 Michal> uart_open(0) called
 Michal> ulite_ioctl 5401 bff76a18
 Michal> n_tty_ioctl
 Michal> ulite_ioctl 540b 2
 Michal> n_tty_ioctl
 Michal> n_tty_ioctl_helper TCFLSH
 Michal> tty_perform_flush TCIOFLUSH
 Michal> tty_perform_flush TCOFLUSH
 Michal> tty_driver_flush_buffer
 Michal> uart_flush_buffer(0) called

So your userspace is calling tcflush, and serial_core responds by
flushing (dropping) the buffer. That seems like expected behaviour to
me.

This is presumably from the busybox getty applet, which does:

static void termios_init(struct termios *tp, int speed, struct options *op)
{
	speed_t ispeed, ospeed;
	/*
	 * Initial termios settings: 8-bit characters, raw-mode, blocking i/o.
	 * Special characters are set after we have read the login name; all
	 * reads will be done in raw mode anyway. Errors will be dealt with
	 * later on.
	 */
	/* flush input and output queues, important for modems! */
	tcflush(0, TCIOFLUSH);

You could change that to a tcdrain() if that's not what you want.

-- 
Bye, Peter Korsgaard

Re: Uartlite - ulite_transmit

[Michal Simek]

Hi Peter,

> Hi,
> 
>  >> The problem is the uart_flush_buffer() call we see after uart_open() in
>  >> 4. If doesn't seem to come from serial_core (only called from uart_close
>  >> / uart_hangup), so presumably it comes from the TTY core or
>  >> userspace. Could you add a bit more debug to figure out where exactly it
>  >> comes from?
> 
>  Michal> Last week I have also implemented simple ioctl function for
>  Michal> uartlite - just printk to see what happen. Look at the second
>  Michal> log below.
> 
>  Michal> uart_open(0) called
>  Michal> ulite_ioctl 5401 bff76a18
>  Michal> n_tty_ioctl
>  Michal> ulite_ioctl 540b 2
>  Michal> n_tty_ioctl
>  Michal> n_tty_ioctl_helper TCFLSH
>  Michal> tty_perform_flush TCIOFLUSH
>  Michal> tty_perform_flush TCOFLUSH
>  Michal> tty_driver_flush_buffer
>  Michal> uart_flush_buffer(0) called
> 
> So your userspace is calling tcflush, and serial_core responds by
> flushing (dropping) the buffer. That seems like expected behaviour to
> me.
> 
> This is presumably from the busybox getty applet, which does:
> 
> static void termios_init(struct termios *tp, int speed, struct options *op)
> {
> 	speed_t ispeed, ospeed;
> 	/*
> 	 * Initial termios settings: 8-bit characters, raw-mode, blocking i/o.
> 	 * Special characters are set after we have read the login name; all
> 	 * reads will be done in raw mode anyway. Errors will be dealt with
> 	 * later on.
> 	 */
> 	/* flush input and output queues, important for modems! */
> 	tcflush(0, TCIOFLUSH);
> 
> You could change that to a tcdrain() if that's not what you want.
> 

Great that's work. Just for the record it is tcdrain(STDOUT_FILENO);
Patch against busybox 1.14.3 version is below. Maybe worth to added it 
mainline busybox.

Thanks for your big help.
Michal


diff --git 
a/software/petalinux-dist/user/busybox/busybox-1.14.3/loginutils/getty.c 
b/software/petalinux-dist/user/busybox/busybo
index 24a182f..4c99e92 100644
--- a/software/petalinux-dist/user/busybox/busybox-1.14.3/loginutils/getty.c
+++ b/software/petalinux-dist/user/busybox/busybox-1.14.3/loginutils/getty.c
@@ -279,6 +279,8 @@ static void termios_init(struct termios *tp, int 
speed, struct options *op)
          * later on.
          */
  #ifdef __linux__
+       /* wait until all output written to the stdout has been 
transmitted */
+       tcdrain(STDOUT_FILENO);
         /* flush input and output queues, important for modems! */
         ioctl(0, TCFLSH, TCIOFLUSH); /* tcflush(0, TCIOFLUSH)? - same */
  #endif


-- 
Michal Simek, Ing. (M.Eng)
w: www.monstr.eu p: +42-0-721842854
Maintainer of Linux kernel 2.6 Microblaze Linux - http://www.monstr.eu/fdt/
Microblaze U-BOOT custodian

Re: Uartlite - ulite_transmit

[Peter Korsgaard]

>>>>> "Michal" == Michal Simek <monstr@monstr.eu> writes:

Hi,

 >> /* flush input and output queues, important for modems! */
 >> tcflush(0, TCIOFLUSH);
 >> 
 >> You could change that to a tcdrain() if that's not what you want.
 >> 

 Michal> Great that's work. Just for the record it is tcdrain(STDOUT_FILENO);

Yes. Notice that the code has changed a bit in busybox git (but same
functionality).

 Michal> Patch against busybox 1.14.3 version is below. Maybe worth to
 Michal> added it mainline busybox.

Yes, please bring it up with the busybox devs.

 Michal> Thanks for your big help.

You're welcome.

-- 
Bye, Peter Korsgaard

Re: Uartlite - ulite_transmit

[Michal Simek]

Peter Korsgaard wrote:
>>>>>> "Michal" == Michal Simek <monstr@monstr.eu> writes:
> 
> Hi,
> 
>  >> /* flush input and output queues, important for modems! */
>  >> tcflush(0, TCIOFLUSH);
>  >> 
>  >> You could change that to a tcdrain() if that's not what you want.
>  >> 
> 
>  Michal> Great that's work. Just for the record it is tcdrain(STDOUT_FILENO);
> 
> Yes. Notice that the code has changed a bit in busybox git (but same
> functionality).
> 
>  Michal> Patch against busybox 1.14.3 version is below. Maybe worth to
>  Michal> added it mainline busybox.
> 
> Yes, please bring it up with the busybox devs.
> 
>  Michal> Thanks for your big help.
> 
> You're welcome.

Will do in a sec. I will CC you too.

Thanks,
Michal

-- 
Michal Simek, Ing. (M.Eng)
w: www.monstr.eu p: +42-0-721842854
Maintainer of Linux kernel 2.6 Microblaze Linux - http://www.monstr.eu/fdt/
Microblaze U-BOOT custodian

Re: Uartlite - ulite_transmit

[Peter Korsgaard]

>>>>> "Michal" == Michal Simek <monstr@monstr.eu> writes:

Hi,

 Michal> I looked at that loop and I think that we should reread actual
 Michal> status before ulite_transmit because status reg can be changed
 Michal> when ulite_receive is executed. What do you think? (BTW: status
 Michal> reading can be moved directly to ulite_receive/transmit
 Michal> functions)

 Michal>     do {
 Michal>         int stat = ioread32be(port->membase + ULITE_STATUS);
 Michal>         busy  = ulite_receive(port, stat);
 Michal>         stat = ioread32be(port->membase + ULITE_STATUS); // check
 Michal> status again
 Michal>         busy |= ulite_transmit(port, stat);
 Michal>         n++;
 Michal>     } while (busy);

It shouldn't really matter - ulite_transmit() only looks at TXFULL, and
in the unlikely case where it was full but 1 character got transmitted
during ulite_receive, we will catch it during the 2nd iteration of the
loop (as busy will be true).

The logic was afaik more-or-less directly copied from 8250.c

 Michal> 1. Before fault happen:
 Michal> ISR is called, status is 0x18 (interrupt enabled, tx fifo full) just
 Michal> to ulite_transmit and detect TXFULL and return to ISR. Head and tail
 Michal> are correct
 Michal> 2. Broken part
 Michal> ISR is called, status is 0x14 (interrupt enabled, tx fifo empty), jump
 Michal> to ulite_transmit. Here I am printing (head and tail values are
 Michal> zero). Xmit buffer address is the same. Then uart_circ_empty(xmit)
 Michal> detects that head and tail are the same which means nothing to print.

 Michal> My question: Is there any part of the code which can change xmit head
 Michal> and tail values?

Yes, ulite_transmit does (for tail). head is only changed by the serial core.

 Michal> BTW: Getty is providing that login prompt. Could it be an issue with getty?

Maybe. Or the fact that it calls set_termios or similar. Are you unable
to reproduce the problem with other programs?

-- 
Bye, Peter Korsgaard