IOIO deadlocking on write?

[Travis Wyatt]

When having the IOIO read/write a lot of data (currently over UART and SPI) it eventually seems to deadlock. I continue to receive incoming data on UART but outgoing data over UART and the SPI writeRead get stuck in a wait(). This happens anywhere from 5-10 minutes of continually receiving data on the UART (while at the same time reading sensor data from an ADXL345). While all threads that want to write are waiting, my threads that receive data continue to receive data (are not deadlocked). I'm using IOIO0330.

Here is the stack trace on the thread that is trying to write UART data:

  at java.lang.Object.wait(Native Method)

  at java.lang.Object.wait(Object.java:358)

  at ioio.lib.impl.FlowControlledOutputStream.write(FlowControlledOutputStream.java:76)

  at java.io.OutputStream.write(OutputStream.java:120)

  at java.io.DataOutputStream.write(DataOutputStream.java:99)

  at java.io.FilterOutputStream.write(FilterOutputStream.java:105)

  at edu.sdsu.rocket.io.PacketOutputStream.writePacket(PacketOutputStream.java:42)

  at edu.sdsu.rocket.control.devices.SB70.writePacket(SB70.java:57)

  at edu.sdsu.rocket.io.PacketMultiplexer.writePacket(PacketMultiplexer.java:33)

  at edu.sdsu.rocket.io.PacketMultiplexer.write(PacketMultiplexer.java:24)

  at edu.sdsu.rocket.control.controllers.PacketController$FlushThread.run(PacketController.java:189)

  at java.lang.Thread.run(Thread.java:1019)

And then the stack trace of the thread that is trying to read my ADXL345 accelerometer:

  at java.lang.Object.wait(Native Method)

  at java.lang.Object.wait(Object.java:358)

  at ioio.lib.impl.SpiMasterImpl$SpiResult.waitReady(SpiMasterImpl.java:58)

  at ioio.lib.impl.SpiMasterImpl.writeRead(SpiMasterImpl.java:119)

  at ioio.lib.impl.SpiMasterImpl.writeRead(SpiMasterImpl.java:155)

  at edu.sdsu.rocket.control.devices.ADXL345.read(ADXL345.java:246)

  at edu.sdsu.rocket.control.devices.ADXL345.loop(ADXL345.java:272)

  at edu.sdsu.rocket.control.devices.DeviceRunnable.run(DeviceRunnable.java:20)

  at java.lang.Thread.run(Thread.java:1019)

The project is open source and can be found at:

https://github.com/twyatt/sdsu-rocket

I know having a snippet of code to test against would make this easier to debug but I was just hoping that maybe it was something obvious that I am overlooking. If needed, I'll try to put together code that reproduces the issue (outside of our project) but some of the setup of the project might be fairly unique to our setup (i.e. we are using a NetBurner SB70LC to transfer data to the IOIO's UART via ethernet).

Any help would be greatly appreciated.

-Travis

[Ytai Ben-Tsvi]

I don't think it is something obvious, so a small test is probably better.

Is this over BT or USB? If BT, try to see whether it's happening over USB as well?

It seems to be that data is getting dropped somewhere.

-Travis

--
You received this message because you are subscribed to the Google Groups "ioio-users" group.
To unsubscribe from this group and stop receiving emails from it, send an email to ioio-users+...@googlegroups.com.
To post to this group, send email to ioio-...@googlegroups.com.
Visit this group at http://groups.google.com/group/ioio-users.
For more options, visit https://groups.google.com/groups/opt_out.
 
 

[Travis Wyatt]

Thanks for the quick reply Ytai!

I was using bluetooth but I just tested it and the same issue occurs over USB.

I did some logging and think I found the cause (or at least one of the causes) of the issue, still trying to figure out how I would fix this?

In FlowControlledOutputStream.write(int) I added the following logging:

...

while (!closed_ && !queue_.offer((byte) oneByte)) {

    System.out.println("write(int) -> wait() with queue_.remainingCapacity() = " + queue_.remainingCapacity());

    wait();

}

...

