The WolfspyreLabs Blog/ 2022/ November/ Getting Unifi Protect logs into loki/ Getting Unifi Protect logs into loki November 14 2022·18 mins Guh. Fun Camera Logs #Some useful reminders Each camera gets its’ own, rotating logfile1 . These live in /volume1/.srv/unifi-protect/logs/cameras/ The device’s MAC address is used as the filename in uppercase. EX: AF09F9A0D05C.log The camera logs look something like this: Breakdown of a camera logfile entry # Unifi Protect Camera Log file breakdown 2022-11-13T06:54:24.538Z - info: name: FFAA009912AB_2; hasAudio: 1; suppressAudio: 0; hasVideo: 1; suppressVideo: 0; withTalkback: 0; withOpus: 0; opusSampleRate: none; extendedFormat: 1; avFlags: 0x07 [appname:source-code-file:source-function:line#] { datetime: '2022-11-13T06:54:24Z', ident: 'application-pretty-name', pid: 422, uptime: '105303,062', cameraMac: 'FFAA009912AB' } Unifi Protect Camera Logs 2022-11-13T06:54:08.207Z - info: some message here [appname:source-code-file:source-function:line#] { datetime: '2022-11-13T06:54:08Z', ident: 'app-prettypname', pid: 422, uptime: '105286,764', cameraMac: 'FFAA009912AB' } 2022-11-13T06:54:12.909Z - info: Persisted [otherappname:source-code-file:source-function:line#] { datetime: '2022-11-13T06:54:12Z', ident: 'other-app-pretty-name', pid: 415, uptime: '105291,526', cameraMac: 'FFAA009912AB' } 2022-11-13T06:54:24.528Z - info: ChangeVideoSettings IPC called [yetanotherappname:source-code-file:source-function:line#] { datetime: '2022-11-13T06:54:24Z', ident: 'yet-another-application-pretty-name', pid: 422, uptime: '105303,052', cameraMac: 'FFAA009912AB' } so, a regex which matches the log line would be something like: '^(\d{4}-\d{2}-\d{2}).(\d{2}:\d{2}:\d{2}.\d+). - (\w+): (.*)\[(\w+):([\w\.]+):([\w\.]+):(\d+)\]' Tons of fun, right? So how do we get there from here? Attempt #4 # promtail config attempt 4 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 server: log_level: debug http_listen_port: 3101 client: url: http://lokihost:3100/loki/api/v1/push positions: filename: /run/promtail_positions.yaml scrape_configs: - job_name: protect pipeline_stages: - multiline: firstline: '^(\d{4}-\d{2}-\d{2}).(\d{2}:\d{2}:\d{2}.\d+). - (\w+): (.*)\[(\w+):([\w\.]+):([\w\.]+):(\d+)\]' max_wait_time: 2s - regex: expression: '^(?P<date>\d{4}-\d{2}-\d{2}).(?P<time>\d{2}:\d{2}:\d{2}.\d+). - (?P<level>\w+): (?P<message>.*)\[(?P<appname>\w+):(?P<sourcefile>[\w\.]+):(?P<codefunction>[\w\.]+):(?P<linenum>\d+)\]' - labels: date: time: level: message: static_configs: - targets: - localhost labels: job: protect # A `job` label is fairly standard in prometheus and useful for linking metrics and logs. host: protect role: cameras agent: promtail __path__: /volume1/.srv/unifi-protect/logs/cameras/????????????.log promtail log vonit 4 level=debug ts=2022-11-13T18:32:04.657947758Z caller=promtail.go:115 msg="Reloading configuration file" level=info ts=2022-11-13T18:32:04.664388615Z caller=promtail.go:123 msg="Reloading configuration file" md5sum=6fb358755d2ddcd2bdc1fc91acfc0462 level=warn ts=2022-11-13T18:32:04.664434061Z caller=config.go:70 msg="use of CLI client.* and config file Client block are both deprecated in favour of the config file Clients block and will be removed in a future release" level=debug ts=2022-11-13T18:32:04.667853407Z caller=manager.go:289 component=discovery msg="Starting provider" provider=static/0 subs=map[protect:{}] level=debug ts=2022-11-13T18:32:04.67020684Z caller=manager.go:323 component=discovery msg="Discoverer channel closed" provider=static/0 level=info ts=2022-11-13T18:32:04.671467497Z caller=server.go:323 http=[::]:3101 grpc=[::]:9095 msg="server listening on addresses" level=info ts=2022-11-13T18:32:04.67476734Z caller=main.go:171 msg="Starting Promtail" version="(version=HEAD-1b627d8, branch=HEAD, revision=1b627d880)" level=warn ts=2022-11-13T18:32:04.674832878Z caller=promtail.go:220 msg="enable watchConfig" level=debug ts=2022-11-13T18:32:09.672262807Z caller=filetargetmanager.go:292 msg="new target" labels="{__address__=\"localhost\"}" level=info ts=2022-11-13T18:32:09.672406979Z caller=filetargetmanager.go:352 msg="Adding target" key="/camz/????????????.log:{agent=\"promtail\", host=\"protect\", job=\"protect\", role=\"cameras\"}" level=info ts=2022-11-13T18:32:09.67261914Z caller=filetarget.go:282 msg="watching new directory" directory=/camz level=debug ts=2022-11-13T18:32:09.672654386Z caller=filetarget.go:332 msg="tailing new file" filename=/camz/44D9E794DDD4.log level=info ts=2022-11-13T18:32:09.672873489Z caller=tailer.go:143 component=tailer msg="tail routine: started" path=/camz/44D9E794DDD4.log ts=2022-11-13T18:32:09.673588333Z caller=log.go:168 level=info msg="Seeked /camz/44D9E794DDD4.log - &{Offset:0 Whence:0}" level=debug ts=2022-11-13T18:32:09.674662252Z caller=multiline.go:123 component=file_pipeline component=stage type=multiline msg="creating new stream" stream=4eb14ad2719a968a level=debug ts=2022-11-13T18:32:09.674729315Z caller=multiline.go:132 component=file_pipeline component=stage type=multiline msg="pass entry" stream=4eb14ad2719a968a line="2022-11-13T17:22:52.990Z - info: Persisted [ubnt_ctlserver:Persistence.cpp:persist:66]" level=debug ts=2022-11-13T18:32:09.674779406Z caller=multiline.go:163 component=file_pipeline component=stage type=multiline msg="processing line" line="2022-11-13T17:22:52.990Z - info: Persisted [ubnt_ctlserver:Persistence.cpp:persist:66]" stream=4eb14ad2719a968a level=debug ts=2022-11-13T18:32:09.674810195Z caller=multiline.go:177 component=file_pipeline component=stage type=multiline msg="flush multiline block because new start line" block= stream=4eb14ad2719a968a level=debug ts=2022-11-13T18:32:09.674831932Z caller=multiline.go:203 component=file_pipeline component=stage type=multiline msg="nothing to flush" buffer_len=0 level=debug ts=2022-11-13T18:32:09.674867058Z caller=multiline.go:132 component=file_pipeline component=stage type=multiline msg="pass entry" stream=4eb14ad2719a968a line={ level=debug ts=2022-11-13T18:32:09.674893287Z caller=multiline.go:163 component=file_pipeline component=stage type=multiline msg="processing line" line={ stream=4eb14ad2719a968a level=debug ts=2022-11-13T18:32:09.674922121Z caller=multiline.go:132 component=file_pipeline component=stage type=multiline msg="pass entry" stream=4eb14ad2719a968a line=" datetime: '2022-11-13T17:22:52Z'," level=debug ts=2022-11-13T18:32:09.67495459Z caller=multiline.go:163 component=file_pipeline component=stage type=multiline msg="processing line" line=" datetime: '2022-11-13T17:22:52Z'," stream=4eb14ad2719a968a level=debug ts=2022-11-13T18:32:09.674979704Z caller=multiline.go:177 component=file_pipeline component=stage type=multiline msg="flush multiline block because new start line" block="2022-11-13T17:22:52.990Z - info: Persisted [ubnt_ctlserver:Persistence.cpp:persist:66]\n{" stream=4eb14ad2719a968a level=debug ts=2022-11-13T18:32:09.675051636Z caller=regex.go:121 component=file_pipeline component=stage type=regex msg="regex did not match" input="2022-11-13T17:22:52.990Z - info: Persisted [ubnt_ctlserver:Persistence.cpp:persist:66]\n{" regex="^(?P<date>\\d{4}-\\d{2}-\\d{2}).(?P<time>\\d{2}:\\d{2}:\\d{2}.\\d+). - (?P<level>\\w+): (?P<message>.*)\\[(?P<appname>\\w+):(?P<sourcefile>[\\w\\.]+):(?P<codefunction>[\\w\\.]+):(?P<linenum>\\d+)\\]\\n\\{$\\n(^ (\\w+): (.*),?$\\n)+\\}" level=debug ts=2022-11-13T18:32:09.675221351Z caller=multiline.go:132 component=file_pipeline component=stage type=multiline msg="pass entry" stream=4eb14ad2719a968a line=" ident: 'ctl'," level=debug ts=2022-11-13T18:32:09.675251711Z caller=multiline.go:163 component=file_pipeline component=stage type=multiline msg="processing line" line=" ident: 'ctl'," stream=4eb14ad2719a968a level=debug ts=2022-11-13T18:32:09.675287677Z caller=multiline.go:132 component=file_pipeline component=stage type=multiline msg="pass entry" stream=4eb14ad2719a968a line=" pid: 415," level=debug ts=2022-11-13T18:32:09.67531286Z caller=multiline.go:163 component=file_pipeline component=stage type=multiline msg="processing line" line=" pid: 415," stream=4eb14ad2719a968a level=debug ts=2022-11-13T18:32:09.675351483Z caller=multiline.go:132 component=file_pipeline component=stage type=multiline msg="pass entry" stream=4eb14ad2719a968a line=" uptime: '143011,552'," level=debug ts=2022-11-13T18:32:09.675376203Z caller=multiline.go:163 component=file_pipeline component=stage type=multiline msg="processing line" line=" uptime: '143011,552'," stream=4eb14ad2719a968a level=debug ts=2022-11-13T18:32:09.675440695Z caller=multiline.go:132 component=file_pipeline component=stage type=multiline msg="pass entry" stream=4eb14ad2719a968a line=" cameraMac: '44D9E794DDD4'" level=debug ts=2022-11-13T18:32:09.675466632Z caller=multiline.go:163 component=file_pipeline component=stage type=multiline msg="processing line" line=" cameraMac: '44D9E794DDD4'" stream=4eb14ad2719a968a level=debug ts=2022-11-13T18:32:09.675552175Z caller=multiline.go:132 component=file_pipeline component=stage type=multiline msg="pass entry" stream=4eb14ad2719a968a line=} level=debug ts=2022-11-13T18:32:09.675576313Z caller=multiline.go:132 component=file_pipeline component=stage type=multiline msg="pass entry" stream=4eb14ad2719a968a line="2022-11-13T17:23:04.192Z - info: ChangeVideoSettings IPC called [ubnt_streamer:changevideosettingshandler.cpp:HandleRequest:48]" level=debug ts=2022-11-13T18:32:09.675613187Z caller=multiline.go:163 component=file_pipeline component=stage type=multiline msg="processing line" line=} stream=4eb14ad2719a968a level=debug ts=2022-11-13T18:32:09.67563669Z caller=multiline.go:163 component=file_pipeline component=stage type=multiline msg="processing line" line="2022-11-13T17:23:04.192Z - info: ChangeVideoSettings IPC called [ubnt_streamer:changevideosettingshandler.cpp:HandleRequest:48]" stream=4eb14ad2719a968a level=debug ts=2022-11-13T18:32:09.67567977Z caller=multiline.go:177 component=file_pipeline component=stage type=multiline msg="flush multiline block because new start line" block=" datetime: '2022-11-13T17:22:52Z',\n ident: 'ctl',\n pid: 415,\n uptime: '143011,552',\n cameraMac: '44D9E794DDD4'\n}" stream=4eb14ad2719a968a level=debug ts=2022-11-13T18:32:09.675717553Z caller=regex.go:121 component=file_pipeline component=stage type=regex msg="regex did not match" input=" datetime: '2022-11-13T17:22:52Z',\n ident: 'ctl',\n pid: 415,\n uptime: '143011,552',\n cameraMac: '44D9E794DDD4'\n}" regex="^(?P<date>\\d{4}-\\d{2}-\\d{2}).(?P<time>\\d{2}:\\d{2}:\\d{2}.\\d+). - (?P<level>\\w+): (?P<message>.*)\\[(?P<appname>\\w+):(?P<sourcefile>[\\w\\.]+):(?P<codefunction>[\\w\\.]+):(?P<linenum>\\d+)\\]\\n\\{$\\n(^ (\\w+): (.*),?$\\n)+\\}" level=debug ts=2022-11-13T18:32:09.675757068Z caller=multiline.go:132 component=file_pipeline component=stage type=multiline msg="pass entry" stream=4eb14ad2719a968a line={ level=debug ts=2022-11-13T18:32:09.675793994Z caller=multiline.go:163 component=file_pipeline component=stage type=multiline msg="processing line" line={ stream=4eb14ad2719a968a level=debug ts=2022-11-13T18:32:09.675826205Z caller=multiline.go:132 component=file_pipeline component=stage type=multiline msg="pass entry" stream=4eb14ad2719a968a line=" datetime: '2022-11-13T17:23:04Z'," level=debug ts=2022-11-13T18:32:09.675853668Z caller=multiline.go:132 component=file_pipeline component=stage type=multiline msg="pass entry" stream=4eb14ad2719a968a line=" ident: 'streamer'," level=debug ts=2022-11-13T18:32:09.675872234Z caller=multiline.go:163 component=file_pipeline component=stage type=multiline msg="processing line" line=" datetime: '2022-11-13T17:23:04Z'," stream=4eb14ad2719a968a level=debug ts=2022-11-13T18:32:09.675945503Z caller=multiline.go:177 component=file_pipeline component=stage type=multiline msg="flush multiline block because new start line" block="2022-11-13T17:23:04.192Z - info: ChangeVideoSettings IPC called [ubnt_streamer:changevideosettingshandler.cpp:HandleRequest:48]\n{" stream=4eb14ad2719a968a level=debug ts=2022-11-13T18:32:09.675981194Z caller=multiline.go:163 component=file_pipeline component=stage type=multiline msg="processing line" line=" ident: 'streamer'," stream=4eb14ad2719a968a level=debug ts=2022-11-13T18:32:09.676012515Z caller=multiline.go:132 component=file_pipeline component=stage type=multiline msg="pass entry" stream=4eb14ad2719a968a line=" pid: 422," level=debug ts=2022-11-13T18:32:09.676037423Z caller=multiline.go:163 component=file_pipeline component=stage type=multiline msg="processing line" line=" pid: 422," stream=4eb14ad2719a968a level=debug ts=2022-11-13T18:32:09.676094012Z caller=regex.go:121 component=file_pipeline component=stage type=regex msg="regex did not match" input="2022-11-13T17:23:04.192Z - info: ChangeVideoSettings IPC called [ubnt_streamer:changevideosettingshandler.cpp:HandleRequest:48]\n{" regex="^(?P<date>\\d{4}-\\d{2}-\\d{2}).(?P<time>\\d{2}:\\d{2}:\\d{2}.\\d+). - (?P<level>\\w+): (?P<message>.*)\\[(?P<appname>\\w+):(?P<sourcefile>[\\w\\.]+):(?P<codefunction>[\\w\\.]+):(?P<linenum>\\d+)\\]\\n\\{$\\n(^ (\\w+): (.*),?$\\n)+\\}" level=debug ts=2022-11-13T18:32:09.676150378Z caller=multiline.go:132 component=file_pipeline component=stage type=multiline msg="pass entry" stream=4eb14ad2719a968a line=" uptime: '143022,778'," level=debug ts=2022-11-13T18:32:09.676176521Z caller=multiline.go:163 component=file_pipeline component=stage type=multiline msg="processing line" line=" uptime: '143022,778'," stream=4eb14ad2719a968a level=debug ts=2022-11-13T18:32:09.676210053Z caller=multiline.go:132 component=file_pipeline component=stage type=multiline msg="pass entry" stream=4eb14ad2719a968a line=" cameraMac: '44D9E794DDD4'" level=debug ts=2022-11-13T18:32:09.67623599Z caller=multiline.go:163 component=file_pipeline component=stage type=multiline msg="processing line" line=" cameraMac: '44D9E794DDD4'" stream=4eb14ad2719a968a level=debug ts=2022-11-13T18:32:09.676273636Z caller=multiline.go:132 component=file_pipeline component=stage type=multiline msg="pass entry" stream=4eb14ad2719a968a line=} level=debug ts=2022-11-13T18:32:09.676297362Z caller=multiline.go:163 component=file_pipeline component=stage type=multiline msg="processing line" line=} stream=4eb14ad2719a968a level=debug ts=2022-11-13T18:32:09.676329247Z caller=multiline.go:132 component=file_pipeline component=stage type=multiline msg="pass entry" stream=4eb14ad2719a968a line="2022-11-13T17:23:04.203Z - info: name: ktMDW6CtPUf1KDro; hasAudio: 1; suppressAudio: 0; hasVideo: 1; suppressVideo: 0; withTalkback: 0; withOpus: 1; opusSampleRate: 24000; extendedFormat: 1; avFlags: 0x07 [" level=debug ts=2022-11-13T18:32:09.676354088Z caller=multiline.go:163 component=file_pipeline component=stage type=multiline msg="processing line" line="2022-11-13T17:23:04.203Z - info: name: ktMDW6CtPUf1KDro; hasAudio: 1; suppressAudio: 0; hasVideo: 1; suppressVideo: 0; withTalkback: 0; withOpus: 1; opusSampleRate: 24000; extendedFormat: 1; avFlags: 0x07 [" stream=4eb14ad2719a968a level=debug ts=2022-11-13T18:32:09.676383213Z caller=multiline.go:177 component=file_pipeline component=stage type=multiline msg="flush multiline block because new start line" block=" datetime: '2022-11-13T17:23:04Z',\n ident: 'streamer',\n pid: 422,\n uptime: '143022,778',\n cameraMac: '44D9E794DDD4'\n}" stream=4eb14ad2719a968a level=debug ts=2022-11-13T18:32:09.676416591Z caller=regex.go:121 component=file_pipeline component=stage type=regex msg="regex did not match" input=" datetime: '2022-11-13T17:23:04Z',\n ident: 'streamer',\n pid: 422,\n uptime: '143022,778',\n cameraMac: '44D9E794DDD4'\n}" regex="^(?P<date>\\d{4}-\\d{2}-\\d{2}).(?P<time>\\d{2}:\\d{2}:\\d{2}.\\d+). - (?P<level>\\w+): (?P<message>.*)\\[(?P<appname>\\w+):(?P<sourcefile>[\\w\\.]+):(?P<codefunction>[\\w\\.]+):(?P<linenum>\\d+)\\]\\n\\{$\\n(^ (\\w+): (.*),?$\\n)+\\}" level=debug ts=2022-11-13T18:32:09.676472991Z caller=multiline.go:132 component=file_pipeline component=stage type=multiline msg="pass entry" stream=4eb14ad2719a968a line=ubnt_encoder:containerflv.cpp:BuildOnMetadata:488] level=debug ts=2022-11-13T18:32:09.676498654Z caller=multiline.go:163 component=file_pipeline component=stage type=multiline msg="processing line" line=ubnt_encoder:containerflv.cpp:BuildOnMetadata:488] stream=4eb14ad2719a968a level=debug ts=2022-11-13T18:32:09.676644575Z caller=multiline.go:132 component=file_pipeline component=stage type=multiline msg="pass entry" stream=4eb14ad2719a968a line={ level=debug ts=2022-11-13T18:32:09.676671797Z caller=multiline.go:132 component=file_pipeline component=stage type=multiline msg="pass entry" stream=4eb14ad2719a968a line=" datetime: '2022-11-13T17:23:04Z'," level=debug ts=2022-11-13T18:32:09.676710146Z caller=multiline.go:163 component=file_pipeline component=stage type=multiline msg="processing line" line={ stream=4eb14ad2719a968a level=debug ts=2022-11-13T18:32:09.676735243Z caller=multiline.go:163 component=file_pipeline component=stage type=multiline msg="processing line" line=" datetime: '2022-11-13T17:23:04Z'," stream=4eb14ad2719a968a level=debug ts=2022-11-13T18:32:09.676758952Z caller=multiline.go:177 component=file_pipeline component=stage type=multiline msg="flush multiline block because new start line" block="2022-11-13T17:23:04.203Z - info: name: ktMDW6CtPUf1KDro; hasAudio: 1; suppressAudio: 0; hasVideo: 1; suppressVideo: 0; withTalkback: 0; withOpus: 1; opusSampleRate: 24000; extendedFormat: 1; avFlags: 0x07 [\nubnt_encoder:containerflv.cpp:BuildOnMetadata:488]\n{" stream=4eb14ad2719a968a level=debug ts=2022-11-13T18:32:09.676808941Z caller=regex.go:121 component=file_pipeline component=stage type=regex msg="regex did not match" input="2022-11-13T17:23:04.203Z - info: name: ktMDW6CtPUf1KDro; hasAudio: 1; suppressAudio: 0; hasVideo: 1; suppressVideo: 0; withTalkback: 0; withOpus: 1; opusSampleRate: 24000; extendedFormat: 1; avFlags: 0x07 [\nubnt_encoder:containerflv.cpp:BuildOnMetadata:488]\n{" regex="^(?P<date>\\d{4}-\\d{2}-\\d{2}).(?P<time>\\d{2}:\\d{2}:\\d{2}.\\d+). - (?P<level>\\w+): (?P<message>.*)\\[(?P<appname>\\w+):(?P<sourcefile>[\\w\\.]+):(?P<codefunction>[\\w\\.]+):(?P<linenum>\\d+)\\]\\n\\{$\\n(^ (\\w+): (.*),?$\\n)+\\}" level=debug ts=2022-11-13T18:32:09.67685881Z caller=multiline.go:132 component=file_pipeline component=stage type=multiline msg="pass entry" stream=4eb14ad2719a968a line=" ident: 'streamer'," level=debug ts=2022-11-13T18:32:09.676883478Z caller=multiline.go:163 component=file_pipeline component=stage type=multiline msg="processing line" line=" ident: 'streamer'," stream=4eb14ad2719a968a level=debug ts=2022-11-13T18:32:09.676919719Z caller=multiline.go:132 component=file_pipeline component=stage type=multiline msg="pass entry" stream=4eb14ad2719a968a line=" pid: 422," level=debug ts=2022-11-13T18:32:09.676948759Z caller=multiline.go:163 component=file_pipeline component=stage type=multiline msg="processing line" line=" pid: 422," stream=4eb14ad2719a968a level=debug ts=2022-11-13T18:32:09.676980627Z caller=multiline.go:132 component=file_pipeline component=stage type=multiline msg="pass entry" stream=4eb14ad2719a968a line=" uptime: '143022,789'," level=debug ts=2022-11-13T18:32:09.677004388Z caller=multiline.go:163 component=file_pipeline component=stage type=multiline msg="processing line" line=" uptime: '143022,789'," stream=4eb14ad2719a968a level=debug ts=2022-11-13T18:32:09.677040165Z caller=multiline.go:132 component=file_pipeline component=stage type=multiline msg="pass entry" stream=4eb14ad2719a968a line=" cameraMac: '44D9E794DDD4'" level=debug ts=2022-11-13T18:32:09.677064439Z caller=multiline.go:163 component=file_pipeline component=stage type=multiline msg="processing line" line=" cameraMac: '44D9E794DDD4'" stream=4eb14ad2719a968a level=debug ts=2022-11-13T18:32:09.677118902Z caller=multiline.go:132 component=file_pipeline component=stage type=multiline msg="pass entry" stream=4eb14ad2719a968a line=} level=debug ts=2022-11-13T18:32:09.677144085Z caller=multiline.go:163 component=file_pipeline component=stage type=multiline msg="processing line" line=} stream=4eb14ad2719a968a level=debug ts=2022-11-13T18:32:09.677187045Z caller=multiline.go:132 component=file_pipeline component=stage type=multiline msg="pass entry" stream=4eb14ad2719a968a line="2022-11-13T17:23:04.213Z - info: Transport created for channel 2: `tcp://198.18.36.62:7550?retryInterval=1&connectTimeout=5` [ubnt_encoder:outstream.cpp:AddTransport:93]" level=debug ts=2022-11-13T18:32:09.677216857Z caller=multiline.go:163 component=file_pipeline component=stage type=multiline msg="processing line" line="2022-11-13T17:23:04.213Z - info: Transport created for channel 2: `tcp://198.18.36.62:7550?retryInterval=1&connectTimeout=5` [ubnt_encoder:outstream.cpp:AddTransport:93]" stream=4eb14ad2719a968a level=debug ts=2022-11-13T18:32:09.677245246Z caller=multiline.go:177 component=file_pipeline component=stage type=multiline msg="flush multiline block because new start line" block=" datetime: '2022-11-13T17:23:04Z',\n ident: 'streamer',\n pid: 422,\n uptime: '143022,789',\n cameraMac: '44D9E794DDD4'\n}" stream=4eb14ad2719a968a level=debug ts=2022-11-13T18:32:09.677274869Z caller=regex.go:121 component=file_pipeline component=stage type=regex msg="regex did not match" input=" datetime: '2022-11-13T17:23:04Z',\n ident: 'streamer',\n pid: 422,\n uptime: '143022,789',\n cameraMac: '44D9E794DDD4'\n}" regex="^(?P<date>\\d{4}-\\d{2}-\\d{2}).(?P<time>\\d{2}:\\d{2}:\\d{2}.\\d+). - (?P<level>\\w+): (?P<message>.*)\\[(?P<appname>\\w+):(?P<sourcefile>[\\w\\.]+):(?P<codefunction>[\\w\\.]+):(?P<linenum>\\d+)\\]\\n\\{$\\n(^ (\\w+): (.*),?$\\n)+\\}" level=debug ts=2022-11-13T18:32:09.677390103Z caller=multiline.go:132 component=file_pipeline component=stage type=multiline msg="pass entry" stream=4eb14ad2719a968a line={ level=debug ts=2022-11-13T18:32:09.677417944Z caller=multiline.go:132 component=file_pipeline component=stage type=multiline msg="pass entry" stream=4eb14ad2719a968a line=" datetime: '2022-11-13T17:23:04Z'," level=debug ts=2022-11-13T18:32:09.677484338Z caller=multiline.go:163 component=file_pipeline component=stage type=multiline msg="processing line" line={ stream=4eb14ad2719a968a level=debug ts=2022-11-13T18:32:09.677522807Z caller=multiline.go:163 component=file_pipeline component=stage type=multiline msg="processing line" line=" datetime: '2022-11-13T17:23:04Z'," stream=4eb14ad2719a968a level=debug ts=2022-11-13T18:32:09.677563264Z caller=multiline.go:177 component=file_pipeline component=stage type=multiline msg="flush multiline block because new start line" block="2022-11-13T17:23:04.213Z - info: Transport created for channel 2: `tcp://198.18.36.62:7550?retryInterval=1&connectTimeout=5` [ubnt_encoder:outstream.cpp:AddTransport:93]\n{" stream=4eb14ad2719a968a level=debug ts=2022-11-13T18:32:09.67762575Z caller=regex.go:121 component=file_pipeline component=stage type=regex msg="regex did not match" input="2022-11-13T17:23:04.213Z - info: Transport created for channel 2: `tcp://198.18.36.62:7550?retryInterval=1&connectTimeout=5` [ubnt_encoder:outstream.cpp:AddTransport:93]\n{" regex="^(?P<date>\\d{4}-\\d{2}-\\d{2}).(?P<time>\\d{2}:\\d{2}:\\d{2}.\\d+). - (?P<level>\\w+): (?P<message>.*)\\[(?P<appname>\\w+):(?P<sourcefile>[\\w\\.]+):(?P<codefunction>[\\w\\.]+):(?P<linenum>\\d+)\\]\\n\\{$\\n(^ (\\w+): (.*),?$\\n)+\\}" level=debug ts=2022-11-13T18:32:09.677672362Z caller=multiline.go:132 component=file_pipeline component=stage type=multiline msg="pass entry" stream=4eb14ad2719a968a line=" ident: 'streamer'," level=debug ts=2022-11-13T18:32:09.677697322Z caller=multiline.go:163 component=file_pipeline component=stage type=multiline msg="processing line" line=" ident: 'streamer'," stream=4eb14ad2719a968a level=debug ts=2022-11-13T18:32:09.677726002Z caller=multiline.go:132 component=file_pipeline component=stage type=multiline msg="pass entry" stream=4eb14ad2719a968a line=" pid: 422," level=debug ts=2022-11-13T18:32:09.677749111Z caller=multiline.go:163 component=file_pipeline component=stage type=multiline msg="processing line" line=" pid: 422," stream=4eb14ad2719a968a level=debug ts=2022-11-13T18:32:09.677788111Z caller=multiline.go:132 component=file_pipeline component=stage type=multiline msg="pass entry" stream=4eb14ad2719a968a line=" uptime: '143022,812'," level=debug ts=2022-11-13T18:32:09.677825568Z caller=multiline.go:163 component=file_pipeline component=stage type=multiline msg="processing line" line=" uptime: '143022,812'," stream=4eb14ad2719a968a level=debug ts=2022-11-13T18:32:09.677860814Z caller=multiline.go:132 component=file_pipeline component=stage type=multiline msg="pass entry" stream=4eb14ad2719a968a line=" cameraMac: '44D9E794DDD4'" level=debug ts=2022-11-13T18:32:09.677893351Z caller=multiline.go:163 component=file_pipeline component=stage type=multiline msg="processing line" line=" cameraMac: '44D9E794DDD4'" stream=4eb14ad2719a968a level=debug ts=2022-11-13T18:32:09.677942534Z caller=multiline.go:132 component=file_pipeline component=stage type=multiline msg="pass entry" stream=4eb14ad2719a968a line=} level=debug ts=2022-11-13T18:32:09.677967529Z caller=multiline.go:163 component=file_pipeline component=stage type=multiline msg="processing line" line=} stream=4eb14ad2719a968a level=debug ts=2022-11-13T18:32:11.678634155Z caller=multiline.go:158 component=file_pipeline component=stage type=multiline msg="flush multiline block due to 2s timeout" block=" datetime: '2022-11-13T17:23:04Z',\n ident: 'streamer',\n pid: 422,\n uptime: '143022,812',\n cameraMac: '44D9E794DDD4'\n}" level=debug ts=2022-11-13T18:32:11.67872899Z caller=regex.go:121 component=file_pipeline component=stage type=regex msg="regex did not match" input=" datetime: '2022-11-13T17:23:04Z',\n ident: 'streamer',\n pid: 422,\n uptime: '143022,812',\n cameraMac: '44D9E794DDD4'\n}" regex="^(?P<date>\\d{4}-\\d{2}-\\d{2}).(?P<time>\\d{2}:\\d{2}:\\d{2}.\\d+). - (?P<level>\\w+): (?P<message>.*)\\[(?P<appname>\\w+):(?P<sourcefile>[\\w\\.]+):(?P<codefunction>[\\w\\.]+):(?P<linenum>\\d+)\\]\\n\\{$\\n(^ (\\w+): (.*),?$\\n)+\\}" level=debug ts=2022-11-13T18:32:13.679526126Z caller=multiline.go:158 component=file_pipeline component=stage type=multiline msg="flush multiline block due to 2s timeout" block= level=debug ts=2022-11-13T18:32:13.679586555Z caller=multiline.go:203 component=file_pipeline component=stage type=multiline msg="nothing to flush" buffer_len=0 level=debug ts=2022-11-13T18:32:15.680530315Z caller=multiline.go:158 component=file_pipeline component=stage type=multiline msg="flush multiline block due to 2s timeout" block= level=debug ts=2022-11-13T18:32:15.680595235Z caller=multiline.go:203 component=file_pipeline component=stage type=multiline msg="nothing to flush" buffer_len=0 Attempt #5 #Well…… we’re getting somewhere, for sure! promtail’s now able to grab the data from the logline part of the message…. but, as you can see, The json part isn’t getting parsed properly…. promtail config.yaml #5 server: log_level: debug http_listen_port: 3101 client: url: http://lokihost:3100/loki/api/v1/push positions: filename: /run/promtail_positions.yaml scrape_configs: - job_name: protect pipeline_stages: - multiline: firstline: '^(\d{4}-\d{2}-\d{2}).(\d{2}:\d{2}:\d{2}.\d+). - (\w+): (.*)\[(\w+):([\w\.]+):([\w\.]+):(\d+)\](.*)?$' max_wait_time: 2s - replace: expression: (\n) replace: "" - regex: expression: '^(?P<date>\d{4}-\d{2}-\d{2}).(?P<time>\d{2}:\d{2}:\d{2}.\d+). - (?P<level>\w+): (?P<message>.*)\[(?P<appname>\w+):(?P<sourcefile>[\w\.]+):(?P<codefunction>[\w\.]+):(?P<linenum>\d+)\]' - json: expressions: datetime: datetime ident: ident pid: pid uptime: uptime cameraMac: cameraMac - labels: date: time: level: message: agent: appname: codefunction: datass: filename: linenum: - labels: level: static_configs: - targets: - localhost labels: job: protect # A `job` label is fairly standard in prometheus and useful for linking metrics and logs. host: protect role: cameras agent: promtail __path__: /cams/????????????.log #/volume1/.srv/unifi-protect/logs/cameras/????????????.log promtail log vomit #5 level=debug ts=2022-11-13T21:32:20.275907917Z caller=promtail.go:115 msg="Reloading configuration file" level=info ts=2022-11-13T21:32:20.277911786Z caller=promtail.go:123 msg="Reloading configuration file" md5sum=35dc37be88c6bb0aaa6d7adab1e6f164 level=warn ts=2022-11-13T21:32:20.2779513Z caller=config.go:70 msg="use of CLI client.* and config file Client block are both deprecated in favour of the config file Clients block and will be removed in a future release" level=debug ts=2022-11-13T21:32:20.279251315Z caller=manager.go:289 component=discovery msg="Starting provider" provider=static/0 subs=map[protect:{}] level=debug ts=2022-11-13T21:32:20.279572093Z caller=manager.go:323 component=discovery msg="Discoverer channel closed" provider=static/0 level=info ts=2022-11-13T21:32:20.281157366Z caller=server.go:323 http=[::]:3101 grpc=[::]:9095 msg="server listening on addresses" level=info ts=2022-11-13T21:32:20.281529213Z caller=main.go:171 msg="Starting Promtail" version="(version=HEAD-1b627d8, branch=HEAD, revision=1b627d880)" level=warn ts=2022-11-13T21:32:20.28163567Z caller=promtail.go:220 msg="enable watchConfig" level=debug ts=2022-11-13T21:32:25.279682464Z caller=filetargetmanager.go:292 msg="new target" labels="{__address__=\"localhost\"}" level=info ts=2022-11-13T21:32:25.279818013Z caller=filetargetmanager.go:352 msg="Adding target" key="/camz/????????????.log:{agent=\"promtail\", host=\"protect\", job=\"protect\", role=\"cameras\"}" level=info ts=2022-11-13T21:32:25.280017831Z caller=filetarget.go:282 msg="watching new directory" directory=/camz level=debug ts=2022-11-13T21:32:25.280102517Z caller=filetarget.go:332 msg="tailing new file" filename=/camz/44D9E794DDD4.log ts=2022-11-13T21:32:25.280276089Z caller=log.go:168 level=info msg="Seeked /camz/44D9E794DDD4.log - &{Offset:0 Whence:0}" level=info ts=2022-11-13T21:32:25.280336038Z caller=tailer.go:143 component=tailer msg="tail routine: started" path=/camz/44D9E794DDD4.log level=debug ts=2022-11-13T21:32:25.28045645Z caller=multiline.go:123 component=file_pipeline component=stage type=multiline msg="creating new stream" stream=4eb14ad2719a968a level=debug ts=2022-11-13T21:32:25.280495124Z caller=multiline.go:132 component=file_pipeline component=stage type=multiline msg="pass entry" stream=4eb14ad2719a968a line="2022-11-13T21:02:28.185Z - info: Forcibly set medium stream to 150Kbps for fast startup in minimum required bitrate [ubnt_encoder:outstream.cpp:SignalFeedbackMessages:309]" level=debug ts=2022-11-13T21:32:25.282006305Z caller=multiline.go:163 component=file_pipeline component=stage type=multiline msg="processing line" line="2022-11-13T21:02:28.185Z - info: Forcibly set medium stream to 150Kbps for fast startup in minimum required bitrate [ubnt_encoder:outstream.cpp:SignalFeedbackMessages:309]" stream=4eb14ad2719a968a level=debug ts=2022-11-13T21:32:25.282060888Z caller=multiline.go:177 component=file_pipeline component=stage type=multiline msg="flush multiline block because new start line" block= stream=4eb14ad2719a968a level=debug ts=2022-11-13T21:32:25.282088557Z caller=multiline.go:203 component=file_pipeline component=stage type=multiline msg="nothing to flush" buffer_len=0 level=debug ts=2022-11-13T21:32:25.282083654Z caller=multiline.go:132 component=file_pipeline component=stage type=multiline msg="pass entry" stream=4eb14ad2719a968a line={ level=debug ts=2022-11-13T21:32:25.282136334Z caller=multiline.go:163 component=file_pipeline component=stage type=multiline msg="processing line" line={ stream=4eb14ad2719a968a level=debug ts=2022-11-13T21:32:25.282171237Z caller=multiline.go:132 component=file_pipeline component=stage type=multiline msg="pass entry" stream=4eb14ad2719a968a line=" datetime: '2022-11-13T21:02:28Z'," level=debug ts=2022-11-13T21:32:25.282197552Z caller=multiline.go:132 component=file_pipeline component=stage type=multiline msg="pass entry" stream=4eb14ad2719a968a line=" ident: 'streamer'," level=debug ts=2022-11-13T21:32:25.282226677Z caller=multiline.go:163 component=file_pipeline component=stage type=multiline msg="processing line" line=" datetime: '2022-11-13T21:02:28Z'," stream=4eb14ad2719a968a level=debug ts=2022-11-13T21:32:25.282261855Z caller=multiline.go:163 component=file_pipeline component=stage type=multiline msg="processing line" line=" ident: 'streamer'," stream=4eb14ad2719a968a level=debug ts=2022-11-13T21:32:25.282289112Z caller=multiline.go:132 component=file_pipeline component=stage type=multiline msg="pass entry" stream=4eb14ad2719a968a line=" pid: 422," level=debug ts=2022-11-13T21:32:25.282320089Z caller=multiline.go:163 component=file_pipeline component=stage type=multiline msg="processing line" line=" pid: 422," stream=4eb14ad2719a968a level=debug ts=2022-11-13T21:32:25.282357409Z caller=multiline.go:132 component=file_pipeline component=stage type=multiline msg="pass entry" stream=4eb14ad2719a968a line=" uptime: '156186,779'," level=debug ts=2022-11-13T21:32:25.282383501Z caller=multiline.go:163 component=file_pipeline component=stage type=multiline msg="processing line" line=" uptime: '156186,779'," stream=4eb14ad2719a968a level=debug ts=2022-11-13T21:32:25.282414426Z caller=multiline.go:132 component=file_pipeline component=stage type=multiline msg="pass entry" stream=4eb14ad2719a968a line=" cameraMac: '44D9E794DDD4'" level=debug ts=2022-11-13T21:32:25.282442747Z caller=multiline.go:163 component=file_pipeline component=stage type=multiline msg="processing line" line=" cameraMac: '44D9E794DDD4'" stream=4eb14ad2719a968a level=debug ts=2022-11-13T21:32:25.28247609Z caller=multiline.go:132 component=file_pipeline component=stage type=multiline msg="pass entry" stream=4eb14ad2719a968a line=} level=debug ts=2022-11-13T21:32:25.282500484Z caller=multiline.go:163 component=file_pipeline component=stage type=multiline msg="processing line" line=} stream=4eb14ad2719a968a level=debug ts=2022-11-13T21:32:25.282533433Z caller=multiline.go:132 component=file_pipeline component=stage type=multiline msg="pass entry" stream=4eb14ad2719a968a line="2022-11-13T21:02:29.785Z - info: Forcibly set medium stream to 150Kbps for fast startup in minimum required bitrate [ubnt_encoder:outstream.cpp:SignalFeedbackMessages:309]" level=debug ts=2022-11-13T21:32:25.282573118Z caller=multiline.go:163 component=file_pipeline component=stage type=multiline msg="processing line" line="2022-11-13T21:02:29.785Z - info: Forcibly set medium stream to 150Kbps for fast startup in minimum required bitrate [ubnt_encoder:outstream.cpp:SignalFeedbackMessages:309]" stream=4eb14ad2719a968a level=debug ts=2022-11-13T21:32:25.282654307Z caller=multiline.go:177 component=file_pipeline component=stage type=multiline msg="flush multiline block because new start line" block="2022-11-13T21:02:28.185Z - info: Forcibly set medium stream to 150Kbps for fast startup in minimum required bitrate [ubnt_encoder:outstream.cpp:SignalFeedbackMessages:309]\n{\n datetime: '2022-11-13T21:02:28Z',\n ident: 'streamer',\n pid: 422,\n uptime: '156186,779',\n cameraMac: '44D9E794DDD4'\n}" stream=4eb14ad2719a968a level=debug ts=2022-11-13T21:32:25.2830914Z caller=multiline.go:132 component=file_pipeline component=stage type=multiline msg="pass entry" stream=4eb14ad2719a968a line={ level=debug ts=2022-11-13T21:32:25.283106108Z caller=replace.go:165 component=file_pipeline component=stage type=replace msg="extracted data debug in replace stage" extracteddata="map[agent:promtail filename:/camz/44D9E794DDD4.log host:protect job:protect role:cameras]" level=debug ts=2022-11-13T21:32:25.283132371Z caller=multiline.go:163 component=file_pipeline component=stage type=multiline msg="processing line" line={ stream=4eb14ad2719a968a level=debug ts=2022-11-13T21:32:25.283177989Z caller=multiline.go:132 component=file_pipeline component=stage type=multiline msg="pass entry" stream=4eb14ad2719a968a line=" datetime: '2022-11-13T21:02:29Z'," level=debug ts=2022-11-13T21:32:25.283206137Z caller=multiline.go:132 component=file_pipeline component=stage type=multiline msg="pass entry" stream=4eb14ad2719a968a line=" ident: 'streamer'," level=debug ts=2022-11-13T21:32:25.283217537Z caller=multiline.go:163 component=file_pipeline component=stage type=multiline msg="processing line" line=" datetime: '2022-11-13T21:02:29Z'," stream=4eb14ad2719a968a level=debug ts=2022-11-13T21:32:25.283248617Z caller=multiline.go:163 component=file_pipeline component=stage type=multiline msg="processing line" line=" ident: 'streamer'," stream=4eb14ad2719a968a level=debug ts=2022-11-13T21:32:25.283245309Z caller=regex.go:132 component=file_pipeline component=stage type=regex msg="extracted data debug in regex stage" extracteddata="map[agent:promtail appname:ubnt_encoder codefunction:SignalFeedbackMessages date:2022-11-13 filename:/camz/44D9E794DDD4.log host:protect job:protect level:info linenum:309 message:Forcibly set medium stream to 150Kbps for fast startup in minimum required bitrate role:cameras sourcefile:outstream.cpp time:21:02:28.185]" level=debug ts=2022-11-13T21:32:25.283275395Z caller=multiline.go:132 component=file_pipeline component=stage type=multiline msg="pass entry" stream=4eb14ad2719a968a line=" pid: 422," level=debug ts=2022-11-13T21:32:25.283326532Z caller=multiline.go:163 component=file_pipeline component=stage type=multiline msg="processing line" line=" pid: 422," stream=4eb14ad2719a968a level=debug ts=2022-11-13T21:32:25.283344309Z caller=multiline.go:132 component=file_pipeline component=stage type=multiline msg="pass entry" stream=4eb14ad2719a968a line=" uptime: '156188,407'," level=debug ts=2022-11-13T21:32:25.283377858Z caller=multiline.go:163 component=file_pipeline component=stage type=multiline msg="processing line" line=" uptime: '156188,407'," stream=4eb14ad2719a968a level=debug ts=2022-11-13T21:32:25.283378475Z caller=multiline.go:132 component=file_pipeline component=stage type=multiline msg="pass entry" stream=4eb14ad2719a968a line=" cameraMac: '44D9E794DDD4'" level=debug ts=2022-11-13T21:32:25.283445332Z caller=multiline.go:163 component=file_pipeline component=stage type=multiline msg="processing line" line=" cameraMac: '44D9E794DDD4'" stream=4eb14ad2719a968a level=debug ts=2022-11-13T21:32:25.283474629Z caller=multiline.go:132 component=file_pipeline component=stage type=multiline msg="pass entry" stream=4eb14ad2719a968a line=} level=debug ts=2022-11-13T21:32:25.28349887Z caller=multiline.go:163 component=file_pipeline component=stage type=multiline msg="processing line" line=} stream=4eb14ad2719a968a level=debug ts=2022-11-13T21:32:25.28350883Z caller=multiline.go:132 component=file_pipeline component=stage type=multiline msg="pass entry" stream=4eb14ad2719a968a line="2022-11-13T21:02:32.985Z - info: Persisted [ubnt_ctlserver:Persistence.cpp:persist:66]" level=debug ts=2022-11-13T21:32:25.283542293Z caller=multiline.go:132 component=file_pipeline component=stage type=multiline msg="pass entry" stream=4eb14ad2719a968a line={ level=debug ts=2022-11-13T21:32:25.28355419Z caller=multiline.go:163 component=file_pipeline component=stage type=multiline msg="processing line" line="2022-11-13T21:02:32.985Z - info: Persisted [ubnt_ctlserver:Persistence.cpp:persist:66]" stream=4eb14ad2719a968a level=debug ts=2022-11-13T21:32:25.283640179Z caller=multiline.go:177 component=file_pipeline component=stage type=multiline msg="flush multiline block because new start line" block="2022-11-13T21:02:29.785Z - info: Forcibly set medium stream to 150Kbps for fast startup in minimum required bitrate [ubnt_encoder:outstream.cpp:SignalFeedbackMessages:309]\n{\n datetime: '2022-11-13T21:02:29Z',\n ident: 'streamer',\n pid: 422,\n uptime: '156188,407',\n cameraMac: '44D9E794DDD4'\n}" stream=4eb14ad2719a968a level=debug ts=2022-11-13T21:32:25.283683704Z caller=multiline.go:163 component=file_pipeline component=stage type=multiline msg="processing line" line={ stream=4eb14ad2719a968a level=debug ts=2022-11-13T21:32:25.283711339Z caller=multiline.go:132 component=file_pipeline component=stage type=multiline msg="pass entry" stream=4eb14ad2719a968a line=" datetime: '2022-11-13T21:02:33Z'," level=debug ts=2022-11-13T21:32:25.283737945Z caller=multiline.go:163 component=file_pipeline component=stage type=multiline msg="processing line" line=" datetime: '2022-11-13T21:02:33Z'," stream=4eb14ad2719a968a level=debug ts=2022-11-13T21:32:25.283861133Z caller=json.go:145 component=file_pipeline component=stage type=json msg="failed to unmarshal log line" err="ReadMapCB: expect { or n, but found 2, error found in #1 byte of ...|2022-11-13T|..., bigger context ...|2022-11-13T21:02:28.185Z - info: Forcibly set mediu|..." level=debug ts=2022-11-13T21:32:25.284022465Z caller=multiline.go:132 component=file_pipeline component=stage type=multiline msg="pass entry" stream=4eb14ad2719a968a line=" ident: 'ctl'," level=debug ts=2022-11-13T21:32:25.284054317Z caller=multiline.go:163 component=file_pipeline component=stage type=multiline msg="processing line" line=" ident: 'ctl'," stream=4eb14ad2719a968a level=debug ts=2022-11-13T21:32:25.284089888Z caller=multiline.go:132 component=file_pipeline component=stage type=multiline msg="pass entry" stream=4eb14ad2719a968a line=" pid: 415," level=debug ts=2022-11-13T21:32:25.284120848Z caller=multiline.go:163 component=file_pipeline component=stage type=multiline msg="processing line" line=" pid: 415," stream=4eb14ad2719a968a level=debug ts=2022-11-13T21:32:25.284161837Z caller=multiline.go:132 component=file_pipeline component=stage type=multiline msg="pass entry" stream=4eb14ad2719a968a line=" uptime: '156191,638'," level=debug ts=2022-11-13T21:32:25.284189197Z caller=multiline.go:163 component=file_pipeline component=stage type=multiline msg="processing line" line=" uptime: '156191,638'," stream=4eb14ad2719a968a level=debug ts=2022-11-13T21:32:25.284193226Z caller=replace.go:165 component=file_pipeline component=stage type=replace msg="extracted data debug in replace stage" extracteddata="map[agent:promtail filename:/camz/44D9E794DDD4.log host:protect job:protect role:cameras]" level=debug ts=2022-11-13T21:32:25.2842277Z caller=multiline.go:132 component=file_pipeline component=stage type=multiline msg="pass entry" stream=4eb14ad2719a968a line=" cameraMac: '44D9E794DDD4'" level=debug ts=2022-11-13T21:32:25.284254357Z caller=multiline.go:163 component=file_pipeline component=stage type=multiline msg="processing line" line=" cameraMac: '44D9E794DDD4'" stream=4eb14ad2719a968a level=debug ts=2022-11-13T21:32:25.284291815Z caller=multiline.go:132 component=file_pipeline component=stage type=multiline msg="pass entry" stream=4eb14ad2719a968a line=} level=debug ts=2022-11-13T21:32:25.284316209Z caller=multiline.go:163 component=file_pipeline component=stage type=multiline msg="processing line" line=} stream=4eb14ad2719a968a level=debug ts=2022-11-13T21:32:25.284305632Z caller=regex.go:132 component=file_pipeline component=stage type=regex msg="extracted data debug in regex stage" extracteddata="map[agent:promtail appname:ubnt_encoder codefunction:SignalFeedbackMessages date:2022-11-13 filename:/camz/44D9E794DDD4.log host:protect job:protect level:info linenum:309 message:Forcibly set medium stream to 150Kbps for fast startup in minimum required bitrate role:cameras sourcefile:outstream.cpp time:21:02:29.785]" level=debug ts=2022-11-13T21:32:25.284361312Z caller=json.go:145 component=file_pipeline component=stage type=json msg="failed to unmarshal log line" err="ReadMapCB: expect { or n, but found 2, error found in #1 byte of ...|2022-11-13T|..., bigger context ...|2022-11-13T21:02:29.785Z - info: Forcibly set mediu|..." level=debug ts=2022-11-13T21:32:27.285429326Z caller=multiline.go:158 component=file_pipeline component=stage type=multiline msg="flush multiline block due to 2s timeout" block="2022-11-13T21:02:32.985Z - info: Persisted [ubnt_ctlserver:Persistence.cpp:persist:66]\n{\n datetime: '2022-11-13T21:02:33Z',\n ident: 'ctl',\n pid: 415,\n uptime: '156191,638',\n cameraMac: '44D9E794DDD4'\n}" level=debug ts=2022-11-13T21:32:27.286126408Z caller=replace.go:165 component=file_pipeline component=stage type=replace msg="extracted data debug in replace stage" extracteddata="map[agent:promtail filename:/camz/44D9E794DDD4.log host:protect job:protect role:cameras]" level=debug ts=2022-11-13T21:32:27.286251071Z caller=regex.go:132 component=file_pipeline component=stage type=regex msg="extracted data debug in regex stage" extracteddata="map[agent:promtail appname:ubnt_ctlserver codefunction:persist date:2022-11-13 filename:/camz/44D9E794DDD4.log host:protect job:protect level:info linenum:66 message:Persisted role:cameras sourcefile:Persistence.cpp time:21:02:32.985]" level=debug ts=2022-11-13T21:32:27.286306289Z caller=json.go:145 component=file_pipeline component=stage type=json msg="failed to unmarshal log line" err="ReadMapCB: expect { or n, but found 2, error found in #1 byte of ...|2022-11-13T|..., bigger context ...|2022-11-13T21:02:32.985Z - info: Persisted [ubnt_ct|..." level=debug ts=2022-11-13T21:32:29.286424511Z caller=multiline.go:158 component=file_pipeline component=stage type=multiline msg="flush multiline block due to 2s timeout" block= level=debug ts=2022-11-13T21:32:29.28647918Z caller=multiline.go:203 component=file_pipeline component=stage type=multiline msg="nothing to flush" buffer_len=0 okay… so ….. back to the drawing board once more into the breech… fixup the json #So we have the blob of log message metadata in a capture group! woot! So…….. now what? How do we get the data into a parsed set of KV pairs? The JSON problem now is twofold. The json stage is looking at the entire logline The json blob is not properly formatted to appease the json parser. The first part of the problem is easy enough. The grafana json stage docs2 pointed out that there’s a source key one may provide the json stage, to scope its parsing to just a facet of the complete message consumed. The second part, however, is jus a lil different. json parser says no parsing for you level=debug ts=2022-11-14T04:33:51.257411935Z caller=json.go:145 component=file_pipeline component=stage type=json msg="failed to unmarshal log line" err="ReadString: expects \" or n, but found d, error found in #4 byte of ...|{ datetime: '|..., bigger context ...|{ datetime: '2022-11-14T04:33:08Z', ident: 'ctl', p|..." What we're starting with { "datetime": '2022-11-14T04:33:03Z', "ident": 'streamer', "pid": 422, "uptime": '183222,061', "cameraMac": '44D9E794DDD4'} what the json parser expects { "datetime": "2022-11-14T04:33:03Z", ident: 'streamer', pid: 422, uptime: '183222,061', cameraMac: '44D9E794DDD4'}\ {"log":"log message","stream":"stderr","time":"2019-04-30T02:12:41.8443515Z"} OR….. to save on postage…. #Looking at this from a wider lens, what we’re really trying to do here is parse out the data…. Since we’re gonna have to perform a regex anyways… is it more efficient to just…. chop it up with regex once, rather than doing a few weird one-off regex substitutions and THEN parsing the result with a json parser? IDK, to be honest… spoze it depends on the performance of the regexes, but I’m not gonna run down that rabbit hole …… today. instead, I’mma jus try an use the replace stage3 and chop the string into named capture groups and extract the values into label KVs. fortunately, there’s a pretty straightforward example of this in the loki/promtail pipeline stage docs4 promtail config.yaml #5 server: log_level: debug http_listen_port: 3101 client: url: http://metrics.wolfspyre.io:3100/loki/api/v1/push positions: filename: /run/promtail_positions.yaml scrape_configs: - job_name: protect pipeline_stages: - multiline: firstline: '^(\d{4}-\d{2}-\d{2}).(\d{2}:\d{2}:\d{2}.\d+). - (\w+): (.*)\[(\w+):([\w\.]+):([\w\.]+):(\d+)\](.*)?$' max_wait_time: 2s - replace: expression: (\n) replace: "" - regex: expression: '^(?P<date>\d{4}-\d{2}-\d{2}).(?P<time>\d{2}:\d{2}:\d{2}.\d+). - (?P<level>\w+): (?P<message>.*)\[(?P<appname>\w+):(?P<sourcefile>[\w\.]+):(?P<codefunction>[\w\.]+):(?P<linenum>\d+)\](?P<datass>.*)?' - replace: expression: ".*datetime.\\s+'(?P<datetime>.*)',.*ident.\\s+'(?P<ident>.*)',.*pid.\\s+(?P<pid>\\d+),.*uptime.\\s+'(?P<uptime>.*)',.*cameraMac.\\s+'(?P<cameraMac>.+)'.*" source: "datass" replace: '{{ .Value }}' - replace: expression: (.*) source: "datass" replace: "" - labeldrop: - datass - labels: date: time: level: message: agent: appname: codefunction: datetime: ident: pid: uptime: cameraMac: linenum: static_configs: - targets: - localhost labels: job: protect # A `job` label is fairly standard in prometheus and useful for linking metrics and logs. host: protect role: cameras agent: promtail __path__: /volume1/.srv/unifi-protect/logs/cameras/????????????.log server: #log_level: debug http_listen_port: 3101 client: url: http://metrics.wolfspyre.io:3100/loki/api/v1/push positions: filename: /run/promtail_positions.yaml scrape_configs: - job_name: protect pipeline_stages: - multiline: firstline: '^(\d{4}-\d{2}-\d{2}).(\d{2}:\d{2}:\d{2}.\d+). - (\w+): (.*)\[(\w+):([\w\.]+):([\w\.]+):(\d+)\](.*)?$' max_wait_time: 2s # - replace: # expression: (\n) # replace: "" - regex: expression: '^(?P<date>\d{4}-\d{2}-\d{2}).(?P<time>\d{2}:\d{2}:\d{2}.\d+). - (?P<level>\w+): (?P<message>.*)\[(?P<appname>\w+):(?P<sourcefile>[\w\.]+):(?P<codefunction>[\w\.]+):(?P<linenum>\d+)\](?P<datass>.*)?' - match: pipeline_name: 'cameralog' selector: '{agent="promtail"} |~ ".*cameraMac.*"' stages: - replace: #{ datetime: '2022-11-15T01:51:33Z', ident: 'ctl', pid: 415, uptime: '259932,367', cameraMac: '44D9E794DDD4'} expression: ".*datetime.\\s+'(?P<datetime>.*)',.*ident.\\s+'(?P<ident>.*)',.*pid.\\s+(?P<pid>\\d+),.*uptime.\\s+'(?P<uptime>.*)',.*cameraMac.\\s+'(?P<cameraMac>.+)'.*" source: "datass" replace: "" #{{ .Value }}' - labels: datetime: ident: pid: uptime: cameraMac: #- replace: # expression: (.*) # source: "datass" # replace: "" - labeldrop: - datass - labels: date: time: level: message: agent: appname: codefunction: # datetime: # ident: # pid: # uptime: # cameraMac: # filename: linenum: static_configs: - targets: - localhost labels: job: protect # A `job` label is fairly standard in prometheus and useful for linking metrics and logs. host: protect role: cameras agent: promtail __path__: /volume1/.srv/unifi-protect/logs/cameras/????????????.log It’s worth noting that unless you constrain the filename portion of the logfile to 12 characters, any tool looking for these logfiles matching *.log will consume the logfile as new everytime it’s rotated. This is because Ubiquiti decided to use the strategy: Lets just append a number to the end of the filename-pre-.log-suffix when performing rotation. It’ll be fine if we just rotate AF09F9A0D05C2.log to AF09F9A0D05C3.log… and AF09F9A0D05C1.log to AF09F9A0D05C2.log and then finally rotate AF09F9A0D05C.log to AF09F9A0D05C1.log. What could possibly go wrong? expression: “^(?P\S+) (?P\S+) (\S+) \[(?P[\w:/]+\s[+\-]\d{4})\] "(?P\S+)\s?(?P\S+)?\s?(?P\S+)?" (?P\d{3}|-) (?P\d+|-)\s?"?(?P[^"])"?\s?"?(?P[^"])?"?$” replace: ‘{{ .Value | ToUpper }}’ ↩︎ https://grafana.com/docs/loki/latest/clients/promtail/stages/json/ ↩︎ https://grafana.com/docs/loki/latest/clients/promtail/stages/replace/ ↩︎ https://grafana.com/docs/loki/latest/clients/promtail/stages/replace/#replace-with-named-captured-group ↩︎