cron.go: the crons are not working for automatic starting of broadcasts

Issue #224 resolved
Trek Hopton created an issue

Checking the google cloud logs we see logs like this:

DEFAULT 2023-02-25T01:30:00.001259Z 2023/02/25 01:30:00 cron run: calling "camOn" at site=492735809745 with "": <nil>
WARNING 2023-02-25T01:30:00.009185Z [pid1-app] Exit 2 app (pid 11): /layers/google.go.build/bin/main [session:H9P1VC6]
WARNING 2023-02-25T01:30:00.009792Z [pid1] A process stopped unexpectedly: <nil> [session:H9P1VC6]
INFO 2023-02-25T01:30:00.010038Z [pid1] Sending terminated signal to processes [session:H9P1VC6]
INFO 2023-02-25T01:30:00.010223Z [pid1] Stopping all processes [session:H9P1VC6]
INFO 2023-02-25T01:30:00.010231Z [pid1] Done [session:H9P1VC6]
INFO 2023-02-25T01:30:00.010428Z [pid1] shutdown [session:H9P1VC6]
DEFAULT 2023-02-25T01:30:00.089874Z [protoPayload.method: GET] [protoPayload.status: 500] [protoPayload.latency: 57 ms] [protoPayload.userAgent: AppEngine-Google; (+http://code.google.com/appengine)] /broadcastcheck
WARNING 2023-02-25T01:30:00.124869967Z Container called exit(0).
ERROR 2023-02-25T01:30:00.124993Z panic: cannot unmarshal broadcast config data: unexpected end of JSON input goroutine 351 [running]: main.camOnCallback.func1(0x0, 0x0, 0xc0001e6f38, 0x4) /layers/google.go.appengine_gomod/srv/broadcast.go:914 +0x1bf main.(*scheduler).set.func8() /layers/google.go.appengine_gomod/srv/cron.go:222 +0x16e github.com/robfig/cron/v3.FuncJob.Run(0xc000436510) /layers/google.go.gomod/gopath/pkg/mod/github.com/robfig/cron/v3@v3.0.1/cron.go:136 +0x25 github.com/robfig/cron/v3.(*Cron).startJob.func1(0xc0004b1540, 0xef5b60, 0xc000436510) /layers/google.go.gomod/gopath/pkg/mod/github.com/robfig/cron/v3@v3.0.1/cron.go:312 +0x65 created by github.com/robfig/cron/v3.(*Cron).startJob /layers/google.go.gomod/gopath/pkg/mod/github.com/robfig/cron/v3@v3.0.1/cron.go:310 +0x73
INFO 2023-02-25T01:30:00.966243Z [protoPayload.method: GET] [protoPayload.status: 200] [protoPayload.responseSize: 259 B] [protoPayload.latency: 31.505 s] [protoPayload.userAgent: Go-http-client 1.1] /poll?vn=161&ma=8C:C6:81:6C:E1:99&dk=16620386&ut=24519
INFO 2023-02-25T01:30:01.134101Z [pid1] started [session:51GB8DM]
DEBUG 2023-02-25T01:30:01.135850Z [pid1-app] Using app start info from /srv/.googleconfig/app_start.json: &main.appStart{Entrypoint:struct { Type string "json:\"type\""; UnparsedValue string "json:\"unparsed_value\""; Command string "json:\"command\""; WorkDir string "json:\"workdir\"" }{Type:"Generated", UnparsedValue:"", Command:"main", WorkDir:""}, EntrypointFromAppYAML:"", EntrypointContents:"", Runtime:"go115"} [session:51GB8DM]
INFO 2023-02-25T01:30:01.136082Z [pid1] Starting processes [app nginx] [session:51GB8DM]
INFO 2023-02-25T01:30:01.137345Z [pid1-app] app has no prerequisites, starting immediately [session:51GB8DM]
INFO 2023-02-25T01:30:01.137779Z [pid1-nginx] nginx waiting for any of 3 prerequisite(s): [portbind:tcp:localhost:8080 portbind:tcp:localhost:8081 portbind:unix:/tmp/google-config/app.sock] [session:51GB8DM]
INFO 2023-02-25T01:30:01.169302Z [pid1-app] Starting app (pid 12): /layers/google.go.build/bin/main [session:51GB8DM]
DEFAULT 2023-02-25T01:30:01.368774Z 2023/02/25 01:30:01 Running in App Engine mode
DEFAULT 2023-02-25T01:30:02.031359Z 2023/02/25 01:30:02 Initializing OAuth2
DEFAULT 2023-02-25T01:30:07.273155Z 2023/02/25 01:30:07 setting cron: Test
DEFAULT 2023-02-25T01:30:07.273172Z 2023/02/25 01:30:07 failed to set job {Skey:201489903059 ID:Test Time:1970-01-01 05:03:00 +0000 UTC TOD: Repeat:false Minutes:303 Action:set Var:Test Data:true Enabled:true} from site=201489903059: could not get cron spec for job: Test: no time spec specified for job
DEFAULT 2023-02-25T01:30:08.091571Z 2023/02/25 01:30:08 setting cron: CamOff
DEFAULT 2023-02-25T01:30:08.091584Z 2023/02/25 01:30:08 cron: CamOff spec: Sunset
DEFAULT 2023-02-25T01:30:08.091592Z 2023/02/25 01:30:08 failed to set job {Skey:214536881915 ID:CamOff Time:1970-01-01 18:00:00 +0000 UTC TOD:Sunset Repeat:false Minutes:1080 Action:set Var:ExampleESP.Power Data:false Enabled:true} from site=214536881915: failed to add cron spec Sunset to the cron scheduler: expected exactly 5 fields, found 1: [Sunset]

It seems like a poorly formed JSON string is perhaps the culprit which results in crons not being able to be called.

Comments (2)

  1. Trek Hopton reporter

    job.Data is also reported as being <nil> in the first log. Not sure if this is where to start.

  2. Trek Hopton reporter

    This issue was due to old crons being invalidated by new requirements pushed with vidforward. The crons were deleted so the issue is fixed.

  3. Log in to comment