Bug #1798

Multiple ASYNCIO errors

Added by Ema Nymton almost 7 years ago. Updated almost 7 years ago.

Status:FixedStart date:11/30/2013
Priority:HighDue date:
Assignee:Andreas Smas% Done:

100%

Category:General
Target version:4.4
Found in version:4.3.633 Platform:PS3

Description

Hi
I get constant (i.e. every second) ASYNCIO poll errors when playing a file over SMB

ASYNCIO [ERROR]: Poll failed --

Note that this doesn't affect the playback or the performances.

Associated revisions

Revision 5927c9b7
Added by Andreas Smas almost 7 years ago

When ASYNCIO Poll error occurs, output more info in log

refs #1798

Change included in version 4.3.632

Revision 393c5eb7
Added by Andreas Smas almost 7 years ago

ASYNCIO: Add names to all file descriptor structs

refs #1798

Change included in version 4.3.633

Revision d1fcd3f0
Added by Andreas Smas almost 7 years ago

asyncio: Handle errors from poll() in a more resilient way

poll() on ps3 can return error if there is a problem with one of the fd:s

Fixes #1798

Change included in version 4.3.636

History

#1 Updated by Ema Nymton almost 7 years ago

Any idea?

#2 Updated by Andreas Smas almost 7 years ago

  • Status changed from New to Accepted
  • Assignee set to Andreas Smas
  • Target version set to 4.4

Trying to reproduce this...

#3 Updated by Ema Nymton almost 7 years ago

Hard for me to reproduce this too... Sometimes the messages won't appear during an entire session, sometimes, once every second when playing a movie. Go figure :

#4 Updated by Leonid Protasov almost 7 years ago

Any details on smb server you play the link from? OS type/version etc?

#5 Updated by Ema Nymton almost 7 years ago

I stream files from a Synology DS409 running the latest possible software, DSM 4.2-3243

#6 Updated by Leonid Protasov almost 7 years ago

It's interesting to try to stream that file from Linux/Windows samba share. Will you get those errors too or not?

#7 Updated by Ema Nymton almost 7 years ago

The Synology is running Linux and SMB is handled by smbd. What do you think those errors could be caused by?

#8 Updated by Leonid Protasov almost 7 years ago

Have no idea. Is that bug still alive on the latest ST build?

#9 Updated by Leonid Protasov almost 7 years ago

  • Priority changed from Normal to High

