Twonky Server Issue : internal error (specified device does not exist)

aldapooh
aldapooh Posts: 14
edited November 10 in Personal Cloud Storage
NAS542 Firmware Firmware version:V5.21(ABAG.7)

Since few days Twonky Server does not start properly

I did not change any NAS / Twonky settings neither did I upgrade NAS Firmware.
All of a sudden Twonky shows the error in Web:
Internal error (Specified device does not exist)



When checking twonkyserver-log.log I see the following errors:

<div>2021-11-10 16:00:53:626&nbsp; &nbsp; 101303 [Startup] - LOG_SYSTEM: twonkylib_init : *** Starting TwonkyServer (Product Name:Twonky, Version:8.5.2, Build-date:Jan 20 2021) ***</div><div>2021-11-10 16:00:53:626&nbsp; &nbsp; 101369 [Startup] - LOG_SYSTEM: twonkylib_init : *** Platform:arm_msp_linux_gnueabihf__zyxel-NAS-540-arm-msp-gnueabihf-oem, Snapshot:Twonky_8.5.2-4_20210119&nbsp; TA:2ba39c0b0291f07f2a85af402f680ff4e602af89 ***</div><div>2021-11-10 16:00:53:626&nbsp; &nbsp; 101252 [Startup] - LOG_SYSTEM: twonkylib_init : using logfile /tmp/twonkyserver-log.txt</div><div>2021-11-10 16:00:53:626&nbsp; &nbsp; 101265 [Startup] - LOG_SYSTEM: twonkylib_init : Executable file: /usr/local/dmsf/binary/twonkyserver</div><div>2021-11-10 16:00:53:626&nbsp; &nbsp; 101239 [Startup] - LOG_SYSTEM: twonkylib_init : Command Line Parameters: 2</div><div>2021-11-10 16:00:53:626&nbsp; &nbsp; 101231 [Startup] - LOG_SYSTEM: twonkylib_init : cmdline 1:-appdata</div><div>2021-11-10 16:00:53:626&nbsp; &nbsp; 101249 [Startup] - LOG_SYSTEM: twonkylib_init : cmdline 2:/i-data/.media/twonkymedia</div><div>2021-11-10 16:00:53:700&nbsp; &nbsp; 159353 [Startup] - LOG_SYSTEM: upnp_ini_file_read_properties_from_file : reading ini settings from /i-data/.media/twonkymedia/twonkyserver.ini</div><div>2021-11-10 16:00:53:734&nbsp; &nbsp; 142907 [Startup] - LOG_SYSTEM: upnp_ini_file_read_properties_from_file : friendlyname = %HOSTNAME%</div><div>2021-11-10 16:00:53:734&nbsp; &nbsp; 142888 [Startup] - LOG_SYSTEM: upnp_ini_file_read_properties_from_file : ip =&nbsp;</div><div>2021-11-10 16:00:53:734&nbsp; &nbsp; 142899 [Startup] - LOG_SYSTEM: upnp_ini_file_read_properties_from_file : nicrestart = 0</div><div>2021-11-10 16:01:03:855&nbsp; 11040380 [Error] - LOG_HTTP: tls_client_session_create : TLS client session authentication failed: X509_ERROR_NONE</div><div>2021-11-10 16:01:03:856&nbsp; 11021951 [Error] - LOG_HTTP: upnp_tls_client_twonky_session_create : TLS client-module: could not create session</div><div>2021-11-10 16:01:03:856&nbsp; 11021928 [Error] - LOG_HTTP: _HTTP_talk : TLS: cannot create client-session in _HTTP_talk</div><div>2021-11-10 16:01:03:885&nbsp; 11025942 [Error] - LOG_HTTP: tls_client_session_create : TLS client session authentication failed: X509_ERROR_NONE</div><div>2021-11-10 16:01:03:885&nbsp; 11007513 [Error] - LOG_HTTP: upnp_tls_client_twonky_session_create : TLS client-module: could not create session</div><div>2021-11-10 16:01:03:885&nbsp; 11007490 [Error] - LOG_HTTP: _HTTP_talk : TLS: cannot create client-session in _HTTP_talk</div><div>2021-11-10 16:15:32:159&nbsp; 19236032 [Error] - LOG_HTTP: rssProcessServerList : Error processing /nmc/rss/server/RBuuid:55076f6e-6b79-1d65-a477-082697781704,0?start=0&fmt=json: 3</div><div>2021-11-10 16:20:02:679&nbsp; 19689017 [Error] - LOG_HTTP: rssProcessServerList : Error processing /nmc/rss/server/RBuuid:55076f6e-6b79-1d65-a477-082697781704,0?start=0&fmt=json: 3</div><div>2021-11-10 16:24:24:779&nbsp; 20097369 [Error] - LOG_HTTP: rssProcessServerList : Error processing /nmc/rss/server/RBuuid:55076f6e-6b79-1d65-a477-082697781704,0?start=0&fmt=json: 3</div><div>2021-11-10 16:26:19:797&nbsp; 20305709 [Error] - LOG_HTTP: rssProcessServerList : Error processing /nmc/rss/server/RBuuid:55076f6e-6b79-1d65-a477-082697781704,0?start=0&fmt=json: 3</div><div>2021-11-10 16:27:41:249&nbsp; 20411878 [Error] - LOG_HTTP: rssProcessServerList : Error processing /nmc/rss/server/RBuuid:55076f6e-6b79-1d65-a477-082697781704,0?start=0&fmt=json: 3</div><div>2021-11-10 16:35:55:559&nbsp; 21309256 [Error] - LOG_HTTP: rssProcessServerList : Error processing /nmc/rss/server/RBuuid:55076f6e-6b79-1d65-a477-082697781704,0?start=0&fmt=json: 3</div><div>2021-11-10 16:44:50:379&nbsp; 22165817 [Error] - LOG_HTTP: rssProcessServerList : Error processing /nmc/rss/server/RBuuid:55076f6e-6b79-1d65-a477-082697781704,0?start=0&fmt=json: 3</div>



