09/09 19:04:39 Info: Starting Roon v2.0 (build 1303) production on macosx
09/09 19:04:39 Info: Local time is 9/9/2023 7:04:39 PM, UTC time is 9/10/2023 12:04:39 AM
09/09 19:04:39 Trace: [roondns] loaded 25 last-known-good entries
09/09 19:04:39 Debug: Attempting to load library: /System/Library/Frameworks/Foundation.framework/Foundation
09/09 19:04:39 Info: Library[/System/Library/Frameworks/Foundation.framework/Foundation] Loaded success => True
09/09 19:04:39 Debug: Attempting to load library: /System/Library/Frameworks/AppKit.framework/AppKit
09/09 19:04:39 Info: Library[/System/Library/Frameworks/AppKit.framework/AppKit] Loaded success => True
09/09 19:04:39 Debug: Attempting to load framework: /System/Library/Frameworks/Cocoa.framework
09/09 19:04:39 Info: Framework[/System/Library/Frameworks/Cocoa.framework] Loaded success => True
09/09 19:04:39 Debug: Attempting to load framework: /System/Library/Frameworks/OpenGL.framework
09/09 19:04:39 Info: Framework[/System/Library/Frameworks/OpenGL.framework] Loaded success => True
09/09 19:04:39 Trace: Switching display link to display 189000129
09/09 19:04:39 Trace: Checking if we are already running
09/09 19:04:39 Warn: get lock file path: /tmp/.rnsem502-roon
09/09 19:04:39 Info: GetLockFile, fd: 333
09/09 19:04:39 Warn: GetLockFile, res: 0
09/09 19:04:39 Trace: Nope, we are the only one running
09/09 19:04:39 Info: Is 64 bit? True
09/09 19:04:39 Info: Loading broo project: ui.broox
09/09 19:04:39 Debug: OpenGL Version: 4.1 INTEL-18.8.6
09/09 19:04:39 Debug: OpenGL Vendor: Intel Inc.
09/09 19:04:39 Debug: OpenGL Renderer: Intel Iris OpenGL Engine
09/09 19:04:39 Debug: OpenGL Shader Language: 4.10
09/09 19:04:39 Debug: OpenGL extension count: 45
09/09 19:04:39 Debug: OpenGL extension 0: GL_ARB_blend_func_extended
09/09 19:04:39 Debug: OpenGL extension 1: GL_ARB_draw_buffers_blend
09/09 19:04:39 Debug: OpenGL extension 2: GL_ARB_draw_indirect
09/09 19:04:39 Debug: OpenGL extension 3: GL_ARB_ES2_compatibility
09/09 19:04:39 Debug: OpenGL extension 4: GL_ARB_explicit_attrib_location
09/09 19:04:39 Debug: OpenGL extension 5: GL_ARB_gpu_shader_fp64
09/09 19:04:39 Debug: OpenGL extension 6: GL_ARB_gpu_shader5
09/09 19:04:39 Debug: OpenGL extension 7: GL_ARB_instanced_arrays
09/09 19:04:39 Debug: OpenGL extension 8: GL_ARB_internalformat_query
09/09 19:04:39 Debug: OpenGL extension 9: GL_ARB_occlusion_query2
09/09 19:04:39 Debug: OpenGL extension 10: GL_ARB_sample_shading
09/09 19:04:39 Debug: OpenGL extension 11: GL_ARB_sampler_objects
09/09 19:04:39 Debug: OpenGL extension 12: GL_ARB_separate_shader_objects
09/09 19:04:39 Debug: OpenGL extension 13: GL_ARB_shader_bit_encoding
09/09 19:04:39 Debug: OpenGL extension 14: GL_ARB_shader_subroutine
09/09 19:04:39 Debug: OpenGL extension 15: GL_ARB_shading_language_include
09/09 19:04:39 Debug: OpenGL extension 16: GL_ARB_tessellation_shader
09/09 19:04:39 Debug: OpenGL extension 17: GL_ARB_texture_buffer_object_rgb32
09/09 19:04:39 Debug: OpenGL extension 18: GL_ARB_texture_cube_map_array
09/09 19:04:39 Debug: OpenGL extension 19: GL_ARB_texture_gather
09/09 19:04:39 Debug: OpenGL extension 20: GL_ARB_texture_query_lod
09/09 19:04:39 Debug: OpenGL extension 21: GL_ARB_texture_rgb10_a2ui
09/09 19:04:39 Debug: OpenGL extension 22: GL_ARB_texture_storage
09/09 19:04:39 Debug: OpenGL extension 23: GL_ARB_texture_swizzle
09/09 19:04:39 Debug: OpenGL extension 24: GL_ARB_timer_query
09/09 19:04:39 Debug: OpenGL extension 25: GL_ARB_transform_feedback2
09/09 19:04:39 Debug: OpenGL extension 26: GL_ARB_transform_feedback3
09/09 19:04:39 Debug: OpenGL extension 27: GL_ARB_vertex_attrib_64bit
09/09 19:04:39 Debug: OpenGL extension 28: GL_ARB_vertex_type_2_10_10_10_rev
09/09 19:04:39 Debug: OpenGL extension 29: GL_ARB_viewport_array
09/09 19:04:39 Debug: OpenGL extension 30: GL_EXT_debug_label
09/09 19:04:39 Debug: OpenGL extension 31: GL_EXT_debug_marker
09/09 19:04:39 Debug: OpenGL extension 32: GL_EXT_framebuffer_multisample_blit_scaled
09/09 19:04:39 Debug: OpenGL extension 33: GL_EXT_texture_compression_s3tc
09/09 19:04:39 Debug: OpenGL extension 34: GL_EXT_texture_filter_anisotropic
09/09 19:04:39 Debug: OpenGL extension 35: GL_EXT_texture_sRGB_decode
09/09 19:04:39 Debug: OpenGL extension 36: GL_APPLE_client_storage
09/09 19:04:39 Debug: OpenGL extension 37: GL_APPLE_container_object_shareable
09/09 19:04:39 Debug: OpenGL extension 38: GL_APPLE_flush_render
09/09 19:04:39 Debug: OpenGL extension 39: GL_APPLE_object_purgeable
09/09 19:04:39 Debug: OpenGL extension 40: GL_APPLE_rgb_422
09/09 19:04:39 Debug: OpenGL extension 41: GL_APPLE_row_bytes
09/09 19:04:39 Debug: OpenGL extension 42: GL_APPLE_texture_range
09/09 19:04:39 Debug: OpenGL extension 43: GL_ATI_texture_mirror_once
09/09 19:04:39 Debug: OpenGL extension 44: GL_NV_texture_barrier
09/09 19:04:39 Debug: OpenGL maximum texture size: 16384
09/09 19:04:39 Debug: OpenGL maximum array texture layers: 2048
09/09 19:04:39 Debug: Framebuffer info : R8G8B8A8, color encoding: 0x2601, depth: 24, stencil: 0
09/09 19:04:39 Debug: Vertex highp int: range (-2^31 to 2^30), precision: 0 bits
09/09 19:04:39 Debug: Vertex mediump int: range (-2^31 to 2^30), precision: 0 bits
09/09 19:04:39 Debug: Vertex lowp int: range (-2^31 to 2^30), precision: 0 bits
09/09 19:04:39 Debug: Vertex highp float: range (-2^127 to 2^127), precision: 23 bits
09/09 19:04:39 Debug: Vertex mediump float: range (-2^127 to 2^127), precision: 23 bits
09/09 19:04:39 Debug: Vertex lowp float: range (-2^127 to 2^127), precision: 23 bits
09/09 19:04:39 Debug: Fragment highp int: range (-2^31 to 2^30), precision: 0 bits
09/09 19:04:39 Debug: Fragment mediump int: range (-2^31 to 2^30), precision: 0 bits
09/09 19:04:39 Debug: Fragment lowp int: range (-2^31 to 2^30), precision: 0 bits
09/09 19:04:39 Debug: Fragment highp float: range (-2^127 to 2^127), precision: 23 bits
09/09 19:04:39 Debug: Fragment mediump float: range (-2^127 to 2^127), precision: 23 bits
09/09 19:04:39 Debug: Fragment lowp float: range (-2^127 to 2^127), precision: 23 bits
09/09 19:04:39 Trace: [realtime] fetching time from NTP server
09/09 19:04:39 Debug: Maximum parallel texture loading jobs: 3
09/09 19:04:39 Trace: [ipaddresses] enumerating addresses
09/09 19:04:39 Debug: Maximum OpenGl texture size is 16384
09/09 19:04:39 Trace: [ipaddresses] FOUND lo0 127.0.0.1
09/09 19:04:39 Trace: [ipaddresses] SKIPPED gif0: no ipv4
09/09 19:04:39 Trace: [ipaddresses] SKIPPED stf0: no ipv4
09/09 19:04:39 Trace: [realtime] Got time from NTP: 9/10/2023 12:04:39 AM UTC (3903293079568ms)
09/09 19:04:39 Trace: [ipaddresses] SKIPPED en0: no ipv4
09/09 19:04:39 Trace: [ipaddresses] FOUND en1 192.168.0.174
09/09 19:04:39 Trace: [ipaddresses] SKIPPED en2: no ipv4
09/09 19:04:39 Trace: [ipaddresses] SKIPPED en3: no ipv4
09/09 19:04:39 Trace: [ipaddresses] SKIPPED bridge0: no ipv4
09/09 19:04:39 Trace: [ipaddresses] SKIPPED p2p0: no ipv4
09/09 19:04:39 Trace: [ipaddresses] SKIPPED awdl0: no ipv4
09/09 19:04:39 Trace: [ipaddresses] SKIPPED llw0: no ipv4
09/09 19:04:39 Trace: [ipaddresses] SKIPPED utun0: no ipv4
09/09 19:04:39 Trace: [ipaddresses] SKIPPED utun1: no ipv4
09/09 19:04:39 Trace: [ipaddresses] SKIPPED utun2: no ipv4
09/09 19:04:39 Trace: [realtime] Updated clock skew to 00:00:00.0069030 (6.903ms)
09/09 19:04:39 Debug: using FreeType v2.10.1
09/09 19:04:39 Trace: [broo/imagecache] loaded 0 cache entries from /Users/Mike/Library/Roon/Cache/brooimages_1/index.db, current: 512mb / 0mb
09/09 19:04:39 Warn: [orbit] init failed due to ArgumentOutOfRange_IndexCountBuffer Arg_ParamName_Name, bytes, reiniting
09/09 19:04:39 Trace: [brooengine] Loaded atlas list. 0ms
09/09 19:04:39 Trace: [brooengine] Window is running in scale 2
09/09 19:04:39 Trace: [brooengine] Using atlas scale 2
09/09 19:04:39 Debug: render area size initial value: 699x610
09/09 19:04:39 Info: Loaded broo project: ui.broox, atlas: ui
09/09 19:04:39 Info: Kicking off event loop
09/09 19:04:39 Info: Kicking off event loop
09/09 19:04:39 Info: [broker] starting baa7f176-8564-4100-8c66-f70177498342
09/09 19:04:39 Debug: ui running on thread 1
09/09 19:04:39 Info: Kicking off main
09/09 19:04:39 Info: Creating root
09/09 19:04:39 Trace: [httpcache] loaded 2 cache entries from /Users/Mike/Library/Roon/Cache/httpcache_2.db, current: 0mb / 128mb
09/09 19:04:39 Debug: [brooengine Loaded atlas texture ui_atlas@2x-1.png in 336ms
09/09 19:04:39 Trace: [brooengine] Loaded atlas. 349ms (336ms across all threads)
09/09 19:04:40 Info: [broker/locations] adding storage location: Internet:Name=Internet Media:Id=e268f098-04c4-4e65-af3f-38ba3c3fcecb
09/09 19:04:40 Info: [broker/locations] media availability: Internet:Name=Internet Media:Id=e268f098-04c4-4e65-af3f-38ba3c3fcecb is online
09/09 19:04:40 Info: [broker/locations] adding storage location: MetadataService:Name=Metadata Service:Id=13769258-b70b-4243-b1d6-bd46e8257ba8
09/09 19:04:40 Info: [broker/locations] media availability: MetadataService:Name=Metadata Service:Id=13769258-b70b-4243-b1d6-bd46e8257ba8 is online
09/09 19:04:40 Info: [broker/locations] adding storage location: Offline:Name=Offline:Id=f1e4b43f-f643-47ba-b875-fd93b32a6006
09/09 19:04:40 Debug: [broker/locations/migration] start, propname: loc_3ba5487c67f546c0bf0ad053d37c38c1
09/09 19:04:40 Debug: [broker/locations] Migrating UUID based storage location, id: loc_3ba5487c67f546c0bf0ad053d37c38c1, version: 2
09/09 19:04:40 Debug: [broker/locations/migration] start, propname: loc_29bdcae6b5fdd66627bfa1f6afceabac
09/09 19:04:40 Debug: [broker/locations] Migrating UUID based storage location, id: loc_29bdcae6b5fdd66627bfa1f6afceabac, version: 2
09/09 19:04:40 Debug: [broker/locations/migration] start, propname: loc_14fc4112682d42a59fe7f5cc6adca73c
09/09 19:04:40 Debug: [broker/locations] Migrating UUID based storage location, id: loc_14fc4112682d42a59fe7f5cc6adca73c, version: 2
09/09 19:04:40 Trace: [storage] [directory] directorystorage init, location(/Users/Mike/Music, dirwatcher is available: True)
09/09 19:04:40 Trace: [storage] [directory] init just before reorg delete thread, path: /Users/Mike/Music
09/09 19:04:40 Info: [broker/locations] storage location backend created and attached (DefaultMusicFolder:Name=Music Folder:Id=29bdcae6-b5fd-d666-27bf-a1f6afceabac)
09/09 19:04:40 Trace: [storage] [directory] temp directory cleared, path: /Users/Mike/Music/.tmp
09/09 19:04:40 Info: [broker/locations] adding storage location: DefaultMusicFolder:Name=Music Folder:Id=29bdcae6-b5fd-d666-27bf-a1f6afceabac
09/09 19:04:40 Info: [broker/locations] media availability: DefaultMusicFolder:Name=Music Folder:Id=29bdcae6-b5fd-d666-27bf-a1f6afceabac is online
09/09 19:04:40 Info: [broker/locations/directorystoragelocation] initializing FileBrowser.Entry: Untitled, AppleAPFSMedia : /Users/Mike, drive availability is: False
09/09 19:04:40 Info: [broker/locations/directorystoragelocation] drive is not available so disposing resources (if they exist): FileBrowser.Entry: Untitled, AppleAPFSMedia : /Users/Mike
09/09 19:04:40 Info: [broker/locations] storage location backend (Folder:Name=:Location=FileBrowser.Entry: Untitled, AppleAPFSMedia : /Users/Mike:Id=3ba5487c-67f5-46c0-bf0a-d053d37c38c1) offline reason changed to: DriveNotReady
09/09 19:04:40 Info: [broker/locations/directorystoragelocation] we'd like to keep this volume mounted: mounted:/
09/09 19:04:40 Info: [broker/locations] created enabled location, FileBrowser.Entry: Untitled, AppleAPFSMedia : /Users/Mike
09/09 19:04:40 Info: [broker/locations] adding storage location: Folder:Name=:Location=FileBrowser.Entry: Untitled, AppleAPFSMedia : /Users/Mike:Id=3ba5487c-67f5-46c0-bf0a-d053d37c38c1
09/09 19:04:40 Info: [broker/locations/directorystoragelocation] initializing FileBrowser.Entry: Untitled, AppleAPFSMedia : /Users/Mike/Music/Music/Music, drive availability is: False
09/09 19:04:40 Info: [broker/locations/directorystoragelocation] drive is not available so disposing resources (if they exist): FileBrowser.Entry: Untitled, AppleAPFSMedia : /Users/Mike/Music/Music/Music
09/09 19:04:40 Info: [broker/locations] storage location backend (Folder:Name=:Location=FileBrowser.Entry: Untitled, AppleAPFSMedia : /Users/Mike/Music/Music/Music:Id=14fc4112-682d-42a5-9fe7-f5cc6adca73c) offline reason changed to: DriveNotReady
09/09 19:04:40 Info: [broker/locations/directorystoragelocation] we'd like to keep this volume mounted: mounted:/
09/09 19:04:40 Info: [broker/locations] created enabled location, FileBrowser.Entry: Untitled, AppleAPFSMedia : /Users/Mike/Music/Music/Music
09/09 19:04:40 Info: [broker/locations] adding storage location: Folder:Name=:Location=FileBrowser.Entry: Untitled, AppleAPFSMedia : /Users/Mike/Music/Music/Music:Id=14fc4112-682d-42a5-9fe7-f5cc6adca73c
09/09 19:04:40 Info: [stats] 36180mb Virtual, 366mb Physical, 178mb Managed
09/09 19:04:40 Info: [remoting/distributedbroker] V2 Protocol Support is enabled
09/09 19:04:40 Info: [remoting/brokerserver] Enabling broker server (V2)
09/09 19:04:40 Info: [broker/httpserver] HTTP server listening on port 9300
09/09 19:04:40 Info: [broker/httpserver] HTTPS server listening on port 55000
09/09 19:04:40 Trace: [broker/backups] initializing
09/09 19:04:40 Info: [loadstatus] account loading is complete
09/09 19:04:40 Trace: [broker/accounts] Data updated. AccountStatus=NoAccountConfigured MachineStatus=NeedsAccount UserId=<none>
09/09 19:04:40 Trace: [broker/accounts] [heartbeat] now=9/10/2023 12:04:40 AM nextauthrefresh=9/9/2023 11:59:40 PM nextmachineallocate=1/1/0001 12:00:00 AM
09/09 19:04:40 Trace: [broker/accounts] doing auth refresh, next=9/9/2023 11:59:40 PM
09/09 19:04:40 Trace: [broker/accounts] doing machine allocate, next=9/10/2023 4:04:40 AM
09/09 19:04:40 Trace: [inetdiscovery] added device broker/baa7f176-8564-4100-8c66-f70177498342 in addr:__ADDR__
09/09 19:04:40 Info: [libraryapi] loaded first run time 3/22/2021 11:47:30 AM
09/09 19:04:40 Warn: AddTopLevel: win_apploading(5)
09/09 19:04:40 Trace: [devicedb] initializing
09/09 19:04:40 Info: [raatserver] [runner] Start or Connect...
09/09 19:04:40 Info: [raatserver] [runner] Start or Connect... /Volumes/Roon/Roon.app/Contents/MacOS/RAATServer
09/09 19:04:40 Info: ConnectOrStartAndWaitForExit RAATServer, path: /Volumes/Roon/Roon.app/Contents/MacOS/RAATServer
09/09 19:04:40 Info: [raatserver] [runner] Status: Started
09/09 19:04:40 Warn: [multicastreceiver] couldn't bind to iface 127.0.0.1:5350, message: Invalid argument
09/09 19:04:40 Warn: [multicastreceiver] couldn't bind to iface 192.168.0.174:5350, message: Invalid argument
09/09 19:04:40 Info: [roonapi] audioinput is supported
09/09 19:04:40 Trace: [broker/services] refreshing metadata URL bits
09/09 19:04:40 Info: [broker/services] using url override for metadata: https://metadataserver.roonlabs.net/md/
09/09 19:04:40 Info: [broker/services] using url override for identifier: https://identifier.roonlabs.net/identifier/
09/09 19:04:40 Info: [broker/services] using url override for imagecache: https://imagecache.roonlabs.net/im/
09/09 19:04:40 Info: [broker/services] using url override for swim: https://swim.roonlabs.net/
09/09 19:04:40 Info: [broker/services] using url override for metadataservice2: https://metadata.roonlabs.net/
09/09 19:04:40 Info: [broker/services] using url override for qobuzservice: https://qobuz.roonlabs.net/
09/09 19:04:40 Info: [broker/services] using url override for tidalservice: https://tidal.roonlabs.net/
09/09 19:04:40 Info: [broker/services] using url override for kkboxservice: https://kkbox.roonlabs.net/
09/09 19:04:40 Info: [broker/services] using url override for searchservice: https://search.roonlabs.net/
09/09 19:04:40 Info: [broker/services] using url override for discoverservice: https://discover.roonlabs.net/
09/09 19:04:40 Info: [broker/services] using url override for browseservice: https://discover.roonlabs.net/
09/09 19:04:40 Debug: initialize backend in 1590ms
09/09 19:04:41 Debug: ev_app_init: showing broker choosing window
09/09 19:04:41 Trace: [mobile] [remoteconnectivity] found new upnp device: Device={ DeviceType=urn:schemas-upnp-org:device:InternetGatewayDevice Version=1 FriendlyName=Archer AX3000 Manufacturer=TP-Link ModelName=Archer AX3000 UDN=uuid:e4c797e0-82ce-4f84-b56d-085d9d77c8cd Description=Archer AX3000 ModelNumber=1.0 ManufacturerUri=http://www.tp-link.com/ ModelUrl=http://www.tp-link.com/Device={ DeviceType=urn:schemas-upnp-org:device:WANDevice Version=1 FriendlyName=WANDevice Manufacturer=MiniUPnP ModelName=WAN Device UDN=uuid:e4c797e0-82ce-4f84-b56d-085d9d77c8cd Description=WAN Device ModelNumber=20200303 UPC=000000000000 ManufacturerUri=http://miniupnp.free.fr/ ModelUrl=http://miniupnp.free.fr/Device={ DeviceType=urn:schemas-upnp-org:device:WANConnectionDevice Version=1 FriendlyName=WANConnectionDevice Manufacturer=MiniUPnP ModelName=MiniUPnPd UDN=uuid:e4c797e0-82ce-4f84-b56d-085d9d77c8cd Description=MiniUPnP daemon ModelNumber=20200303 UPC=000000000000 ManufacturerUri=http://miniupnp.free.fr/ ModelUrl=http://miniupnp.free.fr/Service={ ServiceType=urn:schemas-upnp-org:service:WANIPConnection ServiceVersion=1 ServiceId=urn:upnp-org:serviceId:WANIPConn1 ControlUri=http://192.168.0.1:1900/ctl/IPConn SCPDUri=http://192.168.0.1:1900/WANIPCn.xml } } Service={ ServiceType=urn:schemas-upnp-org:service:WANCommonInterfaceConfig ServiceVersion=1 ServiceId=urn:upnp-org:serviceId:WANCommonIFC1 ControlUri=http://192.168.0.1:1900/ctl/CmnIfCfg SCPDUri=http://192.168.0.1:1900/WANCfg.xml } } Service={ ServiceType=urn:schemas-upnp-org:service:Layer3Forwarding ServiceVersion=1 ServiceId=urn:upnp-org:serviceId:Layer3Forwarding1 ControlUri=http://192.168.0.1:1900/ctl/L3F SCPDUri=http://192.168.0.1:1900/L3F.xml } }
09/09 19:04:41 Warn: AddTopLevel: win_choosebroker(23)
09/09 19:04:41 Trace: [mobile] [remoteconnectivity] Port Verification started due to: found UPnP WANConnectiondevice, not testing port opening because mobile module init has not finished
09/09 19:04:41 Debug: app_init completed
09/09 19:04:41 Debug: trigger: appinitwasnotrun
09/09 19:04:41 Debug: trigger: do nothing
09/09 19:04:41 Warn: [ui/slowness] widget win_choosebroker(23) > stackpanel(25) > vpanel(26) took 261ms to OnMeasure
09/09 19:04:41 Warn: [ui/slowness] widget win_choosebroker(23) > stackpanel(25) took 271ms to OnMeasure
09/09 19:04:41 Warn: [ui/slowness] widget win_choosebroker(23) took 279ms to OnMeasure
09/09 19:04:41 Debug: Created new font texture with id: 2
09/09 19:04:41 Info: Using FTMSI-B Cache
09/09 19:04:41 Debug: [broker/filebrowser/volumeattached] initial listing found drive mounted at /
09/09 19:04:41 Trace: windowDidChangeScreen: <BrooWindow: 0x7f83ec735530>
09/09 19:04:41 Trace: Switching display link to display 189000129
09/09 19:04:41 Debug: [broker/filebrowser] getpartitioninfo 1 command: /usr/sbin/diskutil, args: info -plist '/'
09/09 19:04:41 Debug: render area size changed value: 1024x740
09/09 19:04:41 Info: [broker/messaging] initializing
09/09 19:04:41 Info: [broker/dropbox] no account configured
09/09 19:04:41 Info: [metadata] initializing
09/09 19:04:41 Info: [remoting] loaded protocol hash 23492bf4f71d53e171cd759ea27056888f809c90 from /Volumes/Roon/Roon.app/Contents/MonoBundle/.xamarin/osx-x64/Roon.Broker.Api.Remote.dll
09/09 19:04:41 Trace: [remoting/distributedbroker] Enabling remote broker tracking
09/09 19:04:41 Trace: [library] endmutation in 15ms
09/09 19:04:41 Info: [music] first pass through media thread is done
09/09 19:04:41 Info: [transport] initializing
09/09 19:04:41 Trace: [devicedb] refreshing, etag=W/"29e85b-18a6d04590d"
09/09 19:04:41 Trace: [broker/accounts] doing auth refresh in EnsureAuthReady, next=9/10/2023 1:04:41 AM
09/09 19:04:41 Trace: [devicedb] builtin device db found at /Volumes/Roon/Roon.app/Contents/Resources/devicedb-prod.zip
09/09 19:04:41 Warn: [auth] EnsureAuthReady failed: Result[Status=NotLoggedIn]
09/09 19:04:41 Trace: [devicedb] loading device db at /Users/Mike/Library/Roon/Cache/devicedb-prod.zip
09/09 19:04:41 Trace: [geoip] GET https://geoip.roonlabs.net/geoip/1/lookup
09/09 19:04:41 Info: [loadstatus] IsLocalLibraryLoading True => False
09/09 19:04:42 Trace: [roonbridge] [sood] Refreshing device list
09/09 19:04:42 Debug: [broker/filebrowser] getpartitioninfo 2 command: /usr/sbin/diskutil, args: info -plist '/dev/disk2'
09/09 19:04:42 Trace: [volumewatcher] ev_VolumeChanged DidMount: /
09/09 19:04:42 Trace: [volumewatcher] ev_VolumeChanged DidMount: /dev
09/09 19:04:42 Trace: [volumewatcher] ev_VolumeChanged DidMount: /System/Volumes/VM
09/09 19:04:42 Trace: [volumewatcher] ev_VolumeChanged DidMount: /System/Volumes/Preboot
09/09 19:04:42 Trace: [volumewatcher] ev_VolumeChanged DidMount: /System/Volumes/Update
09/09 19:04:42 Trace: [volumewatcher] ev_VolumeChanged DidMount: /System/Volumes/Data
09/09 19:04:42 Trace: [volumewatcher] ev_VolumeChanged DidMount: /System/Volumes/Data/home
09/09 19:04:42 Trace: [volumewatcher] ev_VolumeChanged DidMount: /Volumes/Roon
09/09 19:04:42 Debug: [broker/filebrowser/volumeattached] found newly mounted drive at /
09/09 19:04:42 Debug: [broker/filebrowser/volumeattached] found newly mounted drive at /dev
09/09 19:04:42 Debug: [broker/filebrowser/volumeattached] found newly mounted drive at /System/Volumes/VM
09/09 19:04:42 Debug: [broker/filebrowser/volumeattached] found newly mounted drive at /System/Volumes/Preboot
09/09 19:04:42 Debug: [broker/filebrowser/volumeattached] found newly mounted drive at /System/Volumes/Update
09/09 19:04:42 Debug: [broker/filebrowser/volumeattached] found newly mounted drive at /System/Volumes/Data
09/09 19:04:42 Debug: [broker/filebrowser/volumeattached] found newly mounted drive at /System/Volumes/Data/home
09/09 19:04:42 Debug: [broker/filebrowser/volumeattached] found newly mounted drive at /Volumes/Roon
09/09 19:04:42 Debug: [broker/filebrowser] getpartitioninfo 1 command: /usr/sbin/diskutil, args: info -plist '/'
09/09 19:04:42 Debug: [broker/filebrowser] getpartitioninfo 1 command: /usr/sbin/diskutil, args: info -plist 'Roon'
09/09 19:04:42 Debug: [broker/filebrowser/volumeattached] loading from mount, and volume exists already with UUID "mounted:/". updating values /: |Untitled|AppleAPFSMedia => /|Untitled|AppleAPFSMedia
09/09 19:04:42 Info: [broker/filebrowser/volumeattached] Volume's availability changed: True
09/09 19:04:42 Debug: [broker/filebrowser/drive] availability on drive's volume changed: True: VolumeAttached[id:mounted:/,title: Untitled,subtitle:AppleAPFSMedia,mountdir:/]
09/09 19:04:42 Info: [broker/locations/directorystoragelocation] drive availabilitychanged: True, FileBrowser.Entry: Untitled, AppleAPFSMedia : /Users/Mike (it was False)
09/09 19:04:42 Info: [broker/locations/directorystoragelocation] drive is available checking to referencing fs provider and setting up dirwatcher: FileBrowser.Entry: Untitled, AppleAPFSMedia : /Users/Mike
09/09 19:04:42 Debug: [broker/locations/directorystoragelocation] drive path lookup took 6ms: FileBrowser.Entry: Untitled, AppleAPFSMedia : /Users/Mike
09/09 19:04:42 Debug: [broker/locations/directorystoragelocation] dirwatcher init took 0ms: FileBrowser.Entry: Untitled, AppleAPFSMedia : /Users/Mike
09/09 19:04:42 Info: [broker/locations/directorystoragelocation] attaching backend: FileBrowser.Entry: Untitled, AppleAPFSMedia : /Users/Mike
09/09 19:04:42 Trace: [storage] [directory] directorystorage init, location(/Users/Mike, dirwatcher is available: True)
09/09 19:04:42 Trace: [storage] [directory] init just before reorg delete thread, path: /Users/Mike
09/09 19:04:42 Trace: [storage] [directory] temp directory cleared, path: /Users/Mike/.tmp
09/09 19:04:42 Info: [broker/locations] storage location backend created and attached (Folder:Name=:Location=FileBrowser.Entry: Untitled, AppleAPFSMedia : /Users/Mike:Id=3ba5487c-67f5-46c0-bf0a-d053d37c38c1)
09/09 19:04:42 Info: [broker/locations] media availability: Folder:Name=:Location=FileBrowser.Entry: Untitled, AppleAPFSMedia : /Users/Mike:Id=3ba5487c-67f5-46c0-bf0a-d053d37c38c1 is online
09/09 19:04:42 Info: [broker/locations/directorystoragelocation] drive availabilitychanged: True, FileBrowser.Entry: Untitled, AppleAPFSMedia : /Users/Mike/Music/Music/Music (it was False)
09/09 19:04:42 Info: [broker/locations/directorystoragelocation] drive is available checking to referencing fs provider and setting up dirwatcher: FileBrowser.Entry: Untitled, AppleAPFSMedia : /Users/Mike/Music/Music/Music
09/09 19:04:42 Debug: [broker/locations/directorystoragelocation] drive path lookup took 0ms: FileBrowser.Entry: Untitled, AppleAPFSMedia : /Users/Mike/Music/Music/Music
09/09 19:04:42 Debug: [broker/locations/directorystoragelocation] dirwatcher init took 2ms: FileBrowser.Entry: Untitled, AppleAPFSMedia : /Users/Mike/Music/Music/Music
09/09 19:04:42 Info: [broker/locations/directorystoragelocation] attaching backend: FileBrowser.Entry: Untitled, AppleAPFSMedia : /Users/Mike/Music/Music/Music
09/09 19:04:42 Trace: [storage] [directory] directorystorage init, location(/Users/Mike/Music/Music/Music, dirwatcher is available: True)
09/09 19:04:42 Trace: [storage] [directory] init just before reorg delete thread, path: /Users/Mike/Music/Music/Music
09/09 19:04:42 Trace: [storage] [directory] temp directory cleared, path: /Users/Mike/Music/Music/Music/.tmp
09/09 19:04:42 Info: [broker/locations] storage location backend created and attached (Folder:Name=:Location=FileBrowser.Entry: Untitled, AppleAPFSMedia : /Users/Mike/Music/Music/Music:Id=14fc4112-682d-42a5-9fe7-f5cc6adca73c)
09/09 19:04:42 Info: [broker/locations] media availability: Folder:Name=:Location=FileBrowser.Entry: Untitled, AppleAPFSMedia : /Users/Mike/Music/Music/Music:Id=14fc4112-682d-42a5-9fe7-f5cc6adca73c is online
09/09 19:04:42 Debug: [broker/filebrowser/volumeattached] initial listing found drive mounted at /dev
09/09 19:04:42 Debug: [broker/filebrowser/volumeattached] initial listing found drive mounted at /System/Volumes/VM
09/09 19:04:42 Debug: [broker/filebrowser/volumeattached] initial listing found drive mounted at /System/Volumes/Preboot
09/09 19:04:42 Debug: [broker/filebrowser/volumeattached] initial listing found drive mounted at /System/Volumes/Update
09/09 19:04:42 Debug: [broker/filebrowser/volumeattached] initial listing found drive mounted at /System/Volumes/Data
09/09 19:04:42 Debug: [broker/filebrowser/volumeattached] initial listing found drive mounted at /System/Volumes/Data/home
09/09 19:04:42 Debug: [broker/filebrowser/volumeattached] initial listing found drive mounted at /Volumes/Roon
09/09 19:04:42 Debug: [broker/filebrowser] getpartitioninfo 1 command: /usr/sbin/diskutil, args: info -plist 'Roon'
09/09 19:04:42 Debug: [easyhttp] [3] GET to https://api.roonlabs.net/devicedb/1/devicedb-prod.zip returned after 553 ms, status code: 304, request body size: 0 B
09/09 19:04:42 Debug: [easyhttp] [1] POST to https://api.roonlabs.net/discovery/1/query returned after 597 ms, status code: 200, request body size: 140 B
09/09 19:04:42 Debug: [broker/filebrowser] getpartitioninfo 2 command: /usr/sbin/diskutil, args: info -plist '/dev/disk2'
09/09 19:04:42 Debug: [easyhttp] [4] POST to https://api.roonlabs.net/discovery/1/query returned after 489 ms, status code: 200, request body size: 74 B
09/09 19:04:42 Debug: [broker/filebrowser/volumeattached] loading from mount, and volume exists already with UUID "mounted:/". updating values /: /|Untitled|AppleAPFSMedia => /|Untitled|AppleAPFSMedia
09/09 19:04:42 Info: [broker/filebrowser/volumeattached] Volume's availability changed: True
09/09 19:04:42 Debug: [broker/filebrowser/drive] availability on drive's volume changed: True: VolumeAttached[id:mounted:/,title: Untitled,subtitle:AppleAPFSMedia,mountdir:/]
09/09 19:04:42 Info: [broker/locations/directorystoragelocation] drive availabilitychanged: True, FileBrowser.Entry: Untitled, AppleAPFSMedia : /Users/Mike (it was True)
09/09 19:04:42 Info: [broker/locations/directorystoragelocation] drive availabilitychanged: True, FileBrowser.Entry: Untitled, AppleAPFSMedia : /Users/Mike/Music/Music/Music (it was True)
09/09 19:04:42 Trace: [broker/httpserver] https port changed. Kicking off discovery cycle
09/09 19:04:42 Trace: [devicedb] loaded 159 vendors, 984 products from devicedb with timestamp 9/7/2023 12:21:54 AM
09/09 19:04:42 Trace: [devicedb] valid cached device db found at /Users/Mike/Library/Roon/Cache/devicedb-prod.zip
09/09 19:04:42 Info: [loadstatus] IsTransportLoading True => False
09/09 19:04:42 Info: [loadstatus] IsStartup True => False
09/09 19:04:42 Info: [mobile] initializing
09/09 19:04:42 Info: [roonapi] initializing
09/09 19:04:42 Info: [roonapi] crestron is supported
09/09 19:04:42 Info: [roonapi] control4 is supported
09/09 19:04:42 Trace: [mobile] [remoteconnectivity] Port Verification started due to: initial check at init, not testing port opening because the broker is not loaded and ready. account status: NoAccountConfigured, machine status: NeedsAccount, load status: NotReady
09/09 19:04:42 Trace: [inetdiscovery] added service com.roonlabs.roon.api.tcp for device broker/baa7f176-8564-4100-8c66-f70177498342
09/09 19:04:42 Trace: [inetdiscovery] added service com.roonlabs.roon.api.http for device broker/baa7f176-8564-4100-8c66-f70177498342
09/09 19:04:42 Info: [roonapi] listening on port 9150
09/09 19:04:42 Trace: [mobile] [remoteconnectivity] Port Verification started due to: load status changed, not testing port opening because the broker is not loaded and ready. account status: NoAccountConfigured, machine status: NeedsAccount, load status: Ready
09/09 19:04:42 Trace: [devicedb] Not Modified. Nothing to do
09/09 19:04:42 Debug: [easyhttp] [2] GET to https://api.roonlabs.net/geoip/geoip/1/lookup returned after 902 ms, status code: 200, request body size: 0 B
09/09 19:04:42 Trace: [geoip] GOT {"country_iso":"US","state":"Texas","city":"Jasper","latitude":30.9202,"longitude":-93.99658,"postalcode":"75951","ip":"192.161.241.22","status":"Success","country":"United States of America","source":"ipify","state_iso":"TX","decimal_ip":"3231838486","ipaddress":"192.161.241.22"}
09/09 19:04:43 Debug: [easyhttp] [5] POST to https://api.roonlabs.net/roonmobile/1/cores/announce returned after 370 ms, status code: 401
09/09 19:04:47 Debug: ev_app_init: using local broker [is_essentials=0]
09/09 19:04:47 Info: [client/root] Broker changed null => hdmusics-Mac-mini-5 (Local Broker baa7f176-8564-4100-8c66-f70177498342)
09/09 19:04:47 Info: [client/root] Client is controlling the local broker
09/09 19:04:47 Debug: ev_app_init: showing login window
09/09 19:04:47 Warn: AddTopLevel: win_login(282)
09/09 19:04:48 Debug: trigger: appinitwasnotrun
09/09 19:04:48 Debug: trigger: do nothing
09/09 19:04:48 Debug: [easyhttp] [6] POST to https://api.roonlabs.net/discovery/1/register returned after 741 ms, status code: 200, request body size: 616 B
09/09 19:04:48 Trace: [inetdiscovery] registered 1 devices, 2 services
09/09 19:04:48 Debug: [broker/locations/directorystoragelocation] ev_subdirectory, path: /Users/Mike
09/09 19:04:51 Debug: [easyhttp] [7] GET to https://api.roonlabs.net/push-manager/1/connect returned after 314 ms, status code: 200, request body size: 0 B
09/09 19:04:51 Debug: [push2] push connector url received from push manager: ws://push-connector-v2-0.prd-roonlabs-1.prd.roonlabs.net/
09/09 19:04:51 Trace: [push2] connecting to push2 connector at ws://push-connector-v2-0.prd-roonlabs-1.prd.roonlabs.net/
09/09 19:04:51 Debug: launching sso login url: https://go.roonlabs.com/Roon/account-login?id=94af1bcf-b651-483d-a120-f6796033dde2&challenge=nKFzOEJuFeklF6pO3mQb7OUwnL8iEAPtxAbXB5qGgTA
09/09 19:04:51 Info: [client] opening web url https://go.roonlabs.com/Roon/account-login?id=94af1bcf-b651-483d-a120-f6796033dde2&challenge=nKFzOEJuFeklF6pO3mQb7OUwnL8iEAPtxAbXB5qGgTA
09/09 19:04:52 Trace: [push2] connected to push2 connector at ws://push-