Got it myself. It's not related to SMB connection. Look:
00:09:45.508: Video [DEBUG]:Playing rtmp://s2.streambox.in:1935/watch?wmsAuth=c2VydmVyX3RpbWU9MTM4OTAwMjQ5NyZoYXNoX3ZhbHVlPTEyMTg5M2EyOTExZWYxMTFjZThlOThkMTA0Nzg1NGZhJnZhbGlkbWludXRlcz04NjQwMA==/mp4:nnJtgDOdYi88S.mp4
00:09:45.510: media [DEBUG]:Settings initialized for URL watch_is:video:/7241/Rozhdestvenskii-SHrektakl-Osla-Donkey-s-Christmas-Shrektacular:%u0420%u043E%u0436%u0434%u0435%u0441%u0442%u0432%u0435%u043D%u0441%u043A%u0438%u0439%20%u0428%u0440%u0435%u043A%u0442%u0430%u043A%u043B%u044C%20%7C%20%u041E%u0441%u043B%u0430%20Donkey%27s%20Christmas%20Shrektacular:<font color="6699CC">SD RTMP</font>
00:09:45.515: AVSYNC [DEBUG]:Set to 0 ms
00:09:45.517: SVSYNC [DEBUG]:Set to 0s
00:09:45.885: THREADS [DEBUG]:Created thread audio decoder (0x10900e8)
00:09:45.939: Subscanner [DEBUG]:Starting subtitle scan for Рождественский Шректакль | Осла Donkey's Christmas Shrektacular (imdbid:<unknown>;) year:0 season:-1 episode:-1 duration:0 opensubhash:0000000000000000
00:09:45.940: THREADS [DEBUG]:Created thread subscanner (0x10900e9)
00:09:45.940: THREADS [DEBUG]:Thread 0x10900e9 (subscanner) exiting
00:09:45.940: RTMP [INFO]:Metadata:
00:09:45.941: RTMP [INFO]:trackinfo:
00:09:45.941: RTMP [INFO]: timescale 12800.00
00:09:45.941: RTMP [INFO]: length 22333440.00
00:09:45.942: RTMP [INFO]: language eng
00:09:45.942: RTMP [INFO]:sampledescription:
00:09:45.942: RTMP [INFO]: sampletype avc1
00:09:45.942: RTMP [INFO]: timescale 44100.00
00:09:45.943: RTMP [INFO]: length 76945279.00
00:09:45.943: RTMP [INFO]: language eng
00:09:45.943: RTMP [INFO]:sampledescription:
00:09:45.944: RTMP [INFO]: sampletype mp4a
00:09:45.944: RTMP [INFO]: audiochannels 2.00
00:09:45.945: RTMP [INFO]: audiosamplerate 44100.00
00:09:45.945: RTMP [INFO]: videoframerate 25.00
00:09:45.945: RTMP [INFO]: aacaot 2.00
00:09:45.945: RTMP [INFO]: avclevel 30.00
00:09:45.946: RTMP [INFO]: avcprofile 100.00
00:09:45.946: RTMP [INFO]: audiocodecid mp4a
00:09:45.946: RTMP [INFO]: videocodecid avc1
00:09:45.946: RTMP [INFO]: width 720.00
00:09:45.947: RTMP [INFO]: height 400.00
00:09:45.947: RTMP [INFO]: frameWidth 720.00
00:09:45.948: RTMP [INFO]: frameHeight 400.00
00:09:45.948: RTMP [INFO]: displayWidth 720.00
00:09:45.948: RTMP [INFO]: displayHeight 400.00
00:09:45.949: RTMP [INFO]: framerate 25.00
00:09:45.949: RTMP [INFO]: moovposition 524114664.00
00:09:45.950: RTMP [INFO]: duration 1744.80
00:09:45.950: RTMP [DEBUG]:Video size 720 x 400
00:09:45.984: VDEC [DEBUG]:Opening codec h264 level 42 using 54157309 bytes of RAM
00:09:45.987: VDEC [DEBUG]:Cell accelerated codec created using 54157309 bytes of RAM
00:09:45.997: audio [DEBUG]:Codec changed to aac
00:09:45.998: AUDIO [DEBUG]:The state is 0
00:09:45.999: AUDIO [DEBUG]:PS3 audio port 0 opened (2 channels)
00:09:46.000: Audio [DEBUG]:Converting from [stereo 44100Hz fltp] to [stereo 48000Hz flt]
00:15:21.812: ASYNCIO [ERROR]:Poll failed --
00:15:22.867: ASYNCIO [ERROR]:Poll failed --
00:15:23.878: ASYNCIO [ERROR]:Poll failed --
00:15:24.889: ASYNCIO [ERROR]:Poll failed --
00:15:25.899: ASYNCIO [ERROR]:Poll failed --
00:15:26.910: ASYNCIO [ERROR]:Poll failed --
00:15:27.920: ASYNCIO [ERROR]:Poll failed --
00:15:28.931: ASYNCIO [ERROR]:Poll failed --
00:15:29.941: ASYNCIO [ERROR]:Poll failed --
00:15:30.952: ASYNCIO [ERROR]:Poll failed --
00:15:31.963: ASYNCIO [ERROR]:Poll failed --
00:15:32.974: ASYNCIO [ERROR]:Poll failed --
00:15:33.984: ASYNCIO [ERROR]:Poll failed --
00:15:34.995: ASYNCIO [ERROR]:Poll failed --
00:15:36.006: ASYNCIO [ERROR]:Poll failed --
00:15:37.017: ASYNCIO [ERROR]:Poll failed --
00:15:38.027: ASYNCIO [ERROR]:Poll failed --
00:15:39.038: ASYNCIO [ERROR]:Poll failed --
00:15:40.049: ASYNCIO [ERROR]:Poll failed --
00:15:41.059: ASYNCIO [ERROR]:Poll failed --
00:15:42.070: ASYNCIO [ERROR]:Poll failed --
00:15:43.080: ASYNCIO [ERROR]:Poll failed --
00:15:44.091: ASYNCIO [ERROR]:Poll failed --
00:15:45.101: ASYNCIO [ERROR]:Poll failed --
00:15:46.112: ASYNCIO [ERROR]:Poll failed --
00:15:47.123: ASYNCIO [ERROR]:Poll failed --
00:15:48.134: ASYNCIO [ERROR]:Poll failed --
00:15:49.144: ASYNCIO [ERROR]:Poll failed --
00:15:50.155: ASYNCIO [ERROR]:Poll failed --
00:15:51.166: ASYNCIO [ERROR]:Poll failed --
00:15:52.176: ASYNCIO [ERROR]:Poll failed --
00:15:53.187: ASYNCIO [ERROR]:Poll failed --
00:15:54.197: ASYNCIO [ERROR]:Poll failed --
00:15:55.208: ASYNCIO [ERROR]:Poll failed --
00:15:56.219: ASYNCIO [ERROR]:Poll failed --
00:15:57.229: ASYNCIO [ERROR]:Poll failed --
00:15:58.240: ASYNCIO [ERROR]:Poll failed --
00:15:59.250: ASYNCIO [ERROR]:Poll failed --
00:16:00.261: ASYNCIO [ERROR]:Poll failed --
00:16:01.272: ASYNCIO [ERROR]:Poll failed --
00:16:02.282: ASYNCIO [ERROR]:Poll failed --
00:16:03.293: ASYNCIO [ERROR]:Poll failed --
00:16:04.303: ASYNCIO [ERROR]:Poll failed --
00:16:05.314: ASYNCIO [ERROR]:Poll failed --
00:16:06.325: ASYNCIO [ERROR]:Poll failed --
00:16:07.335: ASYNCIO [ERROR]:Poll failed --
00:16:08.346: ASYNCIO [ERROR]:Poll failed --
00:16:09.357: ASYNCIO [ERROR]:Poll failed --
00:16:10.368: ASYNCIO [ERROR]:Poll failed --
00:16:11.379: ASYNCIO [ERROR]:Poll failed --
00:16:12.390: ASYNCIO [ERROR]:Poll failed --
00:16:13.400: ASYNCIO [ERROR]:Poll failed --
00:16:14.411: ASYNCIO [ERROR]:Poll failed --
00:16:15.422: ASYNCIO [ERROR]:Poll failed --
00:16:16.432: ASYNCIO [ERROR]:Poll failed --
00:16:17.443: ASYNCIO [ERROR]:Poll failed --
00:16:18.453: ASYNCIO [ERROR]:Poll failed --
00:16:19.464: ASYNCIO [ERROR]:Poll failed --
00:16:20.475: ASYNCIO [ERROR]:Poll failed --
00:16:21.486: ASYNCIO [ERROR]:Poll failed --
00:16:22.496: ASYNCIO [ERROR]:Poll failed --
00:16:23.507: ASYNCIO [ERROR]:Poll failed --
00:16:24.517: ASYNCIO [ERROR]:Poll failed --
00:16:25.528: ASYNCIO [ERROR]:Poll failed --
00:16:26.538: ASYNCIO [ERROR]:Poll failed --
00:16:27.549: ASYNCIO [ERROR]:Poll failed --
00:16:28.560: ASYNCIO [ERROR]:Poll failed --
00:16:29.570: ASYNCIO [ERROR]:Poll failed --
00:16:30.581: ASYNCIO [ERROR]:Poll failed --
00:16:31.591: ASYNCIO [ERROR]:Poll failed --
00:16:32.602: ASYNCIO [ERROR]:Poll failed --
00:16:33.613: ASYNCIO [ERROR]:Poll failed --
00:16:34.624: ASYNCIO [ERROR]:Poll failed --
00:16:35.634: ASYNCIO [ERROR]:Poll failed --
00:16:36.645: ASYNCIO [ERROR]:Poll failed --
00:16:37.656: ASYNCIO [ERROR]:Poll failed --
00:16:38.666: ASYNCIO [ERROR]:Poll failed --
00:16:39.677: ASYNCIO [ERROR]:Poll failed --
00:16:40.688: ASYNCIO [ERROR]:Poll failed --
00:16:41.698: ASYNCIO [ERROR]:Poll failed --
00:16:42.709: ASYNCIO [ERROR]:Poll failed --
00:16:43.719: ASYNCIO [ERROR]:Poll failed --
00:16:44.730: ASYNCIO [ERROR]:Poll failed --
00:16:45.741: ASYNCIO [ERROR]:Poll failed --
00:16:46.752: ASYNCIO [ERROR]:Poll failed --
00:16:47.763: ASYNCIO [ERROR]:Poll failed --
00:16:48.774: ASYNCIO [ERROR]:Poll failed --
00:16:49.785: ASYNCIO [ERROR]:Poll failed --
00:16:50.796: ASYNCIO [ERROR]:Poll failed --
00:16:51.807: ASYNCIO [ERROR]:Poll failed --
00:16:52.817: ASYNCIO [ERROR]:Poll failed --
00:16:53.828: ASYNCIO [ERROR]:Poll failed --
00:16:54.839: ASYNCIO [ERROR]:Poll failed --
00:16:55.849: ASYNCIO [ERROR]:Poll failed --
00:16:56.860: ASYNCIO [ERROR]:Poll failed --
00:16:57.870: ASYNCIO [ERROR]:Poll failed --
00:16:58.881: ASYNCIO [ERROR]:Poll failed --
00:16:59.892: ASYNCIO [ERROR]:Poll failed --
00:17:00.902: ASYNCIO [ERROR]:Poll failed --
00:17:01.913: ASYNCIO [ERROR]:Poll failed --
00:17:02.924: ASYNCIO [ERROR]:Poll failed --
00:17:03.934: ASYNCIO [ERROR]:Poll failed --
00:17:04.945: ASYNCIO [ERROR]:Poll failed --
00:17:05.956: ASYNCIO [ERROR]:Poll failed --
00:17:06.968: ASYNCIO [ERROR]:Poll failed --
00:17:07.979: ASYNCIO [ERROR]:Poll failed --
00:17:08.989: ASYNCIO [ERROR]:Poll failed --
00:17:10.000: ASYNCIO [ERROR]:Poll failed --
00:17:11.010: ASYNCIO [ERROR]:Poll failed --
00:17:12.021: ASYNCIO [ERROR]:Poll failed --
00:17:13.032: ASYNCIO [ERROR]:Poll failed --
00:17:14.043: ASYNCIO [ERROR]:Poll failed --
00:17:15.053: ASYNCIO [ERROR]:Poll failed --
00:17:16.064: ASYNCIO [ERROR]:Poll failed --
00:17:17.075: ASYNCIO [ERROR]:Poll failed --
00:17:18.086: ASYNCIO [ERROR]:Poll failed --
00:17:19.096: ASYNCIO [ERROR]:Poll failed --
00:17:20.107: ASYNCIO [ERROR]:Poll failed --
00:17:21.118: ASYNCIO [ERROR]:Poll failed --
00:17:22.129: ASYNCIO [ERROR]:Poll failed --
00:17:23.140: ASYNCIO [ERROR]:Poll failed --
00:17:24.152: ASYNCIO [ERROR]:Poll failed --
00:17:25.163: ASYNCIO [ERROR]:Poll failed --
00:17:26.173: ASYNCIO [ERROR]:Poll failed --
00:17:27.184: ASYNCIO [ERROR]:Poll failed --
00:17:28.194: ASYNCIO [ERROR]:Poll failed --
00:17:29.205: ASYNCIO [ERROR]:Poll failed --
00:17:30.215: ASYNCIO [ERROR]:Poll failed --
00:17:31.226: ASYNCIO [ERROR]:Poll failed --
00:17:32.237: ASYNCIO [ERROR]:Poll failed --
00:17:33.248: ASYNCIO [ERROR]:Poll failed --
00:17:34.259: ASYNCIO [ERROR]:Poll failed --
00:17:35.270: ASYNCIO [ERROR]:Poll failed --
00:17:36.280: ASYNCIO [ERROR]:Poll failed --
00:17:37.291: ASYNCIO [ERROR]:Poll failed --
00:17:38.302: ASYNCIO [ERROR]:Poll failed --
00:17:39.312: ASYNCIO [ERROR]:Poll failed --
00:17:40.323: ASYNCIO [ERROR]:Poll failed --
00:17:41.333: ASYNCIO [ERROR]:Poll failed --
00:17:42.344: ASYNCIO [ERROR]:Poll failed --
00:17:43.355: ASYNCIO [ERROR]:Poll failed --
00:17:44.365: ASYNCIO [ERROR]:Poll failed --
00:17:45.376: ASYNCIO [ERROR]:Poll failed --
00:17:46.386: ASYNCIO [ERROR]:Poll failed --
00:17:47.397: ASYNCIO [ERROR]:Poll failed --
00:17:48.408: ASYNCIO [ERROR]:Poll failed --
00:17:49.418: ASYNCIO [ERROR]:Poll failed --
00:17:50.429: ASYNCIO [ERROR]:Poll failed --
00:17:51.440: ASYNCIO [ERROR]:Poll failed --
00:17:52.450: ASYNCIO [ERROR]:Poll failed --
00:17:53.461: ASYNCIO [ERROR]:Poll failed --
00:17:54.471: ASYNCIO [ERROR]:Poll failed --
00:17:55.482: ASYNCIO [ERROR]:Poll failed --
00:17:56.492: ASYNCIO [ERROR]:Poll failed --
00:17:57.503: ASYNCIO [ERROR]:Poll failed --
00:17:58.514: ASYNCIO [ERROR]:Poll failed --
00:17:59.525: ASYNCIO [ERROR]:Poll failed --
00:18:00.535: ASYNCIO [ERROR]:Poll failed --
00:18:01.546: ASYNCIO [ERROR]:Poll failed --
00:18:02.556: ASYNCIO [ERROR]:Poll failed --
00:18:03.567: ASYNCIO [ERROR]:Poll failed --
00:18:04.578: ASYNCIO [ERROR]:Poll failed --
00:18:05.588: ASYNCIO [ERROR]:Poll failed --
00:18:06.599: ASYNCIO [ERROR]:Poll failed --
00:18:07.610: ASYNCIO [ERROR]:Poll failed --
00:18:08.621: ASYNCIO [ERROR]:Poll failed --
00:18:09.632: ASYNCIO [ERROR]:Poll failed --
00:18:10.642: ASYNCIO [ERROR]:Poll failed --
00:18:11.654: ASYNCIO [ERROR]:Poll failed --
00:18:12.665: ASYNCIO [ERROR]:Poll failed --
00:18:13.676: ASYNCIO [ERROR]:Poll failed --
00:18:14.686: ASYNCIO [ERROR]:Poll failed --
00:18:15.697: ASYNCIO [ERROR]:Poll failed --
00:18:16.708: ASYNCIO [ERROR]:Poll failed --
00:18:17.718: ASYNCIO [ERROR]:Poll failed --
00:18:18.729: ASYNCIO [ERROR]:Poll failed --
00:18:19.740: ASYNCIO [ERROR]:Poll failed --
00:18:20.751: ASYNCIO [ERROR]:Poll failed --
00:18:21.761: ASYNCIO [ERROR]:Poll failed --
00:18:22.772: ASYNCIO [ERROR]:Poll failed --
00:18:23.782: ASYNCIO [ERROR]:Poll failed --
00:18:24.793: ASYNCIO [ERROR]:Poll failed --
00:18:25.804: ASYNCIO [ERROR]:Poll failed --
00:18:26.814: ASYNCIO [ERROR]:Poll failed --
00:18:27.825: ASYNCIO [ERROR]:Poll failed --
00:18:28.835: ASYNCIO [ERROR]:Poll failed --
00:18:29.846: ASYNCIO [ERROR]:Poll failed --
00:18:30.857: ASYNCIO [ERROR]:Poll failed --
00:18:31.868: ASYNCIO [ERROR]:Poll failed --
00:18:32.878: ASYNCIO [ERROR]:Poll failed --
00:18:33.889: ASYNCIO [ERROR]:Poll failed --
00:18:34.900: ASYNCIO [ERROR]:Poll failed --
00:18:35.910: ASYNCIO [ERROR]:Poll failed --
00:18:36.921: ASYNCIO [ERROR]:Poll failed --
00:18:37.932: ASYNCIO [ERROR]:Poll failed --
00:18:38.942: ASYNCIO [ERROR]:Poll failed --
00:18:39.953: ASYNCIO [ERROR]:Poll failed --
00:18:40.965: ASYNCIO [ERROR]:Poll failed --
00:18:41.975: ASYNCIO [ERROR]:Poll failed --
00:18:42.986: ASYNCIO [ERROR]:Poll failed --
00:18:43.997: ASYNCIO [ERROR]:Poll failed --
00:18:45.007: ASYNCIO [ERROR]:Poll failed --
00:18:46.018: ASYNCIO [ERROR]:Poll failed --
00:18:47.028: ASYNCIO [ERROR]:Poll failed --
00:18:48.039: ASYNCIO [ERROR]:Poll failed --
00:18:49.050: ASYNCIO [ERROR]:Poll failed --
00:18:50.061: ASYNCIO [ERROR]:Poll failed --
00:18:51.071: ASYNCIO [ERROR]:Poll failed --
00:18:52.082: ASYNCIO [ERROR]:Poll failed --
00:18:53.093: ASYNCIO [ERROR]:Poll failed --
00:18:54.104: ASYNCIO [ERROR]:Poll failed --
00:18:55.114: ASYNCIO [ERROR]:Poll failed --
00:18:56.125: ASYNCIO [ERROR]:Poll failed --
00:18:57.135: ASYNCIO [ERROR]:Poll failed --
00:18:58.146: ASYNCIO [ERROR]:Poll failed --
00:18:59.157: ASYNCIO [ERROR]:Poll failed --
00:19:00.168: ASYNCIO [ERROR]:Poll failed --
00:19:01.178: ASYNCIO [ERROR]:Poll failed --
00:19:02.189: ASYNCIO [ERROR]:Poll failed --
00:19:03.199: ASYNCIO [ERROR]:Poll failed --
00:19:04.211: ASYNCIO [ERROR]:Poll failed --
00:19:05.221: ASYNCIO [ERROR]:Poll failed --
00:19:06.232: ASYNCIO [ERROR]:Poll failed --
00:19:07.243: ASYNCIO [ERROR]:Poll failed --
00:19:08.253: ASYNCIO [ERROR]:Poll failed --
00:19:09.264: ASYNCIO [ERROR]:Poll failed --
00:19:10.274: ASYNCIO [ERROR]:Poll failed --
00:19:11.285: ASYNCIO [ERROR]:Poll failed --
00:19:12.296: ASYNCIO [ERROR]:Poll failed --
00:19:13.306: ASYNCIO [ERROR]:Poll failed --
00:19:14.317: ASYNCIO [ERROR]:Poll failed --
00:19:15.328: ASYNCIO [ERROR]:Poll failed --
00:19:16.339: ASYNCIO [ERROR]:Poll failed --
00:19:17.350: ASYNCIO [ERROR]:Poll failed --
00:19:18.361: ASYNCIO [ERROR]:Poll failed --
00:19:19.371: ASYNCIO [ERROR]:Poll failed --
00:19:20.382: ASYNCIO [ERROR]:Poll failed --
00:19:21.393: ASYNCIO [ERROR]:Poll failed --
00:19:22.403: ASYNCIO [ERROR]:Poll failed --
00:19:23.414: ASYNCIO [ERROR]:Poll failed --
00:19:24.425: ASYNCIO [ERROR]:Poll failed --
00:19:25.435: ASYNCIO [ERROR]:Poll failed --
00:19:26.446: ASYNCIO [ERROR]:Poll failed --
00:19:27.457: ASYNCIO [ERROR]:Poll failed --
00:19:28.467: ASYNCIO [ERROR]:Poll failed --
00:19:29.478: ASYNCIO [ERROR]:Poll failed --
00:19:30.489: ASYNCIO [ERROR]:Poll failed --
00:19:31.500: ASYNCIO [ERROR]:Poll failed --
00:19:32.511: ASYNCIO [ERROR]:Poll failed --
00:19:33.521: ASYNCIO [ERROR]:Poll failed --
00:19:34.532: ASYNCIO [ERROR]:Poll failed --
00:19:35.542: ASYNCIO [ERROR]:Poll failed --
00:19:36.554: ASYNCIO [ERROR]:Poll failed --
00:19:37.564: ASYNCIO [ERROR]:Poll failed --
00:19:38.575: ASYNCIO [ERROR]:Poll failed --
00:19:39.585: ASYNCIO [ERROR]:Poll failed --
00:19:40.596: ASYNCIO [ERROR]:Poll failed --
00:19:41.607: ASYNCIO [ERROR]:Poll failed --
00:19:42.618: ASYNCIO [ERROR]:Poll failed --
00:19:43.628: ASYNCIO [ERROR]:Poll failed --
00:19:44.639: ASYNCIO [ERROR]:Poll failed --
00:19:45.649: ASYNCIO [ERROR]:Poll failed --
00:19:46.660: ASYNCIO [ERROR]:Poll failed --
00:19:47.671: ASYNCIO [ERROR]:Poll failed --
00:19:48.681: ASYNCIO [ERROR]:Poll failed --
00:19:49.692: ASYNCIO [ERROR]:Poll failed --
00:19:50.703: ASYNCIO [ERROR]:Poll failed --
00:19:51.713: ASYNCIO [ERROR]:Poll failed --
00:19:52.724: ASYNCIO [ERROR]:Poll failed --
00:19:53.735: ASYNCIO [ERROR]:Poll failed --
00:19:54.745: ASYNCIO [ERROR]:Poll failed --
00:19:55.756: ASYNCIO [ERROR]:Poll failed --
00:19:56.766: ASYNCIO [ERROR]:Poll failed --
00:19:57.777: ASYNCIO [ERROR]:Poll failed --
00:19:58.788: ASYNCIO [ERROR]:Poll failed --
00:19:59.798: ASYNCIO [ERROR]:Poll failed --
00:20:00.809: ASYNCIO [ERROR]:Poll failed --
00:20:01.820: ASYNCIO [ERROR]:Poll failed --
00:20:02.830: ASYNCIO [ERROR]:Poll failed --
00:20:03.841: ASYNCIO [ERROR]:Poll failed --
00:20:04.851: ASYNCIO [ERROR]:Poll failed --
00:20:05.862: ASYNCIO [ERROR]:Poll failed --
00:20:06.873: ASYNCIO [ERROR]:Poll failed --
00:20:07.884: ASYNCIO [ERROR]:Poll failed --
00:20:08.894: ASYNCIO [ERROR]:Poll failed --
00:20:09.905: ASYNCIO [ERROR]:Poll failed --
00:20:10.916: ASYNCIO [ERROR]:Poll failed --
00:20:11.926: ASYNCIO [ERROR]:Poll failed --
00:20:12.937: ASYNCIO [ERROR]:Poll failed --
00:20:13.947: ASYNCIO [ERROR]:Poll failed --
00:20:14.958: ASYNCIO [ERROR]:Poll failed --
00:20:15.968: ASYNCIO [ERROR]:Poll failed --
00:20:16.979: ASYNCIO [ERROR]:Poll failed --
00:20:17.990: ASYNCIO [ERROR]:Poll failed --
00:20:19.001: ASYNCIO [ERROR]:Poll failed --
00:20:20.011: ASYNCIO [ERROR]:Poll failed --
00:20:21.022: ASYNCIO [ERROR]:Poll failed --
00:20:22.032: ASYNCIO [ERROR]:Poll failed --
00:20:23.043: ASYNCIO [ERROR]:Poll failed --
00:20:24.054: ASYNCIO [ERROR]:Poll failed --
00:20:25.065: ASYNCIO [ERROR]:Poll failed --
00:20:26.075: ASYNCIO [ERROR]:Poll failed --
00:20:27.122: ASYNCIO [ERROR]:Poll failed --
00:20:28.132: ASYNCIO [ERROR]:Poll failed --
00:20:29.143: ASYNCIO [ERROR]:Poll failed --
00:20:30.153: ASYNCIO [ERROR]:Poll failed --
00:20:31.164: ASYNCIO [ERROR]:Poll failed --
00:20:32.175: ASYNCIO [ERROR]:Poll failed --
00:20:33.185: ASYNCIO [ERROR]:Poll failed --
00:20:34.196: ASYNCIO [ERROR]:Poll failed --
00:20:35.207: ASYNCIO [ERROR]:Poll failed --
00:20:36.218: ASYNCIO [ERROR]:Poll failed --
00:20:37.228: ASYNCIO [ERROR]:Poll failed --
00:20:38.239: ASYNCIO [ERROR]:Poll failed --
00:20:39.249: ASYNCIO [ERROR]:Poll failed --
00:20:40.260: ASYNCIO [ERROR]:Poll failed --
00:20:41.270: ASYNCIO [ERROR]:Poll failed --
00:20:42.281: ASYNCIO [ERROR]:Poll failed --
00:20:43.292: ASYNCIO [ERROR]:Poll failed --
00:20:44.303: ASYNCIO [ERROR]:Poll failed --
00:20:45.314: ASYNCIO [ERROR]:Poll failed --
00:20:46.325: ASYNCIO [ERROR]:Poll failed --
00:20:47.336: ASYNCIO [ERROR]:Poll failed --
00:20:48.347: ASYNCIO [ERROR]:Poll failed --
00:20:49.358: ASYNCIO [ERROR]:Poll failed --
00:20:50.369: ASYNCIO [ERROR]:Poll failed --
00:20:51.380: ASYNCIO [ERROR]:Poll failed --
00:20:52.391: ASYNCIO [ERROR]:Poll failed --
00:20:53.402: ASYNCIO [ERROR]:Poll failed --
00:20:54.412: ASYNCIO [ERROR]:Poll failed --
00:20:55.423: ASYNCIO [ERROR]:Poll failed --
00:20:56.434: ASYNCIO [ERROR]:Poll failed --
00:20:57.444: ASYNCIO [ERROR]:Poll failed --
00:20:58.455: ASYNCIO [ERROR]:Poll failed --
00:20:59.031: SPUMINER [DEBUG]:SPU-2 found nonce 0x7fc6df86 for work 2e4e
00:20:59.466: ASYNCIO [ERROR]:Poll failed --
00:21:00.476: ASYNCIO [ERROR]:Poll failed --
00:21:01.487: ASYNCIO [ERROR]:Poll failed --
00:21:02.498: ASYNCIO [ERROR]:Poll failed --
00:21:03.509: ASYNCIO [ERROR]:Poll failed --
00:21:04.519: ASYNCIO [ERROR]:Poll failed --
00:21:05.530: ASYNCIO [ERROR]:Poll failed --
00:21:06.541: ASYNCIO [ERROR]:Poll failed --
00:21:07.551: ASYNCIO [ERROR]:Poll failed --
00:21:08.594: ASYNCIO [ERROR]:Poll failed --
00:21:09.605: ASYNCIO [ERROR]:Poll failed --
00:21:10.615: ASYNCIO [ERROR]:Poll failed --
00:21:11.626: ASYNCIO [ERROR]:Poll failed --
00:21:12.637: ASYNCIO [ERROR]:Poll failed --
00:21:13.647: ASYNCIO [ERROR]:Poll failed --
00:21:14.658: ASYNCIO [ERROR]:Poll failed --
00:21:15.670: ASYNCIO [ERROR]:Poll failed --
00:21:16.681: ASYNCIO [ERROR]:Poll failed --
00:21:17.691: ASYNCIO [ERROR]:Poll failed --
00:21:18.703: ASYNCIO [ERROR]:Poll failed --
00:21:19.714: ASYNCIO [ERROR]:Poll failed --
00:21:20.724: ASYNCIO [ERROR]:Poll failed --
00:21:21.735: ASYNCIO [ERROR]:Poll failed --
00:21:22.746: ASYNCIO [ERROR]:Poll failed --
00:21:23.756: ASYNCIO [ERROR]:Poll failed --
00:21:24.767: ASYNCIO [ERROR]:Poll failed --
00:21:25.777: ASYNCIO [ERROR]:Poll failed --
00:21:26.788: ASYNCIO [ERROR]:Poll failed --
00:21:27.798: ASYNCIO [ERROR]:Poll failed --
00:21:28.809: ASYNCIO [ERROR]:Poll failed --
00:21:29.820: ASYNCIO [ERROR]:Poll failed --
00:21:30.831: ASYNCIO [ERROR]:Poll failed --
00:21:31.842: ASYNCIO [ERROR]:Poll failed --
00:21:32.853: ASYNCIO [ERROR]:Poll failed --
00:21:33.863: ASYNCIO [ERROR]:Poll failed --
00:21:34.874: ASYNCIO [ERROR]:Poll failed --
00:21:35.884: ASYNCIO [ERROR]:Poll failed --
00:21:36.895: ASYNCIO [ERROR]:Poll failed --
00:21:37.906: ASYNCIO [ERROR]:Poll failed --
00:21:38.916: ASYNCIO [ERROR]:Poll failed --
00:21:39.927: ASYNCIO [ERROR]:Poll failed --
00:21:40.946: ASYNCIO [ERROR]:Poll failed --
00:21:41.965: ASYNCIO [ERROR]:Poll failed --
00:21:42.976: ASYNCIO [ERROR]:Poll failed --
00:21:43.998: ASYNCIO [ERROR]:Poll failed --
00:21:45.018: ASYNCIO [ERROR]:Poll failed --
00:21:46.028: ASYNCIO [ERROR]:Poll failed --
00:21:47.039: ASYNCIO [ERROR]:Poll failed --
00:21:48.050: ASYNCIO [ERROR]:Poll failed --
00:21:49.060: ASYNCIO [ERROR]:Poll failed --
00:21:50.071: ASYNCIO [ERROR]:Poll failed --
00:21:51.081: ASYNCIO [ERROR]:Poll failed --
00:21:52.092: ASYNCIO [ERROR]:Poll failed --
00:21:53.102: ASYNCIO [ERROR]:Poll failed --
00:21:54.113: ASYNCIO [ERROR]:Poll failed --
00:21:55.124: ASYNCIO [ERROR]:Poll failed --
00:21:56.134: ASYNCIO [ERROR]:Poll failed --
00:21:57.145: ASYNCIO [ERROR]:Poll failed --
00:21:58.155: ASYNCIO [ERROR]:Poll failed --