log as a picture due to display issue



PS restart of NAS does not help

Please advise
Thanks!

Best Answer

  • aldapooh
    aldapooh Posts: 14
    Accepted Answer
    What I found on with my own research that the issue is probably related to persistency and parameters below from twonkyparameters.ini:

    # scheme for UDN creation, stored after inital UUID creating (DO NOT MODIFY to keep UUID persistence)
    udn_scheme=uuid:54776f6e-6b79-1d65-a477-082697781704

    This UUID was no longer valid - the reason is not known to me.

    Now to resolution part:

    I cannot install and unistall Twonky as it part of ZyXEL NAS and delivered as OEM. There is no easy way to install/uninstall something on this NAS without root access

    restarting of Twonky or/and NAS do not help

    what helped was - disabling the Twonky shares via NAS Web UI -and virtually killing the Twonky DB. Restarting Twonky. And enabling the Twonky Shares via NAS Web UI.

    That triggered Twonky DB rescan of all files, and Twonky started working.

    What I still do not understand how the issue popped up. And if there was a more elegant way to solve my issue.

    Can you maybe report a bug for that issue and see if there is a better way to handle such errors? (when experiencing the error Twonky process allocated up to 90% CPU and was basically hanging so to me it looks like a bug anyway) Also understanding the root cause would be nice

    Thanks, -A