And then in FlowControlledOutputStream.FlushThread.run() I added the following logging:

...

while (readyToSend_ == 0 || queue_.isEmpty()) {

    System.out.println("readyToSend_ = " + readyToSend_ + ", queue_.isEmpty() = " + queue_.isEmpty());

    FlowControlledOutputStream.this.wait();

}

...

My log then reads:

...

07-27 10:34:42.983: I/System.out(2785): readyToSend_ = 0, queue_.isEmpty() = false

07-27 10:34:42.983: I/System.out(2785): readyToSend_ = 0, queue_.isEmpty() = false

07-27 10:34:42.983: I/System.out(2785): readyToSend_ = 0, queue_.isEmpty() = false

07-27 10:34:42.983: I/System.out(2785): readyToSend_ = 192, queue_.isEmpty() = true

07-27 10:34:42.983: I/System.out(2785): readyToSend_ = 191, queue_.isEmpty() = true

07-27 10:34:42.983: I/System.out(2785): readyToSend_ = 190, queue_.isEmpty() = true

07-27 10:34:42.983: I/System.out(2785): readyToSend_ = 189, queue_.isEmpty() = true

07-27 10:34:42.983: I/System.out(2785): readyToSend_ = 188, queue_.isEmpty() = true

07-27 10:34:42.983: I/System.out(2785): readyToSend_ = 170, queue_.isEmpty() = true

07-27 10:34:43.003: I/System.out(2785): readyToSend_ = 0, queue_.isEmpty() = false

07-27 10:34:43.003: I/System.out(2785): readyToSend_ = 0, queue_.isEmpty() = false

07-27 10:34:43.003: I/System.out(2785): readyToSend_ = 0, queue_.isEmpty() = false

07-27 10:34:43.003: I/System.out(2785): readyToSend_ = 0, queue_.isEmpty() = false

07-27 10:34:43.003: I/System.out(2785): write(int) -> wait() with queue_.remainingCapacity() = 0

After the write(int) wait() call it seems all write ops are deadlocked. From the logging it seems this only occurs if the write(int) is called when readyToSend_ = 0 and the queue_ is full.

-Travis

[Ytai Ben-Tsvi]

You're going in the right direction I think.

