[OpenSIPS-Users] Invalid parameter errors

Tue Mar 26 16:53:30 EDT 2019

Sorry, I forgot to link the trace: https://pastebin.com/EHs95mHV

Ben Newlin

From: Ben Newlin <Ben.Newlin at genesys.com>
Date: Tuesday, March 26, 2019 at 4:51 PM
To: OpenSIPS users mailling list <users at lists.opensips.org>
Subject: Re: [OpenSIPS-Users] Invalid parameter errors

Liviu,

I have reproduced this error I believe. I increased logging here [2] but it doesn’t show much to me.

My current theory is that this is a parameter nesting problem. Since this code is part of our logging, it takes a lot of parameters, some of which were themselves parameters to the logging function.

Is there some maximum number of routes a parameter can be passed through?

Ben Newlin

From: Users <users-bounces at lists.opensips.org> on behalf of Ben Newlin <Ben.Newlin at genesys.com>
Reply-To: OpenSIPS users mailling list <users at lists.opensips.org>
Date: Tuesday, March 5, 2019 at 11:02 AM
To: OpenSIPS users mailling list <users at lists.opensips.org>
Subject: Re: [OpenSIPS-Users] Invalid parameter errors

Liviu,

I think the offending lines appear to be these:

if (route(is_null, $param($var(add_rlog_j))))
if (route(is_json, $param($var(add_rlog_j))))

These calls work most of the time, but there seem to be some cases where this parameter is not passed properly and causes the errors I am seeing. I have not been able to isolate the specific values of $param($var(add_rlog_j)) that cause the issue. I thought it may be when it is NULL, but that doesn’t appear to be the case.

Ben Newlin

From: Users <users-bounces at lists.opensips.org> on behalf of Ben Newlin <Ben.Newlin at genesys.com>
Reply-To: OpenSIPS users mailling list <users at lists.opensips.org>
Date: Friday, February 1, 2019 at 12:30 PM
To: OpenSIPS users mailling list <users at lists.opensips.org>
Subject: Re: [OpenSIPS-Users] Invalid parameter errors

Liviu,

You’re right, there are quite a lot of them. Almost all of our use of parameterized routes and json access is in a subset of code that performs our logging, and none of that changed when the errors began.

Routes:
route(is_null, $param(1))
route(is_null, $param(2))
route(is_json, $param(2))
route(is_null, $json(rlog/$param(1)))
route(json_rlog, "thread_name", $pp);
route(json_rlog, "level", $param(1));
route(json_rlog, "route", $param(2));
route(rlog_start, $param(1), $param(2));
route(is_null, $param(3))
route(json_rlog, "message", $param(3));
route(is_null, $json(rlog_msg))
route(json_rlog, "message", $var(rlog_msg));
route(rlog_v, $param(1));
route(json_rlog, "callID", $ci);
route(json_rlog, "requestUri", $ru);
route(json_rlog, "fromUri", $fu);
route(json_rlog, "toUri", $tu);
route(json_rlog, "sipStatus", $rs);
route(json_rlog, "sipReason", $rr);
route(json_rlog, "mflags", $mf);
route(json_rlog, "conversation", $avp(cnv_id));
route(json_rlog, "callState", $avp(call_state));
route(json_rlog, "method", $rm);
route(is_null, $json(rlog_msg))
route(is_null, $param($var(add_rlog_i)))
route(is_null, $param($var(add_rlog_j)))
route(is_json, $param($var(add_rlog_j)))
route(is_null, $param(1))
route(is_null, $param($var(i))))
route(add_rlog_msg_data, "function", "t_relay", "retcode", $var(relay_rc));
route(add_rlog_msg_data, "sipStatus", $param(1), "sipReason", $param(2));
route(add_rlog_msg_data, "maxfwd", $hdr(Max-Forwards));
route(is_null, $param(1))
route(is_null, $param(1))
route(is_null, $param(1))
route(is_null, $var(ft_cache_val))
route(is_null, $param(2))
route(is_null, $var(ft_orgs))
route(add_rlog_msg_data, "feature", $param(1), "orgID", $param(2), "allow", $var(ft_allow));
route(add_rlog_msg_data, "state", $shv(state));
route(add_rlog_msg_data, "group", $var(group));
route(add_rlog_msg_data, "dir", $var(dir), "group", $var(group));
route(add_rlog_msg_data, "rr_params", $rr_params);
route(add_rlog_msg_data, "rr_params", $rr_params);
route(add_rlog_msg_data, "state", $shv(state));
route(add_rlog_msg_data, "domain", $hdr(x-special-header));

