Bug #53
closed
panic: runtime error: slice bounds out of range [:111] with capacity 8
Added by Jörg Ebeling over 2 years ago. Updated over 2 years ago.
100%
Description
Full crash (probably related to a 8th LDAP client):
Nov 4 16:31:06 server02 l2cpbg[47993]: panic: runtime error: slice bounds out of range [:111] with capacity 8
Nov 4 16:31:06 server02 l2cpbg[47993]: goroutine 127 [running]:
Nov 4 16:31:06 server02 l2cpbg[47993]: github.com/nmcclain/asn1-ber.decodePacket(0xc00068608b, 0x2, 0x8, 0xc000680a20, 0xc00068608b, 0x2, 0x8)
Nov 4 16:31:06 server02 l2cpbg[47993]: #011/home/jebeling/go/pkg/mod/github.com/nmcclain/asn1-ber@v0.0.0-20170104154839-2661553a0484/ber.go:335 +0x7e5
Nov 4 16:31:06 server02 l2cpbg[47993]: github.com/nmcclain/asn1-ber.decodePacket(0xc000686037, 0x5c, 0x5c, 0xc000680780, 0xc000686037, 0x5c, 0x5c)
Nov 4 16:31:06 server02 l2cpbg[47993]: #011/home/jebeling/go/pkg/mod/github.com/nmcclain/asn1-ber@v0.0.0-20170104154839-2661553a0484/ber.go:341 +0x279
Nov 4 16:31:06 server02 l2cpbg[47993]: github.com/nmcclain/asn1-ber.decodePacket(0xc000686006, 0x8d, 0x8d, 0xc0006804e0, 0xc000686006, 0x8d, 0x8d)
Nov 4 16:31:06 server02 l2cpbg[47993]: #011/home/jebeling/go/pkg/mod/github.com/nmcclain/asn1-ber@v0.0.0-20170104154839-2661553a0484/ber.go:341 +0x279
Nov 4 16:31:06 server02 l2cpbg[47993]: github.com/nmcclain/asn1-ber.decodePacket(0xc000686000, 0x93, 0x93, 0x90, 0x90, 0x0, 0x0)
Nov 4 16:31:06 server02 l2cpbg[47993]: #011/home/jebeling/go/pkg/mod/github.com/nmcclain/asn1-ber@v0.0.0-20170104154839-2661553a0484/ber.go:341 +0x279
Nov 4 16:31:06 server02 l2cpbg[47993]: github.com/nmcclain/asn1-ber.DecodePacket(...)
Nov 4 16:31:06 server02 l2cpbg[47993]: #011/home/jebeling/go/pkg/mod/github.com/nmcclain/asn1-ber@v0.0.0-20170104154839-2661553a0484/ber.go:304
Nov 4 16:31:06 server02 l2cpbg[47993]: github.com/nmcclain/asn1-ber.ReadPacket(0xe34c00, 0xc000278000, 0xc000278000, 0xe34c00, 0xc000278000)
Nov 4 16:31:06 server02 l2cpbg[47993]: #011/home/jebeling/go/pkg/mod/github.com/nmcclain/asn1-ber@v0.0.0-20170104154839-2661553a0484/ber.go:253 +0x56c
Nov 4 16:31:06 server02 l2cpbg[47993]: github.com/nmcclain/ldap.(*Server).handleConnection(0xc000245030, 0xe48de0, 0xc000278000)
Nov 4 16:31:06 server02 l2cpbg[47993]: #011/usr/src/Apehaenger/ldap/server.go:231 +0x2e5
Nov 4 16:31:06 server02 l2cpbg[47993]: created by github.com/nmcclain/ldap.(*Server).Serve
Nov 4 16:31:06 server02 l2cpbg[47993]: #011/usr/src/Apehaenger/ldap/server.go:215 +0xf6
Nov 4 16:31:06 server02 systemd[1]: l2cpbg.service: Main process exited, code=exited, status=2/INVALIDARGUMENT
Files
| l2cpbg_0.9.4beta4dbg1_amd64.deb (8.88 MB) l2cpbg_0.9.4beta4dbg1_amd64.deb | Jörg Ebeling, 11/04/2021 08:27 PM | ||
| l2cpbg_0.9.4beta5dbg2_amd64.deb (8.88 MB) l2cpbg_0.9.4beta5dbg2_amd64.deb | Jörg Ebeling, 11/08/2021 08:06 PM | ||
| l2cpbg_0.9.4beta5dbg2_linux-amd64.tgz (10.2 MB) l2cpbg_0.9.4beta5dbg2_linux-amd64.tgz | Jörg Ebeling, 11/08/2021 08:06 PM | ||
| l2cpbg_0.9.4beta5dbg2_windows-64bit.zip (10.2 MB) l2cpbg_0.9.4beta5dbg2_windows-64bit.zip | Jörg Ebeling, 11/08/2021 08:06 PM | ||
| l2cpbg_0.9.4beta6dbg1_amd64.deb (8.88 MB) l2cpbg_0.9.4beta6dbg1_amd64.deb | Jörg Ebeling, 11/09/2021 12:08 AM | ||
| l2cpbg_0.9.4beta6dbg1_linux-amd64.tgz (10.2 MB) l2cpbg_0.9.4beta6dbg1_linux-amd64.tgz | Jörg Ebeling, 11/09/2021 12:08 AM | ||
| l2cpbg_0.9.4beta6dbg1_windows-64bit.zip (10.2 MB) l2cpbg_0.9.4beta6dbg1_windows-64bit.zip | Jörg Ebeling, 11/09/2021 12:08 AM |
Updated by Jörg Ebeling over 2 years ago
- Status changed from New to In Progress
Michael,
this might become complicated ;-)
The error clearly happen in the external asn1-ber library of the ldap server.
Two people made changes there during the last year (one of them was myself ^^).
We need a reliable reproduction case. I might be wrong, but my guess is that it might have something to do with special (unicode) characters, like German "umlaut". Either in the search request or the response. Unfortunately in general I already test them in my test-cases. So either I missed a tested somewhere or it's a very special or broken character.
Looking forward...
Updated by Michael Gruth over 2 years ago
Hallo Jörg,
es passiert beim Reverse-Lookup, ich in dem Reverse Lookup ist mein
Eintrag und zwei Namen mit Umlauten (Wörner, Müller).
Ich kann es reproduzieren, jedesmal wenn ich mir die Einträge im in der
"Anrufliste" anschaue passiert der crash, danach muss ich dann die N670
rebooten.
Hie nochmal ein Crash mit "Debug" Flag an:
Nov 4 18:04:23 server02 l2cpbg[51773]: [server] Correlation Text
'192.168.1.210:42058|2021-11-04 18:04:23.838317584 +0100 CET
m=+38.439457079|1' = 0x82825740 = 82825740
Nov 4 18:04:23 server02 l2cpbg[51773]: [server] Search request #1:
(homePhone=01575xxxxx) from 192.168.1.210:42058 {82825740}
Nov 4 18:04:23 server02 l2cpbg[51773]: [server] Stats
&ldap.Stats{Conns:1, Binds:1, Unbinds:0, Searches:1,
statsMutex:sync.Mutex{state:0, sema:0x0}}
Nov 4 18:04:23 server02 l2cpbg[51773]: [server] Search(searchReq
ldap.SearchRequest{BaseDN:"ou=Kontakte, dc=gruth, dc=net", Scope:2,
DerefAliases:0, SizeLimit:99, TimeLimit:0, TypesOnly:false,
Filter:"(homePhone=01575xx xxxxx)", Attributes:[]string{"cn"},
Controls:[]ldap.Control{}}, ...
Nov 4 18:04:23 server02 l2cpbg[51773]: [server] s.request.Filter
'(homePhone=01575xxxxx)'
Nov 4 18:04:23 server02 l2cpbg[51773]: [server] DB search for key
prefix 'EKontakte.+491575123456' matching
'(?i)^EKontakte.+491575123456.'
Nov 4 18:04:23 server02 l2cpbg[51773]: [server] Regexp matching key
'EKontakte.+491575123456.a3ca482e-9822-463a-bb7c-91947d0a5133'
Nov 4 18:04:23 server02 l2cpbg[51773]: [server] Collected CardIds
map[{a3ca482e-9822-463a-bb7c-91947d0a5133 Kontakte}:true]
Nov 4 18:04:23 server02 l2cpbg[51773]: [server] 1 records returned for
search request #1: (homePhone=01575xxxxx) from 192.168.1.210:42058
{82825740}
Nov 4 18:04:23 server02 l2cpbg[51773]: panic: runtime error: slice
bounds out of range [:102] with capacity 8
Nov 4 18:04:23 server02 l2cpbg[51773]: goroutine 76 [running]:
Nov 4 18:04:23 server02 l2cpbg[51773]:
github.com/nmcclain/asn1-ber.decodePacket(0xc0001fc174, 0x2, 0x8,
0xc00021e360, 0xc0001fc174, 0x2, 0x8)
Nov 4 18:04:23 server02 l2cpbg[51773]:
#011/home/jebeling/go/pkg/mod/github.com/nmcclain/asn1-ber@v0.0.0-20170104154839-2661553a0484/ber.go:335
+0x7e5
Nov 4 18:04:23 server02 l2cpbg[51773]:
github.com/nmcclain/asn1-ber.decodePacket(0xc0001fc135, 0x47, 0x47,
0xc00021e0c0, 0xc0001fc135, 0x47, 0x47)
Nov 4 18:04:23 server02 l2cpbg[51773]:
#011/home/jebeling/go/pkg/mod/github.com/nmcclain/asn1-ber@v0.0.0-20170104154839-2661553a0484/ber.go:341
+0x279
Nov 4 18:04:23 server02 l2cpbg[51773]:
github.com/nmcclain/asn1-ber.decodePacket(0xc0001fc105, 0x77, 0x77,
0xc0004a1e00, 0xc0001fc105, 0x77, 0x77)
Nov 4 18:04:23 server02 l2cpbg[51773]:
#011/home/jebeling/go/pkg/mod/github.com/nmcclain/asn1-ber@v0.0.0-20170104154839-2661553a0484/ber.go:341
+0x279
Nov 4 18:04:23 server02 l2cpbg[51773]:
github.com/nmcclain/asn1-ber.decodePacket(0xc0001fc100, 0x7c, 0x7c,
0x7a, 0x7a, 0x0, 0x0)
Nov 4 18:04:23 server02 l2cpbg[51773]:
#011/home/jebeling/go/pkg/mod/github.com/nmcclain/asn1-ber@v0.0.0-20170104154839-2661553a0484/ber.go:341
+0x279
Nov 4 18:04:23 server02 l2cpbg[51773]:
github.com/nmcclain/asn1-ber.DecodePacket(...)
Nov 4 18:04:23 server02 l2cpbg[51773]:
#011/home/jebeling/go/pkg/mod/github.com/nmcclain/asn1-ber@v0.0.0-20170104154839-2661553a0484/ber.go:304
Nov 4 18:04:23 server02 l2cpbg[51773]:
github.com/nmcclain/asn1-ber.ReadPacket(0xe34c00, 0xc0000a88a0,
0xc0000a88a0, 0xe34c00, 0xc0000a88a0)
Nov 4 18:04:23 server02 l2cpbg[51773]:
#011/home/jebeling/go/pkg/mod/github.com/nmcclain/asn1-ber@v0.0.0-20170104154839-2661553a0484/ber.go:253
+0x56c
Nov 4 18:04:23 server02 l2cpbg[51773]:
github.com/nmcclain/ldap.(Server).handleConnection(0xc0001c30a0,
0xe48de0, 0xc0000a88a0)
Nov 4 18:04:23 server02 l2cpbg[51773]:
#011/usr/src/Apehaenger/ldap/server.go:231 +0x2e5
Nov 4 18:04:23 server02 l2cpbg[51773]: created by
github.com/nmcclain/ldap.(Server).Serve
Nov 4 18:04:23 server02 l2cpbg[51773]:
#011/usr/src/Apehaenger/ldap/server.go:215 +0xf6
Nov 4 18:04:23 server02 systemd[1]: l2cpbg.service: Main process
exited, code=exited, status=2/INVALIDARGUMENT
Nov 4 18:04:23 server02 systemd[1]: l2cpbg.service: Failed with result
'exit-code'.
Nov 4 18:04:24 server02 systemd[1]: l2cpbg.service: Scheduled restart
job, restart counter is at 1.
Nov 4 18:04:24 server02 l2cpbg[51795]: LDAP-2-CardDAV (1 way read)
Phone Book Gateway version 0.9.4beta4 @ linux-systemd
Nov 4 18:04:24 server02 l2cpbg[51795]: Loaded config '/etc/l2cpbg.conf'
Nov 4 18:04:24 server02 l2cpbg[51795]: [config] ldapAttributes
[]string{"c", "cn", "company", "department", "facsimileTelephoneNumber",
"givenName", "homePhone", "l", "mail", "mobile", "postalAddress",
"postalCode",
"sn ", "street",
"telephoneNumber"}
Nov 4 18:04:24 server02 l2cpbg[51795]: [intern] Decoded License data
internal.License{Info:internal.LicenseInfo{Company:"", Name:"Michael
Gruth", Email:"xxx@xxx.net", Street:"", Zip:"", City:"",
State:""}, Type:"E valuation", AppName:"L2CPBGRUL",
AppVersion:"^(0|1)\.", OsType:"", EndDate:time.Time{wall:0xcecff38,
ext:63776392688, loc:(time.Location)(0x122f8c0)}}
Nov 4 18:04:24 server02 l2cpbg[51795]: [intern] Evaluation licensed to
xxx@xxx.net until 2021-12-29
Nov 4 18:04:24 server02 l2cpbg[51795]: [ db ] DB directory
'/tmp/l2cpbg.db'
Nov 4 18:04:24 server02 l2cpbg[51795]: All 1 tables opened in 1ms
Nov 4 18:04:24 server02 l2cpbg[51795]: Replaying file id: 0 at offset:
4152040
Nov 4 18:04:24 server02 l2cpbg[51795]: Replay took: 11.126µs
Nov 4 18:04:24 server02 l2cpbg[51795]: [ db ] DB Version '2'
Nov 4 18:04:24 server02 l2cpbg[51795]: [server] ldapConfigCompString
"dc=gruth, dc=net\n49\n6109\n0\n7\ntrue\ntrue\nfalse\nDE\n3"
Nov 4 18:04:24 server02 l2cpbg[51795]: [client] Syncing with CardDAV
server 'https://server01:5001/carddav/grutmic/'...
Nov 4 18:04:24 server02 l2cpbg[51795]: [server] Start LDAP server on
0.0.0.0:1389
Nov 4 18:04:24 server02 l2cpbg[51795]: [client] Principal of user
'grutmic' = '/carddav/grutmic/'
Nov 4 18:04:24 server02 l2cpbg[51795]: [client] Address book home =
'/carddav/grutmic/'
Nov 4 18:04:24 server02 l2cpbg[51795]: [client] Found matching
AddressBook 'Kontakte'
Nov 4 18:04:24 server02 l2cpbg[51795]: [client] Found matching
AddressBook 'Intern'
Nov 4 18:04:24 server02 l2cpbg[51795]: [client] Got Sync-Token
'http://radicale.org/ns/sync/15_4547' for AddressBook 'Kontakte' from db
Nov 4 18:04:24 server02 l2cpbg[51795]: [client] Sync collection
'Kontakte' based on Sync-Token 'http://radicale.org/ns/sync/15_4547'
Nov 4 18:04:24 server02 l2cpbg[51795]: [client] Saving Sync-Token
'http://radicale.org/ns/sync/15_4547' for AddressBook 'Kontakte'
Nov 4 18:04:24 server02 l2cpbg[51795]: [client] Got Sync-Token
'http://radicale.org/ns/sync/16_4581' for AddressBook 'Intern' from db
Nov 4 18:04:24 server02 l2cpbg[51795]: [client] Sync collection
'Intern' based on Sync-Token 'http://radicale.org/ns/sync/16_4581'
Nov 4 18:04:24 server02 l2cpbg[51795]: [client] Saving Sync-Token
'http://radicale.org/ns/sync/16_4581' for AddressBook 'Intern'
Nov 4 18:06:33 server02 l2cpbg[51795]: [server] Correlation Text
'192.168.1.210:42070|2021-11-04 18:06:33.575603589 +0100 CET
m=+129.360214101|1' = 0xd3063921 = d3063921
Nov 4 18:06:33 server02 l2cpbg[51795]: [server] Search request #1:
(cn=) from 192.168.1.210:42070 {d3063921}
Nov 4 18:06:33 server02 l2cpbg[51795]: [server] Stats
&ldap.Stats{Conns:1, Binds:1, Unbinds:0, Searches:1,
statsMutex:sync.Mutex{state:0, sema:0x0}}
Nov 4 18:06:33 server02 l2cpbg[51795]: [server] Search(searchReq
ldap.SearchRequest{BaseDN:"ou=Kontakte, dc=gruth, dc=net", Scope:2,
DerefAliases:0, SizeLimit:99, TimeLimit:0, TypesOnly:false,
Filter:"(cn=)", Attribute s:[]string{"cn"}, Controls:[]ldap.Control{}}, ...
Nov 4 18:06:33 server02 l2cpbg[51795]: [server] s.request.Filter '(cn=)'
Gruß
Michael
Am 04.11.2021 um 17:57 schrieb Jörg Ebeling:
Removed sensible info
Updated by Michael Gruth over 2 years ago
Hallo Jörg,
es passiert beim Revers-Lookup der Anrufliste und eben ist es auch noch
beim Aufruf der Intern Liste (ein weiteres CARDDAV Adressbuch) passiert,
ich denke die letzte Mail war nicht rausgegangen, hängt auch mit dran.
Nov 4 18:19:24 server02 l2cpbg[51795]: [client] Syncing with CardDAV
server 'https://server01:5001/carddav/grutmic/'...
Nov 4 18:19:24 server02 l2cpbg[51795]: [client] Principal of user
'grutmic' = '/carddav/grutmic/'
Nov 4 18:19:24 server02 l2cpbg[51795]: [client] Address book home =
'/carddav/grutmic/'
Nov 4 18:19:24 server02 l2cpbg[51795]: [client] Found matching
AddressBook 'Kontakte'
Nov 4 18:19:24 server02 l2cpbg[51795]: [client] Found matching
AddressBook 'Intern'
Nov 4 18:19:24 server02 l2cpbg[51795]: [client] Got Sync-Token
'http://radicale.org/ns/sync/15_4547' for AddressBook 'Kontakte' from db
Nov 4 18:19:24 server02 l2cpbg[51795]: [client] Sync collection
'Kontakte' based on Sync-Token 'http://radicale.org/ns/sync/15_4547'
Nov 4 18:19:24 server02 l2cpbg[51795]: [client] Saving Sync-Token
'http://radicale.org/ns/sync/15_4547' for AddressBook 'Kontakte'
Nov 4 18:19:24 server02 l2cpbg[51795]: [client] Got Sync-Token
'http://radicale.org/ns/sync/16_4581' for AddressBook 'Intern' from db
Nov 4 18:19:24 server02 l2cpbg[51795]: [client] Sync collection
'Intern' based on Sync-Token 'http://radicale.org/ns/sync/16_4581'
Nov 4 18:19:24 server02 l2cpbg[51795]: [client] Saving Sync-Token
'http://radicale.org/ns/sync/16_4581' for AddressBook 'Intern'
Nov 4 18:19:51 server02 l2cpbg[51795]: [server] Correlation Text
'192.168.1.210:34136|2021-11-04 18:19:51.903834634 +0100 CET
m=+927.688445128|8' = 0x90f57f63 = 90f57f63
Nov 4 18:19:51 server02 l2cpbg[51795]: [server] Search request #8:
(cn=) from 192.168.1.210:34136 {90f57f63}
Nov 4 18:19:51 server02 l2cpbg[51795]: [server] Stats
&ldap.Stats{Conns:8, Binds:8, Unbinds:6, Searches:8,
statsMutex:sync.Mutex{state:0, sema:0x0}}
Nov 4 18:19:51 server02 l2cpbg[51795]: [server] Search(searchReq
ldap.SearchRequest{BaseDN:"ou=Intern, dc=gruth, dc=net", Scope:2,
DerefAliases:0, SizeLimit:50, TimeLimit:0, TypesOnly:false,
Filter:"(cn=)", Attributes:[]string{"cn"}, Controls:[]ldap.Control{}}, ...
Nov 4 18:19:51 server02 l2cpbg[51795]: [server] s.request.Filter '(cn=)'
Nov 4 18:19:51 server02 l2cpbg[51795]: [server] Regexp matching key
'mIntern.cn.erdgeschoss.7bd0a3b6-5b43-4949-ac88-7cf2ccbd4a83'
Nov 4 18:19:51 server02 l2cpbg[51795]: [server] Regexp matching key
'mIntern.cn.kellergeschoss.2ffb1107-bc0a-4358-82a0-88542810e782'
Nov 4 18:19:51 server02 l2cpbg[51795]: [server] Regexp matching key
'mIntern.cn.obergeschoss.c2f60026-6408-49ed-bb84-59f1c1a51082'
Nov 4 18:19:51 server02 l2cpbg[51795]: [server] Collected CardIds
map[{2ffb1107-bc0a-4358-82a0-88542810e782 Intern}:true
{7bd0a3b6-5b43-4949-ac88-7cf2ccbd4a83 Intern}:true
{c2f60026-6408-49ed-bb84-59f1c1a51082 Intern}:true]
Nov 4 18:19:51 server02 l2cpbg[51795]: [server] 4 records returned for
search request #8: (cn=) from 192.168.1.210:34136 {90f57f63}
Nov 4 18:20:47 server02 l2cpbg[51795]: panic: runtime error: slice
bounds out of range [:66] with capacity 8
Nov 4 18:20:47 server02 l2cpbg[51795]: goroutine 85 [running]:
Nov 4 18:20:47 server02 l2cpbg[51795]:
github.com/nmcclain/asn1-ber.decodePacket(0xc00018a862, 0x2, 0x8,
0xc005a84ae0, 0xc00018a862, 0x2, 0x8)
Nov 4 18:20:47 server02 l2cpbg[51795]:
#011/home/jebeling/go/pkg/mod/github.com/nmcclain/asn1-ber@v0.0.0-20170104154839-2661553a0484/ber.go:335
+0x7e5
Nov 4 18:20:47 server02 l2cpbg[51795]:
github.com/nmcclain/asn1-ber.decodePacket(0xc00018a817, 0x53, 0x53,
0xc005a84780, 0xc00018a817, 0x53, 0x53)
Nov 4 18:20:47 server02 l2cpbg[51795]:
#011/home/jebeling/go/pkg/mod/github.com/nmcclain/asn1-ber@v0.0.0-20170104154839-2661553a0484/ber.go:341
+0x279
Nov 4 18:20:47 server02 l2cpbg[51795]:
github.com/nmcclain/asn1-ber.decodePacket(0xc00018a7e6, 0x84, 0x84,
0xc005a844e0, 0xc00018a7e6, 0x84, 0x84)
Nov 4 18:20:47 server02 l2cpbg[51795]:
#011/home/jebeling/go/pkg/mod/github.com/nmcclain/asn1-ber@v0.0.0-20170104154839-2661553a0484/ber.go:341
+0x279
Nov 4 18:20:47 server02 l2cpbg[51795]:
github.com/nmcclain/asn1-ber.decodePacket(0xc00018a7e0, 0x8a, 0x8a,
0x87, 0x87, 0x0, 0x0)
Nov 4 18:20:47 server02 l2cpbg[51795]:
#011/home/jebeling/go/pkg/mod/github.com/nmcclain/asn1-ber@v0.0.0-20170104154839-2661553a0484/ber.go:341
+0x279
Nov 4 18:20:47 server02 l2cpbg[51795]:
github.com/nmcclain/asn1-ber.DecodePacket(...)
Nov 4 18:20:47 server02 l2cpbg[51795]:
#011/home/jebeling/go/pkg/mod/github.com/nmcclain/asn1-ber@v0.0.0-20170104154839-2661553a0484/ber.go:304
Nov 4 18:20:47 server02 l2cpbg[51795]:
github.com/nmcclain/asn1-ber.ReadPacket(0xe34c00, 0xc005d6e000,
0xc005d6e000, 0xe34c00, 0xc005d6e000)
Nov 4 18:20:47 server02 l2cpbg[51795]:
#011/home/jebeling/go/pkg/mod/github.com/nmcclain/asn1-ber@v0.0.0-20170104154839-2661553a0484/ber.go:253
+0x56c
Nov 4 18:20:47 server02 l2cpbg[51795]:
github.com/nmcclain/ldap.(*Server).handleConnection(0xc0001c4fc0,
0xe48de0, 0xc005d6e000)
Nov 4 18:20:47 server02 l2cpbg[51795]:
#011/usr/src/Apehaenger/ldap/server.go:231 +0x2e5
Nov 4 18:20:47 server02 l2cpbg[51795]: created by
github.com/nmcclain/ldap.(*Server).Serve
Nov 4 18:20:47 server02 l2cpbg[51795]:
#011/usr/src/Apehaenger/ldap/server.go:215 +0xf6
Nov 4 18:20:47 server02 systemd[1]: l2cpbg.service: Main process
exited, code=exited, status=2/INVALIDARGUMENT
Nov 4 18:20:47 server02 systemd[1]: l2cpbg.service: Failed with result
'exit-code'.
Nov 4 18:20:47 server02 systemd[1]: l2cpbg.service: Consumed 9.593s CPU
time.
Nov 4 18:20:47 server02 systemd[1]: l2cpbg.service: Scheduled restart
job, restart counter is at 2.
Nov 4 18:20:47 server02 systemd[1]: l2cpbg.service: Consumed 9.593s CPU
time.
Nov 4 18:20:47 server02 l2cpbg[52231]: LDAP-2-CardDAV (1 way read)
Phone Book Gateway version 0.9.4beta4 @ linux-systemd
Nov 4 18:20:47 server02 l2cpbg[52231]: Loaded config '/etc/l2cpbg.conf'
Hallo Jörg,
es passiert beim Reverse-Lookup, ich in dem Reverse Lookup ist mein
Eintrag und zwei Namen mit Umlauten (Wörner, Müller).
Ich kann es reproduzieren, jedesmal wenn ich mir die Einträge im in der
"Anrufliste" anschaue passiert der crash, danach muss ich dann die N670
rebooten.
Hie nochmal ein Crash mit "Debug" Flag an:
Nov 4 18:04:23 server02 l2cpbg[51773]: [server] Correlation Text
'192.168.1.210:42058|2021-11-04 18:04:23.838317584 +0100 CET
m=+38.439457079|1' = 0x82825740 = 82825740
Nov 4 18:04:23 server02 l2cpbg[51773]: [server] Search request #1:
(homePhone=0157xxxxxxxx) from 192.168.1.210:42058 {82825740}
Nov 4 18:04:23 server02 l2cpbg[51773]: [server] Stats
&ldap.Stats{Conns:1, Binds:1, Unbinds:0, Searches:1,
statsMutex:sync.Mutex{state:0, sema:0x0}}
Nov 4 18:04:23 server02 l2cpbg[51773]: [server] Search(searchReq
ldap.SearchRequest{BaseDN:"ou=Kontakte, dc=gruth, dc=net", Scope:2,
DerefAliases:0, SizeLimit:99, TimeLimit:0, TypesOnly:false,
Filter:"(homePhone=0157xxxxxxxx)", Attributes:[]string{"cn"},
Controls:[]ldap.Control{}}, ...
Nov 4 18:04:23 server02 l2cpbg[51773]: [server] s.request.Filter
'(homePhone=0157xxxxxxxx)'
Nov 4 18:04:23 server02 l2cpbg[51773]: [server] DB search for key
prefix 'EKontakte.+49157xxxxxxxx' matching
'(?i)^EKontakte.+49157xxxxxxxx.'
Nov 4 18:04:23 server02 l2cpbg[51773]: [server] Regexp matching key
'EKontakte.+49157xxxxxxxx.a3ca482e-9822-463a-bb7c-91947d0a5133'
Nov 4 18:04:23 server02 l2cpbg[51773]: [server] Collected CardIds
map[{a3ca482e-9822-463a-bb7c-91947d0a5133 Kontakte}:true]
Nov 4 18:04:23 server02 l2cpbg[51773]: [server] 1 records returned for
search request #1: (homePhone=0157xxxxxxxx) from 192.168.1.210:42058
{82825740}
Nov 4 18:04:23 server02 l2cpbg[51773]: panic: runtime error: slice
bounds out of range [:102] with capacity 8
Nov 4 18:04:23 server02 l2cpbg[51773]: goroutine 76 [running]:
Nov 4 18:04:23 server02 l2cpbg[51773]:
github.com/nmcclain/asn1-ber.decodePacket(0xc0001fc174, 0x2, 0x8,
0xc00021e360, 0xc0001fc174, 0x2, 0x8)
Nov 4 18:04:23 server02 l2cpbg[51773]:
#011/home/jebeling/go/pkg/mod/github.com/nmcclain/asn1-ber@v0.0.0-20170104154839-2661553a0484/ber.go:335
+0x7e5
Nov 4 18:04:23 server02 l2cpbg[51773]:
github.com/nmcclain/asn1-ber.decodePacket(0xc0001fc135, 0x47, 0x47,
0xc00021e0c0, 0xc0001fc135, 0x47, 0x47)
Nov 4 18:04:23 server02 l2cpbg[51773]:
#011/home/jebeling/go/pkg/mod/github.com/nmcclain/asn1-ber@v0.0.0-20170104154839-2661553a0484/ber.go:341
+0x279
Nov 4 18:04:23 server02 l2cpbg[51773]:
github.com/nmcclain/asn1-ber.decodePacket(0xc0001fc105, 0x77, 0x77,
0xc0004a1e00, 0xc0001fc105, 0x77, 0x77)
Nov 4 18:04:23 server02 l2cpbg[51773]:
#011/home/jebeling/go/pkg/mod/github.com/nmcclain/asn1-ber@v0.0.0-20170104154839-2661553a0484/ber.go:341
+0x279
Nov 4 18:04:23 server02 l2cpbg[51773]:
github.com/nmcclain/asn1-ber.decodePacket(0xc0001fc100, 0x7c, 0x7c,
0x7a, 0x7a, 0x0, 0x0)
Nov 4 18:04:23 server02 l2cpbg[51773]:
#011/home/jebeling/go/pkg/mod/github.com/nmcclain/asn1-ber@v0.0.0-20170104154839-2661553a0484/ber.go:341
+0x279
Nov 4 18:04:23 server02 l2cpbg[51773]:
github.com/nmcclain/asn1-ber.DecodePacket(...)
Nov 4 18:04:23 server02 l2cpbg[51773]:
#011/home/jebeling/go/pkg/mod/github.com/nmcclain/asn1-ber@v0.0.0-20170104154839-2661553a0484/ber.go:304
Nov 4 18:04:23 server02 l2cpbg[51773]:
github.com/nmcclain/asn1-ber.ReadPacket(0xe34c00, 0xc0000a88a0,
0xc0000a88a0, 0xe34c00, 0xc0000a88a0)
Nov 4 18:04:23 server02 l2cpbg[51773]:
#011/home/jebeling/go/pkg/mod/github.com/nmcclain/asn1-ber@v0.0.0-20170104154839-2661553a0484/ber.go:253
+0x56c
Nov 4 18:04:23 server02 l2cpbg[51773]:
github.com/nmcclain/ldap.(Server).handleConnection(0xc0001c30a0,
0xe48de0, 0xc0000a88a0)
Nov 4 18:04:23 server02 l2cpbg[51773]:
#011/usr/src/Apehaenger/ldap/server.go:231 +0x2e5
Nov 4 18:04:23 server02 l2cpbg[51773]: created by
github.com/nmcclain/ldap.(Server).Serve
Nov 4 18:04:23 server02 l2cpbg[51773]:
#011/usr/src/Apehaenger/ldap/server.go:215 +0xf6
Nov 4 18:04:23 server02 systemd[1]: l2cpbg.service: Main process
exited, code=exited, status=2/INVALIDARGUMENT
Nov 4 18:04:23 server02 systemd[1]: l2cpbg.service: Failed with result
'exit-code'.
Nov 4 18:04:24 server02 systemd[1]: l2cpbg.service: Scheduled restart
job, restart counter is at 1.
Nov 4 18:04:24 server02 l2cpbg[51795]: LDAP-2-CardDAV (1 way read)
Phone Book Gateway version 0.9.4beta4 @ linux-systemd
Nov 4 18:04:24 server02 l2cpbg[51795]: Loaded config '/etc/l2cpbg.conf'
Nov 4 18:04:24 server02 l2cpbg[51795]: [config] ldapAttributes
[]string{"c", "cn", "company", "department", "facsimileTelephoneNumber",
"givenName", "homePhone", "l", "mail", "mobile", "postalAddress",
"postalCode",
"sn ", "street",
"telephoneNumber"}
Nov 4 18:04:24 server02 l2cpbg[51795]: [intern] Decoded License data
internal.License{Info:internal.LicenseInfo{Company:"", Name:"Michael
Gruth", Email:"michael@gruth.net", Street:"", Zip:"", City:"",
State:""}, Type:"E valuation", AppName:"L2CPBGRUL",
AppVersion:"^(0|1)\.", OsType:"", EndDate:time.Time{wall:0xcecff38,
ext:63776392688, loc:(time.Location)(0x122f8c0)}}
Nov 4 18:04:24 server02 l2cpbg[51795]: [intern] Evaluation licensed to
michael@gruth.net until 2021-12-29
Nov 4 18:04:24 server02 l2cpbg[51795]: [ db ] DB directory
'/tmp/l2cpbg.db'
Nov 4 18:04:24 server02 l2cpbg[51795]: All 1 tables opened in 1ms
Nov 4 18:04:24 server02 l2cpbg[51795]: Replaying file id: 0 at offset:
4152040
Nov 4 18:04:24 server02 l2cpbg[51795]: Replay took: 11.126µs
Nov 4 18:04:24 server02 l2cpbg[51795]: [ db ] DB Version '2'
Nov 4 18:04:24 server02 l2cpbg[51795]: [server] ldapConfigCompString
"dc=gruth, dc=net\n49\n6109\n0\n7\ntrue\ntrue\nfalse\nDE\n3"
Nov 4 18:04:24 server02 l2cpbg[51795]: [client] Syncing with CardDAV
server 'https://server01:5001/carddav/grutmic/'...
Nov 4 18:04:24 server02 l2cpbg[51795]: [server] Start LDAP server on
0.0.0.0:1389
Nov 4 18:04:24 server02 l2cpbg[51795]: [client] Principal of user
'grutmic' = '/carddav/grutmic/'
Nov 4 18:04:24 server02 l2cpbg[51795]: [client] Address book home =
'/carddav/grutmic/'
Nov 4 18:04:24 server02 l2cpbg[51795]: [client] Found matching
AddressBook 'Kontakte'
Nov 4 18:04:24 server02 l2cpbg[51795]: [client] Found matching
AddressBook 'Intern'
Nov 4 18:04:24 server02 l2cpbg[51795]: [client] Got Sync-Token
'http://radicale.org/ns/sync/15_4547' for AddressBook 'Kontakte' from db
Nov 4 18:04:24 server02 l2cpbg[51795]: [client] Sync collection
'Kontakte' based on Sync-Token 'http://radicale.org/ns/sync/15_4547'
Nov 4 18:04:24 server02 l2cpbg[51795]: [client] Saving Sync-Token
'http://radicale.org/ns/sync/15_4547' for AddressBook 'Kontakte'
Nov 4 18:04:24 server02 l2cpbg[51795]: [client] Got Sync-Token
'http://radicale.org/ns/sync/16_4581' for AddressBook 'Intern' from db
Nov 4 18:04:24 server02 l2cpbg[51795]: [client] Sync collection
'Intern' based on Sync-Token 'http://radicale.org/ns/sync/16_4581'
Nov 4 18:04:24 server02 l2cpbg[51795]: [client] Saving Sync-Token
'http://radicale.org/ns/sync/16_4581' for AddressBook 'Intern'
Nov 4 18:06:33 server02 l2cpbg[51795]: [server] Correlation Text
'192.168.1.210:42070|2021-11-04 18:06:33.575603589 +0100 CET
m=+129.360214101|1' = 0xd3063921 = d3063921
Nov 4 18:06:33 server02 l2cpbg[51795]: [server] Search request #1:
(cn=) from 192.168.1.210:42070 {d3063921}
Nov 4 18:06:33 server02 l2cpbg[51795]: [server] Stats
&ldap.Stats{Conns:1, Binds:1, Unbinds:0, Searches:1,
statsMutex:sync.Mutex{state:0, sema:0x0}}
Nov 4 18:06:33 server02 l2cpbg[51795]: [server] Search(searchReq
ldap.SearchRequest{BaseDN:"ou=Kontakte, dc=gruth, dc=net", Scope:2,
DerefAliases:0, SizeLimit:99, TimeLimit:0, TypesOnly:false,
Filter:"(cn=)", Attribute s:[]string{"cn"}, Controls:[]ldap.Control{}}, ...
Nov 4 18:06:33 server02 l2cpbg[51795]: [server] s.request.Filter '(cn=)'
Gruß
Michael
Am 04.11.2021 um 17:57 schrieb Jörg Ebeling:
Updated by Jörg Ebeling over 2 years ago
Michael,
thanks a lot for the detailed info.
I build some additional tests with special German chars, but couldn't get L2CPBG to crash.
Could you please export me the VCF of the contact which let him crash during the reverse lookup?!
Send it as "Privater Kommentar" (under the edit box) or by Mail.
Also feel free to change the sensible information like phone number before sending the VCF.
In addition I built a debug version which prints the search-result directly before it get forwarded to the LDAP-Server.
Please be so kind, start it with "trace" logging level, fire the critical reverse lookup so that L2CPBG crashes and send me the result.
One last questions:
Do you have an idea why this crashes doesn't happen the days before?
Cheers
Jörg
Updated by Jörg Ebeling over 2 years ago
- File l2cpbg_0.9.4beta5dbg2_amd64.deb l2cpbg_0.9.4beta5dbg2_amd64.deb added
- File l2cpbg_0.9.4beta5dbg2_linux-amd64.tgz l2cpbg_0.9.4beta5dbg2_linux-amd64.tgz added
- File l2cpbg_0.9.4beta5dbg2_windows-64bit.zip l2cpbg_0.9.4beta5dbg2_windows-64bit.zip added
- % Done changed from 0 to 60
Hi Michael!
Here's a special version with debugging info about the connection packages which crashes the ASN1-Ber package decoding. With this infos, I should be able to debug, and hopefully fix, the crashes.
Logging level debug is enough.
Please install, let it crash and drop me the log.
Looking forward for the logs... and... thanks a lot for your ongoing support!!
Updated by Jörg Ebeling over 2 years ago
- File l2cpbg_0.9.4beta6dbg1_amd64.deb l2cpbg_0.9.4beta6dbg1_amd64.deb added
- File l2cpbg_0.9.4beta6dbg1_linux-amd64.tgz l2cpbg_0.9.4beta6dbg1_linux-amd64.tgz added
- File l2cpbg_0.9.4beta6dbg1_windows-64bit.zip l2cpbg_0.9.4beta6dbg1_windows-64bit.zip added
- Status changed from In Progress to Feedback
- % Done changed from 60 to 100
Hi Michael.
Thanks a lot for the debug log. It was very helpful.
I've been able now to identify the crash-packet. At the moment I've the impression that it is a broken/wrong packet, in special because also others @ github already detected such packets.
So I hardened the ASN1-Ber library for such packets so that it's not crashing anymore... at least for this kind of LDAP search request.
We should see now a "handleConnection ber.ReadPacket ERROR: ..." instead of the crash.
Not sure how your N670 will handle this, but L2CPBG should stay alive and with the new error we possibly might identify the kind of search request.
Looking forward to your feedback! ;-)