How can we help you today?
Start a new topic

Provisioning fails with 500 internal server error

We've just moved offices and since moving our Snom phones I have noticed that provisioning is not working. In the phone logs I can see a "Config setup: code 500" message.


Nov 11 14:15:33.870 [NOTICE] PHN: Fetching URL: https://<server-addr>:443/snom.php?...

Nov 11 14:15:33.871 [DEBUG2] WEBCLIENT: Send TCP none

Nov 11 14:15:33.872 [DEBUG2] WEBCLIENT: Socket 25 dns_resolving

Nov 11 14:15:33.876 [DEBUG1] TLS: 0xae1cf0 session cache rem 0

Nov 11 14:15:33.877 [DEBUG1] TLS: 0xaede08 SSL Alert read/0:warning:close notify

Nov 11 14:15:33.877 [ERROR ] PHN: TPL: Socket Error: 23/34/connected, Tls error, closing

Nov 11 14:15:33.878 [DEBUG2] PHN: WEB: HTTP 23/443 disconnected

Nov 11 14:15:33.878 [DEBUG2] PHN: WEB: HTTP 23/443 deleted

Nov 11 14:15:33.881 [DEBUG2] WEBCLIENT: Socket 24 connected

Nov 11 14:15:33.885 [DEBUG1] PHN: Add Cache: <server-addr>=<ip-addr> (ttl=60, type=5)

Nov 11 14:15:33.885 [DEBUG1] PHN: Add Cache: <server-addr>=<ip-addr> (ttl=60, type=5)

Nov 11 14:15:33.885 [DEBUG1] PHN: Add Cache: <server-addr>=<ip-addr> (ttl=60, type=5)

Nov 11 14:15:33.885 [DEBUG1] PHN: Add Cache: <server-addr>=<ip-addr> (ttl=60, type=5)

Nov 11 14:15:33.885 [DEBUG1] PHN: Add Cache: <server-addr>=<ip-addr> (ttl=60, type=5)

Nov 11 14:15:33.885 [DEBUG1] PHN: Add Cache: <server-addr>=<ip-addr> (ttl=60, type=5)

Nov 11 14:15:33.886 [DEBUG2] WEBCLIENT: Socket 25 dns_resolved

Nov 11 14:15:33.886 [DEBUG2] WEBCLIENT: Send TCP dns_resolved

Nov 11 14:15:33.887 [DEBUG2] WEBCLIENT: Socket 25 connecting

Nov 11 14:15:33.892 [DEBUG2] TLS: 0xaede08 SSL_connect/0 before/connect initialization (0)

Nov 11 14:15:33.892 [DEBUG2] TLS: 0xaede08 SSL_connect/0 SSLv2/v3 write client hello A (0)

Nov 11 14:15:33.892 [DEBUG2] WEBCLIENT: Socket 25 connected

Nov 11 14:15:33.900 [DEBUG2] WEBCLIENT: Socket 24 disconnected

Nov 11 14:15:33.900 [DEBUG2] WEBCLIENT: Socket 24 deleted

Nov 11 14:15:33.900 [INFO ] PHN: Update: Fetching FW URL: http://provisioning.snom.com:80/update6to7/update.php done, result 403

Nov 11 14:15:33.906 [DEBUG2] TLS: 0xaede08 SSL_connect/0 SSLv3 read server hello A (0)

Nov 11 14:15:33.912 [WARN ] TLS: CertVerification for PhoneCtx disabled!

Nov 11 14:15:33.916 [DEBUG2] TLS: 0xaede08 SSL_connect/0 SSLv3 read server certificate A (0)

Nov 11 14:15:33.952 [DEBUG2] TLS: 0xaede08 SSL_connect/0 SSLv3 read server key exchange A (0)

Nov 11 14:15:33.954 [DEBUG2] TLS: 0xaede08 SSL_connect/0 SSLv3 read server done A (0)

Nov 11 14:15:34.007 [DEBUG2] TLS: 0xaede08 SSL_connect/0 SSLv3 write client key exchange A (0)

Nov 11 14:15:34.009 [DEBUG2] TLS: 0xaede08 SSL_connect/0 SSLv3 write change cipher spec A (0)

Nov 11 14:15:34.009 [DEBUG2] TLS: 0xaede08 SSL_connect/0 SSLv3 write finished A (0)

Nov 11 14:15:34.010 [DEBUG2] TLS: 0xaede08 SSL_connect/0 SSLv3 flush data (0)

Nov 11 14:15:34.015 [DEBUG2] TLS: 0xaede08 SSL_connect/0 SSLv3 read server session ticket A (0)

Nov 11 14:15:34.016 [DEBUG2] TLS: 0xaede08 SSL_connect/0 SSLv3 read finished A (0)

Nov 11 14:15:34.017 [DEBUG2] TLS: 0xaede08 handshake success

Nov 11 14:15:34.017 [DEBUG1] TLS: 0xad89c8 session cache add 1

Nov 11 14:15:34.053 [DEBUG1] TLS: 0xaede08 SSL Alert write/0:warning:close notify

Nov 11 14:15:34.054 [DEBUG2] WEBCLIENT: Socket 25 disconnecting

Nov 11 14:15:34.055 [DEBUG2] WEBCLIENT: Socket 25 disconnected

Nov 11 14:15:34.055 [DEBUG2] WEBCLIENT: Socket 25 deleted

Nov 11 14:15:34.055 [INFO ] PHN: Config setup: code: 500, uri: https://<server-addr>:443/scripts/snom.php?...


The provisioning URL works if I connect directly from my laptop. 


Does anyone have any idea why this might be?


We also switched to using HTTPS on the provisioning server recently so I was thinking this could be related. 




1 Comment

