Giter Club home page Giter Club logo

Comments (12)

rbalykov avatar rbalykov commented on August 20, 2024

Hi @peternewman
github just gives a choice on repo creation.
Let me know if some more participants are to be invited (or repo made public maybe).

Looks like it's better to discuss the issue here.

from cdmx.

rbalykov avatar rbalykov commented on August 20, 2024

Here we go again.
The unit has been rewrote from "line dicsipline" from "character device",
it has allowed to workaround double-opened file (ldattach vs olad)
and gave olad exclusive access, but problem is still here.

On start olad:

  • opens /dev/cdmx000
  • requests exclusive mode, ioctl 540C
  • gets/sets termios (next two ioctls)
  • polls input buffer, gets null bytes to read
  • writes polling message
  • the reply is generated (cdmx: 444: cdmx_enttec_msg: new message pending)
  • nothing more happens here, olad just continues to start.

Later:

  • olad makes two more requests (cdmx_enttec_msg: output frame is pending, message is dropped: port 0, label 78)
  • and doesn't read replies
  • then reports: Usb widget doesn't respond.
  • then log shows thousands of reads/polls/ioctls.

So trial is almost the same, except "File is busy" message appeared using ldattach.
Gonna try it with some more software.

[86971.586647] olad[10379]: olad/PluginManager.cpp:73: Skipping Pathport because it was disabled
[86971.587807] olad[10379]: olad/PluginManager.cpp:73: Skipping FTDI USB DMX because it was disabled
[86971.589158] olad[10379]: olad/PluginManager.cpp:73: Skipping UART native DMX because it was disabled
[86972.105135] kernel: cdmx: 255: cdmx_open: file cdmx000, cdata 5dac6abe dev_t F500000
[86972.105159] kernel: cdmx: 261: cdmx_open: ->>> done
[86972.105187] kernel: cdmx: 673: cdmx_ioctl: cmd 0x540C, param 0x8CEB3100
[86972.105231] kernel: cdmx: 673: cdmx_ioctl: cmd 0x5401, param 0xB3BFE778
[86972.105248] kernel: cdmx: 673: cdmx_ioctl: cmd 0x5402, param 0xB3BFE754
[86972.105433] kernel: cdmx: 652: cdmx_poll: port 0
[86972.105954] kernel: cdmx: 529: cdmx_write: port 0
[86972.106096] kernel: cdmx: 444: cdmx_enttec_msg: new message pending
[86972.106166] kernel: cdmx: 448: cdmx_enttec_msg: ->>> TX not implemented yet
[86972.106180] kernel: cdmx: 560: cdmx_write: ->>> done file cdmx000, id 0, result 5
[86971.594165] olad[10379]: olad/PluginManager.cpp:195: Trying to start Dummy
[86971.595116] olad[10379]: olad/plugin_api/DeviceManager.cpp:105: Installed device: Dummy Device:1-1
[86971.595934] olad[10379]: olad/PluginManager.cpp:200: Started Dummy
[86971.596639] olad[10379]: olad/PluginManager.cpp:195: Trying to start Serial USB
[86971.597388] olad[10379]: common/thread/Thread.cpp:194: Thread , policy SCHED_OTHER, priority 0
[86971.598115] olad[10379]: plugins/usbpro/WidgetDetectorThread.cpp:215: Found potential USB Serial device at /dev/cdmx000
[86971.598909] olad[10379]: common/io/Serial.cpp:197: Acquired /var/lock/LCK..cdmx000
[86971.599620] olad[10379]: plugins/usbpro/WidgetDetectorThread.cpp:384: trying stage 0 for 0xb3200e60
[86971.600479] olad[10379]: olad/PluginManager.cpp:200: Started Serial USB
[86972.307790] kernel: cdmx: 529: cdmx_write: port 0
[86972.307948] kernel: cdmx: 385: cdmx_enttec_msg: output frame is pending, message is dropped: port 0, label 78
[86972.315063] kernel: cdmx: 560: cdmx_write: ->>> done file cdmx000, id 0, result 5
[86972.516065] kernel: cdmx: 529: cdmx_write: port 0
[86972.516105] kernel: cdmx: 385: cdmx_enttec_msg: output frame is pending, message is dropped: port 0, label 10
[86972.521654] kernel: cdmx: 560: cdmx_write: ->>> done file cdmx000, id 0, result 5
[86972.206162] olad[10379]: plugins/usbpro/UsbProWidgetDetector.cpp:323: USB Widget didn't respond to messages, esta id 0, device id 0
[86972.725223] kernel: cdmx: 652: cdmx_poll: port 0
[86972.725450] kernel: cdmx: 529: cdmx_write: port 0
[86972.725595] kernel: cdmx: 560: cdmx_write: ->>> done file cdmx000, id 0, result 6
[86972.726086] kernel: cdmx: 652: cdmx_poll: port 0
[86972.726362] kernel: cdmx: 673: cdmx_ioctl: cmd 0x541B, param 0xB3BFE338
[86972.726512] kernel: cdmx: 574: cdmx_read: port 0