JSON:
$json(rlog/$param(1)) = NULL;
$json(rlog/$param(1)) := $param(2);
route(is_null, $json(rlog/$param(1)))
$json(rlog/$param(1)) = $(param(2){re.subst,/"/\\"/g});
$json(rlog/message) := $json(rlog_msg);
$json(rlog/t) = $(time("%Y-%m-%dT%T."){s.select,1,"}) + $(Tsm{s.fill.left,0,6}) + "Z"; #"
$json(rlog_msg/$param($var(add_rlog_i))) = "<null>";
$json(rlog_msg/$param($var(add_rlog_i))) := $param($var(add_rlog_j));
$json(rlog_msg/$param($var(add_rlog_i))) = $(param($var(add_rlog_j)){re.subst,/"/\\"/g});
$json(rlog_msg/function) = $param(1);
$json(rlog_msg/retcode) = $var(add_rlog_msg_retcode);
$json(rlog_msg/params[]) = $(param($var(i)){re.subst,/"/\\"/g});
$json(rlog_msg/destUri) = $du;
$json(rlog_msg/srcIp) = $si;
$json(rlog_msg/srcPort) = $sp;
$json(rlog_msg/replyCode) = $T_reply_code;
$json(rlog_msg/protocol) = $(proto{s.tolower});
$json(rlog/errClass) = $(err.class{s.escape.common});
$json(rlog/errLevel) = $(err.level{s.escape.common});
$json(rlog/errInfo) = $(err.info{s.escape.common});
$json(rlog/errRcode) = $(err.rcode{s.escape.common});
$json(rlog/errRreason) = $(err.rreason{s.escape.common});
$json(rlog/msg) = $(mb{s.escape.common});

We have a few cases where we used parameterized parameter references, if that makes sense. I suspect it may be something related to that? For example, the only error line number that references a line where json access or variable assignment is actually being performed is here:

$json(rlog_msg/$param($var(add_rlog_i))) = $(param($var(add_rlog_j)){re.subst,/"/\\"/g});

Ben Newlin

From: Users <users-bounces at lists.opensips.org> on behalf of Liviu Chircu <liviu at opensips.org>
Reply-To: OpenSIPS users mailling list <users at lists.opensips.org>
Date: Thursday, January 24, 2019 at 3:12 PM
To: "users at lists.opensips.org" <users at lists.opensips.org>
Subject: Re: [OpenSIPS-Users] Invalid parameter errors

Hi Ben,

We are actually dealing with two bugs here, which may or may not be related to one another.

Bug #1: bad? variable during a route() call
-------------------------------------------------------

For this one, can you enumerate all "route()" calls in your script which pass at least one variable, along with their full parameter call syntax?  Example call:

route(sequential_requests, $rm, $avp(myinfo));

Bug #2: bad "key variable" during a $json expansion
----------------------------------------------------------------------

For this one, can you enumerate all $json() variable appearances which include at least one parameterized key access?  I realize there may be lots of these, but you may group them into "categories" and print out a few ones that might be relevant (i.e. their index may contain an INT-only variable, which is >wrong<). Example appearances:

$json(http_body/$var(tag))
$json(http_body/users[0]/$avp(username))

Best regards,

Liviu Chircu

OpenSIPS Developer

http://www.opensips-solutions.com
On 24.01.2019 01:37, Ben Newlin wrote:
Liviu,

Thank you for the quick response. I do see 2 such errors shortly after startup:

ERROR:core:pv_get_param: cannot get spec value
ERROR:core:pv_get_param: cannot get spec value

However, after that it just continues on with more of the same errors that keep scrolling. There is a variation of the scrolling errors that was I didn’t included before, in case it helps:

ERROR:core:comp_scriptvar: cannot get left var value
WARNING:core:do_action: error in expression at opensips.cfg:583
ERROR:json:expand_tag_list: Non string value in key
ERROR:json:pv_set_json: Cannot expand variables in path
ERROR:core:do_assign: setting PV failed
ERROR:core:do_assign: error at opensips.cfg:346
ALERT:core:pv_get_param: BUG: invalid parameter type 1836017711

There aren’t any other non-repeating errors. I have picked up your commit and will try to gather more information from it, but this issue is primarily happening in our production environment so it may take a bit.

Also, I haven’t completely verified this yet, but it seems that enabling TLS has made the errors stop somehow. Continuing to investigate that.

Ben Newlin

From: Users <users-bounces at lists.opensips.org><mailto:users-bounces at lists.opensips.org> on behalf of Liviu Chircu <liviu at opensips.org><mailto:liviu at opensips.org>
Reply-To: OpenSIPS users mailling list <users at lists.opensips.org><mailto:users at lists.opensips.org>
Date: Tuesday, January 22, 2019 at 6:08 PM
To: "users at lists.opensips.org"<mailto:users at lists.opensips.org> <users at lists.opensips.org><mailto:users at lists.opensips.org>
Subject: Re: [OpenSIPS-Users] Invalid parameter errors

Hi, Ben!

The strange "...type 1836017711" errors seem to be caused by a poorly handed error condition (a secondary bug), which is now fixed [1]. If this theory holds, you must have a "cannot get spec value" error (or slew of errors) in the earlier section of your OpenSIPS log (possibly right after restart or shortly after starting to process traffic).

Could you please confirm/infirm the above?  If true, are there any other relevant errors thrown around that initial "cannot get spec value" error message?  Those error logs could be key to making progress in understanding the main bug.

Best regards,

[1]: https://github.com/OpenSIPS/opensips/commit/52ff74af8702a

Liviu Chircu

OpenSIPS Developer

http://www.opensips-solutions.com
On 22.01.2019 20:58, Ben Newlin wrote:
Hi,

Since upgrading to 2.4.4 we are seeing the following logs scrolling nearly continuously on our servers:

ALERT:core:pv_get_param: BUG: invalid parameter type 1836017711
ERROR:core:comp_scriptvar: cannot get left var value
WARNING:core:do_action: error in expression at opensips.cfg:583
ALERT:core:pv_get_param: BUG: invalid parameter type 1836017711
ERROR:core:comp_scriptvar: cannot get left var value
WARNING:core:do_action: error in expression at opensips.cfg:583
ALERT:core:pv_get_param: BUG: invalid parameter type 1836017711
ERROR:core:comp_scriptvar: cannot get left var value
ALERT:core:pv_get_param: BUG: invalid parameter type 1836017711
ERROR:core:comp_scriptvar: cannot get left var value
WARNING:core:do_action: error in expression at opensips.cfg:439

It seems to be related to our use of the json module. We often pass json variable types as parameters to other routes and I believe the errors are caused by that. But it’s hard to say as there are a few different script lines referenced in the errors, but some of them point to return statements and other code sections that don’t really make sense. For example, line 583 referenced in the error above is:

  return(-1);

Any ideas?

Ben Newlin

_______________________________________________

Users mailing list

Users at lists.opensips.org<mailto:Users at lists.opensips.org>

http://lists.opensips.org/cgi-bin/mailman/listinfo/users

_______________________________________________

Users mailing list

Users at lists.opensips.org<mailto:Users at lists.opensips.org>

http://lists.opensips.org/cgi-bin/mailman/listinfo/users
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.opensips.org/pipermail/users/attachments/20190326/549e2f78/attachment-0001.html>