No idea what happened with the formatting of the previous post! I will try again here:

We've just moved offices and since moving our Snom phones I have noticed that provisioning is not working. In the phone logs I can see a "Config setup: code 500" message.


Nov 11 14:15:33.870 [NOTICE] PHN: Fetching URL: https://<server-addr>:443/snom.php?...
Nov 11 14:15:33.871 [DEBUG2] WEBCLIENT: Send TCP none
Nov 11 14:15:33.872 [DEBUG2] WEBCLIENT: Socket 25 dns_resolving
Nov 11 14:15:33.876 [DEBUG1] TLS: 0xae1cf0 session cache rem 0
Nov 11 14:15:33.877 [DEBUG1] TLS: 0xaede08 SSL Alert read/0:warning:close notify
Nov 11 14:15:33.877 [ERROR ] PHN: TPL: Socket Error: 23/34/connected, Tls error, closing
Nov 11 14:15:33.878 [DEBUG2] PHN: WEB: HTTP 23/443 disconnected
Nov 11 14:15:33.878 [DEBUG2] PHN: WEB: HTTP 23/443 deleted
Nov 11 14:15:33.881 [DEBUG2] WEBCLIENT: Socket 24 connected
Nov 11 14:15:33.885 [DEBUG1] PHN: Add Cache: <server-addr>=<ip-addr> (ttl=60, type=5)
Nov 11 14:15:33.885 [DEBUG1] PHN: Add Cache: <server-addr>=<ip-addr> (ttl=60, type=5)
Nov 11 14:15:33.885 [DEBUG1] PHN: Add Cache: <server-addr>=<ip-addr> (ttl=60, type=5)
Nov 11 14:15:33.885 [DEBUG1] PHN: Add Cache: <server-addr>=<ip-addr> (ttl=60, type=5)
Nov 11 14:15:33.885 [DEBUG1] PHN: Add Cache: <server-addr>=<ip-addr> (ttl=60, type=5)
Nov 11 14:15:33.885 [DEBUG1] PHN: Add Cache: <server-addr>=<ip-addr> (ttl=60, type=5)
Nov 11 14:15:33.886 [DEBUG2] WEBCLIENT: Socket 25 dns_resolved
Nov 11 14:15:33.886 [DEBUG2] WEBCLIENT: Send TCP dns_resolved
Nov 11 14:15:33.887 [DEBUG2] WEBCLIENT: Socket 25 connecting
Nov 11 14:15:33.892 [DEBUG2] TLS: 0xaede08 SSL_connect/0 before/connect initialization (0)
Nov 11 14:15:33.892 [DEBUG2] TLS: 0xaede08 SSL_connect/0 SSLv2/v3 write client hello A (0)
Nov 11 14:15:33.892 [DEBUG2] WEBCLIENT: Socket 25 connected
Nov 11 14:15:33.900 [DEBUG2] WEBCLIENT: Socket 24 disconnected
Nov 11 14:15:33.900 [DEBUG2] WEBCLIENT: Socket 24 deleted
Nov 11 14:15:33.900 [INFO ] PHN: Update: Fetching FW URL: http://provisioning.snom.com:80/update6to7/update.php done, result 403
Nov 11 14:15:33.906 [DEBUG2] TLS: 0xaede08 SSL_connect/0 SSLv3 read server hello A (0)
Nov 11 14:15:33.912 [WARN ] TLS: CertVerification for PhoneCtx disabled!
Nov 11 14:15:33.916 [DEBUG2] TLS: 0xaede08 SSL_connect/0 SSLv3 read server certificate A (0)
Nov 11 14:15:33.952 [DEBUG2] TLS: 0xaede08 SSL_connect/0 SSLv3 read server key exchange A (0)
Nov 11 14:15:33.954 [DEBUG2] TLS: 0xaede08 SSL_connect/0 SSLv3 read server done A (0)
Nov 11 14:15:34.007 [DEBUG2] TLS: 0xaede08 SSL_connect/0 SSLv3 write client key exchange A (0)
Nov 11 14:15:34.009 [DEBUG2] TLS: 0xaede08 SSL_connect/0 SSLv3 write change cipher spec A (0)
Nov 11 14:15:34.009 [DEBUG2] TLS: 0xaede08 SSL_connect/0 SSLv3 write finished A (0)
Nov 11 14:15:34.010 [DEBUG2] TLS: 0xaede08 SSL_connect/0 SSLv3 flush data (0)
Nov 11 14:15:34.015 [DEBUG2] TLS: 0xaede08 SSL_connect/0 SSLv3 read server session ticket A (0)
Nov 11 14:15:34.016 [DEBUG2] TLS: 0xaede08 SSL_connect/0 SSLv3 read finished A (0)
Nov 11 14:15:34.017 [DEBUG2] TLS: 0xaede08 handshake success
Nov 11 14:15:34.017 [DEBUG1] TLS: 0xad89c8 session cache add 1
Nov 11 14:15:34.053 [DEBUG1] TLS: 0xaede08 SSL Alert write/0:warning:close notify
Nov 11 14:15:34.054 [DEBUG2] WEBCLIENT: Socket 25 disconnecting
Nov 11 14:15:34.055 [DEBUG2] WEBCLIENT: Socket 25 disconnected
Nov 11 14:15:34.055 [DEBUG2] WEBCLIENT: Socket 25 deleted
Nov 11 14:15:34.055 [INFO ] PHN: Config setup: code: 500, uri: https://<server-addr>:443/scripts/snom.php?...

 

The provisioning URL works if I connect directly from my laptop. 


Does anyone have any idea why this might be?


We also switched to using HTTPS on the provisioning server recently so I was thinking this could be related. 

Login or Signup to post a comment