Skip to content

Print the messages of a forked worker process once - #886

Merged
caglarpir merged 18 commits into
mapillary:mainfrom
caglarpir:log-worker-warnings-once
Oct 22, 2026
Merged

caglarpir merged 18 commits into
mapillary:mainfrom
caglarpir:log-worker-warnings-once

Conversation

@caglarpir

Copy link
Copy Markdown
Contributor

Stacked on #885; review the last commit.

Problem

Where the process pool forks its workers (Linux before Python 3.14), every warning a worker logs while extracting metadata is printed twice. utils.configure_logger(), the pool's initializer, adds a handler to the logger, which already has the one the worker inherited from its parent.

Fix

configure_logger() adds no handler to a logger that already has one, and still sets its level.

Verification

  • A script that forces the fork start method prints a worker's warning twice on main and once with the fix. With spawn and forkserver it prints once either way.
  • New unit tests, including one in a forked subprocess (skipped where fork is unavailable). Unit and integration tests, doctests, mypy --python-version 3.9, ruff check, ruff format --check and usort diff are clean.

The README lists NMEA among the sources that geotag videos, but no video
was read from an NMEA file: process and video_process gave the video no
description at all, and exited 0, so it was silently left out. Sampling
fell back to the GPS in the video, which a video recorded with an
external logger does not have.

Read the NMEA file into a track and place it on the video exactly as a
GPX track is: synced by the GPS clock of the video, or by
--video_start_time, or assumed to start with the video, with the
interpolation options, the coverage checks and the clipping of process.
GPXVideoExtractor now reads its file through _parse_tracks(), which
NMEAVideoExtractor overrides, and names the format of the file in its
messages. A file that is not valid NMEA is reported as an invalid GPX
file is. Interval sampling checks an NMEA track started with the video
by --interpolation_use_gpx_start_time as it checks a GPX track.

On an action camera video with a GPX and the same track as NMEA, process gives
the same track, and video_process samples the same frames at the same
positions.
Images geotagged from an NMEA file failed with a traceback when the
file had an RMC sentence without a date, such as the last one of a log
cut short (TypeError), or GGA sentences and no RMC sentence at all
(UnboundLocalError), and a video was failed as if the file were not
NMEA. A void RMC sentence, which receivers log before they acquire a
fix, gave the date of their unset clock, and a GGA sentence without a
fix added a point at 0, 0. Only $GP sentences were read, so a log of a
receiver of several systems, which writes $GN sentences, gave no points
at all.

Skip RMC sentences that are void or have no date or time, and GGA
sentences without a time or a fix, and read the sentences of any
talker, keeping the first fix of each time, so that a receiver that logs
a fix from two talkers does not give two points at the same time. GGA
sentences without the date of any RMC sentence give no points, with a
warning. The points read from valid files are the same.
process searches a directory for the images and videos it can process,
and skips the other files. It skipped a file named explicitly the same
way, without a word: `process VID.insv` processed 0 files and exited 0,
with nothing on stderr, so a user could not tell why the video was not
there.

Warn of such a file. It is still skipped, and the run does not fail:
callers that pass the files a user selected rely on that, and find the
skipped files in the process report (--process_report_path). A zip file
is not warned of, as process_and_upload uploads it.
video_process samples each video into a folder of its own in the import
path, and then processes the import path with the same options. With
--skip_subfolders, the processing step skipped those folders: it found
no samples, wrote an empty description file and exited 0, and
video_process_and_upload uploaded nothing.

Process, and upload, the sample folders of the videos as import paths
of their own. --skip_subfolders still keeps the other subfolders of the
import path out, and the description file is written to the import path,
as without the option.
For a video without a GPS clock, process places a GPX track at the start
of the video: it assumes the track starts with it, or
--interpolation_use_gpx_start_time says so. --interpolation_offset_time
then moves the track back, before the start of the video. The upload
drops the points before video time 0 without putting one at 0, so the
first frames had no position: with an offset of 2.5 seconds and a point
every second, the first half second of the video.

Clip such a track at the start of the video, with a point interpolated
at video time 0, as a track that a clock places is clipped at both ends.
Its end is left as it is, as the track of a timelapse without a GPS
clock runs on past the end of the video. Sampling, which reads its track
only within the video, is unchanged.

The warning of a track that runs on for more than twice the video said,
with an offset too, that the video was assumed to start with the track.
With an offset, it now says where along the track the offset places the
start of the video, and lists checking the offset next to trimming the
GPX and video_process --video_start_time. Without one, it is unchanged.
A GPX file can hold several trips, with the GPS logger switched off in
between. A video or an image recorded during such a gap was given a
position interpolated between the last point before it and the first
after it, which can be hours and kilometres apart. A dashcam clip placed
by --video_start_time in a 14-hour gap of a six-day GPX was sampled and
geotagged as if the track covered it: the coverage checks compared the
video or image only with the ends of the track.