At this point Showtime's webserver is dead. I managed to get log via Webman's FTP server. Video opened above was still playing fine.

#10 Updated by Ema Nymton almost 7 years ago

Nice catch! I wasn't able to reproduce it at will!

#11 Updated by Ema Nymton almost 7 years ago

I assumed this was linked to files being played over SMB as I never encountered this error at all when I was playing my files on a local medium (external HDD). I suspect this bug has been introduced in the new ST builds around September onwards.

#12 Updated by Leonid Protasov almost 7 years ago

I see miner between those ASYNCIOs xD

#13 Updated by Leonid Protasov almost 7 years ago

Well Showtime's FTP server is not answering too. UPnP dissapeared in Windows7 Network neighbourhood. But plugins are working, I can play items etc. So network works, but somehow Showtime's network modules/deamons fail. ASYNCIO [ERROR]:Poll failed -- keeps flooding log.

#14 Updated by Leonid Protasov almost 7 years ago

  • Found in version changed from 4.3.536 to 4.3.633

Keeps flooding with:
00:01:49.248: ASYNCIO [ERROR]:Poll failed -- errno:104
00:01:49.279: ASYNCIO [ERROR]:FD dump follows
00:01:49.280: ASYNCIO [ERROR]:FD 0x4000005a events:19 refcount:1 (HTTP connection)
00:01:49.280: ASYNCIO [ERROR]:FD 0x4000004d events:1 refcount:1 (http-server)
00:01:49.280: ASYNCIO [ERROR]:FD 0x4000004c events:1 refcount:1 (ftp-server)
00:01:49.280: ASYNCIO [ERROR]:FD 0x4000004a events:1 refcount:1 (Courier)
00:01:50.291: ASYNCIO [ERROR]:Poll failed -- errno:104
00:01:50.291: ASYNCIO [ERROR]:FD dump follows
00:01:50.291: ASYNCIO [ERROR]:FD 0x4000005a events:19 refcount:1 (HTTP connection)
00:01:50.292: ASYNCIO [ERROR]:FD 0x4000004d events:1 refcount:1 (http-server)
00:01:50.292: ASYNCIO [ERROR]:FD 0x4000004c events:1 refcount:1 (ftp-server)
00:01:50.292: ASYNCIO [ERROR]:FD 0x4000004a events:1 refcount:1 (Courier)
00:01:51.303: ASYNCIO [ERROR]:Poll failed -- errno:104