end of log:

[86992.946068] kernel: cdmx: 673: cdmx_ioctl: cmd 0x541B, param 0xB3BFE338
[86992.946104] kernel: cdmx: 652: cdmx_poll: port 0
[86992.946132] kernel: cdmx: 673: cdmx_ioctl: cmd 0x541B, param 0xB3BFE338
[86992.946761] kernel: cdmx: 269: cdmx_release: file cdmx000, cdata 5dac6abe dev_t F500000
[86993.267193] olad[10379]: plugins/usbpro/UsbProWidgetDetector.cpp:323: USB Widget didn't respond to messages, esta id 0, device id 0
[86993.270706] olad[10379]: plugins/usbpro/UsbProWidgetDetector.cpp:326: Is device in USB Controller mode if it's a Goddard?
[86993.271732] olad[10379]: plugins/usbpro/WidgetDetectorThread.cpp:384: trying stage 1 for 0xb3200e60
[86993.272702] olad[10379]: common/io/TimeoutManager.cpp:92: timeout 0xb3201274 already in remove set
[86993.273718] olad[10379]: plugins/usbpro/WidgetDetectorThread.cpp:381: no more detectors to try for  0xb3200e60
[86993.274621] olad[10379]: common/io/Serial.cpp:245: Released /var/lock/LCK..cdmx000
[86996.396603] systemd[1]: Stopping LSB: OLA daemon...
[86996.465408] olad[10412]:  * Stopping OLA daemon olad

from cdmx.

peternewman avatar peternewman commented on August 20, 2024

it has allowed to workaround double-opened file (ldattach vs olad)
That sounds like good progress.

Where is cdmx_poll defined?

* writes polling message

What do you mean by this?

Where are these in your code:

[86972.105433] kernel: cdmx: 652: cdmx_poll: port 0
[86972.105954] kernel: cdmx: 529: cdmx_write: port 0

Assuming the first number after cdmx is a line number they don't seem to tie up with the current main code.

Either way, what is it writing at that point and why?

* the reply is generated (cdmx: 444: cdmx_enttec_msg: new message pending)

From what I can see in the current code, by the point you get this message we've already failed as it's stuck in pending mode.

* olad makes two more requests (cdmx_enttec_msg: output frame is pending, message is dropped: port 0, label 78)

* and doesn't read replies

From what I can see, you don't ever reply to labels 78 or 10:

cdmx/cdmx.c

Lines 339 to 344 in a672666

if (port->read_from.pending)
{
K_ERR("output frame is pending, message is dropped: port %d, label %d",
port->id, port->write_to.msglabel);
return -EBUSY;
}

So again it's broken before it even receives those messages.

So trial is almost the same, except "File is busy" message appeared using ldattach.

That wouldn't be equivalent to

cdmx/cdmx.c

Line 343 in a672666

return -EBUSY;

would it? I've not looked at the ldattach code.

from cdmx.

rbalykov avatar rbalykov commented on August 20, 2024

Where is cdmx_poll defined?

Have commited changes and added faillog-timesorted.txt, line numbers now match the log.
It includes complete boot log, so start watching with line 1142