Consecutive points more than an hour apart now leave a gap that counts
as outside the track, like the time before its start or after its end.
ExifTool's geotagger likewise treats a time in a gap of more than
GeoMaxIntSecs (30 minutes by default) as outside the track.

- An image (or a sampled frame geotagged from the GPX) in a gap fails
  with MapillaryOutsideGPXTrackError, so a later geotag source can take
  it, as it does an image past either end of the track.
- A video that falls in a gap misses the track, and raises or warns as
  one that misses it before or after does. One that falls in a gap only
  in part warns that part of it is outside the track.

Both errors name the gap: its length, and the time and position of the
last point before it and the first after it. For a timelapse the gap is
measured in GPS time, as the other checks are. The video's own GPS
track, which the legacy video sources geotag images from, is not
checked.

The limit can be raised with MAPILLARY_TOOLS_MAX_GPX_GAP_SECONDS (3600
by default), like the other limits in constants.py.
--filetypes gopro, blackvue or camm limits process to the videos of
those types. The type of a video is known only once it is read, so the
native reader tried only the readers of those types, and reported a
video none of them recognized as having no GPS. ExifTool, which the
default sources fall back to, then read it anyway: a GoPro video with
--filetypes blackvue was processed as a GoPro video and exited 0, a
BlackVue video with --filetypes gopro as a generic video, and in a
folder of mixed cameras, the videos of the other cameras were reported
as errors.

Leave a video out of the results once a source finds out that it is of
none of the types --filetypes asks for, as the files of other kinds are:
a source read it as another type, or the native reader, given all of
them, recognized none of them in it. No later source reads it. A video
read as a generic video is of a type that is not known, and is kept, so
a GPX or ExifTool still geotags a video of a type asked for. A source
limited further by its own filetypes leaves the video to the next one,
as before. A video that the native reader recognizes, but whose GPS is
empty or noisy, is reported as before, while one that no source can read
is left out: it may not be of any of the types asked for.
ExifToolReadVideo read the QuickTime and Insta360 GPS tags of a video as
one flat list per tag, and zipped them into points, padding a short list
at its end. A record without a tag shifted every later value of that tag
onto the point before it. A BlackVue writes no GPSTrack while it stands
still, nor a GPSAltitude in its last record, so the headings and
altitudes of the points after them were those of other points.

A BlackVue video also holds a copy of its GPS log in the low resolution
recording embedded in it, which ExifTool lists as well. The shifted
headings kept the two copies of a point from matching, so the track had
every point twice.

Group the tags by record instead: a record starts at its SampleTime, at
its GPSDateTime, which ExifTool lists first in a record, or at a tag
that the record so far already has. Each point takes its fields from its
own record, and the copies match and merge.
The outlier filter splits a GoPro track wherever two consecutive points
are more than 30 m apart, merges the pieces that can be reached from
one another at no more than the usual ground speed, and keeps the
largest group. A single sample far off the track splits it in two: a
Hero 7 recorded one at (0.000001, 2.36) in the middle of a walk. The
pieces on either side of it are 1.2 m apart, but also only a third of a
second, over which GPS jitter alone reads 3.6 m/s, faster than the
2.7 m/s the walk's ground speeds allow. They were not merged, and the
first 221 seconds of the 531-second video were dropped: video_process
sampled 132 frames at 5 m instead of 223, all from after the sample.

Also merge pieces whose ends are no farther apart than the points
within a piece, whatever the time between them. Of 74 sample videos
from GoPro cameras, only that one changes: it keeps all of its track
but the sample off it. Tracks rejected as noisy stay rejected.
Dashcams that write their GPS as LIGOGPSINFO, such as the GKU D900 and
the Abask A8 (which encrypts it), failed to geotag with "No GPS data
found from the video", although ExifTool decodes their GPS into the LIGO
group. ExifToolReadVideo did not read that group.

Read it, after every group that it read before, so that no video
geotagged today changes. The LIGO GPS times are in UTC. The clocks of
these cameras need not be: two sample clips show the position of their
GPS record at UTC time T on screen at camera time T - 8 h and T - 5 h,
and the daylight in them is that of the GPS times.
… it to 1970

Some FLIR thermal cameras write 0001:01:01 00:00:00 to DateTimeOriginal,
CreateDate and ModifyDate when they have no date. That time has no Unix
time, and geo.as_unix_time() replaced its year with 1970, so the image
was geotagged with a capture time of 1970-01-01 00:00:00 and uploaded
as ready.

