unify *log and *dryrun logging across all agents

CGREvent will be included in the logs and dryrun will now take
precedence over log.
This commit is contained in:
ionutboangiu
2026-02-10 18:56:53 +02:00
committed by Dan Christian Bogos
parent 14d1429446
commit 5b2a8b8784
7 changed files with 268 additions and 140 deletions

View File

@@ -63,10 +63,17 @@ func processRequest(ctx *context.Context, reqProcessor *config.RequestProcessor,
}
}
if reqProcessor.Flags.Has(utils.MetaLog) {
if reqProcessor.Flags.Has(utils.MetaLog) || reqType == utils.MetaDryRun {
logPrefix := "LOG"
if reqType == utils.MetaDryRun {
logPrefix = "DRY_RUN"
}
utils.Logger.Info(
fmt.Sprintf("<%s> LOG, processorID: %s, %s message: %s",
agentName, reqProcessor.ID, strings.ToLower(agentName[:len(agentName)-5]), agReq.Request.String()))
fmt.Sprintf("<%s> %s, processorID: %s, %s message: %s",
agentName, logPrefix, reqProcessor.ID, strings.ToLower(agentName[:len(agentName)-5]), agReq.Request.String()))
utils.Logger.Info(
fmt.Sprintf("<%s> %s, processorID: %s, CGREvent: %s",
agentName, logPrefix, reqProcessor.ID, utils.ToIJSON(cgrEv)))
}
replyState := utils.OK
@@ -74,10 +81,7 @@ func processRequest(ctx *context.Context, reqProcessor *config.RequestProcessor,
default:
return false, fmt.Errorf("unknown request type: <%s>", reqType)
case utils.MetaNone: // do nothing on CGRateS side
case utils.MetaDryRun:
utils.Logger.Info(
fmt.Sprintf("<%s> DRY_RUN, processorID: %s, %sMessage: %s",
agentName, reqProcessor.ID, agentName[:len(agentName)-5], agReq.Request.String()))
case utils.MetaDryRun: // do nothing on CGRateS side, logging handled above
case utils.MetaAuthorize:
authArgs := sessions.NewV1AuthorizeArgs(
reqProcessor.Flags.GetBool(utils.MetaAttributes),
@@ -229,15 +233,14 @@ func processRequest(ctx *context.Context, reqProcessor *config.RequestProcessor,
return
}
endTime := time.Now()
if reqProcessor.Flags.Has(utils.MetaLog) {
if reqProcessor.Flags.Has(utils.MetaLog) || reqType == utils.MetaDryRun {
logPrefix := "LOG"
if reqType == utils.MetaDryRun {
logPrefix = "DRY_RUN"
}
utils.Logger.Info(
fmt.Sprintf("<%s> LOG, %s reply: %s",
agentName, agentName[:len(agentName)-5], agReq.Reply))
}
if reqType == utils.MetaDryRun {
utils.Logger.Info(
fmt.Sprintf("<%s> DRY_RUN, %s reply: %s",
agentName, agentName[:len(agentName)-5], agReq.Reply))
fmt.Sprintf("<%s> %s, %s reply: %s",
agentName, logPrefix, agentName[:len(agentName)-5], agReq.Reply))
}
if reqProcessor.Flags.Has(utils.MetaDryRun) {
return true, nil

View File

@@ -335,10 +335,17 @@ func (ra *RadiusAgent) processRequest(req *radigo.Packet, reqProcessor *config.R
err = nil // reset the error and continue the processing
}
}
if reqProcessor.Flags.Has(utils.MetaLog) {
if reqProcessor.Flags.Has(utils.MetaLog) || reqType == utils.MetaDryRun {
logPrefix := "LOG"
if reqType == utils.MetaDryRun {
logPrefix = "DRY_RUN"
}
utils.Logger.Info(
fmt.Sprintf("<%s> LOG, processorID: %s, radius message: %s",
utils.RadiusAgent, reqProcessor.ID, agReq.Request.String()))
fmt.Sprintf("<%s> %s, processorID: %s, radius message: %s",
utils.RadiusAgent, logPrefix, reqProcessor.ID, agReq.Request.String()))
utils.Logger.Info(
fmt.Sprintf("<%s> %s, processorID: %s, CGREvent: %s",
utils.RadiusAgent, logPrefix, reqProcessor.ID, utils.ToIJSON(cgrEv)))
}
replyState := utils.OK
@@ -346,10 +353,7 @@ func (ra *RadiusAgent) processRequest(req *radigo.Packet, reqProcessor *config.R
default:
return false, fmt.Errorf("unknown request type: <%s>", reqType)
case utils.MetaNone: // do nothing on CGRateS side
case utils.MetaDryRun:
utils.Logger.Info(
fmt.Sprintf("<%s> DRY_RUN, processorID: %s, CGREvent: %s",
utils.RadiusAgent, reqProcessor.ID, utils.ToJSON(cgrEv)))
case utils.MetaDryRun: // do nothing on CGRateS side, logging handled above
case utils.MetaAuthorize:
authArgs := sessions.NewV1AuthorizeArgs(
reqProcessor.Flags.GetBool(utils.MetaAttributes),
@@ -509,15 +513,14 @@ func (ra *RadiusAgent) processRequest(req *radigo.Packet, reqProcessor *config.R
return false, err
}
endTime := time.Now()
if reqProcessor.Flags.Has(utils.MetaLog) {
if reqProcessor.Flags.Has(utils.MetaLog) || reqType == utils.MetaDryRun {
logPrefix := "LOG"
if reqType == utils.MetaDryRun {
logPrefix = "DRY_RUN"
}
utils.Logger.Info(
fmt.Sprintf("<%s> LOG, Radius reply: %s",
utils.RadiusAgent, agReq.Reply))
}
if reqType == utils.MetaDryRun {
utils.Logger.Info(
fmt.Sprintf("<%s> DRY_RUN, Radius reply: %s",
utils.RadiusAgent, agReq.Reply))
fmt.Sprintf("<%s> %s, Radius reply: %s",
utils.RadiusAgent, logPrefix, agReq.Reply))
}
if reqProcessor.Flags.Has(utils.MetaDryRun) {
return true, nil

View File

@@ -409,19 +409,23 @@ func (sa *SIPAgent) processRequest(reqProcessor *config.RequestProcessor,
err = nil // reset the error and continue the processing
}
}
if reqProcessor.Flags.Has(utils.MetaLog) {
if reqProcessor.Flags.Has(utils.MetaLog) || reqType == utils.MetaDryRun {
logPrefix := "LOG"
if reqType == utils.MetaDryRun {
logPrefix = "DRY_RUN"
}
utils.Logger.Info(
fmt.Sprintf("<%s> LOG, processorID: %s, SIP message: %s",
utils.SIPAgent, reqProcessor.ID, agReq.Request.String()))
fmt.Sprintf("<%s> %s, processorID: %s, SIP message: %s",
utils.SIPAgent, logPrefix, reqProcessor.ID, agReq.Request.String()))
utils.Logger.Info(
fmt.Sprintf("<%s> %s, processorID: %s, CGREvent: %s",
utils.SIPAgent, logPrefix, reqProcessor.ID, utils.ToIJSON(cgrEv)))
}
switch reqType {
default:
return false, fmt.Errorf("unknown request type: <%s>", reqType)
case utils.MetaNone: // do nothing on CGRateS side
case utils.MetaDryRun:
utils.Logger.Info(
fmt.Sprintf("<%s> DRY_RUN, processorID: %s, CGREvent: %s",
utils.SIPAgent, reqProcessor.ID, utils.ToJSON(cgrEv)))
case utils.MetaDryRun: // do nothing on CGRateS side, logging handled above
case utils.MetaAuthorize:
authArgs := sessions.NewV1AuthorizeArgs(
reqProcessor.Flags.GetBool(utils.MetaAttributes),
@@ -472,15 +476,14 @@ func (sa *SIPAgent) processRequest(reqProcessor *config.RequestProcessor,
return false, err
}
endTime := time.Now()
if reqProcessor.Flags.Has(utils.MetaLog) {
if reqProcessor.Flags.Has(utils.MetaLog) || reqType == utils.MetaDryRun {
logPrefix := "LOG"
if reqType == utils.MetaDryRun {
logPrefix = "DRY_RUN"
}
utils.Logger.Info(
fmt.Sprintf("<%s> LOG, SIP reply: %s",
utils.SIPAgent, agReq.Reply))
}
if reqType == utils.MetaDryRun {
utils.Logger.Info(
fmt.Sprintf("<%s> DRY_RUN, SIP reply: %s",
utils.SIPAgent, agReq.Reply))
fmt.Sprintf("<%s> %s, SIP reply: %s",
utils.SIPAgent, logPrefix, agReq.Reply))
}
if reqProcessor.Flags.Has(utils.MetaDryRun) {
return true, nil

View File

@@ -288,12 +288,6 @@ func (erS *ERService) processEvent(cgrEv *utils.CGREvent,
}
}
}()
// log the event created if requested by flags
if rdrCfg.Flags.Has(utils.MetaLog) {
utils.Logger.Info(
fmt.Sprintf("<%s> LOG, reader: <%s>, message: %s",
utils.ERs, rdrCfg.ID, utils.ToIJSON(cgrEv)))
}
// find out reqType
var reqType string
for _, typ := range []string{
@@ -317,15 +311,21 @@ func (erS *ERService) processEvent(cgrEv *utils.CGREvent,
err = nil // reset the error and continue the processing
}
}
if rdrCfg.Flags.Has(utils.MetaLog) || reqType == utils.MetaDryRun {
logPrefix := "LOG"
if reqType == utils.MetaDryRun {
logPrefix = "DRY_RUN"
}
utils.Logger.Info(
fmt.Sprintf("<%s> %s, reader: <%s>, CGREvent: %s",
utils.ERs, logPrefix, rdrCfg.ID, utils.ToIJSON(cgrEv)))
}
// execute the action based on reqType
switch reqType {
default:
return fmt.Errorf("unsupported reqType: <%s>", reqType)
case utils.MetaNone: // do nothing on CGRateS side
case utils.MetaDryRun:
utils.Logger.Info(
fmt.Sprintf("<%s> DRYRUN, reader: <%s>, CGREvent: <%s>",
utils.ERs, rdrCfg.ID, utils.ToJSON(cgrEv)))
case utils.MetaDryRun: // do nothing on CGRateS side, logging handled above
case utils.MetaAuthorize:
authArgs := sessions.NewV1AuthorizeArgs(
rdrCfg.Flags.Has(utils.MetaAttributes),

View File

@@ -34,7 +34,7 @@ import (
)
func TestDiamULI(t *testing.T) {
// t.Skip("configuration reference for *3gpp_uli request_fields; does not assert values")
t.Skip("configuration reference for *3gpp_uli request_fields; does not verify anything")
switch *utils.DBType {
case utils.MetaInternal:
case utils.MetaMySQL, utils.MetaMongo, utils.MetaPostgres:

View File

@@ -18,14 +18,12 @@ along with this program. If not, see <https://www.gnu.org/licenses/>
package general_tests
import (
"bufio"
"bytes"
"encoding/json"
"fmt"
"io"
"os"
"path/filepath"
"regexp"
"strconv"
"strings"
"testing"
"time"
@@ -122,42 +120,28 @@ func TestERsLineNr(t *testing.T) {
}
verifyLogLines := func(t *testing.T, reader io.Reader) {
fieldRegex := regexp.MustCompile(`"Field":"test(\d+)"`)
lineNumberRegex := regexp.MustCompile(`"LineNumber":"(\d+)"`)
records := 0
scanner := bufio.NewScanner(reader)
for scanner.Scan() {
line := scanner.Text()
if !strings.Contains(line, `"Field":"test`) {
t.Helper()
data, err := io.ReadAll(reader)
if err != nil {
t.Fatal(err)
}
parts := strings.Split(string(data), "CGREvent: ")
var records int
for _, part := range parts[1:] {
var cgrEv utils.CGREvent
if err := json.NewDecoder(strings.NewReader(part)).Decode(&cgrEv); err != nil {
t.Fatalf("failed to decode CGREvent: %v", err)
}
field, _ := cgrEv.Event["Field"].(string)
if !strings.HasPrefix(field, "test") {
continue
}
records++
fieldMatch := fieldRegex.FindStringSubmatch(line)
lineNumberMatch := lineNumberRegex.FindStringSubmatch(line)
if len(fieldMatch) != 2 || len(lineNumberMatch) != 2 {
t.Fatalf("invalid log line format: %s", line)
}
testNumber, err := strconv.Atoi(fieldMatch[1])
if err != nil {
t.Fatal(err)
}
lineNumber, err := strconv.Atoi(lineNumberMatch[1])
if err != nil {
t.Fatal(err)
}
if testNumber != lineNumber {
t.Errorf("mismatch in line: %s, field number: %d, line number: %d", line, testNumber, lineNumber)
lineNumber, _ := cgrEv.Event["LineNumber"].(string)
if want := strings.TrimPrefix(field, "test"); lineNumber != want {
t.Errorf("got LineNumber=%s, want %s (Field=%s)", lineNumber, want, field)
}
}
if err := scanner.Err(); err != nil {
t.Errorf("error reading input: %v", err)
}
if records != 18 {
t.Errorf("expected ERs to process 18 records, but it processed %d records", records)
}
@@ -184,7 +168,7 @@ TRL6
<field>test6</field>
</root>`)
time.Sleep(5 * time.Millisecond) // wait for the files to be processed
time.Sleep(20 * time.Millisecond) // wait for the files to be processed
// Check that the suffixes of the 'test' fields match the LineNumber field.
logData := strings.NewReader(buf.String())

View File

@@ -23,6 +23,7 @@ package general_tests
import (
"bufio"
"bytes"
"encoding/json"
"fmt"
"path"
"strings"
@@ -368,25 +369,20 @@ cgrates.org,FLTR_VARS,*string,~*vars.*readerID,mysql,`,
GracefulShutdown: true,
}
ng.Run(t)
time.Sleep(1 * time.Second)
time.Sleep(500 * time.Millisecond)
t.Run("VerifyProcessedFieldsFromLogs", func(t *testing.T) {
time.Sleep(100 * time.Millisecond) // give enough time to process from sql table
records := 0
scanner := bufio.NewScanner(strings.NewReader(buf.String()))
timeStartFormated := timeStart.Format("2006-01-02T15:04:05Z07:00")
expectedLog := fmt.Sprintf("\"Event\":{\"Account\":\"1001\",\"AnswerTime\":\"%s\",\"CGRID\":\"%s\",\"Category\":\"call\",\"CostDetails\":\"{\\\"CGRID\\\":\\\"test1\\\",\\\"RunID\\\":\\\"*default\\\",\\\"StartTime\\\":\\\"2017-01-09T16:18:21Z\\\",\\\"Usage\\\":180000000000,\\\"Cost\\\":2.3,\\\"Charges\\\":[{\\\"RatingID\\\":\\\"RatingID2\\\",\\\"Increments\\\":[{\\\"Usage\\\":120000000000,\\\"Cost\\\":2,\\\"AccountingID\\\":\\\"a012888\\\",\\\"CompressFactor\\\":1},{\\\"Usage\\\":1000000000,\\\"Cost\\\":0.005,\\\"AccountingID\\\":\\\"44d6c02\\\",\\\"CompressFactor\\\":60}],\\\"CompressFactor\\\":1}],\\\"AccountSummary\\\":{\\\"Tenant\\\":\\\"cgrates.org\\\",\\\"ID\\\":\\\"1001\\\",\\\"BalanceSummaries\\\":[{\\\"UUID\\\":\\\"uuid1\\\",\\\"ID\\\":\\\"\\\",\\\"Type\\\":\\\"*monetary\\\",\\\"Initial\\\":0,\\\"Value\\\":50,\\\"Disabled\\\":false}],\\\"AllowNegative\\\":false,\\\"Disabled\\\":false},\\\"Rating\\\":{\\\"c1a5ab9\\\":{\\\"ConnectFee\\\":0.1,\\\"RoundingMethod\\\":\\\"*up\\\",\\\"RoundingDecimals\\\":5,\\\"MaxCost\\\":0,\\\"MaxCostStrategy\\\":\\\"\\\",\\\"TimingID\\\":\\\"\\\",\\\"RatesID\\\":\\\"ec1a177\\\",\\\"RatingFiltersID\\\":\\\"43e77dc\\\"}},\\\"Accounting\\\":{\\\"44d6c02\\\":{\\\"AccountID\\\":\\\"cgrates.org:1001\\\",\\\"BalanceUUID\\\":\\\"uuid1\\\",\\\"RatingID\\\":\\\"\\\",\\\"Units\\\":120.7,\\\"ExtraChargeID\\\":\\\"\\\"},\\\"a012888\\\":{\\\"AccountID\\\":\\\"cgrates.org:1001\\\",\\\"BalanceUUID\\\":\\\"uuid1\\\",\\\"RatingID\\\":\\\"\\\",\\\"Units\\\":120.7,\\\"ExtraChargeID\\\":\\\"\\\"}},\\\"RatingFilters\\\":null,\\\"Rates\\\":{\\\"ec1a177\\\":[{\\\"GroupIntervalStart\\\":0,\\\"Value\\\":0.01,\\\"RateIncrement\\\":60000000000,\\\"RateUnit\\\":1000000000}]},\\\"Timings\\\":null}\",\"Destination\":\"1002\",\"OriginID\":\"oid2\",\"RequestType\":\"*rated\",\"SetupTime\":\"%s\",\"Subject\":\"1001\",\"Tenant\":\"cgrates.org\",\"ToR\":\"*voice\",\"Usage\":\"10000000000\"},\"APIOpts\":{}}>", timeStartFormated, cgrID, timeStartFormated)
var ersLogsCount int
for scanner.Scan() {
line := scanner.Text()
if !strings.Contains(line, "<ERs> DRYRUN, reader: <mysql>") {
if !strings.Contains(line, "<ERs> DRY_RUN, reader: <mysql>") {
continue
}
records++
if !strings.Contains(line, expectedLog) {
t.Errorf("expected \n<%q>, \nreceived\n<%q>", expectedLog, line)
}
if strings.Contains(line, "[INFO] <ERs> DRYRUN") {
if strings.Contains(line, "[INFO] <ERs> DRY_RUN") {
ersLogsCount++
}
}
@@ -399,6 +395,33 @@ cgrates.org,FLTR_VARS,*string,~*vars.*readerID,mysql,`,
if ersLogsCount != 1 {
t.Error("Expected only 1 ERS Dryrun log, received: ", ersLogsCount)
}
idx := strings.Index(buf.String(), "CGREvent: ")
if idx == -1 {
t.Fatal("CGREvent not found in log output")
}
var cgrEv utils.CGREvent
if err := json.NewDecoder(strings.NewReader(buf.String()[idx+len("CGREvent: "):])).Decode(&cgrEv); err != nil {
t.Fatal(err)
}
timeStartFormatted := timeStart.Format("2006-01-02T15:04:05Z07:00")
expectedEvent := map[string]any{
"Account": "1001",
"AnswerTime": timeStartFormatted,
"CGRID": cgrID,
"Category": "call",
"CostDetails": utils.ToJSON(cdr2.CostDetails),
"Destination": "1002",
"OriginID": "oid2",
"RequestType": "*rated",
"SetupTime": timeStartFormatted,
"Subject": "1001",
"Tenant": "cgrates.org",
"ToR": "*voice",
"Usage": "10000000000",
}
if got, want := utils.ToJSON(cgrEv.Event), utils.ToJSON(expectedEvent); got != want {
t.Errorf("got event\n%s\nwant\n%s", got, want)
}
})
t.Run("VerifyRowsNotDeleted", func(t *testing.T) {
@@ -531,25 +554,20 @@ cgrates.org,FLTR_VARS,*string,~*vars.*readerID,mysql,`,
GracefulShutdown: true,
}
ng.Run(t)
time.Sleep(1 * time.Second)
time.Sleep(500 * time.Millisecond)
t.Run("VerifyProcessedFieldsFromLogs", func(t *testing.T) {
time.Sleep(100 * time.Millisecond) // give enough time to process from sql table
records := 0
scanner := bufio.NewScanner(strings.NewReader(buf.String()))
timeStartFormated := timeStart.Format("2006-01-02T15:04:05Z07:00")
expectedLog := fmt.Sprintf("\"Event\":{\"Account\":\"1001\",\"AnswerTime\":\"%s\",\"CGRID\":\"%s\",\"Category\":\"call\",\"CostDetails\":\"{\\\"CGRID\\\":\\\"test1\\\",\\\"RunID\\\":\\\"*default\\\",\\\"StartTime\\\":\\\"2017-01-09T16:18:21Z\\\",\\\"Usage\\\":180000000000,\\\"Cost\\\":2.3,\\\"Charges\\\":[{\\\"RatingID\\\":\\\"RatingID2\\\",\\\"Increments\\\":[{\\\"Usage\\\":120000000000,\\\"Cost\\\":2,\\\"AccountingID\\\":\\\"a012888\\\",\\\"CompressFactor\\\":1},{\\\"Usage\\\":1000000000,\\\"Cost\\\":0.005,\\\"AccountingID\\\":\\\"44d6c02\\\",\\\"CompressFactor\\\":60}],\\\"CompressFactor\\\":1}],\\\"AccountSummary\\\":{\\\"Tenant\\\":\\\"cgrates.org\\\",\\\"ID\\\":\\\"1001\\\",\\\"BalanceSummaries\\\":[{\\\"UUID\\\":\\\"uuid1\\\",\\\"ID\\\":\\\"\\\",\\\"Type\\\":\\\"*monetary\\\",\\\"Initial\\\":0,\\\"Value\\\":50,\\\"Disabled\\\":false}],\\\"AllowNegative\\\":false,\\\"Disabled\\\":false},\\\"Rating\\\":{\\\"c1a5ab9\\\":{\\\"ConnectFee\\\":0.1,\\\"RoundingMethod\\\":\\\"*up\\\",\\\"RoundingDecimals\\\":5,\\\"MaxCost\\\":0,\\\"MaxCostStrategy\\\":\\\"\\\",\\\"TimingID\\\":\\\"\\\",\\\"RatesID\\\":\\\"ec1a177\\\",\\\"RatingFiltersID\\\":\\\"43e77dc\\\"}},\\\"Accounting\\\":{\\\"44d6c02\\\":{\\\"AccountID\\\":\\\"cgrates.org:1001\\\",\\\"BalanceUUID\\\":\\\"uuid1\\\",\\\"RatingID\\\":\\\"\\\",\\\"Units\\\":120.7,\\\"ExtraChargeID\\\":\\\"\\\"},\\\"a012888\\\":{\\\"AccountID\\\":\\\"cgrates.org:1001\\\",\\\"BalanceUUID\\\":\\\"uuid1\\\",\\\"RatingID\\\":\\\"\\\",\\\"Units\\\":120.7,\\\"ExtraChargeID\\\":\\\"\\\"}},\\\"RatingFilters\\\":null,\\\"Rates\\\":{\\\"ec1a177\\\":[{\\\"GroupIntervalStart\\\":0,\\\"Value\\\":0.01,\\\"RateIncrement\\\":60000000000,\\\"RateUnit\\\":1000000000}]},\\\"Timings\\\":null}\",\"Destination\":\"1002\",\"OriginID\":\"oid2\",\"RequestType\":\"*rated\",\"SetupTime\":\"%s\",\"Subject\":\"1001\",\"Tenant\":\"cgrates.org\",\"ToR\":\"*voice\",\"Usage\":\"10000000000\"},\"APIOpts\":{}}>", timeStartFormated, cgrID, timeStartFormated)
var ersLogsCount int
for scanner.Scan() {
line := scanner.Text()
if !strings.Contains(line, "<ERs> DRYRUN, reader: <mysql>") {
if !strings.Contains(line, "<ERs> DRY_RUN, reader: <mysql>") {
continue
}
records++
if !strings.Contains(line, expectedLog) {
t.Errorf("expected \n<%q>, \nreceived\n<%q>", expectedLog, line)
}
if strings.Contains(line, "[INFO] <ERs> DRYRUN") {
if strings.Contains(line, "[INFO] <ERs> DRY_RUN") {
ersLogsCount++
}
}
@@ -562,6 +580,33 @@ cgrates.org,FLTR_VARS,*string,~*vars.*readerID,mysql,`,
if ersLogsCount != 1 {
t.Error("Expected only 1 ERS Dryrun log, received: ", ersLogsCount)
}
idx := strings.Index(buf.String(), "CGREvent: ")
if idx == -1 {
t.Fatal("CGREvent not found in log output")
}
var cgrEv utils.CGREvent
if err := json.NewDecoder(strings.NewReader(buf.String()[idx+len("CGREvent: "):])).Decode(&cgrEv); err != nil {
t.Fatal(err)
}
timeStartFormatted := timeStart.Format("2006-01-02T15:04:05Z07:00")
expectedEvent := map[string]any{
"Account": "1001",
"AnswerTime": timeStartFormatted,
"CGRID": cgrID,
"Category": "call",
"CostDetails": utils.ToJSON(cdr2.CostDetails),
"Destination": "1002",
"OriginID": "oid2",
"RequestType": "*rated",
"SetupTime": timeStartFormatted,
"Subject": "1001",
"Tenant": "cgrates.org",
"ToR": "*voice",
"Usage": "10000000000",
}
if got, want := utils.ToJSON(cgrEv.Event), utils.ToJSON(expectedEvent); got != want {
t.Errorf("got event\n%s\nwant\n%s", got, want)
}
})
t.Run("VerifyRowsNotDeleted", func(t *testing.T) {
@@ -700,25 +745,20 @@ cgrates.org,FLTR_VARS,*string,~*vars.*readerID,mysql,`,
GracefulShutdown: true,
}
ng.Run(t)
time.Sleep(1 * time.Second)
time.Sleep(500 * time.Millisecond)
t.Run("VerifyProcessedFieldsFromLogs", func(t *testing.T) {
time.Sleep(100 * time.Millisecond) // give enough time to process from sql table
records := 0
scanner := bufio.NewScanner(strings.NewReader(buf.String()))
timeStartFormated := timeStart.Format("2006-01-02T15:04:05Z07:00")
expectedLog := fmt.Sprintf("\"Event\":{\"Account\":\"1001\",\"AnswerTime\":\"%s\",\"CGRID\":\"%s\",\"Category\":\"call\",\"CostDetails\":\"{\\\"CGRID\\\":\\\"test1\\\",\\\"RunID\\\":\\\"*default\\\",\\\"StartTime\\\":\\\"2017-01-09T16:18:21Z\\\",\\\"Usage\\\":180000000000,\\\"Cost\\\":2.3,\\\"Charges\\\":[{\\\"RatingID\\\":\\\"RatingID2\\\",\\\"Increments\\\":[{\\\"Usage\\\":120000000000,\\\"Cost\\\":2,\\\"AccountingID\\\":\\\"a012888\\\",\\\"CompressFactor\\\":1},{\\\"Usage\\\":1000000000,\\\"Cost\\\":0.005,\\\"AccountingID\\\":\\\"44d6c02\\\",\\\"CompressFactor\\\":60}],\\\"CompressFactor\\\":1}],\\\"AccountSummary\\\":{\\\"Tenant\\\":\\\"cgrates.org\\\",\\\"ID\\\":\\\"1001\\\",\\\"BalanceSummaries\\\":[{\\\"UUID\\\":\\\"uuid1\\\",\\\"ID\\\":\\\"\\\",\\\"Type\\\":\\\"*monetary\\\",\\\"Initial\\\":0,\\\"Value\\\":50,\\\"Disabled\\\":false}],\\\"AllowNegative\\\":false,\\\"Disabled\\\":false},\\\"Rating\\\":{\\\"c1a5ab9\\\":{\\\"ConnectFee\\\":0.1,\\\"RoundingMethod\\\":\\\"*up\\\",\\\"RoundingDecimals\\\":5,\\\"MaxCost\\\":0,\\\"MaxCostStrategy\\\":\\\"\\\",\\\"TimingID\\\":\\\"\\\",\\\"RatesID\\\":\\\"ec1a177\\\",\\\"RatingFiltersID\\\":\\\"43e77dc\\\"}},\\\"Accounting\\\":{\\\"44d6c02\\\":{\\\"AccountID\\\":\\\"cgrates.org:1001\\\",\\\"BalanceUUID\\\":\\\"uuid1\\\",\\\"RatingID\\\":\\\"\\\",\\\"Units\\\":120.7,\\\"ExtraChargeID\\\":\\\"\\\"},\\\"a012888\\\":{\\\"AccountID\\\":\\\"cgrates.org:1001\\\",\\\"BalanceUUID\\\":\\\"uuid1\\\",\\\"RatingID\\\":\\\"\\\",\\\"Units\\\":120.7,\\\"ExtraChargeID\\\":\\\"\\\"}},\\\"RatingFilters\\\":null,\\\"Rates\\\":{\\\"ec1a177\\\":[{\\\"GroupIntervalStart\\\":0,\\\"Value\\\":0.01,\\\"RateIncrement\\\":60000000000,\\\"RateUnit\\\":1000000000}]},\\\"Timings\\\":null}\",\"Destination\":\"1002\",\"OriginID\":\"oid2\",\"RequestType\":\"*rated\",\"SetupTime\":\"%s\",\"Subject\":\"1001\",\"Tenant\":\"cgrates.org\",\"ToR\":\"*voice\",\"Usage\":\"10000000000\"},\"APIOpts\":{}}>", timeStartFormated, cgrID, timeStartFormated)
var ersLogsCount int
for scanner.Scan() {
line := scanner.Text()
if !strings.Contains(line, "<ERs> DRYRUN, reader: <mysql>") {
if !strings.Contains(line, "<ERs> DRY_RUN, reader: <mysql>") {
continue
}
records++
if !strings.Contains(line, expectedLog) {
t.Errorf("expected \n<%q>, \nreceived\n<%q>", expectedLog, line)
}
if strings.Contains(line, "[INFO] <ERs> DRYRUN") {
if strings.Contains(line, "[INFO] <ERs> DRY_RUN") {
ersLogsCount++
}
}
@@ -731,6 +771,33 @@ cgrates.org,FLTR_VARS,*string,~*vars.*readerID,mysql,`,
if ersLogsCount != 1 {
t.Error("Expected only 1 ERS Dryrun log, received: ", ersLogsCount)
}
idx := strings.Index(buf.String(), "CGREvent: ")
if idx == -1 {
t.Fatal("CGREvent not found in log output")
}
var cgrEv utils.CGREvent
if err := json.NewDecoder(strings.NewReader(buf.String()[idx+len("CGREvent: "):])).Decode(&cgrEv); err != nil {
t.Fatal(err)
}
timeStartFormatted := timeStart.Format("2006-01-02T15:04:05Z07:00")
expectedEvent := map[string]any{
"Account": "1001",
"AnswerTime": timeStartFormatted,
"CGRID": cgrID,
"Category": "call",
"CostDetails": utils.ToJSON(cdr2.CostDetails),
"Destination": "1002",
"OriginID": "oid2",
"RequestType": "*rated",
"SetupTime": timeStartFormatted,
"Subject": "1001",
"Tenant": "cgrates.org",
"ToR": "*voice",
"Usage": "10000000000",
}
if got, want := utils.ToJSON(cgrEv.Event), utils.ToJSON(expectedEvent); got != want {
t.Errorf("got event\n%s\nwant\n%s", got, want)
}
})
t.Run("VerifyRowsNotDeleted", func(t *testing.T) {
@@ -909,25 +976,20 @@ cgrates.org,FLTR_VARS,*string,~*vars.*readerID,mysql,`,
GracefulShutdown: true,
}
ng.Run(t)
time.Sleep(1 * time.Second)
time.Sleep(500 * time.Millisecond)
t.Run("VerifyProcessedFieldsFromLogs", func(t *testing.T) {
time.Sleep(100 * time.Millisecond) // give enough time to process from sql table
records := 0
scanner := bufio.NewScanner(strings.NewReader(buf.String()))
timeStartFormated := timeStart.Format("2006-01-02T15:04:05Z07:00")
expectedLog := fmt.Sprintf("\"Event\":{\"Account\":\"1001\",\"AnswerTime\":\"%s\",\"CGRID\":\"%s\",\"Category\":\"call\",\"CostDetails\":\"{\\\"CGRID\\\":\\\"test1\\\",\\\"RunID\\\":\\\"*default\\\",\\\"StartTime\\\":\\\"2017-01-09T16:18:21Z\\\",\\\"Usage\\\":180000000000,\\\"Cost\\\":2.3,\\\"Charges\\\":[{\\\"RatingID\\\":\\\"RatingID2\\\",\\\"Increments\\\":[{\\\"Usage\\\":120000000000,\\\"Cost\\\":2,\\\"AccountingID\\\":\\\"a012888\\\",\\\"CompressFactor\\\":1},{\\\"Usage\\\":1000000000,\\\"Cost\\\":0.005,\\\"AccountingID\\\":\\\"44d6c02\\\",\\\"CompressFactor\\\":60}],\\\"CompressFactor\\\":1}],\\\"AccountSummary\\\":{\\\"Tenant\\\":\\\"cgrates.org\\\",\\\"ID\\\":\\\"1001\\\",\\\"BalanceSummaries\\\":[{\\\"UUID\\\":\\\"uuid1\\\",\\\"ID\\\":\\\"\\\",\\\"Type\\\":\\\"*monetary\\\",\\\"Initial\\\":0,\\\"Value\\\":50,\\\"Disabled\\\":false}],\\\"AllowNegative\\\":false,\\\"Disabled\\\":false},\\\"Rating\\\":{\\\"c1a5ab9\\\":{\\\"ConnectFee\\\":0.1,\\\"RoundingMethod\\\":\\\"*up\\\",\\\"RoundingDecimals\\\":5,\\\"MaxCost\\\":0,\\\"MaxCostStrategy\\\":\\\"\\\",\\\"TimingID\\\":\\\"\\\",\\\"RatesID\\\":\\\"ec1a177\\\",\\\"RatingFiltersID\\\":\\\"43e77dc\\\"}},\\\"Accounting\\\":{\\\"44d6c02\\\":{\\\"AccountID\\\":\\\"cgrates.org:1001\\\",\\\"BalanceUUID\\\":\\\"uuid1\\\",\\\"RatingID\\\":\\\"\\\",\\\"Units\\\":120.7,\\\"ExtraChargeID\\\":\\\"\\\"},\\\"a012888\\\":{\\\"AccountID\\\":\\\"cgrates.org:1001\\\",\\\"BalanceUUID\\\":\\\"uuid1\\\",\\\"RatingID\\\":\\\"\\\",\\\"Units\\\":120.7,\\\"ExtraChargeID\\\":\\\"\\\"}},\\\"RatingFilters\\\":null,\\\"Rates\\\":{\\\"ec1a177\\\":[{\\\"GroupIntervalStart\\\":0,\\\"Value\\\":0.01,\\\"RateIncrement\\\":60000000000,\\\"RateUnit\\\":1000000000}]},\\\"Timings\\\":null}\",\"Destination\":\"1002\",\"OriginID\":\"oid2\",\"RequestType\":\"*rated\",\"SetupTime\":\"%s\",\"Subject\":\"1001\",\"Tenant\":\"cgrates.org\",\"ToR\":\"*voice\",\"Usage\":\"10000000000\"},\"APIOpts\":{}}>", timeStartFormated, cgrID, timeStartFormated)
var ersLogsCount int
for scanner.Scan() {
line := scanner.Text()
if !strings.Contains(line, "<ERs> DRYRUN, reader: <mysql>") {
if !strings.Contains(line, "<ERs> DRY_RUN, reader: <mysql>") {
continue
}
records++
if !strings.Contains(line, expectedLog) {
t.Errorf("expected \n<%q>, \nreceived\n<%q>", expectedLog, line)
}
if strings.Contains(line, "[INFO] <ERs> DRYRUN") {
if strings.Contains(line, "[INFO] <ERs> DRY_RUN") {
ersLogsCount++
}
}
@@ -940,6 +1002,33 @@ cgrates.org,FLTR_VARS,*string,~*vars.*readerID,mysql,`,
if ersLogsCount != 1 {
t.Error("Expected only 1 ERS Dryrun log, received: ", ersLogsCount)
}
idx := strings.Index(buf.String(), "CGREvent: ")
if idx == -1 {
t.Fatal("CGREvent not found in log output")
}
var cgrEv utils.CGREvent
if err := json.NewDecoder(strings.NewReader(buf.String()[idx+len("CGREvent: "):])).Decode(&cgrEv); err != nil {
t.Fatal(err)
}
timeStartFormatted := timeStart.Format("2006-01-02T15:04:05Z07:00")
expectedEvent := map[string]any{
"Account": "1001",
"AnswerTime": timeStartFormatted,
"CGRID": cgrID,
"Category": "call",
"CostDetails": utils.ToJSON(cdr2.CostDetails),
"Destination": "1002",
"OriginID": "oid2",
"RequestType": "*rated",
"SetupTime": timeStartFormatted,
"Subject": "1001",
"Tenant": "cgrates.org",
"ToR": "*voice",
"Usage": "10000000000",
}
if got, want := utils.ToJSON(cgrEv.Event), utils.ToJSON(expectedEvent); got != want {
t.Errorf("got event\n%s\nwant\n%s", got, want)
}
})
t.Run("VerifyRowsCount", func(t *testing.T) {
@@ -1098,25 +1187,20 @@ cgrates.org,FLTR_VARS,*string,~*vars.*readerID,mysql,`,
GracefulShutdown: true,
}
ng.Run(t)
time.Sleep(1 * time.Second)
time.Sleep(500 * time.Millisecond)
t.Run("VerifyProcessedFieldsFromLogs", func(t *testing.T) {
time.Sleep(100 * time.Millisecond) // give enough time to process from sql table
records := 0
scanner := bufio.NewScanner(strings.NewReader(buf.String()))
timeStartFormated := timeStart.Format("2006-01-02T15:04:05Z07:00")
expectedLog := fmt.Sprintf("\"Event\":{\"Account\":\"1001\",\"AnswerTime\":\"%s\",\"CGRID\":\"%s\",\"Category\":\"call\",\"CostDetails\":\"{\\\"CGRID\\\":\\\"test1\\\",\\\"RunID\\\":\\\"*default\\\",\\\"StartTime\\\":\\\"2017-01-09T16:18:21Z\\\",\\\"Usage\\\":180000000000,\\\"Cost\\\":2.3,\\\"Charges\\\":[{\\\"RatingID\\\":\\\"RatingID2\\\",\\\"Increments\\\":[{\\\"Usage\\\":120000000000,\\\"Cost\\\":2,\\\"AccountingID\\\":\\\"a012888\\\",\\\"CompressFactor\\\":1},{\\\"Usage\\\":1000000000,\\\"Cost\\\":0.005,\\\"AccountingID\\\":\\\"44d6c02\\\",\\\"CompressFactor\\\":60}],\\\"CompressFactor\\\":1}],\\\"AccountSummary\\\":{\\\"Tenant\\\":\\\"cgrates.org\\\",\\\"ID\\\":\\\"1001\\\",\\\"BalanceSummaries\\\":[{\\\"UUID\\\":\\\"uuid1\\\",\\\"ID\\\":\\\"\\\",\\\"Type\\\":\\\"*monetary\\\",\\\"Initial\\\":0,\\\"Value\\\":50,\\\"Disabled\\\":false}],\\\"AllowNegative\\\":false,\\\"Disabled\\\":false},\\\"Rating\\\":{\\\"c1a5ab9\\\":{\\\"ConnectFee\\\":0.1,\\\"RoundingMethod\\\":\\\"*up\\\",\\\"RoundingDecimals\\\":5,\\\"MaxCost\\\":0,\\\"MaxCostStrategy\\\":\\\"\\\",\\\"TimingID\\\":\\\"\\\",\\\"RatesID\\\":\\\"ec1a177\\\",\\\"RatingFiltersID\\\":\\\"43e77dc\\\"}},\\\"Accounting\\\":{\\\"44d6c02\\\":{\\\"AccountID\\\":\\\"cgrates.org:1001\\\",\\\"BalanceUUID\\\":\\\"uuid1\\\",\\\"RatingID\\\":\\\"\\\",\\\"Units\\\":120.7,\\\"ExtraChargeID\\\":\\\"\\\"},\\\"a012888\\\":{\\\"AccountID\\\":\\\"cgrates.org:1001\\\",\\\"BalanceUUID\\\":\\\"uuid1\\\",\\\"RatingID\\\":\\\"\\\",\\\"Units\\\":120.7,\\\"ExtraChargeID\\\":\\\"\\\"}},\\\"RatingFilters\\\":null,\\\"Rates\\\":{\\\"ec1a177\\\":[{\\\"GroupIntervalStart\\\":0,\\\"Value\\\":0.01,\\\"RateIncrement\\\":60000000000,\\\"RateUnit\\\":1000000000}]},\\\"Timings\\\":null}\",\"Destination\":\"1002\",\"ExtraInfo\":\"extraInfo\",\"Id\":\"2\",\"OriginID\":\"oid2\",\"RequestType\":\"*rated\",\"SetupTime\":\"%s\",\"Subject\":\"1001\",\"Tenant\":\"cgrates.org\",\"ToR\":\"*voice\",\"Usage\":\"10000000000\"},\"APIOpts\":{}}>", timeStartFormated, cgrID, timeStartFormated)
var ersLogsCount int
for scanner.Scan() {
line := scanner.Text()
if !strings.Contains(line, "<ERs> DRYRUN, reader: <mysql>") {
if !strings.Contains(line, "<ERs> DRY_RUN, reader: <mysql>") {
continue
}
records++
if !strings.Contains(line, expectedLog) {
t.Errorf("expected \n<%q>, \nreceived\n<%q>", expectedLog, line)
}
if strings.Contains(line, "[INFO] <ERs> DRYRUN") {
if strings.Contains(line, "[INFO] <ERs> DRY_RUN") {
ersLogsCount++
}
}
@@ -1129,6 +1213,35 @@ cgrates.org,FLTR_VARS,*string,~*vars.*readerID,mysql,`,
if ersLogsCount != 1 {
t.Error("Expected only 1 ERS Dryrun log, received: ", ersLogsCount)
}
idx := strings.Index(buf.String(), "CGREvent: ")
if idx == -1 {
t.Fatal("CGREvent not found in log output")
}
var cgrEv utils.CGREvent
if err := json.NewDecoder(strings.NewReader(buf.String()[idx+len("CGREvent: "):])).Decode(&cgrEv); err != nil {
t.Fatal(err)
}
timeStartFormatted := timeStart.Format("2006-01-02T15:04:05Z07:00")
expectedEvent := map[string]any{
"Account": "1001",
"AnswerTime": timeStartFormatted,
"CGRID": cgrID,
"Category": "call",
"CostDetails": utils.ToJSON(cdr2.CostDetails),
"Destination": "1002",
"ExtraInfo": "extraInfo",
"Id": "2",
"OriginID": "oid2",
"RequestType": "*rated",
"SetupTime": timeStartFormatted,
"Subject": "1001",
"Tenant": "cgrates.org",
"ToR": "*voice",
"Usage": "10000000000",
}
if got, want := utils.ToJSON(cgrEv.Event), utils.ToJSON(expectedEvent); got != want {
t.Errorf("got event\n%s\nwant\n%s", got, want)
}
})
t.Run("VerifyRowsCount", func(t *testing.T) {
@@ -1279,25 +1392,20 @@ cgrates.org,FLTR_VARS,*string,~*vars.*readerID,mysql,`,
GracefulShutdown: true,
}
ng.Run(t)
time.Sleep(1 * time.Second)
time.Sleep(500 * time.Millisecond)
t.Run("VerifyProcessedFieldsFromLogs", func(t *testing.T) {
time.Sleep(100 * time.Millisecond) // give enough time to process from sql table
records := 0
scanner := bufio.NewScanner(strings.NewReader(buf.String()))
timeStartFormated := timeStart.Format("2006-01-02T15:04:05Z07:00")
expectedLog := fmt.Sprintf("\"Event\":{\"Account\":\"1001\",\"AnswerTime\":\"%s\",\"CGRID\":\"%s\",\"Category\":\"call\",\"CostDetails\":\"{\\\"CGRID\\\":\\\"test1\\\",\\\"RunID\\\":\\\"*default\\\",\\\"StartTime\\\":\\\"2017-01-09T16:18:21Z\\\",\\\"Usage\\\":180000000000,\\\"Cost\\\":2.3,\\\"Charges\\\":[{\\\"RatingID\\\":\\\"RatingID2\\\",\\\"Increments\\\":[{\\\"Usage\\\":120000000000,\\\"Cost\\\":2,\\\"AccountingID\\\":\\\"a012888\\\",\\\"CompressFactor\\\":1},{\\\"Usage\\\":1000000000,\\\"Cost\\\":0.005,\\\"AccountingID\\\":\\\"44d6c02\\\",\\\"CompressFactor\\\":60}],\\\"CompressFactor\\\":1}],\\\"AccountSummary\\\":{\\\"Tenant\\\":\\\"cgrates.org\\\",\\\"ID\\\":\\\"1001\\\",\\\"BalanceSummaries\\\":[{\\\"UUID\\\":\\\"uuid1\\\",\\\"ID\\\":\\\"\\\",\\\"Type\\\":\\\"*monetary\\\",\\\"Initial\\\":0,\\\"Value\\\":50,\\\"Disabled\\\":false}],\\\"AllowNegative\\\":false,\\\"Disabled\\\":false},\\\"Rating\\\":{\\\"c1a5ab9\\\":{\\\"ConnectFee\\\":0.1,\\\"RoundingMethod\\\":\\\"*up\\\",\\\"RoundingDecimals\\\":5,\\\"MaxCost\\\":0,\\\"MaxCostStrategy\\\":\\\"\\\",\\\"TimingID\\\":\\\"\\\",\\\"RatesID\\\":\\\"ec1a177\\\",\\\"RatingFiltersID\\\":\\\"43e77dc\\\"}},\\\"Accounting\\\":{\\\"44d6c02\\\":{\\\"AccountID\\\":\\\"cgrates.org:1001\\\",\\\"BalanceUUID\\\":\\\"uuid1\\\",\\\"RatingID\\\":\\\"\\\",\\\"Units\\\":120.7,\\\"ExtraChargeID\\\":\\\"\\\"},\\\"a012888\\\":{\\\"AccountID\\\":\\\"cgrates.org:1001\\\",\\\"BalanceUUID\\\":\\\"uuid1\\\",\\\"RatingID\\\":\\\"\\\",\\\"Units\\\":120.7,\\\"ExtraChargeID\\\":\\\"\\\"}},\\\"RatingFilters\\\":null,\\\"Rates\\\":{\\\"ec1a177\\\":[{\\\"GroupIntervalStart\\\":0,\\\"Value\\\":0.01,\\\"RateIncrement\\\":60000000000,\\\"RateUnit\\\":1000000000}]},\\\"Timings\\\":null}\",\"Destination\":\"1002\",\"OriginID\":\"oid2\",\"RequestType\":\"*rated\",\"SetupTime\":\"%s\",\"Subject\":\"1001\",\"Tenant\":\"cgrates.org\",\"ToR\":\"*voice\",\"Usage\":\"10000000000\"},\"APIOpts\":{}}>", timeStartFormated, cgrID, timeStartFormated)
var ersLogsCount int
for scanner.Scan() {
line := scanner.Text()
if !strings.Contains(line, "<ERs> DRYRUN, reader: <mysql>") {
if !strings.Contains(line, "<ERs> DRY_RUN, reader: <mysql>") {
continue
}
records++
if !strings.Contains(line, expectedLog) {
t.Errorf("expected \n<%q>, \nreceived\n<%q>", expectedLog, line)
}
if strings.Contains(line, "[INFO] <ERs> DRYRUN") {
if strings.Contains(line, "[INFO] <ERs> DRY_RUN") {
ersLogsCount++
}
}
@@ -1310,6 +1418,33 @@ cgrates.org,FLTR_VARS,*string,~*vars.*readerID,mysql,`,
if ersLogsCount != 1 {
t.Error("Expected only 1 ERS Dryrun log, received: ", ersLogsCount)
}
idx := strings.Index(buf.String(), "CGREvent: ")
if idx == -1 {
t.Fatal("CGREvent not found in log output")
}
var cgrEv utils.CGREvent
if err := json.NewDecoder(strings.NewReader(buf.String()[idx+len("CGREvent: "):])).Decode(&cgrEv); err != nil {
t.Fatal(err)
}
timeStartFormatted := timeStart.Format("2006-01-02T15:04:05Z07:00")
expectedEvent := map[string]any{
"Account": "1001",
"AnswerTime": timeStartFormatted,
"CGRID": cgrID,
"Category": "call",
"CostDetails": utils.ToJSON(cdr2.CostDetails),
"Destination": "1002",
"OriginID": "oid2",
"RequestType": "*rated",
"SetupTime": timeStartFormatted,
"Subject": "1001",
"Tenant": "cgrates.org",
"ToR": "*voice",
"Usage": "10000000000",
}
if got, want := utils.ToJSON(cgrEv.Event), utils.ToJSON(expectedEvent); got != want {
t.Errorf("got event\n%s\nwant\n%s", got, want)
}
})
t.Run("VerifyRowsCount", func(t *testing.T) {
@@ -1520,7 +1655,7 @@ cgrates.org,FLTR_VARS,*string,~*vars.*readerID,mysql,`,
GracefulShutdown: true,
}
ng.Run(t)
time.Sleep(1 * time.Second)
time.Sleep(500 * time.Millisecond)
t.Run("VerifyProcessedFieldsFromLogs", func(t *testing.T) {
time.Sleep(100 * time.Millisecond) // give enough time to process from sql table