Either way, what is it writing at that point and why?

Log messages from user-space have bigger latency then kernel-space,
so is required journalctl | sort > file, mentioned above.

From what I can see in the current code, by the point you get this message we've already failed as it's stuck in pending mode.

The most valuable part of log, sorted by precise time:

   1189 Sep 13 07:43:57.699311 odroid olad[1500]: plugins/usbpro/WidgetDetectorThread.cpp:215: Found potential USB Serial device at /dev/cdmx000
   1190 Sep 13 07:43:57.699669 odroid olad[1500]: common/io/Serial.cpp:197: Acquired /var/lock/LCK..cdmx000
   1191 Sep 13 07:43:57.700032 odroid olad[1500]: plugins/usbpro/WidgetDetectorThread.cpp:384: trying stage 0 for 0xb3200e60
   1192 Sep 13 07:43:57.701063 odroid olad[1500]: olad/PluginManager.cpp:200: Started Serial USB
   1193 Sep 13 07:43:57.703973 odroid kernel: cdmx: 255: cdmx_open: file cdmx000, cdata 6666a8d0 dev_t F500000
   1194 Sep 13 07:43:57.704584 odroid kernel: cdmx: 261: cdmx_open: ->>> done
   1195 Sep 13 07:43:57.704982 odroid kernel: cdmx: 672: cdmx_ioctl: cmd 0x540C, param 0x6A80E900
   1196 Sep 13 07:43:57.705328 odroid kernel: cdmx: 672: cdmx_ioctl: cmd 0x5401, param 0xB3BFE778
   1197 Sep 13 07:43:57.705670 odroid kernel: cdmx: 672: cdmx_ioctl: cmd 0x5402, param 0xB3BFE754
   1198 Sep 13 07:43:57.705970 odroid kernel: cdmx: 652: cdmx_poll: port 0
   1199 Sep 13 07:43:57.706302 odroid kernel: cdmx: 529: cdmx_write: port 0
   1200 Sep 13 07:43:57.706633 odroid kernel: cdmx: 444: cdmx_enttec_msg: new message pending, label=77
   1201 Sep 13 07:43:57.707038 odroid kernel: cdmx: 448: cdmx_enttec_msg: ->>> TX not implemented yet
   1202 Sep 13 07:43:57.707405 odroid kernel: cdmx: 560: cdmx_write: ->>> done file cdmx000, id 0, result 5
   1203 Sep 13 07:43:57.914369 odroid kernel: cdmx: 529: cdmx_write: port 0
   1204 Sep 13 07:43:57.917202 odroid kernel: cdmx: 385: cdmx_enttec_msg: output frame is pending, message is dropped: port 0, label 78
   1205 Sep 13 07:43:57.920985 odroid kernel: cdmx: 560: cdmx_write: ->>> done file cdmx000, id 0, result 5
   1206 Sep 13 07:43:58.118600 odroid kernel: cdmx: 529: cdmx_write: port 0
   1207 Sep 13 07:43:58.120909 odroid kernel: cdmx: 385: cdmx_enttec_msg: output frame is pending, message is dropped: port 0, label 10
   1208 Sep 13 07:43:58.123280 odroid kernel: cdmx: 560: cdmx_write: ->>> done file cdmx000, id 0, result 5
   1209 Sep 13 07:43:58.323063 odroid olad[1500]: plugins/usbpro/UsbProWidgetDetector.cpp:323: USB Widget didn't respond to messages, esta id 0, device id 0
   1210 Sep 13 07:43:58.323563 odroid olad[1500]: plugins/usbpro/UsbProWidgetDetector.cpp:326: Is device in USB Controller mode if it's a Goddard?
   1211 Sep 13 07:43:58.324646 odroid olad[1500]: plugins/usbpro/WidgetDetectorThread.cpp:384: trying stage 1 for 0xb3200e60
   1212 Sep 13 07:43:58.340384 odroid kernel: cdmx: 652: cdmx_poll: port 0
   1213 Sep 13 07:43:58.342945 odroid kernel: cdmx: 529: cdmx_write: port 0
   1214 Sep 13 07:43:58.351400 odroid kernel: cdmx: 560: cdmx_write: ->>> done file cdmx000, id 0, result 6
   1215 Sep 13 07:43:58.351954 odroid kernel: cdmx: 652: cdmx_poll: port 0
   1216 Sep 13 07:43:58.352350 odroid kernel: cdmx: 672: cdmx_ioctl: cmd 0x541B, param 0xB3BFE338
   1217 Sep 13 07:43:58.352734 odroid kernel: cdmx: 574: cdmx_read: port 0
   1218 Sep 13 07:43:58.353168 odroid kernel: cdmx: 589: cdmx_read: size 9, lsb 1, msb 0
   1219 Sep 13 07:43:58.353548 odroid kernel: cdmx: 607: cdmx_read: header 1 byte(s)
   1220 Sep 13 07:43:58.354068 odroid kernel: cdmx: 630: cdmx_read: footer 1 byte(s)
   1221 Sep 13 07:43:58.354525 odroid kernel: cdmx: 642: cdmx_read: ->>> 2 bytes total read
   1222 Sep 13 07:43:58.354990 odroid kernel: cdmx: 672: cdmx_ioctl: cmd 0x541B, param 0xB3BFE338
   1223 Sep 13 07:43:58.355380 odroid kernel: cdmx: 652: cdmx_poll: port 0
   1224 Sep 13 07:43:58.526071 odroid olad[1500]: plugins/usbpro/WidgetDetectorThread.cpp:381: no more detectors to try for  0xb3200e60
   1225 Sep 13 07:43:58.527629 odroid olad[1500]: common/io/Serial.cpp:245: Released /var/lock/LCK..cdmx000
   1226 Sep 13 07:43:58.535289 odroid kernel: cdmx: 269: cdmx_release: file cdmx000, cdata 6666a8d0 dev_t F500000

would it? I've not looked at the ldattach code.

it's like "open; cfmakeraw; ioctl-attach; sleep"

from cdmx.

rbalykov avatar rbalykov commented on August 20, 2024

Could it be FNCTL trick-lock?

from cdmx.

peternewman avatar peternewman commented on August 20, 2024

Yeah agreed, I think this is the vendor label check:

   1198 Sep 13 07:43:57.705970 odroid kernel: cdmx: 652: cdmx_poll: port 0
   1199 Sep 13 07:43:57.706302 odroid kernel: cdmx: 529: cdmx_write: port 0

Then it seems to get the serial and name

   1204 Sep 13 07:43:57.917202 odroid kernel: cdmx: 385: cdmx_enttec_msg: output frame is pending, message is dropped: port 0, label 78
   1205 Sep 13 07:43:57.920985 odroid kernel: cdmx: 560: cdmx_write: ->>> done file cdmx000, id 0, result 5
   1206 Sep 13 07:43:58.118600 odroid kernel: cdmx: 529: cdmx_write: port 0
   1207 Sep 13 07:43:58.120909 odroid kernel: cdmx: 385: cdmx_enttec_msg: output frame is pending, message is dropped: port 0, label 10
   1208 Sep 13 07:43:58.123280 odroid kernel: cdmx: 560: cdmx_write: ->>> done file cdmx000, id 0, result 5

But the OLA read only shows up here:

   1215 Sep 13 07:43:58.351954 odroid kernel: cdmx: 652: cdmx_poll: port 0
   1216 Sep 13 07:43:58.352350 odroid kernel: cdmx: 672: cdmx_ioctl: cmd 0x541B, param 0xB3BFE338
   1217 Sep 13 07:43:58.352734 odroid kernel: cdmx: 574: cdmx_read: port 0
   1218 Sep 13 07:43:58.353168 odroid kernel: cdmx: 589: cdmx_read: size 9, lsb 1, msb 0
   1219 Sep 13 07:43:58.353548 odroid kernel: cdmx: 607: cdmx_read: header 1 byte(s)
   1220 Sep 13 07:43:58.354068 odroid kernel: cdmx: 630: cdmx_read: footer 1 byte(s)
   1221 Sep 13 07:43:58.354525 odroid kernel: cdmx: 642: cdmx_read: ->>> 2 bytes total read
   1222 Sep 13 07:43:58.354990 odroid kernel: cdmx: 672: cdmx_ioctl: cmd 0x541B, param 0xB3BFE338
   1223 Sep 13 07:43:58.355380 odroid kernel: cdmx: 652: cdmx_poll: port 0