The image extractors now convert the capture time themselves, and report
an image whose capture time has no Unix time as a geotagging error,
"Unable to extract timestamp from the image", as they do an image with
no capture time.
Some FLIR thermal cameras write the GPS IFD with bad offsets. ExifTool
warns "Bad offset for GPS GPSLatitude" and reports no position, but
exif_read.gps_to_decimal() converted whatever the offsets pointed at:
0 degrees, 0.25 minutes and 76.2 seconds, for both the latitude and the
longitude. The image was geotagged at (0.0253154, 0.0253154) and
uploaded as ready.

gps_to_decimal() now returns None for minutes or seconds outside
[0, 60], which no coordinate has, so such an image is reported as a
geotagging error, "Unable to extract GPS Longitude or GPS Latitude from
the image". 60 itself is accepted, as a writer may round 59.996 up.

Empty or missing latitude and longitude refs are still read as north
and east: some cameras write them so, with valid coordinates.
Some dashcams record with non-square pixels: the AZDome GS63H writes
2880x2160 frames with a sample aspect ratio of 4:3, displayed at 16:9.
Sampled frames kept the stored size, with the pixel shape left only as a
JPEG density hint that most viewers ignore, so every image of such a
video came out squeezed to 4:3.

When ffprobe reports non-square pixels for the sampled stream, scale its
frames to square pixels, stretching one side to the displayed size
(3840x2160 here) rather than shrinking the other. Frames of streams with
square pixels, or a pixel shape ffprobe does not report, are extracted
with the same ffmpeg command as before.
…sync

Interval sampling stamps the frames of a video by its own GPS clock,
which it reads from the telemetry. GPS rejected as noise gives it no
telemetry, so the frames of such a video were stamped from its creation
time at --video_duration_ratio. GPX sync, in distance sampling and
process, still reads the clock of that GPS, and places the GPX by it. The
geotagging stage then put the interval samples elsewhere along the GPX:
a 12x GoPro MAX 2 timelapse sampled every 0.25 seconds with
--interpolation_use_gpx_start_time had its 5 samples placed within the
first second of its 12-second track, and without the option, its
creation time placed all of them outside the track.

Stamp the interval samples of such a video by the clock that GPX sync
places the track of its first GPX source by: the GPS clock of the video,
or with --interpolation_use_gpx_start_time, the start of the track at
the pace of that clock. A placeholder clock, which GPX sync ignores, is
ignored here too, and a video without a GPX source is stamped as before.
GPXVideoExtractor._sync_clock() now makes that choice for both.
A video with a GPS clock of its own is paced by it, and distance
sampling stamps its frames with its GPS timestamps. Sampling such a video
by distance ignored --video_duration_ratio and --video_start_time
without a word, so a mistyped or unneeded option went unnoticed. Only
interval sampling said that it ignored the ratio, and nothing said that
the start time was ignored, also when the clock synced a GPX.

Warn of both, with the wording interval sampling uses for the ratio:
in distance sampling of a video by its own GPS, and when the video's GPS
clock syncs a GPX track. The start time is still used where it is: to
place a GPX on a video without a GPS clock, and to stamp the frames that
no GPS timestamp stamps. Interval sampling stamps the frames from it, so
it does not warn of it.
Sampling a video without a GPS clock, which a GPX track is assumed to
start with, refuses a track that runs on for longer than the whole
video, as the video could start anywhere along it. The error suggested
--interpolation_use_gpx_start_time if the track was started with the
video. That option starts the track with the video too, and refuses the
same track for the same reason, so following the advice led to another
error.

Give the advice that the option's own refusal gives: --video_duration_ratio
for a timelapse, and for a GPS logger left running, --video_start_time
with the start of the track, ready to paste. A track of a day or more
covers more than the video, so only the time the video started is asked
for.
…on_use_gpx_start_time

With --interpolation_use_gpx_start_time, distance sampling started the
GPX track at video time 0, and the geotagging stage of video_process
starts it at the first sample. The sampler reads frame times as
composition times, without the edit list, so B-frames put the first
frame of a video after time 0: 40 ms into a Sony FDR-X3000 video. Every
frame was picked by its position along the track, and placed 40 ms
earlier along it, so each description disagreed with the time and
position written into its frame.

When distance sampling, start the track at the composition time of the
first frame, where the geotagging stage puts it, for a video without GPS
and for one whose GPS clock paces the track. Interval sampling, which
ffmpeg cuts from time 0, still stamps its samples from the start of the
track, and process, which uploads the track with the video, still starts
it at time 0.
Every warning that a worker process logged while extracting metadata
printed twice where the process pool forks its workers, as on Linux
before Python 3.14: configure_logger(), the pool's initializer, added a
handler to the logger, which already had the one that the worker
inherited from its parent.

configure_logger() now adds no handler to a logger that has one, and
still sets its level.
@caglarpir
caglarpir force-pushed the log-worker-warnings-once branch from ffdffae to e538ba3 Compare October 22, 2026 20:18
@caglarpir
caglarpir merged commit 9507d93 into mapillary:main Oct 22, 2026
16 checks passed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant