14/3/2013 10:19:31 [ERROR ] PHN: TPL: Socket Error: 25/27/connected, poll data_cb -> Resource temporarily unavailable (11)

[Paul Multi]

Hi,

 

I have some strange errors from one client in my 3cx network and I cant pin point the root cause.

For a moment I thought it could be the PnP settings (url) how ever after an update the issue perssits.

 

1/1/1970 00:00:00 [ALERT ] PHN: Starting up 2

1/1/1970 00:00:00 [ALERT ] PHN: Starting up 3

1/1/2000 00:00:32 [ALERT ] CFG: read_old_settings: No /snomconfig/raw_settings found for reading.

1/1/2000 00:00:32 [NOTICE] CFG: read_xml_settings: found phone-settings XML header

1/1/2000 00:00:32 [NOTICE] CFG: read_xml_settings: found one byte encoding: 0

1/1/2000 00:00:32 [NOTICE] CFG: read_xml_settings: found network-settings XML header

1/1/2000 00:00:32 [NOTICE] CFG: read_xml_settings: found one byte encoding: 1

1/1/2000 00:00:32 [NOTICE] CFG: read_xml_settings: found ReplacementPlan XML header

1/1/2000 00:00:32 [NOTICE] CFG: read_xml_settings: found one byte encoding: 1

1/1/2000 00:00:32 [NOTICE] CFG: read_xml_settings: found function-keys XML header

1/1/2000 00:00:32 [NOTICE] CFG: read_xml_settings: found one byte encoding: 0

1/1/2000 00:00:33 [NOTICE] CFG: read_xml_settings: found firmware-settings XML header

1/1/2000 00:00:33 [NOTICE] CFG: read_xml_settings: found one byte encoding: 0

1/1/2000 00:00:33 [CRITIC] GUI: Display disabled state: [off]

1/1/2000 00:00:33 [NOTICE] PHN: Fast read of /mnt/snomlang/gui_lang_DA.xml successful.

1/1/2000 00:00:33 [NOTICE] PHN: Fast read of /mnt/snomlang/gui_lang_DE.xml successful.

1/1/2000 00:00:33 [NOTICE] PHN: Fast read of /mnt/snomlang/gui_lang_EN.xml successful.

1/1/2000 00:00:33 [NOTICE] PHN: Fast read of /mnt/snomlang/gui_lang_ES.xml successful.

1/1/2000 00:00:33 [NOTICE] PHN: Fast read of /mnt/snomlang/gui_lang_FR.xml successful.

1/1/2000 00:00:33 [NOTICE] PHN: Fast read of /mnt/snomlang/gui_lang_IT.xml successful.

1/1/2000 00:00:33 [NOTICE] PHN: Fast read of /mnt/snomlang/gui_lang_NL.xml successful.

1/1/2000 00:00:33 [NOTICE] PHN: Fast read of /mnt/snomlang/gui_lang_PT.xml successful.

1/1/2000 00:00:33 [NOTICE] PHN: Fast read of /mnt/snomlang/gui_lang_RU.xml successful.

1/1/2000 00:00:33 [NOTICE] PHN: Fast read of /mnt/snomlang/gui_lang_SV.xml successful.

1/1/2000 00:00:33 [NOTICE] PHN: Using gui lang Svenska at index:9 from: /mnt/snomlang/gui_lang_SV.xml

1/1/2000 00:00:34 [NOTICE] PHN: Fast read of /mnt/snomlang/web_lang_DA.xml successful.

1/1/2000 00:00:34 [NOTICE] PHN: Fast read of /mnt/snomlang/web_lang_DE.xml successful.

1/1/2000 00:00:34 [NOTICE] PHN: Fast read of /mnt/snomlang/web_lang_EN.xml successful.

1/1/2000 00:00:34 [NOTICE] PHN: Fast read of /mnt/snomlang/web_lang_ES.xml successful.

1/1/2000 00:00:34 [NOTICE] PHN: Fast read of /mnt/snomlang/web_lang_FR.xml successful.

1/1/2000 00:00:34 [NOTICE] PHN: Fast read of /mnt/snomlang/web_lang_IT.xml successful.

1/1/2000 00:00:34 [NOTICE] PHN: Fast read of /mnt/snomlang/web_lang_NL.xml successful.

1/1/2000 00:00:34 [NOTICE] PHN: Fast read of /mnt/snomlang/web_lang_PT.xml successful.

1/1/2000 00:00:34 [NOTICE] PHN: Fast read of /mnt/snomlang/web_lang_RU.xml successful.

1/1/2000 00:00:34 [NOTICE] PHN: Using web lang English at index:2 from: /mnt/snomlang/web_lang_EN.xml

1/1/2000 00:00:35 [NOTICE] CFG: read_xml_settings: found dial-plan XML header

1/1/2000 00:00:35 [NOTICE] CFG: read_xml_settings: found one byte encoding: 0

1/1/2000 00:00:36 [NOTICE] PHN: SIP: Udp listener connected

1/1/2000 00:00:36 [NOTICE] PHN: Setting server prio 1, type redirection, url: >http://10.10.5.34:5000/provisioning/TcxProvFiles/3cxProv_130104143719_126.xml<'>http://10.10.5.34:5000/provisioning/TcxProvFiles/3cxProv_130104143719_126.xml<

1/1/2000 00:00:36 [NOTICE] PHN: Fetching URL: http://10.10.5.34:5000/provisioning/TcxProvFiles/3cxProv_130104143719_126.xml

1/1/2000 00:00:38 [NOTICE] LID: Opening TCP socket on port 7547

1/1/2000 00:00:38 [NOTICE] LID: Opening TCP socket on port 843

1/1/2000 00:00:38 [FATAL ] PHN: Phone::uboot_version:1.1.3-u

1/1/2000 00:00:38 [NOTICE] CFG: read_xml_settings: found no XML header; probably old style format

1/1/2000 00:00:38 [NOTICE] PHN: Config setup: found old style settings

1/1/2000 00:00:38 [NOTICE] PHN: last prov successful:1; uri: >http://10.10.5.34:5000/provisioning/TcxProvFiles/3cxProv_130104143719_126.xml<'>http://10.10.5.34:5000/provisioning/TcxProvFiles/3cxProv_130104143719_126.xml<; default uri: >http://provisioning.snom.com/snom370/snom370.php?mac={mac}<

1/1/2000 00:00:38 [NOTICE] PHN: Fetching URL: http://10.10.5.34:5000/provisioning/TcxProvFiles/3cxProv_130104143719_126-0004133A516E.xml

1/1/2000 00:00:38 [ALERT ] PHN: Config setup: code: 404, uri: http://10.10.5.34:5000/provisioning/TcxProvFiles/3cxProv_130104143719_126-0004133A516E.xml

1/1/2000 00:00:38 [NOTICE] PHN: Fetching URL: http://127.0.0.1:80/dummy.htm

1/1/2000 00:00:38 [ERROR ] PHN: TPL: Socket Error: 11/21/connecting, connect_cb -> Operation now in progress (150)

1/1/2000 00:00:38 [NOTICE] PHN: webclient::on_tcp_close conn_id:3

1/1/2000 00:00:38 [ALERT ] PHN: Config setup: code: 500, uri: http://127.0.0.1:80/dummy.htm

1/1/2000 00:00:38 [NOTICE] PHN: Fetching FW URL: http://10.10.5.34:5000/provisioning/TcxProvFiles/snom370-firmware.htm

1/1/2000 00:00:38 [NOTICE] PHN: Fetching URL: http://10.10.5.34:5000/provisioning/TcxProvFiles/snom370-firmware.htm

1/1/2000 00:00:38 [NOTICE] PHN: Last provisioning was successful, thus stop here!

1/1/2000 00:00:38 [NOTICE] PHN: Go to wizzard if all settings have been read.

1/1/2000 00:00:38 [NOTICE] PHN: SetProvisioningDone

1/1/2000 01:00:39 [CRITIC] PHN: start_dst(954036000) end_dst(972788400) offset_dst(3600) offset_utc(3600)

1/1/2000 01:00:39 [CRITIC] PHN: start DST: 03/26/2000 02:00:00 (954036000)

1/1/2000 01:00:39 [CRITIC] PHN: end DST: 10/29/2000 03:00:00 (972788400)

1/1/2000 01:00:39 [NOTICE] CFG: read_xml_settings: found phone-book XML header

1/1/2000 01:00:39 [NOTICE] CFG: read_xml_settings: found one byte encoding: 0

1/1/2000 01:00:39 [NOTICE] PHN: Starting straiten of tbook, size now is 0

1/1/2000 01:00:39 [NOTICE] PHN: Done straiten of tbook, size now is 0

1/1/2000 01:00:39 [NOTICE] PHN: ProvUtils::UcLookUpFirmwareUpdateViaDNS: domain: ><

