> On Nov 21, 2017, at 10:58 AM, Georgy Yakovlev <[email protected]> wrote: > > > >> On Nov 21, 2017, at 8:49 AM, Hiltjo Posthuma <[email protected]> wrote: >> >> On Mon, Nov 20, 2017 at 09:20:59PM -0800, [email protected] wrote: >>>> Synopsis: relayd mitm exits with SIGBUS SIG_DFL code BUS_OBJERR<3> >>>> addr=0x... trapno=4 >>>> Category: system >>>> Environment: >>> System : OpenBSD 6.2 >>> Details : OpenBSD 6.2 (GENERIC.MP) #0: Thu Oct 12 19:53:18 CEST 2017 >>> >>> [email protected]:/usr/src/sys/arch/amd64/compile/GENERIC.MP >>> >>> Architecture: OpenBSD.amd64 >>> Machine : amd64 >>>> Description: >>> >>> Building a small home router using apu2c4, >>> tryring to configure relayd as mitm transparent proxy but >>> it crashes every time I do a https request. >>> plain http works fine. >>> >>> >>> Here's a part I get running relayd in verbose mode: >>> >>> ca_engine_init: using RSA privsep engine >>> ca_engine_init: using RSA privsep engine >>> init_tables: created 0 tables >>> relay_launch: running relay plaininspect >>> relay_tls_ctx_create: loading certificate >>> relay_tls_ctx_create: loading CA certificate >>> relay_tls_ctx_create: loading certificate >>> relay_launch: running relay tlsinspect >>> relay_preconnect: session 1: process 2 >>> relay_tls_transaction: session 1: scheduling on EV_WRITE >>> relay tlsinspect, tls session 1 connected (1 active) >>> relay_tls_inspect_create: loading intercepted certificate >>> relay_tls_transaction: session 1: scheduling on EV_READ >>> kill_tables: deleted 0 tables >>> flush_rulesets: flushed rules >>> ca exiting, pid 39470 >>> pfe exiting, pid 89867 >>> hce exiting, pid 73813 >>> lost child: pid 60617 terminated; signal 10 >>> parent terminating, pid 36651 >>> >>> >>> Here is kdump part of pid 60617: >>> ... >>> 60617 relayd CALL kevent(4,0xbf3dd22000,3,0xbf960ca800,64,0x7f7fffffb2b0) >>> 60617 relayd STRU struct timespec { 56.976745000 } >>> 60617 relayd STRU struct kevent [3] { ident=7, filter=EVFILT_READ, >>> flags=0x2<EV_DELETE>, fflags=0<>, data=0, udata=0x0 } { ident=7, >>> filter=EVFILT_READ, flags=0x11<EV_ADD|EV_ONESHOT>, fflags=0x2<NOTE_EOF>, >>> data=0, udata=0xbf37dd9048 } { ident=10, filter=EVFILT_READ, >>> flags=0x11<EV_ADD|EV_ONESHOT>, fflags=0x2<NOTE_EOF>, data=0, >>> udata=0xbf80055b48 } >>> 60617 relayd STRU struct kevent { ident=10, filter=EVFILT_READ, >>> flags=0x11<EV_ADD|EV_ONESHOT>, fflags=0<>, data=517, udata=0xbf80055b48 } >>> 60617 relayd RET kevent 1 >>> 60617 relayd CALL clock_gettime(CLOCK_MONOTONIC,0x7f7fffffb350) >>> 60617 relayd STRU struct timespec { 1811.240483460 } >>> 60617 relayd RET clock_gettime 0 >>> 60617 relayd CALL kbind(0x7f7fffffb1a0,24,0xba17667cef9e165f) >>> 60617 relayd RET kbind 0 >>> 60617 relayd CALL >>> mmap(0,0x5000,0x3<PROT_READ|PROT_WRITE>,0x1002<MAP_PRIVATE|MAP_ANON>,-1,0) >>> 60617 relayd RET mmap 819564601344/0xbed1db6000 >>> 60617 relayd CALL >>> mmap(0,0x5000,0x3<PROT_READ|PROT_WRITE>,0x1002<MAP_PRIVATE|MAP_ANON>,-1,0) >>> 60617 relayd RET mmap 823219187712/0xbfabaff000 >>> 60617 relayd CALL read(10,0xbed1db6003,0x5) >>> 60617 relayd GIO fd 10 read 5 bytes >>> 60617 relayd RET read 5 >>> 60617 relayd CALL read(10,0xbed1db6008,0x200) >>> 60617 relayd GIO fd 10 read 512 bytes >>> 60617 relayd RET read 512/0x200 >>> 60617 relayd CALL gettimeofday(0x7f7fffffb040,0) >>> 60617 relayd STRU struct timeval { 1511238874<"Nov 20 20:34:34 >>> 2017">.086852 } >>> 60617 relayd RET gettimeofday 0 >>> 60617 relayd CALL kbind(0x7f7fffffaf90,24,0xba17667cef9e165f) >>> 60617 relayd RET kbind 0 >>> 60617 relayd CALL kbind(0x7f7fffffae80,24,0xba17667cef9e165f) >>> 60617 relayd RET kbind 0 >>> 60617 relayd CALL kbind(0x7f7fffffaee0,24,0xba17667cef9e165f) >>> 60617 relayd RET kbind 0 >>> 60617 relayd CALL kbind(0x7f7fffffaf80,24,0xba17667cef9e165f) >>> 60617 relayd RET kbind 0 >>> 60617 relayd CALL kbind(0x7f7fffffaf80,24,0xba17667cef9e165f) >>> 60617 relayd RET kbind 0 >>> 60617 relayd PSIG SIGBUS SIG_DFL code BUS_OBJERR<3> addr=0xbee87387f8 >>> trapno=4 >>> 36651 relayd RET wait4 60617/0xecc9 >>> "lost child: pid 60617 terminated; signal 10 >>> >>> >>> configs: >>> >>> # /etc/relayd.conf >>> prefork 1 >>> http protocol httpfilter { >>> return error style 'body { background: #f3f3f3; color: #606060; }' >>> pass >>> >>> match label "Content blocked" >>> block request quick url "neverssl.com/" value "*" >>> block request quick url "facebook.com/" value "*" >>> >>> tls ca key "/etc/ssl/relayd/ca.key" password "secret" >>> tls ca cert "/etc/ssl/relayd/ca.crt" >>> tls { tlsv1, sslv3 } >>> } >>> >>> relay plaininspect { >>> listen on 127.0.0.1 port 8080 >>> protocol httpfilter >>> forward to destination >>> } >>> >>> relay tlsinspect { >>> listen on 127.0.0.1 port 8443 tls >>> protocol httpfilter >>> forward with tls to destination >>> } >>> >>> >>> # /etc/pf.conf >>> set block-policy drop >>> set loginterface egress >>> set skip on lo >>> match out on egress inet from !(egress:network) to any nat-to (egress:0) >>> block in all >>> pass in quick on lan inet proto tcp from any to port 80 divert-to localhost >>> port 8080 >>> pass in quick on lan inet proto tcp from any to port 443 divert-to >>> localhost port 8443 >>> pass in on lan inet >>> pass out inet >>> >>> >>>> How-To-Repeat: >>> Configure relayd as specified above. Try to make a https request. >>> >>> Certificates created using commands: >>> # openssl req -x509 -days 365 -newkey rsa:2048 \ >>> -keyout /etc/ssl/relayd/ca.key -out /etc/ssl/relayd/ca.crt >>> >>> # openssl req -nodes -x509 -days 365 -newkey rsa:2048 \ >>> -keyout /etc/ssl/private/127.0.0.1.key -out /etc/ssl/127.0.0.1.crt >>> >>> All the fields are filled in. >>> >>> >>>> Fix: >>> Not known, sorry. >>> I'd like to help find the rootcause of this but will need some guidance. >>> >>> >>> dmesg: >>> OpenBSD 6.2 (GENERIC.MP) #0: Thu Oct 12 19:53:18 CEST 2017 >>> >>> [email protected]:/usr/src/sys/arch/amd64/compile/GENERIC.MP >>> real mem = 4261072896 (4063MB) >>> avail mem = 4124913664 (3933MB) >>> mpath0 at root >>> scsibus0 at mpath0: 256 targets >>> mainbus0 at root >>> bios0 at mainbus0: SMBIOS rev. 2.7 @ 0xdffb7020 (7 entries) >>> bios0: vendor coreboot version "4.0.7" date 02/28/2017 >>> bios0: PC Engines APU2 >>> acpi0 at bios0: rev 2 >>> acpi0: sleep states S0 S1 S2 S3 S4 S5 >>> acpi0: tables DSDT FACP SSDT APIC HEST SSDT SSDT HPET >>> acpi0: wakeup devices PWRB(S4) PBR4(S4) PBR5(S4) PBR6(S4) PBR7(S4) PBR8(S4) >>> UOH1(S3) UOH3(S3) UOH5(S3) XHC0(S4) >>> acpitimer0 at acpi0: 3579545 Hz, 32 bits >>> acpimadt0 at acpi0 addr 0xfee00000: PC-AT compat >>> cpu0 at mainbus0: apid 0 (boot processor) >>> cpu0: AMD GX-412TC SOC, 998.26 MHz >>> cpu0: >>> FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,CFLUSH,MMX,FXSR,SSE,SSE2,HTT,SSE3,PCLMUL,MWAIT,SSSE3,CX16,SSE4.1,SSE4.2,MOVBE,POPCNT,AES,XSAVE,AVX,F16C,NXE,MMXX,FFXSR,PAGE1GB,RDTSCP,LONG,LAHF,CMPLEG,SVM,EAPICSP,AMCR8,ABM,SSE4A,MASSE,3DNOWP,OSVW,IBS,SKINIT,TOPEXT,ITSC,BMI1 >>> cpu0: 32KB 64b/line 2-way I-cache, 32KB 64b/line 8-way D-cache, 2MB >>> 64b/line 16-way L2 cache >>> cpu0: ITLB 32 4KB entries fully associative, 8 4MB entries fully associative >>> cpu0: DTLB 40 4KB entries fully associative, 8 4MB entries fully associative >>> cpu0: TSC frequency 998262150 Hz >>> cpu0: smt 0, core 0, package 0 >>> mtrr: Pentium Pro MTRR support, 8 var ranges, 88 fixed ranges >>> cpu0: apic clock running at 99MHz >>> cpu0: mwait min=64, max=64, IBE >>> cpu1 at mainbus0: apid 1 (application processor) >>> cpu1: AMD GX-412TC SOC, 998.14 MHz >>> cpu1: >>> FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,CFLUSH,MMX,FXSR,SSE,SSE2,HTT,SSE3,PCLMUL,MWAIT,SSSE3,CX16,SSE4.1,SSE4.2,MOVBE,POPCNT,AES,XSAVE,AVX,F16C,NXE,MMXX,FFXSR,PAGE1GB,RDTSCP,LONG,LAHF,CMPLEG,SVM,EAPICSP,AMCR8,ABM,SSE4A,MASSE,3DNOWP,OSVW,IBS,SKINIT,TOPEXT,ITSC,BMI1 >>> cpu1: 32KB 64b/line 2-way I-cache, 32KB 64b/line 8-way D-cache, 2MB >>> 64b/line 16-way L2 cache >>> cpu1: ITLB 32 4KB entries fully associative, 8 4MB entries fully associative >>> cpu1: DTLB 40 4KB entries fully associative, 8 4MB entries fully associative >>> cpu1: smt 0, core 1, package 0 >>> cpu2 at mainbus0: apid 2 (application processor) >>> cpu2: AMD GX-412TC SOC, 998.14 MHz >>> cpu2: >>> FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,CFLUSH,MMX,FXSR,SSE,SSE2,HTT,SSE3,PCLMUL,MWAIT,SSSE3,CX16,SSE4.1,SSE4.2,MOVBE,POPCNT,AES,XSAVE,AVX,F16C,NXE,MMXX,FFXSR,PAGE1GB,RDTSCP,LONG,LAHF,CMPLEG,SVM,EAPICSP,AMCR8,ABM,SSE4A,MASSE,3DNOWP,OSVW,IBS,SKINIT,TOPEXT,ITSC,BMI1 >>> cpu2: 32KB 64b/line 2-way I-cache, 32KB 64b/line 8-way D-cache, 2MB >>> 64b/line 16-way L2 cache >>> cpu2: ITLB 32 4KB entries fully associative, 8 4MB entries fully associative >>> cpu2: DTLB 40 4KB entries fully associative, 8 4MB entries fully associative >>> cpu2: smt 0, core 2, package 0 >>> cpu3 at mainbus0: apid 3 (application processor) >>> cpu3: AMD GX-412TC SOC, 998.14 MHz >>> cpu3: >>> FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,CFLUSH,MMX,FXSR,SSE,SSE2,HTT,SSE3,PCLMUL,MWAIT,SSSE3,CX16,SSE4.1,SSE4.2,MOVBE,POPCNT,AES,XSAVE,AVX,F16C,NXE,MMXX,FFXSR,PAGE1GB,RDTSCP,LONG,LAHF,CMPLEG,SVM,EAPICSP,AMCR8,ABM,SSE4A,MASSE,3DNOWP,OSVW,IBS,SKINIT,TOPEXT,ITSC,BMI1 >>> cpu3: 32KB 64b/line 2-way I-cache, 32KB 64b/line 8-way D-cache, 2MB >>> 64b/line 16-way L2 cache >>> cpu3: ITLB 32 4KB entries fully associative, 8 4MB entries fully associative >>> cpu3: DTLB 40 4KB entries fully associative, 8 4MB entries fully associative >>> cpu3: smt 0, core 3, package 0 >>> ioapic0 at mainbus0: apid 4 pa 0xfec00000, version 21, 24 pins >>> ioapic1 at mainbus0: apid 5 pa 0xfec20000, version 21, 32 pins >>> , remapped to apid 5 >>> acpihpet0 at acpi0: 14318180 Hz >>> acpiprt0 at acpi0: bus 0 (PCI0) >>> acpiprt1 at acpi0: bus -1 (PBR4) >>> acpiprt2 at acpi0: bus 1 (PBR5) >>> acpiprt3 at acpi0: bus 2 (PBR6) >>> acpiprt4 at acpi0: bus 3 (PBR7) >>> acpiprt5 at acpi0: bus 4 (PBR8) >>> acpicpu0 at acpi0: C2(0@400 io@0x1771), C1(@1 halt!), PSS >>> acpicpu1 at acpi0: C2(0@400 io@0x1771), C1(@1 halt!), PSS >>> acpicpu2 at acpi0: C2(0@400 io@0x1771), C1(@1 halt!), PSS >>> acpicpu3 at acpi0: C2(0@400 io@0x1771), C1(@1 halt!), PSS >>> acpibtn0 at acpi0: PWRB >>> cpu0: 998 MHz: speeds: 1000 800 600 MHz >>> pci0 at mainbus0 bus 0 >>> pchb0 at pci0 dev 0 function 0 "AMD AMD64 16h Root Complex" rev 0x00 >>> pchb1 at pci0 dev 2 function 0 "AMD AMD64 16h Host" rev 0x00 >>> ppb0 at pci0 dev 2 function 2 "AMD AMD64 16h PCIE" rev 0x00: msi >>> pci1 at ppb0 bus 1 >>> em0 at pci1 dev 0 function 0 "Intel I210" rev 0x03: msi, address >>> 00:0d:b9:49:c1:14 >>> ppb1 at pci0 dev 2 function 3 "AMD AMD64 16h PCIE" rev 0x00: msi >>> pci2 at ppb1 bus 2 >>> em1 at pci2 dev 0 function 0 "Intel I210" rev 0x03: msi, address >>> 00:0d:b9:49:c1:15 >>> ppb2 at pci0 dev 2 function 4 "AMD AMD64 16h PCIE" rev 0x00: msi >>> pci3 at ppb2 bus 3 >>> em2 at pci3 dev 0 function 0 "Intel I210" rev 0x03: msi, address >>> 00:0d:b9:49:c1:16 >>> ppb3 at pci0 dev 2 function 5 "AMD AMD64 16h PCIE" rev 0x00: msi >>> pci4 at ppb3 bus 4 >>> athn0 at pci4 dev 0 function 0 "Atheros AR9281" rev 0x01: apic 5 int 16 >>> athn0: AR9280 rev 2 (2T2R), ROM rev 22, address 04:f0:21:34:37:63 >>> "AMD CCP" rev 0x00 at pci0 dev 8 function 0 not configured >>> xhci0 at pci0 dev 16 function 0 "AMD Bolton xHCI" rev 0x11: msi >>> usb0 at xhci0: USB revision 3.0 >>> uhub0 at usb0 configuration 1 interface 0 "AMD xHCI root hub" rev 3.00/1.00 >>> addr 1 >>> ahci0 at pci0 dev 17 function 0 "AMD Hudson-2 SATA" rev 0x40: apic 4 int >>> 19, AHCI 1.3 >>> ahci0: port 0: 6.0Gb/s >>> scsibus1 at ahci0: 32 targets >>> sd0 at scsibus1 targ 0 lun 0: <ATA, SATA SSD, SBFM> SCSI3 0/direct fixed >>> naa.0000000000000000 >>> sd0: 57241MB, 512 bytes/sector, 117231408 sectors, thin >>> ehci0 at pci0 dev 19 function 0 "AMD Hudson-2 USB2" rev 0x39: apic 4 int 18 >>> usb1 at ehci0: USB revision 2.0 >>> uhub1 at usb1 configuration 1 interface 0 "AMD EHCI root hub" rev 2.00/1.00 >>> addr 1 >>> piixpm0 at pci0 dev 20 function 0 "AMD Hudson-2 SMBus" rev 0x42: SMBus >>> disabled >>> pcib0 at pci0 dev 20 function 3 "AMD Hudson-2 LPC" rev 0x11 >>> sdhc0 at pci0 dev 20 function 7 "AMD Bolton SD/MMC" rev 0x01: apic 4 int 16 >>> sdhc0: SDHC 2.0, 50 MHz base clock >>> sdmmc0 at sdhc0: 4-bit, sd high-speed, mmc high-speed, dma >>> pchb2 at pci0 dev 24 function 0 "AMD AMD64 16h Link Cfg" rev 0x00 >>> pchb3 at pci0 dev 24 function 1 "AMD AMD64 16h Address Map" rev 0x00 >>> pchb4 at pci0 dev 24 function 2 "AMD AMD64 16h DRAM Cfg" rev 0x00 >>> km0 at pci0 dev 24 function 3 "AMD AMD64 16h Misc Cfg" rev 0x00 >>> pchb5 at pci0 dev 24 function 4 "AMD AMD64 16h CPU Power" rev 0x00 >>> pchb6 at pci0 dev 24 function 5 "AMD AMD64 16h Misc Cfg" rev 0x00 >>> isa0 at pcib0 >>> isadma0 at isa0 >>> com0 at isa0 port 0x3f8/8 irq 4: ns16550a, 16 byte fifo >>> com0: console >>> com1 at isa0 port 0x2f8/8 irq 3: ns16550a, 16 byte fifo >>> pcppi0 at isa0 port 0x61 >>> spkr0 at pcppi0 >>> lpt0 at isa0 port 0x378/4 irq 7 >>> wbsio0 at isa0 port 0x2e/2: NCT5104D rev 0x53 >>> vmm0 at mainbus0: SVM/RVI >>> scsibus2 at sdmmc0: 2 targets, initiator 0 >>> sd1 at scsibus2 targ 1 lun 0: <SD/MMC, SD04G, 0030> SCSI2 0/direct removable >>> sd1: 3796MB, 512 bytes/sector, 7774208 sectors >>> umass0 at uhub0 port 4 configuration 1 interface 0 "JetFlash Mass Storage >>> Device" rev 2.00/11.00 addr 2 >>> umass0: using SCSI over Bulk-Only >>> scsibus3 at umass0: 2 targets, initiator 0 >>> sd2 at scsibus3 targ 1 lun 0: <JetFlash, Transcend 8GB, 1100> SCSI0 >>> 0/direct removable serial.856410009TLZQ9GF3QPO >>> sd2: 7728MB, 512 bytes/sector, 15826944 sectors >>> uhub2 at uhub1 port 1 configuration 1 interface 0 "Advanced Micro Devices >>> product 0x7900" rev 2.00/0.18 addr 2 >>> vscsi0 at root >>> scsibus4 at vscsi0: 256 targets >>> softraid0 at root >>> scsibus5 at softraid0: 256 targets >>> root on sd0a (0ab533048d7473ef.a) swap on sd0b dump on sd0b >>> >> >> Hey, >> >> Can you try it with a default or higher prefork value such as: >> prefork 4? >> >> I think a prefork value of 1 is too low, because it is also reserved for the >> health-checking process iirc. I've run into a similar issue where the process >> also crashes because of this. >> >> Please report back, >> >> -- >> Kind regards, >> Hiltjo > > Hi! > I tried this before with the default prefork of 4 and got the same result. > The only reason I’m setting "prefork 1" is to get a shorter ktrace to > be able to examine that single fork and maybe use gdb on it. > But from what I can remember it cleanly kills all remaining forks > after that problematic fork is terminated. > > I will try a larger value and report back, thanks for suggestion. > > > Regards, > Georgy.
Previous reply went off the list, sorry. Tried with prefork 8, absolutely clean fresh 6.2 installation, same thing. Happens on yesterday’s snapshot as well. I can crash it with a browser, with curl or just anything that requests a https connection. relay_tls_transaction: session 1: scheduling on EV_WRITE relay tlsinspect, tls session 1 connected (1 active) relay_tls_inspect_create: loading intercepted certificate relay_tls_transaction: session 1: scheduling on EV_READ ca exiting, pid 5844 ca exiting, pid 38895 ca exiting, pid 36887 ca exiting, pid 68879 ca exiting, pid 6559 ca exiting, pid 99958 kill_tables: deleted 0 tables flush_rulesets: flushed rules pfe exiting, pid 77548 ca exiting, pid 23133 lost child: pid 31536 terminated; signal 10 ca exiting, pid 2332 hce exiting, pid 74474 relay exiting, pid 42819 relay exiting, pid 25876 relay exiting, pid 21303 relay exiting, pid 72036 relay exiting, pid 60193 relay exiting, pid 90190 relay exiting, pid 66264 parent terminating, pid 7816 Trying out to debug with gdb but that’s not something I’m good at.
