error: template: tpl:1:17: executing "tpl"

[pashagolub]

Expected Behavior

No error

Actual Behavior

error executing template        {"error": "template: tpl:1:17: executing \"tpl\" at <index (split (.Value (ctx_key \"data.source\")) \"function() {\") 1>: error calling index: reflect: slice index out of range"}
single http request     {"target": "https://kino.1tv.ru/"}
single http request     {"target": "https://smotrim.ru/"}
error executing template        {"error": "template: tpl:1:17: executing \"tpl\" at <index (split (.Value (ctx_key \"data.source\")) \"function() {\") 1>: error calling index: reflect: slice index out of range"}
single http request     {"target": "https://admin.kino.1tv.ru/"}

Steps to Reproduce the Problem

$ sudo docker run --rm -it --pull always ghcr.io/arriven/db1000n
latest: Pulling from arriven/db1000n
Digest: sha256:3383d841e547b16a67deee3a4d9f05185aaa579c7fb12205dea4a7d1cff2a0d5
Status: Image is up to date for ghcr.io/arriven/db1000n:latest
running db1000n {"version": "v0.8.33", "pid": 1}
...

Specifications

• Version: 0.8.33
• Platform: Docker under Ubuntu

[sq2mo]

Same issue here, also visible on non-docker launch.

[arriven]

This is a job that is designed to bypass qrator failing due to qrator not being enabled by the target. As far as I remember this one should've been a warning but simple output doesn't display log level (I should probably add it back). Anyhow, it's only affecting that bypass job which is not needed if the protection isn't enabled

[pashagolub]

Would it be possible to address this issue somehow? It produces a visual garbage

error executing template        {"error": "template: tpl:1:17: executing \"tpl\" at <index (split (.Value (ctx_key \"data.source\")) \"function() {\") 1>: error calling index: reflect: slice index out of range"}
error executing template        {"error": "template: tpl:1:17: executing \"tpl\" at <index (split (.Value (ctx_key \"data.source\")) \"function() {\") 1>: error calling index: reflect: slice index out of range"}

[roman-kruglov]

This is a job that is designed to bypass qrator failing due to qrator not being enabled by the target. As far as I remember this one should've been a warning but simple output doesn't display log level (I should probably add it back). Anyhow, it's only affecting that bypass job which is not needed if the protection isn't enabled

-log-format console already has that additional information.

[arriven]

I've moved those logs to debug output as it usually doesn't mean anything to a regular user, will be available with next release

[pashagolub]

-log-format console already has that additional information.

Is it a known issue with timestamp representation in this mode?

1.6520072161734493e+09  info    job/http.go:69  single http request     {"target": "https://www.rbc.ru/search/?query=%D0%B0%20%D1%81%20%D0%BA%20%D0%BD%D0%B0%20%D0%B2%20%D0%BE%D1%82"}
1.652007228045275e+09   info    job/http.go:69  single http request     {"target": "https://www.kolesa-darom.ru/catalog/avto/akkumulyatory/"}

[roman-kruglov]

Would it be possible to address this issue somehow? It produces a visual garbage

error executing template        {"error": "template: tpl:1:17: executing \"tpl\" at <index (split (.Value (ctx_key \"data.source\")) \"function() {\") 1>: error calling index: reflect: slice index out of range"}
error executing template        {"error": "template: tpl:1:17: executing \"tpl\" at <index (split (.Value (ctx_key \"data.source\")) \"function() {\") 1>: error calling index: reflect: slice index out of range"}

I also encounter similar errors time to time. Like right now:

error executing template    {"error": "template: tpl:1:17: executing \"tpl\" at <index (split (.Value (ctx_key \"data.source\")) \"function() {\") 1>: error calling index: reflect: slice index out of range"}

I think this is related to the current config rather than the app itself. Not sure how severe this is, to me it seems like some fuck up in configs. If it's not that - maybe we could tweek the message itself to make it more understandable for ordinary folks like me?

Ah, hiding it to debug makes even more sense

[roman-kruglov]

-log-format console already has that additional information.

Is it a known issue with timestamp representation in this mode?

1.6520072161734493e+09  info    job/http.go:69  single http request     {"target": "https://www.rbc.ru/search/?query=%D0%B0%20%D1%81%20%D0%BA%20%D0%BD%D0%B0%20%D0%B2%20%D0%BE%D1%82"}
1.652007228045275e+09   info    job/http.go:69  single http request     {"target": "https://www.kolesa-darom.ru/catalog/avto/akkumulyatory/"}

It's configurable (in code) like described here https://pkg.go.dev/go.uber.org/zap@v1.21.0/zapcore#EncoderConfig namely EncodeTime and probably EncodeDuration.

I can change it to something else. What would be the expected or preferred form? @Arriven what do you think?

[arriven]

I'd probably use something like iso8601 or rfc3339 for console layout but leave it as is for json one

[arriven]

https://github.com/uber-go/zap/blob/6f34060764b5ea1367eecda380ba8a9a0de3f0e6/zapcore/encoder.go#L135 looks like it already has implementations for that

[roman-kruglov]

https://github.com/uber-go/zap/blob/6f34060764b5ea1367eecda380ba8a9a0de3f0e6/zapcore/encoder.go#L135 looks like it already has implementations for that

yep, just need to switch to another one

[roman-kruglov]

here it goes https://github.com/Arriven/db1000n/pull/538 - changes the time format for console log format output

[roman-kruglov]

these issues seem to be addressed, propose to close this issue