1/1/2000 01:00:39 [NOTICE] CFG: Settings: Config stored

1/1/2000 01:00:40 [CRITIC] PHN: SIP: packet 1000001 dest invalid udp:10.10.5.34:5060 for Request DISCOVER/-

1/1/2000 01:00:40 [WARN ] PHN: SIP: process_registrar_packet: 401 needs 128 bit nonce

1/1/2000 01:00:40 [NOTICE] PHN: SIP: process auth:Match challenge for user=143, realm=3CXPhoneSystem

1/1/2000 01:00:41 [CRITIC] PHN: SIP: Registered at registrar as 143@3cx.x.se (Expires: 1800 secs)

14/3/2013 10:19:15 [CRITIC] PHN: start_dst(1364695200) end_dst(1382842800) offset_dst(3600) offset_utc(3600)

14/3/2013 10:19:15 [CRITIC] PHN: start DST: 03/31/2013 02:00:00 (1364695200)

14/3/2013 10:19:15 [CRITIC] PHN: end DST: 10/27/2013 03:00:00 (1382842800)

14/3/2013 10:19:15 [WARN ] PHN: SIP: process_registrar_packet: 401 needs 128 bit nonce

14/3/2013 10:19:15 [NOTICE] PHN: SIP: process auth:Match challenge for user=143, realm=3CXPhoneSystem

14/3/2013 10:19:15 [WARN ] PHN: SIP: process_registrar_packet: 401 needs 128 bit nonce

14/3/2013 10:19:15 [NOTICE] PHN: SIP: process auth:Match challenge for user=143, realm=3CXPhoneSystem

14/3/2013 10:19:18 [NOTICE] PHN: TPL: Socket 20 idle/connect timeout

14/3/2013 10:19:22 [NOTICE] PHN: TPL: Socket 13 idle/connect timeout

14/3/2013 10:19:23 [NOTICE] PHN: TPL: Socket 14 idle/connect timeout

14/3/2013 10:19:31 [ERROR ] PHN: TPL: Socket Error: 21/21/connected, poll data_cb -> Resource temporarily unavailable (11)

14/3/2013 10:19:31 [ERROR ] PHN: TPL: Socket Error: 22/24/connected, poll data_cb -> Resource temporarily unavailable (11)

14/3/2013 10:19:31 [ERROR ] PHN: TPL: Socket Error: 23/25/connected, poll data_cb -> Resource temporarily unavailable (11)

14/3/2013 10:19:31 [ERROR ] PHN: TPL: Socket Error: 24/26/connected, poll data_cb -> Resource temporarily unavailable (11)

14/3/2013 10:19:31 [ERROR ] PHN: TPL: Socket Error: 25/27/connected, poll data_cb -> Resource temporarily unavailable (11)

14/3/2013 10:19:34 [NOTICE] PHN: TPL: Socket 27 idle/connect timeout

14/3/2013 10:19:34 [NOTICE] PHN: TPL: Socket 28 idle/connect timeout

14/3/2013 10:19:34 [NOTICE] PHN: TPL: Socket 29 idle/connect timeout

14/3/2013 10:19:34 [NOTICE] PHN: TPL: Socket 30 idle/connect timeout

14/3/2013 10:19:34 [NOTICE] PHN: TPL: Socket 26 idle/connect timeout

 

 

This part----------------------------------------------------------------------------------------------------------------

14/3/2013 10:19:37 [ERROR ] PHN: TPL: Socket Error: 32/24/connected, poll data_cb -> Resource temporarily unavailable (11)

14/3/2013 10:19:37 [ERROR ] PHN: TPL: Socket Error: 33/25/connected, poll data_cb -> Resource temporarily unavailable (11)

14/3/2013 10:19:37 [ERROR ] PHN: TPL: Socket Error: 34/26/connected, poll data_cb -> Resource temporarily unavailable (11)

14/3/2013 10:19:37 [ERROR ] PHN: TPL: Socket Error: 35/27/connected, poll data_cb -> Resource temporarily unavailable (11)

14/3/2013 10:19:37 [ERROR ] PHN: TPL: Socket Error: 36/28/connected, read -> Resource temporarily unavailable (11)

 

Any help here would be great

[Vodia PBX]

Solution: Use snom ONE

[Paul Multi]

Solution: Use snom ONE

 

Please elaborate?

[Vodia PBX]

On this forum, we support snom ONE, not 3CX...