Instrument readyToSend() (number of bytes we got permission from the IOIO to send) and line 118 or so (number of bytes that we've just removed from the Java queue and wrote to the IOIO).

BTW, the IOIO buffer is 256B large, it is strange that you never got that, but then again I'm not sure whether you sent all the logs or just a snippet.

[Travis Wyatt]

I'm still trying to track this down but I have found that if I don't read from my ADXL345 accelerometer (over SPI) and instead respond w/ zeros (instead of the read data) over UART that it never deadlocks, only when reading/writing UART and SPI. Not sure if I'm doing something strange that is causing the deadlock by using SPI at the same time.

And yes, the logs were just a snippet; the bytesToSend fluctuate between 0 and 256.

Let me know if you have any other tips of things I could try, otherwise I will keep poking at this.

Thanks again,

Travis

[Travis Wyatt]

I've pulled out a bunch of code from our project to have a small test project (with just a hand full of classes) and the problem continues to occur.

I'll attach the test code but unfortunately it still receives the UART data from a NetBurner SB70 LC so it would be hard for you to run it and reproduce the error, unless you have another device that could send out UART to the IOIO for testing?

Or perhaps there would be a way to simulate the queue filling up while writing to UART and SPI?

I'll continue to try and test the issue but I feel this problem is reaching beyond the scope of my understanding so it may take me a very long time to figure this one out; any further help with the issue would be greatly appreciated.

Thanks so much Ytai!

-Travis

[Travis Wyatt]

Alright, I'm not sure if I've been just looking at this too long and am now completely off base but...

Could it be a firmware issue? As it does seem that the thread is waiting for readyToSend_ to != 0 (as it should) and readyToSend(int) is not being called. So I added logging to IOIOProtocol:

(around line 630 of IOIOProtocol.java)

...

  byte[] data = new byte[256];

  try {

    while (true) {

      arg1 = readByte();

      System.out.println("IOIO: " + arg1);

      switch (arg1) {

      case ESTABLISH_CONNECTION:

...

At first when I'm receiving/sending UART data and querying the ADXL345 accelerometer over SPI the logs read a variety of arg1:

...

07-28 20:43:32.714: I/System.out(896): IOIO: 14

07-28 20:43:32.714: I/System.out(896): ioio.lib.impl.FlowControlledOutputStream$FlushThread: wait(): readyToSend_ = 0, queue_.remainingCapacity() = 987

07-28 20:43:32.714: I/System.out(896): IOIO: 17

07-28 20:43:32.714: I/System.out(896): ioio.lib.impl.FlowControlledOutputStream$FlushThread: wait(): readyToSend_ = 0, queue_.remainingCapacity() = 964

07-28 20:43:32.714: I/System.out(896): ioio.lib.impl.FlowControlledOutputStream$FlushThread: wait(): readyToSend_ = 0, queue_.remainingCapacity() = 941

07-28 20:43:32.714: I/System.out(896): IOIO: 14

07-28 20:43:32.714: I/System.out(896): IOIO: 14

07-28 20:43:32.714: I/System.out(896): IOIO: 15

07-28 20:43:32.714: I/System.out(896): readyToSend_ = 129

07-28 20:43:32.724: I/System.out(896): ioio.lib.impl.FlowControlledOutputStream$FlushThread: wait(): readyToSend_ = 46, queue_.remainingCapacity() = 1024

07-28 20:43:32.724: I/System.out(896): IOIO: 14

...

07-28 20:43:32.734: I/System.out(896): IOIO: 14

07-28 20:43:32.734: I/System.out(896): ioio.lib.impl.FlowControlledOutputStream$FlushThread: wait(): readyToSend_ = 23, queue_.remainingCapacity() = 1024

07-28 20:43:32.734: I/System.out(896): IOIO: 14

07-28 20:43:32.734: I/System.out(896): IOIO: 15

07-28 20:43:32.734: I/System.out(896): readyToSend_ = 132

07-28 20:43:32.734: I/System.out(896): IOIO: 14

07-28 20:43:32.734: I/System.out(896): ioio.lib.impl.FlowControlledOutputStream$FlushThread: wait(): readyToSend_ = 109, queue_.remainingCapacity() = 1024

07-28 20:43:32.744: I/System.out(896): IOIO: 14

07-28 20:43:32.744: I/System.out(896): IOIO: 14

...

07-28 20:43:32.744: I/System.out(896): IOIO: 14

07-28 20:43:32.744: I/System.out(896): ioio.lib.impl.FlowControlledOutputStream$FlushThread: wait(): readyToSend_ = 86, queue_.remainingCapacity() = 1024

07-28 20:43:32.754: I/System.out(896): IOIO: 14

07-28 20:43:32.754: I/System.out(896): IOIO: 14

07-28 20:43:32.754: I/System.out(896): IOIO: 17

07-28 20:43:32.754: I/System.out(896): IOIO: 14

07-28 20:43:32.754: I/System.out(896): IOIO: 14

...

But then when what I thought was the thread deadlocking (but now seems more to be the firmware not feeding us data) the logs read:

07-28 20:27:08.774: I/System.out(868): IOIO: 14

07-28 20:27:08.774: I/System.out(868): IOIO: 14

07-28 20:27:08.774: I/System.out(868): IOIO: 14

07-28 20:27:08.774: I/System.out(868): IOIO: 14

07-28 20:27:08.774: I/System.out(868): IOIO: 14

07-28 20:27:08.774: I/System.out(868): IOIO: 14

07-28 20:27:08.774: I/System.out(868): IOIO: 14

I only get 14 (which is UART_DATA). Which does show why I'm still able to receive data over UART but the SPI stops working and I can't send anything over UART. Is it time for me to start jumping into the firmware code to figure out what is going on?

Thanks,

Travis

[Ytai Ben-Tsvi]

It might very well be a firmware issue, but you picked a very inconvenient place (IMO) to tap into.

I would instrument FlowControlledOutputStream as suggested originally to get a better idea on what's happening.

The protocol parsing code is very simple and very unlikely to have such bugs in it. It is either that the firmware is dropping notifications or that the higher level of the software are treating them incorrectly.

The correlation with SPI here is pretty surprising, and suggests that perhaps the link get saturated or something similar.

Does each one (UART, SPI) work perfectly reliably otherwise?

[Travis Wyatt]

What exactly do you mean "instrument" FlowControlledOutputStream? I've been running the Android app using the "Debug As..." (from Eclipse) and then examining threads/variables when the lock occurs (just making sure that that is the right approach?).

The SPI and UART work reliably when I only run one at a time, but I'm not sure if it is specifically related to SPI or that I am just pushing too much data through the IOIO by having it run alongside the UART.

I'm sending around 4 bytes from a computer over ethernet to request sensor data from the phone/IOIO (via UART) and then responding with the sensor data (approx. 20 or so bytes back through UART). The setup runs fairly reliably when getting the sensor data at about 5 Hz or less but when I increase it to about 15 Hz or more then after about 10-30 seconds I can no longer send any data (be it UART or SPI) so everything seems to just hang and wait. I understand that I may be overloading it with data but I was just hoping it would just drop data and then when I lower the rate it should recover and continue to function, but when in the "locked" state I can lower the sensor requests to 1 Hz and I still won't be able to talk at all via the IOIO.

Later tomorrow I'll have a chance to hook up some more sensors (some SPI and some I2C) and see if I can pull sensor data at high frequencies (while not utilizing the UART) and see if I get the same locking issues.

Otherwise, is there anything else you might advise as to how I should further try to find the cause of the problem (something that I can check/do that would rule out or confirm that it is a firmware issue or a software issue, or something I am just doing absurdly wrong)?

And thanks for all your help Ytai!!

-Travis

[Ytai Ben-Tsvi]

By "instrument" I mean put logging instructions in places of interest.

The data rates you're talking about are extremely low. They shouldn't be a problem at all (even 1000 times as fast shouldn't I imagine...)

If I'm getting you right, the process of the data flow is:

1. Request comes in to the Android through the IOIO UART.
2. Android executes a SPI transaction.
3. Android sends the result of this transaction back over UART.

Is this right?

[Travis Wyatt]

That's close...

1. A thread is running per sensor (currently testing w/ a single ADXL345 accelerometer but will be testing with more sensors soon) and continually requesting sensor readings over IOIO SPI and storing the values.
2. Another thread is running, reading from IOIO UART where requests come in asking for sensor data.
3. In response, the most recent sensor reading is sent back through IOIO UART.

We are continually reading sensor data so that after we initiate the rocket launch sequence and the rocket takes off, the threads will continue to record sensor data after the UART connection has been severed (the UART connection goes to the NetBurner SB70 LC which converts the signal to ethernet which runs to a bunker ~200 ft away).

• The ADXL345 is being queried at a set frequency using Thread.sleep(10L) to get readings at approximately 100 Hz.
  
• The UART requests for the most recent sensor readings come in at an adjustable 1 to 100 Hz, whereas I see the locks occur if I set the UART polling frequency above 15 Hz or so; also, the lock occurs quicker at higher frequencies.

I did set the SPI rate for the ADXL345 to SpiMaster.Rate.RATE_2M, not sure if that would be a problem? I remember setting it high so that I could attempt to poll at higher frequencies from it later (provided I can figure out this locking issue).

Thanks again for taking the time to help Ytai! I owe you a beer or something! :-)

-Travis

[Travis Wyatt]

I've done some more testing/logging and found that the problem is a UART issue, not an issue with SPI running concurrently with UART (or rather, perhaps a concurrency issue). I setup our project to test without using SPI and instead queried accelerometer data from the phone's internal accelerometer and then requested/responded with that data over 2 different UART channels. I found that even without SPI, the lock still occurred but not as quickly.

Can I not run two different threads and have them check the UART input streams at the same time? (even though they are input streams on 2 separate UART pins)?

Or is it an issue with the IOIO?

Here is a logging snippet I did in case it offers any clues (the numbers in brackets at the beginning of each log message are the Thread IDs):

...

08-02 22:56:16.168: I/System.out(1018): [13] FlowControlledOutputStream.readyToSend(130) Line 89: readyToSend_ = 176

08-02 22:56:16.168: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 176, queue_.remainingCapacity() = 1024

08-02 22:56:16.168: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 119: readyToSend_ = 133, queue_.remainingCapacity() = 1024

08-02 22:56:16.168: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 133, queue_.remainingCapacity() = 1024

08-02 22:56:16.188: D/dalvikvm(1018): GC_CONCURRENT freed 420K, 52% free 2856K/5895K, external 76K/587K, paused 2ms+6ms

08-02 22:56:16.218: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 119: readyToSend_ = 90, queue_.remainingCapacity() = 1024

08-02 22:56:16.218: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 90, queue_.remainingCapacity() = 1024

08-02 22:56:16.258: I/System.out(1018): [13] FlowControlledOutputStream.readyToSend(132) Line 89: readyToSend_ = 222

08-02 22:56:16.258: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 222, queue_.remainingCapacity() = 1024

08-02 22:56:16.258: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 119: readyToSend_ = 158, queue_.remainingCapacity() = 1002

08-02 22:56:16.258: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 119: readyToSend_ = 136, queue_.remainingCapacity() = 1024

08-02 22:56:16.258: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 136, queue_.remainingCapacity() = 1024

08-02 22:56:16.258: I/System.out(1018): [15] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 243

08-02 22:56:16.268: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 119: readyToSend_ = 93, queue_.remainingCapacity() = 1024

08-02 22:56:16.268: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 93, queue_.remainingCapacity() = 1024

08-02 22:56:16.268: I/System.out(1018): [15] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 200

08-02 22:56:16.278: I/System.out(1018): [15] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 157

08-02 22:56:16.278: I/System.out(1018): [15] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 114

08-02 22:56:16.288: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 119: readyToSend_ = 29, queue_.remainingCapacity() = 1002

08-02 22:56:16.288: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 119: readyToSend_ = 7, queue_.remainingCapacity() = 1024

08-02 22:56:16.288: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 7, queue_.remainingCapacity() = 1024

08-02 22:56:16.288: I/System.out(1018): [15] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 113

08-02 22:56:16.288: I/System.out(1018): [15] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 112

08-02 22:56:16.288: I/System.out(1018): [15] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 111

08-02 22:56:16.288: I/System.out(1018): [15] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 110

08-02 22:56:16.298: I/System.out(1018): [15] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 109

08-02 22:56:16.298: I/System.out(1018): [15] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 108

08-02 22:56:16.298: I/System.out(1018): [15] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 71

08-02 22:56:16.298: I/System.out(1018): [15] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 70

08-02 22:56:16.298: I/System.out(1018): [13] FlowControlledOutputStream.readyToSend(131) Line 89: readyToSend_ = 138

08-02 22:56:16.298: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 138, queue_.remainingCapacity() = 1024

08-02 22:56:16.298: I/System.out(1018): [15] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 69

08-02 22:56:16.298: I/System.out(1018): [15] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 68

08-02 22:56:16.298: I/System.out(1018): [15] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 67

08-02 22:56:16.298: I/System.out(1018): [15] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 66

08-02 22:56:16.298: I/System.out(1018): [15] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 65

08-02 22:56:16.298: I/System.out(1018): [15] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 64

08-02 22:56:16.298: I/System.out(1018): [15] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 55

08-02 22:56:16.298: I/System.out(1018): [15] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 28

08-02 22:56:16.298: I/System.out(1018): [15] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 27

08-02 22:56:16.298: I/System.out(1018): [15] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 26

08-02 22:56:16.298: I/System.out(1018): [15] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 25

08-02 22:56:16.308: I/System.out(1018): [15] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 24

08-02 22:56:16.308: I/System.out(1018): [18] FlowControlledOutputStream.write() Line 75: queue.remainingCapacity() = 0

08-02 22:56:16.308: I/System.out(1018): [15] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 0

08-02 22:56:16.308: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 119: readyToSend_ = 95, queue_.remainingCapacity() = 1024

08-02 22:56:16.308: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 95, queue_.remainingCapacity() = 1024

08-02 22:56:16.318: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 119: readyToSend_ = 52, queue_.remainingCapacity() = 1024

08-02 22:56:16.318: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 52, queue_.remainingCapacity() = 1024

08-02 22:56:16.538: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 119: readyToSend_ = 7, queue_.remainingCapacity() = 1024

08-02 22:56:16.538: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 7, queue_.remainingCapacity() = 1024

08-02 22:56:16.538: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 119: readyToSend_ = 0, queue_.remainingCapacity() = 873

08-02 22:56:16.538: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 873

08-02 22:56:16.548: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 872

08-02 22:56:16.548: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 871

08-02 22:56:16.548: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 870

08-02 22:56:16.558: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 869

08-02 22:56:16.558: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 868

08-02 22:56:16.558: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 867

08-02 22:56:16.558: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 866

08-02 22:56:16.558: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 865

08-02 22:56:16.558: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 864

08-02 22:56:16.558: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 863

08-02 22:56:16.558: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 862

08-02 22:56:16.558: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 861

08-02 22:56:16.558: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 860

08-02 22:56:16.558: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 859

08-02 22:56:16.558: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 858

08-02 22:56:16.568: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 857

08-02 22:56:16.568: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 856

08-02 22:56:16.568: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 689

08-02 22:56:16.568: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 688

08-02 22:56:16.578: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 687

08-02 22:56:16.578: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 686

08-02 22:56:16.578: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 685

08-02 22:56:16.578: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 684

08-02 22:56:16.578: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 683

08-02 22:56:16.578: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 682

08-02 22:56:16.588: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 681

08-02 22:56:16.588: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 680

08-02 22:56:16.588: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 679

08-02 22:56:16.588: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 678

08-02 22:56:16.588: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 677

08-02 22:56:16.588: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 676

08-02 22:56:16.598: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 675

08-02 22:56:16.598: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 646

08-02 22:56:16.738: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 645

08-02 22:56:16.738: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 644

08-02 22:56:16.748: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 643

08-02 22:56:16.748: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 642

08-02 22:56:16.758: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 487

08-02 22:56:16.758: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 486

08-02 22:56:16.758: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 485

08-02 22:56:16.758: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 484

08-02 22:56:16.758: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 483

08-02 22:56:16.768: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 482

08-02 22:56:16.768: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 481

08-02 22:56:16.768: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 480

08-02 22:56:16.768: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 479

08-02 22:56:16.768: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 478

08-02 22:56:16.768: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 477

08-02 22:56:16.778: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 476

08-02 22:56:16.778: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 475

08-02 22:56:16.778: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 474

08-02 22:56:16.778: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 473

08-02 22:56:16.778: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 472

08-02 22:56:16.778: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 471

08-02 22:56:16.788: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 431

08-02 22:56:16.788: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 430

08-02 22:56:16.788: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 429

08-02 22:56:16.788: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 428

08-02 22:56:16.788: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 427

08-02 22:56:16.788: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 426

08-02 22:56:16.788: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 425

08-02 22:56:16.798: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 400

08-02 22:56:16.798: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 399

08-02 22:56:16.798: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 398

08-02 22:56:16.798: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 393

08-02 22:56:16.808: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 259

08-02 22:56:16.808: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 258

08-02 22:56:16.808: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 257

08-02 22:56:16.808: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 256

08-02 22:56:16.808: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 255

08-02 22:56:16.818: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 254

08-02 22:56:16.818: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 253

08-02 22:56:16.818: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 252

08-02 22:56:16.818: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 251

08-02 22:56:16.818: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 250

08-02 22:56:16.818: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 249

08-02 22:56:16.828: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 248

08-02 22:56:16.828: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 247

08-02 22:56:16.828: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 246

08-02 22:56:16.828: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 245

08-02 22:56:16.828: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 244

08-02 22:56:16.828: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 216

08-02 22:56:16.929: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 215

08-02 22:56:16.929: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 214

08-02 22:56:16.939: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 213

08-02 22:56:16.939: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 212

08-02 22:56:16.939: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 211

08-02 22:56:16.939: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 210

08-02 22:56:16.939: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 171

08-02 22:56:16.949: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 170

08-02 22:56:16.949: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 169

08-02 22:56:16.949: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 168

08-02 22:56:16.949: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 167

08-02 22:56:16.949: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 166

08-02 22:56:16.949: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 165

08-02 22:56:16.949: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 164

08-02 22:56:16.959: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 130

08-02 22:56:16.959: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 129

08-02 22:56:16.959: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 128

08-02 22:56:16.959: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 127

08-02 22:56:16.959: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 126

08-02 22:56:16.969: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 125

08-02 22:56:16.969: I/System.out(1018): [19] FlowControlledOutputStream.write() Line 75: queue.remainingCapacity() = 0

08-02 22:56:16.969: I/System.out(1018): [16] FlowControlledOutputStream.FlushThread.run() Line 111: readyToSend_ = 0, queue_.remainingCapacity() = 0

(at this point all IOIO reads are locked, including any reads on either UART RX pin).

Any help would be much appreciated,

Travis

[Travis Wyatt]

Correction, the lock only occurs on writes (so the UART output streams, *not* the input streams)...Sorry, its late and I've been staring at this way too long.

[Ytai Ben-Tsvi]

You're getting close. Please add clearer and more log messages so we can actually see when bytes are:

1. Pushed to the queue.
2. Pulled out from the queue.
3. Sent to the IOIO.
4. The IOIO reports more space available in its own buffers.

After each such event, log the event and its details, along with the current size of the Android-side queue and the IOIO-side queue.

[Travis Wyatt]

Hey Ytai,

School has started for me and the rocket was successfully launched using the Android phone/IOIO so I don't really have time to look into this any further, although details of the rocket/project/launch can be found at:

http://rocket.sdsu.edu/

At the launch site we ended up requesting sensor data from the IOIO at 1 Hz (to be sure we didn't have any lock ups while on the launch pad), which worked out.

For anyone else having similar issues: we did find that requesting a IOIO disconnect was the only way to get the IOIO back and be able to continue any communication with it (which we needed that feature so we could remain a safe distance from the rocket prior to launch).

Also, a great resource for others might be the code we wrote to interface with a bunch of different sensors (the entire project is open source):

ITG-3205 Gyroscope: https://github.com/twyatt/ioio-itg3205

MAX31855 Thermocouple: https://github.com/twyatt/ioio-max31855

MS5611 Barometer: https://github.com/twyatt/ioio-ms5611

ADXL345 Accelerometer: https://github.com/twyatt/ioio-adxl345

...and there were others that can be found in the rocket project code base itself:

https://github.com/twyatt/sdsu-rocket

Thanks again Ytai and good luck with your projects!

-Travis

[NIKHIL MHATRE]

hi twyatt,

im using adxl 345 with ur code. but it shows magnitude 3 n likewise but ideally it should be 1 when accelerometer at rest.

[Travis Wyatt]

Are you using the code found at:

https://github.com/twyatt/ioio-adxl345

Or do you have custom code to interface w/ the ADXL345 sensor? (if so, you'll need to post your code or any modifications for me to be able to help at all)

--
You received this message because you are subscribed to a topic in the Google Groups "ioio-users" group.
To unsubscribe from this topic, visit https://groups.google.com/d/topic/ioio-users/g91ZqviEugI/unsubscribe.
To unsubscribe from this group and all its topics, send an email to ioio-users+...@googlegroups.com.

To post to this group, send email to ioio-...@googlegroups.com.
Visit this group at http://groups.google.com/group/ioio-users.

For more options, visit https://groups.google.com/d/optout.