Which OLA scheduler are you using? You could try:

       --no-use-epoll
              Disable the use of epoll(), revert to select()

       --no-use-kqueue
              Disable the use of kqueue(), revert to select()

I wonder if you're not correctly setting bits for the answer to https://www.manpagez.com/man/2/FD_ISSET/ in SelectPoller::CheckDescriptors?

from cdmx.

rbalykov avatar rbalykov commented on August 20, 2024 
       --no-use-epoll
              Disable the use of epoll(), revert to select()

       --no-use-kqueue
              Disable the use of kqueue(), revert to select()

I wonder if you're not correctly setting bits for the answer to https://www.manpagez.com/man/2/FD_ISSET/ in SelectPoller::CheckDescriptors?

That's it, found it on OLA code.
Seems like implementing Epoll is better choice

from cdmx.

rbalykov avatar rbalykov commented on August 20, 2024

Finally, it works using '--no-use-epoll'.
Now, epoll support is have to be implemented.

from cdmx.

peternewman avatar peternewman commented on August 20, 2024

Finally, it works using '--no-use-epoll'.
Now, epoll support is have to be implemented.

Excellent, glad we got there in the end!

The epoll stuff is in here:
https://github.com/OpenLightingProject/ola/blob/master/common/io/EPoller.cpp

I've no idea, but I'd imagine its around epoll_wait and generating events.

You should also check kqueue (assuming it's enabled via configure). I think you should be able to do --use-kqueue to switch to that.

You can check the export map on the webserver via /debug in case it doesn't log anything useful.

I think this is probably a better bet all round than line discipline within OLA given OpenLightingProject/ola#795 which generally makes sense apart from in this specific case.

from cdmx.

rbalykov avatar rbalykov commented on August 20, 2024

done with EPOLL, let's suffer with UART

from cdmx.

peternewman avatar peternewman commented on August 20, 2024

done with EPOLL

Excellent.

You should probably either fix kpoll too or leave a note saying that doesn't work:
https://github.com/OpenLightingProject/ola/blob/master/common/io/KQueuePoller.cpp

let's suffer with UART

? 😕

from cdmx.

rbalykov avatar rbalykov commented on August 20, 2024

let's suffer with UART

? 😕

Going to implement UART, nobody said that would be easy.

from cdmx.

Related Issues (6)

Recommend Projects

  • React photo React

    A declarative, efficient, and flexible JavaScript library for building user interfaces.

  • Vue.js photo Vue.js

    🖖 Vue.js is a progressive, incrementally-adoptable JavaScript framework for building UI on the web.

  • Typescript photo Typescript

    TypeScript is a superset of JavaScript that compiles to clean JavaScript output.

  • TensorFlow photo TensorFlow

    An Open Source Machine Learning Framework for Everyone

  • Django photo Django

    The Web framework for perfectionists with deadlines.

  • D3 photo D3

    Bring data to life with SVG, Canvas and HTML. 📊📈🎉

Recommend Topics

  • javascript

    JavaScript (JS) is a lightweight interpreted programming language with first-class functions.

  • web

    Some thing interesting about web. New door for the world.

  • server

    A server is a program made to process requests and deliver data to clients.

  • Machine learning

    Machine learning is a way of modeling and interpreting data that allows a piece of software to respond intelligently.

  • Game

    Some thing interesting about game, make everyone happy.

Recommend Org

  • Facebook photo Facebook

    We are working to build community through open source technology. NB: members must have two-factor auth.

  • Microsoft photo Microsoft

    Open source projects and samples from Microsoft.

  • Google photo Google

    Google ❤️ Open Source for everyone.

  • D3 photo D3

    Data-Driven Documents codes.