[solved] PHP error reported in curl_setopt() /etc/inc/dyndns.class:294

[phil.davis]

2.3-ALPHA (amd64)
built on Tue Oct 06 19:08:21 CDT 2015

amd64
10.2-STABLE
FreeBSD 10.2-STABLE #84 8aae621(devel): Tue Oct  6 19:26:43 CDT 2015     root@pfs23-amd64-builder:/usr/home/pfsense/pfsense/tmp/obj/usr/home/pfsense/pfsense/tmp/FreeBSD-src/sys/pfSense

Crash report details:

PHP Errors:
[07-Oct-2015 08:59:11 Asia/Kathmandu] PHP Stack trace:
[07-Oct-2015 08:59:11 Asia/Kathmandu] PHP   1\. {main}() /etc/rc.dyndns.update:0
[07-Oct-2015 08:59:11 Asia/Kathmandu] PHP   2\. services_dyndns_configure() /etc/rc.dyndns.update:46
[07-Oct-2015 08:59:11 Asia/Kathmandu] PHP   3\. services_dyndns_configure_client() /etc/inc/services.inc:1772
[07-Oct-2015 08:59:11 Asia/Kathmandu] PHP   4\. updatedns->updatedns() /etc/inc/services.inc:1750
[07-Oct-2015 08:59:11 Asia/Kathmandu] PHP   5\. updatedns->_update() /etc/inc/dyndns.class:257
[07-Oct-2015 08:59:11 Asia/Kathmandu] PHP   6\. curl_setopt() /etc/inc/dyndns.class:294

There is no mention of what the PHP error is, just the stack trace above.
/etc/inc/dyndns.class:294 is:

curl_setopt($ch, CURLOPT_IPRESOLVE, CURL_IPRESOLVE_V4 );

which was added only 4 days ago by: https://github.com/pfsense/pfsense/commit/becd6caa05c6e5cd4ca25c596b8a2350b501b9fb

The IP address of the DynDNS service on this box is up-to-date (showing green) but that might be just because the actual external public IP upstream of this system has not changed for a while.

[cmb]

Which provider(s) are you using?

[phil.davis]

DynDNS (dynamic) only

[phil.davis]

I noticed that I had another trace logged:

[07-Oct-2015 18:48:09 Asia/Kathmandu] PHP Stack trace:
[07-Oct-2015 18:48:09 Asia/Kathmandu] PHP   1\. {main}() /usr/local/www/services_dyndns_edit.php:0
[07-Oct-2015 18:48:09 Asia/Kathmandu] PHP   2\. services_dyndns_configure_client() /usr/local/www/services_dyndns_edit.php:214
[07-Oct-2015 18:48:09 Asia/Kathmandu] PHP   3\. updatedns->updatedns() /etc/inc/services.inc:1750
[07-Oct-2015 18:48:09 Asia/Kathmandu] PHP   4\. updatedns->_update() /etc/inc/dyndns.class:257
[07-Oct-2015 18:48:09 Asia/Kathmandu] PHP   5\. curl_setopt() /etc/inc/dyndns.class:294

and that was when I was trying the recently re-added "Save & Force Update" button.

A few seconds after the above PHP error stack trace the system log has good stuff:

Oct 7 18:48:29 php-fpm[75016]: /services_dyndns_edit.php: phpDynDNS: updating cache file /conf/dyndns_wandyndns'wan-xxx.dyndns-ip.com'0.cache: 123.4.5.6
Oct 7 18:48:29 php-fpm[75016]: /services_dyndns_edit.php: phpDynDNS (wan-xxx.dyndns-ip.com): (Success) IP Address Changed Successfully! (123.4.5.6)

(Name and IP address changed to obfuscate a bit)

[phil.davis]

It is repeatable. I edited and "Save & Force Update" the entry.
PHP stack trace:

[07-Oct-2015 23:52:19 Asia/Kathmandu] PHP Stack trace:
[07-Oct-2015 23:52:19 Asia/Kathmandu] PHP   1\. {main}() /usr/local/www/services_dyndns_edit.php:0
[07-Oct-2015 23:52:19 Asia/Kathmandu] PHP   2\. services_dyndns_configure_client() /usr/local/www/services_dyndns_edit.php:214
[07-Oct-2015 23:52:19 Asia/Kathmandu] PHP   3\. updatedns->updatedns() /etc/inc/services.inc:1750
[07-Oct-2015 23:52:19 Asia/Kathmandu] PHP   4\. updatedns->_update() /etc/inc/dyndns.class:257
[07-Oct-2015 23:52:19 Asia/Kathmandu] PHP   5\. curl_setopt() /etc/inc/dyndns.class:294

System log:

Oct 7 23:52:16 check_reload_status: Syncing firewall
Oct 7 23:52:39 php-fpm[52775]: /services_dyndns_edit.php: phpDynDNS: updating cache file /conf/dyndns_wandyndns'wan-xxx.dyndns-ip.com'0.cache: 123.4.5.6
Oct 7 23:52:40 php-fpm[52775]: /services_dyndns_edit.php: phpDynDNS (wan-xxx.dyndns-ip.com): (Success) IP Address Changed Successfully! (123.4.5.6)

Note that on this APU it takes about 30 seconds from pressing "Save & Force Update" until the action completes (that will be some combination of saving changes to SD card, getting response from "checkip" site, communicating with DynDNS…) and is also roughly the time between the stack trace and the system log success messages. So the stack trace happens early in the sequence.

There does not seem to be any user-problem-symptom here. The stack trace just seems to be an artifact of something in that curl code, and the stack trace output going to the PHP error file means that the dashboard thinks there is a "crash report".

[cmb]

Thanks, that's fixed now.
https://github.com/pfsense/pfsense/commit/0ec4b3b4beedefb70d407f402fb379a21f0e03d6

Part of the delay there is the fact checkip.dyndns.org doesn't reply to the first SYN you send. I noticed that recently in doing some other testing of dynamic DNS. I presume it's because some jerks are continually DDoSing them. It also replies really slowly after replying to the second SYN, and sometimes not at all. It probably ought to background that, though the downside there is it'll show outdated info when you get back to services_dyndns.php. Looking at those delays more closely is something I'll get to at some point. If anyone else digs into it, feedback on findings appreciated.

[phil.davis]

2.3-ALPHA (amd64)
built on Thu Oct 08 19:06:50 CDT 2015
plus applying that change to /etc/inc/dyndns.class

When I "Save & Force Update" it works, good entries are in the system log, no PHP errors or stack trace happens.

Looks good, thanks.