Answers

  • aldapooh
    aldapooh Posts: 14
    edited November 10
    Logfile in readable format:

    2021-11-10 16:00:53:626    101303 [Startup] - LOG_SYSTEM: twonkylib_init : *** Starting TwonkyServer (Product Name:Twonky, Version:8.5.2, Build-date:Jan 20 2021) ***
    2021-11-10 16:00:53:626    101369 [Startup] - LOG_SYSTEM: twonkylib_init : *** Platform:arm_msp_linux_gnueabihf__zyxel-NAS-540-arm-msp-gnueabihf-oem, Snapshot:Twonky_8.5.2-4_20210119  TA:2ba39c0b0291f07f2a85af402f680ff4e602af89 ***
    2021-11-10 16:00:53:626    101252 [Startup] - LOG_SYSTEM: twonkylib_init : using logfile /tmp/twonkyserver-log.txt
    2021-11-10 16:00:53:626    101265 [Startup] - LOG_SYSTEM: twonkylib_init : Executable file: /usr/local/dmsf/binary/twonkyserver
    2021-11-10 16:00:53:626    101239 [Startup] - LOG_SYSTEM: twonkylib_init : Command Line Parameters: 2
    2021-11-10 16:00:53:626    101231 [Startup] - LOG_SYSTEM: twonkylib_init : cmdline 1:-appdata
    2021-11-10 16:00:53:626    101249 [Startup] - LOG_SYSTEM: twonkylib_init : cmdline 2:/i-data/.media/twonkymedia
    2021-11-10 16:00:53:700    159353 [Startup] - LOG_SYSTEM: upnp_ini_file_read_properties_from_file : reading ini settings from /i-data/.media/twonkymedia/twonkyserver.ini
    2021-11-10 16:00:53:734    142907 [Startup] - LOG_SYSTEM: upnp_ini_file_read_properties_from_file : friendlyname = %HOSTNAME%
    2021-11-10 16:00:53:734    142888 [Startup] - LOG_SYSTEM: upnp_ini_file_read_properties_from_file : ip = 
    2021-11-10 16:00:53:734    142899 [Startup] - LOG_SYSTEM: upnp_ini_file_read_properties_from_file : nicrestart = 0
    2021-11-10 16:01:03:855  11040380 [Error] - LOG_HTTP: tls_client_session_create : TLS client session authentication failed: X509_ERROR_NONE
    2021-11-10 16:01:03:856  11021951 [Error] - LOG_HTTP: upnp_tls_client_twonky_session_create : TLS client-module: could not create session
    2021-11-10 16:01:03:856  11021928 [Error] - LOG_HTTP: _HTTP_talk : TLS: cannot create client-session in _HTTP_talk
    2021-11-10 16:01:03:885  11025942 [Error] - LOG_HTTP: tls_client_session_create : TLS client session authentication failed: X509_ERROR_NONE
    2021-11-10 16:01:03:885  11007513 [Error] - LOG_HTTP: upnp_tls_client_twonky_session_create : TLS client-module: could not create session
    2021-11-10 16:01:03:885  11007490 [Error] - LOG_HTTP: _HTTP_talk : TLS: cannot create client-session in _HTTP_talk
    2021-11-10 16:15:32:159  19236032 [Error] - LOG_HTTP: rssProcessServerList : Error processing /nmc/rss/server/RBuuid:55076f6e-6b79-1d65-a477-082697781704,0?start=0&fmt=json: 3
    2021-11-10 16:20:02:679  19689017 [Error] - LOG_HTTP: rssProcessServerList : Error processing /nmc/rss/server/RBuuid:55076f6e-6b79-1d65-a477-082697781704,0?start=0&fmt=json: 3
    2021-11-10 16:24:24:779  20097369 [Error] - LOG_HTTP: rssProcessServerList : Error processing /nmc/rss/server/RBuuid:55076f6e-6b79-1d65-a477-082697781704,0?start=0&fmt=json: 3
    2021-11-10 16:26:19:797  20305709 [Error] - LOG_HTTP: rssProcessServerList : Error processing /nmc/rss/server/RBuuid:55076f6e-6b79-1d65-a477-082697781704,0?start=0&fmt=json: 3
    2021-11-10 16:27:41:249  20411878 [Error] - LOG_HTTP: rssProcessServerList : Error processing /nmc/rss/server/RBuuid:55076f6e-6b79-1d65-a477-082697781704,0?start=0&fmt=json: 3
    2021-11-10 16:35:55:559  21309256 [Error] - LOG_HTTP: rssProcessServerList : Error processing /nmc/rss/server/RBuuid:55076f6e-6b79-1d65-a477-082697781704,0?start=0&fmt=json: 3
    2021-11-10 16:44:50:379  22165817 [Error] - LOG_HTTP: rssProcessServerList : Error processing /nmc/rss/server/RBuuid:55076f6e-6b79-1d65-a477-082697781704,0?start=0&fmt=json: 3

  • aldapooh
    aldapooh Posts: 14
    top command shows twonkyserver consuming most of CPU (90%) and is basically hanging

     2025  2023 root     S N  55884  5.5   1 88.9 /usr/local/dmsf/binary/twonkyserver -appdata /i-data/.media/twonkymedia

  • aldapooh
    aldapooh Posts: 14
    I tried to disable twonky via NAS Control Panel and enabling after some time



    This did not resolve the issue. Still getting error: Internal error (Specified device does not exist)

    But the twonkyserver-log shows now errors as below:

    2021-11-10 17:28:38:277    101303 [Startup] - LOG_SYSTEM: twonkylib_init : *** Starting TwonkyServer (Product Name:Twonky, Version:8.5.2, Build-date:Jan 20 2021) ***
    2021-11-10 17:28:38:277    101369 [Startup] - LOG_SYSTEM: twonkylib_init : *** Platform:arm_msp_linux_gnueabihf__zyxel-NAS-540-arm-msp-gnueabihf-oem, Snapshot:Twonky_8.5.2-4_20210119  TA:2ba39c0b0291f07f2a85af402f680ff4e602af89 ***
    2021-11-10 17:28:38:277    101252 [Startup] - LOG_SYSTEM: twonkylib_init : using logfile /tmp/twonkyserver-log.txt
    2021-11-10 17:28:38:277    101265 [Startup] - LOG_SYSTEM: twonkylib_init : Executable file: /usr/local/dmsf/binary/twonkyserver
    2021-11-10 17:28:38:277    101239 [Startup] - LOG_SYSTEM: twonkylib_init : Command Line Parameters: 2
    2021-11-10 17:28:38:277    101231 [Startup] - LOG_SYSTEM: twonkylib_init : cmdline 1:-appdata
    2021-11-10 17:28:38:277    101249 [Startup] - LOG_SYSTEM: twonkylib_init : cmdline 2:/i-data/.media/twonkymedia
    2021-11-10 17:28:38:283    159353 [Startup] - LOG_SYSTEM: upnp_ini_file_read_properties_from_file : reading ini settings from /i-data/.media/twonkymedia/twonkyserver.ini
    2021-11-10 17:28:38:284    142907 [Startup] - LOG_SYSTEM: upnp_ini_file_read_properties_from_file : friendlyname = %HOSTNAME%
    2021-11-10 17:28:38:284    142888 [Startup] - LOG_SYSTEM: upnp_ini_file_read_properties_from_file : ip = 
    2021-11-10 17:28:38:284    142899 [Startup] - LOG_SYSTEM: upnp_ini_file_read_properties_from_file : nicrestart = 0
    2021-11-10 17:28:40:875  11129283 [Error] - LOG_SYSTEM: upnp_add_dial_chromecast_device : Invoked with incomplete DIAL device: [name:<null>] [udn:uuid:985f0ff0-144511df-8000-84a46622169c] [url:http://192.168.1.62:41952/dd.xml] [ip:192.168.1.62]
    2021-11-10 17:28:40:876  11127848 [Error] - LOG_SYSTEM: upnp_add_dial_chromecast_device : Invoked with incomplete DIAL device: [name:<null>] [udn:uuid:985f0ff0-144511df-8000-84a46622169c] [url:http://192.168.1.62:41952/dd.xml] [ip:192.168.1.62]
    2021-11-10 17:28:40:876  11126413 [Error] - LOG_SYSTEM: upnp_add_dial_chromecast_device : Invoked with incomplete DIAL device: [name:<null>] [udn:uuid:985f0ff0-144511df-8000-84a46622169c] [url:http://192.168.1.62:41952/dd.xml] [ip:192.168.1.62]
    2021-11-10 17:31:23:169  17500907 [Error] - LOG_HTTP: rssProcessServerList : Error processing /nmc/rss/server/RBuuid:55076f6e-6b79-1d65-a477-082697781704,0?start=0&fmt=json: 3