#15 Updated by Leonid Protasov almost 7 years ago

This bug is related to https://showtimemediacenter.com/issues/1778
I also get mp3 with clicking soung and from time to time playback even interrupts. When that happens - ASYNCIO flooding above is happening.

#16 Updated by Ema Nymton almost 7 years ago

Now that's really a weird stuff...

#17 Updated by Leonid Protasov almost 7 years ago

I rechecked and it seems like is not related. I just caught ASYNCIO madness at the time of trying. And clicking sound was from corrupted MP3 files :)

#18 Updated by Leonid Protasov almost 7 years ago

Guess what. I checked my settings:dev and HTTP connection reuse was on. Switched it off and no more ASINCIOs...

#19 Updated by Andreas Smas almost 7 years ago

Interesting. Must be some kind of memory corruption going on then. I'll investigate

#20 Updated by Leonid Protasov almost 7 years ago

Turning off connection reuse just made madness start later. MP3 play nice. But log is flooding.
00:35:32.545: SPUMINER [DEBUG]:SPU-5 found nonce 0xe1b62fa2 for work 304d
00:39:11.554: Audio [DEBUG]:Starting playback of smb://192.168.0.190/c$/sams/Narcotic.mp3
00:39:11.866: lastfm [DEBUG]:Loading images for artist Giorgos Mazonakis
00:39:12.305: lastfm [DEBUG]:HTTP query to lastfm failed: HTTP error: 400
00:39:12.306: lastfm [DEBUG]:Loading coverart for album Sabbato
00:43:03.951: Audio [DEBUG]:Starting playback of smb://192.168.0.190/c$/sams/Lloyd Banks - On Fire.mp3
00:44:15.477: SPUMINER [DEBUG]:SPU-0 found nonce 0x0c86fca6 for work 3057
00:46:12.879: Audio [DEBUG]:Starting playback of smb://192.168.0.190/c$/sams/50 Cent - Poppin Them Thangs.mp3
00:46:12.890: lastfm [DEBUG]:Loading coverart for album Beg For Mercy
00:50:16.221: Audio [DEBUG]:Starting playback of smb://192.168.0.190/c$/sams/50 cent - Projects Too Hot.mp3
00:50:16.553: lastfm [DEBUG]:Loading coverart for album нет альбома
00:52:05.414: lastfm [DEBUG]:Loading images for artist 50 cent
00:52:58.284: ASYNCIO [ERROR]:Poll failed -- errno:104
00:52:58.284: ASYNCIO [ERROR]:FD dump follows
00:52:58.285: ASYNCIO [ERROR]:FD 0x40000178 events:19 refcount:1 (HTTP connection)
00:52:58.285: ASYNCIO [ERROR]:FD 0x40000060 events:1 refcount:1 (http-server)
00:52:58.285: ASYNCIO [ERROR]:FD 0x4000005f events:1 refcount:1 (ftp-server)
00:52:58.285: ASYNCIO [ERROR]:FD 0x4000005d events:1 refcount:1 (Courier)
00:52:59.296: ASYNCIO [ERROR]:Poll failed -- errno:104
00:52:59.296: ASYNCIO [ERROR]:FD dump follows
00:52:59.297: ASYNCIO [ERROR]:FD 0x40000178 events:19 refcount:1 (HTTP connection)
00:52:59.298: ASYNCIO [ERROR]:FD 0x40000060 events:1 refcount:1 (http-server)
00:52:59.298: ASYNCIO [ERROR]:FD 0x4000005f events:1 refcount:1 (ftp-server)
00:52:59.298: ASYNCIO [ERROR]:FD 0x4000005d events:1 refcount:1 (Courier)
00:53:00.309: ASYNCIO [ERROR]:Poll failed -- errno:104

#21 Updated by Leonid Protasov almost 7 years ago

I assumed that miner can have effect on this issue. I did:
1. switched off miner and turned on http connection reuse.
2. switched off miner and turned off http connection reuse
in case 1 - ASYNCIO happened quickly
in case 2 - ASYNCIO happened in half an hour.

So miner has no effect on that. HTTP connection reuse make issue happen quick. But even with HTTP connection reuse off and with miner off - issue happens. So looks like memleak or something.

#22 Updated by Andreas Smas almost 7 years ago

  • Status changed from Accepted to Fixed
  • % Done changed from 0 to 100

Applied in changeset git|commit:d1fcd3f00dd18fd71b44486ae04d406f8789b949.

Also available in: Atom PDF